Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Richard W.M. Jones]

On Wed, May 27, 2015 at 07:08:41PM +0200, Tom Gundersen wrote:
> This should be fixed by 86c3bece38bcf55da6387d20c6f01da9ad0284dc.
> Thanks for the help in debugging this, and sorry for the
> inconvenience.

Also this fixes a bug where 'udevadm settle' would go into a loop for
a few minutes after you create a new partition (RHBZ#1225641).

Thanks,

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
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Martin Pitt]

Hey Tom,

Tom Gundersen [2015-05-27 19:08 +0200]:
> This should be fixed by 86c3bece38bcf55da6387d20c6f01da9ad0284dc.
> Thanks for the help in debugging this, and sorry for the
> inconvenience.

Works like a charm. Great work, thanks!

Martin
-- 
Martin Pitt| http://www.piware.de
Ubuntu Developer (www.ubuntu.com)  | Debian Developer  (www.debian.org)
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Filipe Brandenburger]

On Wed, May 27, 2015 at 10:08 AM, Tom Gundersen  wrote:
> This should be fixed by 86c3bece38bcf55da6387d20c6f01da9ad0284dc.
> Thanks for the help in debugging this, and sorry for the
> inconvenience.

And I can confirm the timeout is gone.

Thanks for fixing it quickly Tom! Glad to help you isolate it.

Cheers,
Filipe
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Tom Gundersen]

On Wed, May 27, 2015 at 6:23 PM, Tom Gundersen  wrote:
> On Wed, May 27, 2015 at 6:16 PM, Filipe Brandenburger
>  wrote:
>> Hi Tom,
>>
>> On Wed, May 27, 2015 at 8:45 AM, Tom Gundersen  wrote:
>>> It appears a few people see this, but I was not able to reproduce. If
>>> anyone could reproduce with this patch applied [0], it would be most
>>> helpful (and post the output of "journalctl -b -u systemd-udevd").
>>
>> Done.
>>
>> Console output from udev in initramfs:
>> http://paste.fedoraproject.org/226145/43216143/
>>
>> And the output of the journalctl command you asked:
>> http://paste.fedoraproject.org/226146/43274324/
>>
>> I have this on Arch Linux with mkinitcpio. Using latest systemd from
>> git plus your patch.
>
> Thanks, that explains it (and teaches me how to reproduce)!

This should be fixed by 86c3bece38bcf55da6387d20c6f01da9ad0284dc.
Thanks for the help in debugging this, and sorry for the
inconvenience.

Cheers,

Tom
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Tom Gundersen]

On Wed, May 27, 2015 at 6:16 PM, Filipe Brandenburger
 wrote:
> Hi Tom,
>
> On Wed, May 27, 2015 at 8:45 AM, Tom Gundersen  wrote:
>> It appears a few people see this, but I was not able to reproduce. If
>> anyone could reproduce with this patch applied [0], it would be most
>> helpful (and post the output of "journalctl -b -u systemd-udevd").
>
> Done.
>
> Console output from udev in initramfs:
> http://paste.fedoraproject.org/226145/43216143/
>
> And the output of the journalctl command you asked:
> http://paste.fedoraproject.org/226146/43274324/
>
> I have this on Arch Linux with mkinitcpio. Using latest systemd from
> git plus your patch.

Thanks, that explains it (and teaches me how to reproduce)!

Cheers,

Tom
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Filipe Brandenburger]

Hi Tom,

On Wed, May 27, 2015 at 8:45 AM, Tom Gundersen  wrote:
> It appears a few people see this, but I was not able to reproduce. If
> anyone could reproduce with this patch applied [0], it would be most
> helpful (and post the output of "journalctl -b -u systemd-udevd").

Done.

Console output from udev in initramfs:
http://paste.fedoraproject.org/226145/43216143/

And the output of the journalctl command you asked:
http://paste.fedoraproject.org/226146/43274324/

I have this on Arch Linux with mkinitcpio. Using latest systemd from
git plus your patch.

HTH!
Filipe
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Tom Gundersen]

