ZWave Debugging
(→Advanced debugging for developers) |
m |
||
| Line 9: | Line 9: | ||
The logs are in the directory /var/log/cmh. The first 2 digits are the 'log level'. The file: DCERouter.log contains the logging information from the core message router. The file: x-ZWave.log (where x is usually 9) contains all the logs from the Z-Wave module. | The logs are in the directory /var/log/cmh. The first 2 digits are the 'log level'. The file: DCERouter.log contains the logging information from the core message router. The file: x-ZWave.log (where x is usually 9) contains all the logs from the Z-Wave module. | ||
| − | <u>Log levels for data sent to the Z-Wave dongle</u>:<br> 40 = data sent to the Z-Wave dongle<br>41 = data received from the Z-Wave dongle<br> | + | <u>Log levels for data sent to the Z-Wave dongle</u>:<br> 40 = data sent to the Z-Wave dongle<br>41 = data received from the Z-Wave dongle<br>01 = critical errors<br>05 = warnings<br>07 = events<br>08 = commands<br>10 = status messages |
So, if you want to watch the router's logs and see what commands are being sent to the various devices, do this: | So, if you want to watch the router's logs and see what commands are being sent to the various devices, do this: | ||
| − | '''cd /var/log/cmh<br> tail -f DCERouter.log | grep '^08'''' | + | '''cd /var/log/cmh<br> tail -f DCERouter.log | grep '^08'''' |
Now from Vera's dashboard, send commands to the devices and you'll see them in the log. The | grep '^08' means to filter only lines that start with 08, meaning log level 08 ("Commands"). tail -f means "follow the log". To stop the tail and get back to the console, if you used ssh to login, you just press Ctrl+C. Unfortunately, often times telnet doesn't forward Ctrl+C, so, when using telnet you need to press Ctrl+Z and then type this to kill the tail command: killall tail; fg | Now from Vera's dashboard, send commands to the devices and you'll see them in the log. The | grep '^08' means to filter only lines that start with 08, meaning log level 08 ("Commands"). tail -f means "follow the log". To stop the tail and get back to the console, if you used ssh to login, you just press Ctrl+C. Unfortunately, often times telnet doesn't forward Ctrl+C, so, when using telnet you need to press Ctrl+Z and then type this to kill the tail command: killall tail; fg | ||
| Line 19: | Line 19: | ||
To watch the traffic on the Z-Wave serial bus, type: | To watch the traffic on the Z-Wave serial bus, type: | ||
| − | '''cd /var/log/cmh<br> tail -f 9-ZWave.log | grep '^40\|^41'''' | + | '''cd /var/log/cmh<br> tail -f 9-ZWave.log | grep '^40\|^41'''' |
| − | which means show log level 40 or 41. Normally Vera is polling all the nodes every few seconds, so the logs fill up quickly with Z-Wave traffic from the polling. If you want to turn off automatic polling temporarily for this session so the logs aren't cluttered with polling traffic, type: | + | which means show log level 40 or 41. Normally Vera is polling all the nodes every few seconds, so the logs fill up quickly with Z-Wave traffic from the polling. If you want to turn off automatic polling temporarily for this session so the logs aren't cluttered with polling traffic, type: |
'''/usr/bin/MessageSend localhost 0 9 1 966 5 0'''<br>(assuming the Z-Wave device is #9, as default, add 225 1 to make the change permanent) | '''/usr/bin/MessageSend localhost 0 9 1 966 5 0'''<br>(assuming the Z-Wave device is #9, as default, add 225 1 to make the change permanent) | ||
| − | To force a poll of device 13, type:<br>'''/usr/bin/MessageSend localhost 0 9 1 966 2 13 5 UPDATE''' | + | To force a poll of device 13, type:<br>'''/usr/bin/MessageSend localhost 0 9 1 966 2 13 5 UPDATE''' |
Next you can send "COMMAND: #191 - Send Code" to either a Z-Wave Node and the parameter 9 (Text) is a command, or send it to the Z-Wave device and it is a frame. The contents of text are a string of hex or decimal numbers separated with spaces, dashes or underscores, and hex values are preceded with 0x or x. So assuming a dimmable light is device 20 in node 15, either command below will dim it to 50%: | Next you can send "COMMAND: #191 - Send Code" to either a Z-Wave Node and the parameter 9 (Text) is a command, or send it to the Z-Wave device and it is a frame. The contents of text are a string of hex or decimal numbers separated with spaces, dashes or underscores, and hex values are preceded with 0x or x. So assuming a dimmable light is device 20 in node 15, either command below will dim it to 50%: | ||
| Line 47: | Line 47: | ||
Every time you do something with Vera this results in a "job". So let's assume you want to see what Vera is doing to configure a device. Type 'date' to see the date/time. Click the 'configure right now' button for the device. Type ''grep AddJob 9-ZWave.log'' to see all the log entries with 'AddJob' in them. Each one is given a number, and an abbreviated description. Say the first job after the 'date' is ''10 01/26/09 16:35:51.640 JobHandler::AddJob job#6 :conf_jh#9 (0x00DD7390) P:40 S:0 <00DD7390> conf_jh#9 type ZWJob_ConfigureNode first 0'' This means it's job#6, the name 'conf_jh#9' means it's a configure job from the main job handler for node #9. You may see lots of other jobs right after #6 to do things like set the Version/Manufacturer, set Associations, etc., because the main configure job (#6) may spawn many other jobs. To see all the log entries for job #6, type ''grep "job#6" 9-ZWave.log''. Pay attention to the lines with m_eJobStatus which indicate the status, such as ''m_eJobStatus Job completed ok''. Let's say you want to see what data is being sent/received as part of job#6, you could do this: ''grep 'job#6\|^40\|^41\|^01\|^05' 9-ZWave.log'' so you see all log entries for job #6, all incoming/outgoing data, plus critical errors (1) and warnings (5). Look for the line 'ready to run' in the logs, which will indicate where job #6 is starting. The logs are color coded, and the less that comes with busybox in Vera doesn't support the -R parameter to view the logs in color, which is much easier to read. So, you can set a root password if you haven't already (type ''passwd''), and then use scp to copy the log files from Vera to another Linux/Mac/Windows with cygwin pc, and then run: ''grep 'job#6\|^40\|^41\|^01\|^05' 9-ZWave.log | less -R'' to see just the filtered portion of the logs in color. | Every time you do something with Vera this results in a "job". So let's assume you want to see what Vera is doing to configure a device. Type 'date' to see the date/time. Click the 'configure right now' button for the device. Type ''grep AddJob 9-ZWave.log'' to see all the log entries with 'AddJob' in them. Each one is given a number, and an abbreviated description. Say the first job after the 'date' is ''10 01/26/09 16:35:51.640 JobHandler::AddJob job#6 :conf_jh#9 (0x00DD7390) P:40 S:0 <00DD7390> conf_jh#9 type ZWJob_ConfigureNode first 0'' This means it's job#6, the name 'conf_jh#9' means it's a configure job from the main job handler for node #9. You may see lots of other jobs right after #6 to do things like set the Version/Manufacturer, set Associations, etc., because the main configure job (#6) may spawn many other jobs. To see all the log entries for job #6, type ''grep "job#6" 9-ZWave.log''. Pay attention to the lines with m_eJobStatus which indicate the status, such as ''m_eJobStatus Job completed ok''. Let's say you want to see what data is being sent/received as part of job#6, you could do this: ''grep 'job#6\|^40\|^41\|^01\|^05' 9-ZWave.log'' so you see all log entries for job #6, all incoming/outgoing data, plus critical errors (1) and warnings (5). Look for the line 'ready to run' in the logs, which will indicate where job #6 is starting. The logs are color coded, and the less that comes with busybox in Vera doesn't support the -R parameter to view the logs in color, which is much easier to read. So, you can set a root password if you haven't already (type ''passwd''), and then use scp to copy the log files from Vera to another Linux/Mac/Windows with cygwin pc, and then run: ''grep 'job#6\|^40\|^41\|^01\|^05' 9-ZWave.log | less -R'' to see just the filtered portion of the logs in color. | ||
| − | <br> You can also use MessageSend to send Vera's normal DCE commands directly to devices. The ID's are the same as LinuxMCE. You can also '''tail -f DCERouter.log | grep '^08'''' | + | <br> You can also use MessageSend to send Vera's normal DCE commands directly to devices. The ID's are the same as LinuxMCE. You can also '''tail -f DCERouter.log | grep '^08'''' |
From the console, if you want to see if a device is configured, enable verbose logging: '''/usr/bin/VerboseLogging.sh enable''', restart the Z-Wave device: '''/usr/bin/MessageSend localhost 0 9 7 1''' then wait for it to finish checking all the devices and '''grep UpdateNode 9-ZWave.log'''. You'll see: '''ZWaveJobHandler::UpdateNodes node 13 PK_DeviceTemplate 37 type ZWaveNonDimmableLight PK_Device 19 cap 0xc9 sec 0xc res 0x0 bas 0x4 gen 0x10 spe 0x3 config 1 LS (on/off)-45W-IPCAM classes 25,27,2b,2c,72,73,77,82,85,86,91,ef,''' config 1 means the device is configured. To reconfigure a device from the command line, send it command 776. For this device it would be: '''/usr/bin/MessageSend localhost 0 19 1 776'''. | From the console, if you want to see if a device is configured, enable verbose logging: '''/usr/bin/VerboseLogging.sh enable''', restart the Z-Wave device: '''/usr/bin/MessageSend localhost 0 9 7 1''' then wait for it to finish checking all the devices and '''grep UpdateNode 9-ZWave.log'''. You'll see: '''ZWaveJobHandler::UpdateNodes node 13 PK_DeviceTemplate 37 type ZWaveNonDimmableLight PK_Device 19 cap 0xc9 sec 0xc res 0x0 bas 0x4 gen 0x10 spe 0x3 config 1 LS (on/off)-45W-IPCAM classes 25,27,2b,2c,72,73,77,82,85,86,91,ef,''' config 1 means the device is configured. To reconfigure a device from the command line, send it command 776. For this device it would be: '''/usr/bin/MessageSend localhost 0 19 1 776'''. | ||
| − | Reset the Z-Wave network:<br>'''/usr/bin/MessageSend localhost 0 9 1 776 51 SIS''' | + | Reset the Z-Wave network:<br>'''/usr/bin/MessageSend localhost 0 9 1 776 51 SIS''' |
Do a 'soft reset' that doesn't lose any devices, but resets the dongle:<br> '''/usr/bin/MessageSend localhost 0 9 1 776 51 SOFT''' | Do a 'soft reset' that doesn't lose any devices, but resets the dongle:<br> '''/usr/bin/MessageSend localhost 0 9 1 776 51 SOFT''' | ||
Revision as of 21:11, 6 August 2009
Contents |
Easy Z-Wave Debugging
Advanced debugging for developers
Here are some hints for debugging Z-Wave protocol issues. You can access Vera by telnet, or if you already set a password, by ssh.
First, be sure you check the box "verbose logs" under 'Advanced', 'Logging', or, from a console run /usr/bin/VerboseLogging.sh enable.
The logs are in the directory /var/log/cmh. The first 2 digits are the 'log level'. The file: DCERouter.log contains the logging information from the core message router. The file: x-ZWave.log (where x is usually 9) contains all the logs from the Z-Wave module.
Log levels for data sent to the Z-Wave dongle:
40 = data sent to the Z-Wave dongle
41 = data received from the Z-Wave dongle
01 = critical errors
05 = warnings
07 = events
08 = commands
10 = status messages
So, if you want to watch the router's logs and see what commands are being sent to the various devices, do this:
cd /var/log/cmh
tail -f DCERouter.log | grep '^08'
Now from Vera's dashboard, send commands to the devices and you'll see them in the log. The | grep '^08' means to filter only lines that start with 08, meaning log level 08 ("Commands"). tail -f means "follow the log". To stop the tail and get back to the console, if you used ssh to login, you just press Ctrl+C. Unfortunately, often times telnet doesn't forward Ctrl+C, so, when using telnet you need to press Ctrl+Z and then type this to kill the tail command: killall tail; fg
To watch the traffic on the Z-Wave serial bus, type:
cd /var/log/cmh
tail -f 9-ZWave.log | grep '^40\|^41'
which means show log level 40 or 41. Normally Vera is polling all the nodes every few seconds, so the logs fill up quickly with Z-Wave traffic from the polling. If you want to turn off automatic polling temporarily for this session so the logs aren't cluttered with polling traffic, type:
/usr/bin/MessageSend localhost 0 9 1 966 5 0
(assuming the Z-Wave device is #9, as default, add 225 1 to make the change permanent)
To force a poll of device 13, type:
/usr/bin/MessageSend localhost 0 9 1 966 2 13 5 UPDATE
Next you can send "COMMAND: #191 - Send Code" to either a Z-Wave Node and the parameter 9 (Text) is a command, or send it to the Z-Wave device and it is a frame. The contents of text are a string of hex or decimal numbers separated with spaces, dashes or underscores, and hex values are preceded with 0x or x. So assuming a dimmable light is device 20 in node 15, either command below will dim it to 50%:
/usr/bin/MessageSend localhost 0 9 1 191 9 "0 x13 15 0x3 0x26 0x1 50 4 1" #send data (func id x13) to node 15 command class 0x26 command 0x1 (set multi level) to 10% (size=3) with transmit options=4 and funcid=1
/usr/bin/MessageSend localhost 0 20 1 191 9 "x26 x1 50" #send the message directly to device 20 (the node, not 9 the Z-Wave dongle), so the node id and 'send data' frame are assumed
--Luup update: wget "http://127.0.0.1:49451/data_request?id=lu_action&DeviceNum=1&serviceId=urn:micasaverde-com:serviceId:ZWaveNetwork1&action=SendData&Node=7&Data=x26-x1-20" node 7 to 20%
--Luup update: wget "http://127.0.0.1:49451/data_request?id=lu_action&DeviceNum=1&serviceId=urn:micasaverde-com:serviceId:ZWaveNetwork1&action=SendData&Data=0-x13-7-0x3-0x26-0x1-50-4-1" node 7 to 20%
/usr/bin/MessageSend localhost 0 14 1 191 9 "x85 2 1" #Tell device 14 to report its association group 1
Ask node 4 (a thermostat) to report its temperature: "0 0x13 0x4 0x2 0x40 0x2 5 1"
You can also put an R in front of the binary data, and include the full frame, and it simulates a received frame on the serial api, rather than sending a frame. So to simulate receiving a FUNC_ID_ZW_APPLICATION_UPDATE from node 1 run:
/usr/bin/MessageSend localhost 0 9 1 191 9 "R0x1 0x9 0x0 0x49 0x84 0x1 0x3 0x2 0x2 0x1 0x38"
or an encrypted message from node 29 with FUNC_ID_APPLICATION_COMMAND_HANDLER, COMMAND_CLASS_SECURITY: "R0x01 0x1C 0x00 0x04 0x00 29 0x16 0x98 0x81 0xEC 0xE1 0x10 0x56 0xFC 0x13 0xDF 0x04 0x45 0x60 0x24 0xA8 0x43 0x89 0xE8 0x22 0x36 0x15 0xA9 0xB1 0x1C"
Note that the logs will rotate regularly, meaning the DCERouter.log is archived as DCERouter.log.1.gz, and the old DCERouter.log.1.gz becomes DCERouter.log.2.gz. This is handled by the root cron process that runs /usr/bin/Rotate_Logs.sh.
Every time you do something with Vera this results in a "job". So let's assume you want to see what Vera is doing to configure a device. Type 'date' to see the date/time. Click the 'configure right now' button for the device. Type grep AddJob 9-ZWave.log to see all the log entries with 'AddJob' in them. Each one is given a number, and an abbreviated description. Say the first job after the 'date' is 10 01/26/09 16:35:51.640 JobHandler::AddJob job#6 :conf_jh#9 (0x00DD7390) P:40 S:0 <00DD7390> conf_jh#9 type ZWJob_ConfigureNode first 0 This means it's job#6, the name 'conf_jh#9' means it's a configure job from the main job handler for node #9. You may see lots of other jobs right after #6 to do things like set the Version/Manufacturer, set Associations, etc., because the main configure job (#6) may spawn many other jobs. To see all the log entries for job #6, type grep "job#6" 9-ZWave.log. Pay attention to the lines with m_eJobStatus which indicate the status, such as m_eJobStatus Job completed ok. Let's say you want to see what data is being sent/received as part of job#6, you could do this: grep 'job#6\|^40\|^41\|^01\|^05' 9-ZWave.log so you see all log entries for job #6, all incoming/outgoing data, plus critical errors (1) and warnings (5). Look for the line 'ready to run' in the logs, which will indicate where job #6 is starting. The logs are color coded, and the less that comes with busybox in Vera doesn't support the -R parameter to view the logs in color, which is much easier to read. So, you can set a root password if you haven't already (type passwd), and then use scp to copy the log files from Vera to another Linux/Mac/Windows with cygwin pc, and then run: grep 'job#6\|^40\|^41\|^01\|^05' 9-ZWave.log | less -R to see just the filtered portion of the logs in color.
You can also use MessageSend to send Vera's normal DCE commands directly to devices. The ID's are the same as LinuxMCE. You can also tail -f DCERouter.log | grep '^08'
From the console, if you want to see if a device is configured, enable verbose logging: /usr/bin/VerboseLogging.sh enable, restart the Z-Wave device: /usr/bin/MessageSend localhost 0 9 7 1 then wait for it to finish checking all the devices and grep UpdateNode 9-ZWave.log. You'll see: ZWaveJobHandler::UpdateNodes node 13 PK_DeviceTemplate 37 type ZWaveNonDimmableLight PK_Device 19 cap 0xc9 sec 0xc res 0x0 bas 0x4 gen 0x10 spe 0x3 config 1 LS (on/off)-45W-IPCAM classes 25,27,2b,2c,72,73,77,82,85,86,91,ef, config 1 means the device is configured. To reconfigure a device from the command line, send it command 776. For this device it would be: /usr/bin/MessageSend localhost 0 19 1 776.
Reset the Z-Wave network:
/usr/bin/MessageSend localhost 0 9 1 776 51 SIS
Do a 'soft reset' that doesn't lose any devices, but resets the dongle:
/usr/bin/MessageSend localhost 0 9 1 776 51 SOFT
Zwave Log Messages
Zwave LastNote
Status="Aborted" LastNote="Timed out waiting for the node to reply"
Status="Aborted" LastNote="Node is not configured"
Status="Aborted" LastNote="Unable to get any information on node"
Status="Aborted" LastNote="Transmit failed with code: 1"
Remote Upgrade with preserve settings
curl -k -s -S --fail --retry 3 -o /tmp/firmware.img http://download.controlmyhouse.net/betafirmware/ftp/wl500gP-1.0.543.trx
/usr/bin/cmh-upgrade.sh
