Error: Invalid character in chunk size

[florianbeer]

homebridge-nb is working fine as far as I can tell, but looking at my homebridge log I can see the error below being logged exactly every 10 minutes.

[7/24/2022, 11:41:34 AM] [Nuki] warning: 172.16.1.105: request 1: GET /info
[7/24/2022, 11:41:34 AM] [Nuki] warning: 172.16.1.105: request 1: error: http status 503 Service Unavailable
[7/24/2022, 11:41:35 AM] [Nuki] Nuki_Bridge_3A29AFEC: warning: request 4247: error: Parse Error: Invalid character in chunk size
[7/24/2022, 11:41:35 AM] [Nuki] Nuki_Bridge_3A29AFEC: warning: heartbeat error: Parse Error: Invalid character in chunk size

Is this something to be concerned about or just a warning that won't impact the functionality?

[ebaauw]

Dunno, I haven't seen that one before. Does the error persist after you power-cycle the Niki bridge?

If so, please enable Homebridge DEBUG mode, set Log Level to 2, and capture the debug messages around the error (like 2 minutes before and after). Could you also list the output of nb -DD discover?

[florianbeer]

Power cycling seems to have removed the error message.
I only got one warning which I suspect is just due to WiFi connectivity:

[7/24/2022, 1:14:02 PM] [Nuki] warning: 172.16.1.105: request 1: GET /info
[7/24/2022, 1:14:02 PM] [Nuki] warning: 172.16.1.105: request 1: error: http status 503 Service Unavailable

Here is the output of nb -DD discover:

nb discover: nuki server: request 1: GET /bridges
nb discover: nuki server: request 1: GET https://api.nuki.io/discover/bridges
nb discover: nuki server: request 1: response: {"bridges":[{"bridgeId":xxx,"ip":"172.16.1.105","port":8080,"dateUpdated":"2022-07-24T10:42:21Z"}],"errorCode":0}
nb discover: nuki server: request 1: 200 OK
nb discover: 172.16.1.105: request 1: GET /info
nb discover: 172.16.1.105: request 1: GET http://172.16.1.105:8080/info
nb discover: 172.16.1.105: request 1: response: {"type":"Buffer","data":[72,84,84,80,32,52,48,49,32,85,110,97,117,116,104,111,114,105,122,101,100]}
nb discover: 172.16.1.105: request 1: 401 Unauthorized
[
  {
    "bridgeId": xxx,
    "dateUpdated": "2022-07-24T10:42:21Z",
    "ip": "172.16.1.105",
    "port": 8080
  }
]

The only thing that stands out is the last line in the header the says 401 Unauthorized.

[ebaauw]

The 401 is expected. Homebridge NB queries the Nuki discovery server every 10 minutes to find new or changed bridges. It then tries to query each of the discovered bridges, to check that they're reachable (if your ISP shares "your" public IP address, some-one else's bridge might be returned).

The 503 is an HTTP status returned by the Nuki bridge; WiFi connectivity is fine. Typically this means it's not ready to give a proper answer. Could be because it was still booting, could be because it's receiving too many requests. The Nuki bridge has a very aggressive definition of "too many"; make sure you only run one instance of Homebridge NB and don't use any other software polling the bridge.

[florianbeer]

Got it, thanks for your explanation.

[minamoanes]

@ebaauw I'm also receiving the same error, @florianbeer did you mange to solve it?

[florianbeer]

The message was gone after I rebooted the bridge, activated homebridge debug mode and set logging to 3.

After I reversed logging and debug mode, the message started to appear again after a while. So no, I did not solve it. But since it doesn’t seem to impact the normal functionality I didn’t pursue it further.

[ebaauw]

As far as I can tell, it's an intermittent issue with the Nuki bridge, not being able to handle a request and/or send a correct response. As I said before, the bridge is not very powerful, and doesn't seen to handle concurrent requests too well. Sometimes it helps to power-cycle the bridge. I've also seen issues where the bridge fails to register with the Nuki discovery server, which would also be solved by power-cycling the bridge.

I double-checked my own logs and regularly see both warning messages. The Invalid character in chunk size seems to be preceded all the time by a 503 Service Unavailable in the previous second. Maybe I can tweak the timing of the discovery, so it won't coincide with polling the bridge. And maybe I can filter out known bridges, before checking that they're reachable, but that's going to be tricky with my current software design.

Looking at the request IDs from the bridge client, there's plenty of requests that do succeed, so indeed, functionality shouldn't be impacted.

Note to self: I'm a bit suspicious, that I don't see any 503 from the bridge client, only from the discovery. Maybe I fail to check the http status correctly?

[Tyraenor]

As far as I can tell, it's an intermittent issue with the Nuki bridge, not being able to handle a request and/or send a correct response. As I said before, the bridge is not very powerful, and doesn't seen to handle concurrent requests too well. Sometimes it helps to power-cycle the bridge. I've also seen issues where the bridge fails to register with the Nuki discovery server, which would also be solved by power-cycling the bridge.

I double-checked my own logs and regularly see both warning messages. The Invalid character in chunk size seems to be preceded all the time by a 503 Service Unavailable in the previous second. Maybe I can tweak the timing of the discovery, so it won't coincide with polling the bridge. And maybe I can filter out known bridges, before checking that they're reachable, but that's going to be tricky with my current software design.

Looking at the request IDs from the bridge client, there's plenty of requests that do succeed, so indeed, functionality shouldn't be impacted.

Note to self: I'm a bit suspicious, that I don't see any 503 from the bridge client, only from the discovery. Maybe I fail to check the http status correctly?

This "issue" still happens for me today. Any chance you will get rid of this?