--initialize-at-build-time appears to be ignored | AWS XRay SDK

[sherl0cks]

Describe the bug
I'm trying to get the AWS XRay SDK working using Manual Instrumentation from this doc. When doing so, I get an error during mvn clean install -Dnative -Dquarkus.native.container-build=true :

Caused by: com.oracle.graal.pointsto.constraints.UnsupportedFeatureException: Detected a FileDescriptor in the image heap. File descriptors opened during image generation are no longer open at image run time, and the files might not even be present anymore at image run time.  To see how this object got instantiated use -H:+TraceClassInitialization. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image run time by using the option --initialize-at-build-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Detailed message:
Trace:  object java.net.PlainDatagramSocketImpl
        object java.net.DatagramSocket
        object com.amazonaws.xray.emitters.DefaultEmitter
        object com.amazonaws.xray.AWSXRayRecorder
        field com.amazonaws.xray.AWSXRay.globalRecorder

Setting --initialize-at-build-time=com.amazonaws.xray in quarkus.native.additional-build-args appears to have no effect. I notice that --initialize-at-build-time= is set twice per #5480.

Expected behavior
Setting --initialize-at-build-time=com.amazonaws.xray would lead the static field with a file handle to resolve at build time, and the stack trace to go away.

Actual behavior
It doesn't happen, even though I'm following guidance from the stacktrace.

To Reproduce
Steps to reproduce the behavior:

1. Add to your pom.xml

        <dependency>
            <groupId>com.amazonaws</groupId>
            <artifactId>aws-xray-recorder-sdk-aws-sdk-v2</artifactId>
            <version>2.4.0</version>
        </dependency>

2. Instrument the AWS SDK per Manual Instrumentation from this doc.
3. Update application.properties with --initialize-at-build-time=com.amazonaws.xray
4. mvn clean install -Dnative -Dquarkus.native.container-build=true

Configuration

quarkus.lambda.handler=myHandler
quarkus.ssl.native=true
quarkus.native.additional-build-args=\
  -H:ReflectionConfigurationFiles=reflection-config.json,\
  --initialize-at-build-time=com.amazonaws.xray,\
  --initialize-at-run-time=com.some.avro

Environment (please complete the following information):

• Output of uname -a or ver: Darwin Kernel Version 18.7.0: Sun Dec 1 18:59:03 PST 2019; root:xnu-4903.278.19~1/RELEASE_X86_64 x86_64
• Output of java -version: openjdk version "1.8.0_212"
  OpenJDK Runtime Environment (AdoptOpenJDK)(build 1.8.0_212-b03)
  OpenJDK 64-Bit Server VM (AdoptOpenJDK)(build 25.212-b03, mixed mode)
• GraalVM version (if different from Java): 19.2.1-grl via sdkman
• Quarkus version or git rev: 1.1.1.Final

Additional context
If you need a reproducer, let me know. I could create one on Monday.

[gsmet]

By default, Quarkus initializes everything at build time and only selected classes at runtime.

The issue you have is because com.amazonaws.xray.emitters.DefaultEmitter is initialized at build time during the native image compilation and you end up with a file descriptor in the heap when the memory snapshot is taken.

What you want is to initialize this one at runtime.

[jaikiran]

Hello @sherl0cks,
I can understand why you used the --initialize-at-build-time - the error message says this:

You can request class initialization at image run time by using the option --initialize-at-build-time=<class-name>

Unfortunately, that error message (from Graal) has a typo. It should have said --initialize-at-run-time. That error message has been fixed upstream in Graal oracle/graal#1854. I don't know if it made 19.3.x release of Graal or whether it will only be in 20.x release of Graal.

[sherl0cks]

@jaikiran @gsmet Thanks, this is useful info. When I switch the package to initialize at runtime, I get the below. I cannot seem to find any docs on the subject. How do I handle this?

2020-01-25 01:21:50,234 SEVERE [com.ama.xra.int.TracingInterceptor] (Lambda Thread) Unable to parse default operation parameter whitelist at file:/project/lib/com.amazonaws.aws-xray-recorder-sdk-aws-sdk-v2-2.4.0.jar!/com/amazonaws/xray/interceptors/DefaultOperationParameterWhitelist.json. This will affect this handler's ability to capture AWS operation parameter information.: java.nio.file.NoSuchFileException: /project/lib/com.amazonaws.aws-xray-recorder-sdk-aws-sdk-v2-2.4.0.jar

[sherl0cks]

OK - looks like I can resolve the file by changing the --initialize-at-run-time=com.amazonaws.xray.AWSXray to the whole package --initialize-at-run-time=com.amazonaws.xray. This gets past the first issue, but now I have a commons logging issue. The solution discussed to exclude the transitives in https://quarkus.io/guides/dynamodb#configuring-dynamodb-clients does not seem to work. Thoughts?

I know #4968 is tackling a bigger AWS refactor. I haven't been able to check if xray was in there yet. If not, it prob should be.

Caused by: org.apache.commons.logging.LogConfigurationException: java.lang.ClassNotFoundException: org.apache.commons.logging.impl.LogFactoryImpl (Caused by java.lang.ClassNotFoundException: org.apache.commons.logging.impl.LogFactoryImpl)
	at org.apache.commons.logging.LogFactory.createFactory(LogFactory.java:1158)
	at org.apache.commons.logging.LogFactory$2.run(LogFactory.java:960)
	at java.security.AccessController.doPrivileged(AccessController.java:69)
	at org.apache.commons.logging.LogFactory.newFactory(LogFactory.java:957)
	at org.apache.commons.logging.LogFactory.getFactory(LogFactory.java:624)
	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:655)
	at com.amazonaws.xray.interceptors.TracingInterceptor.<clinit>(TracingInterceptor.java:42)
	at com.oracle.svm.core.hub.ClassInitializationInfo.invokeClassInitializer(ClassInitializationInfo.java:350)
	at com.oracle.svm.core.hub.ClassInitializationInfo.initialize(ClassInitializationInfo.java:270)
	... 24 more
Caused by: java.lang.ClassNotFoundException: org.apache.commons.logging.impl.LogFactoryImpl
	at com.oracle.svm.core.hub.ClassForNameSupport.forName(ClassForNameSupport.java:60)
	at java.lang.ClassLoader.loadClass(Target_java_lang_ClassLoader.java:131)
	at org.apache.commons.logging.LogFactory.createFactory(LogFactory.java:1020)
	... 32 more

[gsmet]

Just exclude commons-logging and use https://search.maven.org/artifact/org.jboss.logging/commons-logging-jboss-logging/1.0.0.Final/jar instead.

[sherl0cks]

Got passed the logging libs issues by adding the logging artifact as top level dep and excluding commons logging from ALL aws deps. Now working to resolve registering for reflecting items around Jackson

@gsmet any feedback if #4968 will seek to address AWS X Ray? If not, we may be interested to publish an xray extension, cuz getting this bootstrapped is a pain.

[sherl0cks]

Got reflection working, and we've run into what appears to be a more fundamental issue. At runtime, everything boots up correctly, but when tracing should begin, we get the following:
WARN [com.ama.xra.con.LambdaSegmentContext] (Lambda Thread) _X_AMZN_TRACE_ID is missing a trace ID, parent ID, or sampling decision. Subsegment S3 discarded.

It appears the root cause here is that AWS Lambda Custom Runtimes are required to do several things, including propagate the _X_AMZN_TRACE_ID environment variable. The quarkus lambda extension handles these concerns in Java code, but does not handle pass on _X_AMZN_TRACE_ID from the /runtime/invocation/next invocation. Digging into the AWS XRay SDK, there does not appear to be a way to set the trace id in the recorder apart from a environment variable though I haven't looked at this extensively.

So at this point, it appears that sending xray subsegments is not possible with the current aws lambda extension for quarkus, and that we have the following options forward:

1. update the quarkus extension with some approach to set the env var despite the fact that java doesn't allow that by default.
2. change the strategy for the quarkus lambda extension to use a bootstrap script to set the env vars and then pass information to the quarkus process
3. ask if aws will allow another way of setting the trace ID, perhaps via a system property?

[sherl0cks]

@patriot1burke ☝️ given you wrote most of that lambda extension that handles these concerns and may have some thoughts on this.

[sherl0cks]

Bumping this thread @gsmet @patriot1burke @jaikiran. This is a must have feature for any one that wants to deploy quarkus to production on AWS Lambda, which is precisely what we want to do. We are interested and willing to contribute a PR here, but we’d like agreement on a general direction before doing so.

[patriot1burke]

I should be able to look at it on Tuesday. Looks like a simple fix.

[sherl0cks]

Great news. Let us know if you need any input / testing / etc.

[patriot1burke]

• Propagate the tracing header – Get the X-Ray tracing header from the Lambda-Runtime-Trace-Id header in the API response. Set the _X_AMZN_TRACE_ID environment variable with the same value for the X-Ray SDK to use.

@sherl0cks X-RAY recorder (java) looks for the env var? Looks like you can hack env variables within java: https://stackoverflow.com/questions/318239/how-do-i-set-environment-variables-from-java

@gsmet I think we need a AWS X-Ray extension that:

• Sets the --initialize-at-run-time flag
• excludes apache logging

I can code this up quickly. Testing it is another matter as I'm completely unfamiliar with xray

[sherl0cks]

@patriot1burke I’m not an JAVA AWS xray SDK expert, but fortunately the source is oss , and from my reading of the code and docs, there is no other way to set the variable in the SDK than the environment variable. Link to code on github in one of my comments above.

I’m fine with whatever approach y’all want to maintain. Random thought - does process builder have platform specific code which may cause issues with native executables?

We can test this with X-ray in AWS Lambda so long as we have guidance on how to build/consume the appropriate dependency.

[patriot1burke]

@sherl0cks See my stackoverflow link above. I think getenv is hackable. Can only try it :)