Author Topic: Zwave device stops working and fails to restart  (Read 5532 times)

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #30 on: December 27, 2010, 01:27:09 pm »
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?

donpaul

  • Guru
  • ****
  • Posts: 300
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #31 on: January 04, 2011, 03:33:53 pm »
I am seeing the same issues with my stick. It has worked flawless for the past year, then I upgraded and Zwave hangs every day. I literally have to remove it, and plug it back in before it will work. After a day or so, it will stop responding again. zwave driver problem maybe?

Here is a truncated log. This repeated several times then stopped at 00:22.

05   01/02/11 21:55:04.913      ERROR: ZW_SEND could not be delivered to Z-Wave stack <0xb7133b90>
05   01/02/11 21:55:05.168      ERROR: callback id is invalid! <0xb7133b90>
05   01/02/11 21:58:11.936      No callback received: await_callback: 233 timer: 31 <0xb7133b90>
05   01/02/11 22:05:44.356      No callback received: await_callback: 22 timer: 31 <0xb7133b90>
01   01/04/11 0:20:42.978      ERROR! Out of frame flow!! <0xb71a9b90>
01   01/04/11 0:20:42.979      Checksum incorrect ff - sending NAK <0xb71a9b90>
01   01/04/11 0:20:42.980      ERROR! Out of frame flow!! <0xb71a9b90>
05   01/04/11 0:22:34.889      No callback received: await_callback: 147 timer: 31 <0xb71a9b90>
05   01/04/11 0:22:38.089      No callback received: await_callback: 147 timer: 31 <0xb71a9b90>
05   01/04/11 0:22:41.289      No callback received: await_callback: 147 timer: 31 <0xb71a9b90>
01   01/04/11 0:22:41.289      ERROR: Dropping command, no callback received after three resends <0xb71a9b90>
01   01/04/11 0:22:41.289      ERROR: Three dropped commands in a row, soft-resetting controller <0xb71a9b90>

hari

  • Administrator
  • LinuxMCE God
  • *****
  • Posts: 2421
    • View Profile
    • ago control
Re: Zwave device stops working and fails to restart
« Reply #32 on: January 04, 2011, 04:23:49 pm »
Please provide the complete log
rock your home - http://www.agocontrol.com home automation

hari

  • Administrator
  • LinuxMCE God
  • *****
  • Posts: 2421
    • View Profile
    • ago control
Re: Zwave device stops working and fails to restart
« Reply #33 on: January 04, 2011, 05:00:03 pm »
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...
I've commited a patch, should be available within a few hours with apt-get update

please test and report. Be aware that I never encountered those soft lockups so i cannot test it myself.

br Hari
« Last Edit: January 04, 2011, 07:52:21 pm by hari »
rock your home - http://www.agocontrol.com home automation

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #34 on: January 04, 2011, 06:50:11 pm »
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.

donpaul

  • Guru
  • ****
  • Posts: 300
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #35 on: January 06, 2011, 01:27:32 am »
So far so good for me.

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #36 on: January 08, 2011, 01:26:19 pm »
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

hari

  • Administrator
  • LinuxMCE God
  • *****
  • Posts: 2421
    • View Profile
    • ago control
Re: Zwave device stops working and fails to restart
« Reply #37 on: January 08, 2011, 11:13:50 pm »
You need to associate he smoke detector with the dongle
rock your home - http://www.agocontrol.com home automation

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #38 on: January 09, 2011, 02:39:13 pm »
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

esev

  • Veteran
  • ***
  • Posts: 87
    • View Profile
    • Eric Severance
Re: Zwave device stops working and fails to restart
« Reply #39 on: January 09, 2011, 02:52:53 pm »
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

Is the Z-Stick still stuck?  If so, can you get us some more information about it?  Login to your linuxmce computer as root and do the following:

First, figure out which process ID belongs to the ZWave driver.
Code: [Select]
ps -ef | grep 112_ZWaveYou should see a line like this:
Code: [Select]
root     23937 23870  0 Jan08 pts/22   00:00:05 /usr/pluto/bin/ZWave -d 183 -r localhost -l /var/log/pluto/183_ZWave.logIn the example above, 23937 is the process ID.

Next, run the following:
Code: [Select]
cd /usr/pluto/bin
gdb ZWave -p <processID>
thread apply all bt full