On Tue, May 26, 2015 at 5:11 PM, Martin Pitt  wrote:
> Hello Tom, all,
>
> with 220 I get a severe boot time regression:
>
>   $ systemd-analyze
>   Startup finished in 30.751s (kernel) + 11.706s (userspace) = 42.458s
>
> which used to be
>
>   $ systemd-analyze
>   Startup finished in 703ms (kernel) + 890ms (userspace) = 1.593s
>
> (this is a VM)
>
> It seems udevd --daemon spends 30 seconds timing out in the initramfs:
>
>   [0.384519] systemd-udevd[55]: starting version 220
>   [   30.736381] systemd-udevd[56]: timeout, giving up waiting for workers to 
> finish
>
> and then some more in the real root:
>
>$ systemd-analyze blame
>  10.826s dev-vda1.device
>  10.067s systemd-tmpfiles-setup-dev.service
>  10.031s systemd-sysctl.service
>  10.019s systemd-journald.service
>  10.005s sys-fs-fuse-connections.mount
>  10.001s tmp.mount
>
> (full journal at http://paste.ubuntu.com/11372265/, but it's not very
> useful)
>
> I bisected this to
>
>   http://cgit.freedesktop.org/systemd/systemd/commit/?id=e237d8c
>   udevd: move file descriptors to Manager
>
> this is hard to revert individually as there are lots of other recent changes
> in udev around this commit, but any version before that commit is fast
> and doesn't give that timeout error.
>
> Current trunk as of commit 185abfc3 still has that problem, so it
> wasn't fixed by one of the recent udev commits.
>
> Does anyone else see this too? Any idea what causes this?

It appears a few people see this, but I was not able to reproduce. If
anyone could reproduce with this patch applied [0], it would be most
helpful (and post the output of "journalctl -b -u systemd-udevd").

Cheers,

Tom

[0]: 
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Tom Gundersen]

On Tue, May 26, 2015 at 9:04 PM, Christian Hesse  wrote:
> Martin Pitt  on Tue, 2015/05/26 17:11:
>> Hello Tom, all,
>>
>> with 220 I get a severe boot time regression:
>>
>>   $ systemd-analyze
>>   Startup finished in 30.751s (kernel) + 11.706s (userspace) = 42.458s
>>
>> which used to be
>>
>>   $ systemd-analyze
>>   Startup finished in 703ms (kernel) + 890ms (userspace) = 1.593s
>>
>> (this is a VM)
>>
>> It seems udevd --daemon spends 30 seconds timing out in the initramfs:
>>
>>   [0.384519] systemd-udevd[55]: starting version 220
>>   [   30.736381] systemd-udevd[56]: timeout, giving up waiting for workers
>> to finish
>>
>> and then some more in the real root:
>>
>>$ systemd-analyze blame
>>  10.826s dev-vda1.device
>>  10.067s systemd-tmpfiles-setup-dev.service
>>  10.031s systemd-sysctl.service
>>  10.019s systemd-journald.service
>>  10.005s sys-fs-fuse-connections.mount
>>  10.001s tmp.mount
>>
>> (full journal at http://paste.ubuntu.com/11372265/, but it's not very
>> useful)
>>
>> I bisected this to
>>
>>   http://cgit.freedesktop.org/systemd/systemd/commit/?id=e237d8c
>>   udevd: move file descriptors to Manager
>>
>> this is hard to revert individually as there are lots of other recent
>> changes in udev around this commit, but any version before that commit is
>> fast and doesn't give that timeout error.
>>
>> Current trunk as of commit 185abfc3 still has that problem, so it
>> wasn't fixed by one of the recent udev commits.
>>
>> Does anyone else see this too? Any idea what causes this?
>
> I do see this as well. And probably we have an upstream bug [0] already.

Oh, and this bug report is probably unrelated. It is an old one (that
I could never reproduce), and the relevant parts were reworked
(probably causing the current issues).

-t

> Wondering whether or not my report about "inotify_add_watch() failed: Bad
> file descriptor" [1] is related. Do you see that as well?
> BTW, is it expected to have fd_inotify in udevd.c and inotify_fd in
> udev_watch.c?
>
> [0] https://bugs.freedesktop.org/show_bug.cgi?id=90051
> [1] http://lists.freedesktop.org/archives/systemd-devel/2015-May/032213.html
> --
> main(a){char*c=/*Schoene Gruesse */"B?IJj;MEH"
> "CX:;",b;for(a/*Chris   get my mail address:*/=0;b=c[a++];)
> putchar(b-1/(/*   gcc -o sig sig.c && ./sig*/b/42*2-3)*42);}
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Tom Gundersen]

On Tue, May 26, 2015 at 9:04 PM, Christian Hesse  wrote:
> Martin Pitt  on Tue, 2015/05/26 17:11:
>> Hello Tom, all,
>>
>> with 220 I get a severe boot time regression:
>>
>>   $ systemd-analyze
>>   Startup finished in 30.751s (kernel) + 11.706s (userspace) = 42.458s
>>
>> which used to be
>>
>>   $ systemd-analyze
>>   Startup finished in 703ms (kernel) + 890ms (userspace) = 1.593s
>>
>> (this is a VM)
>>
>> It seems udevd --daemon spends 30 seconds timing out in the initramfs:
>>
>>   [0.384519] systemd-udevd[55]: starting version 220
>>   [   30.736381] systemd-udevd[56]: timeout, giving up waiting for workers
>> to finish
>>
>> and then some more in the real root:
>>
>>$ systemd-analyze blame
>>  10.826s dev-vda1.device
>>  10.067s systemd-tmpfiles-setup-dev.service
>>  10.031s systemd-sysctl.service
>>  10.019s systemd-journald.service
>>  10.005s sys-fs-fuse-connections.mount
>>  10.001s tmp.mount
>>
>> (full journal at http://paste.ubuntu.com/11372265/, but it's not very
>> useful)
>>
>> I bisected this to
>>
>>   http://cgit.freedesktop.org/systemd/systemd/commit/?id=e237d8c
>>   udevd: move file descriptors to Manager
>>
>> this is hard to revert individually as there are lots of other recent
>> changes in udev around this commit, but any version before that commit is
>> fast and doesn't give that timeout error.
>>
>> Current trunk as of commit 185abfc3 still has that problem, so it
>> wasn't fixed by one of the recent udev commits.
>>
>> Does anyone else see this too? Any idea what causes this?
>
> I do see this as well. And probably we have an upstream bug [0] already.
>
> Wondering whether or not my report about "inotify_add_watch() failed: Bad
> file descriptor" [1] is related. Do you see that as well?
> BTW, is it expected to have fd_inotify in udevd.c and inotify_fd in
> udev_watch.c?

This is unrelated.

Cheers,

Tom
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Christian Hesse]

Martin Pitt  on Tue, 2015/05/26 17:11:
> Hello Tom, all,
> 
> with 220 I get a severe boot time regression:
> 
>   $ systemd-analyze
>   Startup finished in 30.751s (kernel) + 11.706s (userspace) = 42.458s
> 
> which used to be
> 
>   $ systemd-analyze
>   Startup finished in 703ms (kernel) + 890ms (userspace) = 1.593s
> 
> (this is a VM)
> 
> It seems udevd --daemon spends 30 seconds timing out in the initramfs:
> 
>   [0.384519] systemd-udevd[55]: starting version 220
>   [   30.736381] systemd-udevd[56]: timeout, giving up waiting for workers
> to finish
> 
> and then some more in the real root:
> 
>$ systemd-analyze blame
>  10.826s dev-vda1.device
>  10.067s systemd-tmpfiles-setup-dev.service
>  10.031s systemd-sysctl.service
>  10.019s systemd-journald.service
>  10.005s sys-fs-fuse-connections.mount
>  10.001s tmp.mount
> 
> (full journal at http://paste.ubuntu.com/11372265/, but it's not very
> useful)
> 
> I bisected this to
> 
>   http://cgit.freedesktop.org/systemd/systemd/commit/?id=e237d8c
>   udevd: move file descriptors to Manager
> 
> this is hard to revert individually as there are lots of other recent
> changes in udev around this commit, but any version before that commit is
> fast and doesn't give that timeout error.
> 
> Current trunk as of commit 185abfc3 still has that problem, so it
> wasn't fixed by one of the recent udev commits.
> 
> Does anyone else see this too? Any idea what causes this?

I do see this as well. And probably we have an upstream bug [0] already.

Wondering whether or not my report about "inotify_add_watch() failed: Bad
file descriptor" [1] is related. Do you see that as well?
BTW, is it expected to have fd_inotify in udevd.c and inotify_fd in
udev_watch.c?

[0] https://bugs.freedesktop.org/show_bug.cgi?id=90051
[1] http://lists.freedesktop.org/archives/systemd-devel/2015-May/032213.html
-- 
main(a){char*c=/*Schoene Gruesse */"B?IJj;MEH"
"CX:;",b;for(a/*Chris   get my mail address:*/=0;b=c[a++];)
putchar(b-1/(/*   gcc -o sig sig.c && ./sig*/b/42*2-3)*42);}


pgpjACQJgD4Y4.pgp
Description: OpenPGP digital signature
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Tom Gundersen]

On Tue, May 26, 2015 at 5:11 PM, Martin Pitt  wrote:
> Hello Tom, all,
>
> with 220 I get a severe boot time regression:
>
>   $ systemd-analyze
>   Startup finished in 30.751s (kernel) + 11.706s (userspace) = 42.458s
>
> which used to be
>
>   $ systemd-analyze
>   Startup finished in 703ms (kernel) + 890ms (userspace) = 1.593s
>
> (this is a VM)
>
> It seems udevd --daemon spends 30 seconds timing out in the initramfs:
>
>   [0.384519] systemd-udevd[55]: starting version 220
>   [   30.736381] systemd-udevd[56]: timeout, giving up waiting for workers to 
> finish
>
> and then some more in the real root:
>
>$ systemd-analyze blame
>  10.826s dev-vda1.device
>  10.067s systemd-tmpfiles-setup-dev.service
>  10.031s systemd-sysctl.service
>  10.019s systemd-journald.service
>  10.005s sys-fs-fuse-connections.mount
>  10.001s tmp.mount
>
> (full journal at http://paste.ubuntu.com/11372265/, but it's not very
> useful)
>
> I bisected this to
>
>   http://cgit.freedesktop.org/systemd/systemd/commit/?id=e237d8c
>   udevd: move file descriptors to Manager
>
> this is hard to revert individually as there are lots of other recent changes
> in udev around this commit, but any version before that commit is fast
> and doesn't give that timeout error.
>
> Current trunk as of commit 185abfc3 still has that problem, so it
> wasn't fixed by one of the recent udev commits.
>
> Does anyone else see this too? Any idea what causes this?

FWIW, I'm looking into this.

Cheers,

Tom
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel

[systemd-devel] 220 udev boot regression: timeout, giving up waiting for workers to finish

[Martin Pitt]

Hello Tom, all,

with 220 I get a severe boot time regression:

  $ systemd-analyze
  Startup finished in 30.751s (kernel) + 11.706s (userspace) = 42.458s

which used to be

  $ systemd-analyze
  Startup finished in 703ms (kernel) + 890ms (userspace) = 1.593s

(this is a VM)

It seems udevd --daemon spends 30 seconds timing out in the initramfs:

  [0.384519] systemd-udevd[55]: starting version 220
  [   30.736381] systemd-udevd[56]: timeout, giving up waiting for workers to 
finish

and then some more in the real root:

   $ systemd-analyze blame
 10.826s dev-vda1.device
 10.067s systemd-tmpfiles-setup-dev.service
 10.031s systemd-sysctl.service
 10.019s systemd-journald.service
 10.005s sys-fs-fuse-connections.mount
 10.001s tmp.mount

(full journal at http://paste.ubuntu.com/11372265/, but it's not very
useful)

I bisected this to

  http://cgit.freedesktop.org/systemd/systemd/commit/?id=e237d8c
  udevd: move file descriptors to Manager

this is hard to revert individually as there are lots of other recent changes
in udev around this commit, but any version before that commit is fast
and doesn't give that timeout error.

Current trunk as of commit 185abfc3 still has that problem, so it
wasn't fixed by one of the recent udev commits.

Does anyone else see this too? Any idea what causes this?

Thanks,

Martin

-- 
Martin Pitt| http://www.piware.de
Ubuntu Developer (www.ubuntu.com)  | Debian Developer  (www.debian.org)


signature.asc
Description: Digital signature
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel