On Thu, Oct 10, 2013 at 06:49:30PM +0200, Toralf Förster wrote: > On 10/10/2013 12:33 AM, Richard Weinberger wrote: > > Am 09.10.2013 23:47, schrieb Jan Kara: > >> On Wed 09-10-13 20:43:50, Richard Weinberger wrote: > >>> CC'ing mm folks. > >>> Please see below. > >> Added Fenguang to CC since he is the author of this code. > > > > Thx, get_maintainer.pl didn't list him. > > > >>> Am 09.10.2013 19:26, schrieb Toralf Förster: > >>>> On 10/08/2013 10:07 PM, Geert Uytterhoeven wrote: > >>>>> On Sun, Oct 6, 2013 at 11:01 PM, Toralf Förster > >>>>> <toralf.foers...@gmx.de> wrote: > >>>>>>> Hmm, now pages_dirtied is zero, according to the backtrace, but the > >>>>>>> BUG_ON() > >>>>>>> asserts its strict positive?!? > >>>>>>> > >>>>>>> Can you please try the following instead of the BUG_ON(): > >>>>>>> > >>>>>>> if (pause < 0) { > >>>>>>> printk("pages_dirtied = %lu\n", pages_dirtied); > >>>>>>> printk("task_ratelimit = %lu\n", task_ratelimit); > >>>>>>> printk("pause = %ld\n", pause); > >>>>>>> } > >>>>>>> > >>>>>>> Gr{oetje,eeting}s, > >>>>>>> > >>>>>>> Geert > >>>>>> I tried it in different ways already - I'm completely unsuccessful in > >>>>>> getting any printk output. > >>>>>> As soon as the issue happens I do have a > >>>>>> > >>>>>> BUG: soft lockup - CPU#0 stuck for 22s! [trinity-child0:1521] > >>>>>> > >>>>>> at stderr of the UML and then no further input is accepted. With > >>>>>> uml_mconsole I'm however able > >>>>>> to run very basic commands like a crash dump, sysrq ond so on. > >>>>> > >>>>> You may get an idea of the magnitude of pages_dirtied by using a chain > >>>>> of > >>>>> BUG_ON()s, like: > >>>>> > >>>>> BUG_ON(pages_dirtied > 2000000000); > >>>>> BUG_ON(pages_dirtied > 1000000000); > >>>>> BUG_ON(pages_dirtied > 100000000); > >>>>> BUG_ON(pages_dirtied > 10000000); > >>>>> BUG_ON(pages_dirtied > 1000000); > >>>>> > >>>>> Probably 1 million is already too much for normal operation? > >>>>> > >>>> period = HZ * pages_dirtied / task_ratelimit; > >>>> BUG_ON(pages_dirtied > 2000000000); > >>>> BUG_ON(pages_dirtied > 1000000000); <-------------- this > >>>> is line 1467 > >>> > >>> Summary for mm people: > >>> > >>> Toralf runs trinty on UML/i386. > >>> After some time pages_dirtied becomes very large. > >>> More than 1000000000 pages in this case. > >> Huh, this is really strange. pages_dirtied is passed into > >> balance_dirty_pages() from current->nr_dirtied. So I wonder how a value > >> over 10^9 can get there. After all that is over 4TB so I somewhat doubt the > >> task was ever able to dirty that much during its lifetime (but correct me > >> if I'm wrong here, with UML and memory backed disks it is not totally > >> impossible)... I went through the logic of handling ->nr_dirtied but > >> I didn't find any obvious problem there. Hum, maybe one thing - what > >> 'task_ratelimit' values do you see in balance_dirty_pages? If that one was > >> huge, we could possibly accumulate huge current->nr_dirtied. > > > > Toralf, you can try a snipplet like this one to get the values printed out: > > diff --git a/mm/page-writeback.c b/mm/page-writeback.c > > index f5236f8..a80e520 100644 > > --- a/mm/page-writeback.c > > +++ b/mm/page-writeback.c > > @@ -1463,6 +1463,12 @@ static void balance_dirty_pages(struct address_space > > *mapping, > > goto pause; > > } > > period = HZ * pages_dirtied / task_ratelimit; > > + > > + { > > + extern int printf(char *, ...); > > + printf("---> task_ratelimit: %lu\n", > > task_ratelimit); > > + } > > + > > pause = period; > > if (current->dirty_paused_when) > > pause -= now - current->dirty_paused_when; > > > > > > Yes, printf(), not printk(). > > Using this hack we print directly to host's stdout. :) > > > *head smack* ofc - works fine. > So given this diff : > > iff --git a/mm/page-writeback.c b/mm/page-writeback.c > index f5236f8..5a2c337 100644 > --- a/mm/page-writeback.c > +++ b/mm/page-writeback.c > @@ -1464,6 +1464,13 @@ static void balance_dirty_pages(struct address_space > *mapping, > } > period = HZ * pages_dirtied / task_ratelimit; > pause = period; > + if (pause < 0) { > + extern int printf(char *, ...); > + printf("overflow : pause : %li\n", pause); > + printf("overflow : pages_dirtied : %lu\n", > pages_dirtied); > + printf("overflow : task_ratelimit: %lu\n", > task_ratelimit); > + BUG_ON(1); > + } > if (current->dirty_paused_when) > pause -= now - current->dirty_paused_when; > /* > @@ -1503,6 +1510,13 @@ static void balance_dirty_pages(struct address_space > *mapping, > } > > pause: > + if (pause < 0) {
Oops, we got ick : pause : -984 here! Since pause is bounded by [min_pause, max_pause], it means something goes wrong with the bounds. Would you help print min_pause and max_pause as well? It seems there are "long <=> unsigned long" conversion problems in bdi_max_pause(), which might make max_pause a negative number. And the min_pause calculation is based on max_pause to some degree.. Thanks, Fengguang > + extern int printf(char *, ...); > + printf("ick : pause : %li\n", pause); > + printf("ick: pages_dirtied : %lu\n", pages_dirtied); > + printf("ick: task_ratelimit: %lu\n", task_ratelimit); > + BUG_ON(1); > + } > trace_balance_dirty_pages(bdi, > dirty_thresh, > background_thresh, > > > I got this : > > > > > * Starting local > net.core.warnings = 0 > [ ok ] > ick : pause : -984 > ick: pages_dirtied : 0 > ick: task_ratelimit: 0 > Kernel panic - > not syncing: BUG! > CPU: 0 PID: 1434 Comm: trinity-child2 Not tainted > 3.12.0-rc4-00029-g0e7a3ed-dirty #12 > 47397c84 47397cb0 0841b5a0 084c30e8 085f76e0 084b4745 47397cbc 00000000 > fffffc28 01fff278 085cb4a0 47397d2c 0841c5a0 084b4745 084c5398 > 000005ee > 08432cf0 43e47600 471757f8 47397cf0 ffffff0c 47397cdc 5256d8b9 > 3417ec18 47397c5c: [<08060b2c>] show_stack+0x7c/0xd0 > 47397c7c: [<0841e34d>] dump_stack+0x26/0x28 > 47397c8c: [<0841b5a0>] panic+0x7a/0x180 > 47397cb4: [<0841c5a0>] balance_dirty_pages.isra.32+0x4e3/0x5ad > 47397d30: [<080d3595>] balance_dirty_pages_ratelimited+0xf5/0x100 > 47397d44: [<080e4a3f>] __do_fault+0x3cf/0x440 > 47397d9c: [<080e6e0f>] handle_mm_fault+0xef/0x7c0 > 47397dec: [<080e7817>] __get_user_pages+0x227/0x420 > 47397e24: [<080e7ae3>] get_user_pages+0x63/0x70 > 47397e4c: [<08143dc6>] SyS_io_setup+0x3c6/0x760 > 47397eb0: [<08062984>] handle_syscall+0x64/0x80 > 47397ef0: [<08074fb5>] userspace+0x475/0x5f0 > 47397fec: [<0805f750>] fork_handler+0x60/0x70 > 47397ffc: [<00000000>] 0x0 > > > EIP: 0073:[<40001282>] CPU: 0 Not tainted ESP: 007b:bfb348f8 EFLAGS: 00000246 > Not tainted > EAX: ffffffda EBX: 00001000 ECX: 080d0000 EDX: 80000048 > ESI: 80fbff1f EDI: ffe02f77 EBP: 90f6e2a3 DS: 007b ES: 007b > 47397c0c: [<0807947f>] show_regs+0x10f/0x120 > 47397c28: [<080623a9>] panic_exit+0x29/0x50 > 47397c38: [<0809ba86>] notifier_call_chain+0x36/0x60 > 47397c60: [<0809bba1>] __atomic_notifier_call_chain+0x21/0x30 > 47397c70: [<0809bbdf>] atomic_notifier_call_chain+0x2f/0x40 > 47397c8c: [<0841b5bc>] panic+0x96/0x180 > 47397cb4: [<0841c5a0>] balance_dirty_pages.isra.32+0x4e3/0x5ad > 47397d30: [<080d3595>] balance_dirty_pages_ratelimited+0xf5/0x100 > 47397d44: [<080e4a3f>] __do_fault+0x3cf/0x440 > 47397d9c: [<080e6e0f>] handle_mm_fault+0xef/0x7c0 > 47397dec: [<080e7817>] __get_user_pages+0x227/0x420 > 47397e24: [<080e7ae3>] get_user_pages+0x63/0x70 > 47397e4c: [<08143dc6>] SyS_io_setup+0x3c6/0x760 > 47397eb0: [<08062984>] handle_syscall+0x64/0x80 > 47397ef0: [<08074fb5>] userspace+0x475/0x5f0 > 47397fec: [<0805f750>] fork_handler+0x60/0x70 > 47397ffc: [<00000000>] 0x0 > > /home/tfoerste/workspace/bin/start_uml.sh: line 115: 18718 Aborted > (core dumped) $LINUX earlyprintk ubda=$ROOTFS ubdb=$SWAP eth0=$NET > mem=$MEM $TTY umid=uml_$NAME rootfstype=ext4 "$ARGS" > > > >From what I see there are 2 different types of issues - and this is an > >example of the other of both > > > Thanks, > > //richard > > > > > -- > MfG/Sincerely > Toralf Förster > pgp finger print: 7B1A 07F4 EC82 0F90 D4C2 8936 872A E508 7DB6 9DA3 ------------------------------------------------------------------------------ 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=60134071&iu=/4140/ostg.clktrk _______________________________________________ User-mode-linux-devel mailing list User-mode-linux-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/user-mode-linux-devel