Errors not reported in emonpiupdate.log file

Hardware emonPi
1

Continuing the discussion from Mqtt_input script run as systemd instead of initd:

Glyn - I ran the emonPi Update to get the mqtt_input script changes. The script seemed to run OK and there were no errors in the emonpiupdate.log. But there were two areas that did not update. Can the errors (or some hints) be added back into the emonPi Update log?

An emonpiupdate.log update usually displays the files changed:

Updating db0e857..76b78ad
Fast-forward
 Modules/feed/Views/feedlist_view.php |  2 +-
 Modules/user/profile/profile.php     |  2 +-

 
But these two areas did not update:

git pull /home/pi/emonpi
Updating 0ce7f23..2d27aeb
...
git pull /home/pi/emonhub
Updating 24205b5..9ab0f49
git pull ...

 
So I ran the git pull command by hand:

rpi-rw
cd /home/pi/emonpi
git branch
git pull

 
and got this error:

Updating 0ce7f23..2d27aeb
error: Your local changes to the following files would be overwritten by merge:
	rc.local_jessieminimal
Please, commit your changes or stash them before you can merge.
Aborting

 
The git pull /home/pi/emonpi and the git pull /home/pi/emonhub both had this error:

error: Your local changes to the following files would be overwritten by merge:

2017-01-06 at 14.47.43 - emonpiupdate.log.txt (2.7 KB)

2

It sounds like you’ve made edits to the code on your emonPi at some point, you are right the updated files are normally listed unless you get the “already up to date” message, if you don’t get one or the other the pull failed.

You can use git diff to view any changes either the whole repo in one go or by specifying a specific filename eg git diff rc.local_jessieminimal(from within the right directory).

Using git stash will record the changes so you can reapply them at a later date should you choose or you can force a pull or checkout to loose the changes. or just manually undo them, which ever method you use once the changes are undone a git pull or emonpi update should work.

3

Yes I did make changes to two files. I was following a topic and trying some of the changes (It may have been your changes!).

I knew there would be changes I needed to toss (or stash) away and I was expecting the Please, commit your changes or stash them before you can merge errors. What threw me was there were no errors in the emonpiupdate.log file. To me it seems wrong.

4

I see what you mean, I think that might be due to the command being run from within a script rather than a terminal. The “error” message is probably send to stderr and when run from a terminal, both stdout and stderr are sent to the screen, but not from a script.

If that is the case redirecting each git pull’s stderr to stdout in the update script would give a better output. I would need to experiment to confirm if that was the case though.

5

Yeah I noticed that. I have no idea why the git pull messages are not being
passed to the log. I haven’t changed anything to my knowledge. Maybe it’s a
git issue. I agree, it would be very useful to have git report any issues
with a git pull.

  • sent from my mobile device
6

@Jon can you run this one liner and post the emonpiupdate.log it creates?

rpi-rw && rm /home/pi/data/emonpiupdate.log && sudo /home/pi/emonpi/firstbootupdate

You won’t be able to see the logfile “live” in emoncms but you can still download it that way.

The command is only forcing a “firstbootupdate” without a reboot. It’s the same update process, just started differently…

7

seemed to run A-OK. I already corrected the changed files (i.e., rc.local_jessieminimal) so there were no stash/merge type errors.

2017-01-07 at 14-09-31 - emonpiupdate.log.txt (5.7 KB)

8

That would be only if redirected by /dev/null 2>&1 wouldn’t it? i.e. to force no console output during script execution.

Unless redirected as above, I’ve seen both stdin and stderr display output on the console during script execution.

9

The way the emonpi update scripts “log” is simply to redirect “the output” to a file instead of the screen. Because the scripts are running other command line utilities some of the “output” from them can be either stdout or stderr (and some can even detect if they are being run from the command line and redirect stderr to stdout in that instance).

The point here is that there are no “error” messages being logged to /home/pi/data/emonpiupdate.log with a standard emonpi update via emoncms, but I found they are logged via a “firstbootupdate”.

The standard emonpi update seems to be done by the command /home/pi/emonpi/service-runner-update.sh > /home/pi/data/emonpiupdate.log being issued from the cron controlled service-runner, If I run that command from the commandline I see all the missing messages in the terminal as they are not being redirected to emonpiupdate.log.

That output in the terminal is incomplete and although recognizable, it doesn’t make much sense as the bulk of the output is going to “emonpiupdate.log”. I have since found all the missing messages are sometimes logged to /var/log/service-runner.log.

By editing the service-runner @ line 21 to

$script 2>&1 >> $logfile 2>&1

so the command actually issued is

/home/pi/emonpi/service-runner-update.sh 2>&1 >> /home/pi/data/emonpiupdate.log 2>&1

it matches the command issued by the firstbootupdate but the log still isn’t as complete, there are still error messages not being passed to emonpiupdate.log and landing in service-runner.log instead, despite the same command with the same redirects.

I have also noticed that although it says to add “/home/pi/emonpi/./firstbootupdate” to /etc/rc.local in the firstbootupdate script this seems to have changed at some point to be

su pi -c '/home/pi/emonpi/./firstbootupdate'

so that previous “test” command was effectively incorrect and should have been

rpi-rw && rm /home/pi/data/emonpiupdate.log && /home/pi/emonpi/firstbootupdate

ie no sudo, I had put that in because rc.local is run as root but the “su pi” will run it as user pi. Alas this doesn’t resolve the missing messages, but it does explain the

update running as root: remove sudo crontab service runner entries
switching to Pi user & restarting script

**MANUAL SYSTEM REBOOT REQUIRED**

Please shutdown and reboot emonPi then run Update again

in @jon’s last log.

Although you had resolved all the local change stashes etc, this latest log has all the branch details that were previously missing and the avrdude printout is back, the pip version notice is there and there seems to be some errors reported about the new mqtt_input unit too.

With the edit to the service-runner above the output to service-runner.log on my emonPi is currently

STARTING: /home/pi/emonpi/service-runner-update.sh > /home/pi/data/emonpiupdate.log
You are using pip version 8.1.2, however version 9.0.1 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.

avrdude-original: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 0.00s

avrdude-original: Device signature = 0x1e950f
avrdude-original: NOTE: "flash" memory has been specified, an erase cycle will be performed
                  To disable this feature, specify the -D option.
avrdude-original: erasing chip
avrdude-original: reading input file "/home/pi/emonpi/firmware/compiled/latest.hex"
avrdude-original: input file /home/pi/emonpi/firmware/compiled/latest.hex auto detected as Intel Hex
avrdude-original: writing flash (17898 bytes):

Writing | ################################################## | 100% 2.52s

avrdude-original: 17898 bytes of flash written
avrdude-original: verifying flash memory against /home/pi/emonpi/firmware/compiled/latest.hex:
avrdude-original: load data flash data from input file /home/pi/emonpi/firmware/compiled/latest.hex:
avrdude-original: input file /home/pi/emonpi/firmware/compiled/latest.hex auto detected as Intel Hex
avrdude-original: input file /home/pi/emonpi/firmware/compiled/latest.hex contains 17898 bytes
avrdude-original: reading on-chip flash data:

Reading | ################################################## | 100% 1.92s

avrdude-original: verifying ...
avrdude-original: 17898 bytes of flash verified
strace: |autoreset: Broken pipe
strace: |autoreset: Broken pipe
strace: |autoreset: Broken pipe
strace: |autoreset: Broken pipe
strace: |autoreset: Broken pipe

avrdude-original done.  Thank you.

strace: |autoreset: Broken pipe
Already on 'emonpi'
Failed to restart mqtt_input.service: Unit mqtt_input.service failed to load: Invalid argument. See system logs and 'systemctl status mqtt_input.service' for details.
COMPLETE: /home/pi/emonpi/service-runner-update.sh > /home/pi/data/emonpiupdate.log

This is also where any messages from git about local changes aborting a pull sometimes end up, I’m now guessing it depended on which method I had used (service-runner or firstbootupdate) but there are very clear differences between the 2 methods that go beyond the make up of the command line and I have not managed to locate why yet and to be honest I feel it might be beyond me.