Project

General

Profile

Actions

Bug #12652

closed

osd/PGLog.cc: 732: FAILED assert(log.log.size() == log_keys_debug.size())

Added by Sage Weil over 8 years ago. Updated over 8 years ago.

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


Related issues 3 (0 open3 closed)

Related to Ceph - Bug #10718: osd/PGLog.h: 279: FAILED assert(log.log.size() == log_keys_debug.size())ResolvedSamuel Just02/02/2015

Actions
Copied to Ceph - Backport #12845: osd/PGLog.cc: 732: FAILED assert(log.log.size() == log_keys_debug.size())ResolvedSage Weil08/09/2015Actions
Copied to Ceph - Backport #12846: osd/PGLog.cc: 732: FAILED assert(log.log.size() == log_keys_debug.size())ResolvedLoïc Dachary08/09/2015Actions
Actions #1

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.

Actions #2

Updated by Sage Weil over 8 years ago

  • Description updated (diff)
Actions #3

Updated by Sage Weil over 8 years ago

  • Backport set to hammer,firely
Actions #4

Updated by Sage Weil over 8 years ago

  • Status changed from New to Fix Under Review
Actions #5

Updated by Sage Weil over 8 years ago

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

Updated by Loïc Dachary over 8 years ago

  • Status changed from Pending Backport to Resolved
Actions

Also available in: Atom PDF