Skip to content

Improve the diagnostic experience by deprecating the flag "--verbose" and standardize the debug logs #1247

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

Closed
5 tasks
FeynmanZhou opened this issue Mar 31, 2025 · 1 comment · Fixed by #1260
Closed
5 tasks
Assignees
Labels
enhancement New feature or request
Milestone

Comments

@FeynmanZhou
Copy link
Member

FeynmanZhou commented Mar 31, 2025

Is your feature request related to a problem?

Known problems

  • The user is confused about when to use --verbose and --debug.
  • Poor readability of debug logs. No separator lines between request and response information. Users need to add separator lines manually for readability.
  • Each log entry does not provide a precise timestamp to trace the sequence of events accurately. notation SHOULD use the Nanoseconds precision to print the timestamp in the first field of each line.
  • The user environment information is not printed out. This causes a higher cost to reproduce the issues for notation developers locally.

A sample debug log of notation sign:

DEBU[2025-03-31T16:37:29-07:00] Request #0
> Request: "HEAD" "https://ghcr.io/v2/chocolate-labs/oras/manifests/v1"
> Request headers:
   "Accept": "application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, application/vnd.oci.artifact.manifest.v1+json"
   "User-Agent": "notation/2.0.0-alpha.1" 
DEBU[2025-03-31T16:37:29-07:00] Response #0
< Response status: "401 Unauthorized"
< Response headers:
   "X-Github-Request-Id": "5BAF:103779:3C9A782:3E5A8CD:67EB2739"
   "Content-Type": "application/json"
   "Www-Authenticate": "Bearer realm=\"https://ghcr.io/token\",service=\"ghcr.io\",scope=\"repository:chocolate-labs/oras:pull\""
   "Date": "Mon, 31 Mar 2025 23:37:29 GMT"
   "Content-Length": "73" 
DEBU[2025-03-31T16:37:29-07:00] started executing credential helper program docker-credential-desktop with action get 
DEBU[2025-03-31T16:37:29-07:00] successfully finished executing credential helper program docker-credential-desktop with action get 
DEBU[2025-03-31T16:37:29-07:00] Request #1
> Request: "GET" "https://ghcr.io/token?scope=repository%3Achocolate-labs%2Foras%3Apull&service=ghcr.io"
> Request headers:
   "Authorization": "*****"
   "User-Agent": "notation/2.0.0-alpha.1" 
DEBU[2025-03-31T16:37:29-07:00] Response #1
< Response status: "200 OK"
< Response headers:
   "Content-Type": "application/json"
   "Docker-Distribution-Api-Version": "registry/2.0"
   "Date": "Mon, 31 Mar 2025 23:37:29 GMT"
   "Content-Length": "137"
   "X-Github-Request-Id": "5BAF:103779:3C9A7BD:3E5A906:67EB2739" 
DEBU[2025-03-31T16:37:29-07:00] Request #2
> Request: "HEAD" "https://ghcr.io/v2/chocolate-labs/oras/manifests/v1"
> Request headers:
   "Accept": "application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, application/vnd.oci.artifact.manifest.v1+json"
   "Authorization": "*****"
   "User-Agent": "notation/2.0.0-alpha.1" 
DEBU[2025-03-31T16:37:29-07:00] Response #2
< Response status: "403 Forbidden"
< Response headers:
   "Content-Length": "86"
   "X-Github-Request-Id": "5BAF:103779:3C9A7DA:3E5A92A:67EB2739"
   "Content-Type": "application/json"
   "Docker-Distribution-Api-Version": "registry/2.0"
   "Date": "Mon, 31 Mar 2025 23:37:29 GMT" 
Error: failed to get manifest descriptor: HEAD "https://ghcr.io/v2/chocolate-labs/oras/manifests/v1": response status code 403: Forbidden
feynmanzhou@feynmanzhous-MacBook-Pro Downloads % notation sign ghcr.io/chocolate-labs/oras:v1 --key local-test --signature-format cose -v
Error: failed to get manifest descriptor: HEAD "https://ghcr.io/v2/chocolate-labs/oras/manifests/v1": response status code 403: Forbidden
feynmanzhou@feynmanzhous-MacBook-Pro Downloads % notation inspect ghcr.io/chocolate-labs/oras:v1
Error: failed to get manifest descriptor: HEAD "https://ghcr.io/v2/chocolate-labs/oras/manifests/v1": response status code 403: Forbidden

What solution do you propose?

Improve the diagnostic experience by deprecating the flag "--verbose" and standardize the debug logs.

Currently, notation offers two global options, --verbose and --debug, which enable users to generate verbose output and logs respectively. These features facilitate both users and developers in inspecting notation's performance, interactions with external services and internal systems, and in diagnosing issues by providing a clear picture of the tool's operations.

Given the diverse roles and scenarios in which notation CLI is utilized, we have received feedback from users and developers to improve the diagnostic experience. Enhancing logging experience can significantly benefit notation users and developers by making diagnostics clearer and more unambiguous.

I would propose the following solutions to Notation diagnostic experience:

  • Deprecate the --verbose flag but keep --debug flag to avoid ambiguity and duplicated INFO level logs in two outputs. It is reasonable to continue using --debug to enable logs with different levels as it is in notation.
  • Add two empty lines as the separator between each request and response for readability.
  • Add timestamp of each request and response to the beginning of each request and response. Use the Nanoseconds precision to print the timestamp
  • Considering notation is not a daemon service so parsing debug logs to a logging system is not a common scenario. The target users of the debug logs are normal users and notation developers. Thereby, the debug logs in TTY mode and non-TTY (--no-tty) should be consistent, except for the color. Specifically, debug logs SHOULD be colored-code in a TTY mode for better readability on terminal but keeping plain text without color in a non-TTY mode.
  • Show running environment details of notation such as OS/Arch in the output of notation version. It would be helpful to help the notation developers locate and reproduce the issue easier.

What alternatives have you considered?

N/A

Any additional context?

No response

@FeynmanZhou
Copy link
Member Author

@JeyJeyGao I've listed my suggested enhancements in this issue. In addiontion to known enhancements above, have you identified others? I will raise a PR for the guidance of the debug logs.

Maybe you could convert each one into a sub-issue when you raise PR for each of them.

JeyJeyGao added a commit that referenced this issue May 13, 2025
Pending on #1260

Example of notation version command
```
Notation - a tool to sign and verify artifacts.

Version:     v2.0.0-alpha.1+unreleased
Go version:  go1.24.0
OS/Arch:     linux/amd64
Git commit:  c68425f
```

Resolve part of #1247

---------

Signed-off-by: Junjie Gao <[email protected]>
JeyJeyGao added a commit that referenced this issue May 13, 2025
Pending on #1260

This PR removed the `--verbose` flag support as proposed in
#1260.

Resolve part of #1247

---------

Signed-off-by: Junjie Gao <[email protected]>
FeynmanZhou pushed a commit to FeynmanZhou/notation that referenced this issue May 15, 2025
Pending on notaryproject#1260

Example of notation version command
```
Notation - a tool to sign and verify artifacts.

Version:     v2.0.0-alpha.1+unreleased
Go version:  go1.24.0
OS/Arch:     linux/amd64
Git commit:  c68425f
```

Resolve part of notaryproject#1247

---------

Signed-off-by: Junjie Gao <[email protected]>
FeynmanZhou pushed a commit to FeynmanZhou/notation that referenced this issue May 15, 2025
…ct#1276)

Pending on notaryproject#1260

This PR removed the `--verbose` flag support as proposed in
notaryproject#1260.

Resolve part of notaryproject#1247

---------

Signed-off-by: Junjie Gao <[email protected]>
FeynmanZhou added a commit to FeynmanZhou/notation that referenced this issue May 15, 2025
Resolve notaryproject#1247 

This proposal document aims to:

1. Identify the usability issues of the `--verbose` and `--debug`
options.
2. Clarify the concepts of different types of output and logs for
diagnostic purposes.
3. List the guiding principles to write comprehensive, clear, and
conducive debug output and debug logs for effective diagnosis.
4. Propose solutions to improve the diagnostic experience for `notation`
CLI users and developers.

---------

Signed-off-by: Feynman Zhou <[email protected]>
JeyJeyGao added a commit that referenced this issue May 15, 2025
Pending on #1260

Fix:
- updated timestamp to UTC with nanosecond
- added new line after request and response log

