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

fix: add runtime hints for trace #1990

Merged
merged 14 commits into from
Aug 3, 2023
Merged

fix: add runtime hints for trace #1990

merged 14 commits into from
Aug 3, 2023

Conversation

zhumin8
Copy link
Contributor

@zhumin8 zhumin8 commented Jun 29, 2023

Builds on top of CI setup in #1933. Will rebase once its merged in.

This pr:

  • adds TraceRuntimeHints in trace autoconfig module and unit test for it. This allows native builds.
  • adds SampleRuntimeHints this enables pubsub trace portion of the sample to run after Native Build. not exactly sure why this is needed.
  • adds TestRuntimeHints to allow logging portion of the test setup run as expect. (same as fix: add runtime hints for logging #1933)

CI test should run sample integration test.

To test run manually:

  • run application, build with mvn clean package -Pnative-sample-config -Pnative, then run application with ./target/spring-cloud-gcp-trace-sample. Then follow sample README to test functionality.
  • run test: mvn -PnativeTest clean test -Pnative-sample-config
    expect to get:
com.example.TraceSampleApplicationIntegrationTests > testTracesAreLoggedCorrectly() SUCCESSFUL


Test run finished after 18500 ms
[         3 containers found      ]
[         0 containers skipped    ]
[         3 containers started    ]
[         0 containers aborted    ]
[         3 containers successful ]
[         0 containers failed     ]
[         1 tests found           ]
[         0 tests skipped         ]
[         1 tests started         ]
[         0 tests aborted         ]
[         1 tests successful      ]
[         0 tests failed          ]

UPDATE: start failing on ci and local after rebase. Need investigate.

@mpeddada1
Copy link
Contributor

mpeddada1 commented Jul 12, 2023

Pasting in error message for reference:

21:05:59.307 [main] INFO  c.e.LoggingSampleApplicationIntegrationTests - No active profile set, falling back to 1 default profile: "default"
21:06:01.061 [main] WARN  o.s.t.c.aot.TestContextAotGenerator - Failed to generate AOT artifacts for test classes [com.example.LoggingSampleApplicationIntegrationTests]
org.springframework.test.context.aot.TestContextAotException: Failed to process test class [com.example.LoggingSampleApplicationIntegrationTests] for AOT
	at org.springframework.test.context.aot.TestContextAotGenerator.processAheadOfTime(TestContextAotGenerator.java:239)
	at org.springframework.test.context.aot.TestContextAotGenerator.lambda$processAheadOfTime$4(TestContextAotGenerator.java:205)
	at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:721)
	at org.springframework.util.MultiValueMapAdapter.forEach(MultiValueMapAdapter.java:179)
	at org.springframework.test.context.aot.TestContextAotGenerator.processAheadOfTime(TestContextAotGenerator.java:1[97](https://github.com/GoogleCloudPlatform/spring-cloud-gcp/actions/runs/5603876214/job/15181479077?pr=1990#step:13:98))
	at org.springframework.test.context.aot.TestContextAotGenerator.processAheadOfTime(TestContextAotGenerator.java:159)
	at org.springframework.test.context.aot.TestAotProcessor.performAotProcessing(TestAotProcessor.java:91)
	at org.springframework.test.context.aot.TestAotProcessor.doProcess(TestAotProcessor.java:72)
	at org.springframework.test.context.aot.TestAotProcessor.doProcess(TestAotProcessor.java:39)
	at org.springframework.context.aot.AbstractAotProcessor.process(AbstractAotProcessor.java:82)
	at org.springframework.boot.test.context.SpringBootTestAotProcessor.main(SpringBootTestAotProcessor.java:63)
Caused by: java.lang.NoClassDefFoundError: org/aspectj/lang/ProceedingJoinPoint
	at com.google.cloud.spring.autoconfigure.trace.aot.TraceRuntimeHints.registerHints(TraceRuntimeHints.java:34)
	at 

....

Failures (1):
  JUnit Jupiter:LoggingSampleApplicationIntegrationTests
    ClassSource [className = 'com.example.LoggingSampleApplicationIntegrationTests', filePosition = null]
    => java.lang.ExceptionInInitializerError
       org.springframework.test.context.TestContextManager.<init>(TestContextManager.java:113)
       org.junit.jupiter.engine.execution.ExtensionValuesStore.lambda$getOrComputeIfAbsent$4(ExtensionValuesStore.java:86)
       org.junit.jupiter.engine.execution.ExtensionValuesStore$MemoizingSupplier.computeValue(ExtensionValuesStore.java:223)
       org.junit.jupiter.engine.execution.ExtensionValuesStore$MemoizingSupplier.get(ExtensionValuesStore.java:211)
       org.junit.jupiter.engine.execution.ExtensionValuesStore$StoredValue.evaluate(ExtensionValuesStore.java:191)
       [...]
       Suppressed: java.lang.NoClassDefFoundError: Could not initialize class org.springframework.test.context.BootstrapUtils
         org.springframework.test.context.TestContextManager.<init>(TestContextManager.java:113)
         org.junit.jupiter.engine.execution.ExtensionValuesStore.lambda$getOrComputeIfAbsent$4(ExtensionValuesStore.java:86)
         org.junit.jupiter.engine.execution.ExtensionValuesStore$MemoizingSupplier.computeValue(ExtensionValuesStore.java:223)
         org.junit.jupiter.engine.execution.ExtensionValuesStore$MemoizingSupplier.get(ExtensionValuesStore.java:211)
         org.junit.jupiter.engine.execution.ExtensionValuesStore$StoredValue.evaluate(ExtensionValuesStore.java:191)
         [...]
     Caused by: java.lang.IllegalStateException: Failed to load class for @org.springframework.test.context.web.WebAppConfiguration
       org.springframework.test.context.BootstrapUtils.loadWebAppConfigurationClass(BootstrapUtils.java:213)
       org.springframework.test.context.BootstrapUtils.<clinit>(BootstrapUtils.java:63)
       [...]
     Caused by: java.lang.ClassNotFoundException: org.springframework.test.context.web.WebAppConfiguration
       [email protected]/java.lang.Class.forName(DynamicHub.java:1132)
       org.springframework.util.ClassUtils.forName(ClassUtils.java:284)
       org.springframework.test.context.BootstrapUtils.loadWebAppConfigurationClass(BootstrapUtils.java:209)
       [...]

@mpeddada1
Copy link
Contributor

mpeddada1 commented Jul 19, 2023

A note for GraalVM for JDK 17 implementation (not applicable to GraalVM 22.3.2): The argument to enable RunReachabilityHandlersConcurrently feature is needed for this sample in GraalVM for JDK 17 (GraalVM 23):

<plugin>
	<groupId>org.graalvm.buildtools</groupId>
	<artifactId>native-maven-plugin</artifactId>
	<configuration>
		<buildArgs>
		  <arg>-H:+RunReachabilityHandlersConcurrently</arg>
		</buildArgs>
	</configuration>
</plugin>

Without this argument, the tests fail at build time with the following error:

Failed generating 'native-tests' after 45.4s.

The build process encountered an unexpected error:

> java.lang.NullPointerException: Cannot invoke "java.util.Set.iterator()" because "triggers" is null

Comment on lines 42 to 43
TypeReference.of(com.google.protobuf.Value.class),
TypeReference.of(com.google.protobuf.Value.Builder.class)),
Copy link
Contributor

@mpeddada1 mpeddada1 Jul 19, 2023

Choose a reason for hiding this comment

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

These two configurations may be removed after the static jsons are generated through googleapis/sdk-platform-java#1841. For now, we get the following error without these configurations:

Failures (1):
  JUnit Jupiter:TraceSampleApplicationIntegrationTests:testTracesAreLoggedCorrectly()
    MethodSource [className = 'com.example.TraceSampleApplicationIntegrationTests', methodName = 'testTracesAreLoggedCorrectly', methodParameterTypes = '']
    => java.lang.IllegalStateException: Generated message class "com.google.protobuf.Value$Builder" missing method "hasNullValue".
       com.google.protobuf.GeneratedMessageV3.getMethodOrDie(GeneratedMessageV3.java:1998)
       com.google.protobuf.GeneratedMessageV3.access$1000(GeneratedMessageV3.java:79)
       com.google.protobuf.GeneratedMessageV3$FieldAccessorTable$SingularFieldAccessor$ReflectionInvoker.<init>(GeneratedMessageV3.java:2353)
       com.google.protobuf.GeneratedMessageV3$FieldAccessorTable$SingularFieldAccessor.<init>(GeneratedMessageV3.java:2418)
       com.google.protobuf.GeneratedMessageV3$FieldAccessorTable$SingularEnumFieldAccessor.<init>(GeneratedMessageV3.java:2893)
       [...]
     Caused by: java.lang.NoSuchMethodException: com.google.protobuf.Value$Builder.hasNullValue()
       [email protected]/java.lang.Class.checkMethod(DynamicHub.java:1038)
       [email protected]/java.lang.Class.getMethod(DynamicHub.java:1023)
       com.google.protobuf.GeneratedMessageV3.getMethodOrDie(GeneratedMessageV3.java:1995)
       [...]

Copy link
Member

Choose a reason for hiding this comment

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

I don't see com.google.protobuf.Value as an entry in the Trace library's reflect-config.json. It does show up for some, though: https://github.com/search?q=repo%3Agoogleapis%2Fgoogle-cloud-java+com.google.protobuf.Value+path%3A**%2Freflect-config.json&type=code&p=1

  • Do we need to adjust the generation logic to include more than messages defined in the protos, or is a non-trace library triggering the reflection lookup?

Copy link
Contributor

@mpeddada1 mpeddada1 Jul 31, 2023

Choose a reason for hiding this comment

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

Good point! Analyzing the stacktrace of the test shows that the use of com.google.protobuf.Value is coming from

This line of code eventually leads to GeneratedMessageV3#getMethodOrDie being called:
Screenshot 2023-07-31 at 6 07 51 PM

I've moved the configuration to the test/ directory.

Copy link
Contributor

Choose a reason for hiding this comment

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

[Update] Tests are passing without these configurations after rebasing with origin/main.

Comment on lines +26 to +34

@Override
public void registerHints(RuntimeHints hints, ClassLoader classLoader) {
hints.reflection().registerTypes(
Arrays.asList(TypeReference.of(Application.class)),
hint -> hint.withMembers(
MemberCategory.INVOKE_PUBLIC_METHODS));
}
}
Copy link
Contributor

Choose a reason for hiding this comment

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

Without this configuration, the sample test results in:

com.example.TraceSampleApplicationIntegrationTests > testTracesAreLoggedCorrectly() FAILED


Failures (1):
  JUnit Jupiter:TraceSampleApplicationIntegrationTests:testTracesAreLoggedCorrectly()
    MethodSource [className = 'com.example.TraceSampleApplicationIntegrationTests', methodName = 'testTracesAreLoggedCorrectly', methodParameterTypes = '']
    => com.oracle.svm.core.jdk.UnsupportedFeatureError: ThreadMXBean methods
       org.graalvm.nativeimage.builder/com.oracle.svm.core.util.VMError.unsupportedFeature(VMError.java:89)
       org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.management.SubstrateThreadMXBean.findDeadlockedThreads(SubstrateThreadMXBean.java:258)
       org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:157)
       org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
       org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
       org.awaitility.core.ConditionFactory.until(ConditionFactory.java:985)
       org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:769)
       com.example.TraceSampleApplicationIntegrationTests.testTracesAreLoggedCorrectly(TraceSampleApplicationIntegrationTests.java:191)
       [email protected]/java.lang.reflect.Method.invoke(Method.java:568)
       org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727)
       [...]

@mpeddada1 mpeddada1 marked this pull request as ready for review July 21, 2023 20:01
@mpeddada1 mpeddada1 requested a review from a team as a code owner July 21, 2023 20:01
Comment on lines 42 to 43
TypeReference.of(com.google.protobuf.Value.class),
TypeReference.of(com.google.protobuf.Value.Builder.class)),
Copy link
Member

Choose a reason for hiding this comment

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

I don't see com.google.protobuf.Value as an entry in the Trace library's reflect-config.json. It does show up for some, though: https://github.com/search?q=repo%3Agoogleapis%2Fgoogle-cloud-java+com.google.protobuf.Value+path%3A**%2Freflect-config.json&type=code&p=1

  • Do we need to adjust the generation logic to include more than messages defined in the protos, or is a non-trace library triggering the reflection lookup?

@mpeddada1
Copy link
Contributor

Thanks for the review @burkedavison! Adding some initial findings here. The dependency tree of the sample shows that the protobuf-java dependency which contains the com.google.protobuf.Value is brought in from google-cloud-trace:

[INFO] +- com.google.api.grpc:grpc-google-cloud-trace-v1:jar:2.20.0:test
[INFO] |  +- io.grpc:grpc-api:jar:1.55.1:compile
[INFO] |  +- io.grpc:grpc-context:jar:1.55.1:compile
[INFO] |  +- com.google.code.findbugs:jsr305:jar:3.0.2:compile
[INFO] |  +- com.google.errorprone:error_prone_annotations:jar:2.18.0:compile
[INFO] |  +- io.grpc:grpc-stub:jar:1.55.1:compile
[INFO] |  +- io.grpc:grpc-protobuf:jar:1.55.1:compile
[INFO] |  +- com.google.api.grpc:proto-google-common-protos:jar:2.21.0:compile
[INFO] |  +- io.grpc:grpc-protobuf-lite:jar:1.55.1:compile
[INFO] |  +- com.google.protobuf:protobuf-java:jar:3.23.2:compile
[INFO] |  +- com.google.api.grpc:proto-google-cloud-trace-v1:jar:2.20.0:test
[INFO] |  +- com.google.guava:guava:jar:31.1-jre:compile
[INFO] |  +- com.google.guava:failureaccess:jar:1.0.1:compile
[INFO] |  +- com.google.guava:listenablefuture:jar:9999.0-empty-to-avoid-conflict-with-guava:compile
[INFO] |  +- org.checkerframework:checker-qual:jar:3.33.0:compile
[INFO] |  \- com.google.j2objc:j2objc-annotations:jar:2.8:compile

