It looks to me that neither of these last two log excerpts correspond with the earlier ones you posted. The first is the wrong date (the crash happened on the 24th, not the 25th), and the second is too early in the day.
I'm surprised you are not seeing weewx entries in /var/log/syslog. Did you change the logging in any way? I should add that I am traveling, so I do not have an RPi available to remind me of what gets logged where. -tk On Thu, Dec 26, 2019 at 8:37 AM Franklin Bockstael <[email protected]> wrote: > Hi Thomas. > > We are looking at /var/log/weewx.log > This is the output of /var/log/syslog around the time of the first error > > Dec 25 17:11:51 Grandix rngd[526]: stats: entropy added to kernel pool: > 724608 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2 successes: 39 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2 failures: 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2(2001-10-10) Monobit: 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2(2001-10-10) Poker: 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2(2001-10-10) Runs: 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2(2001-10-10) Long run: > 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS 140-2(2001-10-10) > Continuous run: 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: HRNG source speed: (min=86.238; > avg=499.925; max=835.776)Kibits/s > Dec 25 17:11:51 Grandix rngd[526]: stats: FIPS tests speed: (min=1.401; > avg=4.988; max=6.191)Mibits/s > Dec 25 17:11:51 Grandix rngd[526]: stats: Lowest ready-buffers level: 2 > Dec 25 17:11:51 Grandix rngd[526]: stats: Entropy starvations: 0 > Dec 25 17:11:51 Grandix rngd[526]: stats: Time spent starving for entropy: > (min=0; avg=0.000; max=0)us > Dec 25 17:15:01 Grandix CRON[13002]: (pi) CMD (/home/pi/upload > /dev/null) > Dec 25 17:15:01 Grandix CRON[13003]: (pi) CMD (/home/pi/launch.sh) > Dec 25 17:15:01 Grandix CRON[12994]: (CRON) info (No MTA installed, > discarding output) > Dec 25 17:17:01 Grandix CRON[13028]: (root) CMD ( cd / && run-parts > --report /etc/cron.hourly) > Dec 25 17:20:01 Grandix CRON[13046]: (pi) CMD (/home/pi/launch.sh) > Dec 25 17:20:01 Grandix CRON[13047]: (pi) CMD (/home/pi/upload > /dev/null) > Dec 25 17:20:01 Grandix CRON[13038]: (CRON) info (No MTA installed, > discarding output) > > > And on the time of the second error > > Dec 25 22:15:02 Grandix CRON[14832]: (pi) CMD (/home/pi/launch.sh) > Dec 25 22:15:02 Grandix CRON[14833]: (pi) CMD (/home/pi/upload > /dev/null) > Dec 25 22:15:02 Grandix CRON[14823]: (CRON) info (No MTA installed, > discarding output) > Dec 25 22:17:01 Grandix CRON[14855]: (root) CMD ( cd / && run-parts > --report /etc/cron.hourly) > Dec 25 22:20:01 Grandix CRON[14874]: (pi) CMD (/home/pi/upload > /dev/null) > Dec 25 22:20:01 Grandix CRON[14877]: (pi) CMD (/home/pi/launch.sh) > Dec 25 22:20:01 Grandix CRON[14866]: (CRON) info (No MTA installed, > discarding output) > Dec 25 22:22:30 Grandix kernel: [ 0.000000] Booting Linux on physical > CPU 0x0 > Dec 25 22:22:30 Grandix fake-hwclock[82]: Wed 25 Dec 21:17:01 UTC 2019 > > > The fake-hwclock is giving a time of 21:17:01 wich should be 21:22:30. > This is more than 300 seconds difference (the time between 2 messages from > the Vantage console?). Am I very wrong if Isuspect this is the thing that > is giving me those errors and freezes? > > Several pid on startup is caused by me rebooting manually the RPi but in > the log I sometimes find multiple instances of weewx or a new instance with > aother pid. > The question is why the RPi is thinking it should start a new weewx > process. > I looked at top and there is nothing abnormal there. Just one process of > weewx and no abnormal load. Weewx is the only process that is running on > that RPi. > What I see with that strange thing is the dates of occuring and the > timestamp that is mentioned in the log. > > Op donderdag 26 december 2019 13:22:38 UTC+1 schreef Thomas Keffer: >> >> Could be a systemd issue. Perhaps your RPi was low on memory, and systemd >> had to kill weewxd? >> >> Things to try: >> 1. Which log are we looking at here? If it's a systemd issue, it should >> have told us that it is killing a process. But, not all logs show all >> messages, so it's possible that the systemd messages are ending up >> someplace else. >> 2. There are several process IDs appearing on start up. Double check that >> only one instance of weewxd is running. >> 3. Using a tool such as "top", check the amount of memory that's >> available. Do you have other things besides weewxd running? >> 4. The "strange things happening with strange timestamps" looks normal to >> me. What is catching your eye here? >> >> -tk >> >> On Thu, Dec 26, 2019 at 2:35 AM Franklin Bockstael <[email protected]> >> wrote: >> >>> >>> 1. I obeserved this until now and had some time without errors. But >>> suddenly on Christmas Eve there they were again. The system is installed >>> on >>> a fresh SANDISK sd-card with latest weewx on a RPi B. In my log file I >>> find >>> this: >>> >>> Dec 24 17:15:22 Grandix weewx[629]: cheetahgenerator: Generated 2 files >>> for report StandardReport in 2.10 seconds >>> Dec 24 17:15:22 Grandix weewx[629]: reportengine: Running report 'FTP' >>> Dec 24 17:15:22 Grandix weewx[629]: reportengine: Found configuration >>> file /home/weewx/skins/Ftp/skin.conf for report 'FTP' >>> Dec 24 17:15:22 Grandix weewx[629]: ftpupload: Attempting connection to >>> grandix.nl >>> Dec 24 17:15:22 Grandix weewx[629]: ftpupload: Connected to grandix.nl >>> Dec 24 17:15:22 Grandix weewx[629]: ftpupload: Uploaded file >>> /grandixweerdata.htm >>> Dec 24 17:15:22 Grandix weewx[629]: ftpupload: Uploaded file >>> /openweerdata.htm >>> Dec 24 17:15:22 Grandix weewx[629]: ftpgenerator: ftp'd 2 files in 0.33 >>> seconds >>> Dec 24 17:15:22 Grandix weewx[629]: reportengine: Report 'RSYNC' not >>> enabled. Skipping. >>> Dec 24 17:18:08 Grandix weewx[629]: engine: Received signal TERM (15). >>> Dec 24 17:18:08 Grandix weewx[629]: engine: Main loop exiting. Shutting >>> engine down. >>> Dec 24 17:18:08 Grandix weewx[629]: engine: Shutting down StdReport >>> thread >>> Dec 24 17:18:08 Grandix weewx[629]: engine: StdReport thread has been >>> terminated >>> Dec 24 17:18:08 Grandix weewx[629]: restx: Shut down AWEKAS thread. >>> Dec 24 17:18:08 Grandix weewx[629]: restx: Shut down WOW thread. >>> Dec 24 17:18:08 Grandix weewx[629]: restx: Shut down CWOP thread. >>> Dec 24 17:18:08 Grandix weewx[629]: restx: Shut down PWSWeather thread. >>> Dec 24 17:18:08 Grandix weewx[629]: restx: Shut down Wunderground-PWS >>> thread. >>> Dec 24 17:18:08 Grandix weewx[629]: engine: Terminating weewx version >>> 3.9.2 >>> Dec 24 17:18:08 Grandix weewx[629]: **** Traceback (most recent >>> call last): >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 894, in main >>> Dec 24 17:18:08 Grandix weewx[629]: **** engine.run() >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 188, in run >>> Dec 24 17:18:08 Grandix weewx[629]: **** for packet in >>> self.console.genLoopPackets(): >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/home/weewx/bin/weewx/drivers/vantage.py", line 508, in genLoopPackets >>> Dec 24 17:18:08 Grandix weewx[629]: **** for _loop_packet in >>> self.genDavisLoopPackets(200): >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/home/weewx/bin/weewx/drivers/vantage.py", line 535, in genDavisLoopPackets >>> Dec 24 17:18:08 Grandix weewx[629]: **** _buffer = >>> self.port.read(99) >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/home/weewx/bin/weewx/drivers/vantage.py", line 256, in read >>> Dec 24 17:18:08 Grandix weewx[629]: **** _buffer = >>> self.serial_port.read(chars) >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/usr/lib/python2.7/dist-packages/serial/serialposix.py", line 472, in read >>> Dec 24 17:18:08 Grandix weewx[629]: **** ready, _, _ = >>> select.select([self.fd, self.pipe_abort_read_r], [], [], >>> timeout.time_left()) >>> Dec 24 17:18:08 Grandix weewx[629]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 812, in sigTERMhandler >>> Dec 24 17:18:08 Grandix weewx[629]: **** raise Terminate >>> Dec 24 17:18:08 Grandix weewx[629]: **** Terminate >>> Dec 24 17:18:14 Grandix weewx[750]: Stopping weewx weather system: >>> weewx.. >>> Dec 24 17:18:15 Grandix weewx[792]: engine: Initializing weewx version >>> 3.9.2 >>> Dec 24 17:18:15 Grandix weewx[792]: engine: Using Python 2.7.13 >>> (default, Sep 26 2018, 18:42:22) #012[GCC 6.3.0 20170516] >>> Dec 24 17:18:15 Grandix weewx[792]: engine: Platform >>> Linux-4.19.66+-armv6l-with-debian-9.9 >>> Dec 24 17:18:15 Grandix weewx[792]: engine: Locale is 'en_GB.UTF-8' >>> Dec 24 17:18:15 Grandix weewx[792]: engine: pid file is >>> /var/run/weewx.pid >>> Dec 24 17:18:16 Grandix weewx[781]: Starting weewx weather system: weewx. >>> >>> >>> And on Christmas Dayon 22:20again, this time out of the blue: >>> >>> Dec 25 22:20:28 Grandix weewx[796]: ftpupload: Uploaded file >>> /openweerdata.htm >>> Dec 25 22:20:28 Grandix weewx[796]: ftpgenerator: ftp'd 2 files in 0.34 >>> seconds >>> Dec 25 22:20:28 Grandix weewx[796]: reportengine: Report 'RSYNC' not >>> enabled. Skipping. >>> Dec 25 22:20:35 Grandix weewx[796]: restx: WOW: Failed upload attempt 1: >>> timed out >>> Dec 25 22:20:40 Grandix weewx[796]: restx: WOW: Failed upload attempt 2: >>> HTTP Error 429: Too frequent observations. >>> Dec 25 22:20:45 Grandix weewx[796]: restx: WOW: Failed upload attempt 3: >>> HTTP Error 429: Too frequent observations. >>> Dec 25 22:20:50 Grandix weewx[796]: restx: WOW: Failed to publish record >>> 2019-12-25 22:20:00 CET (1577308800): Failed upload after 3 tries >>> Dec 25 22:23:01 Grandix weewx[574]: engine: Initializing weewx version >>> 3.9.2 >>> Dec 25 22:23:01 Grandix weewx[574]: engine: Using Python 2.7.13 >>> (default, Sep 26 2018, 18:42:22) #012[GCC 6.3.0 20170516] >>> Dec 25 22:23:01 Grandix weewx[574]: engine: Platform >>> Linux-4.19.66+-armv6l-with-debian-9.11 >>> >>> >>> Later that evening: >>> >>> Dec 25 23:18:01 Grandix weewx[594]: restx: Unable to shut down WOW thread >>> Dec 25 23:18:01 Grandix weewx[594]: restx: Shut down CWOP thread. >>> Dec 25 23:18:01 Grandix weewx[594]: restx: Shut down PWSWeather thread. >>> Dec 25 23:18:01 Grandix weewx[594]: restx: Shut down Wunderground-PWS >>> thread. >>> Dec 25 23:18:01 Grandix weewx[594]: engine: Terminating weewx version >>> 3.9.2 >>> Dec 25 23:18:01 Grandix weewx[594]: **** Traceback (most recent >>> call last): >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 894, in main >>> Dec 25 23:18:01 Grandix weewx[594]: **** engine.run() >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 191, in run >>> Dec 25 23:18:01 Grandix weewx[594]: **** >>> self.dispatchEvent(weewx.Event(weewx.NEW_LOOP_PACKET, packet=packet)) >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 224, in dispatchEvent >>> Dec 25 23:18:01 Grandix weewx[594]: **** callback(event) >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 546, in new_loop_packet >>> Dec 25 23:18:01 Grandix weewx[594]: **** >>> self.accumulator.addRecord(event.packet, add_hilo=self.loop_hilo) >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/accum.py", line 260, in addRecord >>> Dec 25 23:18:01 Grandix weewx[594]: **** func(self, record, >>> obs_type, add_hilo, weight) >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/accum.py", line 319, in add_value >>> Dec 25 23:18:01 Grandix weewx[594]: **** >>> self[obs_type].addSum(val, weight=weight) >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/accum.py", line 96, in addSum >>> Dec 25 23:18:01 Grandix weewx[594]: **** self.sum += val >>> Dec 25 23:18:01 Grandix weewx[594]: **** File >>> "/home/weewx/bin/weewx/engine.py", line 812, in sigTERMhandler >>> Dec 25 23:18:01 Grandix weewx[594]: **** raise Terminate >>> Dec 25 23:18:01 Grandix weewx[594]: **** Terminate >>> Dec 25 23:18:02 Grandix weewx[653]: Stopping weewx weather system: >>> weewx..... >>> Dec 25 23:18:04 Grandix weewx[730]: engine: Initializing weewx version >>> 3.9.2 >>> Dec 25 23:18:04 Grandix weewx[730]: engine: Using Python 2.7.13 >>> (default, Sep 26 2018, 18:42:22) #012[GCC 6.3.0 20170516] >>> Dec 25 23:18:04 Grandix weewx[730]: engine: Platform >>> Linux-4.19.66+-armv6l-with-debian-9.11 >>> Dec 25 23:18:04 Grandix weewx[730]: engine: Locale is 'en_GB.UTF-8' >>> Dec 25 23:18:04 Grandix weewx[730]: engine: pid file is >>> /var/run/weewx.pid >>> Dec 25 23:18:04 Grandix weewx[719]: Starting weewx weather system: weewx. >>> Dec 25 23:18:05 Grandix weewx[734]: engine: Using configuration file >>> /home/weewx/weewx.conf >>> Dec 25 23:18:05 Grandix weewx[734]: engine: Debug is 1 >>> Dec 25 23:18:05 Grandix weewx[734]: engine: Initializing engine >>> >>> >>> >>> When the second process weewx starts the RPi cuts off all posibility to >>> connect to it via ssh and cannot ping the RPi. So I have to reboot the RPi, >>> restart the weewx process again and then everything is running ok for some >>> time (longer or shorter). I ordered a hardware RTC but did not receive it >>> yet. >>> What I can't understand is that it worked flawless for years and >>> suddenly it is giving me all these trouble I don't understand. >>> What can I do more? >>> >>> Another issue in the log files I can't explain is this: >>> Dec 24 23:30:20 Grandix weewx[796]: vantage: DMPAFT complete: page >>> timestamp 2019-12-16 02:15:00 CET (1576458900) less than final timestamp >>> 2019-12-24 23:30:00 CET (1577226600) >>> Dec 24 23:30:20 Grandix weewx[796]: vantage: Catch up complete. >>> Dec 24 23:30:20 Grandix weewx[796]: vantage: Requesting 200 LOOP packets. >>> Dec 24 23:30:20 Grandix weewx[796]: vantage: Gentle wake up of console >>> successful >>> >>> >>> Why is this strange thing happening with strange timestamps? >>> >>> >>> >>> >>> Op maandag 4 november 2019 16:10:43 UTC+1 schreef vince: >>>> >>>> On Monday, November 4, 2019 at 1:35:30 AM UTC-8, Franklin Bockstael >>>> wrote: >>>> >>>>> The uptime is not so important I guess. Everytime this error occurs >>>>> the pi becomes unresponsive and I have to reboot. Iti s not a real long >>>>> time that it is on because this happens sometimes twice a day and then not >>>>> for a few weeks. >>>>> >>>> >>>> You're not telling us what 'unresponsive' means. Can you ping it ? >>>> >>>> A pi that is unresponsive over wifi, especially a model-B, is typically >>>> it losing its wifi connection if you have an after-market wifi dongle >>>> plugged into USB. I used to see that frequently years ago on my model-B >>>> cards before I got a much more powerful wifi access point. >>>> >>>> I turned on debug now and restarted weewx. I have to wait till this >>>>> happens again. >>>>> >>>>> >>>> That is always the next step. >>>> >>>> You're not giving us enough information to help much here. You could >>>> be out of ram. You could have a SD card that is throwing errors. You >>>> could have poor power on the pi. Far too many possibilities with no real >>>> data from you that we can go on. >>>> >>> -- >>> 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 [email protected]. >>> To view this discussion on the web visit >>> https://groups.google.com/d/msgid/weewx-user/cfb9d670-22ae-4e34-9e61-b2173cf6cc35%40googlegroups.com >>> <https://groups.google.com/d/msgid/weewx-user/cfb9d670-22ae-4e34-9e61-b2173cf6cc35%40googlegroups.com?utm_medium=email&utm_source=footer> >>> . >>> >> -- > 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 [email protected]. > To view this discussion on the web visit > https://groups.google.com/d/msgid/weewx-user/ea648256-3906-4bc0-8ee2-5580ae9509b7%40googlegroups.com > <https://groups.google.com/d/msgid/weewx-user/ea648256-3906-4bc0-8ee2-5580ae9509b7%40googlegroups.com?utm_medium=email&utm_source=footer> > . > -- 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 [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-user/CAPq0zEBzOUc7AkeOT82pfncac-hQw5bHjG5jAsSR%2BGZnvYzmzA%40mail.gmail.com.
