Important log messages are lost when application cannot start

[forest-code42]

Type: Bug

Component:
io.awspring.cloud.autoconfigure.config.*
org.apache.commons.logging.LogFactory

TBH I am not sure if this bug is specific to spring-cloud-aws or if its more related to spring boots application startup process / logging during startup as a whole.

Describe the bug

Spring Cloud version 3.4.0

We ran into an issue with recent versions of AWS SDK when running on ECS.

This Line:

https://github.com/awspring/spring-cloud-aws/blob/main/spring-cloud-aws-autoconfigure/src/main/java/io/awspring/cloud/autoconfigure/config/secretsmanager/SecretsManagerPropertySources.java#L56

		try {
			SecretsManagerPropertySource propertySource = new SecretsManagerPropertySource(context, client);
			propertySource.init();
			return propertySource;
		}
		catch (Exception e) {
			LOG.warn("Unable to load AWS secret from " + context + ". " + e.getMessage());
			if (!optional) {
				throw new AwsSecretsManagerPropertySourceNotFoundException(e);
			}
		}

Would handle the thrown exception: java.lang.IllegalStateException: Either the environment variable AWS_WEB_IDENTITY_TOKEN_FILE or the javaproperty aws.webIdentityTokenFile must be set.

The LOG.warn("Unable to load AWS secret from " + context + ". " + e.getMessage()); statement definitely gets executed (I watched it happen in the remote debugger) but nothing is visible in the log regardless of whether or not the debugger is enabled / running / attached.

When that exception is thrown, the log looks like this:

....
 22:18:51,166 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [CLOUDWATCHV2] not referenced. Skipping further processing.
 22:18:51,166 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
 22:18:51,167 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [STDOUT] to Logger[ROOT]
 22:18:51,172 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@2ce6c6ec - End of configuration.
 22:18:51,175 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@1bae316d - Registering current configuration as safe fallback point
 22:18:51,175 |-INFO in ch.qos.logback.classic.util.ContextInitializer@39d9314d - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 1204 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY

 2025-12-01T22:18:55.870Z ERROR  --- [           main] o.s.b.d.LoggingFailureAnalysisReporter   :

 ***************************
 APPLICATION FAILED TO START
 ***************************

 Description:

 Config data resource '[SecretsManagerConfigDataResource@2c7106d9 context = '/foo/foo-app/rds/service/apm6Z?prefix=spring.datasource.', optional = false, enabled = true]' via location 'aws-secretsmanager:/foo/foo-app/rds/service/apm6Z?prefix=spring.datasource.' does not exist

 Action:

 Check that the value 'aws-secretsmanager:/foo/foo-app/rds/service/apm6Z?prefix=spring.datasource.' is correct, or prefix it with 'optional:'

However in this case, the /foo/foo-app/rds/service/apm6Z secret DOES exist. The issue is the error

java.lang.IllegalStateException: Either the environment variable AWS_WEB_IDENTITY_TOKEN_FILE or the javaproperty aws.webIdentityTokenFile must be set.

is preventing SecretsManagerPropertySources from doing its work.

We can side step this issue by setting

org.springframework.boot.BootstrapRegistryInitializer=com.foo.config.SecretsManagerBootstrapConfiguration in resources/META-INF/spring.factories

where it sets custom BootstrapRegistry.InstanceSuppliers w/ SecretsManagerClient.builder().credentialsProvider(...) and SsmClient.builder().credentialsProvider(...)s which use an AwsCredentialsProviderChain that omits the WebIdentityTokenFileCredentialsProvider. ( see: https://docs.awspring.io/spring-cloud-aws/docs/3.4.0/reference/html/index.html#customizing-secretsmanagerclient )

However, this does not address the issue: the issue is that in some cases, important log messages are being swallowed when the app can't start.

I know this because if I use the "fixed" version and then change the secret name in the SPRING_CONFIG_IMPORT env var, i see the Unable to load AWS secret from ... error as it should be:

23:03:24,177 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@2ce6c6ec - End of configuration.
23:03:24,178 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@1bae316d - Registering current configuration as safe fallback point
23:03:24,178 |-INFO in ch.qos.logback.classic.util.ContextInitializer@39d9314d - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 617 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY

23:03:30,592 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [CLOUDWATCHV2] not referenced. Skipping further processing.
2025-12-01T23:03:31.115Z  INFO 7 --- [           main] .a.c.a.c.s.SecretsManagerPropertySources : Loading secrets from AWS Secret Manager secret with name: /foo/foo-service/rds/service/9if8b?prefix=spring.datasource., optional: true
2025-12-01T23:03:31.117Z  WARN 7 --- [           main] .a.c.a.c.s.SecretsManagerPropertySources : Unable to load AWS secret from /foo/foo-service/rds/service/9if8b?prefix=spring.datasource.. Secrets Manager can't find the specified secret. (Service: SecretsManager, Status Code: 400, Request ID: xxxxxx) (SDK Attempt Count: 1)
2025-12-01T23:03:31.120Z  INFO 7 --- [           main] .a.c.a.c.s.SecretsManagerPropertySources : Loading secrets from AWS Secret Manager secret with name: /foo/foo-service/rds/service/9if8b?prefix=spring.datasource., optional: true
2025-12-01T23:03:31.121Z  WARN 7 --- [           main] .a.c.a.c.s.SecretsManagerPropertySources : Unable to load AWS secret from /foo/foo-service/rds/service/9if8b?prefix=spring.datasource.. Secrets Manager can't find the specified secret. (Service: SecretsManager, Status Code: 400, Request ID: xxxxxx) (SDK Attempt Count: 1)
2025-12-01T23:03:31.121Z  INFO 7 --- [           main] .a.c.a.c.p.ParameterStorePropertySources : Loading property from AWS Parameter Store with name: /foo/foo-service/, optional: false
23:03:33,347 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [CLOUDWATCHV2] not referenced. Skipping further processing.

Sample

I cannot directly share the code I am working on. I may be able to provide a purpose-built minimal sample on request.

[forest-code42]

I noticed when I was going thru in the debugger, the type of the LOG object which comes from the LogFactory.getLog was named something like AsyncLogger..

IDK if thats relevant at all but I'm wondering if perhaps a different logger could be used during startup which would print immediately, to prevent this issue where log messages that are critical to understanding why the app failed, end up hidden from the operator.

[MatejNedic]

Hey @forest-code42 ,thanks on opening the issue.
This is indeed is the problem and it will be resolved in Spring Cloud AWS 4.0.0
For parameter store this is already solved please check the following PR -> #1309

Will leave the issue open for S3 and SecretsManager implementation

[maciejwalkowiak]

Fixed in #1540 and #1541