Project

General

Profile

Bug #13897

(jewel) rados/objectstore/objectstore.yaml common/Mutex.cc: 105: FAILED assert(r == 0)

Added by Loïc Dachary over 8 years ago. Updated over 7 years ago.

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

0%

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

Description

2015-11-26T17:52:53.906 INFO:teuthology.orchestra.run.target181169.stderr:common/Mutex.cc: In function 'void Mutex::Lock(bool)' thread 7fc3137fe700 time 2015-11-26 17:52:53.836454
2015-11-26T17:52:53.906 INFO:teuthology.orchestra.run.target181169.stderr:common/Mutex.cc: 105: FAILED assert(r == 0)
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: ceph version 9.2.0-46-g97293b5 (97293b554026cff96da59760aeb577660867a2ac)
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x8b) [0x7fc3352a72cb]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 2: (Mutex::Lock(bool)+0x19c) [0x7fc33529766c]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 3: (FileStore::_journaled_ahead(FileStore::OpSequencer*, FileStore::Op*, Context*)+0x1ea) [0x7fc33505365a]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 4: (Context::complete(int)+0x9) [0x7fc33501a2c9]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 5: (Finisher::finisher_thread_entry()+0x158) [0x7fc335285f18]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 6: (()+0x8182) [0x7fc33371e182]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: 7: (clone()+0x6d) [0x7fc3322a847d]
2015-11-26T17:52:53.944 INFO:teuthology.orchestra.run.target181169.stderr: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2015-11-26T17:52:53.945 INFO:teuthology.orchestra.run.target181169.stderr:2015-11-26 17:52:53.841478 7fc3137fe700 -1 common/Mutex.cc: In function 'void Mutex::Lock(bool)' thread 7fc3137fe700 time 2015-11-26 17:52:53.836454

Related issues

Related to Ceph - Bug #13176: test/ceph_objectstore_tool.py: common/Mutex.cc: In function 'void Mutex::Lock(bool) Resolved 09/20/2015

History

#1 Updated by Loïc Dachary over 8 years ago

  • Related to Bug #13176: test/ceph_objectstore_tool.py: common/Mutex.cc: In function 'void Mutex::Lock(bool) added

#2 Updated by Loïc Dachary over 8 years ago

@David Does that ring a bell by any chance ?

#3 Updated by Sage Weil over 8 years ago

  • Priority changed from Normal to Urgent

#4 Updated by Sage Weil over 8 years ago

  • Status changed from New to Need More Info

Loic, do you have the path for the original run? The logs should help track this down.

#5 Updated by Loïc Dachary over 8 years ago

I did not keep the URL of the run where it happened.

#6 Updated by Yuri Weinstein about 8 years ago

Here is more info:
Run: http://pulpito.ovh.sepia.ceph.com:8081/teuthology-2016-01-06_21:00:01-rados-infernalis-distro-basic-openstack/
Job: ['61312']
Logs: http://teuthology.ovh.sepia.ceph.com/teuthology/teuthology-2016-01-06_21:00:01-rados-infernalis-distro-basic-openstack/61312/teuthology.log

2016-01-07T00:26:50.340 INFO:teuthology.orchestra.run.target087216.stderr:common/Mutex.cc: In function 'void Mutex::Lock(bool)' thread 7f52ce71d700 time 2016-01-07 00:26:50.236793
2016-01-07T00:26:50.340 INFO:teuthology.orchestra.run.target087216.stderr:common/Mutex.cc: 105: FAILED assert(r == 0)
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: ceph version 9.2.0-27-g64fab4f (64fab4f080c5b7d79b51b8db8c71428b507efec5)
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x8b) [0x7f52dfaab27b]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 2: (Mutex::Lock(bool)+0x19c) [0x7f52dfa9b61c]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 3: (FileStore::_journaled_ahead(FileStore::OpSequencer*, FileStore::Op*, Context*)+0x1ea) [0x7f52df85760a]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 4: (Context::complete(int)+0x9) [0x7f52df81e279]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 5: (Finisher::finisher_thread_entry()+0x158) [0x7f52dfa89ec8]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 6: (()+0x8182) [0x7f52ddcb7182]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: 7: (clone()+0x6d) [0x7f52dc84147d]
2016-01-07T00:26:50.342 INFO:teuthology.orchestra.run.target087216.stderr: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

