fuzz tested 32 bit user mode linux image hangs at in histfs

When I fuzz testing a 32 bit UML at a 32 bit host (guest 3.12.-rc6-x, host 3.11.6) with trinity and use hostfs for the victom files for trinity. then trintiy often hangs while trying to finish.

At the host I do have 1 process eating 100% CPU power of 1 core. A back trace of thet linux process at the hosts gives :

tfoerste@n22 ~ $ sudo gdb /usr/local/bin/linux-v3.12-rc6-57-g69c88dc 16749 -n -batch -ex bt radix_tree_next_chunk (root=0x21, iter=0x47647c60, flags=12) at lib/radix-tree.c:769
769 while (++offset < RADIX_TREE_MAP_SIZE) {

#0  radix_tree_next_chunk (root=0x21, iter=0x47647c60, flags=12) at lib/radix-tree.c:769
#1  0x080cc13e in find_get_pages (mapping=0x483ed240, start=0, nr_pages=14, pages=0xc) at mm/filemap.c:844
#2  0x080d5caa in pagevec_lookup (pvec=0x47647cc4, mapping=0x21, start=33, nr_pages=33) at mm/swap.c:914
#3  0x080d609a in truncate_inode_pages_range (mapping=0x483ed240, lstart=0, lend=-1) at mm/truncate.c:241
#4  0x080d643f in truncate_inode_pages (mapping=0x21, lstart=51539607585) at mm/truncate.c:358
#5  0x08260838 in hostfs_evict_inode (inode=0x483ed188) at fs/hostfs/hostfs_kern.c:242
#6  0x0811a8cf in evict (inode=0x483ed188) at fs/inode.c:549
#7  0x0811b2ad in iput_final (inode=<optimized out>) at fs/inode.c:1391
#8  iput (inode=0x483ed188) at fs/inode.c:1409
#9  0x08117648 in dentry_iput (dentry=<optimized out>) at fs/dcache.c:331

#10 d_kill (dentry=0x47d6d580, parent=0x47d95d10) at fs/dcache.c:477
#11 0x08118068 in dentry_kill (dentry=<optimized out>, unlock_on_failure=<optimized out>) at fs/dcache.c:586
#12 dput (dentry=0x47d6d580) at fs/dcache.c:641
#13 0x08104903 in __fput (file=0x47471840) at fs/file_table.c:264
#14 0x0810496b in ____fput (work=0x47471840) at fs/file_table.c:282
#15 0x08094496 in task_work_run () at kernel/task_work.c:123
#16 0x0807efd2 in exit_task_work (task=<optimized out>) at include/linux/task_work.h:21
#17 do_exit (code=1196535808) at kernel/exit.c:787
#18 0x0807f5dd in do_group_exit (exit_code=0) at kernel/exit.c:920
#19 0x0807f649 in SYSC_exit_group (error_code=<optimized out>) at kernel/exit.c:931
#20 SyS_exit_group (error_code=0) at kernel/exit.c:929
#21 0x08062984 in handle_syscall (r=0x4763b1d4) at arch/um/kernel/skas/syscall.c:35
#22 0x08074fb5 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #23 userspace (regs=0x4763b1d4) at arch/um/os-Linux/skas/process.c:431
#24 0x0805f750 in fork_handler () at arch/um/kernel/process.c:160
#25 0x00000000 in ?? ()

Last message of trinity's watchdog are :

...
[watchdog] exit_reason=2, but 2 children still running. Bailing main loop. Exit reason: Reached maximum syscall count. [watchdog] Reached limit 10001. Telling children to exit. [watchdog] [1516] Watchdog exiting

I'm unsure if this is only UML specific, interesting for the fs people or mm or ... ?

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

That trace is identical to the one you reported yesterday. But this time no nfs is in the game, right?

Thanks,
//richard

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Right - I could narrow down it in the meanwhile to hostfs only. First I argued if NFS sometimes might force the issue to happen later but in the mean while I don't think so.

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Am 22.10.2013 18:23, schrieb Toralf Förster:

It looks like we never find a way out of the while(1) in radix_tree_next_chunk().

Thanks,
//richard

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

But today I found a proof that it is not only fs/hostfs specific :

tfoerste@n22 ~ $ sudo gdb /home/tfoerste/devel/linux/linux 22692 -n -batch -ex bt 0x08298fcc in radix_tree_next_chunk (root=0x25, iter=0x3ba6fc4c, flags=6) at lib/radix-tree.c:770
770 if (node->slots[offset])

#0  0x08298fcc in radix_tree_next_chunk (root=0x25, iter=0x3ba6fc4c, flags=6) at lib/radix-tree.c:770
#1  0x080cc20e in find_get_pages (mapping=0x3b0d61dc, start=0, nr_pages=14, pages=0x6) at mm/filemap.c:844
#2  0x080d5d7a in pagevec_lookup (pvec=0x3ba6fcb0, mapping=0x25, start=37, nr_pages=37) at mm/swap.c:914
#3  0x080d616a in truncate_inode_pages_range (mapping=0x3b0d61dc, lstart=0, lend=-1) at mm/truncate.c:241
#4  0x080d650f in truncate_inode_pages (mapping=0x25, lstart=25769803813) at mm/truncate.c:358
#5  0x08205b08 in nfs4_evict_inode (inode=0x3b0d6124) at fs/nfs/nfs4super.c:101
#6  0x0811a99f in evict (inode=0x3b0d6124) at fs/inode.c:549
#7  0x0811b37d in iput_final (inode=<optimized out>) at fs/inode.c:1391
#8  iput (inode=0x3b0d6124) at fs/inode.c:1409
#9  0x081d6014 in nfs_dentry_iput (dentry=0x6, inode=0x3b0d6124) at fs/nfs/dir.c:1255

#10 0x08117705 in dentry_iput (dentry=<optimized out>) at fs/dcache.c:329
#11 d_kill (dentry=0x4508a000, parent=0x47adf790) at fs/dcache.c:477
#12 0x08118138 in dentry_kill (dentry=<optimized out>, unlock_on_failure=<optimized out>) at fs/dcache.c:586
#13 dput (dentry=0x4508a000) at fs/dcache.c:641
#14 0x081049d3 in __fput (file=0x3baf3000) at fs/file_table.c:264
#15 0x08104a3b in ____fput (work=0x3baf3000) at fs/file_table.c:282
#16 0x08094496 in task_work_run () at kernel/task_work.c:123
#17 0x0807efd2 in exit_task_work (task=<optimized out>) at include/linux/task_work.h:21
#18 do_exit (code=1167823872) at kernel/exit.c:787
#19 0x0807f5dd in do_group_exit (exit_code=0) at kernel/exit.c:920
#20 0x0807f649 in SYSC_exit_group (error_code=<optimized out>) at kernel/exit.c:931
#21 SyS_exit_group (error_code=0) at kernel/exit.c:929
#22 0x08062984 in handle_syscall (r=0x459741d4) at arch/um/kernel/skas/syscall.c:35
#23 0x08074fb5 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #24 userspace (regs=0x459741d4) at arch/um/os-Linux/skas/process.c:431
#25 0x0805f750 in fork_handler () at arch/um/kernel/process.c:160
#26 0x00000000 in ?? ()

But it happened rarely and I did not found a scenario to easily reproduce it till now.

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

FWIW here's a slightly different and much shorter gdb back trace

tfoerste@n22 ~/devel/linux $ sudo gdb /usr/local/bin/linux-v3.12-rc7 3105 -n -batch -ex bt 0x08298f16 in radix_tree_next_chunk (root=0x0, iter=0x46c2fcec, flags=18) at lib/radix-tree.c:756
756 if ((flags & RADIX_TREE_ITER_TAGGED) ?

#0  0x08298f16 in radix_tree_next_chunk (root=0x0, iter=0x46c2fcec, flags=18) at lib/radix-tree.c:756
#1  0x080cc20e in find_get_pages (mapping=0x26c35130, start=0, nr_pages=14, pages=0x12) at mm/filemap.c:844
#2  0x080d5d7a in pagevec_lookup (pvec=0x46c2fd50, mapping=0x0, start=0, nr_pages=0) at mm/swap.c:914
#3  0x080d616a in truncate_inode_pages_range (mapping=0x26c35130, lstart=0, lend=-1) at mm/truncate.c:241
#4  0x080d650f in truncate_inode_pages (mapping=0x0, lstart=77309411328) at mm/truncate.c:358
#5  0x0818d7e2 in ext4_evict_inode (inode=0x26c35078) at fs/ext4/inode.c:228
#6  0x0811a99f in evict (inode=0x26c35078) at fs/inode.c:549
#7  0x0811b37d in iput_final (inode=<optimized out>) at fs/inode.c:1391
#8  iput (inode=0x26c35078) at fs/inode.c:1409
#9  0x08111717 in do_unlinkat (dfd=5, pathname=0x80686c4 <create_proc_mconsole+4> "_\b\205\322tJU\211\345\203\354\024\307D$\020") at fs/namei.c:3730

#10 0x08111835 in SYSC_unlinkat (flag=<optimized out>, pathname=<optimized out>, dfd=<optimized out>) at fs/namei.c:3756
#11 SyS_unlinkat (dfd=5, pathname=134645444, flag=0) at fs/namei.c:3748
#12 0x08062984 in handle_syscall (r=0x48408dd4) at arch/um/kernel/skas/syscall.c:35
#13 0x08074fb5 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #14 userspace (regs=0x48408dd4) at arch/um/os-Linux/skas/process.c:431
#15 0x0805f750 in fork_handler () at arch/um/kernel/process.c:160
#16 0x5a5a5a5a in ?? ()

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

In this case it must stop after scanning whole tree in line:
/* Overflow after ~0UL */
if (!index)
return NULL;

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

A fresh current example with latest git tree shows that lines 769 and 770 do alternate :

tfoerste@n22 ~/devel/linux $ sudo gdb /usr/local/bin/linux-v3.12-48-gbe408cd 16619 -n -batch -ex bt 0x08296a8c in radix_tree_next_chunk (root=0x25, iter=0x462e7c64, flags=12) at lib/radix-tree.c:770
770 if (node->slots[offset])

#0  0x08296a8c in radix_tree_next_chunk (root=0x25, iter=0x462e7c64, flags=12) at lib/radix-tree.c:770
#1  0x080cc1fe in find_get_pages (mapping=0x462ad470, start=0, nr_pages=14, pages=0xc) at mm/filemap.c:844
#2  0x080d5d6a in pagevec_lookup (pvec=0x462e7cc8, mapping=0x25, start=37, nr_pages=37) at mm/swap.c:914
#3  0x080d615a in truncate_inode_pages_range (mapping=0x462ad470, lstart=0, lend=-1) at mm/truncate.c:241
#4  0x080d64ff in truncate_inode_pages (mapping=0x25, lstart=51539607589) at mm/truncate.c:358

tfoerste@n22 ~/devel/linux $ sudo gdb /usr/local/bin/linux-v3.12-48-gbe408cd 16619 -n -batch -ex bt radix_tree_next_chunk (root=0x28, iter=0x462e7c64, flags=18) at lib/radix-tree.c:769
769 while (++offset < RADIX_TREE_MAP_SIZE) {

#0  radix_tree_next_chunk (root=0x28, iter=0x462e7c64, flags=18) at lib/radix-tree.c:769
#1  0x080cc1fe in find_get_pages (mapping=0x462ad470, start=0, nr_pages=14, pages=0x12) at mm/filemap.c:844
#2  0x080d5d6a in pagevec_lookup (pvec=0x462e7cc8, mapping=0x28, start=40, nr_pages=40) at mm/swap.c:914
#3  0x080d615a in truncate_inode_pages_range (mapping=0x462ad470, lstart=0, lend=-1) at mm/truncate.c:241
#4  0x080d64ff in truncate_inode_pages (mapping=0x28, lstart=77309411368) at mm/truncate.c:358
#5  0x0825e388 in hostfs_evict_inode (inode=0x462ad3b8) at fs/hostfs/hostfs_kern.c:242
#6  0x0811a8df in evict (inode=0x462ad3b8) at fs/inode.c:549

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Am 06.11.2013 22:18, schrieb Toralf Förster:

Can you please ask gdb for the value of offset?

Thanks,
//richard

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Still trying to get those values. One attempt to do that was to replace -O2 with -O0 in the Makefile, but that resulted into this error :

LD kernel/built-in.o
CC mm/memory.o
In function ‘zap_pmd_range’,
inlined from ‘zap_pud_range’ at mm/memory.c:1265:8,
inlined from ‘unmap_page_range’ at mm/memory.c:1290:8:
mm/memory.c:1220:23: error: call to ‘__compiletime_assert_1220’ declared with attribute error: BUILD_BUG failed mm/memory.c: In function ‘follow_page_mask’:
mm/memory.c:1530:18: error: call to ‘__compiletime_assert_1530’ declared with attribute error: BUILD_BUG failed make[1]: *** [mm/memory.o] Error 1
make: *** [mm] Error 2

With -O1 it compiled at least.

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Am 09.11.2013 20:07, schrieb Toralf Förster:

You cannot build Linux with -O1/O0.
Try printing the value using printk...

Thanks,
//richard

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Or even printf(), since this an UML kernel.

Stian

------------------------------------------------------------------------------
November Webinars for C, C++, Fortran Developers
Accelerate application performance with scalable programming models. Explore techniques for threading, error checking, porting, and tuning. Get the most from the latest Intel processors and coprocessors. See abstracts and register
http://pubads.g.doubleclick.net/gampad/clk?id=60136231&iu=/4140/ostg.clktrk
_______________________________________________
User-mode-linux-devel mailing list [email protected]
https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel

With this change

index 7811ed3..b2e9db5 100644
@@ -767,6 +767,7 @@ restart:
                                                offset + 1);
                        else
                                while (++offset < RADIX_TREE_MAP_SIZE) {
+                                       printk ("node->slots[offset] %p offeset %lu\n", node->slots[offset], offset);
                                        if (node->slots[offset])
                                                break;
                                }

against v3.12-48-gbe408cd these are the last lines in the syslog of the UML (command: ssh root@trinity "tail -f /var/log/messages")

...

Nov 10 13:26:32 trinity kernel: node->slots[offset]   (null) offeset 23
Nov 10 13:26:32 trinity kernel: node->slots[offset]   (null) offeset 24
Nov 10 13:26:32 trinity kernel: node->slots[offset]   (null) offeset 25
Nov 10 13:26:32 trinity kernel: node->slots[offset]   (null) offeset 26
Nov 10 13:26:32 trinity kernel: node->slots[offset]   (null) offeset 27
...
Nov 10 13:49:11 trinity sshd[3628]: pam_unix(sshd:session): session closed for user tfoerste
Nov 10 13:49:15 trinity sshd[3858]: pam_unix(sshd:session): session opened for user tfoerste by (uid=0)
Nov 10 13:49:15 trinity su[3862]: Successful su for root by root
Nov 10 13:49:15 trinity su[3862]: + ??? root:root
Nov 10 13:49:15 trinity su[3862]: pam_unix(su:session): session opened for user root by (uid=0)
Nov 10 13:49:15 trinity su[3862]: pam_unix(su:session): session closed for user root
Nov 10 13:49:15 trinity tfoerste: M=/mnt/hostfs

It is now at (I left the computer for a while) and I gdo et this output of 3 subsequent calls of the gdb back trace at the host system :

tfoerste@n22 ~/devel/linux $ sudo gdb /home/tfoerste/devel/linux/linux 8946 -n -batch -ex bt
string (buf=0x8609ef9 <textbuf.25662+25> "ll) offeset 4\n", end=0x860a2c0 <cont> "4721fffc: [<00000000>] 0x0k_handler+0x60/0x700360d/0x4e00ffff 00000000 4721fc0c: [<0805f8cc>] __switch_to+0x5c/0xf0", s=0x84c0980 <null+3> "ll)", spec=...) at lib/vsprintf.c:524
524 *buf = *s;

#0  string (buf=0x8609ef9 <textbuf.25662+25> "ll) offeset 4\n", end=0x860a2c0 <cont> "4721fffc:  [<00000000>] 0x0k_handler+0x60/0x700360d/0x4e00ffff 00000000 4721fc0c:  [<0805f8cc>] __switch_to+0x5c/0xf0", s=0x84c0980 <null+3> "ll)", spec=...) at lib/vsprintf.c:524
#1  0x0829ac42 in pointer (fmt=0x75 <Address 0x75 out of bounds>, buf=0x8609ef4 <textbuf.25662+20> "  (null) offeset 4\n", end=0x5 <Address 0x5 out of bounds>, ptr=0x0, spec=...) at lib/vsprintf.c:1239
#2  0x0829a9dd in vsnprintf (buf=0x8609ee0 <textbuf.25662> "node->slots[offset]   (null) offeset 4\n", size=992, fmt=0x8609efc <textbuf.25662+28> " offeset 4\n", args=0x4370fc10 "") at lib/vsprintf.c:1667
#3  0x0829b0f7 in vscnprintf (buf=0x75 <Address 0x75 out of bounds>, size=992, fmt=0x75 <Address 0x75 out of bounds>, args=0x75 <Address 0x75 out of bounds>) at lib/vsprintf.c:1776
#4  0x080a6968 in vprintk_emit (facility=0, level=-1, dict=0x0, dictlen=0, fmt=0x75 <Address 0x75 out of bounds>, args=0x75 <Address 0x75 out of bounds>) at kernel/printk/printk.c:1548
#5  0x08419b05 in printk (fmt=0x75 <Address 0x75 out of bounds>) at kernel/printk/printk.c:1690
#6  0x08296a8d in radix_tree_next_chunk (root=0x75, iter=0x4370fc54, flags=0) at lib/radix-tree.c:770
#7  0x080cc1fe in find_get_pages (mapping=0x44bb707c, start=0, nr_pages=14, pages=0x5) at mm/filemap.c:844
#8  0x080d5d6a in pagevec_lookup (pvec=0x4370fcb8, mapping=0x75, start=117, nr_pages=117) at mm/swap.c:914
#9  0x080d615a in truncate_inode_pages_range (mapping=0x44bb707c, lstart=32809, lend=-1) at mm/truncate.c:241

#10 0x080d64ff in truncate_inode_pages (mapping=0x75, lstart=21474836597) at mm/truncate.c:358
#11 0x080d6a0d in truncate_pagecache (inode=0x75, newsize=32809) at mm/truncate.c:597
#12 0x081d9118 in nfs_vmtruncate (offset=<optimized out>, inode=<optimized out>) at fs/nfs/inode.c:554
#13 nfs_setattr_update_inode (inode=0x44bb6fc4, attr=0x8029) at fs/nfs/inode.c:585
#14 0x081e73ba in nfs_proc_setattr (dentry=0x75, fattr=0x0, sattr=0x4370fe1c) at fs/nfs/proc.c:142
#15 0x081da99c in nfs_setattr (dentry=0x47fb5b00, attr=0x4370fe1c) at fs/nfs/inode.c:523
#16 0x0811c256 in notify_change (dentry=0x47fb5b00, attr=0x4370fe1c) at fs/attr.c:248
#17 0x081011bb in do_truncate (dentry=0x47fb5b00, length=502511206441, time_attrs=5, filp=0x8609efc <textbuf.25662+28>) at fs/open.c:60 #18 0x081013f2 in do_sys_ftruncate (fd=117, length=32809, small=1) at fs/open.c:190
#19 0x081016da in SYSC_ftruncate (length=<optimized out>, fd=<optimized out>) at fs/open.c:200
#20 SyS_ftruncate (fd=129, length=32809) at fs/open.c:198
#21 0x08062974 in handle_syscall (r=0x473c9fd4) at arch/um/kernel/skas/syscall.c:35
#22 0x08074fa5 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #23 userspace (regs=0x473c9fd4) at arch/um/os-Linux/skas/process.c:431
#24 0x0805f740 in fork_handler () at arch/um/kernel/process.c:160
#25 0x00000000 in ?? ()

tfoerste@n22 ~/devel/linux $ sudo gdb /home/tfoerste/devel/linux/linux 8946 -n -batch -ex bt
0x082995e7 in string (buf=0x8609ef8 <textbuf.25662+24> "ull) offeset 57\n", end=0x860a2c0 <cont> "4721fffc: [<00000000>] 0x0k_handler+0x60/0x700360d/0x4e00ffff 00000000 4721fc0c: [<0805f8cc>] __switch_to+0x5c/0xf0", s=0x84c097f <null+2> "ull)", spec=...) at lib/vsprintf.c:524
524 *buf = *s;

#0  0x082995e7 in string (buf=0x8609ef8 <textbuf.25662+24> "ull) offeset 57\n", end=0x860a2c0 <cont> "4721fffc:  [<00000000>] 0x0k_handler+0x60/0x700360d/0x4e00ffff 00000000 4721fc0c:  [<0805f8cc>] __switch_to+0x5c/0xf0", s=0x84c097f <null+2> "ull)", spec=...) at lib/vsprintf.c:524
#1  0x0829ac42 in pointer (fmt=0x75 <Address 0x75 out of bounds>, buf=0x8609ef4 <textbuf.25662+20> "  (null) offeset 57\n", end=0x5 <Address 0x5 out of bounds>, ptr=0x0, spec=...) at lib/vsprintf.c:1239
#2  0x0829a9dd in vsnprintf (buf=0x8609ee0 <textbuf.25662> "node->slots[offset]   (null) offeset 57\n", size=992, fmt=0x8609efc <textbuf.25662+28> " offeset 57\n", args=0x4370fc10 "") at lib/vsprintf.c:1667
#3  0x0829b0f7 in vscnprintf (buf=0x75 <Address 0x75 out of bounds>, size=992, fmt=0x75 <Address 0x75 out of bounds>, args=0x75 <Address 0x75 out of bounds>) at lib/vsprintf.c:1776
#4  0x080a6968 in vprintk_emit (facility=0, level=-1, dict=0x0, dictlen=0, fmt=0x75 <Address 0x75 out of bounds>, args=0x75 <Address 0x75 out of bounds>) at kernel/printk/printk.c:1548
#5  0x08419b05 in printk (fmt=0x75 <Address 0x75 out of bounds>) at kernel/printk/printk.c:1690
#6  0x08296a8d in radix_tree_next_chunk (root=0x75, iter=0x4370fc54, flags=0) at lib/radix-tree.c:770
#7  0x080cc1fe in find_get_pages (mapping=0x44bb707c, start=0, nr_pages=14, pages=0x5) at mm/filemap.c:844
#8  0x080d5d6a in pagevec_lookup (pvec=0x4370fcb8, mapping=0x75, start=117, nr_pages=117) at mm/swap.c:914
#9  0x080d615a in truncate_inode_pages_range (mapping=0x44bb707c, lstart=32809, lend=-1) at mm/truncate.c:241

#10 0x080d64ff in truncate_inode_pages (mapping=0x75, lstart=21474836597) at mm/truncate.c:358
#11 0x080d6a0d in truncate_pagecache (inode=0x75, newsize=32809) at mm/truncate.c:597
#12 0x081d9118 in nfs_vmtruncate (offset=<optimized out>, inode=<optimized out>) at fs/nfs/inode.c:554
#13 nfs_setattr_update_inode (inode=0x44bb6fc4, attr=0x8029) at fs/nfs/inode.c:585
#14 0x081e73ba in nfs_proc_setattr (dentry=0x75, fattr=0x0, sattr=0x4370fe1c) at fs/nfs/proc.c:142
#15 0x081da99c in nfs_setattr (dentry=0x47fb5b00, attr=0x4370fe1c) at fs/nfs/inode.c:523
#16 0x0811c256 in notify_change (dentry=0x47fb5b00, attr=0x4370fe1c) at fs/attr.c:248
#17 0x081011bb in do_truncate (dentry=0x47fb5b00, length=502511206441, time_attrs=5, filp=0x8609efc <textbuf.25662+28>) at fs/open.c:60 #18 0x081013f2 in do_sys_ftruncate (fd=117, length=32809, small=1) at fs/open.c:190
#19 0x081016da in SYSC_ftruncate (length=<optimized out>, fd=<optimized out>) at fs/open.c:200
#20 SyS_ftruncate (fd=129, length=32809) at fs/open.c:198
#21 0x08062974 in handle_syscall (r=0x473c9fd4) at arch/um/kernel/skas/syscall.c:35
#22 0x08074fa5 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #23 userspace (regs=0x473c9fd4) at arch/um/os-Linux/skas/process.c:431
#24 0x0805f740 in fork_handler () at arch/um/kernel/process.c:160
#25 0x00000000 in ?? ()

tfoerste@n22 ~/devel/linux $ sudo gdb /home/tfoerste/devel/linux/linux 8946 -n -batch -ex bt
string (buf=0x8609efb <textbuf.25662+27> ") offeset 20\n", end=0x860a2c0 <cont> "4721fffc: [<00000000>] 0x0k_handler+0x60/0x700360d/0x4e00ffff 00000000 4721fc0c: [<0805f8cc>] __switch_to+0x5c/0xf0", s=0x84c0982 <null+5> ")", spec=...) at lib/vsprintf.c:524
524 *buf = *s;

#0  string (buf=0x8609efb <textbuf.25662+27> ") offeset 20\n", end=0x860a2c0 <cont> "4721fffc:  [<00000000>] 0x0k_handler+0x60/0x700360d/0x4e00ffff 00000000 4721fc0c:  [<0805f8cc>] __switch_to+0x5c/0xf0", s=0x84c0982 <null+5> ")", spec=...) at lib/vsprintf.c:524
#1  0x0829ac42 in pointer (fmt=0x6c <Address 0x6c out of bounds>, buf=0x8609ef4 <textbuf.25662+20> "  (null) offeset 20\n", end=0x5 <Address 0x5 out of bounds>, ptr=0x0, spec=...) at lib/vsprintf.c:1239
#2  0x0829a9dd in vsnprintf (buf=0x8609ee0 <textbuf.25662> "node->slots[offset]   (null) offeset 20\n", size=992, fmt=0x8609efc <textbuf.25662+28> " offeset 20\n", args=0x4370fc10 "") at lib/vsprintf.c:1667
#3  0x0829b0f7 in vscnprintf (buf=0x6c <Address 0x6c out of bounds>, size=992, fmt=0x6c <Address 0x6c out of bounds>, args=0x6c <Address 0x6c out of bounds>) at lib/vsprintf.c:1776
#4  0x080a6968 in vprintk_emit (facility=0, level=-1, dict=0x0, dictlen=0, fmt=0x6c <Address 0x6c out of bounds>, args=0x6c <Address 0x6c out of bounds>) at kernel/printk/printk.c:1548
#5  0x08419b05 in printk (fmt=0x6c <Address 0x6c out of bounds>) at kernel/printk/printk.c:1690
#6  0x08296a8d in radix_tree_next_chunk (root=0x6c, iter=0x4370fc54, flags=0) at lib/radix-tree.c:770
#7  0x080cc1fe in find_get_pages (mapping=0x44bb707c, start=0, nr_pages=14, pages=0x5) at mm/filemap.c:844
#8  0x080d5d6a in pagevec_lookup (pvec=0x4370fcb8, mapping=0x6c, start=108, nr_pages=108) at mm/swap.c:914
#9  0x080d615a in truncate_inode_pages_range (mapping=0x44bb707c, lstart=32809, lend=-1) at mm/truncate.c:241

#10 0x080d64ff in truncate_inode_pages (mapping=0x6c, lstart=21474836588) at mm/truncate.c:358
#11 0x080d6a0d in truncate_pagecache (inode=0x6c, newsize=32809) at mm/truncate.c:597
#12 0x081d9118 in nfs_vmtruncate (offset=<optimized out>, inode=<optimized out>) at fs/nfs/inode.c:554
#13 nfs_setattr_update_inode (inode=0x44bb6fc4, attr=0x8029) at fs/nfs/inode.c:585
#14 0x081e73ba in nfs_proc_setattr (dentry=0x6c, fattr=0x0, sattr=0x4370fe1c) at fs/nfs/proc.c:142
#15 0x081da99c in nfs_setattr (dentry=0x47fb5b00, attr=0x4370fe1c) at fs/nfs/inode.c:523
#16 0x0811c256 in notify_change (dentry=0x47fb5b00, attr=0x4370fe1c) at fs/attr.c:248
#17 0x081011bb in do_truncate (dentry=0x47fb5b00, length=463856500777, time_attrs=5, filp=0x8609efc <textbuf.25662+28>) at fs/open.c:60 #18 0x081013f2 in do_sys_ftruncate (fd=108, length=32809, small=1) at fs/open.c:190
#19 0x081016da in SYSC_ftruncate (length=<optimized out>, fd=<optimized out>) at fs/open.c:200
#20 SyS_ftruncate (fd=129, length=32809) at fs/open.c:198
#21 0x08062974 in handle_syscall (r=0x473c9fd4) at arch/um/kernel/skas/syscall.c:35
#22 0x08074fa5 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #23 userspace (regs=0x473c9fd4) at arch/um/os-Linux/skas/process.c:431
#24 0x0805f740 in fork_handler () at arch/um/kernel/process.c:160
#25 0x00000000 in ?? ()

The fuzzer trinity is still running and tries to kill one of it childs (the output comes from a ssh command, which started trinity in the UML):

...
w[atchdog] sending SIGKILL to pid 4345. [diff:261] [watchdog] sending SIGKILL to pid 4346. [diff:263] [watchdog] sending SIGKILL to pid 4344. [diff:263] [watchdog] sending SIGKILL to pid 4345. [diff:266] [watchdog] sending SIGKILL to pid 4346. [diff:267] [watchdog] sending SIGKILL to pid 4344. [diff:267] [watchdog] sending SIGKILL to pid 4345. [diff:270] [watchdog] sending SIGKILL to pid 4346. [diff:271] [watchdog] sending SIGKILL to pid 4344. [diff:271]
...

but I cannot connect to the UML via ssh.

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Am 10.11.2013 16:14, schrieb Toralf Förster:

In the mean while I think that it is not the radix-tree itself where the hang is related to. With this patch :

index 353b683..22a5926 100644
@@ -355,6 +355,8 @@ EXPORT_SYMBOL(truncate_inode_pages_range);
  */
 void truncate_inode_pages(struct address_space *mapping, loff_t lstart)
 {
+       if (lstart > 0)
+               printk ("lstart=%lld\n", lstart);
        truncate_inode_pages_range(mapping, lstart, (loff_t)-1);
 }
 EXPORT_SYMBOL(truncate_inode_pages);

against v3.12-10087-g1213959 I get in the syslog entires like :

Nov 17 14:07:12 trinity tfoerste: M=/mnt/nfsv4
Nov 17 14:07:27 trinity kernel: lstart=2147418111
Nov 17 14:07:30 trinity kernel: lstart=14531581
Nov 17 14:07:30 trinity kernel: lstart=8388607
Nov 17 14:07:30 trinity kernel: lstart=187
Nov 17 14:07:32 trinity kernel: lstart=2048
Nov 17 14:08:00 trinity kernel: lstart=11264
Nov 17 14:08:00 trinity kernel: lstart=44297
Nov 17 14:08:05 trinity kernel: lstart=31
Nov 17 14:08:34 trinity kernel: lstart=1542
Nov 17 14:08:35 trinity kernel: lstart=30
Nov 17 14:08:35 trinity kernel: lstart=2088809
Nov 17 14:08:37 trinity kernel: lstart=208
Nov 17 14:08:37 trinity kernel: lstart=7276806
Nov 17 14:08:37 trinity kernel: lstart=191
...
Nov 17 14:11:22 trinity tfoerste: M=/mnt/nfsv4
Nov 17 14:11:36 trinity kernel: lstart=255
Nov 17 14:11:36 trinity kernel: lstart=500676444
Nov 17 14:11:37 trinity kernel: lstart=1024
Nov 17 14:11:37 trinity kernel: lstart=12786775
Nov 17 14:11:37 trinity kernel: lstart=16728385
Nov 17 14:11:37 trinity kernel: lstart=44
Nov 17 14:11:37 trinity kernel: lstart=516
Nov 17 14:11:38 trinity kernel: lstart=17407
Nov 17 14:11:38 trinity kernel: lstart=31
Nov 17 14:11:38 trinity kernel: lstart=65534
Nov 17 14:11:39 trinity kernel: lstart=4302304271
Nov 17 14:11:40 trinity kernel: lstart=65536
Nov 17 14:11:40 trinity kernel: lstart=678625087
Nov 17 14:11:40 trinity kernel: lstart=190464262
Nov 17 14:11:41 trinity kernel: lstart=268435343
Nov 17 14:11:42 trinity kernel: lstart=109
Nov 17 14:11:42 trinity kernel: lstart=2088960
Nov 17 14:11:42 trinity kernel: lstart=989582838
Nov 17 14:11:42 trinity kernel: lstart=3838
Nov 17 14:11:42 trinity kernel: lstart=327
Nov 17 14:11:43 trinity kernel: lstart=119
Nov 17 14:12:14 trinity kernel: lstart=9949
Nov 17 14:12:14 trinity kernel: lstart=4096
Nov 17 14:12:15 trinity kernel: lstart=3
Nov 17 14:12:18 trinity sshd[9636]: pam_unix(sshd:session): session closed for user tfoerste

...

Does this helps ?

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

With this diff against latest Linus tree v3.12-11355-g57498f9 :

index 7811ed3..54d9802 100644
@@ -750,6 +750,7 @@ restart:
        /* Index outside of the tree */
        if (offset >= RADIX_TREE_MAP_SIZE)
                return NULL;
+       printk ("offset a: %lu \n", offset);
 
        node = rnode;
        while (1) {

@@ -770,6 +771,7 @@ restart:
                                        if (node->slots[offset])
                                                break;
                                }
+                       printk ("offset b: %lu \n", offset);
                        index &= ~((RADIX_TREE_MAP_SIZE << shift) - 1);
                        index += offset << shift;
                        /* Overflow after ~0UL */

@@ -812,6 +814,7 @@ restart:
                }
        }
 
+       printk ("offset c: %lu \n", offset);
        return node->slots + offset;
 }
 EXPORT_SYMBOL(radix_tree_next_chunk);

I got today these syslog message when the trinity process hangs at a 32 bit Gentoo linux:

Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset c: 63
Nov 22 21:29:29 trinity kernel: offset a: 0
Nov 22 21:29:29 trinity kernel: offset b: 3
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset c: 63
Nov 22 21:29:29 trinity kernel: offset a: 0
Nov 22 21:29:29 trinity kernel: offset b: 3
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity sshd[1299]: pam_unix(sshd:session): session closed for user tfoerste
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset c: 63
Nov 22 21:29:29 trinity kernel: offset a: 0
Nov 22 21:29:29 trinity kernel: offset b: 3
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:29 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset c: 63
Nov 22 21:29:30 trinity kernel: offset a: 0
Nov 22 21:29:30 trinity kernel: offset b: 3
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset c: 63
Nov 22 21:29:30 trinity kernel: offset a: 0
Nov 22 21:29:30 trinity kernel: offset b: 3
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity sshd[1533]: pam_unix(sshd:session): session opened for user root by (uid=0)
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset b: 63
Nov 22 21:29:30 trinity kernel: offset c: 63
Nov 22 21:29:30 trinity kernel: offset a: 0
Nov 22 21:29:30 trinity kernel: offset b: 3
Nov 22 21:29:31 trinity kernel: offset b: 63
Nov 22 21:29:31 trinity kernel: offset b: 63
Nov 22 21:29:31 trinity kernel: offset b: 63
Nov 22 21:29:31 trinity kernel: offset b: 63
Nov 22 21:29:31 trinity kernel: offset b: 63
Nov 22 21:29:31 trinity kernel: offset c: 63
Nov 22 21:29:31 trinity shutdown[1536]: shutting down for system halt
Nov 22 21:29:31 trinity init: Switching to runlevel: 0

FWIW gdb's output :

tfoerste@n22 ~/devel/linux $ sudo gdb /home/tfoerste/devel/linux/linux 3612 -n -batch -ex bt 0x083d3c83 in memcpy ()

#0  0x083d3c83 in memcpy ()
#1  0x080a6257 in log_store (facility=0, level=4, flags=LOG_NEWLINE, ts_nsec=0, dict=0x86101e0 <__log_buf+25512> "\200=\355\265D", dict_len=0, text=0x86101e0 <__log_buf+25512> "\200=\355\265D", text_len=13) at kernel/printk/printk.c:344
#2  0x080a7158 in vprintk_emit (facility=0, level=4, dict=0x0, dictlen=0, fmt=0x63a8 <Address 0x63a8 out of bounds>, args=0x63a8 <Address 0x63a8 out of bounds>) at kernel/printk/printk.c:1610
#3  0x08423845 in printk (fmt=0x63a8 <Address 0x63a8 out of bounds>) at kernel/printk/printk.c:1690
#4  0x0829c39e in radix_tree_next_chunk (root=0x63a8, iter=0x3f, flags=0) at lib/radix-tree.c:774
#5  0x080cc78e in find_get_pages (mapping=0x48c21010, start=0, nr_pages=14, pages=0x86101e0 <__log_buf+25512>) at mm/filemap.c:844
#6  0x080d654a in pagevec_lookup (pvec=0x49bffcc8, mapping=0x63a8, start=25512, nr_pages=25512) at mm/swap.c:937
#7  0x080d694a in truncate_inode_pages_range (mapping=0x48c21010, lstart=0, lend=-1) at mm/truncate.c:241
#8  0x080d6cef in truncate_inode_pages (mapping=0x63a8, lstart=603765886628684712) at mm/truncate.c:358
#9  0x08260a48 in hostfs_evict_inode (inode=0x48c20f58) at fs/hostfs/hostfs_kern.c:233

#10 0x0811b46f in evict (inode=0x48c20f58) at fs/inode.c:549
#11 0x0811bf5d in iput_final (inode=<optimized out>) at fs/inode.c:1419
#12 iput (inode=0x48c20f58) at fs/inode.c:1437
#13 0x08118858 in dentry_iput (dentry=<optimized out>) at fs/dcache.c:300
#14 d_kill (parent=<optimized out>, dentry=<optimized out>) at fs/dcache.c:447
#15 dentry_kill (dentry=0x4957de70, unlock_on_failure=<optimized out>) at fs/dcache.c:549
#16 0x08118b5d in dput (dentry=0x4957de70) at fs/dcache.c:605
#17 0x08105353 in __fput (file=0x48a7cd80) at fs/file_table.c:261
#18 0x081053bb in ____fput (work=0x48a7cd80) at fs/file_table.c:279
#19 0x08094486 in task_work_run () at kernel/task_work.c:123
#20 0x0807efb2 in exit_task_work (task=<optimized out>) at include/linux/task_work.h:21
#21 do_exit (code=1217397248) at kernel/exit.c:787
#22 0x0807f5fd in do_group_exit (exit_code=0) at kernel/exit.c:920
#23 0x0807f669 in SYSC_exit_group (error_code=<optimized out>) at kernel/exit.c:931
#24 SyS_exit_group (error_code=0) at kernel/exit.c:929
#25 0x08062ab4 in handle_syscall (r=0x48a787cc) at arch/um/kernel/skas/syscall.c:35
#26 0x08075115 in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198 #27 userspace (regs=0x48a787cc) at arch/um/os-Linux/skas/process.c:431
#28 0x0805f770 in fork_handler () at arch/um/kernel/process.c:149
#29 0x00000000 in ?? ()

MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to [email protected].  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>