Uploaded image for project: 'WiredTiger'
  1. WiredTiger
  2. WT-6739

WT Panic from __wt_hs_insert_updates during update test in MongoDB 4.4

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: None
    • None
    • Storage - Ra 2020-10-05

      During a patch test run of an unrelated change, a MongoDB server aborted with the following error:

      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.538+00:00 E  STORAGE  22435   [thread316] "WiredTiger error","attr":{"error":-31804,"message":"[1601322673:538891][122759:0x7f09c7ca2700], file:collection-10--5349519424230698019.wt, eviction-server: __wt_hs_insert_updates, 906: Inserting updates older than obsolete updates or updates that are already in the history store to the history store may corrupt the data.: WT_PANIC: WiredTiger library panic"}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.539+00:00 F  -        23089   [thread316] "Fatal assertion","attr":{"msgid":50853,"file":"src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp","line":446}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.539+00:00 F  -        23090   [thread316] "\n\n***aborting after fassert() failure\n\n"
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.542+00:00 F  CONTROL  4757800 [thread316] "Writing fatal message","attr":{"message":"Got signal: 6 (Aborted).\n"}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.602+00:00 I  NETWORK  22944   [conn375] "Connection ended","attr":{"remote":"127.0.0.1:49545","connectionId":375,"connectionCount":24}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.633+00:00 I  -        20883   [conn374] "Interrupted operation as its client disconnected","attr":{"opId":11041}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.634+00:00 I  NETWORK  22944   [conn374] "Connection ended","attr":{"remote":"127.0.0.1:49541","connectionId":374,"connectionCount":23}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.634+00:00 I  NETWORK  22944   [conn376] "Connection ended","attr":{"remote":"127.0.0.1:49547","connectionId":376,"connectionCount":22}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.657+00:00 I  CONTROL  31431   [thread316] "BACKTRACE: {bt}","attr":{"bt":{"backtrace":[{"a":"7F09D86B12E1","b":"7F09D5897000","o":"2E1A2E1","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.605","s+":"1E1"},{"a":"7F09D86B2A09","b":"7F09D5897000","o":"2E1BA09","s":"_ZN5mongo15printStackTraceEv","s+":"29"},{"a":"7F09D86AFDF6","b":"7F09D5897000","o":"2E18DF6","s":"_ZN5mongo12_GLOBAL__N_116abruptQuitActionEiP7siginfoPv","s+":"66"},{"a":"7F09D41347E0","b":"7F09D4125000","o":"F7E0","s":"_L_unlock_16","s+":"2D"},{"a":"7F09D3DC34F5","b":"7F09D3D91000","o":"324F5","s":"gsignal","s+":"35"},{"a":"7F09D3DC4CD5","b":"7F09D3D91000","o":"33CD5","s":"abort","s+":"175"},{"a":"7F09D67EEB49","b":"7F09D5897000","o":"F57B49","s":"_ZN5mongo25fassertFailedWithLocationEiPKcj","s+":"12B"},{"a":"7F09D64B7843","b":"7F09D5897000","o":"C20843","s":"_ZN5mongo12_GLOBAL__N_141mdb_handle_error_with_startup_suppressionEP18__wt_event_handlerP12__wt_sessioniPKc.cold.1034","s+":"16"},{"a":"7F09D69D055B","b":"7F09D5897000","o":"113955B","s":"__eventv","s+":"3FB"},{"a":"7F09D64CE46E","b":"7F09D5897000","o":"C3746E","s":"__wt_panic_func","s+":"AA"},{"a":"7F09D64C22E1","b":"7F09D5897000","o":"C2B2E1","s":"__wt_hs_insert_updates.cold.33","s+":"18A"},{"a":"7F09D69AE5CF","b":"7F09D5897000","o":"11175CF","s":"__rec_write_wrapup","s+":"34F"},{"a":"7F09D69AFFA1","b":"7F09D5897000","o":"1118FA1","s":"__wt_reconcile","s+":"941"},{"a":"7F09D6975BF5","b":"7F09D5897000","o":"10DEBF5","s":"__wt_evict","s+":"EA5"},{"a":"7F09D696D7E9","b":"7F09D5897000","o":"10D67E9","s":"__evict_page","s+":"6B9"},{"a":"7F09D696E1C5","b":"7F09D5897000","o":"10D71C5","s":"__evict_lru_pages","s+":"75"},{"a":"7F09D69706C5","b":"7F09D5897000","o":"10D96C5","s":"__wt_evict_thread_run","s+":"75"},{"a":"7F09D69E0409","b":"7F09D5897000","o":"1149409","s":"__thread_run","s+":"39"},{"a":"7F09D412CAA1","b":"7F09D4125000","o":"7AA1","s":"start_thread","s+":"D1"},{"a":"7F09D3E79C4D","b":"7F09D3D91000","o":"E8C4D","s":"clone","s+":"6D"}],"processInfo":{"mongodbVersion":"4.4.1-108-gc96e896-patch-5f721b05e3c3317a06cde453","gitVersion":"c96e896100fa42e1176a1879f9ad8c251ac820cf","compiledModules":[],"uname":{"sysname":"Linux","release":"2.6.32-220.el6.x86_64","version":"#1 SMP Wed Nov 9 08:03:13 EST 2011","machine":"x86_64"},"somap":[{"b":"7F09D5897000","elfType":3,"buildId":"D708B2E4B3E23685CA68D5F3DAA3B3F30D5EC998"}]}}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.657+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D86B12E1","b":"7F09D5897000","o":"2E1A2E1","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.605","s+":"1E1"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.657+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D86B2A09","b":"7F09D5897000","o":"2E1BA09","s":"_ZN5mongo15printStackTraceEv","s+":"29"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.657+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D86AFDF6","b":"7F09D5897000","o":"2E18DF6","s":"_ZN5mongo12_GLOBAL__N_116abruptQuitActionEiP7siginfoPv","s+":"66"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.657+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D41347E0","b":"7F09D4125000","o":"F7E0","s":"_L_unlock_16","s+":"2D"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.657+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D3DC34F5","b":"7F09D3D91000","o":"324F5","s":"gsignal","s+":"35"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D3DC4CD5","b":"7F09D3D91000","o":"33CD5","s":"abort","s+":"175"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D67EEB49","b":"7F09D5897000","o":"F57B49","s":"_ZN5mongo25fassertFailedWithLocationEiPKcj","s+":"12B"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D64B7843","b":"7F09D5897000","o":"C20843","s":"_ZN5mongo12_GLOBAL__N_141mdb_handle_error_with_startup_suppressionEP18__wt_event_handlerP12__wt_sessioniPKc.cold.1034","s+":"16"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D69D055B","b":"7F09D5897000","o":"113955B","s":"__eventv","s+":"3FB"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D64CE46E","b":"7F09D5897000","o":"C3746E","s":"__wt_panic_func","s+":"AA"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D64C22E1","b":"7F09D5897000","o":"C2B2E1","s":"__wt_hs_insert_updates.cold.33","s+":"18A"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D69AE5CF","b":"7F09D5897000","o":"11175CF","s":"__rec_write_wrapup","s+":"34F"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D69AFFA1","b":"7F09D5897000","o":"1118FA1","s":"__wt_reconcile","s+":"941"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D6975BF5","b":"7F09D5897000","o":"10DEBF5","s":"__wt_evict","s+":"EA5"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D696D7E9","b":"7F09D5897000","o":"10D67E9","s":"__evict_page","s+":"6B9"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D696E1C5","b":"7F09D5897000","o":"10D71C5","s":"__evict_lru_pages","s+":"75"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D69706C5","b":"7F09D5897000","o":"10D96C5","s":"__wt_evict_thread_run","s+":"75"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D69E0409","b":"7F09D5897000","o":"1149409","s":"__thread_run","s+":"39"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D412CAA1","b":"7F09D4125000","o":"7AA1","s":"start_thread","s+":"D1"}}
      [ReplicaSetFixture:job0:node1] | 2020-09-28T19:51:13.658+00:00 I  CONTROL  31427   [thread316] "  Frame: {frame}","attr":{"frame":{"a":"7F09D3E79C4D","b":"7F09D3D91000","o":"E8C4D","s":"clone","s+":"6D"}}
      

      The test running at the time was push2.js, which appends ~700,000 bytes to a document in a loop until that document exceeds the BSON maximum size (16 MB). Just prior to the crash, the node in question steps down from PRIMARY; I'm not sure if that is related to the issue here.

            Assignee:
            chenhao.qu@mongodb.com Chenhao Qu
            Reporter:
            milkie@mongodb.com Eric Milkie
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Created:
              Updated:
              Resolved: