Windows native build with ASan - Claude AI notes: ASan found a heap-use-after-free bug

Help!
52

Thinking out loud here so @jan, @peter.ludemann and @mgondan1 can see this and possibly comment.

The builds for the tests discussed below are done using MSVC + CMake, Debug, with ASan enabled..

Note: I am not entirely sure the following interpretation is correct. I have been trying to confirm details in Microsoft documentation, but searching for %ERRORLEVEL% has not been very helpful.

On Windows, %ERRORLEVEL% is used to propagate process exit codes (see Microsoft’s documentation on system error codes).

It appears that some tests do not check the value of %ERRORLEVEL% when running on Windows. As a result, tests may report as passed while still returning a non-zero exit code, which can lead to invalid or unexpected results.

This may be happening in the following case.

PREDICATE(call_cpp_ex, 2)
{ try
  { PlCheckFail(PlCall(A1, PL_Q_CATCH_EXCEPTION));
  } catch ( PlException& ex )
  { bool rc = A2.unify_term(ex.term());
    Plx_clear_exception();
    return rc;
  }
  return A2.unify_string("no exception");
}

Corresponding test

test(call_cpp_06,nondet) :-
    call_cpp_ex(unknown_pred(hello(世界四)), Ex),
    assertion(subsumes_term(error(existence_error(procedure, unknown_pred/1), _), Ex)).

When this test is run by itself, it reports success: passed (0.031 sec CPU)

However, checking %ERRORLEVEL% afterward shows that the return value is 1, not 0:

C:\dev-MSVC-PR\swipl-devel\build>"C:\dev-MSVC-PR\swipl-devel\build\src\Debug\swipl.exe" -p "foreign=" -f none --no-packs --on-error=status -s "C:/dev-MSVC-PR/swipl-devel/packages/cpp/test_cpp.pl" -g "run_tests(cpp:call_cpp_06)" -t halt
% Start unit: cpp
% [1/1] cpp:call_cpp_06 .................................................................................................................................... passed (0.035 sec)
% test passed

C:\dev-MSVC-PR\swipl-devel\build>echo %ERRORLEVEL%
1

For comparison, similar tests do return 0 as expected:

test(call_cpp_05, Ex == "no exception") :-
    call_cpp_ex(writeln(hello(世界四)), Ex).

C:\dev-MSVC-PR\swipl-devel\build>"C:\dev-MSVC-PR\swipl-devel\build\src\Debug\swipl.exe" -p "foreign=" -f none --no-packs --on-error=status -s "C:/dev-MSVC-PR/swipl-devel/packages/cpp/test_cpp.pl" -g "run_tests(cpp:call_cpp_05)" -t halt  
% Start unit: cpp
% [1/1] cpp:call_cpp_05 ..hello(世界四)
............................................................................................................................................................ passed (0.039 sec)
% End unit cpp: passed (0.047 sec CPU)
% test passed in 0.114 seconds (0.125 cpu)

C:\dev-MSVC-PR\swipl-devel\build>echo %ERRORLEVEL%                                                                                                                                     
0

test(call_cpp_03, error(existence_error(procedure,unknown_pred/1))) :-
    call_cpp(unknown_pred(hello(世界四))).

C:\dev-MSVC-PR\swipl-devel\build>"C:\dev-MSVC-PR\swipl-devel\build\src\Debug\swipl.exe" -p "foreign=" -f none --no-packs --on-error=status -s "C:/dev-MSVC-PR/swipl-devel/packages/cpp/test_cpp.pl" -g "run_tests(cpp:call_cpp_03)" -t halt
% Start unit: cpp
% [1/1] cpp:call_cpp_03 .................................................................................................................................... passed (0.039 sec)        
% End unit cpp: passed (0.031 sec CPU)
% test passed in 0.108 seconds (0.094 cpu)

C:\dev-MSVC-PR\swipl-devel\build>echo %ERRORLEVEL%
0

What led me to this

When call_cpp_06 is blocked, the output looks correct and test numbering proceeds as expected:

% [13/247] cpp:call_cpp_04 ..................................................................................................................... passed (0.000 sec)
% [14/247] cpp:call_cpp_05 ..hello(世界四)
................................................................................................................................................ passed (0.001 sec)        
% [15/247] cpp:call_cpp_09 ..................................................................................................................... passed (0.000 sec)        
% [16/247] cpp:as_string_01 .................................................................................................................... passed (0.000 sec)

(call_cpp_07 and call_cpp_08 are also blocked.)

However, when call_cpp_06 is unblocked, the output changes in an unexpected way:

% [13/248] cpp:call_cpp_04 ................................................................................................................................. passed (0.000 sec)        
% [14/248] cpp:call_cpp_05 ..hello(世界四)
............................................................................................................................................................ passed (0.000 sec)        
% [15/248] cpp:call_cpp_06 ................................................................................................................................. passed (0.000 sec)        
% 5 tests are blocked (use run_tests/2 with show_blocked(true) for details)
% All 248 (+-233 sub-tests) tests passed

What I would expect instead is for the output to continue with the remaining tests, for example:

% [16/248] cpp:call_cpp_09 ..................................................................................................................... passed (0.000 sec)        
% [17/248] cpp:as_string_01 .................................................................................................................... passed (0.000 sec)

…and then the rest of the test suite.