Skip to content

Instantly share code, notes, and snippets.

@d3flex

d3flex/ibtest_trace.txt

Created January 18, 2022 13:09
Show Gist options

  • Select an option

    Learn more about clone URLs
  • Save d3flex/b1963dda0e4c33d86aa1196915bddcb4 to your computer and use it in GitHub Desktop.

Select an option

Learn more about clone URLs
Save d3flex/b1963dda0e4c33d86aa1196915bddcb4 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
ibtest_trace.txt
sonic-1:~ # less /var/log/messages | tail -n 50
2022-01-18T13:33:08.816649-05:00 sonic-1 kernel: [ 2038.926624][ C0] pending: vmstat_update, lru_add_drain_per_cpu BAR(105)
2022-01-18T13:33:08.816654-05:00 sonic-1 kernel: [ 2038.926668][ C0] workqueue ib_cm: flags=0x8
2022-01-18T13:33:08.854496-05:00 sonic-1 kernel: [ 2038.964451][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=1/1 refcnt=3
2022-01-18T13:33:08.854503-05:00 sonic-1 kernel: [ 2038.964456][ C0] pending: cm_work_handler [ib_cm]
2022-01-18T13:33:08.854504-05:00 sonic-1 kernel: [ 2038.964472][ C0] inactive: cm_work_handler [ib_cm]
2022-01-18T13:33:08.854505-05:00 sonic-1 kernel: [ 2038.964496][ C0] pool 20: cpus=10 node=0 flags=0x0 nice=0 hung=934s workers=3 idle: 12865 411
2022-01-18T13:33:39.472146-05:00 sonic-1 kernel: [ 2069.582102][ C0] BUG: workqueue lockup - pool cpus=10 node=0 flags=0x0 nice=0 stuck for 965s!
2022-01-18T13:33:39.480948-05:00 sonic-1 kernel: [ 2069.590909][ C0] Showing busy workqueues and worker pools:
2022-01-18T13:33:39.480956-05:00 sonic-1 kernel: [ 2069.590911][ C0] workqueue events: flags=0x0
2022-01-18T13:33:39.480958-05:00 sonic-1 kernel: [ 2069.590916][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=12/256 refcnt=13
2022-01-18T13:33:39.480959-05:00 sonic-1 kernel: [ 2069.590923][ C0] in-flight: 176:__svc_rdma_free [rpcrdma]
2022-01-18T13:33:39.548741-05:00 sonic-1 kernel: [ 2069.590953][ C0] pending: kfree_rcu_monitor, ib_cq_rdma_dim_work [ib_core], __svc_rdma_free [rpcrdma], free_work, rpc_free_client_work [sunrpc], rpc_free_client_work [sunrpc], pwq_unbound_release_workfn, pwq_unbound_release_workfn, nfsd_file_gc_worker [nfsd], irq_affinity_notify, irq_affinity_notify
2022-01-18T13:33:39.548747-05:00 sonic-1 kernel: [ 2069.591168][ C0] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 refcnt=2
2022-01-18T13:33:39.548748-05:00 sonic-1 kernel: [ 2069.591175][ C0] pending: vmstat_shepherd
2022-01-18T13:33:39.548750-05:00 sonic-1 kernel: [ 2069.591182][ C0] workqueue rcu_gp: flags=0x8
2022-01-18T13:33:39.548751-05:00 sonic-1 kernel: [ 2069.658710][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=2/256 refcnt=3
2022-01-18T13:33:39.548752-05:00 sonic-1 kernel: [ 2069.658716][ C0] pending: process_srcu, wait_rcu_exp_gp
2022-01-18T13:33:39.548753-05:00 sonic-1 kernel: [ 2069.658728][ C0] workqueue mm_percpu_wq: flags=0x8
2022-01-18T13:33:39.548754-05:00 sonic-1 kernel: [ 2069.658731][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=2/256 refcnt=4
2022-01-18T13:33:39.548755-05:00 sonic-1 kernel: [ 2069.658736][ C0] pending: vmstat_update, lru_add_drain_per_cpu BAR(105)
2022-01-18T13:33:39.548760-05:00 sonic-1 kernel: [ 2069.658782][ C0] workqueue ib_cm: flags=0x8
2022-01-18T13:33:39.586576-05:00 sonic-1 kernel: [ 2069.696549][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=1/1 refcnt=3
2022-01-18T13:33:39.586582-05:00 sonic-1 kernel: [ 2069.696555][ C0] pending: cm_work_handler [ib_cm]
2022-01-18T13:33:39.586583-05:00 sonic-1 kernel: [ 2069.696570][ C0] inactive: cm_work_handler [ib_cm]
2022-01-18T13:33:39.586588-05:00 sonic-1 kernel: [ 2069.696591][ C0] pool 20: cpus=10 node=0 flags=0x0 nice=0 hung=965s workers=3 idle: 12865 411
2022-01-18T13:34:08.535990-05:00 sonic-1 sshd[12896]: gkr-pam: unable to locate daemon control file
2022-01-18T13:34:08.536166-05:00 sonic-1 sshd[12896]: gkr-pam: stashed password to try later in open session
2022-01-18T13:34:08.543242-05:00 sonic-1 sshd[12894]: Accepted keyboard-interactive/pam for root from 10.162.6.237 port 43584 ssh2
2022-01-18T13:34:08.549901-05:00 sonic-1 systemd-logind[1083]: New session 5 of user root.
2022-01-18T13:34:08.550488-05:00 sonic-1 systemd[1]: Started Session 5 of User root.
2022-01-18T13:34:08.554390-05:00 sonic-1 sshd[12894]: pam_unix(sshd:session): session opened for user root by (uid=0)
2022-01-18T13:34:10.192147-05:00 sonic-1 kernel: [ 2100.302091][ C0] BUG: workqueue lockup - pool cpus=10 node=0 flags=0x0 nice=0 stuck for 996s!
2022-01-18T13:34:10.200963-05:00 sonic-1 kernel: [ 2100.310916][ C0] Showing busy workqueues and worker pools:
2022-01-18T13:34:10.200971-05:00 sonic-1 kernel: [ 2100.310918][ C0] workqueue events: flags=0x0
2022-01-18T13:34:10.200973-05:00 sonic-1 kernel: [ 2100.310921][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=13/256 refcnt=14
2022-01-18T13:34:10.200974-05:00 sonic-1 kernel: [ 2100.310929][ C0] in-flight: 176:__svc_rdma_free [rpcrdma]
2022-01-18T13:34:10.270841-05:00 sonic-1 kernel: [ 2100.310981][ C0] pending: kfree_rcu_monitor, ib_cq_rdma_dim_work [ib_core], __svc_rdma_free [rpcrdma], free_work, rpc_free_client_work [sunrpc], rpc_free_client_work [sunrpc], pwq_unbound_release_workfn, pwq_unbound_release_workfn, nfsd_file_gc_worker [nfsd], irq_affinity_notify, irq_affinity_notify, bpf_prog_free_deferred
2022-01-18T13:34:10.270851-05:00 sonic-1 kernel: [ 2100.311210][ C0] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 refcnt=2
2022-01-18T13:34:10.270852-05:00 sonic-1 kernel: [ 2100.311217][ C0] pending: vmstat_shepherd
2022-01-18T13:34:10.270853-05:00 sonic-1 kernel: [ 2100.311229][ C0] workqueue rcu_gp: flags=0x8
2022-01-18T13:34:10.270855-05:00 sonic-1 kernel: [ 2100.380789][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=2/256 refcnt=3
2022-01-18T13:34:10.270856-05:00 sonic-1 kernel: [ 2100.380795][ C0] pending: process_srcu, wait_rcu_exp_gp
2022-01-18T13:34:10.270858-05:00 sonic-1 kernel: [ 2100.380808][ C0] workqueue mm_percpu_wq: flags=0x8
2022-01-18T13:34:10.270859-05:00 sonic-1 kernel: [ 2100.380811][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=2/256 refcnt=4
2022-01-18T13:34:10.270860-05:00 sonic-1 kernel: [ 2100.380816][ C0] pending: vmstat_update, lru_add_drain_per_cpu BAR(105)
2022-01-18T13:34:10.308673-05:00 sonic-1 kernel: [ 2100.380903][ C0] workqueue ib_cm: flags=0x8
2022-01-18T13:34:10.308681-05:00 sonic-1 kernel: [ 2100.418637][ C0] pwq 20: cpus=10 node=0 flags=0x0 nice=0 active=1/1 refcnt=3
2022-01-18T13:34:10.308692-05:00 sonic-1 kernel: [ 2100.418642][ C0] pending: cm_work_handler [ib_cm]
2022-01-18T13:34:10.308693-05:00 sonic-1 kernel: [ 2100.418661][ C0] inactive: cm_work_handler [ib_cm]
2022-01-18T13:34:10.308701-05:00 sonic-1 kernel: [ 2100.418686][ C0] pool 20: cpus=10 node=0 flags=0x0 nice=0 hung=996s workers=3 idle: 12865 411
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment