Bug #4553
closedkclient: lockdep report, crash involving ceph fs and libceph
0%
Description
I really don't know what to assign this to, but it looks like
a big complex potential deadlock so I thought I should grab the
kernel output so someone else can take a look at it.
I'm testing using a kernel with some recent changes I've made,
but right now I don't think the following is related to that.
Here's the kernel being tested:
review/wip-4392-2 1655ae7 libceph: verify requests queued in order
It is based on the current testing branch:
8383641 libceph: wrap auth methods in a mutex
Here are the newer commits in the kernel being tested:
1655ae7 libceph: verify requests queued in order
532902a libceph: send queued requests when starting new one
b1e0294 libceph: keep request lists in tid order
317b8e1 libceph: requeue only sent requests when kicking
349cd3a libceph: no more kick_requests() race
76752dc libceph: slightly defer registering osd request
5128453 libceph: initialize data fields on last msg put
...
Here's the current state of the ceph "next" branch:
70e0ee8 rgw: bucket index ops on system buckets shouldn't do anything
Here's the state of teuthology I'm using:
c50b143 thrashosds: add test_backfill_full
OK, here's the yaml file:
interactive-on-error: roles: - [mon.a, mon.c, osd.0, osd.1, osd.2] - [mon.b, mds.a, osd.3, osd.4, osd.5] - [client.0] kernel: mon: branch: review_wip-4392-2 kdb: true client: branch: review_wip-4392-2 kdb: true overrides: ceph: conf: osd: osd op complaint time: 120 fs: btrfs log-whitelist: - clocks not synchronized - old request tasks: - install: - ceph: branch: next conf: global: ms inject socket failures: 5000 mon: debug mon: 10 debug paxos: osd: debug ms: 1 debug journal: 20 osd debug op order: true - kclient: - workunit: clients: all: - misc/trivial_sync.sh - kernel_untar_build.sh - suites/blogbench.sh - suites/dbench.sh - suites/tiobench.sh - suites/fsstress.sh - suites/ffsb.sh
The test that had just started was "suites/ffsb.sh". Here is
the end of the teuthology test output:
INFO:teuthology.task.workunit.client.0.out:make[1]: Leaving directory `/tmp/cephtest/mnt.0/client.0/tmp/ffsb-6.0-rc2' INFO:teuthology.task.workunit.client.0.out:FFSB version 6.0-RC2 started INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out:benchmark time = 300 INFO:teuthology.task.workunit.client.0.out:ThreadGroup 0 INFO:teuthology.task.workunit.client.0.out:================ INFO:teuthology.task.workunit.client.0.out: num_threads = 32 INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out: read_random = off INFO:teuthology.task.workunit.client.0.out: read_size = 0 (0B) INFO:teuthology.task.workunit.client.0.out: read_blocksize = 0 (0B) INFO:teuthology.task.workunit.client.0.out: read_skip = off INFO:teuthology.task.workunit.client.0.out: read_skipsize = 0 (0B) INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out: write_random = on INFO:teuthology.task.workunit.client.0.out: write_size = 5242880 (5MB) INFO:teuthology.task.workunit.client.0.out: fsync_file = 0 INFO:teuthology.task.workunit.client.0.out: write_blocksize = 4096 (4KB) INFO:teuthology.task.workunit.client.0.out: wait time = 0 INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out: op weights INFO:teuthology.task.workunit.client.0.out: read = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: readall = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: write = 1 (100.00%) INFO:teuthology.task.workunit.client.0.out: create = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: append = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: delete = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: metaop = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: createdir = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: stat = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: writeall = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: writeall_fsync = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: open_close = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: write_fsync = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: create_fsync = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: append_fsync = 0 (0.00%) INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out:FileSystem . INFO:teuthology.task.workunit.client.0.out:========== INFO:teuthology.task.workunit.client.0.out: num_dirs = 0 INFO:teuthology.task.workunit.client.0.out: starting files = 128 INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out: min file size = 104857600 (100MB) INFO:teuthology.task.workunit.client.0.out: max file size = 104857600 (100MB) INFO:teuthology.task.workunit.client.0.out: directio = off INFO:teuthology.task.workunit.client.0.out: alignedio = on INFO:teuthology.task.workunit.client.0.out: bufferedio = off INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out: aging is off INFO:teuthology.task.workunit.client.0.out: current utilization = 0.13% INFO:teuthology.task.workunit.client.0.out: INFO:teuthology.task.workunit.client.0.out:checking existing fs: . INFO:teuthology.task.workunit.client.0.out:recreating new fileset INFO:teuthology.task.workunit.client.0.err:opendir: No such file or directory INFO:teuthology.task.workunit.client.0.out:fs setup took 189 secs INFO:teuthology.task.workunit.client.0.out:Syncing()...10 sec INFO:teuthology.task.workunit.client.0.out:Starting Actual Benchmark At: Tue Mar 26 08:59:58 2013 INFO:teuthology.task.workunit.client.0.out:
The test now seems to be hung, which may be related (I think so).
It also eventually led to a crash (which may have been due to
other things, I'm just not sure yet).
Here's information captured from the console, describing the
lockdep issues.
[ 4559.235679] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4559.513882] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4559.574219] libceph: osd2 10.214.132.116:6806 socket closed (con state OPEN) [ 4559.664004] libceph: osd1 10.214.132.116:6803 socket closed (con state OPEN) [ 4559.772118] [ 4559.773638] ========================================================= [ 4559.780540] [ INFO: possible irq lock inversion dependency detected ] [ 4559.787021] 3.8.0-ceph-00226-g1655ae7 #1 Not tainted [ 4559.792001] --------------------------------------------------------- [ 4559.798452] kswapd0/38 just changed the state of lock: [ 4559.803608] (&osdc->map_sem){++++.-}, at: [<ffffffffa05e95a5>] ceph_osdc_start_request+0x65/0x170 [libceph] [ 4559.813556] but this lock took another, RECLAIM_FS-unsafe lock in the past: [ 4559.820526] (&monc->mutex){+.+.+.} and interrupts could create inverse lock ordering between them. [ 4559.830128] [ 4559.830128] other info that might help us debug this: [ 4559.836677] Possible interrupt unsafe locking scenario: [ 4559.836677] [ 4559.843487] CPU0 CPU1 [ 4559.848029] ---- ---- [ 4559.852572] lock(&monc->mutex); [ 4559.855948] local_irq_disable(); [ 4559.861878] lock(&osdc->map_sem); [ 4559.867932] lock(&monc->mutex); [ 4559.873816] <Interrupt> [ 4559.876451] lock(&osdc->map_sem); [ 4559.880176] [ 4559.880176] *** DEADLOCK *** [ 4559.880176] [ 4559.886133] no locks held by kswapd0/38. [ 4559.890073] [ 4559.890073] the shortest dependencies between 2nd lock and 1st lock: [ 4559.899088] -> (&monc->mutex){+.+.+.} ops: 181682 { [ 4559.904181] HARDIRQ-ON-W at: [ 4559.907442] [<ffffffff810b50bd>] __lock_acquire+0x67d/0x1d10 [ 4559.915060] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4559.922321] [<ffffffff8165aadb>] mutex_lock_nested+0x4b/0x320 [ 4559.930023] [<ffffffffa05e5f36>] ceph_monc_open_session+0x26/0x50 [libceph] [ 4559.938954] [<ffffffffa05de26a>] __ceph_open_session+0x3a/0x250 [libceph] [ 4559.947728] [<ffffffffa06241ed>] ceph_mount+0x37d/0x840 [ceph] [ 4559.955522] [<ffffffff81187ba3>] mount_fs+0x43/0x1b0 [ 4559.962429] [<ffffffff811a2fc6>] vfs_kern_mount+0x76/0x120 [ 4559.969868] [<ffffffff811a5284>] do_mount+0x1f4/0xa20 [ 4559.976881] [<ffffffff811a5b40>] sys_mount+0x90/0xe0 [ 4559.983787] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4559.991657] SOFTIRQ-ON-W at: [ 4559.994925] [<ffffffff810b50f5>] __lock_acquire+0x6b5/0x1d10 [ 4560.002534] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.009803] [<ffffffff8165aadb>] mutex_lock_nested+0x4b/0x320 [ 4560.017503] [<ffffffffa05e5f36>] ceph_monc_open_session+0x26/0x50 [libceph] [ 4560.026421] [<ffffffffa05de26a>] __ceph_open_session+0x3a/0x250 [libceph] [ 4560.035167] [<ffffffffa06241ed>] ceph_mount+0x37d/0x840 [ceph] [ 4560.042961] [<ffffffff81187ba3>] mount_fs+0x43/0x1b0 [ 4560.049870] [<ffffffff811a2fc6>] vfs_kern_mount+0x76/0x120 [ 4560.057308] [<ffffffff811a5284>] do_mount+0x1f4/0xa20 [ 4560.064301] [<ffffffff811a5b40>] sys_mount+0x90/0xe0 [ 4560.071208] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4560.079081] RECLAIM_FS-ON-W at: [ 4560.082606] [<ffffffff810b75e6>] mark_held_locks+0x86/0x140 [ 4560.090389] [<ffffffff810b7d41>] lockdep_trace_alloc+0x71/0xd0 [ 4560.098437] [<ffffffff8117b023>] kmem_cache_alloc_trace+0x33/0x150 [ 4560.106831] [<ffffffff810705b2>] __request_module+0x112/0x280 [ 4560.114791] [<ffffffff812feb3c>] crypto_larval_lookup+0x8c/0x180 [ 4560.123020] [<ffffffff812fec53>] crypto_alg_mod_lookup+0x23/0x90 [ 4560.131241] [<ffffffff812fed31>] crypto_alloc_base+0x41/0xb0 [ 4560.139114] [<ffffffffa05f283f>] ceph_crypto_alloc_cipher+0x1f/0x30 [libceph] [ 4560.148470] [<ffffffffa05f28ad>] ceph_aes_encrypt2+0x5d/0x2c0 [libceph] [ 4560.157305] [<ffffffffa05f3961>] ceph_encrypt2+0xb1/0xc0 [libceph] [ 4560.165706] [<ffffffffa05f3e3f>] ceph_x_encrypt+0x4f/0x70 [libceph] [ 4560.174196] [<ffffffffa05f4e7f>] ceph_x_build_request+0xdf/0x2f0 [libceph] [ 4560.183290] [<ffffffffa05f1dbe>] ceph_build_auth_request+0x4e/0xb0 [libceph] [ 4560.192558] [<ffffffffa05f2440>] ceph_handle_auth_reply+0x250/0x2e0 [libceph] [ 4560.201912] [<ffffffffa05e7162>] dispatch+0x192/0x7d0 [libceph] [ 4560.210053] [<ffffffffa05e3158>] con_work+0x19f8/0x2e80 [libceph] [ 4560.218368] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4560.226328] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4560.234028] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.241014] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.248540] INITIAL USE at: [ 4560.251721] [<ffffffff810b4d42>] __lock_acquire+0x302/0x1d10 [ 4560.259245] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.266422] [<ffffffff8165aadb>] mutex_lock_nested+0x4b/0x320 [ 4560.274032] [<ffffffffa05e5f36>] ceph_monc_open_session+0x26/0x50 [libceph] [ 4560.282871] [<ffffffffa05de26a>] __ceph_open_session+0x3a/0x250 [libceph] [ 4560.291522] [<ffffffffa06241ed>] ceph_mount+0x37d/0x840 [ceph] [ 4560.299248] [<ffffffff81187ba3>] mount_fs+0x43/0x1b0 [ 4560.306069] [<ffffffff811a2fc6>] vfs_kern_mount+0x76/0x120 [ 4560.313420] [<ffffffff811a5284>] do_mount+0x1f4/0xa20 [ 4560.320319] [<ffffffff811a5b40>] sys_mount+0x90/0xe0 [ 4560.327139] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4560.334923] } [ 4560.336696] ... key at: [<ffffffffa06060b8>] __key.28897+0x0/0xffffffffffff03fb [libceph] [ 4560.345519] ... acquired at: [ 4560.348587] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.354196] [<ffffffff8165aadb>] mutex_lock_nested+0x4b/0x320 [ 4560.360236] [<ffffffffa05e784d>] ceph_monc_got_osdmap+0x2d/0x60 [libceph] [ 4560.367318] [<ffffffffa05eb6f7>] ceph_osdc_handle_map+0x287/0x580 [libceph] [ 4560.374583] [<ffffffffa05e70f0>] dispatch+0x120/0x7d0 [libceph] [ 4560.380797] [<ffffffffa05e3158>] con_work+0x19f8/0x2e80 [libceph] [ 4560.387185] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4560.393223] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4560.399002] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.404089] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.409697] [ 4560.411208] -> (&osdc->map_sem){++++.-} ops: 707694 { [ 4560.416388] HARDIRQ-ON-W at: [ 4560.419563] [<ffffffff810b50bd>] __lock_acquire+0x67d/0x1d10 [ 4560.427002] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.434083] [<ffffffff8165bd46>] down_write+0x36/0x59 [ 4560.440899] [<ffffffffa05eb555>] ceph_osdc_handle_map+0xe5/0x580 [libceph] [ 4560.449561] [<ffffffffa05e70f0>] dispatch+0x120/0x7d0 [libceph] [ 4560.457270] [<ffffffffa05e3158>] con_work+0x19f8/0x2e80 [libceph] [ 4560.465152] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4560.472679] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4560.479949] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.486509] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.493589] HARDIRQ-ON-R at: [ 4560.496766] [<ffffffff810b4f6f>] __lock_acquire+0x52f/0x1d10 [ 4560.504204] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.511285] [<ffffffff8165bcf9>] down_read+0x39/0x50 [ 4560.518024] [<ffffffffa05e95a5>] ceph_osdc_start_request+0x65/0x170 [libceph] [ 4560.526946] [<ffffffffa062f508>] ceph_writepages_start+0x8d8/0xf50 [ceph] [ 4560.535520] [<ffffffff8113c7e3>] do_writepages+0x23/0x40 [ 4560.542601] [<ffffffff811ac95b>] __writeback_single_inode+0x3b/0x180 [ 4560.550731] [<ffffffff811aedc0>] writeback_sb_inodes+0x280/0x3e0 [ 4560.558519] [<ffffffff811aefbe>] __writeback_inodes_wb+0x9e/0xd0 [ 4560.566306] [<ffffffff811af1eb>] wb_writeback+0x1fb/0x320 [ 4560.573474] [<ffffffff811b08a9>] wb_do_writeback+0xb9/0x1d0 [ 4560.580826] [<ffffffff811b0a53>] bdi_writeback_thread+0x93/0x270 [ 4560.588614] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.595176] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.602253] SOFTIRQ-ON-W at: [ 4560.605449] [<ffffffff810b50f5>] __lock_acquire+0x6b5/0x1d10 [ 4560.612885] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.619959] [<ffffffff8165bd46>] down_write+0x36/0x59 [ 4560.626776] [<ffffffffa05eb555>] ceph_osdc_handle_map+0xe5/0x580 [libceph] [ 4560.635438] [<ffffffffa05e70f0>] dispatch+0x120/0x7d0 [libceph] [ 4560.643146] [<ffffffffa05e3158>] con_work+0x19f8/0x2e80 [libceph] [ 4560.651030] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4560.658556] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4560.665823] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.672378] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.679457] SOFTIRQ-ON-R at: [ 4560.682635] [<ffffffff810b50f5>] __lock_acquire+0x6b5/0x1d10 [ 4560.690071] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.697150] [<ffffffff8165bcf9>] down_read+0x39/0x50 [ 4560.705030] [<ffffffffa05e95a5>] ceph_osdc_start_request+0x65/0x170 [libceph] [ 4560.713946] [<ffffffffa062f508>] ceph_writepages_start+0x8d8/0xf50 [ceph] [ 4560.722522] [<ffffffff8113c7e3>] do_writepages+0x23/0x40 [ 4560.729617] [<ffffffff811ac95b>] __writeback_single_inode+0x3b/0x180 [ 4560.737750] [<ffffffff811aedc0>] writeback_sb_inodes+0x280/0x3e0 [ 4560.745538] [<ffffffff811aefbe>] __writeback_inodes_wb+0x9e/0xd0 [ 4560.753325] [<ffffffff811af1eb>] wb_writeback+0x1fb/0x320 [ 4560.760492] [<ffffffff811b08a9>] wb_do_writeback+0xb9/0x1d0 [ 4560.767844] [<ffffffff811b0a53>] bdi_writeback_thread+0x93/0x270 [ 4560.775632] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.782194] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.789272] IN-RECLAIM_FS-R at: [ 4560.792710] [<ffffffff810b4ffd>] __lock_acquire+0x5bd/0x1d10 [ 4560.800406] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.807760] [<ffffffff8165bcf9>] down_read+0x39/0x50 [ 4560.814746] [<ffffffffa05e95a5>] ceph_osdc_start_request+0x65/0x170 [libceph] [ 4560.823928] [<ffffffffa05eb20f>] ceph_osdc_writepages+0xdf/0x180 [libceph] [ 4560.832848] [<ffffffffa063025a>] writepage_nounlock+0x22a/0x410 [ceph] [ 4560.841422] [<ffffffffa0630bee>] ceph_writepage+0x3e/0x70 [ceph] [ 4560.849477] [<ffffffff81143164>] shrink_page_list+0x554/0x900 [ 4560.857265] [<ffffffff81143ac7>] shrink_inactive_list+0x217/0x400 [ 4560.865400] [<ffffffff811442ed>] shrink_lruvec+0x2fd/0x470 [ 4560.872925] [<ffffffff811452e3>] kswapd+0x5d3/0xa90 [ 4560.879824] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.886660] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.894014] INITIAL USE at: [ 4560.897109] [<ffffffff810b4d42>] __lock_acquire+0x302/0x1d10 [ 4560.904458] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4560.911452] [<ffffffff8165bd46>] down_write+0x36/0x59 [ 4560.918184] [<ffffffffa05eb555>] ceph_osdc_handle_map+0xe5/0x580 [libceph] [ 4560.926761] [<ffffffffa05e70f0>] dispatch+0x120/0x7d0 [libceph] [ 4560.934382] [<ffffffffa05e3158>] con_work+0x19f8/0x2e80 [libceph] [ 4560.942178] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4560.949635] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4560.956812] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4560.963285] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4560.970276] } [ 4560.971958] ... key at: [<ffffffffa06060e0>] __key.29826+0x0/0xffffffffffff03d3 [libceph] [ 4560.980704] ... acquired at: [ 4560.983687] [<ffffffff810b3eff>] check_usage_forwards+0x11f/0x150 [ 4560.990076] [<ffffffff810b48e8>] mark_lock+0x198/0x2f0 [ 4560.995509] [<ffffffff810b4ffd>] __lock_acquire+0x5bd/0x1d10 [ 4561.001462] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4561.007069] [<ffffffff8165bcf9>] down_read+0x39/0x50 [ 4561.012329] [<ffffffffa05e95a5>] ceph_osdc_start_request+0x65/0x170 [libceph] [ 4561.019771] [<ffffffffa05eb20f>] ceph_osdc_writepages+0xdf/0x180 [libceph] [ 4561.026939] [<ffffffffa063025a>] writepage_nounlock+0x22a/0x410 [ceph] [ 4561.033756] [<ffffffffa0630bee>] ceph_writepage+0x3e/0x70 [ceph] [ 4561.040056] [<ffffffff81143164>] shrink_page_list+0x554/0x900 [ 4561.046095] [<ffffffff81143ac7>] shrink_inactive_list+0x217/0x400 [ 4561.052482] [<ffffffff811442ed>] shrink_lruvec+0x2fd/0x470 [ 4561.058261] [<ffffffff811452e3>] kswapd+0x5d3/0xa90 [ 4561.063434] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4561.068522] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4561.074130] [ 4561.075665] [ 4561.075665] stack backtrace: [ 4561.080046] Pid: 38, comm: kswapd0 Not tainted 3.8.0-ceph-00226-g1655ae7 #1 [ 4561.087021] Call Trace: [ 4561.089488] [<ffffffff810b3dd8>] print_irq_inversion_bug.part.37+0x1e8/0x1f0 [ 4561.096635] [<ffffffff810b3eff>] check_usage_forwards+0x11f/0x150 [ 4561.102830] [<ffffffff810b48e8>] mark_lock+0x198/0x2f0 [ 4561.108072] [<ffffffff810b3de0>] ? print_irq_inversion_bug.part.37+0x1f0/0x1f0 [ 4561.115401] [<ffffffff810b4ffd>] __lock_acquire+0x5bd/0x1d10 [ 4561.121164] [<ffffffff81338a61>] ? vsnprintf+0x461/0x640 [ 4561.126585] [<ffffffffa05e8ab9>] ? ceph_osdc_build_request+0x119/0x650 [libceph] [ 4561.134095] [<ffffffffa05e95a5>] ? ceph_osdc_start_request+0x65/0x170 [libceph] [ 4561.141515] [<ffffffff810b6d22>] lock_acquire+0xa2/0x140 [ 4561.146928] [<ffffffffa05e95a5>] ? ceph_osdc_start_request+0x65/0x170 [libceph] [ 4561.154349] [<ffffffff8165bcf9>] down_read+0x39/0x50 [ 4561.159422] [<ffffffffa05e95a5>] ? ceph_osdc_start_request+0x65/0x170 [libceph] [ 4561.166855] [<ffffffffa05e95a5>] ceph_osdc_start_request+0x65/0x170 [libceph] [ 4561.174108] [<ffffffffa05eb20f>] ceph_osdc_writepages+0xdf/0x180 [libceph] [ 4561.181085] [<ffffffffa063025a>] writepage_nounlock+0x22a/0x410 [ceph] [ 4561.187711] [<ffffffffa0630bee>] ceph_writepage+0x3e/0x70 [ceph] [ 4561.193815] [<ffffffff81143164>] shrink_page_list+0x554/0x900 [ 4561.199665] [<ffffffff81143ac7>] shrink_inactive_list+0x217/0x400 [ 4561.205862] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4561.211883] [<ffffffff811442ed>] shrink_lruvec+0x2fd/0x470 [ 4561.217472] [<ffffffff8114227c>] ? shrink_slab+0x1dc/0x300 [ 4561.223053] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4561.229857] [<ffffffff811452e3>] kswapd+0x5d3/0xa90 [ 4561.234838] [<ffffffff8107ae10>] ? __init_waitqueue_head+0x60/0x60 [ 4561.241113] [<ffffffff81144d10>] ? try_to_free_pages+0x1a0/0x1a0 [ 4561.247221] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4561.252109] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4561.258298] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4561.263714] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4561.270132] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4561.305432] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4561.341964] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4561.415362] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4561.461996] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4562.595792] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4562.695317] libceph: osd1 10.214.132.116:6803 socket closed (con state OPEN) [ 4562.782819] libceph: osd2 10.214.132.116:6806 socket closed (con state OPEN)
And finally, here's some subsequent console output, leading
ultimately to a crash. The system (or maybe just my connection)
seems to be locked up solid so I can't get any more. I think
I will be power cycling it to get the machine back.
[ 4575.988573] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4576.518337] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4576.584345] libceph: osd1 10.214.132.116:6803 socket closed (con state OPEN) [ 4577.111907] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4577.391608] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4577.699085] libceph: osd1 10.214.132.116:6803 socket closed (con state OPEN) [ 4579.518966] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4603.896963] INFO: rcu_sched self-detected stall on CPU { 0} (t=2100 jiffies g=229053 c=229052 q=482) [ 4603.906376] Pid: 24447, comm: kworker/0:4 Not tainted 3.8.0-ceph-00226-g1655ae7 #1 [ 4603.913972] Call Trace: [ 4603.916437] <IRQ> [<ffffffff810f5d02>] rcu_pending+0x192/0x6f0 [ 4603.922502] [<ffffffff8108f653>] ? account_system_time+0xb3/0x210 [ 4603.926917] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 3, t=2103 jiffies, g=229053, c=229052, q=488) [ 4603.926918] Task dump for CPU 0: [ 4603.926920] kworker/0:4 R running task 0 24447 2 0x00000000 [ 4603.926923] ffff8804152fb308 ffffffff810b783d ffff8804152fb328 0000000000000282 [ 4603.926924] ffff88043ff6a438 0000000000000282 ffff8804152fb368 ffffffff81085343 [ 4603.926926] 0000000000000030 ffffea00078ba0c0 ffff8804152fb520 ffffea00078ba0e0 [ 4603.926927] Call Trace: [ 4603.926932] [<ffffffff810b783d>] ? trace_hardirqs_on+0xd/0x10 [ 4603.926935] [<ffffffff81085343>] ? __wake_up+0x53/0x70 [ 4603.926939] [<ffffffff81142f20>] ? shrink_page_list+0x310/0x900 [ 4603.926941] [<ffffffff811439a6>] ? shrink_inactive_list+0xf6/0x400 [ 4603.926944] [<ffffffff81339c9a>] ? delay_tsc+0x4a/0x80 [ 4603.926948] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4603.926950] [<ffffffff8165de34>] ? _raw_spin_unlock_irq+0x34/0x40 [ 4603.926952] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4603.926953] [<ffffffff81143a3b>] ? shrink_inactive_list+0x18b/0x400 [ 4603.926955] [<ffffffff810b783d>] ? trace_hardirqs_on+0xd/0x10 [ 4603.926957] [<ffffffff811442ed>] ? shrink_lruvec+0x2fd/0x470 [ 4603.926960] [<ffffffff811accd6>] ? bdi_queue_work+0x86/0x150 [ 4603.926964] [<ffffffff8107ae10>] ? __init_waitqueue_head+0x60/0x60 [ 4603.926966] [<ffffffff81144806>] ? do_try_to_free_pages+0x126/0x3a0 [ 4603.926967] [<ffffffff81144c3f>] ? try_to_free_pages+0xcf/0x1a0 [ 4603.926969] [<ffffffff811393d9>] ? __alloc_pages_nodemask+0x579/0x8a0 [ 4603.926973] [<ffffffff8117110a>] ? alloc_pages_current+0xba/0x170 [ 4603.926976] [<ffffffff8154074e>] ? sk_page_frag_refill+0x7e/0x130 [ 4603.926979] [<ffffffff815980e9>] ? tcp_sendmsg+0x309/0xe30 [ 4603.926982] [<ffffffff815c34b9>] ? inet_sendmsg+0xb9/0xf0 [ 4603.926983] [<ffffffff815c3405>] ? inet_sendmsg+0x5/0xf0 [ 4603.926985] [<ffffffff8153a912>] ? sock_sendmsg+0xd2/0xf0 [ 4603.926989] [<ffffffff813060f8>] ? crypto_shash_update+0x18/0x30 [ 4603.926997] [<ffffffffa0000056>] ? crc32c+0x56/0x7c [libcrc32c] [ 4603.926999] [<ffffffff8153a970>] ? kernel_sendmsg+0x40/0x60 [ 4603.927008] [<ffffffffa05e23c0>] ? con_work+0xc60/0x2e80 [libceph] [ 4603.927009] [<ffffffff8109651b>] ? idle_balance+0x1fb/0x330 [ 4603.927011] [<ffffffff8109651b>] ? idle_balance+0x1fb/0x330 [ 4603.927013] [<ffffffff81072ba9>] ? process_one_work+0x199/0x510 [ 4603.927014] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4603.927016] [<ffffffff810f7a7f>] ? rcu_irq_exit+0x7f/0xd0 [ 4603.927018] [<ffffffff8165e7f3>] ? retint_restore_args+0x13/0x13 [ 4603.927023] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4603.927024] [<ffffffff81074895>] ? worker_thread+0x165/0x3f0 [ 4603.927026] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4603.927028] [<ffffffff8107a4ba>] ? kthread+0xea/0xf0 [ 4603.927030] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4603.927032] [<ffffffff81666dac>] ? ret_from_fork+0x7c/0xb0 [ 4603.927034] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4604.207021] [<ffffffff810f845b>] rcu_check_callbacks+0xab/0x160 [ 4604.213049] [<ffffffff81066638>] update_process_times+0x48/0x90 [ 4604.219074] [<ffffffff810afdb6>] tick_sched_handle.isra.10+0x36/0x50 [ 4604.225527] [<ffffffff810afebc>] tick_sched_timer+0x4c/0x80 [ 4604.231237] [<ffffffff8107e9c6>] __run_hrtimer+0x86/0x1f0 [ 4604.236741] [<ffffffff810afe70>] ? tick_nohz_handler+0xa0/0xa0 [ 4604.242686] [<ffffffff810a970c>] ? ktime_get_update_offsets+0x4c/0xd0 [ 4604.249281] [<ffffffff8107f2b7>] hrtimer_interrupt+0xf7/0x250 [ 4604.255131] [<ffffffff81041b46>] hpet_interrupt_handler+0x16/0x40 [ 4604.261333] [<ffffffff810ee7ae>] handle_irq_event_percpu+0x5e/0x230 [ 4604.267704] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4604.273723] [<ffffffff810ee9c8>] handle_irq_event+0x48/0x70 [ 4604.279399] [<ffffffff810f12d7>] handle_edge_irq+0x77/0x110 [ 4604.285079] [<ffffffff81016212>] handle_irq+0x22/0x40 [ 4604.290233] [<ffffffff81668aaa>] do_IRQ+0x5a/0xe0 [ 4604.295044] [<ffffffff8165e732>] common_interrupt+0x72/0x72 [ 4604.300778] <EOI> [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4604.307625] [<ffffffff8165de34>] ? _raw_spin_unlock_irq+0x34/0x40 [ 4604.313824] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4604.320027] [<ffffffff81143a3b>] shrink_inactive_list+0x18b/0x400 [ 4604.326222] [<ffffffff810b783d>] ? trace_hardirqs_on+0xd/0x10 [ 4604.332073] [<ffffffff811442ed>] shrink_lruvec+0x2fd/0x470 [ 4604.337662] [<ffffffff811accd6>] ? bdi_queue_work+0x86/0x150 [ 4604.343424] [<ffffffff8107ae10>] ? __init_waitqueue_head+0x60/0x60 [ 4604.349759] [<ffffffff81144806>] do_try_to_free_pages+0x126/0x3a0 [ 4604.355955] [<ffffffff81144c3f>] try_to_free_pages+0xcf/0x1a0 [ 4604.361801] [<ffffffff811393d9>] __alloc_pages_nodemask+0x579/0x8a0 [ 4604.368182] [<ffffffff8117110a>] alloc_pages_current+0xba/0x170 [ 4604.374204] [<ffffffff8154074e>] sk_page_frag_refill+0x7e/0x130 [ 4604.380225] [<ffffffff815980e9>] tcp_sendmsg+0x309/0xe30 [ 4604.385641] [<ffffffff815c34b9>] inet_sendmsg+0xb9/0xf0 [ 4604.390979] [<ffffffff815c3405>] ? inet_sendmsg+0x5/0xf0 [ 4604.396399] [<ffffffff8153a912>] sock_sendmsg+0xd2/0xf0 [ 4604.401729] [<ffffffff813060f8>] ? crypto_shash_update+0x18/0x30 [ 4604.407843] [<ffffffffa0000056>] ? crc32c+0x56/0x7c [libcrc32c] [ 4604.413868] [<ffffffff8153a970>] kernel_sendmsg+0x40/0x60 [ 4604.419377] [<ffffffffa05e23c0>] con_work+0xc60/0x2e80 [libceph] [ 4604.425490] [<ffffffff8109651b>] ? idle_balance+0x1fb/0x330 [ 4604.431181] [<ffffffff8109651b>] ? idle_balance+0x1fb/0x330 [ 4604.436894] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4604.442744] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4604.448766] [<ffffffff810f7a7f>] ? rcu_irq_exit+0x7f/0xd0 [ 4604.454271] [<ffffffff8165e7f3>] ? retint_restore_args+0x13/0x13 [ 4604.460385] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4604.466974] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4604.472561] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4604.478413] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4604.483308] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4604.489505] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4604.494921] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4613.010446] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4621.954715] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4621.961990] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4622.066824] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4622.235849] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4622.333686] libceph: osd1 10.214.132.116:6803 socket closed (con state OPEN) [ 4622.696381] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4622.738472] libceph: osd2 10.214.132.116:6806 socket closed (con state OPEN) [ 4624.941354] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4625.140097] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4625.178203] libceph: osd2 10.214.132.116:6806 socket closed (con state OPEN) [ 4625.296607] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4625.427142] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4625.607493] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4625.763427] libceph: osd2 10.214.132.116:6806 socket closed (con state OPEN) [ 4625.808217] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4627.594601] libceph: osd1 10.214.132.116:6803 socket closed (con state OPEN) [ 4628.153725] libceph: osd3 10.214.132.118:6800 socket closed (con state OPEN) [ 4628.338422] libceph: osd4 10.214.132.118:6803 socket closed (con state OPEN) [ 4628.380127] libceph: osd0 10.214.132.116:6800 socket closed (con state OPEN) [ 4628.434586] libceph: osd5 10.214.132.118:6806 socket closed (con state OPEN) [ 4649.704822] INFO: rcu_sched self-detected stall on CPU { 0} (t=2100 jiffies g=229113 c=229112 q=598) [ 4649.714167] Pid: 26683, comm: kworker/0:2 Not tainted 3.8.0-ceph-00226-g1655ae7 #1 [ 4649.721763] Call Trace: [ 4649.724230] <IRQ> [ 4649.724837] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 2, t=2102 jiffies, g=229113, c=229112, q=598) [ 4649.724842] Task dump for CPU 0: [ 4649.724844] kworker/0:2 R running task 0 26683 2 0x00000000 [ 4649.724846] ffffffff81072b3c 0000000000000046 0000000000000001 0000000000000000 [ 4649.724848] ffff88043fc1cd35 ffffffffa05e1760 ffff880090289fd8 ffff88043fc0e440 [ 4649.724850] ffffffffa0605c80 0000000000000000 0000000000000000 ffffffffa05f8d0e [ 4649.724852] Call Trace: [ 4649.724853] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4649.724860] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4649.724871] [<ffffffff81074895>] ? worker_thread+0x165/0x3f0 [ 4649.724873] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4649.724874] [<ffffffff8107a4ba>] ? kthread+0xea/0xf0 [ 4649.724877] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4649.724879] [<ffffffff81666dac>] ? ret_from_fork+0x7c/0xb0 [ 4649.724884] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4649.820216] [<ffffffff810f5d02>] rcu_pending+0x192/0x6f0 [ 4649.825874] [<ffffffff8108f653>] ? account_system_time+0xb3/0x210 [ 4649.832076] [<ffffffff810f845b>] rcu_check_callbacks+0xab/0x160 [ 4649.838095] [<ffffffff81066638>] update_process_times+0x48/0x90 [ 4649.844121] [<ffffffff810afdb6>] tick_sched_handle.isra.10+0x36/0x50 [ 4649.850593] [<ffffffff810afebc>] tick_sched_timer+0x4c/0x80 [ 4649.856269] [<ffffffff8107e9c6>] __run_hrtimer+0x86/0x1f0 [ 4649.861771] [<ffffffff810afe70>] ? tick_nohz_handler+0xa0/0xa0 [ 4649.867709] [<ffffffff810a970c>] ? ktime_get_update_offsets+0x4c/0xd0 [ 4649.874261] [<ffffffff8107f2b7>] hrtimer_interrupt+0xf7/0x250 [ 4649.880117] [<ffffffff81041b46>] hpet_interrupt_handler+0x16/0x40 [ 4649.886379] [<ffffffff810ee7ae>] handle_irq_event_percpu+0x5e/0x230 [ 4649.892750] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4649.898774] [<ffffffff810ee9c8>] handle_irq_event+0x48/0x70 [ 4649.904501] [<ffffffff810f12d7>] handle_edge_irq+0x77/0x110 [ 4649.910178] [<ffffffff81016212>] handle_irq+0x22/0x40 [ 4649.915376] [<ffffffff81668aaa>] do_IRQ+0x5a/0xe0 [ 4649.920187] [<ffffffff8165e732>] common_interrupt+0x72/0x72 [ 4649.925869] <EOI> [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4649.932708] [<ffffffff8165de34>] ? _raw_spin_unlock_irq+0x34/0x40 [ 4649.938907] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4649.945101] [<ffffffff81143a3b>] shrink_inactive_list+0x18b/0x400 [ 4649.951296] [<ffffffff810b783d>] ? trace_hardirqs_on+0xd/0x10 [ 4649.957144] [<ffffffff811442ed>] shrink_lruvec+0x2fd/0x470 [ 4649.962737] [<ffffffff811accd6>] ? bdi_queue_work+0x86/0x150 [ 4649.968499] [<ffffffff8107ae10>] ? __init_waitqueue_head+0x60/0x60 [ 4649.974782] [<ffffffff81144806>] do_try_to_free_pages+0x126/0x3a0 [ 4649.980975] [<ffffffff81144c3f>] try_to_free_pages+0xcf/0x1a0 [ 4649.986826] [<ffffffff811393d9>] __alloc_pages_nodemask+0x579/0x8a0 [ 4649.993196] [<ffffffff8117110a>] alloc_pages_current+0xba/0x170 [ 4649.999235] [<ffffffff8154074e>] sk_page_frag_refill+0x7e/0x130 [ 4650.005300] [<ffffffff815980e9>] tcp_sendmsg+0x309/0xe30 [ 4650.010717] [<ffffffff815c34b9>] inet_sendmsg+0xb9/0xf0 [ 4650.016071] [<ffffffff815c3405>] ? inet_sendmsg+0x5/0xf0 [ 4650.021489] [<ffffffff8153a912>] sock_sendmsg+0xd2/0xf0 [ 4650.026847] [<ffffffff813060f8>] ? crypto_shash_update+0x18/0x30 [ 4650.032960] [<ffffffffa0000056>] ? crc32c+0x56/0x7c [libcrc32c] [ 4650.038996] [<ffffffff8153a970>] kernel_sendmsg+0x40/0x60 [ 4650.044503] [<ffffffffa05e23c0>] con_work+0xc60/0x2e80 [libceph] [ 4650.050616] [<ffffffff8108f000>] ? cpuacct_charge+0xb0/0xc0 [ 4650.056290] [<ffffffff8108ef78>] ? cpuacct_charge+0x28/0xc0 [ 4650.061969] [<ffffffff810861c8>] ? finish_task_switch+0x48/0x110 [ 4650.068086] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4650.073935] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4650.079973] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4650.086572] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4650.092166] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4650.099171] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4650.104071] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4650.110272] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4650.115748] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4671.091205] INFO: rcu_sched self-detected stall on CPU { 0} (t=2100 jiffies g=229114 c=229113 q=3151) [ 4671.100640] Pid: 26683, comm: kworker/0:2 Not tainted 3.8.0-ceph-00226-g1655ae7 #1 [ 4671.108296] Call Trace: [ 4671.110763] <IRQ> [<ffffffff810f5d02>] rcu_pending+0x192/0x6f0 [ 4671.116827] [<ffffffff8108f653>] ? account_system_time+0xb3/0x210 [ 4671.123027] [<ffffffff810f845b>] rcu_check_callbacks+0xab/0x160 [ 4671.129048] [<ffffffff81066638>] update_process_times+0x48/0x90 [ 4671.131151] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 1, t=2104 jiffies, g=229114, c=229113, q=3152) [ 4671.131153] Task dump for CPU 0: [ 4671.131158] kworker/0:2 R running task 0 26683 2 0x00000000 [ 4671.131165] ffffffff81072b3c 0000000000000046 0000000000000001 0000000000000000 [ 4671.131166] ffff88043fc1cd35 ffffffffa05e1760 ffff880090289fd8 ffff88043fc0e440 [ 4671.131168] ffffffffa0605c80 0000000000000000 0000000000000000 ffffffffa05f8d0e [ 4671.131169] Call Trace: [ 4671.131173] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4671.131184] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4671.131187] [<ffffffff81074895>] ? worker_thread+0x165/0x3f0 [ 4671.131188] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4671.131190] [<ffffffff8107a4ba>] ? kthread+0xea/0xf0 [ 4671.131192] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4671.131195] [<ffffffff81666dac>] ? ret_from_fork+0x7c/0xb0 [ 4671.131197] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4671.228529] [<ffffffff810afdb6>] tick_sched_handle.isra.10+0x36/0x50 [ 4671.234986] [<ffffffff810afebc>] tick_sched_timer+0x4c/0x80 [ 4671.240666] [<ffffffff8107e9c6>] __run_hrtimer+0x86/0x1f0 [ 4671.246203] [<ffffffff810afe70>] ? tick_nohz_handler+0xa0/0xa0 [ 4671.252164] [<ffffffff810a970c>] ? ktime_get_update_offsets+0x4c/0xd0 [ 4671.258708] [<ffffffff8107f2b7>] hrtimer_interrupt+0xf7/0x250 [ 4671.264557] [<ffffffff81041b46>] hpet_interrupt_handler+0x16/0x40 [ 4671.270752] [<ffffffff810ee7ae>] handle_irq_event_percpu+0x5e/0x230 [ 4671.277121] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4671.283205] [<ffffffff810ee9c8>] handle_irq_event+0x48/0x70 [ 4671.288878] [<ffffffff810f12d7>] handle_edge_irq+0x77/0x110 [ 4671.294558] [<ffffffff81016212>] handle_irq+0x22/0x40 [ 4671.299712] [<ffffffff81668aaa>] do_IRQ+0x5a/0xe0 [ 4671.304549] [<ffffffff8165e732>] common_interrupt+0x72/0x72 [ 4671.310223] <EOI> [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4671.317085] [<ffffffff8165de34>] ? _raw_spin_unlock_irq+0x34/0x40 [ 4671.323328] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4671.329524] [<ffffffff81143a3b>] shrink_inactive_list+0x18b/0x400 [ 4671.335719] [<ffffffff810b783d>] ? trace_hardirqs_on+0xd/0x10 [ 4671.341594] [<ffffffff811442ed>] shrink_lruvec+0x2fd/0x470 [ 4671.347182] [<ffffffff811accd6>] ? bdi_queue_work+0x86/0x150 [ 4671.353025] [<ffffffff8107ae10>] ? __init_waitqueue_head+0x60/0x60 [ 4671.359307] [<ffffffff81144806>] do_try_to_free_pages+0x126/0x3a0 [ 4671.365529] [<ffffffff81144c3f>] try_to_free_pages+0xcf/0x1a0 [ 4671.371438] [<ffffffff811393d9>] __alloc_pages_nodemask+0x579/0x8a0 [ 4671.377809] [<ffffffff8117110a>] alloc_pages_current+0xba/0x170 [ 4671.383846] [<ffffffff8154074e>] sk_page_frag_refill+0x7e/0x130 [ 4671.389871] [<ffffffff815980e9>] tcp_sendmsg+0x309/0xe30 [ 4671.395301] [<ffffffff815c34b9>] inet_sendmsg+0xb9/0xf0 [ 4671.400630] [<ffffffff815c3405>] ? inet_sendmsg+0x5/0xf0 [ 4671.406057] [<ffffffff8153a912>] sock_sendmsg+0xd2/0xf0 [ 4671.411466] [<ffffffff813060f8>] ? crypto_shash_update+0x18/0x30 [ 4671.417579] [<ffffffffa0000056>] ? crc32c+0x56/0x7c [libcrc32c] [ 4671.423668] [<ffffffff8153a970>] kernel_sendmsg+0x40/0x60 [ 4671.429177] [<ffffffffa05e23c0>] con_work+0xc60/0x2e80 [libceph] [ 4671.435325] [<ffffffff8108f000>] ? cpuacct_charge+0xb0/0xc0 [ 4671.441066] [<ffffffff8108ef78>] ? cpuacct_charge+0x28/0xc0 [ 4671.446745] [<ffffffff810861c8>] ? finish_task_switch+0x48/0x110 [ 4671.452854] [<ffffffff81072ba9>] process_one_work+0x199/0x510 [ 4671.458703] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4671.464759] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4671.471365] [<ffffffff81074895>] worker_thread+0x165/0x3f0 [ 4671.476951] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4671.482813] [<ffffffff8107a4ba>] kthread+0xea/0xf0 [ 4671.487706] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4671.493933] [<ffffffff81666dac>] ret_from_fork+0x7c/0xb0 [ 4671.499357] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4676.392896] INFO: task ffsb:26654 blocked for more than 120 seconds. [ 4676.399268] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4676.407141] ffsb D ffffffff81130150 0 26654 24977 0x00000000 [ 4676.414254] ffff880413d0b938 0000000000000046 ffffffff8165e05f 0000000000000002 [ 4676.421767] ffff88041f77bf20 ffff880413d0bfd8 ffff880413d0bfd8 ffff880413d0bfd8 [ 4676.429288] ffff88042d585eb0 ffff88041f77bf20 ffff880413d0b938 ffff88043fc54ed8 [ 4676.436807] Call Trace: [ 4676.439276] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4676.446090] [<ffffffff81130150>] ? __lock_page+0x70/0x70 [ 4676.451508] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4676.456494] [<ffffffff8165cc3f>] io_schedule+0x8f/0xd0 [ 4676.461734] [<ffffffff8113015e>] sleep_on_page+0xe/0x20 [ 4676.467072] [<ffffffff8165a6da>] __wait_on_bit_lock+0x5a/0xc0 [ 4676.472928] [<ffffffff81130147>] __lock_page+0x67/0x70 [ 4676.478175] [<ffffffff8107ae50>] ? autoremove_wake_function+0x40/0x40 [ 4676.484728] [<ffffffff81130b87>] find_lock_page+0x67/0x80 [ 4676.490229] [<ffffffff81130d3f>] grab_cache_page_write_begin+0x6f/0xf0 [ 4676.496874] [<ffffffffa063096e>] ceph_write_begin+0x4e/0xd0 [ceph] [ 4676.503163] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4676.509189] [<ffffffff8113064a>] generic_file_buffered_write+0x11a/0x290 [ 4676.516000] [<ffffffff81131df6>] __generic_file_aio_write+0x1b6/0x3b0 [ 4676.522549] [<ffffffffa062cee5>] ceph_aio_write+0x935/0xaa0 [ceph] [ 4676.528843] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4676.535395] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4676.541336] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4676.546756] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4676.551916] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4676.556993] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4676.563022] INFO: lockdep is turned off. [ 4676.566959] INFO: task ffsb:26656 blocked for more than 120 seconds. [ 4676.573326] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4676.581181] ffsb D ffffffff81130150 0 26656 24977 0x00000000 [ 4676.588293] ffff8804144ff938 0000000000000046 ffffffff8165e05f 0000000000000002 [ 4676.595814] ffff880413fe0000 ffff8804144fffd8 ffff8804144fffd8 ffff8804144fffd8 [ 4676.603335] ffff88042d540000 ffff880413fe0000 ffff8804144ff938 ffff88043fcd4ed8 [ 4676.610837] Call Trace: [ 4676.613317] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4676.620123] [<ffffffff81130150>] ? __lock_page+0x70/0x70 [ 4676.625545] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4676.630527] [<ffffffff8165cc3f>] io_schedule+0x8f/0xd0 [ 4676.635778] [<ffffffff8113015e>] sleep_on_page+0xe/0x20 [ 4676.641112] [<ffffffff8165a6da>] __wait_on_bit_lock+0x5a/0xc0 [ 4676.646969] [<ffffffff81130147>] __lock_page+0x67/0x70 [ 4676.652216] [<ffffffff8107ae50>] ? autoremove_wake_function+0x40/0x40 [ 4676.658765] [<ffffffff81130b87>] find_lock_page+0x67/0x80 [ 4676.664272] [<ffffffff81130d3f>] grab_cache_page_write_begin+0x6f/0xf0 [ 4676.670914] [<ffffffffa063096e>] ceph_write_begin+0x4e/0xd0 [ceph] [ 4676.677205] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4676.683232] [<ffffffff8113064a>] generic_file_buffered_write+0x11a/0x290 [ 4676.690039] [<ffffffff81131df6>] __generic_file_aio_write+0x1b6/0x3b0 [ 4676.696611] [<ffffffffa062cee5>] ceph_aio_write+0x935/0xaa0 [ceph] [ 4676.702908] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4676.709455] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4676.715398] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4676.720814] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4676.725975] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4676.731044] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4676.737070] INFO: lockdep is turned off. [ 4676.741013] INFO: task ffsb:26659 blocked for more than 120 seconds. [ 4676.747386] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4676.755249] ffsb D 00000000ffffffff 0 26659 24977 0x00000000 [ 4676.762353] ffff880412cf7bb8 0000000000000046 0000000000000007 0000000000000006 [ 4676.769855] ffff880413088000 ffff880412cf7fd8 ffff880412cf7fd8 ffff880412cf7fd8 [ 4676.777365] ffff8804150c5eb0 ffff880413088000 ffffffff8165ac75 ffff8804289d74c8 [ 4676.784883] Call Trace: [ 4676.787352] [<ffffffff8165ac75>] ? mutex_lock_nested+0x1e5/0x320 [ 4676.793465] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4676.798450] [<ffffffff8165ce8e>] schedule_preempt_disabled+0xe/0x10 [ 4676.804827] [<ffffffff8165abe1>] mutex_lock_nested+0x151/0x320 [ 4676.810771] [<ffffffffa062cec0>] ? ceph_aio_write+0x910/0xaa0 [ceph] [ 4676.817241] [<ffffffffa062cec0>] ceph_aio_write+0x910/0xaa0 [ceph] [ 4676.823535] [<ffffffff81090bb4>] ? select_task_rq_fair+0x54/0x8a0 [ 4676.829730] [<ffffffff81090bb4>] ? select_task_rq_fair+0x54/0x8a0 [ 4676.835937] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4676.841871] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4676.847296] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4676.852483] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4676.857553] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4676.863596] INFO: lockdep is turned off. [ 4676.867540] INFO: task ffsb:26663 blocked for more than 120 seconds. [ 4676.873932] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4676.881786] ffsb D 00000000ffffffff 0 26663 24977 0x00000000 [ 4676.888898] ffff880414735bb8 0000000000000046 0000000000000007 0000000000000006 [ 4676.896413] ffff88041f620000 ffff880414735fd8 ffff880414735fd8 ffff880414735fd8 [ 4676.903933] ffff88042d540000 ffff88041f620000 ffffffff8165ac75 ffff8804289d74c8 [ 4676.912616] Call Trace: [ 4676.915089] [<ffffffff8165ac75>] ? mutex_lock_nested+0x1e5/0x320 [ 4676.921202] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4676.926196] [<ffffffff8165ce8e>] schedule_preempt_disabled+0xe/0x10 [ 4676.932570] [<ffffffff8165abe1>] mutex_lock_nested+0x151/0x320 [ 4676.938517] [<ffffffffa062cec0>] ? ceph_aio_write+0x910/0xaa0 [ceph] [ 4676.944989] [<ffffffffa062cec0>] ceph_aio_write+0x910/0xaa0 [ceph] [ 4676.951275] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4676.957225] [<ffffffff8108ca5e>] ? try_to_wake_up+0x2e/0x2f0 [ 4676.963002] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4676.968420] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4676.973607] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4676.978676] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4676.984704] INFO: lockdep is turned off. [ 4676.988646] INFO: task ffsb:26666 blocked for more than 120 seconds. [ 4676.995035] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4677.002900] ffsb D ffffffff81130150 0 26666 24977 0x00000000 [ 4677.010008] ffff880413da3938 0000000000000046 ffffffff8165e05f 0000000000000002 [ 4677.017530] ffff880413c78000 ffff880413da3fd8 ffff880413da3fd8 ffff880413da3fd8 [ 4677.025049] ffff88042d533f20 ffff880413c78000 ffff880413da3938 ffff88043fc54ed8 [ 4677.032569] Call Trace: [ 4677.035038] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4677.041855] [<ffffffff81130150>] ? __lock_page+0x70/0x70 [ 4677.047268] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4677.052258] [<ffffffff8165cc3f>] io_schedule+0x8f/0xd0 [ 4677.057504] [<ffffffff8113015e>] sleep_on_page+0xe/0x20 [ 4677.062851] [<ffffffff8165a6da>] __wait_on_bit_lock+0x5a/0xc0 [ 4677.068703] [<ffffffff81130147>] __lock_page+0x67/0x70 [ 4677.073957] [<ffffffff8107ae50>] ? autoremove_wake_function+0x40/0x40 [ 4677.080498] [<ffffffff81130b87>] find_lock_page+0x67/0x80 [ 4677.086015] [<ffffffff81130d3f>] grab_cache_page_write_begin+0x6f/0xf0 [ 4677.092662] [<ffffffffa063096e>] ceph_write_begin+0x4e/0xd0 [ceph] [ 4677.098946] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4677.104980] [<ffffffff8113064a>] generic_file_buffered_write+0x11a/0x290 [ 4677.111819] [<ffffffff81131df6>] __generic_file_aio_write+0x1b6/0x3b0 [ 4677.118370] [<ffffffffa062cee5>] ceph_aio_write+0x935/0xaa0 [ceph] [ 4677.124681] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4677.131231] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4677.137179] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4677.142603] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4677.147763] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4677.152845] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4677.158864] INFO: lockdep is turned off. [ 4677.162814] INFO: task ffsb:26670 blocked for more than 120 seconds. [ 4677.169179] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4677.177045] ffsb D ffffffff81130150 0 26670 24977 0x00000000 [ 4677.184157] ffff880412dc5938 0000000000000046 ffffffff8165e05f 0000000000000002 [ 4677.191671] ffff88042d0b9f90 ffff880412dc5fd8 ffff880412dc5fd8 ffff880412dc5fd8 [ 4677.199183] ffff88042d585eb0 ffff88042d0b9f90 ffff880412dc5938 ffff88043fc54ed8 [ 4677.206694] Call Trace: [ 4677.209163] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4677.215981] [<ffffffff81130150>] ? __lock_page+0x70/0x70 [ 4677.221403] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4677.226393] [<ffffffff8165cc3f>] io_schedule+0x8f/0xd0 [ 4677.231646] [<ffffffff8113015e>] sleep_on_page+0xe/0x20 [ 4677.236977] [<ffffffff8165a6da>] __wait_on_bit_lock+0x5a/0xc0 [ 4677.242839] [<ffffffff81130147>] __lock_page+0x67/0x70 [ 4677.248087] [<ffffffff8107ae50>] ? autoremove_wake_function+0x40/0x40 [ 4677.254642] [<ffffffff81130b87>] find_lock_page+0x67/0x80 [ 4677.260150] [<ffffffff81130d3f>] grab_cache_page_write_begin+0x6f/0xf0 [ 4677.266798] [<ffffffffa063096e>] ceph_write_begin+0x4e/0xd0 [ceph] [ 4677.273086] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4677.279110] [<ffffffff8113064a>] generic_file_buffered_write+0x11a/0x290 [ 4677.285922] [<ffffffff81131df6>] __generic_file_aio_write+0x1b6/0x3b0 [ 4677.292486] [<ffffffffa062cee5>] ceph_aio_write+0x935/0xaa0 [ceph] [ 4677.298773] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4677.305325] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4677.311266] [<ffffffff8165e7f3>] ? retint_restore_args+0x13/0x13 [ 4677.317384] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4677.322803] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4677.327963] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4677.333044] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4677.339064] INFO: lockdep is turned off. [ 4677.343016] INFO: task ffsb:26673 blocked for more than 120 seconds. [ 4677.349387] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4677.357253] ffsb D 00000000ffffffff 0 26673 24977 0x00000000 [ 4677.364358] ffff880414559e28 0000000000000046 0000000000000007 0000000000000006 [ 4677.371872] ffff880414511f90 ffff880414559fd8 ffff880414559fd8 ffff880414559fd8 [ 4677.379374] ffff880415211f90 ffff880414511f90 ffffffff8165ac75 ffff880421c9dce0 [ 4677.386894] Call Trace: [ 4677.389363] [<ffffffff8165ac75>] ? mutex_lock_nested+0x1e5/0x320 [ 4677.395488] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4677.400475] [<ffffffff8165ce8e>] schedule_preempt_disabled+0xe/0x10 [ 4677.406857] [<ffffffff8165abe1>] mutex_lock_nested+0x151/0x320 [ 4677.412811] [<ffffffffa062b605>] ? ceph_llseek+0x45/0x160 [ceph] [ 4677.418919] [<ffffffff811a0f7c>] ? fget_light+0x3c/0x130 [ 4677.424351] [<ffffffffa062b605>] ceph_llseek+0x45/0x160 [ceph] [ 4677.430288] [<ffffffff811836d3>] vfs_llseek+0x33/0x40 [ 4677.435451] [<ffffffff81183c5e>] sys_lseek+0x7e/0x90 [ 4677.440523] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4677.446551] INFO: lockdep is turned off. [ 4677.450493] INFO: task ffsb:26674 blocked for more than 120 seconds. [ 4677.456866] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4677.464729] ffsb D ffffffff81130150 0 26674 24977 0x00000000 [ 4677.471837] ffff880413c9f938 0000000000000046 ffffffff8165e05f 0000000000000002 [ 4677.479351] ffff880412c83f20 ffff880413c9ffd8 ffff880413c9ffd8 ffff880413c9ffd8 [ 4677.486870] ffff88042d073f20 ffff880412c83f20 ffff880413c9f938 ffff88043fc14ed8 [ 4677.494381] Call Trace: [ 4677.496851] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4677.503668] [<ffffffff81130150>] ? __lock_page+0x70/0x70 [ 4677.509089] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4677.514080] [<ffffffff8165cc3f>] io_schedule+0x8f/0xd0 [ 4677.519326] [<ffffffff8113015e>] sleep_on_page+0xe/0x20 [ 4677.524666] [<ffffffff8165a6da>] __wait_on_bit_lock+0x5a/0xc0 [ 4677.530517] [<ffffffff81130147>] __lock_page+0x67/0x70 [ 4677.535769] [<ffffffff8107ae50>] ? autoremove_wake_function+0x40/0x40 [ 4677.542317] [<ffffffff81130b87>] find_lock_page+0x67/0x80 [ 4677.547819] [<ffffffff81130d3f>] grab_cache_page_write_begin+0x6f/0xf0 [ 4677.554469] [<ffffffffa063096e>] ceph_write_begin+0x4e/0xd0 [ceph] [ 4677.560751] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4677.566784] [<ffffffff8113064a>] generic_file_buffered_write+0x11a/0x290 [ 4677.573608] [<ffffffff81131df6>] __generic_file_aio_write+0x1b6/0x3b0 [ 4677.580160] [<ffffffffa062cee5>] ceph_aio_write+0x935/0xaa0 [ceph] [ 4677.586452] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4677.592998] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4677.598936] [<ffffffff8165e7f3>] ? retint_restore_args+0x13/0x13 [ 4677.605053] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4677.610467] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4677.615632] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4677.620704] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4677.626734] INFO: lockdep is turned off. [ 4677.630675] INFO: task ffsb:26676 blocked for more than 120 seconds. [ 4677.637056] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4677.644921] ffsb D ffffffff81130150 0 26676 24977 0x00000000 [ 4677.652040] ffff880412cf3938 0000000000000046 ffffffff8165e05f 0000000000000002 [ 4677.659551] ffff880413fd8000 ffff880412cf3fd8 ffff880412cf3fd8 ffff880412cf3fd8 [ 4677.667061] ffff88042d585eb0 ffff880413fd8000 ffff880412cf3938 ffff88043fc54ed8 [ 4677.674573] Call Trace: [ 4677.677041] [<ffffffff8165e05f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80 [ 4677.683859] [<ffffffff81130150>] ? __lock_page+0x70/0x70 [ 4677.689281] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4677.694284] [<ffffffff8165cc3f>] io_schedule+0x8f/0xd0 [ 4677.699524] [<ffffffff8113015e>] sleep_on_page+0xe/0x20 [ 4677.704874] [<ffffffff8165a6da>] __wait_on_bit_lock+0x5a/0xc0 [ 4677.710744] [<ffffffff81130147>] __lock_page+0x67/0x70 [ 4677.715983] [<ffffffff8107ae50>] ? autoremove_wake_function+0x40/0x40 [ 4677.722537] [<ffffffff81130b87>] find_lock_page+0x67/0x80 [ 4677.728036] [<ffffffff81130d3f>] grab_cache_page_write_begin+0x6f/0xf0 [ 4677.734684] [<ffffffffa063096e>] ceph_write_begin+0x4e/0xd0 [ceph] [ 4677.740973] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4677.746998] [<ffffffff8113064a>] generic_file_buffered_write+0x11a/0x290 [ 4677.753811] [<ffffffff81131df6>] __generic_file_aio_write+0x1b6/0x3b0 [ 4677.760365] [<ffffffffa062cee5>] ceph_aio_write+0x935/0xaa0 [ceph] [ 4677.766687] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4677.773238] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4677.779178] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4677.784601] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4677.789758] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4677.794838] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4677.800865] INFO: lockdep is turned off. [ 4677.804802] INFO: task ffsb:26678 blocked for more than 120 seconds. [ 4677.811175] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 4677.819032] ffsb D 00000000ffffffff 0 26678 24977 0x00000000 [ 4677.826162] ffff880413dadbb8 0000000000000046 0000000000000007 0000000000000006 [ 4677.833676] ffff88042d5c3f20 ffff880413dadfd8 ffff880413dadfd8 ffff880413dadfd8 [ 4677.841213] ffff88042d535eb0 ffff88042d5c3f20 ffffffff8165ac75 ffff8804289d74c8 [ 4677.849785] Call Trace: [ 4677.852266] [<ffffffff8165ac75>] ? mutex_lock_nested+0x1e5/0x320 [ 4677.858377] [<ffffffff8165cb69>] schedule+0x29/0x70 [ 4677.863370] [<ffffffff8165ce8e>] schedule_preempt_disabled+0xe/0x10 [ 4677.869741] [<ffffffff8165abe1>] mutex_lock_nested+0x151/0x320 [ 4677.875694] [<ffffffffa062cec0>] ? ceph_aio_write+0x910/0xaa0 [ceph] [ 4677.882187] [<ffffffffa062cec0>] ceph_aio_write+0x910/0xaa0 [ceph] [ 4677.888477] [<ffffffff810b67f0>] ? lock_release_non_nested+0xa0/0x310 [ 4677.895025] [<ffffffff810b4d42>] ? __lock_acquire+0x302/0x1d10 [ 4677.900968] [<ffffffff8108ca5e>] ? try_to_wake_up+0x2e/0x2f0 [ 4677.906732] [<ffffffff81183843>] do_sync_write+0xa3/0xe0 [ 4677.912161] [<ffffffff81183ef3>] vfs_write+0xb3/0x180 [ 4677.917312] [<ffffffff81184232>] sys_write+0x52/0xa0 [ 4677.922394] [<ffffffff81666e59>] system_call_fastpath+0x16/0x1b [ 4677.928416] INFO: lockdep is turned off. [ 4710.039798] INFO: rcu_sched self-detected stall on CPU { 0} (t=2100 jiffies g=229118 c=229117 q=863) [ 4710.049151] Pid: 26683, comm: kworker/0:2 Not tainted 3.8.0-ceph-00226-g1655ae7 #1 [ 4710.056745] Call Trace: [ 4710.059212] <IRQ> [ 4710.059907] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 1, t=2102 jiffies, g=229118, c=229117, q=863) [ 4710.059911] Task dump for CPU 0: [ 4710.059912] kworker/0:2 R running task 0 26683 2 0x00000000 [ 4710.059915] ffff880090289308 ffffffff810b783d ffff880090289328 0000000000000282 [ 4710.059917] ffff88043ff72238 0000000000000282 ffff880090289368 ffffffff81085343 [ 4710.059919] 0000000000000002 ffffea000f816140 ffff880090289520 ffffea000f816160 [ 4710.059921] Call Trace: [ 4710.059922] [<ffffffff810b783d>] ? trace_hardirqs_on+0xd/0x10 [ 4710.059927] [<ffffffff81085343>] ? __wake_up+0x53/0x70 [ 4710.059931] [<ffffffff81142f20>] ? shrink_page_list+0x310/0x900 [ 4710.059935] [<ffffffff811439a6>] ? shrink_inactive_list+0xf6/0x400 [ 4710.059937] [<ffffffff811439a6>] ? shrink_inactive_list+0xf6/0x400 [ 4710.059938] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4710.059942] [<ffffffff8165de34>] ? _raw_spin_unlock_irq+0x34/0x40 [ 4710.059944] [<ffffffff8165de30>] ? _raw_spin_unlock_irq+0x30/0x40 [ 4710.059946] [<ffffffff81143a3b>] ? shrink_inactive_list+0x18b/0x400 [ 4710.059948] [<ffffffff8113a4da>] ? global_dirtyable_memory+0x1a/0x50 [ 4710.059950] [<ffffffff811442ed>] ? shrink_lruvec+0x2fd/0x470 [ 4710.059952] [<ffffffff811accd6>] ? bdi_queue_work+0x86/0x150 [ 4710.059955] [<ffffffff8107ae10>] ? __init_waitqueue_head+0x60/0x60 [ 4710.059959] [<ffffffff81144806>] ? do_try_to_free_pages+0x126/0x3a0 [ 4710.059961] [<ffffffff81144c3f>] ? try_to_free_pages+0xcf/0x1a0 [ 4710.059963] [<ffffffff811393d9>] ? __alloc_pages_nodemask+0x579/0x8a0 [ 4710.059965] [<ffffffff8117110a>] ? alloc_pages_current+0xba/0x170 [ 4710.059968] [<ffffffff8154074e>] ? sk_page_frag_refill+0x7e/0x130 [ 4710.059971] [<ffffffff815980e9>] ? tcp_sendmsg+0x309/0xe30 [ 4710.059974] [<ffffffff815c34b9>] ? inet_sendmsg+0xb9/0xf0 [ 4710.059977] [<ffffffff815c3405>] ? inet_sendmsg+0x5/0xf0 [ 4710.059979] [<ffffffff8153a912>] ? sock_sendmsg+0xd2/0xf0 [ 4710.059981] [<ffffffff813060f8>] ? crypto_shash_update+0x18/0x30 [ 4710.059990] [<ffffffffa0000056>] ? crc32c+0x56/0x7c [libcrc32c] [ 4710.059993] [<ffffffff8153a970>] ? kernel_sendmsg+0x40/0x60 [ 4710.059995] [<ffffffffa05e23c0>] ? con_work+0xc60/0x2e80 [libceph] [ 4710.060003] [<ffffffff8108f000>] ? cpuacct_charge+0xb0/0xc0 [ 4710.060006] [<ffffffff8108ef78>] ? cpuacct_charge+0x28/0xc0 [ 4710.060008] [<ffffffff810861c8>] ? finish_task_switch+0x48/0x110 [ 4710.060010] [<ffffffff81072ba9>] ? process_one_work+0x199/0x510 [ 4710.060012] [<ffffffff81072b3c>] ? process_one_work+0x12c/0x510 [ 4710.060013] [<ffffffffa05e1760>] ? ceph_con_close+0xd0/0xd0 [libceph] [ 4710.060018] [<ffffffff81074895>] ? worker_thread+0x165/0x3f0 [ 4710.060020] [<ffffffff81074730>] ? manage_workers+0x2a0/0x2a0 [ 4710.060021] [<ffffffff8107a4ba>] ? kthread+0xea/0xf0 [ 4710.060024] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4710.060025] [<ffffffff81666dac>] ? ret_from_fork+0x7c/0xb0 [ 4710.060028] [<ffffffff8107a3d0>] ? flush_kthread_work+0x1a0/0x1a0 [ 4710.335519] [<ffffffff810f5d02>] rcu_pending+0x192/0x6f0 [ 4710.341177] [<ffffffff8108f653>] ? account_system_time+0xb3/0x210 [ 4710.347381] [<ffffffff810f845b>] rcu_check_callbacks+0xab/0x160 [ 4710.353409] [<ffffffff81066638>] update_process_times+0x48/0x90 [ 4710.359486] [<ffffffff810afdb6>] tick_sched_handle.isra.10+0x36/0x50 [ 4710.365939] [<ffffffff810afebc>] tick_sched_timer+0x4c/0x80 [ 4710.371623] [<ffffffff8107e9c6>] __run_hrtimer+0x86/0x1f0 [ 4710.377128] [<ffffffff810afe70>] ? tick_nohz_handler+0xa0/0xa0 [ 4710.383079] [<ffffffff810a970c>] ? ktime_get_update_offsets+0x4c/0xd0 [ 4710.389624] [<ffffffff8107f2b7>] hrtimer_interrupt+0xf7/0x250 [ 4710.395473] [<ffffffff81041b46>] hpet_interrupt_handler+0x16/0x40 [ 4710.401669] [<ffffffff810ee7ae>] handle_irq_event_percpu+0x5e/0x230 [ 4710.408039] [<ffffffff8134141d>] ? do_raw_spin_unlock+0x5d/0xb0 [ 4710.414067] [<ffffffff810ee9c8>] handle_irq_event+0x48/0x70 [ 4710.419742] [<ffffffff810f12d7>] handle_edge_irq+0x77/0x110 [ 4710.4254