OSX debugging

[ObiWahn]

The problem does not occur on linux.

https://github.com/microsoft/mimalloc/blob/master/src/alloc.c#L212

(lldb) r
Process 93543 launched: './bin/arangodbtests' (x86_64)
mimalloc: option 'secure': 0
mimalloc: option 'pool_commit': 0
mimalloc: process init: 0x7fffc980c3c0
mimalloc: debug level : 1
mimalloc: option 'show_errors': 1
mimalloc: error: trying to mi_free a pointer that does not point to a valid heap space: 0x111040000
mimalloc: assertion failed: at "/Users/jenkins/arangodb/3rdParty/mimalloc/src/options.c":121, _mi_error_message
  assertion: "false"
Process 93543 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
    frame #0: 0x00007fffc0a21d42 libsystem_kernel.dylib`__pthread_kill + 10
libsystem_kernel.dylib`__pthread_kill:
->  0x7fffc0a21d42 <+10>: jae    0x7fffc0a21d4c            ; <+20>
    0x7fffc0a21d44 <+12>: movq   %rax, %rdi
    0x7fffc0a21d47 <+15>: jmp    0x7fffc0a1acaf            ; cerror_nocancel
    0x7fffc0a21d4c <+20>: retq   
Target 0: (arangodbtests) stopped.
(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
  * frame #0: 0x00007fffc0a21d42 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fffc0b0f457 libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fffc0987420 libsystem_c.dylib`abort + 129
    frame #3: 0x00000001055e339f arangodbtests`_mi_assert_fail(assertion="false", fname="/Users/jenkins/arangodb/3rdParty/mimalloc/src/options.c", line=121, func="_mi_error_message") at options.c:136
    frame #4: 0x00000001055e3e24 arangodbtests`_mi_error_message(fmt="trying to mi_free a pointer that does not point to a valid heap space: %p\n") at options.c:121
    frame #5: 0x00000001055dfa53 arangodbtests`mi_free(p=0x0000000111040000) at alloc.c:212
    frame #6: 0x00000001055dfbc5 arangodbtests`_ZdlPv(p=0x0000000111040000) at alloc-override.c:90
    frame #7: 0x0000000105573910 arangodbtests`testing::internal::MakeAndRegisterTestInfo(test_case_name="ActiveFailover", name="creating_a_job_should_create_a_job_in_todo", type_param=0x0000000000000000, value_param=0x0000000000000000, code_location=(file = "/Users/jenkins/arangodb/tests/Agency/ActiveFailoverTest.cpp", line = 113), fixture_class_id=0x0000000109537728, set_up_tc=(arangodbtests`testing::Test::SetUpTestCase() at gtest.h:20190), tear_down_tc=(arangodbtests`testing::Test::TearDownTestCase() at gtest.h:20198), factory=0x0000000111020000)(), void (*)(), testing::internal::TestFactoryBase*) at gtest-all.cc:4053
    frame #8: 0x00000001000ae474 arangodbtests`::__cxx_global_var_init.29() at ActiveFailoverTest.cpp:113
    frame #9: 0x00000001000aee64 arangodbtests`_GLOBAL__sub_I_ActiveFailoverTest.cpp at ActiveFailoverTest.cpp:0
    frame #10: 0x000000010f80ca1b dyld`ImageLoaderMachO::doModInitFunctions(ImageLoader::LinkContext const&) + 385
    frame #11: 0x000000010f80cc1e dyld`ImageLoaderMachO::doInitialization(ImageLoader::LinkContext const&) + 40
    frame #12: 0x000000010f8084aa dyld`ImageLoader::recursiveInitialization(ImageLoader::LinkContext const&, unsigned int, char const*, ImageLoader::InitializerTimingList&, ImageLoader::UninitedUpwards&) + 338
    frame #13: 0x000000010f807524 dyld`ImageLoader::processInitializers(ImageLoader::LinkContext const&, unsigned int, ImageLoader::InitializerTimingList&, ImageLoader::UninitedUpwards&) + 138
    frame #14: 0x000000010f8075b9 dyld`ImageLoader::runInitializers(ImageLoader::LinkContext const&, ImageLoader::InitializerTimingList&) + 75
    frame #15: 0x000000010f7f947a dyld`dyld::initializeMainExecutable() + 195
    frame #16: 0x000000010f7fd8c6 dyld`dyld::_main(macho_header const*, unsigned long, int, char const**, char const**, char const**, unsigned long*) + 3966
    frame #17: 0x000000010f7f8249 dyld`dyldbootstrap::start(macho_header const*, int, char const**, long, macho_header const*, unsigned long*) + 470
    frame #18: 0x000000010f7f8036 dyld`_dyld_start + 54
