SignalK / freeboard-sk

Chartplotter implementation for Signal K servers
Apache License 2.0
35 stars 27 forks source link

Weather watch timer error! #157

Closed Haimana closed 2 months ago

Haimana commented 3 months ago

Hello,

Latest version installed (2.8.2), and also noticed in previous version, I have this error in dashboard.

image

It appear 1 min after first poll - let's say 15 min after SK restart, if poll interval is set at 15 min.

Log for first poll:

Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Weather: wake from sleep....poll provider. Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Wake timer watchdog -> OK Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Weather: Polling provider. Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Vessel position: {"longitude":28.584616666666665,"latitude":43.808033333333334}. Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Weather: Calling service API.....(attempt: 1) Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Position: {"longitude":28.584616666666665,"latitude":43.808033333333334} Jun 02 10:11:34 2024-06-02T07:11:34.383Z @signalk/freeboard-sk Weather: polling weather provider. Jun 02 10:11:35 2024-06-02T07:11:35.036Z @signalk/freeboard-sk Weather: data received.... Jun 02 10:11:35 2024-06-02T07:11:35.037Z @signalk/freeboard-sk METEO - emit deltas* Jun 02 10:11:35 2024-06-02T07:11:35.037Z @signalk/freeboard-sk METEO * Jun 02 10:11:35 2024-06-02T07:11:35.037Z @signalk/freeboard-sk ** METEO OBS ***

And 1 minute after first poll:

Jun 02 10:12:34 2024-06-02T07:12:34.383Z @signalk/freeboard-sk Weather: wake from sleep....poll provider. Jun 02 10:12:34 2024-06-02T07:12:34.383Z @signalk/freeboard-sk Wake timer watchdog -> OK Jun 02 10:12:34 2024-06-02T07:12:34.383Z @signalk/freeboard-sk Weather: Polling provider. Jun 02 10:12:34 2024-06-02T07:12:34.384Z @signalk/freeboard-sk Vessel position: {"longitude":28.584600000000002,"latitude":43.80805}. Jun 02 10:12:34 2024-06-02T07:12:34.384Z @signalk/freeboard-sk Weather: Next poll due in 14 min(s)... sleep for 60 secs... Jun 02 10:12:35 2024-06-02T07:12:35.037Z @signalk/freeboard-sk Weather: wake from sleep....poll provider. > Jun 02 10:12:35 2024-06-02T07:12:35.037Z @signalk/freeboard-sk Wake timer watchdog -> NOT OK... Stopping wake timer! Jun 02 10:12:35 2024-06-02T07:12:35.037Z @signalk/freeboard-sk Watch interval < 50 secs. (0.653 secs) Jun 02 10:12:35 2024-06-02T07:12:35.038Z @signalk/freeboard-sk Vessel position: {"longitude":28.584600000000002,"latitude":43.80805}. Jun 02 10:12:35 2024-06-02T07:12:35.038Z @signalk/freeboard-sk *** Weather: Next poll due in 14 min(s)... sleep for 60 secs...

The weather forecast is working well in freeboard-sk even after this error.

Best regards, Seb

panaaj commented 3 months ago

The message should only appear when the timer is polling more frequently than required (this is to protect against a runaway timer and limit any cost impact of exceeding API free thresholds).

From the log it appears that the timer is working correctly (log entries are time stamped 1 minute apart).

Can you please confirm this is the case, if so then it is just a fix to the logic displaying the message.

Haimana commented 3 months ago

Yes indeed, timer is working as you said, every 1 minute.

panaaj commented 3 months ago

Jun 02 10:12:35 2024-06-02T07:12:35.037Z @signalk/freeboard-sk Watch interval < 50 secs. (0.653 secs)

This line in the log indicates why the error is showing. The 60 sec timer was triggered 1/2 a second after the previous trigger.

I have tried reproducing it on my Pi devices with the current version of server with no success.

When this has occurred in the past (on a Pi) it required a reboot (even if running in Docker) to have the timer trigger at the correct interval.