weewx 4.0 doesnt do a clean exit

[Cat22]

I noticed that whenever i stop weewx (under systemd - systemctl stop weewx) it stops with an error. how do we fix this? Its not hurting anything but it seems weewx ought to be able to exit gracefully.

weewxd[22586]: LOOP:   2020-05-09 01:54:10 PDT (1589014450) altimeter: 29.9989454584283, appTemp: 54.97090145017383, barometer: 29.992, beaufort: 0, cloudbase: 2556.1648670782447, consBatter>etc
weewxd[22586]: LOOP:   2020-05-09 01:54:12 PDT (1589014452) altimeter: 29.9989454584283, appTemp: 54.97090145017383, barometer: 29.992, beaufort: 0, cloudbase: 2556.1648670782447, consBatter>etc
python[22586]: weewx[22586] INFO __main__: Received signal TERM (15).
python[22586]: weewx[22586] INFO weewx.engine: Main loop exiting. Shutting engine down.
python[22586]: weewx[22586] INFO weewx.engine: Shutting down StdReport thread
python[22586]: weewx[22586] DEBUG weewx.engine: StdReport thread has been terminated
python[22586]: weewx[22586] DEBUG weewx.restx: Shut down CWOP thread.
python[22586]: weewx[22586] DEBUG weewx.restx: Shut down Wunderground-PWS thread.
python[22586]: weewx[22586] INFO __main__: Terminating weewx version 4.0.0
python[22586]: weewx[22586] INFO __main__:     ****  Traceback (most recent call last):
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewxd", line 154, in main
python[22586]: weewx[22586] INFO __main__:     ****      engine.run()
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewx/engine.py", line 188, in run
python[22586]: weewx[22586] INFO __main__:     ****      for packet in self.console.genLoopPackets():
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewx/drivers/vantage.py", line 532, in genLoopPackets
python[22586]: weewx[22586] INFO __main__:     ****      for _loop_packet in self.genDavisLoopPackets(200):
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewx/drivers/vantage.py", line 559, in genDavisLoopPackets
python[22586]: weewx[22586] INFO __main__:     ****      loop_packet = self._get_packet()
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewx/drivers/vantage.py", line 572, in _get_packet
python[22586]: weewx[22586] INFO __main__:     ****      _buffer = self.port.read(99)
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewx/drivers/vantage.py", line 279, in read
python[22586]: weewx[22586] INFO __main__:     ****      _buffer = self.serial_port.read(chars)
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/lib/python3.8/site-packages/serial/serialposix.py", line 482, in read
python[22586]: weewx[22586] INFO __main__:     ****      ready, _, _ = select.select([self.fd, self.pipe_abort_read_r], [], [], timeout.time_left())
python[22586]: weewx[22586] INFO __main__:     ****    File "/usr/local/bin/weewx/bin/weewxd", line 257, in sigTERMhandler
python[22586]: weewx[22586] INFO __main__:     ****      raise Terminate
python[22586]: weewx[22586] INFO __main__:     ****  Terminate
weewxd[22586]: LOOP:   2020-05-09 01:54:14 PDT (1589014454) altimeter: 29.9989454584283, appTemp: 54.97090145017383, barometer: 29.992, beaufort: 0, cloudbase: 2556.1648670782447, consBatter>etc

[gjr80]

Not sure I see an error there, just a copy of the stack trace.

Gary

[Vince Skahan]

On Saturday, May 9, 2020 at 2:14:13 AM UTC-7, gjr80 wrote:

Not sure I see an error there, just a copy of the stack trace.

I've seen that as well repeatedly.

Try to do a "systemctl stop weewx" or "systemctl restart weewx" and it's pretty ugly in syslog.  Ideally it would look like a clean shutdown ala the v3 behavior.

 

[John Kline]

The stack trace when exiting is intentional.

bin/weewxd:

        except Terminate:

            log.info("Terminating weewx version %s", weewx.__version__)

            weeutil.logger.log_traceback(log.info, "    ****  ")

            signal.signal(signal.SIGTERM, signal.SIG_DFL)

            os.kill(0, signal.SIGTERM)

On May 9, 2020, at 7:45 AM, Vince Skahan <vince...@gmail.com> wrote:



