Comment 5 for bug 534549

Revision history for this message
Chase Douglas (chasedouglas) wrote :

@Simone:

Great! I've got everything I need to do more digging. The following (at the end of the trace) shows clearly exactly what is causing the bug:

# tracer: function
#
# function latency trace v1.1.5 on 2.6.32-16-generic
# --------------------------------------------------------------------
# latency: 0 us, #120241/31431691, CPU#0 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:2)
# -----------------
# | task: -0 (uid:0 nice:0 policy:0 rt_prio:0)
# -----------------
#
# _------=> CPU#
# / _-----=> irqs-off
# | / _----=> need-resched
# || / _---=> hardirq/softirq
# ||| / _--=> preempt-depth
# |||| /_--=> lock-depth
# |||||/ delay
# cmd pid |||||| time | caller
# \ / |||||| \ | /
  <idle>-0 0.Ns.. 57071005us : rfcomm_session_timeout <-run_timer_softirq
  <idle>-0 0.Ns.. 57071007us : rfcomm_session_del <-rfcomm_session_timeout
  <idle>-0 0.Ns.. 57071009us : rfcomm_session_clear_timer <-rfcomm_session_del
  <idle>-0 0.Ns.. 57071012us : sock_release <-rfcomm_session_del
  <idle>-0 0.Ns.. 57071014us : l2cap_sock_release <-sock_release
  <idle>-0 0.Ns.. 57071016us : l2cap_sock_shutdown <-l2cap_sock_release
  <idle>-0 0.Ns.. 57071018us+: lock_sock_nested <-l2cap_sock_shutdown
  <idle>-0 0.Ns.. 57071019us : _cond_resched <-lock_sock_nested

Now we need to figure out what here needs to be moved out of irq context. I'll be looking into it further tomorrow.