lkml.org 
[lkml]   [2011]   [Aug]   [9]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [PATCH v2 1/6] TTY: serial, remove BTM from wait_until_sent
    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
    [unhandled content-type:application/octet-stream]
    \
     
     \ /
      Last update: 2011-08-10 03:11    [W:0.070 / U:92.300 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site