Bug #4974
nightlies: failed assert at Monitor::StoreConverter::_convert_machines
0%
Description
this seems to happen after upgrading from bobtail to next branch, when the daemons are restarted. all the monitors seems to crash.
logs: ubuntu@teuthology:/a/teuthology-2013-05-09_01:30:04-upgrade-master-testing-basic/9561
2013-05-09T01:39:02.816 INFO:teuthology.misc.health.err:2013-05-09 01:39:18.541333 7f8ee9310700 0 -- :/9994 >> 10.214.132.26:6790/0 pipe(0x7f8ed4000c00 sd=8 :0 s=1 pgs=0 cs=0 l=1).fault 2013-05-09T01:39:04.938 INFO:teuthology.task.ceph.mon.a.err:mon/Monitor.cc: In function 'void Monitor::StoreConverter::_convert_machines(std::string)' thread 7fe9998af780 time 2013-05-09 01:39:20.662331 2013-05-09T01:39:04.938 INFO:teuthology.task.ceph.mon.a.err:mon/Monitor.cc: 4413: FAILED assert(0 == "Duplicate GV -- something is wrong!") 2013-05-09T01:39:04.938 INFO:teuthology.task.ceph.mon.a.err: ceph version 0.61-120-g6c1e479 (6c1e4791782ce2b3e101ee80640d896bcda684de) 2013-05-09T01:39:04.938 INFO:teuthology.task.ceph.mon.a.err: 1: (Monitor::StoreConverter::_convert_machines(std::string)+0x1021) [0x4ad6f1] 2013-05-09T01:39:04.938 INFO:teuthology.task.ceph.mon.a.err: 2: (Monitor::StoreConverter::_convert_machines()+0xf1) [0x4ae6e1] 2013-05-09T01:39:04.939 INFO:teuthology.task.ceph.mon.a.err: 3: (Monitor::StoreConverter::convert()+0x185) [0x4ae9a5] 2013-05-09T01:39:04.939 INFO:teuthology.task.ceph.mon.a.err: 4: (main()+0x416) [0x48c3a6] 2013-05-09T01:39:04.939 INFO:teuthology.task.ceph.mon.a.err: 5: (__libc_start_main()+0xed) [0x7fe99796976d] 2013-05-09T01:39:04.939 INFO:teuthology.task.ceph.mon.a.err: 6: ceph-mon() [0x48fddd] 2013-05-09T01:39:04.939 INFO:teuthology.task.ceph.mon.a.err: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. 2013-05-09T01:39:04.939 INFO:teuthology.task.ceph.mon.a.err:2013-05-09 01:39:20.663233 7fe9998af780 -1 mon/Monitor.cc: In function 'void Monitor::StoreConverter::_convert_machines(std::string)' thread 7fe9998af780 time 2013-05-09 01:39:20.662331 2013-05-09T01:39:04.940 INFO:teuthology.task.ceph.mon.a.err:mon/Monitor.cc: 4413: FAILED assert(0 == "Duplicate GV -- something is wrong!") 2013-05-09T01:39:04.940 INFO:teuthology.task.ceph.mon.a.err: 2013-05-09T01:39:04.940 INFO:teuthology.task.ceph.mon.a.err: ceph version 0.61-120-g6c1e479 (6c1e4791782ce2b3e101ee80640d896bcda684de) 2013-05-09T01:39:04.940 INFO:teuthology.task.ceph.mon.a.err: 1: (Monitor::StoreConverter::_convert_machines(std::string)+0x1021) [0x4ad6f1] 2013-05-09T01:39:04.940 INFO:teuthology.task.ceph.mon.a.err: 2: (Monitor::StoreConverter::_convert_machines()+0xf1) [0x4ae6e1] 2013-05-09T01:39:04.940 INFO:teuthology.task.ceph.mon.a.err: 3: (Monitor::StoreConverter::convert()+0x185) [0x4ae9a5] 2013-05-09T01:39:04.941 INFO:teuthology.task.ceph.mon.a.err: 4: (main()+0x416) [0x48c3a6] 2013-05-09T01:39:04.941 INFO:teuthology.task.ceph.mon.a.err: 5: (__libc_start_main()+0xed) [0x7fe99796976d] 2013-05-09T01:39:04.941 INFO:teuthology.task.ceph.mon.a.err: 6: ceph-mon() [0x48fddd] 2013-05-09T01:39:04.941 INFO:teuthology.task.ceph.mon.a.err: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. 2013-05-09T01:39:04.941 INFO:teuthology.task.ceph.mon.a.err: 2013-05-09T01:39:04.949 INFO:teuthology.task.ceph.mon.a.err: 0> 2013-05-09 01:39:20.663233 7fe9998af780 -1 mon/Monitor.cc: In function 'void Monitor::StoreConverter::_convert_machines(std::string)' thread 7fe9998af780 time 2013-05-09 01:39:20.662331 2013-05-09T01:39:04.949 INFO:teuthology.task.ceph.mon.a.err:mon/Monitor.cc: 4413: FAILED assert(0 == "Duplicate GV -- something is wrong!") 2013-05-09T01:39:04.950 INFO:teuthology.task.ceph.mon.a.err: 2013-05-09T01:39:04.950 INFO:teuthology.task.ceph.mon.a.err: ceph version 0.61-120-g6c1e479 (6c1e4791782ce2b3e101ee80640d896bcda684de) 2013-05-09T01:39:04.950 INFO:teuthology.task.ceph.mon.a.err: 1: (Monitor::StoreConverter::_convert_machines(std::string)+0x1021) [0x4ad6f1] 2013-05-09T01:39:04.950 INFO:teuthology.task.ceph.mon.a.err: 2: (Monitor::StoreConverter::_convert_machines()+0xf1) [0x4ae6e1] 2013-05-09T01:39:04.950 INFO:teuthology.task.ceph.mon.a.err: 3: (Monitor::StoreConverter::convert()+0x185) [0x4ae9a5] 2013-05-09T01:39:04.950 INFO:teuthology.task.ceph.mon.a.err: 4: (main()+0x416) [0x48c3a6] 2013-05-09T01:39:04.951 INFO:teuthology.task.ceph.mon.a.err: 5: (__libc_start_main()+0xed) [0x7fe99796976d] 2013-05-09T01:39:04.951 INFO:teuthology.task.ceph.mon.a.err: 6: ceph-mon() [0x48fddd] 2013-05-09T01:39:04.951 INFO:teuthology.task.ceph.mon.a.err: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. ubuntu@teuthology:/a/teuthology-2013-05-09_01:30:04-upgrade-master-testing-basic/9561$ cat orig.config.yaml kernel: kdb: true sha1: b5b09be30cf99f9c699e825629f02e3bce555d44 machine_type: plana nuke-on-error: true overrides: ceph: conf: mon: debug mon: 20 debug ms: 20 debug paxos: 20 log-whitelist: - slow request sha1: 5177fcb6bf384d5c9caed9b28f28f656823b3d64 s3tests: branch: master workunit: sha1: 5177fcb6bf384d5c9caed9b28f28f656823b3d64 roles: - - mon.a - mds.a - osd.0 - osd.1 - - mon.b - mon.c - osd.2 - osd.3 - - client.0 tasks: - chef: null - clock.check: null - install: branch: bobtail - ceph: null - workunit: branch: bobtail clients: client.0: - rbd/import_export.sh env: RBD_CREATE_ARGS: --new-format - install.upgrade: all: branch: next - ceph.restart: - osd.0 - osd.1 - osd.2 - osd.3 - mon.a - mon.b - mon.c - mds.a - workunit: clients: client.0: - rbd/import_export.sh env: RBD_CREATE_ARGS: --new-format
Associated revisions
mon: Monitor: tolerate GV duplicates during conversion
Fixes: #4974
Signed-off-by: Joao Eduardo Luis <joao.luis@inktank.com>
mon: Monitor: tolerate GV duplicates during conversion
Fixes: #4974
Signed-off-by: Joao Eduardo Luis <joao.luis@inktank.com>
(cherry picked from commit ba05b16ee2b6e25141f2ab88265a1cf92dcd493c)
History
#1 Updated by Tamilarasi muthamizhan almost 11 years ago
also,
logs: ubuntu@teuthology:/a/teuthology-2013-05-09_01:30:04-upgrade-master-testing-basic/9574
ubuntu@teuthology:/a/teuthology-2013-05-09_01:30:04-upgrade-master-testing-basic/9574$ cat orig.config.yaml
kernel:
kdb: true
sha1: b5b09be30cf99f9c699e825629f02e3bce555d44
machine_type: plana
nuke-on-error: true
overrides:
ceph:
conf:
mon:
debug mon: 20
debug ms: 20
debug paxos: 20
log-whitelist:
- slow request
sha1: 5177fcb6bf384d5c9caed9b28f28f656823b3d64
s3tests:
branch: master
workunit:
sha1: 5177fcb6bf384d5c9caed9b28f28f656823b3d64
roles:
- - mon.a
- mds.a
- osd.0
- osd.1
- - mon.b
- mon.c
- osd.2
- osd.3
- client.1
- - client.0
tasks:
- chef: null
- clock.check: null
- install:
branch: bobtail
- ceph:
conf:
client:
client mount timeout: 600
rgw init timeout: 600
- rgw:
- client.0
- s3tests:
client.0:
force-branch: bobtail
rgw_server: client.0
- install.upgrade:
all:
branch: next
- ceph.restart:
- osd.0
- osd.1
- osd.2
- osd.3
- mon.a
- mon.b
- mon.c
- mds.a
- rgw.client.0
- swift:
client.0:
rgw_server: client.0
#2 Updated by Tamilarasi muthamizhan almost 11 years ago
- Priority changed from Normal to Urgent
#3 Updated by Matthew Via almost 11 years ago
Hi, I also encountered this error after updating from bobtail to cuttlefish .61.1 .
I started by restarting all the monitors at the same time, and the monitor would not start. Attempting to relocate the store.db/ directory results in the following (similar looking) monitor log:
https://pastee.org/rxy9q
#4 Updated by Joao Eduardo Luis almost 11 years ago
We lost the logs for these runs after being nuked. I left a teuthology job running overnight to reproduce it, but for some reason it was interrupted and borked out (maybe some connectivity error of sorts, no idea).
I'm trying again to reproduce it.
Matthew, do you happen to have logs for this? Or maybe a store you can provide us?
#5 Updated by Joao Eduardo Luis almost 11 years ago
Matthew provided a store for me to play with.
Doing some analysis, it looks like the issue is confined to the mdsmap, and it appears to be some gv collision instead of a conversion bug. Details follow.
After obtaining all GVs on the store (gv.dump.raw) as well as removing any duplicates (gv.dump.uniq), we found 5 collisions: $ diff ../gv.dump.raw ../gv.dump.uniq 4948d4947 < 87314 5862d5860 < 152449 6876d6873 < 206011 9509d9505 < 768923 10883d10878 < 1081341 All these map to the mdsmap: $ grep '87314\|152449\|206011\|768923\|1081341' ../gv.dump 1081341 mdsmap:10886 1081341 mdsmap:10887 87314 mdsmap:4945 87314 mdsmap:4946 152449 mdsmap:5859 152449 mdsmap:5860 206011 mdsmap:6875 206011 mdsmap:6876 768923 mdsmap:9510 768923 mdsmap:9511 And we also noticed that those that should have been the next GV for each version do not exist. Gradually increasing version numbers do not return the continuous version space I was expecting to find: $ grep '87315\|152450\|206012\|768924\|1081342' ../gv.dump [returns nothing] $ grep '87316\|152451\|206013\|768925\|1081343' ../gv.dump 1081343 mdsmap:10888 $ grep '87317\|152452\|206014\|768926\|1081344' ../gv.dump 87317 mdsmap:4947 768926 mdsmap:9512 $ grep '87318\|152453\|206015\|768927\|1081345' ../gv.dump [returns nothing] $ grep '87319\|152454\|206016\|768928\|1081346' ../gv.dump 152454 mdsmap:5861 206016 mdsmap:6877
Now focusing in finding whatever is wrong with the mdsmap gv stashing
#6 Updated by Joao Eduardo Luis almost 11 years ago
- Status changed from New to In Progress
Forgot to update status
#7 Updated by Sage Weil almost 11 years ago
we hit it again! leaving the machines locked and task hung.
ubuntu@teuthology:/a/teuthology-2013-05-11_01:30:03-upgrade-master-testing-basic/11354$ grep role teuthology.log
2013-05-11T02:08:25.530 INFO:teuthology.task.internal:roles: ubuntu@plana58.front.sepia.ceph.com - ['mon.a', 'mds.a', 'osd.0', 'osd.1']
2013-05-11T02:08:25.530 INFO:teuthology.task.internal:roles: ubuntu@plana59.front.sepia.ceph.com - ['mon.b', 'mon.c', 'osd.2', 'osd.3']
2013-05-11T02:08:25.530 INFO:teuthology.task.internal:roles: ubuntu@plana83.front.sepia.ceph.com - ['client.0']
2013-05-11T02:10:50.032 INFO:teuthology.task.ceph:ctx.disk_config.remote_to_roles_to_dev: {Remote(name=u'ubuntu@plana58.front.sepia.ceph.com'): {}, Remote(name=u'ubuntu@plana59.front.sepia.ceph.com'): {}}
2013-05-11T02:11:34.572 DEBUG:teuthology.task.workunit:getting remote for 0 role client.0
#8 Updated by Sage Weil almost 11 years ago
- Priority changed from Urgent to Immediate
#9 Updated by Joao Eduardo Luis almost 11 years ago
plana's status is now gone, no logs on teuthology, but I'll update the ticket next with a description on what's happening and plan of attack.
"locked_since": "2013-05-13T03:00:20", "description": "/var/lib/teuthworker/archive/teuthology-2013-05-13_01:00:36-fs-master-testing-basic/12418", "locked_by": "scheduled_teuthology@teuthology", "name": "ubuntu@plana58.front.sepia.ceph.com"
#10 Updated by Joao Eduardo Luis almost 11 years ago
Cause:
We had a bug on bobtail that would create duplicate GV versions, so there's a fair chance that at some point, some clusters might have hit it and created those duplicate versions.
After upgrading to a bug free version, the incorrect state went away for all the machines except the mdsmap -- basically because mdsmaps are not trimmed, while all others are. This is why all the reports so far have been caused by duplicates on the mdsmap monitor.
Solution:
As we cannot disregard those versions, the simplest approach is to merge the duplicates in one single Paxos version during conversion. The nature of the global version guarantees that these versions always come before whatever their next versions are. So, if we have a given GV = A for any two versions B and C, we can guarantee that either B > C or C > B, and that both B and C are greater than any version D with a gv A' < A, and that both B and C are smaller than any version D' with a gv A'' > A.
This guarantees the correct ordering of operations with respect to Paxos versions.
#11 Updated by Joao Eduardo Luis almost 11 years ago
Pushed wip-4974 to gh. It fixes Via's store, but haven't dumped the transactions yet to make sure the correct ordering is being maintained -- although, logic-wise, it should (but would love to make sure before merging this).
#12 Updated by Joao Eduardo Luis almost 11 years ago
- Status changed from In Progress to Fix Under Review
#13 Updated by Greg Farnum almost 11 years ago
- Status changed from Fix Under Review to In Progress
Comments on github.
#14 Updated by Sage Weil almost 11 years ago
- Status changed from In Progress to Resolved