[uml-devel] BUG: soft lockup for a user mode linux image

["Toralf Förster" <toralf.foerster@gmx.de>]

[-- Attachment #1: Type: text/plain, Size: 4232 bytes --]

(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



[-- Attachment #2: 1 --]
[-- Type: text/plain, Size: 4078 bytes --]

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 ?? ()

[-- Attachment #3: 2 --]
[-- Type: text/plain, Size: 3500 bytes --]

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 ?? ()

[-- Attachment #4: Type: text/plain, Size: 416 bytes --]

------------------------------------------------------------------------------
October Webinars: Code for Performance
Free Intel webinars can help you accelerate application performance.
Explore tips for MPI, OpenMP, advanced profiling, and more. Get the most from 
the latest Intel processors and coprocessors. See abstracts and register >
http://pubads.g.doubleclick.net/gampad/clk?id=60134791&iu=/4140/ostg.clktrk

[-- Attachment #5: Type: text/plain, Size: 194 bytes --]

_______________________________________________
User-mode-linux-devel mailing list
User-mode-linux-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel