Linux Archive - Soft Lockups while running the daily cron job : what do with them

On 05/17/2011 11:33 AM, Emmanuel Kasper wrote:
> Hello
> On a relatively busy xen server, running 10 VM, I noticed soft lock
> coming regularly, around 06:25.
>
>
> kern.log.2.gz:May 2 06:27:15 vaduz kernel: [10156409.027744] INFO: task
> dpkg-query:24275 blocked for more than 120 seconds.
> kern.log.2.gz:May 4 06:27:13 vaduz kernel: [10329259.982553] INFO: task
> locate:6752 blocked for more than 120 seconds.
> syslog.6.gz:May 12 06:27:17 vaduz kernel: [11020672.410138] INFO: task
> update-dlocated:9078 blocked for more than 120 seconds.
> syslog.7.gz:May 11 06:27:22 vaduz kernel: [10934249.078237] INFO: task
> dlocate:15949 blocked for more than 120 seconds.
> syslog.7.gz:May 11 06:27:28 vaduz kernel: [10934255.518954] INFO: task
> kjournald:1297 blocked for more than 120 seconds.
> syslog.7.gz:May 11 06:27:45 vaduz kernel: [10934272.704136] INFO: task
> pdflush:244 blocked for more than 120 seconds.
>
> I guess every debian sysadmin around here will recognize the time at
> which the daily crontab jobs :)
>
> Am I right to think here that my server is simply starving for I/O ? I
> am thinking of split cron jobs out between 5:00 and 7:00, would that be
> the right thing to do ?

A lot of people is suffering this bug and still is unknown where exactly is
the problem.

For me started to happen with the upgrade to Squeeze. I workarounded it
downgrading the kernel to lenny's one.

It will be very useful that you report it on the bugzilla's kernel.

The bug number is the following:

https://bugzilla.kernel.org/show_bug.cgi?id=18632

If you know how to reproduce it or when will it happen please do the
following when it is happening (as root)

echo t >/proc/sysrq-trigger

As a trick you can left the following dirty loop on a screen waiting for it
to happen:

while sleep 5; do dmesg |grep -q 'blocked for more than 120 seconds' &&
echo t >/proc/sysrq-trigger && break; done

And then a lot of info about the internal kernel status will be printed to
/var/log/kern.log

Upload that info with a brief description of what the system was doing when
it happened among useful information about your system like filesystems in
use, kind of cpu, modules loaded...

>
> BTW if I understand right this kernel log is an INFO message, so it
> means the kernel will not kill the process ? Or will he ?
>

No, the kernel will not kill anything. Only is letting you know that a
process was blocked for more than 120 seconds because the kernel was unable
to give the process the slot for I/O that it was requesting.