Hi,
after some time I've again used my speaker selector as GSD deivce (I wrote GSD code), but it doesn't work anymore.
Even more, sending command to it, crashes GSD device and causes restart of winxp Orbiter (probably some other too).
Cause errors in log are a bit cryptic and unfamiliar to me, I'm kindly asking if someone knows better what those messages mean and where to start fixing things :
DCERouter.log :
13 03/25/09 12:04:24.265 TCPIP: Accepting incoming connection on socket 80, port 3450, from IP 127.0.0.1. <0xb4439b90>
08 03/25/09 12:04:24.269 Received Message from 0 (unknown / ) to 81 (Zone 1:Bedroom / House Speakers), type 1 id 192 Command:On, retry none, parameters: <0x98dfab90>
08 03/25/09 12:04:24.269 Parameter 97(PK_Pipe): <0x98dfab90>
08 03/25/09 12:04:24.269 Parameter 98(PK_Device_Pipes): <0x98dfab90>
13 03/25/09 12:04:24.270 Ready to send message type 1 id 192 to 80 ESS-Speaker Selector RS232 on socket 127(0x79414608) using lock: 0x794146ec <0xb6c3eb90>
13 03/25/09 12:04:24.270 Response 1 to realsendmessage type 1 id 192 socket 153 using lock: 0x794146ec expected response: 0 <0xb6c3eb90>
13 03/25/09 12:04:24.270 Got response: 1 to message type 1 id 192 to 80 ESS-Speaker Selector RS232 on socket 153 using lock: 0x794146ec <0xb6c3eb90>
13 03/25/09 12:04:24.270 No response expected. returning <0xb6c3eb90>
3 03/25/09 12:04:25 DCERouter (server) Device died... count=10/200 dev=DCERouter
GSD device log :
/var/log/pluto/80_Generic_Serial_Device.log
25-03-2009 11:45:20 (***):SetVolumeInZone: volume: 100 [10] => Zone: 4
25-03-2009 11:45:20 (***):Send_RS232_Command: [0419]
25-03-2009 11:45:20 (***):Initialization of ESS GSD Device finished !!!!
25-03-2009 11:45:20 (***):Response from ESS: [0002]
25-03-2009 11:45:21 (***):Response from ESS: [0020]
25-03-2009 11:45:21 (***):Response from ESS: [0003]
25-03-2009 11:45:21 (***):Response from ESS: [0119]
25-03-2009 11:45:21 (***):Response from ESS: [0219]
25-03-2009 11:45:21 (***):Response from ESS: [0319]
25-03-2009 11:45:21 (***):Response from ESS: [0419]
05 03/25/09 12:04:24.270 GSDMessageTranslator isCmdImplemented = false <0xb6009b90>
05 03/25/09 12:04:24.299 #### Pre-Process Queue = 1 <0xb6009b90>
05 03/25/09 12:04:24.299 _QueueProc Pre - 192 : 0 <0xb780cb90>
05 03/25/09 12:04:24.300 GSD-Sleep Pre 192 : 0 <0xb780cb90>
05 03/25/09 12:04:24.300 Process Queue = 1 <0xb780cb90>
25-03-2009 12:04:24 (***):Got Command with ID: 192 from: 0 to: 81
25-03-2009 12:04:24 (***):SendZoneCommand: Child Zone Zone 1[1]
25-03-2009 12:04:24 (***):Send_RS232_Command: [0101]
05 03/25/09 12:04:24.303 GSD-Sleep Post 192 : 0 <0xb780cb90>
05 03/25/09 12:04:24.303 _QueueProc Post - 192 : 0 <0xb780cb90>
25-03-2009 12:04:24 (***):Response from ESS: [0101]
05 03/25/09 12:04:25.575 Socket::ReceiveData 0x80aa6c0 failed, bytes left 0 start: 109430000 1: 0 1b: 0 2: 0 2b: 0 m_Socket: 8 Command_Impl1 Dev #80 <0xb6009b90>
13 03/25/09 12:04:25.575 Socket::Close() m_Socket 8 <0xb6009b90>
13 03/25/09 12:04:25.575 Socket::Close() m_Socket 8 closesocket: 0 <0xb6009b90>
05 03/25/09 12:04:25.575 Socket::ReceiveString2 ReceiveData failed m_Socket: -1 Command_Impl1 Dev #80 <0xb6009b90>
01 03/25/09 12:04:25.575 Receive string failed in HandleRequestSocket 18:ReceiveData failed Command_Impl1 Dev #80 <0xb6009b90>
05 03/25/09 12:04:25.576 Dumping 1 locks <0xb6009b90>
05 03/25/09 12:04:25.576 finished check for exceptions <0xb6009b90>
05 03/25/09 12:04:25.576 OL: (0x80aa80c) (>102) MessageQueue Command_Impl.cpp l:822 time: 1:00:00a (1237979065 s) thread: 3061885840 Rel: Y Got: Y <0xb6009b90>
13 03/25/09 12:04:25.576 Exiting MessageQueueThread_DCECI thread... <0xb680ab90>
25-03-2009 12:04:25 (***):Send_RS232_Command: [0002]
05 03/25/09 12:04:25.624 Trying to send DATA while not connected. <0xb5808b90>
25-03-2009 12:04:25 (***):Send_RS232_Command: [0020]
05 03/25/09 12:04:25.624 Trying to send DATA while not connected. <0xb5808b90>
25-03-2009 12:04:25 (***):Send_RS232_Command: [0003]
05 03/25/09 12:04:25.625 Trying to send DATA while not connected. <0xb5808b90>
25-03-2009 12:04:25 (***):Shutting Down ESS GSD Device finished !!!!
13 03/25/09 12:04:25.625 Exiting BeginHandleRequestThread thread... <0xb6009b90>
13 03/25/09 12:04:25.802 Socket::Close() m_Socket 4 <0xb780d6c0>
13 03/25/09 12:04:25.802 Socket::Close() m_Socket 4 closesocket: 0 <0xb780d6c0>
13 03/25/09 12:04:25.802 Socket::Close() m_Socket 5 <0xb780d6c0>
13 03/25/09 12:04:25.802 Socket::Close() m_Socket 5 closesocket: 0 <0xb780d6c0>
13 03/25/09 12:04:25.805 Socket::~Socket(): deleting socket @0x80ab6d8 Event Dev #80 (socket id in destructor: m_Socket: -1) <0xb780d6c0>
13 03/25/09 12:04:25.805 Socket::~Socket(): deleting socket @0x813b318 Event Dev #80 (socket id in destructor: m_Socket: -1) <0xb780d6c0>
13 03/25/09 12:04:25.805 ~HandleRequestSocket 0x80aa6c0 device: 80 ip: 127.0.0.1 <0xb780d6c0>
13 03/25/09 12:04:25.805 RequestSocket::Disconnect 0x80aa6c0 device: 80 <0xb780d6c0>
13 03/25/09 12:04:25.805 Socket::~Socket(): deleting socket @0x80aa6c0 Command_Impl1 Dev #80 (socket id in destructor: m_Socket: -1) <0xb780d6c0>
Return code: 2
2 03/25/09 12:04:26 80 (spawning-device) Device requests restart... count=1/50 dev=80
Wed Mar 25 12:04:26 CET 2009 Restart
========== NEW LOG SECTION ==========
1 03/25/09 12:04:34 80 (spawning-device) Starting... 1
1 03/25/09 12:04:34 80 (spawning-device) Found /usr/pluto/bin/Generic_Serial_Device
05 03/25/09 12:04:37.288 Creating child 81 <0xb77b56c0>
05 03/25/09 12:04:37.288 Note: Device manager has attached a device of type 1867 that this has no custom event handler for. It will not fire events. <0xb77b56c0>
05 03/25/09 12:04:37.288 Note: Device manager has attached a device of type 1867 that this has no custom handler for. This is normal for IR. <0xb77b56c0>
05 03/25/09 12:04:37.288 Creating child 82 <0xb77b56c0>
05 03/25/09 12:04:37.288 Note: Device manager has attached a device of type 1867 that this has no custom event handler for. It will not fire events. <0xb77b56c0>
05 03/25/09 12:04:37.288 Note: Device manager has attached a device of type 1867 that this has no custom handler for. This is normal for IR. <0xb77b56c0>
05 03/25/09 12:04:37.288 Creating child 83 <0xb77b56c0>
05 03/25/09 12:04:37.289 Note: Device manager has attached a device of type 1867 that this has no custom event handler for. It will not fire events. <0xb77b56c0>
05 03/25/09 12:04:37.289 Note: Device manager has attached a device of type 1867 that this has no custom handler for. This is normal for IR. <0xb77b56c0>
05 03/25/09 12:04:37.289 Creating child 84 <0xb77b56c0>
05 03/25/09 12:04:37.289 Note: Device manager has attached a device of type 1867 that this has no custom event handler for. It will not fire events. <0xb77b56c0>
05 03/25/09 12:04:37.289 Note: Device manager has attached a device of type 1867 that this has no custom handler for. This is normal for IR. <0xb77b56c0>
RCODE:
0:require 'Ruby_Generic_Serial_Device'
1:class Command < Ruby_Generic_Serial_Device::RubyCommandWrapper
2:end
3:class Device_80 < Ruby_Generic_Serial_Device::RubySerialIOWrapper
4:#### 192 ####################################################################
5:def cmd_192(pk_pipe, pk_device_pipes, cmd=nil)
6:@returnParamArray.clear
7:SendZoneCommand(cmd)
8:
9:return @returnParamArray
10:end
11:#### 193 ####################################################################
12:def cmd_193(pk_pipe, cmd=nil)
13:@returnParamArray.clear
14:SendZoneCommand(cmd)
15:
16:return @returnParamArray
17:end
18:#### 313 ####################################################################
19:def cmd_313(level, cmd=nil)
20:@returnParamArray.clear
21:SendZoneCommand(cmd)
22:
23:return @returnParamArray
24:end
25:#### 350 ####################################################################
26:def cmd_350(cmd=nil)
27:@returnParamArray.clear
28:ReceiveReport()
29:
30:
31:return @returnParamArray
32:end
33:#### 355 ####################################################################
34:def cmd_355(cmd=nil)
35:@returnParamArray.clear
36:log("Initializing ESS GSD Device\n")
37:
38:sleep 1.0
39:Send_RS232_Command("0002"); #All Zones OFF
40:sleep 1.0
41:Send_RS232_Command("0020"); #All Zones Max Volume
42:sleep 1.0
43:Send_RS232_Command("0003"); #All Zones Select A
44:sleep 1.0
45:$ZoneVolumes = Hash.new()
46:$ZoneStatus = Hash.new()
47:
48:SetZones("OFF")
49:SetZonesInitialVolumes()
50:
51:log("Initialization of ESS GSD Device finished !!!!\n")
52:
53:
54:
55:return @returnParamArray
56:end
57:#### 356 ####################################################################
58:def cmd_356(cmd=nil)
59:@returnParamArray.clear
60:Send_RS232_Command("0002"); #All Zones OFF
61:
62:Send_RS232_Command("0020"); #All Zones Max Volume
63:
64:Send_RS232_Command("0003"); #All Zones Select A
65:
66:
67:log("Shutting Down ESS GSD Device finished !!!!\n")
68:
69:return @returnParamArray
70:end
71:#### PRIVATE METHODS ####################################################################
72:###########################################################3 Internal Methods
73:# To do list :
74:# - parsing of response from device (needed for advanced use)
75:#
76:#
77:# RS232 protocol, ZN=Zone Number (00 is all, 01-31 separate zones)
78:# ZN 01 ON
79:# ZN 02 OFF
80:# ZN 03 A AMP
81:# ZN 04 B AMP
82:# ZN 07 VOLUME UP
83:# ZN 08 VOLUME DOWN
84:# ZN 09 SET LEVEL 0
85:# ZN 10 SET LEVEL 1
86:# ZN 11 SET LEVEL 2
87:# ZN 12 SET LEVEL 3
88:# ZN 13 SET LEVEL 4
89:# ZN 14 SET LEVEL 5
90:# ZN 15 SET LEVEL 6
91:# ZN 16 SET LEVEL 7
92:# ZN 17 SET LEVEL 8
93:# ZN 18 SET LEVEL 9
94:# ZN 19 SET LEVEL 10
95:# ZN 20 SET LEVEL 11
96:# ZN 32 ? STATUS
97:# ZN 33 ? LEVEL
98:# ZN 34 ? ON/OFF
99:# ZN 35 ? A/B
100:#Example responses to queries (todo)
101:#[0132]{16}
102:#[0133]{06}
103:#[0032]{16}
104:#{16}
105:#{1B}
106:#{3B}
107:#[0034]{10}
108:#{10}
109:#{10}
110:#{10}
111:#[0035]{00}
112:#{00}
113:#{00}
114:#{20}
115:
116:
117:def log(line)
118: $log = File.open("/var/log/pluto/" + device_.devid_.to_s + "_Generic_Serial_Device.log", "a")
119:# $log = File.open("/var/log/pluto/ESS.log", "a")
120: logTime = Time.now
121: timeStr = logTime.strftime("%d-%m-%Y %H:%M:%S ")
122:
123: $log.puts timeStr + "(***):" + line.to_s
124: $log.close
125:end
126:
127:def Send_RS232_Command(command)
128: log("Send_RS232_Command: [" + command+ "]\n")
129: conn_.Send("[" + command+ "]")
130:end
131:
132:
133:def SendZoneCommand(cmd)
134:
135: log("Got Command with ID: " + cmd.id_.to_s + " from: " + cmd.devidfrom_.to_s + " to: " + cmd.devidto_.to_s + "\n")
136: zone = GetZone(cmd.devidto_)
137: if( zone >= 0 )
138:# zone_desc=device_.childdevices_[cmd.devidto_].devdata_[186]
139: zone_desc = sprintf ("Zone %d",zone)
140: log("SendZoneCommand: Child Zone " + zone_desc + "[" + zone.to_s + "]\n")
141: elsif (cmd.devidto_ == device_.devid_)
142: log("SendZoneCommand: All Zones " + zone.to_s + ". Sending command to all zones !!!")
143: zone=0
144: zone_desc="All Zones"
145: else
146: log("SendZoneCommand: Invalid zone " + zone.to_s + ". Send commands only to valid devices!!!")
147: end
148:
149: serial_command = ""
150:
151: case cmd.id_
152: when 192 #192 is ON
153: serial_command = sprintf("%02d",zone)+sprintf("%02d",1);
154: Send_RS232_Command(serial_command);
155: temp_cmd = Command.new(cmd.id_, -1001, 1, 2, 48);
156: temp_cmd.params_[10] = "1";
157: SendCommand(temp_cmd);
158: $ZoneStatus[zone.to_s] = "ON";
159: if (zone==0)
160: SetZones("ON")
161: end
162: when 193 #193 is OFF
163: serial_command = sprintf("%02d",zone)+sprintf("%02d",2);
164: Send_RS232_Command(serial_command);
165: temp_cmd = Command.new(cmd.id_, -1001, 1, 2, 48);
166: temp_cmd.params_[10] = "0";
167: SendCommand(temp_cmd);
168: $ZoneStatus[zone.to_s] = "OFF";
169: if (zone==0)
170: SetZones("OFF")
171: end
172:
173: when 90 #90 is Volume Down
174: serial_command = sprintf("%02d",zone)+sprintf("%02d",8);
175: Send_RS232_Command(serial_command);
176: $ZoneVolumes[zone.to_s] = $ZoneVolumes[zone.to_s] - 10
177: if ($ZoneVolumes[zone.to_s]<0)
178: $ZoneVolumes[zone.to_s]=0
179: end
180: SetDeviceDataInDB( cmd.devidto_, 158, ($ZoneVolumes[zone.to_s]).to_s ) # 158 = DEVICEDATA_Volume_Level_CONST
181: temp_cmd = Command.new(cmd.devidto_, -1001, 1, 2, 71);
182: temp_cmd.params_[30] = ($ZoneVolumes[zone.to_s]).to_s
183: SendCommand(temp_cmd);
184:
185: when 89 #90 is Volume Up
186: serial_command = sprintf("%02d",zone)+sprintf("%02d",7);
187: Send_RS232_Command(serial_command);
188: $ZoneVolumes[zone.to_s] = $ZoneVolumes[zone.to_s] + 10
189: if ($ZoneVolumes[zone.to_s]>=120)
190: $ZoneVolumes[zone.to_s]=110
191: end
192: SetDeviceDataInDB( cmd.devidto_, 158, ($ZoneVolumes[zone.to_s]).to_s ) # 158 = DEVICEDATA_Volume_Level_CONST
193: temp_cmd = Command.new(cmd.devidto_, -1001, 1, 2, 71);
194: temp_cmd.params_[30] = ($ZoneVolumes[zone.to_s]).to_s
195: SendCommand(temp_cmd);
196: when 313 #313 is Set Volume with Level as Param #76
197: log("313:Set Volume Command: Got Cmd with ID: " + cmd.id_.to_s + " from: " + cmd.devidfrom_.to_s + " to: " + cmd.devidto_.to_s + " | Zone : " + zone.to_s + "\n")
198: level=(cmd.params_[76]).to_i
199: if level >110
200: level=110
201: log("313:Set Volume Command: Volume too high - truncated to max level of 110\n")
202: elsif level <0
203: level=0
204: log("313:Set Volume Command: Volume too low - truncated to min level of 0\n")
205: end
206: level = (level/10.0).round
207: serial_command = sprintf("%02d",zone)+sprintf("%02d",level+9);
208: Send_RS232_Command(serial_command);
209: $ZoneVolumes[zone.to_s] = (cmd.params_[76]).to_i
210: SetDeviceDataInDB( cmd.devidto_, 158, ($ZoneVolumes[zone.to_s]).to_s ) # 158 = DEVICEDATA_Volume_Level_CONST
211: temp_cmd = Command.new(cmd.devidto_, -1001, 1, 2, 71);
212: temp_cmd.params_[30] = ($ZoneVolumes[zone.to_s]).to_s
213: SendCommand(temp_cmd);
214: if (zone==0)
215: SetVolumes($ZoneVolumes[zone.to_s])
216: end
217:
218: when 616 #616 is Select A
219: serial_command = sprintf("%02d",zone)+sprintf("%02d",3);
220: Send_RS232_Command(serial_command);
221: when 617 #617 is Select B
222: serial_command = sprintf("%02d",zone)+sprintf("%02d",4);
223: Send_RS232_Command(serial_command);
224: else
225: log("Yet not implemented: Handler for command: ID " + cmd.id.to_s)
226: end
227:
228:
229:end
230:
231:
232:def GetZone(deviceDestination)
233: if( device_.mapDevice_PortChannel_.has_key?(deviceDestination) and
234: device_.mapDevice_PortChannel_[deviceDestination] != nil and
235: !device_.mapDevice_PortChannel_[deviceDestination].empty? )
236: return device_.mapDevice_PortChannel_[deviceDestination].to_i
237: end
238:
239: return -1
240:end
241:
242:
243:def ReceiveReport()
244: @buff = conn_.RecvDelimited("]", 1000)
245: log("Response from ESS: " + @buff + "\n")
246:# log("Calling DecodeReceivedInfo: " + @buff + "\n")
247:# temp_resp=@buff;
248:# DecodeReceivedInfo(temp_resp)
249:# log("End of DecodeReceivedInfo: " + temp_resp + "\n")
250:end
251:
252:def SetVolumeInZone(level,zone)
253:# Sets Normalized Volume Level (0..100) in certain zone
254: normlevel = (level.to_i/10.0).round
255: log("SetVolumeInZone: volume: " + level.to_s + " ["+ normlevel.to_s + "] => Zone: " + zone + "\n")
256:
257: serial_command = sprintf("%02d",zone)+sprintf("%02d",normlevel+9);
258: Send_RS232_Command(serial_command);
259:# log("313:Set Volume Command: Got Cmd with ID: " + cmd.id_.to_s + " from: " + cmd.devidfrom_.to_s + " to: " + cmd.devidto_.to_s + " | Zone : " + zone.to_s + "\n")
260: $ZoneVolumes[zone.to_s] = level.to_i
261:
262:end
263:
264:def SetZonesInitialVolumes()
265: log("####### Set Initial Volume Levels for zones\n")
266: device_.mapDevice_PortChannel_.each do |key, value|
267: volume = device_.childdevices_[key].devdata_[208]
268: log("Zone " + value.to_s + " => " + volume.to_s + "\n")
269: sleep 1.0
270: SetVolumeInZone(volume.to_i,value)
271: SetDeviceDataInDB( device_.childdevices_[key].devid_, 158, ($ZoneVolumes[value.to_s]).to_s ) # 158 = DEVICEDATA_Volume_Level_CONST
272: end
273:
274:end
275:
276:
277:def SetZones(state)
278: log("####### Setting all zones to " + state + "\n")
279: device_.mapDevice_PortChannel_.each do |key, value|
280: $ZoneStatus[value] = state
281: log("Zone " + value.to_s + " => " + state + "\n")
282: end
283:end
284:
285:def SetVolumes(level_int)
286: log("####### Set Volume Levels for all zones\n")
287: device_.mapDevice_PortChannel_.each do |key, value|
288: log("Zone " + value.to_s + " => " + level_int.to_s + "\n")
289: $ZoneVolumes[value.to_s] = level_int
290: SetDeviceDataInDB( device_.childdevices_[key].devid_, 158, ($ZoneVolumes[value.to_s]).to_s ) # 158 = DEVICEDATA_Volume_Level_CONST
291: end
292:end
293:def cmd_ReceiveCommandForChild(cmd)
294:SendZoneCommand(cmd)
295:
296:end
297:#### 953 ####################################################################
298:def cmd_953(cmd=nil)
299:@returnParamArray.clear
300:SendZoneCommand(cmd)
301:
302:return @returnParamArray
303:end
304:#### 954 ####################################################################
305:def cmd_954(cmd=nil)
306:@returnParamArray.clear
307:SendZoneCommand(cmd)
308:
309:return @returnParamArray
310:end
311:#### START SETTERS ####################################################################
312:def initialize()
313:super
314:@returnParamArray=Array.new
315:end
316:#### END SETTERS ####################################################################
317:end
Thanks in advance,
regards,
Bulek.