Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AS & KBS | Optimize log #362

Merged
merged 2 commits into from
Apr 8, 2024
Merged

Conversation

Xynnn007
Copy link
Member

@Xynnn007 Xynnn007 commented Apr 8, 2024

This PR mainly optimize the logs of both AS and KBS. including:

  • make logs more readable
  • make detailed and long logs as "debug" level, and brief logs as "info" level.

Examples.

Before this PR

[2024-04-07T06:15:35Z INFO  api_server::http::attest] Cookie 9c47605b5f7d42bca784b5024e071d65 attestation Json(Attestation { tee_pubkey: TeePubKey { kty: "RSA", alg: "RSA1_5", k_mod: "rWKEKFCeBQrTwQgy6QR3lhzKFxqZiZuwhoetIRkuSPNgQJC8UmP5k6uwFGbF81xyNX3FDbbYhq0zsAqDyoDBPhhpl5nTg0D2_5JX7G20ky_eT6hFuNcoHNflmmJxPJmF1A1uqNX-xwAq2XCeWF0bZ10p6o9cNJ_PG0NIlrvHjQavf1tyfn59jfc_PrrtP1q6Kkq-155IJ3p7yFHyhnyT05R_soJ7hDknYgVDX-KeqCheSD_67hZAMFn7gIF-DAu47fW3KzssC1J7P5VgBaB8d3o2qeKTAwbOkHjgw3VmcXBYt4-d2DoXr489w8ZLNBstx0XRsUz2hi9QA_8xlHSyNw", k_exp: "AQAB" }, tee_evidence: "{\"cc_eventlog\":null,\"quote\":\"BQACAIEAAAAAAAAAk5pyM/ecTKmUCg2zlX8GB9osfjJsVpaImmpqtPimSxcAAAAAAwCIAgAABQECAAAAAAAAAAAAAAAAABzGoXq3memmk/rHU2vmHBLuHg+rragtDJmeCMzuKqht53sIcPVYxXDn/+VdbUf6BAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAEAAAAADnQgYAAAAAAN+6IhtIoir4URVC7nlmA/NzgoAIQNzZeHA5Cb+OZNTIoenehufJY4v8ukIvOIZACgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAJtSnzaJ4ujruJnpq7vD2rOU1lRejNsooqu5zC83e4OmXAG6VrgkzT7ohd8gBR9RKB24qnPEc3sKO6NCR5hkTQVb6nq9T/zV5GfkqzRPaojGr3tNQK+CnAPpnBfpa2M6HwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA2CBfOx6fXvMhXu6KgECBrIHKtNoZA1HvFZhtgmNxG3vvFJXXcMueS9GhigW69hOwAAAAAAAAAAAAAAAAAAAAAFAQIAAAAAAAAAAAAAAAAAODyH07uwR7LRcerKlTEu3pnyWAiNx4j2rizPi23YSP6NR2KeCLP2y9SgDdR6WgM9zBAAALJhWTviMLFRQrTJH0rZX4NLCCetjdV52vemGh2jnL0ZDLQAhN4KwxPR/DDRCM7JBlxC6dDCoJMnu2KMSdTBHD7dkYh6RhFwsM8f5hEgwoSQG7DDvQNY5D4dnQ9XonMfm9ey5rsXo5lbjLb4DR9HCJaR/IsfrNXhXVE50MZEpAbQBgBGEAAAAgIYGgP/AAYAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFQAAAAAAAADnAAAAAAAAAOWjp7XYMMKVO5hTTGxZo6NP3DTpM/f1iY8Khc8IhGvKAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAADcnip8b5SPF0dONKf8Q+0DD3wVY/G6vd9jQMguDlSoxQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAIABgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABL2UGrT+loMaDjo7e7oMLmikl/wwWR66S0dUQQFc0CgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA0eN7DaC2STro34OFM9/cFxu3htS8047yQ+WgorK7GL4COVgGWWHhUuJYC6o4wM8snfIUzAIT8sJyQ6TA9hUpAiAAAAECAwQFBgcICQoLDA0ODxAREhMUFRYXGBkaGxwdHh8FAF4OAAAtLS0tLUJFR0lOIENFUlRJRklDQVRFLS0tLS0KTUlJRThEQ0NCSmVnQXdJQkFnSVZBSzBLbkJqY0FPUU10dFArZlRuRlU5MC9vbEdMTUFvR0NDcUdTTTQ5QkFNQwpNSEF4SWpBZ0JnTlZCQU1NR1VsdWRHVnNJRk5IV0NCUVEwc2dVR3hoZEdadmNtMGdRMEV4R2pBWUJnTlZCQW9NCkVVbHVkR1ZzSUVOdmNuQnZjbUYwYVc5dU1SUXdFZ1lEVlFRSERBdFRZVzUwWVNCRGJHRnlZVEVMTUFrR0ExVUUKQ0F3Q1EwRXhDekFKQmdOVkJBWVRBbFZUTUI0WERUSTBNRE14T0RBNE5ETTFNVm9YRFRNeE1ETXhPREE0TkRNMQpNVm93Y0RFaU1DQUdBMVVFQXd3WlNXNTBaV3dnVTBkWUlGQkRTeUJEWlhKMGFXWnBZMkYwWlRFYU1CZ0dBMVVFCkNnd1JTVzUwWld3Z1EyOXljRzl5WVhScGIyNHhGREFTQmdOVkJBY01DMU5oYm5SaElFTnNZWEpoTVFzd0NRWUQKVlFRSURBSkRRVEVMTUFrR0ExVUVCaE1DVlZNd1dUQVRCZ2NxaGtqT1BRSUJCZ2dxaGtqT1BRTUJCd05DQUFRVQorUlNPT1dlQndCbFJNYnRLeXVrWXRPdE95VDhRdGpweUt5OXpSa09lYmZ1WWtxMkRUelhsallMUzV3OTRraVVFClpINXdNRHhHaDYwcVhLcTZoVTZIbzRJREREQ0NBd2d3SHdZRFZSMGpCQmd3Rm9BVWxXOWR6YjBiNGVsQVNjblUKOURQT0FWY0wzbFF3YXdZRFZSMGZCR1F3WWpCZ29GNmdYSVphYUhSMGNITTZMeTloY0drdWRISjFjM1JsWkhObApjblpwWTJWekxtbHVkR1ZzTG1OdmJTOXpaM2d2WTJWeWRHbG1hV05oZEdsdmJpOTJNeTl3WTJ0amNtdy9ZMkU5CmNHeGhkR1p2Y20wbVpXNWpiMlJwYm1jOVpHVnlNQjBHQTFVZERnUVdCQlFjU3BjYitJRHR6bHhrUTZESm9ObWIKL2VZamV6QU9CZ05WSFE4QkFmOEVCQU1DQnNBd0RBWURWUjBUQVFIL0JBSXdBRENDQWprR0NTcUdTSWI0VFFFTgpBUVNDQWlvd2dnSW1NQjRHQ2lxR1NJYjRUUUVOQVFFRUVQQnBoTWpaTkRSU3VaZkVpemJXNW5nd2dnRmpCZ29xCmhraUcrRTBCRFFFQ01JSUJVekFRQmdzcWhraUcrRTBCRFFFQ0FRSUJBVEFRQmdzcWhraUcrRTBCRFFFQ0FnSUIKQVRBUUJnc3Foa2lHK0UwQkRRRUNBd0lCQWpBUUJnc3Foa2lHK0UwQkRRRUNCQUlCQWpBUUJnc3Foa2lHK0UwQgpEUUVDQlFJQkF6QVFCZ3NxaGtpRytFMEJEUUVDQmdJQkFUQVFCZ3NxaGtpRytFMEJEUUVDQndJQkFEQVFCZ3NxCmhraUcrRTBCRFFFQ0NBSUJBekFRQmdzcWhraUcrRTBCRFFFQ0NRSUJBREFRQmdzcWhraUcrRTBCRFFFQ0NnSUIKQURBUUJnc3Foa2lHK0UwQkRRRUNDd0lCQURBUUJnc3Foa2lHK0UwQkRRRUNEQUlCQURBUUJnc3Foa2lHK0UwQgpEUUVDRFFJQkFEQVFCZ3NxaGtpRytFMEJEUUVDRGdJQkFEQVFCZ3NxaGtpRytFMEJEUUVDRHdJQkFEQVFCZ3NxCmhraUcrRTBCRFFFQ0VBSUJBREFRQmdzcWhraUcrRTBCRFFFQ0VRSUJEVEFmQmdzcWhraUcrRTBCRFFFQ0VnUVEKQVFFQ0FnTUJBQU1BQUFBQUFBQUFBREFRQmdvcWhraUcrRTBCRFFFREJBSUFBREFVQmdvcWhraUcrRTBCRFFFRQpCQWFRd0c4QUFBQXdEd1lLS29aSWh2aE5BUTBCQlFvQkFUQWVCZ29xaGtpRytFMEJEUUVHQkJCcW5xTzQyZWMwClNWM0VDM0QxbGZsaE1FUUdDaXFHU0liNFRRRU5BUWN3TmpBUUJnc3Foa2lHK0UwQkRRRUhBUUVCL3pBUUJnc3EKaGtpRytFMEJEUUVIQWdFQi96QVFCZ3NxaGtpRytFMEJEUUVIQXdFQi96QUtCZ2dxaGtqT1BRUURBZ05IQURCRQpBaUJIeTI4WGxWZU1FODROTjZaVkNVZFFjdWhZUnJQcXV6UTIvL3JIMGJzQjhRSWdOZ0tERFQ0ZEI5WUlNWU9sCkdQamFlbjZocUR0d0JKazgwdkhQZmpFZU5xdz0KLS0tLS1FTkQgQ0VSVElGSUNBVEUtLS0tLQotLS0tLUJFR0lOIENFUlRJRklDQVRFLS0tLS0KTUlJQ2xqQ0NBajJnQXdJQkFnSVZBSlZ2WGMyOUcrSHBRRW5KMVBRenpnRlhDOTVVTUFvR0NDcUdTTTQ5QkFNQwpNR2d4R2pBWUJnTlZCQU1NRVVsdWRHVnNJRk5IV0NCU2IyOTBJRU5CTVJvd0dBWURWUVFLREJGSmJuUmxiQ0JECmIzSndiM0poZEdsdmJqRVVNQklHQTFVRUJ3d0xVMkZ1ZEdFZ1EyeGhjbUV4Q3pBSkJnTlZCQWdNQWtOQk1Rc3cKQ1FZRFZRUUdFd0pWVXpBZUZ3MHhPREExTWpFeE1EVXdNVEJhRncwek16QTFNakV4TURVd01UQmFNSEF4SWpBZwpCZ05WQkFNTUdVbHVkR1ZzSUZOSFdDQlFRMHNnVUd4aGRHWnZjbTBnUTBFeEdqQVlCZ05WQkFvTUVVbHVkR1ZzCklFTnZjbkJ2Y21GMGFXOXVNUlF3RWdZRFZRUUhEQXRUWVc1MFlTQkRiR0Z5WVRFTE1Ba0dBMVVFQ0F3Q1EwRXgKQ3pBSkJnTlZCQVlUQWxWVE1Ga3dFd1lIS29aSXpqMENBUVlJS29aSXpqMERBUWNEUWdBRU5TQi83dDIxbFhTTwoyQ3V6cHh3NzRlSkI3MkV5REdnVzVyWEN0eDJ0VlRMcTZoS2s2eitVaVJaQ25xUjdwc092Z3FGZVN4bG1UbEpsCmVUbWkyV1l6M3FPQnV6Q0J1REFmQmdOVkhTTUVHREFXZ0JRaVpReldXcDAwaWZPRHRKVlN2MUFiT1NjR3JEQlMKQmdOVkhSOEVTekJKTUVlZ1JhQkRoa0ZvZEhSd2N6b3ZMMk5sY25ScFptbGpZWFJsY3k1MGNuVnpkR1ZrYzJWeQpkbWxqWlhNdWFXNTBaV3d1WTI5dEwwbHVkR1ZzVTBkWVVtOXZkRU5CTG1SbGNqQWRCZ05WSFE0RUZnUVVsVzlkCnpiMGI0ZWxBU2NuVTlEUE9BVmNMM2xRd0RnWURWUjBQQVFIL0JBUURBZ0VHTUJJR0ExVWRFd0VCL3dRSU1BWUIKQWY4Q0FRQXdDZ1lJS29aSXpqMEVBd0lEUndBd1JBSWdYc1ZraTB3K2k2VllHVzNVRi8yMnVhWGUwWUpEajFVZQpuQStUakQxYWk1Y0NJQ1liMVNBbUQ1eGtmVFZwdm80VW95aVNZeHJEV0xtVVI0Q0k5Tkt5ZlBOKwotLS0tLUVORCBDRVJUSUZJQ0FURS0tLS0tCi0tLS0tQkVHSU4gQ0VSVElGSUNBVEUtLS0tLQpNSUlDanpDQ0FqU2dBd0lCQWdJVUltVU0xbHFkTkluemc3U1ZVcjlRR3prbkJxd3dDZ1lJS29aSXpqMEVBd0l3CmFERWFNQmdHQTFVRUF3d1JTVzUwWld3Z1UwZFlJRkp2YjNRZ1EwRXhHakFZQmdOVkJBb01FVWx1ZEdWc0lFTnYKY25CdmNtRjBhVzl1TVJRd0VnWURWUVFIREF0VFlXNTBZU0JEYkdGeVlURUxNQWtHQTFVRUNBd0NRMEV4Q3pBSgpCZ05WQkFZVEFsVlRNQjRYRFRFNE1EVXlNVEV3TkRVeE1Gb1hEVFE1TVRJek1USXpOVGsxT1Zvd2FERWFNQmdHCkExVUVBd3dSU1c1MFpXd2dVMGRZSUZKdmIzUWdRMEV4R2pBWUJnTlZCQW9NRVVsdWRHVnNJRU52Y25CdmNtRjAKYVc5dU1SUXdFZ1lEVlFRSERBdFRZVzUwWVNCRGJHRnlZVEVMTUFrR0ExVUVDQXdDUTBFeEN6QUpCZ05WQkFZVApBbFZUTUZrd0V3WUhLb1pJemowQ0FRWUlLb1pJemowREFRY0RRZ0FFQzZuRXdNRElZWk9qL2lQV3NDemFFS2k3CjFPaU9TTFJGaFdHamJuQlZKZlZua1k0dTNJamtEWVlMME14TzRtcXN5WWpsQmFsVFZZeEZQMnNKQks1emxLT0IKdXpDQnVEQWZCZ05WSFNNRUdEQVdnQlFpWlF6V1dwMDBpZk9EdEpWU3YxQWJPU2NHckRCU0JnTlZIUjhFU3pCSgpNRWVnUmFCRGhrRm9kSFJ3Y3pvdkwyTmxjblJwWm1sallYUmxjeTUwY25WemRHVmtjMlZ5ZG1salpYTXVhVzUwClpXd3VZMjl0TDBsdWRHVnNVMGRZVW05dmRFTkJMbVJsY2pBZEJnTlZIUTRFRmdRVUltVU0xbHFkTkluemc3U1YKVXI5UUd6a25CcXd3RGdZRFZSMFBBUUgvQkFRREFnRUdNQklHQTFVZEV3RUIvd1FJTUFZQkFmOENBUUV3Q2dZSQpLb1pJemowRUF3SURTUUF3UmdJaEFPVy81UWtSK1M5Q2lTRGNOb293THVQUkxzV0dmL1lpN0dTWDk0Qmd3VHdnCkFpRUE0SjBsckhvTXMrWG81by9zWDZPOVFXeEhSQXZaVUdPZFJRN2N2cVJYYXFJPQotLS0tLUVORCBDRVJUSUZJQ0FURS0tLS0tCgA=\"}" })
[2024-04-07T06:15:35Z INFO  actix_web::middleware::logger] 8.147.116.39 "POST /kbs/v0/attest HTTP/1.1" 200 4943 "-" "attestation-agent-kbs-client/0.1.0" 0.028964
[2024-04-07T06:15:35Z INFO  api_server::http::resource] Get pkey from auth header
[2024-04-07T06:15:35Z WARN  api_server::token::coco] No Trusted Certificate in Config, skip verification of JWK cert of Attestation Token
[2024-04-07T06:15:35Z INFO  api_server::http::resource] Resource description: ResourceDesc { repository_name: "default", resource_type: "aliyun", resource_tag: "ecs_ram_role" }
[2024-04-07T06:15:35Z DEBUG api_server::policy_engine::opa] Evaluated: {"allow":true}
[2024-04-07T06:15:35Z INFO  actix_web::middleware::logger] 8.147.116.39 "GET /kbs/v0/resource/default/aliyun/ecs_ram_role HTTP/1.1" 200 585 "-" "attestation-agent-kbs-client/0.1.0" 0.005432

After this PR

[2024-04-08T08:57:17Z INFO  actix_web::middleware::logger] 59.82.45.9 "POST /kbs/v0/auth HTTP/1.1" 200 74 "-" "attestation-agent-kbs-client/0.1.0" 0.000079
[2024-04-08T08:57:17Z INFO  api_server::http::attest] Attest API called.
[2024-04-08T08:57:17Z DEBUG api_server::http::attest] Session ID f871be1200ca4bd8aa5b64deec2086c2
[2024-04-08T08:57:17Z DEBUG api_server::http::attest] Attestation: {
      "tee-pubkey": {
        "kty": "RSA",
        "alg": "RSA1_5",
        "n": "wItTt8dSiq6KkQp0bAvdEpTcHZlIyNVfCjBXPyjOvP-aJpLK4nxYBBdvrvGkmSU4Uj1WClrNl4GeTlju05JKgpRhm1-jDQSr-xRTn1PEmT9ywNdruGhaOu9rjVlYKA2JR5Wlt3oc25dn88rxDWteQfyuSjdQvpCcwQsg9fCGxZwng86MZ8JGcMYaBBylyghkrruucYXMMU1ktAQbrEvIeTTuJnwAYczC5mbZJYbqvQcgIYuZ61-U-lbUNM4KuVTUWR7MN57u-4ftcYKWq2RlEmRrmaSPASlHJrdBXihbusJ2uabJOSJZZxAiy4k2I322rfYl2Z_RjckP0ocR-JCAow",
        "e": "AQAB"
      },
      "tee-evidence": "{\"svn\":\"1\",\"report_data\":\"O56zADB1kqZcKkYUQSYecoC6uMQjQuP/+6LxwCeFN2jSAU3fw6XI3580ihdB2pZN\"}"
    }
[2024-04-08T08:57:17Z INFO  actix_web::middleware::logger] 59.82.45.9 "POST /kbs/v0/attest HTTP/1.1" 200 2218 "-" "attestation-agent-kbs-client/0.1.0" 0.003992
[2024-04-08T08:57:18Z DEBUG api_server::http::resource] Get pkey from auth header
[2024-04-08T08:57:18Z WARN  api_server::token::coco] No Trusted Certificate in Config, skip verification of JWK cert of Attestation Token
[2024-04-08T08:57:18Z INFO  api_server::http::resource] Get resource from kbs:///default/key/ssh-demo
[2024-04-08T08:57:18Z DEBUG api_server::policy_engine::opa] OPA Evaluated: {"allow":true}
[2024-04-08T08:57:18Z INFO  api_server::http::resource] Resource access request passes policy check.
[2024-04-08T08:57:18Z INFO  actix_web::middleware::logger] 59.82.45.9 "GET /kbs/v0/resource/default/key/ssh-demo HTTP/1.1" 200 530 "-" "attestation-agent-kbs-client/0.1.0" 0.001344

Xynnn007 added 2 commits April 8, 2024 16:39
This commit mainly hides long logs that display specific data content
under the debug level, and only have short message prompts for info
level logs.

Signed-off-by: Xynnn007 <[email protected]>
Hide long details under debug level, and only print brief log under info
level.

Signed-off-by: Xynnn007 <[email protected]>
Copy link
Member

@fitzthum fitzthum left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Incredible work. Let's try to hold people to this standard with new code.

@Xynnn007 Xynnn007 merged commit 49b5353 into confidential-containers:main Apr 8, 2024
17 checks passed
@Xynnn007 Xynnn007 deleted the opt-log branch April 8, 2024 14:41
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants