[FIXED] cleaning up sanitize=thread found several races #771

levb · 2024-07-13T05:07:39Z

note: I've been working on a bigger PR for async fetch (aka Consume), it is not ready yet but since it will be a big PR I'll try to send in parts that are ready to simplify the review. This is part 1.

Lock on msgDlvWorker->lock where we were not before.
Use natsSock_Shutdown rather than natsSock_Close from natsConnection_Reconnect to avoid a potential data race with the readloop.
Cleanup thread sanitizer CI runs and prior test failures. Fixes Tests failing -fsanitize=thread #672

Before this PR warnings generated by-fsanitize=thread in CI were ignored, since the detailed test logs were dropped and not scanned. This PR adds the log scanning.

It also uncovered several issues with the existing tests, all of them but one were relatively trivial. In Test_ForceReconnect detected a race caused by us forecefully close-ing an fd which is still being read on by the readloop. I could not think of a simple solution that would not have performance implications, so I disabled the test for thread sanitizer. The code seems to be doing the right thing anyway, and the readloop thread would error out, as designed.

The following tests were fixed:

Test_SrvVersionAtLeast
Test_ForcedReconnect
Test_ClientAutoUnsubAndReconnect
Test_AutoUnsubNoUnsubOnDestroy
Test_EventLoop
Test_JetStreamOrderedConsSrvRestart
Test_JetStreamOrderedConsumerWithErrors

This PR also adds a few more CI jobs, including (experimentally for now) DEV_MODE. I will remove the DEV_MODE jobs if they prove flaky and not easily fixable. Same for the (added) debug/sanitize jobs, will monitor and remove/fix if too slow/flaky.

test/test.c

codecov · 2024-07-13T05:11:42Z

Codecov Report

Attention: Patch coverage is 28.57143% with 15 lines in your changes missing coverage. Please review.

Project coverage is 68.79%. Comparing base (1553d4a) to head (bf65830).
Report is 2 commits behind head on main.

Files	Patch %	Lines
src/js.c	20.00%	3 Missing and 5 partials ⚠️
src/conn.c	36.36%	3 Missing and 4 partials ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #771      +/-   ##
==========================================
+ Coverage   68.71%   68.79%   +0.08%     
==========================================
  Files          39       39              
  Lines       15207    15227      +20     
  Branches     3143     3153      +10     
==========================================
+ Hits        10449    10476      +27     
+ Misses       1700     1684      -16     
- Partials     3058     3067       +9

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

kozlovic

All good catches with missing unlocking in tests. I have a question regarding the need of verbose output for sanitize thread and about the reconnect implementation.

.github/workflows/build-test.yml

test/test.c

kozlovic

Remove redirect to temp file? By the way, if you would have preferred having different PRs, you could have had one with just the close->shutdown change, that's it, and then once merged, rebase the PR that was just CI/Tests.
Finally, I had disabled sanitize=thread in Travis due to some bug in Ubuntu/travis combination. We may want to reactivate from time to time to see if that works now.

.github/workflows/build-test.yml

kozlovic · 2024-07-14T00:01:08Z

test/CMakeLists.txt

@@ -45,6 +45,10 @@ foreach(name ${listOfTestNames})
  # Make sure the test passes
  set_tests_properties(Test_${name} PROPERTIES PASS_REGULAR_EXPRESSION "ALL PASSED")

+  # Set TSAN_OPTIONS for the test
+  set_tests_properties(Test_${name} PROPERTIES


Does this have an effect on any other builds? (where we don't need/want sanitize)

I don't think so, since TSAN is for Thread SANitizer, and it's an environment variable for running the tests, not a build flag but I put it in an if for NATS_SANITIZE only just in case.

levb · 2024-07-15T09:14:08Z

@kozlovic The travis build still does sanitize=thread for clang. I tried to enable gcc, and got the same cmake configuration-time failure, so disabled it back. I added a fuller matrix of sanitize to GH Actions, will see what it produces.

levb · 2024-07-15T09:56:48Z

@kozlovic The fuller matrix found a couple more, in the code, missing libDlvWorker lock; please check.

kozlovic · 2024-07-15T18:09:41Z

.github/workflows/on-push-release.yml

+      sanitize: address
+      server_version: main
+
+  san-thread:


nit: Not sure why you would shorten to san- here while you used santize- for the address matrix run above :-)

shorter is better? :) (will change for consistency)

kozlovic · 2024-07-15T18:10:52Z

src/conn.c

@@ -1137,17 +1137,29 @@ _resendSubscriptions(natsConnection *nc)

        adjustedMax = 0;
        natsSub_Lock(sub);
+        if (sub->libDlvWorker != NULL)


There are macro for lock/unlock of this in sub.c. Maybe we move the definition of these in sub.h (we include this header in conn.c), and so you could replace these 2 lines with:

SUB_DLV_WORKER_LOCK(sub);

@kozlovic I stayed away from further exposing these macros. I am about to submit a re-factor (just passed all tests now without kicking!) that hopefully eliminates the need for double-locking, leaving the worker lock almost exclusively to protect the message queue. Ditto for the sub->closed comment.

It's ok with me if we keep this PR "hanging" for now until you see the upcoming solution, and then we can decide which way to fix? I just want to have it as my base branch to get the CI/unrelated test fixes out of the way.

Not sure I understand the last part, that is, do you want to merge this PR to be the base for the other work or the other work will be the (re)base for the CI changes. Either way, I am going to LGTM this PR so that you proceed as you wish.

