Add Rbac Access Denied Policy Info in Access logs (#3100)

* Add Rbac Access Denied Policy Info in Access logs

* fix lint error

Signed-off-by: gargnupur <[email protected]>

* fix based on feedback

Signed-off-by: gargnupur <[email protected]>

* fix based on feedback

Signed-off-by: gargnupur <[email protected]>

Author: gargnupur

extensions/common/context.cc

@@ -428,6 +428,11 @@ void populateExtendedHTTPRequestInfo(RequestInfo* request_info) {
   getValue({"request", "url_path"}, &request_info->url_path);
   getValue({"request", "host"}, &request_info->url_host);
   getValue({"request", "scheme"}, &request_info->url_scheme);
+  std::string response_details;
+  getValue({"response", "code_details"}, &response_details);
+  if (!response_details.empty()) {
+    request_info->response_details = response_details;
+  }
 }
 
 void populateExtendedRequestInfo(RequestInfo* request_info) {
@@ -448,6 +453,11 @@ void populateExtendedRequestInfo(RequestInfo* request_info) {
       envoy_original_dst_host ? envoy_original_dst_host->toString() : "";
   getValue({"upstream", "transport_failure_reason"},
            &request_info->upstream_transport_failure_reason);
+  std::string response_details;
+  getValue({"connection", "termination_details"}, &response_details);
+  if (!response_details.empty()) {
+    request_info->response_details = response_details;
+  }
 }
 
 void populateTCPRequestInfo(bool outbound, RequestInfo* request_info) {

extensions/common/context.h

@@ -159,6 +159,7 @@ struct RequestInfo {
   // populateExtendedHTTPRequestInfo.
   std::string source_address;
   std::string destination_address;
+  std::string response_details;
 
   // Additional fields for access log.
   std::string route_name;

extensions/stackdriver/log/logger.cc

@@ -18,6 +18,7 @@
 #include "extensions/stackdriver/common/constants.h"
 #include "google/logging/v2/log_entry.pb.h"
 #include "google/protobuf/util/time_util.h"
+#include "re2/re2.h"
 
 #ifndef NULL_PLUGIN
 #include "api/wasm/cpp/proxy_wasm_intrinsics.h"
@@ -31,6 +32,13 @@ namespace Extensions {
 namespace Stackdriver {
 namespace Log {
 namespace {
+// Matches Rbac Access denied string.
+// It is of the format:
+// "rbac_access_denied_matched_policy[ns[NAMESPACE]-policy[POLICY]-rule[POLICY_INDEX]]"
+const RE2 rbac_denied_match(
+    "rbac_access_denied_matched_policy\\[ns\\[(.*)\\]-policy\\[(.*)\\]-rule\\[("
+    ".*)\\]\\]");
+constexpr char kRbacAccessDenied[] = "AuthzDenied";
 void setSourceCanonicalService(
     const ::Wasm::Common::FlatNode& peer_node_info,
     google::protobuf::Map<std::string, std::string>* label_map) {
@@ -158,6 +166,21 @@ void fillExtraLabels(
   }
 }
 
+bool fillAuthInfo(const std::string& response_details,
+                  google::protobuf::Map<std::string, std::string>* label_map) {
+  std::string policy_name, policy_namespace, policy_rule_index;
+  if (RE2::PartialMatch(response_details, rbac_denied_match, &policy_namespace,
+                        &policy_name, &policy_rule_index)) {
+    (*label_map)["response_details"] = kRbacAccessDenied;
+    (*label_map)["policy_name"] =
+        absl::StrCat(policy_namespace, ".", policy_name);
+    (*label_map)["policy_rule"] = policy_rule_index;
+    return true;
+  }
+
+  return false;
+}
+
 }  // namespace
 
 using google::protobuf::util::TimeUtil;
@@ -341,6 +364,11 @@ void Logger::fillAndFlushLogEntry(
       (*label_map)["upstream_transport_failure_reason"] =
           request_info.upstream_transport_failure_reason;
     }
+    if (!request_info.response_details.empty()) {
+      if (!fillAuthInfo(request_info.response_details, label_map)) {
+        (*label_map)["response_details"] = request_info.response_details;
+      }
+    }
   }
 
   // Insert trace headers, if exist.

go.mod

@@ -9,6 +9,7 @@ require (
 	github.com/fsnotify/fsnotify v1.4.9
 	github.com/ghodss/yaml v1.0.0
 	github.com/golang/protobuf v1.4.2
+	github.com/google/go-cmp v0.5.0
 	github.com/kr/pretty v0.1.0 // indirect
 	github.com/prometheus/client_model v0.2.0
 	github.com/prometheus/common v0.9.1

scripts/check-style.sh

@@ -34,7 +34,7 @@ if [[ ! -x "${CLANG_FORMAT}" || "${CLANG_VERSION}" != "${CLANG_VERSION_REQUIRED}
     echo "Unsupported environment." ; exit 1 ;
   fi
 
-  LLVM_URL_PREFIX="https://https://github.com/llvm/llvm-project/releases/download/llvmorg"
+  LLVM_URL_PREFIX="https://github.com/llvm/llvm-project/releases/download/llvmorg"
   echo "Downloading clang-format: ${LLVM_URL_PREFIX}-${CLANG_VERSION_REQUIRED}/clang+llvm-${CLANG_VERSION_REQUIRED}-${CLANG_BIN}"
   echo "Installing required clang-format ${CLANG_VERSION_REQUIRED} to ${CLANG_DIRECTORY}"
 

test/envoye2e/inventory.go

@@ -45,6 +45,8 @@ func init() {
 			"TestStackdriverTCPMetadataExchange/BaseCase",
 			"TestStackdriverTCPMetadataExchange/NoAlpn",
 			"TestStackdriverAttributeGen",
+			"TestStackdriverCustomAccessLog",
+			"TestStackdriverRbacAccessDenied",
 			"TestStatsPayload/Default/envoy.wasm.runtime.null",
 			"TestStatsPayload/Customized/envoy.wasm.runtime.null",
 			"TestStatsPayload/UseHostHeader/envoy.wasm.runtime.null",

test/envoye2e/stackdriver_plugin/stackdriver.go

@@ -23,8 +23,10 @@ import (
 	"time"
 
 	"github.com/golang/protobuf/proto"
+	"github.com/google/go-cmp/cmp"
 	logging "google.golang.org/genproto/googleapis/logging/v2"
 	monitoring "google.golang.org/genproto/googleapis/monitoring/v3"
+	"google.golang.org/protobuf/testing/protocmp"
 
 	"istio.io/proxy/test/envoye2e/driver"
 	"istio.io/proxy/test/envoye2e/env"
@@ -186,6 +188,10 @@ func (s *checkStackdriver) Run(p *driver.Params) error {
 				for want := range s.lwant {
 					log.Println(want)
 				}
+				// Adding more logs for debugging in case of failures.
+				if diff := cmp.Diff(s.sd.ls, s.lwant, protocmp.Transform()); diff != "" {
+					log.Printf("t diff: %v\ngot:\n %v\nwant:\n %v\n", diff, s.sd.ls, s.lwant)
+				}
 				return fmt.Errorf("failed to receive expected logs")
 			}
 		}

test/envoye2e/stackdriver_plugin/stackdriver_test.go

@@ -832,3 +832,66 @@ func TestStackdriverCustomAccessLog(t *testing.T) {
 		t.Fatal(err)
 	}
 }
+
+func TestStackdriverRbacAccessDenied(t *testing.T) {
+	t.Parallel()
+	respCode := "403"
+	logEntryCount := 5
+
+	params := driver.NewTestParams(t, map[string]string{
+		"ServiceAuthenticationPolicy": "NONE",
+		"DirectResponseCode":          respCode,
+		"SDLogStatusCode":             respCode,
+		"StackdriverRootCAFile":       driver.TestPath("testdata/certs/stackdriver.pem"),
+		"StackdriverTokenFile":        driver.TestPath("testdata/certs/access-token"),
+		"RbacAccessDenied":            "true",
+	}, envoye2e.ProxyE2ETests)
+
+	sdPort := params.Ports.Max + 1
+	stsPort := params.Ports.Max + 2
+	params.Vars["SDPort"] = strconv.Itoa(int(sdPort))
+	params.Vars["STSPort"] = strconv.Itoa(int(stsPort))
+	params.Vars["ClientMetadata"] = params.LoadTestData("testdata/client_node_metadata.json.tmpl")
+	params.Vars["ServerMetadata"] = params.LoadTestData("testdata/server_node_metadata.json.tmpl")
+	params.Vars["ClientHTTPFilters"] = driver.LoadTestData("testdata/filters/mx_outbound.yaml.tmpl")
+	params.Vars["ServerHTTPFilters"] = driver.LoadTestData("testdata/filters/mx_inbound.yaml.tmpl") + "\n" +
+		driver.LoadTestData("testdata/filters/rbac.yaml.tmpl") + "\n" +
+		driver.LoadTestData("testdata/filters/stackdriver_inbound.yaml.tmpl")
+	sd := &Stackdriver{Port: sdPort}
+	intRespCode, _ := strconv.Atoi(respCode)
+	if err := (&driver.Scenario{
+		Steps: []driver.Step{
+			&driver.XDS{},
+			sd,
+			&SecureTokenService{Port: stsPort},
+			&driver.Update{Node: "client", Version: "0", Listeners: []string{
+				params.LoadTestData("testdata/listener/client.yaml.tmpl"),
+			}},
+			&driver.Update{Node: "server", Version: "0", Listeners: []string{
+				params.LoadTestData("testdata/listener/server.yaml.tmpl"),
+			}},
+			&driver.Envoy{Bootstrap: params.LoadTestData("testdata/bootstrap/server.yaml.tmpl")},
+			&driver.Envoy{Bootstrap: params.LoadTestData("testdata/bootstrap/client.yaml.tmpl")},
+			&driver.Sleep{Duration: 1 * time.Second},
+			&driver.Repeat{
+				N: logEntryCount,
+				Step: &driver.HTTPCall{
+					Port:         params.Ports.ClientPort,
+					ResponseCode: intRespCode,
+				},
+			},
+			sd.Check(params,
+				nil, []SDLogEntry{
+					{
+						LogBaseFile:   "testdata/stackdriver/server_access_log.yaml.tmpl",
+						LogEntryFile:  []string{"testdata/stackdriver/server_access_log_entry.yaml.tmpl"},
+						LogEntryCount: logEntryCount,
+					},
+				},
+				nil, true,
+			),
+		},
+	}).Run(params); err != nil {
+		t.Fatal(err)
+	}
+}

testdata/filters/rbac.yaml.tmpl

@@ -6,7 +6,7 @@
       rules:
         action: DENY
         policies:
-          "test":
+          ns[foo]-policy[httpbin-deny]-rule[0]:
             permissions:
               - any: true
             principals:

testdata/stackdriver/client_access_log_entry.yaml.tmpl

@@ -52,4 +52,5 @@ labels:
   {{- end }}
   upstream_cluster: "server-outbound-cluster"
   route_name: client_route
+  response_details: "via_upstream"
 severity: INFO

testdata/stackdriver/client_gateway_access_log_entry.yaml.tmpl

@@ -21,6 +21,7 @@ labels:
   destination_canonical_revision: version-1
   destination_canonical_service: ratings
   log_sampled: "false"
+  response_details: "via_upstream"
   upstream_cluster: "server-outbound-cluster"
   route_name: client_route
 severity: INFO

testdata/stackdriver/gateway_access_log_entry.yaml.tmpl

@@ -21,6 +21,7 @@ labels:
   source_canonical_service: ratings
   source_canonical_revision: version-1
   log_sampled: "false"
+  response_details: "via_upstream"
   upstream_cluster: "server-inbound-cluster"
   route_name: server_route
 severity: INFO

testdata/stackdriver/server_access_log_entry.yaml.tmpl

@@ -40,5 +40,12 @@ labels:
   log_sampled: "false"
   {{- end }}
   upstream_cluster: "server-inbound-cluster"
+  {{- if .Vars.RbacAccessDenied }}
+  response_details: "AuthzDenied"
+  policy_name: "foo.httpbin-deny"
+  policy_rule: "0"
+  {{-  else }}
+  response_details: "via_upstream"
   route_name: server_route
+  {{- end }}
 severity: INFO