search

stonegray / speedtest2ha

Containerized speedtest results in Home Assistant via MQTT
https://hub.docker.com/repository/docker/stonegray/speedtest2ha/general
5 stars 3 forks source link

Poor handling of unavailable speedtest server / Test fails after a while #6

Closed mcfrojd closed 1 year ago

mcfrojd commented 1 year ago

I installed this using this docker-compose.yaml

---
version: "3.4"
services:
################################################################
# Speedtest2ha                                                ##
# https://github.com/stonegray/speedtest2ha                   ##
################################################################
  speedtest:
    image: stonegray/speedtest2ha:main
    container_name: speedtest2ha
    environment:
      - MQTT_HOST=mqtt://192.168.***.**
      - MQTT_USER=**********
      - MQTT_PASS=***********
      - CRON=*/30 * * * *
    restart: always

The initial run worked fine and the sensors was auto discovered in HA.

Later when i checked i found this error from the container.

2023-01-12T14:30:00.977816463Z Starting test...
2023-01-12T14:30:00.977960694Z Data { testinprogress: 'true' }
2023-01-12T14:30:00.977967612Z Processing sensor upload undefined speedtest/upload
2023-01-12T14:30:00.977970486Z Processing sensor download undefined speedtest/download
2023-01-12T14:30:00.977972940Z Processing sensor ping undefined speedtest/ping
2023-01-12T14:30:00.977975313Z Processing sensor jitter undefined speedtest/jitter
2023-01-12T14:30:00.977977608Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-12T14:30:00.977979947Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-12T14:30:00.977986906Z Backend did not provide the following key, skipping: upload
2023-01-12T14:30:00.977989655Z Backend did not provide the following key, skipping: download
2023-01-12T14:30:00.977991924Z Backend did not provide the following key, skipping: ping
2023-01-12T14:30:00.977994165Z Backend did not provide the following key, skipping: jitter
2023-01-12T14:30:00.978006608Z Backend did not provide the following key, skipping: uploadtotal
2023-01-12T14:30:00.978009169Z Backend did not provide the following key, skipping: downloadtotal
2023-01-12T14:30:00.978054128Z Processing sensor testinprogress true speedtest/testinprogress
2023-01-12T14:30:00.980534476Z Processing sensor runtest undefined speedtest/runtest
2023-01-12T14:30:00.980551787Z Processing sensor schedule undefined speedtest/schedule
2023-01-12T14:30:00.980555001Z Finished updating sensors
2023-01-12T14:30:00.980562264Z Backend did not provide the following key, skipping: runtest
2023-01-12T14:30:00.980565037Z Backend did not provide the following key, skipping: schedule
2023-01-12T14:30:01.804363727Z Data { testinprogress: 'false' }
2023-01-12T14:30:01.804396412Z Processing sensor upload undefined speedtest/upload
2023-01-12T14:30:01.804402261Z Processing sensor download undefined speedtest/download
2023-01-12T14:30:01.804406353Z Processing sensor ping undefined speedtest/ping
2023-01-12T14:30:01.804410098Z Processing sensor jitter undefined speedtest/jitter
2023-01-12T14:30:01.804413801Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-12T14:30:01.804417624Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-12T14:30:01.804421339Z Processing sensor testinprogress false speedtest/testinprogress
2023-01-12T14:30:01.804424944Z Sending data...
2023-01-12T14:30:01.804428431Z Data {
2023-01-12T14:30:01.804432075Z   error: true,
2023-01-12T14:30:01.804435766Z   message: 'Unable to connect to servers to test latency.'
2023-01-12T14:30:01.804439491Z }
2023-01-12T14:30:01.804443205Z Processing sensor upload undefined speedtest/upload
2023-01-12T14:30:01.804465018Z Processing sensor download undefined speedtest/download
2023-01-12T14:30:01.804467892Z Processing sensor ping undefined speedtest/ping
2023-01-12T14:30:01.804470123Z Processing sensor jitter undefined speedtest/jitter
2023-01-12T14:30:01.804472306Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-12T14:30:01.804474615Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-12T14:30:01.804476915Z Processing sensor testinprogress undefined speedtest/testinprogress
2023-01-12T14:30:01.804479161Z Processing sensor runtest undefined speedtest/runtest
2023-01-12T14:30:01.804481336Z Processing sensor schedule undefined speedtest/schedule
2023-01-12T14:30:01.804483546Z Finished updating sensors
2023-01-12T14:30:01.804485735Z Processing sensor runtest undefined speedtest/runtest
2023-01-12T14:30:01.804487926Z Processing sensor schedule undefined speedtest/schedule
2023-01-12T14:30:01.804490149Z Finished updating sensors
2023-01-12T14:30:01.804368531Z Backend did not provide the following key, skipping: upload
2023-01-12T14:30:01.804525674Z Backend did not provide the following key, skipping: download
2023-01-12T14:30:01.804528098Z Backend did not provide the following key, skipping: ping
2023-01-12T14:30:01.804530292Z Backend did not provide the following key, skipping: jitter
2023-01-12T14:30:01.804532528Z Backend did not provide the following key, skipping: uploadtotal
2023-01-12T14:30:01.804534750Z Backend did not provide the following key, skipping: downloadtotal
2023-01-12T14:30:01.804537047Z Backend did not provide the following key, skipping: upload
2023-01-12T14:30:01.804539242Z Backend did not provide the following key, skipping: download
2023-01-12T14:30:01.804541424Z Backend did not provide the following key, skipping: ping
2023-01-12T14:30:01.804543624Z Backend did not provide the following key, skipping: jitter
2023-01-12T14:30:01.804545822Z Backend did not provide the following key, skipping: uploadtotal
2023-01-12T14:30:01.804548033Z Backend did not provide the following key, skipping: downloadtotal
2023-01-12T14:30:01.804550242Z Backend did not provide the following key, skipping: testinprogress
2023-01-12T14:30:01.804552447Z Backend did not provide the following key, skipping: runtest
2023-01-12T14:30:01.804554663Z Backend did not provide the following key, skipping: schedule
2023-01-12T14:30:01.804556849Z Backend did not provide the following key, skipping: runtest
2023-01-12T14:30:01.804559049Z Backend did not provide the following key, skipping: schedule

Any idea why this is? The sensors in HA are now "unavailable" The current release in github when i deployed the docker was: https://github.com/stonegray/speedtest2ha/releases/tag/20230112053512 And it looks as the image tag on dockerhub is from the same release time as the github release.

stonegray commented 1 year ago

Thanks for the report. That error originates from within speedtest-cli itself. It could be caused by the speedtest server itself being overloaded.

It originates here: https://github.com/sivel/speedtest-cli/blob/22210ca35228f0bbcef75a7c14587c4ecb875ab4/speedtest.py#L1504

You can try running speedtest in a browser and forcing it to use a server ID you know works, or exclude servers that are frequently down with SPEEDTEST_SERVER_EXCLUDE.

Fast.com has far more servers (provided by Netflix) so should avoid the issue. You can try SPEEDTEST_BACKEND_FAST=true, although it only reports download speed at the moment.

Appears to affect the HA integration as well: https://github.com/home-assistant/core/issues/85375

I'd suggest leaving it for now. It will come back online normally if the next test succeeds. I'll see about adding a function to retry failed tests, or maybe failover to fast.com. Not sure it will help but should be easy to implement.

mcfrojd commented 1 year ago

I have been running moafrancky/speedtest2mqtt with no issues prior, not sure if that docker is similar to yours. Today when i looked at the docker the same error is still present. I removed the docker. I removed "Speedtest Connector" from my Mqtt integration in Home assistant. I removed all topics related to speedtest and speedtester in mqtt explorer. I restarted home assistant. I re-deployed the docker and the following happend.

The docker spins-up, and give this log:

