On Wed, 18.02.15 10:41, Thierry Parmentelat (thierry.parmente...@inria.fr)
wrote:
> root@bigjohn /vservers # journalctl -b -f
> -- Logs begin at Fri 2014-09-05 04:28:57 CEST. --
> Feb 18 10:38:25 bigjohn.pl.sophia.inria.fr systemd[1]: Looping too fast.
> Throttling execution a little.
> Feb 18 10:38:26 bigjohn.pl.sophia.inria.fr systemd[1]: Looping too fast.
> Throttling execution a little.
> Feb 18 10:38:28 bigjohn.pl.sophia.inria.fr systemd[1]: Looping too fast.
> Throttling execution a little.
> Feb 18 10:38:30 bigjohn.pl.sophia.inria.fr systemd[1]: Looping too fast.
> Throttling execution a little.
> Feb 18 10:38:31 bigjohn.pl.sophia.inria.fr systemd[1]: Looping too fast.
> Throttling execution a little.
> Feb 18 10:38:33 bigjohn.pl.sophia.inria.fr systemd[1]: Looping too fast.
> Throttling execution a little.
THis is happens if for some reason the event loop entered a busy
loop. It's simply a protection against eating up all CPU forever. It's
a symptom of another bug, which is the one to track down.
> # strace -p 1
> <…>
> recvmsg(42, 0x7fff3ea64d00, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1
> EAGAIN (Resource temporarily unavailable)
> timerfd_settime(3, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={0, 1}},
> NULL) = 0
> epoll_wait(4, {{EPOLLIN, {u32=3, u64=3}}}, 36, 0) = 1
> clock_gettime(CLOCK_BOOTTIME, {1959524, 957887776}) = 0
> read(3, "\1\0\0\0\0\0\0\0", 8) = 8
> recvmsg(42, 0x7fff3ea64d00, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1
> EAGAIN (Resource temporarily unavailable)
> timerfd_settime(3, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={0, 1}},
> NULL) = 0
> epoll_wait(4, {{EPOLLIN, {u32=3, u64=3}}}, 36, 0) = 1
> clock_gettime(CLOCK_BOOTTIME, {1959524, 958282696}) = 0
> read(3, "\1\0\0\0\0\0\0\0", 8) = 8
> recvmsg(42, 0x7fff3ea64d00, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1
> EAGAIN (Resource temporarily unavailable)
> timerfd_settime(3, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={0, 1}},
> NULL) = 0
> epoll_wait(4, {{EPOLLIN, {u32=3, u64=3}}}, 36, 0) = 1
> clock_gettime(CLOCK_BOOTTIME, {1959524, 958617432}) = 0
> ^CProcess 1 detached
Hmm, this appears to be caused by a timer that is not reset. First the
timer fd is set to the earliest possible trigger, then epoll_wait() is
entered, which immediately quites. Then the tiemrfd elapse counter is
read which is 1.
It would be interesting to figure out which timer this is.
To make this work, can you reproduce the issue, then use gdb:
1. Type "gdb" to start it
2. Type "attach 1" to attach to PID 1
3. Type "b source_dispatch" to set a break point on the source_dispatch function
4. Type "c" to continue execution
5. This should then break on the next execution of the source_dispatch function
6. This should happen immediately, after all PID 1 is busy looping
around a timer. Use "p s->description" to get a short description
string for the event that is being dispatched. In fact, please use
"p *s" to get all data about the event, and paste it here.
Thanks!
Lennart
--
Lennart Poettering, Red Hat
_______________________________________________
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
