* Re: linux-next: Tree for September 4
[not found] ` <20080905113042.0f6d5850.akpm@linux-foundation.org>
@ 2008-09-06 11:25 ` Rafael J. Wysocki
2008-09-06 13:42 ` James Bottomley
0 siblings, 1 reply; 2+ messages in thread
From: Rafael J. Wysocki @ 2008-09-06 11:25 UTC (permalink / raw)
To: Andrew Morton; +Cc: Stephen Rothwell, linux-next, LKML, linux-scsi, linux-ide
On Friday, 5 of September 2008, Andrew Morton wrote:
> On Fri, 5 Sep 2008 12:56:35 +0200 "Rafael J. Wysocki" <rjw@sisk.pl> wrote:
>
> > On Friday, 5 of September 2008, Andrew Morton wrote:
> > > On Thu, 4 Sep 2008 19:36:06 +1000 Stephen Rothwell <sfr@canb.auug.org.au> wrote:
> > >
> > > > I have created today's linux-next tree at
> > > > git://git.kernel.org/pub/scm/linux/kernel/git/sfr/linux-next.git
> > >
> > > The infamous Vaio hasn't finished catching up with you guys yet.
> > > Something in linux-next broke suspend-to-RAM.
> > >
> > > An `echo mem > /sys/power/state' causes "Freezing of tasks failed after
> > > 20.00 seconds (1 tasks refusing to freeze):"
> > >
> > > dmesg: http://userweb.kernel.org/~akpm/dmesg-sony-suspend.txt
> > > config: http://userweb.kernel.org/~akpm/config-sony.txt
> > >
> > > This only happens after the X server has been started.
> > >
> > > Mainline is OK.
> >
> > According to your dmesg the process that refused to freeze was
> >
> > hald-addon-stor
> >
> > which got stuck in ... getnstimeofday (???) (can you check what
> > source code corresponds to getnstimeofday+0x37/0xbc pls?):
> >
> > hald-addon-st D 00000046 0 2322 2282
> > f4de5b74 00000046 f4de5b54 00000046 f4de5b5c c0135f56 f6b96e44 f4deaf40
> > f4deb0bc f5580948 f4de5bb0 f4de5b6c c013336e f6aa77c8 f6aa77c8 f6aa77a0
> > f4de5bb0 f4de5b7c c0331f09 f4de5bd0 c01f4205 00000000 00000000 00000000
> > Call Trace:
> > [<c0135f56>] ? getnstimeofday+0x37/0xbc
> > [<c013336e>] ? ktime_get_ts+0x40/0x44
> > [<c0331f09>] io_schedule+0x39/0x6c
> > [<c01f4205>] get_request_wait+0x80/0xcd
> > ...
>
> (gdb) x/60i getnstimeofday
> 0xc0135d63 <getnstimeofday>: push %ebp
> 0xc0135d64 <getnstimeofday+1>: mov %esp,%ebp
> 0xc0135d66 <getnstimeofday+3>: push %edi
> 0xc0135d67 <getnstimeofday+4>: push %esi
> 0xc0135d68 <getnstimeofday+5>: push %ebx
> 0xc0135d69 <getnstimeofday+6>: sub $0x8,%esp
> 0xc0135d6c <getnstimeofday+9>: mov %eax,0xffffffec(%ebp)
> 0xc0135d6f <getnstimeofday+12>: mov 0xc045a2c0,%eax
> 0xc0135d74 <getnstimeofday+17>: mov %eax,0xfffffff0(%ebp)
> 0xc0135d77 <getnstimeofday+20>: test $0x1,%al
> 0xc0135d79 <getnstimeofday+22>: je 0xc0135d7f <getnstimeofday+28>
> 0xc0135d7b <getnstimeofday+24>: pause
> 0xc0135d7d <getnstimeofday+26>: jmp 0xc0135d6f <getnstimeofday+12>
> 0xc0135d7f <getnstimeofday+28>: mov 0xffffffec(%ebp),%ecx
> 0xc0135d82 <getnstimeofday+31>: mov 0xc05db920,%eax
> 0xc0135d87 <getnstimeofday+36>: mov 0xc05db924,%edx
> 0xc0135d8d <getnstimeofday+42>: mov %eax,(%ecx)
> 0xc0135d8f <getnstimeofday+44>: mov %edx,0x4(%ecx)
> 0xc0135d92 <getnstimeofday+47>: mov 0xc05db938,%eax
> 0xc0135d97 <getnstimeofday+52>: call *0x10(%eax)
> 0xc0135d9a <getnstimeofday+55>: mov 0xc05db938,%esi
> 0xc0135da0 <getnstimeofday+61>: mov 0x1c(%esi),%ecx
> 0xc0135da3 <getnstimeofday+64>: sub 0x48(%esi),%eax
> 0xc0135da6 <getnstimeofday+67>: sbb 0x4c(%esi),%edx
> 0xc0135da9 <getnstimeofday+70>: and 0x14(%esi),%eax
> 0xc0135dac <getnstimeofday+73>: and 0x18(%esi),%edx
> 0xc0135daf <getnstimeofday+76>: mov %edx,%edi
> 0xc0135db1 <getnstimeofday+78>: imul %ecx,%edi
> 0xc0135db4 <getnstimeofday+81>: mul %ecx
> 0xc0135db6 <getnstimeofday+83>: mov 0x24(%esi),%ecx
> 0xc0135db9 <getnstimeofday+86>: lea (%edi,%edx,1),%edx
> 0xc0135dbc <getnstimeofday+89>: mov %eax,%ebx
> 0xc0135dbe <getnstimeofday+91>: mov %edx,%esi
> 0xc0135dc0 <getnstimeofday+93>: xor %edi,%edi
> 0xc0135dc2 <getnstimeofday+95>: shrd %cl,%edx,%ebx
> 0xc0135dc5 <getnstimeofday+98>: shr %cl,%esi
> 0xc0135dc7 <getnstimeofday+100>: test $0x20,%cl
> 0xc0135dca <getnstimeofday+103>: cmovne %esi,%ebx
> 0xc0135dcd <getnstimeofday+106>: cmovne %edi,%esi
> 0xc0135dd0 <getnstimeofday+109>: mov %ebx,%edx
>
> (gdb) l *0xc0135d9a
> 0xc0135d9a is in getnstimeofday (kernel/time/timekeeping.c:104).
> 99
> 100 /* read clocksource: */
> 101 cycle_now = clocksource_read(clock);
> 102
> 103 /* calculate the delta since the last update_wall_time: */
> 104 cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
> 105
> 106 /* convert to nanoseconds: */
> 107 nsecs = cyc2ns(clock, cycle_delta);
> 108
>
> Which implies that someone mucked up xtime_lock.
>
> But I don't think any of that is correct. The getnstimeofday is just
> stack gunk. hald is in D state and is asleep in get_request_wait().
Right. It looks like there was a media change in the CD drive and hald was
waiting for the device in sr_test_unit_ready() forever. Apparently, the device
could not get ready.
It looks like a SATA/ATA (whatever the CD-ROM is attached to) issue or sr_mod
breakage.
Thanks,
Rafael
^ permalink raw reply [flat|nested] 2+ messages in thread
* Re: linux-next: Tree for September 4
2008-09-06 11:25 ` linux-next: Tree for September 4 Rafael J. Wysocki
@ 2008-09-06 13:42 ` James Bottomley
0 siblings, 0 replies; 2+ messages in thread
From: James Bottomley @ 2008-09-06 13:42 UTC (permalink / raw)
To: Rafael J. Wysocki
Cc: Andrew Morton, Stephen Rothwell, linux-next, LKML, linux-scsi,
linux-ide
On Sat, 2008-09-06 at 13:25 +0200, Rafael J. Wysocki wrote:
> On Friday, 5 of September 2008, Andrew Morton wrote:
> > On Fri, 5 Sep 2008 12:56:35 +0200 "Rafael J. Wysocki" <rjw@sisk.pl> wrote:
> >
> > > On Friday, 5 of September 2008, Andrew Morton wrote:
> > > > On Thu, 4 Sep 2008 19:36:06 +1000 Stephen Rothwell <sfr@canb.auug.org.au> wrote:
> > > >
> > > > > I have created today's linux-next tree at
> > > > > git://git.kernel.org/pub/scm/linux/kernel/git/sfr/linux-next.git
> > > >
> > > > The infamous Vaio hasn't finished catching up with you guys yet.
> > > > Something in linux-next broke suspend-to-RAM.
> > > >
> > > > An `echo mem > /sys/power/state' causes "Freezing of tasks failed after
> > > > 20.00 seconds (1 tasks refusing to freeze):"
> > > >
> > > > dmesg: http://userweb.kernel.org/~akpm/dmesg-sony-suspend.txt
> > > > config: http://userweb.kernel.org/~akpm/config-sony.txt
> > > >
> > > > This only happens after the X server has been started.
> > > >
> > > > Mainline is OK.
> > >
> > > According to your dmesg the process that refused to freeze was
> > >
> > > hald-addon-stor
> > >
> > > which got stuck in ... getnstimeofday (???) (can you check what
> > > source code corresponds to getnstimeofday+0x37/0xbc pls?):
> > >
> > > hald-addon-st D 00000046 0 2322 2282
> > > f4de5b74 00000046 f4de5b54 00000046 f4de5b5c c0135f56 f6b96e44 f4deaf40
> > > f4deb0bc f5580948 f4de5bb0 f4de5b6c c013336e f6aa77c8 f6aa77c8 f6aa77a0
> > > f4de5bb0 f4de5b7c c0331f09 f4de5bd0 c01f4205 00000000 00000000 00000000
> > > Call Trace:
> > > [<c0135f56>] ? getnstimeofday+0x37/0xbc
> > > [<c013336e>] ? ktime_get_ts+0x40/0x44
> > > [<c0331f09>] io_schedule+0x39/0x6c
> > > [<c01f4205>] get_request_wait+0x80/0xcd
> > > ...
> >
> > (gdb) x/60i getnstimeofday
> > 0xc0135d63 <getnstimeofday>: push %ebp
> > 0xc0135d64 <getnstimeofday+1>: mov %esp,%ebp
> > 0xc0135d66 <getnstimeofday+3>: push %edi
> > 0xc0135d67 <getnstimeofday+4>: push %esi
> > 0xc0135d68 <getnstimeofday+5>: push %ebx
> > 0xc0135d69 <getnstimeofday+6>: sub $0x8,%esp
> > 0xc0135d6c <getnstimeofday+9>: mov %eax,0xffffffec(%ebp)
> > 0xc0135d6f <getnstimeofday+12>: mov 0xc045a2c0,%eax
> > 0xc0135d74 <getnstimeofday+17>: mov %eax,0xfffffff0(%ebp)
> > 0xc0135d77 <getnstimeofday+20>: test $0x1,%al
> > 0xc0135d79 <getnstimeofday+22>: je 0xc0135d7f <getnstimeofday+28>
> > 0xc0135d7b <getnstimeofday+24>: pause
> > 0xc0135d7d <getnstimeofday+26>: jmp 0xc0135d6f <getnstimeofday+12>
> > 0xc0135d7f <getnstimeofday+28>: mov 0xffffffec(%ebp),%ecx
> > 0xc0135d82 <getnstimeofday+31>: mov 0xc05db920,%eax
> > 0xc0135d87 <getnstimeofday+36>: mov 0xc05db924,%edx
> > 0xc0135d8d <getnstimeofday+42>: mov %eax,(%ecx)
> > 0xc0135d8f <getnstimeofday+44>: mov %edx,0x4(%ecx)
> > 0xc0135d92 <getnstimeofday+47>: mov 0xc05db938,%eax
> > 0xc0135d97 <getnstimeofday+52>: call *0x10(%eax)
> > 0xc0135d9a <getnstimeofday+55>: mov 0xc05db938,%esi
> > 0xc0135da0 <getnstimeofday+61>: mov 0x1c(%esi),%ecx
> > 0xc0135da3 <getnstimeofday+64>: sub 0x48(%esi),%eax
> > 0xc0135da6 <getnstimeofday+67>: sbb 0x4c(%esi),%edx
> > 0xc0135da9 <getnstimeofday+70>: and 0x14(%esi),%eax
> > 0xc0135dac <getnstimeofday+73>: and 0x18(%esi),%edx
> > 0xc0135daf <getnstimeofday+76>: mov %edx,%edi
> > 0xc0135db1 <getnstimeofday+78>: imul %ecx,%edi
> > 0xc0135db4 <getnstimeofday+81>: mul %ecx
> > 0xc0135db6 <getnstimeofday+83>: mov 0x24(%esi),%ecx
> > 0xc0135db9 <getnstimeofday+86>: lea (%edi,%edx,1),%edx
> > 0xc0135dbc <getnstimeofday+89>: mov %eax,%ebx
> > 0xc0135dbe <getnstimeofday+91>: mov %edx,%esi
> > 0xc0135dc0 <getnstimeofday+93>: xor %edi,%edi
> > 0xc0135dc2 <getnstimeofday+95>: shrd %cl,%edx,%ebx
> > 0xc0135dc5 <getnstimeofday+98>: shr %cl,%esi
> > 0xc0135dc7 <getnstimeofday+100>: test $0x20,%cl
> > 0xc0135dca <getnstimeofday+103>: cmovne %esi,%ebx
> > 0xc0135dcd <getnstimeofday+106>: cmovne %edi,%esi
> > 0xc0135dd0 <getnstimeofday+109>: mov %ebx,%edx
> >
> > (gdb) l *0xc0135d9a
> > 0xc0135d9a is in getnstimeofday (kernel/time/timekeeping.c:104).
> > 99
> > 100 /* read clocksource: */
> > 101 cycle_now = clocksource_read(clock);
> > 102
> > 103 /* calculate the delta since the last update_wall_time: */
> > 104 cycle_delta = (cycle_now - clock->cycle_last) & clock->mask;
> > 105
> > 106 /* convert to nanoseconds: */
> > 107 nsecs = cyc2ns(clock, cycle_delta);
> > 108
> >
> > Which implies that someone mucked up xtime_lock.
> >
> > But I don't think any of that is correct. The getnstimeofday is just
> > stack gunk. hald is in D state and is asleep in get_request_wait().
>
> Right. It looks like there was a media change in the CD drive and hald was
> waiting for the device in sr_test_unit_ready() forever. Apparently, the device
> could not get ready.
>
> It looks like a SATA/ATA (whatever the CD-ROM is attached to) issue or sr_mod
> breakage.
Um, I don't see how that follows.
get_request_wait() is the first thing the block layer does to try to get
a request structure for the queue. If it's stuck there it means that
block was out of requests and is waiting for some memory to free up. If
we're stuck there, nothing went down to the CD.
However, being stuck here really isn't good news. These things are
mempool backed to prevent writeout deadlock ... we shouldn't be running
out of them. What does
/sys/block/<dev>/queue/nr_reqeusts
and
/sys/block/<dev>/stat
say for this device?
James
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2008-09-06 13:42 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <20080904193606.573f2cb3.sfr@canb.auug.org.au>
[not found] ` <200809051256.36257.rjw@sisk.pl>
[not found] ` <20080905113042.0f6d5850.akpm@linux-foundation.org>
2008-09-06 11:25 ` linux-next: Tree for September 4 Rafael J. Wysocki
2008-09-06 13:42 ` James Bottomley
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).