2023-01-13T11:45:09.889972050Z Starting test...
2023-01-13T11:45:09.892394856Z Data { testinprogress: 'true' }
2023-01-13T11:45:09.892457902Z Processing sensor upload undefined speedtest/upload
2023-01-13T11:45:09.892616559Z Backend did not provide the following key, skipping: upload
2023-01-13T11:45:09.892672981Z Processing sensor download undefined speedtest/download
2023-01-13T11:45:09.892907446Z Backend did not provide the following key, skipping: download
2023-01-13T11:45:09.892968207Z Processing sensor ping undefined speedtest/ping
2023-01-13T11:45:09.893008350Z Backend did not provide the following key, skipping: ping
2023-01-13T11:45:09.893051939Z Processing sensor jitter undefined speedtest/jitter
2023-01-13T11:45:09.893095382Z Backend did not provide the following key, skipping: jitter
2023-01-13T11:45:09.893156010Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-13T11:45:09.893192688Z Backend did not provide the following key, skipping: uploadtotal
2023-01-13T11:45:09.893374028Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-13T11:45:09.893410943Z Backend did not provide the following key, skipping: downloadtotal
2023-01-13T11:45:09.893460164Z Processing sensor testinprogress true speedtest/testinprogress
2023-01-13T11:45:09.932886064Z Connected to MQTT
2023-01-13T11:45:09.933948395Z Processing sensor runtest undefined speedtest/runtest
2023-01-13T11:45:09.934033087Z Backend did not provide the following key, skipping: runtest
2023-01-13T11:45:09.934039376Z Backend did not provide the following key, skipping: schedule
2023-01-13T11:45:09.934045582Z Processing sensor schedule undefined speedtest/schedule
2023-01-13T11:45:09.934053146Z Finished updating sensors
2023-01-13T11:45:09.935042289Z Sent discovery to MQTT
2023-01-13T11:45:27.496054474Z Data { testinprogress: 'false' }
2023-01-13T11:45:27.496079398Z Processing sensor upload undefined speedtest/upload
2023-01-13T11:45:27.496131369Z Backend did not provide the following key, skipping: upload
2023-01-13T11:45:27.496370947Z Processing sensor download undefined speedtest/download
2023-01-13T11:45:27.496380377Z Backend did not provide the following key, skipping: download
2023-01-13T11:45:27.496465773Z Processing sensor ping undefined speedtest/ping
2023-01-13T11:45:27.496474339Z Backend did not provide the following key, skipping: ping
2023-01-13T11:45:27.496556953Z Processing sensor jitter undefined speedtest/jitter
2023-01-13T11:45:27.496620227Z Backend did not provide the following key, skipping: jitter
2023-01-13T11:45:27.496674867Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-13T11:45:27.496688615Z Backend did not provide the following key, skipping: uploadtotal
2023-01-13T11:45:27.496764343Z Backend did not provide the following key, skipping: downloadtotal
2023-01-13T11:45:27.496781603Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-13T11:45:27.496784402Z Processing sensor testinprogress false speedtest/testinprogress
2023-01-13T11:45:27.496976085Z Sending data...
2023-01-13T11:45:27.497391937Z Data {
2023-01-13T11:45:27.497397500Z   error: false,
2023-01-13T11:45:27.497400034Z   download: 553.36,
2023-01-13T11:45:27.497402343Z   upload: 52.58,
2023-01-13T11:45:27.497404640Z   ping: 22.22,
2023-01-13T11:45:27.497406961Z   server: {
2023-01-13T11:45:27.497409291Z     url: 'http://speedtestse.pvdatanet.com:8080/speedtest/upload.php',
2023-01-13T11:45:27.497411711Z     lat: 'xx.xxxx',
2023-01-13T11:45:27.497413992Z     lon: 'xx.xxxx',
2023-01-13T11:45:27.497416283Z     name: 'Stockholm',
2023-01-13T11:45:27.497418557Z     country: 'Sweden',
2023-01-13T11:45:27.497420821Z     cc: 'SE',
2023-01-13T11:45:27.497423074Z     sponsor: 'PVDataNet',
2023-01-13T11:45:27.497425311Z     id: '38854',
2023-01-13T11:45:27.497427576Z     host: 'speedtestse.pvdatanet.com:8080',
2023-01-13T11:45:27.497429863Z     d: 50.932587656080635,
2023-01-13T11:45:27.497432091Z     latency: 22.22
2023-01-13T11:45:27.497434510Z   },
2023-01-13T11:45:27.497436778Z   timestamp: '2023-01-13T11:45:10.054562Z',
2023-01-13T11:45:27.497439069Z   bytes_sent: 65.94,
2023-01-13T11:45:27.497441352Z   bytes_received: 409373932,
2023-01-13T11:45:27.497443588Z   share: null,
2023-01-13T11:45:27.497449056Z   client: {
2023-01-13T11:45:27.497451381Z     ip: 'xx.xxx.xx.xxx',
2023-01-13T11:45:27.497453673Z     lat: 'xx.xxxx',
2023-01-13T11:45:27.497455954Z     lon: 'xx.xxxx',
2023-01-13T11:45:27.497458414Z     isp: 'Tele2 Sweden',
2023-01-13T11:45:27.497460684Z     isprating: '3.7',
2023-01-13T11:45:27.497462972Z     rating: '0',
2023-01-13T11:45:27.497465218Z     ispdlavg: '0',
2023-01-13T11:45:27.497467533Z     ispulavg: '0',
2023-01-13T11:45:27.497469755Z     loggedin: '0',
2023-01-13T11:45:27.497472049Z     country: 'SE'
2023-01-13T11:45:27.497474372Z   },
2023-01-13T11:45:27.497476571Z   bytes_recieved: 0
2023-01-13T11:45:27.497478820Z }
2023-01-13T11:45:27.497484650Z Processing sensor upload 52.58 speedtest/upload
2023-01-13T11:45:27.497534491Z Backend did not provide the following key, skipping: runtest
2023-01-13T11:45:27.497542764Z Processing sensor runtest undefined speedtest/runtest
2023-01-13T11:45:27.497545324Z Processing sensor schedule undefined speedtest/schedule
2023-01-13T11:45:27.497618958Z Backend did not provide the following key, skipping: schedule
2023-01-13T11:45:27.497629707Z Finished updating sensors
2023-01-13T11:45:27.497633881Z Processing sensor download 553.36 speedtest/download
2023-01-13T11:45:27.502762171Z Processing sensor ping 22.22 speedtest/ping
2023-01-13T11:45:27.502926217Z Backend did not provide the following key, skipping: jitter
2023-01-13T11:45:27.502937190Z Processing sensor jitter undefined speedtest/jitter
2023-01-13T11:45:27.503026003Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-13T11:45:27.503042211Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-13T11:45:27.503046717Z Processing sensor testinprogress undefined speedtest/testinprogress
2023-01-13T11:45:27.503050554Z Processing sensor runtest undefined speedtest/runtest
2023-01-13T11:45:27.503060909Z Backend did not provide the following key, skipping: uploadtotal
2023-01-13T11:45:27.503063610Z Backend did not provide the following key, skipping: downloadtotal
2023-01-13T11:45:27.503065944Z Backend did not provide the following key, skipping: testinprogress
2023-01-13T11:45:27.503115483Z Backend did not provide the following key, skipping: runtest
2023-01-13T11:45:27.503120583Z Backend did not provide the following key, skipping: schedule
2023-01-13T11:45:27.503126110Z Processing sensor schedule undefined speedtest/schedule
2023-01-13T11:45:27.503128688Z Finished updating sensors

