> Steve Lord <lord@xxxxxxx> wrote:
>
> > As for debugging this hang - it is a little tricky without something like
> > kdb. Getting a stack trace for the mount process would be critical to worki
ng
> > out what went wrong. I suspect some read of a block from disk did not wake
> > up the requesting thread. There is tracing in the pagebuf module, but it
> > relied on kdb to dump the results, mapping these trace calls onto printk
> > messages, or some other mechanism may help.
>
> i tried it with the poor mans debugger - printk :-)
>
> i put printk's all over xfs_mountfs_int (which i hope is the right
> point for the mounting stage) and to my confusion - non of them were
> printed out (the first one was before xfs_mount_common - maybe i
> should move it before the xfs_readsb) ... i'll try to look at this
> a bit deeper - also i will try to find out how to use xmon (if that
> is possible on my machine)
>
The place you probably need to scatter printk all over is fs/pagebuf/page_buf.c
the easiest way to do this is to edit include/linux/page_buf.h and ensure
that PAGEBUF_TRACE is defined (it is dependent on CONFIG_KDB at the moment).
Make sure that debug_pagebuf is set to 1.
Then edit pb_trace_func in page_buf.c and instead of putting data into a
trace buffer, take something based on the code in kdb/modules/kdbm_pg.c
which does this:
if ((trace->event < EV_SIZE) && event_names[trace->event]) {
event = event_names[trace->event];
} else if (trace->event == 1000) {
event = (char *)trace->misc;
} else {
event = value;
sprintf(value, "%8d", trace->event);
kdb_printf("pb 0x%lx [%s] (hold %u lock %d) misc 0x%p",
trace->pb, event,
trace->hold, trace->lock_value,
trace->misc);
kdb_symbol_print((unsigned int)trace->ra, NULL,
KDB_SP_SPACEB|KDB_SP_PAREN|KDB_SP_NEWLINE);
kdb_printf(" offset 0x%Lx size 0x%x task 0x%p\n",
trace->offset, trace->size, trace->task);
kdb_printf(" flags: %s\n",
pb_flags(trace->flags));
(clearly those need to become printk messages).
you should then be able to get output which looks something like this:
pb 0xc15bd080 [done] (hold 1 lock 0) misc 0x00000000
([xfs]xfs_buf_iodone_callbacks+0x168)
offset 0x100c80000 size 0x2000 task 0xc02d8000
flags: MAPPED ASYNC LOCK LOCKABLE ALL_PAGES_MAPPED ADDR_ALLOCATED
MEM_ALLOCATED
pb 0xc15bd080 [unlock] (hold 1 lock 1) misc 0x00000000
([pagebuf]pagebuf_iodone+0x6c)
offset 0x100c80000 size 0x2000 task 0xc02d8000
flags: MAPPED ASYNC LOCK LOCKABLE ALL_PAGES_MAPPED ADDR_ALLOCATED
MEM_ALLOCATED
......
The first thing to establish is is the first I/O on a pagebuf completing,
this is the super block.
This is what the super block read ends up looking like:
pb 0xc155dee0 [get] (hold 1 lock 0) misc 0xc050eb00
([pagebuf]pagebuf_get_no_daddr+0x22)
offset 0x0 size 0x200 task 0xc237a000
flags: NONE LOCKABLE FORECIO
pb 0xc155dee0 [no_daddr] (hold 1 lock 0) misc 0xc6bc0800
([xfs]xfs_pb_ngetr+0x16)
offset 0x0 size 0x200 task 0xc237a000
flags: MAPPED NONE LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [ioreq] (hold 1 lock 0) misc 0x00000000 ([xfs]xfsbdstrat+0x2b)
offset 0x0 size 0x200 task 0xc237a000
flags: READ MAPPED NONE LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [hold] (hold 2 lock 0) misc 0x00000000
([pagebuf]pagebuf_segment_apply+0x38)
offset 0x0 size 0x200 task 0xc237a000
flags: READ MAPPED NONE LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [rele] (hold 2 lock 0) misc 0xc887dbb8
([pagebuf]pagebuf_segment_apply+0x120)
offset 0x0 size 0x200 task 0xc237a000
flags: READ MAPPED NONE LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [iowait] (hold 1 lock 0) misc 0x00000000 ([xfs]xfs_readsb+0x40)
offset 0x0 size 0x200 task 0xc237a000
flags: READ MAPPED NONE LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [done] (hold 1 lock 0) misc 0x00000000
([pagebuf]_end_pagebuf_page_io+0x143)
offset 0x0 size 0x200 task 0xc02d8000
flags: MAPPED LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [iowaited] (hold 1 lock 0) misc 0x00000000 ([xfs]xfs_readsb+0x40)
offset 0x0 size 0x200 task 0xc237a000
flags: MAPPED LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [rele] (hold 1 lock 0) misc 0xc887dbb8 ([xfs]xfs_readsb+0xa7)
offset 0x0 size 0x200 task 0xc237a000
flags: MAPPED LOCKABLE MEM_ALLOCATED FORECIO
pb 0xc155dee0 [unlock] (hold 1 lock 1) misc 0x00000000 ([xfs]xfs_sb_relse+0x10)
offset 0x0 size 0x200 task 0xc237a000
flags: MAPPED LOCKABLE MEM_ALLOCATED FORECIO
The iowait is the mount thread going to sleep waiting for the read to complete,
the done is the interrupt going off on I/O completion and the iowaited is the
mount thread waking up.
After this it will get really verbose, it has to go read the log to see if a
clean unmount was performed.
Steve
|