* finish_task_switch high in profiles in 2.6.7 @ 2004-06-24 9:15 Yusuf Goolamabbas 2004-06-24 9:27 ` Nick Piggin 0 siblings, 1 reply; 15+ messages in thread From: Yusuf Goolamabbas @ 2004-06-24 9:15 UTC (permalink / raw) To: linux-kernel Hi, I have a fairly busy mailserver which also has a simple iptables ruleset (blocking some IP's) running 2.6.7 with the deadline i/o scheduler. vmstat was reporting that system time was around 80%. I did the following readprofile -r ; sleep 240 ; readprofile -n -m /boot/System.map-`uname -r` | sort -rn -k 1,1 | head -22 48036 total 0.2274 9684 finish_task_switch 80.0331 6992 default_idle 158.9091 6335 __wake_up 87.9861 5671 remove_wait_queue 76.6351 4150 add_wait_queue 59.2857 2459 sysenter_past_esp 21.7611 1304 find_get_page 21.0323 1160 __mod_timer 4.1281 938 do_gettimeofday 5.0430 756 del_timer_sync 2.4787 753 del_timer 7.1714 599 handle_IRQ_event 5.9900 570 do_page_fault 0.4612 485 __do_softirq 2.8529 476 do_sigaction 0.9136 469 do_getitimer 1.7055 464 do_setitimer 0.9768 392 get_offset_tsc 17.0435 340 current_kernel_time 4.9275 293 in_group_p 2.4417 272 eligible_child 1.4093 On a 2.6.5 box with a similar workload, the profile is as follows 131202 total 0.3704 42080 fget 667.9365 12868 schedule 8.1084 11231 default_idle 255.2500 9157 fput 436.0476 6642 remove_wait_queue 89.7568 6076 __wake_up 93.4769 5056 page_remove_rmap 13.4111 4144 add_wait_queue 59.2000 2255 fget_light 17.4806 2176 sysenter_past_esp 19.2566 1271 kfree 11.6606 1148 kmem_cache_alloc 14.9091 934 __kmalloc 6.6714 890 __mod_timer 3.1673 768 del_timer_sync 2.9538 717 buffered_rmqueue 1.5621 715 kmem_cache_free 8.2184 613 free_hot_cold_page 2.4618 612 del_timer 5.8286 588 __find_get_block 3.0466 588 do_page_fault 0.4757 I am trying to determine where the system time is going and don't have much zen to begin with. Any assistance would be appreciated ? ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 9:15 finish_task_switch high in profiles in 2.6.7 Yusuf Goolamabbas @ 2004-06-24 9:27 ` Nick Piggin 2004-06-24 9:34 ` Yusuf Goolamabbas 0 siblings, 1 reply; 15+ messages in thread From: Nick Piggin @ 2004-06-24 9:27 UTC (permalink / raw) To: Yusuf Goolamabbas; +Cc: linux-kernel Yusuf Goolamabbas wrote: > Hi, I have a fairly busy mailserver which also has a simple iptables > ruleset (blocking some IP's) running 2.6.7 with the deadline i/o > scheduler. vmstat was reporting that system time was around 80%. I did > the following > > readprofile -r ; sleep 240 ; readprofile -n -m /boot/System.map-`uname > -r` | sort -rn -k 1,1 | head -22 > > 48036 total 0.2274 > 9684 finish_task_switch 80.0331 > 6992 default_idle 158.9091 > 6335 __wake_up 87.9861 > 5671 remove_wait_queue 76.6351 > 4150 add_wait_queue 59.2857 > 2459 sysenter_past_esp 21.7611 > 1304 find_get_page 21.0323 > 1160 __mod_timer 4.1281 > 938 do_gettimeofday 5.0430 > 756 del_timer_sync 2.4787 > 753 del_timer 7.1714 > 599 handle_IRQ_event 5.9900 > 570 do_page_fault 0.4612 > 485 __do_softirq 2.8529 > 476 do_sigaction 0.9136 > 469 do_getitimer 1.7055 > 464 do_setitimer 0.9768 > 392 get_offset_tsc 17.0435 > 340 current_kernel_time 4.9275 > 293 in_group_p 2.4417 > 272 eligible_child 1.4093 > > On a 2.6.5 box with a similar workload, the profile is as follows > > 131202 total 0.3704 > 42080 fget 667.9365 > 12868 schedule 8.1084 > 11231 default_idle 255.2500 > 9157 fput 436.0476 > 6642 remove_wait_queue 89.7568 > 6076 __wake_up 93.4769 > 5056 page_remove_rmap 13.4111 > 4144 add_wait_queue 59.2000 > 2255 fget_light 17.4806 > 2176 sysenter_past_esp 19.2566 > 1271 kfree 11.6606 > 1148 kmem_cache_alloc 14.9091 > 934 __kmalloc 6.6714 > 890 __mod_timer 3.1673 > 768 del_timer_sync 2.9538 > 717 buffered_rmqueue 1.5621 > 715 kmem_cache_free 8.2184 > 613 free_hot_cold_page 2.4618 > 612 del_timer 5.8286 > 588 __find_get_block 3.0466 > 588 do_page_fault 0.4757 > > I am trying to determine where the system time is going and don't have > much zen to begin with. Any assistance would be appreciated ? > Is it an SMP system? What sort of workload is it? Does it use threads? Check vmstat to see how much context switching is going on with each kernel. Thanks. ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 9:27 ` Nick Piggin @ 2004-06-24 9:34 ` Yusuf Goolamabbas 2004-06-24 9:45 ` Nick Piggin 2004-06-24 14:30 ` William Lee Irwin III 0 siblings, 2 replies; 15+ messages in thread From: Yusuf Goolamabbas @ 2004-06-24 9:34 UTC (permalink / raw) To: Nick Piggin; +Cc: linux-kernel > Is it an SMP system? What sort of workload is it? Does it use threads? > Check vmstat to see how much context switching is going on with each > kernel. Yes, It's an SMP (Dual P3-800). Workload is a busy mailserver (get lots of SMTP traffic, validate users against a remote database, reject a truckload of connections). CONFIG_4K_STACKS=y on the 2.6.7 box, e100 driver with NAPI turned off. No threads The 2.6.7 box shows this wrt context swithes procs memory swap io system cpu r b swpd free buff cache si so bi bo in cs us sy wa id 3 0 0 73096 63000 78100 0 0 0 524 5571 14772 25 73 0 2 6 0 0 70932 63000 78100 0 0 0 448 5861 11368 34 65 0 1 7 0 0 72916 63008 78092 0 0 0 12 5838 14956 30 70 0 1 7 0 0 70852 63016 78084 0 0 0 1008 5551 13951 30 69 0 1 22 0 0 65300 63016 78084 0 0 0 0 5989 16043 34 66 0 1 19 0 0 66516 63020 78148 0 0 0 1252 6100 14653 31 69 0 0 29 1 0 67620 63024 78212 0 0 0 992 6314 14747 31 69 0 0 The 2.6.5 box shows this procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu---- r b swpd free buff cache si so bi bo in cs us sy id wa 166 0 0 137752 38148 188836 0 0 0 2424 5973 21695 30 70 0 0 34 0 0 135928 38160 189028 0 0 0 2160 5923 22532 32 68 0 0 28 1 0 136928 38184 189344 0 0 0 2904 6393 22098 31 69 0 0 32 1 0 136672 38204 189324 0 0 0 3240 6412 21362 32 68 0 0 33 0 0 135456 38216 189380 0 0 0 1708 6044 24735 28 72 0 0 17 0 0 135372 38264 189536 0 0 0 3044 6305 22326 35 64 0 0 229 0 0 135060 38272 189732 0 0 0 2340 6416 23697 33 67 0 0 32 0 0 134100 38288 189852 0 0 0 3068 6342 24016 33 67 0 0 16 0 0 134292 38300 190044 0 0 0 2408 6451 24727 31 69 0 0 ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 9:34 ` Yusuf Goolamabbas @ 2004-06-24 9:45 ` Nick Piggin 2004-06-24 10:05 ` Yusuf Goolamabbas 2004-06-24 14:30 ` William Lee Irwin III 1 sibling, 1 reply; 15+ messages in thread From: Nick Piggin @ 2004-06-24 9:45 UTC (permalink / raw) To: Yusuf Goolamabbas; +Cc: linux-kernel Yusuf Goolamabbas wrote: >>Is it an SMP system? What sort of workload is it? Does it use threads? >>Check vmstat to see how much context switching is going on with each >>kernel. > > > Yes, It's an SMP (Dual P3-800). Workload is a busy mailserver (get lots > of SMTP traffic, validate users against a remote database, reject a > truckload of connections). CONFIG_4K_STACKS=y on the 2.6.7 box, e100 > driver with NAPI turned off. No threads > OK > The 2.6.7 box shows this wrt context swithes > > procs memory swap io system cpu > r b swpd free buff cache si so bi bo in cs us sy wa id > 3 0 0 73096 63000 78100 0 0 0 524 5571 14772 25 73 0 2 > 6 0 0 70932 63000 78100 0 0 0 448 5861 11368 34 65 0 1 > 7 0 0 72916 63008 78092 0 0 0 12 5838 14956 30 70 0 1 > 7 0 0 70852 63016 78084 0 0 0 1008 5551 13951 30 69 0 1 > 22 0 0 65300 63016 78084 0 0 0 0 5989 16043 34 66 0 1 > 19 0 0 66516 63020 78148 0 0 0 1252 6100 14653 31 69 0 0 > 29 1 0 67620 63024 78212 0 0 0 992 6314 14747 31 69 0 0 > > The 2.6.5 box shows this > > procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu---- > r b swpd free buff cache si so bi bo in cs us sy id wa > 166 0 0 137752 38148 188836 0 0 0 2424 5973 21695 30 70 0 0 > 34 0 0 135928 38160 189028 0 0 0 2160 5923 22532 32 68 0 0 > 28 1 0 136928 38184 189344 0 0 0 2904 6393 22098 31 69 0 0 > 32 1 0 136672 38204 189324 0 0 0 3240 6412 21362 32 68 0 0 > 33 0 0 135456 38216 189380 0 0 0 1708 6044 24735 28 72 0 0 > 17 0 0 135372 38264 189536 0 0 0 3044 6305 22326 35 64 0 0 > 229 0 0 135060 38272 189732 0 0 0 2340 6416 23697 33 67 0 0 32 0 0 134100 38288 189852 0 0 0 3068 6342 24016 33 67 0 0 > 16 0 0 134292 38300 190044 0 0 0 2408 6451 24727 31 69 0 0 > OK. They're both using 100% CPU... is 2.6.5 getting more work done? ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 9:45 ` Nick Piggin @ 2004-06-24 10:05 ` Yusuf Goolamabbas 2004-06-24 10:10 ` Nick Piggin 0 siblings, 1 reply; 15+ messages in thread From: Yusuf Goolamabbas @ 2004-06-24 10:05 UTC (permalink / raw) To: Nick Piggin; +Cc: linux-kernel > OK. They're both using 100% CPU... is 2.6.5 getting more work done? So far, it looks like both are doing similar amount of work. am getting more measurements from other boxes My concern was the high system usage, I had suspected that it might have been due interrupts generated on the NIC. This was not evident in the profile I generated Regards, Yusuf ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 10:05 ` Yusuf Goolamabbas @ 2004-06-24 10:10 ` Nick Piggin 0 siblings, 0 replies; 15+ messages in thread From: Nick Piggin @ 2004-06-24 10:10 UTC (permalink / raw) To: Yusuf Goolamabbas; +Cc: linux-kernel Yusuf Goolamabbas wrote: >>OK. They're both using 100% CPU... is 2.6.5 getting more work done? > > > So far, it looks like both are doing similar amount of work. am getting > more measurements from other boxes > > My concern was the high system usage, I had suspected that it might have > been due interrupts generated on the NIC. This was not evident in the > profile I generated > OK, keep me CCed on any further developments. In particular if context switches are up or performance is down. Thanks Nick ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 9:34 ` Yusuf Goolamabbas 2004-06-24 9:45 ` Nick Piggin @ 2004-06-24 14:30 ` William Lee Irwin III 2004-06-24 15:33 ` William Lee Irwin III 1 sibling, 1 reply; 15+ messages in thread From: William Lee Irwin III @ 2004-06-24 14:30 UTC (permalink / raw) To: Yusuf Goolamabbas; +Cc: Nick Piggin, linux-kernel On Thu, Jun 24, 2004 at 05:34:40PM +0800, Yusuf Goolamabbas wrote: > Yes, It's an SMP (Dual P3-800). Workload is a busy mailserver (get lots > of SMTP traffic, validate users against a remote database, reject a > truckload of connections). CONFIG_4K_STACKS=y on the 2.6.7 box, e100 > driver with NAPI turned off. No threads > The 2.6.7 box shows this wrt context swithes > procs memory swap io system cpu > r b swpd free buff cache si so bi bo in cs us sy wa id > 19 0 0 66516 63020 78148 0 0 0 1252 6100 14653 31 69 0 0 > 22 0 0 65300 63016 78084 0 0 0 0 5989 16043 34 66 0 1 > 29 1 0 67620 63024 78212 0 0 0 992 6314 14747 31 69 0 0 > The 2.6.5 box shows this > procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu---- > r b swpd free buff cache si so bi bo in cs us sy id wa > 34 0 0 135928 38160 189028 0 0 0 2160 5923 22532 32 68 0 0 > 166 0 0 137752 38148 188836 0 0 0 2424 5973 21695 30 70 0 0 > 229 0 0 135060 38272 189732 0 0 0 2340 6416 23697 33 67 0 0 32 0 0 134100 38288 189852 0 0 0 3068 6342 24016 33 67 0 0 This doesn't look like very intense context switching in either case. 2.6.7 appears to be doing less context switching. I don't see a significant difference in system time, either. Could you please send me complete profiles? -- wli ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 14:30 ` William Lee Irwin III @ 2004-06-24 15:33 ` William Lee Irwin III 0 siblings, 0 replies; 15+ messages in thread From: William Lee Irwin III @ 2004-06-24 15:33 UTC (permalink / raw) To: Yusuf Goolamabbas, Nick Piggin, linux-kernel On Thu, Jun 24, 2004 at 07:30:00AM -0700, William Lee Irwin III wrote: > This doesn't look like very intense context switching in either case. 2.6.7 > appears to be doing less context switching. I don't see a significant > difference in system time, either. > Could you please send me complete profiles? $ awk '{ A[$2] = $1 } END { tot = A["total"]; for (x in A) { if (x != "total") { printf "%4.4f\t%s\n", 100.0*A[x]/tot, x } } }' < /tmp/yusuf-2.6.5 |sort -k 2,2 > /tmp/scaled-2.6.5 $ awk '{ A[$2] = $1 } END { tot = A["total"]; for (x in A) { if (x != "total") { printf "%4.4f\t%s\n", 100.0*A[x]/tot, x } } }' < /tmp/yusuf-2.6.7 |sort -k 2,2 > /tmp/scaled-2.6.7 $ join -1 2 -2 2 -e 0 -a 1 -a 2 /tmp/scaled-2.6.5 /tmp/scaled-2.6.7 | awk 'BEGIN { printf "%%before %%after %%diff func\n" } { A[$1] = $3 ; B[$1] = $2 ; D[$1] = $3 - $2 } END { n = 0; for (x in D) { ++n }; while (n != 0) { z = -1000.0; for (x in D) { if (D[x] > z) { y = x; z = A[x] } }; printf "%8.4f %8.4f %8.4f %s\n", B[y], A[y], D[y], y; delete D[y]; delete A[y]; delete B[y]; --n }; }' %before %after %diff func 0.0000 20.1599 20.1599 finish_task_switch 5.0624 11.8057 6.7433 remove_wait_queue 3.1585 8.6394 5.4809 add_wait_queue 4.6310 13.1880 8.5570 __wake_up 8.5601 14.5557 5.9956 default_idle 1.6585 5.1191 3.4606 sysenter_past_esp 0.0000 2.7146 2.7146 find_get_page 0.6783 2.4149 1.7366 __mod_timer 0.0000 1.9527 1.9527 do_gettimeofday 0.0000 1.2470 1.2470 handle_IRQ_event 0.0000 1.1866 1.1866 do_page_fault 0.4665 1.5676 1.1011 del_timer 0.0000 1.0097 1.0097 __do_softirq 0.0000 0.9909 0.9909 do_sigaction 0.5854 1.5738 0.9884 del_timer_sync 0.0000 0.9764 0.9764 do_getitimer 0.0000 0.9659 0.9659 do_setitimer 0.0000 0.8161 0.8161 get_offset_tsc 0.0000 0.7078 0.7078 current_kernel_time 0.0000 0.6100 0.6100 in_group_p 9.8078 0.0000 -9.8078 schedule 3.8536 0.0000 -3.8536 page_remove_rmap 0.4672 0.0000 -0.4672 free_hot_cold_page 0.4482 0.0000 -0.4482 __find_get_block 0.7119 0.0000 -0.7119 __kmalloc 6.9793 0.0000 -6.9793 fput 32.0727 0.0000 -32.0727 fget 0.5465 0.0000 -0.5465 buffered_rmqueue 0.5450 0.0000 -0.5450 kmem_cache_free 0.8750 0.0000 -0.8750 kmem_cache_alloc 0.9687 0.0000 -0.9687 kfree 1.7187 0.0000 -1.7187 fget_light ^ permalink raw reply [flat|nested] 15+ messages in thread
[parent not found: <2ayz2-1Um-15@gated-at.bofh.it>]
* Re: finish_task_switch high in profiles in 2.6.7 [not found] <2ayz2-1Um-15@gated-at.bofh.it> @ 2004-06-24 10:25 ` Andi Kleen 2004-06-24 10:44 ` Yusuf Goolamabbas 0 siblings, 1 reply; 15+ messages in thread From: Andi Kleen @ 2004-06-24 10:25 UTC (permalink / raw) To: Yusuf Goolamabbas; +Cc: linux-kernel Yusuf Goolamabbas <yusufg@outblaze.com> writes: > Hi, I have a fairly busy mailserver which also has a simple iptables > ruleset (blocking some IP's) running 2.6.7 with the deadline i/o > scheduler. vmstat was reporting that system time was around 80%. I did > the following How many context switches do you get in vmstat? Most likely you just have far too many of them. readprofile will attribute most of the cost to finish_task_switch, because that one reenables the interrupts (and the profiling only works with interrupts on) Too many context switches are usually caused by user space. -Andi ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 10:25 ` Andi Kleen @ 2004-06-24 10:44 ` Yusuf Goolamabbas 2004-06-24 11:36 ` Andi Kleen 0 siblings, 1 reply; 15+ messages in thread From: Yusuf Goolamabbas @ 2004-06-24 10:44 UTC (permalink / raw) To: Andi Kleen; +Cc: linux-kernel > How many context switches do you get in vmstat? Mentioned in a subsequent message http://marc.theaimsgroup.com/?l=linux-kernel&m=108806991921498&w=2 > Most likely you just have far too many of them. readprofile will attribute > most of the cost to finish_task_switch, because that one reenables the > interrupts (and the profiling only works with interrupts on) > > Too many context switches are usually caused by user space. Hmm, Is there a way to determine which syscall would be the culprit. I guess this is where something like DTrace would be invaluable http://www.sun.com/bigadmin/content/dtrace/ ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 10:44 ` Yusuf Goolamabbas @ 2004-06-24 11:36 ` Andi Kleen 2004-06-24 14:05 ` William Lee Irwin III 0 siblings, 1 reply; 15+ messages in thread From: Andi Kleen @ 2004-06-24 11:36 UTC (permalink / raw) To: Yusuf Goolamabbas; +Cc: Andi Kleen, linux-kernel > Hmm, Is there a way to determine which syscall would be the culprit. I > guess this is where something like DTrace would be invaluable Find out which program does it (most likely those with the most system time) and then strace it. > > http://www.sun.com/bigadmin/content/dtrace/ Sounds like a inferior clone of dprobes to me. But I doubt it would help tracking this down. -Andi ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 11:36 ` Andi Kleen @ 2004-06-24 14:05 ` William Lee Irwin III 2004-06-24 21:22 ` William Lee Irwin III 0 siblings, 1 reply; 15+ messages in thread From: William Lee Irwin III @ 2004-06-24 14:05 UTC (permalink / raw) To: Andi Kleen; +Cc: Yusuf Goolamabbas, linux-kernel On Thu, Jun 24, 2004 at 01:36:08PM +0200, Andi Kleen wrote: > Sounds like a inferior clone of dprobes to me. But I doubt it > would help tracking this down. The schedprof thing I wrote to track down the source of context switches during database creation may prove useful, since it has at least demonstrated where thundering herds came from properly once before and is damn near idiotproof -- it requires no more than readprofile(1) from userspace. I'll dredge that up again and maybe we'll see if it helps here. It will also properly point to sys_sched_yield() and the like in the event of badly-behaved userspace. -- wli ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 14:05 ` William Lee Irwin III @ 2004-06-24 21:22 ` William Lee Irwin III 2004-06-24 21:56 ` William Lee Irwin III 0 siblings, 1 reply; 15+ messages in thread From: William Lee Irwin III @ 2004-06-24 21:22 UTC (permalink / raw) To: Andi Kleen, Yusuf Goolamabbas, linux-kernel On Thu, Jun 24, 2004 at 07:05:39AM -0700, William Lee Irwin III wrote: > The schedprof thing I wrote to track down the source of context > switches during database creation may prove useful, since it has > at least demonstrated where thundering herds came from properly once > before and is damn near idiotproof -- it requires no more than > readprofile(1) from userspace. I'll dredge that up again and maybe > we'll see if it helps here. It will also properly point to > sys_sched_yield() and the like in the event of badly-behaved userspace. Brute-force port of schedprof to 2.6.7-final. Compiletested on sparc64 only. No runtime testing. Given that the context switch rate is actually *reduced* in 2.6.7 vs. 2.6.5, I expect that this will not, in fact, reveal anything useful. -- wli Index: schedprof-2.6.7/include/linux/sched.h =================================================================== --- schedprof-2.6.7.orig/include/linux/sched.h 2004-06-15 22:18:57.000000000 -0700 +++ schedprof-2.6.7/include/linux/sched.h 2004-06-24 14:02:48.273041152 -0700 @@ -180,7 +180,11 @@ #define MAX_SCHEDULE_TIMEOUT LONG_MAX extern signed long FASTCALL(schedule_timeout(signed long timeout)); +extern signed long FASTCALL(__schedule_timeout(signed long timeout)); asmlinkage void schedule(void); +asmlinkage void __schedule(void); +void __sched_profile(void *); +#define sched_profile() __sched_profile(__builtin_return_address(0)) struct namespace; Index: schedprof-2.6.7/include/linux/profile.h =================================================================== --- schedprof-2.6.7.orig/include/linux/profile.h 2004-06-15 22:19:22.000000000 -0700 +++ schedprof-2.6.7/include/linux/profile.h 2004-06-24 14:02:48.275040848 -0700 @@ -13,6 +13,7 @@ /* init basic kernel profiler */ void __init profile_init(void); +void schedprof_init(void); extern unsigned int * prof_buffer; extern unsigned long prof_len; Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-15 22:19:51.000000000 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 14:02:48.292038264 -0700 @@ -2181,7 +2181,7 @@ /* * schedule() is the main scheduler function. */ -asmlinkage void __sched schedule(void) +asmlinkage void __sched __schedule(void) { long *switch_count; task_t *prev, *next; @@ -2317,6 +2317,11 @@ goto need_resched; } +asmlinkage void __sched schedule(void) +{ + sched_profile(); + __schedule(); +} EXPORT_SYMBOL(schedule); #ifdef CONFIG_PREEMPT @@ -2338,7 +2343,8 @@ need_resched: ti->preempt_count = PREEMPT_ACTIVE; - schedule(); + sched_profile(); + __schedule(); ti->preempt_count = 0; /* we could miss a preemption opportunity between schedule and now */ @@ -2476,7 +2482,8 @@ do { __set_current_state(TASK_UNINTERRUPTIBLE); spin_unlock_irq(&x->wait.lock); - schedule(); + sched_profile(); + __schedule(); spin_lock_irq(&x->wait.lock); } while (!x->done); __remove_wait_queue(&x->wait, &wait); @@ -2508,7 +2515,8 @@ current->state = TASK_INTERRUPTIBLE; SLEEP_ON_HEAD - schedule(); + sched_profile(); + __schedule(); SLEEP_ON_TAIL } @@ -2521,7 +2529,8 @@ current->state = TASK_INTERRUPTIBLE; SLEEP_ON_HEAD - timeout = schedule_timeout(timeout); + sched_profile(); + timeout = __schedule_timeout(timeout); SLEEP_ON_TAIL return timeout; @@ -2536,7 +2545,8 @@ current->state = TASK_UNINTERRUPTIBLE; SLEEP_ON_HEAD - schedule(); + sched_profile(); + __schedule(); SLEEP_ON_TAIL } @@ -2549,7 +2559,8 @@ current->state = TASK_UNINTERRUPTIBLE; SLEEP_ON_HEAD - timeout = schedule_timeout(timeout); + sched_profile(); + timeout = __schedule_timeout(timeout); SLEEP_ON_TAIL return timeout; @@ -2987,7 +2998,7 @@ * to the expired array. If there are no other threads running on this * CPU then this function will return. */ -asmlinkage long sys_sched_yield(void) +static long sched_yield(void) { runqueue_t *rq = this_rq_lock(); prio_array_t *array = current->array; @@ -3013,15 +3024,22 @@ _raw_spin_unlock(&rq->lock); preempt_enable_no_resched(); - schedule(); + __schedule(); return 0; } +asmlinkage long sys_sched_yield(void) +{ + __sched_profile(sys_sched_yield); + return sched_yield(); +} + void __sched __cond_resched(void) { set_current_state(TASK_RUNNING); - schedule(); + sched_profile(); + __schedule(); } EXPORT_SYMBOL(__cond_resched); @@ -3035,7 +3053,8 @@ void __sched yield(void) { set_current_state(TASK_RUNNING); - sys_sched_yield(); + sched_profile(); + sched_yield(); } EXPORT_SYMBOL(yield); @@ -3052,7 +3071,8 @@ struct runqueue *rq = this_rq(); atomic_inc(&rq->nr_iowait); - schedule(); + sched_profile(); + __schedule(); atomic_dec(&rq->nr_iowait); } @@ -3064,7 +3084,8 @@ long ret; atomic_inc(&rq->nr_iowait); - ret = schedule_timeout(timeout); + sched_profile(); + ret = __schedule_timeout(timeout); atomic_dec(&rq->nr_iowait); return ret; } @@ -4029,3 +4050,93 @@ EXPORT_SYMBOL(__preempt_write_lock); #endif /* defined(CONFIG_SMP) && defined(CONFIG_PREEMPT) */ + +static atomic_t *schedprof_buf; +static int sched_profiling; +static unsigned long schedprof_len; + +#include <linux/bootmem.h> +#include <asm/sections.h> + +void __sched_profile(void *__pc) +{ + if (schedprof_buf) { + unsigned long pc = (unsigned long)__pc; + pc -= min(pc, (unsigned long)_stext); + atomic_inc(&schedprof_buf[min(pc, schedprof_len)]); + } +} + +static int __init schedprof_setup(char *s) +{ + int n; + if (get_option(&s, &n)) + sched_profiling = 1; + return 1; +} +__setup("schedprof=", schedprof_setup); + +void __init schedprof_init(void) +{ + if (!sched_profiling) + return; + schedprof_len = (unsigned long)(_etext - _stext) + 1; + schedprof_buf = alloc_bootmem(schedprof_len*sizeof(atomic_t)); + printk(KERN_INFO "Scheduler call profiling enabled\n"); +} + +#ifdef CONFIG_PROC_FS +#include <linux/proc_fs.h> + +static ssize_t +read_sched_profile(struct file *file, char __user *buf, size_t count, loff_t *ppos) +{ + unsigned long p = *ppos; + ssize_t read; + char * pnt; + unsigned int sample_step = 1; + + if (p >= (schedprof_len+1)*sizeof(atomic_t)) + return 0; + if (count > (schedprof_len+1)*sizeof(atomic_t) - p) + count = (schedprof_len+1)*sizeof(atomic_t) - p; + read = 0; + + while (p < sizeof(atomic_t) && count > 0) { + put_user(*((char *)(&sample_step)+p),buf); + buf++; p++; count--; read++; + } + pnt = (char *)schedprof_buf + p - sizeof(atomic_t); + if (copy_to_user(buf,(void *)pnt,count)) + return -EFAULT; + read += count; + *ppos += read; + return read; +} + +static ssize_t write_sched_profile(struct file *file, const char __user *buf, + size_t count, loff_t *ppos) +{ + memset(schedprof_buf, 0, sizeof(atomic_t)*schedprof_len); + return count; +} + +static struct file_operations sched_profile_operations = { + .read = read_sched_profile, + .write = write_sched_profile, +}; + +static int proc_schedprof_init(void) +{ + struct proc_dir_entry *entry; + if (!sched_profiling) + return 1; + entry = create_proc_entry("schedprof", S_IWUSR | S_IRUGO, NULL); + if (entry) { + entry->proc_fops = &sched_profile_operations; + entry->size = sizeof(atomic_t)*(schedprof_len + 1); + } + return !!entry; +} +module_init(proc_schedprof_init); +#endif Index: schedprof-2.6.7/kernel/timer.c =================================================================== --- schedprof-2.6.7.orig/kernel/timer.c 2004-06-15 22:19:52.000000000 -0700 +++ schedprof-2.6.7/kernel/timer.c 2004-06-24 14:03:30.242660800 -0700 @@ -1100,7 +1100,7 @@ * * In all cases the return value is guaranteed to be non-negative. */ -fastcall signed long __sched schedule_timeout(signed long timeout) +fastcall signed long __sched __schedule_timeout(signed long timeout) { struct timer_list timer; unsigned long expire; @@ -1115,7 +1115,7 @@ * but I' d like to return a valid offset (>=0) to allow * the caller to do everything it want with the retval. */ - schedule(); + __schedule(); goto out; default: /* @@ -1143,7 +1143,7 @@ timer.function = process_timeout; add_timer(&timer); - schedule(); + __schedule(); del_singleshot_timer_sync(&timer); timeout = expire - jiffies; @@ -1152,6 +1152,11 @@ return timeout < 0 ? 0 : timeout; } +fastcall signed long __sched schedule_timeout(signed long timeout) +{ + sched_profile(); + return __schedule_timeout(timeout); +} EXPORT_SYMBOL(schedule_timeout); /* Thread ID - the internal kernel "pid" */ Index: schedprof-2.6.7/arch/alpha/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/alpha/kernel/semaphore.c 2004-06-15 22:19:23.000000000 -0700 +++ schedprof-2.6.7/arch/alpha/kernel/semaphore.c 2004-06-24 14:02:48.302036744 -0700 @@ -66,7 +66,6 @@ { struct task_struct *tsk = current; DECLARE_WAITQUEUE(wait, tsk); - #ifdef CONFIG_DEBUG_SEMAPHORE printk("%s(%d): down failed(%p)\n", tsk->comm, tsk->pid, sem); @@ -83,7 +82,8 @@ * that we are asleep, and then sleep. */ while (__sem_update_count(sem, -1) <= 0) { - schedule(); + sched_profile(); + __schedule(); set_task_state(tsk, TASK_UNINTERRUPTIBLE); } remove_wait_queue(&sem->wait, &wait); @@ -108,7 +108,6 @@ struct task_struct *tsk = current; DECLARE_WAITQUEUE(wait, tsk); long ret = 0; - #ifdef CONFIG_DEBUG_SEMAPHORE printk("%s(%d): down failed(%p)\n", tsk->comm, tsk->pid, sem); @@ -129,7 +128,8 @@ ret = -EINTR; break; } - schedule(); + sched_profile(); + __schedule(); set_task_state(tsk, TASK_INTERRUPTIBLE); } Index: schedprof-2.6.7/arch/arm/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/arm/kernel/semaphore.c 2004-06-15 22:19:17.000000000 -0700 +++ schedprof-2.6.7/arch/arm/kernel/semaphore.c 2004-06-24 14:02:48.308035832 -0700 @@ -78,8 +78,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_UNINTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } @@ -128,8 +128,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_INTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } Index: schedprof-2.6.7/arch/arm26/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/arm26/kernel/semaphore.c 2004-06-15 22:19:02.000000000 -0700 +++ schedprof-2.6.7/arch/arm26/kernel/semaphore.c 2004-06-24 14:02:48.310035528 -0700 @@ -79,8 +79,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_UNINTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } @@ -129,8 +129,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_INTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } Index: schedprof-2.6.7/arch/cris/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/cris/kernel/semaphore.c 2004-06-15 22:19:11.000000000 -0700 +++ schedprof-2.6.7/arch/cris/kernel/semaphore.c 2004-06-24 14:02:48.312035224 -0700 @@ -101,7 +101,8 @@ DOWN_HEAD(TASK_UNINTERRUPTIBLE) if (waking_non_zero(sem)) break; - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_UNINTERRUPTIBLE) } @@ -119,7 +120,8 @@ ret = 0; break; } - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_INTERRUPTIBLE) return ret; } Index: schedprof-2.6.7/arch/h8300/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/h8300/kernel/semaphore.c 2004-06-15 22:19:36.000000000 -0700 +++ schedprof-2.6.7/arch/h8300/kernel/semaphore.c 2004-06-24 14:02:48.314034920 -0700 @@ -103,7 +103,8 @@ DOWN_HEAD(TASK_UNINTERRUPTIBLE) if (waking_non_zero(sem)) break; - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_UNINTERRUPTIBLE) } @@ -122,7 +123,8 @@ ret = 0; break; } - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_INTERRUPTIBLE) return ret; } Index: schedprof-2.6.7/arch/i386/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/i386/kernel/semaphore.c 2004-06-15 22:19:17.000000000 -0700 +++ schedprof-2.6.7/arch/i386/kernel/semaphore.c 2004-06-24 14:02:48.316034616 -0700 @@ -79,8 +79,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irqrestore(&sem->wait.lock, flags); - - schedule(); + sched_profile(); + __schedule(); spin_lock_irqsave(&sem->wait.lock, flags); tsk->state = TASK_UNINTERRUPTIBLE; @@ -132,8 +132,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irqrestore(&sem->wait.lock, flags); - - schedule(); + sched_profile(); + __schedule(); spin_lock_irqsave(&sem->wait.lock, flags); tsk->state = TASK_INTERRUPTIBLE; Index: schedprof-2.6.7/arch/ia64/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/ia64/kernel/semaphore.c 2004-06-15 22:19:17.000000000 -0700 +++ schedprof-2.6.7/arch/ia64/kernel/semaphore.c 2004-06-24 14:02:48.318034312 -0700 @@ -70,8 +70,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irqrestore(&sem->wait.lock, flags); - - schedule(); + sched_profile(); + __schedule(); spin_lock_irqsave(&sem->wait.lock, flags); tsk->state = TASK_UNINTERRUPTIBLE; @@ -123,8 +123,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irqrestore(&sem->wait.lock, flags); - - schedule(); + sched_profile(); + __schedule(); spin_lock_irqsave(&sem->wait.lock, flags); tsk->state = TASK_INTERRUPTIBLE; Index: schedprof-2.6.7/arch/m68k/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/m68k/kernel/semaphore.c 2004-06-15 22:19:43.000000000 -0700 +++ schedprof-2.6.7/arch/m68k/kernel/semaphore.c 2004-06-24 14:02:48.320034008 -0700 @@ -103,7 +103,8 @@ DOWN_HEAD(TASK_UNINTERRUPTIBLE) if (waking_non_zero(sem)) break; - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_UNINTERRUPTIBLE) } @@ -122,7 +123,8 @@ ret = 0; break; } - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_INTERRUPTIBLE) return ret; } Index: schedprof-2.6.7/arch/m68knommu/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/m68knommu/kernel/semaphore.c 2004-06-15 22:20:26.000000000 -0700 +++ schedprof-2.6.7/arch/m68knommu/kernel/semaphore.c 2004-06-24 14:02:48.321033856 -0700 @@ -104,7 +104,8 @@ DOWN_HEAD(TASK_UNINTERRUPTIBLE) if (waking_non_zero(sem)) break; - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_UNINTERRUPTIBLE) } @@ -123,7 +124,8 @@ ret = 0; break; } - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_INTERRUPTIBLE) return ret; } Index: schedprof-2.6.7/arch/mips/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/mips/kernel/semaphore.c 2004-06-15 22:19:37.000000000 -0700 +++ schedprof-2.6.7/arch/mips/kernel/semaphore.c 2004-06-24 14:02:48.323033552 -0700 @@ -132,7 +132,8 @@ for (;;) { if (waking_non_zero(sem)) break; - schedule(); + sched_profile(); + __schedule(); __set_current_state(TASK_UNINTERRUPTIBLE); } __set_current_state(TASK_RUNNING); @@ -261,7 +262,8 @@ ret = 0; break; } - schedule(); + sched_profile(); + __schedule(); __set_current_state(TASK_INTERRUPTIBLE); } __set_current_state(TASK_RUNNING); Index: schedprof-2.6.7/arch/parisc/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/parisc/kernel/semaphore.c 2004-06-15 22:19:43.000000000 -0700 +++ schedprof-2.6.7/arch/parisc/kernel/semaphore.c 2004-06-24 14:02:48.325033248 -0700 @@ -68,7 +68,8 @@ /* we can _read_ this without the sentry */ if (sem->count != -1) break; - schedule(); + sched_profile(); + __schedule(); } DOWN_TAIL @@ -89,7 +90,8 @@ ret = -EINTR; break; } - schedule(); + sched_profile(); + __schedule(); } DOWN_TAIL Index: schedprof-2.6.7/arch/ppc/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/ppc/kernel/semaphore.c 2004-06-15 22:19:44.000000000 -0700 +++ schedprof-2.6.7/arch/ppc/kernel/semaphore.c 2004-06-24 14:02:48.327032944 -0700 @@ -86,7 +86,8 @@ * that we are asleep, and then sleep. */ while (__sem_update_count(sem, -1) <= 0) { - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_UNINTERRUPTIBLE; } remove_wait_queue(&sem->wait, &wait); @@ -121,7 +122,8 @@ retval = -EINTR; break; } - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_INTERRUPTIBLE; } tsk->state = TASK_RUNNING; Index: schedprof-2.6.7/arch/ppc64/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/ppc64/kernel/semaphore.c 2004-06-15 22:18:57.000000000 -0700 +++ schedprof-2.6.7/arch/ppc64/kernel/semaphore.c 2004-06-24 14:02:48.329032640 -0700 @@ -86,7 +86,8 @@ * that we are asleep, and then sleep. */ while (__sem_update_count(sem, -1) <= 0) { - schedule(); + sched_profile(); + __schedule(); set_task_state(tsk, TASK_UNINTERRUPTIBLE); } remove_wait_queue(&sem->wait, &wait); @@ -120,7 +121,8 @@ retval = -EINTR; break; } - schedule(); + sched_profile(); + __schedule(); set_task_state(tsk, TASK_INTERRUPTIBLE); } remove_wait_queue(&sem->wait, &wait); Index: schedprof-2.6.7/arch/s390/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/s390/kernel/semaphore.c 2004-06-15 22:20:03.000000000 -0700 +++ schedprof-2.6.7/arch/s390/kernel/semaphore.c 2004-06-24 14:02:48.331032336 -0700 @@ -69,7 +69,8 @@ __set_task_state(tsk, TASK_UNINTERRUPTIBLE); add_wait_queue_exclusive(&sem->wait, &wait); while (__sem_update_count(sem, -1) <= 0) { - schedule(); + sched_profile(); + __schedule(); set_task_state(tsk, TASK_UNINTERRUPTIBLE); } remove_wait_queue(&sem->wait, &wait); @@ -97,7 +98,8 @@ retval = -EINTR; break; } - schedule(); + sched_profile(); + __schedule(); set_task_state(tsk, TASK_INTERRUPTIBLE); } remove_wait_queue(&sem->wait, &wait); Index: schedprof-2.6.7/arch/sh/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/sh/kernel/semaphore.c 2004-06-15 22:19:44.000000000 -0700 +++ schedprof-2.6.7/arch/sh/kernel/semaphore.c 2004-06-24 14:02:48.332032184 -0700 @@ -110,7 +110,8 @@ DOWN_HEAD(TASK_UNINTERRUPTIBLE) if (waking_non_zero(sem)) break; - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_UNINTERRUPTIBLE) } @@ -128,7 +129,8 @@ ret = 0; break; } - schedule(); + sched_profile(); + __schedule(); DOWN_TAIL(TASK_INTERRUPTIBLE) return ret; } Index: schedprof-2.6.7/arch/sparc/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/sparc/kernel/semaphore.c 2004-06-15 22:20:04.000000000 -0700 +++ schedprof-2.6.7/arch/sparc/kernel/semaphore.c 2004-06-24 14:02:48.334031880 -0700 @@ -68,8 +68,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_UNINTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } @@ -118,8 +118,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_INTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } Index: schedprof-2.6.7/arch/sparc64/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/sparc64/kernel/semaphore.c 2004-06-15 22:19:44.000000000 -0700 +++ schedprof-2.6.7/arch/sparc64/kernel/semaphore.c 2004-06-24 14:02:48.336031576 -0700 @@ -100,7 +100,8 @@ add_wait_queue_exclusive(&sem->wait, &wait); while (__sem_update_count(sem, -1) <= 0) { - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_UNINTERRUPTIBLE; } remove_wait_queue(&sem->wait, &wait); @@ -208,7 +209,8 @@ retval = -EINTR; break; } - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_INTERRUPTIBLE; } tsk->state = TASK_RUNNING; Index: schedprof-2.6.7/arch/v850/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/v850/kernel/semaphore.c 2004-06-15 22:19:44.000000000 -0700 +++ schedprof-2.6.7/arch/v850/kernel/semaphore.c 2004-06-24 14:02:48.338031272 -0700 @@ -79,8 +79,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_UNINTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } @@ -129,8 +129,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irq(&semaphore_lock); - - schedule(); + sched_profile(); + __schedule(); tsk->state = TASK_INTERRUPTIBLE; spin_lock_irq(&semaphore_lock); } Index: schedprof-2.6.7/arch/x86_64/kernel/semaphore.c =================================================================== --- schedprof-2.6.7.orig/arch/x86_64/kernel/semaphore.c 2004-06-15 22:20:26.000000000 -0700 +++ schedprof-2.6.7/arch/x86_64/kernel/semaphore.c 2004-06-24 14:02:48.340030968 -0700 @@ -80,8 +80,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irqrestore(&sem->wait.lock, flags); - - schedule(); + sched_profile(); + __schedule(); spin_lock_irqsave(&sem->wait.lock, flags); tsk->state = TASK_UNINTERRUPTIBLE; @@ -133,8 +133,8 @@ } sem->sleepers = 1; /* us - see -1 above */ spin_unlock_irqrestore(&sem->wait.lock, flags); - - schedule(); + sched_profile(); + __schedule(); spin_lock_irqsave(&sem->wait.lock, flags); tsk->state = TASK_INTERRUPTIBLE; Index: schedprof-2.6.7/lib/rwsem.c =================================================================== --- schedprof-2.6.7.orig/lib/rwsem.c 2004-06-15 22:18:54.000000000 -0700 +++ schedprof-2.6.7/lib/rwsem.c 2004-06-24 14:02:48.343030512 -0700 @@ -163,7 +163,7 @@ for (;;) { if (!waiter->task) break; - schedule(); + __schedule(); set_task_state(tsk, TASK_UNINTERRUPTIBLE); } @@ -178,7 +178,7 @@ struct rw_semaphore fastcall __sched *rwsem_down_read_failed(struct rw_semaphore *sem) { struct rwsem_waiter waiter; - + sched_profile(); rwsemtrace(sem,"Entering rwsem_down_read_failed"); waiter.flags = RWSEM_WAITING_FOR_READ; @@ -194,7 +194,7 @@ struct rw_semaphore fastcall __sched *rwsem_down_write_failed(struct rw_semaphore *sem) { struct rwsem_waiter waiter; - + sched_profile(); rwsemtrace(sem,"Entering rwsem_down_write_failed"); waiter.flags = RWSEM_WAITING_FOR_WRITE; Index: schedprof-2.6.7/init/main.c =================================================================== --- schedprof-2.6.7.orig/init/main.c 2004-06-15 22:19:01.000000000 -0700 +++ schedprof-2.6.7/init/main.c 2004-06-24 14:02:48.346030056 -0700 @@ -445,6 +445,7 @@ if (panic_later) panic(panic_later, panic_param); profile_init(); + schedprof_init(); local_irq_enable(); #ifdef CONFIG_BLK_DEV_INITRD if (initrd_start && !initrd_below_start_ok && ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 21:22 ` William Lee Irwin III @ 2004-06-24 21:56 ` William Lee Irwin III 2004-06-25 6:51 ` William Lee Irwin III 0 siblings, 1 reply; 15+ messages in thread From: William Lee Irwin III @ 2004-06-24 21:56 UTC (permalink / raw) To: Andi Kleen, Yusuf Goolamabbas, linux-kernel [-- Attachment #1: Type: text/plain, Size: 422 bytes --] On Thu, Jun 24, 2004 at 02:22:48PM -0700, William Lee Irwin III wrote: > Brute-force port of schedprof to 2.6.7-final. Compiletested on sparc64 > only. No runtime testing. > Given that the context switch rate is actually *reduced* in 2.6.7 vs. > 2.6.5, I expect that this will not, in fact, reveal anything useful. While I'm spraying out untested code, I might as well do these, which I've not even compiled. =) -- wli [-- Attachment #2: schedprof_mmap-2.6.7 --] [-- Type: text/plain, Size: 3429 bytes --] Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-24 14:02:48.292038264 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 14:39:50.035281952 -0700 @@ -4063,7 +4063,7 @@ if (schedprof_buf) { unsigned long pc = (unsigned long)__pc; pc -= min(pc, (unsigned long)_stext); - atomic_inc(&schedprof_buf[min(pc, schedprof_len)]); + atomic_inc(&schedprof_buf[min(pc + 1, schedprof_len - 1)]); } } @@ -4081,8 +4081,9 @@ if (!sched_profiling) return; schedprof_len = (unsigned long)(_etext - _stext) + 1; - schedprof_buf = alloc_bootmem(schedprof_len*sizeof(atomic_t)); + schedprof_buf = alloc_bootmem(sizeof(atomic_t)*schedprof_len); printk(KERN_INFO "Scheduler call profiling enabled\n"); + schedprof_buf[0] = 1; } #ifdef CONFIG_PROC_FS @@ -4092,38 +4093,59 @@ read_sched_profile(struct file *file, char __user *buf, size_t count, loff_t *ppos) { unsigned long p = *ppos; - ssize_t read; - char * pnt; unsigned int sample_step = 1; - if (p >= (schedprof_len+1)*sizeof(atomic_t)) + if (p >= sizeof(atomic_t)*schedprof_len) return 0; - if (count > (schedprof_len+1)*sizeof(atomic_t) - p) - count = (schedprof_len+1)*sizeof(atomic_t) - p; - read = 0; - - while (p < sizeof(atomic_t) && count > 0) { - put_user(*((char *)(&sample_step)+p),buf); - buf++; p++; count--; read++; - } - pnt = (char *)schedprof_buf + p - sizeof(atomic_t); - if (copy_to_user(buf,(void *)pnt,count)) + count = min(schedprof_len*sizeof(atomic_t) - p, count); + if (copy_to_user(buf, (char *)schedprof_buf + p, count)) return -EFAULT; - read += count; - *ppos += read; - return read; + *ppos += count; + return count; } static ssize_t write_sched_profile(struct file *file, const char __user *buf, size_t count, loff_t *ppos) { - memset(schedprof_buf, 0, sizeof(atomic_t)*schedprof_len); + memset(&schedprof_buf[1], 0, (schedprof_len-1)*sizeof(atomic_t)); return count; } +static int mmap_sched_profile(struct file *file, struct vm_area_struct *vma) +{ + unsigned long pfn, vaddr, base_pfn = __pa(schedprof_buf)/PAGE_SIZE; + if (vma->vm_pgoff + vma_pages(vma) > schedprof_pages) + return -ENODEV; + vma->vm_flags |= VM_RESERVED|VM_IO; + for (vaddr = vma->vm_start; vaddr < vma->vm_end; vaddr += PAGE_SIZE) { + pgd_t *pgd = pgd_offset(vma->vm_mm, vaddr); + pmd_t *pmd; + pte_t *pte, pte_val; + + spin_lock(&vma->vm_mm->page_table_lock); + pmd = pmd_alloc(vma->vm_mm, pgd, vaddr); + if (!pmd) + goto enomem; + pte = pte_alloc_map(vma->vm_mm, pmd, vaddr); + if (!pte) + goto enomem; + pfn = base_pfn + linear_page_index(vma, vaddr); + pte_val = pfn_pte(pfn, vma->vm_page_prot); + set_pte(pte, pte_val); + update_mmu_cache(vma, vaddr, pte_val); + pte_unmap(pte); + spin_unlock(&vma->vm_mm->page_table_lock); + } + return 0; +enomem: + spin_unlock(&vma->vm_mm->page_table_lock); + return -ENOMEM; +} + static struct file_operations sched_profile_operations = { .read = read_sched_profile, .write = write_sched_profile, + .mmap = mmap_sched_profile, }; static int proc_schedprof_init(void) @@ -4134,7 +4156,7 @@ entry = create_proc_entry("schedprof", S_IWUSR | S_IRUGO, NULL); if (entry) { entry->proc_fops = &sched_profile_operations; - entry->size = sizeof(atomic_t)*(schedprof_len + 1); + entry->size = sizeof(atomic_t)*schedprof_len; } return !!entry; } [-- Attachment #3: schedprof_proc_init-2.6.7 --] [-- Type: text/plain, Size: 627 bytes --] Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-24 14:39:50.035281952 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 14:40:04.347106224 -0700 @@ -4152,13 +4152,13 @@ { struct proc_dir_entry *entry; if (!sched_profiling) - return 1; + return 0; entry = create_proc_entry("schedprof", S_IWUSR | S_IRUGO, NULL); if (entry) { entry->proc_fops = &sched_profile_operations; entry->size = sizeof(atomic_t)*schedprof_len; } - return !!entry; + return !entry; } module_init(proc_schedprof_init); #endif [-- Attachment #4: schedprof_shift-2.6.7 --] [-- Type: text/plain, Size: 1465 bytes --] Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-24 14:40:04.347106224 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 14:51:35.285067688 -0700 @@ -4052,7 +4052,7 @@ #endif /* defined(CONFIG_SMP) && defined(CONFIG_PREEMPT) */ static atomic_t *schedprof_buf; -static int sched_profiling; +static int sched_profiling, schedprof_shift; static unsigned long schedprof_len; #include <linux/bootmem.h> @@ -4062,11 +4062,22 @@ { if (schedprof_buf) { unsigned long pc = (unsigned long)__pc; - pc -= min(pc, (unsigned long)_stext); + pc = (pc - min(pc, (unsigned long)_stext)) >> schedprof_shift; atomic_inc(&schedprof_buf[min(pc + 1, schedprof_len - 1)]); } } +static int __init schedprof_shift_setup(char *s) +{ + int n; + if (get_option(&s, &n)) { + scheprof_shift = n; + sched_profiling = 1; + } + return 1; +} +__setup("schedprof_shift=", schedprof_shift_setup); + static int __init schedprof_setup(char *s) { int n; @@ -4080,10 +4091,10 @@ { if (!sched_profiling) return; - schedprof_len = (unsigned long)(_etext - _stext) + 1; + schedprof_len = ((unsigned long)(_etext - _stext) >> schedprof_shift) + 1; schedprof_buf = alloc_bootmem(sizeof(atomic_t)*schedprof_len); printk(KERN_INFO "Scheduler call profiling enabled\n"); - schedprof_buf[0] = 1; + schedprof_buf[0] = 1 << schedprof_shift; } #ifdef CONFIG_PROC_FS ^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: finish_task_switch high in profiles in 2.6.7 2004-06-24 21:56 ` William Lee Irwin III @ 2004-06-25 6:51 ` William Lee Irwin III 0 siblings, 0 replies; 15+ messages in thread From: William Lee Irwin III @ 2004-06-25 6:51 UTC (permalink / raw) To: Andi Kleen, Yusuf Goolamabbas, linux-kernel [-- Attachment #1: Type: text/plain, Size: 217 bytes --] On Thu, Jun 24, 2004 at 02:56:45PM -0700, William Lee Irwin III wrote: > While I'm spraying out untested code, I might as well do these, which > I've not even compiled. =) Okay, these compile -- ship it! =) -- wli [-- Attachment #2: schedprof_mmap-2.6.7 --] [-- Type: text/plain, Size: 3756 bytes --] Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-24 14:02:48.292038264 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 23:43:43.734205632 -0700 @@ -4053,7 +4053,7 @@ static atomic_t *schedprof_buf; static int sched_profiling; -static unsigned long schedprof_len; +static unsigned long schedprof_len, schedprof_pages; #include <linux/bootmem.h> #include <asm/sections.h> @@ -4063,7 +4063,7 @@ if (schedprof_buf) { unsigned long pc = (unsigned long)__pc; pc -= min(pc, (unsigned long)_stext); - atomic_inc(&schedprof_buf[min(pc, schedprof_len)]); + atomic_inc(&schedprof_buf[min(pc + 1, schedprof_len - 1)]); } } @@ -4081,8 +4081,10 @@ if (!sched_profiling) return; schedprof_len = (unsigned long)(_etext - _stext) + 1; - schedprof_buf = alloc_bootmem(schedprof_len*sizeof(atomic_t)); + schedprof_buf = alloc_bootmem_pages(sizeof(atomic_t)*schedprof_len); + schedprof_pages = PAGE_ALIGN(sizeof(atomic_t)*schedprof_len)/PAGE_SIZE; printk(KERN_INFO "Scheduler call profiling enabled\n"); + atomic_set(&schedprof_buf[0], 1); } #ifdef CONFIG_PROC_FS @@ -4092,38 +4094,58 @@ read_sched_profile(struct file *file, char __user *buf, size_t count, loff_t *ppos) { unsigned long p = *ppos; - ssize_t read; - char * pnt; - unsigned int sample_step = 1; - if (p >= (schedprof_len+1)*sizeof(atomic_t)) + if (p >= sizeof(atomic_t)*schedprof_len) return 0; - if (count > (schedprof_len+1)*sizeof(atomic_t) - p) - count = (schedprof_len+1)*sizeof(atomic_t) - p; - read = 0; - - while (p < sizeof(atomic_t) && count > 0) { - put_user(*((char *)(&sample_step)+p),buf); - buf++; p++; count--; read++; - } - pnt = (char *)schedprof_buf + p - sizeof(atomic_t); - if (copy_to_user(buf,(void *)pnt,count)) + count = min(schedprof_len*sizeof(atomic_t) - p, count); + if (copy_to_user(buf, (char *)schedprof_buf + p, count)) return -EFAULT; - read += count; - *ppos += read; - return read; + *ppos += count; + return count; } static ssize_t write_sched_profile(struct file *file, const char __user *buf, size_t count, loff_t *ppos) { - memset(schedprof_buf, 0, sizeof(atomic_t)*schedprof_len); + memset(&schedprof_buf[1], 0, (schedprof_len-1)*sizeof(atomic_t)); return count; } +static int mmap_sched_profile(struct file *file, struct vm_area_struct *vma) +{ + unsigned long pfn, vaddr, base_pfn = __pa(schedprof_buf)/PAGE_SIZE; + if (vma->vm_pgoff + vma_pages(vma) > schedprof_pages) + return -ENODEV; + vma->vm_flags |= VM_RESERVED|VM_IO; + for (vaddr = vma->vm_start; vaddr < vma->vm_end; vaddr += PAGE_SIZE) { + pgd_t *pgd = pgd_offset(vma->vm_mm, vaddr); + pmd_t *pmd; + pte_t *pte, pte_val; + + spin_lock(&vma->vm_mm->page_table_lock); + pmd = pmd_alloc(vma->vm_mm, pgd, vaddr); + if (!pmd) + goto enomem; + pte = pte_alloc_map(vma->vm_mm, pmd, vaddr); + if (!pte) + goto enomem; + pfn = base_pfn + linear_page_index(vma, vaddr); + pte_val = pfn_pte(pfn, vma->vm_page_prot); + set_pte(pte, pte_val); + update_mmu_cache(vma, vaddr, pte_val); + pte_unmap(pte); + spin_unlock(&vma->vm_mm->page_table_lock); + } + return 0; +enomem: + spin_unlock(&vma->vm_mm->page_table_lock); + return -ENOMEM; +} + static struct file_operations sched_profile_operations = { .read = read_sched_profile, .write = write_sched_profile, + .mmap = mmap_sched_profile, }; static int proc_schedprof_init(void) @@ -4134,7 +4156,7 @@ entry = create_proc_entry("schedprof", S_IWUSR | S_IRUGO, NULL); if (entry) { entry->proc_fops = &sched_profile_operations; - entry->size = sizeof(atomic_t)*(schedprof_len + 1); + entry->size = sizeof(atomic_t)*schedprof_len; } return !!entry; } [-- Attachment #3: schedprof_proc_init-2.6.7 --] [-- Type: text/plain, Size: 627 bytes --] Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-24 23:43:43.734205632 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 23:43:54.660544576 -0700 @@ -4152,13 +4152,13 @@ { struct proc_dir_entry *entry; if (!sched_profiling) - return 1; + return 0; entry = create_proc_entry("schedprof", S_IWUSR | S_IRUGO, NULL); if (entry) { entry->proc_fops = &sched_profile_operations; entry->size = sizeof(atomic_t)*schedprof_len; } - return !!entry; + return !entry; } module_init(proc_schedprof_init); #endif [-- Attachment #4: schedprof_shift-2.6.7 --] [-- Type: text/plain, Size: 1583 bytes --] Index: schedprof-2.6.7/kernel/sched.c =================================================================== --- schedprof-2.6.7.orig/kernel/sched.c 2004-06-24 23:42:11.200272928 -0700 +++ schedprof-2.6.7/kernel/sched.c 2004-06-24 23:42:41.895606528 -0700 @@ -4052,7 +4052,7 @@ #endif /* defined(CONFIG_SMP) && defined(CONFIG_PREEMPT) */ static atomic_t *schedprof_buf; -static int sched_profiling; +static int sched_profiling, schedprof_shift; static unsigned long schedprof_len, schedprof_pages; #include <linux/bootmem.h> @@ -4062,11 +4062,22 @@ { if (schedprof_buf) { unsigned long pc = (unsigned long)__pc; - pc -= min(pc, (unsigned long)_stext); + pc = (pc - min(pc, (unsigned long)_stext)) >> schedprof_shift; atomic_inc(&schedprof_buf[min(pc + 1, schedprof_len - 1)]); } } +static int __init schedprof_shift_setup(char *s) +{ + int n; + if (get_option(&s, &n)) { + schedprof_shift = n; + sched_profiling = 1; + } + return 1; +} +__setup("schedprof_shift=", schedprof_shift_setup); + static int __init schedprof_setup(char *s) { int n; @@ -4080,11 +4091,11 @@ { if (!sched_profiling) return; - schedprof_len = (unsigned long)(_etext - _stext) + 1; + schedprof_len = ((unsigned long)(_etext-_stext)>>schedprof_shift) + 1; schedprof_buf = alloc_bootmem_pages(sizeof(atomic_t)*schedprof_len); schedprof_pages = PAGE_ALIGN(sizeof(atomic_t)*schedprof_len)/PAGE_SIZE; printk(KERN_INFO "Scheduler call profiling enabled\n"); - atomic_set(&schedprof_buf[0], 1); + atomic_set(&schedprof_buf[0], 1 << schedprof_shift); } #ifdef CONFIG_PROC_FS ^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2004-06-25 6:52 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2004-06-24 9:15 finish_task_switch high in profiles in 2.6.7 Yusuf Goolamabbas
2004-06-24 9:27 ` Nick Piggin
2004-06-24 9:34 ` Yusuf Goolamabbas
2004-06-24 9:45 ` Nick Piggin
2004-06-24 10:05 ` Yusuf Goolamabbas
2004-06-24 10:10 ` Nick Piggin
2004-06-24 14:30 ` William Lee Irwin III
2004-06-24 15:33 ` William Lee Irwin III
[not found] <2ayz2-1Um-15@gated-at.bofh.it>
2004-06-24 10:25 ` Andi Kleen
2004-06-24 10:44 ` Yusuf Goolamabbas
2004-06-24 11:36 ` Andi Kleen
2004-06-24 14:05 ` William Lee Irwin III
2004-06-24 21:22 ` William Lee Irwin III
2004-06-24 21:56 ` William Lee Irwin III
2004-06-25 6:51 ` William Lee Irwin III
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox