[Linux][arm][MinOpts] Segmentation fault in System.Xml.Linq.Events.Tests

[echesakov]

Segmentation fault in System.Xml.Linq.Events.Tests https://ci.dot.net/job/dotnet_coreclr/job/master/job/jitstress/job/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/3/consoleText

===========================================================================================================
/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/tests/System.Xml.Linq.Events.Tests/netcoreapp-Linux-Release-arm /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/tests/System.Xml.Linq.Events.Tests/netcoreapp-Linux-Release-arm
xUnit.net console test runner (32-bit .NET Core)
Copyright (C) 2014 Outercurve Foundation.

Discovering: System.Xml.Linq.Events.Tests
Discovered:  System.Xml.Linq.Events.Tests
Starting:    System.Xml.Linq.Events.Tests
./RunTests.sh: line 128: 30362 Segmentation fault      $RUNTIME_PATH/dotnet xunit.console.netcore.exe System.Xml.Linq.Events.Tests.dll -xml testResults.xml -notrait Benchmark=true -notrait category=nonnetcoreapptests -notrait category=nonlinuxtests -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/tests/System.Xml.Linq.Events.Tests/netcoreapp-Linux-Release-arm
----- end 06:11:45 ----- exit code 139 ----------------------------------------------------------
exit code 139 means SIGSEGV Illegal memory access. Deref invalid pointer, overrunning buffer, stack overflow etc. Core dumped.
Looking around for any Linux dump...
... found no dump in /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/tests/System.Xml.Linq.Events.Tests/netcoreapp-Linux-Release-arm
error: One or more tests failed while running tests from ''.  Exit code 139.

Running tests in /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/tests/System.Xml.Linq.Misc.Tests/netcoreapp-Linux-Release-arm
timeout --kill-after=30s 15m ./RunTests.sh /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/testhost/netcoreapp-Linux-Release-arm

----- start 06:11:45 =============== To repro directly: =====================================================
pushd .
#!/usr/bin/env bash
export COMPlus_JITMinOpts=1
chmod +x /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/dotnet
/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_corefx_minopts_tst_prtest/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/dotnet xunit.console.netcore.exe System.Xml.Linq.Misc.Tests.dll  -xml testResults.xml -notrait Benchmark=true -notrait category=nonnetcoreapptests -notrait category=nonlinuxtests  -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
popd
===========================================================================================================

[echesakov]

I was trying to localize a root cause for this issue by running with HeapVerify=1 GCStressLog=1 under lldb+sos. It seems that when HeapVerification fails it always happens with an object at the beginning of Gen-2 heap:

(lldb) run
xUnit.net console test runner (32-bit .NET Core)
Copyright (C) 2014 Outercurve Foundation.

Discovering: System.Xml.Linq.Events.Tests
Discovered:  System.Xml.Linq.Events.Tests
Starting:    System.Xml.Linq.Events.Tests
Process 2914 stopped
* thread dotnet/coreclr#9, name = 'dotnet', stop reason = signal SIGTRAP
    frame #0: 0xb6879a02 libcoreclr.so`DBG_DebugBreak + 2
libcoreclr.so`DBG_DebugBreak:
->  0xb6879a02 <+2>: udf    #0x1
    0xb6879a04 <+4>: bx     lr

libcoreclr.so`DBG_DebugBreak_End:
    0xb6879a06 <+0>: movs   r0, r0

libcoreclr.so`ThrowExceptionFromContextInternal:
    0xb6879a08 <+0>: push   {r7}

Process 2914 launched: '/home/ubuntu/echesakov/coreclr/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/dotnet' (arm)

(lldb) bt
* thread dotnet/coreclr#9, name = 'dotnet', stop reason = signal SIGTRAP
  * frame #0: 0xb6879a02 libcoreclr.so`DBG_DebugBreak + 2
    frame dotnet/coreclr#1: 0xb67fe048 libcoreclr.so`::DebugBreak() at debug.cpp:405
    frame dotnet/coreclr#2: 0xb66d2aec libcoreclr.so`WKS::gc_heap::verify_heap(int) [inlined] WKS::FATAL_GC_ERROR() at gcpriv.h:28
    frame dotnet/coreclr#3: 0xb66d2ae8 libcoreclr.so`WKS::gc_heap::verify_heap(begin_gc_p=<unavailable>) at gc.cpp:33226
    frame dotnet/coreclr#4: 0xb66d4f62 libcoreclr.so`WKS::gc_heap::garbage_collect(n=0) at gc.cpp:16785
    frame dotnet/coreclr#5: 0xb66c85d2 libcoreclr.so`WKS::GCHeap::GarbageCollectGeneration(this=<unavailable>, gen=<unavailable>, reason=reason_alloc_soh) at gc.cpp:35081
    frame dotnet/coreclr#6: 0xb66c9de6 libcoreclr.so`WKS::gc_heap::try_allocate_more_space(acontext=0x0021e740, size=88, gen_number=0) at gc.cpp:13197
    frame dotnet/coreclr#7: 0xb66eabb4 libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) [inlined] WKS::gc_heap::allocate_more_space(size=<unavailable>, alloc_generation_number=0) at gc.cpp:13490
    frame dotnet/coreclr#8: 0xb66eabaa libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) at gc.cpp:13521
    frame dotnet/coreclr#9: 0xb66eab80 libcoreclr.so`WKS::GCHeap::Alloc(this=<unavailable>, context=0x0021e740, size=88, flags=0) at gc.cpp:34419
    frame dotnet/coreclr#10: 0xb64d1a8a libcoreclr.so`SlowAllocateString(unsigned int) [inlined] Alloc(size=<unavailable>, bFinalize=NO, bContainsPointers=NO) at gchelpers.cpp:241
    frame dotnet/coreclr#11: 0xb64d1a58 libcoreclr.so`SlowAllocateString(cchStringLength=36) at gchelpers.cpp:1023
    frame dotnet/coreclr#12: 0xb64e82aa libcoreclr.so`FramedAllocateString(stringLength=36) at jithelpers.cpp:2916
    frame dotnet/coreclr#13: 0xb1264824
    frame dotnet/coreclr#14: 0xb12641ba
    frame dotnet/coreclr#15: 0xaa17db50

