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

Noisy logs #3202

Open
rngadam opened this issue Aug 28, 2024 · 9 comments · May be fixed by #3332
Open

Noisy logs #3202

rngadam opened this issue Aug 28, 2024 · 9 comments · May be fixed by #3332

Comments

@rngadam
Copy link
Contributor

rngadam commented Aug 28, 2024

At the agent start, the stdout of the agent shows multiple banner messages and output from print statements.

Having noisy logs makes it more difficult to identify quickly actual problems.

Expect to:

  • be able to suppress those banner messages
  • not have print statements (should be logging)

list of print statements

https://gist.github.com/rngadam/3cccd0f515091544f745d681d8119ae4

rngadam added a commit to rngadam/aries-cloudagent-python that referenced this issue Aug 28, 2024
rngadam added a commit to rngadam/aries-cloudagent-python that referenced this issue Aug 28, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
rngadam added a commit to rngadam/aries-cloudagent-python that referenced this issue Aug 28, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
rngadam added a commit to rngadam/aries-cloudagent-python that referenced this issue Aug 28, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
@WadeBarnes
Copy link
Contributor

WadeBarnes commented Aug 28, 2024

The deprecation banner and notices should only be displayed when you are using deprecated features. Suppressing these messages defeats the purpose of the messages - to let you know you are using deprecated features and you should migrate to alternate (replacement) features. So, the best practice way to get rid of the messages is to migrate away from the deprecated features you're using.

I do agree the messages should be logged rather than being printed.

Regarding the standard ACA-Py startup banner. I think this is a very important piece of diagnostic information that should not be suppressed. It provides you with a summary of the agent configuration and version that can help you identify issues right off the bat.

@rngadam
Copy link
Contributor Author

rngadam commented Aug 28, 2024

The deprecation banner and notices should only be displayed when you are using deprecated features. Suppressing these messages defeats the purpose of the messages - to let you know you are using deprecated features and you should migrate to alternate (replacement) features. So, the best practice way to get rid of the messages is to migrate away from the deprecated features you're using.

I expected that too, but if you look at the code the banner is printed everytime (there's no conditional):

from here:

https://github.com/hyperledger/aries-cloudagent-python/blob/90895bbc3f2bf203bbfe35f0464a9ea1f37ebeaa/aries_cloudagent/core/conductor.py#L321-L338

the only condition for printing the deprecation notice is having transports configured (aka transport is not disabled)

https://github.com/hyperledger/aries-cloudagent-python/blob/90895bbc3f2bf203bbfe35f0464a9ea1f37ebeaa/aries_cloudagent/config/logging.py#L389-L429

It's giving a deprecation notice whatever config and even though #2368 is not done yet. Correct me if I'm wrong, but there seems to be no way to "correctly" configure the agent to get rid of the deprecation notice.

@rngadam
Copy link
Contributor Author

rngadam commented Aug 28, 2024

Regarding the standard ACA-Py startup banner. I think this is a very important piece of diagnostic information that should not be suppressed. It provides you with a summary of the agent configuration and version that can help you identify issues right off the bat.

Perhaps in regular usage but it interferes with testing (I'm forking 100 agents from the same parent process, creating a storm of output) and creates the habit of eventually ignoring output that could/should be important.

@WadeBarnes
Copy link
Contributor

It's giving a deprecation notice whatever config and even though #2368 is not done yet. Correct me if I'm wrong, but there seems to be no way to "correctly" configure the agent to get rid of the deprecation notice.

@swcurran, @dbluhm, @jamshale, Can any of you comment on this?

rngadam added a commit to rngadam/aries-cloudagent-python that referenced this issue Aug 28, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
@jamshale
Copy link
Contributor

I don't think we'd want to add another configuration for this. We're really trying not to bloat the configurations. But, printing the banner nicely with the logger will be a bit tricky because it's configured to print the timestamp and class.

This seems like a pretty niche use case. The depreciation notice is only like 10 lines of output. If other maintainers don't care about adding a configuration than the open PR looks acceptable.

@swcurran
Copy link
Contributor

I don’t like the idea of the flag to block the banner. The whole point of the messages is that they be ugly and in the face of the deployers so that they become aware of the need to evolve their deployment. Especially if they go away when the deployment removes the deprecated feature. That’s the behaviour we want to encourage — “This message will not be printed if you update your deployment to do X, Y and Z. Do it today!!”.

If a deployment simply adds that flag, they will not see the future messages and will not know about future deprecations.

I think we should not add this.

@rngadam
Copy link
Contributor Author

rngadam commented Aug 28, 2024

@swcurran @jamshale as it is now, there's no way around the "deprecation notice".

It is deprecating something without any working alternatives to upgrade to.

For me, that is not deprecation, it is noise for which I cannot do anything about, polluting my stdout and causing me to miss actual important error messages.

@jamshale
Copy link
Contributor

Why don't you just test with your own fork or image? Or you should be able to filter your log output for single instances. You could also spread your instances startups out do the logs aren't all mixed up.

There is a lot of ways around this and finding these errors easier isn't something we need to fix by adding another configuration parameter.

@swcurran
Copy link
Contributor

What deprecation are you talking about? Do you mean this one?

:: Receiving a core DIDComm protocol with the `did:sov:BzCbsNYhMrjHiqZDTUASHg;spec` ::
:: prefix is deprecated. All parties sending this prefix should be notified that    ::
:: support for receiving such messages will be removed in a future release. Use     ::
:: https://didcomm.org/ instead. 

If so, that is not about “did:sov” vs. “did:indy”. Rather — it is the prefix to a DIDComm message type, such as:
https://didcomm.org/basicmessage/1.0/ which used to be sent as did:sov:BzCbsNYhMrjHiqZDTUASHg;spec/basicmessage/1.0/. The did:sov… part of that is a specific DID and is treated as a hard-coded string in the initial DIDComm protocols. We’re trying to eliminate it from the code base.

I fully agree that there should be a way to suppress such messages, and I’m not sure about this one, since the message is saying “hey, if you get a message from another party using the old prefix you should yell at them”. There is a flag to ensure that your deployment is not sending out such a prefix (since 0.5.5), and that flag is now automatically active for all ACA-Py deployments (since 0.11.0).

How about we do this:

  1. Remove the did:sov DIDComm message type prefix deprecation message as it has been two full releases since ACA-Py was changed to only send out the https://didcomm.org replacement.
  2. Document that all deprecation messages SHOULD provide information (or a link) to how the message can be suppressed — usually by migrating to the replacement approach. That cannot be a universal “Don’t show deprecation messages”, since that defeats their very valuable purpose.
  3. Nice to have — update the existing messages according to 2.

Thoughts?

ff137 pushed a commit to didx-xyz/acapy that referenced this issue Nov 5, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
ff137 pushed a commit to didx-xyz/acapy that referenced this issue Nov 6, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
@ff137 ff137 linked a pull request Nov 7, 2024 that will close this issue
ff137 pushed a commit to didx-xyz/acapy that referenced this issue Nov 7, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
ff137 pushed a commit to didx-xyz/acapy that referenced this issue Nov 12, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
ff137 pushed a commit to didx-xyz/acapy that referenced this issue Nov 13, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
ff137 pushed a commit to didx-xyz/acapy that referenced this issue Nov 14, 2024
…nt by logging statements

Signed-off-by: Ricky Ng-Adam <[email protected]>
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 a pull request may close this issue.

4 participants