weewx doesn't start automatically after reboot

[bgra...@umw.edu]

Hello,

I've about finished moving weewx to a new computer and from debian to Ubuntu. Everything seems to be working correctly except the auto restart after reboot. I can stop/start/restart from the service or init.d commands and all works correctly. There is something incorrect with my configuration for startup. Here are some log messages:

After computer reboot weewx fails to start:
root@nuc:~# service weewx status
? weewx.service - weewx weather system
   Loaded: loaded (/etc/systemd/system/weewx.service; disabled; vendor preset: enabled)
   Active: inactive (dead)
+++++++++++++++++++++++++++++++++++++++

Manual restart of weewx service:
root@nuc:~# service weewx restart
root@nuc:~# service weewx status
? weewx.service - weewx weather system
   Loaded: loaded (/etc/systemd/system/weewx.service; disabled; vendor preset: enabled)
   Active: active (running) since Wed 2017-03-22 10:11:05 EDT; 7s ago
 Main PID: 2398 (weewxd)
   CGroup: /system.slice/weewx.service
           mq2398 /usr/bin/python /home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf

+++++++++++++++++++++++++++++++++++++++

Manual stop/start from init.d:
root@nuc:/etc/init.d# ./weewx stop
[ ok ] Stopping weewx (via systemctl): weewx.service.
root@nuc:/etc/init.d# ./weewx start
[ ok ] Starting weewx (via systemctl): weewx.service.
root@nuc:/etc/init.d# ./weewx status
? weewx.service - weewx weather system
   Loaded: loaded (/etc/systemd/system/weewx.service; disabled; vendor preset: enabled)
   Active: active (running) since Wed 2017-03-22 10:13:08 EDT; 13s ago
 Main PID: 2491 (weewxd)
   CGroup: /system.slice/weewx.service
           mq2491 /usr/bin/python /home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf

Any suggestions will be appreciated.  Thanks in advance.

Bob

[Andrew Milner]

what does the weewx log say??  is weewx waiting for the time to be set correctly, or a network to be available perhaps??  The key should lie in the weewx log (or/and system startup log - syslog)

[bgra...@umw.edu]

Andrew,

I rebooted with debug on weewx and nothing showed up in syslog or weewx.log. I searched around for the "(/etc/systemd/system/weewx.service; disabled; vendor preset: enabled)" message and tried the command "systemctl enable weewx." The result after reboot was this:

root@nuc:~# service weewx status
? weewx.service - weewx weather system

   Loaded: loaded (/etc/systemd/system/weewx.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Wed 2017-03-22 15:29:33 EDT; 38s ago
  Process: 810 ExecStart=/home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf (code=exited, status=0/SUCCESS)
 Main PID: 810 (code=exited, status=0/SUCCESS)

Mar 22 15:29:33 nuc weewxd[810]: Traceback (most recent call last):
Mar 22 15:29:33 nuc weewxd[810]:   File "/home/weewx/bin/weewxd", line 64, in <module>
Mar 22 15:29:33 nuc weewxd[810]:     weewx.engine.main(options, args)
Mar 22 15:29:33 nuc weewxd[810]:   File "/home/weewx/bin/weewx/engine.py", line 833, in main
Mar 22 15:29:33 nuc weewxd[810]:     daemon.daemonize(pidfile=options.pidfile)
Mar 22 15:29:33 nuc weewxd[810]:   File "/home/weewx/bin/daemon.py", line 79, in daemonize
Mar 22 15:29:33 nuc weewxd[810]:     os.dup2(si.fileno(), sys.stdin.fileno())
Mar 22 15:29:33 nuc weewxd[810]:   File "/home/weewx/bin/weewx/engine.py", line 803, in sigTERMhandler
Mar 22 15:29:33 nuc weewxd[810]:     raise Terminate
Mar 22 15:29:33 nuc weewxd[810]: weewx.engine.Terminate

It started fine manually:

root@nuc:~# service weewx restart
root@nuc:~# service weewx status
? weewx.service - weewx weather system

   Loaded: loaded (/etc/systemd/system/weewx.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2017-03-22 15:31:08 EDT; 3s ago
 Main PID: 2519 (weewxd)
   CGroup: /system.slice/weewx.service
           mq2519 /usr/bin/python /home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf

There must be some conflict between in the systemctl startup process. I moved the "weewx.service" (no modifications) according to directions in startup.
I'm now wise enough in the ways of linux to figure this one out.

Thanks for the quick reply.

Bob
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

[Thomas Keffer]

Hi, Bob

What kind of operating system is this? I'm wondering if it is having a reaction to the daemonizing strategy weewx uses.

I would also like to see a bit more of the log, starting with the first weewx log entry, through the 15:39:33 termination.

-tk

--
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+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[vk3...@gmail.com]

Looks like you are using systemd - in that case I had this problem until I asses the lines to the .service. file to  wait until everything necessary is started. From memory this is the file system, network time (and in my case the network and an NFS mount point).

If not then you can edit the sysv (or whatever it is called) to add in the equivalent items.

Susan

[vk3...@gmail.com]

That 'asses' word should be 'added'!!!

[bgra...@umw.edu]

Tom,

I have attached the weewx.log portion which contains the info you requested. The system is Ubuntu 16.04.1 running on an Intel i5 (Intel NUC box). I tried rebooting again this morning and had some new results:

root@nuc:~# service weewx status
? weewx.service - weewx weather system
   Loaded: loaded (/etc/systemd/system/weewx.service; enabled; vendor preset: enabled)

   Active: failed (Result: exit-code) since Thu 2017-03-23 10:05:01 EDT; 37s ago
  Process: 1076 ExecStart=/home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf (code=exited, status=4)
 Main PID: 1076 (code=exited, status=4)

Mar 23 10:05:01 nuc weewx[891]: engine: pid file is /var/run/weewx.pid
Mar 23 10:05:01 nuc systemd[1]: weewx.service: Supervising process 1076 which is not our child. We'll most likely not notice when it exits.
Mar 23 10:05:01 nuc weewx[1076]: engine: Using configuration file /home/weewx/weewx.conf
Mar 23 10:05:01 nuc weewx[1076]: engine: Loading station type Vantage (weewx.drivers.vantage)
Mar 23 10:05:01 nuc weewx[1076]: import of driver failed: [Errno 2] could not open port /dev/ttyUSB0: [Errno 2] No such file or directory: '/dev/ttyUSB0' (<class 'serial.s
Mar 23 10:05:01 nuc weewx[1076]: engine: Unable to load driver: [Errno 2] could not open port /dev/ttyUSB0: [Errno 2] No such file or directory: '/dev/ttyUSB0'
Mar 23 10:05:01 nuc weewx[1076]:     ****  Exiting...
Mar 23 10:05:01 nuc systemd[1]: weewx.service: Main process exited, code=exited, status=4/NOPERMISSION
Mar 23 10:05:01 nuc systemd[1]: weewx.service: Unit entered failed state.
Mar 23 10:05:01 nuc systemd[1]: weewx.service: Failed with result 'exit-code'.
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

? weewx.service - weewx weather system
   Loaded: loaded (/etc/systemd/system/weewx.service; enabled; vendor preset: enabled)

   Active: failed (Result: timeout) since Thu 2017-03-23 10:08:16 EDT; 1min 14s ago
  Process: 2348 ExecStart=/home/weewx/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /home/weewx/weewx.conf (code=exited, status=0/SUCCESS)
 Main PID: 2348 (code=exited, status=0/SUCCESS)

Mar 23 10:06:46 nuc weewx[2352]: restx: PWSWeather: Data for station N4MRV will be posted
Mar 23 10:06:46 nuc weewx[2352]: restx: CWOP: Data for station N4MRV-1 will be posted
Mar 23 10:06:46 nuc weewx[2352]: restx: WOW: Data for station 964806001 will be posted
Mar 23 10:06:46 nuc weewx[2352]: restx: AWEKAS: Data will be uploaded for user bgrattan
Mar 23 10:06:46 nuc weewx[2352]: engine: Starting up weewx version 3.7.0
Mar 23 10:06:46 nuc weewx[2352]: engine: Clock error is -1.64 seconds (positive is fast)
Mar 23 10:06:46 nuc weewx[2352]: engine: Starting main packet loop.
Mar 23 10:08:16 nuc systemd[1]: weewx.service: State 'stop-sigterm' timed out. Killing.
Mar 23 10:08:16 nuc systemd[1]: weewx.service: Unit entered failed state.
Mar 23 10:08:16 nuc systemd[1]: weewx.service: Failed with result 'timeout'.

In the first listing, ttyUSB0 didn't load fast enough (haven't seen this before). I restarted the service and it seems to start but crash on it's own (second listing). I restarted again and it seemed to take off and stay running. Susan's comment below seems to make sense that things that weewx needs aren't starting fast enough. Is there a way to initiate the restart but delay it to wait for what it needs?

Thanks for your help and thanks to Susan who made the suggestion below.

Bob

To unsubscribe from this group and stop receiving emails from it, send an email to weewx-user+...@googlegroups.com.

[mwall]

On Thursday, March 23, 2017 at 10:56:40 AM UTC-4, bgrattan wrote:

Susan's comment below seems to make sense that things that weewx needs aren't starting fast enough. Is there a way to initiate the restart but delay it to wait for what it needs?

bob,

there are at least two strategies for dealing with unavailable resources:

1) configure your init system to deal with it.  in this case, you would modify the init system's configuration files to let it know that weewx should not be started until after the resource(s) are available.  for an rc/upstart system that would be /etc/init.d/weewx, for a systemd system that would be /etc/systemd/system/weewx.service.

2) configure weewx to deal with it.  use the loop_on_init=true in weewx.conf to tell weewx that it should keep retrying during startup (normal behavior is to quit on startup when required resources are not available).

