[SERVER-19180] Object update - Assertion: 10320:BSONElement: bad type -80 Created: 28/Jun/15  Updated: 30/Jul/15  Resolved: 30/Jul/15

Status: Closed
Project: Core Server
Component/s: Storage
Affects Version/s: 2.6.3
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Trace Webster Assignee: Ramon Fernandez Marina
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

CentOS release 6.5


Attachments: Zip Archive bad type -80.zip     Zip Archive mongodb-27727.zip    
Operating System: ALL
Participants:

 Description   

We have not been able to determine the cause of this yet. We are seeing this BSON error on an update after several hours into a longevity test.

2015-01-13T05:42:09.066+0530 [conn5732843] Assertion: 10320:BSONElement: bad type -80
2015-01-13T05:42:09.076+0530 [conn5732843] session_cache_3.session 0x11da801 0x117c9f9 0x11614b6 0x76fe6a 0xd2e38e 0xaa1fbf 0xaa3ec5 0xaa06dd 0xaa71bc 0xd6f36f 0xc443c9 0xc504b6 0xa05661 0xa05df0 0xa08cff 0xa0980d 0xa0d3ee 0xa2295a 0xa2431b 0xa26269 
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0x11da801]
 /usr/bin/mongod(_ZN5mongo10logContextEPKc+0x159) [0x117c9f9]
 /usr/bin/mongod(_ZN5mongo11msgassertedEiPKc+0xe6) [0x11614b6]
 /usr/bin/mongod(_ZNK5mongo11BSONElement4sizeEv+0x1ca) [0x76fe6a]
 /usr/bin/mongod(_ZN5mongo18IndexBoundsChecker8checkKeyERKNS_7BSONObjEPiPbPSt6vectorIPKNS_11BSONElementESaIS9_EEPS6_IbSaIbEE+0xfe) [0xd2e38e]
 /usr/bin/mongod(_ZN5mongo9IndexScan8checkEndEv+0x1cf) [0xaa1fbf]
 /usr/bin/mongod(_ZN5mongo9IndexScan4workEPm+0x6c5) [0xaa3ec5]
 /usr/bin/mongod(_ZN5mongo10FetchStage4workEPm+0xad) [0xaa06dd]
 /usr/bin/mongod(_ZN5mongo18KeepMutationsStage4workEPm+0x3c) [0xaa71bc]
 /usr/bin/mongod(_ZN5mongo12PlanExecutor7getNextEPNS_7BSONObjEPNS_7DiskLocE+0xef) [0xd6f36f]
 /usr/bin/mongod(_ZN5mongo6updateERKNS_13UpdateRequestEPNS_7OpDebugEPNS_12UpdateDriverEPNS_14CanonicalQueryE+0x9c9) [0xc443c9]
 /usr/bin/mongod(_ZN5mongo14UpdateExecutor7executeEv+0x66) [0xc504b6]
 /usr/bin/mongod() [0xa05661]
 /usr/bin/mongod(_ZN5mongo18WriteBatchExecutor10execUpdateERKNS_12BatchItemRefEPNS_7BSONObjEPPNS_16WriteErrorDetailE+0x80) [0xa05df0]
 /usr/bin/mongod(_ZN5mongo18WriteBatchExecutor11bulkExecuteERKNS_21BatchedCommandRequestEPSt6vectorIPNS_19BatchedUpsertDetailESaIS6_EEPS4_IPNS_16WriteErrorDetailESaISB_EE+0x1df) [0xa08cff]
 /usr/bin/mongod(_ZN5mongo18WriteBatchExecutor12executeBatchERKNS_21BatchedCommandRequestEPNS_22BatchedCommandResponseE+0x8cd) [0xa0980d]
 /usr/bin/mongod(_ZN5mongo8WriteCmd3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3de) [0xa0d3ee]
 /usr/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3a) [0xa2295a]
 /usr/bin/mongod(_ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0xfeb) [0xa2431b]
 /usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x6c9) [0xa26269]



 Comments   
