Messages

Just curious.. did anyone look at the files and logs I provided?

Trust the below is readable and what you asked for.
Have left the system in the same state if you need anything more... (Gcore uploading when i write this..)
(For some reason we are no longer allowed to post links so you have to modify the below..

Can you share your /var/log/kern.log and /var/log/kern.log.0 with us?  The output of the following would be helpful too
ww_w.thorland.org/kern.log
ww_w.thorland.org/kern.log.0

Code Select Expand

ls -al /proc/5376/fd

Result:

Code Select Expand



linuxmce@dcerouter:~$ linuxmce@dcerouter:~$ sudo ls -al /proc/5376/fd
total 0
dr-x------ 2 root root  0 2011-01-10 14:53 .
dr-xr-xr-x 7 root root  0 2011-01-10 06:23 ..
lrwx------ 1 root root 64 2011-01-10 14:53 0 -> /dev/pts/18
lrwx------ 1 root root 64 2011-01-10 14:53 1 -> /dev/pts/18
lrwx------ 1 root root 64 2011-01-10 14:53 2 -> /dev/pts/18
l-wx------ 1 root root 64 2011-01-10 14:53 3 -> /var/log/pluto/112_ZWave.log
lrwx------ 1 root root 64 2011-01-10 14:53 4 -> socket:[61143]
lrwx------ 1 root root 64 2011-01-10 14:53 5 -> socket:[63368]
lrwx------ 1 root root 64 2011-01-10 14:53 6 -> /dev/ttyUSB0
lrwx------ 1 root root 64 2011-01-10 14:53 7 -> socket:[63459]
linuxmce@dcerouter:~$


It would also help to have a copy of the ZWave process in its stuck state.  You can create a complete snapshot of that process with gcore.  Here is how to run it:

Code Select Expand

gcore <processID>
ww_w.thorland.org/gcore-output.5376

The last line of output after running gcore will be the filename containing the process state.  If you can get us a copy of that file and of your /usr/pluto/bin/ZWave executable that would help us a lot!

ww_w.thorland.org/ZWave

Stopped working again today... here is the output..
I left it as is, if more info is needed. (i.e. no restart yet)

Code Select Expand

ps -ef | grep 112_ZWave

Output:

Code Select Expand


linuxmce@dcerouter:~$ linuxmce@dcerouter:~$ ps -ef | grep 112_ZWave
n09 pts/18   00:00:04 /usr/pluto/bin/ZWave -d 112 -r localhost -l /var/log/pluto/112_ZWave.log
www-data 25391 16228  0 Jan09 ?        00:00:00 sh -c tail -f /var/log/pluto/112_ZWave.log | /usr/pluto/bin/ansi2html
www-data 25392 25391  0 Jan09 ?        00:00:00 tail -f /var/log/pluto/112_ZWave.log
linuxmce 26647 24873  0 17:36 pts/30   00:00:00 grep 112_ZWave
linuxmce@dcerouter:~$


Code Select Expand

cd /usr/pluto/bin
gdb ZWave -p <processID>
thread apply all bt full


Output:

Code Select Expand


dcerouter_1012936:/usr/pluto/bin# gdb ZWave -p 5376 thread apply all bt full
Excess command line arguments ignored. (thread ...)
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <xxxxorg/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...
Attaching to program: /usr/pluto/bin/ZWave, process 5376
Reading symbols from /usr/pluto/lib/libSerializeClass.so...done.
Loaded symbols for /usr/pluto/lib/libSerializeClass.so
Reading symbols from /usr/pluto/lib/libDCECommon.so...done.
Loaded symbols for /usr/pluto/lib/libDCECommon.so
Reading symbols from /usr/pluto/lib/libPlutoUtils.so...done.
Loaded symbols for /usr/pluto/lib/libPlutoUtils.so
Reading symbols from /lib/tls/i686/cmov/libpthread.so.0...done.
[Thread debugging using libthread_db enabled]
[New Thread 0xb70c46c0 (LWP 5376)]
[New Thread 0xb5effb90 (LWP 6889)]
[New Thread 0xb68c2b90 (LWP 6884)]
[New Thread 0xb70c3b90 (LWP 6883)]
Loaded symbols for /lib/tls/i686/cmov/libpthread.so.0
Reading symbols from /usr/lib/libstdc++.so.6...done.
Loaded symbols for /usr/lib/libstdc++.so.6
Reading symbols from /lib/tls/i686/cmov/libm.so.6...done.
Loaded symbols for /lib/tls/i686/cmov/libm.so.6
Reading symbols from /lib/libgcc_s.so.1...done.
Loaded symbols for /lib/libgcc_s.so.1
Reading symbols from /lib/tls/i686/cmov/libc.so.6...done.
Loaded symbols for /lib/tls/i686/cmov/libc.so.6
Reading symbols from /usr/lib/libmysqlclient_r.so.15...done.
Loaded symbols for /usr/lib/libmysqlclient_r.so.15
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/tls/i686/cmov/libcrypt.so.1...done.
Loaded symbols for /lib/tls/i686/cmov/libcrypt.so.1
Reading symbols from /lib/tls/i686/cmov/libnsl.so.1...done.
Loaded symbols for /lib/tls/i686/cmov/libnsl.so.1
Reading symbols from /usr/lib/libz.so.1...done.
Loaded symbols for /usr/lib/libz.so.1
Reading symbols from /lib/tls/i686/cmov/libnss_files.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_files.so.2
0xb7738430 in __kernel_vsyscall ()
(gdb)
(gdb) thread apply all bt full

Thread 4 (Thread 0xb70c3b90 (LWP 6883)):
#0  0xb7738430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb759c08b in write () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#2  0x0806ebf4 in WriteSerialStringEx ()
No locals.
#3  0x0807b15e in ZWApi::ZWApi::receiveFunction ()
No locals.
#4  0x0807b756 in start ()
No locals.
#5  0xb759550f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#6  0xb73efa0e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.

Thread 3 (Thread 0xb68c2b90 (LWP 6884)):
#0  0xb7738430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb7599075 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#2  0xb75d602b in PlutoLock::CondWait (this=0xb68c233c) at MultiThreadIncludes.cpp:532
       iResult = 165352524
#3  0xb7699a76 in DCE::Command_Impl::ProcessMessageQueue (this=0x9db1350) at Command_Impl.cpp:827
       copyMessageQueue = {<std::_List_base<DCE::Message*, std::allocator<DCE::Message*> >> = {
   _M_impl = {<std::allocator<std::_List_node<DCE::Message*> >> = {<__gnu_cxx::new_allocator<std::_List_node<DCE::Message*> >> = {<No data fields>}, <No data fields>},
     _M_node = {_M_next = 0xb761722c, _M_prev = 0xb76d7ff4}}}, <No data fields>}
       itMessageQueue = {_M_node = 0xb68c23b8}
       mq = {m_sFileName = {static npos = 4294967295, _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
     _M_p = 0x9dc2e84 "Command_Impl.cpp"}}, m_Line = 822, m_LockNum = 146, m_bReleased = true, m_bLog = false, m_bLogErrorsOnly = false, m_bGotLock = true,
 m_bIgnoreDeadlock = false, m_sMessage = {static npos = 4294967295,
   _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>}, _M_p = 0xb758a694 ""}}, m_pMyLock = 0x9db148c,
 m_tTime = 0, m_thread = 3062639504}
#4  0xb76969b0 in MessageQueueThread_DCECI (param=0x9db1350) at Command_Impl.cpp:48
       p = (class DCE::Command_Impl *) 0x9db1350
#5  0xb759550f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#6  0xb73efa0e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.

Thread 2 (Thread 0xb5effb90 (LWP 6889)):
#0  0xb7738430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb73e7df1 in select () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.
#2  0xb7683289 in DCE::Socket::ReceiveData (this=0x9db1350, iSize=1, pcData=0xb5efe258 "\020ãﵧ@5·\202âïµdÇD·\001", nTimeout=-1) at Socket.cpp:760
       tv = {tv_sec = 0, tv_usec = 160000}
       tv_select_1 = {tv_sec = 1294677892, tv_usec = 19954}
       tv_select = {tv_sec = 0, tv_usec = 995998}
       iRet = 0
---Type <return> to continue, or q <return> to quit---
       rfds = {fds_bits = {128, 0 <repeats 31 times>}}
       tv_total = {tv_sec = -6253, tv_usec = 14254}
       tv_select_2 = {tv_sec = 1294677892, tv_usec = 19951}
       nInternalReceiveTimeout = 0
       iBytesLeft = 1
       sSM = {m_sFileName = {static npos = 4294967295, _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
     _M_p = 0x9dc5804 "Socket.cpp"}}, m_Line = 689, m_LockNum = 1556, m_bReleased = false, m_bLog = 145, m_bLogErrorsOnly = true, m_bGotLock = true, m_bIgnoreDeadlock = true,
 m_sMessage = {static npos = 4294967295, _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
     _M_p = 0xb758a694 ""}}, m_pMyLock = 0x9db13a0, m_tTime = 1294671639, m_thread = 3052403600}
       clk_start = 5250000
       clk_select1 = 0
       clk_select1b = 0
       clk_select2 = 0
       clk_select2b = 0