That looks perfectly ok to me.

But when i look in home assistant the "Speedtest Connector" seems to have been discovered but all the sensors says unavailble.

See screenshot here: Home Assistant https://picoshare.mcfrojd.com/!4L85ykQzQk

"mqtt info" from homeassistant https://picoshare.mcfrojd.com/!xCDZ7r98ph

Here is a screenshot from mqtt explorer: https://picoshare.mcfrojd.com/!hT7pPPei74

Maybe the problem with the next speedtest will be because the docker cant update the unavailible sensors? Because the next run gives me this errors in the portainer logs:

2023-01-13T12:00:00.432943260Z Starting test...
2023-01-13T12:00:00.433122691Z Data { testinprogress: 'true' }
2023-01-13T12:00:00.433134913Z Processing sensor upload undefined speedtest/upload
2023-01-13T12:00:00.433137943Z Processing sensor download undefined speedtest/download
2023-01-13T12:00:00.433146503Z Backend did not provide the following key, skipping: upload
2023-01-13T12:00:00.433266193Z Backend did not provide the following key, skipping: download
2023-01-13T12:00:00.433277635Z Backend did not provide the following key, skipping: ping
2023-01-13T12:00:00.433280840Z Backend did not provide the following key, skipping: jitter
2023-01-13T12:00:00.433283727Z Backend did not provide the following key, skipping: uploadtotal
2023-01-13T12:00:00.433286472Z Backend did not provide the following key, skipping: downloadtotal
2023-01-13T12:00:00.433295778Z Processing sensor ping undefined speedtest/ping
2023-01-13T12:00:00.433299397Z Processing sensor jitter undefined speedtest/jitter
2023-01-13T12:00:00.433302717Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-13T12:00:00.433305563Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-13T12:00:00.433307872Z Processing sensor testinprogress true speedtest/testinprogress
2023-01-13T12:00:00.435875617Z Backend did not provide the following key, skipping: runtest
2023-01-13T12:00:00.435899082Z Processing sensor runtest undefined speedtest/runtest
2023-01-13T12:00:00.435902403Z Processing sensor schedule undefined speedtest/schedule
2023-01-13T12:00:00.435940009Z Finished updating sensors
2023-01-13T12:00:00.435972772Z Backend did not provide the following key, skipping: schedule
2023-01-13T12:00:01.326330385Z Data { testinprogress: 'false' }
2023-01-13T12:00:01.326458451Z Processing sensor upload undefined speedtest/upload
2023-01-13T12:00:01.326553592Z Backend did not provide the following key, skipping: upload
2023-01-13T12:00:01.326638737Z Processing sensor download undefined speedtest/download
2023-01-13T12:00:01.326713169Z Backend did not provide the following key, skipping: download
2023-01-13T12:00:01.326795199Z Processing sensor ping undefined speedtest/ping
2023-01-13T12:00:01.326869562Z Backend did not provide the following key, skipping: ping
2023-01-13T12:00:01.326940206Z Processing sensor jitter undefined speedtest/jitter
2023-01-13T12:00:01.327069229Z Backend did not provide the following key, skipping: jitter
2023-01-13T12:00:01.327152518Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-13T12:00:01.327238873Z Backend did not provide the following key, skipping: uploadtotal
2023-01-13T12:00:01.327321697Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-13T12:00:01.327396501Z Backend did not provide the following key, skipping: downloadtotal
2023-01-13T12:00:01.327465534Z Processing sensor testinprogress false speedtest/testinprogress
2023-01-13T12:00:01.327644205Z Sending data...
2023-01-13T12:00:01.327783028Z Data {
2023-01-13T12:00:01.327788550Z   error: true,
2023-01-13T12:00:01.327791363Z   message: 'Unable to connect to servers to test latency.'
2023-01-13T12:00:01.327793855Z }
2023-01-13T12:00:01.328034620Z Processing sensor upload undefined speedtest/upload
2023-01-13T12:00:01.328102737Z Backend did not provide the following key, skipping: upload
2023-01-13T12:00:01.328192004Z Processing sensor download undefined speedtest/download
2023-01-13T12:00:01.328258431Z Backend did not provide the following key, skipping: download
2023-01-13T12:00:01.328341803Z Processing sensor ping undefined speedtest/ping
2023-01-13T12:00:01.328409430Z Backend did not provide the following key, skipping: ping
2023-01-13T12:00:01.328495713Z Processing sensor jitter undefined speedtest/jitter
2023-01-13T12:00:01.328565991Z Backend did not provide the following key, skipping: jitter
2023-01-13T12:00:01.328649346Z Processing sensor uploadtotal undefined speedtest/uploadtotal
2023-01-13T12:00:01.328728179Z Backend did not provide the following key, skipping: uploadtotal
2023-01-13T12:00:01.328830519Z Processing sensor downloadtotal undefined speedtest/downloadtotal
2023-01-13T12:00:01.328896236Z Backend did not provide the following key, skipping: downloadtotal
2023-01-13T12:00:01.328989304Z Processing sensor testinprogress undefined speedtest/testinprogress
2023-01-13T12:00:01.329056806Z Backend did not provide the following key, skipping: testinprogress
2023-01-13T12:00:01.329155728Z Processing sensor runtest undefined speedtest/runtest
2023-01-13T12:00:01.329238513Z Backend did not provide the following key, skipping: runtest
2023-01-13T12:00:01.329347952Z Processing sensor schedule undefined speedtest/schedule
2023-01-13T12:00:01.329431814Z Backend did not provide the following key, skipping: schedule
2023-01-13T12:00:01.329524160Z Finished updating sensors
2023-01-13T12:00:01.329615523Z Processing sensor runtest undefined speedtest/runtest
2023-01-13T12:00:01.329709433Z Backend did not provide the following key, skipping: runtest
2023-01-13T12:00:01.329796531Z Processing sensor schedule undefined speedtest/schedule
2023-01-13T12:00:01.329887545Z Backend did not provide the following key, skipping: schedule
2023-01-13T12:00:01.329969208Z Finished updating sensors

Maybe there is someting else i need to do to make it work? I can and have been able to run speedtest without any interuptions for years , and to me my problem seems to be the unavailible sensors.

I have removed all yaml code i had setup for speedtest2mqtt prior to testing out your docker. And all of the mqtt topics was removed.

stonegray commented 1 year ago

Thanks for the detailed report. This looks like a bug. Will look into it this weekend.

pyrech commented 1 year ago

Hello @stonegray. Thanks a lot for your work on this project. Unfortunately I didn't get it working as each run result in the same error posted above, aka Backend did not provide the following key, skipping xxx. Did you have time to find the bug since? Thanks 🙂

stonegray commented 1 year ago

Fixed in latest update.

pyrech commented 1 year ago

Simply awesome. Thanks 🙌