Development Roadmap 2019 - Robust Backup Process

Thanks for trying @borpin, could it be session related? The backup module requires administration privileges https://github.com/emoncms/backup/blob/master/backup/backup_controller.php#L29 it is currently hidden with any other level of access. You may need to disabled rememberme cookie based login if your using that…?

@TrystanLea - no I don’t think so. I can switch to the Admin screen. Just to be clear, I can now get to the backup page, just when I try an Export, I can see the export and import logs being called (in a separate admin page) but nothing appears in the log screen and no export is created.

The backup process is triggered by service-runner, is that still running?

Is it the right one?
There’s 3 x service runners:

  1. a cron-driven bash based service-runner that is triggered by flag files stored in the filesystem
  2. a cron-driven bash based service-runner that is triggered by a redis value
  3. a systemd managed python based service-runner that is triggered by a redis value.

yip - it is your vastly improved version :smile:

[email protected]:/var/www2/backup# systemctl status service-runner.service
● service-runner.service - Emoncms service-runner Input Script
   Loaded: loaded (/usr/lib/systemd/system/service-runner.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2019-01-18 20:38:20 GMT; 9h ago
 Main PID: 823 (python)
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/service-runner.service
           └─823 /usr/bin/python /var/www/emoncms/scripts/services/service-runner/service-runner.py

Jan 18 20:38:20 DietPi-EmoncmsVM systemd[1]: Started Emoncms service-runner Input Script.
Jan 18 20:38:49 DietPi-EmoncmsVM service-runner[823]: Starting service-runner
Jan 18 20:38:49 DietPi-EmoncmsVM service-runner[823]: Connected to redis-server

Ok, from memory it should log whenever it runs a process - is there anything in the log? There’s nothing in the log extract that appears in your post just now… I wonder if the backup process isn’t pushing the right value to redis?

There is nothing in the log when I push the button. The code looks OK. Debug set to 1 in EmonCMS.

I meant the log for service-runner… but I’ve just tested it here and (despite there being “print” statements in the script) there doesn’t appear to be anything logged in the syslog :frowning:

I’m sure that worked previously…

1 Like

Ok, turns out there IS stuff in the syslog!
Here’s my syslog:

[email protected](ro):~$ tail /var/log/syslog
Jan 19 06:35:17 emonpi service-runner[6731]: Got flag: /home/pi/backup/emoncms-export.sh /tmp/emoncms-flag-export>/home/pi/data/emoncms-export.log
Jan 19 06:35:17 emonpi service-runner[6731]: STARTING: /home/pi/backup/emoncms-export.sh /tmp/emoncms-flag-export > /home/pi/data/emoncms-export.log 2>&1

I have no idea why journalctl -u service-runner says nothing could be found…

What do you get if you run: grep service-runner /var/log/syslog ?

I’m running dietpi in ramlog mode so there is no syslog file! I can access by journctl, but like you there is nothing there.

[edit]
journalctl --system | grep service-runner gives me the same except this warning (which is interesting).

Jan 18 20:48:04 DietPi-EmoncmsVM systemd[1]: Configuration file /usr/lib/systemd/system/service-runner.service is marked executable. Please remove executable permission bits. Proceeding anyway.

Turns out I need sudo to use journalctl :frowning:

[email protected](ro):~$ sudo journalctl -u service-runner
-- Logs begin at Wed 2019-01-02 02:20:01 UTC, end at Sat 2019-01-19 07:02:26 UTC. --
Jan 19 06:35:17 emonpi service-runner[6731]: Got flag: /home/pi/backup/emoncms-export.sh /tmp/emoncms-flag-export>/home/
Jan 19 06:35:17 emonpi service-runner[6731]: STARTING: /home/pi/backup/emoncms-export.sh /tmp/emoncms-flag-export > /hom
Jan 19 06:35:17 emonpi sudo[7459]: pi : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm /home/pi/data/emoncms.sql
Jan 19 06:35:17 emonpi sudo[7459]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 19 06:35:18 emonpi sudo[7459]: pam_unix(sudo:session): session closed for user root
Jan 19 06:35:18 emonpi sudo[7470]: pi : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/service feedwriter stop
Jan 19 06:35:18 emonpi sudo[7470]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 19 06:35:18 emonpi sudo[7470]: pam_unix(sudo:session): session closed for user root
Jan 19 06:45:38 emonpi sudo[10175]: pi : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/service feedwriter start
Jan 19 06:45:38 emonpi sudo[10175]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 19 06:45:46 emonpi sudo[10175]: pam_unix(sudo:session): session closed for user root
Jan 19 06:45:46 emonpi service-runner[6731]: COMPLETE: /home/pi/backup/emoncms-export.sh /tmp/emoncms-flag-export > /hom

Since you’re running as root, that shouldn’t be your issue. Service-runner should be logging something if it is triggered though - maybe check redis to see if the key is logged?

I was reasonably sure service-runner was working as I think the mqtt output uses it now? If not is there any way to test it?

How can I check redis?

If you stop service-runner first, then trigger a backup, there should be a command waiting in redis for service-runner to execute.

You can grab that command using redis-cli lpop service-runner from a bash prompt - as long as service-runner is not running when you triggered the backup :slight_smile:

1 Like

Sorry for the delay. In checking this through, I discovered I wasn’t running of a linked version of service-runner but rather one I had copied across when you were developing this.

Backup is too cute for that, it checks for service-runner running (a good thing normally) :slight_smile:

@TrystanLea, see below still not sure what is preventing this working. Something is failing silently.

[edit] @Greebo, trying to think of ways to debug this:

  • Is there a way to monitor redis? I found a log but there is nothing in it.
  • Is there any way to sent a test message to redis for service-runner from the command line?

Backup is definitely getting to the point of sending the key to redis.

So I have discovered redis-cli --slave The command is definitely getting to redis…

"RPUSH","emoncms:service-runner","/var/www2/backup/emoncms-export.sh /tmp/emoncms-flag-export>/var/www2/data/emoncms-export.log"

Should I see that service-runner pulls the token off? If I try an lpop there is nothing there.

Does service runner do any checks on the command given or the return value?

I am wondering if it is file permissions again.

Could service-runner emit a heartbeat to the syslog?

Hi @Greebo, found the problem - service-runner is looking for service-runner in Redis, when in fact I have emoncms:service-runner. I think this was the recent change to the Redis options in settings.php.

I’ll open an Issue. Redis prefix in service-runner · Issue #1167 · emoncms/emoncms · GitHub

[edit] Also explains why the command redis-cli lpop service-runner returned nill. When I changed the python script, it started creating a whole load of backups :joy::joy::joy::joy:

1 Like

See related emonPi service-runner now uses redis (core, wifi, sync & postprocess module updates required) discussion ( I’ve added this link to the github issue too)

1 Like

As indicated in the linked thread, I’ll revisit that python code for service-runner (probably tonight at this stage) and submit a PR. I’m glad we ended up getting to the bottom of your backup issues Brian.

1 Like

Thanks. It is quite nice to find solutions and learn some stuff along the way.

@bwduncan - can you have a look at this, please?

Not sure why this has not been noticed before.

I also found this thread Multi-instance service-runner @Greebo has the behaviour of Redis changed do you know such that the colon isn’t added by default anymore after the prefix?

@TrystanLea FYI

I had to re-read that thread to re-familiarise myself with the discussion… I’m not sure it ever went anywhere though. Certainly re-reading that thread didn’t trigger any recollections!

Searching for any posts I’d made since that linked topic related to redis, I couldn’t find anything…

1 Like

I think phpredis may have changed and the delimiter (colon) is no longer added. I note the examples all have a colon at the end of the prefix.

I suggest this has not been noticed as 99% do not use the prefix.

The solution I feel would be to add a comment to the effect that the only prefix that should be used is "emoncms:" (with a colon)