This file is indexed.

/usr/share/doc/user-mode-linux-doc/html/UserModeLinux-HOWTO-12.html is in user-mode-linux-doc 20060501-1.

This file is owned by root:root, with mode 0o644.

The actual contents of the file can be viewed below.

  1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
690
691
692
693
694
695
696
697
698
699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742
743
744
745
746
747
748
749
750
751
752
753
754
755
756
757
758
759
760
761
762
763
764
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2 Final//EN">
<HTML>
<HEAD>
 <META NAME="GENERATOR" CONTENT="LinuxDoc-Tools 0.9.21">
 <TITLE>User Mode Linux HOWTO : Kernel debugging examples</TITLE>
 <LINK HREF="UserModeLinux-HOWTO-13.html" REL=next>
 <LINK HREF="UserModeLinux-HOWTO-11.html" REL=previous>
 <LINK HREF="UserModeLinux-HOWTO.html#toc12" REL=contents>
</HEAD>
<BODY>
<A HREF="UserModeLinux-HOWTO-13.html">Next</A>
<A HREF="UserModeLinux-HOWTO-11.html">Previous</A>
<A HREF="UserModeLinux-HOWTO.html#toc12">Contents</A>
<HR>
<H2><A NAME="s12">12.</A> <A HREF="UserModeLinux-HOWTO.html#toc12">Kernel debugging examples</A></H2>

<H2><A NAME="ss12.1">12.1</A> <A HREF="UserModeLinux-HOWTO.html#toc12.1">The case of the hung fsck</A>
</H2>

<P>When booting up the kernel, fsck failed, and dropped me into a shell to fix
things up.  I ran fsck -y, which hung:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
Setting hostname uml                    [ OK ]
Checking root filesystem
/dev/fhd0 was not cleanly unmounted, check forced.
Error reading block 86894 (Attempt to read block from filesystem resulted in short read) while reading indirect blocks of inode 19780.

/dev/fhd0: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
        (i.e., without -a or -p options)
[ FAILED ]

*** An error occurred during the file system check.
*** Dropping you to a shell; the system will reboot
*** when you leave the shell.
Give root password for maintenance
(or type Control-D for normal startup): 

[root@uml /root]# fsck -y /dev/fhd0
fsck -y /dev/fhd0
Parallelizing fsck version 1.14 (9-Jan-1999)
e2fsck 1.14, 9-Jan-1999 for EXT2 FS 0.5b, 95/08/09
/dev/fhd0 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Error reading block 86894 (Attempt to read block from filesystem resulted in short read) while reading indirect blocks of inode 19780.  Ignore error? yes

Inode 19780, i_blocks is 1548, should be 540.  Fix? yes

Pass 2: Checking directory structure
Error reading block 49405 (Attempt to read block from filesystem resulted in short read).  Ignore error? yes

Directory inode 11858, block 0, offset 0: directory corrupted
Salvage? yes

Missing '.' in directory inode 11858.
Fix? yes

Missing '..' in directory inode 11858.
Fix? yes
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The standard drill in this sort of situation is to fire up gdb on the
signal thread, which, in this case, was pid 1935.  In another window, I
run gdb and attach pid 1935.</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>

~/linux/2.3.26/um 1016: gdb linux
GNU gdb 4.17.0.11 with Linux support
Copyright 1998 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux"...

(gdb) att 1935
Attaching to program `/home/dike/linux/2.3.26/um/linux', Pid 1935
0x100756d9 in __wait4 ()
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Let's see what's currently running:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p current_task.pid
$1 = 0
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>It's the idle thread, which means that fsck went to sleep for some
reason and never woke up.</P>

<P>Let's guess that the last process in the process list is fsck:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p current_task.prev_task.comm
$13 = "fsck.ext2\000\000\000\000\000\000"
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>It is, so let's see what it thinks it's up to:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p current_task.prev_task.thread
$14 = {extern_pid = 1980, tracing = 0, want_tracing = 0, forking = 0, 
  kernel_stack_page = 0, signal_stack = 1342627840, syscall = {id = 4, args = {
      3, 134973440, 1024, 0, 1024}, have_result = 0, result = 50590720}, 
  request = {op = 2, u = {exec = {ip = 1350467584, sp = 2952789424}, fork = {
        regs = {1350467584, 2952789424, 0 &lt;repeats 15 times>}, sigstack = 0, 
        pid = 0}, switch_to = 0x507e8000, thread = {proc = 0x507e8000, 
        arg = 0xaffffdb0, flags = 0, new_pid = 0}, input_request = {
        op = 1350467584, fd = -1342177872, proc = 0, pid = 0}}}}
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The interesting things here are the fact that its .thread.syscall.id
is __NR_write (see the big switch in arch/um/kernel/syscall_kern.c or the
defines in include/asm-um/arch/unistd.h), and that it never returned.
Also, its .request.op is OP_SWITCH (see arch/um/include/user_util.h).
These mean that it went into a write, and, for some reason, called
schedule().</P>

<P>The fact that it never returned from write means that its stack
should be fairly interesting.  Its pid is 1980 (.thread.extern_pid).
That process is being ptraced by the signal thread, so it must be
detached before gdb can attach it:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) call detach(1980)

Program received signal SIGSEGV, Segmentation fault.
&lt;function called from gdb>
The program being debugged stopped while in a function called from GDB.
When the function (detach) is done executing, GDB will silently
stop (instead of continuing to evaluate the expression containing
the function call).
(gdb) call detach(1980)
$15 = 0
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The first detach segfaults for some reason, and the second one
succeeds.</P>

<P>Now I detach from the signal thread, attach to the fsck thread, and
look at its stack:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) det
Detaching from program: /home/dike/linux/2.3.26/um/linux Pid 1935
(gdb) att 1980
Attaching to program `/home/dike/linux/2.3.26/um/linux', Pid 1980
0x10070451 in __kill ()
(gdb) bt
#0  0x10070451 in __kill ()
#1  0x10068ccd in usr1_pid (pid=1980) at process.c:30
#2  0x1006a03f in _switch_to (prev=0x50072000, next=0x507e8000)
    at process_kern.c:156
#3  0x1006a052 in switch_to (prev=0x50072000, next=0x507e8000, last=0x50072000)
    at process_kern.c:161
#4  0x10001d12 in schedule () at sched.c:777
#5  0x1006a744 in __down (sem=0x507d241c) at semaphore.c:71
#6  0x1006aa10 in __down_failed () at semaphore.c:157
#7  0x1006c5d8 in segv_handler (sc=0x5006e940) at trap_user.c:174
#8  0x1006c5ec in kern_segv_handler (sig=11) at trap_user.c:182
#9  &lt;signal handler called>
#10 0x10155404 in errno ()
#11 0x1006c0aa in segv (address=1342179328, is_write=2) at trap_kern.c:50
#12 0x1006c5d8 in segv_handler (sc=0x5006eaf8) at trap_user.c:174
#13 0x1006c5ec in kern_segv_handler (sig=11) at trap_user.c:182
#14 &lt;signal handler called>
#15 0xc0fd in ?? ()
#16 0x10016647 in sys_write (fd=3, 
    buf=0x80b8800 &lt;Address 0x80b8800 out of bounds>, count=1024)
    at read_write.c:159
#17 0x1006d5b3 in execute_syscall (syscall=4, args=0x5006ef08)
    at syscall_kern.c:254
#18 0x1006af87 in really_do_syscall (sig=12) at syscall_user.c:35
#19 &lt;signal handler called>
#20 0x400dc8b0 in ?? ()
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The interesting things here are :
<UL>
<LI>There are two segfaults on this stack (frames 9 and 14)</LI>
<LI>The first faulting address (frame 11) is 0x50000800
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p (void *)1342179328
$16 = (void *) 0x50000800
</PRE>
</CODE></BLOCKQUOTE>
</LI>
</UL>
</P>

<P>The initial faulting address is interesting because it is on the idle
thread's stack.  I had been seeing the idle thread segfault for no
apparent reason, and the cause looked like stack corruption.  In hopes
of catching the culprit in the act, I had turned off all protections
to that stack while the idle thread wasn't running.  This apparently
tripped that trap.</P>

