[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

Yes, everything has been working fine since the changes.  No, there isn't 
anything else talking to the WLL, except that the WLL posts to the Davis 
WLL website - but those are all outbound.  Since I changed the check on the 
counter from 1 to 2 I have seen none of those warning messages.

I wait to install your new code once it arrives until week after next, as I 
will be out of town, and I know what I have now is stable - so, no rush.

THANKS!

JRJ

On Friday, June 18, 2021 at 9:38:16 AM UTC-5 michael.s...@gmail.com wrote:

> OK, I've just taken a look into the 5 minutes thing. Forget my point from 
> above, the 5 minutes correspond to the 300 second archive interval.
> I was able to confirm this by changing the interval.
>
> Michael Schantl schrieb am Freitag, 18. Juni 2021 um 15:41:57 UTC+2:
>
>> OK, will push a new release shortly with the change you suggested.
>> Did everything work in the last few days?
>>
>> On the topic of the regular messages, is there any other device or 
>> process talking to the WLL. I've noticed that the WLL's HTTP server can act 
>> weird when there are too many connections in too quick succession.
>>
>> - Michael
>>
>>
>> cub...@gmail.com schrieb am Dienstag, 15. Juni 2021 um 23:42:40 UTC+2:
>>
>>> FYI, now that I am monitoring for the WARNING messages, I am seeing them 
>>> like clockwork every 5 minutes - in the SAME SECOND for which I see weewx 
>>> "Added record" messages.  Doubt it is a coincidence - correlation is nearly 
>>> 99% (once in a while there is no WARNING.  Suggest only issuing the warning 
>>> if >= 2 misses.
>>>
>>> JRJ
>>>
>>> On Saturday, June 12, 2021 at 1:50:39 PM UTC-5 michael.s...@gmail.com 
>>> wrote:
>>>
 Hi JRJ,
 thank you for the extensive debugging.
 I've just pushed a new dev release 
 
 .

 Yeah, you're right with the missing timeout. I had assumed the requests 
 library honors the socket timeout configured globally, but apparently not. 
 The standard WeeWX timeout option is now also used for the HTTP requests.
 Additionally, for good measures, I've also added a watchdog for when no 
 packets are received. It has an option to configure the iterations allowed 
 without data. See the changelog for details.

 - Michael

 cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:

> I noticed that there is no timeout keyword on the request call 
> davis_http.request_current.  I will add one to see if it helps.  (I also 
> note that there is no timeout on the call in start_broadcast either.
>
> JRJ
>
> On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:
>
>> I just noticed that the call to _poll_callback()  [to 
>> WllPollHost.poll] is indeed apparently not returning - noticed in the 
>> above 
>> logs that there is NO message "Polled current conditions".  Working 
>> theory: 
>> if it receives a UDP (broadcast) packet while it is doing the HTTP poll 
>> request, the driver gets confused.
>>
>> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>>
>>>
>>> Happened again while I was looking at logs.  Just for grins, I fired 
>>> off an HTTP request from my PC, and it woke back up.
>>>
>>> So:  for some reason the WLL driver scheduler _do_tick method call 
>>> to _poll_callback() never returns, so that _do_tick never returns to 
>>> _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
>>> some reason it is calling _do_tick() before scheduling the next tick by 
>>> calling enterabs?  (And no, there is no exception being caught, as far 
>>> as I 
>>> can tell.)
>>>
>>> Adding a log.debug call after the _poll_callback() call - but I have 
>>> no doubt that under these conditions it will not be triggered.
>>>
>>> On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:
>>>
 Here are some more datapoints from the log that confirm that the 
 needed HTTP request to the WLL box is not occurring:

 Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: 13scheduler ticks until next push 
 refresh
 Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
 03:37:11 
 Z
 Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Scheduler tick
 Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Notifying poll callback
 Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: 12scheduler ticks until next push 
 refresh
 Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Next scheduler 

[weewx-user] Re: weewx stopped for no apparent reason

[Michael Schantl]

OK, I've just taken a look into the 5 minutes thing. Forget my point from 
above, the 5 minutes correspond to the 300 second archive interval.
I was able to confirm this by changing the interval.

Michael Schantl schrieb am Freitag, 18. Juni 2021 um 15:41:57 UTC+2:

> OK, will push a new release shortly with the change you suggested.
> Did everything work in the last few days?
>
> On the topic of the regular messages, is there any other device or process 
> talking to the WLL. I've noticed that the WLL's HTTP server can act weird 
> when there are too many connections in too quick succession.
>
> - Michael
>
>
> cub...@gmail.com schrieb am Dienstag, 15. Juni 2021 um 23:42:40 UTC+2:
>
>> FYI, now that I am monitoring for the WARNING messages, I am seeing them 
>> like clockwork every 5 minutes - in the SAME SECOND for which I see weewx 
>> "Added record" messages.  Doubt it is a coincidence - correlation is nearly 
>> 99% (once in a while there is no WARNING.  Suggest only issuing the warning 
>> if >= 2 misses.
>>
>> JRJ
>>
>> On Saturday, June 12, 2021 at 1:50:39 PM UTC-5 michael.s...@gmail.com 
>> wrote:
>>
>>> Hi JRJ,
>>> thank you for the extensive debugging.
>>> I've just pushed a new dev release 
>>> 
>>> .
>>>
>>> Yeah, you're right with the missing timeout. I had assumed the requests 
>>> library honors the socket timeout configured globally, but apparently not. 
>>> The standard WeeWX timeout option is now also used for the HTTP requests.
>>> Additionally, for good measures, I've also added a watchdog for when no 
>>> packets are received. It has an option to configure the iterations allowed 
>>> without data. See the changelog for details.
>>>
>>> - Michael
>>>
>>> cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:
>>>
 I noticed that there is no timeout keyword on the request call 
 davis_http.request_current.  I will add one to see if it helps.  (I also 
 note that there is no timeout on the call in start_broadcast either.

 JRJ

 On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:

> I just noticed that the call to _poll_callback()  [to 
> WllPollHost.poll] is indeed apparently not returning - noticed in the 
> above 
> logs that there is NO message "Polled current conditions".  Working 
> theory: 
> if it receives a UDP (broadcast) packet while it is doing the HTTP poll 
> request, the driver gets confused.
>
> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>
>>
>> Happened again while I was looking at logs.  Just for grins, I fired 
>> off an HTTP request from my PC, and it woke back up.
>>
>> So:  for some reason the WLL driver scheduler _do_tick method call to 
>> _poll_callback() never returns, so that _do_tick never returns to 
>> _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
>> some reason it is calling _do_tick() before scheduling the next tick by 
>> calling enterabs?  (And no, there is no exception being caught, as far 
>> as I 
>> can tell.)
>>
>> Adding a log.debug call after the _poll_callback() call - but I have 
>> no doubt that under these conditions it will not be triggered.
>>
>> On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:
>>
>>> Here are some more datapoints from the log that confirm that the 
>>> needed HTTP request to the WLL box is not occurring:
>>>
>>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 13scheduler ticks until next push 
>>> refresh
>>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
>>> 03:37:11 
>>> Z
>>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Scheduler tick
>>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Notifying poll callback
>>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 12scheduler ticks until next push 
>>> refresh
>>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
>>> 03:37:22 
>>> Z
>>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Scheduler tick
>>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Notifying poll callback
>>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 11scheduler ticks until next push 
>>> refresh
>>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
>>> 03:37:33 
>>> Z
>>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 

[weewx-user] Re: weewx stopped for no apparent reason

[Michael Schantl]

OK, will push a new release shortly with the change you suggested.
Did everything work in the last few days?

On the topic of the regular messages, is there any other device or process 
talking to the WLL. I've noticed that the WLL's HTTP server can act weird 
when there are too many connections in too quick succession.

- Michael


cub...@gmail.com schrieb am Dienstag, 15. Juni 2021 um 23:42:40 UTC+2:

> FYI, now that I am monitoring for the WARNING messages, I am seeing them 
> like clockwork every 5 minutes - in the SAME SECOND for which I see weewx 
> "Added record" messages.  Doubt it is a coincidence - correlation is nearly 
> 99% (once in a while there is no WARNING.  Suggest only issuing the warning 
> if >= 2 misses.
>
> JRJ
>
> On Saturday, June 12, 2021 at 1:50:39 PM UTC-5 michael.s...@gmail.com 
> wrote:
>
>> Hi JRJ,
>> thank you for the extensive debugging.
>> I've just pushed a new dev release 
>> 
>> .
>>
>> Yeah, you're right with the missing timeout. I had assumed the requests 
>> library honors the socket timeout configured globally, but apparently not. 
>> The standard WeeWX timeout option is now also used for the HTTP requests.
>> Additionally, for good measures, I've also added a watchdog for when no 
>> packets are received. It has an option to configure the iterations allowed 
>> without data. See the changelog for details.
>>
>> - Michael
>>
>> cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:
>>
>>> I noticed that there is no timeout keyword on the request call 
>>> davis_http.request_current.  I will add one to see if it helps.  (I also 
>>> note that there is no timeout on the call in start_broadcast either.
>>>
>>> JRJ
>>>
>>> On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:
>>>
 I just noticed that the call to _poll_callback()  [to WllPollHost.poll] 
 is indeed apparently not returning - noticed in the above logs that there 
 is NO message "Polled current conditions".  Working theory: if it receives 
 a UDP (broadcast) packet while it is doing the HTTP poll request, the 
 driver gets confused.

 On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:

>
> Happened again while I was looking at logs.  Just for grins, I fired 
> off an HTTP request from my PC, and it woke back up.
>
> So:  for some reason the WLL driver scheduler _do_tick method call to 
> _poll_callback() never returns, so that _do_tick never returns to 
> _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
> some reason it is calling _do_tick() before scheduling the next tick by 
> calling enterabs?  (And no, there is no exception being caught, as far as 
> I 
> can tell.)
>
> Adding a log.debug call after the _poll_callback() call - but I have 
> no doubt that under these conditions it will not be triggered.
>
> On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:
>
>> Here are some more datapoints from the log that confirm that the 
>> needed HTTP request to the WLL box is not occurring:
>>
>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 13scheduler ticks until next push 
>> refresh
>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
>> 03:37:11 
>> Z
>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 12scheduler ticks until next push 
>> refresh
>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
>> 03:37:22 
>> Z
>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 11scheduler ticks until next push 
>> refresh
>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
>> 03:37:33 
>> Z
>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 10scheduler ticks until next push 
>> refresh
>> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
>> 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

FYI, now that I am monitoring for the WARNING messages, I am seeing them 
like clockwork every 5 minutes - in the SAME SECOND for which I see weewx 
"Added record" messages.  Doubt it is a coincidence - correlation is nearly 
99% (once in a while there is no WARNING.  Suggest only issuing the warning 
if >= 2 misses.

JRJ

On Saturday, June 12, 2021 at 1:50:39 PM UTC-5 michael.s...@gmail.com wrote:

> Hi JRJ,
> thank you for the extensive debugging.
> I've just pushed a new dev release 
> 
> .
>
> Yeah, you're right with the missing timeout. I had assumed the requests 
> library honors the socket timeout configured globally, but apparently not. 
> The standard WeeWX timeout option is now also used for the HTTP requests.
> Additionally, for good measures, I've also added a watchdog for when no 
> packets are received. It has an option to configure the iterations allowed 
> without data. See the changelog for details.
>
> - Michael
>
> cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:
>
>> I noticed that there is no timeout keyword on the request call 
>> davis_http.request_current.  I will add one to see if it helps.  (I also 
>> note that there is no timeout on the call in start_broadcast either.
>>
>> JRJ
>>
>> On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:
>>
>>> I just noticed that the call to _poll_callback()  [to WllPollHost.poll] 
>>> is indeed apparently not returning - noticed in the above logs that there 
>>> is NO message "Polled current conditions".  Working theory: if it receives 
>>> a UDP (broadcast) packet while it is doing the HTTP poll request, the 
>>> driver gets confused.
>>>
>>> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>>>

 Happened again while I was looking at logs.  Just for grins, I fired 
 off an HTTP request from my PC, and it woke back up.

 So:  for some reason the WLL driver scheduler _do_tick method call to 
 _poll_callback() never returns, so that _do_tick never returns to 
 _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
 some reason it is calling _do_tick() before scheduling the next tick by 
 calling enterabs?  (And no, there is no exception being caught, as far as 
 I 
 can tell.)

 Adding a log.debug call after the _poll_callback() call - but I have no 
 doubt that under these conditions it will not be triggered.

 On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:

> Here are some more datapoints from the log that confirm that the 
> needed HTTP request to the WLL box is not occurring:
>
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:11 
> Z
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:22 
> Z
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:33 
> Z
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:44 
> Z
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
>
> *** That was the last log message including scheduler
>
> After that we see (excluding most of the .mappers log entries)
>
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
> Starting new HTTP connection (1): 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

FYI, just had my first case under the new code - worked fine.

Suggestion:  The message logged is the same for both start_broadcast and 
request_current - spotted that when I saw the message and I couldn't tell 
which had failed without looking at the debug log to see the DEBUG entry - 
and even at that I am not 100% certain - if they overlapped?

Here is what got logged (sans the "mapper" entries)

*Jun 15 08:44:10 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-15 13:44:20 
Z*
*Jun 15 13:44:20 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.scheduler: Scheduler tick*
*Jun 15 13:44:20 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.scheduler: Notifying poll callback*
*Jun 15 13:44:20 mythtv2 weewx[297697] DEBUG urllib3.connectionpool: 
Starting new HTTP connection (1): vantagevieww.lan:80*
*Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG urllib3.connectionpool: 
http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None*
Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.davis_broadcast: Received 395 bytes from 
('192.168.42.75', 25447)
Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
*Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet*
Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 8.0, 
'windGustDir': 77}
Jun 15 13:44:21 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 15 13:44:24 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.davis_broadcast: Received 395 bytes from 
('192.168.42.75', 25447)
Jun 15 13:44:24 mythtv2 weewx[297697] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
*Jun 15 13:44:24 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet*
Jun 15 13:44:24 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 15 13:44:24 mythtv2 weewx[297697] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 8.0, 
'windGustDir': 77}
Jun 15 13:44:24 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Waiting 
for new packet
*Jun 15 13:44:29 mythtv2 weewx[297697] WARNING user.weatherlink_live: No 
data since 1 iterations*
Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.davis_broadcast: Received 395 bytes from 
('192.168.42.75', 25447)
Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
*Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet*
Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 8.0, 
'windGustDir': 77}
Jun 15 13:44:29 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 15 08:44:21 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-15 13:44:31 
Z
Jun 15 13:44:31 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.davis_broadcast: Received 395 bytes from 
('192.168.42.75', 25447)
Jun 15 13:44:31 mythtv2 weewx[297697] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
*Jun 15 13:44:31 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet*
Jun 15 13:44:31 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 15 13:44:31 mythtv2 weewx[297697] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 8.0, 
'windGustDir': 77}
Jun 15 13:44:31 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 15 13:44:34 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.davis_broadcast: Received 395 bytes from 
('192.168.42.75', 25447)
Jun 15 13:44:34 mythtv2 weewx[297697] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
*Jun 15 13:44:34 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet*
Jun 15 13:44:34 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 15 13:44:34 mythtv2 weewx[297697] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 8.0, 
'windGustDir': 77}
Jun 15 13:44:34 mythtv2 weewx[297697] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 15 13:44:36 mythtv2 weewx[297697] DEBUG 
user.weatherlink_live.davis_broadcast: Received 395 bytes from 
('192.168.42.75', 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

FYI, I did have an instance of the issue late yesterday, and the patch I 
put did allow it to recover.   I just installed the dev release snapshot 
and will keep you posted if/when I see the recoveries.  THANKS!

JRJ

On Saturday, June 12, 2021 at 1:50:39 PM UTC-5 michael.s...@gmail.com wrote:

> Hi JRJ,
> thank you for the extensive debugging.
> I've just pushed a new dev release 
> 
> .
>
> Yeah, you're right with the missing timeout. I had assumed the requests 
> library honors the socket timeout configured globally, but apparently not. 
> The standard WeeWX timeout option is now also used for the HTTP requests.
> Additionally, for good measures, I've also added a watchdog for when no 
> packets are received. It has an option to configure the iterations allowed 
> without data. See the changelog for details.
>
> - Michael
>
> cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:
>
>> I noticed that there is no timeout keyword on the request call 
>> davis_http.request_current.  I will add one to see if it helps.  (I also 
>> note that there is no timeout on the call in start_broadcast either.
>>
>> JRJ
>>
>> On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:
>>
>>> I just noticed that the call to _poll_callback()  [to WllPollHost.poll] 
>>> is indeed apparently not returning - noticed in the above logs that there 
>>> is NO message "Polled current conditions".  Working theory: if it receives 
>>> a UDP (broadcast) packet while it is doing the HTTP poll request, the 
>>> driver gets confused.
>>>
>>> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>>>

 Happened again while I was looking at logs.  Just for grins, I fired 
 off an HTTP request from my PC, and it woke back up.

 So:  for some reason the WLL driver scheduler _do_tick method call to 
 _poll_callback() never returns, so that _do_tick never returns to 
 _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
 some reason it is calling _do_tick() before scheduling the next tick by 
 calling enterabs?  (And no, there is no exception being caught, as far as 
 I 
 can tell.)

 Adding a log.debug call after the _poll_callback() call - but I have no 
 doubt that under these conditions it will not be triggered.

 On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:

> Here are some more datapoints from the log that confirm that the 
> needed HTTP request to the WLL box is not occurring:
>
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:11 
> Z
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:22 
> Z
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:33 
> Z
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:44 
> Z
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
>
> *** That was the last log message including scheduler
>
> After that we see (excluding most of the .mappers log entries)
>
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
> Starting new HTTP connection (1): vantagevieww.lan:80
> Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
> 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

FYI, since I made the change (using my own code, and only on the 
WllPollHost related call, it has stayed up.  HOWEVER, it also has not 
issued any error message, and it has not yet been, say, 3 days, so that 
might be a coincidence.  After, say, Tuesday, I'll give your new dev 
release a whirl (or sooner if the one that is running now locks up.)

(I have no idea if the request class honors any global timeout default, or 
not - no clue there.)

You are more than welcome - I actually enjoy debugging.  ;)

JRJ

On Saturday, June 12, 2021 at 1:50:39 PM UTC-5 michael.s...@gmail.com wrote:

> Hi JRJ,
> thank you for the extensive debugging.
> I've just pushed a new dev release 
> 
> .
>
> Yeah, you're right with the missing timeout. I had assumed the requests 
> library honors the socket timeout configured globally, but apparently not. 
> The standard WeeWX timeout option is now also used for the HTTP requests.
> Additionally, for good measures, I've also added a watchdog for when no 
> packets are received. It has an option to configure the iterations allowed 
> without data. See the changelog for details.
>
> - Michael
>
> cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:
>
>> I noticed that there is no timeout keyword on the request call 
>> davis_http.request_current.  I will add one to see if it helps.  (I also 
>> note that there is no timeout on the call in start_broadcast either.
>>
>> JRJ
>>
>> On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:
>>
>>> I just noticed that the call to _poll_callback()  [to WllPollHost.poll] 
>>> is indeed apparently not returning - noticed in the above logs that there 
>>> is NO message "Polled current conditions".  Working theory: if it receives 
>>> a UDP (broadcast) packet while it is doing the HTTP poll request, the 
>>> driver gets confused.
>>>
>>> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>>>

 Happened again while I was looking at logs.  Just for grins, I fired 
 off an HTTP request from my PC, and it woke back up.

 So:  for some reason the WLL driver scheduler _do_tick method call to 
 _poll_callback() never returns, so that _do_tick never returns to 
 _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
 some reason it is calling _do_tick() before scheduling the next tick by 
 calling enterabs?  (And no, there is no exception being caught, as far as 
 I 
 can tell.)

 Adding a log.debug call after the _poll_callback() call - but I have no 
 doubt that under these conditions it will not be triggered.

 On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:

> Here are some more datapoints from the log that confirm that the 
> needed HTTP request to the WLL box is not occurring:
>
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:11 
> Z
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:22 
> Z
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:33 
> Z
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
> 03:37:44 
> Z
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
>
> *** That was the last log message including scheduler
>

[weewx-user] Re: weewx stopped for no apparent reason

[Michael Schantl]

Hi JRJ,
thank you for the extensive debugging.
I've just pushed a new dev release 

.

Yeah, you're right with the missing timeout. I had assumed the requests 
library honors the socket timeout configured globally, but apparently not. 
The standard WeeWX timeout option is now also used for the HTTP requests.
Additionally, for good measures, I've also added a watchdog for when no 
packets are received. It has an option to configure the iterations allowed 
without data. See the changelog for details.

- Michael

cub...@gmail.com schrieb am Freitag, 11. Juni 2021 um 18:13:15 UTC+2:

> I noticed that there is no timeout keyword on the request call 
> davis_http.request_current.  I will add one to see if it helps.  (I also 
> note that there is no timeout on the call in start_broadcast either.
>
> JRJ
>
> On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:
>
>> I just noticed that the call to _poll_callback()  [to WllPollHost.poll] 
>> is indeed apparently not returning - noticed in the above logs that there 
>> is NO message "Polled current conditions".  Working theory: if it receives 
>> a UDP (broadcast) packet while it is doing the HTTP poll request, the 
>> driver gets confused.
>>
>> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>>
>>>
>>> Happened again while I was looking at logs.  Just for grins, I fired off 
>>> an HTTP request from my PC, and it woke back up.
>>>
>>> So:  for some reason the WLL driver scheduler _do_tick method call to 
>>> _poll_callback() never returns, so that _do_tick never returns to 
>>> _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
>>> some reason it is calling _do_tick() before scheduling the next tick by 
>>> calling enterabs?  (And no, there is no exception being caught, as far as I 
>>> can tell.)
>>>
>>> Adding a log.debug call after the _poll_callback() call - but I have no 
>>> doubt that under these conditions it will not be triggered.
>>>
>>> On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:
>>>
 Here are some more datapoints from the log that confirm that the needed 
 HTTP request to the WLL box is not occurring:

 Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
 Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
 03:37:11 
 Z
 Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Scheduler tick
 Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Notifying poll callback
 Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
 Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
 03:37:22 
 Z
 Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Scheduler tick
 Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Notifying poll callback
 Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
 Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
 03:37:33 
 Z
 Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Scheduler tick
 Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Notifying poll callback
 Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
 Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 
 03:37:44 
 Z
 Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Scheduler tick
 Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.scheduler: Notifying poll callback

 *** That was the last log message including scheduler

 After that we see (excluding most of the .mappers log entries)

 Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
 Starting new HTTP connection (1): vantagevieww.lan:80
 Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
 http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 
 None
 Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.davis_broadcast: Received 394 bytes from 
 ('192.168.42.75', 25447)
 Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
 user.weatherlink_live.packets: Trying to create UDP conditions packet
 Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

I noticed that there is no timeout keyword on the request call 
davis_http.request_current.  I will add one to see if it helps.  (I also 
note that there is no timeout on the call in start_broadcast either.

JRJ

On Friday, June 11, 2021 at 10:58:48 AM UTC-5 Jay Jaeger wrote:

> I just noticed that the call to _poll_callback()  [to WllPollHost.poll] is 
> indeed apparently not returning - noticed in the above logs that there is 
> NO message "Polled current conditions".  Working theory: if it receives a 
> UDP (broadcast) packet while it is doing the HTTP poll request, the driver 
> gets confused.
>
> On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:
>
>>
>> Happened again while I was looking at logs.  Just for grins, I fired off 
>> an HTTP request from my PC, and it woke back up.
>>
>> So:  for some reason the WLL driver scheduler _do_tick method call to 
>> _poll_callback() never returns, so that _do_tick never returns to 
>> _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
>> some reason it is calling _do_tick() before scheduling the next tick by 
>> calling enterabs?  (And no, there is no exception being caught, as far as I 
>> can tell.)
>>
>> Adding a log.debug call after the _poll_callback() call - but I have no 
>> doubt that under these conditions it will not be triggered.
>>
>> On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:
>>
>>> Here are some more datapoints from the log that confirm that the needed 
>>> HTTP request to the WLL box is not occurring:
>>>
>>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
>>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:11 
>>> Z
>>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Scheduler tick
>>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Notifying poll callback
>>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
>>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:22 
>>> Z
>>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Scheduler tick
>>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Notifying poll callback
>>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
>>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:33 
>>> Z
>>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Scheduler tick
>>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Notifying poll callback
>>> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
>>> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:44 
>>> Z
>>> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Scheduler tick
>>> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.scheduler: Notifying poll callback
>>>
>>> *** That was the last log message including scheduler
>>>
>>> After that we see (excluding most of the .mappers log entries)
>>>
>>> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
>>> Starting new HTTP connection (1): vantagevieww.lan:80
>>> Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
>>> http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 
>>> None
>>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
>>> ('192.168.42.75', 25447)
>>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.packets: Trying to create UDP conditions packet
>>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.data_host: Received new broadcast packet
>>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
>>> Emitting push (broadcast) packet
>>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.service: WllWindGustService: Updating record with 
>>> dict: {'windGust': 0.75, 'windGustDir': 114}
>>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
>>> Waiting for new packet
>>> << SNIP >>
>>> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
>>> ('192.168.42.75', 25447)
>>> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
>>> user.weatherlink_live.packets: Trying to create UDP conditions packet
>>> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
>>> 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

I just noticed that the call to _poll_callback()  [to WllPollHost.poll] is 
indeed apparently not returning - noticed in the above logs that there is 
NO message "Polled current conditions".  Working theory: if it receives a 
UDP (broadcast) packet while it is doing the HTTP poll request, the driver 
gets confused.

On Friday, June 11, 2021 at 10:35:39 AM UTC-5 Jay Jaeger wrote:

>
> Happened again while I was looking at logs.  Just for grins, I fired off 
> an HTTP request from my PC, and it woke back up.
>
> So:  for some reason the WLL driver scheduler _do_tick method call to 
> _poll_callback() never returns, so that _do_tick never returns to 
> _scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
> some reason it is calling _do_tick() before scheduling the next tick by 
> calling enterabs?  (And no, there is no exception being caught, as far as I 
> can tell.)
>
> Adding a log.debug call after the _poll_callback() call - but I have no 
> doubt that under these conditions it will not be triggered.
>
> On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:
>
>> Here are some more datapoints from the log that confirm that the needed 
>> HTTP request to the WLL box is not occurring:
>>
>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
>> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:11 
>> Z
>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
>> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:22 
>> Z
>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
>> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:33 
>> Z
>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
>> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:44 
>> Z
>> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Scheduler tick
>> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.scheduler: Notifying poll callback
>>
>> *** That was the last log message including scheduler
>>
>> After that we see (excluding most of the .mappers log entries)
>>
>> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
>> Starting new HTTP connection (1): vantagevieww.lan:80
>> Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
>> http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None
>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
>> ('192.168.42.75', 25447)
>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.packets: Trying to create UDP conditions packet
>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.data_host: Received new broadcast packet
>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
>> Emitting push (broadcast) packet
>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.service: WllWindGustService: Updating record with 
>> dict: {'windGust': 0.75, 'windGustDir': 114}
>> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
>> Waiting for new packet
>> << SNIP >>
>> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
>> ('192.168.42.75', 25447)
>> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.packets: Trying to create UDP conditions packet
>> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.data_host: Received new broadcast packet
>> << snip >>
>> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
>> Emitting push (broadcast) packet
>> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG 
>> user.weatherlink_live.service: WllWindGustService: New wind vector 0.00:0 
>> larger than 0.00:0
>> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG 
>> 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

Happened again while I was looking at logs.  Just for grins, I fired off an 
HTTP request from my PC, and it woke back up.

So:  for some reason the WLL driver scheduler _do_tick method call to 
_poll_callback() never returns, so that _do_tick never returns to 
_scheduler_tick and thus it goes off to sleepy-land.   QUERY:  Is there 
some reason it is calling _do_tick() before scheduling the next tick by 
calling enterabs?  (And no, there is no exception being caught, as far as I 
can tell.)

Adding a log.debug call after the _poll_callback() call - but I have no 
doubt that under these conditions it will not be triggered.

On Friday, June 11, 2021 at 10:06:10 AM UTC-5 Jay Jaeger wrote:

> Here are some more datapoints from the log that confirm that the needed 
> HTTP request to the WLL box is not occurring:
>
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
> Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:11 
> Z
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
> Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:22 
> Z
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
> Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:33 
> Z
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
> Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:44 
> Z
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Scheduler tick
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.scheduler: Notifying poll callback
>
> *** That was the last log message including scheduler
>
> After that we see (excluding most of the .mappers log entries)
>
> Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
> Starting new HTTP connection (1): vantagevieww.lan:80
> Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
> http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None
> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
> ('192.168.42.75', 25447)
> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
> Trying to create UDP conditions packet
> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.data_host: Received new broadcast packet
> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
> Emitting push (broadcast) packet
> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
> WllWindGustService: Updating record with dict: {'windGust': 0.75, 
> 'windGustDir': 114}
> Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Waiting 
> for new packet
> << SNIP >>
> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
> ('192.168.42.75', 25447)
> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
> Trying to create UDP conditions packet
> Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.data_host: Received new broadcast packet
> << snip >>
> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live: 
> Emitting push (broadcast) packet
> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
> WllWindGustService: New wind vector 0.00:0 larger than 0.00:0
> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
> WllWindGustService: Updating record with dict: {'windGust': 0.0, 
> 'windGustDir': 0}
> Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Waiting 
> for new packet
> Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG 
> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
> ('192.168.42.75', 25447)
> Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
> Trying to create UDP conditions packet
> Jun 10 22:42:28 mythtv2 weewx[239040] 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

Here are some more datapoints from the log that confirm that the needed 
HTTP request to the WLL box is not occurring:

Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: 13scheduler ticks until next push refresh
Jun 10 22:37:01 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:11 
Z
Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Scheduler tick
Jun 10 22:37:11 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Notifying poll callback
Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: 12scheduler ticks until next push refresh
Jun 10 22:37:12 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:22 
Z
Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Scheduler tick
Jun 10 22:37:22 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Notifying poll callback
Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: 11scheduler ticks until next push refresh
Jun 10 22:37:23 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:33 
Z
Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Scheduler tick
Jun 10 22:37:33 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Notifying poll callback
Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: 10scheduler ticks until next push refresh
Jun 10 22:37:34 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Next scheduler tick at 2021-06-11 03:37:44 
Z
Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Scheduler tick
Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.scheduler: Notifying poll callback

*** That was the last log message including scheduler

After that we see (excluding most of the .mappers log entries)

Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
Starting new HTTP connection (1): vantagevieww.lan:80
Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.davis_broadcast: Received 394 bytes from 
('192.168.42.75', 25447)
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 0.75, 
'windGustDir': 114}
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Waiting 
for new packet
<< SNIP >>
Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.davis_broadcast: Received 394 bytes from 
('192.168.42.75', 25447)
Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
Jun 10 22:38:00 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet
<< snip >>
Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
WllWindGustService: New wind vector 0.00:0 larger than 0.00:0
Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 0.0, 
'windGustDir': 0}
Jun 10 22:42:25 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.davis_broadcast: Received 394 bytes from 
('192.168.42.75', 25447)
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.mappers: 
THMapping[['1']]: Observation not found in packet
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.mappers: 
THIndoorMapping[[]]: Observation not found in packet
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.mappers: 
BaroMapping[[]]: Observation not found in packet
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.mappers: 
RainMapping[['1']]: Mapped: rainSize=0.01
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.mappers: 
RainMapping[['1']]: Mapped: rainCountRate=0
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG user.weatherlink_live.mappers: 
RainMapping[['1']]: Mapped: rainRate=0.0
Jun 10 22:42:28 mythtv2 weewx[239040] DEBUG 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

This time it lasted only a couple of hours before 

Jun 10 22:37:44 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
Starting new HTTP connection (1): vantagevieww.lan:80 [Last HTTP request]
Jun 10 22:37:45 mythtv2 weewx[239040] DEBUG urllib3.connectionpool: 
http://vantagevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.davis_broadcast: Received 394 bytes from 
('192.168.42.75', 25447)
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
Jun 10 22:37:46 mythtv2 weewx[239040] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet
...
Jun 10 22:42:30 mythtv2 weewx[239040] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 0.0, 
'windGustDir': 0}
Jun 10 22:42:30 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 10 22:42:50 mythtv2 weewx[239040] message repeated 4 times: [ DEBUG 
user.weatherlink_live: Waiting for new packet]
Jun 10 22:42:55 mythtv2 weewx[239040] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 10 22:43:50 mythtv2 weewx[239040] message repeated 11 times: [ DEBUG 
user.weatherlink_live: Waiting for new packet]

JRJ

On Thursday, June 10, 2021 at 8:26:15 PM UTC-5 Jay Jaeger wrote:

> So, it happened again.  Here is how the events seem to have unfolded, 
> based on the logs:
>
> *** The last HTTP request seems to have gone out at 16:26 (so, before data 
> stopped flowing) - there were no more HTTP requests after that - it was the 
> last appearnce of http or HTTP from the weewx process in the logs:
>
> Jun 10 16:26:12 mythtv2 weewx[206240] DEBUG urllib3.connectionpool: 
> http://vanta
> gevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None
>
> *** The last every-5-minute record update was at 16:40 CDT Today:
> Jun 10 16:40:16 mythtv2 weewx[206240] INFO weewx.manager: Added record 
> 2021-06-10 16:40:00 CDT (1623361200) to daily summary in 'weewx'
>
> *** UDP packets continued until 16:43, after which they stopped 
> (presumably because the WLL box was in need of an HTTP "tickle"_
>
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG 
> user.weatherlink_live.davis_broadcast: Received 394 bytes from 
> ('192.168.42.75', 25447)
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.packets: 
> Trying to create UDP conditions packet
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG 
> user.weatherlink_live.data_host: Received new broadcast packet
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
> THMapping[['1']]: Observation not found in packet
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
> THIndoorMapping[[]]: Observation not found in packet
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
> BaroMapping[[]]: Observation not found in packet
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
> RainMapping[['1']]: Mapped: rainSize=0.01
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
> RainM
> << SNIP  more of the above >>
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live: 
> Emitting push (broadcast) packet
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.service: 
> WllWindGustService: Updating record with dict: {'windGust': 2.62, 
> 'windGustDir': 106}
> Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live: Waiting 
> for new packet
> Jun 10 16:43:49 mythtv2 weewx[206240] message repeated 7 times: [ DEBUG 
> user.weatherlink_live: Waiting for new packet]
>
> After that, no more UDP packets were flowing, and the WLL driver repeated 
> the waiting for packet message from then on (this time is as I am posting)
> Jun 10 20:09:25 mythtv2 weewx[206240] message repeated 4 times: [ DEBUG 
> user.weatherlink_live: Waiting for new packet]
>
> My diagnosis is that the most likely cause was that WLL didn't receive a 
> needed HTTP request to keep data flowing, because either the WLL driver 
> didn't send it for some reason, or the connection attempt failed or some 
> such.
>
> Perhaps a cure/workaround would be this:  one expects to see those UDP 
> packets about every two seconds.  If 15  (or maybe 30) have gone by, 
> generate an error log entry and send an HTTP request - all one would have 
> to do is put a counter in the place where it is issuing the Waiting message 
> (regardless of whether debugging was enabled or not)  .  Also, if the code 
> is relying on an HTTP TCP connection staying open between requests, it 
> would be better to open a new TCP connection for each request (I haven't 
> looked at the code.) 
>
> JRJ
>
> On Wednesday, June 9, 2021 at 1:30:17 PM UTC-5 michael.s...@gmail.com 
> wrote:
>
>> @JRJ: So, you're saying that WeeWX stopped generating reports but data 
>> still was recorded in the database, correct?
>> If yes, it seems unlikely that 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

So, it happened again.  Here is how the events seem to have unfolded, based 
on the logs:

*** The last HTTP request seems to have gone out at 16:26 (so, before data 
stopped flowing) - there were no more HTTP requests after that - it was the 
last appearnce of http or HTTP from the weewx process in the logs:

Jun 10 16:26:12 mythtv2 weewx[206240] DEBUG urllib3.connectionpool: 
http://vanta
gevieww.lan:80 "GET /v1/current_conditions HTTP/1.1" 200 None

*** The last every-5-minute record update was at 16:40 CDT Today:
Jun 10 16:40:16 mythtv2 weewx[206240] INFO weewx.manager: Added record 
2021-06-10 16:40:00 CDT (1623361200) to daily summary in 'weewx'

*** UDP packets continued until 16:43, after which they stopped (presumably 
because the WLL box was in need of an HTTP "tickle"_

Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG 
user.weatherlink_live.davis_broadcast: Received 394 bytes from 
('192.168.42.75', 25447)
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.packets: 
Trying to create UDP conditions packet
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG 
user.weatherlink_live.data_host: Received new broadcast packet
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
THMapping[['1']]: Observation not found in packet
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
THIndoorMapping[[]]: Observation not found in packet
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
BaroMapping[[]]: Observation not found in packet
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
RainMapping[['1']]: Mapped: rainSize=0.01
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.mappers: 
RainM
<< SNIP  more of the above >>
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live: Emitting 
push (broadcast) packet
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live.service: 
WllWindGustService: Updating record with dict: {'windGust': 2.62, 
'windGustDir': 106}
Jun 10 16:43:14 mythtv2 weewx[206240] DEBUG user.weatherlink_live: Waiting 
for new packet
Jun 10 16:43:49 mythtv2 weewx[206240] message repeated 7 times: [ DEBUG 
user.weatherlink_live: Waiting for new packet]

After that, no more UDP packets were flowing, and the WLL driver repeated 
the waiting for packet message from then on (this time is as I am posting)
Jun 10 20:09:25 mythtv2 weewx[206240] message repeated 4 times: [ DEBUG 
user.weatherlink_live: Waiting for new packet]

My diagnosis is that the most likely cause was that WLL didn't receive a 
needed HTTP request to keep data flowing, because either the WLL driver 
didn't send it for some reason, or the connection attempt failed or some 
such.

Perhaps a cure/workaround would be this:  one expects to see those UDP 
packets about every two seconds.  If 15  (or maybe 30) have gone by, 
generate an error log entry and send an HTTP request - all one would have 
to do is put a counter in the place where it is issuing the Waiting message 
(regardless of whether debugging was enabled or not)  .  Also, if the code 
is relying on an HTTP TCP connection staying open between requests, it 
would be better to open a new TCP connection for each request (I haven't 
looked at the code.) 

JRJ

On Wednesday, June 9, 2021 at 1:30:17 PM UTC-5 michael.s...@gmail.com wrote:

> @JRJ: So, you're saying that WeeWX stopped generating reports but data 
> still was recorded in the database, correct?
> If yes, it seems unlikely that it's a driver issue and more on the weewx 
> engine's side.
>
> cub...@gmail.com schrieb am Mittwoch, 9. Juni 2021 um 20:22:01 UTC+2:
>
>> @chris:  yes, indeed, the issue on my system was that weewx stopped 
>> producing reports (and also there were no reporting-related messages in the 
>> log.  I do am now running with debug set to 1 in the config.
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:
>>
>>> JRJ:
>>>
>>> Are you saying that weewx stopped generating reports? My weewx stopped 
>>> generating reports, with no error messages, at 4:00 AM. Restarting service 
>>> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
>>> crontab entry to reboot my raspberry pi each morning:
>>> 5 4 * * * /sbin/shutdown -r now
>>>
>>> So far, it has not happened again. I'm using a WMII, with serial port 
>>> connection, using Python3 and the latest version of the driver from 
>>> JayJaeger
>>>
>>> Chris Shaker
>>>
>>> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>>>
 @michael:  It should not be related to the SCP upload, which continues 
 even after weewx has gone "night night".  It is running from a cron, not 
 under weewx.  It merely copies the generated HTML/graphics up to another 
 machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
 and causing a report to fail there ought to be a message from Python about 
 that, and there are no such 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

@eric thread population is up to you, if you want to post on this one, that 
is fine with me.  FYI, I have now been running a little over 1 full day 
with debug with the newer WeatherLinkLive driver with no untoward events - 
but note that the first one took over two days to occur.

On Thursday, June 10, 2021 at 12:29:41 PM UTC-5 Eric K wrote:

> @JRJ, it appears this (or something similar) has just happened on my weewx 
> 4.5.1 installation.
> I suppose I should start a new thread on it.  
> I'll be watching yours to see if you find out whats going wrong!
>
> On Wednesday, June 9, 2021 at 2:29:39 PM UTC-5 cub...@gmail.com wrote:
>
>> @michael:  No, that is not what I am saying.  In fact, the converse is 
>> likely true: that it ALSO stopped recording data in the database, as there 
>> are no more messages of the sort "Added record ... to database" INFO level 
>> messages in my logs once this occurred, as can be seen in my original post 
>> - *all* messages out of weewx stopped at 03:15:18 in that example.  (Of 
>> course it did also stop generating reports.)
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 1:30:17 PM UTC-5 michael.s...@gmail.com 
>> wrote:
>>
>>> @JRJ: So, you're saying that WeeWX stopped generating reports but data 
>>> still was recorded in the database, correct?
>>> If yes, it seems unlikely that it's a driver issue and more on the weewx 
>>> engine's side.
>>>
>>> cub...@gmail.com schrieb am Mittwoch, 9. Juni 2021 um 20:22:01 UTC+2:
>>>
 @chris:  yes, indeed, the issue on my system was that weewx stopped 
 producing reports (and also there were no reporting-related messages in 
 the 
 log.  I do am now running with debug set to 1 in the config.

 JRJ

 On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com 
 wrote:

> JRJ:
>
> Are you saying that weewx stopped generating reports? My weewx stopped 
> generating reports, with no error messages, at 4:00 AM. Restarting 
> service 
> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
> crontab entry to reboot my raspberry pi each morning:
> 5 4 * * * /sbin/shutdown -r now
>
> So far, it has not happened again. I'm using a WMII, with serial port 
> connection, using Python3 and the latest version of the driver from 
> JayJaeger
>
> Chris Shaker
>
> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>
>> @michael:  It should not be related to the SCP upload, which 
>> continues even after weewx has gone "night night".  It is running from a 
>> cron, not under weewx.  It merely copies the generated HTML/graphics up 
>> to 
>> another machine.  It runs  every 17  minutes.  If it were, say, locking 
>> up 
>> a file and causing a report to fail there ought to be a message from 
>> Python 
>> about that, and there are no such messages.  This same SCP was running 
>> with 
>> weewx version 3 for many months without issues - originally every 15 
>> minutes, I changed it from 15 to 17 yesterday to put it out of sync from 
>> the report generation a bit it after the second failure, just in case.  
>>
>> [It did occur to me to add a little mod akin to the RSYNC present in 
>> weewx itself, or to cut over to using  then RSYNC under weewx after the 
>> rest of this gets straightened out.]
>>
>> I also verified that all of the files and directories are owned by 
>> and have the same group as the weewx process, and they are, so it should 
>> not be an issue of file permissions during report generation, either.
>>
>> Regarding the dev release driver, sure, I'll give that a try, and 
>> turn on more logging later today.
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
>> wrote:
>>
>>> Nah, the logging level change doesn't matter, I've published a dev 
>>> release a few days ago making exactly that change.
>>>
>>> I'd suggest you to try the new driver version anyway since I also 
>>> made some changes regarding the HTTP interaction with the WLL. You 
>>> should 
>>> also enable debug logging so we get a more exhaustive look into what's 
>>> going on.
>>>
>>> My suspicion is that something's wrong with the report generation or 
>>> the SCP upload. Was the last iteration of the report actually uploaded 
>>> correctly?
>>>
>>>
>>>
>>> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>>>
 On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com 
 wrote:

> (Note: I  did "tweaked" the WLL driver code to suppress the 
> "Emitting poll/(broadcast) messages by changing those two log calls 
> to 
> "log.debug").  


 I'd suggest running the unaltered driver and especially in this 
 

[weewx-user] Re: weewx stopped for no apparent reason

[Eric K]

@JRJ, it appears this (or something similar) has just happened on my weewx 
4.5.1 installation.
I suppose I should start a new thread on it.  
I'll be watching yours to see if you find out whats going wrong!

On Wednesday, June 9, 2021 at 2:29:39 PM UTC-5 cub...@gmail.com wrote:

> @michael:  No, that is not what I am saying.  In fact, the converse is 
> likely true: that it ALSO stopped recording data in the database, as there 
> are no more messages of the sort "Added record ... to database" INFO level 
> messages in my logs once this occurred, as can be seen in my original post 
> - *all* messages out of weewx stopped at 03:15:18 in that example.  (Of 
> course it did also stop generating reports.)
>
> JRJ
>
> On Wednesday, June 9, 2021 at 1:30:17 PM UTC-5 michael.s...@gmail.com 
> wrote:
>
>> @JRJ: So, you're saying that WeeWX stopped generating reports but data 
>> still was recorded in the database, correct?
>> If yes, it seems unlikely that it's a driver issue and more on the weewx 
>> engine's side.
>>
>> cub...@gmail.com schrieb am Mittwoch, 9. Juni 2021 um 20:22:01 UTC+2:
>>
>>> @chris:  yes, indeed, the issue on my system was that weewx stopped 
>>> producing reports (and also there were no reporting-related messages in the 
>>> log.  I do am now running with debug set to 1 in the config.
>>>
>>> JRJ
>>>
>>> On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:
>>>
 JRJ:

 Are you saying that weewx stopped generating reports? My weewx stopped 
 generating reports, with no error messages, at 4:00 AM. Restarting service 
 weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
 crontab entry to reboot my raspberry pi each morning:
 5 4 * * * /sbin/shutdown -r now

 So far, it has not happened again. I'm using a WMII, with serial port 
 connection, using Python3 and the latest version of the driver from 
 JayJaeger

 Chris Shaker

 On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:

> @michael:  It should not be related to the SCP upload, which continues 
> even after weewx has gone "night night".  It is running from a cron, not 
> under weewx.  It merely copies the generated HTML/graphics up to another 
> machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
> and causing a report to fail there ought to be a message from Python 
> about 
> that, and there are no such messages.  This same SCP was running with 
> weewx 
> version 3 for many months without issues - originally every 15 minutes, I 
> changed it from 15 to 17 yesterday to put it out of sync from the report 
> generation a bit it after the second failure, just in case.  
>
> [It did occur to me to add a little mod akin to the RSYNC present in 
> weewx itself, or to cut over to using  then RSYNC under weewx after the 
> rest of this gets straightened out.]
>
> I also verified that all of the files and directories are owned by and 
> have the same group as the weewx process, and they are, so it should not 
> be 
> an issue of file permissions during report generation, either.
>
> Regarding the dev release driver, sure, I'll give that a try, and turn 
> on more logging later today.
>
> JRJ
>
> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
> wrote:
>
>> Nah, the logging level change doesn't matter, I've published a dev 
>> release a few days ago making exactly that change.
>>
>> I'd suggest you to try the new driver version anyway since I also 
>> made some changes regarding the HTTP interaction with the WLL. You 
>> should 
>> also enable debug logging so we get a more exhaustive look into what's 
>> going on.
>>
>> My suspicion is that something's wrong with the report generation or 
>> the SCP upload. Was the last iteration of the report actually uploaded 
>> correctly?
>>
>>
>>
>> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>>
>>> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com 
>>> wrote:
>>>
 (Note: I  did "tweaked" the WLL driver code to suppress the 
 "Emitting poll/(broadcast) messages by changing those two log calls to 
 "log.debug").  
>>>
>>>
>>> I'd suggest running the unaltered driver and especially in this case 
>>> so you get the maximum logging so the author can help you.
>>>
>>> If you start changing his code, eventually it'll be "you changed it, 
>>> you own the results good or bad" when he can't recreate the issue 
>>> because 
>>> your code has diverged from the authoritative version.
>>>
>>>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

@michael:  No, that is not what I am saying.  In fact, the converse is 
likely true: that it ALSO stopped recording data in the database, as there 
are no more messages of the sort "Added record ... to database" INFO level 
messages in my logs once this occurred, as can be seen in my original post 
- *all* messages out of weewx stopped at 03:15:18 in that example.  (Of 
course it did also stop generating reports.)

JRJ

On Wednesday, June 9, 2021 at 1:30:17 PM UTC-5 michael.s...@gmail.com wrote:

> @JRJ: So, you're saying that WeeWX stopped generating reports but data 
> still was recorded in the database, correct?
> If yes, it seems unlikely that it's a driver issue and more on the weewx 
> engine's side.
>
> cub...@gmail.com schrieb am Mittwoch, 9. Juni 2021 um 20:22:01 UTC+2:
>
>> @chris:  yes, indeed, the issue on my system was that weewx stopped 
>> producing reports (and also there were no reporting-related messages in the 
>> log.  I do am now running with debug set to 1 in the config.
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:
>>
>>> JRJ:
>>>
>>> Are you saying that weewx stopped generating reports? My weewx stopped 
>>> generating reports, with no error messages, at 4:00 AM. Restarting service 
>>> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
>>> crontab entry to reboot my raspberry pi each morning:
>>> 5 4 * * * /sbin/shutdown -r now
>>>
>>> So far, it has not happened again. I'm using a WMII, with serial port 
>>> connection, using Python3 and the latest version of the driver from 
>>> JayJaeger
>>>
>>> Chris Shaker
>>>
>>> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>>>
 @michael:  It should not be related to the SCP upload, which continues 
 even after weewx has gone "night night".  It is running from a cron, not 
 under weewx.  It merely copies the generated HTML/graphics up to another 
 machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
 and causing a report to fail there ought to be a message from Python about 
 that, and there are no such messages.  This same SCP was running with 
 weewx 
 version 3 for many months without issues - originally every 15 minutes, I 
 changed it from 15 to 17 yesterday to put it out of sync from the report 
 generation a bit it after the second failure, just in case.  

 [It did occur to me to add a little mod akin to the RSYNC present in 
 weewx itself, or to cut over to using  then RSYNC under weewx after the 
 rest of this gets straightened out.]

 I also verified that all of the files and directories are owned by and 
 have the same group as the weewx process, and they are, so it should not 
 be 
 an issue of file permissions during report generation, either.

 Regarding the dev release driver, sure, I'll give that a try, and turn 
 on more logging later today.

 JRJ

 On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
 wrote:

> Nah, the logging level change doesn't matter, I've published a dev 
> release a few days ago making exactly that change.
>
> I'd suggest you to try the new driver version anyway since I also made 
> some changes regarding the HTTP interaction with the WLL. You should also 
> enable debug logging so we get a more exhaustive look into what's going 
> on.
>
> My suspicion is that something's wrong with the report generation or 
> the SCP upload. Was the last iteration of the report actually uploaded 
> correctly?
>
>
>
> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>
>> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:
>>
>>> (Note: I  did "tweaked" the WLL driver code to suppress the 
>>> "Emitting poll/(broadcast) messages by changing those two log calls to 
>>> "log.debug").  
>>
>>
>> I'd suggest running the unaltered driver and especially in this case 
>> so you get the maximum logging so the author can help you.
>>
>> If you start changing his code, eventually it'll be "you changed it, 
>> you own the results good or bad" when he can't recreate the issue 
>> because 
>> your code has diverged from the authoritative version.
>>
>>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/d3dd45dd-1288-4050-b9f8-9f6c0264f4ben%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Michael Schantl]

@JRJ: So, you're saying that WeeWX stopped generating reports but data 
still was recorded in the database, correct?
If yes, it seems unlikely that it's a driver issue and more on the weewx 
engine's side.

cub...@gmail.com schrieb am Mittwoch, 9. Juni 2021 um 20:22:01 UTC+2:

> @chris:  yes, indeed, the issue on my system was that weewx stopped 
> producing reports (and also there were no reporting-related messages in the 
> log.  I do am now running with debug set to 1 in the config.
>
> JRJ
>
> On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:
>
>> JRJ:
>>
>> Are you saying that weewx stopped generating reports? My weewx stopped 
>> generating reports, with no error messages, at 4:00 AM. Restarting service 
>> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
>> crontab entry to reboot my raspberry pi each morning:
>> 5 4 * * * /sbin/shutdown -r now
>>
>> So far, it has not happened again. I'm using a WMII, with serial port 
>> connection, using Python3 and the latest version of the driver from 
>> JayJaeger
>>
>> Chris Shaker
>>
>> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>>
>>> @michael:  It should not be related to the SCP upload, which continues 
>>> even after weewx has gone "night night".  It is running from a cron, not 
>>> under weewx.  It merely copies the generated HTML/graphics up to another 
>>> machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
>>> and causing a report to fail there ought to be a message from Python about 
>>> that, and there are no such messages.  This same SCP was running with weewx 
>>> version 3 for many months without issues - originally every 15 minutes, I 
>>> changed it from 15 to 17 yesterday to put it out of sync from the report 
>>> generation a bit it after the second failure, just in case.  
>>>
>>> [It did occur to me to add a little mod akin to the RSYNC present in 
>>> weewx itself, or to cut over to using  then RSYNC under weewx after the 
>>> rest of this gets straightened out.]
>>>
>>> I also verified that all of the files and directories are owned by and 
>>> have the same group as the weewx process, and they are, so it should not be 
>>> an issue of file permissions during report generation, either.
>>>
>>> Regarding the dev release driver, sure, I'll give that a try, and turn 
>>> on more logging later today.
>>>
>>> JRJ
>>>
>>> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
>>> wrote:
>>>
 Nah, the logging level change doesn't matter, I've published a dev 
 release a few days ago making exactly that change.

 I'd suggest you to try the new driver version anyway since I also made 
 some changes regarding the HTTP interaction with the WLL. You should also 
 enable debug logging so we get a more exhaustive look into what's going on.

 My suspicion is that something's wrong with the report generation or 
 the SCP upload. Was the last iteration of the report actually uploaded 
 correctly?



 vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:

> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:
>
>> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
>> poll/(broadcast) messages by changing those two log calls to 
>> "log.debug").  
>
>
> I'd suggest running the unaltered driver and especially in this case 
> so you get the maximum logging so the author can help you.
>
> If you start changing his code, eventually it'll be "you changed it, 
> you own the results good or bad" when he can't recreate the issue because 
> your code has diverged from the authoritative version.
>
>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/7b992998-efb5-49fa-8086-1b342af62352n%40googlegroups.com.

Re: [weewx-user] Re: weewx stopped for no apparent reason

[Christopher J. Shaker]

Jay:

I tried 'sudo service weewx restart', and it did NOT fix the problem. I 
rebooted the machine, and it worked
great. Hopefully, now that I've got debug enabled, if it happens again, 
I can debug it.


Thank you for sharing your WMII driver for Python 3!

Chris Shaker

On 6/9/2021 11:20 AM, Jay Jaeger wrote:
@Chris:  Version 3 weewx with my wmII was rock solid.  I didn't run 
the wmII more than a day under version 4, so I can't speak to that.  I 
had no issues restarting weewx - didn't need a reboot.


NOTE:  systemd behavior, being what it is, if a service crashes, it 
still is not STOPPED, and it won't start a service that it thinks is 
still running.  Instead, you have to stop it (service weewx stop) 
before you can start it (or, you could do a "service weewx restart" 
which does a stop first.)


JRJ

On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:

JRJ:

Are you saying that weewx stopped generating reports? My weewx
stopped generating reports, with no error messages, at 4:00 AM.
Restarting service weewx did not fix it. Rebooting my raspberry pi
DID fix it. So, I added a crontab entry to reboot my raspberry pi
each morning:
5 4 * * * /sbin/shutdown -r now

So far, it has not happened again. I'm using a WMII, with serial
port connection, using Python3 and the latest version of the
driver from JayJaeger

Chris Shaker

On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:

@michael:  It should not be related to the SCP upload, which
continues even after weewx has gone "night night".  It is
running from a cron, not under weewx.  It merely copies the
generated HTML/graphics up to another machine.  It runs  every
17 minutes.  If it were, say, locking up a file and causing a
report to fail there ought to be a message from Python about
that, and there are no such messages.  This same SCP was
running with weewx version 3 for many months without issues -
originally every 15 minutes, I changed it from 15 to 17
yesterday to put it out of sync from the report generation a
bit it after the second failure, just in case.

[It did occur to me to add a little mod akin to the RSYNC
present in weewx itself, or to cut over to using then RSYNC
under weewx after the rest of this gets straightened out.]

I also verified that all of the files and directories are
owned by and have the same group as the weewx process, and
they are, so it should not be an issue of file permissions
during report generation, either.

Regarding the dev release driver, sure, I'll give that a try,
and turn on more logging later today.

JRJ

On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5
michael.s...@gmail.com wrote:

Nah, the logging level change doesn't matter, I've
published a dev release a few days ago making exactly that
change.

I'd suggest you to try the new driver version anyway since
I also made some changes regarding the HTTP interaction
with the WLL. You should also enable debug logging so we
get a more exhaustive look into what's going on.

My suspicion is that something's wrong with the report
generation or the SCP upload. Was the last iteration of
the report actually uploaded correctly?



vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:

On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7
cub...@gmail.com wrote:

(Note: I did "tweaked" the WLL driver code to
suppress the "Emitting poll/(broadcast) messages
by changing those two log calls to "log.debug"). 



I'd suggest running the unaltered driver and
especially in this case so you get the maximum logging
so the author can help you.

If you start changing his code, eventually it'll be
"you changed it, you own the results good or bad" when
he can't recreate the issue because your code has
diverged from the authoritative version.

--
You received this message because you are subscribed to a topic in the 
Google Groups "weewx-user" group.
To unsubscribe from this topic, visit 
https://groups.google.com/d/topic/weewx-user/GYnuZbTdhuM/unsubscribe 
.
To unsubscribe from this group and all its topics, send an email to 
weewx-user+unsubscr...@googlegroups.com 
.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/868ff588-eed6-4cee-b94b-61143e0cfa85n%40googlegroups.com 

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

@chris:  yes, indeed, the issue on my system was that weewx stopped 
producing reports (and also there were no reporting-related messages in the 
log.  I do am now running with debug set to 1 in the config.

JRJ

On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:

> JRJ:
>
> Are you saying that weewx stopped generating reports? My weewx stopped 
> generating reports, with no error messages, at 4:00 AM. Restarting service 
> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
> crontab entry to reboot my raspberry pi each morning:
> 5 4 * * * /sbin/shutdown -r now
>
> So far, it has not happened again. I'm using a WMII, with serial port 
> connection, using Python3 and the latest version of the driver from 
> JayJaeger
>
> Chris Shaker
>
> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>
>> @michael:  It should not be related to the SCP upload, which continues 
>> even after weewx has gone "night night".  It is running from a cron, not 
>> under weewx.  It merely copies the generated HTML/graphics up to another 
>> machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
>> and causing a report to fail there ought to be a message from Python about 
>> that, and there are no such messages.  This same SCP was running with weewx 
>> version 3 for many months without issues - originally every 15 minutes, I 
>> changed it from 15 to 17 yesterday to put it out of sync from the report 
>> generation a bit it after the second failure, just in case.  
>>
>> [It did occur to me to add a little mod akin to the RSYNC present in 
>> weewx itself, or to cut over to using  then RSYNC under weewx after the 
>> rest of this gets straightened out.]
>>
>> I also verified that all of the files and directories are owned by and 
>> have the same group as the weewx process, and they are, so it should not be 
>> an issue of file permissions during report generation, either.
>>
>> Regarding the dev release driver, sure, I'll give that a try, and turn on 
>> more logging later today.
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
>> wrote:
>>
>>> Nah, the logging level change doesn't matter, I've published a dev 
>>> release a few days ago making exactly that change.
>>>
>>> I'd suggest you to try the new driver version anyway since I also made 
>>> some changes regarding the HTTP interaction with the WLL. You should also 
>>> enable debug logging so we get a more exhaustive look into what's going on.
>>>
>>> My suspicion is that something's wrong with the report generation or the 
>>> SCP upload. Was the last iteration of the report actually uploaded 
>>> correctly?
>>>
>>>
>>>
>>> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>>>
 On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:

> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
> poll/(broadcast) messages by changing those two log calls to 
> "log.debug").  


 I'd suggest running the unaltered driver and especially in this case so 
 you get the maximum logging so the author can help you.

 If you start changing his code, eventually it'll be "you changed it, 
 you own the results good or bad" when he can't recreate the issue because 
 your code has diverged from the authoritative version.



-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/65135631-d715-4e50-b787-ab792eb83881n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

@Chris:  Version 3 weewx with my wmII was rock solid.  I didn't run the 
wmII more than a day under version 4, so I can't speak to that.  I had no 
issues restarting weewx - didn't need a reboot.

NOTE:  systemd behavior, being what it is, if a service crashes, it still 
is not STOPPED, and it won't start a service that it thinks is still 
running.  Instead, you have to stop it (service weewx stop) before you can 
start it (or, you could do a "service weewx restart" which does a stop 
first.)

JRJ

On Wednesday, June 9, 2021 at 12:09:08 PM UTC-5 cjsh...@gmail.com wrote:

> JRJ:
>
> Are you saying that weewx stopped generating reports? My weewx stopped 
> generating reports, with no error messages, at 4:00 AM. Restarting service 
> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
> crontab entry to reboot my raspberry pi each morning:
> 5 4 * * * /sbin/shutdown -r now
>
> So far, it has not happened again. I'm using a WMII, with serial port 
> connection, using Python3 and the latest version of the driver from 
> JayJaeger
>
> Chris Shaker
>
> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>
>> @michael:  It should not be related to the SCP upload, which continues 
>> even after weewx has gone "night night".  It is running from a cron, not 
>> under weewx.  It merely copies the generated HTML/graphics up to another 
>> machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
>> and causing a report to fail there ought to be a message from Python about 
>> that, and there are no such messages.  This same SCP was running with weewx 
>> version 3 for many months without issues - originally every 15 minutes, I 
>> changed it from 15 to 17 yesterday to put it out of sync from the report 
>> generation a bit it after the second failure, just in case.  
>>
>> [It did occur to me to add a little mod akin to the RSYNC present in 
>> weewx itself, or to cut over to using  then RSYNC under weewx after the 
>> rest of this gets straightened out.]
>>
>> I also verified that all of the files and directories are owned by and 
>> have the same group as the weewx process, and they are, so it should not be 
>> an issue of file permissions during report generation, either.
>>
>> Regarding the dev release driver, sure, I'll give that a try, and turn on 
>> more logging later today.
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
>> wrote:
>>
>>> Nah, the logging level change doesn't matter, I've published a dev 
>>> release a few days ago making exactly that change.
>>>
>>> I'd suggest you to try the new driver version anyway since I also made 
>>> some changes regarding the HTTP interaction with the WLL. You should also 
>>> enable debug logging so we get a more exhaustive look into what's going on.
>>>
>>> My suspicion is that something's wrong with the report generation or the 
>>> SCP upload. Was the last iteration of the report actually uploaded 
>>> correctly?
>>>
>>>
>>>
>>> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>>>
 On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:

> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
> poll/(broadcast) messages by changing those two log calls to 
> "log.debug").  


 I'd suggest running the unaltered driver and especially in this case so 
 you get the maximum logging so the author can help you.

 If you start changing his code, eventually it'll be "you changed it, 
 you own the results good or bad" when he can't recreate the issue because 
 your code has diverged from the authoritative version.



-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/868ff588-eed6-4cee-b94b-61143e0cfa85n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Christopher Shaker]

I have set debug to 1, and disabled the crontab reboot, to see if I can 
collect some debug data.
Chris Shaker


On Wednesday, June 9, 2021 at 10:09:08 AM UTC-7 Christopher Shaker wrote:

> JRJ:
>
> Are you saying that weewx stopped generating reports? My weewx stopped 
> generating reports, with no error messages, at 4:00 AM. Restarting service 
> weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
> crontab entry to reboot my raspberry pi each morning:
> 5 4 * * * /sbin/shutdown -r now
>
> So far, it has not happened again. I'm using a WMII, with serial port 
> connection, using Python3 and the latest version of the driver from 
> JayJaeger
>
> Chris Shaker
>
> On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:
>
>> @michael:  It should not be related to the SCP upload, which continues 
>> even after weewx has gone "night night".  It is running from a cron, not 
>> under weewx.  It merely copies the generated HTML/graphics up to another 
>> machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
>> and causing a report to fail there ought to be a message from Python about 
>> that, and there are no such messages.  This same SCP was running with weewx 
>> version 3 for many months without issues - originally every 15 minutes, I 
>> changed it from 15 to 17 yesterday to put it out of sync from the report 
>> generation a bit it after the second failure, just in case.  
>>
>> [It did occur to me to add a little mod akin to the RSYNC present in 
>> weewx itself, or to cut over to using  then RSYNC under weewx after the 
>> rest of this gets straightened out.]
>>
>> I also verified that all of the files and directories are owned by and 
>> have the same group as the weewx process, and they are, so it should not be 
>> an issue of file permissions during report generation, either.
>>
>> Regarding the dev release driver, sure, I'll give that a try, and turn on 
>> more logging later today.
>>
>> JRJ
>>
>> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
>> wrote:
>>
>>> Nah, the logging level change doesn't matter, I've published a dev 
>>> release a few days ago making exactly that change.
>>>
>>> I'd suggest you to try the new driver version anyway since I also made 
>>> some changes regarding the HTTP interaction with the WLL. You should also 
>>> enable debug logging so we get a more exhaustive look into what's going on.
>>>
>>> My suspicion is that something's wrong with the report generation or the 
>>> SCP upload. Was the last iteration of the report actually uploaded 
>>> correctly?
>>>
>>>
>>>
>>> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>>>
 On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:

> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
> poll/(broadcast) messages by changing those two log calls to 
> "log.debug").  


 I'd suggest running the unaltered driver and especially in this case so 
 you get the maximum logging so the author can help you.

 If you start changing his code, eventually it'll be "you changed it, 
 you own the results good or bad" when he can't recreate the issue because 
 your code has diverged from the authoritative version.



-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/f9a4522f-95bd-408b-a323-30fa8b07cc59n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Christopher Shaker]

JRJ:

Are you saying that weewx stopped generating reports? My weewx stopped 
generating reports, with no error messages, at 4:00 AM. Restarting service 
weewx did not fix it. Rebooting my raspberry pi DID fix it. So, I added a 
crontab entry to reboot my raspberry pi each morning:
5 4 * * * /sbin/shutdown -r now

So far, it has not happened again. I'm using a WMII, with serial port 
connection, using Python3 and the latest version of the driver from 
JayJaeger

Chris Shaker

On Wednesday, June 9, 2021 at 5:46:52 AM UTC-7 cub...@gmail.com wrote:

> @michael:  It should not be related to the SCP upload, which continues 
> even after weewx has gone "night night".  It is running from a cron, not 
> under weewx.  It merely copies the generated HTML/graphics up to another 
> machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
> and causing a report to fail there ought to be a message from Python about 
> that, and there are no such messages.  This same SCP was running with weewx 
> version 3 for many months without issues - originally every 15 minutes, I 
> changed it from 15 to 17 yesterday to put it out of sync from the report 
> generation a bit it after the second failure, just in case.  
>
> [It did occur to me to add a little mod akin to the RSYNC present in weewx 
> itself, or to cut over to using  then RSYNC under weewx after the rest of 
> this gets straightened out.]
>
> I also verified that all of the files and directories are owned by and 
> have the same group as the weewx process, and they are, so it should not be 
> an issue of file permissions during report generation, either.
>
> Regarding the dev release driver, sure, I'll give that a try, and turn on 
> more logging later today.
>
> JRJ
>
> On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com 
> wrote:
>
>> Nah, the logging level change doesn't matter, I've published a dev 
>> release a few days ago making exactly that change.
>>
>> I'd suggest you to try the new driver version anyway since I also made 
>> some changes regarding the HTTP interaction with the WLL. You should also 
>> enable debug logging so we get a more exhaustive look into what's going on.
>>
>> My suspicion is that something's wrong with the report generation or the 
>> SCP upload. Was the last iteration of the report actually uploaded 
>> correctly?
>>
>>
>>
>> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>>
>>> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:
>>>
 (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
 poll/(broadcast) messages by changing those two log calls to "log.debug"). 
  
>>>
>>>
>>> I'd suggest running the unaltered driver and especially in this case so 
>>> you get the maximum logging so the author can help you.
>>>
>>> If you start changing his code, eventually it'll be "you changed it, you 
>>> own the results good or bad" when he can't recreate the issue because your 
>>> code has diverged from the authoritative version.
>>>
>>>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/98562a13-b40a-4588-8438-81c6957964fen%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

@michael:  It should not be related to the SCP upload, which continues even 
after weewx has gone "night night".  It is running from a cron, not under 
weewx.  It merely copies the generated HTML/graphics up to another 
machine.  It runs  every 17  minutes.  If it were, say, locking up a file 
and causing a report to fail there ought to be a message from Python about 
that, and there are no such messages.  This same SCP was running with weewx 
version 3 for many months without issues - originally every 15 minutes, I 
changed it from 15 to 17 yesterday to put it out of sync from the report 
generation a bit it after the second failure, just in case.  

[It did occur to me to add a little mod akin to the RSYNC present in weewx 
itself, or to cut over to using  then RSYNC under weewx after the rest of 
this gets straightened out.]

I also verified that all of the files and directories are owned by and have 
the same group as the weewx process, and they are, so it should not be an 
issue of file permissions during report generation, either.

Regarding the dev release driver, sure, I'll give that a try, and turn on 
more logging later today.

JRJ

On Wednesday, June 9, 2021 at 1:40:52 AM UTC-5 michael.s...@gmail.com wrote:

> Nah, the logging level change doesn't matter, I've published a dev release 
> a few days ago making exactly that change.
>
> I'd suggest you to try the new driver version anyway since I also made 
> some changes regarding the HTTP interaction with the WLL. You should also 
> enable debug logging so we get a more exhaustive look into what's going on.
>
> My suspicion is that something's wrong with the report generation or the 
> SCP upload. Was the last iteration of the report actually uploaded 
> correctly?
>
>
>
> vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:
>
>> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:
>>
>>> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
>>> poll/(broadcast) messages by changing those two log calls to "log.debug").  
>>
>>
>> I'd suggest running the unaltered driver and especially in this case so 
>> you get the maximum logging so the author can help you.
>>
>> If you start changing his code, eventually it'll be "you changed it, you 
>> own the results good or bad" when he can't recreate the issue because your 
>> code has diverged from the authoritative version.
>>
>>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/417b50a5-b506-47b6-a101-7eae9d8d4e51n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

@vince:  I worked in IT for over 36 years, and with UNIX and "C" since 
1976.  I know what I am doing.  There can be lots of reasons why an issue 
appears on one machine vs. another, often related to the timing 
relationship between events.  Yes, it occurred to me that logging at the 
DEBUG level is in order, but haven't gotten around to it yet (the last post 
was just before I went to bed last night).  I also wrote a little program 
to monitor the UDP messages coming from the WLL (has to run from another 
machine), but haven't deployed it yet.
 
On Tuesday, June 8, 2021 at 11:10:01 PM UTC-5 vince wrote:

> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:
>
>> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
>> poll/(broadcast) messages by changing those two log calls to "log.debug").  
>
>
> I'd suggest running the unaltered driver and especially in this case so 
> you get the maximum logging so the author can help you.
>
> If you start changing his code, eventually it'll be "you changed it, you 
> own the results good or bad" when he can't recreate the issue because your 
> code has diverged from the authoritative version.
>
>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/00bb9414-98c5-45c6-ae4b-0043904447aen%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Michael Schantl]

Nah, the logging level change doesn't matter, I've published a dev release 
a few days ago making exactly that change.

I'd suggest you to try the new driver version anyway since I also made some 
changes regarding the HTTP interaction with the WLL. You should also enable 
debug logging so we get a more exhaustive look into what's going on.

My suspicion is that something's wrong with the report generation or the 
SCP upload. Was the last iteration of the report actually uploaded 
correctly?



vince schrieb am Mittwoch, 9. Juni 2021 um 06:10:01 UTC+2:

> On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:
>
>> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
>> poll/(broadcast) messages by changing those two log calls to "log.debug").  
>
>
> I'd suggest running the unaltered driver and especially in this case so 
> you get the maximum logging so the author can help you.
>
> If you start changing his code, eventually it'll be "you changed it, you 
> own the results good or bad" when he can't recreate the issue because your 
> code has diverged from the authoritative version.
>
>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/1527f17f-a7a7-4b18-b69c-e6e0d5938a62n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[vince]

On Tuesday, June 8, 2021 at 12:43:44 PM UTC-7 cub...@gmail.com wrote:

> (Note: I  did "tweaked" the WLL driver code to suppress the "Emitting 
> poll/(broadcast) messages by changing those two log calls to "log.debug").  


I'd suggest running the unaltered driver and especially in this case so you 
get the maximum logging so the author can help you.

If you start changing his code, eventually it'll be "you changed it, you 
own the results good or bad" when he can't recreate the issue because your 
code has diverged from the authoritative version.

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/cbeb6755-e2b1-4479-b6c7-e8b31846211an%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

FYI, it has happened again, at about 18:00 today.  Any suggestions on 
instrumentation?

JRJ

On Tuesday, June 8, 2021 at 2:43:44 PM UTC-5 Jay Jaeger wrote:

> I knew the log looked "normal" aside from messages from weewx stopping - 
> had there been some error or other, I would have tracked it down on my 
> own.  The log extract was done using "grep weewx /var/log/syslog" [my logs 
> rotate at midnight].   (Note: I  ded "tweaked" the WLL driver code to 
> suppress the "Emitting poll/(broadcast) messages by changing those two log 
> calls to "log.debug").  
>
> weewx simply went night-night.  The "reportengine" message shown in my 
> post was the last message from weewx until I restarted it.  Note the 15 
> minute gap between that and the CRON message - there ought to have been a 
> couple more report generation sequences in between, which there were not.
>
> weewx did catch the TERM signal and ended normally when I ran "service 
> weewx stop".
>
> JRJ
>
> On Tuesday, June 8, 2021 at 12:40:24 PM UTC-5 michael.s...@gmail.com 
> wrote:
>
>> Hi, I'm the author of that WLL driver.
>>
>> Yes, the UDP broadcasts come from the WeatherLink Live. The driver should 
>> continue to 'tickle' the WLL even if any packets should have been missed, 
>> so that shouldn't be an issue.
>>
>> Were there no errors in the log? Your log dump looks absolutely normal.
>>
>> - Michael
>>
>>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/1f708044-cdf0-410a-b194-12a311d0c669n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

I knew the log looked "normal" aside from messages from weewx stopping - 
had there been some error or other, I would have tracked it down on my 
own.  The log extract was done using "grep weewx /var/log/syslog" [my logs 
rotate at midnight].   (Note: I  ded "tweaked" the WLL driver code to 
suppress the "Emitting poll/(broadcast) messages by changing those two log 
calls to "log.debug").  

weewx simply went night-night.  The "reportengine" message shown in my post 
was the last message from weewx until I restarted it.  Note the 15 minute 
gap between that and the CRON message - there ought to have been a couple 
more report generation sequences in between, which there were not.

weewx did catch the TERM signal and ended normally when I ran "service 
weewx stop".

JRJ

On Tuesday, June 8, 2021 at 12:40:24 PM UTC-5 michael.s...@gmail.com wrote:

> Hi, I'm the author of that WLL driver.
>
> Yes, the UDP broadcasts come from the WeatherLink Live. The driver should 
> continue to 'tickle' the WLL even if any packets should have been missed, 
> so that shouldn't be an issue.
>
> Were there no errors in the log? Your log dump looks absolutely normal.
>
> - Michael
>
>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/bd79287a-2847-4cd2-9815-33679e84ccb5n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Michael Schantl]

Hi, I'm the author of that WLL driver.

Yes, the UDP broadcasts come from the WeatherLink Live. The driver should 
continue to 'tickle' the WLL even if any packets should have been missed, 
so that shouldn't be an issue.

Were there no errors in the log? Your log dump looks absolutely normal.

- Michael

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/c16c2ff6-926d-4e29-91fb-4c843762be34n%40googlegroups.com.

[weewx-user] Re: weewx stopped for no apparent reason

[Jay Jaeger]

Oh it is worse than unwise.  I know better (I worked in network security 
for years) - incredibly STUPID is more like it.  Fortunately, a sandboxed, 
unpriviledged user - and fixed now.  ;)  [I tried to edit the post post 
facto to take it out, but it wouldn't let me edit the post.  8(]

That "something" which is indeed my LAN is my Davis WeatherLinkLive 
interface box (WLL) - which broadcasts on port 2 when appropriately 
"tickled" by an http request.  (It also makes TCP connections to the Davis 
server for their app.)  The first logs are from the machine at home (named 
mythtv2 for historical reasons), which is where weewx actually runs.  The 
scp is just copying the html and graphics up to my cloud-hosted website - 
not relevant to the problem - that kept on going fine (it is triggered by a 
cron job).  The scp isn't the issue at all.

The bottom logs are from my firewall ("cirithi") as a convenient place to 
spot such broadcasts and log them.

weewx was not stopped in that the service was still running on Linux.  
Whether it was in a blocked or deadlocked process state (waiting for 
something that would never happen) I cannot say for sure.   It might just 
be that the data from the WSS wasn't waking it up any more.  That UDP 
broadcast should be every 3 seconds or so, but weren't  showing up after 
3:18:50 AM.  My *suspicion* is that the weewx WLL driver missed (or didn't 
get) one of the UDP packets, and so didn't wake up to tickle the WLL with 
another HTTP request, and so went off to sleep forever.  

I only posted it here on the off chance that 1) someone else saw weewx go 
to sleep who may or may not be running WLL or 2) someone else running the 
WLL driver noticed the same thing.

On Tuesday, June 8, 2021 at 9:01:08 AM UTC-5 tomn...@frontier.com wrote:

> First thing, it's unwise to post your password for the world to see, so go 
> change that now.  :^)
> Next, if weewx is stopped, try that scp command from the command line.  
> It's way easier to debug that way.
> As for your firewall entries, it looks like something is talking directly 
> to your gateway or LAN broadcast via UDP
> port 2.  Can't say what, but that isn't weewx trying to get to your 
> web hosting service.
> Searching "udp port 2" did mention Davis Weatherlink among other 
> things.  Have you messed with anthing
> related to that?
>
> Chris
>
> On Monday, June 7, 2021 at 1:03:58 PM UTC-6 cub...@gmail.com wrote:
>
>> Over the weekend moved from weewx 3.9.2 to weewx 4.5.1.   It was 
>> essentially a reinstall, as I also moved from a Davis wmII (community 
>> driver) to a VantageVue with WeatherLinkLive (also a community driver), 
>> editing the config file from scratch.
>>
>>  System is Ubuntu Linux LTS 20.04, python 3.8, mySQL 5.7  The last start 
>> of weewx was on 5-Jun-2021.  It stopped reporting after 3:15 CDT on 
>> 7-Jun-2021, for no apparent reason that I can see.  
>>
>> (The exact time seems to have been around 3:18 AM on 7-Jun-2021 - that is 
>> when I no longer saw broadcasts from WeatherLinkLive.)
>>
>> Now, it is certainly possible that this is an issue in the 
>> WeatherLinkLive driver - and I will raise it as an issue with them, but 
>> also decided to check here just in case.
>>
>> The last things in /var/log/syslog were:
>>
>> Jun  7 03:15:17 mythtv2 weewx[119044] INFO weewx.manager: Added record 
>> 2021-06-07 03:15:00 CDT (1623053700) to database 'weewx'
>> Jun  7 03:15:17 mythtv2 weewx[119044] INFO weewx.manager: Added record 
>> 2021-06-07 03:15:00 CDT (1623053700) to daily summary in 'weewx'
>> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.restx: Wunderground-PWS: 
>> Published record 2021-06-07 03:15:00 CDT (1623053700)
>> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.cheetahgenerator: 
>> Generated 8 files for report SeasonsReport in 0.62 seconds
>> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.imagegenerator: 
>> Generated 14 images for report SeasonsReport in 0.29 seconds
>> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.reportengine: Copied 0 
>> files to /opt/weewx/public_html
>> Jun  7 03:30:01 mythtv2 CRON[154439]: (root) CMD (/usr/bin/sshpass -p 
>> 'CM12RVdx' /usr/bin/scp -r /opt/weewx/public_html/* 
>> we...@45.33.104.133:/var/www/html/
>> computercollection.net/public_html/weewx)
>>
>> The last things in my firewall log which is currently logging the 
>> broadcasts:
>>
>> Jun  7 03:18:45 cirith kernel: [23782696.289934] IN=eth1 OUT= 
>> MAC=ff:ff:ff:ff:ff:ff:ec:fa:bc:ce:49:b7:08:00 SRC=192.168.42.75 
>> DST=192.168.42.255 LEN=426 TOS=0x00 PREC=0x00 TTL=128 ID=64354 PROTO=UDP 
>> SPT=25447 DPT=2 LEN=406
>>
>> Jun  7 03:18:47 cirith kernel: [23782698.792825] IN=eth1 OUT= 
>> MAC=ff:ff:ff:ff:ff:ff:ec:fa:bc:ce:49:b7:08:00 SRC=192.168.42.75 
>> DST=192.168.42.255 LEN=426 TOS=0x00 PREC=0x00 TTL=128 ID=64355 PROTO=UDP 
>> SPT=25447 DPT=2 LEN=406
>>
>> Jun  7 03:18:50 cirith kernel: [23782701.291975] IN=eth1 OUT= 
>> MAC=ff:ff:ff:ff:ff:ff:ec:fa:bc:ce:49:b7:08:00 

[weewx-user] Re: weewx stopped for no apparent reason

[tomn...@frontier.com]

First thing, it's unwise to post your password for the world to see, so go 
change that now.  :^)
Next, if weewx is stopped, try that scp command from the command line.  
It's way easier to debug that way.
As for your firewall entries, it looks like something is talking directly 
to your gateway or LAN broadcast via UDP
port 2.  Can't say what, but that isn't weewx trying to get to your web 
hosting service.
Searching "udp port 2" did mention Davis Weatherlink among other 
things.  Have you messed with anthing
related to that?

Chris

On Monday, June 7, 2021 at 1:03:58 PM UTC-6 cub...@gmail.com wrote:

> Over the weekend moved from weewx 3.9.2 to weewx 4.5.1.   It was 
> essentially a reinstall, as I also moved from a Davis wmII (community 
> driver) to a VantageVue with WeatherLinkLive (also a community driver), 
> editing the config file from scratch.
>
>  System is Ubuntu Linux LTS 20.04, python 3.8, mySQL 5.7  The last start 
> of weewx was on 5-Jun-2021.  It stopped reporting after 3:15 CDT on 
> 7-Jun-2021, for no apparent reason that I can see.  
>
> (The exact time seems to have been around 3:18 AM on 7-Jun-2021 - that is 
> when I no longer saw broadcasts from WeatherLinkLive.)
>
> Now, it is certainly possible that this is an issue in the WeatherLinkLive 
> driver - and I will raise it as an issue with them, but also decided to 
> check here just in case.
>
> The last things in /var/log/syslog were:
>
> Jun  7 03:15:17 mythtv2 weewx[119044] INFO weewx.manager: Added record 
> 2021-06-07 03:15:00 CDT (1623053700) to database 'weewx'
> Jun  7 03:15:17 mythtv2 weewx[119044] INFO weewx.manager: Added record 
> 2021-06-07 03:15:00 CDT (1623053700) to daily summary in 'weewx'
> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.restx: Wunderground-PWS: 
> Published record 2021-06-07 03:15:00 CDT (1623053700)
> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.cheetahgenerator: 
> Generated 8 files for report SeasonsReport in 0.62 seconds
> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.imagegenerator: Generated 
> 14 images for report SeasonsReport in 0.29 seconds
> Jun  7 03:15:18 mythtv2 weewx[119044] INFO weewx.reportengine: Copied 0 
> files to /opt/weewx/public_html
> Jun  7 03:30:01 mythtv2 CRON[154439]: (root) CMD (/usr/bin/sshpass -p 
> 'CM12RVdx' /usr/bin/scp -r /opt/weewx/public_html/* 
> we...@45.33.104.133:/var/www/html/computercollection.net/public_html/weewx
> )
>
> The last things in my firewall log which is currently logging the 
> broadcasts:
>
> Jun  7 03:18:45 cirith kernel: [23782696.289934] IN=eth1 OUT= 
> MAC=ff:ff:ff:ff:ff:ff:ec:fa:bc:ce:49:b7:08:00 SRC=192.168.42.75 
> DST=192.168.42.255 LEN=426 TOS=0x00 PREC=0x00 TTL=128 ID=64354 PROTO=UDP 
> SPT=25447 DPT=2 LEN=406
>
> Jun  7 03:18:47 cirith kernel: [23782698.792825] IN=eth1 OUT= 
> MAC=ff:ff:ff:ff:ff:ff:ec:fa:bc:ce:49:b7:08:00 SRC=192.168.42.75 
> DST=192.168.42.255 LEN=426 TOS=0x00 PREC=0x00 TTL=128 ID=64355 PROTO=UDP 
> SPT=25447 DPT=2 LEN=406
>
> Jun  7 03:18:50 cirith kernel: [23782701.291975] IN=eth1 OUT= 
> MAC=ff:ff:ff:ff:ff:ff:ec:fa:bc:ce:49:b7:08:00 SRC=192.168.42.75 
> DST=192.168.42.255 LEN=426 TOS=0x00 PREC=0x00 TTL=128 ID=64356 PROTO=UDP 
> SPT=25447 DPT=2 LEN=406
>
> All times CDT.
>
> JRJ
>

-- 
You received this message because you are subscribed to the Google Groups 
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to weewx-user+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/weewx-user/db45eeae-75e4-474e-88e3-e551e364e5e2n%40googlegroups.com.