(lldb) 

In order to reproduce you could build the tests in this branch:
https://github.com/arangodb/arangodb/tree/feature/mimalloc

[ObiWahn]

I am actually wondering if this might be a bug in our code.

[santagada]

Can't you put it in a debugger and take a look what exactly is happening? But it seems like there is memory being freed during global init (maybe because of a resize?).

Interesting points would be to know what is the state of the heap at that point or right before it, what allocated that memory. I completely don't know how the override works on osx, but we had some problems like that because of the ordering of the heap initialization and overrides.

[daanx]

Ah, that is no good! I am on it -- tomorrow I have access to a Mac and will look into it. For now, the message implies that a pointer is freed that perhaps was allocated using some other malloc? The _ZdlPv routine is plain delete on a C++ object. (One thing it could be is that the overriding is kicking in too late where an object is allocated using the system malloc, and then freed by mimalloc.)

• Can you compile the debug version with cmake ../.. -DMI_CHECK_FULL=ON to enable all assertions?

• By default, the macOS version uses "interpose" but only overrides the four basic functions, malloc, free, realloc and calloc -- I wonder if we need to interpose more functions, like the array new or something.

• By running cmake as cmake ../.. -DMI_CHECK_FULL=ON -DMI_INTERPOSE=OFF we use malloc zones instead of interpose --maybe that will work? This is still more experimental though.

Tomorrow I will also look into it, but just wanted to offer some pointers. There is also the MI_TLS_RECURSE_GUARD that is enabled when MI_INTERPOSE is enabled which prevents recursion as the dylib loader in macOS tries to allocate memory itself (with mimalloc) for thread local storage while the mimalloc module is still being loaded ... :(

[ObiWahn]

MI_INTERPOSE=OFF

cupertino:arangodb-build jenkins$ MIMALLOC_VERBOSE=1 ./bin/arangodbtests --gtest_filter=SimpleHttpClientCommunicatorTest.requests_are_properly_aborted
mimalloc: process init: 0x7fffc980c3c0
mimalloc: debug level : 3
mimalloc: option 'secure': 0
mimalloc: option 'pool_commit': 0
mimalloc: option 'page_reset': 0
mimalloc: option 'cache_reset': 0
Note: Google Test filter = SimpleHttpClientCommunicatorTest.requests_are_properly_aborted
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from SimpleHttpClientCommunicatorTest
[ RUN      ] SimpleHttpClientCommunicatorTest.requests_are_properly_aborted
mimalloc: option 'show_errors': 3
mimalloc: error: trying to mi_free a pointer that does not point to a valid heap space: 0x7fd1b551e6f0
mimalloc: assertion failed: at "/Users/jenkins/arangodb/3rdParty/mimalloc/src/options.c":121, _mi_error_message
  assertion: "false"
Abort trap: 6 (core dumped)

MI_INTERPOSE=ON

cupertino:arangodb-build jenkins$ MIMALLOC_VERBOSE=1 ./bin/arangodbtests --gtest_filter=SimpleHttpClientCommunicatorTest.requests_are_properly_aborted
mimalloc: option 'secure': 0
mimalloc: option 'pool_commit': 0
mimalloc: assertion failed: at "/Users/jenkins/arangodb/3rdParty/mimalloc/src/page.c":101, _mi_page_is_valid
  assertion: "segment->thread_id == page->heap->thread_id"
Abort trap: 6 (core dumped)

I have just pulled the following change into the branch

arangodb/arangodb@6354372
That seems to resolve the problem here (The test fixture is using a builder in the constructor). It was made because we had issues with thread_local variables on windows.

---

Unfortunately we end up with a different error in curl (https://github.com/arangodb/arangodb/blob/devel/3rdParty/curl/curl-7.63.0/lib/url.c#L2708-L2761).

I guess I use the overrides incorrectly. strdup is used in one of your test - So it should work. I think it is
rather strange that within the same TU some of the functions get substituted while others seem to stay the same.
UPDATE -- running your static tests that use strdup on the same machine works fine.

Process 97510 stopped                                        
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x0000000107219ad2 arangodbtests`create_conn_helper_init_proxy(conn=0x00000001109a8800) at url.c:2708
   2705    * Detect what (if any) proxy to use
   2706    *************************************************************/
   2707   if(data->set.str[STRING_PROXY]) {                                      
-> 2708     proxy = strdup(data->set.str[STRING_PROXY]);          
   2709     /* if global proxy is set, this is it */                             
   2710     if(NULL == proxy) {                               
   2711       failf(data, "memory shortage");                                    
Target 0: (arangodbtests) stopped.                            
(lldb) si                                                                        
Process 97510 stopped                                         
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984919 libsystem_c.dylib`strdup
libsystem_c.dylib`strdup:                                                        
->  0x7fffc0984919 <+0>: pushq  %rbp                          
    0x7fffc098491a <+1>: movq   %rsp, %rbp                                       
    0x7fffc098491d <+4>: pushq  %r15
    0x7fffc098491f <+6>: pushq  %r14
Target 0: (arangodbtests) stopped.
(lldb) s
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc098491a libsystem_c.dylib`strdup + 1
libsystem_c.dylib`strdup:
->  0x7fffc098491a <+1>: movq   %rsp, %rbp
    0x7fffc098491d <+4>: pushq  %r15
    0x7fffc098491f <+6>: pushq  %r14
    0x7fffc0984921 <+8>: pushq  %rbx
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc098491d libsystem_c.dylib`strdup + 4
libsystem_c.dylib`strdup:
->  0x7fffc098491d <+4>: pushq  %r15
    0x7fffc098491f <+6>: pushq  %r14
    0x7fffc0984921 <+8>: pushq  %rbx
    0x7fffc0984922 <+9>: pushq  %rax
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc098491f libsystem_c.dylib`strdup + 6
libsystem_c.dylib`strdup:
->  0x7fffc098491f <+6>:  pushq  %r14
    0x7fffc0984921 <+8>:  pushq  %rbx
    0x7fffc0984922 <+9>:  pushq  %rax
    0x7fffc0984923 <+10>: movq   %rdi, %r14
Target 0: (arangodbtests) stopped.
(lldb) s
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984921 libsystem_c.dylib`strdup + 8
libsystem_c.dylib`strdup:
->  0x7fffc0984921 <+8>:  pushq  %rbx
    0x7fffc0984922 <+9>:  pushq  %rax
    0x7fffc0984923 <+10>: movq   %rdi, %r14
    0x7fffc0984926 <+13>: callq  0x7fffc0929b40            ; strlen
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped                                                                                                                                                                                                                                                [210/11845]
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984922 libsystem_c.dylib`strdup + 9
libsystem_c.dylib`strdup:
->  0x7fffc0984922 <+9>:  pushq  %rax
    0x7fffc0984923 <+10>: movq   %rdi, %r14
    0x7fffc0984926 <+13>: callq  0x7fffc0929b40            ; strlen
    0x7fffc098492b <+18>: movq   %rax, %rbx
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984923 libsystem_c.dylib`strdup + 10
libsystem_c.dylib`strdup:
->  0x7fffc0984923 <+10>: movq   %rdi, %r14
    0x7fffc0984926 <+13>: callq  0x7fffc0929b40            ; strlen
    0x7fffc098492b <+18>: movq   %rax, %rbx
    0x7fffc098492e <+21>: incq   %rbx
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984926 libsystem_c.dylib`strdup + 13
libsystem_c.dylib`strdup:
->  0x7fffc0984926 <+13>: callq  0x7fffc0929b40            ; strlen
    0x7fffc098492b <+18>: movq   %rax, %rbx
    0x7fffc098492e <+21>: incq   %rbx
    0x7fffc0984931 <+24>: movq   %rbx, %rdi
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b40 libsystem_c.dylib`strlen
libsystem_c.dylib`strlen:
->  0x7fffc0929b40 <+0>: pushq  %rbp
    0x7fffc0929b41 <+1>: movq   %rsp, %rbp
    0x7fffc0929b44 <+4>: movq   %rdi, %rcx
    0x7fffc0929b47 <+7>: movq   %rdi, %rdx
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b41 libsystem_c.dylib`strlen + 1
libsystem_c.dylib`strlen:
->  0x7fffc0929b41 <+1>:  movq   %rsp, %rbp
    0x7fffc0929b44 <+4>:  movq   %rdi, %rcx
    0x7fffc0929b47 <+7>:  movq   %rdi, %rdx
    0x7fffc0929b4a <+10>: andq   $-0x10, %rdi
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b44 libsystem_c.dylib`strlen + 4
libsystem_c.dylib`strlen:
->  0x7fffc0929b44 <+4>:  movq   %rdi, %rcx
    0x7fffc0929b47 <+7>:  movq   %rdi, %rdx
    0x7fffc0929b4a <+10>: andq   $-0x10, %rdi
    0x7fffc0929b4e <+14>: pxor   %xmm0, %xmm0
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped                                                                                                                                                                                                                                                [150/11845]
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b47 libsystem_c.dylib`strlen + 7
libsystem_c.dylib`strlen:
->  0x7fffc0929b47 <+7>:  movq   %rdi, %rdx
    0x7fffc0929b4a <+10>: andq   $-0x10, %rdi
    0x7fffc0929b4e <+14>: pxor   %xmm0, %xmm0
    0x7fffc0929b52 <+18>: pcmpeqb (%rdi), %xmm0
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b4a libsystem_c.dylib`strlen + 10
libsystem_c.dylib`strlen:
->  0x7fffc0929b4a <+10>: andq   $-0x10, %rdi
    0x7fffc0929b4e <+14>: pxor   %xmm0, %xmm0
    0x7fffc0929b52 <+18>: pcmpeqb (%rdi), %xmm0
    0x7fffc0929b56 <+22>: pmovmskb %xmm0, %esi
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b4e libsystem_c.dylib`strlen + 14
libsystem_c.dylib`strlen:
->  0x7fffc0929b4e <+14>: pxor   %xmm0, %xmm0
    0x7fffc0929b52 <+18>: pcmpeqb (%rdi), %xmm0
    0x7fffc0929b56 <+22>: pmovmskb %xmm0, %esi
    0x7fffc0929b5a <+26>: andq   $0xf, %rcx
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b52 libsystem_c.dylib`strlen + 18
libsystem_c.dylib`strlen:
->  0x7fffc0929b52 <+18>: pcmpeqb (%rdi), %xmm0
    0x7fffc0929b56 <+22>: pmovmskb %xmm0, %esi
    0x7fffc0929b5a <+26>: andq   $0xf, %rcx
    0x7fffc0929b5e <+30>: orq    $-0x1, %rax
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b56 libsystem_c.dylib`strlen + 22
libsystem_c.dylib`strlen:
->  0x7fffc0929b56 <+22>: pmovmskb %xmm0, %esi
    0x7fffc0929b5a <+26>: andq   $0xf, %rcx
    0x7fffc0929b5e <+30>: orq    $-0x1, %rax
    0x7fffc0929b62 <+34>: shlq   %cl, %rax
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b5a libsystem_c.dylib`strlen + 26
libsystem_c.dylib`strlen:
->  0x7fffc0929b5a <+26>: andq   $0xf, %rcx
    0x7fffc0929b5e <+30>: orq    $-0x1, %rax
    0x7fffc0929b62 <+34>: shlq   %cl, %rax
    0x7fffc0929b65 <+37>: andl   %eax, %esi
Target 0: (arangodbtests) stopped.
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b5e libsystem_c.dylib`strlen + 30
libsystem_c.dylib`strlen:
->  0x7fffc0929b5e <+30>: orq    $-0x1, %rax
    0x7fffc0929b62 <+34>: shlq   %cl, %rax
    0x7fffc0929b65 <+37>: andl   %eax, %esi
    0x7fffc0929b67 <+39>: je     0x7fffc0929b80            ; <+64>
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b62 libsystem_c.dylib`strlen + 34
libsystem_c.dylib`strlen:
->  0x7fffc0929b62 <+34>: shlq   %cl, %rax
    0x7fffc0929b65 <+37>: andl   %eax, %esi
    0x7fffc0929b67 <+39>: je     0x7fffc0929b80            ; <+64>
    0x7fffc0929b69 <+41>: bsfl   %esi, %eax
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b65 libsystem_c.dylib`strlen + 37
libsystem_c.dylib`strlen:
->  0x7fffc0929b65 <+37>: andl   %eax, %esi
    0x7fffc0929b67 <+39>: je     0x7fffc0929b80            ; <+64>
    0x7fffc0929b69 <+41>: bsfl   %esi, %eax
    0x7fffc0929b6c <+44>: subq   %rdx, %rdi
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b67 libsystem_c.dylib`strlen + 39
libsystem_c.dylib`strlen:
->  0x7fffc0929b67 <+39>: je     0x7fffc0929b80            ; <+64>
    0x7fffc0929b69 <+41>: bsfl   %esi, %eax
    0x7fffc0929b6c <+44>: subq   %rdx, %rdi
    0x7fffc0929b6f <+47>: addq   %rdi, %rax
Target 0: (arangodbtests) stopped.
(lldb) s
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b69 libsystem_c.dylib`strlen + 41
libsystem_c.dylib`strlen:
->  0x7fffc0929b69 <+41>: bsfl   %esi, %eax
    0x7fffc0929b6c <+44>: subq   %rdx, %rdi
    0x7fffc0929b6f <+47>: addq   %rdi, %rax
    0x7fffc0929b72 <+50>: popq   %rbp
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b6c libsystem_c.dylib`strlen + 44
libsystem_c.dylib`strlen:
->  0x7fffc0929b6c <+44>: subq   %rdx, %rdi
    0x7fffc0929b6f <+47>: addq   %rdi, %rax
    0x7fffc0929b72 <+50>: popq   %rbp
    0x7fffc0929b73 <+51>: retq
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b6f libsystem_c.dylib`strlen + 47
libsystem_c.dylib`strlen:
->  0x7fffc0929b6f <+47>: addq   %rdi, %rax
    0x7fffc0929b72 <+50>: popq   %rbp
    0x7fffc0929b73 <+51>: retq
    0x7fffc0929b74 <+52>: nopw   %cs:(%rax,%rax)
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b72 libsystem_c.dylib`strlen + 50
libsystem_c.dylib`strlen:
->  0x7fffc0929b72 <+50>: popq   %rbp
    0x7fffc0929b73 <+51>: retq
    0x7fffc0929b74 <+52>: nopw   %cs:(%rax,%rax)
    0x7fffc0929b80 <+64>: addq   $0x10, %rdi
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0929b73 libsystem_c.dylib`strlen + 51
libsystem_c.dylib`strlen:
->  0x7fffc0929b73 <+51>: retq
    0x7fffc0929b74 <+52>: nopw   %cs:(%rax,%rax)
    0x7fffc0929b80 <+64>: addq   $0x10, %rdi
    0x7fffc0929b84 <+68>: pxor   %xmm0, %xmm0
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc098492b libsystem_c.dylib`strdup + 18
libsystem_c.dylib`strdup:
->  0x7fffc098492b <+18>: movq   %rax, %rbx
    0x7fffc098492e <+21>: incq   %rbx
    0x7fffc0984931 <+24>: movq   %rbx, %rdi
    0x7fffc0984934 <+27>: callq  0x7fffc09ae87a            ; symbol stub for: malloc
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc098492e libsystem_c.dylib`strdup + 21
libsystem_c.dylib`strdup:
->  0x7fffc098492e <+21>: incq   %rbx
    0x7fffc0984931 <+24>: movq   %rbx, %rdi
    0x7fffc0984934 <+27>: callq  0x7fffc09ae87a            ; symbol stub for: malloc
    0x7fffc0984939 <+32>: movq   %rax, %r15
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984931 libsystem_c.dylib`strdup + 24
libsystem_c.dylib`strdup:
->  0x7fffc0984931 <+24>: movq   %rbx, %rdi
    0x7fffc0984934 <+27>: callq  0x7fffc09ae87a            ; symbol stub for: malloc
    0x7fffc0984939 <+32>: movq   %rax, %r15
    0x7fffc098493c <+35>: xorl   %eax, %eax
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0984934 libsystem_c.dylib`strdup + 27
libsystem_c.dylib`strdup:
->  0x7fffc0984934 <+27>: callq  0x7fffc09ae87a            ; symbol stub for: malloc
    0x7fffc0984939 <+32>: movq   %rax, %r15
    0x7fffc098493c <+35>: xorl   %eax, %eax
    0x7fffc098493e <+37>: testq  %r15, %r15
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc09ae87a libsystem_c.dylib`malloc
libsystem_c.dylib`malloc:
->  0x7fffc09ae87a <+0>: jmpq   *0x8e3dd10(%rip)          ; (void *)0x00007fffc0a741e8: malloc

libsystem_c.dylib`mbr_gid_to_uuid:
    0x7fffc09ae880 <+0>: jmpq   *0x8e3dd12(%rip)          ; (void *)0x00007fffc09f84b2: mbr_gid_to_uuid

libsystem_c.dylib`mbr_uid_to_uuid:
    0x7fffc09ae886 <+0>: jmpq   *0x8e3dd14(%rip)          ; (void *)0x00007fffc09e1bcd: mbr_uid_to_uuid

libsystem_c.dylib`mbr_uuid_to_id:
    0x7fffc09ae88c <+0>: jmpq   *0x8e3dd16(%rip)          ; (void *)0x00007fffc09f84dc: mbr_uuid_to_id
Target 0: (arangodbtests) stopped.
(lldb) 
Process 97510 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
    frame #0: 0x00007fffc0a741e8 libsystem_malloc.dylib`malloc
libsystem_malloc.dylib`malloc:
->  0x7fffc0a741e8 <+0>: pushq  %rbp
    0x7fffc0a741e9 <+1>: movq   %rsp, %rbp
    0x7fffc0a741ec <+4>: pushq  %rbx
    0x7fffc0a741ed <+5>: pushq  %rax
Target 0: (arangodbtests) stopped.

[ObiWahn]

Any idea why the allocations could be partially replaced?

After adding an extra override for strdup the test was successful. Do you think it is possible that there is some non overridden special allocation function that is used by clangs osx strdup implementation?

[daanx]

Great -- thanks for the debug output. I am currently working on a mac book through these problems too and addressing various issues. My feeling is indeed that the system strdup calls an internal allocation routine... not sure. Also, I read somewhere that one cannot interpose functions in system libraries? So perhaps more is needed. For now, I will concentrate on making at least the basic scenarios work and protect against recursion in the thread local storage allocation.

[daanx]

I think the latest dev branch should now work with MI_INTERPOSE=ON on static-overload test. The dynamic one is still being worked on.

[ObiWahn]

Thank You! Unfortunately we have still problems.

cupertino:arangodb-build jenkins$ cmake -DCMAKE_BUILD_TYPE=Debug -DMI_CHECK_FULL=ON -DMI_INTERPOSE=ON ../arangodb on our mimalloc branch

[100%] Built target arangodbtests
cupertino:arangodb-build jenkins$ MIMALLOC_VERBOSE=1 lldb -- ./bin/arangodbtests --gtest_filter=SimpleHttpClientCommunicatorTest.requests_are_properly_aborted
(lldb) target create "./bin/arangodbtests"
Current executable set to './bin/arangodbtests' (x86_64).
(lldb) settings set -- target.run-args  "--gtest_filter=SimpleHttpClientCommunicatorTest.requests_are_properly_aborted"
(lldb) r
Process 31879 launched: './bin/arangodbtests' (x86_64)
mimalloc: option 'secure': 0
mimalloc: option 'pool_commit': 0
mimalloc: assertion failed: at "/Users/jenkins/arangodb/3rdParty/mimalloc/src/page.c":101, _mi_page_is_valid
  assertion: "segment->thread_id == page->heap->thread_id"
Process 31879 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
    frame #0: 0x00007fffc0a21d42 libsystem_kernel.dylib`__pthread_kill + 10
libsystem_kernel.dylib`__pthread_kill:
->  0x7fffc0a21d42 <+10>: jae    0x7fffc0a21d4c            ; <+20>
    0x7fffc0a21d44 <+12>: movq   %rax, %rdi
    0x7fffc0a21d47 <+15>: jmp    0x7fffc0a1acaf            ; cerror_nocancel
    0x7fffc0a21d4c <+20>: retq
Target 0: (arangodbtests) stopped.
(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
  * frame #0: 0x00007fffc0a21d42 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fffc0b0f457 libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fffc0987420 libsystem_c.dylib`abort + 129
    frame #3: 0x000000010563927f arangodbtests`_mi_assert_fail(assertion="segment->thread_id == page->heap->thread_id", fname="/Users/jenkins/arangodb/3rdParty/mimalloc/src/page.c", line=101, func="_mi_page_is_valid") at options.c:136                                                                                                                                                  
    frame #4: 0x0000000105631126 arangodbtests`_mi_page_is_valid(page=0x0000000111000060) at page.c:101
    frame #5: 0x0000000105633710 arangodbtests`mi_page_fresh_alloc(heap=0x00000001095f2058, pq=0x00000001095f2560, block_size=96) at page.c:219
    frame #6: 0x0000000105634872 arangodbtests`mi_page_fresh(heap=0x00000001095f2058, pq=0x00000001095f2560) at page.c:238
    frame #7: 0x00000001056345f3 arangodbtests`mi_page_queue_find_free_ex(heap=0x00000001095f2058, pq=0x00000001095f2560) at page.c:606
    frame #8: 0x000000010563327d arangodbtests`mi_find_free_page(heap=0x00000001095f2058, size=96) at page.c:634
    frame #9: 0x0000000105632e9f arangodbtests`_mi_malloc_generic(heap=0x00000001095f2058, size=96) at page.c:701
    frame #10: 0x00000001056351dd arangodbtests`_mi_page_malloc(heap=0x00000001095f2058, page=0x000000010783a238, size=96) at alloc.c:27
    frame #11: 0x00000001056353e4 arangodbtests`mi_heap_malloc_small(heap=0x00000001095f2058, size=96) at alloc.c:49
    frame #12: 0x00000001056355f0 arangodbtests`mi_heap_malloc(heap=0x00000001095f2058, size=96) at alloc.c:69
    frame #13: 0x000000010563496d arangodbtests`mi_malloc(size=96) at alloc.c:84
    frame #14: 0x0000000105634cc5 arangodbtests`_Znwm(n=96) at alloc-override.c:97
    frame #15: 0x000000010003edb5 arangodbtests`std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > >::allocate(unsigned long) [inlined] std::__1::__allocate(__size=96) at new:226                                         
    frame #16: 0x000000010003edac arangodbtests`std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > >::allocate(unsigned long) [inlined] std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::_
_1::allocator<char> > >::allocate(this=0x0000000109639358, __n=4, (null)=0x0000000000000000) at memory:1771
    frame #17: 0x000000010003ece6 arangodbtests`std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > >::allocate(unsigned long) [inlined] std::__1::allocator_traits<std::__1::allocator<std::__1::basic_string<char, std::__1
::char_traits<char>, std::__1::allocator<char> > > >::allocate(__a=0x0000000109639358, __n=4) at memory:1526
    frame #18: 0x000000010003ecca arangodbtests`std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > >::allocate(this=0x0000000109639348 size=1, __n=4) at vector:925                                                        
    frame #19: 0x00000001000ae889 arangodbtests`::__cxx_global_var_init.7() [inlined] std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > >::vector(this=0x0000000109639348 size=1, __il=([0] = "/Target/ToDo/", [1] = "/Targ
et/Pending/", [2] = "/Target/Finished/", [3] = "/Target/Failed/")) at vector:1278
    frame #20: 0x00000001000ae79d arangodbtests`::__cxx_global_var_init.7() [inlined] std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > >::vector(this=0x0000000109639348 size=1, __il=([0] = "/Target/ToDo/", [1] = "/Targ
et/Pending/", [2] = "/Target/Finished/", [3] = "/Target/Failed/")) at vector:1272
    frame #21: 0x00000001000ae773 arangodbtests`::__cxx_global_var_init.7() at Job.h:43
    frame #22: 0x00000001000afa7c arangodbtests`_GLOBAL__sub_I_ActiveFailoverTest.cpp at ActiveFailoverTest.cpp:0
    frame #23: 0x000000010f892a1b dyld`ImageLoaderMachO::doModInitFunctions(ImageLoader::LinkContext const&) + 385
    frame #24: 0x000000010f892c1e dyld`ImageLoaderMachO::doInitialization(ImageLoader::LinkContext const&) + 40
    frame #25: 0x000000010f88e4aa dyld`ImageLoader::recursiveInitialization(ImageLoader::LinkContext const&, unsigned int, char const*, ImageLoader::InitializerTimingList&, ImageLoader::UninitedUpwards&) + 338                                                                                                                                                                           
    frame #26: 0x000000010f88d524 dyld`ImageLoader::processInitializers(ImageLoader::LinkContext const&, unsigned int, ImageLoader::InitializerTimingList&, ImageLoader::UninitedUpwards&) + 138                                                                                                                                                                                            
    frame #27: 0x000000010f88d5b9 dyld`ImageLoader::runInitializers(ImageLoader::LinkContext const&, ImageLoader::InitializerTimingList&) + 75
    frame #28: 0x000000010f87f47a dyld`dyld::initializeMainExecutable() + 195
    frame #29: 0x000000010f8838c6 dyld`dyld::_main(macho_header const*, unsigned long, int, char const**, char const**, char const**, unsigned long*) + 3966
    frame #30: 0x000000010f87e249 dyld`dyldbootstrap::start(macho_header const*, int, char const**, long, macho_header const*, unsigned long*) + 470
    frame #31: 0x000000010f87e036 dyld`_dyld_start + 54

(lldb) f 4
frame #4: 0x0000000105631126 arangodbtests`_mi_page_is_valid(page=0x0000000111000060) at page.c:101
   98     mi_assert_internal(page->cookie != 0);
   99     if (page->heap!=NULL) {
   100      mi_segment_t* segment = _mi_page_segment(page);
-> 101      mi_assert_internal(segment->thread_id == page->heap->thread_id);
   102      mi_page_queue_t* pq = mi_page_queue_of(page);
   103      mi_assert_internal(mi_page_queue_contains(pq, page));
   104      mi_assert_internal(pq->block_size==page->block_size || page->block_size > MI_LARGE_SIZE_MAX || page->flags.in_full);
(lldb) p segment->thread_id
(uintptr_t) $0 = 140736574047168
(lldb) p page->heap->thread_id
(uintptr_t) $1 = 0

[daanx]

Good to hear there is progress -- just to confirm , the static-override test passes now right?
Also, the new error is "better" as it is an assertion failure in mimalloc (so happy we have thorough invariant checking!), and it seems to have started the actual program instead of having trouble during the dyld loading.

Actually, this could be related to another issue in the dev branch -- can you check you have the latest dev commits (in particular 1587058) ? Also, cmake the debug version with -DMI_CHECK_FULL=ON to ensure all invariants are checked continuously.

Apologies for your trouble, but your feedback is very helpful to get automatic overriding to work well on macOS.

[ObiWahn]

Sources upgraded maybe 3 hours ago from mimalloc/master

cupertino:bin jenkins$ MIMALLOC_VERBOSE=1 lldb -- ./static-override
(lldb) target create "./static-override"                                                 
Current executable set to './static-override' (x86_64).
(lldb) r
Process 34562 launched: './static-override' (x86_64)
mimalloc: process init: 0x7fffc980c3c0                                                   
mimalloc: debug level : 3
mimalloc: option 'secure': 0
mimalloc: option 'pool_commit': 0
mimalloc: option 'show_errors': 3
mimalloc: error: trying to mi_free a pointer that does not point to a valid heap space: 0x100100100                                                                                 
mimalloc: assertion failed: at "/Users/jenkins/arangodb/3rdParty/mimalloc/src/options.c":121, _mi_error_message                                                                     
  assertion: "false"
Process 34562 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
    frame #0: 0x00007fffc0a21d42 libsystem_kernel.dylib`__pthread_kill + 10              
libsystem_kernel.dylib`__pthread_kill:
->  0x7fffc0a21d42 <+10>: jae    0x7fffc0a21d4c            ; <+20>                       
    0x7fffc0a21d44 <+12>: movq   %rax, %rdi
    0x7fffc0a21d47 <+15>: jmp    0x7fffc0a1acaf            ; cerror_nocancel
    0x7fffc0a21d4c <+20>: retq
Target 0: (static-override) stopped.
(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
  * frame #0: 0x00007fffc0a21d42 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fffc0b0f457 libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fffc0987420 libsystem_c.dylib`abort + 129
    frame #3: 0x000000010000f04f static-override`_mi_assert_fail(assertion="false", fname="/Users/jenkins/arangodb/3rdParty/mimalloc/src/options.c", line=121, func="_mi_error_message") at options.c:136
    frame #4: 0x000000010000fad4 static-override`_mi_error_message(fmt="trying to mi_free a pointer that does not point to a valid heap space: %p\n") at options.c:121              
    frame #5: 0x000000010000a973 static-override`mi_free(p=0x0000000100100100) at alloc.c:212                                                                                       
    frame #6: 0x000000010000a8b5 static-override`free(p=0x0000000100100100) at alloc-override.c:64                                                                                  
    frame #7: 0x00000001000016c5 static-override`main at main-override.c:21
    frame #8: 0x00007fffc08f3235 libdyld.dylib`start + 1
(lldb)                                                                           

211    if (mi_unlikely(_mi_ptr_cookie(segment) != segment->cookie)) {
-> 212      _mi_error_message("trying to mi_free a pointer that does not point to a valid heap space: %p\n", p);
   213      return;

Thank you for your time!

[daanx]

Ah.. frustrating.. on Linux/BSD systems this is so easy with LD_PRELOAD ... :-)
Anyway, I will keep working on this -- I have the macOS machine available maybe tomorrow but otherwise next week. Apologies for your troubles getting the overriding to work for you.

[ObiWahn]

I there anything I can do? Should I try a newer version?

[daanx]

Ah sorry for not following up -- I have been just a bit too busy to look into it further. However, I have been working on improving the situation of dynamic overriding on Windows which should also help on the macOS side. I will try to look into it later today or otherwise tomorrow as I do have a macbook available now for testing.