Pi Gateway no longer logging data

[Nspector5]

I have had a Pi Gateway setup and running with the 8.5 release for about a month, but as of a few days ago, the interface stopped responding and it is no longer logging any of the sensor data.

I can still access the webpage, and if I click on the terminal/log button, I see new data.
If I remote into the Pi, I see that the various .bin files in /gateway/data/db have not been updated for several days.
The gateway.sys.log files shows no errors; only new connection logs.
If I try to remove a node via the web interface, I see a log in gateway.sys.log ([WARN]  removeMetricLog(): removed (/home/pi/gateway/data/db/0205_CM.bin)) but the file does not get removed.
I have tried rebooting my Pi (via sudo reboot) as well as npm udpate to make sure nothing was out of date.

Any idea what might be going wrong?

Thanks.

[Felix]

Could it be no disk space? But i'd expect an exception if there was none...

Is your incoming data still respecting the expected format?
Can you give an example of received data which was not logged?

Anything being added to gateway_nonmatches.db ?

[Nspector5]

I ran df -Bm  and still show several hundred MB available.
The data is still coming in with the same format.
Here is an example of from the terminal log:
10:11:25 AM : {"_id":4,"updated":1475341911200,"rssi":81,"metrics":{"Battery":{"label":"Battery","value":381,"unit":"v","updated":1475341911200},"F":{"label":"F","value":69,"unit":"°","updated":1475341911200,"pin":1,"graph":1}},"type":"WeatherMote","label":"Sleeping Porch","events":{"lowbattAAA":1}}

There are some additions to _nonmatches.db, but just normal corrupted serial data:
{"_id":1474802721832,"data":"�g{�䰇�   [RSSI:-38]\r"}

Any idea?

[Felix]

The data is still coming in with the same format.
Here is an example of from the terminal log:

Code Select Expand

10:11:25 AM : {"_id":4,"updated":1475341911200,"rssi":81,"metrics":{"Battery":{"label":"Battery","value":381,"unit":"v","updated":1475341911200},"F":{"label":"F","value":69,"unit":"°","updated":1475341911200,"pin":1,"graph":1}},"type":"WeatherMote","label":"Sleeping Porch","events":{"lowbattAAA":1}}

This log is generated by this line in gateway.js (processSerialData() function):

Code Select Expand

io.sockets.emit('UPDATENODE', entry);

However I am more interested in the if statement before that is issued, which actually does either an INSERT or an UPDATE, in your example it would fall in the else branch for UPDATE. Locate the same entry in the disk logs and see if it's there.

Either way there's a clear indication the data was received and node was updated, but there seems to be a problem with appending to the neDB gateway.db database. Not really sure what could stop that from working. Let's find the disk logs in the log directory and go from there. Look for any exceptions also.

[Nspector5]

Were are the disk logs? Are they in gateway/logs/gateway.sys.log?

If so, there are no new logs regarding posting data since things stopped working. Here is the last valid log entries regarding receiving data:
[10-01-16_12:12:00.903] [LOG]   post: /home/pi/gateway/data/db/0003_F.bin[1475341920,70]
[10-01-16_12:12:00.909] [LOG]      [3] DB-Updates:1
[10-01-16_12:12:10.396] [LOG]   >: [8] BSMT:75 FRZR:1 HVAC:75 OUTT:66 FRST:72   [RSSI:-36]
[10-01-16_12:12:10.403] [LOG]   post: /home/pi/gateway/data/db/0008_Basement.bin[1475341930,75]
[10-01-16_12:12:10.405] [LOG]   post: /home/pi/gateway/data/db/0008_Freezer.bin[1475341930,1]
[10-01-16_12:12:10.408] [LOG]   post: /home/pi/gateway/data/db/0008_HVAC.bin[1475341930,75]
[10-01-16_12:12:10.410] [LOG]   post: /home/pi/gateway/data/db/0008_Outside.bin[1475341930,66]
[10-01-16_12:12:10.412] [LOG]   post: /home/pi/gateway/data/db/0008_First Floor.bin[1475341930,72]
[10-01-16_12:12:10.425] [LOG]      [8] DB-Updates:1

The rights for the file are rw-r--r-- and it is owned by root. Are the permissions correct?

[Felix]

Yeah so it can't write to the disk for some reason. Rights could be an issue.
My gateway.sys.log rights are:

Code Select Expand

drwxr-xr-x 6 pi   root    4096 Jul 27 13:32 ..
-rw-r--r-- 1 root root 1135924 Oct  6 16:54 gateway.sys.log

My dbs rights are (sample node and db files):

Code Select Expand

drwxr-xr-x 2 pi pi    4096 Oct  6 11:00 .
drwxr-xr-x 4 pi pi    4096 Jan 18  2016 ..
-rw-r--r-- 1 pi pi 9336717 Oct  6 16:55 0099_F.bin
-rw-r--r-- 1 pi pi 1132907 Oct  6 16:55 gateway.db
-rw-r--r-- 1 pi pi  490197 Oct  6 15:09 gateway_nonmatches.db

Here are the rights of the process running the gateway:

Code Select Expand

pi@raspberrypi ~ $ ps aux | grep node
root       937  0.0  0.2   3628  2268 ?        Ss   Sep27   0:00 sudo -u pi /opt/node/bin/node /home/pi/gateway/gateway.js
pi         975  0.2  6.4 107888 61284 ?        Sl   Sep27  38:01 /opt/node/bin/node /home/pi/gateway/gateway.js

I think the problem happens here in this code somewhere:

Code Select Expand

global.processSerialData = function (data) {
      .......................................................
      //save to DB
      db.findOne({_id:id}, function (err, doc) {
        if (doc == null)
        {
          if (settings.general.genNodeIfNoMatch.value == true || settings.general.genNodeIfNoMatch.value == 'true' || hasMatchedMetrics)
          {
            db.insert(entry);
            console.log('   ['+id+'] DB-Insert new _id:' + id);  <--- this should show up in the log after a DB INSERT
          }
          else
          {
            return;
          }
        }
        else
          db.update({ _id: id }, { $set : entry}, {}, function (err, numReplaced) { console.log('   ['+id+'] DB-Updates:' + numReplaced);}) <--- should show up in the log after a DB UPDATE

Notice the console.log lines. If db.update fails and it actually returns something (numReplaced) it should be able to log that to the general log gateway.sys.log
But from your sys.log I dont see any DB updates happening since 10.01, very strange.

Did you change anything? Update any software, rights, sketch? Any automatic updates or something?

[perky]

Looks like a permissions problem, like the db file was copied by root and took on root ownership. If the writing process is running as pi (which it appears to be by the sudo) that could explain things? Try chown the database file to pi?

[Nspector5]

I have changed all of the owners of the log files back to root, and all of the .bin files in the data/db/ folder are owned by pi, but I am still not able to log data. Any other ideas?

[Felix]

What version is your neDB install?
It's impossible things just stopped without a reason. Something must have happened, an update or a permission change. Everything looks good except UPDATEs don't log in sys.log.
You can try adding some more logging to narrow down where/why this happens in processSerialData().
Or you can backup everything and start from a fresh 8.1 install and update the sources to 8.6.

[Nspector5]

It looks like I am running 1.8.0 for neDB. To my knowledge, I was not modifying anything when the system stopped working. Do you have any suggestions for logging in processSerialData()? Is there another system wide log to see what might be going on? If I delete a node from the web interface, the associated .bin in /data/db/ does get deleted.

[perky]

Just a thought, does the database use ports? Could it be a firewall problem?

[Felix]

You can use console.log as seen in other parts of the same function.
If you want to get brave you could even dig the neDB sources and add logging there. The art of debugging never gets old.

[Nspector5]

I don't think console.log would work, as it is currently not writing out the console.log('>: ' + data) in processSerialData function. How does proessSerialData get called? The only new log entries in gateway.sys.log are:
[10-10-16_15:08:43.636] [INFO]  NEW CONNECTION FROM (My IP address here)
These are accurate. Any idea who logs that data?

[Felix]

I don't think console.log would work, as it is currently not writing out the console.log('>: ' + data) in processSerialData function. How does proessSerialData get called? The only new log entries in gateway.sys.log are:
[10-10-16_15:08:43.636] [INFO]  NEW CONNECTION FROM (My IP address here)
These are accurate. Any idea who logs that data?

Nothing getting logged indicates something is denying this app to run properly.
The NEW CONNECTION message is coming from this line.

[Nspector5]

The console.log would not work from within the processSerialData function, as that does not appear to be getting called. How does the processSerialData function get called?