search

ycardon / gigaset-elements-proxy

a simple web and MQTT bridge with gigaset-elements APIs (no more maintained)
GNU General Public License v3.0
18 stars 5 forks source link

App is crashing when it fails to parse raw JSON #10

Closed dotvav closed 5 years ago

dotvav commented 5 years ago

The app will crash after few hours when it doesn't receive the expected response from the Gigaset servers. I have had several errors like the examples below. The problem is that these errors are not caught and the whole process stops. I have updated my upstart configuration with a respawn stanza, but it would be a bit nicer to handle this kind of exceptions (log, retry, return an error status code) more gracefully in the code.

Example1

2019-02-22T20:24:39+0100 /volume1/homeassistant/gigaset-elements-proxy/app.js:170
                                JSON.parse(body)[0].sensors.map(s => {
                                                   ^

TypeError: Cannot read property 'sensors' of undefined
    at Request.request.get [as _callback] (/volume1/homeassistant/gigaset-elements-proxy/app.js:170:24)
    at Request.self.callback (/volume1/homeassistant/gigaset-elements-proxy/node_modules/request/request.js:185:22)
    at emitTwo (events.js:126:13)
    at Request.emit (events.js:214:7)
    at Request.<anonymous> (/volume1/homeassistant/gigaset-elements-proxy/node_modules/request/request.js:1161:10)
    at emitOne (events.js:116:13)
    at Request.emit (events.js:211:7)
    at IncomingMessage.<anonymous> (/volume1/homeassistant/gigaset-elements-proxy/node_modules/request/request.js:1083:12)
    at Object.onceWrapper (events.js:313:30)
    at emitNone (events.js:111:20)

Example2

2019-02-23T17:58:04+0100 /volume1/homeassistant/gigaset-elements-proxy/app.js:85
                        JSON.parse(body).events.reverse().map(ev => {
                                               ^

TypeError: Cannot read property 'reverse' of undefined
    at Request.request.get [as _callback] (/volume1/homeassistant/gigaset-elements-proxy/app.js:85:27)
    at Request.self.callback (/volume1/homeassistant/gigaset-elements-proxy/node_modules/request/request.js:185:22)
    at emitTwo (events.js:126:13)
    at Request.emit (events.js:214:7)
    at Request.<anonymous> (/volume1/homeassistant/gigaset-elements-proxy/node_modules/request/request.js:1161:10)
    at emitOne (events.js:116:13)
    at Request.emit (events.js:211:7)
    at IncomingMessage.<anonymous> (/volume1/homeassistant/gigaset-elements-proxy/node_modules/request/request.js:1083:12)
    at Object.onceWrapper (events.js:313:30)
    at emitNone (events.js:111:20)
h4nc commented 5 years ago

I can not help you, but I'm interessted because of this line

/volume1/homeassistant/gigaset-elements-proxy/app.js

Did you intall it on the same instance that runs home assistant?

Do you know if this is possible with hassio too? You may not be running hassio, I think.

ycardon commented 5 years ago

it would be a bit nicer to handle this kind of exceptions (log, retry, return an error status code) more gracefully in the code.

Yes it makes sense. I'm adding a proper exception catching, at least to get proper logging. I'll be a little cautious about immediate retrying: I suspect gigaset is doing some kind of client ban.

ycardon commented 5 years ago

Just committed, please let me know if it's better and what are your returned message bodies.

dotvav commented 5 years ago

I can not help you, but I'm interessted because of this line

/volume1/homeassistant/gigaset-elements-proxy/app.js

Did you intall it on the same instance that runs home assistant?

Do you knwo if this is possible with hassio too? You may not be running hassio, I think.

I'm running the proxy on the same box as homeassistant, a Synology box. The path is a bit misleading as homeassistant is not installed in that directory :)

Just committed, please let me know if it's better and what are your returned message bodies.

Thanks, I'll try and I will let you know :)

h4nc commented 5 years ago

I thought maybe you somehow changed it to be an addon

https://github.com/ycardon/gigaset-elements-proxy/issues/6

ycardon commented 5 years ago

@dotvav, it appears that some of the parsing errors comes from the gigaset authentication being expired. I've set a lower default re-authentication value (60mn to 10mn) and forced a re-authentication on a parsing error.

@h4nc, about a hass.io add-on: I'm sorry, I couldn't install hass.io properly (neither on a VM nor a pi, I suspect something with IPv6 on my network), so no add-on until I've fixed that.

h4nc commented 5 years ago

I just wanted to repull the new changes that you made, but I get an abort.

Please commit or stash your changes

Yesterday it worked fine to repull. What am I doing wrong?

As everytime when I repull your component I do:

cd gigaset-elements-proxy
sudo rm app.js
git pull
h4nc commented 5 years ago

@ycardon I figured out how to pull again, because of the change in default.yaml, I had to remove that file and after git pull change the settings again to my needs.

This night my binary senors notified me that the gigaset availabilty was offline for some hours. I did not notice this behaviour before the update yesterday. Is this coincidence or why dd this happen?

binary_sensor looks like this:

- platform: rest
  name: gigaset_availability # Online/Offline
  scan_interval: '15'
  resource: http://MYIP:3000/api/v1/me/basestations
  value_template: "{{ value_json[0].status == 'online' }}"

Side questions: 1) I don't have a camera. Is it save to comment out those 3 camera specific lines in the default.yaml? 2) There is a new room feature within the gigaset app, is it save to place the sensors in rooms, or will placing them in rooms interfere with this component and make it fail?

ycardon commented 5 years ago

@h4nc

  1. for your future git troubles, you should check how to do a "force pull" (here for exemple)
  2. well as long as you are not using the corresponding camera urls, it should be safe...
  3. I haven't tried, if the gigaset message structure is not changed this will work. If you try it, send me the new messages and I will try to put the room information in the APIs and MQTT messages.
h4nc commented 5 years ago
  1. I don't want to make something wrong

so instead of 

cd gigaset-elements-proxy
sudo rm app.js
git pull

I will have to to this?

cd gigaset-elements-proxy git fetch --all git reset --hard origin/master git pull origin master

or do I have to change origin master?

  1. I tried and the corresponding links will reply with an error, as expected. I have no camera. What would you do, should I comment those lines out or leave them as they are. Maybe never change a running system is the right idea here?

  2. I already tried. It doesn't influence the structure. Seems like it only does this within the App Maybe you could also try to move them in rooms to confirm?

dotvav commented 5 years ago

@dotvav, it appears that some of the parsing errors comes from the gigaset authentication being expired. I've set a lower default re-authentication value (60mn to 10mn) and forced a re-authentication on a parsing error. suspect something with IPv6 on my network), so no add-on until I've fixed that.

OK I can confirm that once on Feb 24, I the app has been logging "401 Unauthorized" events every 10 seconds for 1 hour.

I have just pulled the latest change so this shouldn't happen anymore.

Do you have any experience with a check_events_interval < 10 seconds? I'm using the Gigaset motion detector to trigger some lights automation at home, and I find the 10s a bit too long. But I am afraid to get disconnected/banned if I hammer the Gigaset endpoint too hard...

ycardon commented 5 years ago

I've set it to 2s... so far it's ok (except for the 1h disconnection, but it seems "normal")

h4nc commented 5 years ago

@ycardon

Could you answer this? Please.

0) I will have to to this?

cd gigaset-elements-proxy git fetch --all git reset --hard origin/master git pull origin master

or do I have to change origin master?

  1. I tried and the corresponding links will reply with an error, as expected. I have no camera. What would you do, should I comment those lines out or leave them as they are. Maybe never change a running system is the right idea here?
  2. I already tried. It doesn't influence the structure. Seems like it only does this within the App Maybe you could also try to move them in rooms to confirm?
ycardon commented 5 years ago

yeah sorry,

  1. yes it should run like this, keep origin master as its said.
  2. if it's not broken, don't fix it
  3. me neither, seems to be inside the app only
h4nc commented 5 years ago
  1. ok I will try that next time you update this tool.

Thanks!

dotvav commented 5 years ago

Not sure what happened today but the app kept dying every 10 minutes and was being restarted by upstart. Not many details in the logs...

2019-03-01T11:55:45+0100 [Fri Mar 01 2019 11:55:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T11:55:47+0100 [Fri Mar 01 2019 11:55:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:05:45+0100 [Fri Mar 01 2019 12:05:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:05:47+0100 [Fri Mar 01 2019 12:05:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:15:45+0100 [Fri Mar 01 2019 12:15:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:15:47+0100 [Fri Mar 01 2019 12:15:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:25:45+0100 [Fri Mar 01 2019 12:25:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:25:47+0100 [Fri Mar 01 2019 12:25:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:35:45+0100 [Fri Mar 01 2019 12:35:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:35:47+0100 [Fri Mar 01 2019 12:35:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:45:45+0100 [Fri Mar 01 2019 12:45:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:45:47+0100 [Fri Mar 01 2019 12:45:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:55:45+0100 [Fri Mar 01 2019 12:55:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:55:47+0100 [Fri Mar 01 2019 12:55:47] [INFO]   authorized on gigaset cloud api
2019-03-01T12:56:20+0100 [Fri Mar 01 2019 12:56:20] [ERROR]  check events | unexpected gigaset response:{"error": {"message": "Unauthorized", "code": 401, "type": "Http401"}}
2019-03-01T12:56:20+0100 [Fri Mar 01 2019 12:56:20] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T12:56:22+0100 [Fri Mar 01 2019 12:56:22] [INFO]   authorized on gigaset cloud api
2019-03-01T13:05:45+0100 [Fri Mar 01 2019 13:05:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:05:47+0100 [Fri Mar 01 2019 13:05:47] [INFO]   authorized on gigaset cloud api
2019-03-01T13:15:45+0100 [Fri Mar 01 2019 13:15:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:15:47+0100 [Fri Mar 01 2019 13:15:47] [INFO]   authorized on gigaset cloud api
2019-03-01T13:25:45+0100 [Fri Mar 01 2019 13:25:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:25:47+0100 [Fri Mar 01 2019 13:25:47] [INFO]   authorized on gigaset cloud api
2019-03-01T13:29:52+0100 [Fri Mar 01 2019 13:29:52] [ERROR]  check events | unexpected gigaset response:undefined
2019-03-01T13:29:52+0100 [Fri Mar 01 2019 13:29:52] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:29:53+0100 [Fri Mar 01 2019 13:29:53] [INFO]   authorized on gigaset cloud api
2019-03-01T13:35:45+0100 [Fri Mar 01 2019 13:35:45] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:35:47+0100 [Fri Mar 01 2019 13:35:47] [INFO]   authorized on gigaset cloud api
2019-03-01T13:45:46+0100 [Fri Mar 01 2019 13:45:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:45:47+0100 [Fri Mar 01 2019 13:45:47] [INFO]   authorized on gigaset cloud api
2019-03-01T13:55:46+0100 [Fri Mar 01 2019 13:55:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T13:55:47+0100 [Fri Mar 01 2019 13:55:47] [INFO]   authorized on gigaset cloud api
2019-03-01T14:05:46+0100 [Fri Mar 01 2019 14:05:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T14:05:47+0100 [Fri Mar 01 2019 14:05:47] [INFO]   authorized on gigaset cloud api
2019-03-01T14:15:46+0100 [Fri Mar 01 2019 14:15:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T14:15:47+0100 [Fri Mar 01 2019 14:15:47] [INFO]   authorized on gigaset cloud api
2019-03-01T14:25:46+0100 [Fri Mar 01 2019 14:25:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T14:25:47+0100 [Fri Mar 01 2019 14:25:47] [INFO]   authorized on gigaset cloud api
2019-03-01T14:35:46+0100 [Fri Mar 01 2019 14:35:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T14:35:47+0100 [Fri Mar 01 2019 14:35:47] [INFO]   authorized on gigaset cloud api
2019-03-01T14:45:46+0100 [Fri Mar 01 2019 14:45:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T14:45:47+0100 [Fri Mar 01 2019 14:45:47] [INFO]   authorized on gigaset cloud api
2019-03-01T14:55:46+0100 [Fri Mar 01 2019 14:55:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T14:55:47+0100 [Fri Mar 01 2019 14:55:47] [INFO]   authorized on gigaset cloud api
2019-03-01T15:05:46+0100 [Fri Mar 01 2019 15:05:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T15:05:47+0100 [Fri Mar 01 2019 15:05:47] [INFO]   authorized on gigaset cloud api
2019-03-01T15:15:46+0100 [Fri Mar 01 2019 15:15:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T15:15:47+0100 [Fri Mar 01 2019 15:15:47] [INFO]   authorized on gigaset cloud api
2019-03-01T15:25:46+0100 [Fri Mar 01 2019 15:25:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T15:25:47+0100 [Fri Mar 01 2019 15:25:47] [INFO]   authorized on gigaset cloud api
2019-03-01T15:35:46+0100 [Fri Mar 01 2019 15:35:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T15:35:47+0100 [Fri Mar 01 2019 15:35:47] [INFO]   authorized on gigaset cloud api
2019-03-01T15:45:46+0100 [Fri Mar 01 2019 15:45:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T15:45:47+0100 [Fri Mar 01 2019 15:45:47] [INFO]   authorized on gigaset cloud api
2019-03-01T15:55:46+0100 [Fri Mar 01 2019 15:55:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T15:55:47+0100 [Fri Mar 01 2019 15:55:47] [INFO]   authorized on gigaset cloud api
2019-03-01T16:05:46+0100 [Fri Mar 01 2019 16:05:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T16:05:47+0100 [Fri Mar 01 2019 16:05:47] [INFO]   authorized on gigaset cloud api
2019-03-01T16:15:46+0100 [Fri Mar 01 2019 16:15:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T16:15:47+0100 [Fri Mar 01 2019 16:15:47] [INFO]   authorized on gigaset cloud api
2019-03-01T16:25:46+0100 [Fri Mar 01 2019 16:25:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T16:25:47+0100 [Fri Mar 01 2019 16:25:47] [INFO]   authorized on gigaset cloud api
2019-03-01T16:35:46+0100 [Fri Mar 01 2019 16:35:46] [INFO]   gigaset-element-provy v1.4.5 starting
2019-03-01T16:35:47+0100 [Fri Mar 01 2019 16:35:47] [INFO]   authorized on gigaset cloud api
h4nc commented 5 years ago

I did not see in the logs, but my gigaset Sensor in ha says something similar.

Often unavailable.

Isn't it normal that it reauthorises every 10 min. @ycardon will give us the answers. thanks Looks exactly the same in my logs. Every 10 mins.

img_8616-2

ycardon commented 5 years ago

@h4nc is right: the auth is now 10mn by default, what is not right is that I’m logging that the service has started each time it re-auth: I should move this log out of the auth function :)

dotvav commented 5 years ago

makes perfect sense, thanks :)

h4nc commented 5 years ago

@ycardon could you notify us here, when you updated the App. Thanks!

h4nc commented 5 years ago

@ycardon today something strange happened. My gigaset turned to custommode, without me or someone else changing it to custommode (individual mode).

Could something from this app lead to this? I mean it isn't able to switch modes right? Or could this app be a security issue, so that someone else got the pw from default.yaml? Is that possible?

Edit: Is there a way to see who or what triggered the mode to switch to custom? (From the logs I don’t think so, but you know it better, so I wanted to ask you).

I’m a little concerned.

Thank you!

ycardon commented 5 years ago

@h4nc, I’d go for something from gigaset side but I cannot be sure. What I know is there is no way inside gigaset-proxy to send commands, it can only read states and events (I try to implement commands but I couldn’t). Your config passwords are not accessible through any port exposed by gigaset-proxy, you have to have a disk/os access to get it. If you are concerned with security you should first check on your router.

h4nc commented 5 years ago

@ycardon thanks! I contacted gigaset and I'm waiting for their reply. Did you had that behaviour before?

Good to know that it can't be the gigaset-proxy. Also good too know that that the password is save in the gigaset-proxy. Router settings should be fine.

One open question: Is there a way in the api to see which device (or who) changed the one. In my knowledge it only tells us that the mode was switched but not from whom.

h4nc commented 5 years ago

@ycardon do you know the answer to that last question?

Is there a way in the api to see which device (or who) changed the one. In my knowledge it only tells us that the mode was switched but not from whom.

thanks

ycardon commented 5 years ago

Well, not in the gigaset-proxy for sure, maybe in the raw gigaset API (check in the /events section) but I don't know if there is enough retention for you to check on old events.

h4nc commented 5 years ago

I was in contact with gigaset about that. The only thing they can tell you, is if it was set from an ios or android device. And if was set from a widget or the App They can't event tell which device/user set the mode. So if they can't tell more, than we also will not be able to get more information out of the api.

In the meanwhile I think someone in family pressed it by accidentally. However to be sure I changed the password.

Edit: I looked in the events section and even for new event there is nothing that would point to a certain device that changed a mode.