SyntaxError: Unexpected token N in JSON at position 0

[greatestview]

My homebridge log is filled with these errors:

[06/02/2022, 21:56:04] [MyVacuum] Error parsing current status info: SyntaxError: Unexpected token N in JSON at position 0 [06/02/2022, 21:56:13] [MyVacuum] Error parsing firmware info: SyntaxError: Unexpected token N in JSON at position 0

The first line appears every 10 seconds, the second infrequently.

First I tought it might be the same issue as described in #16 (and closed #12, #13, #14, #18), but that happens with Valetudo RE while my vacuum runs Valetudo (without RE).

Any ideas? @onfoot, which version combination is working for you?

Versions:

• homebridge-valetudo-xiaomi-vacuum: 0.2.0
• Valetudo 2022.02.01 (same issue on 2022.01)
• Node: 16.13.1
• NPM: 8.1.2

[onfoot]

The plugin works with both versions, but the appropriate one must be indicated in the config. I guess I need to add an option for more verbose logging so it shows the whole string along with the request URL, so I can pinpoint it more easily. Currently I'm running RE, but want to start testing both, so the plugin is more reliable across the board.

[robinfdx]

Hi @onfoot & @greatestview

I've the same issue with my Gen1 and Valetudo RE v0.10.7 (latest).

[2/10/2022, 11:33:47 AM] [Aspiro2000] Error parsing current status info: SyntaxError: Unexpected token N in JSON at position 0 [2/10/2022, 11:33:49 AM] [Aspiro2000] Error parsing firmware info: SyntaxError: Unexpected token N in JSON at position 0

When i check the JSON return of /api/current_status :

{ "msg_ver":8, "state":8, "battery":100, "clean_time":2987, "clean_area":45385000, "error_code":0, "map_present":1, "in_cleaning":0, "fan_power":100, "dnd_enabled":0, "human_state":"Charging", "human_error":"No error", "model":"rockrobo.vacuum.v1" }

When i check the JSON return of /api/get_fw_version :

{ "version":"miio-client 3.3.9\n", "build":"004028", "nodejs":"v12.22.1", "valetudo":"v0.10.7" }

Any ideas @onfoot ?

Thank for your help 🙏

[onfoot]

@robinfdx Have you set the legacy-mode flag to true for your RE vacuum?

[robinfdx]

@onfoot : Yes i've, like this :

{ "bridge": { "name": "Homebridge", "username": "XX:XX:XX:XX:XX:XX", "port": 5XXXX, "pin": "XXX-XXX-XXX" },

"description": "Configuration Xiaomi",

"accessories": [
{
    "accessory": "ValetudoXiaomiVacuum",
    "name": "Aspiro2000",
    "ip": "192.168.XX.XX",

"legacy-mode": true } ],

"platforms": [
]

}

I've restart homebridge but same thing

[robinfdx]

@onfoot : do you ve any idea about this problem ? 😊

[onfoot]

If you can, please enable debug mode in your homebridge and let me know, what the raw responses are when the error occurs. This is usually accomplished by uncommenting DEBUG=* option in /etc/default/homebridge, at least on raspbian or probably unbuntu/debian-based distributions.

[greatestview]

@onfoot, I finally figured it out! Thanks to this guy on reddit, I managed to debug your plugin directly on my pi instance:

The error occurs inside sendJSONRequest and the message is No credentials provided. Well, that was obvious. Your plugin does not work with Valetudo and HTTP Basic Auth activated!

This line in vacuumvaletudo.js#L370 with call to sendJSONRequest caused the error:

const response = await sendJSONRequest({ url: VacuumValetudo.statusUrl(this.ip) });

The solution is very simple and only a few lines of code: Just include HTTP Basic Auth into the config and pass it as a parameter to sendJSONRequest, since it can already be handled there:

const response = await sendJSONRequest({
  url: VacuumValetudo.statusUrl(this.ip),
  authentication: config.basicAuth ? config.basicAuth : null,
});

There are multiple calls to sendJSONRequest inside vacuumvaletudo.js and vacuumre.js. I’m not sure about the other calls. I could provide a pull request with this fix for all sendJSONRequest calls, but I could not test the Valetudo RE part and I need to know first, if Valetudo RE supports Basic Auth.

Workaround since then: Disable HTTP Basic Auth in Valetudo.

[onfoot]

That's awesome, thanks for doing the research! I have another plugin I had to put basic auth support into, so the simple http request function I made for all my plugins already supports it, so I'll make sure first if both valetudos work the same way and enable the support here.

[T-Bone90]

Any news? :)

[onfoot]

Coming right up! Hopefully I'll test the change today and push out an update. Will be untested on Valetudo non-RE for now, though.

[onfoot]

v0.3.0 is ready for consumption. 🎉

[T-Bone90]

Thanks for the new version and happy new year :) I found a Bug in the new version..

No plugin was found for the accessory "Valetudo Vacuum" in your config.json. Please make sure the corresponding plugin is installed correctly.

In the Config I have two entrys for your plugin. The second entry come with v0.3.0.

"accessory": "ValetudoXiaomiVacuum", "name": "Roborock S5", "ip": "xxxxxx"

"name": "Robi", "ip": "xxxxxx", "legacy-mode": false, "accessory": "Valetudo Vacuum"

If I delete the first entry, the Error looks the same. I think I must remove the first entry. Or the plugins write the wrong "accessory" entry in the config.

If I change name or ip in your plugin config, the second entry is change.

I think the new version use the wrong "accessory" name. "Valetudo Vacuum" instead of "ValetudoXiaomiVacuum" :)

[onfoot]

That's interesting, since your error message says the opposite. 😄 You seem to have one "Valetudo Vacuum" plugin configured instead of "ValetudoXiaomiVacuum".

[T-Bone90]

OK that's weird. I just installed your plugin. I used another Roborock Plugin in the past but at the moment your plugin is the only.

The error message says I must delete the second entry (Valetudo Vacuum) because there is no Plugin "Valetudo Vacuum". But If I change the settings in "your" plugin, the second entry in my config file is change. So I can't delete the second plugin. Your plugin use the second entry (Valetudo Vacuum). So I think it's a bug, Something is wrong. :)

[greatestview]

Same here, was ValetudoXiaomiVacuum before, after update a new accessory Valetudo Vacuum was created. After cleaning up the config and removing Valetudo Vacuum it's working again.

[T-Bone90]

Yes that's right. But If I go to Plugins Settings and make entrys, the entry Valetudo Vacuum is automatically recreate in the config file.

[onfoot]

That's wild. The only place the "Valetudo Vacuum" string exists is my local-only config schema file I'm working on to be able to better control the plugin through the Homebridge Web UI in the near future. I'll investigate this issue for sure.

You're both using the UI currently? Or is it also happening when configured from command line?

[T-Bone90]

I only use UI.

[onfoot]

Thanks, I'll check it out!

The weird thing is that the plugin registers itself as ValetudoXiaomiVacuum here so I have no idea where it's grabbing the Valetudo Vacuum name from.

[greatestview]

You’re right, the String Valetudo Vacuum does not appear to be part of the code. Strange.

I can replicate the behavior:

1. Go to /plugins and click settings on Homebridge Valetudo Xiaomi Vacuum.
2. Enter some data.
3. Go to /config and see, that there is a new entry in accessories, which looks like this:

   {
       "name": "Test",
       "ip": "123.123.123",
       "legacy-mode": false,
       "accessory": "Valetudo Vacuum"
   }

Reboot doesn’t change anything. All my plugins are up to date.

Workaround: Delete the entry and keep using an accessory ValetudoXiaomiVacuum.

---

Update: I think I found something. There is a config.schema.json on NPM with Valetudo Vacuum alias!

[onfoot]

Yep, that's the crux of the issue! I just published v0.3.1 without the file for now as it's not complete.

Thanks for noticing! I didn't realise somehow npm grabs the code for the published module. Seems like they want to control the contents in some way.

[greatestview]

That should’ve solved it, thank you!

[onfoot]

So, this seems to be resolved, finally. Isn't it? ;)

[T-Bone90]

No sorry the bug already exist :-( v0.3.1 Every morning 03:35

[6.1.2023, 03:35:57] [Robi] Error parsing current status info: SyntaxError: Unexpected token M in JSON at position 0

[onfoot]

A version with better json parsing diagnostic coming soon, unless I come down with the flu. 🤢

[onfoot]

I'm alive. v0.3.2 is up. Let's try to figure this out.

[T-Bone90]

No, now I get an other error. 😅

[7.1.2023, 03:35:28] [Robi] Error parsing current status info: Error: connect ECONNREFUSED 192.168.255.20:80

[onfoot]

That's a connection refused error - something at this address does not accept calls to port 80. Notice your ip is highly sus: 192.168.255.20 . 🤔

[T-Bone90]

Yes that's my IP range. 192.168.255.x But the IP range is quite regular and can also be used normally. There shouldn't be any problems with that. I will check this night.

[onfoot]

Yeah, I mean the ip is valid, but pretty unusual, so my thought was that maybe there's a typo there somewhere. ;)

Oh, perhaps it's restarting due to some watchdog timer firing, and the http server is not available at that moment.

[T-Bone90]

No there is no typing error ;-)

This morning the same: [8.1.2023, 03:35:07] [Robi] Error parsing current status info: Error: connect EHOSTUNREACH 192.168.255.20:80

[onfoot]

That, in turn, is a "Host unreachable" error, meaning the device was not available for connecting. 🤷‍♂ E.g. its network interface was disconnected at that moment.

[T-Bone90]

Yes but the problems are only since v0.3.2 ;-) Before this error was not.

[onfoot]

So previously you'd only get the Unexpected token M in JSON at position 0 ones?

[onfoot]

Actually, I've been thinking about the errors you're getting. Here they are sorted by time of day: [8.1.2023, 03:35:07] [Robi] Error parsing current status info: Error: connect EHOSTUNREACH 192.168.255.20:80 [7.1.2023, 03:35:28] [Robi] Error parsing current status info: Error: connect ECONNREFUSED 192.168.255.20:80 [6.1.2023, 03:35:57] [Robi] Error parsing current status info: SyntaxError: Unexpected token M in JSON at position 0

That would suggest to me that the vacuum Robi is rebooting at 03:35, for the first few seconds a connection to it is completely unavailable as the network interface is not up. That's the host unreachable error. Then the network is up, but the web server is not yet running, hence the connection refused error. And finally when it's up, it used to get another error, perhaps related to authorization. But we can't tell what error's first M letter stands for. 😄

If it were N, it would probably expand to Not Authorized or No authorization credentials specified or something similar.

Let's gather some more data. 😄

[T-Bone90]

So previously you'd only get the Unexpected token M in JSON at position 0 ones?

Yes! But I don't know what happened.

I take a look at the log one minute ago and see this error messages (all red):

[8.1.2023, 03:35:07] [Robi] Error parsing current status info: Error: connect EHOSTUNREACH 192.168.255.20:80 [8.1.2023, 14:32:54] [Robi] Error parsing current status info: Error: connect ECONNREFUSED 192.168.255.20:80 [9.1.2023, 03:36:16] [Robi] Error parsing current status info: Error: SyntaxError: Unexpected token M in JSON at position 0; content: 'MiioTimeoutError: request timed out:{"method":"get_status","params":{}}'

The second is 14:32.

But I can't believe that my Roborock is reboot every time. 🤔 I use the newest Valetudo.

Here is an Excerpt from my valeted log. Maybe you find some

2023-01-09T02:35:43.031Z Info Set Logfile to /tmp/valetudo.log 2023-01-09T02:35:43.045Z Info Autodetected RoborockS5ValetudoRobot 2023-01-09T02:35:43.218Z Info Starting Valetudo 2023.01.0 2023-01-09T02:35:43.220Z Info Commit ID: xxxxx 2023-01-09T02:35:43.222Z Info Configuration file: /mnt/data/valetudo/valetudo_config.json 2023-01-09T02:35:43.224Z Info Logfile: /tmp/valetudo.log 2023-01-09T02:35:43.226Z Info Robot: Roborock S5 (RoborockS5ValetudoRobot) 2023-01-09T02:35:43.227Z Info JS Runtime Version: v18.12.1-Valetudo 2023-01-09T02:35:43.227Z Info Arch: arm 2023-01-09T02:35:43.232Z Info Max Heap Size: 42 MiB 2023-01-09T02:35:43.233Z Info Node Flags: --expose-gc --max-heap-size=42 2023-01-09T02:35:43.250Z Info Autogenerated System ID: FlawedGeneralCamel 2023-01-09T02:35:43.255Z Info DeviceId xxxxxx 2023-01-09T02:35:43.257Z Info IP 127.0.0.1 2023-01-09T02:35:43.257Z Info CloudSecret xxxxxxx 2023-01-09T02:35:43.259Z Info LocalSecret xxxxxx 2023-01-09T02:35:43.262Z Info Firmware Version: 002034 2023-01-09T02:35:43.269Z Info Current rootfs: system_a (/dev/mmcblk0p8) 2023-01-09T02:35:43.307Z Info Valetudo can be reached via: valetudo-flawedgeneralcamel.local 2023-01-09T02:35:57.673Z Info Current /proc/self/oom_score_adj: 666 2023-01-09T02:35:57.696Z Info Dummycloud is spoofing 127.0.0.1:8053 on 127.0.0.1:8053 2023-01-09T02:35:57.716Z Info Webserver running on port 80 2023-01-09T02:35:57.727Z Info FDSMockServer running on port 8079 2023-01-09T02:35:57.763Z Info Bonjour service "Valetudo FlawedGeneralCamel Web" with type "http" started 2023-01-09T02:35:57.765Z Info Bonjour service "Valetudo FlawedGeneralCamel" with type "valetudo" started 2023-01-09T02:35:56.004Z Info Successfully set the robot time via NTP to 2023-01-09T02:35:56.903Z 2023-01-09T02:36:15.143Z Warn Unable to reach vacuum. Giving up after 100 tries 2023-01-09T02:36:16.378Z Info Dummycloud connected 2023-01-09T10:35:57.005Z Info Successfully set the robot time via NTP to 2023-01-09T10:35:57.903Z