<P>However, the more immediate problem is that second segfault and I'm
going to concentrate on that.  First, I want to see where the fault
happened, so I have to go look at the sigcontent struct in frame 8: </P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) up
#1  0x10068ccd in usr1_pid (pid=1980) at process.c:30
30        kill(pid, SIGUSR1);
(gdb) 
#2  0x1006a03f in _switch_to (prev=0x50072000, next=0x507e8000)
    at process_kern.c:156
156       usr1_pid(getpid());
(gdb) 
#3  0x1006a052 in switch_to (prev=0x50072000, next=0x507e8000, last=0x50072000)
    at process_kern.c:161
161       _switch_to(prev, next);
(gdb) 
#4  0x10001d12 in schedule () at sched.c:777
777             switch_to(prev, next, prev);
(gdb) 
#5  0x1006a744 in __down (sem=0x507d241c) at semaphore.c:71
71                      schedule();
(gdb) 
#6  0x1006aa10 in __down_failed () at semaphore.c:157
157     }
(gdb) 
#7  0x1006c5d8 in segv_handler (sc=0x5006e940) at trap_user.c:174
174       segv(sc->cr2, sc->err &amp; 2);
(gdb) 
#8  0x1006c5ec in kern_segv_handler (sig=11) at trap_user.c:182
182       segv_handler(sc);
(gdb) p *sc
Cannot access memory at address 0x0.
</PRE>
</CODE></BLOCKQUOTE>
</P>
<P>That's not very useful, so I'll try a more manual method:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p *((struct sigcontext *) (&amp;sig + 1))
$19 = {gs = 0, __gsh = 0, fs = 0, __fsh = 0, es = 43, __esh = 0, ds = 43, 
  __dsh = 0, edi = 1342179328, esi = 1350378548, ebp = 1342630440, 
  esp = 1342630420, ebx = 1348150624, edx = 1280, ecx = 0, eax = 0, 
  trapno = 14, err = 4, eip = 268480945, cs = 35, __csh = 0, eflags = 66118, 
  esp_at_signal = 1342630420, ss = 43, __ssh = 0, fpstate = 0x0, oldmask = 0, 
  cr2 = 1280}
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The ip is in handle_mm_fault:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p (void *)268480945
$20 = (void *) 0x1000b1b1
(gdb) i sym $20
handle_mm_fault + 57 in section .text
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Specifically, it's in pte_alloc:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) i line *$20
Line 124 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b1b1 &lt;handle_mm_fault+57>
   and ends at 0x1000b1b7 &lt;handle_mm_fault+63>.
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>To find where in handle_mm_fault this is, I'll jump forward in the
code until I see an address in that procedure:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) i line *0x1000b1c0
Line 126 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b1b7 &lt;handle_mm_fault+63>
   and ends at 0x1000b1c3 &lt;handle_mm_fault+75>.
(gdb) i line *0x1000b1d0
Line 131 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b1d0 &lt;handle_mm_fault+88>
   and ends at 0x1000b1da &lt;handle_mm_fault+98>.
(gdb) i line *0x1000b1e0
Line 61 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b1da &lt;handle_mm_fault+98>
   and ends at 0x1000b1e1 &lt;handle_mm_fault+105>.
(gdb) i line *0x1000b1f0
Line 134 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b1f0 &lt;handle_mm_fault+120>
   and ends at 0x1000b200 &lt;handle_mm_fault+136>.
(gdb) i line *0x1000b200
Line 135 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b200 &lt;handle_mm_fault+136>
   and ends at 0x1000b208 &lt;handle_mm_fault+144>.
(gdb) i line *0x1000b210
Line 139 of "/home/dike/linux/2.3.26/um/include/asm/pgalloc.h"
   starts at address 0x1000b210 &lt;handle_mm_fault+152>
   and ends at 0x1000b219 &lt;handle_mm_fault+161>.