Previous example:
```
DEBU[2025-04-14T07:42:25Z] Request #0
> Request: "HEAD" "https://notationreg.azurecr.io/v2/hello/manifests/v1"
> Request headers:
   "Accept": "application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, application/vnd.oci.artifact.manifest.v1+json"
   "User-Agent": "notation/v2.0.0-alpha.1+unreleased"
DEBU[2025-04-14T07:42:26Z] Response #0
< Response status: "401 Unauthorized"
< Response headers:
   "Content-Length": "199"
   "X-Content-Type-Options": "nosniff"
   "Date": "Mon, 14 Apr 2025 07:42:26 GMT"
   "Server": "AzureContainerRegistry"
   "Connection": "keep-alive"
   "Strict-Transport-Security": "max-age=31536000; includeSubDomains, max-age=31536000; includeSubDomains"
   "Content-Type": "application/json; charset=utf-8"
   "Access-Control-Expose-Headers": "Docker-Content-Digest, WWW-Authenticate, Link, X-Ms-Correlation-Request-Id"
   "Docker-Distribution-Api-Version": "registry/2.0"
   "Www-Authenticate": "Bearer realm=\"https://notationreg.azurecr.io/oauth2/token\",service=\"notationreg.azurecr.io\",scope=\"repository:hello:pull\""
   "X-Ms-Correlation-Request-Id": "df5ee6ff-0afb-47d6-ab98-6835c2e41f8a"
DEBU[2025-04-14T07:42:26Z] Request #1
> Request: "POST" "https://notationreg.azurecr.io/oauth2/token"
> Request headers:
   "Content-Type": "application/x-www-form-urlencoded"
   "User-Agent": "notation/v2.0.0-alpha.1+unreleased"
```

Current example:
```                  
notation sign notationreg.azurecr.io/hello:v1 -d
DEBU[2025-05-12 07:41:42.720229189Z] Request #0
> Request: "HEAD" "https://notationreg.azurecr.io/v2/hello/manifests/v1"
> Request headers:
   "Accept": "application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, application/vnd.oci.artifact.manifest.v1+json"
   "User-Agent": "notation/v2.0.0-alpha.1+unreleased"


DEBU[2025-05-12 07:41:43.248214367Z] Response #0
< Response status: "401 Unauthorized"
< Response headers:
   "Date": "Mon, 12 May 2025 07:41:43 GMT"
   "Server": "AzureContainerRegistry"
   "Access-Control-Expose-Headers": "Docker-Content-Digest, WWW-Authenticate, Link, X-Ms-Correlation-Request-Id"
   "Docker-Distribution-Api-Version": "registry/2.0"
   "Strict-Transport-Security": "max-age=31536000; includeSubDomains, max-age=31536000; includeSubDomains"
   "X-Content-Type-Options": "nosniff"
   "X-Ms-Correlation-Request-Id": "0c11d32c-4ffe-480c-acb3-8d145a83a87e"
   "Content-Type": "application/json; charset=utf-8"
   "Content-Length": "199"
   "Connection": "keep-alive"
   "Www-Authenticate": "Bearer realm=\"https://notationreg.azurecr.io/oauth2/token\",service=\"notationreg.azurecr.io\",scope=\"repository:hello:pull\""


DEBU[2025-05-12 07:41:43.248394566Z] Request #1
> Request: "POST" "https://notationreg.azurecr.io/oauth2/token"
> Request headers:
   "Content-Type": "application/x-www-form-urlencoded"
   "User-Agent": "notation/v2.0.0-alpha.1+unreleased"


DEBU[2025-05-12 07:41:43.414852708Z] Response #1
< Response status: "200 OK"
< Response headers:
   "Connection": "keep-alive"
   "X-Ms-Correlation-Request-Id": "d4baeae0-e47e-4b6f-8767-a7002229a1d6"
   "X-Ms-Ratelimit-Remaining-Calls-Per-Second": "333.316667"
   "Strict-Transport-Security": "max-age=31536000; includeSubDomains"
   "Server": "AzureContainerRegistry"
   "Date": "Mon, 12 May 2025 07:41:43 GMT"
   "Content-Type": "application/json; charset=utf-8"
```

Color:

![image](https://github.com/user-attachments/assets/6a54c33e-2f84-4e4b-a88a-49f1877a2b29)

![image](https://github.com/user-attachments/assets/08173d5c-4327-4545-8ee1-7be94babde18)

![image](https://github.com/user-attachments/assets/c9bc1270-58bd-42f8-9fcf-819779a16687)

![image](https://github.com/user-attachments/assets/2c3a85b9-5118-4e19-9ae1-7457174a934a)

Resolve part of #1247

---------

Signed-off-by: Junjie Gao <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
Status: Done
Development

Successfully merging a pull request may close this issue.

2 participants