Expand client IP debug logging test coverage

tests/gold_tests/autest-site/ats_replay.test.ext

@@ -23,6 +23,15 @@ import re
 import yaml
 
 
+def _contains_expression(contains_entry: dict, default_description: str):
+    '''Create a ContainsExpression tester from a log validation entry.'''
+    expression = contains_entry['expression']
+    description = contains_entry.get('description', default_description)
+    reflags = re.S | re.M if contains_entry.get('multiline', False) else 0
+
+    return Testers.ContainsExpression(expression, description, reflags=reflags)
+
+
 def configure_ats(obj: 'TestRun', server: 'Process', ats_config: dict, dns: Optional['Process'] = None):
     '''Configure ATS per the configuration in the replay file.
 
@@ -134,8 +143,7 @@ def configure_ats(obj: 'TestRun', server: 'Process', ats_config: dict, dns: Opti
         traffic_out = log_validation.get('traffic_out', {})
         for contains_entry in traffic_out.get('contains', []):
             expression = contains_entry['expression']
-            description = contains_entry.get('description', f'Verify traffic_out contains: {expression}')
-            ts.Disk.traffic_out.Content += Testers.ContainsExpression(expression, description)
+            ts.Disk.traffic_out.Content += _contains_expression(contains_entry, f'Verify traffic_out contains: {expression}')
         for excludes_entry in traffic_out.get('excludes', []):
             expression = excludes_entry['expression']
             description = excludes_entry.get('description', f'Verify traffic_out excludes: {expression}')
@@ -149,8 +157,7 @@ def configure_ats(obj: 'TestRun', server: 'Process', ats_config: dict, dns: Opti
         diags_log = log_validation.get('diags_log', {})
         for contains_entry in diags_log.get('contains', []):
             expression = contains_entry['expression']
-            description = contains_entry.get('description', f'Verify diags_log contains: {expression}')
-            ts.Disk.diags_log.Content += Testers.ContainsExpression(expression, description)
+            ts.Disk.diags_log.Content += _contains_expression(contains_entry, f'Verify diags_log contains: {expression}')
         for excludes_entry in diags_log.get('excludes', []):
             expression = excludes_entry['expression']
             description = excludes_entry.get('description', f'Verify diags_log excludes: {expression}')
@@ -164,8 +171,7 @@ def configure_ats(obj: 'TestRun', server: 'Process', ats_config: dict, dns: Opti
         error_log = log_validation.get('error_log', {})
         for contains_entry in error_log.get('contains', []):
             expression = contains_entry['expression']
-            description = contains_entry.get('description', f'Verify error_log contains: {expression}')
-            ts.Disk.error_log.Content += Testers.ContainsExpression(expression, description)
+            ts.Disk.error_log.Content += _contains_expression(contains_entry, f'Verify error_log contains: {expression}')
         for excludes_entry in error_log.get('excludes', []):
             expression = excludes_entry['expression']
             description = excludes_entry.get('description', f'Verify error_log excludes: {expression}')
@@ -260,8 +266,7 @@ def ATSReplayTest(obj, replay_file: str):
     if server_log_validation:
         for contains_entry in server_log_validation.get('contains', []):
             expression = contains_entry['expression']
-            description = contains_entry.get('description', f'Verify server output contains: {expression}')
-            server.Streams.All += Testers.ContainsExpression(expression, description)
+            server.Streams.All += _contains_expression(contains_entry, f'Verify server output contains: {expression}')
         for excludes_entry in server_log_validation.get('excludes', []):
             expression = excludes_entry['expression']
             description = excludes_entry.get('description', f'Verify server output excludes: {expression}')
@@ -273,6 +278,7 @@ def ATSReplayTest(obj, replay_file: str):
     ats_config = autest_config['ats']
     process_config = ats_config.get('process_config', {})
     enable_tls = process_config.get('enable_tls', False)
+    enable_quic = process_config.get('enable_quic', False)
     metric_checks = ats_config.get('metric_checks', [])
     log_validation = ats_config.get('log_validation', None)
 
@@ -284,10 +290,12 @@ def ATSReplayTest(obj, replay_file: str):
         raise ValueError(f"Replay file {replay_file} does not contain 'autest.client' section")
     client_config = autest_config['client']
     name = client_config.get('name', 'client')
-    process_config = client_config.get('process_config', {})
-    https_ports = [ts.Variables.ssl_port] if enable_tls else None
+    process_config = client_config.get('process_config', {}).copy()
+    http_ports = process_config.pop('http_ports', [ts.Variables.port])
+    https_ports = process_config.pop('https_ports', [ts.Variables.ssl_port] if enable_tls else None)
+    http3_ports = process_config.pop('http3_ports', [ts.Variables.ssl_port] if enable_quic else None)
     client = tr.AddVerifierClientProcess(
-        name, replay_file, http_ports=[ts.Variables.port], https_ports=https_ports, **process_config)
+        name, replay_file, http_ports=http_ports, https_ports=https_ports, http3_ports=http3_ports, **process_config)
 
     # Set expected return code if specified. A list of codes is wrapped in
     # Any() so that any of the listed values is accepted.
@@ -300,8 +308,7 @@ def ATSReplayTest(obj, replay_file: str):
     if client_log_validation:
         for contains_entry in client_log_validation.get('contains', []):
             expression = contains_entry['expression']
-            description = contains_entry.get('description', f'Verify client output contains: {expression}')
-            client.Streams.All += Testers.ContainsExpression(expression, description)
+            client.Streams.All += _contains_expression(contains_entry, f'Verify client output contains: {expression}')
         for excludes_entry in client_log_validation.get('excludes', []):
             expression = excludes_entry['expression']
             description = excludes_entry.get('description', f'Verify client output excludes: {expression}')

tests/gold_tests/logging/log-debug-client-ip.test.py

@@ -1,4 +1,5 @@
 '''
+Verify debug logging filtered by client IP.
 '''
 #  Licensed to the Apache Software Foundation (ASF) under one
 #  or more contributor license agreements.  See the NOTICE file
@@ -16,39 +17,15 @@
 #  See the License for the specific language governing permissions and
 #  limitations under the License.
 
-import os
-
 Test.Summary = '''
-Test log filter.
+Verify per-client-IP debug logging emits request and response header dumps.
 '''
 
-ts = Test.MakeATSProcess("ts", enable_cache=False)
-replay_file = "log-filter.replays.yaml"
-server = Test.MakeVerifierServerProcess("server", replay_file)
-nameserver = Test.MakeDNServer("dns", default='127.0.0.1')
-
-ts.Disk.records_config.update(
-    {
-        'proxy.config.diags.debug.enabled': 2,
-        'proxy.config.diags.debug.tags': 'http',
-        'proxy.config.diags.debug.client_ip': '127.0.0.1',
-        'proxy.config.dns.nameservers': f"127.0.0.1:{nameserver.Variables.Port}",
-    })
-ts.Disk.remap_config.AddLine('map / http://localhost:{}/'.format(server.Variables.http_port))
+Test.ContinueOnFail = True
 
-# Verify that the various aspects of the expected debug output for the
-# transaction are logged.
-ts.Disk.traffic_out.Content = Testers.ContainsExpression(
-    r"\+ Incoming Request \+", "Make sure the client request information is present.")
-ts.Disk.traffic_out.Content += Testers.ContainsExpression(
-    r"\+ Proxy's Request after hooks \+", "Make sure the proxy request information is present.")
-ts.Disk.traffic_out.Content += Testers.ContainsExpression(
-    r"\+ Incoming O.S. Response \+", "Make sure the server's response information is present.")
-ts.Disk.traffic_out.Content += Testers.ContainsExpression(
-    r"\+ Proxy's Response 2 \+", "Make sure the proxy response information is present.")
+Test.ATSReplayTest(replay_file='replay/log-debug-client-ip-http.replay.yaml')
+Test.ATSReplayTest(replay_file='replay/log-debug-client-ip-https.replay.yaml')
+Test.ATSReplayTest(replay_file='replay/log-debug-client-ip-http2.replay.yaml')
 
-tr = Test.AddTestRun()
-tr.Processes.Default.StartBefore(server)
-tr.Processes.Default.StartBefore(ts)
-tr.Processes.Default.StartBefore(nameserver)
-tr.AddVerifierClientProcess("client-1", replay_file, http_ports=[ts.Variables.port], other_args="--keys test-1")
+if Condition.HasATSFeature('TS_HAS_QUICHE') and Condition.HasCurlFeature('http3'):
+    Test.ATSReplayTest(replay_file='replay/log-debug-client-ip-http3.replay.yaml')

tests/gold_tests/logging/replay/log-debug-client-ip-http.replay.yaml

@@ -0,0 +1,129 @@
+#  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.
+
+meta:
+  version: "1.0"
+
+autest:
+  description: 'Verify client-IP-filtered debug logging for HTTP/1.1'
+
+  server:
+    name: 'server-log-debug-client-ip-http'
+
+  client:
+    name: 'client-log-debug-client-ip-http'
+
+  ats:
+    name: 'ts-log-debug-client-ip-http'
+    process_config:
+      enable_cache: false
+
+    records_config:
+      proxy.config.diags.debug.enabled: 2
+      proxy.config.diags.debug.tags: 'http'
+      proxy.config.diags.debug.client_ip: '127.0.0.1'
+
+    remap_config:
+    - from: 'http://debug-client-ip-http.test/'
+      to: 'http://127.0.0.1:{SERVER_HTTP_PORT}/'
+
+    log_validation:
+      traffic_out:
+        contains:
+        - expression: '\+ Incoming Request \+(?:(?!\+ Proxy''s Request after hooks \+)[\s\S])*?uuid: log-debug-http-1'
+          description: 'HTTP transaction 1 logs the incoming request headers.'
+          multiline: true
+        - expression: '\+ Proxy''s Request after hooks \+(?:(?!\+ Incoming O.S. Response \+)[\s\S])*?uuid: log-debug-http-1'
+          description: 'HTTP transaction 1 logs the proxy request headers after hooks.'
+          multiline: true
+        - expression: '\+ Incoming O.S. Response \+(?:(?!\+ Proxy''s Response 2 \+)[\s\S])*?uuid: log-debug-http-1'
+          description: 'HTTP transaction 1 logs the incoming origin response headers.'
+          multiline: true
+        - expression: '\+ Proxy''s Response 2 \+(?:(?!\+ Incoming Request \+)[\s\S])*?uuid: log-debug-http-1'
+          description: 'HTTP transaction 1 logs the proxy response headers.'
+          multiline: true
+        - expression: '\+ Incoming Request \+(?:(?!\+ Proxy''s Request after hooks \+)[\s\S])*?uuid: log-debug-http-2'
+          description: 'HTTP transaction 2 logs the incoming request headers.'
+          multiline: true
+        - expression: '\+ Proxy''s Request after hooks \+(?:(?!\+ Incoming O.S. Response \+)[\s\S])*?uuid: log-debug-http-2'
+          description: 'HTTP transaction 2 logs the proxy request headers after hooks.'
+          multiline: true
+        - expression: '\+ Incoming O.S. Response \+(?:(?!\+ Proxy''s Response 2 \+)[\s\S])*?uuid: log-debug-http-2'
+          description: 'HTTP transaction 2 logs the incoming origin response headers.'
+          multiline: true
+        - expression: '\+ Proxy''s Response 2 \+(?:(?!\+ Incoming Request \+)[\s\S])*?uuid: log-debug-http-2'
+          description: 'HTTP transaction 2 logs the proxy response headers.'
+          multiline: true
+
+sessions:
+- transactions:
+  - client-request:
+      method: GET
+      url: /debug-http-1
+      version: '1.1'
+      headers:
+        fields:
+        - [Host, debug-client-ip-http.test]
+        - [Content-Length, 0]
+        - [uuid, log-debug-http-1]
+
+    proxy-request:
+      headers:
+        fields:
+        - [uuid, { value: log-debug-http-1, as: equal }]
+
+    server-response:
+      status: 200
+      reason: OK
+      headers:
+        fields:
+        - [Content-Length, 0]
+        - [uuid, log-debug-http-1]
+
+    proxy-response:
+      status: 200
+      headers:
+        fields:
+        - [uuid, { value: log-debug-http-1, as: equal }]
+
+  - client-request:
+      method: GET
+      url: /debug-http-2
+      version: '1.1'
+      headers:
+        fields:
+        - [Host, debug-client-ip-http.test]
+        - [Content-Length, 0]
+        - [uuid, log-debug-http-2]
+
+    proxy-request:
+      headers:
+        fields:
+        - [uuid, { value: log-debug-http-2, as: equal }]
+
+    server-response:
+      status: 200
+      reason: OK
+      headers:
+        fields:
+        - [Content-Length, 0]
+        - [uuid, log-debug-http-2]
+
+    proxy-response:
+      status: 200
+      headers:
+        fields:
+        - [uuid, { value: log-debug-http-2, as: equal }]