(gdb) i line *0x1000b220
Line 1168 of "memory.c" starts at address 0x1000b21e &lt;handle_mm_fault+166>
   and ends at 0x1000b222 &lt;handle_mm_fault+170>.
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Something is apparently wrong with the page tables or vma_structs,
so lets go back to frame 11 and have a look at them:
<BLOCKQUOTE><CODE>
<PRE>
#11 0x1006c0aa in segv (address=1342179328, is_write=2) at trap_kern.c:50
50        handle_mm_fault(current, vma, address, is_write);
(gdb) call pgd_offset_proc(vma->vm_mm, address)
$22 = (pgd_t *) 0x80a548c
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>That's pretty bogus.  Page tables aren't supposed to be in process
text or data areas.  Let's see what's in the vma:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p *vma
$23 = {vm_mm = 0x507d2434, vm_start = 0, vm_end = 134512640, 
  vm_next = 0x80a4f8c, vm_page_prot = {pgprot = 0}, vm_flags = 31200, 
  vm_avl_height = 2058, vm_avl_left = 0x80a8c94, vm_avl_right = 0x80d1000, 
  vm_next_share = 0xaffffdb0, vm_pprev_share = 0xaffffe63, 
  vm_ops = 0xaffffe7a, vm_pgoff = 2952789626, vm_file = 0xafffffec, 
  vm_private_data = 0x62}
(gdb) p *vma.vm_mm
$24 = {mmap = 0x507d2434, mmap_avl = 0x0, mmap_cache = 0x8048000, 
  pgd = 0x80a4f8c, mm_users = {counter = 0}, mm_count = {counter = 134904288},
  map_count = 134909076, mmap_sem = {count = {counter = 135073792}, 
    sleepers = -1342177872, wait = {lock = &lt;optimized out or zero length>, 
      task_list = {next = 0xaffffe63, prev = 0xaffffe7a}, 
      __magic = -1342177670, __creator = -1342177300}, __magic = 98}, 
  page_table_lock = {}, context = 138, start_code = 0, end_code = 0, 
  start_data = 0, end_data = 0, start_brk = 0, brk = 0, start_stack = 0, 
  arg_start = 0, arg_end = 0, env_start = 0, env_end = 0, rss = 1350381536, 
  total_vm = 0, locked_vm = 0, def_flags = 0, cpu_vm_mask = 0, swap_cnt = 0, 
  swap_address = 0, segments = 0x0}
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>This also pretty bogus.  With all of the 0x80xxxxx and 0xaffffxxx
addresses, this is looking like a stack was plonked down on top of
these structures.  Maybe it's a stack overflow from the next page:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p vma
$25 = (struct vm_area_struct *) 0x507d2434
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>That's towards the lower quarter of the page, so that would have to
have been pretty heavy stack overflow:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) x/100x $25
0x507d2434:     0x507d2434      0x00000000      0x08048000      0x080a4f8c
0x507d2444:     0x00000000      0x080a79e0      0x080a8c94      0x080d1000
0x507d2454:     0xaffffdb0      0xaffffe63      0xaffffe7a      0xaffffe7a
0x507d2464:     0xafffffec      0x00000062      0x0000008a      0x00000000
0x507d2474:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2484:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2494:     0x00000000      0x00000000      0x507d2fe0      0x00000000
0x507d24a4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d24b4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d24c4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d24d4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d24e4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d24f4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2504:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2514:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2524:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2534:     0x00000000      0x00000000      0x507d25dc      0x00000000
0x507d2544:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2554:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2564:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2574:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2584:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d2594:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d25a4:     0x00000000      0x00000000      0x00000000      0x00000000
0x507d25b4:     0x00000000      0x00000000      0x00000000      0x00000000
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>It's not stack overflow.  The only "stack-like" piece of this data
is the vma_struct itself.</P>

<P>At this point, I don't see any avenues to pursue, so I just have to
admit that I have no idea what's going on.  What I will do, though, is
stick a trap on the segfault handler which will stop if it sees any
writes to the idle thread's stack.  That was the thing that happened
first, and it may be that if I can catch it immediately, what's going
on will be somewhat clearer.</P>

<H2><A NAME="ss12.2">12.2</A> <A HREF="UserModeLinux-HOWTO.html#toc12.2">Episode 2: The case of the hung fsck</A>
</H2>

<P>After setting a trap in the SEGV handler for accesses to the signal
thread's stack, I reran the kernel.</P>

