Thu Feb 28 15:45:32 EST 2008 Restart ========== NEW LOG SECTION ========== 1 02/28/08 15:45:40 33 (spawning-device) [1;00mStarting... 1[1;00m 1 02/28/08 15:45:40 33 (spawning-device) [1;00mFound /usr/pluto/bin/ZWave[1;00m 10 02/28/08 15:45:40.354 Device: 33 starting. Connecting to: localhost <0x2ac6a384bb40> 10 02/28/08 15:45:40.359 Setting timeout for socket 4 to 20 <0x2ac6a384bb40> 10 02/28/08 15:45:40.359 DCE Router asked us to wait--it's busy at the moment <0x2ac6a384bb40> 10 02/28/08 15:45:41.484 Socket::SendMessage type 5 id 37 from 33 to -1000 <0x2ac6a384bb40> 10 02/28/08 15:45:41.591 TranslateSerialUSB found /sys/devices/pci0000:00/0000:00:0b.0/usb1/1-5/1-5:1.0/ttyUSB0/ttyUSB0, returning /dev/ttyUSB0 <0x2ac6a384bb40> 36 02/28/08 15:45:41.591 Using serial port: ttyUSB0. <0x2ac6a384bb40> 36 02/28/08 15:45:41.602 SerialConnection::connect init serial mutex <0x2ac6a384bb40> 36 02/28/08 15:45:41.602 receive thread created OK!!!! <0x2ac6a384bb40> 35 02/28/08 15:45:41.602 entry point receiveFunction <0x41001950> 35 02/28/08 15:45:41.809 ++++++++++++ ZWave is connected <0x2ac6a384bb40> 36 02/28/08 15:45:41.809 ### Run Current Job <0x41802950> 36 02/28/08 15:45:41.865 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:41.865 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:45:41.865 SerialConnection::send unlock serial mutex <0x41802950> 05 02/28/08 15:45:46.044 [33;1m### Go to timeout queue[0m <0x41802950> 05 02/28/08 15:45:46.045 [33;1m### execute the next job from timeout queue[0m <0x41802950> 05 02/28/08 15:45:46.045 [33;1mZWJobInitialize::timeoutHandler[0m <0x41802950> 36 02/28/08 15:45:46.100 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:46.100 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:45:46.101 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:46.380 size too small 1 <0x41802950> 35 02/28/08 15:45:46.436 size too small 1 <0x41802950> 35 02/28/08 15:45:46.492 size too small 1 <0x41802950> 35 02/28/08 15:45:46.548 size too small 1 <0x41802950> 35 02/28/08 15:45:46.604 size too small 1 <0x41802950> 35 02/28/08 15:45:46.660 size too small 1 <0x41802950> 05 02/28/08 15:45:51.028 [33;1m### Go to timeout queue[0m <0x41802950> 05 02/28/08 15:45:51.028 [33;1m### execute the next job from timeout queue[0m <0x41802950> 05 02/28/08 15:45:51.028 [33;1mZWJobInitialize::timeoutHandler[0m <0x41802950> 36 02/28/08 15:45:51.084 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:51.084 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:45:51.084 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:51.308 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:45:51.308 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:45:51.308 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:45:51.308 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:45:51.308 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:45:51.308 receiveCommand::begin <0x41802950> 35 02/28/08 15:45:51.308 buffer.size()= 18 <0x41802950> 35 02/28/08 15:45:51.308 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:45:51.308 SerialConnection : received command len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:45:51.309 ZWJobInitialize len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:45:51.309 ZWJobGetVersion len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:45:51.309 Z-Wave 2.24 <0x41802950> 36 02/28/08 15:45:51.364 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:51.364 SerialConnection::send len = 2 buf = 0x00 0x20 <0x41802950> 36 02/28/08 15:45:51.364 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:51.644 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:45:51.644 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:45:51.644 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:45:51.644 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:45:51.644 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:45:51.644 receiveCommand::begin <0x41802950> 35 02/28/08 15:45:51.644 buffer.size()= 10 <0x41802950> 35 02/28/08 15:45:51.644 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:45:51.644 SerialConnection : received command len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:45:51.644 ZWJobInitialize len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:45:51.644 ZWJobGetID len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 36 02/28/08 15:45:51.700 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:51.700 SerialConnection::send len = 2 buf = 0x00 0x02 <0x41802950> 36 02/28/08 15:45:51.700 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:51.924 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:45:52.260 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:45:52.260 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:45:52.260 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:45:52.260 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:45:52.260 receiveCommand::begin <0x41802950> 35 02/28/08 15:45:52.260 buffer.size()= 39 <0x41802950> 35 02/28/08 15:45:52.260 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:45:52.260 SerialConnection : received command len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:45:52.260 ZWJobInitialize len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:45:52.260 ZWJobGetInitData len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 36 02/28/08 15:45:52.316 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:52.316 SerialConnection::send len = 3 buf = 0x00 0x52 0x01 <0x41802950> 36 02/28/08 15:45:52.316 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:52.540 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:45:52.540 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:45:52.540 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:45:52.540 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:45:52.540 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:45:52.540 receiveCommand::begin <0x41802950> 35 02/28/08 15:45:52.540 buffer.size()= 6 <0x41802950> 35 02/28/08 15:45:52.540 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:45:52.540 SerialConnection : received command len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:45:52.540 ZWJobInitialize len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:45:52.540 ZWJobGetSUC len = 3 buf = 0x01 0x52 0x01 <0x41802950> 36 02/28/08 15:45:52.596 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:52.596 SerialConnection::send len = 2 buf = 0x00 0x56 <0x41802950> 36 02/28/08 15:45:52.596 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:52.876 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:45:52.876 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:45:52.876 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:45:52.876 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:45:52.876 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:45:52.876 receiveCommand::begin <0x41802950> 35 02/28/08 15:45:52.876 buffer.size()= 6 <0x41802950> 35 02/28/08 15:45:52.876 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:45:52.876 SerialConnection : received command len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:45:52.876 ZWJobInitialize len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:45:52.876 ZWJobGetSUC len = 3 buf = 0x01 0x56 0x00 <0x41802950> 36 02/28/08 15:45:52.932 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:45:52.932 SerialConnection::send len = 3 buf = 0x00 0x41 0x01 <0x41802950> 36 02/28/08 15:45:52.932 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:45:53.156 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:45:53.156 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:45:53.156 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:45:53.156 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:45:53.156 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:45:53.156 receiveCommand::begin <0x41802950> 35 02/28/08 15:45:53.156 buffer.size()= 11 <0x41802950> 35 02/28/08 15:45:53.156 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:45:53.156 SerialConnection : received command len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:45:53.157 ZWJobInitialize len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:45:53.157 ZWJobGetNodeProtocolInfo len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:45:53.157 ----- INIT ---- 3 <0x41802950> 35 02/28/08 15:45:53.157 ----- INIT ---- 1 <0x41802950> 35 02/28/08 15:45:53.157 ----- INIT ---- 2 <0x41802950> 36 02/28/08 15:45:53.157 ## Current Job Finished --- Left = 0 <0x41802950> 36 02/28/08 15:45:53.158 ZWave::ReportChildDevices trying to get list of devices <0x42003950> 36 02/28/08 15:45:53.158 ZWave::ReportChildDevices got: <0x42003950> 36 02/28/08 15:45:53.158 <0x42003950> 10 02/28/08 15:45:53.158 Socket::SendMessage type 2 id 54 from 33 to -1001 <0x42003950> 10 02/28/08 15:45:53.161 Connect OK <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mCreating child 34[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.161 Got CreateEvent for unknown type 1820. <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mNote: Device manager has attached a device of type 1820 that this has no custom event handler for. It will not fire events.[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.161 Got CreateCommand for unknown type 1820. <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mNote: Device manager has attached a device of type 1820 that this has no custom handler for. This is normal for IR.[0m <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mCreating child 35[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.161 Got CreateEvent for unknown type 38. <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mNote: Device manager has attached a device of type 38 that this has no custom event handler for. It will not fire events.[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.161 Got CreateCommand for unknown type 38. <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mNote: Device manager has attached a device of type 38 that this has no custom handler for. This is normal for IR.[0m <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mCreating child 36[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.161 Got CreateEvent for unknown type 38. <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mNote: Device manager has attached a device of type 38 that this has no custom event handler for. It will not fire events.[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.161 Got CreateCommand for unknown type 38. <0x2ac6a384bb40> 05 02/28/08 15:45:53.161 [33;1mNote: Device manager has attached a device of type 38 that this has no custom handler for. This is normal for IR.[0m <0x2ac6a384bb40> 10 02/28/08 15:45:53.162 Requesthandler 0x667590 (device: 33) runThread now running <0x43005950> 10 02/28/08 15:45:53.468 Receive string: <0x43005950> 10 02/28/08 15:45:53.468 Received 0x667590 device: 33 <0x43005950> 10 02/28/08 15:46:56.175 Receive string: MESSAGE 72 <0x43005950> 10 02/28/08 15:46:56.176 Received MESSAGE 72 0x667590 device: 33 <0x43005950> 10 02/28/08 15:46:56.176 Received Message type 1 ID 193 from 0 to 35 (device: 33) resp 3 <0x43005950> 36 02/28/08 15:46:56.176 Sending Off - 1 <0x43005950> 36 02/28/08 15:46:56.210 ### Run Current Job <0x41802950> 36 02/28/08 15:46:56.267 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:46:56.343 SerialConnection::send len = 9 buf = 0x00 0x13 0x01 0x03 0x25 0x01 0x00 0x05 0x01 <0x41802950> 36 02/28/08 15:46:56.344 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:46:56.695 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:46:56.695 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:46:56.695 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:46:56.696 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:46:56.696 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:46:56.696 receiveCommand::begin <0x41802950> 35 02/28/08 15:46:56.696 buffer.size()= 6 <0x41802950> 35 02/28/08 15:46:56.696 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:46:56.696 SerialConnection : received command len = 3 buf = 0x01 0x13 0x01 <0x41802950> 35 02/28/08 15:46:56.696 ZWJobSwitchChangeLevel: len = 3 buf = 0x01 0x13 0x01 <0x41802950> 35 02/28/08 15:46:56.975 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:46:56.975 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:46:56.975 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:46:56.975 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:46:56.976 receiveCommand::begin <0x41802950> 35 02/28/08 15:46:56.976 buffer.size()= 7 <0x41802950> 35 02/28/08 15:46:56.976 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:46:56.976 SerialConnection : received command len = 4 buf = 0x00 0x13 0x01 0x01 <0x41802950> 35 02/28/08 15:46:56.976 ZWJobSwitchChangeLevel: len = 4 buf = 0x00 0x13 0x01 0x01 <0x41802950> 35 02/28/08 15:46:56.976 ZWJobSwitchChangeLevel: processData the tx status is here <0x41802950> 05 02/28/08 15:46:56.976 [33;1mcommand not ack, device not reachable[0m <0x41802950> 36 02/28/08 15:46:56.976 ## Current Job Finished --- Left = 0 <0x41802950> 10 02/28/08 15:53:13.765 Receive string: MESSAGE 72 <0x43005950> 10 02/28/08 15:53:13.765 Received MESSAGE 72 0x667590 device: 33 <0x43005950> 10 02/28/08 15:53:13.765 Received Message type 1 ID 757 from 0 to 33 (device: 33) resp 0 <0x43005950> 36 02/28/08 15:53:13.765 ZWave::DownloadConfiguration trying to get list of devices <0x43806950> 35 02/28/08 15:53:13.765 -------- 3 <0x43806950> 35 02/28/08 15:53:13.765 SerialConnection ------------- asa 1 <0x43806950> 35 02/28/08 15:53:13.871 SerialConnection ------------- asa 2 <0x43806950> 36 02/28/08 15:53:13.872 waiting for thread to finish <0x43806950> 35 02/28/08 15:53:13.887 exit receiveFunction : nr. of reads 1471 <0x41001950> 36 02/28/08 15:53:13.888 thread finished <0x43806950> 35 02/28/08 15:53:13.888 SerialConnection ------------- asa 3 <0x43806950> 35 02/28/08 15:53:13.888 SerialConnection ------------- asa 4 <0x43806950> 35 02/28/08 15:53:13.888 -------- 4 <0x43806950> 36 02/28/08 15:53:13.899 SerialConnection::connect init serial mutex <0x43806950> 36 02/28/08 15:53:13.899 receive thread created OK!!!! <0x43806950> 35 02/28/08 15:53:13.899 entry point receiveFunction <0x40800950> 35 02/28/08 15:53:14.103 ++++++++++++ ZWave is connected <0x43806950> 36 02/28/08 15:53:14.115 ### Run Current Job <0x41802950> 36 02/28/08 15:53:14.171 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:53:14.171 SerialConnection::send len = 7 buf = 0x00 0x03 0x01 0x02 0x01 0x01 0x21 <0x41802950> 36 02/28/08 15:53:14.172 SerialConnection::send unlock serial mutex <0x41802950> 36 02/28/08 15:53:14.735 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:53:14.735 SerialConnection::send len = 3 buf = 0x00 0x42 0x02 <0x41802950> 36 02/28/08 15:53:14.736 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:53:14.959 size too small 1 <0x41802950> 35 02/28/08 15:53:15.015 size too small 1 <0x41802950> 35 02/28/08 15:53:15.071 size too small 1 <0x41802950> 35 02/28/08 15:53:15.127 size too small 1 <0x41802950> 35 02/28/08 15:53:15.183 size too small 1 <0x41802950> 35 02/28/08 15:53:15.239 size too small 1 <0x41802950> 35 02/28/08 15:53:15.295 size too small 1 <0x41802950> 35 02/28/08 15:53:15.351 size too small 1 <0x41802950> 35 02/28/08 15:53:15.407 size too small 1 <0x41802950> 35 02/28/08 15:53:15.467 size too small 1 <0x41802950> 35 02/28/08 15:53:15.523 size too small 1 <0x41802950> 35 02/28/08 15:53:15.579 size too small 1 <0x41802950> 35 02/28/08 15:53:15.635 size too small 1 <0x41802950> 35 02/28/08 15:53:15.691 size too small 1 <0x41802950> 35 02/28/08 15:53:15.747 size too small 1 <0x41802950> 35 02/28/08 15:53:15.803 size too small 1 <0x41802950> 35 02/28/08 15:53:15.859 size too small 1 <0x41802950> 35 02/28/08 15:53:15.915 size too small 1 <0x41802950> 35 02/28/08 15:53:15.971 size too small 1 <0x41802950> 35 02/28/08 15:53:16.027 size too small 1 <0x41802950> 35 02/28/08 15:53:16.083 size too small 1 <0x41802950> 35 02/28/08 15:53:16.139 size too small 1 <0x41802950> 35 02/28/08 15:53:16.195 size too small 1 <0x41802950> 35 02/28/08 15:53:16.251 size too small 1 <0x41802950> 35 02/28/08 15:53:16.307 size too small 1 <0x41802950> 35 02/28/08 15:53:16.363 size too small 1 <0x41802950> 35 02/28/08 15:53:16.419 size too small 1 <0x41802950> 35 02/28/08 15:53:16.475 size too small 1 <0x41802950> 35 02/28/08 15:53:16.531 size too small 1 <0x41802950> 35 02/28/08 15:53:16.587 size too small 1 <0x41802950> 35 02/28/08 15:53:16.643 size too small 1 <0x41802950> 35 02/28/08 15:53:16.699 size too small 1 <0x41802950> 35 02/28/08 15:53:16.755 size too small 1 <0x41802950> 35 02/28/08 15:53:16.811 size too small 1 <0x41802950> 35 02/28/08 15:53:16.867 size too small 1 <0x41802950> 35 02/28/08 15:53:16.923 size too small 1 <0x41802950> 35 02/28/08 15:53:16.979 size too small 1 <0x41802950> 35 02/28/08 15:53:17.035 size too small 1 <0x41802950> 35 02/28/08 15:53:17.091 size too small 1 <0x41802950> 35 02/28/08 15:53:17.147 size too small 1 <0x41802950> 35 02/28/08 15:53:17.203 size too small 1 <0x41802950> 35 02/28/08 15:53:17.259 size too small 1 <0x41802950> 35 02/28/08 15:53:17.315 size too small 1 <0x41802950> 35 02/28/08 15:53:17.371 size too small 1 <0x41802950> 35 02/28/08 15:53:17.427 size too small 1 <0x41802950> 35 02/28/08 15:53:17.483 size too small 1 <0x41802950> 35 02/28/08 15:53:17.539 size too small 1 <0x41802950> 35 02/28/08 15:53:17.595 size too small 1 <0x41802950> 35 02/28/08 15:53:17.651 size too small 1 <0x41802950> 35 02/28/08 15:53:17.707 size too small 1 <0x41802950> 35 02/28/08 15:53:17.763 size too small 1 <0x41802950> 35 02/28/08 15:53:17.819 size too small 1 <0x41802950> 35 02/28/08 15:53:17.875 size too small 1 <0x41802950> 35 02/28/08 15:53:17.931 size too small 1 <0x41802950> 35 02/28/08 15:53:17.987 size too small 1 <0x41802950> 05 02/28/08 15:53:21.011 [33;1m-------------------------- Job Timeout _________[0m <0x41802950> 10 02/28/08 15:53:21.015 Socket::SendMessage type 2 id 55 from 33 to -1001 <0x43806950> 35 02/28/08 15:53:21.123 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:53:21.123 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:53:21.123 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:53:21.123 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:53:21.123 receiveCommand::begin <0x41802950> 35 02/28/08 15:53:21.123 buffer.size()= 6 <0x41802950> 35 02/28/08 15:53:21.123 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:53:21.123 SerialConnection : received command len = 3 buf = 0x00 0x42 0x02 <0x41802950> 10 02/28/08 15:53:51.828 Receive string: MESSAGE 72 <0x43005950> 10 02/28/08 15:53:51.828 Received MESSAGE 72 0x667590 device: 33 <0x43005950> 10 02/28/08 15:53:51.828 Received Message type 1 ID 757 from 0 to 33 (device: 33) resp 0 <0x43005950> 36 02/28/08 15:53:51.828 ZWave::DownloadConfiguration trying to get list of devices <0x44007950> 35 02/28/08 15:53:51.828 -------- 3 <0x44007950> 35 02/28/08 15:53:51.828 SerialConnection ------------- asa 1 <0x44007950> 35 02/28/08 15:53:51.989 SerialConnection ------------- asa 2 <0x44007950> 36 02/28/08 15:53:51.989 waiting for thread to finish <0x44007950> 35 02/28/08 15:53:52.089 exit receiveFunction : nr. of reads 124 <0x40800950> 36 02/28/08 15:53:52.090 thread finished <0x44007950> 35 02/28/08 15:53:52.090 SerialConnection ------------- asa 3 <0x44007950> 35 02/28/08 15:53:52.090 SerialConnection ------------- asa 4 <0x44007950> 35 02/28/08 15:53:52.090 -------- 4 <0x44007950> 36 02/28/08 15:53:52.100 SerialConnection::connect init serial mutex <0x44007950> 36 02/28/08 15:53:52.101 receive thread created OK!!!! <0x44007950> 35 02/28/08 15:53:52.101 entry point receiveFunction <0x41001950> 35 02/28/08 15:53:52.304 ++++++++++++ ZWave is connected <0x44007950> 36 02/28/08 15:53:52.308 ### Run Current Job <0x41802950> 36 02/28/08 15:53:52.364 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:53:52.364 SerialConnection::send len = 7 buf = 0x00 0x03 0x01 0x02 0x01 0x01 0x21 <0x41802950> 36 02/28/08 15:53:52.365 SerialConnection::send unlock serial mutex <0x41802950> 36 02/28/08 15:53:52.924 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:53:52.925 SerialConnection::send len = 3 buf = 0x00 0x42 0x03 <0x41802950> 36 02/28/08 15:53:52.925 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:53:52.980 size too small 1 <0x41802950> 35 02/28/08 15:53:53.036 size too small 1 <0x41802950> 35 02/28/08 15:53:53.092 size too small 1 <0x41802950> 35 02/28/08 15:53:53.148 size too small 2 <0x41802950> 35 02/28/08 15:53:53.204 size too small 2 <0x41802950> 35 02/28/08 15:53:53.260 size too small 2 <0x41802950> 35 02/28/08 15:53:53.316 size too small 2 <0x41802950> 35 02/28/08 15:53:53.372 size too small 2 <0x41802950> 35 02/28/08 15:53:53.428 size too small 2 <0x41802950> 35 02/28/08 15:53:53.484 size too small 2 <0x41802950> 35 02/28/08 15:53:53.540 size too small 2 <0x41802950> 35 02/28/08 15:53:53.596 size too small 2 <0x41802950> 35 02/28/08 15:53:53.652 size too small 2 <0x41802950> 35 02/28/08 15:53:53.708 size too small 2 <0x41802950> 35 02/28/08 15:53:53.764 size too small 2 <0x41802950> 35 02/28/08 15:53:53.820 size too small 2 <0x41802950> 35 02/28/08 15:53:53.876 size too small 2 <0x41802950> 35 02/28/08 15:53:53.932 size too small 2 <0x41802950> 35 02/28/08 15:53:53.988 size too small 2 <0x41802950> 35 02/28/08 15:53:54.044 size too small 2 <0x41802950> 35 02/28/08 15:53:54.100 size too small 2 <0x41802950> 35 02/28/08 15:53:54.156 size too small 2 <0x41802950> 35 02/28/08 15:53:54.212 size too small 2 <0x41802950> 35 02/28/08 15:53:54.268 size too small 2 <0x41802950> 35 02/28/08 15:53:54.324 size too small 2 <0x41802950> 35 02/28/08 15:53:54.380 size too small 2 <0x41802950> 35 02/28/08 15:53:54.436 size too small 2 <0x41802950> 35 02/28/08 15:53:54.492 size too small 2 <0x41802950> 35 02/28/08 15:53:54.548 size too small 2 <0x41802950> 35 02/28/08 15:53:54.604 size too small 2 <0x41802950> 35 02/28/08 15:53:54.660 size too small 2 <0x41802950> 35 02/28/08 15:53:54.716 size too small 2 <0x41802950> 35 02/28/08 15:53:54.772 size too small 2 <0x41802950> 35 02/28/08 15:53:54.828 size too small 2 <0x41802950> 35 02/28/08 15:53:54.884 size too small 2 <0x41802950> 35 02/28/08 15:53:54.940 size too small 2 <0x41802950> 35 02/28/08 15:53:54.996 size too small 2 <0x41802950> 35 02/28/08 15:53:55.052 size too small 2 <0x41802950> 35 02/28/08 15:53:55.108 size too small 2 <0x41802950> 35 02/28/08 15:53:55.164 size too small 2 <0x41802950> 35 02/28/08 15:53:55.220 size too small 2 <0x41802950> 35 02/28/08 15:53:55.276 size too small 2 <0x41802950> 35 02/28/08 15:53:55.332 size too small 2 <0x41802950> 35 02/28/08 15:53:55.388 size too small 2 <0x41802950> 35 02/28/08 15:53:55.444 size too small 2 <0x41802950> 35 02/28/08 15:53:55.500 size too small 2 <0x41802950> 35 02/28/08 15:53:55.556 size too small 2 <0x41802950> 35 02/28/08 15:53:55.612 size too small 2 <0x41802950> 35 02/28/08 15:53:55.668 size too small 2 <0x41802950> 35 02/28/08 15:53:55.724 size too small 2 <0x41802950> 35 02/28/08 15:53:55.780 size too small 2 <0x41802950> 35 02/28/08 15:53:55.836 size too small 2 <0x41802950> 35 02/28/08 15:53:55.892 size too small 2 <0x41802950> 35 02/28/08 15:53:55.948 size too small 2 <0x41802950> 35 02/28/08 15:53:56.004 size too small 2 <0x41802950> 35 02/28/08 15:53:56.060 size too small 2 <0x41802950> 35 02/28/08 15:53:56.116 size too small 2 <0x41802950> 35 02/28/08 15:53:56.172 size too small 2 <0x41802950> 10 02/28/08 15:53:59.049 Socket::SendMessage type 2 id 55 from 33 to -1001 <0x44007950> 05 02/28/08 15:53:59.050 [33;1m-------------------------- Job Timeout _________[0m <0x41802950> 35 02/28/08 15:53:59.328 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:53:59.328 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:53:59.328 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:53:59.328 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:53:59.328 receiveCommand::begin <0x41802950> 35 02/28/08 15:53:59.328 buffer.size()= 6 <0x41802950> 35 02/28/08 15:53:59.328 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:53:59.328 SerialConnection : received command len = 3 buf = 0x00 0x42 0x03 <0x41802950> 10 02/28/08 15:54:02.005 Receive string: MESSAGE 67 <0x43005950> 10 02/28/08 15:54:02.005 Received MESSAGE 67 0x667590 device: 33 <0x43005950> 10 02/28/08 15:54:02.005 Received Message type 1 ID 756 from 0 to 33 (device: 33) resp 0 <0x43005950> 36 02/28/08 15:54:02.005 ZWave::ReportChildDevices trying to get list of devices <0x44808950> 36 02/28/08 15:54:02.024 ### Run Current Job <0x41802950> 36 02/28/08 15:54:02.080 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:02.080 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:54:02.080 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:02.428 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:02.428 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:02.428 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:02.428 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:02.428 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:02.428 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:02.428 buffer.size()= 18 <0x41802950> 35 02/28/08 15:54:02.428 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:02.428 SerialConnection : received command len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:02.428 ZWJobInitialize len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:02.428 ZWJobGetVersion len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:02.428 Z-Wave 2.24 <0x41802950> 36 02/28/08 15:54:02.484 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:02.484 SerialConnection::send len = 2 buf = 0x00 0x20 <0x41802950> 36 02/28/08 15:54:02.484 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:02.708 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:02.708 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:02.708 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:02.708 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:02.708 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:02.708 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:02.708 buffer.size()= 10 <0x41802950> 35 02/28/08 15:54:02.708 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:02.708 SerialConnection : received command len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:54:02.708 ZWJobInitialize len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:54:02.708 ZWJobGetID len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 36 02/28/08 15:54:02.764 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:02.764 SerialConnection::send len = 2 buf = 0x00 0x02 <0x41802950> 36 02/28/08 15:54:02.764 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.044 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:03.044 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:03.044 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:03.044 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:03.044 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.044 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:03.044 buffer.size()= 39 <0x41802950> 35 02/28/08 15:54:03.044 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:03.044 SerialConnection : received command len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:54:03.044 ZWJobInitialize len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:54:03.044 ZWJobGetInitData len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 36 02/28/08 15:54:03.100 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:03.100 SerialConnection::send len = 3 buf = 0x00 0x52 0x01 <0x41802950> 36 02/28/08 15:54:03.100 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.324 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:03.324 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:03.324 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:03.324 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:03.324 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.324 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:03.324 buffer.size()= 6 <0x41802950> 35 02/28/08 15:54:03.324 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:03.324 SerialConnection : received command len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:54:03.324 ZWJobInitialize len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:54:03.324 ZWJobGetSUC len = 3 buf = 0x01 0x52 0x01 <0x41802950> 36 02/28/08 15:54:03.380 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:03.380 SerialConnection::send len = 2 buf = 0x00 0x56 <0x41802950> 36 02/28/08 15:54:03.380 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.660 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:03.660 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:03.660 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:03.660 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:03.660 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.660 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:03.660 buffer.size()= 6 <0x41802950> 35 02/28/08 15:54:03.660 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:03.660 SerialConnection : received command len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:54:03.660 ZWJobInitialize len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:54:03.660 ZWJobGetSUC len = 3 buf = 0x01 0x56 0x00 <0x41802950> 36 02/28/08 15:54:03.716 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:03.716 SerialConnection::send len = 3 buf = 0x00 0x41 0x01 <0x41802950> 36 02/28/08 15:54:03.716 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.940 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:03.940 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:03.940 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:03.940 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:03.940 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:03.940 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:03.940 buffer.size()= 11 <0x41802950> 35 02/28/08 15:54:03.940 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:03.940 SerialConnection : received command len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:03.940 ZWJobInitialize len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:03.940 ZWJobGetNodeProtocolInfo len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:03.940 ----- INIT ---- 3 <0x41802950> 35 02/28/08 15:54:03.940 ----- INIT ---- 1 <0x41802950> 35 02/28/08 15:54:03.940 ----- INIT ---- 2 <0x41802950> 36 02/28/08 15:54:03.940 ## Current Job Finished --- Left = 0 <0x41802950> 36 02/28/08 15:54:03.948 ZWave::ReportChildDevices got: <0x44808950> 36 02/28/08 15:54:03.948 <0x44808950> 10 02/28/08 15:54:03.948 Socket::SendMessage type 2 id 54 from 33 to -1001 <0x44808950> 10 02/28/08 15:54:04.867 Receive string: MESSAGE 67 <0x43005950> 10 02/28/08 15:54:04.867 Received MESSAGE 67 0x667590 device: 33 <0x43005950> 10 02/28/08 15:54:04.867 Received Message type 1 ID 756 from 0 to 33 (device: 33) resp 3 <0x43005950> 36 02/28/08 15:54:04.868 ZWave::ReportChildDevices trying to get list of devices <0x45009950> 36 02/28/08 15:54:04.896 ### Run Current Job <0x41802950> 36 02/28/08 15:54:04.952 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:04.952 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:54:04.952 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:05.177 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:05.177 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:05.177 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:05.177 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:05.177 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:05.177 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:05.178 buffer.size()= 18 <0x41802950> 35 02/28/08 15:54:05.178 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:05.178 SerialConnection : received command len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:05.178 ZWJobInitialize len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:05.178 ZWJobGetVersion len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:05.178 Z-Wave 2.24 <0x41802950> 36 02/28/08 15:54:05.231 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:05.232 SerialConnection::send len = 2 buf = 0x00 0x20 <0x41802950> 36 02/28/08 15:54:05.232 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:05.511 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:05.512 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:05.512 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:05.512 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:05.512 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:05.512 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:05.512 buffer.size()= 10 <0x41802950> 35 02/28/08 15:54:05.512 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:05.512 SerialConnection : received command len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:54:05.512 ZWJobInitialize len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:54:05.512 ZWJobGetID len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 36 02/28/08 15:54:05.567 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:05.568 SerialConnection::send len = 2 buf = 0x00 0x02 <0x41802950> 36 02/28/08 15:54:05.568 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:05.791 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:05.792 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:05.792 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:05.792 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:05.792 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:05.792 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:05.792 buffer.size()= 39 <0x41802950> 35 02/28/08 15:54:05.792 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:05.792 SerialConnection : received command len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:54:05.792 ZWJobInitialize len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:54:05.792 ZWJobGetInitData len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 36 02/28/08 15:54:05.847 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:05.848 SerialConnection::send len = 3 buf = 0x00 0x52 0x01 <0x41802950> 36 02/28/08 15:54:05.848 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:06.127 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:06.128 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:06.128 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:06.128 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:06.128 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:06.128 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:06.128 buffer.size()= 6 <0x41802950> 35 02/28/08 15:54:06.128 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:06.128 SerialConnection : received command len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:54:06.128 ZWJobInitialize len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:54:06.128 ZWJobGetSUC len = 3 buf = 0x01 0x52 0x01 <0x41802950> 36 02/28/08 15:54:06.183 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:06.183 SerialConnection::send len = 2 buf = 0x00 0x56 <0x41802950> 36 02/28/08 15:54:06.184 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:06.407 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:06.407 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:06.407 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:06.408 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:06.408 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:06.408 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:06.408 buffer.size()= 6 <0x41802950> 35 02/28/08 15:54:06.408 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:06.408 SerialConnection : received command len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:54:06.408 ZWJobInitialize len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:54:06.408 ZWJobGetSUC len = 3 buf = 0x01 0x56 0x00 <0x41802950> 36 02/28/08 15:54:06.463 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:06.463 SerialConnection::send len = 3 buf = 0x00 0x41 0x01 <0x41802950> 36 02/28/08 15:54:06.463 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:06.743 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:06.744 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:06.744 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:06.744 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:06.744 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:06.744 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:06.744 buffer.size()= 11 <0x41802950> 35 02/28/08 15:54:06.744 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:06.744 SerialConnection : received command len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:06.744 ZWJobInitialize len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:06.744 ZWJobGetNodeProtocolInfo len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:06.744 ----- INIT ---- 3 <0x41802950> 35 02/28/08 15:54:06.744 ----- INIT ---- 1 <0x41802950> 35 02/28/08 15:54:06.744 ----- INIT ---- 2 <0x41802950> 36 02/28/08 15:54:06.744 ## Current Job Finished --- Left = 0 <0x41802950> 36 02/28/08 15:54:06.744 ZWave::ReportChildDevices got: <0x45009950> 36 02/28/08 15:54:06.744 <0x45009950> 10 02/28/08 15:54:06.744 Socket::SendMessage type 2 id 54 from 33 to -1001 <0x45009950> 10 02/28/08 15:54:19.629 Receive string: MESSAGE 72 <0x43005950> 10 02/28/08 15:54:19.630 Received MESSAGE 72 0x667590 device: 33 <0x43005950> 10 02/28/08 15:54:19.630 Received Message type 1 ID 788 from 0 to 33 (device: 33) resp 3 <0x43005950> 10 02/28/08 15:54:32.878 Receive string: MESSAGE 67 <0x43005950> 10 02/28/08 15:54:32.878 Received MESSAGE 67 0x667590 device: 33 <0x43005950> 10 02/28/08 15:54:32.878 Received Message type 1 ID 756 from 0 to 33 (device: 33) resp 3 <0x43005950> 36 02/28/08 15:54:32.878 ZWave::ReportChildDevices trying to get list of devices <0x4580a950> 36 02/28/08 15:54:32.898 ### Run Current Job <0x41802950> 36 02/28/08 15:54:32.953 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:32.954 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:54:32.954 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:33.237 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:33.238 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:33.238 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:33.238 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:33.238 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:33.238 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:33.238 buffer.size()= 18 <0x41802950> 35 02/28/08 15:54:33.238 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:33.238 SerialConnection : received command len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:33.238 ZWJobInitialize len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:33.238 ZWJobGetVersion len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:54:33.238 Z-Wave 2.24 <0x41802950> 36 02/28/08 15:54:33.293 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:33.294 SerialConnection::send len = 2 buf = 0x00 0x20 <0x41802950> 36 02/28/08 15:54:33.294 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:33.517 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:33.518 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:33.518 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:33.518 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:33.518 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:33.518 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:33.518 buffer.size()= 10 <0x41802950> 35 02/28/08 15:54:33.518 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:33.518 SerialConnection : received command len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:54:33.518 ZWJobInitialize len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:54:33.518 ZWJobGetID len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 36 02/28/08 15:54:33.573 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:33.573 SerialConnection::send len = 2 buf = 0x00 0x02 <0x41802950> 36 02/28/08 15:54:33.574 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:33.853 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:33.854 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:33.854 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:33.854 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:33.854 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:33.854 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:33.854 buffer.size()= 39 <0x41802950> 35 02/28/08 15:54:33.854 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:33.854 SerialConnection : received command len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:54:33.854 ZWJobInitialize len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:54:33.854 ZWJobGetInitData len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 36 02/28/08 15:54:33.909 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:33.910 SerialConnection::send len = 3 buf = 0x00 0x52 0x01 <0x41802950> 36 02/28/08 15:54:33.910 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:34.133 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:34.134 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:34.134 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:34.134 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:34.134 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:34.134 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:34.134 buffer.size()= 6 <0x41802950> 35 02/28/08 15:54:34.134 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:34.134 SerialConnection : received command len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:54:34.134 ZWJobInitialize len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:54:34.134 ZWJobGetSUC len = 3 buf = 0x01 0x52 0x01 <0x41802950> 36 02/28/08 15:54:34.189 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:34.189 SerialConnection::send len = 2 buf = 0x00 0x56 <0x41802950> 36 02/28/08 15:54:34.189 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:34.469 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:34.469 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:34.470 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:34.470 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:34.470 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:34.470 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:34.470 buffer.size()= 6 <0x41802950> 35 02/28/08 15:54:34.470 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:34.470 SerialConnection : received command len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:54:34.470 ZWJobInitialize len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:54:34.470 ZWJobGetSUC len = 3 buf = 0x01 0x56 0x00 <0x41802950> 36 02/28/08 15:54:34.527 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:54:34.527 SerialConnection::send len = 3 buf = 0x00 0x41 0x01 <0x41802950> 36 02/28/08 15:54:34.527 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:54:34.805 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:54:34.805 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:54:34.805 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:54:34.806 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:54:34.806 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:54:34.806 receiveCommand::begin <0x41802950> 35 02/28/08 15:54:34.806 buffer.size()= 11 <0x41802950> 35 02/28/08 15:54:34.806 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:54:34.806 SerialConnection : received command len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:34.806 ZWJobInitialize len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:34.806 ZWJobGetNodeProtocolInfo len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:54:34.806 ----- INIT ---- 3 <0x41802950> 35 02/28/08 15:54:34.806 ----- INIT ---- 1 <0x41802950> 35 02/28/08 15:54:34.806 ----- INIT ---- 2 <0x41802950> 36 02/28/08 15:54:34.806 ## Current Job Finished --- Left = 0 <0x41802950> 36 02/28/08 15:54:34.813 ZWave::ReportChildDevices got: <0x4580a950> 36 02/28/08 15:54:34.813 <0x4580a950> 10 02/28/08 15:54:34.813 Socket::SendMessage type 2 id 54 from 33 to -1001 <0x4580a950> 10 02/28/08 15:54:58.169 Receive string: MESSAGE 73 <0x43005950> 10 02/28/08 15:54:58.169 Received MESSAGE 73 0x667590 device: 33 <0x43005950> 10 02/28/08 15:54:58.169 Received Message type 7 ID 1 from 0 to 33 (device: 33) resp 0 <0x43005950> 05 02/28/08 15:54:58.169 [33;1mGot a reload command from 0 [0m <0x43005950> 10 02/28/08 15:54:58.424 Command_Impl::OnReload 33 <0x43005950> 10 02/28/08 15:54:58.424 Socket m_Socket 7/0x667590 Command_Impl1 Dev #33 m_bQuit=1 <0x43005950> 10 02/28/08 15:54:58.424 Requesthandler 0x667590 (device: 33) Closing request handler connection <0x43005950> 13 02/28/08 15:54:58.424 Exiting BeginHandleRequestThread thread... <0x43005950> 13 02/28/08 15:54:58.425 Exiting MessageQueueThread_DCECI thread... <0x42804950> 35 02/28/08 15:54:58.425 -------- 3 <0x2ac6a384bb40> 35 02/28/08 15:54:58.425 SerialConnection ------------- asa 1 <0x2ac6a384bb40> 35 02/28/08 15:54:58.556 SerialConnection ------------- asa 2 <0x2ac6a384bb40> 36 02/28/08 15:54:58.556 waiting for thread to finish <0x2ac6a384bb40> 35 02/28/08 15:54:58.656 exit receiveFunction : nr. of reads 216 <0x41001950> 36 02/28/08 15:54:58.656 thread finished <0x2ac6a384bb40> 35 02/28/08 15:54:58.656 SerialConnection ------------- asa 3 <0x2ac6a384bb40> 35 02/28/08 15:54:58.656 SerialConnection ------------- asa 4 <0x2ac6a384bb40> 35 02/28/08 15:54:58.656 -------- 4 <0x2ac6a384bb40> 35 02/28/08 15:54:58.920 SerialConnection ------------- 3 <0x2ac6a384bb40> 35 02/28/08 15:54:58.920 SerialConnection --- destructor <0x2ac6a384bb40> 35 02/28/08 15:54:58.920 SerialConnection ------------- 4 <0x2ac6a384bb40> 10 02/28/08 15:54:58.920 Waiting for message queue thread to quit <0x2ac6a384bb40> 10 02/28/08 15:54:58.920 Socket m_Socket 7/0x667590 Command_Impl1 Dev #33 m_bQuit=1 <0x2ac6a384bb40> 10 02/28/08 15:54:58.920 Socket m_Socket 7/0x667590 Command_Impl1 Dev #33 m_bQuit=1 <0x2ac6a384bb40> 13 02/28/08 15:54:58.920 Socket::Close() m_Socket 4 <0x2ac6a384bb40> 13 02/28/08 15:54:58.920 Socket::Close() m_Socket 4 closesocket: 0 <0x2ac6a384bb40> 13 02/28/08 15:54:58.920 Socket::Close() m_Socket 5 <0x2ac6a384bb40> 13 02/28/08 15:54:58.920 Socket::Close() m_Socket 5 closesocket: 0 <0x2ac6a384bb40> 10 02/28/08 15:54:58.920 Message queue thread quit <0x2ac6a384bb40> 10 02/28/08 15:54:58.920 Message queue thread joined <0x2ac6a384bb40> 10 02/28/08 15:54:58.921 About to call kill spawned devices <0x2ac6a384bb40> 10 02/28/08 15:54:58.921 Need to kill 0 child devices <0x2ac6a384bb40> 10 02/28/08 15:54:58.921 Killing completed. <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 Socket::~Socket(): deleting socket @0x67bb60 Event Dev #33 (socket id in destructor: m_Socket: -1) <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 Socket::~Socket(): deleting socket @0x680860 Event Dev #33 (socket id in destructor: m_Socket: -1) <0x2ac6a384bb40> 10 02/28/08 15:54:58.922 ~Command_Impl finished <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 ~HandleRequestSocket 0x667590 device: 33 ip: 127.0.0.1 <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 RequestSocket::Disconnect 0x667590 device: 33 <0x2ac6a384bb40> 05 02/28/08 15:54:58.922 [33;1mvoid ClientSocket::Disconnect() on this socket: 0x667590 (m_Socket: 7)[0m <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 Socket::Close() m_Socket 7 <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 Socket::Close() m_Socket 7 closesocket: 0 <0x2ac6a384bb40> 13 02/28/08 15:54:58.922 Socket::~Socket(): deleting socket @0x667590 Command_Impl1 Dev #33 (socket id in destructor: m_Socket: -1) <0x2ac6a384bb40> 10 02/28/08 15:54:58.922 Device: 33 ending <0x2ac6a384bb40> Return code: 2 2 02/28/08 15:54:58 33 (spawning-device) [1;33mDevice requests restart... count=1/50 dev=33[1;00m Thu Feb 28 15:54:59 EST 2008 Restart ========== NEW LOG SECTION ========== 1 02/28/08 15:55:07 33 (spawning-device) [1;00mStarting... 1[1;00m 1 02/28/08 15:55:07 33 (spawning-device) [1;00mFound /usr/pluto/bin/ZWave[1;00m 10 02/28/08 15:55:07.161 Device: 33 starting. Connecting to: localhost <0x2b40b5c73b40> 10 02/28/08 15:55:07.175 Setting timeout for socket 4 to 20 <0x2b40b5c73b40> 10 02/28/08 15:55:07.309 Socket::SendMessage type 5 id 37 from 33 to -1000 <0x2b40b5c73b40> 10 02/28/08 15:55:07.533 TranslateSerialUSB found /sys/devices/pci0000:00/0000:00:0b.0/usb1/1-5/1-5:1.0/ttyUSB0/ttyUSB0, returning /dev/ttyUSB0 <0x2b40b5c73b40> 36 02/28/08 15:55:07.533 Using serial port: ttyUSB0. <0x2b40b5c73b40> 36 02/28/08 15:55:07.547 SerialConnection::connect init serial mutex <0x2b40b5c73b40> 36 02/28/08 15:55:07.547 receive thread created OK!!!! <0x2b40b5c73b40> 35 02/28/08 15:55:07.547 entry point receiveFunction <0x41001950> 35 02/28/08 15:55:07.752 ++++++++++++ ZWave is connected <0x2b40b5c73b40> 36 02/28/08 15:55:07.753 ### Run Current Job <0x41802950> 36 02/28/08 15:55:07.807 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:07.807 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:55:07.807 SerialConnection::send unlock serial mutex <0x41802950> 05 02/28/08 15:55:12.043 [33;1m### Go to timeout queue[0m <0x41802950> 05 02/28/08 15:55:12.043 [33;1m### execute the next job from timeout queue[0m <0x41802950> 05 02/28/08 15:55:12.043 [33;1mZWJobInitialize::timeoutHandler[0m <0x41802950> 36 02/28/08 15:55:12.099 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:12.099 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:55:12.099 SerialConnection::send unlock serial mutex <0x41802950> 05 02/28/08 15:55:17.026 [33;1m### Go to timeout queue[0m <0x41802950> 05 02/28/08 15:55:17.026 [33;1m### execute the next job from timeout queue[0m <0x41802950> 05 02/28/08 15:55:17.026 [33;1mZWJobInitialize::timeoutHandler[0m <0x41802950> 36 02/28/08 15:55:17.082 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:17.170 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:55:17.170 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:55:17.506 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:55:17.506 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:55:17.506 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:55:17.506 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:55:17.506 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:55:17.507 receiveCommand::begin <0x41802950> 35 02/28/08 15:55:17.507 buffer.size()= 18 <0x41802950> 35 02/28/08 15:55:17.507 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:55:17.507 SerialConnection : received command len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:55:17.507 ZWJobInitialize len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:55:17.507 ZWJobGetVersion len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:55:17.507 Z-Wave 2.24 <0x41802950> 36 02/28/08 15:55:17.562 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:17.562 SerialConnection::send len = 2 buf = 0x00 0x20 <0x41802950> 36 02/28/08 15:55:17.562 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:55:17.786 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:55:17.786 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:55:17.786 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:55:17.786 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:55:17.786 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:55:17.787 receiveCommand::begin <0x41802950> 35 02/28/08 15:55:17.787 buffer.size()= 10 <0x41802950> 35 02/28/08 15:55:17.787 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:55:17.787 SerialConnection : received command len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:55:17.787 ZWJobInitialize len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:55:17.787 ZWJobGetID len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 36 02/28/08 15:55:17.842 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:17.842 SerialConnection::send len = 2 buf = 0x00 0x02 <0x41802950> 36 02/28/08 15:55:17.842 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:55:18.122 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:55:18.126 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:55:18.127 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:55:18.127 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:55:18.127 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:55:18.127 receiveCommand::begin <0x41802950> 35 02/28/08 15:55:18.127 buffer.size()= 39 <0x41802950> 35 02/28/08 15:55:18.127 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:55:18.127 SerialConnection : received command len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:55:18.127 ZWJobInitialize len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:55:18.128 ZWJobGetInitData len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 36 02/28/08 15:55:18.182 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:18.182 SerialConnection::send len = 3 buf = 0x00 0x52 0x01 <0x41802950> 36 02/28/08 15:55:18.182 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:55:18.406 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:55:18.406 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:55:18.406 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:55:18.406 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:55:18.406 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:55:18.406 receiveCommand::begin <0x41802950> 35 02/28/08 15:55:18.406 buffer.size()= 6 <0x41802950> 35 02/28/08 15:55:18.407 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:55:18.407 SerialConnection : received command len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:55:18.407 ZWJobInitialize len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:55:18.407 ZWJobGetSUC len = 3 buf = 0x01 0x52 0x01 <0x41802950> 36 02/28/08 15:55:18.462 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:18.462 SerialConnection::send len = 2 buf = 0x00 0x56 <0x41802950> 36 02/28/08 15:55:18.462 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:55:18.742 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:55:18.742 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:55:18.742 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:55:18.742 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:55:18.742 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:55:18.742 receiveCommand::begin <0x41802950> 35 02/28/08 15:55:18.742 buffer.size()= 6 <0x41802950> 35 02/28/08 15:55:18.742 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:55:18.742 SerialConnection : received command len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:55:18.743 ZWJobInitialize len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:55:18.743 ZWJobGetSUC len = 3 buf = 0x01 0x56 0x00 <0x41802950> 36 02/28/08 15:55:18.798 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:55:18.798 SerialConnection::send len = 3 buf = 0x00 0x41 0x01 <0x41802950> 36 02/28/08 15:55:18.798 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:55:19.022 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:55:19.022 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:55:19.022 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:55:19.022 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:55:19.022 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:55:19.022 receiveCommand::begin <0x41802950> 35 02/28/08 15:55:19.022 buffer.size()= 11 <0x41802950> 35 02/28/08 15:55:19.022 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:55:19.022 SerialConnection : received command len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:55:19.022 ZWJobInitialize len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:55:19.023 ZWJobGetNodeProtocolInfo len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:55:19.023 ----- INIT ---- 3 <0x41802950> 35 02/28/08 15:55:19.023 ----- INIT ---- 1 <0x41802950> 35 02/28/08 15:55:19.023 ----- INIT ---- 2 <0x41802950> 36 02/28/08 15:55:19.023 ## Current Job Finished --- Left = 0 <0x41802950> 36 02/28/08 15:55:19.031 ZWave::ReportChildDevices trying to get list of devices <0x42003950> 36 02/28/08 15:55:19.031 ZWave::ReportChildDevices got: <0x42003950> 36 02/28/08 15:55:19.031 <0x42003950> 10 02/28/08 15:55:19.032 Socket::SendMessage type 2 id 54 from 33 to -1001 <0x42003950> 10 02/28/08 15:55:19.032 Connect OK <0x2b40b5c73b40> 05 02/28/08 15:55:19.032 [33;1mCreating child 34[0m <0x2b40b5c73b40> 10 02/28/08 15:55:19.032 Got CreateEvent for unknown type 1820. <0x2b40b5c73b40> 05 02/28/08 15:55:19.032 [33;1mNote: Device manager has attached a device of type 1820 that this has no custom event handler for. It will not fire events.[0m <0x2b40b5c73b40> 10 02/28/08 15:55:19.032 Got CreateCommand for unknown type 1820. <0x2b40b5c73b40> 05 02/28/08 15:55:19.032 [33;1mNote: Device manager has attached a device of type 1820 that this has no custom handler for. This is normal for IR.[0m <0x2b40b5c73b40> 10 02/28/08 15:55:19.032 Requesthandler 0x667590 (device: 33) runThread now running <0x43005950> 10 02/28/08 15:55:19.067 Receive string: <0x43005950> 10 02/28/08 15:55:19.067 Received 0x667590 device: 33 <0x43005950> 10 02/28/08 15:56:15.431 Receive string: MESSAGE 67 <0x43005950> 10 02/28/08 15:56:15.431 Received MESSAGE 67 0x667590 device: 33 <0x43005950> 10 02/28/08 15:56:15.431 Received Message type 7 ID 1 from 0 to 33 (device: 33) resp 0 <0x43005950> 05 02/28/08 15:56:15.431 [33;1mGot a reload command from 0 [0m <0x43005950> 10 02/28/08 15:56:15.682 Command_Impl::OnReload 33 <0x43005950> 10 02/28/08 15:56:15.682 Socket m_Socket 7/0x667590 Command_Impl1 Dev #33 m_bQuit=1 <0x43005950> 10 02/28/08 15:56:15.682 Requesthandler 0x667590 (device: 33) Closing request handler connection <0x43005950> 13 02/28/08 15:56:15.682 Exiting BeginHandleRequestThread thread... <0x43005950> 13 02/28/08 15:56:15.682 Exiting MessageQueueThread_DCECI thread... <0x42804950> 35 02/28/08 15:56:15.682 -------- 3 <0x2b40b5c73b40> 35 02/28/08 15:56:15.683 SerialConnection ------------- asa 1 <0x2b40b5c73b40> 35 02/28/08 15:56:15.790 SerialConnection ------------- asa 2 <0x2b40b5c73b40> 36 02/28/08 15:56:15.790 waiting for thread to finish <0x2b40b5c73b40> 35 02/28/08 15:56:15.790 exit receiveFunction : nr. of reads 222 <0x41001950> 36 02/28/08 15:56:15.802 thread finished <0x2b40b5c73b40> 35 02/28/08 15:56:15.803 SerialConnection ------------- asa 3 <0x2b40b5c73b40> 35 02/28/08 15:56:15.803 SerialConnection ------------- asa 4 <0x2b40b5c73b40> 35 02/28/08 15:56:15.803 -------- 4 <0x2b40b5c73b40> 35 02/28/08 15:56:16.070 SerialConnection ------------- 3 <0x2b40b5c73b40> 35 02/28/08 15:56:16.070 SerialConnection --- destructor <0x2b40b5c73b40> 35 02/28/08 15:56:16.070 SerialConnection ------------- 4 <0x2b40b5c73b40> 10 02/28/08 15:56:16.070 Waiting for message queue thread to quit <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 Socket m_Socket 7/0x667590 Command_Impl1 Dev #33 m_bQuit=1 <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 Socket m_Socket 7/0x667590 Command_Impl1 Dev #33 m_bQuit=1 <0x2b40b5c73b40> 13 02/28/08 15:56:16.071 Socket::Close() m_Socket 4 <0x2b40b5c73b40> 13 02/28/08 15:56:16.071 Socket::Close() m_Socket 4 closesocket: 0 <0x2b40b5c73b40> 13 02/28/08 15:56:16.071 Socket::Close() m_Socket 5 <0x2b40b5c73b40> 13 02/28/08 15:56:16.071 Socket::Close() m_Socket 5 closesocket: 0 <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 Message queue thread quit <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 Message queue thread joined <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 About to call kill spawned devices <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 Need to kill 0 child devices <0x2b40b5c73b40> 10 02/28/08 15:56:16.071 Killing completed. <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 Socket::~Socket(): deleting socket @0x67bb60 Event Dev #33 (socket id in destructor: m_Socket: -1) <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 Socket::~Socket(): deleting socket @0x67f560 Event Dev #33 (socket id in destructor: m_Socket: -1) <0x2b40b5c73b40> 10 02/28/08 15:56:16.073 ~Command_Impl finished <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 ~HandleRequestSocket 0x667590 device: 33 ip: 127.0.0.1 <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 RequestSocket::Disconnect 0x667590 device: 33 <0x2b40b5c73b40> 05 02/28/08 15:56:16.073 [33;1mvoid ClientSocket::Disconnect() on this socket: 0x667590 (m_Socket: 7)[0m <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 Socket::Close() m_Socket 7 <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 Socket::Close() m_Socket 7 closesocket: 0 <0x2b40b5c73b40> 13 02/28/08 15:56:16.073 Socket::~Socket(): deleting socket @0x667590 Command_Impl1 Dev #33 (socket id in destructor: m_Socket: -1) <0x2b40b5c73b40> 10 02/28/08 15:56:16.073 Device: 33 ending <0x2b40b5c73b40> Return code: 2 2 02/28/08 15:56:16 33 (spawning-device) [1;33mDevice requests restart... count=1/50 dev=33[1;00m Thu Feb 28 15:56:16 EST 2008 Restart ========== NEW LOG SECTION ========== 1 02/28/08 15:56:24 33 (spawning-device) [1;00mStarting... 1[1;00m 1 02/28/08 15:56:24 33 (spawning-device) [1;00mFound /usr/pluto/bin/ZWave[1;00m 10 02/28/08 15:56:24.273 Device: 33 starting. Connecting to: localhost <0x2ad0aaaf9b40> 10 02/28/08 15:56:24.278 Setting timeout for socket 4 to 20 <0x2ad0aaaf9b40> 10 02/28/08 15:56:24.375 Socket::SendMessage type 5 id 37 from 33 to -1000 <0x2ad0aaaf9b40> 10 02/28/08 15:56:24.455 TranslateSerialUSB found /sys/devices/pci0000:00/0000:00:0b.0/usb1/1-5/1-5:1.0/ttyUSB0/ttyUSB0, returning /dev/ttyUSB0 <0x2ad0aaaf9b40> 36 02/28/08 15:56:24.455 Using serial port: ttyUSB0. <0x2ad0aaaf9b40> 36 02/28/08 15:56:24.466 SerialConnection::connect init serial mutex <0x2ad0aaaf9b40> 35 02/28/08 15:56:24.466 entry point receiveFunction <0x41001950> 36 02/28/08 15:56:24.467 receive thread created OK!!!! <0x2ad0aaaf9b40> 35 02/28/08 15:56:24.677 ++++++++++++ ZWave is connected <0x2ad0aaaf9b40> 36 02/28/08 15:56:24.678 ### Run Current Job <0x41802950> 36 02/28/08 15:56:24.735 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:24.746 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:56:24.746 SerialConnection::send unlock serial mutex <0x41802950> 05 02/28/08 15:56:29.013 [33;1m### Go to timeout queue[0m <0x41802950> 05 02/28/08 15:56:29.013 [33;1m### execute the next job from timeout queue[0m <0x41802950> 05 02/28/08 15:56:29.013 [33;1mZWJobInitialize::timeoutHandler[0m <0x41802950> 36 02/28/08 15:56:29.069 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:29.069 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:56:29.069 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:29.181 size too small 1 <0x41802950> 35 02/28/08 15:56:29.237 size too small 1 <0x41802950> 35 02/28/08 15:56:29.293 size too small 1 <0x41802950> 35 02/28/08 15:56:29.349 size too small 1 <0x41802950> 35 02/28/08 15:56:29.405 size too small 1 <0x41802950> 35 02/28/08 15:56:29.461 size too small 1 <0x41802950> 05 02/28/08 15:56:34.017 [33;1m### Go to timeout queue[0m <0x41802950> 05 02/28/08 15:56:34.017 [33;1m### execute the next job from timeout queue[0m <0x41802950> 05 02/28/08 15:56:34.017 [33;1mZWJobInitialize::timeoutHandler[0m <0x41802950> 36 02/28/08 15:56:34.073 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:34.109 SerialConnection::send len = 2 buf = 0x00 0x15 <0x41802950> 36 02/28/08 15:56:34.109 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:34.428 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:56:34.429 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:56:34.429 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:56:34.429 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:56:34.429 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:56:34.429 receiveCommand::begin <0x41802950> 35 02/28/08 15:56:34.429 buffer.size()= 18 <0x41802950> 35 02/28/08 15:56:34.429 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:56:34.429 SerialConnection : received command len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:56:34.429 ZWJobInitialize len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:56:34.429 ZWJobGetVersion len = 15 buf = 0x01 0x15 0x5a 0x2d 0x57 0x61 0x76 0x65 0x20 0x32 0x2e 0x32 0x34 0x00 0x01 <0x41802950> 35 02/28/08 15:56:34.429 Z-Wave 2.24 <0x41802950> 36 02/28/08 15:56:34.484 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:34.485 SerialConnection::send len = 2 buf = 0x00 0x20 <0x41802950> 36 02/28/08 15:56:34.485 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:34.752 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:56:34.753 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:56:34.753 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:56:34.753 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:56:34.753 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:56:34.753 receiveCommand::begin <0x41802950> 35 02/28/08 15:56:34.753 buffer.size()= 10 <0x41802950> 35 02/28/08 15:56:34.753 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:56:34.753 SerialConnection : received command len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:56:34.753 ZWJobInitialize len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 35 02/28/08 15:56:34.753 ZWJobGetID len = 7 buf = 0x01 0x20 0x00 0x01 0x14 0x7f 0x01 <0x41802950> 36 02/28/08 15:56:34.808 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:34.809 SerialConnection::send len = 2 buf = 0x00 0x02 <0x41802950> 36 02/28/08 15:56:34.809 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.033 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:56:35.033 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:56:35.033 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:56:35.033 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:56:35.033 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.033 receiveCommand::begin <0x41802950> 35 02/28/08 15:56:35.033 buffer.size()= 39 <0x41802950> 35 02/28/08 15:56:35.033 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:56:35.033 SerialConnection : received command len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:56:35.033 ZWJobInitialize len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 35 02/28/08 15:56:35.033 ZWJobGetInitData len = 36 buf = 0x01 0x02 0x04 0x00 0x1d 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x01 0x02 <0x41802950> 36 02/28/08 15:56:35.097 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:35.097 SerialConnection::send len = 3 buf = 0x00 0x52 0x01 <0x41802950> 36 02/28/08 15:56:35.097 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.364 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:56:35.365 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:56:35.365 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:56:35.365 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:56:35.365 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.365 receiveCommand::begin <0x41802950> 35 02/28/08 15:56:35.365 buffer.size()= 6 <0x41802950> 35 02/28/08 15:56:35.365 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:56:35.365 SerialConnection : received command len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:56:35.365 ZWJobInitialize len = 3 buf = 0x01 0x52 0x01 <0x41802950> 35 02/28/08 15:56:35.365 ZWJobGetSUC len = 3 buf = 0x01 0x52 0x01 <0x41802950> 36 02/28/08 15:56:35.424 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:35.425 SerialConnection::send len = 2 buf = 0x00 0x56 <0x41802950> 36 02/28/08 15:56:35.425 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.648 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:56:35.649 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:56:35.649 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:56:35.649 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:56:35.649 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.649 receiveCommand::begin <0x41802950> 35 02/28/08 15:56:35.649 buffer.size()= 6 <0x41802950> 35 02/28/08 15:56:35.649 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:56:35.649 SerialConnection : received command len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:56:35.649 ZWJobInitialize len = 3 buf = 0x01 0x56 0x00 <0x41802950> 35 02/28/08 15:56:35.649 ZWJobGetSUC len = 3 buf = 0x01 0x56 0x00 <0x41802950> 36 02/28/08 15:56:35.704 SerialConnection::send lock serial mutex <0x41802950> 35 02/28/08 15:56:35.704 SerialConnection::send len = 3 buf = 0x00 0x41 0x01 <0x41802950> 36 02/28/08 15:56:35.705 SerialConnection::send unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.968 SerialConnection::hasCommand() popping ACK <0x41802950> 35 02/28/08 15:56:35.969 SerialConnection::hasCommand() front is SOF <0x41802950> 35 02/28/08 15:56:35.969 SerialConnection::hasCommand lock serial mutex <0x41802950> 35 02/28/08 15:56:35.969 SerialConnection::hasCommand wrote ack <0x41802950> 35 02/28/08 15:56:35.969 SerialConnection::hasCommand unlock serial mutex <0x41802950> 35 02/28/08 15:56:35.969 receiveCommand::begin <0x41802950> 35 02/28/08 15:56:35.969 buffer.size()= 11 <0x41802950> 35 02/28/08 15:56:35.969 receiveCommand: eat another command <0x41802950> 35 02/28/08 15:56:35.969 SerialConnection : received command len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:56:35.969 ZWJobInitialize len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:56:35.969 ZWJobGetNodeProtocolInfo len = 8 buf = 0x01 0x41 0xca 0x06 0x00 0x02 0x02 0x01 <0x41802950> 35 02/28/08 15:56:35.969 ----- INIT ---- 3 <0x41802950> 35 02/28/08 15:56:35.969 ----- INIT ---- 1 <0x41802950> 35 02/28/08 15:56:35.969 ----- INIT ---- 2 <0x41802950> 36 02/28/08 15:56:35.969 ## Current Job Finished --- Left = 0 <0x41802950> 36 02/28/08 15:56:35.985 ZWave::ReportChildDevices trying to get list of devices <0x42003950> 36 02/28/08 15:56:35.985 ZWave::ReportChildDevices got: <0x42003950> 36 02/28/08 15:56:35.986 <0x42003950> 10 02/28/08 15:56:35.986 Socket::SendMessage type 2 id 54 from 33 to -1001 <0x42003950> 10 02/28/08 15:56:35.988 Connect OK <0x2ad0aaaf9b40> 05 02/28/08 15:56:35.988 [33;1mCreating child 34[0m <0x2ad0aaaf9b40> 10 02/28/08 15:56:35.988 Got CreateEvent for unknown type 1820. <0x2ad0aaaf9b40> 05 02/28/08 15:56:35.988 [33;1mNote: Device manager has attached a device of type 1820 that this has no custom event handler for. It will not fire events.[0m <0x2ad0aaaf9b40> 10 02/28/08 15:56:35.988 Got CreateCommand for unknown type 1820. <0x2ad0aaaf9b40> 05 02/28/08 15:56:35.988 [33;1mNote: Device manager has attached a device of type 1820 that this has no custom handler for. This is normal for IR.[0m <0x2ad0aaaf9b40> 10 02/28/08 15:56:35.988 Requesthandler 0x667590 (device: 33) runThread now running <0x43005950>