Comment by Trace Webster [ 30/Jul/15 ]

Thank you for the investigation Ramon.

Will look into your suggestions.

Hopefully get it resolved.

Trace

Comment by Ramon Fernandez Marina [ 30/Jul/15 ]

trwebste, the error message you're seeing indicates data corruption, and the logs you uploaded show multiple unclean shutdowns of the server – which are very likely to be the cause of this corruption. Another common source of corruption are flaky disks, so you may want to check your system logs for storage errors, although the unclean server shutdowns are the primary suspect here.

Please consider re-syncing this node from a healthy primary or, if there's none, restore the affected data from backups. I'd strongly encourage you to review all other procedures around this node to prevent unclean shutdowns in the future.

Since I don't see evidence of a bug in the server I'm going to close this ticket. For MongoDB-related support discussion please post on the mongodb-user group or Stack Overflow with the mongodb tag, where your question will reach a larger audience. A question like this involving more discussion would be best posted on the mongodb-user group. See also our Technical Support page for additional support resources.

Regards,
Ramón.

Comment by Trace Webster [ 01/Jul/15 ]

We were able to reproduce with the verbose level at vvvv.

There are 4 files:
One for session ds5%3B334266%3B1744002549 (this overlaps conn54556 and conn50233)
Logging for just conn54558
Logging for just conn50233 (this has the bad type -80)
50 lines up and down for the bad type -80 error

Comment by Trace Webster [ 29/Jun/15 ]

Entire log showing 3 occurrences of the error:

Assertion: 10320:BSONElement: bad type -80

Comment by Trace Webster [ 29/Jun/15 ]

.
I'm seeing some other errors before one of these occurrences, including an invalid documents size. I have uploaded the entire log.

2015-06-21T18:10:46.781+0530 [conn1877] session_cache_4.session Assertion failure false src/mongo/db/structure/btree/key.cpp 433
2015-06-21T18:10:46.800+0530 [conn1877] session_cache_4.session 0x11da801 0x117c9f9 0x1160c1e 0xf1805b 0xb6d82a 0xb69e7d 0xaa1f97 0xaa3ec5 0xaa06dd 0xaa71bc 0xd6f36f 0xc443c9 0xc504b6 0xa05661 0xa05df0 0xa08cff 0xa0980d 0xa0d3ee 0xa2295a 0xa2431b 
 
2015-06-21T18:11:35.076+0530 [conn1893] Assertion: 10334:BSONObj size: -1342177280 (0xB0000000) is invalid. Size must be between 0 and 16793600(16MB) First element: r: ?type=64
2015-06-21T18:11:35.086+0530 [conn1893] session_cache_4.session 0x11da801 0x117c9f9 0x11614b6 0x1161a0c 0x770e4b 0xf17f58 0xb6d82a 0xb69e7d 0xaa1f97 0xaa3ec5 0xaa06dd 0xaa71bc 0xd6f36f 0xc443c9 0xc504b6 0xa05661 0xa05df0 0xa08cff 0xa0980d 0xa0d3ee 
 
2015-06-21T18:11:46.821+0530 [conn1937] Assertion: 10320:BSONElement: bad type -80
2015-06-21T18:11:46.832+0530 [conn1937] session_cache_4.session 0x11da801 0x117c9f9 0x11614b6 0x76fe6a 0xd2e38e 0xaa1fbf 0xaa38a7 0xaa06dd 0xaa71bc 0xd6f36f 0xc443c9 0xc504b6 0xa05661 0xa05df0 0xa08cff 0xa0980d 0xa0d3ee 0xa2295a 0xa2431b 0xa26269 

Comment by Trace Webster [ 29/Jun/15 ]

Thanks Ramon,

Here is a newer example of the same error, with more logging.

This is a replica set, with sharding. Set 11 (below in table) is session_cache_2 which we see in the error.

This error seems to be coming from the primary - sessionmgr02.

I am trying to coordinate a new test with mongo logging set to -vvvv. Anything more please ask and I will provide.

Is there anything I can use the '-80' to investigate?

SESSION:set11 |

Member-1 - 27727 : 172.20.8.54 - ARBITER - L1-S3-CA-ARB-sessionmgr15 - ON-LINE - -------- - 0
Member-2 - 27727 : 172.20.7.40 - PRIMARY - L1-CA-PRI-sessionmgr02 - ON-LINE - -------- - 4
Member-3 - 27727 : 172.20.7.38 - SECONDARY - L1-CA-PRI-sessionmgr01 - ON-LINE - 0 sec - 3
Member-4 - 27727 : 172.20.9.27 - SECONDARY - L1-CA-SEC-sessionmgr01 - ON-LINE - 0 sec - 2
Member-5 - 27727 : 172.20.9.29 - SECONDARY - L1-CA-SEC-sessionmgr02 - ON-LINE - 0 sec - 1

mmand session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:720 locks(micros) r:1686729 reslen:191 1816ms
2015-06-24T06:42:46.251+0530 [conn132567] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:679 locks(micros) r:1668397 reslen:191 1802ms
2015-06-24T06:42:47.929+0530 [conn132576] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:636 locks(micros) r:1521267 reslen:191 1671ms
2015-06-24T06:42:49.782+0530 [conn132578] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:684 locks(micros) r:1646985 reslen:191 1847ms
2015-06-24T06:42:51.457+0530 [conn132580] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:641 locks(micros) r:1600164 reslen:191 1669ms
2015-06-24T06:43:16.161+0530 [conn132602] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:683 locks(micros) r:1711887 reslen:191 1922ms
2015-06-24T06:43:17.926+0530 [conn132607] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:678 locks(micros) r:1566880 reslen:191 1758ms
2015-06-24T06:43:19.645+0530 [conn132609] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:657 locks(micros) r:1524326 reslen:191 1714ms
2015-06-24T06:43:21.337+0530 [conn132611] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:667 locks(micros) r:1555711 reslen:191 1685ms
2015-06-24T06:43:46.059+0530 [conn132633] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:676 locks(micros) r:1610426 reslen:191 1747ms
2015-06-24T06:43:47.677+0530 [conn132639] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:654 locks(micros) r:1487044 reslen:191 1609ms
2015-06-24T06:43:49.240+0530 [conn132646] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:638 locks(micros) r:1474431 reslen:191 1557ms
2015-06-24T06:43:51.008+0530 [conn132648] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:669 locks(micros) r:1615531 reslen:191 1761ms
2015-06-24T06:44:16.091+0530 [conn132671] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:678 locks(micros) r:1629542 reslen:191 1776ms
2015-06-24T06:44:17.847+0530 [conn132676] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:669 locks(micros) r:1663748 reslen:191 1750ms
2015-06-24T06:44:19.505+0530 [conn132678] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:671 locks(micros) r:1519516 reslen:191 1653ms
2015-06-24T06:44:21.242+0530 [conn132680] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:638 locks(micros) r:1582916 reslen:191 1731ms
2015-06-24T06:44:45.740+0530 [conn132703] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:689 locks(micros) r:1491059 reslen:191 1571ms
2015-06-24T06:44:47.421+0530 [conn132708] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:669 locks(micros) r:1527207 reslen:191 1666ms
2015-06-24T06:44:49.252+0530 [conn132715] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:676 locks(micros) r:1636528 reslen:191 1824ms
2015-06-24T06:44:51.032+0530 [conn132718] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:662 locks(micros) r:1611740 reslen:191 1774ms
2015-06-24T06:45:16.231+0530 [conn132753] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:668 locks(micros) r:1592298 reslen:191 1709ms
2015-06-24T06:45:17.913+0530 [conn132758] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:617 locks(micros) r:1543487 reslen:191 1675ms
2015-06-24T06:45:19.674+0530 [conn132760] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:668 locks(micros) r:1591713 reslen:191 1752ms
2015-06-24T06:45:21.395+0530 [conn132762] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:698 locks(micros) r:1605742 reslen:191 1714ms
2015-06-24T06:45:46.278+0530 [conn132785] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:621 locks(micros) r:1483266 reslen:191 1625ms
2015-06-24T06:45:48.183+0530 [conn132790] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:689 locks(micros) r:1722844 reslen:191 1899ms
2015-06-24T06:45:49.796+0530 [conn132797] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:640 locks(micros) r:1449071 reslen:191 1607ms
2015-06-24T06:45:51.419+0530 [conn132799] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:658 locks(micros) r:1550298 reslen:191 1615ms
2015-06-24T06:46:16.170+0530 [conn132823] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:694 locks(micros) r:1661062 reslen:191 1781ms
2015-06-24T06:46:17.672+0530 [conn132827] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:681 locks(micros) r:1349640 reslen:191 1497ms
2015-06-24T06:46:19.137+0530 [conn132829] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:621 locks(micros) r:1385413 reslen:191 1458ms
2015-06-24T06:46:20.839+0530 [conn132831] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:643 locks(micros) r:1582519 reslen:191 1695ms
2015-06-24T06:46:27.136+0530 [conn64943] Assertion: 10320:BSONElement: bad type -80
2015-06-24T06:46:27.153+0530 [conn64943] session_cache_2.session 0x11da801 0x117c9f9 0x11614b6 0x76fe6a 0xd2e38e 0xaa1fbf 0xaa3ec5 0xaa06dd 0xaa71bc 0xd6f36f 0xc443c9 0xc504b6 0xa05661 0xa05df0 0xa08cff 0xa0980d 0xa0d3ee 0xa2295a 0xa2431b 0xa26269
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0x11da801]
 /usr/bin/mongod(_ZN5mongo10logContextEPKc+0x159) [0x117c9f9]
 /usr/bin/mongod(_ZN5mongo11msgassertedEiPKc+0xe6) [0x11614b6]
 /usr/bin/mongod(_ZNK5mongo11BSONElement4sizeEv+0x1ca) [0x76fe6a]
 /usr/bin/mongod(_ZN5mongo18IndexBoundsChecker8checkKeyERKNS_7BSONObjEPiPbPSt6vectorIPKNS_11BSONElementESaIS9_EEPS6_IbSaIbEE+0xfe) [0xd2e38e]
 /usr/bin/mongod(_ZN5mongo9IndexScan8checkEndEv+0x1cf) [0xaa1fbf]
 /usr/bin/mongod(_ZN5mongo9IndexScan4workEPm+0x6c5) [0xaa3ec5]
 /usr/bin/mongod(_ZN5mongo10FetchStage4workEPm+0xad) [0xaa06dd]
 /usr/bin/mongod(_ZN5mongo18KeepMutationsStage4workEPm+0x3c) [0xaa71bc]
 /usr/bin/mongod(_ZN5mongo12PlanExecutor7getNextEPNS_7BSONObjEPNS_7DiskLocE+0xef) [0xd6f36f]
 /usr/bin/mongod(_ZN5mongo6updateERKNS_13UpdateRequestEPNS_7OpDebugEPNS_12UpdateDriverEPNS_14CanonicalQueryE+0x9c9) [0xc443c9]
 /usr/bin/mongod(_ZN5mongo14UpdateExecutor7executeEv+0x66) [0xc504b6]
 /usr/bin/mongod() [0xa05661]
 /usr/bin/mongod(_ZN5mongo18WriteBatchExecutor10execUpdateERKNS_12BatchItemRefEPNS_7BSONObjEPPNS_16WriteErrorDetailE+0x80) [0xa05df0]
 /usr/bin/mongod(_ZN5mongo18WriteBatchExecutor11bulkExecuteERKNS_21BatchedCommandRequestEPSt6vectorIPNS_19BatchedUpsertDetailESaIS6_EEPS4_IPNS_16WriteErrorDetailESaISB_EE+0x1df) [0xa08cff]
 /usr/bin/mongod(_ZN5mongo18WriteBatchExecutor12executeBatchERKNS_21BatchedCommandRequestEPNS_22BatchedCommandResponseE+0x8cd) [0xa0980d]
 /usr/bin/mongod(_ZN5mongo8WriteCmd3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3de) [0xa0d3ee]
 /usr/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3a) [0xa2295a]
 /usr/bin/mongod(_ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0xfeb) [0xa2431b]
 /usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x6c9) [0xa26269]
2015-06-24T06:46:46.230+0530 [conn132855] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:697 locks(micros) r:1671478 reslen:191 1785ms
2015-06-24T06:46:47.954+0530 [conn132859] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:660 locks(micros) r:1593945 reslen:191 1713ms
2015-06-24T06:46:49.668+0530 [conn132865] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:667 locks(micros) r:1588727 reslen:191 1708ms
2015-06-24T06:46:51.238+0530 [conn132868] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:605 locks(micros) r:1465587 reslen:191 1564ms
2015-06-24T06:47:16.102+0530 [conn132890] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:686 locks(micros) r:1616583 reslen:191 1776ms
2015-06-24T06:47:18.009+0530 [conn132894] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:710 locks(micros) r:1680862 reslen:191 1900ms
2015-06-24T06:47:19.733+0530 [conn132896] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:651 locks(micros) r:1561421 reslen:191 1717ms
2015-06-24T06:47:21.455+0530 [conn132899] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:718 locks(micros) r:1617272 reslen:191 1716ms
2015-06-24T06:47:46.268+0530 [conn132921] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:618 locks(micros) r:1491769 reslen:191 1587ms
2015-06-24T06:47:47.909+0530 [conn132925] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:648 locks(micros) r:1548927 reslen:191 1634ms
2015-06-24T06:47:49.685+0530 [conn132928] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:635 locks(micros) r:1627108 reslen:191 1769ms
2015-06-24T06:47:51.346+0530 [conn132935] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:640 locks(micros) r:1531725 reslen:191 1652ms
2015-06-24T06:48:16.199+0530 [conn132957] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:690 locks(micros) r:1705901 reslen:191 1890ms
2015-06-24T06:48:18.014+0530 [conn132961] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:721 locks(micros) r:1674459 reslen:191 1810ms
2015-06-24T06:48:19.585+0530 [conn132963] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:642 locks(micros) r:1482568 reslen:191 1566ms
2015-06-24T06:48:21.218+0530 [conn132966] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:646 locks(micros) r:1520287 reslen:191 1618ms
2015-06-24T06:48:45.946+0530 [conn132988] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:697 locks(micros) r:1448377 reslen:191 1586ms
2015-06-24T06:48:47.762+0530 [conn132992] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:679 locks(micros) r:1689002 reslen:191 1809ms
2015-06-24T06:48:49.421+0530 [conn132994] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:653 locks(micros) r:1553935 reslen:191 1650ms
2015-06-24T06:48:50.983+0530 [conn133001] command session_cache_4.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:605 locks(micros) r:1478233 reslen:191 1557ms
2015-06-24T06:49:15.889+0530 [conn133023] command session_cache.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:710 locks(micros) r:1554757 reslen:191 1689ms
2015-06-24T06:49:17.643+0530 [conn133027] command session_cache_2.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:707 locks(micros) r:1611003 reslen:191 1749ms
2015-06-24T06:49:19.236+0530 [conn133029] command session_cache_3.$cmd command: aggregate { aggregate: "session", pipeline: [ { $project: { _types: 1 } }, { $unwind: "$_types" }, { $group: { _id: "$_types", count: { $sum: 1 } } } ] } keyUpdates:0 numYields:648 locks(micros) r:1492969 reslen:191 1587ms

Comment by Ramon Fernandez Marina [ 29/Jun/15 ]

trwebste, may be helpful to see 50-100 lines of logs before and after this message, could you please upload more detailed logs? Also, can you please provide some information about your setup: is this a stand-alone node, a replica set, etc., and on which node do you see the stack trace above?

Thanks,
Ramón.

Generated at Thu Feb 08 03:50:04 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.