<P>fsck hung again, this time by hitting the trap:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
Setting hostname uml                            [ OK ]
Checking root filesystem
/dev/fhd0 contains a file system with errors, check forced.
Error reading block 86894 (Attempt to read block from filesystem resulted in short read) while reading indirect blocks of inode 19780.  

/dev/fhd0: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
        (i.e., without -a or -p options)
[ FAILED ]

*** An error occurred during the file system check.
*** Dropping you to a shell; the system will reboot
*** when you leave the shell.
Give root password for maintenance
(or type Control-D for normal startup): 

[root@uml /root]# fsck -y /dev/fhd0
fsck -y /dev/fhd0
Parallelizing fsck version 1.14 (9-Jan-1999)
e2fsck 1.14, 9-Jan-1999 for EXT2 FS 0.5b, 95/08/09
/dev/fhd0 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Error reading block 86894 (Attempt to read block from filesystem resulted in short read) while reading indirect blocks of inode 19780.  Ignore error? yes

Pass 2: Checking directory structure
Error reading block 49405 (Attempt to read block from filesystem resulted in short read).  Ignore error? yes

Directory inode 11858, block 0, offset 0: directory corrupted
Salvage? yes

Missing '.' in directory inode 11858.
Fix? yes

Missing '..' in directory inode 11858.
Fix? yes

Untested (4127) [100fe44c]: trap_kern.c line 31
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>I need to get the signal thread to detach from pid 4127 so that I can
attach to it with gdb.  This is done by sending it a SIGUSR1, which is
caught by the signal thread, which detaches the process:
<BLOCKQUOTE><CODE>
<PRE>
kill -USR1 4127
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Now I can run gdb on it:
<BLOCKQUOTE><CODE>
<PRE>
~/linux/2.3.26/um 1034: gdb linux
GNU gdb 4.17.0.11 with Linux support
Copyright 1998 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux"...
(gdb) att 4127
Attaching to program `/home/dike/linux/2.3.26/um/linux', Pid 4127
0x10075891 in __libc_nanosleep ()
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The backtrace shows that it was in a write and that the fault
address (address in frame 3) is 0x50000800, which is right in the
middle of the signal thread's stack page:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) bt
#0  0x10075891 in __libc_nanosleep ()
#1  0x1007584d in __sleep (seconds=1000000)
    at ../sysdeps/unix/sysv/linux/sleep.c:78
#2  0x1006ce9a in stop () at user_util.c:191
#3  0x1006bf88 in segv (address=1342179328, is_write=2) at trap_kern.c:31
#4  0x1006c628 in segv_handler (sc=0x5006eaf8) at trap_user.c:174
#5  0x1006c63c in kern_segv_handler (sig=11) at trap_user.c:182
#6  &lt;signal handler called>
#7  0xc0fd in ?? ()
#8  0x10016647 in sys_write (fd=3, buf=0x80b8800 "R.", count=1024)
    at read_write.c:159
#9  0x1006d603 in execute_syscall (syscall=4, args=0x5006ef08)
    at syscall_kern.c:254
#10 0x1006af87 in really_do_syscall (sig=12) at syscall_user.c:35
#11 &lt;signal handler called>
#12 0x400dc8b0 in ?? ()
#13 &lt;signal handler called>
#14 0x400dc8b0 in ?? ()
#15 0x80545fd in ?? ()
#16 0x804daae in ?? ()
#17 0x8054334 in ?? ()
#18 0x804d23e in ?? ()
#19 0x8049632 in ?? ()
#20 0x80491d2 in ?? ()
#21 0x80596b5 in ?? ()
(gdb) p (void *)1342179328
$3 = (void *) 0x50000800
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Going up the stack to the segv_handler frame and looking at where
in the code the access happened shows that it happened near line 110
of block_dev.c:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) up
#1  0x1007584d in __sleep (seconds=1000000)
    at ../sysdeps/unix/sysv/linux/sleep.c:78
../sysdeps/unix/sysv/linux/sleep.c:78: No such file or directory.
(gdb) 
#2  0x1006ce9a in stop () at user_util.c:191
191       while(1) sleep(1000000);
(gdb) 
#3  0x1006bf88 in segv (address=1342179328, is_write=2) at trap_kern.c:31
31          KERN_UNTESTED();
(gdb) 
#4  0x1006c628 in segv_handler (sc=0x5006eaf8) at trap_user.c:174
174       segv(sc->cr2, sc->err &amp; 2);
(gdb) p *sc
$1 = {gs = 0, __gsh = 0, fs = 0, __fsh = 0, es = 43, __esh = 0, ds = 43, 
  __dsh = 0, edi = 1342179328, esi = 134973440, ebp = 1342631484, 
  esp = 1342630864, ebx = 256, edx = 0, ecx = 256, eax = 1024, trapno = 14, 
  err = 6, eip = 268550834, cs = 35, __csh = 0, eflags = 66070, 
  esp_at_signal = 1342630864, ss = 43, __ssh = 0, fpstate = 0x0, oldmask = 0, 
  cr2 = 1342179328}
(gdb) p (void *)268550834
$2 = (void *) 0x1001c2b2
(gdb) i sym $2
block_write + 1090 in section .text
(gdb) i line *$2
Line 209 of "/home/dike/linux/2.3.26/um/include/asm/arch/string.h"
   starts at address 0x1001c2a1 &lt;block_write+1073>
   and ends at 0x1001c2bf &lt;block_write+1103>.
(gdb) i line *0x1001c2c0
Line 110 of "block_dev.c" starts at address 0x1001c2bf &lt;block_write+1103>
   and ends at 0x1001c2e3 &lt;block_write+1139>.
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Looking at the source shows that the fault happened during a
call to copy_to_user to copy the data into the kernel:
<BLOCKQUOTE><CODE>
<PRE>
107             count -= chars;
108             copy_from_user(p,buf,chars);
109             p += chars;
110             buf += chars;
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>p is the pointer which must contain 0x50000800, since buf contains
0x80b8800 (frame 8 above).  It is defined as:
<BLOCKQUOTE><CODE>
<PRE>
                p = offset + bh->b_data;
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>I need to figure out what bh is, and it just so happens that bh is
passed as an argument to mark_buffer_uptodate and mark_buffer_dirty a
few lines later, so I do a little disassembly:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) disas 0x1001c2bf 0x1001c2e0
Dump of assembler code from 0x1001c2bf to 0x1001c2d0:
0x1001c2bf &lt;block_write+1103>:  addl   %eax,0xc(%ebp)
0x1001c2c2 &lt;block_write+1106>:  movl   0xfffffdd4(%ebp),%edx
0x1001c2c8 &lt;block_write+1112>:  btsl   $0x0,0x18(%edx)
0x1001c2cd &lt;block_write+1117>:  btsl   $0x1,0x18(%edx)
0x1001c2d2 &lt;block_write+1122>:  sbbl   %ecx,%ecx
0x1001c2d4 &lt;block_write+1124>:  testl  %ecx,%ecx
0x1001c2d6 &lt;block_write+1126>:  jne    0x1001c2e3 &lt;block_write+1139>
0x1001c2d8 &lt;block_write+1128>:  pushl  $0x0
0x1001c2da &lt;block_write+1130>:  pushl  %edx
0x1001c2db &lt;block_write+1131>:  call   0x1001819c &lt;__mark_buffer_dirty>
End of assembler dump.
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>At that point, bh is in %edx (address 0x1001c2da), which is
calculated at 0x1001c2c2 as %ebp + 0xfffffdd4, so I figure exactly
what that is, taking %ebp from the sigcontext_struct above:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p (void *)1342631484
$5 = (void *) 0x5006ee3c
(gdb) p 0x5006ee3c+0xfffffdd4
$6 = 1342630928
(gdb) p (void *)$6
$7 = (void *) 0x5006ec10
(gdb) p *((void **)$7)
$8 = (void *) 0x50100200
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Now, I look at the structure to see what's in it, and particularly,
what its b_data field contains:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p *((struct buffer_head *)0x50100200)
$13 = {b_next = 0x50289380, b_blocknr = 49405, b_size = 1024, b_list = 0, 
  b_dev = 15872, b_count = {counter = 1}, b_rdev = 15872, b_state = 24, 
  b_flushtime = 0, b_next_free = 0x501001a0, b_prev_free = 0x50100260, 
  b_this_page = 0x501001a0, b_reqnext = 0x0, b_pprev = 0x507fcf58, 
  b_data = 0x50000800 "", b_page = 0x50004000, 
  b_end_io = 0x10017f60 &lt;end_buffer_io_sync>, b_dev_id = 0x0, 
  b_rsector = 98810, b_wait = {lock = &lt;optimized out or zero length>, 
    task_list = {next = 0x50100248, prev = 0x50100248}, __magic = 1343226448, 
    __creator = 0}, b_kiobuf = 0x0}
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The b_data field is indeed 0x50000800, so the question becomes how
that happened.  The rest of the structure looks fine, so this probably is
not a case of data corruption.  It happened on purpose somehow.</P>

<P>The b_page field is a pointer to the page_struct representing the
0x50000000 page.  Looking at it shows the kernel's idea of the state
of that page:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p *$13.b_page
$17 = {list = {next = 0x50004a5c, prev = 0x100c5174}, mapping = 0x0, 
  index = 0, next_hash = 0x0, count = {counter = 1}, flags = 132, lru = {
    next = 0x50008460, prev = 0x50019350}, wait = {
    lock = &lt;optimized out or zero length>, task_list = {next = 0x50004024, 
      prev = 0x50004024}, __magic = 1342193708, __creator = 0}, 
  pprev_hash = 0x0, buffers = 0x501002c0, virtual = 1342177280, 
  zone = 0x100c5160}
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Some sanity-checking: the virtual field shows the "virtual" address
of this page, which in this kernel is the same as its "physical"
address, and the page_struct itself should be mem_map[0], since it
represents the first page of memory:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p (void *)1342177280
$18 = (void *) 0x50000000
(gdb) p mem_map
$19 = (mem_map_t *) 0x50004000
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>These check out fine.</P>

<P>Now to check out the page_struct itself.  In particular, the flags
field shows whether the page is considered free or not:
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p (void *)132
$21 = (void *) 0x84
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>The "reserved" bit is the high bit, which is definitely not set, so
the kernel considers the signal stack page to be free and available to
be used.</P>

<P>At this point, I jump to conclusions and start looking at my early
boot code, because that's where that page is supposed to be reserved.</P>

<P>In my setup_arch procedure, I have the following code which looks
just fine:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
bootmap_size = init_bootmem(start_pfn, end_pfn - start_pfn);
free_bootmem(__pa(low_physmem) + bootmap_size, high_physmem - low_physmem);
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Two stack pages have already been allocated, and low_physmem points
to the third page, which is the beginning of free memory.</P>

<P>The init_bootmem call declares the entire memory to the boot memory
manager, which marks it all reserved.  The free_bootmem call frees up
all of it, except for the first two pages.  This looks correct to me.</P>

<P>So, I decide to see init_bootmem run and make sure that it is
marking those first two pages as reserved.  I never get that far.</P>

<P>Stepping into init_bootmem, and looking at bootmem_map before
looking at what it contains shows the following:</P>
<P>
<BLOCKQUOTE><CODE>
<PRE>
(gdb) p bootmem_map
$3 = (void *) 0x50000000
</PRE>
</CODE></BLOCKQUOTE>
</P>

<P>Aha!  The light dawns.  That first page is doing double duty as a
stack and as the boot memory map.  The last thing that the boot memory
manager does is to free the pages used by its memory map, so this page is
getting freed even its marked as reserved.</P>

<P>The fix was to initialize the boot memory manager before allocating
those two stack pages, and then allocate them through the boot memory
manager.  After doing this, and fixing a couple of subsequent buglets,
the stack corruption problem disappeared.</P>




<HR>
<A HREF="UserModeLinux-HOWTO-13.html">Next</A>
<A HREF="UserModeLinux-HOWTO-11.html">Previous</A>
<A HREF="UserModeLinux-HOWTO.html#toc12">Contents</A>
</BODY>
</HTML>