Actions
Bug #12652
closedosd/PGLog.cc: 732: FAILED assert(log.log.size() == log_keys_debug.size())
Status:
Resolved
Priority:
Urgent
Assignee:
-
Category:
-
Target version:
-
% Done:
0%
Source:
Q/A
Tags:
Backport:
hammer,firely
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2015-08-08 12:39:07.732502 7f27206b4700 -1 osd/PGLog.cc: In function 'void PGLog::check()' thread 7f27206b4700 time 2015-08-08 12:39:07.583714 osd/PGLog.cc: 732: FAILED assert(log.log.size() == log_keys_debug.size()) ceph version 9.0.2-1176-gc2fc74d (c2fc74d18a5e65b4a5b30d760550935a174613e8) 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x8b) [0xc3d32b] 2: (PGLog::check()+0x67d) [0x7a1bed] 3: (PGLog::write_log(ObjectStore::Transaction&, std::map<std::string, ceph::buffer::list, std::less<std::string>, std::allocator<std::pair<std::string const, ceph::buffer::list> > >*, coll_t const&, ghobject_t const&)+0x1de) [0x7a7 fde] 4: (PG::write_if_dirty(ObjectStore::Transaction&)+0x7a) [0x80975a] 5: (OSD::process_peering_events(std::list<PG*, std::allocator<PG*> > const&, ThreadPool::TPHandle&)+0x2f0) [0x6df820] 6: (OSD::PeeringWQ::_process(std::list<PG*, std::allocator<PG*> > const&, ThreadPool::TPHandle&)+0x18) [0x7343f8] 7: (ThreadPool::worker(ThreadPool::WorkThread*)+0xa56) [0xc2df16] 8: (ThreadPool::WorkThread::entry()+0x10) [0xc2efc0] 9: (()+0x8182) [0x7f273b3b8182] 10: (clone()+0x6d) [0x7f27396fcfbd] NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
/a/sage-2015-08-08_07:57:46-rados:thrash-wip-newstore-sort-distro-basic-multi/1006267
just prior,
2015-08-08 12:39:07.583516 7f27206b4700 5 write_log with: dirty_to: 956'202, dirty_from: 4294967295'18446744073709551615, dirty_divergent_priors: false, divergent_priors: 0, writeout_from: 4294967295'18446744073709551615, trimmed: 2015-08-08 12:39:07.583647 7f27206b4700 -1 log.log.size() != log_keys_debug.size() 2015-08-08 12:39:07.583649 7f27206b4700 -1 actual log: 2015-08-08 12:39:07.583650 7f27206b4700 -1 6'46 (0'0) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:976 2015-08-08 11:37:30.479123 2015-08-08 12:39:07.583658 7f27206b4700 -1 6'55 (6'46) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:977 2015-08-08 11:37:30.503925 2015-08-08 12:39:07.583662 7f27206b4700 -1 6'56 (6'55) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:978 2015-08-08 11:37:30.521613 2015-08-08 12:39:07.583666 7f27206b4700 -1 6'57 (6'56) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:979 2015-08-08 11:37:30.521663 2015-08-08 12:39:07.583670 7f27206b4700 -1 298'191 (6'57) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:5402 2015-08-08 11:57:21.552804 2015-08-08 12:39:07.583675 7f27206b4700 -1 298'192 (298'191) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:5403 2015-08-08 11:57:21.573882 2015-08-08 12:39:07.583679 7f27206b4700 -1 298'193 (298'192) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:5404 2015-08-08 11:57:21.573944 2015-08-08 12:39:07.583685 7f27206b4700 -1 956'199 (298'193) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9105 2015-08-08 12:26:38.508262 2015-08-08 12:39:07.583689 7f27206b4700 -1 956'200 (956'199) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9106 2015-08-08 12:26:38.535341 2015-08-08 12:39:07.583693 7f27206b4700 -1 956'201 (956'200) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9107 2015-08-08 12:26:38.537499 2015-08-08 12:39:07.583698 7f27206b4700 -1 956'202 (956'201) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9108 2015-08-08 12:26:38.537572 2015-08-08 12:39:07.583702 7f27206b4700 -1 log_keys_debug: 2015-08-08 12:39:07.583703 7f27206b4700 -1 0000000006.00000000000000000046 2015-08-08 12:39:07.583704 7f27206b4700 -1 0000000006.00000000000000000055 2015-08-08 12:39:07.583705 7f27206b4700 -1 0000000006.00000000000000000056 2015-08-08 12:39:07.583706 7f27206b4700 -1 0000000006.00000000000000000057 2015-08-08 12:39:07.583707 7f27206b4700 -1 0000000298.00000000000000000191 2015-08-08 12:39:07.583707 7f27206b4700 -1 0000000298.00000000000000000192 2015-08-08 12:39:07.583708 7f27206b4700 -1 0000000298.00000000000000000193 2015-08-08 12:39:07.583709 7f27206b4700 -1 0000000956.00000000000000000199 2015-08-08 12:39:07.583710 7f27206b4700 -1 0000000956.00000000000000000200 2015-08-08 12:39:07.583711 7f27206b4700 -1 0000000956.00000000000000000201
Updated by Sage Weil over 8 years ago
merge_log, just prior:
2015-08-08 12:39:07.582990 7f27206b4700 10 osd.5 pg_epoch: 1296 pg[1.17c( v 956'202 (956'202,956'202] local-les=1224 n=1 ec=5 les/c 1224/1224 1295/1295/1223) [5,4] r=0 lpr=1295 pi=1223-1294/1 crt=956'202 mlcod 0'0 peering NIBBLEWISE] proc_master_log for osd.1: log((0'0,956'202], crt=956'202) missing(0) 2015-08-08 12:39:07.583002 7f27206b4700 10 merge_log log((0'0,956'202], crt=956'202) from osd.1 into log((956'202,956'202], crt=956'202) 2015-08-08 12:39:07.583005 7f27206b4700 10 merge_log extending tail to 0'0 2015-08-08 12:39:07.583008 7f27206b4700 15 6'46 (0'0) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:976 2015-08-08 11:37:30.479123 2015-08-08 12:39:07.583016 7f27206b4700 15 6'55 (6'46) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:977 2015-08-08 11:37:30.503925 2015-08-08 12:39:07.583021 7f27206b4700 15 6'56 (6'55) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:978 2015-08-08 11:37:30.521613 2015-08-08 12:39:07.583026 7f27206b4700 15 6'57 (6'56) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:979 2015-08-08 11:37:30.521663 2015-08-08 12:39:07.583031 7f27206b4700 15 298'191 (6'57) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:5402 2015-08-08 11:57:21.552804 2015-08-08 12:39:07.583036 7f27206b4700 15 298'192 (298'191) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:5403 2015-08-08 11:57:21.573882 2015-08-08 12:39:07.583041 7f27206b4700 15 298'193 (298'192) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:5404 2015-08-08 11:57:21.573944 2015-08-08 12:39:07.583046 7f27206b4700 15 956'199 (298'193) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9105 2015-08-08 12:26:38.508262 2015-08-08 12:39:07.583051 7f27206b4700 15 956'200 (956'199) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9106 2015-08-08 12:26:38.535341 2015-08-08 12:39:07.583056 7f27206b4700 15 956'201 (956'200) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9107 2015-08-08 12:26:38.537499 2015-08-08 12:39:07.583061 7f27206b4700 15 956'202 (956'201) modify 1/2ffc3b7c/mira03825864-195/head by client.4122.0:9108 2015-08-08 12:26:38.537572 2015-08-08 12:39:07.583067 7f27206b4700 10 merge_log result log((0'0,956'202], crt=956'202) missing(0) changed=1
it does mark_dirty_to(956'202)
but writeout does not include the 202 record.
Updated by Sage Weil over 8 years ago
- Status changed from New to Fix Under Review
Updated by Sage Weil over 8 years ago
- Status changed from Fix Under Review to Pending Backport
Updated by Loïc Dachary over 8 years ago
- Status changed from Pending Backport to Resolved
Actions