Re: [PATCH v2 1/6] TTY: serial, remove BTM from wait_until_sent
From: Andreas Bombe <hidden>
Date: 2011-08-10 01:09:42
Also in:
lkml
On Mon, Aug 08, 2011 at 03:21:22PM +0200, Jiri Slaby wrote:
On 07/19/2011 02:35 AM, Andreas Bombe wrote:quoted
On Thu, Jul 14, 2011 at 02:35:10PM +0200, Jiri Slaby wrote:quoted
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
Attachments
- dmesg.sysrqt-complete.gz [application/octet-stream] 29828 bytes