Monitoring systemd service activation times

Question

I'd like to be able to retrieve from systemd how much time the last activation of a oneshot service took. I thought about the following options, but they didn't manage to convince me completely :

1. Compute InactiveEnterTimestamp - InactiveExitTimestamp, e.g. by reading them through the D-Bus interface in Python. This has the disadvantage of being inconsistent (=negative) while the service is running.

2. Use helper scripts in ExecStartPre and ExecStartPost to store a timestamp and compute the elapsed time once the service exits.

3. Use a wrapper script around the service executable that stores the elapsed time somewhere on the filesystem once the main executable exits.

4. Use an helper script in ExecStartPost that stores the value computed in #1.

My preference goes to #4 if possible, then #3 if not. What would you suggest? Is there a better way of doing this?

Background: I am running Tiny Tiny RSS, which has a feed updater script that I run at regular intervals using a systemd timer. I also run Isync the same way to backup the contents of my Gmail inbox. My end goal is to be able to monitor how much time each service activation takes, and be alerted if it takes too long or hasn't run for a long time.

EDIT: My service file looks like this:

[Unit]
Description=Tiny Tiny RSS feeds update
After=network.target mysqld.service postgresql.service

[Service]
Type=oneshot
ExecStart=/usr/bin/php /usr/share/webapps/tt-rss/update.php --feeds
User=ttrss
StandardOutput=syslog
StandardError=syslog

And this is the timer:

[Unit]
Description=Tiny Tiny RSS feeds update timer

[Timer]
OnBootSec=1s
OnUnitInactiveSec=120s
Persistent=true
Unit=tt-rss.service

[Install]
WantedBy=timers.target

Answer 1

Compute InactiveEnterTimestamp - InactiveExitTimestamp

Activation time (in secs) is the result of:

(ActiveEnterTimestampMonotonic - InactiveExitTimestampMonotonic) / 1e6

See the function analyze_plot in the file analyze.c for details.

But you should have RemainAfterExit=yes in your unit to get ActiveEnterTimestampMonotonic.

You can calculate ExecMainExitTimestampMonotonic - ExecMainStartTimestampMonotonic in the PostStartExec without RemainAfterExit.

e.g. by reading them through the D-Bus interface in Python.

You can use systemctl to extract these values:

$ systemctl show -p InactiveExitTimestampMonotonic -p ActiveEnterTimestampMonotonic unit
InactiveExitTimestampMonotonic=44364325621
ActiveEnterTimestampMonotonic=44369331083

According to the Interface Stability Promise:

The stable interfaces are:

...

The command line interface of systemctl, loginctl, journalctl.
We will make sure that scripts invoking these commands will continue
to work with future versions of systemd. Note however that the output
generated by these commands is generally not included in the promise,
unless it is documented in the man page. Example: the output of
"systemctl status" is not stable, but the one of "systemctl show" is,
because the former is intended to be human readable and the latter
computer readable, and this is documented in the man page.

My end goal is to be able to monitor how much time each service activation takes, and be alerted if it takes too long

You can set TimeoutStartSec and OnFailure:

TimeoutStartSec= 

Configures the time to wait for start-up. If a daemon service does
not signal start-up completion within the configured time, the
service will be considered failed and will be shut down again.

OnFailure=

A space-separated list of one or more units that are activated when
this unit enters the "failed" state.

or hasn't run for a long time

You can extract the last success time from the journal:

 journalctl -u your-service MESSAGE='Started your-service.service.'

But you should enable the persistent storage of log messages.