From 98fd68d1e723e3e6e52c9792279081d70e0da858 Mon Sep 17 00:00:00 2001 From: Ciara Stacke Date: Thu, 2 Dec 2021 23:21:27 +0000 Subject: [PATCH] Add grpc_status field --- examples/custom-log-format/README.md | 3 ++- internal/configs/version1/nginx-plus.tmpl | 5 +++++ internal/configs/version1/nginx.tmpl | 5 +++++ .../data/virtual-server-grpc/nginx-config.yaml | 3 ++- tests/suite/resources_utils.py | 12 ++++++++++++ tests/suite/test_virtual_server_grpc.py | 17 ++++++++++++----- 6 files changed, 38 insertions(+), 7 deletions(-) diff --git a/examples/custom-log-format/README.md b/examples/custom-log-format/README.md index 26cd42acf3..a1ff14539e 100644 --- a/examples/custom-log-format/README.md +++ b/examples/custom-log-format/README.md @@ -9,7 +9,7 @@ metadata: name: nginx-config namespace: nginx-ingress data: - log-format: '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" "$resource_name" "$resource_type" "$resource_namespace" "$service"' + log-format: '$remote_addr - $remote_user [$time_local] "$request" $status $grpc_status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" "$resource_name" "$resource_type" "$resource_namespace" "$service"' ``` In addition to the [built-in NGINX variables](https://nginx.org/en/docs/varindex.html), you can also use the variables that the Ingress Controller configures: @@ -17,5 +17,6 @@ In addition to the [built-in NGINX variables](https://nginx.org/en/docs/varindex - $resource_name - The name of the resource - $resource_namespace - The namespace the resource exists in. - $service - The name of the service the client request was sent to. +- $grpc_status - the gRPC status code, which is constructed either from the HTTP/2 trailer (grpc_status) returned from the backend for normal conditions, or from the HTTP/2 header (grpc_status) set either by the backend or by NGINX itself for some error conditions. **note** These variables are only available for Ingress, VirtualServer and VirtualServerRoute resources. diff --git a/internal/configs/version1/nginx-plus.tmpl b/internal/configs/version1/nginx-plus.tmpl index d7cfcaf5d0..917fe4415d 100644 --- a/internal/configs/version1/nginx-plus.tmpl +++ b/internal/configs/version1/nginx-plus.tmpl @@ -51,6 +51,11 @@ http { '"$http_user_agent" "$http_x_forwarded_for"'; {{- end}} + map $upstream_trailer_grpc_status $grpc_status { + default $upstream_trailer_grpc_status; + '' $sent_http_grpc_status; + } + {{if .AccessLogOff}} access_log off; {{else}} diff --git a/internal/configs/version1/nginx.tmpl b/internal/configs/version1/nginx.tmpl index 5e81d17053..42de34b9d3 100644 --- a/internal/configs/version1/nginx.tmpl +++ b/internal/configs/version1/nginx.tmpl @@ -44,6 +44,11 @@ http { '"$http_user_agent" "$http_x_forwarded_for"'; {{- end}} + map $upstream_trailer_grpc_status $grpc_status { + default $upstream_trailer_grpc_status; + '' $sent_http_grpc_status; + } + {{if .AccessLogOff}} access_log off; {{else}} diff --git a/tests/data/virtual-server-grpc/nginx-config.yaml b/tests/data/virtual-server-grpc/nginx-config.yaml index 746232549d..fa3bf4828c 100644 --- a/tests/data/virtual-server-grpc/nginx-config.yaml +++ b/tests/data/virtual-server-grpc/nginx-config.yaml @@ -4,4 +4,5 @@ metadata: name: nginx-config namespace: nginx-ingress data: - http2: "true" \ No newline at end of file + http2: "true" + log-format: '$remote_addr - $remote_user [$time_local] "$request" $status $grpc_status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for"' diff --git a/tests/suite/resources_utils.py b/tests/suite/resources_utils.py index 49a3a43ad5..8a698fa789 100644 --- a/tests/suite/resources_utils.py +++ b/tests/suite/resources_utils.py @@ -1400,3 +1400,15 @@ def write_to_json(fname, data) -> None: with open(f"json_files/{fname}", "w+") as f: json.dump(data, f, ensure_ascii=False, indent=4) + + +def get_last_log_entry(kube_apis, pod_name, namespace) -> str: + """ + :param kube_apis: kube apis + :param pod_name: the name of the pod + :param namespace: the namespace + """ + logs = kube_apis.read_namespaced_pod_log(pod_name, namespace) + # Our log entries end in '\n' which means the final entry when we split on a new line + # is an empty string. Return the second to last entry instead. + return logs.split('\n')[-2] diff --git a/tests/suite/test_virtual_server_grpc.py b/tests/suite/test_virtual_server_grpc.py index 2bc1290c76..cab6a78eca 100644 --- a/tests/suite/test_virtual_server_grpc.py +++ b/tests/suite/test_virtual_server_grpc.py @@ -1,7 +1,5 @@ import grpc import pytest -import time -from kubernetes.client.rest import ApiException from settings import TEST_DATA, DEPLOYMENTS from suite.custom_assertions import assert_event_starts_with_text_and_contains_errors, \ @@ -10,7 +8,8 @@ from suite.grpc.helloworld_pb2_grpc import GreeterStub from suite.resources_utils import create_example_app, wait_until_all_pods_are_ready, \ delete_common_app, create_secret_from_yaml, replace_configmap_from_yaml, \ - delete_items_from_yaml, get_first_pod_name, get_events, wait_before_test, scale_deployment + delete_items_from_yaml, get_first_pod_name, get_events, wait_before_test, \ + scale_deployment, get_last_log_entry from suite.ssl_utils import get_certificate from suite.vs_vsr_resources_utils import get_vs_nginx_template_conf, \ patch_virtual_server_from_yaml @@ -155,10 +154,14 @@ def test_grpc_error_intercept(self, kube_apis, ingress_controller_prerequisites, except grpc.RpcError as e: print(e.details()) pytest.fail("RPC error was not expected during call, exiting...") + # Assert grpc_status is in the logs. The gRPC response in a successful call is 0. + ic_pod_name = get_first_pod_name(kube_apis.v1, ingress_controller_prerequisites.namespace) + last_log = get_last_log_entry(kube_apis.v1, ic_pod_name, ingress_controller_prerequisites.namespace) + assert '"POST /helloworld.Greeter/SayHello HTTP/2.0" 200 0' in last_log scale_deployment(kube_apis.v1, kube_apis.apps_v1_api, "grpc1", virtual_server_setup.namespace, 0) scale_deployment(kube_apis.v1, kube_apis.apps_v1_api, "grpc2", virtual_server_setup.namespace, 0) - time.sleep(1) + wait_before_test() with grpc.secure_channel(target, credentials, options) as channel: stub = GreeterStub(channel) @@ -169,6 +172,11 @@ def test_grpc_error_intercept(self, kube_apis, ingress_controller_prerequisites, pytest.fail("RPC error was expected during call, exiting...") except grpc.RpcError as e: print(e) + # Assert the grpc_status is also in the logs. + ic_pod_name = get_first_pod_name(kube_apis.v1, ingress_controller_prerequisites.namespace) + wait_before_test() + last_log = get_last_log_entry(kube_apis.v1, ic_pod_name, ingress_controller_prerequisites.namespace) + assert '"POST /helloworld.Greeter/SayHello HTTP/2.0" 204 14' in last_log @pytest.mark.parametrize("backend_setup", [{"app_type": "grpc-vs"}], indirect=True) def test_config_after_enable_tls(self, kube_apis, ingress_controller_prerequisites, @@ -229,7 +237,6 @@ def test_grpc_healthcheck_validation(self, kube_apis, ingress_controller_prerequ wait_before_test(2) ic_pod_name = get_first_pod_name(kube_apis.v1, ingress_controller_prerequisites.namespace) vs_events = get_events(kube_apis.v1, virtual_server_setup.namespace) - print(vs_events) assert_event_starts_with_text_and_contains_errors(vs_event_text, vs_events, invalid_fields) assert_vs_conf_not_exists(kube_apis, ic_pod_name, ingress_controller_prerequisites.namespace, virtual_server_setup)