Re: systemd service fails to run with "ConditionACPower=true was not met"

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Fri, Aug 05, 2022 at 11:36:13AM +0100, Barry wrote:
> 
> 
> > On 5 Aug 2022, at 10:48, Richard W.M. Jones <rjones@xxxxxxxxxx> wrote:
> > 
> > Fedora 36, plocate-1.1.15-3.fc36.x86_64, systemd-250.8-1.fc36.x86_64
> > 
> > /usr/lib/systemd/system/plocate-updatedb.service has
> > ConditionACPower=true because they don't want updatedb to run
> > when on a laptop battery.
> > 
> > Now, my machine is an Intel NUC which has an Intel mobile chipset but
> > is very definitely not a laptop.  It doesn't have a battery and always
> > runs off AC power.
> > 
> > But ...
> > 
> >  $ sudo systemctl status plocate-updatedb.service |& cat
> >  ○ plocate-updatedb.service - Update the plocate database
> >       Loaded: loaded (/usr/lib/systemd/system/plocate-updatedb.service; static)
> >       Active: inactive (dead)
> >  TriggeredBy: ● plocate-updatedb.timer
> >    Condition: start condition failed at Fri 2022-08-05 10:29:57 BST; 5min ago
> >               └─ ConditionACPower=true was not met
> > 
> >  Aug 03 14:59:37 dev5 systemd[1]: plocate-updatedb.service - Update the plocate database was skipped because of a failed condition check (ConditionACPower=true).
> >  Aug 04 09:29:21 dev5 systemd[1]: plocate-updatedb.service - Update the plocate database was skipped because of a failed condition check (ConditionACPower=true).
> >  Aug 05 10:29:35 dev5 systemd[1]: plocate-updatedb.service - Update the plocate database was skipped because of a failed condition check (ConditionACPower=true).
> >  Aug 05 10:29:57 dev5 systemd[1]: plocate-updatedb.service - Update the plocate database was skipped because of a failed condition check (ConditionACPower=true).
> > 
> > Looking at systemd sources it seems as if ConditionACPower is checked
> > here:
> > 
> >  https://github.com/systemd/systemd/blob/14e7bc2e77d2699498a1f74d7e4f905f11eca335/src/shared/udev-util.c#L662
> > 
> > It's a bit hard to follow what the code is doing, but I think it's
> > looking in /sys for power_supply devices.  This hardware has two, both
> > with type == USB.  (I believe these are the two USB ports on the front
> > panel that can provide power to other devices, they cannot power the
> > machine itself.)
> > 
> >  $ ll /sys/devices/platform/USBC000:00/power_supply
> >  total 0
> >  drwxr-xr-x. 5 root root 0 Aug  3 09:00 ucsi-source-psy-USBC000:001
> >  drwxr-xr-x. 5 root root 0 Aug  3 09:00 ucsi-source-psy-USBC000:002
> >  $ cat /sys/devices/platform/USBC000:00/power_supply/*/type
> >  USB
> >  USB
> > 
> >  $ cat /sys/devices/platform/USBC000\:00/power_supply/ucsi-source-psy-USBC000\:00*/device/typec/port*/power_role 
> >  [sink]
> >  [sink]
> >  [sink]
> >  [sink]
> > 
> >  $ cat /sys/devices/platform/USBC000\:00/power_supply/ucsi-source-psy-USBC000\:00*/online
> >  0
> >  0
> > 
> > Anyway, I think this is a systemd bug, right?
> 
> That code has lots of debug logs. Try running systemd with log level debug and see which of those logs is printed.

Good idea ...

# systemd-analyze set-log-level debug
# systemctl start plocate-updatedb.service 
# journalctl

The relevant section is attached in full.

It seems as if the code only finds the USB ports, they are all in
"sink" mode, it doesn't find any other power_supply devices so it
assumes battery?  There seem to be at least two things wrong here -
the USB ports are not "sinks" and there are no other power supply
devices.

I think this is a systemd bug.

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
libguestfs lets you edit virtual machines.  Supports shell scripting,
bindings from many languages.  http://libguestfs.org
Aug 05 12:10:14 dev5 systemd[1]: Bus private-bus-connection: changing state UNSET → OPENING
Aug 05 12:10:14 dev5 systemd[1]: sd-bus: starting bus private-bus-connection on fds 27/27 (socket:[382559], socket:[382559])...
Aug 05 12:10:14 dev5 systemd[1]: Bus private-bus-connection: changing state OPENING → AUTHENTICATING
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1 iface=org.freedesktop.systemd1.Manager
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/job iface=org.freedesktop.systemd1.Job
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Unit
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Automount
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Device
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Mount
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Path
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Scope
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Service
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Slice
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Socket
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Swap
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Target
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/systemd1/unit iface=org.freedesktop.systemd1.Timer
Aug 05 12:10:14 dev5 systemd[1]: Registering bus object implementation for path=/org/freedesktop/LogControl1 iface=org.freedesktop.LogControl1
Aug 05 12:10:14 dev5 systemd[1]: Accepted new private connection.
Aug 05 12:10:14 dev5 systemd[1]: Bus private-bus-connection: changing state AUTHENTICATING → RUNNING
Aug 05 12:10:14 dev5 systemd[1]: Got message type=method_call sender=n/a destination=org.freedesktop.systemd1 path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=StartUnit cookie=1 reply_cookie=0 signature=ss error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=start state=enforcing function=bus_unit_method_start_generic path=/usr/lib/systemd/system/plocate-updatedb.service cmdline=n/a: Success
Aug 05 12:10:14 dev5 systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_unit_file_t:s0 tclass=service perm=start state=enforcing function=bus_unit_queue_job path=/usr/lib/systemd/system/plocate-updatedb.service cmdline=n/a: Success
Aug 05 12:10:14 dev5 systemd[1]: plocate-updatedb.service: Trying to enqueue job plocate-updatedb.service/start/replace
Aug 05 12:10:14 dev5 systemd[1]: plocate-updatedb.service: Installed new job plocate-updatedb.service/start as 7863
Aug 05 12:10:14 dev5 systemd[1]: plocate-updatedb.service: Enqueued job plocate-updatedb.service/start as 7863
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=signal sender=org.freedesktop.systemd1 destination=n/a path=/org/freedesktop/systemd1/unit/plocate_2dupdatedb_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=signal sender=org.freedesktop.systemd1 destination=n/a path=/org/freedesktop/systemd1/unit/plocate_2dupdatedb_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=2 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/plocate_2dupdatedb_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=4149 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1/unit/plocate_2dupdatedb_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=4150 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=signal sender=org.freedesktop.systemd1 destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=3 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=4151 reply_cookie=0 signature=uos error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: Sent message type=method_return sender=org.freedesktop.systemd1 destination=n/a path=n/a interface=n/a member=n/a cookie=4 reply_cookie=1 signature=o error-name=n/a error-message=n/a
Aug 05 12:10:14 dev5 systemd[1]: sd-device-enumerator: Scan all dirs
Aug 05 12:10:14 dev5 systemd[1]: sd-device-enumerator: Scanning /sys/bus
Aug 05 12:10:14 dev5 systemd[1]: sd-device-enumerator: Scanning /sys/class
Aug 05 12:10:14 dev5 systemd[1]: port0: The USB type-C port is in power sink mode.
Aug 05 12:10:14 dev5 systemd[1]: port1: The USB type-C port is in power sink mode.
Aug 05 12:10:14 dev5 systemd[1]: ucsi-source-psy-USBC000:001: The USB type-C device has at least one port in power sink mode.
Aug 05 12:10:14 dev5 systemd[1]: ucsi-source-psy-USBC000:001: The power supply is currently offline.
Aug 05 12:10:14 dev5 systemd[1]: port0: The USB type-C port is in power sink mode.
Aug 05 12:10:14 dev5 systemd[1]: port1: The USB type-C port is in power sink mode.
Aug 05 12:10:14 dev5 systemd[1]: ucsi-source-psy-USBC000:002: The USB type-C device has at least one port in power sink mode.
Aug 05 12:10:14 dev5 systemd[1]: ucsi-source-psy-USBC000:002: The power supply is currently offline.
Aug 05 12:10:14 dev5 systemd[1]: All non-battery power supplies are offline, assuming system is running with battery.
Aug 05 12:10:14 dev5 systemd[1]: plocate-updatedb.service: ConditionACPower=true failed.
Aug 05 12:10:14 dev5 systemd[1]: plocate-updatedb.service: Starting requested but condition failed. Not starting unit.
Aug 05 12:10:14 dev5 systemd[1]: plocate-updatedb.service: Job 7863 plocate-updatedb.service/start finished, result=done
_______________________________________________
users mailing list -- users@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to users-leave@xxxxxxxxxxxxxxxxxxxxxxx
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedoraproject.org/archives/list/users@xxxxxxxxxxxxxxxxxxxxxxx
Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
[Index of Archives]     [Older Fedora Users]     [Fedora Announce]     [Fedora Package Announce]     [EPEL Announce]     [EPEL Devel]     [Fedora Magazine]     [Fedora Summer Coding]     [Fedora Laptop]     [Fedora Cloud]     [Fedora Advisory Board]     [Fedora Education]     [Fedora Security]     [Fedora Scitech]     [Fedora Robotics]     [Fedora Infrastructure]     [Fedora Websites]     [Anaconda Devel]     [Fedora Devel Java]     [Fedora Desktop]     [Fedora Fonts]     [Fedora Marketing]     [Fedora Management Tools]     [Fedora Mentors]     [Fedora Package Review]     [Fedora R Devel]     [Fedora PHP Devel]     [Kickstart]     [Fedora Music]     [Fedora Packaging]     [Fedora SELinux]     [Fedora Legal]     [Fedora Kernel]     [Fedora OCaml]     [Coolkey]     [Virtualization Tools]     [ET Management Tools]     [Yum Users]     [Yosemite News]     [Gnome Users]     [KDE Users]     [Fedora Art]     [Fedora Docs]     [Fedora Sparc]     [Libvirt Users]     [Fedora ARM]

  Powered by Linux