Development Roadmap 2019 - Robust Backup Process

TrystanLea · 2019-01-19T00:00:55.789Z

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…?

borpin · 2019-01-19T05:33:37.479Z

TrystanLea:

could it be session related?

@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.

Greebo · 2019-01-19T06:22:14.773Z

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

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

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

borpin · 2019-01-19T06:24:40.393Z

yip - it is your vastly improved version

root@DietPi-EmoncmsVM:/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

Greebo · 2019-01-19T06:28:44.588Z

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?

borpin · 2019-01-19T06:33:42.342Z

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

Greebo · 2019-01-19T06:40:36.506Z

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

I’m sure that worked previously…

Greebo · 2019-01-19T06:42:38.615Z

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

pi@emonpi(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 ?

borpin · 2019-01-19T06:59:19.330Z

Greebo:

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.

Greebo · 2019-01-19T07:05:25.288Z

Turns out I need sudo to use journalctl

pi@emonpi(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?

borpin · 2019-01-19T07:10:05.845Z

Greebo:

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?

Greebo · 2019-01-19T08:36:02.376Z

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

borpin · 2019-01-20T17:21:36.490Z

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.

Greebo:

If you stop service-runner first, then trigger a backup

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

@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?

borpin · 2019-01-20T17:53:05.530Z

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

pb66 · 2019-01-20T18:29:20.802Z

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)

Greebo · 2019-01-20T21:16:56.158Z

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.

borpin · 2019-01-20T21:55:02.015Z

Greebo:

I’m glad we ended up getting to the bottom of your backup issues Brian.

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

borpin · 2022-06-21T20:29:56.205Z

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

Not sure why this has not been noticed before.

github.com/emoncms/emoncms

service-runner.py ignores backup and postprocess requests when emoncms prefix set to "emoncms"

opened 03:43PM - 26 Feb 22 UTC

steversig

emonSD-21Jul21 on a Raspberrypi 3B manually running emoncms-export.sh works … /default-settings.ini:43:; Only a prefix of 'emoncms' or '' will be recognised by service-runner Only "" works on emonSD-21Jul21 which I think covers 95% of the users If you installed it direct from Git then I think that you get a prefix of 'emoncms' which is what my other emoncms setup has Cause of problem is /var/www/emoncms/scripts/services/service-runner/service-runner.py line 15 KEYS = ["service-runner", "emoncms:service-runner"] KEYS are what keys service-runner processes "emoncms:service-runner" has a ":" in the middle of it but the php scripts that set a redis prefix do not add the ":" So service-runner.py ignores the requests $ cd /var/www/emoncms $ grep -rnw . -e '$redis->setOption' *.php ./scripts/feedwriter.php:37: if (!empty($settings['redis']['prefix'])) $redis->setOption(Redis::OPT_PREFIX, $settings['redis']['prefix']); ./scripts/input_queue_processor.php:32: if (!empty($redis_server['prefix'])) $redis->setOption(Redis::OPT_PREFIX, $redis_server['prefix']); ./scripts/services/emoncms_mqtt/emoncms_mqtt.php:86: if (!empty($settings['redis']['prefix'])) $redis->setOption(Redis::OPT_PREFIX, $settings['redis']['prefix']); ./scripts/export_montly_cron.php:38: if (!empty($redis_server['prefix'])) $redis->setOption(Redis::OPT_PREFIX, $redis_server['prefix']); ./scripts/phpmqtt_input.php:88: if (!empty($settings['redis']['prefix'])) $redis->setOption(Redis::OPT_PREFIX, $settings['redis']['prefix']); ./index.php:40: $redis->setOption(Redis::OPT_PREFIX, $settings['redis']['prefix']); index.php:40: $redis->setOption(Redis::OPT_PREFIX, $settings['redis']['prefix']); **Quick fix** Remove ":" from service-runner.py line 15 KEYS = ["service-runner", "emoncmsservice-runner"] **To reproduce** set settings.ini to [redis] prefix = 'emoncms' restart web server submit a Backup from Backup, Export, Create Backup - nothing happens $ redis-cli --scan | grep emoncmsservice-runner emoncmsservice-runner $ redis-cli LRANGE emoncmsservice-runner 0 -1 1) "/opt/emoncms/modules/backup/emoncms-export.sh /tmp/emoncms-flag-export>/var/log/emoncms/exportbackup.log" Wait a while and its still there and I get no export I think that this has been in there rather a long time as the previous version of emonSD had the bug too. I just got mired in redis php versions and ended up running the shell scripts when I couldn't work out what was causing it

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

Greebo · 2022-06-22T06:48:02.432Z

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…

borpin · 2022-06-22T12:31:29.007Z

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)