This is the file, when written to /etc/rsyslog.d/10-emonhub.conf will catch emonhub log messages written to journald by the service logging and forwarded on to rsyslog (the default setup).
template(name="EmonhubMsg" type="string" string="%msg:::drop-last-lf%\n")
if ( $programname == "emonhub" or $programname == "emonhub.py" ) then {
action(type="omfile" file="/var/log/emonhub.log" template="EmonhubMsg")
stop
}
It should work without any modification to the service file (but the service file should not specify a log path).
sudo systemctl restart rsyslog.service
to start it.
[edit] This link was really useful in understanding the rsyslog script.
I reminded Trysrtan of that only just yesterday, my memory might be bad but not that bad!
You are not talking about redirecting per se, you are talking about systemd routing the logfile. I am talking about redirection of stdout and errout as part of the command/script so as to avoid systemd/journald getting involved at all, just like the emonhub setup (with --logfile in the unit) and emoncms. Going back to how the logfiles were generated before everything migrated to systemd.
For example with a shell script you could add
exec 2>&1 1>/var/log/scriptname.log
just under the shebang, or alternatively for a python script
this will put stdout to a logfile directly and doesnât need the missing systemd directive, plus it doesnât just leave stdout to be mopped up by journald etc. Although I havenât tested it, just clarifying what I meant ie NOT using unavailable functions, just common redirection.
I see no reason installing L2R would be problematic, all images have /var/log in tmpfs and if they are a RO OS we can just addsymlinks so the files actually end up in /data (RW partition rather than rootfs)
I think your getting confused there, the rotations are never in RAM with L2R+ (with my olddir mods). The only time you might need additional space in ram to perform the rotations would be if you are using copytruncate which I think we agreed was a bad idea. Avoiding using valuable RAM for rotated logs is precisely why I did the olddir mod to L2R.
Iâm sure this is a misunderstanding too, the "Rather than âpulling outâ I would favour ânot putting inâ, comment was aimed squarely at the systemd units that are just letting stdout go to syslog etc emoncms doesnât use systemd, itâs not a service. Iâm referring to service-runner and emoncms-mqtt etc (feedwriter logs direct to emoncms.log now doesnât it?)
[edit] With regard to logs for emoncms services such as service-runner and emoncms-mqtt, can we please clarify what it is we want? IMO the way the init scripts used to work was spot on. The service start, stops and errors went to journald and the scripts general running logs went to script.log, this was great for debugging and it was consistent with everything else from emonhub and emoncms through to apache2, mosquitto, redis, mysql etc etc etc. Now it seems that we are trying to force all the data together into journald and then possibly filter it out again??? I hope Iâm wrong as that seems really bizzare. Plus it is really confusing things.
I feel the move to use emonlogger was right and it IS consistent, what else doesnât bother managing itâs own log files and expects systemd to do it? Iâve been arguing against emonhub doing that since it was changed to systemd and adding the --logfile arg back in resolves that, AFAIA that only leaves service-runner and maybe emoncms-mqtt that are âinconsistentâ and not logging to a logfile directly?
There are comments made like agreeing that these services should have their logs in the /var/log/emoncms folder which make me think weâre on the same page and then there are comments about custom scripts to pull out the logs from the journal that confuse things again, why put them in to the one pot if you have to separate them again? Just donât put them in! Plus even if we do separate them again, will it not bring the service start/stop/error messages that DO belong in journald out with them, no?
Yes I realised that and Iâm suggesting that is a better to use the OS logging mechanisms. The redirection of output was removed with systemd, presumably for good reason. However I can see some benefit of creating your own, but I would prefer the rotation to be done outside of the script.
Yes and no. Will this keep all the emonhub logs you feel are necessary? As I write this I realise that the sort of concatenating I am doing could be done out of olddir with a postrotate command so yes your original suggestion works.
Ah, now that is an interesting differentiation. I wondered if my catch script for rsyslog would pick up the start stop but it does. (warning log is in reverse) - you can see the normal logging and then the entries when I restart the service.
Apr 24 18:36:46 emonpi emonhub.py[3916]: 2019-04-24 18:36:46,573 INFO MainThread Setting RFM2Pi group: 210 (210g)
Apr 24 18:36:45 emonpi emonhub.py[3916]: 2019-04-24 18:36:45,571 INFO MainThread Setting RFM2Pi frequency: 433 (4b)
Apr 24 18:36:45 emonpi emonhub.py[3916]: 2019-04-24 18:36:45,570 INFO MainThread RFM2Pi device firmware version & configuration: not available
Apr 24 18:36:43 emonpi emonhub.py[3916]: 2019-04-24 18:36:43,563 DEBUG MainThread Opening serial port: /dev/ttyAMA0 @ 38400 bits/s
Apr 24 18:36:43 emonpi emonhub.py[3916]: 2019-04-24 18:36:43,561 INFO MainThread Creating EmonHubJeeInterfacer 'RFM2Pi'
Apr 24 18:36:43 emonpi emonhub.py[3916]: 2019-04-24 18:36:43,560 INFO MainThread Logging level set to DEBUG
Apr 24 18:36:43 emonpi emonhub.py[3916]: 2019-04-24 18:36:43,560 INFO MainThread Opening hub...
Apr 24 18:36:43 emonpi emonhub.py[3916]: 2019-04-24 18:36:43,559 INFO MainThread EmonHub emonHub emon-pi variant v2.1.2
Apr 24 18:36:40 emonpi systemd[1]: Started emonHub service description.
Apr 24 18:36:40 emonpi systemd[1]: Stopped emonHub service description.
Apr 24 18:36:40 emonpi systemd[1]: Stopping emonHub service description...
Apr 24 18:36:37 emonpi emonhub.py[530]: 2019-04-24 18:36:37,051 INFO MQTT Publishing: emonhub/rx/5/values 79,0,79,236.73,0,0,0,0,0,0,0
Apr 24 18:36:37 emonpi emonhub.py[530]: 2019-04-24 18:36:37,049 DEBUG MQTT Publishing: emon/emonpi/pulsecount 0
Apr 24 18:36:37 emonpi emonhub.py[530]: 2019-04-24 18:36:37,047 DEBUG MQTT Publishing: emon/emonpi/t6 0
What happens if you restart the emonhub service? Where do those messages end up? In the Emonhub.log or output to journald?
I can see the logic of splitting the logging like that. Perhaps, if the running log messages went to stdout, and we could pick up all the other status & error from the various services into a specific emon-error.log?
I modified emoncms_mqtt to use the emoncms logger same as for feedwriter. For service-runner there is a logfile for each script that service runner runs, the log file is specified usually in the part of emoncms that sends the command to service-runner. I envisage changing the location of these logs to /var/log/emoncms/ e.g /var/log/emoncms/sync.log & /var/log/emoncms/update.log (instead of
/home/pi/data/emoncms-sync.log) - these logs dont touch the systemd logging system.
As for service-runner that is currently using systemd as far as Im aware, with logs of the form (Im open to a different configuration here):
pi@emonpi:/var/log $ journalctl -f -u service-runner
-- Logs begin at Wed 2019-04-24 18:17:23 BST. --
Apr 24 18:17:37 emonpi systemd[1]: Started Emoncms service-runner Input Script.
Apr 24 18:17:38 emonpi service-runner[649]: Starting service-runner
Apr 24 18:17:38 emonpi service-runner[649]: Connected to redis-server
Apr 24 19:13:42 emonpi service-runner[649]: Got flag: /opt/emon/modules/sync/emoncms-sync.sh>/opt/emon/data/emoncms-sync.log
Apr 24 19:13:42 emonpi service-runner[649]: STARTING: /opt/emon/modules/sync/emoncms-sync.sh > /opt/emon/data/emoncms-sync.log 2>&1
Apr 24 19:13:42 emonpi sudo[1692]: pi : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/php /opt/emon/modules/sync/sync_run.php
Apr 24 19:13:42 emonpi sudo[1692]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 24 19:13:44 emonpi sudo[1692]: pam_unix(sudo:session): session closed for user root
Apr 24 19:13:44 emonpi service-runner[649]: COMPLETE: /opt/emon/modules/sync/emoncms-sync.sh > /opt/emon/data/emoncms-sync.log 2>&1
Which I think is not right, it certainly is not consistent, I get the scripts actioned BY service-runner will have (and should have) their logfiles defined in the command, but I do not think the connection and step by step confirmations of service-runner operation should be in journald (that should just be start/stop/error of the service unit not the service-runner operations) that should go to another log, either to emoncms.log (as per emoncms-mqtt and feedwriter) or itâs own /var/log/emoncms/service-runner.log. either way, it should not (IMO) just be left to stdout so that journald gets it (and we then filter it out again?)
Fantastic!
They have always gone to the system log, thatâs why when we do debugging we ask for (for example) emonhub.log AND a sudo systemctl status emonhub, the latter tells us if itâs running etc, but it also gives us the last few entries of the journald to show when it was restarted or last stopped etc etc, this data will be lost in the depth of the emonhub.log or rotated out very fast if put with the general emonhub logs (either in journald or in emonhub.log).
This sounds like additional writes, when ever existing logs are concatenated with newer logs it is going to add to the writes, I like the aim to be tidier, but I do not think it is feasible, itâs complex and itâs costly, but either way, it would be done post rotation so it doesnât change anything for the actual rotation, it can be added/removed at a later date.
I donât know what you are asking there, the logrotation count will define how many logs are kept.
Where should it log to? If it should log to emonCMSâs log file, how does it determine which instance of emonCMSâs logs it should write to if there are more than one? If youâre going to standardise on a single /var/log/emoncms/ logging folder across installations/distributions etc. then it would certainly make sense for it to log its activity there into its own file.
It would probably be a simple matter to just add a --logfile option to the service-runner python script and write to that instead of stdout if it was provided. Then the log location could be supplied in the service unit file in the ExecStart directive as has been discussed previously.
I can see emonhub rotating its own log and agree that it would be best to do this with logrotate as we can then control the other aspects such as compression and move of rotated logs to @pb66âs log2ram rotated_logs folder
That is different things (I think). Either you let emonhub rotate the logs itself (embedded code in python script) or you let logrotate do it or logrotate, rotates the log rotated by the script .
Of course we are talking about the standard setup. Can be setup differently by the user.
Yes it is but gives a fuller picture over a period of time which could be useful but all the graphs above were doing this and it did not seem excessive over the L2R writes. We could try it and see. The tradeoff may be worthwhile. For me personally, emoncms is on a VM so Iâm more interested in logs I can review, than disk writes (and that may be something to consider in the install scripts).
You have mentioned before about the usefulness of the emonhub logs in debugging. The question is, what is the minimum requirement (in terms of time).
Ok so that can continue (with a little config to pull out just our services log entries rather than having to wade through the syslog or daemon.log). Trouble with doing it via journald is that this information is not persistent and rotates out quickly so it would be good to pull that information out so we can persist it in one place.
That is what has happened here - this is a rsyslog extracted log file of just the emonhub message part. If we were extracting the system messages, Iâd suggest pulling them out verbatim.
Of course! I had over looked the multi-instance aspect, thanks @Greebo. I agree itâs own log in /var/log/emoncms would be ideal. Even if we did log service-runners messages to each respective emoncms, there would still be some instance neutral messages like handling the redis connection, so separate is the way to go I think. And just for the record, I wasnât criticising service-runner, just highlighting service-runner wasnât the same as the others (since the others have changed) and trying to determine what was actually wanted/needed. If service-runner needs to be different thatâs great, it just shouldnât be the template for consistency if it is in fact the âodd ballâ.
Excellent, I didnât labour the point yesterday as I was sure you would think that way once you had seen the rotation happen. The emonhub rotation is great as a safety net, but the files (IMO) are a bit large and emonhub only keepâs the 2 files in play so the history can be short despite the large files. Plus when emonhub rotates, that is a 5M chunk of ram lost until the next L2R+logrotation.
I think the emonhub logrotation config should rotate sooner (at 2 or 3M) and keep more than just 2 files, it will make handling the files easier and cover a longer period. length of retention has been debatewd a couple of times, this is a small detail that can be decided once we are fully up and running, I think it is a trivial decission, there is no point keeping just a couple of files and I donât think anyone expects over a month under any circumstance, so the window isnât that great and debating between 1 week or 2 will not effect the way it works or the size in ram or the write rate with any significance, the existing logs are just renamed (incremented +1) so usefulness vs size on disk are the only real factors.
Just in case emonhub does perform a rotation, the emonhub logrotation conf should also have a pre-rotation script to check and cater for the extra emonhub.log file in ram as part of the overall rotation if possible rather than a double rotation. But this should rarely if ever be called upon if the overall logrotation is effective.
ok great, happy with keeping it in as a safety net, does the size need to be increased >5MB, will logrotate catch it in time? will we otherwise need monit?
Looking at the system service log entries, To pull them into a single log file all that is needed is a series of files in /etc/rsyslog.d named e.g. 10-rsyslog-emonhub.conf of the form
if ( $programname == "emonhub" or $programname == "emonhub.py" ) then {
action(type="omfile" file="/var/log/emoncms/emon-services.log")
stop
}
where the progname need to be correctly identified.
Each configuration file can be installed with the service as it is installed.
Assuming all normal output is going to a specific log entry, this should only capture the other system messages.
I have no idea, I would define the period of retention as âas much as the space on disc permits without being sillyâ keeping a log that is already written doesnât add any additional write load so there is no rush to delete old logs. But that can get out of hand, Iâm not suggesting we keep months and months. In fact as I write this Iâm thinking the rotations must be by size because of the fixed amount of ram we have available to logs and the space on disc is the only real limit in how long to keep files, so the âhow longâ in days will depend heavily on the loglevel and the number of devices and target emoncmsâs etc.
It is if you just add /var/log/journal (plus a logrotation conf?)
Only when it is being fed the output from emonhub and all the other stuff! It ran fine previously.
I really do not think this is needed or even a good idea IMO.
Just as a general query, different processes all writing to the same file isnât going to be an issue is it? I have a feeling feedwriter is now writing to the main log file now. Just askingâŚ