Weird startup problem

Discussions about RaZberry - Z-Wave board for Raspberry computer
Post Reply
mjm
Posts: 4
Joined: 13 Jun 2014 11:31

Weird startup problem

Post by mjm »

I'm having a strange star up problem with my Razberry. When I freshly install or upgrade the software it works all right. However when I do a power down and start again, the Razberry will not run.
Just to be sure I took a new SD card and installed the latest Raspbian Wheezy. I fully updated it and did a dpi-update. Then I installed the Razberry software. Do a reboot, it runs fine. Do a power cycle it fails.

Diagnostics:
- Top does not show a z-way-server process. It does show a zbw-connect process.
- Manually starting the z-way server by doing this:

Code: Select all

pi@razberry /opt/z-way-server $ sudo bash
root@razberry:/opt/z-way-server# export LD_LIBRARY_PATH=$LD_LIBRARY_PATH:/opt/z-way-server/libs
root@razberry:/opt/z-way-server# ./z-way-server
Z-Way version v1.7.0 from 2014-05-23 01:57:35 +0400 (build 588144e02f76d957be654217c09ede3e94d488ee)
Using default configuration file config.xml
Starting Z-Way for device /dev/ttyAMA0...
Starting HTTP server on port 8083...
terminate called after throwing an instance of 'std::length_error'
  what():  basic_string::resize
Aborted
Reinstalling the Razberry software gives this:

Code: Select all

pi@razberry /opt/z-way-server $ wget -q -O - http://razberry.z-wave.me/install | sudo bash
Previous z-way-server installation found
Stopping z-way-server: start-stop-daemon: warning: failed to kill 2365: No such process
done.
Stopping mongoose http server
Making backup of previous version of Z-Way in /opt/z-way-server_2014-06-13-08-39-15
Removing MathKernel
Reading package lists... Done
Building dependency tree       
Reading state information... Done
Package 'wolfram-engine' is not installed, so not removed
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Installing additional libraries
Reading package lists...
Building dependency tree...
Reading state information...
libyajl2 is already the newest version.
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Getting Z-Way for Raspberry Pi
--2014-06-13 08:39:25--  http://razberry.z-wave.me/z-way-server/z-way-server-RaspberryPiXTools-v1.7.0.tgz
Resolving razberry.z-wave.me (razberry.z-wave.me)... 46.20.244.36
Connecting to razberry.z-wave.me (razberry.z-wave.me)|46.20.244.36|:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: 15289402 (15M) [application/x-gzip]
Saving to: `STDOUT'

100%[============================================================>] 15,289,402  1.34M/s   in 9.7s    

2014-06-13 08:39:35 (1.50 MB/s) - written to stdout [15289402/15289402]

Copying settings
!!! Defaults.xml and config.xml updated with new versions !!!
Creating Z-Way startup script
Adding z-way-server to autostart
update-rc.d: using dependency based boot sequencing
--2014-06-13 08:40:02--  http://razberry.z-wave.me/webif_raspberry.tar.gz
Resolving razberry.z-wave.me (razberry.z-wave.me)... 46.20.244.36
Connecting to razberry.z-wave.me (razberry.z-wave.me)|46.20.244.36|:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: 405136 (396K) [application/x-gzip]
Saving to: `STDOUT'

100%[============================================================>] 405,136      881K/s   in 0.4s    

2014-06-13 08:40:03 (881 KB/s) - written to stdout [405136/405136]

--2014-06-13 08:40:03--  http://razberry.z-wave.me/mongoose.pkg.rPi.tgz
Resolving razberry.z-wave.me (razberry.z-wave.me)... 46.20.244.36
Connecting to razberry.z-wave.me (razberry.z-wave.me)|46.20.244.36|:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: 44750 (44K) [application/x-gzip]
Saving to: `STDOUT'

100%[============================================================>] 44,750      --.-K/s   in 0.08s   

2014-06-13 08:40:03 (556 KB/s) - written to stdout [44750/44750]

Adding mongoose to autostart
update-rc.d: using dependency based boot sequencing
Start mongoose http server
Opened config/zddx/d4d0bbc0-DevicesData.xml
Starting z-way-server
Starting z-way-server: done.
Thank you for using RaZberry!
... and the bloody thing works. Top shows the z-way-server process, as expected.

Code: Select all

sudo /etc/init.d/z-way-server stop
sudo /etc/init.d/z-way-server start
Still works.
Manually start Razberry (see above). Still works.

sudo shutdown now + power cycle: no go.

Any suggestions on how to proceed?
User avatar
PoltoS
Posts: 7571
Joined: 26 Jan 2011 19:36

Re: Weird startup problem

Post by PoltoS »

Please send us the log by mail.
R0yk3
Posts: 2
Joined: 04 Mar 2017 00:36

Re: Weird startup problem

Post by R0yk3 »

I see it is a very old thread but i have got exactely the same problem.
reboot stops server and i caanot start it up again.
reinstalling starts the server??

log file is 4Mb cannot attach is, although the file ends with a fault, the server works. I can switch lights. but after a reboot it all stops.. :evil:

Code: Select all

[2017-03-03 22:29:25.634] [D] [zway]   [00] 2
[2017-03-03 22:29:25.634] [D] [zway]   [01] 3
[2017-03-03 22:29:25.634] [D] [zway]   [02] 4
[2017-03-03 22:29:25.634] [D] [zway]   [03] 5
[2017-03-03 22:29:25.634] [D] [zway]   [04] 6
[2017-03-03 22:29:25.634] [D] [zway]   [05] 7
[2017-03-03 22:29:25.634] [D] [zway]   [06] 8
[2017-03-03 22:29:25.634] [D] [zway]   [07] 11
[2017-03-03 22:29:25.634] [D] [zway]   [08] 18
[2017-03-03 22:29:25.634] [D] [zway]   [09] 19
[2017-03-03 22:29:25.634] [D] [zway]   [10] 21
[2017-03-03 22:29:25.634] [D] [zway]   [11] 22
[2017-03-03 22:29:25.634] [D] [zway]   [12] 23
[2017-03-03 22:29:25.634] [D] [zway]   [13] 32
[2017-03-03 22:29:25.634] [D] [zway]   [14] 33
[2017-03-03 22:29:25.634] [D] [zway]   [15] 34
[2017-03-03 22:29:25.634] [D] [zway]   [16] 35
[2017-03-03 22:29:25.634] [D] [zway]   [17] 36
[2017-03-03 22:29:25.634] [D] [zway]   [18] 39
[2017-03-03 22:29:25.634] [D] [zway]   [19] 41
[2017-03-03 22:29:25.634] [D] [zway]   [20] 42
[2017-03-03 22:29:25.634] [D] [zway]   [21] 43
[2017-03-03 22:29:25.634] [D] [zway]   [22] 44
[2017-03-03 22:29:25.634] [D] [zway]   [23] 45
[2017-03-03 22:29:25.634] [D] [zway]   [24] 57
[2017-03-03 22:29:25.634] [D] [zway]   [25] 58
[2017-03-03 22:29:25.634] [D] [zway]   [26] 59
[2017-03-03 22:29:25.634] [D] [zway]   [27] 63
[2017-03-03 22:29:25.634] [D] [zway]   [28] 65
[2017-03-03 22:29:25.634] [D] [zway]   [29] 66
[2017-03-03 22:29:25.634] [D] [zway]   [30] 68
[2017-03-03 22:29:25.634] [D] [zway]   [31] 70
[2017-03-03 22:29:25.634] [D] [zway]   [32] 71
[2017-03-03 22:29:25.634] [D] [zway]   [33] 72
[2017-03-03 22:29:25.635] [D] [zway]   [34] 73
[2017-03-03 22:29:25.635] [D] [zway]   [35] 74
[2017-03-03 22:29:25.635] [D] [zway]   [36] 75
[2017-03-03 22:29:25.635] [D] [zway]   [37] 76
[2017-03-03 22:29:25.635] [D] [zway]   [38] 77
[2017-03-03 22:29:25.635] [D] [zway]   [39] 80
[2017-03-03 22:29:25.635] [D] [zway]   [40] 81
[2017-03-03 22:29:25.635] [D] [zway]   [41] 82
[2017-03-03 22:29:25.635] [D] [zway]   [42] 83
[2017-03-03 22:29:25.635] [D] [zway]   [43] 84
[2017-03-03 22:29:25.635] [D] [zway]   [44] 85
[2017-03-03 22:29:25.635] [D] [zway]   [45] 86
[2017-03-03 22:29:25.635] [D] [zway]   [46] 87
[2017-03-03 22:29:25.635] [D] [zway]   [47] 94
[2017-03-03 22:29:25.635] [D] [zway]   [48] 96
[2017-03-03 22:29:25.635] [D] [zway]   [49] 97
[2017-03-03 22:29:25.635] [D] [zway]   [50] 98
[2017-03-03 22:29:25.635] [D] [zway]   [51] 99
[2017-03-03 22:29:25.635] [D] [zway]   [52] 128
[2017-03-03 22:29:25.635] [D] [zway]   [53] 146
[2017-03-03 22:29:25.635] [D] [zway]   [54] 147
[2017-03-03 22:29:25.635] [D] [zway]   [55] 186
[2017-03-03 22:29:25.635] [D] [zway]   [56] 190
[2017-03-03 22:29:25.635] [D] [zway]   [57] 208
[2017-03-03 22:29:25.635] [D] [zway]   [58] 209
[2017-03-03 22:29:25.635] [D] [zway]   [59] 210
[2017-03-03 22:29:25.635] [D] [zway]   [60] 211
[2017-03-03 22:29:25.635] [D] [zway]   [61] 242
[2017-03-03 22:29:25.635] [D] [zway]   [62] 243
[2017-03-03 22:29:25.635] [D] [zway]   [63] 244
[2017-03-03 22:29:25.635] [D] [zway]   [64] 245
[2017-03-03 22:29:25.635] [D] [zway] SETDATA controller.data.functionClassesNames = string[65]
[2017-03-03 22:29:25.635] [D] [zway]   [00] "SerialAPIGetInitData"
[2017-03-03 22:29:25.635] [D] [zway]   [01] "SerialAPIApplicationNodeInformation"
[2017-03-03 22:29:25.635] [D] [zway]   [02] "ApplicationCommandHandler"
[2017-03-03 22:29:25.635] [D] [zway]   [03] "GetControllerCapabilities"
[2017-03-03 22:29:25.635] [D] [zway]   [04] "SerialAPISetTimeouts"
[2017-03-03 22:29:25.635] [D] [zway]   [05] "GetSerialAPICapabilities"
[2017-03-03 22:29:25.635] [D] [zway]   [06] "SerialAPISoftReset"
[2017-03-03 22:29:25.635] [D] [zway]   [07] "SerialAPISetup"
[2017-03-03 22:29:25.635] [D] [zway]   [08] "SendNodeInformation"
[2017-03-03 22:29:25.635] [D] [zway]   [09] "SendData"
[2017-03-03 22:29:25.636] [D] [zway]   [10] "GetVersion"
[2017-03-03 22:29:25.636] [D] [zway]   [11] "SendDataAbort"
[2017-03-03 22:29:25.636] [D] [zway]   [12] "RFPowerLevelSet"
[2017-03-03 22:29:25.636] [D] [zway]   [13] "GetHomeId"
[2017-03-03 22:29:25.636] [D] [zway]   [14] "MemoryGetByte"
[2017-03-03 22:29:25.636] [D] [zway]   [15] "MemoryPutByte"
[2017-03-03 22:29:25.636] [D] [zway]   [16] "MemoryGetBuffer"
[2017-03-03 22:29:25.636] [D] [zway]   [17] "MemoryPutBuffer"
[2017-03-03 22:29:25.636] [D] [zway]   [18] "FlashAutoProgSet"
[2017-03-03 22:29:25.636] [D] [zway]   [19] "NVMGetId"
[2017-03-03 22:29:25.636] [D] [zway]   [20] "NVMExtReadLongBuffer"
[2017-03-03 22:29:25.636] [D] [zway]   [21] "NVMExtWriteLongBuffer"
[2017-03-03 22:29:25.636] [D] [zway]   [22] "NVMExtReadLongByte"
[2017-03-03 22:29:25.636] [D] [zway]   [23] "NVMExtWriteLongByte"
[2017-03-03 22:29:25.636] [D] [zway]   [24] "ClearNetworkStats"
[2017-03-03 22:29:25.636] [D] [zway]   [25] "GetNetworkStats"
[2017-03-03 22:29:25.636] [D] [zway]   [26] "GetBackgroundRSSI"
[2017-03-03 22:29:25.636] [D] [zway]   [27] "RemoveNodeIdFromNetwork"
[2017-03-03 22:29:25.636] [D] [zway]   [28] "GetNodeProtocolInformation"
[2017-03-03 22:29:25.636] [D] [zway]   [29] "SetDefault"
[2017-03-03 22:29:25.636] [D] [zway]   [30] "ReplicationReceiveComplete"
[2017-03-03 22:29:25.636] [D] [zway]   [31] "AssignReturnRoute"
[2017-03-03 22:29:25.636] [D] [zway]   [32] "DeleteReturnRoute"
[2017-03-03 22:29:25.636] [D] [zway]   [33] "RequestNodeNeighbourUpdate"
[2017-03-03 22:29:25.636] [D] [zway]   [34] "ApplicationNodeUpdate"
[2017-03-03 22:29:25.636] [D] [zway]   [35] "AddNodeToNetwork"
[2017-03-03 22:29:25.636] [D] [zway]   [36] "RemoveNodeFromNetwork"
[2017-03-03 22:29:25.636] [D] [zway]   [37] "CreateNewPrimary"
[2017-03-03 22:29:25.636] [D] [zway]   [38] "ControllerChange"
[2017-03-03 22:29:25.636] [D] [zway]   [39] "SetLearnMode"
[2017-03-03 22:29:25.636] [D] [zway]   [40] "AssignSUCReturnRoute"
[2017-03-03 22:29:25.636] [D] [zway]   [41] "EnableSUC"
[2017-03-03 22:29:25.636] [D] [zway]   [42] "RequestNetworkUpdate"
[2017-03-03 22:29:25.636] [D] [zway]   [43] "SetSUCNodeId"
[2017-03-03 22:29:25.636] [D] [zway]   [44] "DeleteSUCReturnRoute"
[2017-03-03 22:29:25.636] [D] [zway]   [45] "GetSUCNodeId"
[2017-03-03 22:29:25.636] [D] [zway]   [46] "SendSUCNodeId"
[2017-03-03 22:29:25.636] [D] [zway]   [47] "ExploreRequestInclusion"
[2017-03-03 22:29:25.636] [D] [zway]   [48] "RequestNodeInformation"
[2017-03-03 22:29:25.636] [D] [zway]   [49] "RemoveFailedNode"
[2017-03-03 22:29:25.636] [D] [zway]   [50] "IsFailedNode"
[2017-03-03 22:29:25.636] [D] [zway]   [51] "ReplaceFailedNode"
[2017-03-03 22:29:25.636] [D] [zway]   [52] "GetRoutingTableLine"
[2017-03-03 22:29:25.636] [D] [zway]   [53] "GetPriorityRoute"
[2017-03-03 22:29:25.636] [D] [zway]   [54] "SetPriorityRoute"
[2017-03-03 22:29:25.636] [D] [zway]   [55] "RFPowerLevelGet"
[2017-03-03 22:29:25.637] [D] [zway]   [56] "SendTestFrame"
[2017-03-03 22:29:25.637] [D] [zway]   [57] "SetPromiscuousMode"
[2017-03-03 22:29:25.637] [D] [zway]   [58] "PromiscuousCommandHandler"
[2017-03-03 22:29:25.637] [D] [zway]   [59] "WatchDogStart"
[2017-03-03 22:29:25.637] [D] [zway]   [60] "WatchDogStop"
[2017-03-03 22:29:25.637] [D] [zway]   [61] "ZMEFreqChange"
[2017-03-03 22:29:25.637] [D] [zway]   [62] "ZMERestore"
[2017-03-03 22:29:25.637] [D] [zway]   [63] "ZMEBootloaderFlash"
[2017-03-03 22:29:25.637] [D] [zway]   [64] "ZMECapabilities"
[2017-03-03 22:29:25.637] [D] [zway] Opened device: /dev/ttyAMA0
[2017-03-03 22:29:25.637] [D] [zway] Worker thread successfully created
[2017-03-03 22:29:25.637] [D] [zway] Worker thread entry point
[2017-03-03 22:29:25.637] [I] [zway] Adding job: Get controller info and supported function classes
[2017-03-03 22:29:25.647] [D] [zway] SENDING: ( 01 03 00 07 FB )
[2017-03-03 22:30:03.803] [W] [zway] Received SOF, while awaiting ACK
[2017-03-03 22:30:04.303] [I] [zway] Job 0x07 (Get controller info and supported function classes): No ACK received before timeout
[2017-03-03 22:30:04.303] [D] [zway] SENDING: ( 01 03 00 07 FB )
[2017-03-03 22:30:04.515] [I] [zway] Job 0x07 (Get controller info and supported function classes): No ACK received before timeout
[2017-03-03 22:30:04.515] [D] [zway] SENDING: ( 01 03 00 07 FB )
[2017-03-03 22:30:04.805] [I] [zway] Job 0x07 (Get controller info and supported function classes): No ACK received before timeout
[2017-03-03 22:30:04.805] [W] [zway] Job 0x07 (Get controller info and supported function classes) dropped: too many resends
[2017-03-03 22:30:04.805] [D] [zway] Job 0x07 (Get controller info and supported function classes): fail
[2017-03-03 22:30:04.805] [C] [zway] Get Serial API Capabilities returned zero.
[2017-03-03 22:30:04.806] [I] [zway] Removing job: Get controller info and supported function classes
[2017-03-03 22:30:04.817] [D] [zway] Worker thread exit point
[2017-03-03 22:30:04.817] [D] [zway] Worker thread successfully finished
[2017-03-03 22:30:04.832] [E] [zway] SaveData will not save data since it wasn't loaded. This is to prevent data loss.
[2017-03-03 22:30:04.851] [I] [core] Notification: critical (z-wave): Cannot start Z-Wave binding: Error: Bad data - communication failed
User avatar
PoltoS
Posts: 7571
Joined: 26 Jan 2011 19:36

Re: Weird startup problem

Post by PoltoS »

The board looks not answering. Sure you have not changed your bluetooth/UART settings?
R0yk3
Posts: 2
Joined: 04 Mar 2017 00:36

Re: Weird startup problem

Post by R0yk3 »

This should mean that by rebooting the BT starts up?
I resolved ik now by disabling the zway server and controling it with Domoticz. Now the board keeps working?
Strange behaviour..??
User avatar
PoltoS
Posts: 7571
Joined: 26 Jan 2011 19:36

Re: Weird startup problem

Post by PoltoS »

Indeed, this is strange. In that case may be Z-Way was working but some other s/w (like Domoticz) occupied the port?
alexbk66
Posts: 1
Joined: 12 Jul 2017 17:52

Re: Weird startup problem

Post by alexbk66 »

@PoltoS, I need to also stop z-way-server, how do you disable it?
User avatar
PoltoS
Posts: 7571
Joined: 26 Jan 2011 19:36

Re: Weird startup problem

Post by PoltoS »

remove it from /etc/init.d/
User avatar
PoltoS
Posts: 7571
Joined: 26 Jan 2011 19:36

Re: Weird startup problem

Post by PoltoS »

But better keep it ;)
Post Reply