emonSD next steps

emonSD
121

@pb66, just looking at the logs for log2ram and I see this sometimes; does it mean the emonhub log has rotated at that point or that a rotation happened outside log2ram.

sent 2,049,721 bytes  received 9,727 bytes  4,118,896.00 bytes/sec
total size is 9,422,137  speedup is 4.58
sending incremental file list
auth.log
daemon.log
log2ram.log
syslog
emonhub/
emonhub/emonhub.log
emonhub/emonhub.log.1

Couple of observations (been running overnight);

The comment sending incremental file list is not that clear to me as a log comment - are the subsequent files the ones copied?

The log could do with a date time stamp :smiley:.

Looking for the rotated logs and cannot find any. Nothing in /var/log.old. I did create that folder so could that be the issue? Nothing in the logs to suggest an error was found.

All the log2ram output is going into daemon.log as well as log2ram.log.

122

My understanding isn’t in depth enough to know that off hand. Whilst i have had some dealings with it, I only went as deep as I needed. My initial thought is “no” because the deletion of the file is just an indication that the content of that file has been used, not that the changes have applied and stuck.

I think Trystan would say yes. Because there is a notable difference in write levels with the ext2 block sizes. Whether that difference in write levels is absolutly necisary for the target life of the sdcard, I think remains undecided. But this is a near zero running cost optimisation so whilst it does mean a more complex install script needs developing, I see no other reason not to do it.

However, even with the reboot required for L2R, I would recommend we establish exactly what’s happening or take control and stop it happening to be sure of a predictable outcome.

I believe if we looked into it we could get in make arrangements and on rebooting the 3rd partion be ready, L2R be ready and the rootfs expanded. It would be good to use what’s already there.

I was looking into redirecting that path in cmdline.txt so that potentially I could drop a wifi config, blank ssh file and a custom build script into the boot partition, edit cmdline.txt to include `init=/boot/custom_build_script.sh and just let the image self build. This disables the in-built resize and initiates the build script with no interaction. I guess you could even do it without the ssh file once you have got it working 100%.

1 Like
123

I also noticed that there is now a warning message on first boot that the WiFi config is disabled as a country code has not been set. Been a while since I booted a Raspbian image so that may not be new.

124

All you see there is the rsync output redirected to the logfile by L2R unmodified. You should be able to find info about rsync output fairly easily I guess.

Right at the beginning I highlighted L2R is not a finished solution. It’s taken over a year since I first floated the idea of using L2R to get to the point were it gets any consideration at all. I do not maintain the original L2R, but I am willing to develop it for our needs, first we need to establish what they are, then I will look to improve L2R.

I agree timestamped logs are essential. I have already suggested more verbose logs throughout L2R with a user set loglevel. (Look at emonhub for an idea of how I like to do logging.)

We have also discussed L2R providing data to emonhub/emoncms for capture/monitoring eg write stats, logfile sizes, disk usage etc.

Are the permissions and ownership correct on the folder you created? Had you not created the folder, I would have confidently said “in that case no rotations were needed/performed” but cannot now be 100% sure. The folder only gets created automatically IF it doesn’t exist, so I suspect if one does exist, but is not the right permissions, it will fail.

Another thing regarding the logs, logrotate doesn’t actually maintain a log of it’s own. I think it’s output might go to syslog? I have been using redirection in my commandline whilst debugging

sudo logrotate -v /etc/logrotate.conf | sudo tee >> /var/log/logrotate.log

but I would also like to see this output in the L2R logs aswell.

I wasn’t aware of that because there is no log output from L2R in cp mode and since changing to rsync, I had no time to work on this, spent some time looking into rsync rules because Trystan was having issues, moved onto tackling logrotation because you found it wasn’t working and then the discussion got heavily into the logrotation side.

Now there is some interest in using L2R etc, I will start developing further as and when time allows me to, this is something I could have been doing over the last year had there been any interest, but in true OEM fashion we have gone from zero interest to I want it now with no middle ground. My main aim has to be to get it operational for inclusion before we lose interest again, the rest can happen over time.

I will look into the duplicate logs, but at the moment L2R logs hardly anything once an hour so this is a fairly trivial thing until we get more log output, I think if the L2R logging is overhauled to include timestamps and loglevels etc, this would get addressed then anyway. In the meantime, the duplicated logs mean there IS probably a timestamp available via daemon.log if you need one :smile:

125

No That has been around a while. Since this is not an existing emonSD image we can use the in-built wifi settings tool to add wifi at boot. If you include a wpa_supplicant.conf file in the boot partition before booting with something like this content

ctrl_interface=DIR=/var/run/wpa_supplicant GROUP=netdev
    update_config=1
    country=GB
    network={
            ssid="WIFI_SSID"
            psk="WIFI_PSK"
    }

it will start straight up on wifi, no Ethernet required.

This doesn’t work well on oct18 emonSD as the firstboot script doesn’t wait for a network connection so you don’t get the proper initialisation/updates. images prior to that were read-only so the wpa_supplicant.conf file could’nt be copied into /etc/wpa_supplicant so it didn’t work at all.

126

I think that suggests emonhub has made the rotation, what size is emonhub.log.1? is it >5M?

What logrotation command and/or config are you using? The default (by packages) config will not catch emonhub, wildcard “catch all’s” are discouraged in logrotation, the original emonsd logrotation conf did cast a very wide net and it limited everything to 1M.

127

In all cases I’ve done nothing but run the install script.

I’ll delete the log.old folder and see if it self heals. I’ll also put a rsyslog file in place to direct the deamon.log messages to the log2ram log to see what happens. I’d be happy to help with the log2ram development stuff.

128

Just an idea…

If you remove all the output redirection from the script, because stdout and stderr are by default directed to journald and so rsyslog by default as this is run from a service Exec command, you can just catch the log entries with rsyslog

file /etc/rsyslod.d/20-log2rotate

if ( $programname == 'log2ram' ) then {
    action(type="omfile" file="/var/log/log2ram.log")
    stop
}

gives a log file of

Apr 26 10:47:21 emonpi log2ram[3975]: sent 1,051,660 bytes  received 14,654 bytes  2,132,628.00 bytes/sec
Apr 26 10:47:21 emonpi log2ram[3975]: total size is 10,474,113  speedup is 9.82
Apr 26 11:00:33 emonpi log2ram[4034]: sending incremental file list
Apr 26 11:00:33 emonpi log2ram[4034]: auth.log
Apr 26 11:00:33 emonpi log2ram[4034]: daemon.log
Apr 26 11:00:33 emonpi log2ram[4034]: log2ram.log
Apr 26 11:00:33 emonpi log2ram[4034]: syslog
Apr 26 11:00:33 emonpi log2ram[4034]: emonhub/emonhub.log
Apr 26 11:00:34 emonpi log2ram[4034]: sent 468,639 bytes  received 15,829 bytes  322,978.67 bytes/sec
Apr 26 11:00:34 emonpi log2ram[4034]: total size is 10,928,523  speedup is 22.56

Just a thought; YMMV.

129

Yes that would be the intention of “adding proper logging”.

No, this was/is “the issue” with both emonhub and service-runner, both are being resolved by taking control of the output and placing it where we want it before systemd/journald gets hold of it. Even if just for “consistency” we shouldn’t do what we have already ruled out for the other services!

Just a thought now I’ve said that out loud (or rather, typed it out loud?) this is another common factor to emonhub and service-runner besides the fact they are both Python. But the fact they both use an OEM designed service unit and just leave stdout and stderr for the system to handle! (Ref the Emonhub fails to start - #17 by borpin thread).

130

I have no idea what that is without going digging.

I have previously proposed a reader friendly way of formatting the scripts so they are both executable and neatly displayed as informative and accurate documentation, but . . .

131

Could be a combination of python and service-runner, but we have other service file for mqtt for instance.

132

AFAIK (maybe AFAICG “Can Guess”) emonhub and service-runner are the only thing dependent on the system for logging (as it stands currently), both feedwriter and emoncms_mqtt apparently use emonLogger (and are both PHP too?). Or are those changes still waiting in other branches ? I’ve lost track of whats being commit to live master branches and whats being done behind the scenes.

[edit] looks like emoncms_mqtt is emonlogger in stable, feedwriter is fully emonlogger in master only and partial emonlogger in stable. So in stable, only feedwriter partially uses stdout. How frequent those messages are I do not know off hand.

2 Likes
133

Great! I also saw the log2ram error ‘remove write-protected regular file’ and of course the expanded OS partition as you have discussed.

Sure.

I read that this error is always present at this stage and can be ignored.

I would like to revisit that with more testing. For now I think so. Id also like to explore using the inbuilt filesystem buffering & commit, did we actually need to build all of that into emoncms in the first place…?

1 Like
134

There where 4-5 logs every buffered write, so by default 60s. Yes these are in master but not stable as you correctly point out.

135

My intention is to come back to this at the end or perhaps on release v2 of the build script, Im not 100% sure that is works when there are lots of if then type statements and variable use. As the user is then looking at more complex code blocks rather than single line installation commands… I wonder if it would be better to direct the user to the scripts themselves and not cause confusion with .md extentions. Im not rulling this out but not sure its the right way to go. I think its one to come back to as we are already doing a lot of things in parallel for this first release.

1 Like
136

Running the installed script overnight and log folder seems fine except for two things.

@pb66, there is more than one file in the tree called error.log

 pi@emonpi:/var/log $ ls -lah /var/log/*/error*
-rw-r----- 1 root  adm  243 Apr 27 00:17 /var/log/apache2/error.log
-rw-r----- 1 mysql adm    0 Apr 27 00:17 /var/log/mysql/error.log

When they rotate you don’t know which is which in the rotated_logs folder and the subsequent rotation could be all at sea.

Secondly, I’m still not finding a set of emonhub logs that could be used for debugging. Where should they be?

pi@emonpi:/var/log $ ls -lah rotated_logs/
total 260K
drwxr-xr-x  2 root        root 4.0K Apr 27 00:17 .
drwxr-xr-x 14 root        root 4.0K Apr 26 11:35 ..
-rw-r-----  1 root        adm   12K Apr 27 00:17 error.log.1-2019042700.backup
-rw-rw----  1 mysql       adm  1.6K Apr 25 22:36 error.log.1.gz
-rw-r--r--  1 root        root  15K Apr 27 00:17 log2ram.log.1
-rw-r-----  1 Debian-exim adm  3.2K Apr 27 00:17 mainlog.1
-rw-r-----  1 root        adm  214K Apr 27 00:17 syslog.1
137

We seem to have jumped threads, this is really part of the longer “logrotation” discussion in emonSD next steps: filesystem & logrotate, which IMO should have actually been in the emonSD next steps: log2ram thread to keep that all together, but one might argue the emonhub log question should be in emonSD next steps: emonhub logging. This has become a bit crazy and foggy too. I’m not sure any of these threads are going to make sensible reading at a later date, unless you read them all at once in chronological order (ie as one thread).

As previously stated.

I didn’t get as far as exploring what might happen to similarly named log files, I didn’t like the “all in one pot” approach regardless of how that might pan out. But that said. logrotation might be able to distinguish between the logs by file meta (ownership etc) and the different extn’s, I don’t know for sure, but either way, I would rather see the folder structure retained by using more than one olddir path. The alternative would be to instruct logrotation to add a prefix identifier, but that would also require a per conf edit, so no gain over the separate olddirs option.

They should be where the logrotation config defines where they should be

you know logrotation is working because there are other files rotated, so the question is what is logrotation doing (or not doing) with the emonhub logs? Has emonhub been catered for in what you have installed?

My opinion on how the configs should work seems to differ to both your’s and Trystan’s opinion, I do not know what has/hasn’t been decided or coded, nor do I know if whatever might have been coded has installed correctly, or is functioning correctly.

So what do YOU have in the way of config? If it’s just the packaged default config’s, no further logrotation for emonhub beyond it’s own >5M rule would be the expected behaviour. Are you confirming the expected behaviour or is there something in the config that makes you expect something different?

138

There is no logrotation config currently installed as part of the installation script process. Not quite sure where we have got to with this either. This was my last post on the subject where I say that I see your point regarding potentially needing a global override: https://community.openenergymonitor.org/t/emonsd-next-steps-filesystem/10693/144