You are viewing a plain text version of this content. The canonical link for it is here.
Posted to github@trafficserver.apache.org by "bneradt (via GitHub)" <gi...@apache.org> on 2026/04/04 17:44:46 UTC
[PR] Log malformed HTTP/2 requests [trafficserver]
bneradt opened a new pull request, #13059:
URL: https://github.com/apache/trafficserver/pull/13059
Unlike HTTP/1 transactions, malformed HTTP/2 requests are rejected before HttpSM creation, so they bypassed the normal transaction logging path. That left malformed h2 traffic out of squid.log even when similar h1 failures were visible.
This adds a pre-transaction LogAccess path for malformed h2 request headers and emits a best-effort access log entry before resetting the stream.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "cmcfarlen (via GitHub)" <gi...@apache.org>.
cmcfarlen commented on PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#issuecomment-4291724296
Added to milestone 10.2.0 via #13105
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3067241677
##########
src/proxy/logging/CMakeLists.txt:
##########
@@ -54,6 +54,10 @@ if(BUILD_TESTING)
target_compile_definitions(test_RolledLogDeleter PRIVATE TEST_LOG_UTILS)
target_link_libraries(test_RolledLogDeleter tscore ts::inkevent records Catch2::Catch2WithMain)
add_catch2_test(NAME test_RolledLogDeleter COMMAND test_RolledLogDeleter)
+
+ add_executable(test_LogAccess unit-tests/test_LogAccess.cc)
+ target_link_libraries(test_LogAccess ts::logging ts::http ts::inkevent records Catch2::Catch2WithMain)
Review Comment:
True. We can get rid of `ts:http` now, but that was indirectly pulling in `ts::configmanager` which is needed. Replacing it with `ts::configmanager`.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "Copilot (via GitHub)" <gi...@apache.org>.
Copilot commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3035855585
##########
src/proxy/http2/Http2ConnectionState.cc:
##########
@@ -76,6 +78,132 @@ const int buffer_size_index[HTTP2_FRAME_TYPE_MAX] = {
BUFFER_SIZE_INDEX_16K, // HTTP2_FRAME_TYPE_CONTINUATION
};
+/** Fetch a header field value from a decoded HTTP/2 request.
+ *
+ * @param[in] hdr The decoded request header block to inspect.
+ * @param[in] name The field name to look up.
+ * @return The field value, or an empty view if the field is absent.
+ */
+std::string_view
+get_header_field_value(HTTPHdr const &hdr, std::string_view name)
+{
+ if (auto *field = const_cast<HTTPHdr &>(hdr).field_find(name); field != nullptr) {
Review Comment:
`get_header_field_value()` const-casts the `HTTPHdr` to call `field_find()`. Since `HTTPHdr` inherits `MIMEHdr`, you can call the `const` overload (`hdr.field_find(name)`) or use `hdr.value_get(name)` to avoid the const_cast and make the intent clearer.
```suggestion
if (auto *field = hdr.field_find(name); field != nullptr) {
```
##########
tests/gold_tests/connect/replays/h2_malformed_request_logging.replay.yaml:
##########
@@ -0,0 +1,90 @@
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+# This replays healthy HTTP/2 requests to verify their logging.
+
+meta:
+ version: "1.0"
+
+sessions:
+ - protocol:
+ stack: http2
+ tls:
+ sni: www.example.com
+ transactions:
+ - client-request:
+ headers:
+ encoding: esc_json
+ fields:
+ - [ :method, GET ]
+ - [ :scheme, https ]
+ - [ :authority, www.example.com ]
+ - [ :path, /valid-get ]
+ - [ uuid, valid-get ]
+ content:
+ encoding: plain
+ size: 0
+
+ proxy-request:
+ method: GET
+
+ server-response:
+ status: 200
+ reason: OK
+ content:
+ encoding: plain
+ data: response_to_valid_get
+ size: 21
+
+ proxy-response:
+ status: 200
+ content:
+ verify: { value: "response_to_valid_get", as: contains }
+ - protocol:
+ stack: http2
+ tls:
+ sni: www.example.com
+ transactions:
+ - client-request:
+ frames:
+ - HEADERS:
+ headers:
+ fields:
+ - [:method, CONNECT]
+ - [:authority, www.example.com:80]
+ - [uuid, valid-connect]
+ - [test, connect-request]
+ - DATA:
+ content:
+ encoding: plain
+ data: "GET /get HTTP/1.1\r\nuuid: valid-connect\r\ntest: real-request\r\n\r\n"
+
+ # Note: the server will received the tunneled GET request.
Review Comment:
The comment has a grammar typo: “the server will received” should be “the server will receive”.
```suggestion
# Note: the server will receive the tunneled GET request.
```
##########
src/proxy/logging/LogAccess.cc:
##########
@@ -1777,12 +1855,14 @@ LogAccess::marshal_proxy_protocol_tls_group(char *buf)
int
LogAccess::marshal_client_host_port(char *buf)
{
- if (m_http_sm) {
+ if (has_http_sm()) {
auto txn = m_http_sm->get_ua_txn();
if (txn) {
uint16_t port = txn->get_client_port();
marshal_int(buf, port);
}
+ } else if (auto const *pre = this->get_pre_transaction_log_data(); pre != nullptr) {
+ marshal_int(buf, ats_ip_port_host_order(reinterpret_cast<sockaddr const *>(&pre->client_addr)));
Review Comment:
`marshal_client_host_port()` calls `marshal_int(buf, ...)` even when `buf` is nullptr. Log marshaling commonly calls these marshal_* methods with `buf==nullptr` to compute the field length, so this will dereference null and crash. Add a `if (buf) { ... }` guard (similar to `marshal_remote_host_port()`) before writing.
```suggestion
if (buf) {
if (has_http_sm()) {
auto txn = m_http_sm->get_ua_txn();
if (txn) {
uint16_t port = txn->get_client_port();
marshal_int(buf, port);
}
} else if (auto const *pre = this->get_pre_transaction_log_data(); pre != nullptr) {
marshal_int(buf, ats_ip_port_host_order(reinterpret_cast<sockaddr const *>(&pre->client_addr)));
}
```
##########
tests/gold_tests/connect/h2_malformed_request_logging.test.py:
##########
@@ -0,0 +1,207 @@
+'''
+Verify malformed HTTP/2 requests are access logged.
+'''
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import os
+import re
+import sys
+
+Test.Summary = 'Malformed HTTP/2 requests are logged before transaction creation'
+
+
+class MalformedH2RequestLoggingTest:
+ """
+ Exercise malformed and valid HTTP/2 request logging paths.
+ """
+
+ REPLAY_FILE = 'replays/h2_malformed_request_logging.replay.yaml'
+ MALFORMED_CLIENT = 'malformed_h2_request_client.py'
+ MALFORMED_CASES = (
+ {
+ 'scenario': 'connect-missing-authority',
+ 'uuid': 'malformed-connect',
+ 'method': 'CONNECT',
+ 'pqu': '/',
+ 'description': 'Send malformed HTTP/2 CONNECT request',
+ },
+ {
+ 'scenario': 'get-missing-path',
+ 'uuid': 'malformed-get-missing-path',
+ 'method': 'GET',
+ 'pqu': 'https://missing-path.example/',
+ 'description': 'Send malformed HTTP/2 GET request without :path',
+ },
+ {
+ 'scenario': 'get-connection-header',
+ 'uuid': 'malformed-get-connection',
+ 'method': 'GET',
+ 'pqu': 'https://bad-connection.example/bad-connection',
+ 'description': 'Send malformed HTTP/2 GET request with Connection header',
+ },
+ )
+
+ def __init__(self):
+ self._setup_server()
+ self._setup_ts()
+ self._processes_started = False
+ Test.Setup.CopyAs(self.MALFORMED_CLIENT, Test.RunDirectory)
+
+ @property
+ def _squid_log_path(self) -> str:
+ return os.path.join(self._ts.Variables.LOGDIR, 'squid.log')
+
+ def _setup_server(self):
+ self._server = Test.MakeVerifierServerProcess('malformed-request-server', self.REPLAY_FILE)
+ for case in self.MALFORMED_CASES:
+ self._server.Streams.stdout += Testers.ExcludesExpression(
+ f'uuid: {case["uuid"]}',
+ f'{case["description"]} must not reach the origin server.',
+ )
+ self._server.Streams.stdout += Testers.ContainsExpression(
+ 'GET /get HTTP/1.1\nuuid: valid-connect',
+ reflags=re.MULTILINE,
+ description='A valid CONNECT tunnel should still reach the origin.',
+ )
+ self._server.Streams.stdout += Testers.ContainsExpression(
+ r'GET /valid-get HTTP/1\.1\n(?:.*\n)*uuid: valid-get',
+ reflags=re.MULTILINE,
+ description='A valid non-CONNECT request should still reach the origin.',
+ )
+
+ def _setup_ts(self):
+ self._ts = Test.MakeATSProcess('ts', enable_tls=True, enable_cache=False)
+ self._ts.addDefaultSSLFiles()
+ self._ts.Disk.File(
+ os.path.join(self._ts.Variables.CONFIGDIR, 'storage.config'),
+ id='storage_config',
+ typename='ats:config',
+ )
+ self._ts.Disk.storage_config.AddLine('')
+ self._ts.Disk.ssl_multicert_yaml.AddLines(
+ """
+ssl_multicert:
+ - dest_ip: "*"
+ ssl_cert_name: server.pem
+ ssl_key_name: server.key
+""".split('\n'))
+ self._ts.Disk.File(
+ os.path.join(self._ts.Variables.CONFIGDIR, 'ssl_multicert.config'),
+ id='ssl_multicert_config',
+ typename='ats:config',
+ )
+ self._ts.Disk.ssl_multicert_config.AddLine('ssl_cert_name=server.pem ssl_key_name=server.key dest_ip=*')
+
+ self._ts.Disk.records_config.update(
+ {
+ 'proxy.config.diags.debug.enabled': 1,
+ 'proxy.config.diags.debug.tags': 'http|hpack|http2',
+ 'proxy.config.ssl.server.cert.path': self._ts.Variables.SSLDir,
+ 'proxy.config.ssl.server.private_key.path': self._ts.Variables.SSLDir,
+ 'proxy.config.http.server_ports': f'{self._ts.Variables.ssl_port}:ssl',
+ 'proxy.config.http.connect_ports': self._server.Variables.http_port,
+ })
+ self._ts.Disk.remap_config.AddLine(f'map / http://127.0.0.1:{self._server.Variables.http_port}/')
+ self._ts.Disk.logging_yaml.AddLines(
+ """
+logging:
+ formats:
+ - name: malformed_h2_request
+ format: 'uuid=%<{uuid}cqh> cqpv=%<cqpv> cqhm=%<cqhm> crc=%<crc> sstc=%<sstc> pqu=%<pqu>'
+ logs:
+ - filename: squid
+ format: malformed_h2_request
+ mode: ascii
+""".split('\n'))
+ self._ts.Disk.diags_log.Content = Testers.ContainsExpression(
+ 'recv headers malformed request',
+ 'ATS should reject malformed requests at the HTTP/2 layer.',
+ )
+ for index, case in enumerate(self.MALFORMED_CASES):
+ expected = (
+ rf'uuid={case["uuid"]} cqpv=http/2 cqhm={case["method"]} '
+ rf'crc=ERR_INVALID_REQ sstc=0 pqu={re.escape(case["pqu"])}')
+ tester = Testers.ContainsExpression(
+ expected,
+ f'{case["description"]} should be logged with ERR_INVALID_REQ.',
+ )
+ if index == 0:
+ self._ts.Disk.squid_log.Content = tester
+ else:
+ self._ts.Disk.squid_log.Content += tester
+ self._ts.Disk.squid_log.Content += Testers.ContainsExpression(
+ r'uuid=valid-connect cqpv=http/2 cqhm=CONNECT ',
+ 'A valid HTTP/2 CONNECT should still use the normal transaction log path.',
+ )
+ self._ts.Disk.squid_log.Content += Testers.ContainsExpression(
+ r'uuid=valid-get cqpv=http/2 cqhm=GET ',
+ 'A valid HTTP/2 GET should still use the normal transaction log path.',
+ )
+ self._ts.Disk.squid_log.Content += Testers.ExcludesExpression(
+ r'uuid=valid-connect .*crc=ERR_INVALID_REQ',
+ 'Valid HTTP/2 CONNECT logging must not be marked as malformed.',
+ )
+ self._ts.Disk.squid_log.Content += Testers.ExcludesExpression(
+ r'uuid=valid-get .*crc=ERR_INVALID_REQ',
+ 'Valid HTTP/2 GET logging must not be marked as malformed.',
+ )
+
+ def _add_malformed_request_runs(self):
+ for case in self.MALFORMED_CASES:
+ tr = Test.AddTestRun(case['description'])
+ tr.Processes.Default.Command = (
+ f'{sys.executable} {self.MALFORMED_CLIENT} {self._ts.Variables.ssl_port} {case["scenario"]}')
+ tr.Processes.Default.ReturnCode = 0
+ self._keep_support_processes_running(tr)
+ tr.Processes.Default.Streams.stdout += Testers.ContainsExpression(
+ r'Received (RST_STREAM on stream 1 with error code 1|GOAWAY with error code [01])',
+ 'ATS should reject the malformed request at the HTTP/2 layer.',
+ )
+
+ def _add_valid_request_run(self):
+ tr = Test.AddTestRun('Send valid HTTP/2 requests')
+ tr.AddVerifierClientProcess('valid-request-client', self.REPLAY_FILE, https_ports=[self._ts.Variables.ssl_port])
+ self._keep_support_processes_running(tr)
+
+ def _await_malformed_log_entries(self):
+ tr = Test.AddAwaitFileContainsTestRun(
+ 'Await malformed request squid log entries',
+ self._squid_log_path,
+ 'crc=ERR_INVALID_REQ',
+ desired_count=len(self.MALFORMED_CASES),
+ )
+ self._keep_support_processes_running(tr)
+
+ def _keep_support_processes_running(self, tr):
+ if self._processes_started:
+ tr.StillRunningAfter = self._server
+ tr.StillRunningAfter = self._ts
+ return
+
+ tr.Processes.Default.StartBefore(self._server)
+ tr.Processes.Default.StartBefore(self._ts)
+ tr.StillRunningAfter = self._server
+ tr.StillRunningAfter = self._ts
Review Comment:
`StillRunningAfter` is assigned twice, so the second assignment overwrites the first and only one support process is kept running. Use `StillRunningAfter += ...` when adding additional processes (as done in other gold tests).
```suggestion
tr.StillRunningAfter += self._ts
return
tr.Processes.Default.StartBefore(self._server)
tr.Processes.Default.StartBefore(self._ts)
tr.StillRunningAfter = self._server
tr.StillRunningAfter += self._ts
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#issuecomment-4210107705
Converting to a draft while I work on @maskit 's comments. I'll un-draft when the patch is in better shape.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "maskit (via GitHub)" <gi...@apache.org>.
maskit commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3061288484
##########
src/proxy/logging/CMakeLists.txt:
##########
@@ -54,6 +54,10 @@ if(BUILD_TESTING)
target_compile_definitions(test_RolledLogDeleter PRIVATE TEST_LOG_UTILS)
target_link_libraries(test_RolledLogDeleter tscore ts::inkevent records Catch2::Catch2WithMain)
add_catch2_test(NAME test_RolledLogDeleter COMMAND test_RolledLogDeleter)
+
+ add_executable(test_LogAccess unit-tests/test_LogAccess.cc)
+ target_link_libraries(test_LogAccess ts::logging ts::http ts::inkevent records Catch2::Catch2WithMain)
Review Comment:
I wonder what requires `ts::http`.
##########
src/proxy/http/TransactionLogData.cc:
##########
@@ -0,0 +1,284 @@
+/** @file
+
+ TransactionLogData implementation: populate LogData from a live HttpSM.
+
+ @section license License
+
+ Licensed to the Apache Software Foundation (ASF) under one
+ or more contributor license agreements. See the NOTICE file
+ distributed with this work for additional information
+ regarding copyright ownership. The ASF licenses this file
+ to you under the Apache License, Version 2.0 (the
+ "License"); you may not use this file except in compliance
+ with the License. You may obtain a copy of the License at
+
+ http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing, software
+ distributed under the License is distributed on an "AS IS" BASIS,
+ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ See the License for the specific language governing permissions and
+ limitations under the License.
+ */
+
+#include "proxy/http/TransactionLogData.h"
+#include "proxy/http/HttpSM.h"
+#include "proxy/logging/LogAccess.h"
+#include "proxy/hdrs/MIME.h"
+#include "../private/SSLProxySession.h"
+
+namespace
+{
+/** Map HttpTransact::CacheWriteStatus_t to LogCacheWriteCodeType. */
+int
+convert_cache_write_code(HttpTransact::CacheWriteStatus_t t)
+{
+ switch (t) {
+ case HttpTransact::CacheWriteStatus_t::NO_WRITE:
+ return LOG_CACHE_WRITE_NONE;
+ case HttpTransact::CacheWriteStatus_t::LOCK_MISS:
+ return LOG_CACHE_WRITE_LOCK_MISSED;
+ case HttpTransact::CacheWriteStatus_t::IN_PROGRESS:
+ return LOG_CACHE_WRITE_LOCK_ABORTED;
+ case HttpTransact::CacheWriteStatus_t::ERROR:
+ return LOG_CACHE_WRITE_ERROR;
+ case HttpTransact::CacheWriteStatus_t::COMPLETE:
+ return LOG_CACHE_WRITE_COMPLETE;
+ default:
+ ink_assert(!"bad cache write code");
+ return LOG_CACHE_WRITE_NONE;
+ }
+}
+
+int
+compute_client_finish_status(HttpSM *sm)
+{
+ HttpTransact::AbortState_t cl_abort_state = sm->t_state.client_info.abort;
+ if (cl_abort_state == HttpTransact::ABORTED) {
+ if (sm->t_state.client_info.state == HttpTransact::ACTIVE_TIMEOUT ||
+ sm->t_state.client_info.state == HttpTransact::INACTIVE_TIMEOUT) {
+ return LOG_FINISH_TIMEOUT;
+ }
+ return LOG_FINISH_INTR;
+ }
+ return LOG_FINISH_FIN;
+}
+
+int
+compute_proxy_finish_status(HttpSM *sm)
+{
+ if (sm->t_state.current.server) {
+ switch (sm->t_state.current.server->state) {
+ case HttpTransact::ACTIVE_TIMEOUT:
+ case HttpTransact::INACTIVE_TIMEOUT:
+ return LOG_FINISH_TIMEOUT;
+ case HttpTransact::CONNECTION_ERROR:
+ return LOG_FINISH_INTR;
+ default:
+ if (sm->t_state.current.server->abort == HttpTransact::ABORTED) {
+ return LOG_FINISH_INTR;
+ }
+ break;
+ }
+ }
+ return LOG_FINISH_FIN;
+}
+} // end anonymous namespace
+
+TransactionLogData::TransactionLogData(HttpSM *sm) : m_http_sm(sm)
+{
+ ink_assert(sm != nullptr);
+
+ milestones = &sm->milestones;
Review Comment:
I think we don't do these copies now, do we? Since `TransactionLogData` has `m_http_sm`, it should be able to provide getters.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3067235556
##########
src/proxy/http/TransactionLogData.cc:
##########
@@ -0,0 +1,284 @@
+/** @file
+
+ TransactionLogData implementation: populate LogData from a live HttpSM.
+
+ @section license License
+
+ Licensed to the Apache Software Foundation (ASF) under one
+ or more contributor license agreements. See the NOTICE file
+ distributed with this work for additional information
+ regarding copyright ownership. The ASF licenses this file
+ to you under the Apache License, Version 2.0 (the
+ "License"); you may not use this file except in compliance
+ with the License. You may obtain a copy of the License at
+
+ http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing, software
+ distributed under the License is distributed on an "AS IS" BASIS,
+ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ See the License for the specific language governing permissions and
+ limitations under the License.
+ */
+
+#include "proxy/http/TransactionLogData.h"
+#include "proxy/http/HttpSM.h"
+#include "proxy/logging/LogAccess.h"
+#include "proxy/hdrs/MIME.h"
+#include "../private/SSLProxySession.h"
+
+namespace
+{
+/** Map HttpTransact::CacheWriteStatus_t to LogCacheWriteCodeType. */
+int
+convert_cache_write_code(HttpTransact::CacheWriteStatus_t t)
+{
+ switch (t) {
+ case HttpTransact::CacheWriteStatus_t::NO_WRITE:
+ return LOG_CACHE_WRITE_NONE;
+ case HttpTransact::CacheWriteStatus_t::LOCK_MISS:
+ return LOG_CACHE_WRITE_LOCK_MISSED;
+ case HttpTransact::CacheWriteStatus_t::IN_PROGRESS:
+ return LOG_CACHE_WRITE_LOCK_ABORTED;
+ case HttpTransact::CacheWriteStatus_t::ERROR:
+ return LOG_CACHE_WRITE_ERROR;
+ case HttpTransact::CacheWriteStatus_t::COMPLETE:
+ return LOG_CACHE_WRITE_COMPLETE;
+ default:
+ ink_assert(!"bad cache write code");
+ return LOG_CACHE_WRITE_NONE;
+ }
+}
+
+int
+compute_client_finish_status(HttpSM *sm)
+{
+ HttpTransact::AbortState_t cl_abort_state = sm->t_state.client_info.abort;
+ if (cl_abort_state == HttpTransact::ABORTED) {
+ if (sm->t_state.client_info.state == HttpTransact::ACTIVE_TIMEOUT ||
+ sm->t_state.client_info.state == HttpTransact::INACTIVE_TIMEOUT) {
+ return LOG_FINISH_TIMEOUT;
+ }
+ return LOG_FINISH_INTR;
+ }
+ return LOG_FINISH_FIN;
+}
+
+int
+compute_proxy_finish_status(HttpSM *sm)
+{
+ if (sm->t_state.current.server) {
+ switch (sm->t_state.current.server->state) {
+ case HttpTransact::ACTIVE_TIMEOUT:
+ case HttpTransact::INACTIVE_TIMEOUT:
+ return LOG_FINISH_TIMEOUT;
+ case HttpTransact::CONNECTION_ERROR:
+ return LOG_FINISH_INTR;
+ default:
+ if (sm->t_state.current.server->abort == HttpTransact::ABORTED) {
+ return LOG_FINISH_INTR;
+ }
+ break;
+ }
+ }
+ return LOG_FINISH_FIN;
+}
+} // end anonymous namespace
+
+TransactionLogData::TransactionLogData(HttpSM *sm) : m_http_sm(sm)
+{
+ ink_assert(sm != nullptr);
+
+ milestones = &sm->milestones;
Review Comment:
That's a good idea. Implemented with getters.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3067245470
##########
src/proxy/logging/CMakeLists.txt:
##########
@@ -54,6 +54,10 @@ if(BUILD_TESTING)
target_compile_definitions(test_RolledLogDeleter PRIVATE TEST_LOG_UTILS)
target_link_libraries(test_RolledLogDeleter tscore ts::inkevent records Catch2::Catch2WithMain)
add_catch2_test(NAME test_RolledLogDeleter COMMAND test_RolledLogDeleter)
+
+ add_executable(test_LogAccess unit-tests/test_LogAccess.cc)
+ target_link_libraries(test_LogAccess ts::logging ts::http ts::inkevent records Catch2::Catch2WithMain)
Review Comment:
And same with the `logging` target above.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#issuecomment-4218218434
retest
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt merged PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3036151417
##########
tests/gold_tests/connect/h2_malformed_request_logging.test.py:
##########
@@ -0,0 +1,207 @@
+'''
+Verify malformed HTTP/2 requests are access logged.
+'''
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import os
+import re
+import sys
+
+Test.Summary = 'Malformed HTTP/2 requests are logged before transaction creation'
+
+
+class MalformedH2RequestLoggingTest:
+ """
+ Exercise malformed and valid HTTP/2 request logging paths.
+ """
+
+ REPLAY_FILE = 'replays/h2_malformed_request_logging.replay.yaml'
+ MALFORMED_CLIENT = 'malformed_h2_request_client.py'
+ MALFORMED_CASES = (
+ {
+ 'scenario': 'connect-missing-authority',
+ 'uuid': 'malformed-connect',
+ 'method': 'CONNECT',
+ 'pqu': '/',
+ 'description': 'Send malformed HTTP/2 CONNECT request',
+ },
+ {
+ 'scenario': 'get-missing-path',
+ 'uuid': 'malformed-get-missing-path',
+ 'method': 'GET',
+ 'pqu': 'https://missing-path.example/',
+ 'description': 'Send malformed HTTP/2 GET request without :path',
+ },
+ {
+ 'scenario': 'get-connection-header',
+ 'uuid': 'malformed-get-connection',
+ 'method': 'GET',
+ 'pqu': 'https://bad-connection.example/bad-connection',
+ 'description': 'Send malformed HTTP/2 GET request with Connection header',
+ },
+ )
+
+ def __init__(self):
+ self._setup_server()
+ self._setup_ts()
+ self._processes_started = False
+ Test.Setup.CopyAs(self.MALFORMED_CLIENT, Test.RunDirectory)
+
+ @property
+ def _squid_log_path(self) -> str:
+ return os.path.join(self._ts.Variables.LOGDIR, 'squid.log')
+
+ def _setup_server(self):
+ self._server = Test.MakeVerifierServerProcess('malformed-request-server', self.REPLAY_FILE)
+ for case in self.MALFORMED_CASES:
+ self._server.Streams.stdout += Testers.ExcludesExpression(
+ f'uuid: {case["uuid"]}',
+ f'{case["description"]} must not reach the origin server.',
+ )
+ self._server.Streams.stdout += Testers.ContainsExpression(
+ 'GET /get HTTP/1.1\nuuid: valid-connect',
+ reflags=re.MULTILINE,
+ description='A valid CONNECT tunnel should still reach the origin.',
+ )
+ self._server.Streams.stdout += Testers.ContainsExpression(
+ r'GET /valid-get HTTP/1\.1\n(?:.*\n)*uuid: valid-get',
+ reflags=re.MULTILINE,
+ description='A valid non-CONNECT request should still reach the origin.',
+ )
+
+ def _setup_ts(self):
+ self._ts = Test.MakeATSProcess('ts', enable_tls=True, enable_cache=False)
+ self._ts.addDefaultSSLFiles()
+ self._ts.Disk.File(
+ os.path.join(self._ts.Variables.CONFIGDIR, 'storage.config'),
+ id='storage_config',
+ typename='ats:config',
+ )
+ self._ts.Disk.storage_config.AddLine('')
+ self._ts.Disk.ssl_multicert_yaml.AddLines(
+ """
+ssl_multicert:
+ - dest_ip: "*"
+ ssl_cert_name: server.pem
+ ssl_key_name: server.key
+""".split('\n'))
+ self._ts.Disk.File(
+ os.path.join(self._ts.Variables.CONFIGDIR, 'ssl_multicert.config'),
+ id='ssl_multicert_config',
+ typename='ats:config',
+ )
+ self._ts.Disk.ssl_multicert_config.AddLine('ssl_cert_name=server.pem ssl_key_name=server.key dest_ip=*')
+
+ self._ts.Disk.records_config.update(
+ {
+ 'proxy.config.diags.debug.enabled': 1,
+ 'proxy.config.diags.debug.tags': 'http|hpack|http2',
+ 'proxy.config.ssl.server.cert.path': self._ts.Variables.SSLDir,
+ 'proxy.config.ssl.server.private_key.path': self._ts.Variables.SSLDir,
+ 'proxy.config.http.server_ports': f'{self._ts.Variables.ssl_port}:ssl',
+ 'proxy.config.http.connect_ports': self._server.Variables.http_port,
+ })
+ self._ts.Disk.remap_config.AddLine(f'map / http://127.0.0.1:{self._server.Variables.http_port}/')
+ self._ts.Disk.logging_yaml.AddLines(
+ """
+logging:
+ formats:
+ - name: malformed_h2_request
+ format: 'uuid=%<{uuid}cqh> cqpv=%<cqpv> cqhm=%<cqhm> crc=%<crc> sstc=%<sstc> pqu=%<pqu>'
+ logs:
+ - filename: squid
+ format: malformed_h2_request
+ mode: ascii
+""".split('\n'))
+ self._ts.Disk.diags_log.Content = Testers.ContainsExpression(
+ 'recv headers malformed request',
+ 'ATS should reject malformed requests at the HTTP/2 layer.',
+ )
+ for index, case in enumerate(self.MALFORMED_CASES):
+ expected = (
+ rf'uuid={case["uuid"]} cqpv=http/2 cqhm={case["method"]} '
+ rf'crc=ERR_INVALID_REQ sstc=0 pqu={re.escape(case["pqu"])}')
+ tester = Testers.ContainsExpression(
+ expected,
+ f'{case["description"]} should be logged with ERR_INVALID_REQ.',
+ )
+ if index == 0:
+ self._ts.Disk.squid_log.Content = tester
+ else:
+ self._ts.Disk.squid_log.Content += tester
+ self._ts.Disk.squid_log.Content += Testers.ContainsExpression(
+ r'uuid=valid-connect cqpv=http/2 cqhm=CONNECT ',
+ 'A valid HTTP/2 CONNECT should still use the normal transaction log path.',
+ )
+ self._ts.Disk.squid_log.Content += Testers.ContainsExpression(
+ r'uuid=valid-get cqpv=http/2 cqhm=GET ',
+ 'A valid HTTP/2 GET should still use the normal transaction log path.',
+ )
+ self._ts.Disk.squid_log.Content += Testers.ExcludesExpression(
+ r'uuid=valid-connect .*crc=ERR_INVALID_REQ',
+ 'Valid HTTP/2 CONNECT logging must not be marked as malformed.',
+ )
+ self._ts.Disk.squid_log.Content += Testers.ExcludesExpression(
+ r'uuid=valid-get .*crc=ERR_INVALID_REQ',
+ 'Valid HTTP/2 GET logging must not be marked as malformed.',
+ )
+
+ def _add_malformed_request_runs(self):
+ for case in self.MALFORMED_CASES:
+ tr = Test.AddTestRun(case['description'])
+ tr.Processes.Default.Command = (
+ f'{sys.executable} {self.MALFORMED_CLIENT} {self._ts.Variables.ssl_port} {case["scenario"]}')
+ tr.Processes.Default.ReturnCode = 0
+ self._keep_support_processes_running(tr)
+ tr.Processes.Default.Streams.stdout += Testers.ContainsExpression(
+ r'Received (RST_STREAM on stream 1 with error code 1|GOAWAY with error code [01])',
+ 'ATS should reject the malformed request at the HTTP/2 layer.',
+ )
+
+ def _add_valid_request_run(self):
+ tr = Test.AddTestRun('Send valid HTTP/2 requests')
+ tr.AddVerifierClientProcess('valid-request-client', self.REPLAY_FILE, https_ports=[self._ts.Variables.ssl_port])
+ self._keep_support_processes_running(tr)
+
+ def _await_malformed_log_entries(self):
+ tr = Test.AddAwaitFileContainsTestRun(
+ 'Await malformed request squid log entries',
+ self._squid_log_path,
+ 'crc=ERR_INVALID_REQ',
+ desired_count=len(self.MALFORMED_CASES),
+ )
+ self._keep_support_processes_running(tr)
+
+ def _keep_support_processes_running(self, tr):
+ if self._processes_started:
+ tr.StillRunningAfter = self._server
+ tr.StillRunningAfter = self._ts
+ return
+
+ tr.Processes.Default.StartBefore(self._server)
+ tr.Processes.Default.StartBefore(self._ts)
+ tr.StillRunningAfter = self._server
+ tr.StillRunningAfter = self._ts
Review Comment:
AuTest StillRunningAfter doesn't work that way. Multiple assignments is the idiomatic way to configure multiple StillRunningAfter.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "bneradt (via GitHub)" <gi...@apache.org>.
bneradt commented on PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#issuecomment-4283290610
10.2.x backport PR: https://github.com/apache/trafficserver/pull/13105
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [PR] Log malformed HTTP/2 requests [trafficserver]
Posted by "Copilot (via GitHub)" <gi...@apache.org>.
Copilot commented on code in PR #13059:
URL: https://github.com/apache/trafficserver/pull/13059#discussion_r3060869191
##########
src/proxy/ProxyTransaction.cc:
##########
@@ -290,3 +293,127 @@ ProxyTransaction::mark_as_tunnel_endpoint()
ink_assert(nvc != nullptr);
nvc->mark_as_tunnel_endpoint();
}
+
+namespace
+{
+/** Build a best-effort request target for access logging. */
+std::string
+synthesize_request_target(std::string_view method, std::string_view scheme, std::string_view authority, std::string_view path)
+{
+ if (method == static_cast<std::string_view>(HTTP_METHOD_CONNECT)) {
+ if (!authority.empty()) {
+ return std::string(authority);
+ }
+ if (!path.empty()) {
+ return std::string(path);
+ }
+ return {};
+ }
+
+ if (!scheme.empty() && !authority.empty()) {
+ std::string url;
+ url.reserve(scheme.size() + authority.size() + path.size() + 4);
+ url.append(scheme);
+ url.append("://");
+ url.append(authority);
+ if (!path.empty()) {
+ url.append(path);
+ } else {
+ url.push_back('/');
+ }
+ return url;
+ }
+
+ if (!path.empty()) {
+ return std::string(path);
+ }
+
+ return authority.empty() ? std::string{} : std::string(authority);
+}
+
+std::string_view
+get_pseudo_header_value(HTTPHdr const &hdr, std::string_view name)
+{
+ if (auto const *field = hdr.field_find(name); field != nullptr) {
+ return field->value_get();
+ }
+ return {};
+}
+} // end anonymous namespace
+
+void
+ProxyTransaction::log_pre_transaction_access(HTTPHdr const *request, const char *protocol_str)
+{
+ if (get_sm() != nullptr) {
+ return;
+ }
+
+ if (request == nullptr || !request->valid() || request->type_get() != HTTPType::REQUEST) {
+ return;
+ }
+
+ ProxySession *ssn = get_proxy_ssn();
+ if (ssn == nullptr) {
+ return;
+ }
+
+ PreTransactionLogData data;
+
+ data.owned_client_request.create(HTTPType::REQUEST, request->version_get());
+ data.owned_client_request.copy(request);
+ data.client_request = &data.owned_client_request;
+ data.client_connection_is_ssl = ssn->ssl() != nullptr;
+
+ auto const method_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_METHOD);
+ auto const scheme_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_SCHEME);
+ auto const authority_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_AUTHORITY);
+ auto const path_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_PATH);
+
+ if (!method_sv.empty()) {
+ data.owned_method.assign(method_sv.data(), method_sv.size());
+ } else {
+ auto const mget = const_cast<HTTPHdr *>(request)->method_get();
+ data.owned_method.assign(mget.data(), mget.size());
+ }
+
+ data.owned_scheme.assign(scheme_sv.data(), scheme_sv.size());
+ data.owned_authority.assign(authority_sv.data(), authority_sv.size());
+ data.owned_path.assign(path_sv.data(), path_sv.size());
+ data.owned_url = synthesize_request_target(data.owned_method, data.owned_scheme, data.owned_authority, data.owned_path);
+
+ data.client_req_url_str = data.owned_url.c_str();
+ data.client_req_url_len = data.owned_url.size();
+ data.client_req_url_path_str = data.owned_path.c_str();
+ data.client_req_url_path_len = data.owned_path.size();
Review Comment:
`client_req_url_len` / `client_req_url_path_len` are `int` fields, but `.size()` returns `size_t`. Assigning without a cast can trigger narrowing-conversion warnings (and potentially -Werror) and is inconsistent with the unit test which uses `static_cast<int>(...)`. Please cast explicitly (and consider clamping if extremely long values are possible).
```suggestion
data.client_req_url_len = static_cast<int>(data.owned_url.size());
data.client_req_url_path_str = data.owned_path.c_str();
data.client_req_url_path_len = static_cast<int>(data.owned_path.size());
```
##########
src/proxy/ProxyTransaction.cc:
##########
@@ -290,3 +293,127 @@ ProxyTransaction::mark_as_tunnel_endpoint()
ink_assert(nvc != nullptr);
nvc->mark_as_tunnel_endpoint();
}
+
+namespace
+{
+/** Build a best-effort request target for access logging. */
+std::string
+synthesize_request_target(std::string_view method, std::string_view scheme, std::string_view authority, std::string_view path)
+{
+ if (method == static_cast<std::string_view>(HTTP_METHOD_CONNECT)) {
+ if (!authority.empty()) {
+ return std::string(authority);
+ }
+ if (!path.empty()) {
+ return std::string(path);
+ }
+ return {};
+ }
+
+ if (!scheme.empty() && !authority.empty()) {
+ std::string url;
+ url.reserve(scheme.size() + authority.size() + path.size() + 4);
+ url.append(scheme);
+ url.append("://");
+ url.append(authority);
+ if (!path.empty()) {
+ url.append(path);
+ } else {
+ url.push_back('/');
+ }
+ return url;
+ }
+
+ if (!path.empty()) {
+ return std::string(path);
+ }
+
+ return authority.empty() ? std::string{} : std::string(authority);
+}
+
+std::string_view
+get_pseudo_header_value(HTTPHdr const &hdr, std::string_view name)
+{
+ if (auto const *field = hdr.field_find(name); field != nullptr) {
+ return field->value_get();
+ }
+ return {};
+}
+} // end anonymous namespace
+
+void
+ProxyTransaction::log_pre_transaction_access(HTTPHdr const *request, const char *protocol_str)
+{
+ if (get_sm() != nullptr) {
+ return;
+ }
+
+ if (request == nullptr || !request->valid() || request->type_get() != HTTPType::REQUEST) {
+ return;
+ }
+
+ ProxySession *ssn = get_proxy_ssn();
+ if (ssn == nullptr) {
+ return;
+ }
+
+ PreTransactionLogData data;
+
+ data.owned_client_request.create(HTTPType::REQUEST, request->version_get());
+ data.owned_client_request.copy(request);
+ data.client_request = &data.owned_client_request;
+ data.client_connection_is_ssl = ssn->ssl() != nullptr;
+
+ auto const method_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_METHOD);
+ auto const scheme_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_SCHEME);
+ auto const authority_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_AUTHORITY);
+ auto const path_sv = get_pseudo_header_value(*request, PSEUDO_HEADER_PATH);
+
+ if (!method_sv.empty()) {
+ data.owned_method.assign(method_sv.data(), method_sv.size());
+ } else {
+ auto const mget = const_cast<HTTPHdr *>(request)->method_get();
+ data.owned_method.assign(mget.data(), mget.size());
+ }
+
+ data.owned_scheme.assign(scheme_sv.data(), scheme_sv.size());
+ data.owned_authority.assign(authority_sv.data(), authority_sv.size());
+ data.owned_path.assign(path_sv.data(), path_sv.size());
Review Comment:
`scheme_sv` / `authority_sv` / `path_sv` (and the `method_get()` fallback) can be default-constructed `std::string_view{}` when the pseudo header is missing, which means `data()==nullptr`. Calling `std::string::assign(ptr, 0)` with a null pointer is undefined behavior. Please guard each assign with an `empty()` check (clear the string when empty) before using `.data()`.
```suggestion
if (!mget.empty()) {
data.owned_method.assign(mget.data(), mget.size());
} else {
data.owned_method.clear();
}
}
if (!scheme_sv.empty()) {
data.owned_scheme.assign(scheme_sv.data(), scheme_sv.size());
} else {
data.owned_scheme.clear();
}
if (!authority_sv.empty()) {
data.owned_authority.assign(authority_sv.data(), authority_sv.size());
} else {
data.owned_authority.clear();
}
if (!path_sv.empty()) {
data.owned_path.assign(path_sv.data(), path_sv.size());
} else {
data.owned_path.clear();
}
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@trafficserver.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org