(resend - now with attached files)
Running trinity (1 process, no victim files, just "$>trinity -C1) for a longer time
within a 32 bit user mode linux image with a recent git kernel (host: 3.11.3 guest 3.12-rc3-g...)
yields into this konsole message :
* Starting local
net.core.warnings = 0 [ ok ]
BUG: soft lockup - CPU#0 stuck for 23s! [trinity-child0:2031]
and at the host t1 of the "linux"-processes eats all CPU cycles at 1 CPU core.
2 subsequent made back traces made with
$> sudo gdb /home/tfoerste/devel/linux/linux 28144 -n -batch -ex bt
shows nearly a similar position around __get_user_pages() - both are attached.
I'm not surprised that trinity harms a systems - I'm just wondering whether this particular picture is
expected or if it points to an issue.
FWIW the last lines of trinity log were :
[2031] [94] setsid() = 2031
[2031] [95] setresgid(rgid=0xffff33e3, egid=0xffffff93, sgid=0x22000040) = -1 (Operation not permitted)
[2031] [96] vmsplice(fd=5, iov=0x85501e0, nr_segs=300, flags=9) = 0x3000
[2031] [97] setresuid(ruid=0x80549193, euid=0xc61041e0, suid=0xff19b6fa) = -1 (Operation not permitted)
[2031] [98] setpriority(which=0xff010000, who=0xf3737373, niceval=0x8088960c) = -1 (Invalid argument)
[2031] [99] socketcall(call=1, args=0x8550200) = -1 (Address family not supported by protocol)
[2031] [100] access(filename="�", mode=2017) = -1 (Invalid argument)
[2031] [101] getgroups(gidsetsize=0, grouplist=0x80d0000[page_rand]) = 3
[2031] [102] msync(start=0xc0100220, len=0, flags=3) = -1 (Invalid argument)
[2031] [103] sigpending(set=0x40025000) = 0
[2031] [104] signalfd4(ufd=383, user_mask=1, sizemask=0xa4200000, flags=0x80800) = -1 (Invalid argument)
[2031] [105] sendfile(out_fd=383, in_fd=382, offset=0, count=4096) = -1 (Invalid argument)
[2031] [106] fanotify_mark(fanotify_fd=382, flags=5, mask=0x8000023, dfd=382, pathname="/proc/1092/task/1092/fdinfo/68") = -1 (Invalid argument)
[2031] [107] wait4(upid=1, stat_addr=4, options=0xd761979b, ru=8) = -1 (Invalid argument)
[2031] [108] sigpending(set=0x80ca000[page_zeros]) = 0
[2031] [109] setresuid(ruid=0xefffd6fc, euid=0x1bf4c92f, suid=0xffff2e33) = -1 (Operation not permitted)
[2031] [110] munlock(addr=0x40025000, len=34) = 0
[2031] [111] timer_delete(timer_id=0xffffffdc) = -1 (Invalid argument)
[2031] [112] sched_get_priority_max(policy=0x10000040) = -1 (Invalid argument)
[2031] [113] syslog(type=0xc1000000, buf=1, len=0x82a5) = -1 (Operation not permitted)
[2031] [114] setpriority(which=0xc4c806c6, who=0xffffff01, niceval=0xffff0682) = -1 (Invalid argument)
[2031] [115] getgroups16(gidsetsize=0xfffe, grouplist=1) = -1 (Bad address)
[2031] [116] rename(oldname=4, newname=8) = -1 (Bad address)
[2031] [117] inotify_init() = 654
[2031] [118] getgid() = 100
[2031] [119] fstatat64(dfd=382, filename="/sys/devices/virtual/net/sit0/duplex", statbuf=0, flag=0xb545d727) = -1 (Invalid argument)
[2031] [120] unlinkat(dfd=382, pathname="/proc/sys/net/ipv4/neigh/default/retrans_time", flag=0xc00ef76) = -1 (Invalid argument)
[2031] [121] timerfd_create(clockid=0, flags=0) = 655
[2031] [122] munlock(addr=4, len=0x3fff) = -1 (Cannot allocate memory)
[2031] [123] fremovexattr(fd=382, name=0) = -1 (Bad address)
[2031] [124] sched_get_priority_min(policy=0xff58bfef) = -1 (Invalid argument)
[2031] [125] mq_timedreceive(mqdes=397, u_msg_ptr=4, msg_len=5245, u_msg_prio=0xc0100220, u_abs_timeout=0xc0100220) = -1 (Bad address)
[2031] [126] chdir(filename="/proc/116/net/ptype") = -1 (Not a directory)
[2031] [127] ssetmask(newmask=0x88000092) = 0
[2031] [128] statfs(pathname="/proc/6/mounts", buf=0) = -1 (Bad address)
[2031] [129] fchown16(fd=397, user=104, group=0x94100000) = -1 (Operation not permitted)
[2031] [130] fchdir(fd=397) = -1 (Not a directory)
[2031] [131] mkdir(pathname="/proc/1092/task/1092/fdinfo/316", mode=525) = -1 (File exists)
[2031] [132] fsetxattr(fd=386, name=0x856f158, value=0x8571160, size=0, flags=0) = -1 (Numerical result out of range)
[2031] [133] io_setup(nr_events=4095, ctxp=0x40266000) ^CKilled by signal 2.
--
MfG/Sincerely
Toralf Förster
pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3
0x082949e4 in number (buf=0x434dfb21 "/K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", end=0x434dfb22 "K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", num=597699752268362946, spec=...) at lib/vsprintf.c:381
381 char *number(char *buf, char *end, unsigned long long num,
#0 0x082949e4 in number (buf=0x434dfb21 "/K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", end=0x434dfb22 "K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", num=597699752268362946, spec=...) at lib/vsprintf.c:381
#1 0x08295ef7 in vsnprintf (buf=0x434dfb1c "+0x52/K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", size=2147483647, fmt=0x84b74c2 "", args=0x434dfad0 "\t\373MC") at lib/vsprintf.c:1740
#2 0x08296547 in sprintf (buf=0x434dfb22 "K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", fmt=0x434dfb22 "K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b") at lib/vsprintf.c:1875
#3 0x080b76cf in __sprint_symbol (buffer=0x434dfb09 "io_schedule_timeout+0x52/K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", address=3276667675, symbol_offset=1, add_offset=1) at kernel/kallsyms.c:374
#4 0x080b781a in sprint_symbol (buffer=0x434dfb09 "io_schedule_timeout+0x52/K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", address=138503010) at kernel/kallsyms.c:395
#5 0x080b787f in __print_symbol (fmt=0x434dfb22 "K\b\225\036`\b\243^K\b\243^K\bD\373MC\210\247\t\b", address=1129184034) at kernel/kallsyms.c:440
#6 0x08078200 in print_symbol (fmt=<optimized out>, addr=<optimized out>) at include/linux/kallsyms.h:119
#7 print_context_stack (ebp=<optimized out>, tinfo=<optimized out>, stack=<optimized out>) at arch/x86/um/sysrq_32.c:54
#8 show_trace (task=0x434dfffd, stack=0x434dfc44) at arch/x86/um/sysrq_32.c:95
#9 0x0805fb6f in show_stack (task=0x0, esp=0x434dfc44) at arch/um/kernel/sysrq.c:65
#10 0x08413ae6 in __dump_stack () at lib/dump_stack.c:15
#11 dump_stack () at lib/dump_stack.c:60
#12 0x08414981 in schedule_timeout (timeout=-4028) at kernel/timer.c:1460
#13 0x08416362 in io_schedule_timeout (timeout=1129184034) at kernel/sched/core.c:3992
#14 0x08411c31 in balance_dirty_pages (pages_dirtied=17, mapping=<optimized out>) at mm/page-writeback.c:1519
#15 0x080d1ce4 in balance_dirty_pages_ratelimited (mapping=0x60) at mm/page-writeback.c:1653
#16 0x080e2d0c in __do_fault (mm=0x47f24400, vma=0x442095d8, address=1080451072, pmd=0x434dfb22, pgoff=1129184034, flags=1155011416, orig_pte=<incomplete type>) at mm/memory.c:3452
#17 0x080e5286 in do_nonlinear_fault (orig_pte=..., flags=<optimized out>, pmd=<optimized out>, address=<optimized out>, vma=<optimized out>, mm=<optimized out>, page_table=<optimized out>) at mm/memory.c:3518
#18 handle_pte_fault (flags=<optimized out>, pmd=<optimized out>, pte=<optimized out>, address=<optimized out>, vma=<optimized out>, mm=<optimized out>) at mm/memory.c:3717
#19 __handle_mm_fault (flags=<optimized out>, address=<optimized out>, vma=<optimized out>, mm=<optimized out>) at mm/memory.c:3845
#20 handle_mm_fault (mm=0x47f24400, vma=0x442095d8, address=1080451072, flags=1) at mm/memory.c:3868
#21 0x080e5a07 in __get_user_pages (tsk=0x46e23600, mm=0x47f24400, start=1080451072, nr_pages=65, gup_flags=519, pages=0x46f34d20, vmas=0x0, nonblocking=0x0) at mm/memory.c:1822
#22 0x080e5cc3 in get_user_pages (tsk=0x434dfb22, mm=0x434dfb22, start=1129184034, nr_pages=1129184034, write=1, force=0, pages=0xc34dfb1b, vmas=0x60) at mm/memory.c:2019
#23 0x08140cce in aio_setup_ring (ctx=<optimized out>) at fs/aio.c:317
#24 ioctx_alloc (nr_events=<optimized out>) at fs/aio.c:582
#25 SYSC_io_setup (ctxp=<optimized out>, nr_events=<optimized out>) at fs/aio.c:1100
#26 SyS_io_setup (nr_events=4095, ctxp=1076256768) at fs/aio.c:1083
#27 0x080619c2 in handle_syscall (r=0x46e237d4) at arch/um/kernel/skas/syscall.c:35
#28 0x08073f2d in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198
#29 userspace (regs=0x46e237d4) at arch/um/os-Linux/skas/process.c:431
#30 0x0805e6ac in fork_handler () at arch/um/kernel/process.c:160
#31 0x00000000 in ?? ()
format_decode (fmt=0x84b74b8 "+%#lx/%#lx", spec=0x434dfa8c) at lib/vsprintf.c:1375
1375 if (spec->type == FORMAT_TYPE_WIDTH) {
#0 format_decode (fmt=0x84b74b8 "+%#lx/%#lx", spec=0x434dfa8c) at lib/vsprintf.c:1375
#1 0x08295b82 in vsnprintf (buf=0x434dfb19 "", size=2147483647, fmt=0x84b74b8 "+%#lx/%#lx", args=0x434dfac8 "A") at lib/vsprintf.c:1615
#2 0x08296547 in sprintf (buf=0x84b74b8 "+%#lx/%#lx", fmt=0x84b74b8 "+%#lx/%#lx") at lib/vsprintf.c:1875
#3 0x080b76cf in __sprint_symbol (buffer=0x434dfb09 "schedule_timeout", address=1129183884, symbol_offset=1, add_offset=1) at kernel/kallsyms.c:374
#4 0x080b781a in sprint_symbol (buffer=0x434dfb09 "schedule_timeout", address=138496385) at kernel/kallsyms.c:395
#5 0x080b787f in __print_symbol (fmt=0x84b74b8 "+%#lx/%#lx", address=139162808) at kernel/kallsyms.c:440
#6 0x08078200 in print_symbol (fmt=<optimized out>, addr=<optimized out>) at include/linux/kallsyms.h:119
#7 print_context_stack (ebp=<optimized out>, tinfo=<optimized out>, stack=<optimized out>) at arch/x86/um/sysrq_32.c:54
#8 show_trace (task=0x434dfffd, stack=0x434dfc44) at arch/x86/um/sysrq_32.c:95
#9 0x0805fb6f in show_stack (task=0x0, esp=0x434dfc44) at arch/um/kernel/sysrq.c:65
#10 0x08413ae6 in __dump_stack () at lib/dump_stack.c:15
#11 dump_stack () at lib/dump_stack.c:60
#12 0x08414981 in schedule_timeout (timeout=-4028) at kernel/timer.c:1460
#13 0x08416362 in io_schedule_timeout (timeout=139162808) at kernel/sched/core.c:3992
#14 0x08411c31 in balance_dirty_pages (pages_dirtied=17, mapping=<optimized out>) at mm/page-writeback.c:1519
#15 0x080d1ce4 in balance_dirty_pages_ratelimited (mapping=0x11) at mm/page-writeback.c:1653
#16 0x080e2d0c in __do_fault (mm=0x47f24400, vma=0x442095d8, address=1080451072, pmd=0x84b74b8, pgoff=139162808, flags=1155011416, orig_pte=<incomplete type>) at mm/memory.c:3452
#17 0x080e5286 in do_nonlinear_fault (orig_pte=..., flags=<optimized out>, pmd=<optimized out>, address=<optimized out>, vma=<optimized out>, mm=<optimized out>, page_table=<optimized out>) at mm/memory.c:3518
#18 handle_pte_fault (flags=<optimized out>, pmd=<optimized out>, pte=<optimized out>, address=<optimized out>, vma=<optimized out>, mm=<optimized out>) at mm/memory.c:3717
#19 __handle_mm_fault (flags=<optimized out>, address=<optimized out>, vma=<optimized out>, mm=<optimized out>) at mm/memory.c:3845
#20 handle_mm_fault (mm=0x47f24400, vma=0x442095d8, address=1080451072, flags=1) at mm/memory.c:3868
#21 0x080e5a07 in __get_user_pages (tsk=0x46e23600, mm=0x47f24400, start=1080451072, nr_pages=65, gup_flags=519, pages=0x46f34d20, vmas=0x0, nonblocking=0x0) at mm/memory.c:1822
#22 0x080e5cc3 in get_user_pages (tsk=0x84b74b8, mm=0x84b74b8, start=139162808, nr_pages=139162808, write=1, force=0, pages=0x434dfa8c, vmas=0x11) at mm/memory.c:2019
#23 0x08140cce in aio_setup_ring (ctx=<optimized out>) at fs/aio.c:317
#24 ioctx_alloc (nr_events=<optimized out>) at fs/aio.c:582
#25 SYSC_io_setup (ctxp=<optimized out>, nr_events=<optimized out>) at fs/aio.c:1100
#26 SyS_io_setup (nr_events=4095, ctxp=1076256768) at fs/aio.c:1083
#27 0x080619c2 in handle_syscall (r=0x46e237d4) at arch/um/kernel/skas/syscall.c:35
#28 0x08073f2d in handle_trap (local_using_sysemu=<optimized out>, regs=<optimized out>, pid=<optimized out>) at arch/um/os-Linux/skas/process.c:198
#29 userspace (regs=0x46e237d4) at arch/um/os-Linux/skas/process.c:431
#30 0x0805e6ac in fork_handler () at arch/um/kernel/process.c:160
#31 0x00000000 in ?? ()
