Details
-
Improvement
-
Resolution: Won't Fix
-
Major - P3
-
None
-
3.0.7
-
None
-
Sharding
-
Sharding D (12/11/15)
Description
In a sharded scenario involving chunk moves, inserts, and deletes (via TTL) we observe WT "range of pinned ids" statistic growing, indicating long-running transactions. Added this patch to look for transactions taking >100ms.
diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp
|
index 58cdefc..c0a406c 100644
|
--- a/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp
|
+++ b/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp
|
@@ -253,9 +253,15 @@ void WiredTigerRecoveryUnit::_txnClose(bool commit) {
|
invariant(_active);
|
WT_SESSION* s = _session->getSession();
|
if (commit) {
|
+ if (_timer.millis() >= 100)
|
+ log() << "XXX commiting; _timer.millis() " << _timer.millis();
|
+ wassert(_timer.millis() < 100);
|
invariantWTOK(s->commit_transaction(s, NULL));
|
LOG(2) << "WT commit_transaction";
|
} else {
|
+ if (_timer.millis() >= 100)
|
+ log() << "XXX rolling back; _timer.millis() " << _timer.millis();
|
+ wassert(_timer.millis() < 100);
|
invariantWTOK(s->rollback_transaction(s, NULL));
|
LOG(2) << "WT rollback_transaction";
|
}
|
Here was the longest, a transaction that ran for about 23 s:
2015-11-09T13:58:05.984-0500 I STORAGE [migrateThread] XXX rolling back; _timer.millis() 23047
|
2015-11-09T13:58:05.984-0500 I - [migrateThread] warning assertion failure _timer.millis() < 100 src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp 264
|
2015-11-09T13:58:05.990-0500 I CONTROL [migrateThread]
|
0xf62172 0xf0b329 0xeeef6b 0xd87f6b 0xdf3e64 0xe03619 0xe04fdc 0xdf0c79 0xdf1f0d 0xfb154f 0x7f212d8e7182 0x7f212c9e847d
|
----- BEGIN BACKTRACE -----
|
{"backtrace":[{"b":"400000","o":"B62172"},{"b":"400000","o":"B0B329"},{"b":"400000","o":"AEEF6B"},{"b":"400000","o":"987F6B"},{"b":"400000","o":"9F3E64"},{"b":"400000","o":"A03619"},{"b":"400000","o":"A04FDC"},{"b":"400000","o":"9F0C79"},{"b":"400000","o":"9F1F0D"},{"b":"400000","o":"BB154F"},{"b":"7F212D8DF000","o":"8182"},{"b":"7F212C8EE000","o":"FA47D"}],"processInfo":{ "mongodbVersion" : "3.0.8-pre-", "gitVersion" : "d4f8d4b2a576160348de61f972fa478a845234fd", "uname" : { "sysname" : "Linux", "release" : "3.13.0-32-generic", "version" : "#57-Ubuntu SMP Tue Jul 15 03:51:08 UTC 2014", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000", "buildId" : "83C5D7336ECF9A76049E8DE24FC106DEF6241FF9" }, { "b" : "7FFFA00FE000", "elfType" : 3, "buildId" : "E464DBB7341B7B9E7874DC0619C5F429416E6AC6" }, { "b" : "7F212D8DF000", "path" : "/lib/x86_64-linux-gnu/libpthread.so.0", "elfType" : 3, "buildId" : "9318E8AF0BFBE444731BB0461202EF57F7C39542" }, { "b" : "7F212D6D7000", "path" : "/lib/x86_64-linux-gnu/librt.so.1", "elfType" : 3, "buildId" : "92FCF41EFE012D6186E31A59AD05BDBB487769AB" }, { "b" : "7F212D4D3000", "path" : "/lib/x86_64-linux-gnu/libdl.so.2", "elfType" : 3, "buildId" : "C1AE4CB7195D337A77A3C689051DABAA3980CA0C" }, { "b" : "7F212D1CF000", "path" : "/usr/lib/x86_64-linux-gnu/libstdc++.so.6", "elfType" : 3, "buildId" : "4BF6F7ADD8244AD86008E6BF40D90F8873892197" }, { "b" : "7F212CEC9000", "path" : "/lib/x86_64-linux-gnu/libm.so.6", "elfType" : 3, "buildId" : "1D76B71E905CB867B27CEF230FCB20F01A3178F5" }, { "b" : "7F212CCB3000", "path" : "/lib/x86_64-linux-gnu/libgcc_s.so.1", "elfType" : 3, "buildId" : "CC0D578C2E0D86237CA7B0CE8913261C506A629A" }, { "b" : "7F212C8EE000", "path" : "/lib/x86_64-linux-gnu/libc.so.6", "elfType" : 3, "buildId" : "30C94DC66A1FE95180C3D68D2B89E576D5AE213C" }, { "b" : "7F212DAFD000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "9F00581AB3C73E3AEA35995A0C50D24D59A01D47" } ] }}
|
mongod(_ZN5mongo15printStackTraceERSo+0x32) [0xf62172]
|
mongod(_ZN5mongo10logContextEPKc+0xE9) [0xf0b329]
|
mongod(_ZN5mongo9wassertedEPKcS1_j+0x19B) [0xeeef6b]
|
mongod(_ZN5mongo22WiredTigerRecoveryUnit9_txnCloseEb+0x3DB) [0xd87f6b]
|
mongod(_ZN5mongo13MigrateStatus5applyEPNS_16OperationContextERKSsNS_7BSONObjES5_S5_RKS5_Py+0x9B4) [0xdf3e64]
|
mongod(_ZN5mongo13MigrateStatus3_goEPNS_16OperationContextERKSsNS_7BSONObjES5_S5_S4_RKNS_3OIDERKNS_19WriteConcernOptionsE+0x2309) [0xe03619]
|
mongod(_ZN5mongo13MigrateStatus2goEPNS_16OperationContextERKSsNS_7BSONObjES5_S5_S4_RKNS_3OIDERKNS_19WriteConcernOptionsE+0xCC) [0xe04fdc]
|
mongod(_ZN5mongo13migrateThreadESsNS_7BSONObjES0_S0_SsNS_3OIDENS_19WriteConcernOptionsE+0x109) [0xdf0c79]
|
mongod(_ZN5boost6detail11thread_dataINS_3_bi6bind_tIvPFvSsN5mongo7BSONObjES5_S5_SsNS4_3OIDENS4_19WriteConcernOptionsEENS2_5list7INS2_5valueISsEENSB_IS5_EESD_SD_SC_NSB_IS6_EENSB_IS7_EEEEEEE3runEv+0x11D) [0xdf1f0d]
|
mongod(+0xBB154F) [0xfb154f]
|
libpthread.so.0(+0x8182) [0x7f212d8e7182]
|
libc.so.6(clone+0x6D) [0x7f212c9e847d]
|
----- END BACKTRACE -----
|
addr2line:
mongo::printStackTrace(std::ostream&) at src/mongo/util/stacktrace_posix.cpp:105
|
mongo::logContext(char const*) at src/mongo/util/log.cpp:134 (discriminator 1)
|
mongo::wasserted(char const*, char const*, unsigned int) at src/mongo/util/assert_util.cpp:119
|
mongo::WiredTigerRecoveryUnit::_txnClose(bool) at src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp:264 (discriminator 1)
|
mongo::MigrateStatus::apply(mongo::OperationContext*, std::string const&, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj const&, unsigned long long*) at src/mongo/s/d_migrate.cpp:2411
|
~intrusive_ptr at src/third_party/boost/boost/smart_ptr/intrusive_ptr.hpp:96
|
(inlined by) ~SharedBuffer at src/mongo/util/shared_buffer.h:38
|
(inlined by) ~BSONObj at src/mongo/bson/bsonobj.h:90
|
(inlined by) mongo::MigrateStatus::_go(mongo::OperationContext*, std::string const&, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, std::string const&, mongo::OID const&, mongo::WriteConcernOptions const&) at src/mongo/s/d_migrate.cpp:2209
|
~intrusive_ptr at src/third_party/boost/boost/smart_ptr/intrusive_ptr.hpp:96
|
(inlined by) ~SharedBuffer at src/mongo/util/shared_buffer.h:38
|
(inlined by) ~BSONObj at src/mongo/bson/bsonobj.h:90
|
(inlined by) mongo::MigrateStatus::go(mongo::OperationContext*, std::string const&, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, std::string const&, mongo::OID const&, mongo::WriteConcernOptions const&) at src/mongo/s/d_migrate.cpp:1870
|
~intrusive_ptr at src/third_party/boost/boost/smart_ptr/intrusive_ptr.hpp:96
|
(inlined by) ~SharedBuffer at src/mongo/util/shared_buffer.h:38
|
(inlined by) ~BSONObj at src/mongo/bson/bsonobj.h:90
|
(inlined by) mongo::migrateThread(std::string, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, std::string, mongo::OID, mongo::WriteConcernOptions) at src/mongo/s/d_migrate.cpp:2635
|
~basic_string at /usr/include/c++/4.8/bits/basic_string.h:539
|
(inlined by) operator()<void (*)(std::basic_string<char>, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, std::basic_string<char>, mongo::OID, mongo::WriteConcernOptions), boost::_bi::list0> at src/third_party/boost/boost/bind/bind.hpp:670
|
(inlined by) boost::_bi::bind_t<void, void (*)(std::string, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, std::string, mongo::OID, mongo::WriteConcernOptions), boost::_bi::list7<boost::_bi::value<std::string>, boost::_bi::value<mongo::BSONObj>, boost::_bi::value<mongo::BSONObj>, boost::_bi::value<mongo::BSONObj>, boost::_bi::value<std::string>, boost::_bi::value<mongo::OID>, boost::_bi::value<mongo::WriteConcernOptions> > >::operator()() at src/third_party/boost/boost/bind/bind_template.hpp:20
|
(inlined by) boost::detail::thread_data<boost::_bi::bind_t<void, void (*)(std::string, mongo::BSONObj, mongo::BSONObj, mongo::BSONObj, std::string, mongo::OID, mongo::WriteConcernOptions), boost::_bi::list7<boost::_bi::value<std::string>, boost::_bi::value<mongo::BSONObj>, boost::_bi::value<mongo::BSONObj>, boost::_bi::value<mongo::BSONObj>, boost::_bi::value<std::string>, boost::_bi::value<mongo::OID>, boost::_bi::value<mongo::WriteConcernOptions> > > >::run() at src/third_party/boost/boost/thread/detail/thread.hpp:62
|
thread_proxy at src/third_party/boost/libs/thread/src/pthread/thread.cpp:133
|
This transaction was held open for the duration of applying deletes during the catchup phase of a chunk migration.
Attachments
Issue Links
- related to
-
SERVER-21367 Log long-running WT transactions in the integration layer
-
- Closed
-
-
SERVER-21382 Sharding migration transfers all document deletions
-
- Closed
-