Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Battery powered devices fail to complete interview #1364

Closed
2 of 10 tasks
jcam opened this issue Jan 12, 2021 · 17 comments
Closed
2 of 10 tasks

Battery powered devices fail to complete interview #1364

jcam opened this issue Jan 12, 2021 · 17 comments
Assignees
Labels
bug Something isn't working interview overhaul 🔬 Depends on a reworked interview process

Comments

@jcam
Copy link
Contributor

jcam commented Jan 12, 2021

Describe the bug

I have two battery powered devices, a Fibaro FGK-101 door/window sensor and a few Zooz ZSE29 outdoor motion sensors.
The Fibaro device will only complete an interview on the initial deployment if I constantly push the tamper button during the interview. On a restart, it won't complete the interview even if I do that. I've tried sending the refreshinfo command while poking the buttons, no dice.
The ZSE29 seems to work a little better, but never gets past the RestartFromCache stage.

Device information

Which device(s) is/are affected (make/model)?
What are the node IDs?
node id 23 is the ZSE29
node id 24 is the FGK-101

Last Known Working Configuration

  • New device

  • Previously working device (node-zwave-js)

    • Which library version/docker image/adapter version?
    • Have you made any recent configuration changes to the device? Describe.
  • Previously working device (other platform)

    • Which platform? Smartthings
    • Have you made any recent configuration changes to the device? Nothing beyond adding it to ZJS

Installation information
How did you install node-zwave-js?

  • Zwavejs2mqtt (latest) docker image
  • Zwavejs2mqtt (dev) docker image
  • ioBroker.zwave2 adapter
  • Pkg
  • Manual docker build
  • Other (describe)
  • Manually built (git clone - yarn install - yarn run build:full)

Logfile:
zwavejs_1.log

@jcam jcam added the bug Something isn't working label Jan 12, 2021
@jcam
Copy link
Contributor Author

jcam commented Jan 12, 2021

This PR was included #1307

@jcam
Copy link
Contributor Author

jcam commented Jan 12, 2021

possibly related to #900

@AlCalzone
Copy link
Member

22:33:46.507 CNTRLR   [Node 023] Interview stage completed: Neighbors
22:33:46.507 CNTRLR   [Node 023] Interview completed
22:33:46.509 CNTRLR   [Node 023] The node is ready to be used

This might be a UI issue, Node 23 seems to be interviewed just fine once it wakes up.

Node 24 shows a weird interaction of sleeping devices with restarting interviews. Here, the interview finally starts:

22:36:53.957 CNTRLR   [Node 024] Beginning interview - last completed stage: None
22:36:53.958 CNTRLR   [Node 024] new node, doing a full interview...

but somehow a message from an earlier interview attempt is stuck in the wake up queue and jeopardizes the attempt that was just started.

@jcam
Copy link
Contributor Author

jcam commented Jan 13, 2021

Is there some way that Smartthings and similar controllers acts differently? Is there a way to tell a node 'do not go to sleep until i say it is okay', to allow completion of the interview stage? Or, does the smartthings just rely more on old data / stored results from the initial interview?

@jcam
Copy link
Contributor Author

jcam commented Jan 13, 2021

image

just for completeness, here's how the two devices appear in the ui

@jcam
Copy link
Contributor Author

jcam commented Jan 13, 2021

As a note, before I loaded the no sleep timer branch, node 23 never got beyond the blank / nodeinfo phase, so i think that is still worthy of inclusion

@AlCalzone
Copy link
Member

Is there a way to tell a node 'do not go to sleep until i say it is okay', to allow completion of the interview stage?

No. The device is likely sleeping already when the driver attempts to interview it.
However, RestartFromCache is not a problem IMO. The interview was completed before, just must might not have the latest up-to-date values.

@AlCalzone
Copy link
Member

AlCalzone commented Jan 13, 2021

Regarding what we discussed on Slack:

21:55:16.248 CNTRLR » [Node 004] pinging the node...
...
21:55:16.308 CNTRLR   [Node 005] Beginning interview - last completed stage: RestartFromCache
21:55:16.312 CNTRLR » [Node 005] pinging the node...
21:55:16.325 CNTRLR   [Node 006] Beginning interview - last completed stage: RestartFromCache
21:55:16.329 CNTRLR » [Node 006] pinging the node...
21:55:16.345 CNTRLR   [Node 007] Beginning interview - last completed stage: RestartFromCache
21:55:16.348 CNTRLR » [Node 007] pinging the node...
21:55:16.361 CNTRLR   [Node 008] Beginning interview - last completed stage: RestartFromCache
21:55:16.365 CNTRLR » [Node 008] pinging the node...
21:55:16.377 CNTRLR   [Node 009] Beginning interview - last completed stage: RestartFromCache
21:55:16.381 CNTRLR » [Node 009] pinging the node...
21:55:16.393 CNTRLR   [Node 010] Beginning interview - last completed stage: RestartFromCache
21:55:16.397 CNTRLR » [Node 010] pinging the node...
21:55:16.409 CNTRLR   [Node 011] Beginning interview - last completed stage: RestartFromCache
21:55:16.413 CNTRLR » [Node 011] pinging the node...
21:55:16.426 CNTRLR   [Node 012] Beginning interview - last completed stage: RestartFromCache
21:55:16.429 CNTRLR » [Node 012] pinging the node...
21:55:16.442 CNTRLR   [Node 013] Beginning interview - last completed stage: RestartFromCache
21:55:16.446 CNTRLR » [Node 013] pinging the node...
21:55:16.476 CNTRLR   [Node 014] Beginning interview - last completed stage: RestartFromCache
21:55:16.480 CNTRLR » [Node 014] pinging the node...
21:55:16.492 CNTRLR   [Node 015] Beginning interview - last completed stage: RestartFromCache
21:55:16.496 CNTRLR » [Node 015] pinging the node...
21:55:16.508 CNTRLR   [Node 016] Beginning interview - last completed stage: RestartFromCache
21:55:16.511 CNTRLR » [Node 016] pinging the node...
21:55:16.522 CNTRLR   [Node 017] Beginning interview - last completed stage: RestartFromCache
21:55:16.526 CNTRLR » [Node 017] pinging the node...
21:55:16.537 CNTRLR   [Node 018] Beginning interview - last completed stage: RestartFromCache
21:55:16.541 CNTRLR » [Node 018] pinging the node...
21:55:16.552 CNTRLR   [Node 019] Beginning interview - last completed stage: RestartFromCache
21:55:16.556 CNTRLR » [Node 019] pinging the node...
21:55:16.567 CNTRLR   [Node 020] Beginning interview - last completed stage: RestartFromCache
21:55:16.571 CNTRLR » [Node 020] pinging the node...
21:55:16.583 CNTRLR   [Node 021] Beginning interview - last completed stage: RestartFromCache
21:55:16.586 CNTRLR » [Node 021] pinging the node...
21:55:16.598 CNTRLR   [Node 022] Beginning interview - last completed stage: RestartFromCache
21:55:16.601 CNTRLR » [Node 022] pinging the node...
21:55:16.613 CNTRLR   [Node 023] Beginning interview - last completed stage: NodeInfo
21:55:16.625 CNTRLR » [Node 023] querying securely supported commands...
21:55:16.713 CNTRLR   [Node 024] Beginning interview - last completed stage: RestartFromCache
21:55:16.717 CNTRLR » [Node 024] pinging the node...

This does look like a message prioritization issue. All pings go through until Node 22. The query for Node 23 seems to be deprioritized in comparison with the pings. And Node 24's ping is also only done around the same time that Node 23 is quried.

Can you tell me which of your devices are battery-powered?

@jcam
Copy link
Contributor Author

jcam commented Jan 14, 2021

Battery powered is 23 and 24.
The slow part I was referring to was after this phase, when it is iterating through the nodes and saying things like 'Node 4 is alive'. It takes seemingly forEVer for the two striplight dimmers (node 4 and 22, which are hardwired), and only after it finishes this phase, of checking every device is alive and current values, does all communication start working.

@AlCalzone
Copy link
Member

21:55:16.248 CNTRLR » [Node 004] pinging the node...
...
21:55:16.830 CNTRLR « [Node 004] ping successful

That's about 15 seconds after startup. The node status should have been updated there, but it seems that doesn't happen until later:

21:55:22.002 CNTRLR   [Node 004] The node is alive.

@jcam
Copy link
Contributor Author

jcam commented Jan 14, 2021

Right. And the time from Node 004's The node is alive to Node 005's The node is alive is... a full minute, give or take?

Again, these times aren't that bad, I'm just wanting to make sure what's happening is what should be happening.

@AlCalzone
Copy link
Member

If I don't mix anything up right now, these are the times where both nodes should have been detected as alive. 1 second apart, 17 seconds after startup:

21:55:16.830 CNTRLR « [Node 004] ping successful
21:55:17.302 CNTRLR « [Node 005] ping successful

So most likely something isn't working as intended.

@AlCalzone
Copy link
Member

@jcam please try #1397

@jcam
Copy link
Contributor Author

jcam commented Jan 14, 2021

Everything seems to be working and responding, quite a bit earlier than it was. I'm going to review the whole log once it finishes to make sure nothing seems totally out of place

@jcam
Copy link
Contributor Author

jcam commented Jan 18, 2021

Looking back at this issue, the tweaks both in #1397 and in a few others do seem to have improved startup time a bit, and I see that my motion sensor now reports properly after a while (and presumably after a wakeup), however the fibaro door/window sensor still never appears to finish interviewing (and also now says unknown manufacturer/unknown, as reported elsewhere)

@AlCalzone AlCalzone added the interview overhaul 🔬 Depends on a reworked interview process label Jan 21, 2021
@AlCalzone
Copy link
Member

@jcam There's some more improvement in this regard in #1505 - please test that.

@jcam
Copy link
Contributor Author

jcam commented Feb 3, 2021

With 6.1.1, the interview of my failed battery powered Fibaro window sensor now succeeds!

Thank you!

@jcam jcam closed this as completed Feb 3, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working interview overhaul 🔬 Depends on a reworked interview process
Projects
None yet
Development

No branches or pull requests

2 participants