Keep pressing enter at each of the prompts.  When you get back to the (gdb) prompt, press q to exit and detach from the process.

Paste in the results of running thread apply all bt full, that'll help us track down the problem.  It should look something like this
Code: [Select]
root     23937 23870  0 Jan08 pts/22   00:00:05 /usr/pluto/bin/ZWave -d 183 -r localhost -l /var/log/pluto/183_ZWave.log
root     27399 26904  0 08:42 pts/0    00:00:00 grep ZW
dcerouter_:~# cd /usr/pluto/bin/
dcerouter_:/usr/pluto/bin# gdb ZWave -p 23937
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/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 23937
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 0xb71b66c0 (LWP 23937)]
[New Thread 0xb5ffeb90 (LWP 23949)]
[New Thread 0xb67ffb90 (LWP 23947)]
[New Thread 0xb71b5b90 (LWP 23946)]
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
0xb782a430 in __kernel_vsyscall ()
(gdb) bt
#0  0xb782a430 in __kernel_vsyscall ()
#1  0xb7687bf7 in pthread_join () from /lib/tls/i686/cmov/libpthread.so.0
#2  0x080589cf in main ()
(gdb) thread apply all bt full

Thread 4 (Thread 0xb71b5b90 (LWP 23946)):
#0  0xb782a430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb74d9df1 in select () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.
#2  0x0806e609 in ReadSerialStringEx ()
No locals.
#3  0x08079ce4 in ZWApi::ZWApi::receiveFunction ()
No locals.
#4  0x0807a532 in start ()
No locals.
#5  0xb768750f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#6  0xb74e1a0e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.

Thread 3 (Thread 0xb67ffb90 (LWP 23947)):
#0  0xb782a430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb768b075 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#2  0xb76c802b in PlutoLock::CondWait (this=0xb67ff33c) at MultiThreadIncludes.cpp:532
iResult = 154139124
#3  0xb778ba76 in DCE::Command_Impl::ProcessMessageQueue (this=0x92ff8f8) 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>},
      members of std::_List_base<DCE::Message*, std::allocator<DCE::Message*> >::_List_impl:
      _M_node = {
        _M_next = 0xb770922c,
        _M_prev = 0xb77c9ff4
      }
    }
  }, <No data fields>}
itMessageQueue = {
  _M_node = 0xb67ff3b8
}
---Type <return> to continue, or q <return> to quit---
mq = {
  m_sFileName = {
    static npos = 4294967295,
    _M_dataplus = {
      <std::allocator<char>> = {
        <__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
      members of std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Alloc_hider:
      _M_p = 0x930a73c "Command_Impl.cpp"
    }
  },
  m_Line = 822,
  m_LockNum = 104,
  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>},
      members of std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Alloc_hider:
      _M_p = 0xb767c694 ""
    }
  },
  m_pMyLock = 0x92ffa34,
  m_tTime = 0,
  m_thread = 3061840784
}
#4  0xb77889b0 in MessageQueueThread_DCECI (param=0x92ff8f8) at Command_Impl.cpp:48
p = (warning: RTTI symbol not found for class 'DCE::ZWave'
warning: RTTI symbol not found for class 'DCE::ZWave'
class DCE::Command_Impl *) 0x92ff8f8
#5  0xb768750f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#6  0xb74e1a0e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.

Thread 2 (Thread 0xb5ffeb90 (LWP 23949)):
#0  0xb782a430 in __kernel_vsyscall ()
No symbol table info available.
---Type <return> to continue, or q <return> to quit---
#1  0xb74d9df1 in select () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.
#2  0xb7775289 in DCE::Socket::ReceiveData (this=0x92ff8f8, iSize=1, pcData=0xb5ffd258 "\n", nTimeout=-1) at Socket.cpp:760
tv = {
  tv_sec = 0,
  tv_usec = 696000
}
tv_select_1 = {
  tv_sec = 1294580542,
  tv_usec = 723432
}
tv_select = {
  tv_sec = 0,
  tv_usec = 999664
}
iRet = 0
rfds = {
  fds_bits = {128, 0 <repeats 31 times>}
}
tv_total = {
  tv_sec = -662,
  tv_usec = 993200
}
tv_select_2 = {
  tv_sec = 1294580542,
  tv_usec = 723430
}
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>},
      members of std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Alloc_hider:
      _M_p = 0x934e73c "Socket.cpp"
    }
  },
  m_Line = 689,
