On Mon, Aug 08, 2011 at 03:21:22PM +0200, Jiri Slaby wrote: > On 07/19/2011 02:35 AM, Andreas Bombe wrote: > > On Thu, Jul 14, 2011 at 02:35:10PM +0200, Jiri Slaby wrote: > >> This should also fix the issue Andreas is seeing (BTM in comparison to > >> BKL doesn't have any hidden functionality like unlocking during > >> sleeping). > > > > I tested the patch series and it does not appear to make a difference > > for the internal (16550A) serial ports on my system. Also, I am still > > unclear on why it freezes the X display during the timeout period. > > Sorry for the delay. Could you attach output of sysrq-t when this > happens? I mean with a kernel patched by my patch. I did my simple test on ttyS0 again: "stty -F /dev/ttyS0 crtscts" then "echo >/dev/ttyS0". I attached the gzipped sysrq-t list in case you need the complete output. This is just the process while it is trying to close the device (bash's internal echo): [ 321.948012] bash S ffff8800bcc85e80 0 4000 2828 0x00000000 [ 321.948012] ffff880127079c38 0000000000000046 ffff880127079c50 0000000100002fff [ 321.948012] ffff880127079fd8 0000000000011fc0 ffff880127079fd8 0000000000011fc0 [ 321.948012] ffff8801270dde80 ffff8800bcc85e80 ffff880127079c38 0000000100002fff [ 321.948012] Call Trace: [ 321.948012] [<ffffffff813cdf2e>] schedule_timeout+0xb5/0xf2 [ 321.948012] [<ffffffff8104ae2b>] ? call_timer_fn+0x154/0x154 [ 321.948012] [<ffffffff81255d60>] tty_wait_until_sent+0xa3/0xec [ 321.948012] [<ffffffff8105a190>] ? __init_waitqueue_head+0x46/0x46 [ 321.948012] [<ffffffff81268c05>] uart_close+0x12b/0x243 [ 321.948012] [<ffffffff81250454>] ? __tty_fasync+0x5c/0x124 [ 321.948012] [<ffffffff81251a00>] tty_release+0x1d3/0x4d7 [ 321.948012] [<ffffffff813cfbd8>] ? _raw_spin_unlock+0x43/0x51 [ 321.948012] [<ffffffff8110db81>] ? dput+0xfe/0x11d [ 321.948012] [<ffffffff810fdc86>] __fput+0x107/0x1a2 [ 321.948012] [<ffffffff810fdd36>] fput+0x15/0x17 [ 321.948012] [<ffffffff810fb014>] filp_close+0x69/0x75 [ 321.948012] [<ffffffff81109654>] sys_dup3+0x12b/0x153 [ 321.948012] [<ffffffff811096d5>] sys_dup2+0x59/0x60 [ 321.948012] [<ffffffff813d0a12>] system_call_fastpath+0x16/0x1b [ 321.948012] Sched Debug Version: v0.10, 3.1.0-rc1+ser-00011-g37ed45d #87 [ 321.948012] ktime : 321967.638593 [ 321.948012] sched_clk : 321738.307013 [ 321.948012] cpu_clk : 321948.012318 [ 321.948012] jiffies : 4294972787 [ 321.948012] sched_clock_stable : 0 [ 321.948012] [ 321.948012] sysctl_sched [ 321.948012] .sysctl_sched_latency : 12.000000 [ 321.948012] .sysctl_sched_min_granularity : 1.500000 [ 321.948012] .sysctl_sched_wakeup_granularity : 2.000000 [ 321.948012] .sysctl_sched_child_runs_first : 0 [ 321.948012] .sysctl_sched_features : 15471 [ 321.948012] .sysctl_sched_tunable_scaling : 1 (logaritmic) [ 321.948012] [ 321.948012] cpu#0, 3166.466 MHz [ 321.948012] .nr_running : 2 [ 321.948012] .load : 1927 [ 321.948012] .nr_switches : 181895 [ 321.948012] .nr_load_updates : 28885 [ 321.948012] .nr_uninterruptible : 58 [ 321.948012] .next_balance : 4294.972819 [ 321.948012] .curr->pid : 11 [ 321.948012] .clock : 321964.006925 [ 321.948012] .cpu_load[0] : 1927 [ 321.948012] .cpu_load[1] : 1743 [ 321.948012] .cpu_load[2] : 1400 [ 321.948012] .cpu_load[3] : 1137 [ 321.948012] .cpu_load[4] : 871 [ 321.948012] .yld_count : 20444 [ 321.948012] .sched_switch : 0 [ 321.948012] .sched_count : 203439 [ 321.948012] .sched_goidle : 58617 [ 321.948012] .avg_idle : 1000000 [ 321.948012] .ttwu_count : 112788 [ 321.948012] .ttwu_local : 63063 [ 321.948012] [ 321.948012] cfs_rq[0]:/autogroup-58 [ 321.948012] .exec_clock : 995.435149 [ 321.948012] .MIN_vruntime : 962.061080 [ 321.948012] .min_vruntime : 962.061080 [ 321.948012] .max_vruntime : 962.061080 [ 321.948012] .spread : 0.000000 [ 321.948012] .spread0 : -22090.643266 [ 321.948012] .nr_spread_over : 0 [ 321.948012] .nr_running : 1 [ 321.948012] .load : 1024 [ 321.948012] .load_avg : 6435.076254 [ 321.948012] .load_period : 6.287393 [ 321.948012] .load_contrib : 1004 [ 321.948012] .load_tg : 1140 [ 321.948012] .se->exec_start : 321727.319580 [ 321.948012] .se->vruntime : 23059.712463 [ 321.948012] .se->sum_exec_runtime : 995.837577 [ 321.948012] .se->statistics.wait_start : 321964.006925 [ 321.948012] .se->statistics.sleep_start : 0.000000 [ 321.948012] .se->statistics.block_start : 0.000000 [ 321.948012] .se->statistics.sleep_max : 0.000000 [ 321.948012] .se->statistics.block_max : 0.000000 [ 321.948012] .se->statistics.exec_max : 4.000979 [ 321.948012] .se->statistics.slice_max : 2.977407 [ 321.948012] .se->statistics.wait_max : 8.300527 [ 321.948012] .se->statistics.wait_sum : 309.360276 [ 321.948012] .se->statistics.wait_count : 8489 [ 321.948012] .se->load.weight : 903 [ 321.948012] [ 321.948012] cfs_rq[0]:/ [ 321.948012] .exec_clock : 20767.422942 [ 321.948012] .MIN_vruntime : 23059.712463 [ 321.948012] .min_vruntime : 23052.704346 [ 321.948012] .max_vruntime : 23059.712463 [ 321.948012] .spread : 0.000000 [ 321.948012] .spread0 : 0.000000 [ 321.948012] .nr_spread_over : 73 [ 321.948012] .nr_running : 2 [ 321.948012] .load : 1927 [ 321.948012] .load_avg : 0.000000 [ 321.948012] .load_period : 0.000000 [ 321.948012] .load_contrib : 0 [ 321.948012] .load_tg : 0 [ 321.948012] [ 321.948012] rt_rq[0]: [ 321.948012] .rt_nr_running : 0 [ 321.948012] .rt_throttled : 0 [ 321.948012] .rt_time : 0.000000 [ 321.948012] .rt_runtime : 950.000000 [ 321.948012] [ 321.948012] runnable tasks: [ 321.948012] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [ 321.948012] ---------------------------------------------------------------------------------------------------------- [ 321.948012] R kworker/0:1 11 23052.704346 13969 120 23052.704346 555.720586 321027.845811 / [ 321.948012] alsa-sink 3110 962.061080 4307 120 962.061080 1411.254175 258698.264923 /autogroup-58 [ 321.948012] [ 321.948012] cpu#1, 3166.466 MHz [ 321.948012] .nr_running : 0 [ 321.948012] .load : 0 [ 321.948012] .nr_switches : 206709 [ 321.948012] .nr_load_updates : 30117 [ 321.948012] .nr_uninterruptible : -58 [ 321.948012] .next_balance : 4294.972776 [ 321.948012] .curr->pid : 0 [ 321.948012] .clock : 321846.477751 [ 321.948012] .cpu_load[0] : 947 [ 321.948012] .cpu_load[1] : 481 [ 321.948012] .cpu_load[2] : 282 [ 321.948012] .cpu_load[3] : 183 [ 321.948012] .cpu_load[4] : 133 [ 321.948012] .yld_count : 26864 [ 321.948012] .sched_switch : 0 [ 321.948012] .sched_count : 233886 [ 321.948012] .sched_goidle : 75296 [ 321.948012] .avg_idle : 1000000 [ 321.948012] .ttwu_count : 96142 [ 321.948012] .ttwu_local : 60872 [ 321.948012] [ 321.948012] cfs_rq[1]:/autogroup-58 [ 321.948012] .exec_clock : 1096.255751 [ 321.948012] .MIN_vruntime : 0.000001 [ 321.948012] .min_vruntime : 1043.264049 [ 321.948012] .max_vruntime : 0.000001 [ 321.948012] .spread : 0.000000 [ 321.948012] .spread0 : -22009.440297 [ 321.948012] .nr_spread_over : 0 [ 321.948012] .nr_running : 0 [ 321.948012] .load : 0 [ 321.948012] .load_avg : 894.748356 [ 321.948012] .load_period : 6.572338 [ 321.948012] .load_contrib : 136 [ 321.948012] .load_tg : 1140 [ 321.948012] .se->exec_start : 321808.596733 [ 321.948012] .se->vruntime : 20943.081256 [ 321.948012] .se->sum_exec_runtime : 1096.712219 [ 321.948012] .se->statistics.wait_start : 0.000000 [ 321.948012] .se->statistics.sleep_start : 0.000000 [ 321.948012] .se->statistics.block_start : 0.000000 [ 321.948012] .se->statistics.sleep_max : 0.000000 [ 321.948012] .se->statistics.block_max : 0.000000 [ 321.948012] .se->statistics.exec_max : 4.042092 [ 321.948012] .se->statistics.slice_max : 1.274462 [ 321.948012] .se->statistics.wait_max : 11.013496 [ 321.948012] .se->statistics.wait_sum : 303.941198 [ 321.948012] .se->statistics.wait_count : 8528 [ 321.948012] .se->load.weight : 2 [ 321.948012] [ 321.948012] cfs_rq[1]:/autogroup-53 [ 321.948012] .exec_clock : 5152.934351 [ 321.948012] .MIN_vruntime : 0.000001 [ 321.948012] .min_vruntime : 10693.441896 [ 321.948012] .max_vruntime : 0.000001 [ 321.948012] .spread : 0.000000 [ 321.948012] .spread0 : -12359.262450 [ 321.948012] .nr_spread_over : 81 [ 321.948012] .nr_running : 0 [ 321.948012] .load : 0 [ 321.948012] .load_avg : 124.928296 [ 321.948012] .load_period : 6.455088 [ 321.948012] .load_contrib : 19 [ 321.948012] .load_tg : 19 [ 321.948012] .se->exec_start : 321807.916228 [ 321.948012] .se->vruntime : 20936.418846 [ 321.948012] .se->sum_exec_runtime : 5153.129023 [ 321.948012] .se->statistics.wait_start : 0.000000 [ 321.948012] .se->statistics.sleep_start : 0.000000 [ 321.948012] .se->statistics.block_start : 0.000000 [ 321.948012] .se->statistics.sleep_max : 0.000000 [ 321.948012] .se->statistics.block_max : 0.000000 [ 321.948012] .se->statistics.exec_max : 4.032091 [ 321.948012] .se->statistics.slice_max : 7.996020 [ 321.948012] .se->statistics.wait_max : 32.784820 [ 321.948012] .se->statistics.wait_sum : 839.992046 [ 321.948012] .se->statistics.wait_count : 55429 [ 321.948012] .se->load.weight : 2 [ 321.948012] [ 321.948012] cfs_rq[1]:/ [ 321.948012] .exec_clock : 18512.679083 [ 321.948012] .MIN_vruntime : 0.000001 [ 321.948012] .min_vruntime : 20943.081256 [ 321.948012] .max_vruntime : 0.000001 [ 321.948012] .spread : 0.000000 [ 321.948012] .spread0 : -2109.623090 [ 321.948012] .nr_spread_over : 91 [ 321.948012] .nr_running : 0 [ 321.948012] .load : 0 [ 321.948012] .load_avg : 0.000000 [ 321.948012] .load_period : 0.000000 [ 321.948012] .load_contrib : 0 [ 321.948012] .load_tg : 0 [ 321.948012] [ 321.948012] rt_rq[1]: [ 321.948012] .rt_nr_running : 0 [ 321.948012] .rt_throttled : 0 [ 321.948012] .rt_time : 0.000000 [ 321.948012] .rt_runtime : 950.000000 [ 321.948012] [ 321.948012] runnable tasks: [ 321.948012] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [ 321.948012] ---------------------------------------------------------------------------------------------------------- [ 321.948012] [ 321.948012] INFO: lockdep is turned off. -- Andreas Bombe
Attachment:
dmesg.sysrqt-complete.gz
Description: Binary data
