[systemd-udevd] Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with exit code 1

Bug #1682774 reported by bugproxy
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
The Ubuntu-power-systems project
Fix Released
High
Canonical Foundations Team
libvpd (Debian)
Fix Released
Unknown
libvpd (Ubuntu)
Fix Released
High
Dimitri John Ledkov

Bug Description

== Comment: VASANT HEGDE <email address hidden> - 2017-04-13 11:14:43 ==

Problem description :
  systemd-udevd daemon failed to execute udev rules.

Aug 9 01:28:43 abc systemd-udevd[19870]: Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with exit code 1.

Rules file :
-----------
root@abc:/lib/udev/rules.d# cat 60-libvpd-2.2-2.rules
KERNELS=="*", ACTION=="*", DEVPATH=="/devices/*", RUN+="/bin/touch /var/lib/lsvpd/run.vpdupdate"

If I restart the systemd-udevd daemon then it works fine.
    - systemctl restart systemd-udevd

journalctl -u systemd-udevd
-- Logs begin at Wed 2017-04-12 07:19:26 CDT, end at Thu 2017-04-13 11:11:16 CDT. --
Apr 12 07:19:26 w37l systemd[1]: Starting udev Kernel Device Manager...
Apr 12 07:19:27 w37l systemd[1]: Started udev Kernel Device Manager.
Apr 12 07:19:27 w37l systemd-udevd[544]: Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with exit code 1

systemctl show systemd-udevd

Type=notify
Restart=always
NotifyAccess=main
RestartUSec=0
TimeoutStartUSec=1min 30s
TimeoutStopUSec=1min 30s
RuntimeMaxUSec=infinity
WatchdogUSec=3min
WatchdogTimestamp=Thu 2017-04-13 10:56:39 CDT
WatchdogTimestampMonotonic=57706791
FailureAction=none
PermissionsStartOnly=no
RootDirectoryStartOnly=no
RemainAfterExit=no
GuessMainPID=yes
MainPID=489
ControlPID=0
FileDescriptorStoreMax=0
NFileDescriptorStore=0
StatusText=Processing with 72 children at max
StatusErrno=0
Result=success
UID=4294967295
GID=4294967295
ExecMainStartTimestamp=Wed 2017-04-12 07:19:26 CDT
ExecMainStartTimestampMonotonic=4652319
ExecMainExitTimestampMonotonic=0
ExecMainPID=489
ExecMainCode=0
ExecMainStatus=0
ExecStart={ path=/lib/systemd/systemd-udevd ; argv[]=/lib/systemd/systemd-udevd ; ignore_errors=no ; start_time=[n/a] ; stop_time=[n/a] ; pid=0 ; code=(null) ; status=0/0 }
Slice=system.slice
ControlGroup=/system.slice/systemd-udevd.service
MemoryCurrent=18446744073709551615
CPUUsageNSec=18446744073709551615
TasksCurrent=1
Delegate=no
CPUAccounting=no
CPUWeight=18446744073709551615
StartupCPUWeight=18446744073709551615
CPUShares=18446744073709551615
StartupCPUShares=18446744073709551615
CPUQuotaPerSecUSec=infinity
IOAccounting=no
IOWeight=18446744073709551615
StartupIOWeight=18446744073709551615
BlockIOAccounting=no
BlockIOWeight=18446744073709551615
StartupBlockIOWeight=18446744073709551615
MemoryAccounting=no
MemoryLow=0
MemoryHigh=18446744073709551615
MemoryMax=18446744073709551615
MemorySwapMax=18446744073709551615
MemoryLimit=18446744073709551615
DevicePolicy=auto
TasksAccounting=yes
TasksMax=18446744073709551615
UMask=0022
LimitCPU=18446744073709551615
LimitCPUSoft=18446744073709551615
LimitFSIZE=18446744073709551615
LimitFSIZESoft=18446744073709551615
LimitDATA=18446744073709551615
LimitDATASoft=18446744073709551615
LimitSTACK=18446744073709551615
LimitSTACKSoft=8388608
LimitCORE=18446744073709551615
LimitCORESoft=0
LimitRSS=18446744073709551615
LimitRSSSoft=18446744073709551615
LimitNOFILE=4096
LimitNOFILESoft=1024
LimitAS=18446744073709551615
LimitASSoft=18446744073709551615
LimitNPROC=372260
LimitNPROCSoft=372260
LimitMEMLOCK=65536
LimitMEMLOCKSoft=65536
LimitLOCKS=18446744073709551615
LimitLOCKSSoft=18446744073709551615
LimitSIGPENDING=372260
LimitSIGPENDINGSoft=372260
LimitMSGQUEUE=819200
LimitMSGQUEUESoft=819200
LimitNICE=0
LimitNICESoft=0
LimitRTPRIO=0
LimitRTPRIOSoft=0
LimitRTTIME=18446744073709551615
LimitRTTIMESoft=18446744073709551615
OOMScoreAdjust=-1000
Nice=0
IOScheduling=0
CPUSchedulingPolicy=0
CPUSchedulingPriority=0
TimerSlackNSec=50000
CPUSchedulingResetOnFork=no
NonBlocking=no
StandardInput=null
StandardOutput=journal
StandardError=inherit
TTYReset=no
TTYVHangup=no
TTYVTDisallocate=no
SyslogPriority=30
SyslogLevelPrefix=yes
SyslogLevel=6
SyslogFacility=3
SecureBits=0
CapabilityBoundingSet=18446744073709551615
AmbientCapabilities=0
DynamicUser=no
RemoveIPC=no
MountFlags=524288
PrivateTmp=no
PrivateDevices=no
ProtectKernelTunables=no
ProtectKernelModules=no
ProtectControlGroups=no
PrivateNetwork=no
PrivateUsers=no
ProtectHome=no
ProtectSystem=no
SameProcessGroup=no
UtmpMode=init
IgnoreSIGPIPE=yes
NoNewPrivileges=no
SystemCallErrorNumber=0
RuntimeDirectoryMode=0755
MemoryDenyWriteExecute=yes
RestrictRealtime=yes
RestrictNamespace=2114060288
KillMode=mixed
KillSignal=15
SendSIGKILL=yes
SendSIGHUP=no
Id=systemd-udevd.service
Names=systemd-udevd.service
Requires=system.slice
Wants=systemd-udevd-kernel.socket systemd-udevd-control.socket
WantedBy=friendly-recovery.service systemd-udev-trigger.service sysinit.target
Before=friendly-recovery.service sysinit.target plymouth-start.service systemd-networkd.service
After=systemd-sysusers.service systemd-tmpfiles-setup-dev.service systemd-journald.socket system.slice systemd-udevd-kernel.socket systemd-udevd-control.socket
TriggeredBy=systemd-udevd-kernel.socket systemd-udevd-control.socket
Documentation=man:systemd-udevd.service(8) man:udev(7)
Description=udev Kernel Device Manager
LoadState=loaded
ActiveState=active
SubState=running
FragmentPath=/lib/systemd/system/systemd-udevd.service
UnitFileState=static
UnitFilePreset=enabled
StateChangeTimestamp=Wed 2017-04-12 07:19:27 CDT
StateChangeTimestampMonotonic=5890643
InactiveExitTimestamp=Wed 2017-04-12 07:19:26 CDT
InactiveExitTimestampMonotonic=4652377
ActiveEnterTimestamp=Wed 2017-04-12 07:19:27 CDT
ActiveEnterTimestampMonotonic=5890643
ActiveExitTimestampMonotonic=0
InactiveEnterTimestampMonotonic=0
CanStart=yes
CanStop=yes
CanReload=no
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=no
OnFailureJobMode=replace
IgnoreOnIsolate=no
NeedDaemonReload=no
JobTimeoutUSec=infinity
JobTimeoutAction=none
ConditionResult=yes
AssertResult=yes
ConditionTimestamp=Wed 2017-04-12 07:19:26 CDT
ConditionTimestampMonotonic=4651243
AssertTimestamp=Wed 2017-04-12 07:19:26 CDT
AssertTimestampMonotonic=4651252
Transient=no
Perpetual=no
StartLimitIntervalSec=10000000
StartLimitBurst=5
StartLimitAction=none
InvocationID=8c9f082d6b5146fdb05b417857c6efae

Hello Canonical,

I'm not clear why first time (during system boot) it fails to execute rules. Can someone from systemd side take a look and explain why first time it fails to execute rules?

-Vasant

bugproxy (bugproxy)
tags: added: architecture-ppc64le bugnameltc-144627 severity-high targetmilestone-inin1610
Changed in ubuntu:
assignee: nobody → Taco Screen team (taco-screen-team)
affects: ubuntu → systemd (Ubuntu)
Revision history for this message
Steve Langasek (vorlon) wrote :

Hi Vasant,

> Aug 9 01:28:43 abc systemd-udevd[19870]: Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with exit code 1.

What does the filesystem layout look like on this system? Is it possible that you see this failing because it's running before /var/lib is mounted?

Alternatively, is it possible that it's being run while the root filesystem is still mounted read only?

If you need to write a file during early boot before the filesystem is guaranteed to be set up, it would be better to use /run for this instead of /var/lib.

Revision history for this message
Dimitri John Ledkov (xnox) wrote :

This udev rule is shipped by libvpd package, changing package assignment.

affects: systemd (Ubuntu) → libvpd (Ubuntu)
Revision history for this message
bugproxy (bugproxy) wrote : Comment bridged from LTC Bugzilla

------- Comment From <email address hidden> 2017-04-18 07:41 EDT-------
(In reply to comment #14)
> Hi Vasant,
>
> > Aug 9 01:28:43 abc systemd-udevd[19870]: Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with exit code 1.
>
> What does the filesystem layout look like on this system? Is it possible
> that you see this failing because it's running before /var/lib is mounted?

Its default Ubuntu installation and I see message even after booting the system.

>
> Alternatively, is it possible that it's being run while the root filesystem
> is still mounted read only?

Its possible during early boot.. But we see message even after booting the system.

>
> If you need to write a file during early boot before the filesystem is
> guaranteed to be set up, it would be better to use /run for this instead of
> /var/lib.

Ok.. Our requirement is :
We have static vpd.db file under /var/lib/lsvpd which contains system VPD. We use udev script to detect change in devices so that next time someone requests to read from vpd.db we can refresh the database and get upto date information.
Is /run recommended for this kind of usage?

-Vasant

------- Comment From <email address hidden> 2017-04-18 07:47 EDT-------
(In reply to comment #15)
> This udev rule is shipped by libvpd package, changing package assignment.

Correct. Its shipped by libvpd.. but we wanted to understand from systemd-udevd point of view.

-Vasant

Revision history for this message
Dimitri John Ledkov (xnox) wrote : Re: [Bug 1682774] Comment bridged from LTC Bugzilla

On 18 April 2017 at 12:49, bugproxy <email address hidden> wrote:
> ------- Comment From <email address hidden> 2017-04-18 07:41 EDT-------
> (In reply to comment #14)
>> Hi Vasant,
>>
>> > Aug 9 01:28:43 abc systemd-udevd[19870]: Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with exit code 1.
>>
>> What does the filesystem layout look like on this system? Is it possible
>> that you see this failing because it's running before /var/lib is mounted?
>
> Its default Ubuntu installation and I see message even after booting the
> system.
>
>>
>> Alternatively, is it possible that it's being run while the root filesystem
>> is still mounted read only?
>
> Its possible during early boot.. But we see message even after booting
> the system.
>
>>
>> If you need to write a file during early boot before the filesystem is
>> guaranteed to be set up, it would be better to use /run for this instead of
>> /var/lib.
>
> Ok.. Our requirement is :
> We have static vpd.db file under /var/lib/lsvpd which contains system VPD. We use udev script to detect change in devices so that next time someone requests to read from vpd.db we can refresh the database and get upto date information.
> Is /run recommended for this kind of usage?
>

Yes.

Note that /run doesn't persist across reboots, so I hope the udev rule
in question is triggered on every boot; and thereafter when relevant
things change.

> -Vasant
>
> ------- Comment From <email address hidden> 2017-04-18 07:47 EDT-------
> (In reply to comment #15)
>> This udev rule is shipped by libvpd package, changing package assignment.
>
> Correct. Its shipped by libvpd.. but we wanted to understand from
> systemd-udevd point of view.
>

systemd-udevd allows executing arbitrary shell code, and it did so,
and it's out of udev's control to guarantee success or failure of
those commands.

The bug is in the udev rules themself, or rather the code that makes
assumptions that are not guaranteed during udev rule triggering.
Usually, one would start a systemd unit file to check / update things
on boot, with correct file dependencies that e.g. certain directory is
mounted and is writable;
and make udev rules trigger that unit e.g. with SYSTEMD_WANTS=. But
this is just a general advice, I have not looked into libvpd package
specifics.

There is no systemd-udevd bug here, as far as I can tell.

Regards,

Dimitri.

Revision history for this message
Steve Langasek (vorlon) wrote :

On Tue, Apr 18, 2017 at 11:49:17AM -0000, bugproxy wrote:
> > Alternatively, is it possible that it's being run while the root filesystem
> > is still mounted read only?

> Its possible during early boot.. But we see message even after booting
> the system.

Do you mean that the timestamp of when the message was generated was after
system boot? Do you have a way that you are injecting kernel events, so
that this udev rule is triggered post-boot?

> > If you need to write a file during early boot before the filesystem is
> > guaranteed to be set up, it would be better to use /run for this instead of
> > /var/lib.

> Ok.. Our requirement is :
> We have static vpd.db file under /var/lib/lsvpd which contains system VPD. We use udev script to detect change in devices so that next time someone requests to read from vpd.db we can refresh the database and get upto date information.
> Is /run recommended for this kind of usage?

"static" seems to be relative here, since with the current logic you are
asking for it to be regenerated at least once every boot. If the contents
do not need to persist across reboots, then /run is appropriate. If you do
want to save the results across reboots so that they're available early, and
only regenerated if needed, then /var/lib/lsvpd is appropriate.

But I think the only consumers of this database are tools that are run later
in boot (i.e. after reaching multi-user.target), and the database will
always be regenerated unconditionally on boot because there's no other way
to know if the database contents match the current system the disk is
attached to. So it seems to me that /run would be perfectly correct for all
of this.

Revision history for this message
bugproxy (bugproxy) wrote : Comment bridged from LTC Bugzilla

------- Comment From <email address hidden> 2017-04-19 05:48 EDT-------
(In reply to comment #19)
> On Tue, Apr 18, 2017 at 11:49:17AM -0000, bugproxy wrote:
> > > Alternatively, is it possible that it's being run while the root filesystem
> > > is still mounted read only?
>
> > Its possible during early boot.. But we see message even after booting
> > the system.
>
> Do you mean that the timestamp of when the message was generated was after
> system boot? Do you have a way that you are injecting kernel events, so
> that this udev rule is triggered post-boot?

What I meant is, every change in /sys/device entry causes this script to trigger irrespective of whether its during boot time -OR- runtime.

>
> > > If you need to write a file during early boot before the filesystem is
> > > guaranteed to be set up, it would be better to use /run for this instead of
> > > /var/lib.
>
> > Ok.. Our requirement is :
> > We have static vpd.db file under /var/lib/lsvpd which contains system VPD. We use udev script to detect change in devices so that next time someone requests to read from vpd.db we can refresh the database and get upto date information.
> > Is /run recommended for this kind of usage?
>
> "static" seems to be relative here, since with the current logic you are
> asking for it to be regenerated at least once every boot. If the contents
> do not need to persist across reboots, then /run is appropriate. If you do
> want to save the results across reboots so that they're available early, and
> only regenerated if needed, then /var/lib/lsvpd is appropriate.
>
> But I think the only consumers of this database are tools that are run later
> in boot (i.e. after reaching multi-user.target), and the database will
> always be regenerated unconditionally on boot because there's no other way
> to know if the database contents match the current system the disk is
> attached to. So it seems to me that /run would be perfectly correct for all
> of this.

This may need some code changes. Let me give a try and get back to you.

-Vasant

Revision history for this message
Steve Langasek (vorlon) wrote : Re: [Bug 1682774] Comment bridged from LTC Bugzilla

On Wed, Apr 19, 2017 at 09:49:25AM -0000, bugproxy wrote:
> ------- Comment From <email address hidden> 2017-04-19 05:48 EDT-------
> (In reply to comment #19)
> > On Tue, Apr 18, 2017 at 11:49:17AM -0000, bugproxy wrote:
> > > > Alternatively, is it possible that it's being run while the root filesystem
> > > > is still mounted read only?

> > > Its possible during early boot.. But we see message even after booting
> > > the system.

> > Do you mean that the timestamp of when the message was generated was after
> > system boot? Do you have a way that you are injecting kernel events, so
> > that this udev rule is triggered post-boot?

> What I meant is, every change in /sys/device entry causes this script to
> trigger irrespective of whether its during boot time -OR- runtime.

Sure. But I think what we need to understand is if a change in /sys/device
post-boot also triggers the failure, or if it works as expected.

Revision history for this message
bugproxy (bugproxy) wrote : Comment bridged from LTC Bugzilla

------- Comment From <email address hidden> 2017-04-24 02:56 EDT-------
> > What I meant is, every change in /sys/device entry causes this script to
> > trigger irrespective of whether its during boot time -OR- runtime.
>
> Sure. But I think what we need to understand is if a change in /sys/device
> post-boot also triggers the failure, or if it works as expected.

Yes. Right now it triggers failure until we restart systemd-udevd service.

-Vasant

Steve Langasek (vorlon)
Changed in libvpd (Ubuntu):
assignee: Taco Screen team (taco-screen-team) → Dimitri John Ledkov (xnox)
importance: Undecided → High
milestone: none → ubuntu-17.05
Manoj Iyer (manjo)
tags: added: ubuntu-17.04
Manoj Iyer (manjo)
Changed in ubuntu-power-systems:
importance: Undecided → High
Manoj Iyer (manjo)
tags: added: triage-a
Manoj Iyer (manjo)
tags: added: triage-r
removed: triage-a
Revision history for this message
bugproxy (bugproxy) wrote :

------- Comment From <email address hidden> 2017-08-22 08:43 EDT-------
Hello Canonical,

(In reply to comment #29)
> Created attachment 120183 [details]
> [PATCH] Changes run.vpdupdate creation path from /var/lib/lsvpd to /run

Can you please pull attached patch ?

corresponding upstream commit :

commit 7d959c5ff48978853b01c43e959236988a46a018
Author: Brahadambal Srinivasan <email address hidden>
Date: Fri Jun 23 11:13:27 2017 +0530

Changes run.vpdupdate creation path from /var/lib/lsvpd to /run
Process '/bin/touch /var/lib/lsvpd/run.vpdupdate' failed with
exit code 1.

It will apply cleanly on top of Canonical version.

-Vasant

------- Comment From <email address hidden> 2017-08-22 08:44 EDT-------
(In reply to comment #30)
> Hello Canonical,
>
>
> (In reply to comment #29)
> > Created attachment 120183 [details]
> > [PATCH] Changes run.vpdupdate creation path from /var/lib/lsvpd to /run
>
>
> Can you please pull attached patch ?

And this patch is for libvpd package.

-Vasant

Revision history for this message
bugproxy (bugproxy) wrote : [PATCH] Changes run.vpdupdate creation path from /var/lib/lsvpd to /run

------- Comment (attachment only) From <email address hidden> 2017-08-22 08:42 EDT-------

Revision history for this message
bugproxy (bugproxy) wrote : Comment bridged from LTC Bugzilla

------- Comment From <email address hidden> 2017-08-22 09:23 EDT-------
*** Bug 151106 has been marked as a duplicate of this bug. ***

Revision history for this message
Dimitri John Ledkov (xnox) wrote :

Uploaded to ubuntu.
Bug report forwarded to Debian maintainer Frederic Bonnard at https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=872993

Changed in libvpd (Ubuntu):
status: New → Fix Committed
Changed in ubuntu-power-systems:
status: New → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package libvpd - 2.2.5-2ubuntu1

---------------
libvpd (2.2.5-2ubuntu1) artful; urgency=medium

  * Use runtime directory for the udev notify file, instead of
    /var/lib. LP: #1682774

 -- Dimitri John Ledkov <email address hidden> Wed, 23 Aug 2017 13:00:25 +0100

Changed in libvpd (Ubuntu):
status: Fix Committed → Fix Released
Changed in libvpd (Debian):
status: Unknown → New
Manoj Iyer (manjo)
Changed in ubuntu-power-systems:
status: Fix Committed → Fix Released
tags: added: triage-g
removed: triage-r
Changed in ubuntu-power-systems:
assignee: nobody → Canonical Foundations Team (canonical-foundations)
bugproxy (bugproxy)
tags: added: targetmilestone-inin1710
removed: targetmilestone-inin1610
Changed in libvpd (Debian):
status: New → Fix Released
tags: added: id-599c6a42fa3d9228afba11d5
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.