Add to the logs

nginx · Nov 25, 2021 · 6f1b7e6 · 6f1b7e6
1 parent 1f4044f
commit 6f1b7e6
Show file tree

Hide file tree

Showing 5 changed files with 30 additions and 5 deletions.
diff --git 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:

diff --git a/internal/configs/version1/nginx-plus.tmpl b/internal/configs/version1/nginx-plus.tmpl
@@ -47,10 +47,15 @@ http {
                      {{end}}{{end}};
     {{- else -}}
     log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
-                      '$status $body_bytes_sent "$http_referer" '
+                      '$status $grpc_status $body_bytes_sent "$http_referer" '
                       '"$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
@@ -40,10 +40,15 @@ http {
                      {{end}}{{end}};
     {{- else -}}
     log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
-                      '$status $body_bytes_sent "$http_referer" '
+                      '$status $grpc_status $body_bytes_sent "$http_referer" '
                       '"$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/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
@@ -14,7 +14,7 @@
 from suite.ssl_utils import get_certificate
 from suite.vs_vsr_resources_utils import get_vs_nginx_template_conf, \
     patch_virtual_server_from_yaml
-from suite.resources_utils import wait_before_test
+from suite.resources_utils import wait_before_test, get_last_log_entry
 
 
 @pytest.fixture(scope="function")
@@ -134,6 +134,10 @@ def test_connect_grpc_backend(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
 
     @pytest.mark.parametrize("backend_setup", [{"app_type": "grpc-vs"}], indirect=True)
     def test_config_after_enable_tls(self, kube_apis, ingress_controller_prerequisites,
@@ -193,7 +197,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)