From: Toralf F. <tor...@gm...> - 2013-05-12 15:47:16
|
With recent host and guest kernel trinity often triggers that warning which refers to this line WARN_ON(mm->nr_ptes > (FIRST_USER_ADDRESS+PMD_SIZE-1)>>PMD_SHIFT); /me wonders if (and how) I can help to identify the root cause (if it is not already known). -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-12 15:58:48
|
On Sun, May 12, 2013 at 5:47 PM, Toralf Förster <tor...@gm...> wrote: > With recent host and guest kernel trinity often triggers that warning > which refers to this line > > WARN_ON(mm->nr_ptes > (FIRST_USER_ADDRESS+PMD_SIZE-1)>>PMD_SHIFT); > > /me wonders if (and how) I can help to identify the root cause (if it is > not already known). Do you have stub_pte_fix.diff applied? > > -- > MfG/Sincerely > Toralf Förster > pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 > > ------------------------------------------------------------------------------ > Learn Graph Databases - Download FREE O'Reilly Book > "Graph Databases" is the definitive new guide to graph databases and > their applications. This 200-page book is written by three acclaimed > leaders in the field. The early access version is available now. > Download your free book today! http://p.sf.net/sfu/neotech_d2d_may > _______________________________________________ > User-mode-linux-devel mailing list > Use...@li... > https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-12 16:08:18
|
On 05/12/2013 05:58 PM, richard -rw- weinberger wrote: > Do you have stub_pte_fix.diff applied? yes, both the stub and the strnlen patch -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-17 12:22:36
Attachments:
wait_stub_done_fix.diff
|
On Fri, May 17, 2013 at 12:00 PM, richard -rw- weinberger <ric...@gm...> wrote: > On Wed, May 15, 2013 at 9:35 PM, richard -rw- weinberger > <ric...@gm...> wrote: >> On Wed, May 15, 2013 at 9:30 PM, Toralf Förster <tor...@gm...> wrote: >>> On 05/15/2013 09:11 PM, richard -rw- weinberger wrote: >>>> On Wed, May 15, 2013 at 9:06 PM, Toralf Förster <tor...@gm...> wrote: >>>>> On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: >>>>>> This looks like another issue. >>>>>> Are you testing process_vm_writev() with trinity? >>>>>> Looks like it managed to overwrite the stub page of a process, which >>>>>> is not good. >>>>> nope, it is the mremap syscall. >>>>> >>>>> A command like >>>>> >>>>> $>trinity -c mremap -N 10 >>>>> >>>>> immediately after starting a 32 bit Gentoo linux guest with current kernel 3.10-rc1-... + >>>>> strnlen + stub4 patch works, but later a >>>>> >>>>> $>trinity -c mremap -N 1000 >>>>> >>>>> yields into >>>>> >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: Stub registers - >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 0 - 100000 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 1 - 300000 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 2 - 0 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 3 - 0 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 4 - 0 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 5 - 0 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 6 - 0 >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 7 - 7b >>>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 8 - 7b >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 9 - 0 >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 10 - 33 >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 11 - ffffffff >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 12 - 1000c3 >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 13 - 73 >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 14 - 10206 >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 15 - 101028 >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 16 - 7b >>>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 15692, n = 15692, errno = 0, status = 0xb7f >>>>> >>>>> and now that process can't be killed - I had to stop the UML guest. >>>> >>>> Hmm, you've remapped the stub page and therefore the process broke. >>>> I think it would make sense to kill the process in stead of writing >>>> the "wait_stub_done ..." message. >>>> Changing the stub page is as destructive than overwriting the stack. >>> >>> Unfortunately no trinity process can be killed as soon as that happen. >>> Neither pgrep, pkill, nor "ps -efla" do return any result. >>> Killing any of those processes by its pid won't work too. >> >> Hmm, not good. >> I need to create me a reproducer for that. >> I'm unsure what exactly is going on. > > Good news, I have a reproducer for the problem and found out what the > root cause is. > UML is unable to terminate the task with the broken skas page. > A fix is on the way... Toralf, can you please append the attached patch too? It makes processes killable which corrupted their stub pages. -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-17 14:29:05
|
On 05/17/2013 02:22 PM, richard -rw- weinberger wrote: > Toralf, can you please append the attached patch too? > It makes processes killable which corrupted their stub pages. yes - now I can run an trinity infinite with the syscall mremap(). I still get for every x-th the syslog seen below, but processes are now killable (and trinity itself can kill its childs too so far) 2013-05-17T16:27:30.234+02:00 trinity kernel: do_syscall_stub: syscall 91 failed, return value = 0x0, expected return value = 0x0 2013-05-17T16:27:30.234+02:00 trinity kernel: syscall parameters: 0x100000 0x300000 0x0 0x0 0x0 0x0 2013-05-17T16:27:30.441+02:00 trinity kernel: Stub registers - 2013-05-17T16:27:30.441+02:00 trinity kernel: 0 - 100000 2013-05-17T16:27:30.441+02:00 trinity kernel: 1 - 300000 2013-05-17T16:27:30.441+02:00 trinity kernel: 2 - 0 2013-05-17T16:27:30.441+02:00 trinity kernel: 3 - 0 2013-05-17T16:27:30.441+02:00 trinity kernel: 4 - 0 2013-05-17T16:27:30.441+02:00 trinity kernel: 5 - 0 2013-05-17T16:27:30.441+02:00 trinity kernel: 6 - 0 2013-05-17T16:27:30.441+02:00 trinity kernel: 7 - 7b 2013-05-17T16:27:30.441+02:00 trinity kernel: 8 - 7b 2013-05-17T16:27:30.442+02:00 trinity kernel: 9 - 0 2013-05-17T16:27:30.442+02:00 trinity kernel: 10 - 33 2013-05-17T16:27:30.442+02:00 trinity kernel: 11 - ffffffff 2013-05-17T16:27:30.442+02:00 trinity kernel: 12 - 1000c3 2013-05-17T16:27:30.442+02:00 trinity kernel: 13 - 73 2013-05-17T16:27:30.442+02:00 trinity kernel: 14 - 10206 2013-05-17T16:27:30.442+02:00 trinity kernel: 15 - 101028 2013-05-17T16:27:30.442+02:00 trinity kernel: 16 - 7b 2013-05-17T16:27:30.442+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 31946, n = 31946, errno = 0, status = 0xb7f 2013-05-17T16:27:30.442+02:00 trinity kernel: do_syscall_stub : ret = 0, offset = 1052680, data = 41c36008 2013-05-17T16:27:30.443+02:00 trinity kernel: do_syscall_stub: syscall 91 failed, return value = 0x0, expected return value = 0x0 2013-05-17T16:27:30.443+02:00 trinity kernel: syscall parameters: 0x100000 0x300000 0x0 0x0 0x0 0x0 -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: Richard R. W. <ri...@si...> - 2013-05-17 15:07:40
|
----- Ursprüngliche Mail ----- > On 05/17/2013 02:22 PM, richard -rw- weinberger wrote: > > Toralf, can you please append the attached patch too? > > It makes processes killable which corrupted their stub pages. > yes - now I can run an trinity infinite with the syscall mremap(). > > I still get for every x-th the syslog seen below, but processes are > now killable (and trinity itself can kill its childs too so far) That's perfectly fine. Thanks, //richard |
From: richard -r. w. <ric...@gm...> - 2013-05-12 16:11:02
|
On Sun, May 12, 2013 at 6:08 PM, Toralf Förster <tor...@gm...> wrote: > On 05/12/2013 05:58 PM, richard -rw- weinberger wrote: >> Do you have stub_pte_fix.diff applied? > yes, both the stub and the strnlen patch Okay, I fear stub_pte_fix.diff does not do the right thing. /me cooks up a debug patch. Stay tuned. -- Thanks, //richard |
From: richard -r. w. <ric...@gm...> - 2013-05-12 16:31:25
Attachments:
stub_pte_fix2.diff
|
On Sun, May 12, 2013 at 6:10 PM, richard -rw- weinberger <ric...@gm...> wrote: > On Sun, May 12, 2013 at 6:08 PM, Toralf Förster <tor...@gm...> wrote: >> On 05/12/2013 05:58 PM, richard -rw- weinberger wrote: >>> Do you have stub_pte_fix.diff applied? >> yes, both the stub and the strnlen patch > > Okay, I fear stub_pte_fix.diff does not do the right thing. > /me cooks up a debug patch. Stay tuned. Toralf, can you please replace stub_pte_fix.diff with the attached patch? -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-12 18:13:56
|
On 05/12/2013 06:31 PM, richard -rw- weinberger wrote: > Toralf, can you please replace stub_pte_fix.diff with the attached patch? yep - works much better - no WARNING:/BUG: so far (tested 3.10-rc1 + strnlen + stub2 patch) -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: Toralf F. <tor...@gm...> - 2013-05-12 18:45:24
|
On 05/12/2013 06:31 PM, richard -rw- weinberger wrote: > Toralf, can you please replace stub_pte_fix.diff with the attached patch? Hhm, ok, now it tooks hours than minutes, but : 013-05-12T20:37:17.000+02:00 trinity tfoerste: M=/mnt/nfs/n22 2013-05-12T20:37:17.000+02:00 trinity sshd[2344]: pam_unix(sshd:session): session closed for user tfoerste 2013-05-12T20:40:01.000+02:00 trinity cron[2400]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons) 2013-05-12T20:40:47.755+02:00 trinity kernel: ------------[ cut here ]------------ 2013-05-12T20:40:47.755+02:00 trinity kernel: WARNING: at mm/mmap.c:2757 exit_mmap+0x164/0x190() 2013-05-12T20:40:47.755+02:00 trinity kernel: CPU: 0 PID: 2422 Comm: trinity-child0 Not tainted 3.10.0-rc1-00002-gc17b38f #6 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7d9c 408f7dc8 0807bfba 083d51b0 083d9a6e 00000ac5 080eb8e4 080eb8e4 2013-05-12T20:40:47.755+02:00 trinity kernel: 000007d8 40b026c0 3fdbe93c 408f7dd8 0807c083 00000009 00000000 408f7e10 2013-05-12T20:40:47.755+02:00 trinity kernel: 080eb8e4 083d9a6e 00000ac5 c0000000 00000000 25d1f5d8 40b026c0 00000000 408f7d70: [<08060cff>] show_stack+0xcf/0x100 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7d94: [<0835ed89>] dump_stack+0x26/0x28 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7da4: [<0807bfba>] warn_slowpath_common+0x5a/0x80 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7dcc: [<0807c083>] warn_slowpath_null+0x23/0x30 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7ddc: [<080eb8e4>] exit_mmap+0x164/0x190 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7e14: [<0807990d>] mmput+0x3d/0xb0 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7e28: [<08081076>] do_exit+0x2f6/0x880 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7e78: [<080816e9>] do_group_exit+0xa9/0xf0 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7ea0: [<08081749>] SyS_exit_group+0x19/0x20 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7eac: [<08062ab2>] handle_syscall+0x82/0xb0 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7ef4: [<0807518d>] userspace+0x46d/0x590 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7ffc: [<00000000>] 0x0 2013-05-12T20:40:47.757+02:00 trinity kernel: 2013-05-12T20:40:47.757+02:00 trinity kernel: ---[ end trace 610449969e20fc68 ]--- 2013-05-12T20:40:47.758+02:00 trinity kernel: XXX mm->nr_ptes: 4294967295 2013-05-12T20:40:50.000+02:00 trinity sshd[2350]: pam_unix(sshd:session): session closed for user tfoerste -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-12 19:45:44
|
On Sun, May 12, 2013 at 8:45 PM, Toralf Förster <tor...@gm...> wrote: > On 05/12/2013 06:31 PM, richard -rw- weinberger wrote: >> Toralf, can you please replace stub_pte_fix.diff with the attached patch? > > Hhm, > > ok, now it tooks hours than minutes, but : > > 013-05-12T20:37:17.000+02:00 trinity tfoerste: M=/mnt/nfs/n22 > 2013-05-12T20:37:17.000+02:00 trinity sshd[2344]: pam_unix(sshd:session): session closed for user tfoerste > 2013-05-12T20:40:01.000+02:00 trinity cron[2400]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons) > 2013-05-12T20:40:47.755+02:00 trinity kernel: ------------[ cut here ]------------ > 2013-05-12T20:40:47.755+02:00 trinity kernel: WARNING: at mm/mmap.c:2757 exit_mmap+0x164/0x190() > 2013-05-12T20:40:47.755+02:00 trinity kernel: CPU: 0 PID: 2422 Comm: trinity-child0 Not tainted 3.10.0-rc1-00002-gc17b38f #6 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7d9c 408f7dc8 0807bfba 083d51b0 083d9a6e 00000ac5 080eb8e4 080eb8e4 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 000007d8 40b026c0 3fdbe93c 408f7dd8 0807c083 00000009 00000000 408f7e10 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 080eb8e4 083d9a6e 00000ac5 c0000000 00000000 25d1f5d8 40b026c0 00000000 408f7d70: [<08060cff>] show_stack+0xcf/0x100 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7d94: [<0835ed89>] dump_stack+0x26/0x28 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7da4: [<0807bfba>] warn_slowpath_common+0x5a/0x80 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7dcc: [<0807c083>] warn_slowpath_null+0x23/0x30 > 2013-05-12T20:40:47.755+02:00 trinity kernel: 408f7ddc: [<080eb8e4>] exit_mmap+0x164/0x190 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7e14: [<0807990d>] mmput+0x3d/0xb0 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7e28: [<08081076>] do_exit+0x2f6/0x880 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7e78: [<080816e9>] do_group_exit+0xa9/0xf0 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7ea0: [<08081749>] SyS_exit_group+0x19/0x20 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7eac: [<08062ab2>] handle_syscall+0x82/0xb0 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7ef4: [<0807518d>] userspace+0x46d/0x590 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 > 2013-05-12T20:40:47.757+02:00 trinity kernel: 408f7ffc: [<00000000>] 0x0 > 2013-05-12T20:40:47.757+02:00 trinity kernel: > 2013-05-12T20:40:47.757+02:00 trinity kernel: ---[ end trace 610449969e20fc68 ]--- > 2013-05-12T20:40:47.758+02:00 trinity kernel: XXX mm->nr_ptes: 4294967295 > 2013-05-12T20:40:50.000+02:00 trinity sshd[2350]: pam_unix(sshd:session): session closed for user tfoerste Damn, we've underrun the counter. :-\ Can you please test the attached 3rd debug patch? The problem is that we have to install a mapping for the stub pages. This mapping must not have a VMA. Otherwise a UML user process could change this mapping. So, we have to insert PTEs manually and play nasty games with mm->nr_ptes. -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-12 19:54:03
|
On 05/12/2013 09:45 PM, richard -rw- weinberger wrote: > Damn, we've underrun the counter. :-\ > Can you please test the attached 3rd debug patch? yes - but give me a chance and attach a patch ;) -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-12 19:56:32
Attachments:
stub_pte_fix3.diff
|
On Sun, May 12, 2013 at 9:53 PM, Toralf Förster <tor...@gm...> wrote: > On 05/12/2013 09:45 PM, richard -rw- weinberger wrote: >> Damn, we've underrun the counter. :-\ >> Can you please test the attached 3rd debug patch? > > yes - but give me a chance and attach a patch ;) *grrrr* I'm a way to stupid for that new gmail user interface. -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-12 20:29:31
|
On 05/12/2013 09:56 PM, richard -rw- weinberger wrote: > On Sun, May 12, 2013 at 9:53 PM, Toralf Förster <tor...@gm...> wrote: >> On 05/12/2013 09:45 PM, richard -rw- weinberger wrote: >>> Damn, we've underrun the counter. :-\ >>> Can you please test the attached 3rd debug patch? >> >> yes - but give me a chance and attach a patch ;) > > *grrrr* I'm a way to stupid for that new gmail user interface. > > -- > Thanks, > //richard > now it tooks less than 1/4 hour : 2013-05-12T22:27:14.170+02:00 trinity kernel: ------------[ cut here ]------------ 2013-05-12T22:27:14.170+02:00 trinity kernel: WARNING: at mm/mmap.c:2757 exit_mmap+0x164/0x190() 2013-05-12T22:27:14.170+02:00 trinity kernel: CPU: 0 PID: 1303 Comm: trinity-child1 Not tainted 3.10.0-rc1-dirty #7 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7d9c 3e7f7dc8 0807bfca 083d51b0 083d9a66 00000ac5 080eb8f4 080eb8f4 2013-05-12T22:27:14.170+02:00 trinity kernel: 000004f2 3f0ff8c0 4022f53c 3e7f7dd8 0807c093 00000009 00000000 3e7f7e10 2013-05-12T22:27:14.170+02:00 trinity kernel: 080eb8f4 083d9a66 00000ac5 c0000000 00000000 3e6d7440 3f0ff8c0 00000000 3e7f7d70: [<08060cff>] show_stack+0xcf/0x100 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7d94: [<0835ed99>] dump_stack+0x26/0x28 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7da4: [<0807bfca>] warn_slowpath_common+0x5a/0x80 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7dcc: [<0807c093>] warn_slowpath_null+0x23/0x30 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7ddc: [<080eb8f4>] exit_mmap+0x164/0x190 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e14: [<0807991d>] mmput+0x3d/0xb0 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e28: [<08081086>] do_exit+0x2f6/0x880 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e78: [<080816f9>] do_group_exit+0xa9/0xf0 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ea0: [<08081759>] SyS_exit_group+0x19/0x20 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ef4: [<0807519d>] userspace+0x46d/0x590 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ffc: [<00000000>] 0x0 2013-05-12T22:27:14.172+02:00 trinity kernel: 2013-05-12T22:27:14.172+02:00 trinity kernel: ---[ end trace 44efa740a7cc38af ]--- 2013-05-12T22:27:14.173+02:00 trinity kernel: XXX mm->nr_ptes: 4294967295 -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-12 20:31:38
|
On Sun, May 12, 2013 at 10:29 PM, Toralf Förster <tor...@gm...> wrote: > On 05/12/2013 09:56 PM, richard -rw- weinberger wrote: >> On Sun, May 12, 2013 at 9:53 PM, Toralf Förster <tor...@gm...> wrote: >>> On 05/12/2013 09:45 PM, richard -rw- weinberger wrote: >>>> Damn, we've underrun the counter. :-\ >>>> Can you please test the attached 3rd debug patch? >>> >>> yes - but give me a chance and attach a patch ;) >> >> *grrrr* I'm a way to stupid for that new gmail user interface. >> >> -- >> Thanks, >> //richard >> > > now it tooks less than 1/4 hour : > > 2013-05-12T22:27:14.170+02:00 trinity kernel: ------------[ cut here ]------------ > 2013-05-12T22:27:14.170+02:00 trinity kernel: WARNING: at mm/mmap.c:2757 exit_mmap+0x164/0x190() > 2013-05-12T22:27:14.170+02:00 trinity kernel: CPU: 0 PID: 1303 Comm: trinity-child1 Not tainted 3.10.0-rc1-dirty #7 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7d9c 3e7f7dc8 0807bfca 083d51b0 083d9a66 00000ac5 080eb8f4 080eb8f4 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 000004f2 3f0ff8c0 4022f53c 3e7f7dd8 0807c093 00000009 00000000 3e7f7e10 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 080eb8f4 083d9a66 00000ac5 c0000000 00000000 3e6d7440 3f0ff8c0 00000000 3e7f7d70: [<08060cff>] show_stack+0xcf/0x100 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7d94: [<0835ed99>] dump_stack+0x26/0x28 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7da4: [<0807bfca>] warn_slowpath_common+0x5a/0x80 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7dcc: [<0807c093>] warn_slowpath_null+0x23/0x30 > 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7ddc: [<080eb8f4>] exit_mmap+0x164/0x190 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e14: [<0807991d>] mmput+0x3d/0xb0 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e28: [<08081086>] do_exit+0x2f6/0x880 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e78: [<080816f9>] do_group_exit+0xa9/0xf0 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ea0: [<08081759>] SyS_exit_group+0x19/0x20 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ef4: [<0807519d>] userspace+0x46d/0x590 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 > 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ffc: [<00000000>] 0x0 > 2013-05-12T22:27:14.172+02:00 trinity kernel: > 2013-05-12T22:27:14.172+02:00 trinity kernel: ---[ end trace 44efa740a7cc38af ]--- > 2013-05-12T22:27:14.173+02:00 trinity kernel: XXX mm->nr_ptes: 4294967295 Okay, I have to find another solution for the issue. :-\ -- Thanks, //richard |
From: richard -r. w. <ric...@gm...> - 2013-05-12 21:28:59
Attachments:
stub_pte_fix4.diff
|
On Sun, May 12, 2013 at 10:31 PM, richard -rw- weinberger <ric...@gm...> wrote: > On Sun, May 12, 2013 at 10:29 PM, Toralf Förster <tor...@gm...> wrote: >> On 05/12/2013 09:56 PM, richard -rw- weinberger wrote: >>> On Sun, May 12, 2013 at 9:53 PM, Toralf Förster <tor...@gm...> wrote: >>>> On 05/12/2013 09:45 PM, richard -rw- weinberger wrote: >>>>> Damn, we've underrun the counter. :-\ >>>>> Can you please test the attached 3rd debug patch? >>>> >>>> yes - but give me a chance and attach a patch ;) >>> >>> *grrrr* I'm a way to stupid for that new gmail user interface. >>> >>> -- >>> Thanks, >>> //richard >>> >> >> now it tooks less than 1/4 hour : >> >> 2013-05-12T22:27:14.170+02:00 trinity kernel: ------------[ cut here ]------------ >> 2013-05-12T22:27:14.170+02:00 trinity kernel: WARNING: at mm/mmap.c:2757 exit_mmap+0x164/0x190() >> 2013-05-12T22:27:14.170+02:00 trinity kernel: CPU: 0 PID: 1303 Comm: trinity-child1 Not tainted 3.10.0-rc1-dirty #7 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7d9c 3e7f7dc8 0807bfca 083d51b0 083d9a66 00000ac5 080eb8f4 080eb8f4 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 000004f2 3f0ff8c0 4022f53c 3e7f7dd8 0807c093 00000009 00000000 3e7f7e10 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 080eb8f4 083d9a66 00000ac5 c0000000 00000000 3e6d7440 3f0ff8c0 00000000 3e7f7d70: [<08060cff>] show_stack+0xcf/0x100 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7d94: [<0835ed99>] dump_stack+0x26/0x28 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7da4: [<0807bfca>] warn_slowpath_common+0x5a/0x80 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7dcc: [<0807c093>] warn_slowpath_null+0x23/0x30 >> 2013-05-12T22:27:14.170+02:00 trinity kernel: 3e7f7ddc: [<080eb8f4>] exit_mmap+0x164/0x190 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e14: [<0807991d>] mmput+0x3d/0xb0 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e28: [<08081086>] do_exit+0x2f6/0x880 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7e78: [<080816f9>] do_group_exit+0xa9/0xf0 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ea0: [<08081759>] SyS_exit_group+0x19/0x20 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ef4: [<0807519d>] userspace+0x46d/0x590 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: 3e7f7ffc: [<00000000>] 0x0 >> 2013-05-12T22:27:14.172+02:00 trinity kernel: >> 2013-05-12T22:27:14.172+02:00 trinity kernel: ---[ end trace 44efa740a7cc38af ]--- >> 2013-05-12T22:27:14.173+02:00 trinity kernel: XXX mm->nr_ptes: 4294967295 > > Okay, I have to find another solution for the issue. :-\ After a short walk though mm land I've finally found an elegant way to fix the issue. Toralf, please test the attached patch. So far it passed all my tests (calling madvise(), munmap() on the stub VMAs). -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-12 22:13:30
|
On 05/12/2013 11:28 PM, richard -rw- weinberger wrote: > Toralf, please test the attached patch. This happens here after applying the strnlen + stub4 patch on top of 3.10-rc1 2013-05-12T23:49:11.000+02:00 trinity sshd[1034]: pam_unix(sshd:session): session opened for user root by (uid=0) 2013-05-12T23:50:01.000+02:00 trinity cron[1048]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons) 2013-05-12T23:50:58.943+02:00 trinity kernel: Stub registers - 2013-05-12T23:50:58.943+02:00 trinity kernel: 0 - 100000 2013-05-12T23:50:58.943+02:00 trinity kernel: 1 - 2000 2013-05-12T23:50:58.943+02:00 trinity kernel: 2 - 0 2013-05-12T23:50:58.943+02:00 trinity kernel: 3 - 0 2013-05-12T23:50:58.943+02:00 trinity kernel: 4 - 0 2013-05-12T23:50:58.943+02:00 trinity kernel: 5 - 0 2013-05-12T23:50:58.943+02:00 trinity kernel: 6 - 0 2013-05-12T23:50:58.943+02:00 trinity kernel: 7 - 7b 2013-05-12T23:50:58.943+02:00 trinity kernel: 8 - 7b 2013-05-12T23:50:58.947+02:00 trinity kernel: 9 - 0 2013-05-12T23:50:58.947+02:00 trinity kernel: 10 - 33 2013-05-12T23:50:58.947+02:00 trinity kernel: 11 - ffffffff 2013-05-12T23:50:58.947+02:00 trinity kernel: 12 - 1000c3 2013-05-12T23:50:58.947+02:00 trinity kernel: 13 - 73 2013-05-12T23:50:58.947+02:00 trinity kernel: 14 - 10206 2013-05-12T23:50:58.947+02:00 trinity kernel: 15 - 101028 2013-05-12T23:50:58.947+02:00 trinity kernel: 16 - 7b 2013-05-12T23:50:58.947+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 21982, n = 21982, errno = 0, status = 0xb7f 2013-05-12T23:54:30.012+02:00 trinity kernel: INFO: task trinity-child1:1079 blocked for more than 120 seconds. 2013-05-12T23:54:30.012+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2013-05-12T23:54:30.012+02:00 trinity kernel: trinity-child1 D 40001282 0 1079 1025 0x00000000 2013-05-12T23:54:30.012+02:00 trinity kernel: 41090aac 00000001 00000000 4027fc78 0805f98f 4014caac 41090aac 40278000 2013-05-12T23:54:30.012+02:00 trinity kernel: 4014c600 4027fca8 0836071c 4014c600 41090600 00000001 0a554200 4027fcb8 2013-05-12T23:54:30.012+02:00 trinity kernel: 18f581ac 40278000 4014c600 4014c600 400ba71c 4027fcbc 083607b5 4027fcbc 4027fc64: [<0805f98f>] __switch_to+0x5f/0x100 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fc7c: [<0836071c>] __schedule+0x32c/0x370 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fcac: [<083607b5>] schedule+0x55/0x60 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fcc0: [<083612b5>] __down_read+0x95/0xb0 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fcf4: [<0835ff51>] down_read+0x11/0x20 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fd00: [<080f20f5>] process_vm_rw_core.isra.5+0x1f5/0x5c0 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fdd8: [<080f258d>] process_vm_rw+0xcd/0x110 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fe94: [<080f2640>] SyS_process_vm_writev+0x30/0x40 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027feac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fef4: [<0807519d>] userspace+0x46d/0x590 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027ffec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fffc: [<00000000>] 0x0 2013-05-12T23:54:30.017+02:00 trinity kernel: 2013-05-12T23:54:30.017+02:00 trinity kernel: INFO: task trinity-child0:1081 blocked for more than 120 seconds. 2013-05-12T23:54:30.017+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2013-05-12T23:54:30.022+02:00 trinity kernel: trinity-child0 D 40001282 0 1081 1025 0x00000002 2013-05-12T23:54:30.022+02:00 trinity kernel: 41090aac 00000001 00000000 402f79e4 0805f98f 4014e2ac 41090aac 402f0000 2013-05-12T23:54:30.022+02:00 trinity kernel: 4014de00 402f7a14 0836071c 4014de00 41090600 00000001 080fad7d 41350390 2013-05-12T23:54:30.022+02:00 trinity kernel: 000000bb 402f0000 400ba70c 400ba708 4014de00 402f7a28 083607b5 402f7a28 402f79d0: [<0805f98f>] __switch_to+0x5f/0x100 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f79e8: [<0836071c>] __schedule+0x32c/0x370 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a18: [<083607b5>] schedule+0x55/0x60 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a2c: [<08361337>] __down_write_nested+0x67/0xb0 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a60: [<08361399>] __down_write+0x19/0x1b 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a70: [<0835ff71>] down_write+0x11/0x13 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a7c: [<0814cc9a>] do_coredump+0x16a/0x1090 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7b48: [<0808c943>] get_signal_to_deliver+0x553/0x580 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7b74: [<08060adc>] kern_do_signal+0x28c/0x370 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c4c: [<08060bdd>] do_signal+0x1d/0x20 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c58: [<08061ed8>] fatal_sigsegv+0x28/0x30 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c6c: [<080749fb>] wait_stub_done+0xeb/0x100 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c98: [<08073edf>] run_syscall_stub+0x16f/0x2c0 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7ccc: [<080744ef>] unmap+0xff/0x110 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7d14: [<080610c4>] do_ops+0xa4/0x150 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7d54: [<0806168e>] fix_range_common+0x46e/0x4b0 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7dd4: [<080619ee>] flush_tlb_mm_range+0x2e/0x30 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7dec: [<080e8cab>] unmap_region+0xcb/0xe0 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7e28: [<080ea951>] do_munmap+0x231/0x2a0 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7e60: [<080ecf53>] SyS_mremap+0x263/0x480 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7ef4: [<0807519d>] userspace+0x46d/0x590 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7ffc: [<00000000>] 0x0 2013-05-12T23:54:30.030+02:00 trinity kernel: 2013-05-12T23:56:30.026+02:00 trinity kernel: INFO: task trinity-child1:1079 blocked for more than 120 seconds. 2013-05-12T23:56:30.026+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2013-05-12T23:56:30.026+02:00 trinity kernel: trinity-child1 D 40001282 0 1079 1025 0x00000000 2013-05-12T23:56:30.026+02:00 trinity kernel: 41090aac 00000001 00000000 4027fc78 0805f98f 4014caac 41090aac 40278000 2013-05-12T23:56:30.026+02:00 trinity kernel: 4014c600 4027fca8 0836071c 4014c600 41090600 00000001 0a554200 4027fcb8 2013-05-12T23:56:30.026+02:00 trinity kernel: 18f581ac 40278000 4014c600 4014c600 400ba71c 4027fcbc 083607b5 4027fcbc 4027fc64: [<0805f98f>] __switch_to+0x5f/0x100 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fc7c: [<0836071c>] __schedule+0x32c/0x370 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fcac: [<083607b5>] schedule+0x55/0x60 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fcc0: [<083612b5>] __down_read+0x95/0xb0 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fcf4: [<0835ff51>] down_read+0x11/0x20 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fd00: [<080f20f5>] process_vm_rw_core.isra.5+0x1f5/0x5c0 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fdd8: [<080f258d>] process_vm_rw+0xcd/0x110 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fe94: [<080f2640>] SyS_process_vm_writev+0x30/0x40 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027feac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fef4: [<0807519d>] userspace+0x46d/0x590 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027ffec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fffc: [<00000000>] 0x0 2013-05-12T23:56:30.030+02:00 trinity kernel: 2013-05-12T23:56:30.030+02:00 trinity kernel: INFO: task trinity-child0:1081 blocked for more than 120 seconds. 2013-05-12T23:56:30.030+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2013-05-12T23:56:30.034+02:00 trinity kernel: trinity-child0 D 40001282 0 1081 1025 0x00000002 2013-05-12T23:56:30.034+02:00 trinity kernel: 41090aac 00000001 00000000 402f79e4 0805f98f 4014e2ac 41090aac 402f0000 2013-05-12T23:56:30.034+02:00 trinity kernel: 4014de00 402f7a14 0836071c 4014de00 41090600 00000001 080fad7d 41350390 2013-05-12T23:56:30.034+02:00 trinity kernel: 000000bb 402f0000 400ba70c 400ba708 4014de00 402f7a28 083607b5 402f7a28 402f79d0: [<0805f98f>] __switch_to+0x5f/0x100 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f79e8: [<0836071c>] __schedule+0x32c/0x370 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a18: [<083607b5>] schedule+0x55/0x60 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a2c: [<08361337>] __down_write_nested+0x67/0xb0 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a60: [<08361399>] __down_write+0x19/0x1b 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a70: [<0835ff71>] down_write+0x11/0x13 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a7c: [<0814cc9a>] do_coredump+0x16a/0x1090 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7b48: [<0808c943>] get_signal_to_deliver+0x553/0x580 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7b74: [<08060adc>] kern_do_signal+0x28c/0x370 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c4c: [<08060bdd>] do_signal+0x1d/0x20 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c58: [<08061ed8>] fatal_sigsegv+0x28/0x30 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c6c: [<080749fb>] wait_stub_done+0xeb/0x100 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c98: [<08073edf>] run_syscall_stub+0x16f/0x2c0 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7ccc: [<080744ef>] unmap+0xff/0x110 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7d14: [<080610c4>] do_ops+0xa4/0x150 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7d54: [<0806168e>] fix_range_common+0x46e/0x4b0 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7dd4: [<080619ee>] flush_tlb_mm_range+0x2e/0x30 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7dec: [<080e8cab>] unmap_region+0xcb/0xe0 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7e28: [<080ea951>] do_munmap+0x231/0x2a0 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7e60: [<080ecf53>] SyS_mremap+0x263/0x480 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7ef4: [<0807519d>] userspace+0x46d/0x590 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7ffc: [<00000000>] 0x0 2013-05-12T23:56:30.048+02:00 trinity kernel: I restarted the trinity.sh test script again and it gave after few minutes : 2013-05-13T00:01:36.009+02:00 trinity kernel: Stub registers - 2013-05-13T00:01:36.009+02:00 trinity kernel: 0 - 100000 2013-05-13T00:01:36.009+02:00 trinity kernel: 1 - 2000 2013-05-13T00:01:36.009+02:00 trinity kernel: 2 - 0 2013-05-13T00:01:36.009+02:00 trinity kernel: 3 - 0 2013-05-13T00:01:36.009+02:00 trinity kernel: 4 - 0 2013-05-13T00:01:36.009+02:00 trinity kernel: 5 - 0 2013-05-13T00:01:36.009+02:00 trinity kernel: 6 - 0 2013-05-13T00:01:36.009+02:00 trinity kernel: 7 - 7b 2013-05-13T00:01:36.009+02:00 trinity kernel: 8 - 7b 2013-05-13T00:01:36.013+02:00 trinity kernel: 9 - 0 2013-05-13T00:01:36.013+02:00 trinity kernel: 10 - 33 2013-05-13T00:01:36.013+02:00 trinity kernel: 11 - ffffffff 2013-05-13T00:01:36.013+02:00 trinity kernel: 12 - 1000c3 2013-05-13T00:01:36.013+02:00 trinity kernel: 13 - 73 2013-05-13T00:01:36.013+02:00 trinity kernel: 14 - 10206 2013-05-13T00:01:36.013+02:00 trinity kernel: 15 - 101028 2013-05-13T00:01:36.013+02:00 trinity kernel: 16 - 7b 2013-05-13T00:01:36.013+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 23566, n = 23566, errno = 0, status = 0xb7f and then repeated "INFO: task trinity-child0:1093 blocked for more than 120 seconds." -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-13 07:12:23
|
On Mon, May 13, 2013 at 12:13 AM, Toralf Förster <tor...@gm...> wrote: > On 05/12/2013 11:28 PM, richard -rw- weinberger wrote: >> Toralf, please test the attached patch. > > This happens here after applying the strnlen + stub4 patch on top of 3.10-rc1 This looks like another issue. Are you testing process_vm_writev() with trinity? Looks like it managed to overwrite the stub page of a process, which is not good. > > 2013-05-12T23:49:11.000+02:00 trinity sshd[1034]: pam_unix(sshd:session): session opened for user root by (uid=0) > 2013-05-12T23:50:01.000+02:00 trinity cron[1048]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons) > 2013-05-12T23:50:58.943+02:00 trinity kernel: Stub registers - > 2013-05-12T23:50:58.943+02:00 trinity kernel: 0 - 100000 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 1 - 2000 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 2 - 0 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 3 - 0 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 4 - 0 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 5 - 0 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 6 - 0 > 2013-05-12T23:50:58.943+02:00 trinity kernel: 7 - 7b > 2013-05-12T23:50:58.943+02:00 trinity kernel: 8 - 7b > 2013-05-12T23:50:58.947+02:00 trinity kernel: 9 - 0 > 2013-05-12T23:50:58.947+02:00 trinity kernel: 10 - 33 > 2013-05-12T23:50:58.947+02:00 trinity kernel: 11 - ffffffff > 2013-05-12T23:50:58.947+02:00 trinity kernel: 12 - 1000c3 > 2013-05-12T23:50:58.947+02:00 trinity kernel: 13 - 73 > 2013-05-12T23:50:58.947+02:00 trinity kernel: 14 - 10206 > 2013-05-12T23:50:58.947+02:00 trinity kernel: 15 - 101028 > 2013-05-12T23:50:58.947+02:00 trinity kernel: 16 - 7b > 2013-05-12T23:50:58.947+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 21982, n = 21982, errno = 0, status = 0xb7f > 2013-05-12T23:54:30.012+02:00 trinity kernel: INFO: task trinity-child1:1079 blocked for more than 120 seconds. > 2013-05-12T23:54:30.012+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > 2013-05-12T23:54:30.012+02:00 trinity kernel: trinity-child1 D 40001282 0 1079 1025 0x00000000 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 41090aac 00000001 00000000 4027fc78 0805f98f 4014caac 41090aac 40278000 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 4014c600 4027fca8 0836071c 4014c600 41090600 00000001 0a554200 4027fcb8 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 18f581ac 40278000 4014c600 4014c600 400ba71c 4027fcbc 083607b5 4027fcbc 4027fc64: [<0805f98f>] __switch_to+0x5f/0x100 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fc7c: [<0836071c>] __schedule+0x32c/0x370 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fcac: [<083607b5>] schedule+0x55/0x60 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fcc0: [<083612b5>] __down_read+0x95/0xb0 > 2013-05-12T23:54:30.012+02:00 trinity kernel: 4027fcf4: [<0835ff51>] down_read+0x11/0x20 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fd00: [<080f20f5>] process_vm_rw_core.isra.5+0x1f5/0x5c0 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fdd8: [<080f258d>] process_vm_rw+0xcd/0x110 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fe94: [<080f2640>] SyS_process_vm_writev+0x30/0x40 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027feac: [<08062ac2>] handle_syscall+0x82/0xb0 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fef4: [<0807519d>] userspace+0x46d/0x590 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027ffec: [<0805f7fc>] fork_handler+0x6c/0x70 > 2013-05-12T23:54:30.017+02:00 trinity kernel: 4027fffc: [<00000000>] 0x0 > 2013-05-12T23:54:30.017+02:00 trinity kernel: > 2013-05-12T23:54:30.017+02:00 trinity kernel: INFO: task trinity-child0:1081 blocked for more than 120 seconds. > 2013-05-12T23:54:30.017+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > 2013-05-12T23:54:30.022+02:00 trinity kernel: trinity-child0 D 40001282 0 1081 1025 0x00000002 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 41090aac 00000001 00000000 402f79e4 0805f98f 4014e2ac 41090aac 402f0000 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 4014de00 402f7a14 0836071c 4014de00 41090600 00000001 080fad7d 41350390 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 000000bb 402f0000 400ba70c 400ba708 4014de00 402f7a28 083607b5 402f7a28 402f79d0: [<0805f98f>] __switch_to+0x5f/0x100 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f79e8: [<0836071c>] __schedule+0x32c/0x370 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a18: [<083607b5>] schedule+0x55/0x60 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a2c: [<08361337>] __down_write_nested+0x67/0xb0 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a60: [<08361399>] __down_write+0x19/0x1b > 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a70: [<0835ff71>] down_write+0x11/0x13 > 2013-05-12T23:54:30.022+02:00 trinity kernel: 402f7a7c: [<0814cc9a>] do_coredump+0x16a/0x1090 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7b48: [<0808c943>] get_signal_to_deliver+0x553/0x580 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7b74: [<08060adc>] kern_do_signal+0x28c/0x370 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c4c: [<08060bdd>] do_signal+0x1d/0x20 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c58: [<08061ed8>] fatal_sigsegv+0x28/0x30 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c6c: [<080749fb>] wait_stub_done+0xeb/0x100 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7c98: [<08073edf>] run_syscall_stub+0x16f/0x2c0 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7ccc: [<080744ef>] unmap+0xff/0x110 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7d14: [<080610c4>] do_ops+0xa4/0x150 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7d54: [<0806168e>] fix_range_common+0x46e/0x4b0 > 2013-05-12T23:54:30.026+02:00 trinity kernel: 402f7dd4: [<080619ee>] flush_tlb_mm_range+0x2e/0x30 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7dec: [<080e8cab>] unmap_region+0xcb/0xe0 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7e28: [<080ea951>] do_munmap+0x231/0x2a0 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7e60: [<080ecf53>] SyS_mremap+0x263/0x480 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7ef4: [<0807519d>] userspace+0x46d/0x590 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 > 2013-05-12T23:54:30.030+02:00 trinity kernel: 402f7ffc: [<00000000>] 0x0 > 2013-05-12T23:54:30.030+02:00 trinity kernel: > 2013-05-12T23:56:30.026+02:00 trinity kernel: INFO: task trinity-child1:1079 blocked for more than 120 seconds. > 2013-05-12T23:56:30.026+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > 2013-05-12T23:56:30.026+02:00 trinity kernel: trinity-child1 D 40001282 0 1079 1025 0x00000000 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 41090aac 00000001 00000000 4027fc78 0805f98f 4014caac 41090aac 40278000 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 4014c600 4027fca8 0836071c 4014c600 41090600 00000001 0a554200 4027fcb8 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 18f581ac 40278000 4014c600 4014c600 400ba71c 4027fcbc 083607b5 4027fcbc 4027fc64: [<0805f98f>] __switch_to+0x5f/0x100 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fc7c: [<0836071c>] __schedule+0x32c/0x370 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fcac: [<083607b5>] schedule+0x55/0x60 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fcc0: [<083612b5>] __down_read+0x95/0xb0 > 2013-05-12T23:56:30.026+02:00 trinity kernel: 4027fcf4: [<0835ff51>] down_read+0x11/0x20 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fd00: [<080f20f5>] process_vm_rw_core.isra.5+0x1f5/0x5c0 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fdd8: [<080f258d>] process_vm_rw+0xcd/0x110 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fe94: [<080f2640>] SyS_process_vm_writev+0x30/0x40 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027feac: [<08062ac2>] handle_syscall+0x82/0xb0 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fef4: [<0807519d>] userspace+0x46d/0x590 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027ffec: [<0805f7fc>] fork_handler+0x6c/0x70 > 2013-05-12T23:56:30.030+02:00 trinity kernel: 4027fffc: [<00000000>] 0x0 > 2013-05-12T23:56:30.030+02:00 trinity kernel: > 2013-05-12T23:56:30.030+02:00 trinity kernel: INFO: task trinity-child0:1081 blocked for more than 120 seconds. > 2013-05-12T23:56:30.030+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > 2013-05-12T23:56:30.034+02:00 trinity kernel: trinity-child0 D 40001282 0 1081 1025 0x00000002 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 41090aac 00000001 00000000 402f79e4 0805f98f 4014e2ac 41090aac 402f0000 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 4014de00 402f7a14 0836071c 4014de00 41090600 00000001 080fad7d 41350390 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 000000bb 402f0000 400ba70c 400ba708 4014de00 402f7a28 083607b5 402f7a28 402f79d0: [<0805f98f>] __switch_to+0x5f/0x100 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f79e8: [<0836071c>] __schedule+0x32c/0x370 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a18: [<083607b5>] schedule+0x55/0x60 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a2c: [<08361337>] __down_write_nested+0x67/0xb0 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a60: [<08361399>] __down_write+0x19/0x1b > 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a70: [<0835ff71>] down_write+0x11/0x13 > 2013-05-12T23:56:30.034+02:00 trinity kernel: 402f7a7c: [<0814cc9a>] do_coredump+0x16a/0x1090 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7b48: [<0808c943>] get_signal_to_deliver+0x553/0x580 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7b74: [<08060adc>] kern_do_signal+0x28c/0x370 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c4c: [<08060bdd>] do_signal+0x1d/0x20 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c58: [<08061ed8>] fatal_sigsegv+0x28/0x30 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c6c: [<080749fb>] wait_stub_done+0xeb/0x100 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7c98: [<08073edf>] run_syscall_stub+0x16f/0x2c0 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7ccc: [<080744ef>] unmap+0xff/0x110 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7d14: [<080610c4>] do_ops+0xa4/0x150 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7d54: [<0806168e>] fix_range_common+0x46e/0x4b0 > 2013-05-12T23:56:30.041+02:00 trinity kernel: 402f7dd4: [<080619ee>] flush_tlb_mm_range+0x2e/0x30 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7dec: [<080e8cab>] unmap_region+0xcb/0xe0 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7e28: [<080ea951>] do_munmap+0x231/0x2a0 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7e60: [<080ecf53>] SyS_mremap+0x263/0x480 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7eac: [<08062ac2>] handle_syscall+0x82/0xb0 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7ef4: [<0807519d>] userspace+0x46d/0x590 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7fec: [<0805f7fc>] fork_handler+0x6c/0x70 > 2013-05-12T23:56:30.048+02:00 trinity kernel: 402f7ffc: [<00000000>] 0x0 > 2013-05-12T23:56:30.048+02:00 trinity kernel: > > > I restarted the trinity.sh test script again and it gave after few minutes : > > > 2013-05-13T00:01:36.009+02:00 trinity kernel: Stub registers - > 2013-05-13T00:01:36.009+02:00 trinity kernel: 0 - 100000 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 1 - 2000 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 2 - 0 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 3 - 0 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 4 - 0 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 5 - 0 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 6 - 0 > 2013-05-13T00:01:36.009+02:00 trinity kernel: 7 - 7b > 2013-05-13T00:01:36.009+02:00 trinity kernel: 8 - 7b > 2013-05-13T00:01:36.013+02:00 trinity kernel: 9 - 0 > 2013-05-13T00:01:36.013+02:00 trinity kernel: 10 - 33 > 2013-05-13T00:01:36.013+02:00 trinity kernel: 11 - ffffffff > 2013-05-13T00:01:36.013+02:00 trinity kernel: 12 - 1000c3 > 2013-05-13T00:01:36.013+02:00 trinity kernel: 13 - 73 > 2013-05-13T00:01:36.013+02:00 trinity kernel: 14 - 10206 > 2013-05-13T00:01:36.013+02:00 trinity kernel: 15 - 101028 > 2013-05-13T00:01:36.013+02:00 trinity kernel: 16 - 7b > 2013-05-13T00:01:36.013+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 23566, n = 23566, errno = 0, status = 0xb7f > > and then repeated "INFO: task trinity-child0:1093 blocked for more than 120 seconds." > > -- > MfG/Sincerely > Toralf Förster > pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-13 18:07:48
|
On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: > This looks like another issue. > Are you testing process_vm_writev() with trinity? Yes, I use trinity for that Well, with stub2 + strnlen I do now have the following situations : Stressing a 32 bit Gentoo Linux with trinity firing up only the syscall process_vm_writev() gives after few minutes : 2013-05-13T18:59:01.000+02:00 trinity cron[1030]: (root) CMD (rm -f /var/spool/cron/lastrun/cron.hourly) 2013-05-13T19:00:01.349+02:00 trinity kernel: trinity-child0 invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=500 2013-05-13T19:00:01.349+02:00 trinity kernel: CPU: 0 PID: 1028 Comm: trinity-child0 Not tainted 3.10.0-rc1-00036-g05d129d #9 2013-05-13T19:00:01.349+02:00 trinity kernel: 40e87b2c 40e87b88 0835c79d 41e28b3c 41e287b0 000201da 00000000 000001f4 2013-05-13T19:00:01.349+02:00 trinity kernel: 08443920 40e87b5c 08071dfe 00000000 40e87b68 083614bc 00000001 40e87b88 2013-05-13T19:00:01.349+02:00 trinity kernel: 08278d25 08443920 00000001 40e80000 41e28600 41e28600 41e28600 40e87bcc 40e87b00: [<08060cff>] show_stack+0xcf/0x100 2013-05-13T19:00:01.349+02:00 trinity kernel: 40e87b24: [<0835ed79>] dump_stack+0x26/0x28 2013-05-13T19:00:01.349+02:00 trinity kernel: 40e87b34: [<0835c79d>] dump_header.isra.12+0x93/0x1c8 2013-05-13T19:00:01.349+02:00 trinity kernel: 40e87b8c: [<080ce620>] oom_kill_process+0x60/0x310 2013-05-13T19:00:01.349+02:00 trinity kernel: 40e87bd0: [<080cedcd>] out_of_memory+0x2bd/0x320 2013-05-13T19:00:01.349+02:00 trinity kernel: 40e87c1c: [<080d2258>] __alloc_pages_nodemask+0x628/0x750 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87ca8: [<080cbc6b>] filemap_fault+0x32b/0x480 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87cf0: [<080e3d6e>] __do_fault+0x9e/0x450 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87d4c: [<080e68ca>] handle_pte_fault+0x2aa/0x780 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87da4: [<080e6e6c>] handle_mm_fault+0xcc/0xe0 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87dd8: [<08061d57>] handle_page_fault+0x127/0x280 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87e1c: [<08061f86>] segv+0xa6/0x2b0 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87ecc: [<08062203>] segv_handler+0x73/0x80 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87ef4: [<0807503a>] userspace+0x30a/0x590 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-13T19:00:02.116+02:00 trinity kernel: 40e87ffc: [<00000000>] 0x0 2013-05-13T19:00:01.000+02:00 trinity cron[1033]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons) 2013-05-13T19:00:02.151+02:00 trinity kernel: 2013-05-13T19:00:02.151+02:00 trinity kernel: Mem-Info: 2013-05-13T19:00:02.151+02:00 trinity kernel: Normal per-cpu: 2013-05-13T19:00:02.151+02:00 trinity kernel: CPU 0: hi: 186, btch: 31 usd: 56 2013-05-13T19:00:02.151+02:00 trinity kernel: active_anon:107921 inactive_anon:107946 isolated_anon:0 2013-05-13T19:00:02.151+02:00 trinity kernel: active_file:38 inactive_file:431 isolated_file:0 2013-05-13T19:00:02.151+02:00 trinity kernel: unevictable:0 dirty:0 writeback:37542 unstable:0 2013-05-13T19:00:02.151+02:00 trinity kernel: free:923 slab_reclaimable:408 slab_unreclaimable:6561 2013-05-13T19:00:02.151+02:00 trinity kernel: mapped:433 shmem:355 pagetables:326 bounce:0 2013-05-13T19:00:02.151+02:00 trinity kernel: free_cma:0 2013-05-13T19:00:02.162+02:00 trinity kernel: Normal free:3692kB min:3796kB low:4744kB high:5692kB active_anon:431684kB inactive_anon:431784kB active_file:152kB inactive_file:1724kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:950896kB managed:900876kB mlocked:0kB dirty:0kB writeback:150168kB mapped:1732kB shmem:1420kB slab_reclaimable:1632kB slab_unreclaimable:26244kB kernel_stack:1568kB pagetables:1304kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:322 all_unreclaimable? yes 2013-05-13T19:00:02.162+02:00 trinity kernel: lowmem_reserve[]: 0 0 2013-05-13T19:00:02.162+02:00 trinity kernel: Normal: 5*4kB (UEM) 43*8kB (UEM) 8*16kB (UM) 8*32kB (UEM) 6*64kB (EM) 18*128kB (M) 1*256kB (U) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3692kB 2013-05-13T19:00:02.162+02:00 trinity kernel: 38595 total pagecache pages 2013-05-13T19:00:02.162+02:00 trinity kernel: 37759 pages in swap cache 2013-05-13T19:00:02.162+02:00 trinity kernel: Swap cache stats: add 65561, delete 27802, find 25/28 2013-05-13T19:00:02.162+02:00 trinity kernel: Free swap = 0kB 2013-05-13T19:00:02.162+02:00 trinity kernel: Total swap = 262140kB 2013-05-13T19:00:02.162+02:00 trinity kernel: 237724 pages RAM 2013-05-13T19:00:02.162+02:00 trinity kernel: 12505 pages reserved 2013-05-13T19:00:02.169+02:00 trinity kernel: 262899 pages shared 2013-05-13T19:00:02.169+02:00 trinity kernel: 223402 pages non-shared 2013-05-13T19:00:02.169+02:00 trinity kernel: [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 445] 0 445 2242 0 6 73 -1000 udevd 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 869] 0 869 1076 0 4 39 0 syslog-ng 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 870] 0 870 1827 0 5 138 0 syslog-ng 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 884] 0 884 1334 0 5 805 0 haveged 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 898] 0 898 531 0 4 15 0 rngd 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 947] 0 947 596 0 4 28 0 dhcpcd 2013-05-13T19:00:02.169+02:00 trinity kernel: [ 963] 0 963 1289 0 5 84 -1000 sshd 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 991] 0 991 1133 6 5 25 0 cron 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1008] 0 1008 599 0 4 27 0 agetty 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1009] 0 1009 2088 1 5 147 0 sshd 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1012] 0 1012 545 0 4 17 0 tail 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1019] 0 1019 2088 1 5 145 0 sshd 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1021] 1000 1021 2088 89 5 122 0 sshd 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1022] 1000 1022 855 0 4 36 0 bash 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1025] 1000 1025 4141 353 6 1049 0 trinity 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1026] 1000 1026 4141 10 5 1042 0 trinity-watchdo 2013-05-13T19:00:02.180+02:00 trinity kernel: [ 1027] 1000 1027 4141 2 5 1053 0 trinity-main 2013-05-13T19:00:02.189+02:00 trinity kernel: [ 1028] 1000 1028 245051 178095 241 63858 500 trinity-child0 2013-05-13T19:00:02.189+02:00 trinity kernel: Out of memory: Kill process 1028 (trinity-child0) score 1331 or sacrifice child 2013-05-13T19:00:02.189+02:00 trinity kernel: Killed process 1028 (trinity-child0) total-vm:980204kB, anon-rss:710876kB, file-rss:1504kB 2013-05-13T19:01:20.426+02:00 trinity kernel: sshd invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0 2013-05-13T19:01:20.426+02:00 trinity kernel: CPU: 0 PID: 1021 Comm: sshd Not tainted 3.10.0-rc1-00036-g05d129d #9 2013-05-13T19:01:20.426+02:00 trinity kernel: 40c5fb2c 40c5fb88 0835c79d 41f4af3c 41f4abb0 000201da 00000000 00000000 2013-05-13T19:01:20.426+02:00 trinity kernel: 08443920 40c5fb5c 08071dfe 00000000 40c5fb68 083614bc 00000001 40c5fb88 2013-05-13T19:01:20.426+02:00 trinity kernel: 08278d25 08443920 00000001 40c58000 41e28600 41e28600 41e28600 40c5fbcc 40c5fb00: [<08060cff>] show_stack+0xcf/0x100 2013-05-13T19:01:20.426+02:00 trinity kernel: 40c5fb24: [<0835ed79>] dump_stack+0x26/0x28 2013-05-13T19:01:20.426+02:00 trinity kernel: 40c5fb34: [<0835c79d>] dump_header.isra.12+0x93/0x1c8 2013-05-13T19:01:20.426+02:00 trinity kernel: 40c5fb8c: [<080ce620>] oom_kill_process+0x60/0x310 2013-05-13T19:01:20.426+02:00 trinity kernel: 40c5fbd0: [<080cedcd>] out_of_memory+0x2bd/0x320 2013-05-13T19:01:20.426+02:00 trinity kernel: 40c5fc1c: [<080d2258>] __alloc_pages_nodemask+0x628/0x750 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fca8: [<080cbc6b>] filemap_fault+0x32b/0x480 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fcf0: [<080e3d6e>] __do_fault+0x9e/0x450 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fd4c: [<080e68ca>] handle_pte_fault+0x2aa/0x780 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fda4: [<080e6e6c>] handle_mm_fault+0xcc/0xe0 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fdd8: [<08061d57>] handle_page_fault+0x127/0x280 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fe1c: [<08061f86>] segv+0xa6/0x2b0 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fecc: [<08062203>] segv_handler+0x73/0x80 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fef4: [<0807503a>] userspace+0x30a/0x590 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5ffec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-13T19:01:20.559+02:00 trinity kernel: 40c5fffc: [<00000000>] 0x0 2013-05-13T19:01:20.568+02:00 trinity kernel: 2013-05-13T19:01:20.568+02:00 trinity kernel: Mem-Info: 2013-05-13T19:01:20.568+02:00 trinity kernel: Normal per-cpu: 2013-05-13T19:01:20.568+02:00 trinity kernel: CPU 0: hi: 186, btch: 31 usd: 30 2013-05-13T19:01:20.568+02:00 trinity kernel: active_anon:108197 inactive_anon:108240 isolated_anon:0 2013-05-13T19:01:20.568+02:00 trinity kernel: active_file:11 inactive_file:320 isolated_file:32 2013-05-13T19:01:20.568+02:00 trinity kernel: unevictable:0 dirty:0 writeback:34549 unstable:0 2013-05-13T19:01:20.568+02:00 trinity kernel: free:946 slab_reclaimable:401 slab_unreclaimable:6107 2013-05-13T19:01:20.568+02:00 trinity kernel: mapped:399 shmem:353 pagetables:329 bounce:0 2013-05-13T19:01:20.568+02:00 trinity kernel: free_cma:0 2013-05-13T19:01:20.580+02:00 trinity kernel: Normal free:3784kB min:3796kB low:4744kB high:5692kB active_anon:432788kB inactive_anon:432960kB active_file:44kB inactive_file:1280kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:950896kB managed:900876kB mlocked:0kB dirty:0kB writeback:138196kB mapped:1596kB shmem:1412kB slab_reclaimable:1604kB slab_unreclaimable:24428kB kernel_stack:1568kB pagetables:1316kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:1077 all_unreclaimable? yes 2013-05-13T19:01:20.580+02:00 trinity kernel: lowmem_reserve[]: 0 0 2013-05-13T19:01:20.580+02:00 trinity kernel: Normal: 16*4kB (U) 3*8kB (U) 5*16kB (M) 9*32kB (M) 10*64kB (UM) 21*128kB (UM) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3784kB 2013-05-13T19:01:20.580+02:00 trinity kernel: 35426 total pagecache pages 2013-05-13T19:01:20.580+02:00 trinity kernel: 34714 pages in swap cache 2013-05-13T19:01:20.580+02:00 trinity kernel: Swap cache stats: add 129644, delete 94930, find 500/605 2013-05-13T19:01:20.580+02:00 trinity kernel: Free swap = 0kB 2013-05-13T19:01:20.580+02:00 trinity kernel: Total swap = 262140kB 2013-05-13T19:01:20.580+02:00 trinity kernel: 237724 pages RAM 2013-05-13T19:01:20.580+02:00 trinity kernel: 12505 pages reserved 2013-05-13T19:01:20.589+02:00 trinity kernel: 262528 pages shared 2013-05-13T19:01:20.589+02:00 trinity kernel: 223425 pages non-shared 2013-05-13T19:01:20.589+02:00 trinity kernel: [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 445] 0 445 2242 0 6 73 -1000 udevd 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 869] 0 869 1076 0 4 39 0 syslog-ng 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 870] 0 870 1827 38 5 100 0 syslog-ng 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 884] 0 884 1334 0 5 805 0 haveged 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 898] 0 898 531 5 4 10 0 rngd 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 947] 0 947 596 0 4 28 0 dhcpcd 2013-05-13T19:01:20.589+02:00 trinity kernel: [ 963] 0 963 1289 0 5 84 -1000 sshd 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 991] 0 991 1133 9 5 22 0 cron 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1008] 0 1008 599 0 4 27 0 agetty 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1009] 0 1009 2088 32 5 121 0 sshd 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1012] 0 1012 545 8 4 9 0 tail 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1019] 0 1019 2088 0 5 145 0 sshd 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1021] 1000 1021 2088 46 5 122 0 sshd 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1022] 1000 1022 855 0 4 36 0 bash 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1025] 1000 1025 4141 2 6 1049 0 trinity 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1026] 1000 1026 4141 11 5 1041 0 trinity-watchdo 2013-05-13T19:01:20.601+02:00 trinity kernel: [ 1027] 1000 1027 4141 8 5 1047 0 trinity-main 2013-05-13T19:01:20.611+02:00 trinity kernel: [ 1031] 1000 1031 248890 181640 244 63945 500 trinity-child0 2013-05-13T19:01:20.611+02:00 trinity kernel: Out of memory: Kill process 1031 (trinity-child0) score 1344 or sacrifice child 2013-05-13T19:01:20.611+02:00 trinity kernel: Killed process 1031 (trinity-child0) total-vm:995560kB, anon-rss:724988kB, file-rss:1572kB 2013-05-13T19:02:02.000+02:00 trinity sshd[1045]: pam_unix(sshd:session): session opened for user root by (uid=0) 2013-05-13T19:02:02.000+02:00 trinity shutdown[1048]: shutting down for system halt 2013-05-13T19:02:02.000+02:00 trinity sshd[1045]: pam_unix(sshd:session): session closed for user root Stressing the image w/ trinity with all available syscall except process_vm_writev() often gives for the syscall mremap(): 2013-05-13T19:15:28.000+02:00 trinity sshd[1027]: pam_unix(sshd:session): session opened for user root by (uid=0) 2013-05-13T19:16:10.789+02:00 trinity kernel: Stub registers - 2013-05-13T19:16:10.789+02:00 trinity kernel: 0 - 100000 2013-05-13T19:16:10.789+02:00 trinity kernel: 1 - 300000 2013-05-13T19:16:10.789+02:00 trinity kernel: 2 - 0 2013-05-13T19:16:10.789+02:00 trinity kernel: 3 - 0 2013-05-13T19:16:10.789+02:00 trinity kernel: 4 - 0 2013-05-13T19:16:10.789+02:00 trinity kernel: 5 - 0 2013-05-13T19:16:10.789+02:00 trinity kernel: 6 - 0 2013-05-13T19:16:10.789+02:00 trinity kernel: 7 - 7b 2013-05-13T19:16:10.789+02:00 trinity kernel: 8 - 7b 2013-05-13T19:16:10.793+02:00 trinity kernel: 9 - 0 2013-05-13T19:16:10.793+02:00 trinity kernel: 10 - 33 2013-05-13T19:16:10.793+02:00 trinity kernel: 11 - ffffffff 2013-05-13T19:16:10.793+02:00 trinity kernel: 12 - 1000c3 2013-05-13T19:16:10.793+02:00 trinity kernel: 13 - 73 2013-05-13T19:16:10.793+02:00 trinity kernel: 14 - 10206 2013-05-13T19:16:10.793+02:00 trinity kernel: 15 - 101028 2013-05-13T19:16:10.793+02:00 trinity kernel: 16 - 7b 2013-05-13T19:16:10.793+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 29533, n = 29533, errno = 0, status = 0xb7f 2013-05-13T19:18:42.388+02:00 trinity kernel: INFO: task trinity-child0:1035 blocked for more than 120 seconds. 2013-05-13T19:18:42.388+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2013-05-13T19:18:42.388+02:00 trinity kernel: trinity-child0 D 40001282 0 1035 1023 0x00000002 2013-05-13T19:18:42.388+02:00 trinity kernel: 08438acc 00000001 00000000 402579e4 0805f98f 4025baac 08438acc 40250000 2013-05-13T19:18:42.388+02:00 trinity kernel: 4025b600 40257a14 0836071c 4025b600 08438620 00000001 080fad7d 083649c0 2013-05-13T19:18:42.388+02:00 trinity kernel: 000000bb 40250000 400aa94c 400aa948 4025b600 40257a28 083607b5 40257a28 402579d0: [<0805f98f>] __switch_to+0x5f/0x100 2013-05-13T19:18:42.388+02:00 trinity kernel: 402579e8: [<0836071c>] __schedule+0x32c/0x370 2013-05-13T19:18:42.388+02:00 trinity kernel: 40257a18: [<083607b5>] schedule+0x55/0x60 2013-05-13T19:18:42.388+02:00 trinity kernel: 40257a2c: [<08361337>] __down_write_nested+0x67/0xb0 2013-05-13T19:18:42.388+02:00 trinity kernel: 40257a60: [<08361399>] __down_write+0x19/0x1b 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257a70: [<0835ff71>] down_write+0x11/0x13 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257a7c: [<0814cc9a>] do_coredump+0x16a/0x1090 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257b48: [<0808c943>] get_signal_to_deliver+0x553/0x580 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257b74: [<08060adc>] kern_do_signal+0x28c/0x370 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257c4c: [<08060bdd>] do_signal+0x1d/0x20 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257c58: [<08061ed8>] fatal_sigsegv+0x28/0x30 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257c6c: [<080749fb>] wait_stub_done+0xeb/0x100 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257c98: [<08073edf>] run_syscall_stub+0x16f/0x2c0 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257ccc: [<080744ef>] unmap+0xff/0x110 2013-05-13T19:18:42.392+02:00 trinity kernel: 40257d14: [<080610c4>] do_ops+0xa4/0x150 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257d54: [<0806168e>] fix_range_common+0x46e/0x4b0 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257dd4: [<080619ee>] flush_tlb_mm_range+0x2e/0x30 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257dec: [<080e8cab>] unmap_region+0xcb/0xe0 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257e28: [<080ea951>] do_munmap+0x231/0x2a0 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257e60: [<080ecf53>] SyS_mremap+0x263/0x480 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257eac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257ef4: [<0807519d>] userspace+0x46d/0x590 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-13T19:18:42.396+02:00 trinity kernel: 40257ffc: [<00000000>] 0x0 2013-05-13T19:18:42.396+02:00 trinity kernel: 2013-05-13T19:20:01.000+02:00 trinity cron[1038]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons) 2013-05-13T19:20:42.383+02:00 trinity kernel: INFO: task trinity-child0:1035 blocked for more than 120 seconds. 2013-05-13T19:20:42.383+02:00 trinity kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. 2013-05-13T19:20:42.383+02:00 trinity kernel: trinity-child0 D 40001282 0 1035 1023 0x00000002 2013-05-13T19:20:42.383+02:00 trinity kernel: 08438acc 00000001 00000000 402579e4 0805f98f 4025baac 08438acc 40250000 2013-05-13T19:20:42.383+02:00 trinity kernel: 4025b600 40257a14 0836071c 4025b600 08438620 00000001 080fad7d 083649c0 2013-05-13T19:20:42.383+02:00 trinity kernel: 000000bb 40250000 400aa94c 400aa948 4025b600 40257a28 083607b5 40257a28 402579d0: [<0805f98f>] __switch_to+0x5f/0x100 2013-05-13T19:20:42.383+02:00 trinity kernel: 402579e8: [<0836071c>] __schedule+0x32c/0x370 2013-05-13T19:20:42.383+02:00 trinity kernel: 40257a18: [<083607b5>] schedule+0x55/0x60 2013-05-13T19:20:42.383+02:00 trinity kernel: 40257a2c: [<08361337>] __down_write_nested+0x67/0xb0 2013-05-13T19:20:42.383+02:00 trinity kernel: 40257a60: [<08361399>] __down_write+0x19/0x1b 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257a70: [<0835ff71>] down_write+0x11/0x13 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257a7c: [<0814cc9a>] do_coredump+0x16a/0x1090 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257b48: [<0808c943>] get_signal_to_deliver+0x553/0x580 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257b74: [<08060adc>] kern_do_signal+0x28c/0x370 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257c4c: [<08060bdd>] do_signal+0x1d/0x20 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257c58: [<08061ed8>] fatal_sigsegv+0x28/0x30 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257c6c: [<080749fb>] wait_stub_done+0xeb/0x100 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257c98: [<08073edf>] run_syscall_stub+0x16f/0x2c0 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257ccc: [<080744ef>] unmap+0xff/0x110 2013-05-13T19:20:42.387+02:00 trinity kernel: 40257d14: [<080610c4>] do_ops+0xa4/0x150 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257d54: [<0806168e>] fix_range_common+0x46e/0x4b0 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257dd4: [<080619ee>] flush_tlb_mm_range+0x2e/0x30 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257dec: [<080e8cab>] unmap_region+0xcb/0xe0 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257e28: [<080ea951>] do_munmap+0x231/0x2a0 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257e60: [<080ecf53>] SyS_mremap+0x263/0x480 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257eac: [<08062ac2>] handle_syscall+0x82/0xb0 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257ef4: [<0807519d>] userspace+0x46d/0x590 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257fec: [<0805f7fc>] fork_handler+0x6c/0x70 2013-05-13T19:20:42.392+02:00 trinity kernel: 40257ffc: [<00000000>] 0x0 2013-05-13T19:20:42.392+02:00 trinity kernel: And stressing the image with all syscalls except process_vm_writev() and mremap() runs now for a while w/o any interesting things. -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: Toralf F. <tor...@gm...> - 2013-05-15 19:06:22
|
On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: > This looks like another issue. > Are you testing process_vm_writev() with trinity? > Looks like it managed to overwrite the stub page of a process, which > is not good. nope, it is the mremap syscall. A command like $>trinity -c mremap -N 10 immediately after starting a 32 bit Gentoo linux guest with current kernel 3.10-rc1-... + strnlen + stub4 patch works, but later a $>trinity -c mremap -N 1000 yields into 2013-05-15T21:02:04.061+02:00 trinity kernel: Stub registers - 2013-05-15T21:02:04.061+02:00 trinity kernel: 0 - 100000 2013-05-15T21:02:04.061+02:00 trinity kernel: 1 - 300000 2013-05-15T21:02:04.061+02:00 trinity kernel: 2 - 0 2013-05-15T21:02:04.061+02:00 trinity kernel: 3 - 0 2013-05-15T21:02:04.061+02:00 trinity kernel: 4 - 0 2013-05-15T21:02:04.061+02:00 trinity kernel: 5 - 0 2013-05-15T21:02:04.061+02:00 trinity kernel: 6 - 0 2013-05-15T21:02:04.061+02:00 trinity kernel: 7 - 7b 2013-05-15T21:02:04.061+02:00 trinity kernel: 8 - 7b 2013-05-15T21:02:04.065+02:00 trinity kernel: 9 - 0 2013-05-15T21:02:04.065+02:00 trinity kernel: 10 - 33 2013-05-15T21:02:04.065+02:00 trinity kernel: 11 - ffffffff 2013-05-15T21:02:04.065+02:00 trinity kernel: 12 - 1000c3 2013-05-15T21:02:04.065+02:00 trinity kernel: 13 - 73 2013-05-15T21:02:04.065+02:00 trinity kernel: 14 - 10206 2013-05-15T21:02:04.065+02:00 trinity kernel: 15 - 101028 2013-05-15T21:02:04.065+02:00 trinity kernel: 16 - 7b 2013-05-15T21:02:04.065+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 15692, n = 15692, errno = 0, status = 0xb7f and now that process can't be killed - I had to stop the UML guest. -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-15 19:11:58
|
On Wed, May 15, 2013 at 9:06 PM, Toralf Förster <tor...@gm...> wrote: > On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: >> This looks like another issue. >> Are you testing process_vm_writev() with trinity? >> Looks like it managed to overwrite the stub page of a process, which >> is not good. > nope, it is the mremap syscall. > > A command like > > $>trinity -c mremap -N 10 > > immediately after starting a 32 bit Gentoo linux guest with current kernel 3.10-rc1-... + > strnlen + stub4 patch works, but later a > > $>trinity -c mremap -N 1000 > > yields into > > 2013-05-15T21:02:04.061+02:00 trinity kernel: Stub registers - > 2013-05-15T21:02:04.061+02:00 trinity kernel: 0 - 100000 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 1 - 300000 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 2 - 0 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 3 - 0 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 4 - 0 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 5 - 0 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 6 - 0 > 2013-05-15T21:02:04.061+02:00 trinity kernel: 7 - 7b > 2013-05-15T21:02:04.061+02:00 trinity kernel: 8 - 7b > 2013-05-15T21:02:04.065+02:00 trinity kernel: 9 - 0 > 2013-05-15T21:02:04.065+02:00 trinity kernel: 10 - 33 > 2013-05-15T21:02:04.065+02:00 trinity kernel: 11 - ffffffff > 2013-05-15T21:02:04.065+02:00 trinity kernel: 12 - 1000c3 > 2013-05-15T21:02:04.065+02:00 trinity kernel: 13 - 73 > 2013-05-15T21:02:04.065+02:00 trinity kernel: 14 - 10206 > 2013-05-15T21:02:04.065+02:00 trinity kernel: 15 - 101028 > 2013-05-15T21:02:04.065+02:00 trinity kernel: 16 - 7b > 2013-05-15T21:02:04.065+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 15692, n = 15692, errno = 0, status = 0xb7f > > and now that process can't be killed - I had to stop the UML guest. Hmm, you've remapped the stub page and therefore the process broke. I think it would make sense to kill the process in stead of writing the "wait_stub_done ..." message. Changing the stub page is as destructive than overwriting the stack. Maybe we can teach triniy to no change the stub page. I'm sure trinity has also a mechanism to not destroy the stack. -- Thanks, //richard |
From: Toralf F. <tor...@gm...> - 2013-05-15 19:31:03
|
On 05/15/2013 09:11 PM, richard -rw- weinberger wrote: > On Wed, May 15, 2013 at 9:06 PM, Toralf Förster <tor...@gm...> wrote: >> On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: >>> This looks like another issue. >>> Are you testing process_vm_writev() with trinity? >>> Looks like it managed to overwrite the stub page of a process, which >>> is not good. >> nope, it is the mremap syscall. >> >> A command like >> >> $>trinity -c mremap -N 10 >> >> immediately after starting a 32 bit Gentoo linux guest with current kernel 3.10-rc1-... + >> strnlen + stub4 patch works, but later a >> >> $>trinity -c mremap -N 1000 >> >> yields into >> >> 2013-05-15T21:02:04.061+02:00 trinity kernel: Stub registers - >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 0 - 100000 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 1 - 300000 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 2 - 0 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 3 - 0 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 4 - 0 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 5 - 0 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 6 - 0 >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 7 - 7b >> 2013-05-15T21:02:04.061+02:00 trinity kernel: 8 - 7b >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 9 - 0 >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 10 - 33 >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 11 - ffffffff >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 12 - 1000c3 >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 13 - 73 >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 14 - 10206 >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 15 - 101028 >> 2013-05-15T21:02:04.065+02:00 trinity kernel: 16 - 7b >> 2013-05-15T21:02:04.065+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 15692, n = 15692, errno = 0, status = 0xb7f >> >> and now that process can't be killed - I had to stop the UML guest. > > Hmm, you've remapped the stub page and therefore the process broke. > I think it would make sense to kill the process in stead of writing > the "wait_stub_done ..." message. > Changing the stub page is as destructive than overwriting the stack. Unfortunately no trinity process can be killed as soon as that happen. Neither pgrep, pkill, nor "ps -efla" do return any result. Killing any of those processes by its pid won't work too. > Maybe we can teach triniy to no change the stub page. > I'm sure trinity has also a mechanism to not destroy the stack. @trinity Mailing list What do you think about that ? -- MfG/Sincerely Toralf Förster pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 |
From: richard -r. w. <ric...@gm...> - 2013-05-15 19:35:41
|
On Wed, May 15, 2013 at 9:30 PM, Toralf Förster <tor...@gm...> wrote: > On 05/15/2013 09:11 PM, richard -rw- weinberger wrote: >> On Wed, May 15, 2013 at 9:06 PM, Toralf Förster <tor...@gm...> wrote: >>> On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: >>>> This looks like another issue. >>>> Are you testing process_vm_writev() with trinity? >>>> Looks like it managed to overwrite the stub page of a process, which >>>> is not good. >>> nope, it is the mremap syscall. >>> >>> A command like >>> >>> $>trinity -c mremap -N 10 >>> >>> immediately after starting a 32 bit Gentoo linux guest with current kernel 3.10-rc1-... + >>> strnlen + stub4 patch works, but later a >>> >>> $>trinity -c mremap -N 1000 >>> >>> yields into >>> >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: Stub registers - >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 0 - 100000 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 1 - 300000 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 2 - 0 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 3 - 0 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 4 - 0 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 5 - 0 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 6 - 0 >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 7 - 7b >>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 8 - 7b >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 9 - 0 >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 10 - 33 >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 11 - ffffffff >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 12 - 1000c3 >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 13 - 73 >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 14 - 10206 >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 15 - 101028 >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 16 - 7b >>> 2013-05-15T21:02:04.065+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 15692, n = 15692, errno = 0, status = 0xb7f >>> >>> and now that process can't be killed - I had to stop the UML guest. >> >> Hmm, you've remapped the stub page and therefore the process broke. >> I think it would make sense to kill the process in stead of writing >> the "wait_stub_done ..." message. >> Changing the stub page is as destructive than overwriting the stack. > > Unfortunately no trinity process can be killed as soon as that happen. > Neither pgrep, pkill, nor "ps -efla" do return any result. > Killing any of those processes by its pid won't work too. Hmm, not good. I need to create me a reproducer for that. I'm unsure what exactly is going on. -- Thanks, //richard |
From: richard -r. w. <ric...@gm...> - 2013-05-17 10:00:12
|
On Wed, May 15, 2013 at 9:35 PM, richard -rw- weinberger <ric...@gm...> wrote: > On Wed, May 15, 2013 at 9:30 PM, Toralf Förster <tor...@gm...> wrote: >> On 05/15/2013 09:11 PM, richard -rw- weinberger wrote: >>> On Wed, May 15, 2013 at 9:06 PM, Toralf Förster <tor...@gm...> wrote: >>>> On 05/13/2013 09:12 AM, richard -rw- weinberger wrote: >>>>> This looks like another issue. >>>>> Are you testing process_vm_writev() with trinity? >>>>> Looks like it managed to overwrite the stub page of a process, which >>>>> is not good. >>>> nope, it is the mremap syscall. >>>> >>>> A command like >>>> >>>> $>trinity -c mremap -N 10 >>>> >>>> immediately after starting a 32 bit Gentoo linux guest with current kernel 3.10-rc1-... + >>>> strnlen + stub4 patch works, but later a >>>> >>>> $>trinity -c mremap -N 1000 >>>> >>>> yields into >>>> >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: Stub registers - >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 0 - 100000 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 1 - 300000 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 2 - 0 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 3 - 0 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 4 - 0 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 5 - 0 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 6 - 0 >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 7 - 7b >>>> 2013-05-15T21:02:04.061+02:00 trinity kernel: 8 - 7b >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 9 - 0 >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 10 - 33 >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 11 - ffffffff >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 12 - 1000c3 >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 13 - 73 >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 14 - 10206 >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 15 - 101028 >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: 16 - 7b >>>> 2013-05-15T21:02:04.065+02:00 trinity kernel: wait_stub_done : failed to wait for SIGTRAP, pid = 15692, n = 15692, errno = 0, status = 0xb7f >>>> >>>> and now that process can't be killed - I had to stop the UML guest. >>> >>> Hmm, you've remapped the stub page and therefore the process broke. >>> I think it would make sense to kill the process in stead of writing >>> the "wait_stub_done ..." message. >>> Changing the stub page is as destructive than overwriting the stack. >> >> Unfortunately no trinity process can be killed as soon as that happen. >> Neither pgrep, pkill, nor "ps -efla" do return any result. >> Killing any of those processes by its pid won't work too. > > Hmm, not good. > I need to create me a reproducer for that. > I'm unsure what exactly is going on. Good news, I have a reproducer for the problem and found out what the root cause is. UML is unable to terminate the task with the broken skas page. A fix is on the way... -- Thanks, //richard |