[SERVER-65095] Crash MongoDB: Invalid access at address: 0xe8 Created: 30/Mar/22  Updated: 17/Apr/22  Resolved: 17/Apr/22

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

Type: Bug Priority: Major - P3
Reporter: Libelula Soft Assignee: Dmitry Agranat
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-65096 Crash MongoDB: Invalid access at addr... Closed
is duplicated by WT-4032 parent pages can be evicted while bei... Closed
Operating System: ALL
Participants:

 Description   

My mongodb randomly stop working, it's showing the next message:

 

2022-03-30T15:33:28.798+0000 F - [thread1474518] Invalid access at address: 0xe8
2022-03-30T15:33:28.843+0000 F - [thread1474518] Got signal: 11 (Segmentation fault).
0x5601d6b2a681 0x5601d6b29899 0x5601d6b29f06 0x7fd4dc1550c0 0x5601d544ecef 0x5601d5451c6b 0x5601d53dc064 0x5601d53dd0b2 0x5601d53d6083 0x5601d53d6417 0x5601d53d87f2 0x5601d5421a49 0x7fd4dc14b494 0x7fd4dbe8daff

 

 

*Error details*

 

2022-03-30T15:33:28.798+0000 F - [thread1474518] Invalid access at address: 0xe8
2022-03-30T15:33:28.843+0000 F - [thread1474518] Got signal: 11 (Segmentation fault).
0x5601d6b2a681 0x5601d6b29899 0x5601d6b29f06 0x7fd4dc1550c0 0x5601d544ecef 0x5601d5451c6b 0x5601d53dc064 0x5601d53dd0b2 0x5601d53d6083 0x5601d53d6417 0x5601d53d87f2 0x5601d5421a49 0x7fd4dc14b494 0x7fd4dbe8daff
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"5601D497C000","o":"21AE681","s":"_ZN5mongo15printStackTraceERSo"},{"b":"5601D497C000","o":"21AD899"},{"b":"5601D497C000","o":"21ADF06"},{"b":"7FD4DC144000","o":"110C0"},{"b":"5601D497C000","o":"AD2CEF"},{"b":"5601D497C000","o":"AD5C6B","s":"__wt_split_reverse"},{"b":"5601D497C000","o":"A60064"},{"b":"5601D497C000","o":"A610B2","s":"__wt_evict"},{"b":"5601D497C000","o":"A5A083"},{"b":"5601D497C000","o":"A5A417"},{"b":"5601D497C000","o":"A5C7F2","s":"__wt_evict_thread_run"},{"b":"5601D497C000","o":"AA5A49"},{"b":"7FD4DC144000","o":"7494"},{"b":"7FD4DBDA5000","o":"E8AFF","s":"clone"}],"processInfo":{ "mongodbVersion" : "3.6.2", "gitVersion" : "489d177dbd0f0420a8ca04d39fd78d0a2c539420", "compiledModules" : [], "uname" : { "sysname" : "Linux", "release" : "4.9.0-5-amd64", "version" : "#1 SMP Debian 4.9.65-3+deb9u2 (2018-01-04)", "machine" : "x86_64" }, "somap" : [ { "b" : "5601D497C000", "elfType" : 3, "buildId" : "454A81637B4013AE082538A57B34F8A42B39277A" }, { "b" : "7FFCD4BFD000", "path" : "linux-vdso.so.1", "elfType" : 3, "buildId" : "FDF4C2A8DC28984D2E8CA08A2F7DE983C5B12ED4" }, { "b" : "7FD4DCC88000", "path" : "/lib/x86_64-linux-gnu/libresolv.so.2", "elfType" : 3, "buildId" : "1F8BBD45EFD498F52135C7F5B4F856577D5A4997" }, { "b" : "7FD4DCA80000", "path" : "/lib/x86_64-linux-gnu/librt.so.1", "elfType" : 3, "buildId" : "FE41526A83999F2FE9D0F8AADCD61D03A92CBB70" }, { "b" : "7FD4DC87C000", "path" : "/lib/x86_64-linux-gnu/libdl.so.2", "elfType" : 3, "buildId" : "6A5D98612129B8186F21E800AFDFAAA627082F46" }, { "b" : "7FD4DC578000", "path" : "/lib/x86_64-linux-gnu/libm.so.6", "elfType" : 3, "buildId" : "90DA054E12EA1A53EE0CBB5BB5E65F7069AEEE44" }, { "b" : "7FD4DC361000", "path" : "/lib/x86_64-linux-gnu/libgcc_s.so.1", "elfType" : 3, "buildId" : "51AD5FD294CD6C813BED40717347A53434B80B7A" }, { "b" : "7FD4DC144000", "path" : "/lib/x86_64-linux-gnu/libpthread.so.0", "elfType" : 3, "buildId" : "968DF33F83963B559243653D74D27D89605BED02" }, { "b" : "7FD4DBDA5000", "path" : "/lib/x86_64-linux-gnu/libc.so.6", "elfType" : 3, "buildId" : "79450F6E36287865D093EA209B85A222209925FF" }, { "b" : "7FD4DCE9F000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "6F150F33B150D6A81E26A425DD47D713D00F2D29" } ] }}
 mongod(_ZN5mongo15printStackTraceERSo+0x41) [0x5601d6b2a681]
 mongod(+0x21AD899) [0x5601d6b29899]
 mongod(+0x21ADF06) [0x5601d6b29f06]
 libpthread.so.0(+0x110C0) [0x7fd4dc1550c0]
 mongod(+0xAD2CEF) [0x5601d544ecef]
 mongod(__wt_split_reverse+0x11B) [0x5601d5451c6b]
 mongod(+0xA60064) [0x5601d53dc064]
 mongod(__wt_evict+0xFE2) [0x5601d53dd0b2]
 mongod(+0xA5A083) [0x5601d53d6083]
 mongod(+0xA5A417) [0x5601d53d6417]
 mongod(__wt_evict_thread_run+0x72) [0x5601d53d87f2]
 mongod(+0xAA5A49) [0x5601d5421a49]
 libpthread.so.0(+0x7494) [0x7fd4dc14b494]
 libc.so.6(clone+0x3F) [0x7fd4dbe8daff]
----- END BACKTRACE -----
about to fork child process, waiting until server is ready for connections.
forked process: 955
2022-03-30T15:45:12.175+0000 I CONTROL [main] ***** SERVER RESTARTED *****
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] MongoDB starting : pid=955 port=27017 dbpath=/opt/bitnami/mongodb/data/db 64-bit host=ip-172-XX-XX-XX
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] db version v3.6.2
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] git version: 489d177dbd0f0420a8ca04d39fd78d0a2c539420
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] allocator: tcmalloc
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] modules: none
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] build environment:
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] distarch: x86_64
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] target_arch: x86_64
2022-03-30T15:45:12.203+0000 I CONTROL [initandlisten] options: { config: "/opt/bitnami/mongodb/mongodb.conf", net: { bindIp: "0.0.0.0", port: 27017, unixDomainSocket: { filePermissions: 502, pathPrefix: "/opt/bitnami/mongodb/tmp" } }, processManagement: { fork: true, pidFilePath: "/opt/bitnami/mongodb/tmp/mongodb.pid" }, security: { authorization: "enabled" }, setParameter: { enableLocalhostAuthBypass: "0" }, storage: { dbPath: "/opt/bitnami/mongodb/data/db", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/opt/bitnami/mongodb/log/mongodb.log" } }
2022-03-30T15:45:12.204+0000 I - [initandlisten] Detected data files in /opt/bitnami/mongodb/data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2022-03-30T15:45:12.204+0000 I STORAGE [initandlisten] 
2022-03-30T15:45:12.204+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2022-03-30T15:45:12.204+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
2022-03-30T15:45:12.214+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=122416M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
2022-03-30T15:45:12.681+0000 I STORAGE [initandlisten] WiredTiger message [1648655112:681179][955:0x7f011f1ab9c0], txn-recover: Main recovery loop: starting at 77581/103006592
2022-03-30T15:45:12.681+0000 I STORAGE [initandlisten] WiredTiger message [1648655112:681704][955:0x7f011f1ab9c0], txn-recover: Recovering log 77581 through 77583
2022-03-30T15:45:13.230+0000 I STORAGE [initandlisten] WiredTiger message [1648655113:230033][955:0x7f011f1ab9c0], file:index-238-6855356270873914551.wt, txn-recover: Recovering log 77582 through 77583
2022-03-30T15:45:14.211+0000 I STORAGE [initandlisten] WiredTiger message [1648655114:211349][955:0x7f011f1ab9c0], file:index-15-3584316417324618104.wt, txn-recover: Recovering log 77583 through 77583
2022-03-30T15:45:18.640+0000 I STORAGE [initandlisten] 
2022-03-30T15:45:18.640+0000 I STORAGE [initandlisten] ** WARNING: This server is using MONGODB-CR, a deprecated authentication mechanism.
2022-03-30T15:45:18.640+0000 I STORAGE [initandlisten] ** Support will be dropped in a future release.
2022-03-30T15:45:18.640+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/3.0-upgrade-to-scram-sha-1
2022-03-30T15:45:18.643+0000 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/opt/bitnami/mongodb/data/db/diagnostic.data'
2022-03-30T15:45:18.649+0000 I NETWORK [initandlisten] waiting for connections on port 27017 child process started successfully, parent exiting
2022-03-30T15:45:18.674+0000 I NETWORK [listener] connection accepted from 172.XX.XX.XX:49526 #1 (1 connection now open)

 

 

Can someone help me figure out what's the reason?

 



 Comments   
Comment by Libelula Soft [ 31/Mar/22 ]

Thanks for your help, I'm going to migrate to the new version.

Comment by Dmitry Agranat [ 31/Mar/22 ]

Hi mongoatlas@libelulasoft.com, please note that MongoDB 3.6 has reached EOL on April 2021 and the SERVER project is for reporting bugs and feature requests for supported MongoDB versions.

symbolizing the provided backtrace:

 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/mongo/util/stacktrace_posix.cpp:172:0: mongo::printStackTrace(std::ostream&)
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/mongo/util/signal_handlers_synchronous.cpp:180:0: mongo::(anonymous namespace)::printSignalAndBacktrace(int)
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/mongo/util/signal_handlers_synchronous.cpp:276:0: mongo::(anonymous namespace)::abruptQuitWithAddrSignal(int, siginfo*, void*)
 ??:0:0: ??
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/include/btree.i:503:0: __wt_page_only_modify_set
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/include/btree.i:605:0: __wt_page_modify_set
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/btree/bt_split.c:872:0: __split_parent
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/btree/bt_split.c:2185:0: __split_reverse
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/btree/bt_split.c:2206:0: __wt_split_reverse
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/evict/evict_page.c:242:0: __evict_delete_ref
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/evict/evict_page.c:312:0: __evict_page_dirty_update
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/evict/evict_page.c:181:0: __wt_evict
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/evict/evict_lru.c:2290:0: __evict_page
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/evict/evict_lru.c:1169:0: __evict_lru_pages
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/evict/evict_lru.c:320:0: __wt_evict_thread_run
 /data/mci/6452d7722b40e9617fad86fd4ef34763/src/src/third_party/wiredtiger/src/support/thread_group.c:31:0: __thread_run
 ??:0:0: ??
 ??:0:0: ??

It looks like we tried to access a field in a structure where the structure pointer was NULL, and the field was 0xe8 offset from the beginning of the structure, but none of the structures being accessed at or around line 503 of __wt_page_only_modify_set are large enough to be at offset 0xe8, which makes me think this page has been repurposed/overwritten (possibly evicted).

I think it's possible this is WT-4032, which was backported into 3.6.5. Since you are running 3.6.2, you might be affected by this issue.

Regards,
Dima

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