Re: [weewx-development] Correct handling exceptions in driver during connection lost to PWS

[Thomas Keffer]

I think I understand what's happening. Your MySQL server is raising error
#2006 ("MySQL server has gone away"), which is *not* recoverable in the
present version of weewx.

Last May, PR #246  was created to
fix this problem, but it has not been released yet.

It's an easy fix. Just replace your copy of weedb/mysql.py with the present
version
.
Let me know if that helps.

-tk

On Fri, Oct 6, 2017 at 10:07 PM, fpb  wrote:

> Hi Tom
>
>   Thank you for the explanation. WeeWx system would run on again due to
> restart if I understand right. Because I don't see any additional messages
> in the log I cann't catch this (might make sense to add some in the future
> release?), anyway when PWS come back online data are not stored in DB. Have
> I any chance to get/trace status where the WeeWx is?
>  My guess is that DB engine is maybe stoped. I made a test and restart
> MySQL when WeeWx run jobs even PWS is online and I got this in log and same
> situation as PWS is offline.
>
> MySQl log:
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> *171007  6:35:13 [Note] /usr/sbin/mysqld: Normal shutdown171007  6:35:13
> [Note] Event Scheduler: Purging the queue. 0 events171007  6:35:15
> [Warning] /usr/sbin/mysqld: Forcing close of thread 21567  user:
> 'mail'171007  6:35:15 [Warning] /usr/sbin/mysqld: Forcing close of thread
> 18190  user: 'weewx'171007  6:35:15 [Warning] /usr/sbin/mysqld: Forcing
> close of thread 18189  user: 'weewx'171007  6:35:15  InnoDB: Starting
> shutdown...171007  6:35:16  InnoDB: Waiting for 113 pages to be
> flushed171007  6:35:17  InnoDB: Shutdown completed; log sequence number
> 17285249150171007  6:35:17 [Note] /usr/sbin/mysqld: Shutdown
> complete171007  6:35:19 [Note] Plugin 'FEDERATED' is disabled.171007
> 6:35:19 InnoDB: The InnoDB memory heap is disabled171007  6:35:19 InnoDB:
> Mutexes and rw_locks use GCC atomic builtins171007  6:35:19 InnoDB:
> Compressed tables use zlib 1.2.8171007  6:35:19 InnoDB: Using Linux native
> AIO171007  6:35:19 InnoDB: Initializing buffer pool, size = 512.0M171007
> 6:35:19 InnoDB: Completed initialization of buffer pool171007  6:35:19
> InnoDB: highest supported file format is Barracuda.171007  6:35:19  InnoDB:
> Waiting for the background threads to start171007  6:35:20 InnoDB: 5.5.57
> started; log sequence number 17285249150171007  6:35:20 [Note] Server
> hostname (bind-address): '127.0.0.1'; port: 3306171007  6:35:20 [Note]   -
> '127.0.0.1' resolves to '127.0.0.1';171007  6:35:20 [Note] Server socket
> created on IP: '127.0.0.1'.171007  6:35:20 [Note] Event Scheduler: Loaded 0
> events171007  6:35:20 [Note] /usr/sbin/mysqld: ready for
> connections.Version: '5.5.57-0+deb8u1-log'  socket:
> '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)*
>
> WeeWx log:
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> *Oct  7 06:35:13 ferda weewx[27420]: cheetahgenerator: Generated 14 files
> for report StandardReport in 1.49 secondsOct  7 06:35:13 ferda
> weewx[27420]: reportengine: Caught unrecoverable exception in generator
> weewx.imagegenerator.ImageGeneratorOct  7 06:35:13 ferda
> weewx[27420]:   (2006, 'MySQL server has gone away')Oct  7
> 06:35:13 ferda weewx[27420]:   Traceback (most recent call
> last):Oct  7 06:35:13 ferda weewx[27420]: File
> "/usr/share/weewx/weewx/reportengine.py", line 239, in runOct  7 06:35:13
> ferda weewx[27420]:   obj.start()Oct  7 06:35:13 ferda
> weewx[27420]: File
> "/usr/share/weewx/weewx/reportengine.py", line 273, in startOct  7 06:35:13
> ferda weewx[27420]:   self.run()Oct  7 06:35:13 ferda
> weewx[27420]: File
> "/usr/share/weewx/weewx/imagegenerator.py", line 31, in runOct  7 06:35:13
> ferda weewx[27420]:   self.genImages(self.gen_ts)Oct  7
> 06:35:13 ferda weewx[27420]: File
> "/usr/share/weewx/weewx/imagegenerator.py", line 141, in genImagesOct  7
> 06:35:13 ferda weewx[27420]: 
> aggregate_interval=aggregate_interval)Oct  7 06:35:13 ferda
> weewx[27420]: File "/usr/share/weewx/weewx/manager.py",
> line 512, in getSqlVectorsOct  7 06:35:13 ferda weewx[27420]:
>   aggregate_type, aggregate_interval)Oct  7 06:35:13 ferda
> weewx[27420]: File "/usr/share/weewx/weewx/manager.py",
> line 758, in _getSqlVectorsOct  7 06:35:13 ferda weewx[27420]:
>   for _rec in _cursor.execute(sql_str, (startstamp,
> stopstamp)):Oct  7 06:35:13 ferda weewx[27420]: File
> "/usr/share/weewx/weedb/mysql.py", line 47, in guarded_fnOct  7 06:35:13
> ferda weewx[27420]:   raise klass(e)Oct  7 06:35:13 ferda
> weewx[27420]:   DatabaseError: (2006, 'MySQL server has gone
> away')Oct  7 06:35:13 ferda weewx[27420]:   Generator

Re: [weewx-development] Correct handling exceptions in driver during connection lost to PWS

[fpb]

Hi Tom 
 
  Thank you for the explanation. WeeWx system would run on again due to 
restart if I understand right. Because I don't see any additional messages 
in the log I cann't catch this (might make sense to add some in the future 
release?), anyway when PWS come back online data are not stored in DB. Have 
I any chance to get/trace status where the WeeWx is?
 My guess is that DB engine is maybe stoped. I made a test and restart 
MySQL when WeeWx run jobs even PWS is online and I got this in log and same 
situation as PWS is offline.

MySQl log:
























*171007  6:35:13 [Note] /usr/sbin/mysqld: Normal shutdown171007  6:35:13 
[Note] Event Scheduler: Purging the queue. 0 events171007  6:35:15 
[Warning] /usr/sbin/mysqld: Forcing close of thread 21567  user: 
'mail'171007  6:35:15 [Warning] /usr/sbin/mysqld: Forcing close of thread 
18190  user: 'weewx'171007  6:35:15 [Warning] /usr/sbin/mysqld: Forcing 
close of thread 18189  user: 'weewx'171007  6:35:15  InnoDB: Starting 
shutdown...171007  6:35:16  InnoDB: Waiting for 113 pages to be 
flushed171007  6:35:17  InnoDB: Shutdown completed; log sequence number 
17285249150171007  6:35:17 [Note] /usr/sbin/mysqld: Shutdown 
complete171007  6:35:19 [Note] Plugin 'FEDERATED' is disabled.171007  
6:35:19 InnoDB: The InnoDB memory heap is disabled171007  6:35:19 InnoDB: 
Mutexes and rw_locks use GCC atomic builtins171007  6:35:19 InnoDB: 
Compressed tables use zlib 1.2.8171007  6:35:19 InnoDB: Using Linux native 
AIO171007  6:35:19 InnoDB: Initializing buffer pool, size = 512.0M171007  
6:35:19 InnoDB: Completed initialization of buffer pool171007  6:35:19 
InnoDB: highest supported file format is Barracuda.171007  6:35:19  InnoDB: 
Waiting for the background threads to start171007  6:35:20 InnoDB: 5.5.57 
started; log sequence number 17285249150171007  6:35:20 [Note] Server 
hostname (bind-address): '127.0.0.1'; port: 3306171007  6:35:20 [Note]   - 
'127.0.0.1' resolves to '127.0.0.1';171007  6:35:20 [Note] Server socket 
created on IP: '127.0.0.1'.171007  6:35:20 [Note] Event Scheduler: Loaded 0 
events171007  6:35:20 [Note] /usr/sbin/mysqld: ready for 
connections.Version: '5.5.57-0+deb8u1-log'  socket: 
'/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)*

WeeWx log:












































