Noisy logs

[rngadam]

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

[WadeBarnes]

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]

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:

aries-cloudagent-python/aries_cloudagent/core/conductor.py

Lines 321 to 338 in 90895bb

	if context.settings.get("transport.disabled"):
	LoggingConfigurator.print_banner(
	default_label,
	None,
	None,
	self.setup_public_did and self.setup_public_did.did,
	self.admin_server,
	)
	else:
	LoggingConfigurator.print_banner(
	default_label,
	self.inbound_transport_manager.registered_transports,
	self.outbound_transport_manager.registered_transports,
	self.setup_public_did and self.setup_public_did.did,
	self.admin_server,
	)
	LoggingConfigurator.print_notices(context.settings)

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

aries-cloudagent-python/aries_cloudagent/config/logging.py

Lines 389 to 429 in 90895bb

	@classmethod
	def print_notices(cls, settings: Settings):
	"""Print notices and warnings."""
	with Banner(border=":", length=80, file=sys.stderr) as banner:
	if settings.get("wallet.type", "in_memory").lower() == "indy":
	banner.centered("⚠ DEPRECATION NOTICE: ⚠")
	banner.hr()
	banner.print(
	"The Indy wallet type is deprecated, use Askar instead; see: "
	"https://aca-py.org/main/deploying/IndySDKtoAskarMigration/",
	)
	banner.hr()
	if not settings.get("transport.disabled"):
	banner.centered("⚠ DEPRECATION NOTICE: ⚠")
	banner.hr()
	banner.print(
	"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."
	)
	banner.hr()
	banner.print(
	"Aries RFC 0160: Connection Protocol is deprecated and "
	"support will be removed in a future release; "
	"use RFC 0023: DID Exchange instead."
	)
	banner.hr()
	banner.print(
	"Aries RFC 0036: Issue Credential 1.0 is deprecated "
	"and support will be removed in a future release; "
	"use RFC 0453: Issue Credential 2.0 instead."
	)
	banner.hr()
	banner.print(
	"Aries RFC 0037: Present Proof 1.0 is deprecated "
	"and support will be removed in a future release; "
	"use RFC 0454: Present Proof 2.0 instead."
	)
	print()

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]

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]

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?

[jamshale]

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]

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]

@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]

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]

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?