Digging deeper to see if the stacktrace gives us more clues on how this class is being invoked.

@mpeddada1
Copy link
Contributor

Subdirectories for aot.factories don't get recognized. The trace sample fails with:

com.example.TraceSampleApplicationIntegrationTests > testTracesAreLoggedCorrectly() FAILED


Failures (1):
  JUnit Jupiter:TraceSampleApplicationIntegrationTests:testTracesAreLoggedCorrectly()
    MethodSource [className = 'com.example.TraceSampleApplicationIntegrationTests', methodName = 'testTracesAreLoggedCorrectly', methodParameterTypes = '']
    => com.oracle.svm.core.jdk.UnsupportedFeatureError: ThreadMXBean methods
       org.graalvm.nativeimage.builder/com.oracle.svm.core.util.VMError.unsupportedFeature(VMError.java:89)
       org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.management.SubstrateThreadMXBean.findDeadlockedThreads(SubstrateThreadMXBean.java:258)
       org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:157)
       org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
       org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
       org.awaitility.core.ConditionFactory.until(ConditionFactory.java:985)
       org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:769)
       com.example.TraceSampleApplicationIntegrationTests.testTracesAreLoggedCorrectly(TraceSampleApplicationIntegrationTests.java:191)
       [email protected]/java.lang.reflect.Method.invoke(Method.java:568)
       org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727)
       [...]

Using ImportRuntimeHints annotation instead to resolve the failure mentioned in #1990 (comment)

@sonarcloud
Copy link

sonarcloud bot commented Aug 1, 2023

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 0 Code Smells

100.0% 100.0% Coverage
0.0% 0.0% Duplication

@mpeddada1 mpeddada1 merged commit 2ba4a75 into main Aug 3, 2023
29 checks passed
@mpeddada1 mpeddada1 deleted the trace-hints-2 branch August 3, 2023 15:56
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.

3 participants