however, we should be sure that there is not a conflict between the way weewx daemonizes itself and the way systemd tries to assimilate^H^H^H^H^H^H^H^H^H^H manage weewx.  (sorry, the scars are still tender from fighting systemd on a cluster node with 24-cores and 10TB of disk)

m

[Thomas Keffer]

Bob,

Before chasing theories, let's make sure we understand exactly what's in the log.

1. Did the computer reboot somewhere between 15:29:02 and 15:29:33 on March 22?

2. At Mar 22 15:29:33 I am seeing three weewx processes: 810, 1025, and 1006. I can imagine their being two just after the daemon fork, but there should never be three. Did you have another weewx process running? 

3. Did the computer reboot between March 23 10:02:00 and 10:05:01?

General: if the computer was rebooting at the indicated times, we should be seeing some evidence in the logs. Did you filter them in some way? If so, please don't. In this case, we are looking at interactions between the OS and weewx, so it's critical we see log entries from both.

-tk

To unsubscribe from this group and stop receiving emails from it, send an email to weewx-user+unsubscribe@googlegroups.com.

[bgra...@umw.edu]

Matt,

I added the " loop_on_init=true" to weewx.conf and that seemed to do it. I wasn't sure how to add the delay to weewx.service. I'll keep watch on it to be sure it restarts correctly. Thanks so much for the help, also Susan and Tom.

Bob

Last log:

Mar 23 11:35:00 nuc weewx[853]: engine: Initializing weewx version 3.7.0
Mar 23 11:35:00 nuc weewx[853]: engine: Using Python 2.7.12 (default, Nov 19 2016, 06:48:10) #012[GCC 5.4.0 20160609]
Mar 23 11:35:00 nuc weewx[853]: engine: Platform Linux-4.8.0-41-generic-x86_64-with-Ubuntu-16.04-xenial
Mar 23 11:35:00 nuc weewx[853]: engine: Locale is 'en_US.UTF-8'
Mar 23 11:35:00 nuc weewx[853]: engine: pid file is /var/run/weewx.pid
Mar 23 11:35:00 nuc weewx[1105]: engine: Using configuration file /home/weewx/weewx.conf
Mar 23 11:35:00 nuc weewx[1105]: engine: Loading station type Vantage (weewx.drivers.vantage)
Mar 23 11:35:00 nuc weewx[1105]: engine: Unable to load driver: [Errno 2] could not open port /dev/ttyUSB0: [Errno 2] No such file or directory: '/dev/ttyUSB0'
Mar 23 11:36:00 nuc weewx[1105]: engine: retrying...
Mar 23 11:36:00 nuc weewx[1105]: engine: Using configuration file /home/weewx/weewx.conf
Mar 23 11:36:00 nuc weewx[1105]: engine: Loading station type Vantage (weewx.drivers.vantage)
Mar 23 11:36:00 nuc weewx[1105]: engine: StdConvert target unit is 0x1
Mar 23 11:36:00 nuc weewx[1105]: engine: Archive will use data binding wx_binding
Mar 23 11:36:00 nuc weewx[1105]: engine: Record generation will be attempted in 'hardware'
Mar 23 11:36:00 nuc weewx[1105]: engine: Using archive interval of 900 seconds (specified by hardware)
Mar 23 11:36:00 nuc weewx[1105]: engine: Using binding 'wx_binding' to database 'weewx.sdb'
Mar 23 11:36:00 nuc weewx[1105]: engine: Starting up weewx version 3.7.0
Mar 23 11:36:00 nuc weewx[1105]: engine: Clock error is -1.61 seconds (positive is fast)
Mar 23 11:36:00 nuc weewx[1105]: engine: Starting main packet loop.

[Thomas Keffer]

Glad that's working well for you, but I'd still like to know the answers to my questions. It will help us diagnose future problems, or maybe even make engineering changes.

-tk

--
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+unsubscribe@googlegroups.com.

[bgra...@umw.edu]

Tom,

I have attached parts of the syslog file which cover your questions below. These are not filtered, but if you need more on either end I can send more. I tried to cut them down as close as I could by time because of the size. I did reboot at the times you ask about. I have only one instance of weewx that I know of.
If I can do any more testing then please let me know as I will be happy to help in any way I can.  Thanks.
Bob

[Thomas Keffer]

1. Do you actually have a port /dev/ttyUSB0? This should have been set up long before weewx was launched.

2. Unless you actually own a modem, you should remove the modem manager. It will compete with the weewx process for control of /dev/ttyUSB0.

sudo apt-get remove modemmanager

-tk

To unsubscribe from this group and stop receiving emails from it, send an email to weewx-user+unsubscribe@googlegroups.com.

[bgra...@umw.edu]

I have an rs232-->USB adapter which creates ttyUSB0 at startup. Should this be a rule in rules.d? Something I hadn't thought about.
I'll remove the modemmanager. Thanks.
Bob

[Thomas Keffer]

Unless there is something unusual about your adapter, no, that should not be necessary. 

-tk

Bob

--
You received this message because you are subscribed to the Google Groups "weewx-user" group.