Yes there is a "warning" 02:36 that the Roborock can't reach vacuum. I don't know. But I don' have a warning 14:32...

And I'm not the only one who gets the errors. Hmm 🤔

///Edit: I wanted to use HomeKit to clean with my Roborock. I got this error when I flipped the switch

[9.1.2023, 17:36:55] [Robi] Failed to stop cleaning: Error: This callback function has already been called by someone else; it can only be called one time. [9.1.2023, 17:36:55] Error: This callback function has already been called by someone else; it can only be called one time. at /usr/lib/node_modules/homebridge/node_modules/hap-nodejs/src/lib/util/once.ts:12:13 at /usr/lib/node_modules/homebridge-valetudo-xiaomi-vacuum/vacuumvaletudo.js:269:9 at processTicksAndRejections (node:internal/process/task_queues:95:5) [9.1.2023, 17:36:55] Got SIGTERM, shutting down Homebridge... [9.1.2023, 17:36:55] Got SIGTERM, shutting down child bridge process... [9.1.2023, 17:36:55] Got SIGTERM, shutting down child bridge process... [9.1.2023, 17:37:00] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null [9.1.2023, 17:37:05] [HB Supervisor] Restarting Homebridge... ...

I haven't named the switches yet.

I hope this infos help a little bit.

[onfoot]

See? At least the unreachable/refused scenario is confirmed by the first lines of the log:

2023-01-09T02:35:43.218Z
Info
Starting Valetudo 2023.01.0

This is probably it. The time difference is due to it logging in GMT, and homebridge logging in local time.

MiioTimeoutError: request timed out:{"method":"get_status","params":{}} this probably means that Valetudo did start after the reboot, but not all backend is up yet, so Valetudo is timing out in contacting the miio api.

About the "Failed to stop cleaning", however - that is an actual bug I need to investigate, because this is something new. 🤔

[T-Bone90]

Hmm thats confused. I didn't found an option in valetudo because of the reboots (Maybe wanted...).

I can ask and open an issue on valetudo GitHub. But first I'll wait another night and check the log again.

But was is with " Error: connect ECONNREFUSED" 14:32? I don't have any entry in my valetudo log on this time.

[T-Bone90]

This night I didn't get the error in homebridge. But I see this night the same "Starting Valetudo 2023.01.0" in the valetudo log. 🤔

I'll keep checking.

[T-Bone90]

So every night I got this error [13.1.2023, 03:35:25] [Robi] Error parsing current status info: Error: connect ECONNREFUSED 192.168.255.20:80 or this [12.1.2023, 03:36:10] [Robi] Error parsing current status info: Error: SyntaxError: Unexpected token M in JSON at position 0; content: 'MiioTimeoutError: request timed out:{"method":"get_status","params":{}}'

I don't know what role that plays. I kinda can't believe my robot disconnects every night. It definitely can't be the plugin? Otherwise, if you think Valetudo is to blame, I'll ask in the one of the valetudo topic. But I don't think it just cuts off the connection to my vacuum cleaner at night.

Does anybody else have the same problem?

[onfoot]

The plugin simply logs what issue it encountered when connecting to the vacuum at that particular moment. It doesn't control any network interfaces of the device. And because it checks for device's status every once in a while, it may encounter a temporary issue caused by the vacuum rebooting every night at around 3:35. I just checked mine and it rebooted last night at 3:34.

[T-Bone90]

Ahh ok thanks a lot. So it's a valetudo problem. I'll ask there again, apparently on purpose.

[onfoot]

I did a bit of digging and it doesn't seem to be a problem per se. According to a comment in this file all valetudo-capable vacuums reboot daily.