Forbidden access Raspberry Pi web server

johnbanks · 5 March 2019 19:59

Darn it! Just days after my last post (Recurring problem 23 Feb), it’s happened again … twice … when trying to browse

Forbidden
You don’t have permission to access / on this server.
Server unable to read htaccess file, denying access to be safe
________________________________________
Apache/2.4.25 (Raspbian) Server at 192.168.0.167 Port 80

This time it was on two different (but identical) instances of emonTx/RPi running emonSD image Oct 2018.

Using a network scanner, I could see an instance and its IP address. But here was another error message …

HTTP, 403 Forbidden (Apache httpd 2.4.25)

And, I also could not connect via ssh/puTTy – connection refused.

Given the same problem is on identical instances then – SDHC, hardware & power supply issues can be ruled out? And as rootfs and data partitions are run from a USB spinning hard drive, space is not a problem.

The emonTx/RPi’s each with a different Node number communicate with watchman via an EmonHubEmoncmsHTTPInterfacer. So watchman (also running the emonSD image) has a duplicate of all inputs.

I started over – burned a fresh image, copied rootfs & data partitions to USB HDD and ran from that. I then commented out (in fstab) the tmpfs for /var/log and re-booted. Everything seemed fine so I powered down and examined the USB HDD on my windows PC. The /var/log files had survived.
I connected up again. Data was being sent to watchman OK. But now I could not browse to the emonTx/RPi instance which was running but now only controllable via SSH.

I downloaded /var/log to my Windows PC (winSCP) and examined it (Notepad++).
Now on the edge of my ‘comfort/knowledge zone’, I saw many reports – error, fatal, warn, warning, etc
.
One caught my eye –

Mar  5 10:16:31 emonpi-node-13 redis-server[5022]: *** FATAL CONFIG FILE ERROR ***
Mar  5 10:16:31 emonpi-node-13 redis-server[5022]: Reading the configuration file, at line 163
Mar  5 10:16:31 emonpi-node-13 redis-server[5022]: >>> 'logfile /var/log/redis/redis-server.log'
Mar  5 10:16:31 emonpi-node-13 redis-server[5022]: Can't open the log file: No such file or directory
Mar  5 10:16:31 emonpi-node-13 systemd[1]: redis-server.service: Control process exited, code=exited status=1
Mar  5 10:16:31 emonpi-node-13 systemd[1]: Failed to start Advanced key-value store.
Mar  5 10:16:31 emonpi-node-13 systemd[1]: redis-server.service: Unit entered failed state.
Mar  5 10:16:31 emonpi-node-13 systemd[1]: redis-server.service: Failed with result 'exit-code'.
Mar  5 10:16:31 emonpi-node-13 systemd[1]: redis-server.service: Service hold-off time over, scheduling restart.
Mar  5 10:16:31 emonpi-node-13 systemd[1]: Stopped Advanced key-value store.
Mar  5 10:16:31 emonpi-node-13 systemd[1]: Starting Advanced key-value store...
Mar  5 10:16:31 emonpi-node-13 lwrfd[398]: Reconnecting to MQTT ...
Mar  5 10:16:31 emonpi-node-13 run-parts[5026]: run-parts: executing /etc/redis/redis-server.pre-up.d/00_example
Mar  5 10:16:31 emonpi-node-13 lwrfd[398]: Failed to connect to MQTT, return code -1

I’ve put together a selection from the 100’s of log lines …
Log_Extracts.zip (5.9 KB)

Any help or suggestions would be very welcome

djh · 5 March 2019 20:41

'logfile /var/log/redis/redis-server.log'
 Can't open the log file: No such file or directory

So does /var/log/redis exist? And what permissions does it have?

johnbanks · 5 March 2019 21:08

@djh

It doesn’t exist.
Does it exist for you?

pi@emonpi-node-13:/var $ cd /var/log
pi@emonpi-node-13:/var/log $ ls -l
total 62472
-rw-r----- 1 root adm     46794 Mar  5 21:00 auth.log
-rw-r----- 1 root adm     23648 Mar  5 06:25 auth.log.1
-rw-r--r-- 1 root root     6528 Mar  5 00:51 boot.log
-rw-rw---- 1 root utmp        0 Mar  5 06:25 btmp
-rw------- 1 root utmp        0 Mar  5 00:42 btmp.1
-rw-r----- 1 root adm  22910907 Mar  5 21:01 daemon.log
-rw-r----- 1 root adm   8772162 Mar  5 06:25 daemon.log.1
-rw-r----- 1 root adm         0 Mar  5 06:25 debug
-rw-r----- 1 root adm      2770 Mar  5 00:51 debug.1
-rw-r--r-- 1 root root     7107 Mar  5 01:19 dpinstall.log
-rw-r--r-- 1 root root    85752 Mar  5 21:01 emoncms.log
drwxr-xr-x 2 pi   root     4096 Mar  5 00:42 emonpilcd
-rw-r----- 1 root adm     34496 Mar  5 21:00 kern.log
-rw-r----- 1 root adm     72070 Mar  5 06:20 kern.log.1
-rw-r----- 1 root adm     34658 Mar  5 21:00 messages
-rw-r----- 1 root adm     69230 Mar  5 06:25 messages.1
-rw-r----- 1 root adm  22972481 Mar  5 21:01 syslog
-rw-r----- 1 root adm   8856714 Mar  5 06:25 syslog.1
-rw-r----- 1 root adm         0 Mar  5 06:25 user.log
-rw-r----- 1 root adm       840 Mar  5 00:51 user.log.1
-rw-rw-r-- 1 root utmp      384 Mar  5 10:11 wtmp
-rw-rw-r-- 1 root utmp     5376 Mar  5 02:59 wtmp.1
pi@emonpi-node-13:/var/log $

djh · 5 March 2019 21:09

Yes, because I created it. You need to create that directory and make sure it belongs to the redis user. Then redis will probably start and things will get further.

johnbanks · 5 March 2019 21:25

Thx for the lightening response …
I’m perplexed …
I’m a bog-standard user using the emonSD image so if redis is needed, why is it not created - behind the scenes, so to speak?
I’ll create the directory, give it open permissions and restart redis (bit of research needed on my part for that)

djh · 5 March 2019 21:27

Dunno, I was as surprised as you when I installed redis on my openSUSE box and had to create a new directory for it.

I hope that fixes it for you.

johnbanks · 5 March 2019 21:43

@djh

The plot thickens … redis.service not found …

pi@emonpi-node-13:/ $ sudo systemctl restart redis
Failed to restart redis.service: Unit redis.service not found.
pi@emonpi-node-13:/ $

djh · 5 March 2019 21:45

I think you’ll need something like

sudo systemctl start redis@default

but I’m pretty much out of my depth at that so you may do better waiting for more exprt advice.

johnbanks · 5 March 2019 21:54

@djh

Thx - but that didn’t work either …

pi@emonpi-node-13:/ $ sudo systemctl start redis@default
Failed to start [email protected]: Unit [email protected] not found.
pi@emonpi-node-13:/ $

We are in slighty/completely? different situations - I’m just a bog-standard emonSD image user

Agreed - we do need help from the heavy gang experts

borpin · 5 March 2019 22:32

it is not redis it is redis-server

systemctl status redis-server.service

Use the tab key to auto expand.

systemctl status

will list all services

borpin · 5 March 2019 22:40

Had you mentioned that it was running of an HDD before? I suggest this in some way is the cause of the issues.

I’d suggest the opposite. If both exhibit the same symptoms the root cause is likely to be the same.

I’d suggest running one instance off the SD card for a while and see if the problem (of losing connection) persists.

Is there a possibility of power failure causing a reboot?

pb66 · 5 March 2019 22:41

OK where to start?

Firstly there is no “redis” (or redis@default?) service it should be “redis-server” so try

sudo systemctl status redis-server

It is, or rather it should be. ordinarily it is created by rc.local at boot time and the service restarted (don’t ask, long story). What I believe you have done to the /var/log directory shouldn’t effect how that works, but I could be wrong.

Ordinarily I would say that your changes are favorite to upset a reasonably stable operation, but there have been some hiccups with the new emonSD image so I’m less confident.

Either way, that log file list doesn’t look right, there is only one folder, there should be several IIRC (again, I could be wrong, unfortunately there is no build guide published for the current image. so all we know is what we assume or learn from assisting issues such as this).

Ah ha!!!

I just went to grab this info (below) for you and spotted the first line will only allow this to run when /var/log is mounted in tmpfs (there lies the issue for you). So you need to manually create all the folders and files, hopefully just the once. Usually it’s done automajically by the emonSD OR you are guided thru the manual steps in an install guide, making the switch as you have has led you slip through the cracks.

github.com

openenergymonitor/emonpi/blob/2.9.1/rc.local_jessieminimal#L14-L44


      
          # Will only run if /var/log is mounted in tmpfs
          if ( mount | grep "on /var/log "| grep -q "^tmpfs " )
          then
            for i in "redis" "apache2" "mysql" "openhab" "logrotate" "mosquitto" "supervisor"; do mkdir /var/log/"$i"; done
            for i in "emoncms.log" "mysql.log" "mqtt_input.log" "redis/redis-server.log" "service-runner.log" "mysql/error.log" "apache2/error.log" "supervisor/supervisord.log" "ntp_update.log"; do touch /var/log/"$i"; done
            for i in "emoncms.log" "mysql.log" "mqtt_input.log" "redis/redis-server.log" "service-runner.log" "mysql/error.log" "apache2/error.log" "supervisor/supervisord.log" "ntp_update.log"; do ""chmod 666"" /var/log/"$i"; done
            chown -R root:adm /var/log/apache2
            chown -R redis:redis /var/log/redis
            chown -R mysql:adm /var/log/mysql
            chown -R openhab:openhab /var/log/openhab
            chown -R pi:pi /var/log/logrotate
            chown -R mosquitto:mosquitto /var/log/mosquitto
            chown -R dataplicity:dataplicity /var/log/supervisor;
          
            # Restart random seed process now ~/data RW partition has been mounted 
            sudo systemctl restart systemd-random-seed.service
          
            # Start / Restart services,they should run happy now log dir's are created
            sleep 3
            service mysql restart

This file has been truncated. show original

johnbanks · 6 March 2019 22:28

Paul …

Many thx. I used the file you provided to make an executable script …

#!/bin/sh
#
# Run this script if you do not have /var/log in tmpfs

  for i in "redis" "apache2" "mysql" "openhab" "logrotate" "mosquitto" "supervisor"; do mkdir /var/log/"$i"; done
  for i in "emoncms.log" "mysql.log" "mqtt_input.log" "redis/redis-server.log" "service-runner.log" "mysql/error.log" "apache2/error.log" "supervisor/supervisord.log" "ntp_update.log"; do touch /var/log/"$i"; done
  for i in "emoncms.log" "mysql.log" "mqtt_input.log" "redis/redis-server.log" "service-runner.log" "mysql/error.log" "apache2/error.log" "supervisor/supervisord.log" "ntp_update.log"; do ""chmod 666"" /var/log/"$i"; done
  chown -R root:adm /var/log/apache2
  chown -R redis:redis /var/log/redis
  chown -R mysql:adm /var/log/mysql
  chown -R openhab:openhab /var/log/openhab
  chown -R pi:pi /var/log/logrotate
  chown -R mosquitto:mosquitto /var/log/mosquitto
  chown -R dataplicity:dataplicity /var/log/supervisor;

  # Restart random seed process now ~/data RW partition has been mounted 
  sudo systemctl restart systemd-random-seed.service

  # Start / Restart services,they should run happy now log dir's are created
  sleep 3
  service mysql restart
  service redis-server restart
  service mosquitto restart
  service emonhub restart
  service emonPiLCD restart
  service apache2 restart
  service supervisor restart
  service feedwriter restart
  service mqtt_input restart
  service lwrfd restart

exit 0

The script ran, created the extra files/directories and they survived a reboot.

I could access the emonTx/RPi via SSH but I could not browse to it - could not establish a connection (not the FORBIDDEN message)

I could see that watchman another emonTx/RPi on the network was receiving inputs from the problem instance. And, best of all, the hundreds of sylog error lines no longer appeared. I went to bed.

This AM I discovered from syslog that in the early hours it had crashed and rebooted itself …

Mar  6 03:01:50 emonpi-node-13 emonhub.py[305]: 2019-03-06 03:01:50,112 DEBUG    SerialTx   1659 Timestamp : 1551841310.11
Mar  6 03:01:50 emonpi-node-13 emonhub.py[305]: 2019-03-06 03:01:50,113 DEBUG    SerialTx   1659 From Node : 13
Mar  6 03:01:50 emonpi-node-13 emonhub.py[305]: 2019-03-06 03:01:50,113 DEBUG    SerialTx   1659    Values : [0, 0, 0, 0, 244.44, 3020, 3010, 3010, 3010, 3010, 3010, 1]
Mar  6 03:01:50 emonpi-node-13 emonhub.py[305]: 2019-03-06 03:01:50,114 DEBUG    SerialTx   1659 Sent to channel(start)' : ToEmonCMS
Mar  6 03:01:50 emonpi-node-13 emonhub.py[305]: 2019-03-06 03:01:50,115 DEBUG    SerialTx   1659 Sent to channel(end)' : ToEmonCMS
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             Mar  6 02:25:57 emonpi-node-13 systemd-modules-load[92]: Inserted module 'i2c_dev'
Mar  6 02:25:57 emonpi-node-13 fake-hwclock[94]: Wed  6 Mar 02:17:01 UTC 2019
Mar  6 02:25:57 emonpi-node-13 systemd[1]: Started Restore / save the current clock.
Mar  6 02:25:57 emonpi-node-13 systemd[1]: Time has been changed
Mar  6 02:25:57 emonpi-node-13 systemd[1]: Starting File System Check on Root Device...
Mar  6 02:25:57 emonpi-node-13 systemd-fsck[129]: Please pass 'fsck.mode=skip' rather than 'fastboot' on the kernel command line.
Mar  6 02:25:57 emonpi-node-13 systemd[1]: Started File System Check on Root Device.
Mar  6 02:25:57 emonpi-node-13 systemd[1]: Starting Remount Root and Kernel File Systems...

But after the self reboot, it failed to connect to MQTT …

Mar  6 02:26:07 emonpi-node-13 lwrfd[381]: Reconnecting to MQTT ...
Mar  6 02:26:07 emonpi-node-13 supervisord[500]: 2019-03-06 02:26:07,688 INFO RPC interface 'supervisor' initialized
Mar  6 02:26:07 emonpi-node-13 supervisord[500]: 2019-03-06 02:26:07,690 CRIT Server 'unix_http_server' running without any HTTP authentication checking
Mar  6 02:26:07 emonpi-node-13 supervisord[500]: 2019-03-06 02:26:07,691 INFO supervisord started with pid 500
Mar  6 02:26:07 emonpi-node-13 lwrfd[381]: Failed to connect to MQTT, return code -1
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,232 DEBUG    SerialTx   2 NEW FRAME : 13 0 0 0 0 24853 30200 30100 30100 30100 30100 30100 1
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,234 DEBUG    SerialTx   2 Timestamp : 1551839168.23
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,234 DEBUG    SerialTx   2 From Node : 13
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,235 DEBUG    SerialTx   2    Values : [0, 0, 0, 0, 248.53, 3020, 3010, 3010, 3010, 3010, 3010, 1]
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,235 DEBUG    SerialTx   2 Sent to channel(start)' : ToEmonCMS
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,236 DEBUG    SerialTx   2 Sent to channel(end)' : ToEmonCMS
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,361 INFO     MQTT       Connecting to MQTT Server
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,461 DEBUG    To_watchman Buffer size: 1
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,463 INFO     To_watchman sending: http://watchman/emoncms/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1551839168.232513,13,0,0,0,0,248.53,3020,3010,3010,3010,3010,3010,1]]&sentat=1551839168
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,469 INFO     MQTT       connection status: Connection successful
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,471 DEBUG    MQTT       CONACK => Return code: 0
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,572 INFO     MQTT       on_subscribe
Mar  6 02:26:08 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:08,751 DEBUG    To_watchman acknowledged receipt with 'ok' from http://watchman/emoncms

It died seconds thereafter with no syslog entries until I rebooted at about 10am …

Mar  6 02:26:23 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:23,296 DEBUG    MQTT       Publishing: emon/3phase_node13/temp6 3010
Mar  6 02:26:23 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:23,298 DEBUG    MQTT       Publishing: emon/3phase_node13/pulse 1
Mar  6 02:26:23 emonpi-node-13 emonhub.py[303]: 2019-03-06 02:26:23,300 INFO     MQTT       Publishing: emonhub/rx/13/values 0,0,0,0,248.77,3020,3010,3010,3010,3010,3010,1
Mar  6 10:00:54 emonpi-node-13 systemd-timesyncd[259]: Synchronized to time server 129.250.35.251:123 (2.debian.pool.ntp.org).
Mar  6 10:00:54 emonpi-node-13 systemd[1]: Time has been changed
Mar  6 10:00:54 emonpi-node-13 systemd[1]: apt-daily-upgrade.timer: Adding 47min 27.605566s random time.
Mar  6 10:00:54 emonpi-node-13 systemd[1]: apt-daily.timer: Adding 8h 8min 5.313266s random time.
Mar  6 10:00:54 emonpi-node-13 systemd[1]: Starting Clean php session files...
Mar  6 10:00:55 emonpi-node-13 systemd[1]: Starting Daily apt upgrade and clean activities...
Mar  6 10:00:55 emonpi-node-13 supervisord[500]: 2019-03-06 10:00:55,014 INFO exited: tuxtunnel (terminated by SIGKILL; not expected)
Mar  6 10:00:55 emonpi-node-13 emonhub.py[303]: 2019-03-06 10:00:55,018 DEBUG    To_watchman Buffer size: 3
Mar  6 10:00:55 emonpi-node-13 emonhub.py[303]: 2019-03-06 10:00:55,019 INFO     To_watchman sending: http://watchman/emoncms/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1551839173.214865,13,0,0,0,0,248.62,3020,3010,3010,3010,3010,3010,1],[1551839178.220762,13,0,0,0,0,248.99,3020,3010,3010,3010,3010,3010,1],[1551839183.25114,13,0,0,0,0,248.77,3020,3010,3010,3010,3010,3010,1]]&sentat=1551866455
Mar  6 10:00:55 emonpi-node-13 emonhub.py[303]: 2019-03-06 10:00:55,187 DEBUG    To_watchman acknowledged receipt with 'ok' from http://watchman/emoncms
Mar  6 10:00:55 emonpi-node-13 systemd[1]: Started Clean php session files.

It then crashed and self rebooted at 11:29 …

Mar  6 11:29:47 emonpi-node-13 emonhub.py[303]: 2019-03-06 11:29:47,619 DEBUG    MQTT       Publishing: emon/3phase_node13/temp4 3010
Mar  6 11:29:47 emonpi-node-13 emonhub.py[303]: 2019-03-06 11:29:47,621 DEBUG    MQTT       Publishing: emon/3phase_node13/temp5 3010
Mar  6 11:29:47 emonpi-node-13 emonhub.py[303]: 2019-03-06 11:29:47,623 DEBUG    MQTT       Publishing: emon/3phase_node13/temp6 3010
Mar  6 11:29:47 emonpi-node-13 emonhub.py[303]: 2019-03-06 11:29:47,625 DEBUG    MQTT       Publishing: emon/3phase_node13/pulse 1
Mar  6 11:29:47 emonpi-node-13 emonhub.py[303]: 2019-03-06 11:29:47,627 INFO     MQTT       Publishing: emonhub/rx/13/values 0,0,0,0,249.05,3020,3010,3010,3010,3010,3010,1
                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   Mar  6 11:17:06 emonpi-node-13 systemd-modules-load[98]: Inserted module 'i2c_dev'
Mar  6 11:17:06 emonpi-node-13 fake-hwclock[94]: Wed  6 Mar 11:17:01 UTC 2019
Mar  6 11:17:06 emonpi-node-13 systemd[1]: Time has been changed
Mar  6 11:17:06 emonpi-node-13 systemd[1]: Started Restore / save the current clock.
Mar  6 11:17:06 emonpi-node-13 systemd[1]: Starting File System Check on Root Device...
Mar  6 11:17:06 emonpi-node-13 systemd-fsck[131]: Please pass 'fsck.mode=skip' rather than 'fastboot' on the kernel command line.
Mar  6 11:17:06 emonpi-node-13 systemd[1]: Started File System Check on Root Device.

But it only ran until 11:17 before dying again.
I rebooted at 12:16 and currently it’s still running (crippled tho’ as I cannot browse to it) …

Mar  6 11:17:32 emonpi-node-13 emonhub.py[322]: 2019-03-06 11:17:32,998 DEBUG    MQTT       Publishing: emon/3phase_node13/temp5 3010
Mar  6 11:17:33 emonpi-node-13 emonhub.py[322]: 2019-03-06 11:17:33,000 DEBUG    MQTT       Publishing: emon/3phase_node13/temp6 3010
Mar  6 11:17:33 emonpi-node-13 emonhub.py[322]: 2019-03-06 11:17:33,002 DEBUG    MQTT       Publishing: emon/3phase_node13/pulse 1
Mar  6 11:17:33 emonpi-node-13 emonhub.py[322]: 2019-03-06 11:17:33,004 INFO     MQTT       Publishing: emonhub/rx/13/values 0,0,0,0,246.38,3020,3010,3010,3010,3010,3010,1
Mar  6 12:16:08 emonpi-node-13 systemd-timesyncd[261]: Synchronized to time server 193.150.34.2:123 (2.debian.pool.ntp.org).
Mar  6 12:16:08 emonpi-node-13 systemd[1]: Time has been changed
Mar  6 12:16:08 emonpi-node-13 systemd[1]: apt-daily.timer: Adding 10h 33min 24.520174s random time.
Mar  6 12:16:08 emonpi-node-13 systemd[1]: apt-daily-upgrade.timer: Adding 8min 35.155840s random time.
Mar  6 12:16:08 emonpi-node-13 systemd[1]: Starting Clean php session files...
Mar  6 12:16:08 emonpi-node-13 emonhub.py[322]: 2019-03-06 12:16:08,784 DEBUG    To_watchman Buffer size: 3
Mar  6 12:16:08 emonpi-node-13 emonhub.py[322]: 2019-03-06 12:16:08,825 INFO     To_watchman sending: http://watchman/emoncms/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[[1551871042.872834,13,0,0,0,0,245.72,3020,3010,3010,3010,3010,3010,1],[1551871047.901405,13,0,0,0,0,246.72,3020,3010,3010,3010,3010,3010,1],[1551871052.884299,13,0,0,0,0,246.38,3020,3010,3010,3010,3010,3010,1]]&sentat=1551874568
Mar  6 12:16:08 emonpi-node-13 emonhub.py[322]: 2019-03-06 12:16:08,977 DEBUG    To_watchman acknowledged receipt with 'ok' from http://watchman/emoncms
Mar  6 12:16:09 emonpi-node-13 supervisord[498]: 2019-03-06 12:16:09,211 INFO exited: tuxtunnel (terminated by SIGKILL; not expected)
Mar  6 12:16:09 emonpi-node-13 systemd[1]: Started Clean php session files.

There were 2 occasions when it crashed and self rebooted.
When I read the syslog line using Notepad++, there are many NUL’s across the line which do not seem to show up in this posting.
Googling suggests …
NUL bytes in the syslog are a common effect of a crash that prevented the system from cleanly syncing and unmounting the filesystem. They don’t give an indication of what actually triggered the crash.
Usually complete system crashes are caused by some fault in drivers, the kernel, hardware, etc.
Could be a representation that the system was in mid write when it crashed.

Could it be a duff RPi or USB HDD? I’ll start over again with a different RPi to begin with.

Also there have been 4 crashes today. On 3 occasions immediately before the crash, syslog records MQTT publishing. On the other occasion, it was Serial Tx being sent. Might this be relevant?
There are many entries in the mosquito log like this …

1551867304: New connection from 127.0.0.1 on port 1883.
1551867304: New connection from 127.0.0.1 on port 1883.
1551867304: Socket error on client , disconnecting.
1551867304: Socket error on client , disconnecting.

Finally - thx again for yr steer to getting all log files & directories visible.

pb66 · 6 March 2019 23:13

A couple of points, maybe useful, maybe not.

The log output quotes this line a couple of times

Please pass 'fsck.mode=skip' rather than 'fastboot' on the kernel command line

I believe it is telling you to edit the /boot/cmdline.txt to initiate a check of the filesystem using fsck.

Also, if you are running from he’d, how did you do that? Have you mounted the boot partition of the ad card as /boot rather than the hdd boot partition? If these are not correctly mounted and you update the kernel, it leads to alerts of issues as it thinks it is running the later kernel when it is actually running the old kernel as boots from the sd card boot partition (if you have it setup that way) which is not updated if not mounted correctly.

Greebo · 6 March 2019 23:14

How good is your RPi power supply and what sort of USB HDD are you using? The Pi isn’t crashing due to insufficient power being supplied to the HDD in certain circumstances is it?

Just a thought.

johnbanks · 6 March 2019 23:41

@Greebo
I’m using the official Raspberry PSU rated at 2.5A.
The HDD is a 2.5inch laptop drive.
Think I must cut into cord from the RPi to the HDD and insert my ammeter.
It will be interesting to see just what the drive takes when idling & passing data.
Thx

johnbanks · 7 March 2019 00:23

Paul …

‘fastboot’ is what comes with the emonSD image.

I interpret ‘fsck.mode=skip’ to mean - do not do a file system check. Am I incorrect?

I’m not sure I totally understand yr comments re the HDD.
In brief this is what I do …

Burn image to SDHC
Set it up - expanding to fill card, importing backup, emonhub.conf, etc
Then as very last steps …
Change cmdline.txt to use sda1 as rootfs,etc
Change /etc/fstab
Mount the HDD 2 partitions
Copy rootfs & /home/pi/data to the HDD using rsync
Reboot

My revised cmdline has …
elevator=deadline (elevator=deadline is best for USB spinning HDD’s so I’ve read)
root=/dev/sda1
and, at the end, rootdelay=5

My revised /etc/fstab is …

proc                  /proc           proc    defaults          0       0
##PARTUUID=50c2568e-01  /boot           vfat    defaults          0       2
##PARTUUID=50c2568e-02  /               ext4    defaults,noatime,nodiratime  0       1
##PARTUUID=50c2568e-03  /home/pi/data   ext2   defaults,noatime,nodiratime  0    2

# a swapfile is not a swap partition, no line here
#   use  dphys-swapfile swap[on|off]  for that

tmpfs           /tmp             tmpfs   nodev,nosuid,size=30M,mode=1777 0  0
tmpfs           /var/tmp         tmpfs   nodev,nosuid,size=1M,mode=1777  0  0
tmpfs           /var/log         tmpfs   nodev,nosuid,size=50M,mode=1777 0  0

/dev/mmcblk0p1  /boot           vfat    defaults,noatime,nodiratime 0   2
/dev/sda1      /         ext4    defaults,noatime,nodiratime  0       1
/dev/sda2      /home/pi/data   ext2   defaults,noatime,nodiratime  0    2

Tho’ temporarily, I’ve also commented out tmpfs /var/log for all the reasons behind this forum post.

Am I in error?
Pls advise.
Thx

Greebo · 7 March 2019 00:30

The HDD (if you take it out of the case) should have a current rating written on it for both seek and idle… Are the Pi USB ports limited to 500 mA? (I don’t actually recall)

johnbanks · 7 March 2019 00:45

@Greebo

I’ll check the HDD as you suggest.

The emonSD image has max_usb_current=1 set in config.txt and this relates to that …

https://www.raspberrypi.org/forums/viewtopic.php?f=29&t=100244

Thx

Greebo · 7 March 2019 00:49

Ah yes, now I remember using that on mine… hopefully your HDD doesn’t use 1.2A!
It was worth a check