The debug option tells the system to "log up to" syslog.DEBUG, instead of the default. So, more information is kept in the log. I don't have a Raspbian machine around me right now, but I would be surprised if it changed the destination.
In any case, it's a better idea to look at /var/log/syslog, as it has both system and weewx messages, making it easy to correlate the two. -tk On Fri, Dec 27, 2019 at 1:54 AM Franklin Bockstael <[email protected]> wrote: > As asked earlier in this thread I changed debug=0 to debug=1 in > weewx..conf. From then it started to log to /var/log/weewx.log. > I thought this was the normal behaviour? Before, when debug=0, it all was > logged to /var/log/syslog. > I am a bit confused now on what to show you here from what logfile. > > Op donderdag 26 december 2019 23:34:19 UTC+1 schreef Thomas Keffer: >> >> 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/64fa6bcf-4542-4e9b-ab6d-546090904d02%40googlegroups.com > <https://groups.google.com/d/msgid/weewx-user/64fa6bcf-4542-4e9b-ab6d-546090904d02%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/CAPq0zECis2x3bD%2BmTEw4idhyhxZyLU1XvCan6e_iqCqK%2Bib6eA%40mail.gmail.com.
