0

System is a Raspberry Pi 5 running bookworm. Using unison compiled from source 2.53.2

I have created several services for synching files between serverA and serverB when serverA starts up. There are several of these service descriptions; they are all similar to this one:

[Unit]
Description=Start 3dPrint folder synchronization with velmicro

[Service]
Type=simple
User=dennis
Group=dennis
ExecStart=/usr/local/bin/auto-unison 3dPrint-velmicro >> /usr/local/log/unisonservicestart.log 2>&1
Restart=on-failure
StandardOutput=file:%h/log_file

[Install]
WantedBy=multi-user.target

Status of these services:

$> systemctl --all list-unit-files 'unison*'
UNIT FILE                             STATE   PRESET 
unison-3dPrint-velmicro.service       enabled enabled
unison-download-nasrefresh.service    enabled enabled
unison-macdownload-nasrefresh.service enabled enabled
unison-movies-nas.service             enabled enabled
unison-msdn-download.service          enabled enabled
unison-paperPortDocs.service          enabled enabled
unison-picserver-nas.service          enabled enabled
unison-plex-nasrefresh.service        enabled enabled

When I try to see the individual status of a process, (using the one with the above description as an example), I get:

> systemctl status unison-3dPrint-velmicro
× unison-3dPrint-velmicro.service - Start 3dPrint synchronization with velmicro
     Loaded: loaded (/etc/systemd/system/unison-3dPrint-velmicro.service; enabled; preset: enabled)
     Active: failed (Result: exit-code) since Thu 2024-07-25 13:29:42 EDT; 7min ago
   Duration: 31ms
    Process: 2411 ExecStart=/usr/local/bin/auto-unison /home/dennis/.unison/3dPrint-velmicro >> /usr/local/log/unisonservicestart.log 2>&1 (code=exited, status=255/EXCEPTION)
   Main PID: 2411 (code=exited, status=255/EXCEPTION)
        CPU: 30ms

Jul 25 13:29:42 luvnasp1 systemd[1]: unison-3dPrint-velmicro.service: Scheduled restart job, restart counter is at 5.
Jul 25 13:29:42 luvnasp1 systemd[1]: Stopped unison-3dPrint-velmicro.service - Start 3dPrint synchronization with velmicro.
Jul 25 13:29:42 luvnasp1 systemd[1]: unison-3dPrint-velmicro.service: Start request repeated too quickly.
Jul 25 13:29:42 luvnasp1 systemd[1]: unison-3dPrint-velmicro.service: Failed with result 'exit-code'.
Jul 25 13:29:42 luvnasp1 systemd[1]: Failed to start unison-3dPrint-velmicro.service - Start 3dPrint synchronization with velmicro.

When I look in /var/log to see why this job is not starting, I notice there is no syslog file there. Also, the log file in /usr/local/log mentioned on the ExecStart was not created.

This was running last I checked, few days ago... in fact, log shows it was running yesterday... here is the end of that log:

Synchronization complete at 09:44:54  (1 item transferred, 0 skipped, 0 failed)
Unison 2.53.2 (ocaml 4.13.1) started propagating changes at 07:47:44.16 on 24 Jul 2024
[BGN] Updating file RaspberryPi/Raspberry+Pi+5+Four+Bay+NAS/Button Adaptor adjusted.stl from //velmicro//m/3dPrint to /svr/3dPrint
[END] Updating file RaspberryPi/Raspberry+Pi+5+Four+Bay+NAS/Button Adaptor adjusted.stl
Unison 2.53.2 (ocaml 4.13.1) finished propagating changes at 07:47:44.18 on 24 Jul 2024, 0.018 s
Synchronization complete at 07:47:44  (1 item transferred, 0 skipped, 0 failed)

This is the contents of /var/log:

$> ls -l /var/log
total 3028
-rw-r--r--  1 root        root               4220 Jul 21 15:45 alternatives.log
-rw-r--r--  1 root        root              11849 Jun 30 15:20 alternatives.log.1
drwxr-x---  2 root        adm                4096 Jul 25 00:00 apache2
drwxr-xr-x  2 root        root               4096 Jul 21 15:45 apt
-rw-------  1 root        root              30598 Jul 25 13:20 boot.log
-rw-------  1 root        root              33213 Jul 25 00:00 boot.log.1
-rw-------  1 root        root              22811 Jul 18 00:00 boot.log.2
-rw-------  1 root        root              22504 Jul 13 00:00 boot.log.3
-rw-------  1 root        root              45300 Jul 11 00:00 boot.log.4
-rw-------  1 root        root              24476 Jul  9 00:00 boot.log.5
-rw-------  1 root        root              95446 Jul  8 00:00 boot.log.6
-rw-------  1 root        root              47548 Jul  7 00:00 boot.log.7
-rw-r--r--  1 root        root                  0 Mar 15 11:12 bootstrap.log
-rw-rw----  1 root        utmp            1096400 Jul 10 23:27 btmp
-rw-rw----  1 root        utmp            1028800 Jun 30 22:33 btmp.1
drwxr-xr-x  2 root        root               4096 Jul 25 00:00 cups
-rw-r--r--  1 root        root              86361 Jul 21 15:45 dpkg.log
-rw-r--r--  1 root        root             216966 Jun 30 17:14 dpkg.log.1
drwxr-s---  2 Debian-exim adm                4096 Jul 25 00:21 exim4
-rw-r--r--  1 root        root                  0 Mar 15 11:12 faillog
-rw-r--r--  1 root        root                  0 Mar 15 11:12 fontconfig.log
drwxr-xr-x  3 root        root               4096 Mar 15 11:04 hp
drwxr-sr-x+ 3 root        systemd-journal    4096 Mar 15 11:12 journal
-rw-rw-r--  1 root        utmp             296296 Jul 25 14:00 lastlog
drwx--x--x  2 root        root               4096 Jul 25 13:20 lightdm
drwx------  2 root        root               4096 Mar 15 10:59 private
lrwxrwxrwx  1 root        root                 39 Mar 15 10:59 README -> ../../usr/share/doc/systemd/README.logs
-rw-r--r--  1 root        root                126 Jul  7 16:51 rpi-clone.log
drwxr-xr-x  3 root        root               4096 Mar 15 11:01 runit
drwxr-x---  3 root        adm                4096 Jul 25 12:15 samba
-rw-rw-r--  1 root        utmp             228000 Jul 25 14:00 wtmp

How can I determine what is wrong with this service?

Improve this question
1
  • there is no syslog file there - read the README in /var/log
    – Jaromanda X
    Commented Jul 26 at 0:18

2 Answers 2

Reset to default
2

As implied in other comments, systemd does not log anything to /var/log/syslog. It can be configured to hand messages to rsyslog, but it is not by default (and this is a bit redundant, since all the messages go into the journal anyway).

To see the messages for a specific service, use sudo journalctl -xeu [service name]. To see all recent messages from today for the entire system, use sudo journalctl -S today. You can read further about that in man pages and elsewhere online.

The most recent messages are shown w/ systemctl status. Looking at this:

Jul 25 13:29:42 luvnasp1 systemd[1]: unison-3dPrint-velmicro.service: Scheduled restart job, restart counter is at 5.
Jul 25 13:29:42 luvnasp1 systemd[1]: Stopped unison-3dPrint-velmicro.service - Start 3dPrint synchronization with velmicro.
Jul 25 13:29:42 luvnasp1 systemd[1]: unison-3dPrint-velmicro.service: Start request repeated too quickly.
Jul 25 13:29:42 luvnasp1 systemd[1]: unison-3dPrint-velmicro.service: Failed with result 'exit-code'.
Jul 25 13:29:42 luvnasp1 systemd[1]: Failed to start unison-3dPrint-velmicro.service - Start 3dPrint synchronization with velmicro.

There's a loop implied here whereby the service fails, then a restart is tried (because you used Restart=on-failure), it immediately fails again, is throttled ("Start request repeated too quickly"), fails again, etc.

The first problem is:

ExecStart=/usr/local/bin/auto-unison 3dPrint-velmicro >> /usr/local/log/unisonservicestart.log 2>&1

You're using shell operators in there, but you are not invoking a shell, and systemd just runs the command indicated. It does not invoke it using a shell, so the command likely fails because auto-unison chokes on parameters such as >>. See the COMMAND LINES section in man systemd.service.

You could wrap that in a shell invocation if you want to use >>, however, this means there will be no standard output collected by the StandardOutput log (since you will instead be capturing it in a shell and writing it to a file). Or you could just use the StandardOutput log and change file: to append: (which is like > vs. >>). But you can't meaningfully do both.

The log file is never created because the ExecStart command failed and produced no output.

Improve this answer
2
  • Thank you, @goldilocks, this is very clear and understandable. I appreciate you taking the time to go in-depth and explain what you're doing here. In this case, it turned out that, once I sorted the StandardError and removed the pipe symbols from the command, there was actuallly an internal error within auto-unison that was causing all jobs to be unable to run (PHP could not initialize for an unrelated reason). Thanks for your help. But I sill miss syslog. *Yes, I know syslog would not have helped me; not the point. :)
    – Dennis
    Commented Jul 29 at 11:52
  • 1
    For a long time I did use both, because I like traditional (r)syslog features like being able to customize the parsing and sorting of messages. It isn't hard but there are some potential snags, start by installing rsyslog and enabling the service with ForwardToSyslog set in /etc/systemd/journald.conf -- maybe, see unix.stackexchange.com/a/705057/25985 and unix.stackexchange.com/q/196877/25985 I think rsyslog has the imjournal module loaded by default in rsyslog.conf but you should check that.
    – goldilocks ♦
    Commented Jul 29 at 12:48
0

for the no /var/log/syslog -

you don't have to install rsyslog to follow along, the 'sudo journalctl -f | grep unison' will work with what is installed.

or install rsyslog, like the old syslog, and then 'sudo tail -f /var/log/syslog | grep unison'.

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.