flush_to_ldisc executing 2500 times a second ?

[Dave Jones <davej@redhat.com>]

While poking at an unrelated bug, I came up with a perf
command line that showed something curious.

perf record -a -e workqueue:workqueue_execute_start sleep 1
perf trace

shows flush_to_ldisc being executed ~2500 times.
(http://codemonkey.org.uk/junk/flush_to_ldisc.txt)

Steve Rostedt gave me a tip about trace-cmd to get a backtrace,

trace-cmd record -e workqueue_queue_work -O stacktrace sleep 1

which yields thousands of ..

           sleep-17431 [000] 35746.452637: workqueue_queue_work: work struct=0xffff880113f2a2a0 function=flush_to_ldisc workqueue=0xffff88013f80cb68 req_cpu=0 cpu=0
           sleep-17431 [000] 35746.452638: kernel_stack:         <stack trace>
=> __queue_work (ffffffff81068c25)
=> delayed_work_timer_fn (ffffffff81068cc8)
=> run_timer_softirq (ffffffff8105e651)
=> __do_softirq (ffffffff810571af)
=> call_softirq (ffffffff8100bbdc)
=> do_softirq (ffffffff8100d358)
=> irq_exit (ffffffff81057366)
=> smp_apic_timer_interrupt (ffffffff81482b9e)

Which doesn't really tell me much.


At the time of the profiling, there's nothing being output on any tty's
(and the profiling tools are also silent during the actual profiling) so
I'm curious as to what's causing the flushing to be necessary.

Anyone have any ideas what's going on here ? or something further
I could dig into ?

This is with 2.6.37-rc4.

The only other machine I have to test on right now is running 2.6.34, which
doesn't exhibit this behaviour.  I'll try to narrow it down further tomorrow.

	Dave