Skip to content

Fix flaky server access log test by matching entries instead of exact count#6211

Open
delthas wants to merge 2 commits into
development/9.4from
bugfix/CLDSRV-923/fix-flaky-serveraccesslog-test
Open

Fix flaky server access log test by matching entries instead of exact count#6211
delthas wants to merge 2 commits into
development/9.4from
bugfix/CLDSRV-923/fix-flaky-serveraccesslog-test

Conversation

@delthas

@delthas delthas commented Jun 29, 2026

Copy link
Copy Markdown
Contributor

Symptom

testServerAccessLogFile.js flakes with AssertionError: Expected N log entries, got N+1 in file-ft-tests / file-ft-tests-null-compat, on a different operation each run.

Root cause (captured in CI)

The tests asserted an exact access-log entry count per operation and isolated tests by truncating the shared access-log file. Instrumenting the assertion to dump the collected entries caught the extra one red-handed, in two independent failures:

objectDeleteTagging: expected 4, got 5
  [0] CreateBucket        test-server-access-log-bucket
  [1] PutObject           test-server-access-log-bucket/test-object-key
  [2] GetObject           buckettestgetobject/someObject   <-- FOREIGN (unique req_id, http 200)
  [3] PutObjectTagging    test-server-access-log-bucket/test-object-key
  [4] DeleteObjectTagging test-server-access-log-bucket/test-object-key

The extra entry is a GetObject on buckettestgetobject — a bucket owned by test/object/get.js, a different suite. It has a unique req_id (so it is not an SDK-retry duplicate, contrary to the ticket's original hypothesis) and a foreign bucket/key.

Access-log lines are written on the server's res.on('close'), which under HTTP keep-alive can fire long after the response (on socket teardown). A request from another suite can therefore have its line written during a serverAccessLogs test, landing inside the truncate window. This is outside the test's control, so no count-based barrier in the test can fix it.

Fix

Stop asserting an exact count. Match each expected entry against the collected entries by its fields (the same field semantics as validateLogEntry) and ignore anything else. Unordered groups are flattened and matched independently, so interleaved foreign entries are tolerated regardless of when they arrive.

The first commit is an isolated prettier pass on the file (it predated prettier adoption); the second is the functional change.

Issue: CLDSRV-923

@bert-e

bert-e commented Jun 29, 2026

Copy link
Copy Markdown
Contributor

Hello delthas,

My role is to assist you with the merge of this
pull request. Please type @bert-e help to get information
on this process, or consult the user documentation.

Available options
name description privileged authored
/after_pull_request Wait for the given pull request id to be merged before continuing with the current one.
/bypass_author_approval Bypass the pull request author's approval
/bypass_build_status Bypass the build and test status
/bypass_commit_size Bypass the check on the size of the changeset TBA
/bypass_incompatible_branch Bypass the check on the source branch prefix
/bypass_jira_check Bypass the Jira issue check
/bypass_peer_approval Bypass the pull request peers' approval
/bypass_leader_approval Bypass the pull request leaders' approval
/approve Instruct Bert-E that the author has approved the pull request. ✍️
/create_pull_requests Allow the creation of integration pull requests.
/create_integration_branches Allow the creation of integration branches.
/no_octopus Prevent Wall-E from doing any octopus merge and use multiple consecutive merge instead
/unanimity Change review acceptance criteria from one reviewer at least to all reviewers
/wait Instruct Bert-E not to run until further notice.
Available commands
name description privileged
/help Print Bert-E's manual in the pull request.
/status Print Bert-E's current status in the pull request TBA
/clear Remove all comments from Bert-E from the history TBA
/retry Re-start a fresh build TBA
/build Re-start a fresh build TBA
/force_reset Delete integration branches & pull requests, and restart merge process from the beginning.
/reset Try to remove integration branches unless there are commits on them which do not appear on the source branch.

Status report is not available.

@scality scality deleted a comment from bert-e Jun 29, 2026
@bert-e

bert-e commented Jun 29, 2026

Copy link
Copy Markdown
Contributor

Waiting for approval

The following approvals are needed before I can proceed with the merge:

  • the author

  • 2 peers

@codecov

codecov Bot commented Jun 29, 2026

Copy link
Copy Markdown

❌ 1 Tests Failed:

Tests completed Failed Passed Skipped
9443 1 9442 0
View the full list of 1 ❄️ flaky test(s)
"before each" hook for "should retrieve a part that overwrote another part originally copied from an MPU"::GET object With default signature With PartNumber field uploadPartCopy overwrite "before each" hook for "should retrieve a part that overwrote another part originally copied from an MPU"

Flake rate in main: 100.00% (Passed 0 times, Failed 12 times)

Stack Traces | 32.9s run time
Connection timed out after 30000 ms

To view more test analytics, go to the Test Analytics Dashboard
📋 Got 3 mins? Take this short survey to help us improve Test Analytics.

Pure formatting pass with no behavior change, isolated into its own commit so
the functional change that follows has a clean, reviewable diff. The file
predated prettier adoption and had never been reformatted.

Issue: CLDSRV-923
Claude-Session: https://claude.ai/code/session_01QtnfMnRoAwPDEAdqnzPzjj
@delthas delthas force-pushed the bugfix/CLDSRV-923/fix-flaky-serveraccesslog-test branch 3 times, most recently from 2010786 to 3ae0c44 Compare June 30, 2026 13:30
@delthas delthas changed the title Fix flaky server access log test by draining log before truncate Fix flaky server access log test by matching entries instead of exact count Jun 30, 2026
The serverAccessLogs tests asserted an exact entry count per operation while
isolating tests by truncating the shared access-log file. That file is shared
by the whole server process, and a request's line is written on the response
'close' event, which under HTTP keep-alive can fire much later, on socket
teardown. A request from another suite (captured in CI: GetObject on
buckettestgetobject, from test/object/get.js) can therefore have its line
written during a serverAccessLogs test, landing inside the truncate window and
inflating the count by one. The failing operation varied run to run because the
victim was whichever test the foreign write happened to land in.

Match each expected entry against the collected entries by its fields and
ignore anything else, instead of asserting logEntries.length === totalExpected.
Unordered groups are flattened and matched independently, so interleaved
foreign entries are tolerated regardless of when they arrive.

Issue: CLDSRV-923
Claude-Session: https://claude.ai/code/session_01QtnfMnRoAwPDEAdqnzPzjj
@delthas delthas force-pushed the bugfix/CLDSRV-923/fix-flaky-serveraccesslog-test branch from 3ae0c44 to 03b105d Compare July 1, 2026 09:50
@delthas delthas marked this pull request as ready for review July 1, 2026 09:54
@delthas delthas requested review from a team, benzekrimaha, maeldonn and tcarmet July 1, 2026 09:54

@tcarmet tcarmet left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for having a look at it, much appreciated.

Comment on lines +48 to +51
const lines = content
.trim()
.split('\n')
.filter(line => line.length > 0);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll leave up to you to review if you think a little helper for those line would be useful since I see the same pattern below.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants