Local Weather Service onto a Raspberry Pi Issue

[franzstein]

After updating my OpenSprinkler DC 3.0 to firmware 2.1.9 I have also started to update the Local Weather Service running onto a Raspberry Pi.

I followed the steps outlined in: Installing a Local Weather Service onto a Raspberry Pi. Everything worked fine until the end of Step 6.
Enabling and starting the weather service results in:

pi@raspberrypi:~/weather $ sudo systemctl enable weather.service
pi@raspberrypi:~/weather $ sudo systemctl start weather.servicepi@raspberrypi:~/weather $ systemctl status weather.service
● weather.service - OpenSprinkler Weather Server
    Loaded: loaded (/etc/systemd/system/weather.service; enabled; vendor preset:
   Active: activating (auto-restart) (Result: exit-code) since Mon 2019-11-04 16
  Process: 16224 ExecStart=/usr/bin/npm start (code=exited, status=1/FAILURE)
 Main PID: 16224 (code=exited, status=1/FAILURE)
Nov 04 16:29:08 raspberrypi systemd[1]: weather.service: Failed with result 'exi
pi@raspberrypi:~/weather $

The corresponding syslog shows:

pi@raspberrypi:~/weather $ sudo tail -f /var/log/syslog
Nov  4 09:35:09 raspberrypi systemd[1]: Started OpenSprinkler Weather Server.
Nov  4 09:35:11 raspberrypi npm[15597]: > [email protected] start /home/pi/weather
Nov  4 09:35:11 raspberrypi npm[15597]: > node js/server
Nov  4 09:35:12 raspberrypi npm[15597]: events.js:170
Nov  4 09:35:12 raspberrypi npm[15597]:       throw er; // Unhandled 'error' event
Nov  4 09:35:12 raspberrypi npm[15597]:       ^
Nov  4 09:35:12 raspberrypi npm[15597]: Error: listen EADDRINUSE: address already in use 0.0.0.0:80
Nov  4 09:35:12 raspberrypi npm[15597]:     at Server.setupListenHandle [as _listen2] (net.js:1259:14)
Nov  4 09:35:12 raspberrypi npm[15597]:     at listenInCluster (net.js:1307:12)
Nov  4 09:35:12 raspberrypi npm[15597]:     at doListen (net.js:1446:7)
Nov  4 09:35:12 raspberrypi npm[15597]:     at processTicksAndRejections (internal/process/task_queues.js:81:17)
Nov  4 09:35:12 raspberrypi npm[15597]:     at process.runNextTicks [as _tickCallback] (internal/process/task_queues.js:56:3)
Nov  4 09:35:12 raspberrypi npm[15597]:     at Function.Module.runMain (internal/modules/cjs/loader.js:880:11)
Nov  4 09:35:12 raspberrypi npm[15597]:     at internal/main/run_main_module.js:21:11
Nov  4 09:35:12 raspberrypi npm[15597]: Emitted 'error' event at:
Nov  4 09:35:12 raspberrypi npm[15597]:     at emitErrorNT (net.js:1286:8)
Nov  4 09:35:12 raspberrypi npm[15597]:     at processTicksAndRejections (internal/process/task_queues.js:81:17)
Nov  4 09:35:12 raspberrypi npm[15597]:     [... lines matching original stack trace ...]
Nov  4 09:35:12 raspberrypi npm[15597]:     at internal/main/run_main_module.js:21:11
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! code ELIFECYCLE
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! errno 1
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! [email protected] start: <code>node js/server</code>
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! Exit status 1
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR!
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! Failed at the [email protected] start script.
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR! A complete log of this run can be found in:
Nov  4 09:35:12 raspberrypi npm[15597]: npm ERR!     /root/.npm/_logs/2019-11-04T08_35_12_193Z-debug.log
Nov  4 09:35:12 raspberrypi systemd[1]: weather.service: Main process exited, code=exited, status=1/FAILURE
Nov  4 09:35:12 raspberrypi systemd[1]: weather.service: Failed with result 'exit-code'.

Looking at the the recommended error.log shows:

root@raspberrypi:~/.npm/_logs# cat  2019-11-04T08_35_12_193Z-debug.log
0 info it worked if it ends with ok
1 verbose cli [ '/usr/bin/node', '/usr/bin/npm', 'start' ]
2 info using [email protected]
3 info using [email protected]
4 verbose run-script [ 'prestart', 'start', 'poststart' ]
5 info lifecycle [email protected]~prestart: [email protected]
6 info lifecycle [email protected]~start: [email protected]
7 verbose lifecycle [email protected]~start: unsafe-perm in lifecycle true
8 verbose lifecycle [email protected]~start: PATH: /usr/lib/node_modules/npm/node_modules/npm-lifecycle/node-gyp-bin:/home/pi/weather/node_modules/.bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
9 verbose lifecycle [email protected]~start: CWD: /home/pi/weather
10 silly lifecycle [email protected]~start: Args: [ '-c', 'node js/server' ]
11 silly lifecycle [email protected]~start: Returned: code: 1  signal: null
12 info lifecycle [email protected]~start: Failed to exec start script
13 verbose stack Error: [email protected] start: <code>node js/server</code>
13 verbose stack Exit status 1
13 verbose stack     at EventEmitter.<anonymous> (/usr/lib/node_modules/npm/node_modules/npm-lifecycle/index.js:301:16)
13 verbose stack     at EventEmitter.emit (events.js:193:13)
13 verbose stack     at ChildProcess.<anonymous> (/usr/lib/node_modules/npm/node_modules/npm-lifecycle/lib/spawn.js:55:14)
13 verbose stack     at ChildProcess.emit (events.js:193:13)
13 verbose stack     at maybeClose (internal/child_process.js:999:16)
13 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:266:5)
14 verbose pkgid [email protected]
15 verbose cwd /home/pi/weather
16 verbose Linux 4.19.75-v7+
17 verbose argv "/usr/bin/node" "/usr/bin/npm" "start"
18 verbose node v11.15.0
19 verbose npm  v6.7.0
20 error code ELIFECYCLE
21 error errno 1
22 error [email protected] start: <code>node js/server</code>
22 error Exit status 1
23 error Failed at the [email protected] start script.
23 error This is probably not a problem with npm. There is likely additional logging output above.
24 verbose exit [ 1, true ]

Any ideas what went wrong? Some help would be highly appreciated!

[Peter]

Hey Franzstien,

The line “Error: listen EADDRINUSE: address already in use 0.0.0.0:80” suggests that something else may already be using port 80. Are you running a web server on the RPi ?

You can enter sudo netstat -tlnpu at the command line and it will produce a bunch of lines showing what ports are in use. Look for something like the following that has a “:80” in the Local Address column and shows it is being used by my apache web server:

tcp 0 0 0.0.0.0:80 0.0.0.0:* LISTEN 576/apache2

If something is already using port 80 then OS 2.1.9 allows you to set an alternative port, say 3000, and set that in both the “~/weather/.env” file and in the “/su” page of the OS3.0 like “ip_of_the_pi:3000”

Let me know if that fixes the problem or whether we need to look deeper. I will update the docs to reference that OS 2.1.9 removes the restriction on OS using port 80.

[franzstein]

@peter, many thanks for your help. I have changed the port setting to 3000 and the Weather Service is running now without errors.

Unfortunately, there is still a problem with WeeWX’s built-in Weather Underground plug-in. I am running WeeWX and the Weather Service on the same Raspberry PI. According to the hints given in The WeeWX Project I have modified the /etc/weewx/weewx.conf file as follows:

    [[Wunderground]]
        enable = true
        station = anyText
        password = anyText
        server_url = http://127.0.0.1:80/weatherstation/updateweatherstation.php
        rapidfire = False

Unfortunately, WeeWX failed to send the weather observation onto the local Weather Service:

pi@raspberrypi:~ $ sudo /etc/init.d/weewx start
[ ok ] Starting weewx (via systemctl): weewx.service.
pi@raspberrypi:~ $ sudo tail -f /var/log/syslog
Nov  5 09:26:45 raspberrypi weewx[18240]: engine: Using binding 'wx_binding' to database 'weewx.sdb'
Nov  5 09:26:45 raspberrypi weewx[18240]: manager: Starting backfill of daily summaries
Nov  5 09:26:45 raspberrypi weewx[18240]: restx: StationRegistry: Registration not requested.
Nov  5 09:26:45 raspberrypi weewx[18240]: restx: Wunderground-PWS: Data for station anyText will be posted
Nov  5 09:26:45 raspberrypi weewx[18240]: restx: PWSweather: Posting not enabled                                                        .
Nov  5 09:26:45 raspberrypi weewx[18240]: restx: CWOP: Posting not enabled.
Nov  5 09:26:45 raspberrypi weewx[18240]: restx: WOW: Posting not enabled.
Nov  5 09:26:45 raspberrypi weewx[18240]: restx: AWEKAS: Posting not enabled.
Nov  5 09:26:45 raspberrypi weewx[18240]: engine: Starting up weewx version 3.9.2
Nov  5 09:26:45 raspberrypi weewx[18240]: engine: Starting main packet loop.
Nov  5 09:31:47 raspberrypi weewx[18240]: manager: Added record 2019-11-05 09:30:00 CET (1572942600) to database 'weewx.sdb'
Nov  5 09:31:47 raspberrypi weewx[18240]: manager: Added record 2019-11-05 09:30:00 CET (1572942600) to daily summary in 'weewx.sdb'
Nov  5 09:31:50 raspberrypi weewx[18240]: cheetahgenerator: Generated 8 files for report SeasonsReport in 3.13 seconds
Nov  5 09:31:51 raspberrypi weewx[18240]: imagegenerator: Generated 14 images for SeasonsReport in 1.01 seconds
Nov  5 09:31:51 raspberrypi weewx[18240]: copygenerator: copied 5 files to /var/www/html/weewx
Nov  5 09:32:02 raspberrypi weewx[18240]: restx: Wunderground-PWS: Failed to publish record 2019-11-05 09:30:00 CET (1572942600): Failed upload after 3 tries

I’m not sure what causes the problem? There is maybe a change in the WeeWX Wunderground interface. The WeeWX change history 3.9.2 (14 Jul 2019)states:

Posts to the Weather Underground now use https, instead of http. Thanks to user mljenkins! PR #378.

Any ideas how to solve this issue?

[Peter]

In weewx.conf, you need to update the server_url to reflect port 3000 rather than port 80 i.e. server_url = http://127.0.0.1:3000/weatherstation/updateweatherstation.php. Hopefully that will fix things.

[Peter]

We are getting closer 8)

errCode 10 means that the Weather Service is working but has not received sufficient weather observations from weewx to create a meaningful water scale. The Weather Service needs at least 23 hours worth of data. The syslog confirms this at 21:59:29. Note that we have reduced the amount of diagnostic output now that things are more stable with the weather service so the Observation logs aren’t produced any more. So I think it is just a matter of checking back tomorrow to see if things are up and running.

Note that every time you reboot the RPi, the weather service restarts and you need to wait another 24 hours before you start getting water levels produced. If we want to cache the weather observations in Weather Service then you can add LOCAL_PERSISTENCE=true in the Weather Service .env file. This will cause Weather Service to write the received history to disk every 30 minutes so that when it restarts it can pick up from where it left off. You might want to set this option first and then restart the weather service. After 30 minutes, you should see a file called “observations.json” with the history of data.

[franzstein]

@peter, Ok let’s see if things are runnining by tomorrow.

There is also a forum “edit” problem or maybe it’s to late for me and I should better go to bed? Please find below a copy of the now missing #63163 reply.

@peter, thanks again for your help. Unfortunately there exists still a problem with the weather data.

Requesting the weather service with e.g.:

http://192.168.178.39:3000/weather1.py?loc=50,1&wto=“h”:100,”t”:100,”r”:100,”bh:70,”bt”:59,”br”:0

results in:

&errCode=10&scale=100

Looking at syslog shows:

….
Nov 5 21:58:21 raspberrypi weewx[19139]: restx: Wunderground-PWS: Published record 2019-11-05 21:55:00 CET (1572987300)
Nov 5 21:58:24 raspberrypi weewx[19139]: cheetahgenerator: Generated 8 files for report SeasonsReport in 3.14 seconds
Nov 5 21:58:25 raspberrypi weewx[19139]: imagegenerator: Generated 14 images for SeasonsReport in 1.00 seconds
Nov 5 21:58:25 raspberrypi weewx[19139]: copygenerator: copied 5 files to /var/www/html/weewx
Nov 5 21:59:29 raspberrypi npm[16942]: There is insufficient data to support Zimmerman calculation from local PWS.
….

Looking at old syslog files shows that these kind of logs are still missing:
Jun 14 23:55:49 raspberrypi npm[357]: OpenSprinkler Weather Observation: {“action”:”updateraw”,”ID”:”anyText”,”PASSWORD”:”anyText”,”softwaretype”:”weewx-3.9.1″,”baromin”:”29.854″,”dewptf”:”57.4″,”humidity”:”062″,”dateutc”:”2019-06-14 21:55:00″,”dailyrainin”:”0.00″,”winddir”:”161″,”tempf”:”71.1″,”windspeedmph”:”0.6″,”windgustmph”:”2.5″,”rainin”:”0.00″}

Sorry for bothering you again.

[franzstein]

@Peter, well done, weather data is reported now:

http://192.168.178.39:3000/weather1.py?loc=49.47369,10.94380&wto="h":100,"t":100,"r":100,"bh":70,"bt":65,"br":0

&scale=0&tz=52&sunrise=434&sunset=1007&eip=3232281125&rawData={"weatherProvider":"local","h":91.4,"p":0.01,"t":45.4,"raining":0}&errCode=0

Many Thanks.

[wifi75]

hello I have this error:
How I can solve it?

Attachments:

1. 

   weather-1.jpg
   

[Author]

Posts