#7 Updated by Yuri Weinstein about 8 years ago

  • Status changed from Need More Info to New

#8 Updated by Yuri Weinstein about 8 years ago

  • ceph-qa-suite rados added

#10 Updated by Sage Weil about 8 years ago

I don't think we've seen this on master.. some missing backport?

#12 Updated by Sage Weil about 8 years ago

  • Subject changed from rados/objectstore/objectstore.yaml common/Mutex.cc: 105: FAILED assert(r == 0) to (infernalis) rados/objectstore/objectstore.yaml common/Mutex.cc: 105: FAILED assert(r == 0)
  • Priority changed from Urgent to High

#13 Updated by Samuel Just over 7 years ago

  • Status changed from New to Can't reproduce

This doesn't seem to be happening on master, I'm going to chalk it up to an infernalis bug which has since been fixed.

#14 Updated by Nathan Cutler over 7 years ago

  • Subject changed from (infernalis) rados/objectstore/objectstore.yaml common/Mutex.cc: 105: FAILED assert(r == 0) to (jewel) rados/objectstore/objectstore.yaml common/Mutex.cc: 105: FAILED assert(r == 0)
  • Status changed from Can't reproduce to 12

I can reproduce this in the jewel branch by running --suite rados --filter rados/objectstore/objectstore.yaml in OVH. For example: http://teuthology-logs.public.ceph.com/ubuntu-2016-08-30_10%3a14%3a17-rados-jewel---basic-openstack/4/

#15 Updated by Nathan Cutler over 7 years ago

The reproducer is --suite rados --filter rados/objectstore/objectstore.yaml --ceph jewel in OVH. It seems to fail every time, either with this assert or with a segfault. For an example of the segfault, see: http://teuthology-logs.public.ceph.com/ubuntu-2016-08-30_10%3a33%3a12-rados-jewel---basic-openstack/5/

#17 Updated by Nathan Cutler over 7 years ago

I recently did a full rados run (250 jobs) on jewel in the Sepia lab - see https://github.com/ceph/ceph-qa-suite/pull/1096#issuecomment-243079856 for analysis - and this was not seen there. So it only happens in OVH.

#18 Updated by Nathan Cutler over 7 years ago

Reproduced in OVH again with the command:

ceph-workbench -v ceph-qa-suite --suite rados/objectstore/objectstore.yaml --ceph jewel --num 10 distros/all/centos_7.2.yaml

5 of 10 jobs failed, all in the same way as in - segfault in the "ObjectStore/StoreTest.ManyBigWrite/3" test, exactly like this in this job from which logs were captured: http://teuthology-logs.public.ceph.com/ubuntu-2016-08-30_10%3a33%3a12-rados-jewel---basic-openstack/5/

*** Caught signal (Segmentation fault) **
 in thread 7f3fc5d7f4c0 thread_name:ceph_test_objec

Followed by a very long trace, of which I show only a part:

2016-09-14T13:31:45.661 INFO:teuthology.orchestra.run.target158069086103.stderr: ceph version 10.2.2-508-g9bfc0cf (9bfc0cf178dc21b0fe33e0ce3b90a18858abaf1b)
2016-09-14T13:31:45.661 INFO:teuthology.orchestra.run.target158069086103.stderr: 1: (()+0x58314a) [0x7fa4a68f914a]
2016-09-14T13:31:45.661 INFO:teuthology.orchestra.run.target158069086103.stderr: 2: (()+0xf100) [0x7fa4a4914100]
2016-09-14T13:31:45.663 INFO:teuthology.orchestra.run.target158069086103.stderr: 3: (std::list<ceph::buffer::ptr, std::allocator<ceph::buffer::ptr> >::operator=(std::list<ceph::buffer::ptr, std::allocator<ceph::buffer::ptr> > const&)+0x76) [0x7fa4a65e57c6]
2016-09-14T13:31:45.663 INFO:teuthology.orchestra.run.target158069086103.stderr: 4: (KStore::_do_read_stripe(boost::intrusive_ptr<KStore::Onode>, unsigned long, ceph::buffer::list*)+0x1c8) [0x7fa4a66ea918]
2016-09-14T13:31:45.664 INFO:teuthology.orchestra.run.target158069086103.stderr: 5: (KStore::_do_write(KStore::TransContext*, boost::intrusive_ptr<KStore::Onode>, unsigned long, unsigned long, ceph::buffer::list&, unsigned int)+0x314) [0x7fa4a66ebb74]
2016-09-14T13:31:45.665 INFO:teuthology.orchestra.run.target158069086103.stderr: 6: (KStore::_write(KStore::TransContext*, std::shared_ptr<KStore::Collection>&, boost::intrusive_ptr<KStore::Onode>&, unsigned long, unsigned long, ceph::buffer::list&, unsigned int)+0xf2) [0x7fa4a66ecd22]
2016-09-14T13:31:45.666 INFO:teuthology.orchestra.run.target158069086103.stderr: 7: (KStore::_txc_add_transaction(KStore::TransContext*, ObjectStore::Transaction*)+0x16ff) [0x7fa4a66ff56f]
2016-09-14T13:31:45.666 INFO:teuthology.orchestra.run.target158069086103.stderr: 8: (KStore::queue_transactions(ObjectStore::Sequencer*, std::vector<ObjectStore::Transaction, std::allocator<ObjectStore::Transaction> >&, std::shared_ptr<TrackedOp>, ThreadPool::TPHandle*)+0x3a5) [0x7fa4a6700b75]
2016-09-14T13:31:45.666 INFO:teuthology.orchestra.run.target158069086103.stderr: 9: (ObjectStore::apply_transactions(ObjectStore::Sequencer*, std::vector<ObjectStore::Transaction, std::allocator<ObjectStore::Transaction> >&, Context*)+0x1b6) [0x7fa4a6602106]
2016-09-14T13:31:45.666 INFO:teuthology.orchestra.run.target158069086103.stderr: 10: (int apply_transaction<boost::scoped_ptr<ObjectStore> >(boost::scoped_ptr<ObjectStore>&, ObjectStore::Sequencer*, ObjectStore::Transaction&&)+0x147) [0x7fa4a65ee367]
2016-09-14T13:31:45.666 INFO:teuthology.orchestra.run.target158069086103.stderr: 11: (StoreTest_ManyBigWrite_Test::TestBody()+0x5d6) [0x7fa4a65ae736]
2016-09-14T13:31:45.668 INFO:teuthology.orchestra.run.target158069086103.stderr: 12: (void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*)+0x43) [0x7fa4a68f13c3]
2016-09-14T13:31:45.668 INFO:teuthology.orchestra.run.target158069086103.stderr: 13: (testing::Test::Run()+0xb7) [0x7fa4a68e2b87]
2016-09-14T13:31:45.669 INFO:teuthology.orchestra.run.target158069086103.stderr: 14: (testing::TestInfo::Run()+0x9e) [0x7fa4a68e2c2e]
2016-09-14T13:31:45.670 INFO:teuthology.orchestra.run.target158069086103.stderr: 15: (testing::TestCase::Run()+0xa5) [0x7fa4a68e2d35]
2016-09-14T13:31:45.670 INFO:teuthology.orchestra.run.target158069086103.stderr: 16: (testing::internal::UnitTestImpl::RunAllTests()+0x268) [0x7fa4a68e3008]
2016-09-14T13:31:45.671 INFO:teuthology.orchestra.run.target158069086103.stderr: 17: (testing::UnitTest::Run()+0x68) [0x7fa4a68e32c8]
2016-09-14T13:31:45.672 INFO:teuthology.orchestra.run.target158069086103.stderr: 18: (main()+0x260) [0x7fa4a6561f10]
2016-09-14T13:31:45.673 INFO:teuthology.orchestra.run.target158069086103.stderr: 19: (__libc_start_main()+0xf5) [0x7fa4a371db15]
2016-09-14T13:31:45.673 INFO:teuthology.orchestra.run.target158069086103.stderr: 20: (()+0x232ad1) [0x7fa4a65a8ad1]
2016-09-14T13:31:45.674 INFO:teuthology.orchestra.run.target158069086103.stderr:2016-09-14 13:31:48.642567 7fa4a635a4c0 -1 *** Caught signal (Bus error) **
2016-09-14T13:31:45.674 INFO:teuthology.orchestra.run.target158069086103.stderr: in thread 7fa4a635a4c0 thread_name:ceph_test_objec
2016-09-14T13:31:45.675 INFO:teuthology.orchestra.run.target158069086103.stderr:
2016-09-14T13:31:45.675 INFO:teuthology.orchestra.run.target158069086103.stderr: ceph version 10.2.2-508-g9bfc0cf (9bfc0cf178dc21b0fe33e0ce3b90a18858abaf1b)
2016-09-14T13:31:45.676 INFO:teuthology.orchestra.run.target158069086103.stderr: 1: (()+0x58314a) [0x7fa4a68f914a]
2016-09-14T13:31:45.677 INFO:teuthology.orchestra.run.target158069086103.stderr: 2: (()+0xf100) [0x7fa4a4914100]
2016-09-14T13:31:45.677 INFO:teuthology.orchestra.run.target158069086103.stderr: 3: (std::list<ceph::buffer::ptr, std::allocator<ceph::buffer::ptr> >::operator=(std::list<ceph::buffer::ptr, std::allocator<ceph::buffer::ptr> > const&)+0x76) [0x7fa4a65e57c6]
2016-09-14T13:31:45.677 INFO:teuthology.orchestra.run.target158069086103.stderr: 4: (KStore::_do_read_stripe(boost::intrusive_ptr<KStore::Onode>, unsigned long, ceph::buffer::list*)+0x1c8) [0x7fa4a66ea918]
2016-09-14T13:31:45.677 INFO:teuthology.orchestra.run.target158069086103.stderr: 5: (KStore::_do_write(KStore::TransContext*, boost::intrusive_ptr<KStore::Onode>, unsigned long, unsigned long, ceph::buffer::list&, unsigned int)+0x314) [0x7fa4a66ebb74]
2016-09-14T13:31:45.677 INFO:teuthology.orchestra.run.target158069086103.stderr: 6: (KStore::_write(KStore::TransContext*, std::shared_ptr<KStore::Collection>&, boost::intrusive_ptr<KStore::Onode>&, unsigned long, unsigned long, ceph::buffer::list&, unsigned int)+0xf2) [0x7fa4a66ecd22]
2016-09-14T13:31:45.677 INFO:teuthology.orchestra.run.target158069086103.stderr: 7: (KStore::_txc_add_transaction(KStore::TransContext*, ObjectStore::Transaction*)+0x16ff) [0x7fa4a66ff56f]
2016-09-14T13:31:45.679 INFO:teuthology.orchestra.run.target158069086103.stderr: 8: (KStore::queue_transactions(ObjectStore::Sequencer*, std::vector<ObjectStore::Transaction, std::allocator<ObjectStore::Transaction> >&, std::shared_ptr<TrackedOp>, ThreadPool::TPHandle*)+0x3a5) [0x7fa4a6700b75]
2016-09-14T13:31:45.680 INFO:teuthology.orchestra.run.target158069086103.stderr: 9: (ObjectStore::apply_transactions(ObjectStore::Sequencer*, std::vector<ObjectStore::Transaction, std::allocator<ObjectStore::Transaction> >&, Context*)+0x1b6) [0x7fa4a6602106]
2016-09-14T13:31:45.681 INFO:teuthology.orchestra.run.target158069086103.stderr: 10: (int apply_transaction<boost::scoped_ptr<ObjectStore> >(boost::scoped_ptr<ObjectStore>&, ObjectStore::Sequencer*, ObjectStore::Transaction&&)+0x147) [0x7fa4a65ee367]
2016-09-14T13:31:45.681 INFO:teuthology.orchestra.run.target158069086103.stderr: 11: (StoreTest_ManyBigWrite_Test::TestBody()+0x5d6) [0x7fa4a65ae736]
2016-09-14T13:31:45.682 INFO:teuthology.orchestra.run.target158069086103.stderr: 12: (void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*)+0x43) [0x7fa4a68f13c3]
2016-09-14T13:31:45.682 INFO:teuthology.orchestra.run.target158069086103.stderr: 13: (testing::Test::Run()+0xb7) [0x7fa4a68e2b87]
2016-09-14T13:31:45.683 INFO:teuthology.orchestra.run.target158069086103.stderr: 14: (testing::TestInfo::Run()+0x9e) [0x7fa4a68e2c2e]
2016-09-14T13:31:45.684 INFO:teuthology.orchestra.run.target158069086103.stderr: 15: (testing::TestCase::Run()+0xa5) [0x7fa4a68e2d35]
2016-09-14T13:31:45.685 INFO:teuthology.orchestra.run.target158069086103.stderr: 16: (testing::internal::UnitTestImpl::RunAllTests()+0x268) [0x7fa4a68e3008]
2016-09-14T13:31:45.685 INFO:teuthology.orchestra.run.target158069086103.stderr: 17: (testing::UnitTest::Run()+0x68) [0x7fa4a68e32c8]
2016-09-14T13:31:45.686 INFO:teuthology.orchestra.run.target158069086103.stderr: 18: (main()+0x260) [0x7fa4a6561f10]
2016-09-14T13:31:45.687 INFO:teuthology.orchestra.run.target158069086103.stderr: 19: (__libc_start_main()+0xf5) [0x7fa4a371db15]
2016-09-14T13:31:45.687 INFO:teuthology.orchestra.run.target158069086103.stderr: 20: (()+0x232ad1) [0x7fa4a65a8ad1]
2016-09-14T13:31:45.688 INFO:teuthology.orchestra.run.target158069086103.stderr: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2016-09-14T13:31:45.689 INFO:teuthology.orchestra.run.target158069086103.stderr:
2016-09-14T13:31:45.689 INFO:teuthology.orchestra.run.target158069086103.stderr:--- begin dump of recent events ---
2016-09-14T13:31:45.690 INFO:teuthology.orchestra.run.target158069086103.stderr:  -500> 2016-09-14 13:31:48.458183 7fa498ff9700  5 rocksdb: [default] New memtable created with log file: #91
2016-09-14T13:31:45.691 INFO:teuthology.orchestra.run.target158069086103.stderr:
2016-09-14T13:31:45.691 INFO:teuthology.orchestra.run.target158069086103.stderr:  -499> 2016-09-14 13:31:48.458214 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 0 len 19 crc 616131867
2016-09-14T13:31:45.692 INFO:teuthology.orchestra.run.target158069086103.stderr:  -498> 2016-09-14 13:31:48.458234 7fa49affd700  4 rocksdb: (Original Log Time 2016/09/14-13:31:48.458224) Calling FlushMemTableToOutputFile with column family [default], flush slots available 0, compaction slots available 0
2016-09-14T13:31:45.693 INFO:teuthology.orchestra.run.target158069086103.stderr:  -497> 2016-09-14 13:31:48.458241 7fa49affd700  4 rocksdb: [default] [JOB 39] Flushing memtable with next log file: 91
2016-09-14T13:31:45.693 INFO:teuthology.orchestra.run.target158069086103.stderr:
2016-09-14T13:31:45.694 INFO:teuthology.orchestra.run.target158069086103.stderr:  -496> 2016-09-14 13:31:48.458256 7fa49affd700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1473859908458247, "job": 39, "event": "flush_started", "num_memtables": 1, "num_entries": 66, "num_deletes": 0, "memory_usage": 4833630}
2016-09-14T13:31:45.695 INFO:teuthology.orchestra.run.target158069086103.stderr:  -495> 2016-09-14 13:31:48.458259 7fa49affd700  4 rocksdb: [default] [JOB 39] Level-0 flush table #92: started
2016-09-14T13:31:45.695 INFO:teuthology.orchestra.run.target158069086103.stderr:  -494> 2016-09-14 13:31:48.459225 7fa49a7fc700  4 rocksdb: [default] [JOB 31] Generated table #90: 33 keys, 2165954 bytes
2016-09-14T13:31:45.696 INFO:teuthology.orchestra.run.target158069086103.stderr:  -493> 2016-09-14 13:31:48.459265 7fa49a7fc700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1473859908459237, "cf_name": "default", "job": 31, "event": "table_file_creation", "file_number": 90, "file_size": 2165954, "table_properties": {"data_size": 2164140, "index_size": 1411, "filter_size": 0, "raw_key_size": 858, "raw_average_key_size": 26, "raw_value_size": 2162688, "raw_average_value_size": 65536, "num_data_blocks": 33, "num_entries": 33, "filter_policy_name": "", "kDeletedKeys": "0"}}
2016-09-14T13:31:45.697 INFO:teuthology.orchestra.run.target158069086103.stderr:  -492> 2016-09-14 13:31:48.486785 7fa49affd700  4 rocksdb: [default] [JOB 39] Level-0 flush table #92: 4247502 bytes OK
2016-09-14T13:31:45.697 INFO:teuthology.orchestra.run.target158069086103.stderr:  -491> 2016-09-14 13:31:48.486844 7fa49affd700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1473859908486822, "cf_name": "default", "job": 39, "event": "table_file_creation", "file_number": 92, "file_size": 4247502, "table_properties": {"data_size": 4244384, "index_size": 2847, "filter_size": 0, "raw_key_size": 1744, "raw_average_key_size": 26.4242, "raw_value_size": 4241454, "raw_average_value_size": 64264.5, "num_data_blocks": 66, "num_entries": 66, "filter_policy_name": "", "kDeletedKeys": "0"}}
2016-09-14T13:31:45.698 INFO:teuthology.orchestra.run.target158069086103.stderr:  -490> 2016-09-14 13:31:48.489273 7fa49a7fc700  4 rocksdb: [default] [JOB 31] Generated table #93: 33 keys, 2165957 bytes
2016-09-14T13:31:45.699 INFO:teuthology.orchestra.run.target158069086103.stderr:  -489> 2016-09-14 13:31:48.489338 7fa49a7fc700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1473859908489284, "cf_name": "default", "job": 31, "event": "table_file_creation", "file_number": 93, "file_size": 2165957, "table_properties": {"data_size": 2164140, "index_size": 1414, "filter_size": 0, "raw_key_size": 858, "raw_average_key_size": 26, "raw_value_size": 2162688, "raw_average_value_size": 65536, "num_data_blocks": 33, "num_entries": 33, "filter_policy_name": "", "kDeletedKeys": "0"}}
2016-09-14T13:31:45.699 INFO:teuthology.orchestra.run.target158069086103.stderr:  -488> 2016-09-14 13:31:48.496021 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 19 len 32749 crc -1995146826
2016-09-14T13:31:45.700 INFO:teuthology.orchestra.run.target158069086103.stderr:  -487> 2016-09-14 13:31:48.496122 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 32768 len 32768 crc 1997173050
2016-09-14T13:31:45.701 INFO:teuthology.orchestra.run.target158069086103.stderr:  -486> 2016-09-14 13:31:48.496200 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 65536 len 32768 crc 133713951
2016-09-14T13:31:45.701 INFO:teuthology.orchestra.run.target158069086103.stderr:  -485> 2016-09-14 13:31:48.496272 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 98304 len 32768 crc 1997173050
2016-09-14T13:31:45.702 INFO:teuthology.orchestra.run.target158069086103.stderr:  -484> 2016-09-14 13:31:48.496346 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 131072 len 32768 crc 662890953
2016-09-14T13:31:45.703 INFO:teuthology.orchestra.run.target158069086103.stderr:  -483> 2016-09-14 13:31:48.496422 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 163840 len 32768 crc 1997173050
2016-09-14T13:31:45.703 INFO:teuthology.orchestra.run.target158069086103.stderr:  -482> 2016-09-14 13:31:48.496484 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 196608 len 32768 crc -395709274
2016-09-14T13:31:45.704 INFO:teuthology.orchestra.run.target158069086103.stderr:  -481> 2016-09-14 13:31:48.496540 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 229376 len 32768 crc 1997173050
2016-09-14T13:31:45.705 INFO:teuthology.orchestra.run.target158069086103.stderr:  -480> 2016-09-14 13:31:48.496596 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 262144 len 32768 crc 649332410
2016-09-14T13:31:45.706 INFO:teuthology.orchestra.run.target158069086103.stderr:  -479> 2016-09-14 13:31:48.496661 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 294912 len 32768 crc 1997173050
2016-09-14T13:31:45.706 INFO:teuthology.orchestra.run.target158069086103.stderr:  -478> 2016-09-14 13:31:48.496719 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 327680 len 32768 crc 881401059
2016-09-14T13:31:45.706 INFO:teuthology.orchestra.run.target158069086103.stderr:  -477> 2016-09-14 13:31:48.496775 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 360448 len 32768 crc 1997173050
2016-09-14T13:31:45.706 INFO:teuthology.orchestra.run.target158069086103.stderr:  -476> 2016-09-14 13:31:48.496836 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 393216 len 32768 crc -1410934106
2016-09-14T13:31:45.706 INFO:teuthology.orchestra.run.target158069086103.stderr:  -475> 2016-09-14 13:31:48.496900 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 425984 len 32768 crc 1997173050
2016-09-14T13:31:45.707 INFO:teuthology.orchestra.run.target158069086103.stderr:  -474> 2016-09-14 13:31:48.496959 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 458752 len 32768 crc -361917648
2016-09-14T13:31:45.709 INFO:teuthology.orchestra.run.target158069086103.stderr:  -473> 2016-09-14 13:31:48.497015 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 491520 len 32768 crc 1997173050
2016-09-14T13:31:45.709 INFO:teuthology.orchestra.run.target158069086103.stderr:  -472> 2016-09-14 13:31:48.497070 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 524288 len 32768 crc -832408563
2016-09-14T13:31:45.710 INFO:teuthology.orchestra.run.target158069086103.stderr:  -471> 2016-09-14 13:31:48.497143 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 557056 len 32768 crc 1997173050
2016-09-14T13:31:45.711 INFO:teuthology.orchestra.run.target158069086103.stderr:  -470> 2016-09-14 13:31:48.497208 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 589824 len 32768 crc -1776831982
2016-09-14T13:31:45.711 INFO:teuthology.orchestra.run.target158069086103.stderr:  -469> 2016-09-14 13:31:48.497291 7fa498ff9700  5 rocksdb: EmitPhysicalRecord: log 91 offset 622592 len 32768 crc 1997173050
2016-09-14T13:31:45.712 INFO:teuthology.orchestra.run.target158069086103.stderr:  -468> 2016-09-14 13:31:48.497302 7fa49affd700  4 rocksdb: (Original Log Time 2016/09/14-13:31:48.486854) [default] Level-0 commit table #92 started
2016-09-14T13:31:45.713 INFO:teuthology.orchestra.run.target158069086103.stderr:  -467> 2016-09-14 13:31:48.497307 7fa49affd700  4 rocksdb: (Original Log Time 2016/09/14-13:31:48.497255) [default] Level-0 commit table #92: memtable #1 done
2016-09-14T13:31:45.714 INFO:teuthology.orchestra.run.target158069086103.stderr:  -466> 2016-09-14 13:31:48.497309 7fa49affd700  4 rocksdb: (Original Log Time 2016/09/14-13:31:48.497270) EVENT_LOG_v1 {"time_micros": 1473859908497264, "job": 39, "event": "flush_finished", "lsm_state": [17, 10, 8, 0, 0, 0, 0]}
2016-09-14T13:31:45.714 INFO:teuthology.orchestra.run.target158069086103.stderr:  -465> 2016-09-14 13:31:48.497312 7fa49affd700  4 rocksdb: (Original Log Time 2016/09/14-13:31:48.497290) [default] Level summary: base level 1 max bytes base 10485760 files[17 10 8 0 0 0 0] max score 2.25
2016-09-14T13:31:45.715 INFO:teuthology.orchestra.run.target158069086103.stderr:
2016-09-14T13:31:45.716 INFO:teuthology.orchestra.run.target158069086103.stderr:  -464> 2016-09-14 13:31:48.497359 7fa49affd700  5 rocksdb: [JOB 39] Delete store_test_temp_dir/db/000087.log type=0 #87 -- OK
...

#19 Updated by Nathan Cutler over 7 years ago

The crash is not reproducible in Sepia:

teuthology-suite --suite rados/objectstore/objectstore.yaml --ceph jewel --num 10 --machine-type smithi --email ncutler@suse.cz distros/all/centos_7.2.yaml

pass http://pulpito.ceph.com/smithfarm-2016-09-16_19:30:39-rados:objectstore:objectstore.yaml-jewel---basic-smithi/

#20 Updated by Samuel Just over 7 years ago

  • Assignee set to David Zafman
  • Priority changed from High to Urgent

#21 Updated by Samuel Just over 7 years ago

  • Status changed from 12 to Resolved
  • Priority changed from Urgent to High

This is actually two different bugs. The former doesn't seem to have recurred. The latter is a kstore bug and the test has been disabled.

Also available in: Atom PDF