[
https://issues.apache.org/jira/browse/THRIFT-6244?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Jens Geyer resolved THRIFT-6244.
--------------------------------
Assignee: Jens Geyer
Resolution: Fixed
> TNonblockingServerTest intermittently crashes or hangs in
> bad_alloc_does_not_end_the_process
> --------------------------------------------------------------------------------------------
>
> Key: THRIFT-6244
> URL: https://issues.apache.org/jira/browse/THRIFT-6244
> Project: Thrift
> Issue Type: Bug
> Components: C++ - Library
> Reporter: Jens Geyer
> Assignee: Jens Geyer
> Priority: Minor
> Fix For: 0.25.0
>
> Time Spent: 20m
> Remaining Estimate: 0h
>
> {{TNonblockingServerTest}} fails intermittently on AppVeyor, always in the
> case {{bad_alloc_does_not_end_the_process}}: either the test binary crashes
> (ctest reports SEGFAULT) or it hangs until the 300 s ctest timeout.
> The case was added with
> [eda9f8d71|https://github.com/apache/thrift/commit/eda9f8d7171d88082ae5f00642411c11c92ba8a4],
> and the first AppVeyor build that contained it (0.25.0.10466) was also the
> first failure. Since then 11 of 229 jobs have failed (MSVC2022: 8 crashes and
> 2 timeouts out of 192 jobs; MinGW: 1 timeout out of 37), and 11 of 39 builds
> went red because of it. A search of all failed AppVeyor job logs since
> 2025-07-22 finds no earlier failure of this test.
> Example jobs:
> * crash:
> [0.25.0.10469|https://ci.appveyor.com/project/ApacheSoftwareFoundation/thrift/builds/54684673/job/fw4ai49opu5j66kw]
> * timeout:
> [0.25.0.10466|https://ci.appveyor.com/project/ApacheSoftwareFoundation/thrift/builds/54684499/job/ueslnq02ob7c29w7]
> h2. Cause 1: the fixture destroys the server while a thread-pool task is
> still running (crash)
> In the crashing runs, the server output of this case ends like this
> (timestamps removed):
> {noformat}
> TNonblockingServer: IO thread #0 entering loop...
> TNonblockingServer: IO thread #0 run() done!
> TNonblocking: join done for IO thread #0
> TNonblockingServer: process() exception: class std::bad_alloc: bad allocation
> TNonblockingServer: failed to notifyIOThread, closing.
> {noformat}
> The worker handling the deliberately failed call reaches its catch handler
> only after the fixture has already stopped the server:
> * {{FailsFirstCallProcessor}} sets its flag and throws. Meanwhile the second
> worker serves {{canCommunicate()}}, the test body returns, and the fixture is
> torn down.
> * The fixture destructor calls {{stop()}} on the server and {{join()}} on the
> serve thread, but never stops the {{ThreadManager}}.
> * The fixture members are then destroyed in reverse declaration order, the
> server before the thread manager. The {{TNonblockingServer}} destructor
> closes and deletes every connection and the IO threads, including the
> notification pipe; only afterwards does the {{ThreadManager}} destructor wait
> for its workers.
> * The pool task holds a raw pointer to its {{TConnection}}. The task that is
> still unwinding then calls {{notifyIOThread()}} on the deleted connection
> and, when that fails, {{close()}}.
> Four passing runs show the same late ordering, with {{run() done!}} logged
> before the {{bad_alloc}} line; they finished just in time.
> h2. Cause 2: the injected failure is not tied to the call meant to receive it
> (timeout)
> {{FailsFirstCallProcessor}} fails whichever call reaches {{process()}} first,
> tracked in a plain {{bool}} that both pool workers read and write. The call
> that consumes the failure gets no reply. If that is the {{addString}} call
> from {{canCommunicate()}}, its client, which has no receive timeout, blocks
> until ctest kills the test. The missing reply itself is the server behaviour
> tracked in THRIFT-6216; fixing that would turn the hang into a failed check,
> but would not remove the race. Two variants have been observed:
> * Windows: both workers saw the flag unset, and the log shows the
> {{bad_alloc}} line twice.
> * Linux, running the unmodified test under ASan with CPU load from 8 parallel
> loops: the order was inverted. The call meant to fail was served normally,
> its reply hitting the already closed connection ("Broken pipe"), and the call
> from {{canCommunicate()}} received the failure. 2 of 1200 runs hung; 400
> sequential runs all passed. The crash did not reproduce on Linux.
> h2. Proposed fix (test only)
> Both parts are needed, because each one closes only one of the two symptoms:
> # In the fixture destructor, stop the {{ThreadManager}} after joining the
> serve thread and before the server is destroyed. A task still in flight then
> completes while its connection and the notification pipe still exist. On its
> own this does not help with the timeout, because the test body hangs and
> teardown is never reached.
> # Tie the injected failure to the call meant to receive it: for example, use
> a {{std::atomic<bool>}} and call {{canCommunicate()}} only after that call
> has consumed the failure, signalled for instance through a {{Monitor}} right
> before the throw. On its own this does not help with the crash, because the
> failing task can still run into teardown.
> Optionally, a receive timeout on the socket in {{canCommunicate()}} would
> make a regression fail within seconds instead of after 300 s.
> Out of scope: {{TNonblockingServer::stop()}} and the server destructor do not
> wait for tasks still running in the thread pool, so an application currently
> has to stop the server, join the serve thread and stop the {{ThreadManager}}
> before destroying the server. Whether the server itself should wait is a
> separate question.
> _Drafted with AI assistance (Claude Opus 5)._
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