---Type <return> to continue, or q <return> to quit---
  m_LockNum = 861,
  m_bReleased = false,
  m_bLog = 177,
  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>},
      members of std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Alloc_hider:
      _M_p = 0xb767c694 ""
    }
  },
  m_pMyLock = 0x92ff948,
  m_tTime = 1294579881,
  m_thread = 3053448080
}
clk_start = 3300000
clk_select1 = 0
clk_select1b = 0
clk_select2 = 0
clk_select2b = 0
#3  0x080692fc in DCE::Command_Impl::ReceiveData ()
No locals.
#4  0xb77748c8 in DCE::Socket::ReceiveString (this=0x92ff8f8, sRefString=@0xb5ffe374, nTimeout=-1) at Socket.cpp:884
acBuf = "\n\000\000\000??b?\224?/\t\000\000\000\000\000\000\000\000\000???\000\000?e\000\000\000?\001\000\000\000?????????\204^\177\022?5@\002", '\0' <repeats 11 times>, "?\237U?\000\000\000\000?ZS?\220???\004\000\000\000\003\000\000\000@?U?0???????????\003\000\000\0000?4\tt\vG??\237g?0?4\t\224?/\t?????\204^\177\022?5@????0?4\t@?U?\002\000\000\000\030\000\000\000d?S?.", '\0' <repeats 15 times>, "????\f\000\000\000\006\000\000\000\000\000\000\000\000???\000\000\000\000\003\000"...
pcBuf = 0xb5ffd258 "\n"
iLen = 4095
#5  0x0806917b in DCE::Command_Impl::ReceiveString ()
No locals.
#6  0xb77a26f7 in DCE::HandleRequestSocket::RunThread (this=0x92ff8f8) at HandleRequestSocket.cpp:125
sMessage = {
  static npos = 4294967295,
  _M_dataplus = {
    <std::allocator<char>> = {
---Type <return> to continue, or q <return> to quit---
      <__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
    members of std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Alloc_hider:
    _M_p = 0x93509e4 "MESSAGE 67", ' ' <repeats 12 times>
  }
}
#7  0xb77a25d7 in BeginHandleRequestThread (HRqSock=0x92ff8f8) at HandleRequestSocket.cpp:31
pCS = (warning: RTTI symbol not found for class 'DCE::ZWave'
warning: RTTI symbol not found for class 'DCE::ZWave'
DCE::HandleRequestSocket *) 0x92ff8f8
#8  0xb768750f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#9  0xb74e1a0e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.

Thread 1 (Thread 0xb71b66c0 (LWP 23937)):
#0  0xb782a430 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb7687bf7 in pthread_join () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#2  0x080589cf in main ()
No locals.
#0  0xb782a430 in __kernel_vsyscall ()
(gdb) q
The program is running.  Quit anyway (and detach it)? (y or n) y
Detaching from program: /usr/pluto/bin/ZWave, process 23937
Eric Severance
My setup

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #40 on: January 09, 2011, 03:06:57 pm »
Did a reboot so it is working now.. will do the above once it hangs again..

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #41 on: January 10, 2011, 05:49:29 pm »
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]
ps -ef | grep 112_ZWave
Output:
Code: [Select]
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]
cd /usr/pluto/bin
gdb ZWave -p <processID>
thread apply all bt full

Output:
Code: [Select]
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)




esev

  • Veteran
  • ***
  • Posts: 87
    • View Profile
    • Eric Severance
Re: Zwave device stops working and fails to restart
« Reply #42 on: January 10, 2011, 06:21:48 pm »
That is interesting.  It locks up right after sending the soft-reset.  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:

Code: [Select]
ls -al /proc/5376/fd
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]
gcore <processID>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!
Eric Severance
My setup

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #43 on: January 10, 2011, 06:41:15 pm »
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]
ls -al /proc/5376/fd
Result:
Code: [Select]

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]
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

tortho

  • Regular Poster
  • **
  • Posts: 45
    • View Profile
Re: Zwave device stops working and fails to restart
« Reply #44 on: January 15, 2011, 12:23:38 pm »
Just curious.. did anyone look at the files and logs I provided?