Project

General

Profile

Actions

Bug #39031

closed

'rbd mirror status --verbose' will occasionally seg fault

Added by Jason Dillaman about 5 years ago. Updated over 4 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Jason Dillaman
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
luminous,mimic,nautilus
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

https://bugs.launchpad.net/ubuntu/+source/ceph/+bug/1820976

2019-03-20 08:55:20 DEBUG juju-log Running _assess_status()
2019-03-20 08:55:23 DEBUG update-status *** Caught signal (Segmentation fault) **
2019-03-20 08:55:23 DEBUG update-status  in thread 7f0f0b7fe700 thread_name:tp_librbd
2019-03-20 08:55:23 DEBUG update-status  ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
2019-03-20 08:55:23 DEBUG update-status  1: (()+0x1d00e0) [0x5568590090e0]
2019-03-20 08:55:23 DEBUG update-status  2: (()+0x12890) [0x7f0f26c3c890]
2019-03-20 08:55:23 DEBUG update-status  3: (librados::IoCtxImpl::flush_aio_writes()+0x17) [0x7f0f2fd454c7]
2019-03-20 08:55:23 DEBUG update-status  4: (librados::IoCtx::aio_flush()+0xc) [0x7f0f2fd1d96c]
2019-03-20 08:55:23 DEBUG update-status  5: (()+0x64ad8) [0x7f0f3005fad8]
2019-03-20 08:55:23 DEBUG update-status  6: (()+0x5c298) [0x7f0f30057298]
2019-03-20 08:55:23 DEBUG update-status  7: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  8: (()+0x7203d) [0x7f0f3006d03d]
2019-03-20 08:55:23 DEBUG update-status  9: (()+0x72539) [0x7f0f3006d539]
2019-03-20 08:55:23 DEBUG update-status  10: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  11: (()+0xff9b9) [0x7f0f300fa9b9]
2019-03-20 08:55:23 DEBUG update-status  12: (()+0xffee8) [0x7f0f300faee8]
2019-03-20 08:55:23 DEBUG update-status  13: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  14: (ThreadPool::worker(ThreadPool::WorkThread*)+0x8f7) [0x7f0f27309177]
2019-03-20 08:55:23 DEBUG update-status  15: (ThreadPool::WorkThread::entry()+0x10) [0x7f0f2730a0a0]
2019-03-20 08:55:23 DEBUG update-status  16: (()+0x76db) [0x7f0f26c316db]
2019-03-20 08:55:23 DEBUG update-status  17: (clone()+0x3f) [0x7f0f257ed88f]
2019-03-20 08:55:23 DEBUG update-status 2019-03-20 08:55:23.528 7f0f0b7fe700 -1 *** Caught signal (Segmentation fault) **
2019-03-20 08:55:23 DEBUG update-status  in thread 7f0f0b7fe700 thread_name:tp_librbd
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status  ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
2019-03-20 08:55:23 DEBUG update-status  1: (()+0x1d00e0) [0x5568590090e0]
2019-03-20 08:55:23 DEBUG update-status  2: (()+0x12890) [0x7f0f26c3c890]
2019-03-20 08:55:23 DEBUG update-status  3: (librados::IoCtxImpl::flush_aio_writes()+0x17) [0x7f0f2fd454c7]
2019-03-20 08:55:23 DEBUG update-status  4: (librados::IoCtx::aio_flush()+0xc) [0x7f0f2fd1d96c]
2019-03-20 08:55:23 DEBUG update-status  5: (()+0x64ad8) [0x7f0f3005fad8]
2019-03-20 08:55:23 DEBUG update-status  6: (()+0x5c298) [0x7f0f30057298]
2019-03-20 08:55:23 DEBUG update-status  7: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  8: (()+0x7203d) [0x7f0f3006d03d]
2019-03-20 08:55:23 DEBUG update-status  9: (()+0x72539) [0x7f0f3006d539]
2019-03-20 08:55:23 DEBUG update-status  10: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  11: (()+0xff9b9) [0x7f0f300fa9b9]
2019-03-20 08:55:23 DEBUG update-status  12: (()+0xffee8) [0x7f0f300faee8]
2019-03-20 08:55:23 DEBUG update-status  13: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  14: (ThreadPool::worker(ThreadPool::WorkThread*)+0x8f7) [0x7f0f27309177]
2019-03-20 08:55:23 DEBUG update-status  15: (ThreadPool::WorkThread::entry()+0x10) [0x7f0f2730a0a0]
2019-03-20 08:55:23 DEBUG update-status  16: (()+0x76db) [0x7f0f26c316db]
2019-03-20 08:55:23 DEBUG update-status  17: (clone()+0x3f) [0x7f0f257ed88f]
2019-03-20 08:55:23 DEBUG update-status  NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status --- begin dump of recent events ---
2019-03-20 08:55:23 DEBUG update-status   -110> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perfcounters_dump hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -109> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command 1 hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -108> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perf dump hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -107> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perfcounters_schema hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -106> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perf histogram dump hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -105> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command 2 hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -104> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perf schema hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -103> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perf histogram schema hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -102> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command perf reset hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -101> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config show hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status   -100> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config help hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -99> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config set hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -98> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config unset hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -97> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config get hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -96> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config diff hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -95> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command config diff get hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -94> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command log flush hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -93> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command log dump hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -92> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command log reopen hook 0x55685a4a2380
2019-03-20 08:55:23 DEBUG update-status    -91> 2019-03-20 08:55:23.180 7f0f3076ac00  5 asok(0x55685a46a920) register_command dump_mempools hook 0x55685a4d4728
2019-03-20 08:55:23 DEBUG update-status    -90> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient: get_monmap_and_config
2019-03-20 08:55:23 DEBUG update-status    -89> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient: build_initial_monmap
2019-03-20 08:55:23 DEBUG update-status    -88> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient: init
2019-03-20 08:55:23 DEBUG update-status    -87> 2019-03-20 08:55:23.192 7f0f3076ac00  5 adding auth protocol: cephx
2019-03-20 08:55:23 DEBUG update-status    -86> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient: auth_supported 2 method cephx
2019-03-20 08:55:23 DEBUG update-status    -85> 2019-03-20 08:55:23.192 7f0f3076ac00  2 auth: KeyRing::load: loaded key file /etc/ceph/ceph.client.rbd-mirror.juju-d7c3c2-12.keyring
2019-03-20 08:55:23 DEBUG update-status    -84> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient: _reopen_session rank -1
2019-03-20 08:55:23 DEBUG update-status    -83> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient(hunting): picked mon.noname-b con 0x55685a5a9b70 addr 10.219.3.155:6789/0
2019-03-20 08:55:23 DEBUG update-status    -82> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient(hunting): picked mon.noname-c con 0x55685a5ac580 addr 10.219.3.29:6789/0
2019-03-20 08:55:23 DEBUG update-status    -81> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient(hunting): _renew_subs
2019-03-20 08:55:23 DEBUG update-status    -80> 2019-03-20 08:55:23.192 7f0f3076ac00 10 monclient(hunting): authenticate will time out at 2019-03-20 09:00:23.198157
2019-03-20 08:55:23 DEBUG update-status    -79> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
2019-03-20 08:55:23 DEBUG update-status    -78> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting):  got monmap 2, mon.noname-b is now rank -1
2019-03-20 08:55:23 DEBUG update-status    -77> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting): dump:
2019-03-20 08:55:23 DEBUG update-status epoch 2
2019-03-20 08:55:23 DEBUG update-status fsid 9daa41ba-4aea-11e9-8d2e-00163ef81865
2019-03-20 08:55:23 DEBUG update-status last_changed 2019-03-20 08:33:26.053956
2019-03-20 08:55:23 DEBUG update-status created 2019-03-20 08:32:55.946824
2019-03-20 08:55:23 DEBUG update-status 0: 10.219.3.29:6789/0 mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status 1: 10.219.3.137:6789/0 mon.juju-d7c3c2-0
2019-03-20 08:55:23 DEBUG update-status 2: 10.219.3.155:6789/0 mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status    -76> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
2019-03-20 08:55:23 DEBUG update-status    -75> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting):  got monmap 2, mon.juju-d7c3c2-1 is now rank 0
2019-03-20 08:55:23 DEBUG update-status    -74> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting): dump:
2019-03-20 08:55:23 DEBUG update-status epoch 2
2019-03-20 08:55:23 DEBUG update-status fsid 9daa41ba-4aea-11e9-8d2e-00163ef81865
2019-03-20 08:55:23 DEBUG update-status last_changed 2019-03-20 08:33:26.053956
2019-03-20 08:55:23 DEBUG update-status created 2019-03-20 08:32:55.946824
2019-03-20 08:55:23 DEBUG update-status 0: 10.219.3.29:6789/0 mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status 1: 10.219.3.137:6789/0 mon.juju-d7c3c2-0
2019-03-20 08:55:23 DEBUG update-status 2: 10.219.3.155:6789/0 mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status    -73> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting): my global_id is 17885
2019-03-20 08:55:23 DEBUG update-status    -72> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient(hunting): my global_id is 7854
2019-03-20 08:55:23 DEBUG update-status    -71> 2019-03-20 08:55:23.196 7f0f13fff700  1 monclient: found mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status    -70> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient: _send_mon_message to mon.juju-d7c3c2-1 at 10.219.3.29:6789/0
2019-03-20 08:55:23 DEBUG update-status    -69> 2019-03-20 08:55:23.196 7f0f3076ac00  5 monclient: authenticate success, global_id 7854
2019-03-20 08:55:23 DEBUG update-status    -68> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient: handle_config config(0 keys) v1
2019-03-20 08:55:23 DEBUG update-status    -67> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient: handle_monmap mon_map magic: 0 v1
2019-03-20 08:55:23 DEBUG update-status    -66> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient:  got monmap 2, mon.juju-d7c3c2-1 is now rank 0
2019-03-20 08:55:23 DEBUG update-status    -65> 2019-03-20 08:55:23.196 7f0f13fff700 10 monclient: dump:
2019-03-20 08:55:23 DEBUG update-status epoch 2
2019-03-20 08:55:23 DEBUG update-status fsid 9daa41ba-4aea-11e9-8d2e-00163ef81865
2019-03-20 08:55:23 DEBUG update-status last_changed 2019-03-20 08:33:26.053956
2019-03-20 08:55:23 DEBUG update-status created 2019-03-20 08:32:55.946824
2019-03-20 08:55:23 DEBUG update-status 0: 10.219.3.29:6789/0 mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status 1: 10.219.3.137:6789/0 mon.juju-d7c3c2-0
2019-03-20 08:55:23 DEBUG update-status 2: 10.219.3.155:6789/0 mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status    -64> 2019-03-20 08:55:23.196 7f0f127fc700  4 set_mon_vals no callback set
2019-03-20 08:55:23 DEBUG update-status    -63> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: get_monmap_and_config success
2019-03-20 08:55:23 DEBUG update-status    -62> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: shutdown
2019-03-20 08:55:23 DEBUG update-status    -61> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: build_initial_monmap
2019-03-20 08:55:23 DEBUG update-status    -60> 2019-03-20 08:55:23.196 7f0f3076ac00  1 librados: starting msgr at -
2019-03-20 08:55:23 DEBUG update-status    -59> 2019-03-20 08:55:23.196 7f0f3076ac00  1 librados: starting objecter
2019-03-20 08:55:23 DEBUG update-status    -58> 2019-03-20 08:55:23.196 7f0f3076ac00  5 asok(0x55685a46a920) register_command objecter_requests hook 0x55685a5a6bf0
2019-03-20 08:55:23 DEBUG update-status    -57> 2019-03-20 08:55:23.196 7f0f3076ac00  1 librados: setting wanted keys
2019-03-20 08:55:23 DEBUG update-status    -56> 2019-03-20 08:55:23.196 7f0f3076ac00  1 librados: calling monclient init
2019-03-20 08:55:23 DEBUG update-status    -55> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: init
2019-03-20 08:55:23 DEBUG update-status    -54> 2019-03-20 08:55:23.196 7f0f3076ac00  5 adding auth protocol: cephx
2019-03-20 08:55:23 DEBUG update-status    -53> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: auth_supported 2 method cephx
2019-03-20 08:55:23 DEBUG update-status    -52> 2019-03-20 08:55:23.196 7f0f3076ac00  2 auth: KeyRing::load: loaded key file /etc/ceph/ceph.client.rbd-mirror.juju-d7c3c2-12.keyring
2019-03-20 08:55:23 DEBUG update-status    -51> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: _reopen_session rank -1
2019-03-20 08:55:23 DEBUG update-status    -50> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient(hunting): picked mon.noname-a con 0x55685a5af4c0 addr 10.219.3.137:6789/0
2019-03-20 08:55:23 DEBUG update-status    -49> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient(hunting): picked mon.noname-b con 0x55685a5adf00 addr 10.219.3.155:6789/0
2019-03-20 08:55:23 DEBUG update-status    -48> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient(hunting): _renew_subs
2019-03-20 08:55:23 DEBUG update-status    -47> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient(hunting): authenticate will time out at 2019-03-20 09:00:23.201007
2019-03-20 08:55:23 DEBUG update-status    -46> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
2019-03-20 08:55:23 DEBUG update-status    -45> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting):  got monmap 2, mon.noname-a is now rank -1
2019-03-20 08:55:23 DEBUG update-status    -44> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting): dump:
2019-03-20 08:55:23 DEBUG update-status epoch 2
2019-03-20 08:55:23 DEBUG update-status fsid 9daa41ba-4aea-11e9-8d2e-00163ef81865
2019-03-20 08:55:23 DEBUG update-status last_changed 2019-03-20 08:33:26.053956
2019-03-20 08:55:23 DEBUG update-status created 2019-03-20 08:32:55.946824
2019-03-20 08:55:23 DEBUG update-status 0: 10.219.3.29:6789/0 mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status 1: 10.219.3.137:6789/0 mon.juju-d7c3c2-0
2019-03-20 08:55:23 DEBUG update-status 2: 10.219.3.155:6789/0 mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status    -43> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting): my global_id is 7882
2019-03-20 08:55:23 DEBUG update-status    -42> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
2019-03-20 08:55:23 DEBUG update-status    -41> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting):  got monmap 2, mon.juju-d7c3c2-2 is now rank 2
2019-03-20 08:55:23 DEBUG update-status    -40> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting): dump:
2019-03-20 08:55:23 DEBUG update-status epoch 2
2019-03-20 08:55:23 DEBUG update-status fsid 9daa41ba-4aea-11e9-8d2e-00163ef81865
2019-03-20 08:55:23 DEBUG update-status last_changed 2019-03-20 08:33:26.053956
2019-03-20 08:55:23 DEBUG update-status created 2019-03-20 08:32:55.946824
2019-03-20 08:55:23 DEBUG update-status 0: 10.219.3.29:6789/0 mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status 1: 10.219.3.137:6789/0 mon.juju-d7c3c2-0
2019-03-20 08:55:23 DEBUG update-status 2: 10.219.3.155:6789/0 mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status    -39> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient(hunting): my global_id is 17888
2019-03-20 08:55:23 DEBUG update-status    -38> 2019-03-20 08:55:23.196 7f0f137fe700  1 monclient: found mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status    -37> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient: _send_mon_message to mon.juju-d7c3c2-2 at 10.219.3.155:6789/0
2019-03-20 08:55:23 DEBUG update-status    -36> 2019-03-20 08:55:23.196 7f0f3076ac00  5 monclient: authenticate success, global_id 17888
2019-03-20 08:55:23 DEBUG update-status    -35> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: _renew_subs
2019-03-20 08:55:23 DEBUG update-status    -34> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: _send_mon_message to mon.juju-d7c3c2-2 at 10.219.3.155:6789/0
2019-03-20 08:55:23 DEBUG update-status    -33> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient: handle_config config(0 keys) v1
2019-03-20 08:55:23 DEBUG update-status    -32> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient: handle_monmap mon_map magic: 0 v1
2019-03-20 08:55:23 DEBUG update-status    -31> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient:  got monmap 2, mon.juju-d7c3c2-2 is now rank 2
2019-03-20 08:55:23 DEBUG update-status    -30> 2019-03-20 08:55:23.196 7f0f137fe700 10 monclient: dump:
2019-03-20 08:55:23 DEBUG update-status epoch 2
2019-03-20 08:55:23 DEBUG update-status fsid 9daa41ba-4aea-11e9-8d2e-00163ef81865
2019-03-20 08:55:23 DEBUG update-status last_changed 2019-03-20 08:33:26.053956
2019-03-20 08:55:23 DEBUG update-status created 2019-03-20 08:32:55.946824
2019-03-20 08:55:23 DEBUG update-status 0: 10.219.3.29:6789/0 mon.juju-d7c3c2-1
2019-03-20 08:55:23 DEBUG update-status 1: 10.219.3.137:6789/0 mon.juju-d7c3c2-0
2019-03-20 08:55:23 DEBUG update-status 2: 10.219.3.155:6789/0 mon.juju-d7c3c2-2
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status    -29> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: _renew_subs
2019-03-20 08:55:23 DEBUG update-status    -28> 2019-03-20 08:55:23.196 7f0f3076ac00 10 monclient: _send_mon_message to mon.juju-d7c3c2-2 at 10.219.3.155:6789/0
2019-03-20 08:55:23 DEBUG update-status    -27> 2019-03-20 08:55:23.196 7f0f11ffb700  4 set_mon_vals no callback set
2019-03-20 08:55:23 DEBUG update-status    -26> 2019-03-20 08:55:23.196 7f0f3076ac00  1 librados: init done
2019-03-20 08:55:23 DEBUG update-status    -25> 2019-03-20 08:55:23.196 7f0f137fe700  4 mgrc handle_mgr_map Got map version 5
2019-03-20 08:55:23 DEBUG update-status    -24> 2019-03-20 08:55:23.196 7f0f137fe700  4 mgrc handle_mgr_map Active mgr is now 10.219.3.29:6800/13921
2019-03-20 08:55:23 DEBUG update-status    -23> 2019-03-20 08:55:23.196 7f0f137fe700  4 mgrc reconnect Starting new session with 10.219.3.29:6800/13921
2019-03-20 08:55:23 DEBUG update-status    -22> 2019-03-20 08:55:23.200 7f0f3076ac00  5 librbd::io::ImageRequestWQ: 0x55685a42dc70 ImageRequestWQ: ictx=0x55685a5c2010
2019-03-20 08:55:23 DEBUG update-status    -21> 2019-03-20 08:55:23.204 7f0f0bfff700  5 asok(0x55685a46a920) register_command rbd cache flush cinder-ceph/volume-7f4f826a-5441-425d-ac46-72902f89b42a hook 0x7f0f000070a0
2019-03-20 08:55:23 DEBUG update-status    -20> 2019-03-20 08:55:23.204 7f0f0bfff700  5 asok(0x55685a46a920) register_command rbd cache invalidate cinder-ceph/volume-7f4f826a-5441-425d-ac46-72902f89b42a hook 0x7f0f000070a0
2019-03-20 08:55:23 DEBUG update-status    -19> 2019-03-20 08:55:23.232 7f0f0bfff700  5 librbd::io::ImageRequestWQ: 0x55685a42dc70 block_writes: 0x55685a5c2010, num=1
2019-03-20 08:55:23 DEBUG update-status    -18> 2019-03-20 08:55:23.232 7f0f0b7fe700  5 librbd::cache::ObjectCacherObjectDispatch: 0x7f0f00006030 init: 
2019-03-20 08:55:23 DEBUG update-status    -17> 2019-03-20 08:55:23.232 7f0f0b7fe700  5 librbd::cache::ObjectCacherObjectDispatch: 0x7f0f00006030 init: enabling caching...
2019-03-20 08:55:23 DEBUG update-status    -16> 2019-03-20 08:55:23.232 7f0f0b7fe700  5 librbd::cache::ObjectCacherObjectDispatch: 0x7f0f00006030 init: Initial cache settings: size=33554432 num_objects=10 max_dirty=25165824 target_dirty=16777216 max_dirty_age=1
2019-03-20 08:55:23 DEBUG update-status    -15> 2019-03-20 08:55:23.232 7f0f0b7fe700  5 librbd::cache::ObjectCacherObjectDispatch: 0x7f0f00006030 init:  cache bytes 33554432 -> about 855 objects
2019-03-20 08:55:23 DEBUG update-status    -14> 2019-03-20 08:55:23.232 7f0f0b7fe700  5 librbd::io::ObjectDispatcher: 0x55685a456ca0 register_object_dispatch: object_dispatch_layer=1
2019-03-20 08:55:23 DEBUG update-status    -13> 2019-03-20 08:55:23.356 7f0efffff700  1 Journaler::thread_pool worker finish
2019-03-20 08:55:23 DEBUG update-status    -12> 2019-03-20 08:55:23.356 7f0f0bfff700  5 librbd::Watcher: 0x7f0f00004340 block_notifies: blocked_count=1
2019-03-20 08:55:23 DEBUG update-status    -11> 2019-03-20 08:55:23.356 7f0f0b7fe700  5 librbd::io::ImageRequestWQ: 0x55685a42dc70 shut_down: shut_down: in_flight=0
2019-03-20 08:55:23 DEBUG update-status    -10> 2019-03-20 08:55:23.356 7f0f0b7fe700  5 librbd::io::ImageRequestWQ: 0x55685a42dc70 unblock_writes: 0x55685a5c2010, num=0
2019-03-20 08:55:23 DEBUG update-status     -9> 2019-03-20 08:55:23.520 7f0f0b7fe700  5 librbd::io::ObjectDispatcher: 0x55685a456ca0 shut_down: 
2019-03-20 08:55:23 DEBUG update-status     -8> 2019-03-20 08:55:23.520 7f0f0b7fe700  5 librbd::io::ObjectDispatch: 0x55685a5b9850 shut_down: 
2019-03-20 08:55:23 DEBUG update-status     -7> 2019-03-20 08:55:23.520 7f0f0b7fe700  5 librbd::cache::ObjectCacherObjectDispatch: 0x7f0f00006030 shut_down: 
2019-03-20 08:55:23 DEBUG update-status     -6> 2019-03-20 08:55:23.520 7f0f0b7fe700  5 asok(0x55685a46a920) unregister_command rbd cache flush cinder-ceph/volume-7f4f826a-5441-425d-ac46-72902f89b42a
2019-03-20 08:55:23 DEBUG update-status     -5> 2019-03-20 08:55:23.520 7f0f0b7fe700  5 asok(0x55685a46a920) unregister_command rbd cache invalidate cinder-ceph/volume-7f4f826a-5441-425d-ac46-72902f89b42a
2019-03-20 08:55:23 DEBUG update-status     -4> 2019-03-20 08:55:23.520 7f0f3076ac00  5 asok(0x55685a46a920) unregister_command objecter_requests
2019-03-20 08:55:23 DEBUG update-status     -3> 2019-03-20 08:55:23.520 7f0f3076ac00 10 monclient: shutdown
2019-03-20 08:55:23 DEBUG update-status     -2> 2019-03-20 08:55:23.524 7f0f3076ac00  1 librados: shutdown
2019-03-20 08:55:23 DEBUG update-status     -1> 2019-03-20 08:55:23.524 7f0f3076ac00  5 asok(0x55685a46a920) unregister_command dump_mempools
2019-03-20 08:55:23 DEBUG update-status      0> 2019-03-20 08:55:23.528 7f0f0b7fe700 -1 *** Caught signal (Segmentation fault) **
2019-03-20 08:55:23 DEBUG update-status  in thread 7f0f0b7fe700 thread_name:tp_librbd
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status  ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
2019-03-20 08:55:23 DEBUG update-status  1: (()+0x1d00e0) [0x5568590090e0]
2019-03-20 08:55:23 DEBUG update-status  2: (()+0x12890) [0x7f0f26c3c890]
2019-03-20 08:55:23 DEBUG update-status  3: (librados::IoCtxImpl::flush_aio_writes()+0x17) [0x7f0f2fd454c7]
2019-03-20 08:55:23 DEBUG update-status  4: (librados::IoCtx::aio_flush()+0xc) [0x7f0f2fd1d96c]
2019-03-20 08:55:23 DEBUG update-status  5: (()+0x64ad8) [0x7f0f3005fad8]
2019-03-20 08:55:23 DEBUG update-status  6: (()+0x5c298) [0x7f0f30057298]
2019-03-20 08:55:23 DEBUG update-status  7: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  8: (()+0x7203d) [0x7f0f3006d03d]
2019-03-20 08:55:23 DEBUG update-status  9: (()+0x72539) [0x7f0f3006d539]
2019-03-20 08:55:23 DEBUG update-status  10: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  11: (()+0xff9b9) [0x7f0f300fa9b9]
2019-03-20 08:55:23 DEBUG update-status  12: (()+0xffee8) [0x7f0f300faee8]
2019-03-20 08:55:23 DEBUG update-status  13: (()+0x5e079) [0x7f0f30059079]
2019-03-20 08:55:23 DEBUG update-status  14: (ThreadPool::worker(ThreadPool::WorkThread*)+0x8f7) [0x7f0f27309177]
2019-03-20 08:55:23 DEBUG update-status  15: (ThreadPool::WorkThread::entry()+0x10) [0x7f0f2730a0a0]
2019-03-20 08:55:23 DEBUG update-status  16: (()+0x76db) [0x7f0f26c316db]
2019-03-20 08:55:23 DEBUG update-status  17: (clone()+0x3f) [0x7f0f257ed88f]
2019-03-20 08:55:23 DEBUG update-status  NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2019-03-20 08:55:23 DEBUG update-status 
2019-03-20 08:55:23 DEBUG update-status --- logging levels ---
2019-03-20 08:55:23 DEBUG update-status    0/ 5 none
2019-03-20 08:55:23 DEBUG update-status    0/ 1 lockdep
2019-03-20 08:55:23 DEBUG update-status    0/ 1 context
2019-03-20 08:55:23 DEBUG update-status    1/ 1 crush
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mds
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mds_balancer
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mds_locker
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mds_log
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mds_log_expire
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mds_migrator
2019-03-20 08:55:23 DEBUG update-status    0/ 1 buffer
2019-03-20 08:55:23 DEBUG update-status    0/ 1 timer
2019-03-20 08:55:23 DEBUG update-status    0/ 1 filer
2019-03-20 08:55:23 DEBUG update-status    0/ 1 striper
2019-03-20 08:55:23 DEBUG update-status    0/ 1 objecter
2019-03-20 08:55:23 DEBUG update-status    0/ 5 rados
2019-03-20 08:55:23 DEBUG update-status    0/ 5 rbd
2019-03-20 08:55:23 DEBUG update-status    0/ 5 rbd_mirror
2019-03-20 08:55:23 DEBUG update-status    0/ 5 rbd_replay
2019-03-20 08:55:23 DEBUG update-status    0/ 5 journaler
2019-03-20 08:55:23 DEBUG update-status    0/ 5 objectcacher
2019-03-20 08:55:23 DEBUG update-status    0/ 5 client
2019-03-20 08:55:23 DEBUG update-status    1/ 5 osd
2019-03-20 08:55:23 DEBUG update-status    0/ 5 optracker
2019-03-20 08:55:23 DEBUG update-status    0/ 5 objclass
2019-03-20 08:55:23 DEBUG update-status    1/ 3 filestore
2019-03-20 08:55:23 DEBUG update-status    1/ 3 journal
2019-03-20 08:55:23 DEBUG update-status    0/ 0 ms
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mon
2019-03-20 08:55:23 DEBUG update-status    0/10 monc
2019-03-20 08:55:23 DEBUG update-status    1/ 5 paxos
2019-03-20 08:55:23 DEBUG update-status    0/ 5 tp
2019-03-20 08:55:23 DEBUG update-status    1/ 5 auth
2019-03-20 08:55:23 DEBUG update-status    1/ 5 crypto
2019-03-20 08:55:23 DEBUG update-status    1/ 1 finisher
2019-03-20 08:55:23 DEBUG update-status    1/ 1 reserver
2019-03-20 08:55:23 DEBUG update-status    1/ 5 heartbeatmap
2019-03-20 08:55:23 DEBUG update-status    1/ 5 perfcounter
2019-03-20 08:55:23 DEBUG update-status    1/ 5 rgw
2019-03-20 08:55:23 DEBUG update-status    1/ 5 rgw_sync
2019-03-20 08:55:23 DEBUG update-status    1/10 civetweb
2019-03-20 08:55:23 DEBUG update-status    1/ 5 javaclient
2019-03-20 08:55:23 DEBUG update-status    1/ 5 asok
2019-03-20 08:55:23 DEBUG update-status    1/ 1 throttle
2019-03-20 08:55:23 DEBUG update-status    0/ 0 refs
2019-03-20 08:55:23 DEBUG update-status    1/ 5 xio
2019-03-20 08:55:23 DEBUG update-status    1/ 5 compressor
2019-03-20 08:55:23 DEBUG update-status    1/ 5 bluestore
2019-03-20 08:55:23 DEBUG update-status    1/ 5 bluefs
2019-03-20 08:55:23 DEBUG update-status    1/ 3 bdev
2019-03-20 08:55:23 DEBUG update-status    1/ 5 kstore
2019-03-20 08:55:23 DEBUG update-status    4/ 5 rocksdb
2019-03-20 08:55:23 DEBUG update-status    4/ 5 leveldb
2019-03-20 08:55:23 DEBUG update-status    4/ 5 memdb
2019-03-20 08:55:23 DEBUG update-status    1/ 5 kinetic
2019-03-20 08:55:23 DEBUG update-status    1/ 5 fuse
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mgr
2019-03-20 08:55:23 DEBUG update-status    1/ 5 mgrc
2019-03-20 08:55:23 DEBUG update-status    1/ 5 dpdk
2019-03-20 08:55:23 DEBUG update-status    1/ 5 eventtrace
2019-03-20 08:55:23 DEBUG update-status   -2/-2 (syslog threshold)
2019-03-20 08:55:23 DEBUG update-status   99/99 (stderr threshold)
2019-03-20 08:55:23 DEBUG update-status   max_recent       500
2019-03-20 08:55:23 DEBUG update-status   max_new         1000
2019-03-20 08:55:23 DEBUG update-status   log_file 
2019-03-20 08:55:23 DEBUG update-status --- end dump of recent events ---
2019-03-20 08:55:27 DEBUG update-status Traceback (most recent call last):
2019-03-20 08:55:27 DEBUG update-status   File "/var/lib/juju/agents/unit-ceph-rbd-mirror-0/charm/hooks/update-status", line 22, in <module>
2019-03-20 08:55:27 DEBUG update-status     main()
2019-03-20 08:55:27 DEBUG update-status   File "/var/lib/juju/agents/unit-ceph-rbd-mirror-0/.venv/lib/python3.6/site-packages/charms/reactive/__init__.py", line 83, in main
2019-03-20 08:55:27 DEBUG update-status     hookenv._run_atexit()
2019-03-20 08:55:27 DEBUG update-status   File "/var/lib/juju/agents/unit-ceph-rbd-mirror-0/.venv/lib/python3.6/site-packages/charmhelpers/core/hookenv.py", line 1220, in _run_atexit
2019-03-20 08:55:27 DEBUG update-status     callback(*args, **kwargs)
2019-03-20 08:55:27 DEBUG update-status   File "/var/lib/juju/agents/unit-ceph-rbd-mirror-0/.venv/lib/python3.6/site-packages/charms_openstack/charm/core.py", line 1113, in atexit_assess_status
2019-03-20 08:55:27 DEBUG update-status     self._assess_status()
2019-03-20 08:55:27 DEBUG update-status   File "/var/lib/juju/agents/unit-ceph-rbd-mirror-0/.venv/lib/python3.6/site-packages/charms_openstack/charm/core.py", line 1095, in _assess_status
2019-03-20 08:55:27 DEBUG update-status     state, message = f()
2019-03-20 08:55:27 DEBUG update-status   File "lib/charm/openstack/ceph_rbd_mirror.py", line 69, in custom_assess_status_check
2019-03-20 08:55:27 DEBUG update-status     (pool for pool, attrs in endpoint.pools.items()
2019-03-20 08:55:27 DEBUG update-status   File "lib/charm/openstack/ceph_rbd_mirror.py", line 129, in mirror_pools_summary
2019-03-20 08:55:27 DEBUG update-status     pool_stat = self.mirror_pool_status(pool)
2019-03-20 08:55:27 DEBUG update-status   File "lib/charm/openstack/ceph_rbd_mirror.py", line 121, in mirror_pool_status
2019-03-20 08:55:27 DEBUG update-status     universal_newlines=True)
2019-03-20 08:55:27 DEBUG update-status   File "/usr/lib/python3.6/subprocess.py", line 336, in check_output
2019-03-20 08:55:27 DEBUG update-status     **kwargs).stdout
2019-03-20 08:55:27 DEBUG update-status   File "/usr/lib/python3.6/subprocess.py", line 418, in run
2019-03-20 08:55:27 DEBUG update-status     output=stdout, stderr=stderr)
2019-03-20 08:55:27 DEBUG update-status subprocess.CalledProcessError: Command '['rbd', '--id', 'rbd-mirror.juju-d7c3c2-12', 'mirror', 'pool', 'status', '--format', 'json', '--verbose', 'cinder-ceph']' died with <Signals.SIGSEGV: 11>.

Related issues 3 (0 open3 closed)

Copied to rbd - Backport #39427: luminous: 'rbd mirror status --verbose' will occasionally seg faultResolvedJason DillamanActions
Copied to rbd - Backport #39428: nautilus: 'rbd mirror status --verbose' will occasionally seg faultResolvedJason DillamanActions
Copied to rbd - Backport #39429: mimic: 'rbd mirror status --verbose' will occasionally seg faultResolvedJason DillamanActions
Actions #1

Updated by Jason Dillaman about 5 years ago

  • Status changed from New to In Progress
  • Assignee set to Jason Dillaman
Actions #2

Updated by Jason Dillaman about 5 years ago

  • Status changed from In Progress to Fix Under Review
  • Pull request ID set to 27682
Actions #3

Updated by Jason Dillaman about 5 years ago

  • Status changed from Fix Under Review to Pending Backport
Actions #4

Updated by Jason Dillaman about 5 years ago

  • Backport changed from luminous,mimic to luminous,mimic,nautilus
Actions #5

Updated by Nathan Cutler about 5 years ago

  • Copied to Backport #39427: luminous: 'rbd mirror status --verbose' will occasionally seg fault added
Actions #6

Updated by Nathan Cutler about 5 years ago

  • Copied to Backport #39428: nautilus: 'rbd mirror status --verbose' will occasionally seg fault added
Actions #7

Updated by Nathan Cutler about 5 years ago

  • Copied to Backport #39429: mimic: 'rbd mirror status --verbose' will occasionally seg fault added
Actions #8

Updated by Nathan Cutler over 4 years ago

  • Status changed from Pending Backport to Resolved

While running with --resolve-parent, the script "backport-create-issue" noticed that all backports of this issue are in status "Resolved" or "Rejected".

Actions

Also available in: Atom PDF