Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-37394

Invariant failure deadline != Date_t::max() or Invariant failure date.isFormattable()

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Critical - P2 Critical - P2
    • 4.0.4, 4.1.4
    • Affects Version/s: 4.0.2, 4.1.3
    • Component/s: Storage
    • Labels:
      None
    • Fully Compatible
    • ALL
    • v4.0
    • Storage NYC 2018-10-08
    • 39

      This happened in association with invariant seen in SERVER-36907

       

      2018-09-25T23:08:09.928+0000 I TXN      [conn14199] transaction parameters:{ lsid: { id: UUID("6c142ca8-c236-413b-9bc7-020f9e34e10f"), uid: BinData(0, F61FC3336B290B6276B4475A10D1179C7858CC3544AE78465DB782A7F2913A2F) }, txnNumber: 9, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(1537916889, 1456), keysExamined:55 docsExamined:28 nMatched:1 nModified:1 ninserted:15 keysInserted:45 keysDeleted:1 terminationCause:committed timeActiveMicros:66481 timeInactiveMicros:41055 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 9 } }, oplog: { acquireCount: { w: 1 } } } 107ms
2018-09-25T23:08:09.955+0000 F -        [conn14082] Got signal: 6 (Aborted).

----- BEGIN BACKTRACE -----
 mongod(_ZN5mongo15printStackTraceERSo+0x41) [0x559d411f3731]
 mongod(+0x247E949) [0x559d411f2949]
 mongod(+0x247EE2D) [0x559d411f2e2d]
 libpthread.so.0(+0xF6D0) [0x7f57dea0a6d0]
 libc.so.6(gsignal+0x37) [0x7f57de664277]
 libc.so.6(abort+0x148) [0x7f57de665968]
 mongod(_ZN5mongo22invariantFailedWithMsgEPKcRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEES1_j+0x0) [0x559d3f798dec]
 mongod(+0x2487121) [0x559d411fb121]
 mongod(_ZN5mongo20dateToISOStringLocalB5cxx11ENS_6Date_tE+0x31) [0x559d411fb881]
 mongod(+0x9E75A4) [0x559d3f75b5a4]
 mongod(_ZN5mongo9AutoGetDbC2EPNS_16OperationContextENS_10StringDataENS_8LockModeENS_6Date_tE+0x2AF) [0x559d4073be1f]
 mongod(_ZN5mongo17AutoGetCollectionC2EPNS_16OperationContextERKNS_21NamespaceStringOrUUIDENS_8LockModeES6_NS0_8ViewModeENS_6Date_tE+0x12C) [0x559d4073c10c]
 mongod(+0x109F6DA) [0x559d3fe136da]
 mongod(+0x10A0FFC) [0x559d3fe14ffc]
 mongod(_ZN5mongo12BasicCommand10Invocation3runEPNS_16OperationContextEPNS_19CommandReplyBuilderE+0xD9) [0x559d40c48359]
 mongod(+0xB40A1F) [0x559d3f8b4a1f]
 mongod(+0xB4364E) [0x559d3f8b764e]
 mongod(+0xB451A9) [0x559d3f8b91a9]
 mongod(_ZN5mongo23ServiceEntryPointCommon13handleRequestEPNS_16OperationContextERKNS_7MessageERKNS0_5HooksE+0x3D1) [0x559d3f8ba0f1]
 mongod(_ZN5mongo23ServiceEntryPointMongod13handleRequestEPNS_16OperationContextERKNS_7MessageE+0x3A) [0x559d3f8a772a]
 mongod(_ZN5mongo19ServiceStateMachine15_processMessageENS0_11ThreadGuardE+0xBA) [0x559d3f8b247a]
 mongod(_ZN5mongo19ServiceStateMachine15_runNextInGuardENS0_11ThreadGuardE+0x97) [0x559d3f8ad137]
 mongod(+0xB3C941) [0x559d3f8b0941]
 mongod(_ZN5mongo9transport26ServiceExecutorSynchronous8scheduleESt8functionIFvvEENS0_15ServiceExecutor13ScheduleFlagsENS0_23ServiceExecutorTaskNameE+0x1A2) [0x559d40a7ba72]
 mongod(_ZN5mongo19ServiceStateMachine22_scheduleNextWithGuardENS0_11ThreadGuardENS_9transport15ServiceExecutor13ScheduleFlagsENS2_23ServiceExecutorTaskNameENS0_9OwnershipE+0x15F) [0x559d3f8ab34f]
 mongod(_ZN5mongo19ServiceStateMachine15_sourceCallbackENS_6StatusE+0xAF5) [0x559d3f8ae4e5]
 mongod(_ZN5mongo19ServiceStateMachine14_sourceMessageENS0_11ThreadGuardE+0x357) [0x559d3f8ac877]
 mongod(_ZN5mongo19ServiceStateMachine15_runNextInGuardENS0_11ThreadGuardE+0x11D) [0x559d3f8ad1bd]
 mongod(+0xB3C941) [0x559d3f8b0941]
 mongod(+0x1D07FD5) [0x559d40a7bfd5]
 mongod(+0x23D8704) [0x559d4114c704]
 libpthread.so.0(+0x7E25) [0x7f57dea02e25]
 libc.so.6(clone+0x6D) [0x7f57de72cbad]
-----  END BACKTRACE  -----
2018-09-25T23:08:13.711+0000 I CONTROL  [main] ***** SERVER RESTARTED *****

      In addition earlier in the logs there were a bunch of instances of this error:

      2018-09-25T23:08:09.593+0000 I TXN      [conn14160] transaction parameters:{ lsid: { id: UUID("03f47376-630a-4b58-b1c3-e788fb1c0ed6"), uid: BinData(0, F61FC3336B290B6276B4475A10D1179C7858CC3544AE78465DB782A7F2913A2F) }, txnNumber: 4, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(1537916889, 714), keysExamined:8 docsExamined:1 nMatched:1 nModified:1 terminationCause:committed timeActiveMicros:5833 timeInactiveMicros:99574 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 5 } }, oplog: { acquireCount: { w: 1 } } } 105ms
2018-09-25T23:08:09.645+0000 F -        [conn14082] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.645+0000 F -        [conn14082] 

***aborting after invariant() failure


2018-09-25T23:08:09.648+0000 F -        [conn14091] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.648+0000 F -        [conn14091] 

***aborting after invariant() failure


2018-09-25T23:08:09.648+0000 F -        [conn14071] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.648+0000 F -        [conn14071] 

***aborting after invariant() failure


2018-09-25T23:08:09.649+0000 F -        [conn13867] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.649+0000 F -        [conn13867] 

***aborting after invariant() failure


2018-09-25T23:08:09.650+0000 F -        [conn13925] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.650+0000 F -        [conn13925] 

***aborting after invariant() failure


2018-09-25T23:08:09.655+0000 F -        [conn13862] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.655+0000 F -        [conn13862] 

***aborting after invariant() failure


2018-09-25T23:08:09.656+0000 F -        [conn14214] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.656+0000 F -        [conn14186] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.656+0000 F -        [conn14214] 

***aborting after invariant() failure


2018-09-25T23:08:09.656+0000 F -        [conn14186] 

***aborting after invariant() failure


2018-09-25T23:08:09.657+0000 F -        [conn14097] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.657+0000 F -        [conn14068] Invariant failure date.isFormattable() src/mongo/util/time_support.cpp 148
2018-09-25T23:08:09.657+0000 F -        [conn14097] 

***aborting after invariant() failure


2018-09-25T23:08:09.657+0000 F -        [conn14068] 

***aborting after invariant() failure


2018-09-25T23:08:09.658+0000 I TXN      [conn14183] transaction parameters:{ lsid: { id: UUID("f648d6ea-4962-4f64-8b37-239ad3e33274"), uid: BinData(0, F61FC3336B290B6276B4475A10D1179C7858CC3544AE78465DB782A7F2913A2F) }, txnNumber: 3, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(1537916889, 611), keysExamined:59 docsExamined:30 nMatched:1 nModified:1 ninserted:16 keysInserted:48 keysDeleted:1 terminationCause:committed timeActiveMicros:121303 timeInactiveMicros:93804 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 9 } }, oplog: { acquireCount: { w: 1 } } } 215ms

            Assignee:
            milkie@mongodb.com Eric Milkie
            Reporter:
            asya.kamsky@mongodb.com Asya Kamsky
            Votes:
            0 Vote for this issue
            Watchers:
            9 Start watching this issue

              Created:
              Updated:
              Resolved: