lkml.org 
[lkml]   [2002]   [Oct]   [19]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
Date
From
Subjectmassive 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>
\
 
 \ /
  Last update: 2005-03-22 13:30    [W:0.039 / U:0.884 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site