[SERVER-78734] shard mongod process crashes with "Invalid access at address: 0x55d2c1394000" within __wt_evict call Created: 06/Jul/23  Updated: 06/Dec/23  Resolved: 06/Dec/23

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

Type: Bug Priority: Major - P3
Reporter: Ian Springer Assignee: Chris Kelly
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

We are running a v5.0.15 sharded cluster with 20 shards and 5 replicas per shard. This morning a shard mongod process crashed for a secondary. Here's what was logged just prior to the process dying:

{"t":{"$date":"2023-07-06T11:45:23.795+00:00"},"s":"F",  "c":"CONTROL",  "id":6384300, "ctx":"thread574967","msg":"Writing fatal message","attr":{"message":"Invalid access at address: 0x55d2c1394000\n"}}
{"t":{"$date":"2023-07-06T11:45:23.795+00:00"},"s":"F",  "c":"CONTROL",  "id":6384300, "ctx":"thread574967","msg":"Writing fatal message","attr":{"message":"Got signal: 7 (Bus error).\n"}}
{"t":{"$date":"2023-07-06T11:45:23.960+00:00"},"s":"I",  "c":"CONTROL",  "id":31380,   "ctx":"thread574967","msg":"BACKTRACE","attr":{"bt":{"backtrace":[{"a":"55CF4D853455","b":"55CF49927000","o":"3F2C455","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.361","s+":"215"},{"a":"55CF4D855ED9","b":"55CF49927000","o":"3F2EED9","s":"_ZN5mongo15printStackTraceEv","s+":"29"},{"a":"55CF4D84E44C","b":"55CF49927000","o":"3F2744C","s":"abruptQuitWithAddrSignal","s+":"EC"},{"a":"7F0F131C88E0","b":"7F0F131B7000","o":"118E0","s":"funlockfile","s+":"50"},{"a":"55CF4B08B11C","b":"55CF49927000","o":"176411C","s":"__wt_cell_unpack_safe.constprop.11","s+":"9C"},{"a":"55CF4B0935A2","b":"55CF49927000","o":"176C5A2","s":"__wt_page_inmem","s+":"3532"},{"a":"55CF4B0AC96D","b":"55CF49927000","o":"178596D","s":"__split_multi_inmem","s+":"5D"},{"a":"55CF4B0B728B","b":"55CF49927000","o":"179028B","s":"__wt_split_rewrite","s+":"AB"},{"a":"55CF4AFDAE66","b":"55CF49927000","o":"16B3E66","s":"__wt_evict","s+":"10D6"},{"a":"55CF4AFD1F42","b":"55CF49927000","o":"16AAF42","s":"__evict_page","s+":"6A2"},{"a":"55CF4AFD2808","b":"55CF49927000","o":"16AB808","s":"__evict_lru_pages","s+":"78"},{"a":"55CF4AFD7524","b":"55CF49927000","o":"16B0524","s":"__wt_evict_thread_run","s+":"74"},{"a":"55CF4B03D8D9","b":"55CF49927000","o":"17168D9","s":"__thread_run","s+":"39"},{"a":"7F0F131BE44B","b":"7F0F131B7000","o":"744B","s":"start_thread","s+":"DB"},{"a":"7F0F12EF952F","b":"7F0F12E0A000","o":"EF52F","s":"clone","s+":"3F"}],"processInfo":{"mongodbVersion":"5.0.15","gitVersion":"935639beed3d0c19c2551c93854b831107c0b118","compiledModules":[],"uname":{"sysname":"Linux","release":"4.14.314-238.539.amzn2.x86_64","version":"#1 SMP Tue May 23 16:44:05 UTC 2023","machine":"x86_64"},"somap":[{"b":"55CF49927000","elfType":3,"buildId":"11A652B403DB0E37E9EAC8044BD6400062B20A1E"},{"b":"7F0F131B7000","path":"/lib64/libpthread.so.0","elfType":3,"buildId":"BC2E8D5CDFB0A3CC6DB42A136DD1BB61AF8EED99"},{"b":"7F0F12E0A000","path":"/lib64/libc.so.6","elfType":3,"buildId":"140E425DB38E5E4C2BFA7E56F3609E707B850AC5"}]}}}}
{"t":{"$date":"2023-07-06T11:45:23.960+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4D853455","b":"55CF49927000","o":"3F2C455","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.361","s+":"215"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4D855ED9","b":"55CF49927000","o":"3F2EED9","s":"_ZN5mongo15printStackTraceEv","s+":"29"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4D84E44C","b":"55CF49927000","o":"3F2744C","s":"abruptQuitWithAddrSignal","s+":"EC"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"7F0F131C88E0","b":"7F0F131B7000","o":"118E0","s":"funlockfile","s+":"50"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4B08B11C","b":"55CF49927000","o":"176411C","s":"__wt_cell_unpack_safe.constprop.11","s+":"9C"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4B0935A2","b":"55CF49927000","o":"176C5A2","s":"__wt_page_inmem","s+":"3532"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4B0AC96D","b":"55CF49927000","o":"178596D","s":"__split_multi_inmem","s+":"5D"}}}{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4B0B728B","b":"55CF49927000","o":"179028B","s":"__wt_split_rewrite","s+":"AB"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4AFDAE66","b":"55CF49927000","o":"16B3E66","s":"__wt_evict","s+":"10D6"}}}
{"t":{"$date":"2023-07-06T11:45:23.961+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4AFD1F42","b":"55CF49927000","o":"16AAF42","s":"__evict_page","s+":"6A2"}}}
{"t":{"$date":"2023-07-06T11:45:23.962+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4AFD2808","b":"55CF49927000","o":"16AB808","s":"__evict_lru_pages","s+":"78"}}}
{"t":{"$date":"2023-07-06T11:45:23.962+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4AFD7524","b":"55CF49927000","o":"16B0524","s":"__wt_evict_thread_run","s+":"74"}}}
{"t":{"$date":"2023-07-06T11:45:23.962+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"55CF4B03D8D9","b":"55CF49927000","o":"17168D9","s":"__thread_run","s+":"39"}}}
{"t":{"$date":"2023-07-06T11:45:23.962+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"7F0F131BE44B","b":"7F0F131B7000","o":"744B","s":"start_thread","s+":"DB"}}}
{"t":{"$date":"2023-07-06T11:45:23.962+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread574967","msg":"Frame","attr":{"frame":{"a":"7F0F12EF952F","b":"7F0F12E0A000","o":"EF52F","s":"clone","s+":"3F"}}}

It appears the crash is related to WiredTiger code:

__wt_evict -> __wt_split_rewrite -> __wt_cell_unpack_safe.constprop

I was able to restart the mongod process without issues.

We have never encountered this before as far as I know, so it is likely something that only occurs occasionally (e.g. maybe a concurrency timing issue).



 Comments   
Comment by Chris Kelly [ 06/Dec/23 ]

We haven’t heard back from you for some time, so I’m going to close this ticket. If this is still an issue for you, please provide additional information and we will reopen the ticket.

Comment by Chris Kelly [ 18/Jul/23 ]

Thanks for the report and extra context ian.springer@salesforce.com. At first glance this appears to be due to hardware issues, and I don't suspect we will derive much further information from the stack trace alone. 

If this is still a problem for you, and you still have data available from the incident, I've created a secure upload portal for you share some diagnostic information. Files uploaded to this portal are hosted on Box, are visible only to MongoDB employees, and are routinely deleted after some time.

For each node in the replica set spanning a time period that includes the incident, would you please archive (tar or zip) and upload to that link:

  • the mongod logs
  • the $dbpath/diagnostic.data directory (the contents are described here)

In this case we see pretty normal WT activity (page eviction and reconciliation) which indicate memory was likely attempted to be written to the disk, and ran into a low level problem of some sort. The detection from AWS seems pretty convincing of this case, but if it continues we would definitely like to gather more information.

 

Christopher

Comment by Ian Springer [ 07/Jul/23 ]

A second `mongod` process crashed this morning with an "Invalid access at address" error and a similar stack trace:

{"t":{"$date":"2023-07-07T08:40:38.608+00:00"},"s":"F",  "c":"CONTROL",  "id":6384300, "ctx":"thread592522","msg":"Writing fatal message","attr":{"message":"Invalid access at address: 0x563b4a148000\n"}}
{"t":{"$date":"2023-07-07T08:40:38.609+00:00"},"s":"F",  "c":"CONTROL",  "id":6384300, "ctx":"thread592522","msg":"Writing fatal message","attr":{"message":"Got signal: 7 (Bus error).\n"}}
{"t":{"$date":"2023-07-07T08:40:38.709+00:00"},"s":"I",  "c":"CONTROL",  "id":31380,   "ctx":"thread592522","msg":"BACKTRACE","attr":{"bt":{"backtrace":[{"a":"5632651FD455","b":"5632612D1000","o":"3F2C455","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.361","s+":"215"},{"a":"5632651FFED9","b":"5632612D1000","o":"3F2EED9","s":"_ZN5mongo15printStackTraceEv","s+":"29"},{"a":"5632651F844C","b":"5632612D1000","o":"3F2744C","s":"abruptQuitWithAddrSignal","s+":"EC"},{"a":"7FBB501B98E0","b":"7FBB501A8000","o":"118E0","s":"funlockfile","s+":"50"},{"a":"7FBB4FF48BCF","b":"7FBB4FDFB000","o":"14DBCF","s":"__memmove_avx_unaligned_erms","s+":"4F"},{"a":"563262AEF53F","b":"5632612D1000","o":"181E53F","s":"__wt_rec_row_leaf","s+":"12FF"},{"a":"5632629B88B6","b":"5632612D1000","o":"16E78B6","s":"__wt_reconcile","s+":"1236"},{"a":"56326298459C","b":"5632612D1000","o":"16B359C","s":"__wt_evict","s+":"80C"},{"a":"56326297BF42","b":"5632612D1000","o":"16AAF42","s":"__evict_page","s+":"6A2"},{"a":"56326297C808","b":"5632612D1000","o":"16AB808","s":"__evict_lru_pages","s+":"78"},{"a":"563262981524","b":"5632612D1000","o":"16B0524","s":"__wt_evict_thread_run","s+":"74"},{"a":"5632629E78D9","b":"5632612D1000","o":"17168D9","s":"__thread_run","s+":"39"},{"a":"7FBB501AF44B","b":"7FBB501A8000","o":"744B","s":"start_thread","s+":"DB"},{"a":"7FBB4FEEA52F","b":"7FBB4FDFB000","o":"EF52F","s":"clone","s+":"3F"}],"processInfo":{"mongodbVersion":"5.0.15","gitVersion":"935639beed3d0c19c2551c93854b831107c0b118","compiledModules":[],"uname":{"sysname":"Linux","release":"4.14.314-238.539.amzn2.x86_64","version":"#1 SMP Tue May 23 16:44:05 UTC 2023","machine":"x86_64"},"somap":[{"b":"5632612D1000","elfType":3,"buildId":"11A652B403DB0E37E9EAC8044BD6400062B20A1E"},{"b":"7FBB501A8000","path":"/lib64/libpthread.so.0","elfType":3,"buildId":"BC2E8D5CDFB0A3CC6DB42A136DD1BB61AF8EED99"},{"b":"7FBB4FDFB000","path":"/lib64/libc.so.6","elfType":3,"buildId":"140E425DB38E5E4C2BFA7E56F3609E707B850AC5"}]}}}}
{"t":{"$date":"2023-07-07T08:40:38.709+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"5632651FD455","b":"5632612D1000","o":"3F2C455","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.361","s+":"215"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"5632651FFED9","b":"5632612D1000","o":"3F2EED9","s":"_ZN5mongo15printStackTraceEv","s+":"29"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"5632651F844C","b":"5632612D1000","o":"3F2744C","s":"abruptQuitWithAddrSignal","s+":"EC"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"7FBB501B98E0","b":"7FBB501A8000","o":"118E0","s":"funlockfile","s+":"50"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"7FBB4FF48BCF","b":"7FBB4FDFB000","o":"14DBCF","s":"__memmove_avx_unaligned_erms","s+":"4F"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"563262AEF53F","b":"5632612D1000","o":"181E53F","s":"__wt_rec_row_leaf","s+":"12FF"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"5632629B88B6","b":"5632612D1000","o":"16E78B6","s":"__wt_reconcile","s+":"1236"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"56326298459C","b":"5632612D1000","o":"16B359C","s":"__wt_evict","s+":"80C"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"56326297BF42","b":"5632612D1000","o":"16AAF42","s":"__evict_page","s+":"6A2"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"56326297C808","b":"5632612D1000","o":"16AB808","s":"__evict_lru_pages","s+":"78"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"563262981524","b":"5632612D1000","o":"16B0524","s":"__wt_evict_thread_run","s+":"74"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"5632629E78D9","b":"5632612D1000","o":"17168D9","s":"__thread_run","s+":"39"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"7FBB501AF44B","b":"7FBB501A8000","o":"744B","s":"start_thread","s+":"DB"}}}
{"t":{"$date":"2023-07-07T08:40:38.710+00:00"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"thread592522","msg":"Frame","attr":{"frame":{"a":"7FBB4FEEA52F","b":"7FBB4FDFB000","o":"EF52F","s":"clone","s+":"3F"}}}

About an hour layer, we received the following message from AWS:

EC2 has detected degradation of the underlying hardware hosting your Amazon EC2 instance (instance-ID: XXX) associated with your AWS account (AWS Account ID: XXX) in the eu-central-1 region. Due to this degradation your instance could already be unreachable. We will stop your instance after 2023-07-21 10:00:00 UTC. Please take appropriate action before this time.

So at this point it seems highly likely that both crashes were due to hardware failures (probably memory).

Comment by Ian Springer [ 07/Jul/23 ]

We received the following message from AWS yesterday in regards to the instance where the mongod process crashed:

One or more of your Amazon EC2 instances associated with your AWS account (AWS Account ID: XXX) are scheduled for maintenance that requires your instances to be retired on 2023-07-20. The following instances in the eu-central-1 region will be stopped after 2023-07-20 18:00:00 UTC.

They sent the message about 6 hours after the mongod process crashed.

So it seems likely the crash was due to hardware issues (I'm guessing memory failure).

Generated at Thu Feb 08 06:39:06 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.