Project

General

Profile

Bug #10352

libceph delayed work items aren't teared down properly

Added by Ilya Dryomov about 7 years ago. Updated almost 7 years ago.

Status:
Resolved
Priority:
High
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
other
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

http://qa-proxy.ceph.com/teuthology/dis-2014-12-17_03:17:27-krbd-giant---basic-multi/663896/teuthology.log

[0]kdb> dumpcommon
[dumpcommon]kdb> set BTAPROMPT 0

[dumpcommon]kdb> set LINES 10000

[dumpcommon]kdb> -summary

sysname Linux
release 3.10.0-ceph-rhrpm-00071-g64ce874a320b
version #1 SMP Wed Dec 17 02:43:56 MSK 2014
machine x86_64
nodename plana23
domainname (none)
ccversion CCVERSION
date 2014-12-17 01:14:38 tz_minuteswest 480
uptime 00:56
load avg 4.37 1.64 1.05

MemTotal: 1998884 kB
MemFree: 1012043 kB
Buffers: 17692 kB
[dumpcommon]kdb> -cpu

Currently on cpu 0
Available cpus: 0, 1-7(I)
[dumpcommon]kdb> -ps

7 idle processes (state I) and
177 sleeping system daemon (state M) processes suppressed,
use 'ps A' to see all.
Task Addr Pid Parent [*] cpu State Thread Command
0xffff88020030cfa0 12678 2 1 0 R 0xffff88020030d638 *kworker/0:2

0xffff880223cf0000 1 0 0 2 S 0xffff880223cf0698 systemd
0xffff8802208d8000 369 1 0 1 S 0xffff8802208d8698 systemd-journal
0xffff8802208dcfa0 379 1 0 0 S 0xffff8802208dd638 lvmetad
0xffff880220c08b60 385 1 0 2 S 0xffff880220c091f8 systemd-udevd
0xffff88022096db00 550 1 0 3 S 0xffff88022096e198 auditd
0xffff880220d94fa0 554 1 0 0 S 0xffff880220d95638 auditd
0xffff880221e738e0 588 1 0 2 S 0xffff880221e73f78 smartd
0xffff880221e716c0 589 1 0 3 S 0xffff880221e71d58 NetworkManager
0xffff8802210aa220 590 1 0 7 S 0xffff8802210aa8b8 NetworkManager
0xffff880222e1cfa0 655 1 0 6 S 0xffff880222e1d638 gdbus
0xffff880221e72d80 597 1 0 6 S 0xffff880221e73418 avahi-daemon
0xffff880221580b60 599 597 0 6 S 0xffff8802215811f8 avahi-daemon
0xffff8802217c96c0 600 1 0 7 S 0xffff8802217c9d58 iprinit
0xffff880221e771c0 603 1 0 3 S 0xffff880221e77858 tuned
0xffff88003718f1c0 652 1 0 4 S 0xffff88003718f858 gmain
0xffff880037188000 653 1 0 1 S 0xffff880037188698 tuned
0xffff88003718ad80 654 1 0 1 S 0xffff88003718b418 tuned
0xffff8802217c8b60 656 1 0 3 S 0xffff8802217c91f8 tuned
0xffff880222e196c0 606 1 0 1 S 0xffff880222e19d58 irqbalance
0xffff8802217cc440 607 1 0 1 S 0xffff8802217ccad8 systemd-logind
0xffff8802217cb8e0 613 1 0 0 S 0xffff8802217cbf78 dbus-daemon
0xffff8800371896c0 619 1 0 4 S 0xffff880037189d58 iprupdate
0xffff8802217ce660 623 1 0 1 S 0xffff8802217cecf8 crond
0xffff8802217ccfa0 624 1 0 5 S 0xffff8802217cd638 atd
0xffff88022176ad80 627 1 0 7 S 0xffff88022176b418 ksmtuned
0xffff880220d916c0 637 1 0 3 S 0xffff880220d91d58 iprdump
0xffff8800c8d4a220 642 1 0 1 S 0xffff8800c8d4a8b8 ntpd
0xffff8802217ca220 649 1 0 0 S 0xffff8802217ca8b8 agetty
0xffff8802217cad80 650 1 0 2 S 0xffff8802217cb418 agetty
0xffff88003718cfa0 657 1 0 1 S 0xffff88003718d638 polkitd
0xffff880220d90000 670 1 0 4 S 0xffff880220d90698 gdbus
0xffff8800c8da2d80 679 1 0 5 S 0xffff8800c8da3418 JS GC Helper
0xffff8800c8da38e0 680 1 0 5 S 0xffff8800c8da3f78 JS Sour~ Thread
0xffff8800c8da4440 681 1 0 6 S 0xffff8800c8da4ad8 runaway-killer-
0xffff8800c8da4fa0 682 1 0 5 S 0xffff8800c8da5638 gmain
0xffff880220d90b60 915 1 0 0 S 0xffff880220d911f8 rhsmcertd
0xffff8800c8d4f1c0 917 1 0 2 S 0xffff8800c8d4f858 rpcbind
0xffff8800c8d4e660 1058 1 0 1 S 0xffff8800c8d4ecf8 rpc.statd
0xffff8802188971c0 1759 1 0 1 S 0xffff880218897858 master
0xffff8802210ae660 1793 1759 0 2 S 0xffff8802210aecf8 pickup
0xffff8802210a96c0 1794 1759 0 2 S 0xffff8802210a9d58 qmgr
0xffff88020030cfa0 12678 2 1 0 R 0xffff88020030d638 *kworker/0:2
0xffff8802208da220 13582 1 0 7 S 0xffff8802208da8b8 rsyslogd
0xffff8800641f2220 13584 1 0 6 S 0xffff8800641f28b8 in:imjournal
0xffff8800641f6660 13585 1 0 0 S 0xffff8800641f6cf8 rs:main Q:Reg
0xffff88022176db00 14168 1 0 3 S 0xffff88022176e198 sshd
0xffff8802208fcfa0 14179 14168 0 1 S 0xffff8802208fd638 sshd
0xffff880037188b60 14182 14179 0 3 S 0xffff8800371891f8 sshd
0xffff880200032d80 15753 627 0 7 S 0xffff880200033418 sleep
0xffff8800641f0b60 15767 1 0 7 S 0xffff8800641f11f8 agetty
0xffff8800c8da0000 15861 385 0 3 S 0xffff8800c8da0698 systemd-udevd
0xffff88020030a220 15912 385 0 6 S 0xffff88020030a8b8 systemd-udevd
0xffff880220c671c0 15938 385 0 6 S 0xffff880220c67858 systemd-udevd
[dumpcommon]kdb> -dmesg 600

<6>[ 2051.635083] rbd0: detected capacity change from 213343744 to 161427456
<6>[ 2051.868253] rbd0: detected capacity change from 161427456 to 245539840
<6>[ 2052.081573] rbd0: detected capacity change from 245539840 to 147099136
<6>[ 2052.215522] rbd0: detected capacity change from 147099136 to 97363968
<4>[ 2052.230283] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<6>[ 2052.315452] rbd0: detected capacity change from 97363968 to 142695424
<6>[ 2052.440533] rbd0: detected capacity change from 142695424 to 213249536
<6>[ 2052.603220] rbd0: detected capacity change from 213249536 to 97737216
<6>[ 2052.835867] rbd0: detected capacity change from 97737216 to 101259776
<6>[ 2052.930086] rbd0: detected capacity change from 101259776 to 229096960
<6>[ 2053.049121] rbd0: detected capacity change from 229096960 to 244953600
<6>[ 2053.241347] rbd0: detected capacity change from 244953600 to 102488064
<6>[ 2053.293071] rbd0: detected capacity change from 102488064 to 213864960
<6>[ 2053.466326] rbd0: detected capacity change from 213864960 to 144012800
<6>[ 2053.603543] rbd0: detected capacity change from 144012800 to 119612928
<6>[ 2053.699490] rbd0: detected capacity change from 119612928 to 223614464
<6>[ 2053.849701] rbd0: detected capacity change from 223614464 to 194128896
<6>[ 2053.926855] rbd0: detected capacity change from 194128896 to 197659136
<6>[ 2054.074851] rbd0: detected capacity change from 197659136 to 231887872
<6>[ 2054.244954] rbd0: detected capacity change from 231887872 to 150221312
<6>[ 2054.336875] rbd0: detected capacity change from 150221312 to 191074816
<6>[ 2054.558924] rbd0: detected capacity change from 191074816 to 25175040
<6>[ 2054.837343] rbd0: detected capacity change from 25175040 to 60905984
<6>[ 2055.004626] rbd0: detected capacity change from 60905984 to 182412800
<6>[ 2055.055865] rbd0: detected capacity change from 182412800 to 118825984
<6>[ 2055.254677] rbd0: detected capacity change from 118825984 to 7435264
<6>[ 2055.435717] rbd0: detected capacity change from 7435264 to 227537920
<6>[ 2055.611051] rbd0: detected capacity change from 227537920 to 120069120
<6>[ 2055.712869] rbd0: detected capacity change from 120069120 to 230793216
<6>[ 2055.908905] rbd0: detected capacity change from 230793216 to 56567808
<6>[ 2056.046273] rbd0: detected capacity change from 56567808 to 155833856
<6>[ 2056.381960] rbd0: detected capacity change from 155833856 to 24217088
<6>[ 2056.476183] rbd0: detected capacity change from 24217088 to 124986880
<6>[ 2056.630183] rbd0: detected capacity change from 124986880 to 205387776
<6>[ 2056.834301] rbd0: detected capacity change from 205387776 to 52600320
<6>[ 2056.926424] rbd0: detected capacity change from 52600320 to 142633472
<6>[ 2057.051489] rbd0: detected capacity change from 142633472 to 230255104
<6>[ 2057.259758] rbd0: detected capacity change from 230255104 to 76900864
<6>[ 2057.359798] rbd0: detected capacity change from 76900864 to 211555840
<6>[ 2057.480785] rbd0: detected capacity change from 211555840 to 233564160
<6>[ 2057.680966] rbd0: detected capacity change from 233564160 to 45549056
<6>[ 2057.771695] rbd0: detected capacity change from 45549056 to 110811136
<6>[ 2057.896882] rbd0: detected capacity change from 110811136 to 142949376
<6>[ 2058.039070] rbd0: detected capacity change from 142949376 to 52148736
<6>[ 2058.194459] rbd0: detected capacity change from 52148736 to 16208896
<6>[ 2058.246033] rbd0: detected capacity change from 16208896 to 61477376
<6>[ 2058.377652] rbd0: detected capacity change from 61477376 to 209786880
<6>[ 2058.585632] rbd0: detected capacity change from 209786880 to 4559360
<6>[ 2058.685795] rbd0: detected capacity change from 4559360 to 101084672
<6>[ 2058.777662] rbd0: detected capacity change from 101084672 to 219771392
<6>[ 2058.869812] rbd0: detected capacity change from 219771392 to 231183360
<6>[ 2059.044903] rbd0: detected capacity change from 231183360 to 229963264
<6>[ 2059.195068] rbd0: detected capacity change from 229963264 to 24186880
<6>[ 2059.303077] rbd0: detected capacity change from 24186880 to 19743232
<6>[ 2060.767773] rbd0: detected capacity change from 19743232 to 3647488
<4>[ 2060.950820] rbd: image image_client.0-clone76: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2061.002535] rbd0: unknown partition table
<6>[ 2061.007532] rbd: rbd0: added with size 0x12d4200
<6>[ 2061.232586] rbd1: unknown partition table
<6>[ 2061.237575] rbd: rbd1: added with size 0x8024600
<4>[ 2061.580727] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 2062.955812] libceph: osd5 10.214.132.18:6805 socket closed (con state OPEN)
<6>[ 2063.690428] rbd0: detected capacity change from 19743232 to 119373824
<6>[ 2063.863912] rbd0: detected capacity change from 119373824 to 235195392
<6>[ 2064.063972] rbd0: detected capacity change from 235195392 to 76112896
<6>[ 2064.163837] rbd0: detected capacity change from 76112896 to 234420224
<6>[ 2064.339231] rbd0: detected capacity change from 234420224 to 173839360
<6>[ 2064.374105] rbd0: detected capacity change from 173839360 to 191083008
<6>[ 2065.533643] rbd0: detected capacity change from 191083008 to 5922816
<4>[ 2065.812580] rbd: image image_client.0-clone77: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2065.867363] rbd0: unknown partition table
<6>[ 2065.872493] rbd: rbd0: added with size 0xb63b200
<4>[ 2066.448603] rbd: image image_client.0-clone75: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2066.510596] rbd1: unknown partition table
<6>[ 2066.515813] rbd: rbd1: added with size 0x37a800
<4>[ 2066.691729] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<6>[ 2066.975484] rbd0: detected capacity change from 191083008 to 116306432
<6>[ 2067.223946] rbd0: detected capacity change from 116306432 to 177940480
<6>[ 2067.499135] rbd0: detected capacity change from 177940480 to 212969984
<6>[ 2067.657308] rbd0: detected capacity change from 212969984 to 147590144
<6>[ 2067.749211] rbd0: detected capacity change from 147590144 to 210128896
<6>[ 2067.933283] rbd0: detected capacity change from 210128896 to 35324416
<6>[ 2068.024362] rbd0: detected capacity change from 35324416 to 141732352
<6>[ 2068.182314] rbd0: detected capacity change from 141732352 to 99421696
<6>[ 2068.282386] rbd0: detected capacity change from 99421696 to 228065792
<6>[ 2068.568587] rbd0: detected capacity change from 228065792 to 140640768
<6>[ 2068.791452] rbd0: detected capacity change from 140640768 to 12185088
<6>[ 2068.891444] rbd0: detected capacity change from 12185088 to 182287872
<6>[ 2069.108682] rbd: rbd0: clone image has been flattened
<6>[ 2069.232483] rbd0: detected capacity change from 182287872 to 208978944
<6>[ 2069.373655] rbd0: detected capacity change from 208978944 to 236920832
<4>[ 2070.657329] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 2070.701664] rbd: image image_client.0-clone78: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2070.724270] rbd0: unknown partition table
<6>[ 2070.724345] rbd: rbd0: added with size 0xe1f2000
<4>[ 2071.222896] rbd: image image_client.0-clone76: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2071.256052] rbd1: unknown partition table
<6>[ 2071.261474] rbd: rbd1: added with size 0x5a6000
<4>[ 2072.210000] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<6>[ 2072.660927] rbd0: detected capacity change from 236920832 to 24635904
<6>[ 2072.758768] rbd0: detected capacity change from 24635904 to 121057280
<6>[ 2072.917123] rbd0: detected capacity change from 121057280 to 80313856
<6>[ 2073.073427] rbd0: detected capacity change from 80313856 to 199263744
<6>[ 2073.341465] rbd0: detected capacity change from 199263744 to 28219904
<6>[ 2073.391489] rbd0: detected capacity change from 28219904 to 27127296
<6>[ 2073.489704] rbd0: detected capacity change from 27127296 to 141751808
<6>[ 2073.609416] rbd0: detected capacity change from 141751808 to 31031808
<6>[ 2073.661659] rbd0: detected capacity change from 31031808 to 97830912
<6>[ 2073.784210] rbd0: detected capacity change from 97830912 to 246086144
<6>[ 2073.942919] rbd0: detected capacity change from 246086144 to 189165056
<6>[ 2074.134923] rbd0: detected capacity change from 189165056 to 68451840
<6>[ 2074.235020] rbd0: detected capacity change from 68451840 to 184101888
<6>[ 2074.367944] rbd0: detected capacity change from 184101888 to 217066496
<6>[ 2074.582190] rbd0: detected capacity change from 217066496 to 59357696
<6>[ 2074.674306] rbd0: detected capacity change from 59357696 to 119108096
<6>[ 2074.790192] rbd0: detected capacity change from 119108096 to 37542400
<4>[ 2075.812773] rbd: image image_client.0-clone79: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2075.865115] rbd0: unknown partition table
<6>[ 2075.870441] rbd: rbd0: added with size 0x23cda00
<6>[ 2076.111678] rbd1: unknown partition table
<6>[ 2076.117037] rbd: rbd1: added with size 0xe1f2000
<4>[ 2077.312591] libceph: osd4 10.214.132.18:6806 socket closed (con state OPEN)
<4>[ 2077.351268] libceph: osd4 10.214.132.18:6806 socket closed (con state OPEN)
<6>[ 2078.424427] rbd0: detected capacity change from 37542400 to 66806272
<6>[ 2078.572381] rbd0: detected capacity change from 66806272 to 234706944
<6>[ 2080.637832] rbd: rbd0: clone image has been flattened
<4>[ 2081.215611] rbd: image image_client.0-clone80: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2081.305381] rbd0: unknown partition table
<6>[ 2081.310715] rbd: rbd0: added with size 0xdfd5800
<4>[ 2082.112706] rbd: image image_client.0-clone78: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2082.146812] rbd1: unknown partition table
<6>[ 2082.146933] rbd: rbd1: added with size 0x23cda00
<4>[ 2082.880646] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<6>[ 2083.422746] rbd0: detected capacity change from 234706944 to 239360000
<6>[ 2083.587606] rbd0: detected capacity change from 239360000 to 209608704
<6>[ 2084.391800] rbd0: detected capacity change from 209608704 to 52210688
<6>[ 2084.488233] rbd0: detected capacity change from 52210688 to 153520128
<6>[ 2085.051273] rbd: rbd0: clone image has been flattened
<6>[ 2085.147757] rbd0: detected capacity change from 153520128 to 237888000
<6>[ 2085.297817] rbd0: detected capacity change from 237888000 to 177200128
<6>[ 2085.624380] rbd0: detected capacity change from 177200128 to 199335936
<6>[ 2085.771194] rbd0: detected capacity change from 199335936 to 178363392
<6>[ 2086.012079] rbd0: detected capacity change from 178363392 to 221938688
<6>[ 2086.409254] rbd0: detected capacity change from 221938688 to 46882304
<6>[ 2086.640239] rbd0: detected capacity change from 46882304 to 206433280
<4>[ 2088.766976] rbd: image image_client.0-clone81: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2088.833720] rbd0: unknown partition table
<6>[ 2088.839018] rbd: rbd0: added with size 0xc4dec00
<6>[ 2089.330978] rbd1: unknown partition table
<6>[ 2089.336509] rbd: rbd1: added with size 0xdfd5800
<4>[ 2090.077686] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<6>[ 2091.838649] rbd0: detected capacity change from 206433280 to 101371904
<6>[ 2092.265723] rbd0: detected capacity change from 101371904 to 195948032
<6>[ 2092.572231] rbd0: detected capacity change from 195948032 to 17889280
<6>[ 2092.624243] rbd0: detected capacity change from 17889280 to 91929600
<6>[ 2092.722329] rbd0: detected capacity change from 91929600 to 187510784
<6>[ 2092.889294] rbd0: detected capacity change from 187510784 to 148244480
<6>[ 2092.961555] rbd0: detected capacity change from 148244480 to 160127488
<6>[ 2093.114535] rbd0: detected capacity change from 160127488 to 236913152
<6>[ 2093.272477] rbd0: detected capacity change from 236913152 to 170947072
<6>[ 2093.389432] rbd0: detected capacity change from 170947072 to 142330368
<6>[ 2093.440669] rbd0: detected capacity change from 142330368 to 158621696
<6>[ 2093.563102] rbd0: detected capacity change from 158621696 to 249854464
<6>[ 2093.724629] rbd0: detected capacity change from 249854464 to 189551616
<6>[ 2093.847729] rbd0: detected capacity change from 189551616 to 130510336
<6>[ 2093.891212] rbd0: detected capacity change from 130510336 to 133538816
<6>[ 2094.366809] rbd: rbd0: clone image has been flattened
<6>[ 2094.463973] rbd0: detected capacity change from 133538816 to 228063232
<6>[ 2094.629943] rbd0: detected capacity change from 228063232 to 49229312
<6>[ 2094.762471] rbd0: detected capacity change from 49229312 to 48223744
<6>[ 2094.806969] rbd0: detected capacity change from 48223744 to 99284480
<6>[ 2094.857074] rbd0: detected capacity change from 99284480 to 125250560
<6>[ 2094.963086] rbd0: detected capacity change from 125250560 to 135201792
<6>[ 2095.080072] rbd0: detected capacity change from 135201792 to 202715136
<6>[ 2095.280657] rbd0: detected capacity change from 202715136 to 13441024
<6>[ 2095.388450] rbd0: detected capacity change from 13441024 to 200593920
<6>[ 2095.563181] rbd0: detected capacity change from 200593920 to 172916224
<6>[ 2095.688733] rbd0: detected capacity change from 172916224 to 219155456
<6>[ 2095.841128] rbd0: detected capacity change from 219155456 to 73019392
<6>[ 2095.882821] rbd0: detected capacity change from 73019392 to 97001472
<6>[ 2096.030882] rbd0: detected capacity change from 97001472 to 145533440
<6>[ 2096.108285] rbd0: detected capacity change from 145533440 to 208893952
<4>[ 2096.253163] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<6>[ 2096.289136] rbd0: detected capacity change from 208893952 to 38039040
<4>[ 2097.180176] rbd: image image_client.0-clone82: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2097.212119] rbd0: unknown partition table
<6>[ 2097.217291] rbd: rbd0: added with size 0x2446e00
<6>[ 2097.449536] rbd1: unknown partition table
<6>[ 2097.454767] rbd: rbd1: added with size 0xc4dec00
<4>[ 2097.784777] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<6>[ 2099.734033] rbd0: detected capacity change from 38039040 to 120387072
<6>[ 2099.867596] rbd0: detected capacity change from 120387072 to 216176128
<6>[ 2100.170215] rbd0: detected capacity change from 216176128 to 225687040
<6>[ 2100.427034] rbd0: detected capacity change from 225687040 to 207728640
<6>[ 2100.476297] rbd0: detected capacity change from 207728640 to 217159168
<6>[ 2100.674089] rbd0: detected capacity change from 217159168 to 53585408
<6>[ 2100.843183] rbd0: detected capacity change from 53585408 to 40378880
<6>[ 2100.887192] rbd0: detected capacity change from 40378880 to 63390720
<6>[ 2101.018144] rbd0: detected capacity change from 63390720 to 59257856
<6>[ 2101.443681] rbd0: detected capacity change from 59257856 to 167710720
<4>[ 2102.991510] rbd: image image_client.0-clone83: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2103.027827] rbd0: unknown partition table
<6>[ 2103.032965] rbd: rbd0: added with size 0x9ff1000
<6>[ 2103.590537] rbd1: unknown partition table
<6>[ 2103.595730] rbd: rbd1: added with size 0x2446e00
<6>[ 2104.965106] rbd0: detected capacity change from 167710720 to 216259584
<6>[ 2105.605117] rbd0: detected capacity change from 216259584 to 193611776
<6>[ 2106.063757] rbd0: detected capacity change from 193611776 to 42492928
<6>[ 2106.288598] rbd0: detected capacity change from 42492928 to 101744640
<6>[ 2106.608592] rbd0: detected capacity change from 101744640 to 198000640
<6>[ 2106.719049] rbd0: detected capacity change from 198000640 to 220859392
<6>[ 2107.040813] rbd0: detected capacity change from 220859392 to 8401408
<6>[ 2107.283926] rbd0: detected capacity change from 8401408 to 50741760
<6>[ 2107.448159] rbd0: detected capacity change from 50741760 to 177784320
<6>[ 2107.573030] rbd0: detected capacity change from 177784320 to 181687808
<6>[ 2107.698196] rbd0: detected capacity change from 181687808 to 224031744
<6>[ 2107.949526] rbd0: detected capacity change from 224031744 to 191158784
<6>[ 2108.172457] rbd0: detected capacity change from 191158784 to 137909760
<6>[ 2108.267629] rbd0: detected capacity change from 137909760 to 208867840
<6>[ 2108.397604] rbd0: detected capacity change from 208867840 to 225909248
<6>[ 2108.531715] rbd0: detected capacity change from 225909248 to 247368192
<6>[ 2108.790026] rbd: rbd0: clone image has been flattened
<6>[ 2108.988731] rbd0: detected capacity change from 247368192 to 26407424
<6>[ 2109.097677] rbd0: detected capacity change from 26407424 to 191222784
<6>[ 2109.251075] rbd0: detected capacity change from 191222784 to 239692800
<6>[ 2109.423179] rbd0: detected capacity change from 239692800 to 28843520
<6>[ 2109.531186] rbd0: detected capacity change from 28843520 to 217647104
<6>[ 2109.656295] rbd0: detected capacity change from 217647104 to 236523008
<6>[ 2109.806308] rbd0: detected capacity change from 236523008 to 249517568
<4>[ 2110.904162] rbd: image image_client.0-clone84: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2110.936389] rbd0: unknown partition table
<6>[ 2110.941609] rbd: rbd0: added with size 0xedf5600
<4>[ 2111.099428] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 2111.394045] rbd: image image_client.0-clone82: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2111.417839] rbd1: unknown partition table
<6>[ 2111.423148] rbd: rbd1: added with size 0x9ff1000
<4>[ 2111.630166] libceph: osd4 10.214.132.18:6806 socket closed (con state OPEN)
<4>[ 2113.414915] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 2113.889311] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 2114.609994] libceph: osd5 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 2114.711134] libceph: osd4 10.214.132.18:6806 socket closed (con state OPEN)
<6>[ 2115.618498] rbd0: detected capacity change from 249517568 to 141533696
<6>[ 2115.776262] rbd0: detected capacity change from 141533696 to 52403200
<6>[ 2115.820769] rbd0: detected capacity change from 52403200 to 57193472
<6>[ 2116.829573] rbd: rbd0: clone image has been flattened
<6>[ 2116.926602] rbd0: detected capacity change from 57193472 to 130748928
<6>[ 2117.143672] rbd0: detected capacity change from 130748928 to 223996416
<6>[ 2117.512113] rbd0: detected capacity change from 223996416 to 6341632
<4>[ 2118.649993] rbd: image image_client.0-clone85: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2118.715671] rbd0: unknown partition table
<6>[ 2118.720919] rbd: rbd0: added with size 0x60c400
<4>[ 2118.745120] libceph: osd5 10.214.132.18:6805 socket closed (con state OPEN)
<6>[ 2118.929020] rbd1: unknown partition table
<6>[ 2118.934267] rbd: rbd1: added with size 0xedf5600
<4>[ 2118.983240] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 2119.431324] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 2119.837315] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 2120.133371] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 2121.381767] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 2122.218111] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 2122.408462] libceph: osd5 10.214.132.18:6805 socket closed (con state OPEN)
<6>[ 2124.749163] rbd: rbd0: clone image now standalone
<6>[ 2124.754964] rbd0: detected capacity change from 6341632 to 0
<4>[ 2124.937802] rbd: image image_client.0-clone86: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2125.019790] rbd0: unknown partition table
<6>[ 2125.025181] rbd: rbd0: added with size 0x60c400
<6>[ 2125.332468] rbd1: unknown partition table
<6>[ 2125.337839] rbd: rbd1: added with size 0x60c400
<6>[ 2125.657846] rbd0: detected capacity change from 6341632 to 148511744
<6>[ 2125.791762] rbd0: detected capacity change from 148511744 to 238388224
<6>[ 2125.986139] rbd0: detected capacity change from 238388224 to 161313280
<6>[ 2126.038461] rbd0: detected capacity change from 161313280 to 203613696
<6>[ 2126.244372] rbd0: detected capacity change from 203613696 to 136144896
<6>[ 2126.297149] rbd0: detected capacity change from 136144896 to 211648512
<6>[ 2127.355430] rbd: rbd0: clone image has been flattened
<4>[ 2127.795225] rbd: image image_client.0-clone87: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2127.843078] rbd0: unknown partition table
<6>[ 2127.848468] rbd: rbd0: added with size 0xc9d8000
<4>[ 2128.192861] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 2128.456384] rbd: image image_client.0-clone85: ignoring parent with overlap 0
<4>[ 2128.464731] rbd: image image_client.0-clone85: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2128.484827] rbd: rbd1: added with size 0x0
<6>[ 2129.552624] rbd0: detected capacity change from 211648512 to 217723904
<6>[ 2129.853260] rbd0: detected capacity change from 217723904 to 249628160
<6>[ 2130.382198] rbd0: detected capacity change from 249628160 to 119948288
<6>[ 2130.630951] rbd0: detected capacity change from 119948288 to 249975296
<6>[ 2130.927854] rbd0: detected capacity change from 249975296 to 117103104
<6>[ 2131.014130] rbd0: detected capacity change from 117103104 to 135186432
<6>[ 2131.057632] rbd0: detected capacity change from 135186432 to 146128896
<6>[ 2131.214081] rbd0: detected capacity change from 146128896 to 239771648
<6>[ 2131.430501] rbd0: detected capacity change from 239771648 to 40621056
<6>[ 2131.534370] rbd0: detected capacity change from 40621056 to 216572928
<6>[ 2132.545459] rbd0: detected capacity change from 216572928 to 36558848
<4>[ 2132.795176] rbd: image image_client.0-clone88: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2132.893452] rbd0: unknown partition table
<6>[ 2132.898998] rbd: rbd0: added with size 0xce8a400
<6>[ 2133.639945] rbd1: unknown partition table
<6>[ 2133.645343] rbd: rbd1: added with size 0xc9d8000
<4>[ 2134.381957] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 2135.247970] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<6>[ 2136.057894] rbd0: detected capacity change from 216572928 to 160137728
<6>[ 2136.472771] rbd0: detected capacity change from 160137728 to 4632576
<6>[ 2136.562552] rbd0: detected capacity change from 4632576 to 64854016
<6>[ 2136.733521] rbd0: detected capacity change from 64854016 to 5121536
<6>[ 2136.833574] rbd0: detected capacity change from 5121536 to 159161344
<6>[ 2136.929724] rbd0: detected capacity change from 159161344 to 100005888
<6>[ 2137.227970] rbd0: detected capacity change from 100005888 to 28176384
<6>[ 2137.338363] rbd0: detected capacity change from 28176384 to 205347328
<6>[ 2137.682419] rbd0: detected capacity change from 205347328 to 122344448
<6>[ 2137.834320] rbd0: detected capacity change from 122344448 to 248693248
<6>[ 2137.996519] rbd0: detected capacity change from 248693248 to 5116416
<6>[ 2138.045381] rbd0: detected capacity change from 5116416 to 47549440
<6>[ 2138.163462] rbd0: detected capacity change from 47549440 to 128805888
<6>[ 2138.263415] rbd0: detected capacity change from 128805888 to 93716480
<6>[ 2138.307051] rbd0: detected capacity change from 93716480 to 99752960
<6>[ 2138.434374] rbd0: detected capacity change from 99752960 to 103378944
<6>[ 2138.688547] rbd0: detected capacity change from 103378944 to 99065344
<6>[ 2138.821892] rbd0: detected capacity change from 99065344 to 56735744
<6>[ 2138.972033] rbd0: detected capacity change from 56735744 to 207195136
<6>[ 2139.122079] rbd0: detected capacity change from 207195136 to 192118272
<6>[ 2139.322293] rbd0: detected capacity change from 192118272 to 185344512
<6>[ 2139.489136] rbd0: detected capacity change from 185344512 to 8148480
<6>[ 2139.655307] rbd0: detected capacity change from 8148480 to 526848
<6>[ 2139.797459] rbd0: detected capacity change from 526848 to 180415488
<6>[ 2139.918467] rbd0: detected capacity change from 180415488 to 222597632
<6>[ 2140.097690] rbd0: detected capacity change from 222597632 to 105043456
<6>[ 2140.222755] rbd0: detected capacity change from 105043456 to 135770624
<6>[ 2140.422710] rbd0: detected capacity change from 135770624 to 11571712
<6>[ 2140.519677] rbd0: detected capacity change from 11571712 to 101338112
<6>[ 2140.610882] rbd0: detected capacity change from 101338112 to 132320768
<6>[ 2140.746756] rbd0: detected capacity change from 132320768 to 70665216
<6>[ 2140.839884] rbd0: detected capacity change from 70665216 to 138366976
<6>[ 2140.932134] rbd0: detected capacity change from 138366976 to 146527744
<6>[ 2141.065210] rbd0: detected capacity change from 146527744 to 57637888
<6>[ 2141.156133] rbd0: detected capacity change from 57637888 to 99233792
<6>[ 2141.357376] rbd0: detected capacity change from 99233792 to 145616384
<4>[ 2141.934128] rbd: image image_client.0-clone87: WARNING: kernel layering is EXPERIMENTAL!
<6>[ 2142.049101] rbd0: unknown partition table
<6>[ 2142.054249] rbd: rbd0: added with size 0x22dd800
<4>[ 2345.914627] libceph: mon0 10.214.131.8:6789 socket closed (con state OPEN)
<6>[ 2345.922638] libceph: mon0 10.214.131.8:6789 session lost, hunting for new mon
<6>[ 2345.933609] libceph: mon1 10.214.132.18:6789 session established
<4>[ 2357.922961] libceph: mon1 10.214.132.18:6789 socket closed (con state OPEN)
<6>[ 2357.930850] libceph: mon1 10.214.132.18:6789 session lost, hunting for new mon
<4>[ 2357.939196] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2374.292544] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2384.314564] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2394.336553] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2404.358589] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2414.380656] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2424.402696] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2434.424684] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2444.446759] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2454.468783] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2464.490710] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2474.512816] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2484.535761] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2494.557882] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2504.578917] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2514.600880] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2524.622901] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2534.645764] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2544.667004] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2554.688988] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2564.711072] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2574.733184] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<6>[ 2578.285102] kgdb: Unregistered I/O driver kgdboc, debugger disabled.
<6>[ 2578.292363] kgdb: Registered I/O driver kgdboc.
<4>[ 2584.755907] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2594.777194] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2604.799924] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2614.821993] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2624.844029] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2634.865309] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2644.887348] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2654.909404] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2664.931445] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2674.953499] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2684.975532] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2694.997484] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2705.019598] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2715.041490] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2725.063517] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2735.085655] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2745.107950] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2755.129673] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2765.151634] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2775.173705] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2785.196726] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2795.218733] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2805.240831] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2815.268648] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2825.283925] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2835.305963] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2845.327912] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2855.350051] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2865.372034] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2875.394095] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2885.417083] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2895.438175] libceph: mon1 10.214.132.18:6789 socket closed (con state CONNECTING)
<4>[ 2905.460150] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2915.482194] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2925.504180] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2935.526222] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2945.548252] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2955.570370] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<4>[ 2965.592393] libceph: mon0 10.214.131.8:6789 socket closed (con state CONNECTING)
<4>[ 2975.614427] libceph: mon2 10.214.131.8:6790 socket closed (con state CONNECTING)
<3>[ 3005.681409] libceph: bad fsid, had 1e6e9c31-177b-4ea0-a5d8-48d83c11b9f7 got 85afa844-1fb6-4a09-9578-b24d898efb00
<3>[ 3005.692218] libceph: auth method 'x' error -1
<3>[ 3015.703678] libceph: bad fsid, had 1e6e9c31-177b-4ea0-a5d8-48d83c11b9f7 got 85afa844-1fb6-4a09-9578-b24d898efb00
<3>[ 3015.714350] libceph: auth method 'x' error -1
<6>[ 3015.848894] libceph: client4115 fsid 85afa844-1fb6-4a09-9578-b24d898efb00
<6>[ 3015.858943] libceph: mon2 10.214.131.8:6790 session established
<6>[ 3015.929119] rbd0: unknown partition table
<6>[ 3015.934524] rbd: rbd0: added with size 0x280000000
<4>[ 3015.984554] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3016.010623] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3016.019121] libceph: osd5 10.214.132.18:6810 socket closed (con state CONNECTING)
<4>[ 3017.317938] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3017.445597] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3017.500037] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3017.500446] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3017.506343] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3017.515058] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3017.517324] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3017.519087] libceph: osd4 10.214.132.18:6805 socket closed (con state CONNECTING)
<4>[ 3017.520412] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3017.520777] libceph: osd3 10.214.132.18:6800 socket closed (con state CONNECTING)
<4>[ 3017.528731] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3017.537096] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3017.537379] libceph: osd0 10.214.131.8:6805 socket closed (con state CONNECTING)
<4>[ 3018.254525] libceph: osd0 10.214.131.8:6805 socket closed (con state CONNECTING)
<4>[ 3018.255850] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3018.272054] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3018.280794] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3018.289013] libceph: osd1 10.214.131.8:6810 socket closed (con state CONNECTING)
<4>[ 3018.298389] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3018.298543] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3019.254295] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3019.262632] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3019.271229] libceph: osd2 10.214.131.8:6800 socket closed (con state CONNECTING)
<4>[ 3019.271294] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3019.272614] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3019.295360] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3019.314278] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3019.355673] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3019.355852] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3019.356604] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3019.357156] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3019.403504] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3019.422393] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3019.422613] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3019.497073] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3019.503433] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3020.242928] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3020.281340] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3020.305462] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3020.316078] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3020.317000] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3020.353186] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<6>[ 3020.536439] BTRFS: device fsid 948aec6d-0c9d-4202-8479-c6231f3e12d2 devid 1 transid 4 /dev/rbd0
<4>[ 3020.789314] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<6>[ 3020.853666] BTRFS info (device rbd0): disk space caching is enabled
<6>[ 3020.860729] BTRFS: flagging fs with big metadata feature
<6>[ 3020.877758] BTRFS: creating UUID tree
<3>[ 3025.725750] libceph: bad fsid, had 1e6e9c31-177b-4ea0-a5d8-48d83c11b9f7 got 85afa844-1fb6-4a09-9578-b24d898efb00
<3>[ 3025.736424] libceph: auth method 'x' error -1
<4>[ 3030.092343] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3030.599299] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3030.661220] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3030.715350] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3030.724604] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3031.407351] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3031.894285] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3032.253665] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3032.724354] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3033.637581] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3033.666609] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3033.699717] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3034.145777] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3034.255800] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3034.482677] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3034.512472] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3034.564156] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3034.745860] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3034.773796] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3034.791536] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3034.825141] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3035.562723] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3035.735425] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3035.743812] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<3>[ 3035.751995] libceph: bad fsid, had 1e6e9c31-177b-4ea0-a5d8-48d83c11b9f7 got 85afa844-1fb6-4a09-9578-b24d898efb00
<3>[ 3035.751995] libceph: auth method 'x' error -1
<4>[ 3036.521524] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3036.764990] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3036.776480] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3036.910606] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3037.129467] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3037.185565] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3037.217889] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3037.351320] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3037.744422] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3037.820583] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3037.830345] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3037.936715] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3038.738189] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3038.783812] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3039.387442] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3039.945179] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3040.135996] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3040.246656] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3040.548030] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3040.622089] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3040.680338] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3040.831209] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3041.989506] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3042.762839] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3042.771211] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3042.910504] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3042.965697] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3042.983063] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3043.056938] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3043.080551] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3043.692827] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3043.782194] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3044.427688] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3044.754994] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3045.404959] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3045.415854] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3045.548882] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3045.571186] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3045.760437] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<3>[ 3045.772422] libceph: bad fsid, had 1e6e9c31-177b-4ea0-a5d8-48d83c11b9f7 got 85afa844-1fb6-4a09-9578-b24d898efb00
<3>[ 3045.783140] libceph: auth method 'x' error -1
<4>[ 3045.827213] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3045.839095] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3045.848049] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3045.992419] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3046.022891] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3046.041726] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3046.235767] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3047.562662] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3047.563785] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3048.060592] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3048.470867] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3048.555223] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3048.563160] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3048.574144] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3048.610455] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3048.616716] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3048.792072] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3048.792239] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3048.831417] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3048.841664] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3048.927176] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3048.975287] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3050.349776] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3050.445696] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3050.454546] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3051.188918] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3051.208705] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3051.248584] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3051.534325] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3052.368341] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3052.447914] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3052.451323] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3052.876765] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3053.249099] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3053.263013] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3053.486045] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3053.488569] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3053.544445] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3053.580947] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3053.703389] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3054.071837] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3054.541703] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3054.727570] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3055.174305] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3055.764825] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3055.786436] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<3>[ 3055.795191] libceph: bad fsid, had 1e6e9c31-177b-4ea0-a5d8-48d83c11b9f7 got 85afa844-1fb6-4a09-9578-b24d898efb00
<3>[ 3055.805753] libceph: auth method 'x' error -1
<4>[ 3056.672662] libceph: osd3 10.214.132.18:6800 socket closed (con state OPEN)
<4>[ 3056.802246] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3056.805313] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<4>[ 3057.198625] libceph: osd4 10.214.132.18:6805 socket closed (con state OPEN)
<4>[ 3057.209514] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3057.708656] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3057.818547] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3058.545421] libceph: osd5 10.214.132.18:6810 socket closed (con state OPEN)
<4>[ 3058.919211] libceph: osd1 10.214.131.8:6810 socket closed (con state OPEN)
<4>[ 3059.525966] libceph: osd0 10.214.131.8:6805 socket closed (con state OPEN)
<4>[ 3062.854575] libceph: osd2 10.214.131.8:6800 socket closed (con state OPEN)
<5>[ 3063.391401] Key type ceph unregistered
<5>[ 3063.406090] Key type dns_resolver unregistered
<1>[ 3065.812440] BUG: unable to handle kernel paging request at ffffffffa052ba20
<1>[ 3065.820247] IP: [<ffffffffa052ba20>] 0xffffffffa052ba1f
<4>[ 3065.826324] PGD 190d067 PUD 190e063 PMD 221249067 PTE 0
<4>[ 3065.832445] Oops: 0010 [#1] SMP
[dumpcommon]kdb> -bt

Stack traceback for pid 12678
0xffff88020030cfa0 12678 2 1 0 R 0xffff88020030d638 *kworker/0:2
ffff8800ca98be20 0000000000000018 ffffffff8108f09b 0000000027213ed8
0000000000000000 ffff880227213ed8 ffff8800c8e24430 ffff88020030cfa0
ffff8800c8e24400 ffff880227213ec0 ffff8800ca98bec0 ffffffff8108fe7b
Call Trace:
[<ffffffff8108f09b>] ? process_one_work+0x17b/0x470
[<ffffffff8108fe7b>] ? worker_thread+0x11b/0x400
[<ffffffff8108fd60>] ? rescuer_thread+0x400/0x400
[<ffffffff8109725f>] ? kthread+0xcf/0xe0
[<ffffffff81097190>] ? kthread_create_on_node+0x140/0x140
[<ffffffff816142fc>] ? ret_from_fork+0x7c/0xb0
[<ffffffff81097190>] ? kthread_create_on_node+0x140/0x140

[0]kdb> rd
ax: 0000000000000000 bx: ffff8800a8224200 cx: dead000000200200
dx: 0000000000000001 si: 0000000000000001 di: ffff8800a8224200
bp: ffff8800ca98be60 sp: ffff8800ca98be20 r8: ffff8800a8224208
r9: dffce777a0224200 r10: dffce777a0224200 r11: ffffffff81d5ff68
r12: ffff8800c8e24400 r13: ffff880227213ec0 r14: ffff880227218000
r15: 0000000000000000 ip: ffffffffa052ba20 flags: 00010282 cs: 00000010
ss: 00000018 ds: 00000018 es: 00000018 fs: 00000018 gs: 00000018

(gdb) disassemble 0xffffffff8108f09b
Dump of assembler code for function process_one_work:
...
0xffffffff8108f08e <+366>: jmpq 0xffffffff8108f093 <process_one_work+371>
0xffffffff8108f093 <+371>: mov %rbx,%rdi
0xffffffff8108f096 <+374>: callq *0x18(%r12) <--
0xffffffff8108f09b <+379>: jmpq 0xffffffff8108f0a0 <process_one_work+384>
0xffffffff8108f0a0 <+384>: mov %gs:0xc7b8,%rax
0xffffffff8108f0a9 <+393>: mov -0x3fbc(%rax),%edx
0xffffffff8108f0af <+399>: test $0xefffffff,%edx
...

[0]kdb> md ffff8800c8e24400
0xffff8800c8e24400 0000000000000000 ffff880227214038 ........8@!'....
0xffff8800c8e24410 ffff8800a8224200 --> ffffffffa052ba20 <-- .B"..... .R.....

%r12 is struct worker, doing work from system_wq ("events").
At offset 0x18 is worker->current_func, which I think was delayed_work() from
net/ceph/mon_client.c even though libceph.ko by that time was already unloaded,
which explains the bad page fault.

system_wq deals primarily with schedule_work() family of functions. It looks
like our work items aren't teared down properly and it's possible to get
delayed_work() shot after module unload.

History

#1 Updated by Ilya Dryomov about 7 years ago

This turned out to have nothing to do with how we tear down delayed_works - that code is fine.
The problem was rbd messing up refcounts left and right for clones with parent_overlap 0, leaving libceph state behind. We saw a bunch of evidence (e.g. #9896 is probably related, I'll have to take a look) but never connected the dots, probably because fsx is currently the only test that exercises parent_overlap code to such an extent.

Reproducer:

# cat delayed_work.sh
#!/bin/bash
MON=1 OSD=1 ./vstart.sh -l -n mon osd
./rbd create --image-format 2 --size 1 foo
./rbd snap create foo@snap
./rbd snap protect foo@snap
./rbd clone foo@snap bar
./rbd resize --allow-shrink --size 0 bar
./rbd resize --size 1 bar
DEV=$(./rbd map bar)
./rbd unmap $DEV
sleep 3
./stop.sh
sleep 3
MON=1 OSD=1 ./vstart.sh -l -n mon osd
sleep 13
rmmod rbd && rmmod libceph
# Bad kernel will crash with a bad page fault on an address corresponding to
# mon_client.c/delayed_work() or osd_client.c/handle_osds_timeout() in the
# unloaded libceph.ko within 10-20 seconds.
sleep 20
echo OK

Fixes posted:

[PATCH 1/3] rbd: fix rbd_dev_parent_get() when parent_overlap 0
[PATCH 2/3] rbd: drop parent_ref in rbd_dev_unprobe() unconditionally

#2 Updated by Ilya Dryomov about 7 years ago

  • Status changed from In Progress to 7

#3 Updated by Ilya Dryomov almost 7 years ago

  • Status changed from 7 to Resolved

In 3.19-rc7.

Also available in: Atom PDF