Messages in this thread Patch in this message | | | Date | Sat, 19 Oct 2002 15:09:52 +0200 | From | Mike Galbraith <> | Subject | massive context switching.. how to trap |
| |
Greetings,
While load testing 2.5.43-mm2, I noticed some peculiar context switch storms. (The test load is a make -j30 bzImage. Box is a PIII-500 w. 128MB ram, using gcc 2.95.3) I do not see storms running the same load under 2.5.44.virgin.
Trying narrow down what the heck it could be, I wrote attached diff.txt. Twice, it produced the cleaned/processed output in trace1.txt (near start of build!). One running task with > 100000 context switches/sec seems unlikely, so I suspect I missed the event, and wonder if there's a better way to photograph the little beasty. The output in trace2.txt is pretty typical.. seems to be much scheduling with no place to go.
Ideas on how to better focus my camera?
-Mike--- kernel/sched.c.org Fri Oct 18 14:46:36 2002 +++ kernel/sched.c Sat Oct 19 14:07:08 2002 @@ -954,6 +954,25 @@ prio_array_t *array; struct list_head *queue; int idx; + int now = jiffies; + static int timeout, context; + + if (context++ > 100000) { + struct task_struct * p; + static void show_task(task_t * p); + + read_lock(&tasklist_lock); + for_each_process(p) + if (p->state == TASK_RUNNING) + show_task(p); + read_unlock(&tasklist_lock); + context = 0; + printk("SPACER\n\n"); + } + if (time_after(now, timeout)) { + context = 0; + timeout = now + HZ; + } /* * Test if we are atomic. Since do_exit() needs to call intogcc R C67D4000 0 503 469 (NOTLB) Trace; c0113a87 <sleep_on+5b/84> Trace; c0113700 <default_wake_function+0/34> Trace; c013cf3f <sleep_on_buffer+f/14> Trace; c0174ec5 <do_get_write_access+291/4ec> Trace; c0175167 <journal_get_write_access+47/68> Trace; c016d21a <ext3_reserve_inode_write+32/a8> Trace; c0174574 <start_this_handle+b8/1c0> Trace; c0174635 <start_this_handle+179/1c0> Trace; c016d2aa <ext3_mark_inode_dirty+1a/34> Trace; c016d357 <ext3_dirty_inode+93/100> Trace; c0155b10 <__mark_inode_dirty+30/d8> Trace; c0150d78 <update_atime+48/50> Trace; c0129626 <do_generic_file_read+342/350> Trace; c01299e7 <__generic_file_aio_read+1cb/1e4> Trace; c0129674 <file_read_actor+0/1a8> Trace; c0129a45 <generic_file_aio_read+45/50> Trace; c013b989 <do_sync_read+81/b4> Trace; c0145f20 <do_lookup+18/88> Trace; c014e596 <dput+1a/1b0> Trace; c0130956 <buffered_rmqueue+fa/120> Trace; c013096f <buffered_rmqueue+113/120> Trace; c013ba81 <vfs_read+c5/144> Trace; c014391c <kernel_read+40/4c> Trace; c0144231 <prepare_binprm+ad/b8> Trace; c0144727 <do_execve+13b/250> Trace; c0105acf <sys_execve+2f/60> Trace; c0106f6b <syscall_call+7/b> cc1 R C6F8E000 0 2376 2326 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C4A2E000 0 2377 2344 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C54EC000 4 2566 2553 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C1DD8000 16 2568 2561 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C2C06000 4 2571 2519 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C110A9A0 16 2581 2538 (NOTLB) Trace; c01ad097 <io_schedule+b/14> Trace; c0128e32 <wait_on_page_bit+a2/b8> Trace; c0114a34 <autoremove_wake_function+0/38> Trace; c0114a34 <autoremove_wake_function+0/38> Trace; c0134d56 <shmem_getpage+1a6/518> Trace; c0135a1e <do_shmem_file_read+4e/1a8> Trace; c0135bd6 <shmem_file_read+5e/78> Trace; c013ba81 <vfs_read+c5/144> Trace; c013bd1a <sys_read+2a/3c> Trace; c0106f6b <syscall_call+7/b>
cc1 R C545E000 4 2609 2592 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C1103830 0 2629 2613 (NOTLB) Trace; c01ad097 <io_schedule+b/14> Trace; c0128e32 <wait_on_page_bit+a2/b8> Trace; c0114a34 <autoremove_wake_function+0/38> Trace; c0114a34 <autoremove_wake_function+0/38> Trace; c0134d56 <shmem_getpage+1a6/518> Trace; c0135a1e <do_shmem_file_read+4e/1a8> Trace; c0135bd6 <shmem_file_read+5e/78> Trace; c013ba81 <vfs_read+c5/144> Trace; c013bd1a <sys_read+2a/3c> Trace; c0106f6b <syscall_call+7/b>
cc1 R C10B3C40 4 2706 2692 (NOTLB) Trace; c01ad097 <io_schedule+b/14> Trace; c0128e32 <wait_on_page_bit+a2/b8> Trace; c0114a34 <autoremove_wake_function+0/38> Trace; c0114a34 <autoremove_wake_function+0/38> Trace; c0134d56 <shmem_getpage+1a6/518> Trace; c0135a1e <do_shmem_file_read+4e/1a8> Trace; c0135bd6 <shmem_file_read+5e/78> Trace; c013ba81 <vfs_read+c5/144> Trace; c013bd1a <sys_read+2a/3c> Trace; c0106f6b <syscall_call+7/b>
cc1 R C50A6000 0 2708 2681 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C4860000 4 2733 2731 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
cc1 R C3012000 0 2737 2722 (NOTLB) Trace; c0113824 <user_schedule+8/c> Trace; c0106f92 <work_resched+5/16>
gcc R C6252000 16 2738 2577 (NOTLB) Trace; c0113a87 <sleep_on+5b/84> Trace; c0113700 <default_wake_function+0/34> Trace; c013cf3f <sleep_on_buffer+f/14> Trace; c0174ec5 <do_get_write_access+291/4ec> Trace; c0175167 <journal_get_write_access+47/68> Trace; c016d21a <ext3_reserve_inode_write+32/a8> Trace; c0174574 <start_this_handle+b8/1c0> Trace; c0174635 <start_this_handle+179/1c0> Trace; c016d2aa <ext3_mark_inode_dirty+1a/34> Trace; c016d357 <ext3_dirty_inode+93/100> Trace; c0155b10 <__mark_inode_dirty+30/d8> Trace; c0150d78 <update_atime+48/50> Trace; c0129626 <do_generic_file_read+342/350> Trace; c01299e7 <__generic_file_aio_read+1cb/1e4> Trace; c0129674 <file_read_actor+0/1a8> Trace; c0129a45 <generic_file_aio_read+45/50> Trace; c013b989 <do_sync_read+81/b4> Trace; c011e12e <update_process_times+2a/30> Trace; c011e006 <update_wall_time+12/3c> Trace; c011e2df <do_timer+4b/cc> Trace; c0124a56 <rcu_process_callbacks+de/f8> Trace; c011b149 <tasklet_action+3d/60> Trace; c011afca <do_softirq+5a/ac> Trace; c013ba81 <vfs_read+c5/144> Trace; c014391c <kernel_read+40/4c> Trace; c0144231 <prepare_binprm+ad/b8> Trace; c0144727 <do_execve+13b/250> Trace; c0105acf <sys_execve+2f/60> Trace; c0106f6b <syscall_call+7/b>
| |