[udev + systemd] systemctl exit met code1

[Sir Isaac]

Ik heb een systemd service gemaakt die ik wil starten en stoppen als een specifieke usb camera wordt ingeplugd of losgemaakt. Deze job werkt goed als ik hem start en stop met systemctl start|stop <service>.
Als udev de webcam detecteert probeert udev de systemd service te starten maar die exit met code 1 zonder zijn werk te doen. Ik kom er niet achter waarom.

Achtergrond:
Dit gaat om een oude Trust Spacecam 320 webcam met ov519 chip die alleen jpg plaatjes uitspuugt. Veel software kan hier niet mee werken. Ik gebruik gstreamer om de camera uit te lezen en de jpegs te converteren naar een gewone videostream. Deze stream kan wel worden gebruikt.

Mijn systemd service:

[Unit]
Description=OV519 webcam

[Service]
Type=simple
ExecStartPre=modprobe v4l2loopback video_nr=1 card_label="Virtual raw camera"
ExecStart=gst-launch-1.0 v4l2src device=/dev/video0  ! jpegdec ! videoconvert ! v4l2sink device=/dev/video1
ExecStopPost=modprobe -r v4l2loopback

En mijn udev rules file:

ACTION=="add", \
  SUBSYSTEM=="video4linux", \
  ATTRS{idVendor}=="05a9", \
  ATTRS{idProduct}=="8519", \
  RUN+="systemctl start webcam-ov519"

ACTION=="remove", \
  SUBSYSTEM=="video4linux", \
  ATTRS{idVendor}=="05a9", \
  ATTRS{idProduct}=="8519", \
  RUN+="systemctl stop webcam-ov519"

Als ik de camera inplug wordt de v4l2loopback niet geladen en de streamer pijplijn wordt niet gestart. In mijn syslog zie ik:

jan 16 19:56:24 Desktop kernel: usb 6-5: new full-speed USB device number 16 using ohci-pci
jan 16 19:56:25 Desktop kernel: usb 6-5: New USB device found, idVendor=05a9, idProduct=8519, bcdDevice= 1.00
jan 16 19:56:25 Desktop kernel: usb 6-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
jan 16 19:56:25 Desktop kernel: usb 6-5: Product: USB Camera
jan 16 19:56:25 Desktop kernel: usb 6-5: Manufacturer: OmniVision Technologies, Inc.
jan 16 19:56:25 Desktop kernel: gspca_main: ov519-2.14.0 probing 05a9:8519
jan 16 19:56:25 Desktop kernel: input: ov519 as /devices/pci0000:00/0000:00:13.0/usb6/6-5/input/input47
jan 16 19:56:25 Desktop mtp-probe[10440]: checking bus 6, device 16: "/sys/devices/pci0000:00/0000:00:13.0/usb6/6-5"
jan 16 19:56:25 Desktop mtp-probe[10440]: bus: 6, device: 16 was not an MTP device
[b]jan 16 19:56:25 Desktop systemd-udevd[10437]: Process 'systemctl start webcam-ov519' failed with exit code 1.[/b]

De output van systemctl status webcam-ov519 is:

webcam-ov519.service - OV519 webcam
   Loaded: loaded (/etc/systemd/system/webcam-ov519.service; static; vendor preset: enabled)
   Active: inactive (dead)

jan 16 13:49:40 Desktop systemd[1]: Starting OV519 webcam...
jan 16 13:49:40 Desktop systemd[1]: Started OV519 webcam.
jan 16 13:49:41 Desktop gst-launch-1.0[4488]: Pijplijn gezet op gepauzeerd ...
jan 16 13:49:41 Desktop gst-launch-1.0[4488]: Pijplijn klaar en heeft PREROLL niet nodig...
jan 16 13:49:41 Desktop gst-launch-1.0[4488]: Pijplijn gezet op afspelen ...
jan 16 13:49:41 Desktop gst-launch-1.0[4488]: New clock: GstSystemClock
jan 16 13:49:57 Desktop systemd[1]: Stopping OV519 webcam...
jan 16 13:49:57 Desktop systemd[1]: webcam-ov519.service: Main process exited, code=killed, status=15/TERM
jan 16 13:49:57 Desktop systemd[1]: webcam-ov519.service: Succeeded.
jan 16 13:49:57 Desktop systemd[1]: Stopped OV519 webcam.

Het lijkt er dus op dat de service wordt gestart maar meteen beeindigd.

Punten waarvan ik vermoed waar het aan zou kunnen liggen:

• Het gst-launcher commando blijft draaien, normaal gesproken op de voorgrond, maar systemd zorgt dat hij naar de achtergond verdwijnt.
• Het type van de systemd service. Op basis van de Arch wiki denk ik dat simple het goede type is. De anderen lijken me niet van toepassing.
• De manier waarom ik met udev de systemd service wil starten. Ik heb ook ergens een andere, heel ingewikkelde, methode gezien. Sinds udev en systemd samengevoegd zijn zou dit toch triviaal moeten zijn.
• er worden remove events gecreerd. Kan het zijn dat een van de andere devices op de webcam (de luidspreker of de knop) deze genereert en dat udev gebruikt om de service te stoppen. Maar dat zou niet moeten omdat ik in mijn udev regels specifiek het video4linux subsysteem heb gespecificeerd.

Weet iemand wat er niet goed gaat?
Heeft iemand een idee hoe ik meer info over de reden van de exitcode kan krijgen?

[Hero of Time]

Het proces draait 16 seconden en sluit dan af. Is het klaar? Crasht het? Dat is niet duidelijk. Maar je type 'simple' is voor iets dat afsluit als 't klaar is iig niet juist. Systemd verwacht namelijk dat het proces blijft draaien en houd het PID bij. Sluit het proces opeens om wat voor reden dan ook, dan zal systemd het proces niet meer zien en is het resultaat exit status 1.

Je zal als type 'oneshot' moeten gebruiken als het na z'n werk gewoon sluit. Dan bekommert systemd zich niet meer om het proces.

Moet het wel blijven draaien, dan zal je moeten verder moeten zoeken naar de oorzaak. Wat gebeurt er met het proces dat je start, gst-launch-1.0? Zet bijvoorbeeld het commando dat je uitvoert in een script en roep vanuit je unit het script aan. Voeg vervolgens allerlei debug info toe aan je script, zoals exit statussen en echo's van verschillende dingen die het moet doen.

[Raynman]

De tijdstippen van je "syslog" en systemctl status komen niet overeen. Volgens die status output werd de service wel succesvol gestart maar al vrij snel weer gestopt. Dat stoppen gaat ook gewoon zonder errors:

Sir Isaac schreef op zaterdag 16 januari 2021 @ 20:13:

jan 16 13:49:57 Desktop systemd[1]: Stopping OV519 webcam...
jan 16 13:49:57 Desktop systemd[1]: webcam-ov519.service: Main process exited, code=killed, status=15/TERM
jan 16 13:49:57 Desktop systemd[1]: webcam-ov519.service: Succeeded.
jan 16 13:49:57 Desktop systemd[1]: Stopped OV519 webcam.

systemd kondigt hier aan de service te gaan stoppen. SIGTERM wordt dan naar het proces (gst-launch-1.0) gestuurd en dat laat zich zo beëindigen, waarmee de service "succesvol" gestopt is. Was dit een handmatige start/stop of werkte de udev trigger toen wel en heb je later iets veranderd? Als een handmatige start/stop wel werkt, lijken je eerste twee mogelijke oorzaken het minst waarschijnlijk.

Kun je niets van logs vinden rondom die mislukte start vanuit udevd? Probeer eens

journalctl -u webcam-ov519.service

Over het gebruik van quotes in ExecStartPre zegt systemd.service(1) het volgende:

Each command line is split on whitespace, with the first item being the command to execute, and the subsequent items being the arguments. Double quotes ("...") and single quotes ('...') may be used to wrap a whole item (the opening quote may appear only at the beginning or after whitespace that is not quoted, and the closing quote must be followed by whitespace or the end of line), in which case everything until the next matching quote becomes part of the same argument. Quotes themselves are removed.

Afgaand op het door mij vetgedrukte stuk zou ik zeggen dat het zo moet:

ExecStartPre=modprobe v4l2loopback video_nr=1 "card_label=Virtual raw camera"

Maar als je bij een handmatige start geen problemen hebt, maakt het misschien niet uit.

Aanvulling: je gebruikt nu het algemene RUN terwijl je ook aangeeft dat udev en systemd nauw samen kunnen werken. Je kunt kijken naar SYSTEMD_WANTS (bij de add rule) met BindsTo (in de service; vervangt de remove rule). Een (willekeurig) voorbeeld: https://superuser.com/que...on-a-device-being-present

[ Voor 7% gewijzigd door Raynman op 17-01-2021 13:09 ]

[Thralas]

Uit de man page van udev over RUN:

Starting daemons or other long-running processes is not allowed; the forked processes, detached or not, will be unconditionally killed after the event handling has finished. In order to activate long-running processes from udev rules, provide a service unit and pull it in from a udev device using the SYSTEMD_WANTS device property. See systemd.device(5) for details.

De oplossing die daar wordt gegeven is inderdaad gebaseerd op SYSTEMD_WANTS.

[ Voor 7% gewijzigd door Thralas op 17-01-2021 17:59 ]

[Sir Isaac]

Kijk, dat zijn reacties waar je wat aan hebt!
Het werkt nu met de volgende udev rule:

ACTION=="add", \
  SUBSYSTEM=="video4linux", \
  ATTRS{idVendor}=="05a9", \
  ATTRS{idProduct}=="8519", \
  SYMLINK+="webcam-ov519",\
  TAG+="systemd",\
  MODE="0660",\
  ENV{SYSTEMD_WANTS}="webcam-ov519.service"

#ACTION=="remove", \
#  SUBSYSTEM=="video4linux", \
#  ATTRS{idVendor}=="05a9", \
#  ATTRS{idProduct}=="8519", \
#  RUN+="systemctl stop webcam-ov519"

Als ik de camera inplug, wordt de symlink /dev/webcam-ov519 gemaakt, wordt v4l2loopback geladen en de gstreamer pipeline gestart.
Als ik camera weer los trek wordt alles weer opgeruimd. Blijkbaar is daar geen BindsTo voor nodig. Volgens syslog crasht de gstreamer pipeline doordat hij niet meer kan lezen van /dev/video0. Dat is wel lomp, maar werkt. Omdat de systemd task eindigt, wordt de v4l2loopback ook verwijderd.

an 19 00:02:21 Desktop gst-launch-1.0[5033]: FOUT: van element /GstPipeline:pipeline0/GstV4l2Src:v4l2src0: Kan niet lezen van bron.
Jan 19 00:02:21 Desktop gst-launch-1.0[5033]: Extra debug-informatie:
Jan 19 00:02:21 Desktop gst-launch-1.0[5033]: gstv4l2bufferpool.c(1040): gst_v4l2_buffer_pool_poll (): /GstPipeline:pipeline0/GstV4l2Src:v4l2src0:
Jan 19 00:02:21 Desktop gst-launch-1.0[5033]: poll error 1: Ongeldig argument (22)
Jan 19 00:02:21 Desktop gst-launch-1.0[5033]: Execution ended after 0:00:30.243930537
Jan 19 00:02:21 Desktop gst-launch-1.0[5033]: Pijplijn gezet op gepauzeerd ...
Jan 19 00:02:22 Desktop gst-launch-1.0[5033]: Pijplijn gezet op gereed ...
Jan 19 00:02:22 Desktop gst-launch-1.0[5033]: Pijplijn gezet op NULL ...
Jan 19 00:02:22 Desktop gst-launch-1.0[5033]: Pijplijn wordt vrijgemaakt ...
Jan 19 00:02:22 Desktop /usr/lib/gdm3/gdm-x-session[1817]: (II) UnloadModule: "libinput"
Jan 19 00:02:22 Desktop /usr/lib/gdm3/gdm-x-session[1817]: (II) systemd-logind: releasing fd for 13:81
Jan 19 00:02:22 Desktop /usr/lib/gdm3/gdm-x-session[1817]: (EE) systemd-logind: failed to release device: Device not taken
[b]Jan 19 00:02:22 Desktop systemd[1]: webcam-ov519.service: Main process exited, code=exited, status=1/FAILU[/b]RE
Jan 19 00:02:22 Desktop gsd-media-keys[2017]: Unable to get default source
Jan 19 00:02:22 Desktop systemd[1]: webcam-ov519.service: Failed with result 'exit-code'.

edit:

Toevoegen van [code]BindsTo=/dev/webcam-ov519[/code] werkt niet. Morgen even uitzoeken wat de correcte input hier is. Een path in de /sys/ directory?

[ Voor 3% gewijzigd door Sir Isaac op 19-01-2021 00:22 ]