*Oct  7 06:35:13 ferda weewx[27420]: cheetahgenerator: Generated 14 files 
for report StandardReport in 1.49 secondsOct  7 06:35:13 ferda 
weewx[27420]: reportengine: Caught unrecoverable exception in generator 
weewx.imagegenerator.ImageGeneratorOct  7 06:35:13 ferda 
weewx[27420]:   (2006, 'MySQL server has gone away')Oct  7 
06:35:13 ferda weewx[27420]:   Traceback (most recent call 
last):Oct  7 06:35:13 ferda weewx[27420]: File 
"/usr/share/weewx/weewx/reportengine.py", line 239, in runOct  7 06:35:13 
ferda weewx[27420]:   obj.start()Oct  7 06:35:13 ferda 
weewx[27420]: File 
"/usr/share/weewx/weewx/reportengine.py", line 273, in startOct  7 06:35:13 
ferda weewx[27420]:   self.run()Oct  7 06:35:13 ferda 
weewx[27420]: File 
"/usr/share/weewx/weewx/imagegenerator.py", line 31, in runOct  7 06:35:13 
ferda weewx[27420]:   self.genImages(self.gen_ts)Oct  7 
06:35:13 ferda weewx[27420]: File 
"/usr/share/weewx/weewx/imagegenerator.py", line 141, in genImagesOct  7 
06:35:13 ferda weewx[27420]:   
aggregate_interval=aggregate_interval)Oct  7 06:35:13 ferda 
weewx[27420]: File "/usr/share/weewx/weewx/manager.py", 
line 512, in getSqlVectorsOct  7 06:35:13 ferda weewx[27420]: 
  aggregate_type, aggregate_interval)Oct  7 06:35:13 ferda 
weewx[27420]: File "/usr/share/weewx/weewx/manager.py", 
line 758, in _getSqlVectorsOct  7 06:35:13 ferda weewx[27420]: 
  for _rec in _cursor.execute(sql_str, (startstamp, 
stopstamp)):Oct  7 06:35:13 ferda weewx[27420]: File 
"/usr/share/weewx/weedb/mysql.py", line 47, in guarded_fnOct  7 06:35:13 
ferda weewx[27420]:   raise klass(e)Oct  7 06:35:13 ferda 
weewx[27420]:   DatabaseError: (2006, 'MySQL server has gone 
away')Oct  7 06:35:13 ferda weewx[27420]:   Generator 
terminatedOct  7 06:35:13 ferda weewx[27420]: copygenerator: copied 0 files 
to /home/www/weewxOct  7 06:36:12 ferda weewx[27420]: engine: Shutting down 
StdReport threadOct  7 06:36:12 ferda weewx[27420]: engine: Caught 
unrecoverable exception in engine:Oct  7 06:36:12 ferda weewx[27420]: 
  (2006, 'MySQL server has gone away')Oct  7 06:36:12 ferda 
weewx[27420]:   Traceback (most recent call last):Oct  7 06:36:12 
ferda weewx[27420]: File "/usr/share/weewx/weewx/engine.py", 
line 871, in mainOct  7 06:36:12 ferda weewx[27420]:   
engine.run()Oct  7 06:36:12 ferda weewx[27420]: File 

Re: [weewx-development] Correct handling exceptions in driver during connection lost to PWS

[Thomas Keffer]

Any number of errors will cause WeeWX to "start from the top," that is,
essentially, reboot the internal engine. One such error is a database
error. Part of the rebooting process is to kill the reporting thread.

So, my guess is that your MySQL database went offline for some reason. This
caused the internal engine to kill the reporting thread, then do a restart.

I don't know why your MySQL database went offline --- you'll have to search
for clues elsewhere. Try its error log (found in /var/log/mysql for Debian
systems). For systemd versions you can try "journalctl -u mysql" for clues.

-tk

On Thu, Oct 5, 2017 at 11:13 AM, fpb  wrote:

> Hi All.
>
>   I am sorry for this question, but I am stuck in solving this problem.
>
>   I had been written driver for my IP and XML based PWS. Due to some
> troubles in my network I am loosing  connection to PWS.
>
>   I tried to manage this situation with goal "When PWS is back online all
> data will be stored to WEEWX without user action."
>   Driver using GenArchiveRecords since from first version witht correct
> management of missing data (TS_SINCE), but there was not done any better
> exception handling. I have been tried add exception handling described in
> docs and examples, but I am stuck in this situation, that "engine: Shutting
> down StdReport thread" comming and I do not have any real idea why. My
> guess is because of MySQL DB has closed session and can not be reconnected.
>
>   Can give me somebody some hints, how to handle exceptions for lost
> connections to PWS, that it will continue grab data from PWS when it come
> back online (grabing from first missing data works correctly)?
>
> Thank you anybody who can help me to understand and tips how to handle it.
>
>
>
>  Below is last part of log. First part is my driver handling of lost
> connection, then after more then 2 days engine come with StdReport + MySQL
> exception. Behavior is that some times fails in 1 day somtimes in 2 or 3
> days.
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> *LOG:Oct  3 7:06:15 ferda weewx[7865]: wanet3: from
> http://me13.lbn.cz/xml.xml  download failed
> attempt 1: 5  .  . . Oct  5 18:38:59 ferda
> weewx[7865]: wanet3: from http://me13.lbn.cz/xml.xml
>  download failed attempt 1: 5  timed out>Oct  5 18:39:39 ferda weewx[7865]: wanet3: from
> http://me13.lbn.cz/xml.xml  download failed
> attempt 2: 5 Oct  5 18:40:19 ferda weewx[7865]:
> wanet3: from http://me13.lbn.cz/xml.xml 
> download failed attempt 3: 5 Oct  5 18:40:59 ferda
> weewx[7865]: wanet3: from http://me13.lbn.cz/xml.xml
>  download failed attempt 4: 5  timed out>Oct  5 18:41:40 ferda weewx[7865]: wanet3: from
> http://me13.lbn.cz/xml.xml  download failed
> attempt 5: 5 Oct  5 18:42:10 ferda weewx[7865]:
> wanet3: download failed after 5 triesOct  5 18:43:20 ferda weewx[7865]:
> wanet3: from http://me13.lbn.cz/xml.xml 
> download failed attempt 1: 5 Oct  5 18:44:00 ferda
> weewx[7865]: wanet3: from http://me13.lbn.cz/xml.xml
>  download failed attempt 2: 5  timed out>Oct  5 18:44:40 ferda weewx[7865]: wanet3: from
> http://me13.lbn.cz/xml.xml  download failed
> attempt 3: 5 Oct  5 18:45:20 ferda weewx[7865]:
> wanet3: from http://me13.lbn.cz/xml.xml 
> download failed attempt 4: 5 Oct  5 18:46:00 ferda
> weewx[7865]: wanet3: from http://me13.lbn.cz/xml.xml
>  download failed attempt 5: 5  timed out>Oct  5 18:46:30 ferda weewx[7865]: wanet3: download failed after
> 5 triesOct  5 18:47:30 ferda weewx[7865]: engine: Shutting down StdReport
> threadOct  5 18:47:30 ferda weewx[7865]: engine: Caught unrecoverable
> exception in engine:Oct  5 18:47:30 ferda weewx[7865]:   (2006,
> 'MySQL server has gone away')Oct  5 18:47:30 ferda weewx[7865]: 
> Traceback (most recent call last):Oct  5 18:47:30 ferda weewx[7865]:
> File "/usr/share/weewx/weewx/engine.py", line 871, in mainOct  5
> 18:47:30 ferda weewx[7865]:   engine.run()Oct  5 18:47:30 ferda
> weewx[7865]: File "/usr/share/weewx/weewx/engine.py", line 190,
> in runOct  5 18:47:30 ferda weewx[7865]: 
> self.dispatchEvent(weewx.Event(weewx.NEW_LOOP_PACKET, packet=packet))Oct  5
> 18:47:30 ferda weewx[7865]: File
> "/usr/share/weewx/weewx/engine.py", line 223, in dispatchEventOct  5
> 18:47:30 ferda weewx[7865]:   callback(event)Oct  5 18:47:30
> ferda weewx[7865]: File "/usr/share/weewx/weewx/wxservices.py",
> line 45, in new_loop_packetOct  5 18:47:30 ferda weewx[7865]: 
> self.calc.do_calculations(event.packet, 'loop')Oct  5 18:47:30 ferda
> weewx[7865]: File