(lldb) sos VerifyHeap
Could not request method table data for object B2600000 (MethodTable: 000809A0).
VerifyHeap  failed

(lldb) dumpobj B2600000
<Note: this object has an invalid CLASS field>
Invalid object
DumpObj B2600000  failed

(lldb) histinit
Attempting to read Stress log
STRESS LOG:
    facilitiesToLog  = 0x80080103
    levelToLog       = 7
    MaxLogSizePerThread = 0x2000000 (33554432)
    MaxTotalLogSize = 0x40000000 (1073741824)
    CurrentTotalLogChunk = 2128
    ThreadsWithLogs  = 5
    Clock frequency  = 1.000 GHz
    Start time         04:30:12
    Last message time  04:32:31
    Total elapsed time 138.957 sec
................................................................
................................................................
................................................................
................................................................
................................................................
................................................................
................................................................
................................................................
................................................................
................................................................
................................................................
..............................
---------------------------- 47019 total entries ------------------------------------
SUCCESS: GCHist structures initialized

(lldb) histobjfind B2600000
 GCCount   Object                                  Message
---------------------------------------------------------
...

(lldb) histobj B2600000
 GCCount   Object                                    Roots
---------------------------------------------------------
      56 B2600000
      55 B2600000
      54 B2600000
      53 B2600000
      52 B2600000
      51 B2600000
      50 B2600000
      49 B2600000
      48 B2600000
      47 B2600000
      46 B2600000
      45 B2600000
      44 B2600000
      43 B2600000
      42 B2600000
      41 B2600000
      40 B2600000
      39 B2600000
      38 B2600000
      37 B2600000
      36 B2600000
      35 B2600000
      34 B2600000
      33 B2600000
      32 B2600000
      31 B2600000
      30 B2600000
      29 B2600000
      28 B2600000
      27 B2600000
      26 B2600000
      25 B2600000
      24 B2600000
      23 B2600000
      22 B2600000
      21 B2600000
      20 B2600000
      19 B2600000
      18 B2600000
      17 B2600000
      16 B2600000
      15 B2600000
      14 B2600000
      13 B2600000
      12 B2600000
      11 B2600000
      10 B2600000
       9 B2600000
       8 B2600000
       7 B2600000
       6 B2600000
       5 B2600000
       4 B2600000
       3 B2600000
       1 B2600000

(lldb) eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0xAAC2E938
generation 1 starts at 0xAAAC9858
generation 2 starts at 0xB2600000
ephemeral segment allocation context: none
 segment     begin  allocated      size
B25FF000  B2600000  B35FEE4C  0xffee4c(16772684)
AA1F5000  AA1F6000  AAD5491C  0xb5e91c(11921692)
Large object heap starts at 0xB3600000
 segment     begin  allocated      size
B35FF000  B3600000  B4338D70  0xd38d70(-1091818508)
A8FFF000  A9000000  A9300020  0x300020(-1091818508)
Total Size:              Size: 0x2b964f8 (45704440) bytes.
------------------------------
GC Heap Size:    Size: 0x2b964f8 (45704440) bytes.

[echesakov]

@dotnet/jit-contrib @janvorli @Maoni0 PTAL
Do you have any suggestions where to proceed from here?

[janvorli]

Now the question is if the MethodTable 000809A0 was a valid one and it has become invalid due to some memory corruption or if the address is wrong due to something overwriting the address B2600000. I would set a breakpoint e.g. to the GCToEEInterface::GcScanRoots and see if the object is valid at that point. If it is, I would set a write watchpoint at its address (watch (int)the_object_address) and continue the execution. If anything modified that location, it would break into the debugger and you'd see what's causing it.

[Maoni0]

note that the fact verify_heap is complaining at the beginning of a GC is saying that the address was valid during the last GC and it got corrupted between the exit of the last GC and the beginning of this GC.

[echesakov]

@janvorli Thank you. I'll try that

[echesakov]

@Maoni0 Yes, you are right. It also can be seen from StressLog dump just before the gc_heap::verify_heap failed

STRESS LOG:
    facilitiesToLog  = 0x80080103
    levelToLog       = 7
    MaxLogSizePerThread = 0x2000000 (33554432)
    MaxTotalLogSize = 0x40000000 (1073741824)
    CurrentTotalLogChunk = 2128
    ThreadsWithLogs  = 5
    Clock frequency  = 1.000 GHz
    Start time             Last message time      Total elapsed time 138.957 sec

THREAD  TIMESTAMP     FACILITY                              MESSAGE
  ID  (sec from start)
--------------------------------------------------------------------------------------
 d2f 138.956746830 : `GC`                         Segment mem 0xaa1f6000 alloc = 0xaad5491c used 0xaaf62ff0 committed 0xaaf67000

 d2f 138.956745914 : `GC`                     Generation 0 [0xaac2e938, (nil)] cur = (nil)

 d2f 138.956745164 : `GC`                         Segment mem 0xaa1f6000 alloc = 0xaad5491c used 0xaaf62ff0 committed 0xaaf67000

 d2f 138.956744247 : `GC`                     Generation 1 [0xaaac9858, (nil)] cur = (nil)

 d2f 138.956743414 : `GC`                         Segment mem 0xaa1f6000 alloc = 0xaad5491c used 0xaaf62ff0 committed 0xaaf67000

 d2f 138.956742497 : `GC`                         Segment mem 0xb2600000 alloc = 0xb35fee4c used 0xb326c000 committed 0xb35ff000

 d2f 138.956741664 : `GC`                     Generation 2 [0xb2600000, 0xaa1f6000] cur = 0xaa1f6000

 d2f 138.956740664 : `GC`                 GC Heap (nil)

 d2f 138.956734997 : `GC`GCALLOC`GCROOTS` } =========== BEGINGC 56, (requested generation = 0, collect_classes = 0) ==========

 d2f 138.956733830 : `GC`                 GC is triggered 

 d2f 138.956721997 : `GC`GCALLOC`GCROOTS` condemned generation num: 0

 d2f 136.128357970 : `GC`                 New commit: a9301000
 d2f 136.128347136 : `GC`                 Growing heap_segment: a8fff000 high address: a9300020

 d2f 135.718646122 : `GC`GCALLOC`GCROOTS` ========== ENDGC 55 (gen = 0, collect_classes = 0) ==========={

 d2f 135.313793356 : `GC`                         Segment mem 0xaa1f6000 alloc = 0xaac2e944 used 0xaaf62ff0 committed 0xaaf67000

 d2f 135.313792439 : `GC`                     Generation 0 [0xaac2e938, (nil)] cur = (nil)

 d2f 135.313791523 : `GC`                         Segment mem 0xaa1f6000 alloc = 0xaac2e944 used 0xaaf62ff0 committed 0xaaf67000

 d2f 135.313790606 : `GC`                     Generation 1 [0xaaac9858, (nil)] cur = (nil)

 d2f 135.313789773 : `GC`                         Segment mem 0xaa1f6000 alloc = 0xaac2e944 used 0xaaf62ff0 committed 0xaaf67000

 d2f 135.313788773 : `GC`                         Segment mem 0xb2600000 alloc = 0xb35fee4c used 0xb326c000 committed 0xb35ff000

 d2f 135.313787773 : `GC`                     Generation 2 [0xb2600000, 0xaa1f6000] cur = 0xaa1f6000

 d2f 135.313786106 : `GC`                 GC Heap (nil)

[janvorli]

@echesakovMSFT I can see I've forgotten to escape the watch command, it should be:
watch *(int*)the_object_address

[echesakov]

I was not sure if this is a related problem or not but when I was running the same tests with HeapVerify=3 I hit this assert

(lldb) run
Process 17498 launched: '/home/ubuntu/echesakov/coreclr/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/dotnet' (arm)

Assert failure(PID 17498 [0x0000445a], Thread: 17498 [0x445a]): !"Pointer updated without using write barrier"
    File: /opt/code/src/gc/gc.cpp Line: 36605
    Image: /mnt/echesakov/coreclr/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/dotnet

Process 17498 stopped
* thread dotnet/coreclr#1, name = 'dotnet', stop reason = signal SIGABRT
    frame #0: 0xb6c9e8e6 libc.so.6`__libc_do_syscall at libc-do-syscall.S:44

Further investigation shows

(lldb) run
Process 21768 launched: '/home/ubuntu/echesakov/coreclr/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/dotnet' (arm)
Process 21768 stopped
* thread dotnet/coreclr#1, name = 'dotnet', stop reason = breakpoint 1.1
    frame #0: 0xb6777a36 libcoreclr.so`WKS::testGCShadowHelper(unsigned char*) [inlined] WKS::testGCShadow(ptr=0xb2800228) at gc.cpp:36605
   36602                    if (!gc_heap::frozen_object_p(*ptr))
   36603        #endif // FEATURE_BASICFREEZE
   36604                    {
-> 36605                        _ASSERTE(!"Pointer updated without using write barrier");
   36606                    }
   36607                }
   36608                /*

(lldb) bt
* thread dotnet/coreclr#1, name = 'dotnet', stop reason = breakpoint 1.1
  * frame #0: 0xb6777a36 libcoreclr.so`WKS::testGCShadowHelper(unsigned char*) [inlined] WKS::testGCShadow(ptr=0xb2800228) at gc.cpp:36605
    frame dotnet/coreclr#1: 0xb6777a12 libcoreclr.so`WKS::testGCShadowHelper(x="$\xbc▒▒) at gc.cpp:36622
    frame dotnet/coreclr#2: 0xb6760652 libcoreclr.so`WKS::checkGCWriteBarrier() at gc.cpp:36650
    frame dotnet/coreclr#3: 0xb675ff70 libcoreclr.so`WKS::gc_heap::garbage_collect(n=0) at gc.cpp:16788
    frame dotnet/coreclr#4: 0xb67535d2 libcoreclr.so`WKS::GCHeap::GarbageCollectGeneration(this=<unavailable>, gen=<unavailable>, reason=reason_alloc_soh) at gc.cpp:35081
    frame dotnet/coreclr#5: 0xb6754de6 libcoreclr.so`WKS::gc_heap::try_allocate_more_space(acontext=0x00102610, size=280, gen_number=0) at gc.cpp:13197
    frame dotnet/coreclr#6: 0xb6775bb4 libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) [inlined] WKS::gc_heap::allocate_more_space(size=<unavailable>, alloc_generation_number=0) at gc.cpp:13490
    frame dotnet/coreclr#7: 0xb6775baa libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) at gc.cpp:13521
    frame dotnet/coreclr#8: 0xb6775b80 libcoreclr.so`WKS::GCHeap::Alloc(this=<unavailable>, context=0x00102610, size=280, flags=0) at gc.cpp:34419
    frame dotnet/coreclr#9: 0xb655ca8a libcoreclr.so`SlowAllocateString(unsigned int) [inlined] Alloc(size=<unavailable>, bFinalize=NO, bContainsPointers=NO) at gchelpers.cpp:241
    frame dotnet/coreclr#10: 0xb655ca58 libcoreclr.so`SlowAllocateString(cchStringLength=132) at gchelpers.cpp:1023
    frame dotnet/coreclr#11: 0xb65732aa libcoreclr.so`FramedAllocateString(stringLength=132) at jithelpers.cpp:2916
    frame dotnet/coreclr#12: 0xae7d9150
    frame dotnet/coreclr#13: 0xae7d8ee0
    frame dotnet/coreclr#14: 0xae7e8fd6
    frame dotnet/coreclr#15: 0xae7e8b88

(lldb) fr v
(Object **) ptr = 0xb2800228
(lldb) x -s4 -fx -c1 0xb2800228
0xb2800228: 0xb280028c
(lldb) x -s4 -fx -c1 0xb280028c
0xb280028c: 0xaffcbe5c
(lldb) dumpobj 0xb280028c
Name:        System.AppDomainSetup
MethodTable: affcbe5c
EEClass:     affa46b8
Size:        20(0x14) bytes
File:        /mnt/echesakov/coreclr/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/shared/Microsoft.NETCore.App/9.9.9/System.Private.CoreLib.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
aff98b84  40001ee        4      System.String[]  0 instance b28002a0 _Entries
affc72c0  40001ef        8        System.String  0 instance 00000000 _AppBase
aff4f640  40001f0        c ...Private.CoreLib]]  0 instance 00000000 _CompatFlags

(lldb) eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0xB2800018
generation 1 starts at 0xB280000C
generation 2 starts at 0xB2800000
ephemeral segment allocation context: none
 segment     begin  allocated      size
B27FF000  B2800000  B2828120  0x28120(164128)
Large object heap starts at 0xB3800000
 segment     begin  allocated      size
B37FF000  B3800000  B3802250  0x2250(-1091343420)
Total Size:              Size: 0x2a370 (172912) bytes.
------------------------------
GC Heap Size:    Size: 0x2a370 (172912) bytes.

Update: Seems that HeapVerify=3 mode doesn't work and any test would fail immediately as in https://github.com/dotnet/coreclr/issues/17428#issuecomment-379413824

[echesakov]

I suspect that the MethodTable value 000809A0 I saw before in lldb was g_gc_pFreeObjectMethodTable set by CObjectHeader::SetFree and for some reason sos VerifyHeap keeps complaining about "objects" having such MT on the heap.

I also think that this was not a reason for gc_heap::verify_heap failure, so probably I need to reproduce the issue again and see at what object gc_heap::verify_heap fails

[echesakov]

Some update on the issue. I left running the test assembly during last night and also removed COMPlus_JITMinOpts=1 (but left COMPlus_VerifyHeap=1) to see if the failure happens in normal mode. I caught Segfault in gc_heap::verify_heap but in different place

* thread dotnet/coreclr#11, name = 'dotnet', stop reason = signal SIGSEGV: invalid address (fault address: 0xcccccccc)
    frame #0: 0xb64a014e libcoreclr.so`MethodTable::SanityCheck() [inlined] MethodTable::GetFlag(this=0xcccccccc, flag=enum_flag_HasComponentSize) const at methodtable.h:4114
    frame dotnet/coreclr#1: 0xb64a014e libcoreclr.so`MethodTable::SanityCheck() [inlined] MethodTable::HasComponentSize(this=0xcccccccc) const at methodtable.h:1891
    frame dotnet/coreclr#2: 0xb64a014e libcoreclr.so`MethodTable::SanityCheck() [inlined] MethodTable::GetComponentSize(this=0xcccccccc) at methodtable.h:1913
    frame dotnet/coreclr#3: 0xb64a014e libcoreclr.so`MethodTable::SanityCheck(this=0xcccccccc) at methodtable.cpp:8008
  * frame dotnet/coreclr#4: 0xb676f2a2 libcoreclr.so`WKS::GCHeap::ValidateObjectMember(this=<unavailable>, obj=0x0000000c) at gc.cpp:33347
    frame dotnet/coreclr#5: 0xb64a5746 libcoreclr.so`Object::ValidateInner(this=0xaaac2010, bDeep=YES, bVerifyNextHeader=NO, bVerifySyncBlock=YES) at object.cpp:760
    frame dotnet/coreclr#6: 0xb6758fa0 libcoreclr.so`WKS::gc_heap::verify_heap(begin_gc_p=<unavailable>) at gc.cpp:33195
    frame dotnet/coreclr#7: 0xb6752376 libcoreclr.so`WKS::gc_heap::gc1() at gc.cpp:15653
    frame dotnet/coreclr#8: 0xb675b25e libcoreclr.so`WKS::gc_heap::garbage_collect(n=<unavailable>) at gc.cpp:0
    frame dotnet/coreclr#9: 0xb674e61a libcoreclr.so`WKS::GCHeap::GarbageCollectGeneration(this=<unavailable>, gen=<unavailable>, reason=reason_alloc_soh) at gc.cpp:35084
    frame dotnet/coreclr#10: 0xb674fe2e libcoreclr.so`WKS::gc_heap::try_allocate_more_space(acontext=0x02197318, size=16012, gen_number=0) at gc.cpp:13197
    frame dotnet/coreclr#11: 0xb6770c74 libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) [inlined] WKS::gc_heap::allocate_more_space(size=<unavailable>, alloc_generation_number=0) at gc.cpp:13490
    frame dotnet/coreclr#12: 0xb6770c6a libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) at gc.cpp:13521
    frame dotnet/coreclr#13: 0xb6770c40 libcoreclr.so`WKS::GCHeap::Alloc(this=<unavailable>, context=0x02197318, size=16012, flags=0) at gc.cpp:34422
    frame dotnet/coreclr#14: 0xb65574b2 libcoreclr.so`FastAllocatePrimitiveArray(MethodTable*, unsigned int, int) [inlined] Alloc(size=<unavailable>, bFinalize=NO, bContainsPointers=NO) at gchelpers.cpp:241
    frame dotnet/coreclr#15: 0xb655746c libcoreclr.so`FastAllocatePrimitiveArray(pMT=0xb5189dd4, cElements=8000, bAllocateInLargeHeap=<unavailable>) at gchelpers.cpp:819
    frame dotnet/coreclr#16: 0xb656ef70 libcoreclr.so`JIT_NewArr1(arrayMT=0xb5189dd4, size=<unavailable>) at jithelpers.cpp:3198

The object (0xaaac2010) where gc_heap::verify_heap fails is a Dictionary

(lldb) dumpobj 0xaaac2010
Name:        System.Collections.Generic.Dictionary`2+Entry[[System.String, System.Private.CoreLib],[System.Int32, System.Private.CoreLib]][]
MethodTable: acd645d4
EEClass:     acd64538
Size:        280316(0x446fc) bytes
Array:       Rank 1, Number of elements 17519, Type VALUETYPE
Fields:
None

and the failure happened during ValidateInner(bDeep=TRUE) meaning that verification was also done on all child object of the collection.

(lldb) fr se 4
frame dotnet/coreclr#4: 0xb676f2a2 libcoreclr.so`WKS::GCHeap::ValidateObjectMember(this=<unavailable>, obj=0x0000000c) at gc.cpp:33347
   33344            go_through_object_cl (method_table (obj), o, s, oo,
   33345                                        {
   33346                                            uint8_t* child_o = *oo;
-> 33347                                            if (child_o)
   33348                                            {
   33349                                                dprintf (3, ("VOM: m: %Ix obj %Ix", (size_t)child_o, o));
   33350                                                MethodTable *pMT = method_table (child_o);

(lldb) x -s4 -fx -c1 oo
0xaaae3008: 0xac626ce8

(lldb) x -s4 -fx -c1 *oo
0xac626ce8: 0xcccccccc

Here child_o(0xac626ce8) has wrong value of pMT (0xcccccccc)

I checked array neighbors of oo and it seems that neighboring objects having same card value (0xac62) have wrong pMT (0xcccccccc)

(lldb) x -s4 -fx -c96 oo-12
0xaaae2fd8: 0xac2d5958 0x0426838b 0xffffffff 0x00000000
0xaaae2fe8: 0xac2d5a28 0x131f89f7 0xffffffff 0x00000000
0xaaae2ff8: 0xac2d5af8 0x0463fcf1 0x00001579 0x00000000
0xaaae3008: 0xac626ce8 0x7378b6e7 0xffffffff 0x00000000
0xaaae3018: 0xac626e20 0x58383c44 0xffffffff 0x00000000
0xaaae3028: 0xac626f58 0x7a885261 0xffffffff 0x00000000
0xaaae3038: 0xac627090 0x1481fbe7 0x000017ab 0x00000000
0xaaae3048: 0xac6271c8 0x4a9a158a 0xffffffff 0x00000000
0xaaae3058: 0xac627300 0x2fd4e773 0xffffffff 0x00000000
0xaaae3068: 0xac627438 0x1485b938 0xffffffff 0x00000000
0xaaae3078: 0xac627570 0x5235b34a 0xffffffff 0x00000000
0xaaae3088: 0xac6276a8 0x646502b1 0xffffffff 0x00000000
0xaaae3098: 0xac6277e0 0x2169ec32 0xffffffff 0x00000000
0xaaae30a8: 0xac627918 0x00e7709c 0xffffffff 0x00000000
0xaaae30b8: 0xac627a50 0x5a2d46c0 0xffffffff 0x00000000
0xaaae30c8: 0xac627b88 0x25fa16a1 0x000010d9 0x00000000
0xaaae30d8: 0xac627cc0 0x0c182357 0xffffffff 0x00000000
0xaaae30e8: 0xac627df8 0x15af6b25 0xffffffff 0x00000000
0xaaae30f8: 0xac627f30 0x74585570 0xffffffff 0x00000000
0xaaae3108: 0xac628068 0x4d38767d 0x00000c53 0x00000000
0xaaae3118: 0xac6281a0 0x33c83a92 0xffffffff 0x00000000
0xaaae3128: 0xac6282d8 0x5a98cf4c 0xffffffff 0x00000000
0xaaae3138: 0xac628410 0x71ec423a 0xffffffff 0x00000000
0xaaae3148: 0xac628548 0x0c913919 0x000001d2 0x00000000

(lldb) x -fx -s4 -c1 0xac2d5958
0xac2d5958: 0xb51b82c0

(lldb) dumpobj 0xac2d5958
Name:        System.String
MethodTable: b51b82c0
EEClass:     b51a73ac
Size:        88(0x58) bytes
File:        /mnt/echesakov/coreclr/_/fx/bin/testhost/netcoreapp-Linux-Release-arm/shared/Microsoft.NETCore.App/9.9.9/System.Private.CoreLib.dll
String:      a70d0edf1-f489-4f17-bc27-f93b1101fdd7
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
b51b0010  40001ab        4         System.Int32  1 instance       37 _stringLength
b5b1b528  40001ac        8          System.Char  1 instance       61 _firstChar
b51b82c0  40001ad       20        System.String  0   shared   static Empty
    >> Domain:Value  000f3418:NotInit  <<

(lldb) x -fx -s4 -c1 0xac627090
0xac627090: 0xcccccccc

(lldb) x -fx -s4 -c1 0xac626e20
0xac626e20: 0xcccccccc

(lldb) x -fx -s4 -c1 0xac626ce8
0xac626ce8: 0xcccccccc

(lldb) x -fx -s4 -c1 0xac628548
0xac628548: 0xcccccccc

I presume that the memory region got moved during GC and that made me wonder if we have some problem with proper use of JIT_WriteBarrier. I found that we use JIT_WriteBarrier_SP_Pre version of JIT_WriteBarrier

(lldb) dis -n JIT_WriteBarrier
libcoreclr.so`JIT_WriteBarrier:
    0xb6623e90 <+0>:   str    r1, [r0]
    0xb6623e92 <+2>:   movw   r3, #0x397c
    0xb6623e96 <+6>:   movt   r3, #0xac11
    0xb6623e9a <+10>:  cmp    r1, r3
    0xb6623e9c <+12>:  blo    0xb6623ebc                ; <+44>
    0xb6623e9e <+14>:  movw   r3, #0x9000
    0xb6623ea2 <+18>:  movt   r3, #0xacb0
    0xb6623ea6 <+22>:  cmp    r1, r3
    0xb6623ea8 <+24>:  bhs    0xb6623ebc                ; <+44>
    0xb6623eaa <+26>:  movw   r3, #0x4bac
    0xb6623eae <+30>:  movt   r3, #0xaa78
    0xb6623eb2 <+34>:  add.w  r3, r3, r0, lsr dotnet/coreclr#10
    0xb6623eb6 <+38>:  mov.w  r0, #0xff
    0xb6623eba <+42>:  strb   r0, [r3]
    0xb6623ebc <+44>:  bx     lr

which I thought should be used only in single-processor scenarios. Decision which JIT_WriteBarrier should be used is made in https://github.com/dotnet/coreclr/blob/3c28c423053f30adedc034c5e2c912bd2adaad10/src/vm/arm/stubs.cpp#L393-L419 and it was chosen according to

(lldb) p g_SystemInfo.dwNumberOfProcessors
(DWORD) $47 = 1

which computed in https://github.com/dotnet/coreclr/blob/3c28c423053f30adedc034c5e2c912bd2adaad10/src/pal/src/misc/sysinfo.cpp#L101 and for some reason the function returns 1 for my system even though I have 4 logical cores

$ cat /proc/cpuinfo | grep processor
processor       : 0
processor       : 1
processor       : 2
processor       : 3

@janvorli Can you please tell if my reasoning here makes sense at all? Next step I would try to hardcode g_SystemInfo.dwNumberOfProcessors=4 to see if the problem still occurs with JIT_WriteBarrier_MP_Pre.

[janvorli]

and for some reason the function returns 1 for my system even though I have 4 logical cores

This is definitely wrong and could be causing intermittent failures since the _SP variant of the barrier is missing the dmb (data memory barrier) instruction necessary for proper multi-processor behavior.

[janvorli]

See this, it is likely the issue with getting the processor count:

seanmonstar/num_cpus#34

[echesakov]

Since my last change dotnet/coreclr#18053 didn't help to fix this issue I continued working on this and I think I found an explanation what happens during the crash.

When I use COMPlus_JITMinOpts=1 together with COMPlus_VerifyHeap=1 I usually get something like this

(lldb) bt
* thread dotnet/coreclr#9, name = 'dotnet', stop reason = signal SIGTRAP
  * frame #0: 0xb697f32a libcoreclr.so`DBG_DebugBreak + 2
    frame dotnet/coreclr#1: 0xb687e598 libcoreclr.so`WKS::gc_heap::verify_heap(int) [inlined] WKS::FATAL_GC_ERROR() at gcpriv.h:28
    frame dotnet/coreclr#2: 0xb687e594 libcoreclr.so`WKS::gc_heap::verify_heap(begin_gc_p=<unavailable>) at gc.cpp:33226
    frame dotnet/coreclr#3: 0xb688048c libcoreclr.so`WKS::gc_heap::garbage_collect(n=0) at gc.cpp:16785
    frame dotnet/coreclr#4: 0xb68761b8 libcoreclr.so`WKS::GCHeap::GarbageCollectGeneration(this=<unavailable>, gen=<unavailable>, reason=reason_alloc_soh) at gc.cpp:35086
    frame dotnet/coreclr#5: 0xb6877868 libcoreclr.so`WKS::gc_heap::try_allocate_more_space(acontext=0x021f7070, size=88, gen_number=0) at gc.cpp:13197
    frame dotnet/coreclr#6: 0xb68925ee libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) [inlined] WKS::gc_heap::allocate_more_space(alloc_generation_number=0) at gc.cpp:13490
    frame dotnet/coreclr#7: 0xb68925e4 libcoreclr.so`WKS::GCHeap::Alloc(gc_alloc_context*, unsigned int, unsigned int) at gc.cpp:13521
    frame dotnet/coreclr#8: 0xb68925d6 libcoreclr.so`WKS::GCHeap::Alloc(this=<unavailable>, context=0x021f7070, size=88, flags=0) at gc.cpp:34424
    frame dotnet/coreclr#9: 0xb672699a libcoreclr.so`SlowAllocateString(unsigned int) [inlined] Alloc(size=88, bFinalize=NO, bContainsPointers=NO) at gchelpers.cpp:241
    frame dotnet/coreclr#10: 0xb6726976 libcoreclr.so`SlowAllocateString(cchStringLength=36) at gchelpers.cpp:1023
    frame dotnet/coreclr#11: 0xb6732fce libcoreclr.so`FramedAllocateString(stringLength=36) at jithelpers.cpp:2916
    frame dotnet/coreclr#12: 0xb1bda0fe
    frame dotnet/coreclr#13: 0xb1bd9a9a
    frame dotnet/coreclr#14: 0xac703df4

As far as I understand what gc_heap::verify_heap does the failure was due to the missing card on card_table for an array (located in large object heap) which presumably must be set by one of the JIT WriteBarriers.

After I have added more stress logging for gc_heap::verify_heap I managed to collect addresses of the array and its element containing GCRef to Gen-0 object (meaning that there must be a card for this part of array)

2229  18.480173735 : `GC`                 Card not set, card_of ((uint8_t*)oo) = 1549c23
2229  18.480173235 : `GC`                 Card not set, oo = aa4e118c
2229  18.480172735 : `GC`                 Card not set, card_of (curr_object) = 1549c20
2229  18.480171985 : `GC`                 Card not set, curr_object = aa4e1010

(lldb) sos DumpArray -start 31 -length 1 -details 0xaa4e1010
Name:        System.Xml.Linq.XHashtable`1+XHashtableState+Entry[[System.Xml.Linq.XName, System.Private.Xml.Linq]][]
MethodTable: af329ba8
EEClass:     af329b44
Size:        3145740(0x30000c) bytes
Array:       Rank 1, Number of elements 262144, Type VALUETYPE
Element Methodtable: af329b04
[31] aa4e118c
    Name:        System.Xml.Linq.XHashtable`1+XHashtableState+Entry[[System.Xml.Linq.XName, System.Private.Xml.Linq]]
    MethodTable: af329b04
    EEClass:     af3410dc
    Size:        20(0x14) bytes
    File:        /mnt/echesakov/coreclr/_/fx6/bin/testhost/netcoreapp-Linux-Release-arm/shared/Microsoft.NETCore.App/9.9.9/System.Private.Xml.Linq.dll
    Fields:
              MT    Field   Offset                 Type VT     Attr    Value Name
        b5462678  4000121        0           System.__Canon      0     instance     ac424554     Value
        b5467b20  4000122        4             System.Int32      1     instance     1614676006     HashCode
        b5467b20  4000123        8             System.Int32      1     instance            0     Next

(lldb) dumpobj 0xac424554
Name:        System.Xml.Linq.XName
MethodTable: af3a4238
EEClass:     af339384
Size:        20(0x14) bytes
File:        /mnt/echesakov/coreclr/_/fx6/bin/testhost/netcoreapp-Linux-Release-arm/shared/Microsoft.NETCore.App/9.9.9/System.Private.Xml.Linq.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
af328e50  400015f        4 ...l.Linq.XNamespace  0 instance b2b2139c _ns
b546b208  4000160        8        System.String  0 instance ac4244fc _localName
b5467b20  4000161        c         System.Int32  1 instance 1454485685 _hashCode

(lldb) eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0xAC2BD614
generation 1 starts at 0xABFC9DF4
generation 2 starts at 0xB2B00000
ephemeral segment allocation context: none
 segment     begin  allocated      size
B2AFF000  B2B00000  B3AFEBEC  0xffebec(16772076)
AB56C000  AB56D000  AC568118  0xffb118(16757016)
Large object heap starts at 0xB3B00000
 segment     begin  allocated      size
B3AFF000  B3B00000  B487EAB0  0xd7eab0(-1091322876)
AA4E0000  AA4E1000  AA7E1020  0x300020(-1091322876)
Total Size:              Size: 0x30787d4 (50825172) bytes.
------------------------------
GC Heap Size:    Size: 0x30787d4 (50825172) bytes.

Here 0xaa4e1010 is an array of structs and its 31st element contains GCRef 0xac424554 to Gen-0 object.

This array is modified via XHashtableState:Resize and XHashtableState:TryAdd defined in System.Private.Xml.Linq.dll using two barriers - JIT_WriteBarrier and JIT_CheckedWriteBarrier.

I believe the problem is in JIT_CheckedWriteBarrier. I have added stress logging for GCToEEInterface::StompWriteBarrier calls

2229  18.196436121 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=aa19c708, lowest_address=98a46000, highest_address=b4aff000, ephemeral_low=0, ephemeral_high=0, operation=0
222b  17.494351920 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=abfc9df4, ephemeral_high=ac56c000, operation=1
2229  16.598062808 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=abfc9df4, ephemeral_high=ac56c000, operation=1
222b  15.790613481 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=abac24a4, ephemeral_high=ac56c000, operation=1
222b  14.690921870 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=abac24a4, ephemeral_high=ac56c000, operation=1
222b  13.164042668 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=abac24a4, ephemeral_high=ac56c000, operation=1
222b  12.036057462 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab736454, ephemeral_high=ac56c000, operation=1
2229  11.119402591 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab736454, ephemeral_high=ac56c000, operation=1
222b  10.062703663 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab736454, ephemeral_high=ac56c000, operation=1
2228   8.858120758 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab56d000, ephemeral_high=ac56c000, operation=1
222a   7.664449191 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab56d000, ephemeral_high=ac56c000, operation=1
222a   6.820682433 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab57506c, ephemeral_high=ac56c000, operation=1
220d   5.988219262 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab57506c, ephemeral_high=ac56c000, operation=1
222a   5.492876311 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab56d000, ephemeral_high=ac56c000, operation=1
222a   5.105871071 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=ab56d000, ephemeral_high=ac56c000, operation=1
222a   5.067281139 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=ab273a70, lowest_address=ab56c000, highest_address=b4aff000, ephemeral_low=0, ephemeral_high=0, operation=0
222a   4.575131523 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=b3092db8, ephemeral_high=b3aff000, operation=1
222b   3.975125613 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=b2bd4994, ephemeral_high=b3aff000, operation=1
220d   3.378289704 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=b2bd4994, ephemeral_high=b3aff000, operation=1
2228   3.071388329 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=b2b3162c, ephemeral_high=b3aff000, operation=1
220b   2.196863475 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=b2b0000c, ephemeral_high=b3aff000, operation=1
2141   1.160779554 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=0, lowest_address=0, highest_address=0, ephemeral_low=b2b0000c, ephemeral_high=b3aff000, operation=1
2141   0.004419168 : `GC`                 GCToEEInterface::StompWriteBarrier card_table=b51c4424, lowest_address=b2aff000, highest_address=b4aff000, ephemeral_low=b2b0000c, ephemeral_high=b3aff000, operation=2

As you can see the last call before the verify_heap got failed was GCToEEInterface::StompWriteBarrier(WriteBarrierOp::StompResize) which should've updated JIT_CheckedWriteBarrier with new values of lowest_address=98a46000, highest_address=b4aff000 but only latter got updated keeping previous value of lowest_address=ab56c000:

(lldb) disassemble -n JIT_CheckedWriteBarrier
libcoreclr.so`JIT_CheckedWriteBarrier:
    0xb6795530 <+0>:   dmb    sy
    0xb6795534 <+4>:   str    r1, [r0]
    0xb6795536 <+6>:   movw   r3, #0xc000
    0xb679553a <+10>:  movt   r3, #0xab56
    0xb679553e <+14>:  cmp    r0, r3
    0xb6795540 <+16>:  blo    0xb679557e                ; <+78>
    0xb6795542 <+18>:  movw   r3, #0xf000
    0xb6795546 <+22>:  movt   r3, #0xb4af
    0xb679554a <+26>:  cmp    r0, r3
    0xb679554c <+28>:  bhs    0xb679557e                ; <+78>
    0xb679554e <+30>:  movw   r3, #0x9df4
    0xb6795552 <+34>:  movt   r3, #0xabfc
    0xb6795556 <+38>:  cmp    r1, r3
    0xb6795558 <+40>:  blo    0xb679557c                ; <+76>
    0xb679555a <+42>:  movw   r3, #0xc000
    0xb679555e <+46>:  movt   r3, #0xac56
    0xb6795562 <+50>:  cmp    r1, r3
    0xb6795564 <+52>:  bhs    0xb679557c                ; <+76>
    0xb6795566 <+54>:  movw   r3, #0xc708
    0xb679556a <+58>:  movt   r3, #0xaa19
    0xb679556e <+62>:  add.w  r3, r3, r0, lsr dotnet/coreclr#10
    0xb6795572 <+66>:  ldrb   r0, [r3]
    0xb6795574 <+68>:  cmp    r0, #0xff
    0xb6795576 <+70>:  itt    ne
    0xb6795578 <+72>:  movne  r0, #0xff
    0xb679557a <+74>:  strbne r0, [r3]
    0xb679557c <+76>:  bx     lr

That explains why there is no card for array 0xaa4e1010 since the address doesn't belong to range [0xab56c000,0xb4aff000[ and would be ignored at the beginning of JIT_CheckedWriteBarrier.

Here is a JitDump for XHashtable:TryAdd(TValue value, out TValue newValue) that modifies the array and there is indeed JIT_CheckedWriteBarrier used for out out TValue newValue

G_M38214_IG01:        ; func=00, offs=000000H, size=0018H, gcrefRegs=0000 {}, byrefRegs=0000 {}, byref, nogc <-- Prolog IG

IN008c: 000000      push    {r4,r5,r6,r7,r8,r9,r10,r11,lr}
IN008d: 000004      sub     sp, 28
IN008e: 000006      add     r11, sp, 56
IN008f: 00000A      movs    r3, 0
IN0090: 00000C      str     r3, [sp+0x10]       // [V04 loc1]
IN0091: 00000E      str     r0, [r11-0x24]
IN0092: 000012      mov     r4, r0
IN0093: 000014      mov     r5, r1
IN0094: 000016      mov     r6, r2

G_M38214_IG02:        ; offs=000018H, size=0022H, gcrefRegs=0030 {r4 r5}, byrefRegs=0040 {r6}, byref, isz

IN0001: 000018      mov     r0, r6
IN0002: 00001A      mov     r1, r5
IN0003: 00001C      movw    r12, 0xe831
IN0004: 000020      movt    r12, 0xb65d
IN0005: 000024      blx     r12         // CORINFO_HELP_CHECKED_ASSIGN_REF
IN0006: 000026      ldr     r3, [r4+12]
IN0007: 000028      adds    r0, r3, 4
IN0008: 00002A      ldr     r0, [r0]
IN0009: 00002C      mov     r1, r5
IN000a: 00002E      ldr     r3, [r3+12]
IN000b: 000030      blx     r3          // ExtractKeyDelegate[__Canon][System.__Canon]:Invoke(ref):ref:this
IN000c: 000032      mov     r7, r0
IN000d: 000034      cmp     r7, 0
IN000e: 000036      bne     SHORT G_M38214_IG04
IN000f: 000038      movs    r0, 1

which later got called from XHashtable:Resize() as follows

 while (entryIdx > EndOfList)
{
  newHashtable.TryAdd(_entries[entryIdx].Value, out newValue);
  entryIdx = _entries[entryIdx].Next;
}

[echesakov]

@janvorli Should this also be enabled for ARM?

https://github.com/dotnet/coreclr/blob/9c5e3d5d86901bd6bc0bd2d56e81cc0edec7eb13/src/vm/gcenv.ee.cpp#L882-L893