kozlovic · 2024-07-15T18:12:22Z

src/conn.c

        // If JS ordered consumer, trigger a reset. Don't check the error
        // condition here. If there is a failure, it will be retried
        // at the next HB interval.
        if ((sub->jsi != NULL) && (sub->jsi->ordered))
        {
            jsSub_resetOrderedConsumer(sub, sub->jsi->sseq+1);
+            if (sub->libDlvWorker != NULL)


and:

SUB_DLV_WORKER_UNLOCK(sub);

kozlovic · 2024-07-15T18:15:22Z

src/js.c

@@ -2045,6 +2045,10 @@ _hbTimerFired(natsTimer *timer, void* closure)
    natsStatus          s    = NATS_OK;

    natsSub_Lock(sub);
+    if (sub->libDlvWorker != NULL)


Same than for conn.c. We also include sub.h here, so that would work.

kozlovic · 2024-07-15T18:24:34Z

src/js.c

+        if (sub->libDlvWorker != NULL)
+        {
+            natsMutex_Lock(sub->libDlvWorker->lock);
+        }
        if (!sub->closed)


Humm... there are may places where we check this under the sub's lock only. Sure, it is set under both locks and checked only under the lib's lock in nats.c (the code that deals with the delivery's pool thread), but if we find many other reports, then I think it would be simpler to modify _deliverMsgs so that we capture sub->closed under the sub's lock after releasing the delivery's lock. Anyway, for now change is ok, but again, let's keep that in mind.

kozlovic

LGTM

kozlovic

LGTM

levb added 2 commits July 12, 2024 21:37

[TEST+CI only] cleanup of sanitizeThread

943b315

Removed repeat 10

eb9412c

levb requested review from mtmk and kozlovic July 13, 2024 05:07

levb commented Jul 13, 2024

View reviewed changes

test/test.c Outdated Show resolved Hide resolved

levb mentioned this pull request Jul 13, 2024

callbacks on natsConnection are called after natsConnection_destroy #735

Open

kozlovic reviewed Jul 13, 2024

View reviewed changes

.github/workflows/build-test.yml Outdated Show resolved Hide resolved

test/test.c Outdated Show resolved Hide resolved

levb added 2 commits July 13, 2024 11:52

use TSAN_OPTIONS

b1a6e9c

PR feedback: use natsSock_Shutdown in natsConnection_Reconnect

7723d1a

levb changed the title ~~[TEST+CI only] cleanup of sanitizeThread~~ [FIXED] use natsSock_Shutdown in Reconnect to avoid a race Jul 13, 2024

levb requested a review from kozlovic July 13, 2024 20:04

kozlovic requested changes Jul 14, 2024

View reviewed changes

levb added 2 commits July 15, 2024 01:53

PR feedback

23e8b68

disabled sanitize with gcc on travis again

4154667

levb added 4 commits July 15, 2024 02:28

Fix data race in _resendSubscriptions: add a delivery worker lock

9966b92

removed a blank line

f54999c

removed TSAN extra verbosity

4846196

fixed another race, in JetStreamSubscribeIdleHeartbeat

ee40b68

levb requested a review from kozlovic July 15, 2024 09:55

levb and others added 3 commits July 15, 2024 03:00

experiment with double-coverage

6804cae

Merge branch 'main' into lev-ci-logging-threadsanitizer

caddb65

Merge branch 'main' into lev-ci-logging-threadsanitizer

80a9b40

levb changed the title ~~[FIXED] use natsSock_Shutdown in Reconnect to avoid a race~~ [FIXED] cleaning up sanitize=thread found several races Jul 15, 2024

kozlovic requested changes Jul 15, 2024

View reviewed changes

kozlovic approved these changes Jul 15, 2024

View reviewed changes

Fixed test_MicroAsyncErrorHandler_MaxPendingMsgs

bf65830

kozlovic approved these changes Jul 19, 2024

View reviewed changes

levb merged commit bd700a9 into main Jul 22, 2024
28 checks passed

levb deleted the lev-ci-logging-threadsanitizer branch July 22, 2024 22:00

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[FIXED] cleaning up sanitize=thread found several races #771

[FIXED] cleaning up sanitize=thread found several races #771

levb commented Jul 13, 2024 •

edited

Loading

codecov bot commented Jul 13, 2024 •

edited

Loading

kozlovic left a comment

kozlovic left a comment

kozlovic Jul 14, 2024

levb Jul 15, 2024

levb commented Jul 15, 2024

levb commented Jul 15, 2024

kozlovic Jul 15, 2024

levb Jul 15, 2024

kozlovic Jul 15, 2024

levb Jul 15, 2024

kozlovic Jul 15, 2024

kozlovic Jul 15, 2024

kozlovic Jul 15, 2024

kozlovic Jul 15, 2024

kozlovic left a comment

kozlovic left a comment

[FIXED] cleaning up sanitize=thread found several races #771

[FIXED] cleaning up sanitize=thread found several races #771

Conversation

levb commented Jul 13, 2024 • edited Loading

codecov bot commented Jul 13, 2024 • edited Loading

Codecov Report

kozlovic left a comment

Choose a reason for hiding this comment

kozlovic left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

levb commented Jul 15, 2024

levb commented Jul 15, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

kozlovic left a comment

Choose a reason for hiding this comment

kozlovic left a comment

Choose a reason for hiding this comment

levb commented Jul 13, 2024 •

edited

Loading

codecov bot commented Jul 13, 2024 •

edited

Loading