Find the answer to your Linux question:
Results 1 to 2 of 2
Hello, I'm using a server Intel based, running two SB Xeon E5-2620 processors, with Suse SP2 (baseline version- no patches). I got one kernel thread that is started by using ...
Enjoy an ad free experience by logging in. Not a member yet? Register.
  1. #1
    Just Joined!
    Join Date
    Oct 2013
    Posts
    2

    strange results on tracer regarding kernel scheduler


    Hello,

    I'm using a server Intel based, running two SB Xeon E5-2620 processors, with Suse SP2 (baseline version- no patches).

    I got one kernel thread that is started by using a worqueue, and then he run in infinite loop, doing a short work and sleep by msleep(5). this thread is bounded to specific core.
    On the same core there is a userspace thread that run in a lower priority, and consume all the time that my thread is sleeping.

    After observing a problematic behavior with my kernel thread, i use the tracing utility in order to understand what happan.

    The traceing output is attached and this is what i saw on it:

    There are two PIDs that involved in this situation, found on core #3.
    548: kworker/3:1-548 (a kernel thread)
    4005: tIcs-3-Wo-4005 ( a user space thread)

    Pid 548 is a task that performs short work and then goes to sleep with: msleep(5).
    As you can see, on part1, 548 is woken at about of 12 msec each time (a normal behavior).

    At the last line of part1, it seams like, tIcs-3-Wo changed his PID to 13642 (????)
    you can also notice that 13642 got <...> instead of the thread name at the begining of each line

    From now, on part2, i saw the PID 13642 instead of 4005, running the tics-3-Wo command.
    Another thing, is that, now 548 is running only at each 25msec.
    There is one hole, at 507.119120 that 548 is sleep for 110msec.
    At the end of part2, we get back the 4005 PID

    In part3, we can see that 548 is running only after 30msec each time.


    Can anyone explain to me what was happan here?

    Thanx
    Attached Files Attached Files

  2. #2
    Just Joined!
    Join Date
    Oct 2013
    Posts
    2
    in order to simplify it, i attach another log that show a clear problem:
    - one real time high priority task is working and then gone to sleep
    - after a few milisec there is a sched_wakeup for this task
    - the sched_switch is happan only about 100 milisec after that.
    - the task that work during this period is set with lower priority.
    - you can see at each 4 milisec, there is the tick timer and some other.

    <...>-9181 [003] 330.999355: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 330.999358: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 330.999358: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331000000000 softexpires=331000000000
    <...>-9181 [003] 330.999358: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 330.999359: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.002044: sched_switch: prev_comm=tIcs-3-Wo prev_pid=9181 prev_prio=55 prev_state=R ==> next_comm=kworker/3:1 next_pid=554 next_prio=5
    kworker/3:1-554 [003] 331.002052: timer_cancel: timer=ffff880274e72678
    kworker/3:1-554 [003] 331.002053: timer_start: timer=ffff880274e72678 function=ioat2_timer_event expires=4294975047 [timeout=2]
    kworker/3:1-554 [003] 331.002138: timer_init: timer=ffff880274459ce0
    kworker/3:1-554 [003] 331.002138: timer_start: timer=ffff880274459ce0 function=process_timeout expires=4294975048 [timeout=3]
    kworker/3:1-554 [003] 331.002140: sched_switch: prev_comm=kworker/3:1 prev_pid=554 prev_prio=5 prev_state=D ==> next_comm=tIcs-3-Wo next_pid=9181 next_prio=55
    <...>-9181 [003] 331.003344: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.003345: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331000000437
    <...>-9181 [003] 331.003347: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.003352: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.003352: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331004000000 softexpires=331004000000
    <...>-9181 [003] 331.003353: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.003353: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.007336: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.007336: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331004000202
    <...>-9181 [003] 331.007339: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.007341: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.007341: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331008000000 softexpires=331008000000
    <...>-9181 [003] 331.007342: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.007342: timer_cancel: timer=ffff880274e72678
    <...>-9181 [003] 331.007342: timer_expire_entry: timer=ffff880274e72678 function=ioat2_timer_event now=4294975047
    <...>-9181 [003] 331.007343: timer_start: timer=ffff880274e72678 function=ioat2_timer_event expires=4294975049 [timeout=2]
    <...>-9181 [003] 331.007419: timer_cancel: timer=ffff880274e72678
    <...>-9181 [003] 331.007419: timer_start: timer=ffff880274e72678 function=ioat2_timer_event expires=4294975548 [timeout=501]
    <...>-9181 [003] 331.007419: timer_expire_exit: timer=ffff880274e72678
    <...>-9181 [003] 331.007419: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.011328: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.011329: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331008000195
    <...>-9181 [003] 331.011331: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.011334: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.011334: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331012000000 softexpires=331012000000
    <...>-9181 [003] 331.011335: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.011335: timer_cancel: timer=ffff880274459ce0
    <...>-9181 [003] 331.011335: timer_expire_entry: timer=ffff880274459ce0 function=process_timeout now=4294975048
    <...>-9181 [003] 331.011337: sched_wakeup: comm=kworker/3:1 pid=554 prio=5 success=1 target_cpu=003
    <...>-9181 [003] 331.011338: timer_expire_exit: timer=ffff880274459ce0
    <...>-9181 [003] 331.011338: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.015320: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.015321: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331012000387
    <...>-9181 [003] 331.015323: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.015325: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.015325: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331016000000 softexpires=331016000000
    <...>-9181 [003] 331.015325: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.015326: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.019313: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.019314: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331016000419
    <...>-9181 [003] 331.019316: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.019319: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.019319: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331020000000 softexpires=331020000000
    <...>-9181 [003] 331.019320: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.019320: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.023305: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.023305: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331020000375
    <...>-9181 [003] 331.023307: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.023310: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.023310: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331024000000 softexpires=331024000000
    <...>-9181 [003] 331.023311: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.023311: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.027298: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.027298: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331024000767
    <...>-9181 [003] 331.027300: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.027303: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.027303: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331028000000 softexpires=331028000000
    <...>-9181 [003] 331.027303: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.027304: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.031289: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.031289: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331028000075
    <...>-9181 [003] 331.031291: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.031293: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.031293: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331032000000 softexpires=331032000000
    <...>-9181 [003] 331.031294: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.031294: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.035282: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.035282: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331032000681
    <...>-9181 [003] 331.035286: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.035289: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.035289: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331036000000 softexpires=331036000000
    <...>-9181 [003] 331.035290: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.035291: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.039274: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.039274: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331036000405
    <...>-9181 [003] 331.039277: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.039279: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.039279: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331040000000 softexpires=331040000000
    <...>-9181 [003] 331.039280: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.039280: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.043265: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.043266: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331040000035
    <...>-9181 [003] 331.043267: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.043269: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.043269: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331044000000 softexpires=331044000000
    <...>-9181 [003] 331.043270: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.043270: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.047258: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.047259: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331044000604
    <...>-9181 [003] 331.047261: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.047263: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.047263: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331048000000 softexpires=331048000000
    <...>-9181 [003] 331.047264: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.047264: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.051250: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.051250: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331048000145
    <...>-9181 [003] 331.051252: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.051253: softirq_raise: vec=9 [action=RCU]
    <...>-9181 [003] 331.051255: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.051255: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331052000000 softexpires=331052000000
    <...>-9181 [003] 331.051256: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.051256: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.051256: softirq_entry: vec=9 [action=RCU]
    <...>-9181 [003] 331.051257: softirq_exit: vec=9 [action=RCU]
    <...>-9181 [003] 331.055242: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.055243: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331052000184
    <...>-9181 [003] 331.055244: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.055246: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.055246: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331056000000 softexpires=331056000000
    <...>-9181 [003] 331.055246: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.055247: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.059235: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.059235: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331056000420
    <...>-9181 [003] 331.059237: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.059240: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.059240: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331060000000 softexpires=331060000000
    <...>-9181 [003] 331.059241: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.059241: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.063226: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.063227: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331060000130
    <...>-9181 [003] 331.063229: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.063229: softirq_raise: vec=9 [action=RCU]
    <...>-9181 [003] 331.063231: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.063232: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331064000000 softexpires=331064000000
    <...>-9181 [003] 331.063232: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.063232: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.063232: softirq_entry: vec=9 [action=RCU]
    <...>-9181 [003] 331.063256: softirq_exit: vec=9 [action=RCU]
    <...>-9181 [003] 331.067219: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.067219: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331064000064
    <...>-9181 [003] 331.067221: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.067222: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.067223: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331068000000 softexpires=331068000000
    <...>-9181 [003] 331.067223: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.067223: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.071211: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.071212: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331068000228
    <...>-9181 [003] 331.071214: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.071216: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.071216: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331072000000 softexpires=331072000000
    <...>-9181 [003] 331.071216: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.071217: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.075203: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.075203: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331072000248
    <...>-9181 [003] 331.075206: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.075208: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.075208: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331076000000 softexpires=331076000000
    <...>-9181 [003] 331.075208: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.075209: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.079195: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.079196: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331076000120
    <...>-9181 [003] 331.079198: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.079198: softirq_raise: vec=9 [action=RCU]
    <...>-9181 [003] 331.079200: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.079201: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331080000000 softexpires=331080000000
    <...>-9181 [003] 331.079201: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.079201: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.079201: softirq_entry: vec=9 [action=RCU]
    <...>-9181 [003] 331.079227: softirq_exit: vec=9 [action=RCU]
    <...>-9181 [003] 331.083188: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.083189: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331080000608
    <...>-9181 [003] 331.083191: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.083195: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.083196: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331084000000 softexpires=331084000000
    <...>-9181 [003] 331.083196: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.083196: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.087180: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.087181: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331084000537
    <...>-9181 [003] 331.087183: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.087186: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.087186: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331088000000 softexpires=331088000000
    <...>-9181 [003] 331.087186: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.087187: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.091172: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.091173: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331088000402
    <...>-9181 [003] 331.091175: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.091178: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.091179: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331092000000 softexpires=331092000000
    <...>-9181 [003] 331.091179: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.091180: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.095165: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.095165: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331092000531
    <...>-9181 [003] 331.095168: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.095168: softirq_raise: vec=9 [action=RCU]
    <...>-9181 [003] 331.095172: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.095172: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331096000000 softexpires=331096000000
    <...>-9181 [003] 331.095173: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.095173: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.095173: softirq_entry: vec=9 [action=RCU]
    <...>-9181 [003] 331.095195: softirq_exit: vec=9 [action=RCU]
    <...>-9181 [003] 331.099157: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.099157: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331096000445
    <...>-9181 [003] 331.099159: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.099163: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.099163: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331100000000 softexpires=331100000000
    <...>-9181 [003] 331.099164: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.099164: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.103148: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.103149: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331100000103
    <...>-9181 [003] 331.103150: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.103152: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.103152: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331104000000 softexpires=331104000000
    <...>-9181 [003] 331.103152: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.103153: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.107141: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.107141: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331104000397
    <...>-9181 [003] 331.107144: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.107147: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.107147: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331108000000 softexpires=331108000000
    <...>-9181 [003] 331.107148: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.107149: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.111133: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.111133: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331108000377
    <...>-9181 [003] 331.111136: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.111136: softirq_raise: vec=9 [action=RCU]
    <...>-9181 [003] 331.111139: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.111140: hrtimer_start: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer expires=331112000000 softexpires=331112000000
    <...>-9181 [003] 331.111140: softirq_entry: vec=1 [action=TIMER]
    <...>-9181 [003] 331.111140: softirq_exit: vec=1 [action=TIMER]
    <...>-9181 [003] 331.111140: softirq_entry: vec=9 [action=RCU]
    <...>-9181 [003] 331.111163: softirq_exit: vec=9 [action=RCU]
    <...>-9181 [003] 331.111816: sched_switch: prev_comm=tIcs-3-Wo prev_pid=9181 prev_prio=55 prev_state=R ==> next_comm=kworker/3:1 next_pid=554 next_prio=5
    kworker/3:1-554 [003] 331.111828: timer_cancel: timer=ffff880274e72678
    kworker/3:1-554 [003] 331.111828: timer_start: timer=ffff880274e72678 function=ioat2_timer_event expires=4294975075 [timeout=2]
    kworker/3:1-554 [003] 331.112172: timer_init: timer=ffff880274459ce0
    kworker/3:1-554 [003] 331.112172: timer_start: timer=ffff880274459ce0 function=process_timeout expires=4294975076 [timeout=3]
    kworker/3:1-554 [003] 331.112174: sched_switch: prev_comm=kworker/3:1 prev_pid=554 prev_prio=5 prev_state=D ==> next_comm=tIcs-3-Wo next_pid=9181 next_prio=55
    <...>-9181 [003] 331.115125: hrtimer_cancel: hrtimer=ffff88027fc6d8c0
    <...>-9181 [003] 331.115126: hrtimer_expire_entry: hrtimer=ffff88027fc6d8c0 function=tick_sched_timer now=331112000221
    <...>-9181 [003] 331.115127: softirq_raise: vec=1 [action=TIMER]
    <...>-9181 [003] 331.115128: softirq_raise: vec=9 [action=RCU]
    <...>-9181 [003] 331.115131: softirq_raise: vec=7 [action=SCHED]
    <...>-9181 [003] 331.115131: hrtimer_expire_exit: hrtimer=ffff88027fc6d8c0

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •