ARTICLE AD BOX
A method receives ProcessHandle toBeKilledProcessHandle and then kills that process normally. Note that this is normal termination of the process so that the shutdown hook gets invoked in that process.
boolean terminated = toBeKilledProcessHandle.destroy();Although the return value terminated is true, that process doesn't get killed actually. That process can be found by ps -ef.
Thread dump of that process has the following portion:
"Thread-3" #29 [1963] prio=5 os_prio=0 cpu=6.63ms elapsed=1524.97s tid=0x000070e474005da0 nid=1963 waiting on condition [0x000070e603c05000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park([email protected]/Native Method) - parking to wait for <0x00000000ff714278> (a java.util.concurrent.CompletableFuture$Signaller) at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:221) at java.util.concurrent.CompletableFuture$Signaller.block([email protected]/CompletableFuture.java:1864) at java.util.concurrent.ForkJoinPool.unmanagedBlock([email protected]/ForkJoinPool.java:3780) at java.util.concurrent.ForkJoinPool.managedBlock([email protected]/ForkJoinPool.java:3725) at java.util.concurrent.CompletableFuture.waitingGet([email protected]/CompletableFuture.java:1898) at java.util.concurrent.CompletableFuture.get([email protected]/CompletableFuture.java:2072) at software.amazon.awssdk.utils.CompletableFutureUtils.joinInterruptibly(CompletableFutureUtils.java:227) at software.amazon.awssdk.http.crt.AwsCrtHttpClient$CrtHttpRequest.call(AwsCrtHttpClient.java:118) at software.amazon.awssdk.http.crt.AwsCrtHttpClient$CrtHttpRequest.call(AwsCrtHttpClient.java:104) at software.amazon.awssdk.core.internal.util.MetricUtils.measureDurationUnsafe(MetricUtils.java:103) at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.executeHttpRequest(MakeHttpRequestStage.java:88) at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:64) at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:46) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:74) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:43) at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:79) at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:41) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:55) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:39) at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.executeRequest(RetryableStage.java:93) at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:56) at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:36) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:53) at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:35) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.executeWithTimer(ApiCallTimeoutTrackingStage.java:82) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:62) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:43) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:50) at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:32) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:37) at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:26) at software.amazon.awssdk.core.internal.http.AmazonSyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonSyncHttpClient.java:210) at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.invoke(BaseSyncClientHandler.java:103) at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.doExecute(BaseSyncClientHandler.java:173) at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.lambda$execute$1(BaseSyncClientHandler.java:80) at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler$$Lambda/0x000070e66c2a3858.get(Unknown Source) at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.measureApiCallSuccess(BaseSyncClientHandler.java:182) at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.execute(BaseSyncClientHandler.java:74) at software.amazon.awssdk.core.client.handler.SdkSyncClientHandler.execute(SdkSyncClientHandler.java:45) at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.execute(AwsSyncClientHandler.java:53) at software.amazon.awssdk.services.s3.DefaultS3Client.uploadPart(DefaultS3Client.java:13556) at com.company.CompanyOperations.uploadPart(CompanyOperations.java:559) at com.company.CompanyWrapper.uploadPart(CompanyWrapper.java:440) at com.company.CompanyObjectOutputStream.flushBuffer(CompanyObjectOutputStream.java:171) at com.company.CompanyObjectOutputStream.close(CompanyObjectOutputStream.java:222) at com.github.luben.zstd.ZstdOutputStreamNoFinalizer.close(ZstdOutputStreamNoFinalizer.java:440) at com.github.luben.zstd.ZstdOutputStreamNoFinalizer.close(ZstdOutputStreamNoFinalizer.java:405) - locked <0x00000000ffddc160> (a com.github.luben.zstd.ZstdOutputStreamNoFinalizer) at sun.nio.cs.StreamEncoder.implClose([email protected]/StreamEncoder.java:435) at sun.nio.cs.StreamEncoder.lockedClose([email protected]/StreamEncoder.java:237) at sun.nio.cs.StreamEncoder.close([email protected]/StreamEncoder.java:222) at java.io.OutputStreamWriter.close([email protected]/OutputStreamWriter.java:266) at java.io.BufferedWriter.implClose([email protected]/BufferedWriter.java:398) at java.io.BufferedWriter.close([email protected]/BufferedWriter.java:386) - locked <0x00000000ffddc148> (a java.io.OutputStreamWriter) at com.company.WriterBaseWrapper.close(WriterBaseWrapper.java:110) at com.company.CustomLog4j2Appender.close(CustomLog4j2Appender.java:74) at com.company.CustomLog4j2Appender.lambda$new$0(CustomLog4j2Appender.java:45) at com.company.CustomLog4j2Appender$$Lambda/0x000070e66c38dfa0.run(Unknown Source) at java.lang.Thread.runWith([email protected]/Thread.java:1596) at java.lang.Thread.run([email protected]/Thread.java:1583) Locked ownable synchronizers: - <0x00000000834100e0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) Details:There is CustomLog4j2Appender.java which is a custom log4j2 appender. It extends AbstractAppender. It has a shutdown hook:
this.shutdownHook = new Thread(() -> { this.close(); }); Runtime.getRuntime().addShutdownHook(this.shutdownHook);The close() will further close all the underlying streams so that a file gets written to S3.
But as seen in stacktrace, AWS library code to upload file to S3 is waiting on <0x00000000ff714278> (a java.util.concurrent.CompletableFuture$Signaller) .
There are no other results for 0x00000000ff714278 in the entire thread-dump. Same for condition [0x000070e603c05000].
How to troubleshoot this further?
What is the issue?
What is the solution so that the calls get completed and the file gets written to S3?
With some attempt to find answer, I got information that - perhaps shutdown hook gets completed even before async operations get completed in other threads. So I added 5 seconds delay in shutdown hook after close() call.
this.shutdownHook = new Thread(() -> { shuttingDown = true; this.close(); try { // Let async operations complete in aws sdk library Thread.sleep(5000); } catch (InterruptedException e) { // ignore } }); Runtime.getRuntime().addShutdownHook(this.shutdownHook);Still it didn't work. Same issue happens.