--
You received this message because you are subscribed to the Google Groups "weewx-development" group.
To unsubscribe from this group and stop receiving emails from it, send an email to weewx-developm...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-development/318d8403-2a3d-4a00-a302-bc1b44ccfcbe%40googlegroups.com.

[Bill Richter]

I agree, that it's ugly.  A normal shutdown should not have a stacktrace.  But wouldn't a simple fix be:

        except Terminate:

            log.info("Terminating weewx version %s", weewx.__version__)

            if weewx.debug >= 2:

                    weeutil.logger.log_traceback(log.info, "    ****  ")

            signal.signal(signal.SIGTERM, signal.SIG_DFL)

            os.kill(0, signal.SIGTERM)

 

I didn't know that the config debug option had more choices that just 1.  I didn't see that ability defined in the V4 documentation. The user guide merely says debug = 1.  I'm guessing that it could be debug = 0|1|2...  I moved from FreeBSD to Raspbian cause of logging support in V4.  I want to use the application not learn it's internals.

[John Kline]

I can’t figure out why you care about this.  It does reveal what was happening on the thread when WeeWX was shut down.  While usually not interesting, sometimes it might be useful.

On May 9, 2020, at 10:36 AM, Bill Richter <bill.g...@gmail.com> wrote:



--

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

To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-development/b11c4670-f8e8-4bd6-aac4-17be3110f267%40googlegroups.com.

[Bill Richter]

I prefer the old behavior on shutdown.  A normal exit status shouldn't prompt a trace.  That's why the debug option exists.  It's the same reason I don't generally want to see Linux core dumps.  I can't fix the kernel.  But I have the option to turn it off or on. It makes systemctl status weewx have nice output.  I don't want to have the patch the source myself. Hence the suggested change.  A better solution might be an config file option traceback_on_exit = NO|yes or YES|no. 

I switched from using my preferred FreeBSD OS to using Raspbian due to the changes in logging.  Irritated that not all the extensions followed the same feature upgrade.  The change to logging made sense.  I am not python savvy enough to provide patches to make FreeBSD work with V4, it wasn't a mainstream support O/S for weewx.  I tracked the V4 BETA stuff for a while, but again realized, I don't want to know how the application works enough to patch I just want to use it. 

As a user, many of whom don't like change, I prefer the old way, the 'expected' way an application closes in a normal fashion.  With suggestions for providing the 'old' way if that way was easy to implement. I figured I'd cast my vote otherwise no one would know.  

Now, I have to patch the source on each upgrade to restore the old behavior. 

[Vince Skahan]

On Saturday, May 9, 2020 at 11:31:12 AM UTC-7, John Kline wrote:

I can’t figure out why you care about this.  It does reveal what was happening on the thread when WeeWX was shut down.  While usually not interesting, sometimes it might be useful.

Because it is inherently confusing to see a stack trace in your syslog if that is 'normal' behavior.  Others have already reported the same thing and show pretty clearly to me that this is confusing multiple people.

I would agree that it's also useful sometimes.  Just not always.

Personally, I like the suggested patch if it works.   If you dial up debugging see more information.  If you run typical debug=1 information (ie, monitor normal operation) this one probably shouldn't be visible for a normal stop/restart that folks do all the time.

[gjr80]

I suggest we all calm down and wait to hear from Tom, there was a pre-3.9.2 commit that solely changed the terminate stacktrace from debug to info log output. But it appeared as debug output in 3.9.2. There is also a couple of seemingly unexplained changes (I can’t find the commit) between 3.9.2 and 4.0.0. Added to the mix is the significant refactoring of code in engine.py that resulted in a lot of code being moved to weewxd plus the change from the syslog package to the logging package.

Bottom line is it is cosmetic only and does not require anyone to do/fix anything.

Gary

[Tom Keffer]

Commit 69a37cb changes it back to V3.x behavior.

-tk

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

To view this discussion on the web visit https://groups.google.com/d/msgid/weewx-development/2b126fee-159c-450a-a22d-81f876103903%40googlegroups.com.

[Cat22]

I think you need more than just the conditional  (weewx.debug>=2) around the stack trace.

I played with that and while it works ok, the systemd log will show that weewx exited but then

ran a few more loops. In other words its out of order, so a user looking at the log wonders "?what?"

It seems to me that weewxd.py ought to set a global exit flag and wait a bit for drivers, engine etc

to return and then exit via a simple return statement. I'm not a python person but thats the general

gist of my idea.