-0 [002] 2061.340888: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [002] 2061.340897: xn_nucleus_sched: status=2000000 -0 [000] 2061.340902: xn_nucleus_sched_remote: status=2000000 -0 [000] 2061.340904: xn_nucleus_sched: status=2000000 -0 [002] 2061.340904: power_start: type=1 state=1 -0 [000] 2061.340906: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [000] 2061.340919: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 -0 [000] 2061.340928: xn_nucleus_sched: status=2000000 -0 [000] 2061.340934: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 -0 [000] 2061.340936: xn_nucleus_sched: status=2000000 -0 [000] 2061.340937: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.340952: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930637849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.340956: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.340957: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.340962: power_start: type=1 state=1 -0 [000] 2061.341743: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 -0 [000] 2061.341748: xn_nucleus_sched: status=2000000 -0 [000] 2061.341750: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.341820: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.341825: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.341828: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [001] 2061.341829: power_start: type=1 state=1 -0 [000] 2061.341835: power_start: type=1 state=1 -0 [003] 2061.341887: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [003] 2061.341896: xn_nucleus_sched: status=2000000 -0 [000] 2061.341901: xn_nucleus_sched_remote: status=2000000 -0 [000] 2061.341903: xn_nucleus_sched: status=2000000 -0 [003] 2061.341903: power_start: type=1 state=1 -0 [000] 2061.341906: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [000] 2061.341924: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 -0 [000] 2061.341927: xn_nucleus_sched: status=2000000 -0 [000] 2061.341934: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 -0 [000] 2061.341940: xn_nucleus_sched: status=2000000 -0 [000] 2061.341942: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.341957: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930638849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.341960: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.341962: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.341966: power_start: type=1 state=1 -0 [000] 2061.342742: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 -0 [000] 2061.342746: xn_nucleus_sched: status=2000000 -0 [000] 2061.342749: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.342841: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.342846: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.342848: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.342855: power_start: type=1 state=1 -0 [002] 2061.342885: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [002] 2061.342894: xn_nucleus_sched: status=2000000 -0 [000] 2061.342899: xn_nucleus_sched_remote: status=2000000 -0 [000] 2061.342901: xn_nucleus_sched: status=2000000 -0 [002] 2061.342901: power_start: type=1 state=1 -0 [000] 2061.342904: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [000] 2061.342916: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 -0 [000] 2061.342925: xn_nucleus_sched: status=2000000 -0 [000] 2061.342932: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 -0 [000] 2061.342933: xn_nucleus_sched: status=2000000 -0 [000] 2061.342935: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.342950: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930639849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.342953: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.342955: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.342959: power_start: type=1 state=1 -0 [000] 2061.343741: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 -0 [000] 2061.343745: xn_nucleus_sched: status=2000000 -0 [000] 2061.343747: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.343818: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.343823: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.343825: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [001] 2061.343827: power_start: type=1 state=1 -0 [000] 2061.343832: power_start: type=1 state=1 -0 [003] 2061.343884: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [003] 2061.343893: xn_nucleus_sched: status=2000000 -0 [000] 2061.343899: xn_nucleus_sched_remote: status=2000000 -0 [000] 2061.343900: xn_nucleus_sched: status=2000000 -0 [003] 2061.343900: power_start: type=1 state=1 -0 [000] 2061.343903: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [000] 2061.343921: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 -0 [000] 2061.343924: xn_nucleus_sched: status=2000000 -0 [000] 2061.343931: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 -0 [000] 2061.343937: xn_nucleus_sched: status=2000000 -0 [000] 2061.343939: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.343954: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930640849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.343957: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.343959: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.343964: power_start: type=1 state=1 -0 [000] 2061.344739: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 -0 [000] 2061.344743: xn_nucleus_sched: status=2000000 -0 [000] 2061.344746: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.344838: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.344843: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.344845: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.344852: power_start: type=1 state=1 -0 [002] 2061.344883: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [002] 2061.344892: xn_nucleus_sched: status=2000000 -0 [000] 2061.344898: xn_nucleus_sched_remote: status=2000000 -0 [000] 2061.344899: xn_nucleus_sched: status=2000000 -0 [002] 2061.344900: power_start: type=1 state=1 -0 [000] 2061.344902: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [000] 2061.344920: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 -0 [000] 2061.344923: xn_nucleus_sched: status=2000000 -0 [000] 2061.344930: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 -0 [000] 2061.344931: xn_nucleus_sched: status=2000000 -0 [000] 2061.344932: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.344948: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930641849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.344951: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.344953: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.344957: power_start: type=1 state=1 -0 [000] 2061.345737: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 -0 [000] 2061.345742: xn_nucleus_sched: status=2000000 -0 [000] 2061.345744: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.345815: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.345819: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.345822: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [001] 2061.345824: power_start: type=1 state=1 -0 [000] 2061.345829: power_start: type=1 state=1 -0 [003] 2061.345881: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [003] 2061.345890: xn_nucleus_sched: status=2000000 -0 [000] 2061.345895: xn_nucleus_sched_remote: status=2000000 -0 [000] 2061.345897: xn_nucleus_sched: status=2000000 -0 [003] 2061.345897: power_start: type=1 state=1 -0 [000] 2061.345900: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [000] 2061.345918: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 -0 [000] 2061.345922: xn_nucleus_sched: status=2000000 -0 [000] 2061.345929: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 -0 [000] 2061.345934: xn_nucleus_sched: status=2000000 -0 [000] 2061.345936: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.345951: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930642849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.345954: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.345955: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 -0 [000] 2061.345960: power_start: type=1 state=1 -0 [000] 2061.346351: lock_acquire: c09aead4 xtime_lock -0 [000] 2061.346360: lock_release: c09aead4 xtime_lock -0 [000] 2061.346367: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346375: lock_acquire: c12f8a60 std_spinlock_raw(&obj_hash[i].lock) -0 [000] 2061.346383: lock_release: c12f8a60 std_spinlock_raw(&obj_hash[i].lock) -0 [000] 2061.346386: hrtimer_cancel: hrtimer=f1087f44 -0 [000] 2061.346390: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346392: hrtimer_expire_entry: hrtimer=f1087f44 function=hrtimer_wakeup now=2064303506553 -0 [000] 2061.346397: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346405: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346409: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346417: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346421: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346428: sched_stat_sleep: comm=reporter pid=2375 delay=1010376861 [ns] -0 [000] 2061.346429: sched_wakeup: comm=reporter pid=2375 prio=120 success=1 target_cpu=000 -0 [000] 2061.346433: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346437: hrtimer_expire_exit: hrtimer=f1087f44 -0 [000] 2061.346440: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346447: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346468: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346476: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) -0 [000] 2061.346484: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) -0 [000] 2061.346487: hrtimer_cancel: hrtimer=c4803d88 -0 [000] 2061.346491: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346500: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346509: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) -0 [000] 2061.346521: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) -0 [000] 2061.346524: hrtimer_start: hrtimer=c4803d88 function=tick_sched_timer expires=2064304000000 softexpires=2064304000000 -0 [000] 2061.346529: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [000] 2061.346536: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [000] 2061.346540: sched_stat_wait: comm=reporter pid=2375 delay=0 [ns] -0 [000] 2061.346546: sched_switch: prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=reporter next_pid=2375 next_prio=120 -0 [000] 2061.346548: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346551: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346554: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346559: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.346564: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.346570: lock_acquire: c12f8a60 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.346575: lock_release: c12f8a60 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.346581: lock_acquire: c0a0d200 pool_lock reporter-2375 [000] 2061.346585: lock_release: c0a0d200 pool_lock reporter-2375 [000] 2061.346592: kfree: call_site=c047fe89 ptr=(null) reporter-2375 [000] 2061.346593: sys_nanosleep -> 0x0 reporter-2375 [000] 2061.346596: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.346601: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.346604: sys_exit: NR 162 = 0 reporter-2375 [000] 2061.346613: sys_write(fd: 1, buf: b7888000, count: a) reporter-2375 [000] 2061.346615: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.346620: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.346623: sys_enter: NR 4 (1, b7888000, a, a, b7888000, b789308c) reporter-2375 [000] 2061.346626: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.346630: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.346637: lock_acquire: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.346642: lock_release: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.346648: lock_acquire: f4398d94 try &tty->atomic_write_lock reporter-2375 [000] 2061.346655: lock_acquire: c1de0e24 read &mm->mmap_sem reporter-2375 [000] 2061.346658: lock_release: c1de0e24 &mm->mmap_sem reporter-2375 [000] 2061.346664: lock_acquire: f4398a34 key reporter-2375 [000] 2061.346668: lock_release: f4398a34 key reporter-2375 [000] 2061.346675: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.346685: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.346690: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.346696: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.346701: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.346708: lock_acquire: c0c73190 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.346714: lock_acquire: c12ee560 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.346719: lock_release: c12ee560 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.346721: timer_start: timer=f439cb24 function=delayed_work_timer_fn expires=1764304 [timeout=1] reporter-2375 [000] 2061.346724: lock_release: c0c73190 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.346729: lock_acquire: f4398a34 key reporter-2375 [000] 2061.346735: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 reporter-2375 [000] 2061.346738: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.346740: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.346804: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.346807: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.346809: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 reporter-2375 [000] 2061.346816: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346819: sched_wakeup: comm=reporter pid=2375 prio=120 success=0 target_cpu=000 reporter-2375 [000] 2061.346822: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346826: lock_release: f4398a34 key reporter-2375 [000] 2061.346832: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.346838: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.346848: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.346853: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [002] 2061.346859: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 reporter-2375 [000] 2061.346863: xn_nucleus_sched: status=42000000 reporter-2375 [000] 2061.346864: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack -0 [002] 2061.346867: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.346871: xn_nucleus_sched_remote: status=40000000 -0 [002] 2061.346872: power_start: type=1 state=1 reporter-2375 [000] 2061.346876: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=2 reporter-2375 [000] 2061.346879: xn_nucleus_sched: status=42000000 reporter-2375 [000] 2061.346885: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 reporter-2375 [000] 2061.346887: xn_nucleus_sched: status=42000000 reporter-2375 [000] 2061.346888: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.346904: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=1288722930643849784 timeout_mode=2 wchan=(null) raw_test-2366 [000] 2061.346907: xn_nucleus_sched: status=42000000 raw_test-2366 [000] 2061.346909: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 reporter-2375 [000] 2061.346915: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.346921: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.346926: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.346928: hrtimer_cancel: hrtimer=c4803d88 reporter-2375 [000] 2061.346930: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.346932: hrtimer_expire_entry: hrtimer=c4803d88 function=tick_sched_timer now=2064304056612 reporter-2375 [000] 2061.346934: lock_acquire: c09aead4 xtime_lock reporter-2375 [000] 2061.346939: lock_release: c09aead4 xtime_lock reporter-2375 [000] 2061.346943: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.346947: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.346959: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346963: sched_stat_runtime: comm=reporter pid=2375 runtime=536453 [ns] vruntime=67439991469 [ns] reporter-2375 [000] 2061.346965: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.346968: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.346971: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346975: lock_acquire: c4b4d8d0 try std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346980: lock_release: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.346986: hrtimer_expire_exit: hrtimer=c4803d88 reporter-2375 [000] 2061.346988: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.346993: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.346997: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.346998: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347001: hrtimer_start: hrtimer=c4803d88 function=tick_sched_timer expires=2064305000000 softexpires=2064305000000 reporter-2375 [000] 2061.347003: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) -0 [001] 2061.347003: lock_acquire: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.347008: lock_release: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.347010: hrtimer_cancel: hrtimer=c4a03d88 reporter-2375 [000] 2061.347012: softirq_entry: vec=1 [action=TIMER] reporter-2375 [000] 2061.347015: lock_acquire: c0c73190 &std_spinlock(&base->lock)->rlock -0 [001] 2061.347017: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347023: lock_acquire: c12ee560 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.347024: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347028: lock_release: c12ee560 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.347030: lock_acquire: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347030: timer_cancel: timer=f439cb24 reporter-2375 [000] 2061.347032: lock_release: c0c73190 &std_spinlock(&base->lock)->rlock -0 [001] 2061.347035: lock_release: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347036: lock_acquire: f1087c9c &(&tty->buf.work)->timer -0 [001] 2061.347037: hrtimer_start: hrtimer=c4a03d88 function=tick_sched_timer expires=2064305125000 softexpires=2064305125000 reporter-2375 [000] 2061.347038: timer_expire_entry: timer=f439cb24 function=delayed_work_timer_fn now=1764304 reporter-2375 [000] 2061.347041: lock_acquire: c12ee560 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.347043: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347046: lock_release: c12ee560 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.347050: lock_acquire: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347052: lock_acquire: c494e410 &std_spinlock(&cwq->lock)->rlock -0 [001] 2061.347055: lock_release: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347059: lock_acquire: c494aadc &std_spinlock(&(&(*({ do { const void *__vpp_verify = (typeof((&(all_workqueue_stat))))((void *)0); (void)__vpp_verify; } while (0); ({ unsigned long __ptr; __asm__ ("" : "=r"(__ptr) : "0"((typeof(*(&(all_workqueue_stat))) *)(&(all_workqueue_stat)))); (typeof((typeof(*(&(all_workqueue_stat))) *)(&(all_workqueue_stat)))) (__ptr + (((__per_cpu_offset[cpu])))); }); })))->lock)->rlock -0 [001] 2061.347062: lock_acquire: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347065: lock_release: c494aadc &std_spinlock(&(&(*({ do { const void *__vpp_verify = (typeof((&(all_workqueue_stat))))((void *)0); (void)__vpp_verify; } while (0); ({ unsigned long __ptr; __asm__ ("" : "=r"(__ptr) : "0"((typeof(*(&(all_workqueue_stat))) *)(&(all_workqueue_stat)))); (typeof((typeof(*(&(all_workqueue_stat))) *)(&(all_workqueue_stat)))) (__ptr + (((__per_cpu_offset[cpu])))); }); })))->lock)->rlock -0 [001] 2061.347068: lock_release: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347068: workqueue_insertion: thread=events/0:15 func=flush_to_ldisc reporter-2375 [000] 2061.347071: lock_acquire: c494e43c key -0 [001] 2061.347074: lock_acquire: f70e0010 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.347077: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.347079: lock_release: f70e0010 &std_spinlock(&base->lock)->rlock -0 [001] 2061.347083: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347083: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347086: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.347087: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347091: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.347093: power_start: type=1 state=1 reporter-2375 [000] 2061.347094: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347103: sched_stat_runtime: comm=reporter pid=2375 runtime=139896 [ns] vruntime=67440131365 [ns] reporter-2375 [000] 2061.347105: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.347108: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.347111: sched_stat_sleep: comm=events/0 pid=15 delay=1000070554 [ns] reporter-2375 [000] 2061.347111: sched_wakeup: comm=events/0 pid=15 prio=120 success=1 target_cpu=000 reporter-2375 [000] 2061.347114: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347118: lock_release: c494e43c key reporter-2375 [000] 2061.347123: lock_release: c494e410 &std_spinlock(&cwq->lock)->rlock reporter-2375 [000] 2061.347126: timer_expire_exit: timer=f439cb24 reporter-2375 [000] 2061.347128: lock_release: f1087c9c &(&tty->buf.work)->timer reporter-2375 [000] 2061.347132: lock_acquire: c0c73190 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.347137: lock_release: c0c73190 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.347139: softirq_exit: vec=1 [action=TIMER] reporter-2375 [000] 2061.347140: softirq_entry: vec=7 [action=SCHED] reporter-2375 [000] 2061.347145: softirq_exit: vec=7 [action=SCHED] reporter-2375 [000] 2061.347145: softirq_entry: vec=9 [action=RCU] reporter-2375 [000] 2061.347154: lock_acquire: c09f7e90 rcu_node_level_0 reporter-2375 [000] 2061.347159: lock_release: c09f7e90 rcu_node_level_0 reporter-2375 [000] 2061.347171: softirq_exit: vec=9 [action=RCU] reporter-2375 [000] 2061.347179: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347184: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347190: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347196: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347201: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347205: lock_release: f4398a34 key reporter-2375 [000] 2061.347211: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347216: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347221: lock_release: f4398a34 key reporter-2375 [000] 2061.347228: lock_release: f4398d94 &tty->atomic_write_lock reporter-2375 [000] 2061.347233: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347238: lock_release: f4398a34 key reporter-2375 [000] 2061.347249: kfree: call_site=c047fe89 ptr=(null) reporter-2375 [000] 2061.347250: sys_write -> 0xa reporter-2375 [000] 2061.347253: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347258: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347261: sys_exit: NR 4 = 10 reporter-2375 [000] 2061.347271: sys_write(fd: 1, buf: b7888000, count: 36) reporter-2375 [000] 2061.347274: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347278: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347282: sys_enter: NR 4 (1, b7888000, 36, 36, b7888000, b7892ad4) reporter-2375 [000] 2061.347284: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.347288: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.347294: lock_acquire: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.347299: lock_release: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.347304: lock_acquire: f4398d94 try &tty->atomic_write_lock reporter-2375 [000] 2061.347311: lock_acquire: c1de0e24 read &mm->mmap_sem reporter-2375 [000] 2061.347314: lock_release: c1de0e24 &mm->mmap_sem reporter-2375 [000] 2061.347319: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347324: lock_release: f4398a34 key reporter-2375 [000] 2061.347330: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347340: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347345: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347351: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347355: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347362: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347368: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347371: sched_wakeup: comm=reporter pid=2375 prio=120 success=0 target_cpu=000 reporter-2375 [000] 2061.347373: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347378: lock_release: f4398a34 key reporter-2375 [000] 2061.347383: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347389: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347399: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347404: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347410: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347414: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347421: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347427: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347432: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347436: lock_release: f4398a34 key reporter-2375 [000] 2061.347441: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347447: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347451: lock_release: f4398a34 key reporter-2375 [000] 2061.347458: lock_release: f4398d94 &tty->atomic_write_lock reporter-2375 [000] 2061.347464: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347468: lock_release: f4398a34 key reporter-2375 [000] 2061.347479: kfree: call_site=c047fe89 ptr=(null) reporter-2375 [000] 2061.347480: sys_write -> 0x36 reporter-2375 [000] 2061.347482: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347487: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347490: sys_exit: NR 4 = 54 reporter-2375 [000] 2061.347498: sys_write(fd: 1, buf: b7888000, count: 36) reporter-2375 [000] 2061.347501: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347506: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347509: sys_enter: NR 4 (1, b7888000, 36, 36, b7888000, b7892ad4) reporter-2375 [000] 2061.347511: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.347515: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.347521: lock_acquire: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.347526: lock_release: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.347531: lock_acquire: f4398d94 try &tty->atomic_write_lock reporter-2375 [000] 2061.347538: lock_acquire: c1de0e24 read &mm->mmap_sem reporter-2375 [000] 2061.347541: lock_release: c1de0e24 &mm->mmap_sem reporter-2375 [000] 2061.347546: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347551: lock_release: f4398a34 key reporter-2375 [000] 2061.347557: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347567: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347572: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347578: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347583: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347589: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347595: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347598: sched_wakeup: comm=reporter pid=2375 prio=120 success=0 target_cpu=000 reporter-2375 [000] 2061.347600: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347604: lock_release: f4398a34 key reporter-2375 [000] 2061.347610: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347616: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347626: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347631: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347637: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347641: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347648: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347654: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347658: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347662: lock_release: f4398a34 key reporter-2375 [000] 2061.347668: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.347674: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347678: lock_release: f4398a34 key reporter-2375 [000] 2061.347685: lock_release: f4398d94 &tty->atomic_write_lock reporter-2375 [000] 2061.347690: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347695: lock_release: f4398a34 key reporter-2375 [000] 2061.347706: kfree: call_site=c047fe89 ptr=(null) reporter-2375 [000] 2061.347706: sys_write -> 0x36 reporter-2375 [000] 2061.347709: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347714: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347717: sys_exit: NR 4 = 54 reporter-2375 [000] 2061.347728: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 reporter-2375 [000] 2061.347731: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.347733: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.347781: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=2 timeout=500000 timeout_mode=0 wchan=c1c0f864 raw_test-2366 [000] 2061.347783: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.347785: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 reporter-2375 [000] 2061.347789: sys_write(fd: 1, buf: b7888000, count: 36) reporter-2375 [000] 2061.347792: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.347796: lock_release: c09f8940 trace_wait.lock -0 [001] 2061.347797: power_start: type=1 state=1 reporter-2375 [000] 2061.347800: sys_enter: NR 4 (1, b7888000, 36, 36, b7888000, b7892ad4) reporter-2375 [000] 2061.347805: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.347809: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.347815: lock_acquire: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.347820: lock_release: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.347825: lock_acquire: f4398d94 try &tty->atomic_write_lock reporter-2375 [000] 2061.347832: lock_acquire: c1de0e24 read &mm->mmap_sem reporter-2375 [000] 2061.347835: lock_release: c1de0e24 &mm->mmap_sem reporter-2375 [000] 2061.347840: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347845: lock_release: f4398a34 key reporter-2375 [000] 2061.347851: lock_acquire: f4398de4 &tty->output_lock -0 [003] 2061.347855: xn_nucleus_thread_resume: thread=f9bf7b00 thread_name=rtnet-stack mask=2 -0 [003] 2061.347862: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.347866: xn_nucleus_sched_remote: status=0 -0 [003] 2061.347867: power_start: type=1 state=1 reporter-2375 [000] 2061.347870: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347878: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347882: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347885: hrtimer_cancel: hrtimer=c4803d88 reporter-2375 [000] 2061.347887: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347888: hrtimer_expire_entry: hrtimer=c4803d88 function=tick_sched_timer now=2064305012676 reporter-2375 [000] 2061.347891: lock_acquire: c09aead4 xtime_lock reporter-2375 [000] 2061.347896: lock_release: c09aead4 xtime_lock reporter-2375 [000] 2061.347900: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.347903: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.347913: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347917: sched_stat_runtime: comm=reporter pid=2375 runtime=815889 [ns] vruntime=67440947254 [ns] reporter-2375 [000] 2061.347919: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.347922: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.347926: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.347928: hrtimer_expire_exit: hrtimer=c4803d88 reporter-2375 [000] 2061.347930: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347936: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347940: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.347943: hrtimer_start: hrtimer=c4803d88 function=tick_sched_timer expires=2064306000000 softexpires=2064306000000 reporter-2375 [000] 2061.347945: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.347954: softirq_entry: vec=1 [action=TIMER] reporter-2375 [000] 2061.347957: lock_acquire: c0c73190 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.347961: lock_release: c0c73190 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.347964: softirq_exit: vec=1 [action=TIMER] reporter-2375 [000] 2061.347972: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347976: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347982: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347987: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.347993: lock_acquire: f4398a34 key reporter-2375 [000] 2061.347999: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348002: sched_wakeup: comm=reporter pid=2375 prio=120 success=0 target_cpu=000 reporter-2375 [000] 2061.348005: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348009: lock_release: f4398a34 key reporter-2375 [000] 2061.348015: lock_release: f4398de4 &tty->output_lock -0 [001] 2061.348020: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348023: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.348026: lock_acquire: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.348028: sched_stat_wait: comm=reporter pid=2375 delay=0 [ns] reporter-2375 [000] 2061.348030: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.348031: lock_release: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.348033: hrtimer_cancel: hrtimer=c4a03d88 reporter-2375 [000] 2061.348034: lock_acquire: f4398de4 &tty->output_lock -0 [001] 2061.348035: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) -0 [001] 2061.348037: hrtimer_expire_entry: hrtimer=c4a03d88 function=tick_sched_timer now=2064305163132 reporter-2375 [000] 2061.348045: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348047: lock_acquire: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348050: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348052: lock_release: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348056: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348057: hrtimer_expire_exit: hrtimer=c4a03d88 -0 [001] 2061.348059: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348060: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348065: lock_acquire: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.348067: lock_acquire: f4398a34 key -0 [001] 2061.348070: lock_release: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.348072: hrtimer_start: hrtimer=c4a03d88 function=tick_sched_timer expires=2064306125000 softexpires=2064306125000 reporter-2375 [000] 2061.348073: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.348074: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348078: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348082: lock_release: f4398a34 key -0 [001] 2061.348084: softirq_entry: vec=1 [action=TIMER] -0 [001] 2061.348087: lock_acquire: f70e0010 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.348087: lock_release: f4398de4 &tty->output_lock -0 [001] 2061.348092: lock_release: f70e0010 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.348093: lock_acquire: f4398a34 key -0 [001] 2061.348094: softirq_exit: vec=1 [action=TIMER] -0 [001] 2061.348095: softirq_entry: vec=7 [action=SCHED] reporter-2375 [000] 2061.348098: lock_release: f4398a34 key -0 [001] 2061.348103: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348104: lock_release: f4398d94 &tty->atomic_write_lock -0 [001] 2061.348108: lock_acquire: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348110: lock_acquire: f4398a34 key -0 [001] 2061.348112: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.348115: lock_release: f4398a34 key -0 [001] 2061.348115: lock_acquire: c09f4ee4 read rcu_read_lock -0 [001] 2061.348119: lock_release: c09f4ee4 rcu_read_lock -0 [001] 2061.348122: lock_release: c09f4ee4 rcu_read_lock -0 [001] 2061.348125: lock_release: c4b4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348126: kfree: call_site=c047fe89 ptr=(null) reporter-2375 [000] 2061.348126: sys_write -> 0x36 reporter-2375 [000] 2061.348127: sys_exit: NR 4 = 54 -0 [001] 2061.348128: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348135: sys_write(fd: 1, buf: b7888000, count: 36) reporter-2375 [000] 2061.348138: lock_acquire: c09f8940 trace_wait.lock -0 [001] 2061.348138: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348143: lock_release: c09f8940 trace_wait.lock -0 [001] 2061.348143: lock_acquire: c4d4d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348146: sys_enter: NR 4 (1, b7888000, 36, 36, b7888000, b7892ad4) -0 [001] 2061.348148: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.348149: lock_acquire: c09f4ee4 read rcu_read_lock -0 [001] 2061.348151: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.348153: lock_release: c09f4ee4 rcu_read_lock -0 [001] 2061.348154: lock_release: c09f4ee4 rcu_read_lock -0 [001] 2061.348157: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.348159: lock_acquire: c0a11da0 tty_ldisc_lock -0 [001] 2061.348160: lock_release: c4d4d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.348163: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348163: lock_release: c0a11da0 tty_ldisc_lock reporter-2375 [000] 2061.348169: lock_acquire: f4398d94 try &tty->atomic_write_lock -0 [001] 2061.348173: softirq_exit: vec=7 [action=SCHED] -0 [001] 2061.348174: softirq_entry: vec=9 [action=RCU] reporter-2375 [000] 2061.348175: lock_acquire: c1de0e24 read &mm->mmap_sem reporter-2375 [000] 2061.348179: lock_release: c1de0e24 &mm->mmap_sem reporter-2375 [000] 2061.348184: lock_acquire: f4398a34 key reporter-2375 [000] 2061.348189: lock_release: f4398a34 key -0 [001] 2061.348189: lock_acquire: c09f8050 rcu_node_level_0 -0 [001] 2061.348193: lock_release: c09f8050 rcu_node_level_0 reporter-2375 [000] 2061.348195: lock_acquire: f4398de4 &tty->output_lock -0 [001] 2061.348197: softirq_exit: vec=9 [action=RCU] -0 [001] 2061.348204: lock_acquire: f70e0010 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.348205: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348208: lock_release: f70e0010 &std_spinlock(&base->lock)->rlock reporter-2375 [000] 2061.348210: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348212: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348216: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348217: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348221: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock -0 [001] 2061.348224: power_start: type=1 state=1 reporter-2375 [000] 2061.348227: lock_acquire: f4398a34 key reporter-2375 [000] 2061.348235: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348238: sched_wakeup: comm=reporter pid=2375 prio=120 success=0 target_cpu=000 reporter-2375 [000] 2061.348241: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348245: lock_release: f4398a34 key reporter-2375 [000] 2061.348251: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.348257: lock_acquire: f4398de4 &tty->output_lock reporter-2375 [000] 2061.348267: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.348271: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.348277: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.348282: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 reporter-2375 [000] 2061.348285: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.348287: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f9bf7b00 next_name=rtnet-stack reporter-2375 [000] 2061.348300: xn_nucleus_thread_suspend: thread=f9bf7b00 thread_name=rtnet-stack mask=2 timeout=0 timeout_mode=0 wchan=f9bf8080 reporter-2375 [000] 2061.348302: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.348303: xn_nucleus_sched_switch: prev=f9bf7b00 prev_name=rtnet-stack next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.348321: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=4 timeout=10000 timeout_mode=0 wchan=(null) raw_test-2366 [000] 2061.348325: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.348327: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 reporter-2375 [000] 2061.348333: xn_nucleus_thread_resume: thread=f99e7a40 thread_name=raw_test mask=4 reporter-2375 [000] 2061.348336: xn_nucleus_sched: status=2000000 reporter-2375 [000] 2061.348338: xn_nucleus_sched_switch: prev=f9465880 prev_name=ROOT/0 next=f99e7a40 next_name=raw_test raw_test-2366 [000] 2061.348361: xn_nucleus_thread_suspend: thread=f99e7a40 thread_name=raw_test mask=512 timeout=0 timeout_mode=0 wchan=(null) raw_test-2366 [000] 2061.348364: xn_nucleus_sched: status=2000000 raw_test-2366 [000] 2061.348366: xn_nucleus_sched_switch: prev=f99e7a40 prev_name=raw_test next=f9465880 next_name=ROOT/0 reporter-2375 [000] 2061.348371: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock reporter-2375 [000] 2061.348380: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348385: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348388: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348397: lock_acquire: f7110914 std_spinlock_raw(&vec->lock) reporter-2375 [000] 2061.348401: lock_release: f7110914 std_spinlock_raw(&vec->lock) reporter-2375 [000] 2061.348406: lock_acquire: f7110050 std_spinlock_raw(&vec->lock) reporter-2375 [000] 2061.348411: lock_release: f7110050 std_spinlock_raw(&vec->lock) reporter-2375 [000] 2061.348415: lock_acquire: c0c312cc std_spinlock_raw(&rt_b->rt_runtime_lock) reporter-2375 [000] 2061.348422: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348427: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348430: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348436: lock_acquire: c12f7160 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.348441: lock_release: c12f7160 std_spinlock_raw(&obj_hash[i].lock) reporter-2375 [000] 2061.348443: hrtimer_start: hrtimer=c0c312f0 function=sched_rt_period_timer expires=2065000000000 softexpires=2065000000000 reporter-2375 [000] 2061.348446: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) reporter-2375 [000] 2061.348450: lock_release: c0c312cc std_spinlock_raw(&rt_b->rt_runtime_lock) reporter-2375 [000] 2061.348451: sched_wakeup: comm=raw_test pid=2366 prio=49 success=1 target_cpu=000 reporter-2375 [000] 2061.348454: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348462: lock_acquire: f4398a34 key reporter-2375 [000] 2061.348468: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348473: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348477: lock_release: f4398a34 key reporter-2375 [000] 2061.348483: lock_release: f4398de4 &tty->output_lock reporter-2375 [000] 2061.348489: lock_acquire: f4398a34 key reporter-2375 [000] 2061.348493: lock_release: f4398a34 key reporter-2375 [000] 2061.348500: lock_release: f4398d94 &tty->atomic_write_lock reporter-2375 [000] 2061.348505: lock_acquire: f4398a34 key reporter-2375 [000] 2061.348510: lock_release: f4398a34 key reporter-2375 [000] 2061.348521: kfree: call_site=c047fe89 ptr=(null) reporter-2375 [000] 2061.348521: sys_write -> 0x36 reporter-2375 [000] 2061.348524: lock_acquire: c09f8940 trace_wait.lock reporter-2375 [000] 2061.348529: lock_release: c09f8940 trace_wait.lock reporter-2375 [000] 2061.348532: sys_exit: NR 4 = 54 reporter-2375 [000] 2061.348536: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) reporter-2375 [000] 2061.348540: sched_stat_runtime: comm=reporter pid=2375 runtime=623246 [ns] vruntime=67441570500 [ns] reporter-2375 [000] 2061.348542: lock_acquire: c09f4ee4 read rcu_read_lock reporter-2375 [000] 2061.348546: lock_release: c09f4ee4 rcu_read_lock reporter-2375 [000] 2061.348551: sched_switch: prev_comm=reporter prev_pid=2375 prev_prio=120 prev_state=R ==> next_comm=raw_test next_pid=2366 next_prio=49 reporter-2375 [000] 2061.348552: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348557: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348560: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348566: sys_write(fd: 2, buf: bfc21010, count: 3) raw_test-2366 [000] 2061.348568: lock_acquire: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.348573: lock_release: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.348576: sys_enter: NR 4 (2, bfc21010, 3, 3, bfc21010, bfc20fa8) raw_test-2366 [000] 2061.348579: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.348583: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.348589: lock_acquire: c0a11da0 tty_ldisc_lock raw_test-2366 [000] 2061.348594: lock_release: c0a11da0 tty_ldisc_lock raw_test-2366 [000] 2061.348600: lock_acquire: f4398d94 try &tty->atomic_write_lock raw_test-2366 [000] 2061.348606: lock_acquire: c1de0e24 read &mm->mmap_sem raw_test-2366 [000] 2061.348609: lock_release: c1de0e24 &mm->mmap_sem raw_test-2366 [000] 2061.348614: lock_acquire: f4398a34 key raw_test-2366 [000] 2061.348619: lock_release: f4398a34 key raw_test-2366 [000] 2061.348625: lock_acquire: f4398de4 &tty->output_lock raw_test-2366 [000] 2061.348635: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348640: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348645: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348650: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348656: lock_acquire: f4398a34 key raw_test-2366 [000] 2061.348662: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348665: sched_wakeup: comm=raw_test pid=2366 prio=49 success=0 target_cpu=000 raw_test-2366 [000] 2061.348668: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348672: lock_release: f4398a34 key raw_test-2366 [000] 2061.348678: lock_release: f4398de4 &tty->output_lock raw_test-2366 [000] 2061.348684: lock_acquire: f4398de4 &tty->output_lock raw_test-2366 [000] 2061.348694: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348699: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348705: lock_acquire: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348709: lock_release: f439cb7c &std_spinlock(&tty->buf.lock)->rlock raw_test-2366 [000] 2061.348716: lock_acquire: f4398a34 key raw_test-2366 [000] 2061.348722: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348726: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348730: lock_release: f4398a34 key raw_test-2366 [000] 2061.348736: lock_release: f4398de4 &tty->output_lock raw_test-2366 [000] 2061.348742: lock_acquire: f4398a34 key raw_test-2366 [000] 2061.348746: lock_release: f4398a34 key raw_test-2366 [000] 2061.348753: lock_release: f4398d94 &tty->atomic_write_lock raw_test-2366 [000] 2061.348758: lock_acquire: f4398a34 key raw_test-2366 [000] 2061.348763: lock_release: f4398a34 key raw_test-2366 [000] 2061.348774: kfree: call_site=c047fe89 ptr=(null) raw_test-2366 [000] 2061.348775: sys_write -> 0x3 raw_test-2366 [000] 2061.348777: lock_acquire: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.348782: lock_release: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.348785: sys_exit: NR 4 = 3 raw_test-2366 [000] 2061.348806: sys_open(filename: 8049e4c, flags: 2, mode: 1702022b) raw_test-2366 [000] 2061.348809: lock_acquire: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.348814: lock_release: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.348818: sys_enter: NR 5 (8049e4c, 2, 1702022b, 90, 27, bfc23688) raw_test-2366 [000] 2061.348839: kmem_cache_alloc: call_site=c04f44c9 ptr=f5b52080 bytes_req=4096 bytes_alloc=4160 gfp_flags=GFP_KERNEL raw_test-2366 [000] 2061.348842: lock_acquire: c1de0e24 read &mm->mmap_sem raw_test-2366 [000] 2061.348845: lock_release: c1de0e24 &mm->mmap_sem raw_test-2366 [000] 2061.348850: lock_acquire: c1dd0550 &std_spinlock(&newf->file_lock)->rlock raw_test-2366 [000] 2061.348862: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.348868: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.348872: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.348875: hrtimer_cancel: hrtimer=c4803d88 raw_test-2366 [000] 2061.348877: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.348879: hrtimer_expire_entry: hrtimer=c4803d88 function=tick_sched_timer now=2064306006132 raw_test-2366 [000] 2061.348881: lock_acquire: c09aead4 xtime_lock raw_test-2366 [000] 2061.348886: lock_release: c09aead4 xtime_lock raw_test-2366 [000] 2061.348890: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.348893: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.348905: lock_acquire: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348911: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.348914: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.348917: lock_acquire: c494dd04 std_spinlock_raw(&rt_rq->rt_runtime_lock) raw_test-2366 [000] 2061.348922: lock_release: c494dd04 std_spinlock_raw(&rt_rq->rt_runtime_lock) raw_test-2366 [000] 2061.348925: lock_release: c494d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.348928: hrtimer_expire_exit: hrtimer=c4803d88 raw_test-2366 [000] 2061.348930: lock_acquire: c4803ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.348935: lock_acquire: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.348940: lock_release: c12a0ea0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.348942: hrtimer_start: hrtimer=c4803d88 function=tick_sched_timer expires=2064307000000 softexpires=2064307000000 raw_test-2366 [000] 2061.348944: lock_release: c4803ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.348954: softirq_entry: vec=1 [action=TIMER] raw_test-2366 [000] 2061.348957: lock_acquire: c0c73190 &std_spinlock(&base->lock)->rlock raw_test-2366 [000] 2061.348962: lock_release: c0c73190 &std_spinlock(&base->lock)->rlock raw_test-2366 [000] 2061.348964: softirq_exit: vec=1 [action=TIMER] raw_test-2366 [000] 2061.348965: softirq_entry: vec=9 [action=RCU] raw_test-2366 [000] 2061.348973: lock_acquire: c09f7e90 rcu_node_level_0 raw_test-2366 [000] 2061.348978: lock_release: c09f7e90 rcu_node_level_0 raw_test-2366 [000] 2061.348987: softirq_exit: vec=9 [action=RCU] raw_test-2366 [000] 2061.348994: lock_release: c1dd0550 &std_spinlock(&newf->file_lock)->rlock -0 [001] 2061.348998: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.348999: lock_acquire: c1dfc194 read &fs->lock -0 [001] 2061.349004: lock_acquire: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349005: lock_release: c1dfc194 &fs->lock -0 [001] 2061.349009: lock_release: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349011: lock_acquire: c09f4ee4 read rcu_read_lock -0 [001] 2061.349012: hrtimer_cancel: hrtimer=c4a03d88 -0 [001] 2061.349014: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.349015: lock_acquire: f6686358 &std_spinlock(&dentry->d_lock)->rlock -0 [001] 2061.349015: hrtimer_expire_entry: hrtimer=c4a03d88 function=tick_sched_timer now=2064306142762 raw_test-2366 [000] 2061.349021: lock_release: f6686358 &std_spinlock(&dentry->d_lock)->rlock raw_test-2366 [000] 2061.349025: lock_release: c09f4ee4 rcu_read_lock -0 [001] 2061.349025: lock_acquire: c4b4d8d0 std_spinlock_raw(&rq->lock) raw_test-2366 [000] 2061.349029: lock_acquire: c09ebf50 vfsmount_lock -0 [001] 2061.349030: lock_release: c4b4d8d0 std_spinlock_raw(&rq->lock) -0 [001] 2061.349033: hrtimer_expire_exit: hrtimer=c4a03d88 -0 [001] 2061.349035: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.349036: lock_release: c09ebf50 vfsmount_lock -0 [001] 2061.349040: lock_acquire: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349043: lock_acquire: c09fe728 sysfs_mutex -0 [001] 2061.349045: lock_release: c12e5aa0 std_spinlock_raw(&obj_hash[i].lock) -0 [001] 2061.349048: hrtimer_start: hrtimer=c4a03d88 function=tick_sched_timer expires=2064307125000 softexpires=2064307125000 -0 [001] 2061.349050: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.349054: lock_release: c09fe728 sysfs_mutex -0 [001] 2061.349059: softirq_entry: vec=1 [action=TIMER] raw_test-2366 [000] 2061.349059: lock_acquire: c09f4ee4 read rcu_read_lock -0 [001] 2061.349062: lock_acquire: f70e0010 &std_spinlock(&base->lock)->rlock raw_test-2366 [000] 2061.349063: lock_acquire: f66860e8 &std_spinlock(&dentry->d_lock)->rlock -0 [001] 2061.349067: lock_release: f70e0010 &std_spinlock(&base->lock)->rlock -0 [001] 2061.349069: softirq_exit: vec=1 [action=TIMER] raw_test-2366 [000] 2061.349070: lock_release: f66860e8 &std_spinlock(&dentry->d_lock)->rlock -0 [001] 2061.349070: softirq_entry: vec=9 [action=RCU] raw_test-2366 [000] 2061.349073: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349079: lock_acquire: c09fe728 sysfs_mutex -0 [001] 2061.349085: lock_acquire: c09f8050 rcu_node_level_0 raw_test-2366 [000] 2061.349088: lock_release: c09fe728 sysfs_mutex -0 [001] 2061.349089: lock_release: c09f8050 rcu_node_level_0 -0 [001] 2061.349093: softirq_exit: vec=9 [action=RCU] raw_test-2366 [000] 2061.349095: lock_acquire: c09fe728 sysfs_mutex -0 [001] 2061.349100: lock_acquire: f70e0010 &std_spinlock(&base->lock)->rlock -0 [001] 2061.349104: lock_release: f70e0010 &std_spinlock(&base->lock)->rlock raw_test-2366 [000] 2061.349105: lock_release: c09fe728 sysfs_mutex -0 [001] 2061.349108: lock_acquire: c4a03ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.349111: lock_acquire: c09f4ee4 read rcu_read_lock -0 [001] 2061.349113: lock_release: c4a03ce4 std_spinlock_raw(&cpu_base->lock) raw_test-2366 [000] 2061.349115: lock_acquire: f656bb78 &std_spinlock(&dentry->d_lock)->rlock -0 [001] 2061.349120: power_start: type=1 state=1 raw_test-2366 [000] 2061.349122: lock_release: f656bb78 &std_spinlock(&dentry->d_lock)->rlock raw_test-2366 [000] 2061.349125: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349130: lock_acquire: c09fe728 sysfs_mutex raw_test-2366 [000] 2061.349140: lock_release: c09fe728 sysfs_mutex raw_test-2366 [000] 2061.349145: lock_acquire: c09ebf50 vfsmount_lock raw_test-2366 [000] 2061.349152: lock_release: c09ebf50 vfsmount_lock raw_test-2366 [000] 2061.349158: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.349162: lock_acquire: f6c07428 &std_spinlock(&dentry->d_lock)->rlock raw_test-2366 [000] 2061.349168: lock_release: f6c07428 &std_spinlock(&dentry->d_lock)->rlock raw_test-2366 [000] 2061.349172: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349187: kmem_cache_alloc: call_site=c04ecdce ptr=f3639100 bytes_req=196 bytes_alloc=256 gfp_flags=GFP_KERNEL|GFP_ZERO raw_test-2366 [000] 2061.349191: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.349195: lock_acquire: f6c07de8 &std_spinlock(&dentry->d_lock)->rlock raw_test-2366 [000] 2061.349201: lock_release: f6c07de8 &std_spinlock(&dentry->d_lock)->rlock raw_test-2366 [000] 2061.349205: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349212: lock_acquire: f6c3938c &sb->s_type->i_lock_key raw_test-2366 [000] 2061.349219: lock_release: f6c3938c &sb->s_type->i_lock_key raw_test-2366 [000] 2061.349223: lock_acquire: c09ebe50 files_lock raw_test-2366 [000] 2061.349229: lock_release: c09ebe50 files_lock raw_test-2366 [000] 2061.349234: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.349238: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349243: lock_acquire: f7220e04 &iint->mutex raw_test-2366 [000] 2061.349253: lock_release: f7220e04 &iint->mutex raw_test-2366 [000] 2061.349259: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.349262: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349267: lock_acquire: f7220e04 &iint->mutex raw_test-2366 [000] 2061.349277: lock_release: f7220e04 &iint->mutex raw_test-2366 [000] 2061.349283: lock_acquire: c1dd0550 &std_spinlock(&newf->file_lock)->rlock raw_test-2366 [000] 2061.349290: lock_release: c1dd0550 &std_spinlock(&newf->file_lock)->rlock raw_test-2366 [000] 2061.349296: lock_acquire: c1291e78 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349301: lock_release: c1291e78 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349305: lock_acquire: c12f4ca8 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349310: lock_release: c12f4ca8 std_spinlock_raw(&obj_hash[i].lock) raw_test-2366 [000] 2061.349326: kmem_cache_free: call_site=c04f44a0 ptr=f5b52080 raw_test-2366 [000] 2061.349329: kfree: call_site=c047fe89 ptr=(null) raw_test-2366 [000] 2061.349330: sys_open -> 0x3 raw_test-2366 [000] 2061.349333: lock_acquire: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.349338: lock_release: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.349341: sys_exit: NR 5 = 3 raw_test-2366 [000] 2061.349348: sys_write(fd: 3, buf: 8049e71, count: 1) raw_test-2366 [000] 2061.349351: lock_acquire: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.349356: lock_release: c09f8940 trace_wait.lock raw_test-2366 [000] 2061.349359: sys_enter: NR 4 (3, 8049e71, 1, 90, 27, bfc23688) raw_test-2366 [000] 2061.349361: lock_acquire: c09f4ee4 read rcu_read_lock raw_test-2366 [000] 2061.349366: lock_release: c09f4ee4 rcu_read_lock raw_test-2366 [000] 2061.349371: lock_acquire: c1de0e24 read &mm->mmap_sem raw_test-2366 [000] 2061.349375: lock_release: c1de0e24 &mm->mmap_sem