-
Type: Bug
-
Resolution: Duplicate
-
Priority: Major - P3
-
None
-
Affects Version/s: 2.8.0-rc1
-
Component/s: Storage
-
ALL
wiredtiger primary:
mmsdev:PRIMARY> db.app.migrations.findOne({_id: 'DownloadBaseWindowsMigration'}); 2014-11-26T19:12:29.880+0000 I QUERY Error: error: { "$err" : "Didn't find DiskLoc in WiredTigerRecordStore", "code" : 28556 } at Error (<anonymous>) at DBQuery.next (src/mongo/shell/query.js:259:15) at DBCollection.findOne (src/mongo/shell/collection.js:187:22) at (shell):1:19 at src/mongo/shell/query.js:259
In the logs:
2014-11-26T19:12:29.874+0000 I - [conn1829] Assertion: 28556:Didn't find DiskLoc in WiredTigerRecordStore 2014-11-26T19:12:29.879+0000 I CONTROL [conn1829] 0xf41389 0xee8d61 0xece71f 0xd5833e 0x8f1506 0x9ecba3 0xbcbaba 0xbb90bc 0xa9db93 0x7e0290 0xefd9c1 0x7f79b3a79182 0x7f79b2b79fbd ----- BEGIN BACKTRACE ----- {"backtrace":[{"b":"400000","o":"B41389"},{"b":"400000","o":"AE8D61"},{"b":"400000","o":"ACE71F"},{"b":"400000","o":"95833E"},{"b":"400000","o":"4F1506"},{"b":"400000","o":"5ECBA3"},{"b":"400000","o":"7CBABA"},{"b":"400000","o":"7B90BC"},{"b":"400000","o":"69DB93"},{"b":"400000","o":"3E0290"},{"b":"400000","o":"AFD9C1"},{"b":"7F79B3A71000","o":"8182"},{"b":"7F79B2A7F000","o":"FAFBD"}],"processInfo":{ "mongodbVersion" : "2.8.0-rc1", "gitVersion" : "c8171e7f969519af8b87a43425ae291ee69a0191", "uname" : { "sysname" : "Linux", "release" : "3.13.0-36-generic", "version" : "#63-Ubuntu SMP Wed Sep 3 21:30:07 UTC 2014", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000" }, { "b" : "7FFF89EAE000", "elfType" : 3 }, { "b" : "7F79B3A71000", "path" : "/lib/x86_64-linux-gnu/libpthread.so.0", "elfType" : 3 }, { "b" : "7F79B3869000", "path" : "/lib/x86_64-linux-gnu/librt.so.1", "elfType" : 3 }, { "b" : "7F79B3665000", "path" : "/lib/x86_64-linux-gnu/libdl.so.2", "elfType" : 3 }, { "b" : "7F79B3361000", "path" : "/usr/lib/x86_64-linux-gnu/libstdc++.so.6", "elfType" : 3 }, { "b" : "7F79B305B000", "path" : "/lib/x86_64-linux-gnu/libm.so.6", "elfType" : 3 }, { "b" : "7F79B2E45000", "path" : "/lib/x86_64-linux-gnu/libgcc_s.so.1", "elfType" : 3 }, { "b" : "7F79B2A7F000", "path" : "/lib/x86_64-linux-gnu/libc.so.6", "elfType" : 3 }, { "b" : "7F79B3C8F000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3 } ] }} mongod(_ZN5mongo15printStackTraceERSo+0x29) [0xf41389] mongod(_ZN5mongo10logContextEPKc+0xE1) [0xee8d61] mongod(_ZN5mongo11msgassertedEiPKc+0xAF) [0xece71f] mongod(+0x95833E) [0xd5833e] mongod(_ZNK5mongo10Collection6docForEPNS_16OperationContextERKNS_7DiskLocE+0x16) [0x8f1506] mongod(_ZN5mongo11IDHackStage4workEPm+0x1A3) [0x9ecba3] mongod(_ZN5mongo12PlanExecutor7getNextEPNS_7BSONObjEPNS_7DiskLocE+0x9A) [0xbcbaba] mongod(_ZN5mongo11newRunQueryEPNS_16OperationContextERNS_7MessageERNS_12QueryMessageERNS_5CurOpES3_b+0x99C) [0xbb90bc] mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortEb+0xBB3) [0xa9db93] mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xE0) [0x7e0290] mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x421) [0xefd9c1] libpthread.so.0(+0x8182) [0x7f79b3a79182] libc.so.6(clone+0x6D) [0x7f79b2b79fbd] ----- END BACKTRACE ----- 2014-11-26T19:12:29.879+0000 I COMMAND [conn1829] assertion 28556 Didn't find DiskLoc in WiredTigerRecordStore ns:cloudconf.app.migrations query:{ _id: "DownloadBaseWindowsMigration" } 2014-11-26T19:12:29.879+0000 I COMMAND [conn1829] ntoskip:0 ntoreturn:-1 2014-11-26T19:13:38.306+0000 I QUERY [conn521] command admin.$cmd command: listDatabases { listDatabases: 1 } keyUpdates:0 reslen:4505 4430ms
On the mmapv1 secondary:
mmsdev:SECONDARY> db.app.migrations.findOne({_id: 'DownloadBaseWindowsMigration'}); null
This document is unusual in that we know when it should have been created. According to the app server logs it was created here:
ubuntu@ip-10-167-150-115:/log$ grep DownloadBaseWindowsMigration mms-server.log* mms-server.log: [java] 2014-11-25T19:30:31.674+0000 [main] gid: INFO com.xgen.svc.common.migration.MigrationSvc [runOne:72] - Running migration DownloadBaseWindowsMigration mms-server.log: [java] 2014-11-25T19:30:31.712+0000 [main] gid: INFO com.xgen.svc.common.migration.impl.DownloadBaseWindowsMigration [runInternal:28] - Finished migrating 26 documents mms-server.log: [java] 2014-11-25T19:30:31.713+0000 [main] gid: INFO com.xgen.svc.common.migration.MigrationSvc [runOne:74] - Completed migration DownloadBaseWindowsMigration in 37msec
Furthermore, the app servers would have validated the existence of this document on every start up. They did this successfully on several occasions before hitting this error. According to the log snippets below I would expect the existence of this document to have been validated on 10 occasions, before hitting the error.
[java] 2014-11-25T19:32:07.661+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 14886 (ms) [java] 2014-11-25T21:32:17.503+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 29046 (ms) [java] 2014-11-25T22:31:59.308+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 10328 (ms) [java] 2014-11-25T22:47:17.483+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 29441 (ms) [java] 2014-11-26T00:02:20.766+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 31003 (ms) [java] 2014-11-26T14:32:41.533+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 49895 (ms) [java] 2014-11-26T14:47:01.686+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 13590 (ms) [java] 2014-11-26T15:01:59.900+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 10134 (ms) [java] 2014-11-26T15:16:58.646+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 10882 (ms) [java] 2014-11-26T15:46:56.920+0000 [main] gid: INFO com.xgen.svc.core.ServerMain [start:329] - Started mms in: 9591 (ms) [java] 2014-11-26T17:15:26.277+0000 [main] gid: ERROR com.xgen.svc.common.migration.MigrationRunner [run:183] - An unexpected error occurred: Didn't find DiskLoc in WiredTigerRecordStore
Finally, the expected shape of this document is:
{ "_id" : "DownloadBaseWindowsMigration", "status" : "COMPLETE", "numInserted" : 0, "numDeleted" : 0, "numUpdated" : 26, "startDate" : ISODate("2014-11-25T19:30:31.676Z"), "completedDate" : ISODate("2014-11-25T19:30:31.713Z") }
Please note that the -id is not an ObjectId.
- duplicates
-
SERVER-16351 Erroneous document returned in query (wt) (mms-dev)
- Closed
- is related to
-
SERVER-16649 mongos_rs_auth_shard_failure_tolerance.js should wait for writes to be replicated before shutting down the primary
- Closed