Skip to content

Conversation

@JosiahWI
Copy link
Contributor

@JosiahWI JosiahWI commented Jun 8, 2024

The output of the DUMP_HEADER macro was being written in multiple calls to
fprintf() that raced with other logging, resulting in interleaved output that
intermittently failed the ja3_fingerprint AuTest on CI. Whether other AuTest
failures were related to the same issue is unknown at this point.

This fixes the race condition by batching the calls to a single fprintf() call.
This also refactors the macro to two inline functions. In a benchmark using an
expanded version of the headers in the HttpTransact tests, a 60% speedup was
measured over the macro if all the header data fit in the buffer. In the worst
case that the buffer could only hold a byte at a time, the speedup was 80%.
The benchmark was compiled with -O3 and stderr was piped to /dev/null.

These were the headers used for the benchmark:

  header input1[] = {
    {"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA", "111111111111111111111111"},
    {"BBB",                               "222"                     },
    {"CCC",                               "333"                     },
    {"DDD",                               "333"                     },
    {"EEE",                               "333"                     },
    {"FFF",                               "333"                     },
    {"GGG",                               "333"                     },
    {"HHH",                               "333"                     },
    {"III",                               "333"                     },
    {"JJJ",                               "333"                     },
    {"KKK",                               "333"                     },
  };

This fixes #11431.

@JosiahWI JosiahWI added this to the 10.1.0 milestone Jun 8, 2024
@JosiahWI JosiahWI self-assigned this Jun 8, 2024
@JosiahWI JosiahWI requested a review from bneradt June 8, 2024 16:38
@JosiahWI JosiahWI force-pushed the fix/dump-header-race branch from a4011d0 to b4335e5 Compare June 8, 2024 16:45
@JosiahWI
Copy link
Contributor Author

JosiahWI commented Jun 8, 2024

LSan detected a memory leak in the ImageMagick plugin.

bneradt
bneradt previously requested changes Jun 8, 2024
Copy link
Contributor

@bneradt bneradt left a comment

Choose a reason for hiding this comment

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

Looks good. It's a big bonus that this makes things more efficient when debug logging is on.

@JosiahWI
Copy link
Contributor Author

JosiahWI commented Jun 8, 2024

The regression test PARENT_SELECTION failed.

Copy link
Contributor

@bneradt bneradt left a comment

Choose a reason for hiding this comment

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

Looks good to me. I'll let a non-Yahoo reviewer chip in.

@JosiahWI JosiahWI requested a review from bneradt June 8, 2024 19:34
@bneradt bneradt dismissed their stale review June 8, 2024 19:55

Releasing my blocking review because all changes are done.

cmcfarlen
cmcfarlen previously approved these changes Jun 10, 2024
JosiahWI and others added 11 commits June 10, 2024 15:50
This removes the unused heap argument and updates calls across the whole
codebase accordingly.
This constifies some arguments to mime_field_print and mime_hdr_print and
updates usage throughout the codebase accordingly.
This removes the heap argument from the method and updates the usage
throughout the codebase.
This marks the hdr argument to http_hdr_print as const.
The output of the `DUMP_HEADER` macro was being written in multiple calls to
fprintf() that raced with other logging, resulting in interleaved output that
intermittently failed the ja3_fingerprint AuTest on CI. Whether other AuTest
failures were related to the same issue is unknown at this point.

This fixes the race condition by batching the calls to a single fprintf() call.
This also refactors the macro to two inline functions. In a benchmark using an
expanded version of the headers in the HttpTransact tests, a 60% speedup was
measured over the macro if all the header data fit in the buffer. In the worst
case that the buffer could only hold a byte at a time, the speedup was 80%.
The benchmark was compiled with -O3 and stderr was piped to /dev/null.

These were the headers used for the benchmark:
```
  header input1[] = {
    {"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA", "111111111111111111111111"},
    {"BBB",                               "222"                     },
    {"CCC",                               "333"                     },
    {"DDD",                               "333"                     },
    {"EEE",                               "333"                     },
    {"FFF",                               "333"                     },
    {"GGG",                               "333"                     },
    {"HHH",                               "333"                     },
    {"III",                               "333"                     },
    {"JJJ",                               "333"                     },
    {"KKK",                               "333"                     },
  };
```

This fixes apache#11431.
This makes the following changes:

 * The length parameter to string::append is used instead of adding a
   null terminator.
 * Some erroneous logic left over from testing is fixed.
This is an API change. The parameter is no longer used, so this commit removes
it and updates the developer documentation and core plugins accordingly.
@JosiahWI
Copy link
Contributor Author

Rebased and did the changes requested by @zwoop.

Copy link
Contributor

@bneradt bneradt left a comment

Choose a reason for hiding this comment

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

Looks good to me.

Since the API changed, the example plugins now need updating as well.
@JosiahWI
Copy link
Contributor Author

The AuTest bad_chunked_encoding failed with a very interesting message:

        Reason: Contents of /tmp/sandbox/bad_chunked_encoding/_output/bad_chunked_encoding-verifier-server2/stream.stdout.txt contained expression
     file /tmp/sandbox/bad_chunked_encoding/_output/bad_chunked_encoding-verifier-server2/stream.stdout.txt : Verify that the body never got through. - Failed
        Reason: Contents of /tmp/sandbox/bad_chunked_encoding/_output/bad_chunked_encoding-verifier-server2/stream.stdout.txt contains expression: "abc"
           Details:
             Via: http/1.1 traffic_server[9ecabccd-0556-4866-b183-7e2b1407c2fd] (ApacheTrafficServer/10.1.0) : 17
             Via: http/1.1 traffic_server[9ecabccd-0556-4866-b183-7e2b1407c2fd] (ApacheTrafficServer/10.1.0) : 35
             Via: http/1.1 traffic_server[9ecabccd-0556-4866-b183-7e2b1407c2fd] (ApacheTrafficServer/10.1.0) : 53
             Via: http/1.1 traffic_server[9ecabccd-0556-4866-b183-7e2b1407c2fd] (ApacheTrafficServer/10.1.0) : 71
             Via: http/1.1 traffic_server[9ecabccd-0556-4866-b183-7e2b1407c2fd] (ApacheTrafficServer/10.1.0) : 95
             Via: http/1.1 traffic_server[9ecabccd-0556-4866-b183-7e2b1407c2fd] (ApacheTrafficServer/10.1.0) : 119

@bryancall bryancall requested a review from zwoop June 10, 2024 22:18
@JosiahWI JosiahWI merged commit 054b6a8 into apache:master Jun 11, 2024
@JosiahWI JosiahWI deleted the fix/dump-header-race branch June 12, 2024 11:08
@cmcfarlen cmcfarlen modified the milestones: 10.1.0, 10.0.0 Jun 12, 2024
@cmcfarlen
Copy link
Contributor

Cherry-picked to v10.0.x

cmcfarlen pushed a commit that referenced this pull request Jun 12, 2024
* Remove unused argument from mime_hdr_print

This removes the unused heap argument and updates calls across the whole
codebase accordingly.

* Constify some arguments for MIME printing

This constifies some arguments to mime_field_print and mime_hdr_print and
updates usage throughout the codebase accordingly.

* Remove unused argument from http_hdr_print

This removes the heap argument from the method and updates the usage
throughout the codebase.

* Constify argument to http_hdr_status_get

* Constify argument to http_hdr_print

This marks the hdr argument to http_hdr_print as const.

* Constify the HTTPHdr::print method

* Fix race condition causing interleaved logs

The output of the `DUMP_HEADER` macro was being written in multiple calls to
fprintf() that raced with other logging, resulting in interleaved output that
intermittently failed the ja3_fingerprint AuTest on CI. Whether other AuTest
failures were related to the same issue is unknown at this point.

This fixes the race condition by batching the calls to a single fprintf() call.
This also refactors the macro to two inline functions. In a benchmark using an
expanded version of the headers in the HttpTransact tests, a 60% speedup was
measured over the macro if all the header data fit in the buffer. In the worst
case that the buffer could only hold a byte at a time, the speedup was 80%.
The benchmark was compiled with -O3 and stderr was piped to /dev/null.

These were the headers used for the benchmark:
```
  header input1[] = {
    {"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA", "111111111111111111111111"},
    {"BBB",                               "222"                     },
    {"CCC",                               "333"                     },
    {"DDD",                               "333"                     },
    {"EEE",                               "333"                     },
    {"FFF",                               "333"                     },
    {"GGG",                               "333"                     },
    {"HHH",                               "333"                     },
    {"III",                               "333"                     },
    {"JJJ",                               "333"                     },
    {"KKK",                               "333"                     },
  };
```

This fixes #11431.

* Implement changes requested by Brian Neradt

This makes the following changes:

 * The length parameter to string::append is used instead of adding a
   null terminator.
 * Some erroneous logic left over from testing is fixed.

* Fix formatting

* Add log output to dump_header for invalid hdrs

* Remove bufp parameter from TSMimeHdrPrint

This is an API change. The parameter is no longer used, so this commit removes
it and updates the developer documentation and core plugins accordingly.

* Fix the example plugins

Since the API changed, the example plugins now need updating as well.

(cherry picked from commit 054b6a8)
@bryancall bryancall mentioned this pull request Aug 15, 2024
91 tasks
maskit added a commit to maskit/trafficserver that referenced this pull request Aug 15, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

Status: picked-10.0.0

Development

Successfully merging this pull request may close these issues.

Intermittent CI failures of ja3_fingerprint

4 participants