#3  0x080699c8 in DCE::Command_Impl::ReceiveData ()
No locals.
#4  0xb76828c8 in DCE::Socket::ReceiveString (this=0x9db1350, sRefString=@0xb5eff374, nTimeout=-1) at Socket.cpp:884
       acBuf = "\020ãﵧ@5·\202âïµdÇD·\001\000\000\000\020ãïµ\002\000\000\000ã?5·dÇD·\020ãïµ39.018\000\000Ðâïµ\002\000\000\0000ëïµ\000\000\000\000ô\177F·\000\000\000\000\004\000\000\000ÌI5·3\000\000\0009\000\000\000.\000\000\0000\000\000\0001\000\000\0008\000\000\000\003\000\000\000XXÜ\ttë7·ô\177X·\000\000\000\000\000\000\000 \000\000\000\000¤l\221´\033E\"@qqY·të7·ô\177X·\006\000\000\000\000\000\000\000\n\000\000\000ô\203S·\224\003Û\t\000\000\000\000\000\000\000\000 äïµ\000\000\030,\000\000\000 \005\000\000\000täïµ"...
       pcBuf = 0xb5efe258 "\020ãﵧ@5·\202âïµdÇD·\001"
       iLen = 4095
#5  0x08069847 in DCE::Command_Impl::ReceiveString ()
No locals.
#6  0xb76b06f7 in DCE::HandleRequestSocket::RunThread (this=0x9db1350) at HandleRequestSocket.cpp:125
       sMessage = {static npos = 4294967295, _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
   _M_p = 0x9dc011c "MESSAGE 67", ' ' <repeats 12 times>}}
#7  0xb76b05d7 in BeginHandleRequestThread (HRqSock=0x9db1350) at HandleRequestSocket.cpp:31
       pCS = (DCE::HandleRequestSocket *) 0x9db1350
#8  0xb759550f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#9  0xb73efa0e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.

Thread 1 (Thread 0xb70c46c0 (LWP 5376)):
#0  0xb7738430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb7595bf7 in pthread_join () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#2  0x08058a2f in main ()
No locals.
#0  0xb7738430 in __kernel_vsyscall ()
(gdb)



Did a reboot so it is working now.. will do the above once it hangs again..

Smoke detector, Okay, will try to associate.. so far only paired and showed up in webadmin.

Z-Stick:
Still fails to restart.
See the complete log here:
http://www.thorland.org/112_ZWave.log
and here:
http://www.thorland.org/112_ZWave.log.1

So far so good...

Looks like there is some errors in my log.. "wrong callback type" and some other errors..

Also I can see it mention node 19, but I can not find any node 19 in my system...

Smoke detectors still not logging anything..

Complete log here:
http://www.thorland.org/112_ZWave.log

Thanks,

Will get my better half to install and restart today.
Will report back and also send the complete log on Friday when I get home if it is still running.

Hi,

Log level 36 is enabled, but nothing seen from the smoke detector nodes.....

Have not added any events/scenarios, just wanted to see the node id to set the name on them...
(Have 8 pcs and want to set the room they are in)

When was real smoke defined as a test? :-)

Hari,

Did see after my last update yesterday that the detectors were recognized and automatically (silently) added under security devices.

However when I try to trigger them either by the test button or by smoke nothing pops up in the zwave log..

Hi,

Will anyone look into the possible issues as mentioned above regarding the threads and possible hangs?
Quite annoying. The Z-stick was working properly earlier...

Valent:
What do you mean about pnp signatures?

No soft reset on this "freeze"....

Code Select Expand


01 12/19/10 13:42:07.680 ERROR: Dropping command, no callback received after three resends <0xb7236b90>
36 12/19/10 13:42:37.828 We have been idle for 30 seconds, polling device states <0xb7236b90>
40 12/19/10 13:42:37.928 Sending job 0x859e190 (cb 128) - 0x1 0x9 0x0 0x13 0xff 0x2 0x20 0x2 0x5 0x80 0xbf (###### ####) <0xb7236b90>
05 12/19/10 13:42:41.033 No callback received: await_callback: 128 timer: 31 <0xb7236b90>
40 12/19/10 13:42:41.133 Sending job 0x859e190 (cb 128) - 0x1 0x9 0x0 0x13 0xff 0x2 0x20 0x2 0x5 0x80 0xbf (###### ####) <0xb7236b90>
05 12/19/10 13:42:44.237 No callback received: await_callback: 128 timer: 31 <0xb7236b90>
40 12/19/10 13:42:44.333 Sending job 0x859e190 (cb 128) - 0x1 0x9 0x0 0x13 0xff 0x2 0x20 0x2 0x5 0x80 0xbf (###### ####) <0xb7236b90>
05 12/19/10 13:42:47.437 No callback received: await_callback: 128 timer: 31 <0xb7236b90>
01 12/19/10 13:42:47.437 ERROR: Dropping command, no callback received after three resends <0xb7236b90>
01 12/19/10 13:42:47.437 ERROR: Three dropped commands in a row, soft-resetting controller <0xb7236b90>
36 12/19/10 13:42:47.437 Soft-resetting the Z-Wave chip <0xb7236b90>
40 12/19/10 13:42:47.541 Sending job 0x859e3b0 (cb 129) - 0x1 0xc 0x0 0x13 0xff 0x5 0x60 0x6 0x2 0x20 0x2 0x5 0x81 0xd8 (######`## ####) <0xb7236b90>
05 12/19/10 13:42:50.641 No callback received: await_callback: 129 timer: 31 <0xb7236b90>
40 12/19/10 13:42:50.745 Sending job 0x859e3b0 (cb 129) - 0x1 0xc 0x0 0x13 0xff 0x5 0x60 0x6 0x2 0x20 0x2 0x5 0x81 0xd8 (######`## ####) <0xb7236b90>
05 12/19/10 13:42:53.849 No callback received: await_callback: 129 timer: 31 <0xb7236b90>
40 12/19/10 13:42:53.948 Sending job 0x859e3b0 (cb 129) - 0x1 0xc 0x0 0x13 0xff 0x5 0x60 0x6 0x2 0x20 0x2 0x5 0x81 0xd8 (######`## ####) <0xb7236b90>
05 12/19/10 13:42:57.053 No callback received: await_callback: 129 timer: 31 <0xb7236b90>
01 12/19/10 13:42:57.053 ERROR: Dropping command, no callback received after three resends <0xb7236b90>
40 12/19/10 13:42:57.153 Sending job 0x859e5d0 (cb 130) - 0x1 0x9 0x0 0x13 0xff 0x2 0x31 0x4 0x5 0x82 0xaa (######1####) <0xb7236b90>
05 12/19/10 13:43:00.265 No callback received: await_callback: 130 timer: 31 <0xb7236b90>
40 12/19/10 13:43:00.365 Sending job 0x859e5d0 (cb 130) - 0x1 0x9 0x0 0x13 0xff 0x2 0x31 0x4 0x5 0x82 0xaa (######1####) <0xb7236b90>
05 12/19/10 13:43:03.473 No callback received: await_callback: 130 timer: 31 <0xb7236b90>
40 12/19/10 13:43:03.573 Sending job 0x859e5d0 (cb 130) - 0x1 0x9 0x0 0x13 0xff 0x2 0x31 0x4 0x5 0x82 0xaa (######1####) <0xb7236b90>
05 12/19/10 13:43:06.681 No callback received: await_callback: 130 timer: 31 <0xb7236b90>
01 12/19/10 13:43:06.681 ERROR: Dropping command, no callback received after three resends <0xb7236b90>
40 12/19/10 13:43:06.776 Sending job 0x859e7f0 (cb 0) - 0x1 0x3 0x0 0x8 0xf4 (#####) <0xb7236b90>
05 12/19/10 14:22:28.360 Going to rotate logs... <0xb60ffb90>
36 12/19/10 15:34:10.034 Received command for child <0xb60ffb90>
36 12/19/10 15:34:10.035 ON RECEIVED FOR CHILD 19/0 <0xb60ffb90>
36 12/20/10 5:59:59.627 Received command for child <0xb60ffb90>
36 12/20/10 5:59:59.891 ON RECEIVED FOR CHILD 19/0 <0xb60ffb90>
36 12/20/10 6:00:00.001 Received command for child <0xb60ffb90>


Thanks a lot Hari,

A couple of questions:

- Did you incorporate the tamper switch? (Can be usefull if you rent out a part of your house and want to make sure it is up and running on the part you rent out)
- Is the low battery warning incorporated?
- Is it possible to trigger the alarm/siren on the detector from the LMCE?
- Can LMCE receive the fire alarm and set off all the other detectors? (Know they can be grouped, but it is limited 6 detectors if I'm not totally off)

Did the update today, but assume I have to wait for the next update.. they were not detected now and I could not find everspring as manufacturer in the device templates.

Excellent!!

Any way to include this with apt-get or updating of devices from the web interface?
Or do I have to install the snapshot?

FYI,

- There is no timed events running at that time of the day (which I'm aware of or can see in the setup)
- No one at home used the zwave from the hybrid or md.
- The only thing that might have happened is that someone physically turned on or off one of the lights at home locally (Not through any remotes or computers)