zio-aws icon indicating copy to clipboard operation
zio-aws copied to clipboard

Published 20 hours ago • verified publisher icon zio

zio-aws with http4s client never terminates

Open jmcclell opened this issue 3 years ago • 7 comments

Given the following test case code:

import zio._
import zio.console.Console
import io.github.vigoo.zioaws.{iam, core, http4s}
import io.github.vigoo.zioaws.iam.Iam
import io.github.vigoo.zioaws.core.AwsError
import io.github.vigoo.zioaws.iam.model._

object TestCase extends zio.App {
  val httpClient =  http4s.default
  val awsConfig = httpClient >>> core.config.default
  val aws = awsConfig >>> iam.live

  def putStrLn(s: String) = console.putStrLn(s).orDie
  def putStrLnErr(s: String) = console.putStrLnErr(s).orDie

  val program: ZIO[Console with Iam, AwsError, Unit] =
    for {
      count <- iam.listAccessKeys(ListAccessKeysRequest(Some("user1"))).runCount
      _ <- putStrLn(s"count is: $count")
    } yield ()

  override def run(args: List[String]): URIO[ZEnv, ExitCode] =
    program
      .provideCustomLayer(aws)
      .foldM (
        e => putStrLnErr(s"AWS error: $e").as(ExitCode.failure),
        _ => ZIO.unit.as(ExitCode.success)
      )
}

The threads spawned by http4s client never terminate. This works as expected with the netty client.

Build.sbt:

val zioVersion = "1.0.8"
val zioAwsVersion = "3.16.60.2"
val slf4jVersion = "1.7.5"
val http4sVersion = "0.21.23"

lazy val root = project
  .in(file("."))
  .settings(
    fork := true,
    name := "test-case",
    version := "0.1.0",

    scalaVersion := "2.13.6",

    libraryDependencies ++= Seq(
      "dev.zio" %% "zio" % zioVersion,
      "io.github.vigoo" %% "zio-aws-iam" % zioAwsVersion,
      "io.github.vigoo" %% "zio-aws-http4s" % zioAwsVersion,
      "org.slf4j" % "slf4j-api" % slf4jVersion,
      "ch.qos.logback" % "logback-core" % "1.2.3",
      "ch.qos.logback" % "logback-classic" % "1.2.3",
      "org.http4s" %% "http4s-blaze-client" % http4sVersion,

      "dev.zio" %% "zio-test" % zioVersion % "test",
      "dev.zio" %% "zio-test-sbt" % zioVersion % "test",
      "com.novocode" % "junit-interface" % "0.11" % "test",
    ),

    testFrameworks := Seq(
      new TestFramework("zio.test.sbt.ZTestFramework")
    )
  )

I haven't gotten an example to work quite yet, but this is definitely happening when there are no AWS credentials configured and the unhappy path is executed.

Log:

[success] Generated .bloop/test-case-build.json
[success] Total time: 0 s, completed May 25, 2021 1:26:25 AM
[info] loading settings for project root from build.sbt ...
[info] set current project to test-case (in build file:/Users/jmcclell/dev/test-case/)
[info] compiling 1 Scala source to /Users/jmcclell/dev/test-case/target/scala-2.13/classes ...
[info] running (fork) TestCase
[error] 01:26:30.555 TKD [zio-default-async-19] DEBUG s.a.a.r.p.AwsRegionProviderChain - Unable to load region from software.amazon.awssdk.regions.providers.SystemSettingsRegionProvider@4a07dddf:Unable to load region from system settings. Region must be specified either via environment variable (AWS_REGION) or  system property (aws.region).
[error] 01:26:31.027 TKD [zio-default-async-20] DEBUG s.a.a.a.c.AwsCredentialsProviderChain - Unable to load credentials from SystemPropertyCredentialsProvider(): Unable to load credentials from system settings. Access key must be specified either via environment variable (AWS_ACCESS_KEY_ID) or system property (aws.accessKeyId).
[error] software.amazon.awssdk.core.exception.SdkClientException: Unable to load credentials from system settings. Access key must be specified either via environment variable (AWS_ACCESS_KEY_ID) or system property (aws.accessKeyId).
[error]         at software.amazon.awssdk.core.exception.SdkClientException$BuilderImpl.build(SdkClientException.java:98)
[error]         at software.amazon.awssdk.auth.credentials.internal.SystemSettingsCredentialsProvider.resolveCredentials(SystemSettingsCredentialsProvider.java:58)
[error]         at software.amazon.awssdk.auth.credentials.AwsCredentialsProviderChain.resolveCredentials(AwsCredentialsProviderChain.java:91)
[error]         at software.amazon.awssdk.auth.credentials.internal.LazyAwsCredentialsProvider.resolveCredentials(LazyAwsCredentialsProvider.java:45)
[error]         at software.amazon.awssdk.auth.credentials.DefaultCredentialsProvider.resolveCredentials(DefaultCredentialsProvider.java:104)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsClientHandlerUtils.createExecutionContext(AwsClientHandlerUtils.java:79)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.createExecutionContext(AwsAsyncClientHandler.java:65)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.lambda$execute$1(BaseAsyncClientHandler.java:78)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.measureApiCallSuccess(BaseAsyncClientHandler.java:277)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:74)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52)
[error]         at software.amazon.awssdk.services.iam.DefaultIamAsyncClient.listAccessKeys(DefaultIamAsyncClient.java:6632)
[error]         at software.amazon.awssdk.services.iam.paginators.ListAccessKeysPublisher$ListAccessKeysResponseFetcher.nextPage(ListAccessKeysPublisher.java:136)
[error]         at software.amazon.awssdk.services.iam.paginators.ListAccessKeysPublisher$ListAccessKeysResponseFetcher.nextPage(ListAccessKeysPublisher.java:127)
[error]         at software.amazon.awssdk.core.internal.pagination.async.ItemsSubscription.fetchNextPage(ItemsSubscription.java:81)
[error]         at software.amazon.awssdk.core.internal.pagination.async.ItemsSubscription.handleRequests(ItemsSubscription.java:68)
[error]         at software.amazon.awssdk.core.pagination.async.PaginationSubscription.request(PaginationSubscription.java:60)
[error]         at zio.interop.reactivestreams.Adapters$.$anonfun$process$1(Adapters.scala:73)
[error]         at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[error]         at zio.internal.FiberContext.evaluateNow(FiberContext.scala:398)
[error]         at zio.internal.FiberContext.$anonfun$evaluateLater$1(FiberContext.scala:776)
[error]         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[error]         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[error]         at java.lang.Thread.run(Thread.java:748)
[error] 01:26:31.027 TKD [zio-default-async-20] DEBUG s.a.a.a.c.AwsCredentialsProviderChain - Unable to load credentials from EnvironmentVariableCredentialsProvider(): Unable to load credentials from system settings. Access key must be specified either via environment variable (AWS_ACCESS_KEY_ID) or system property (aws.accessKeyId).
[error] software.amazon.awssdk.core.exception.SdkClientException: Unable to load credentials from system settings. Access key must be specified either via environment variable (AWS_ACCESS_KEY_ID) or system property (aws.accessKeyId).
[error]         at software.amazon.awssdk.core.exception.SdkClientException$BuilderImpl.build(SdkClientException.java:98)
[error]         at software.amazon.awssdk.auth.credentials.internal.SystemSettingsCredentialsProvider.resolveCredentials(SystemSettingsCredentialsProvider.java:58)
[error]         at software.amazon.awssdk.auth.credentials.AwsCredentialsProviderChain.resolveCredentials(AwsCredentialsProviderChain.java:91)
[error]         at software.amazon.awssdk.auth.credentials.internal.LazyAwsCredentialsProvider.resolveCredentials(LazyAwsCredentialsProvider.java:45)
[error]         at software.amazon.awssdk.auth.credentials.DefaultCredentialsProvider.resolveCredentials(DefaultCredentialsProvider.java:104)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsClientHandlerUtils.createExecutionContext(AwsClientHandlerUtils.java:79)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.createExecutionContext(AwsAsyncClientHandler.java:65)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.lambda$execute$1(BaseAsyncClientHandler.java:78)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.measureApiCallSuccess(BaseAsyncClientHandler.java:277)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:74)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52)
[error]         at software.amazon.awssdk.services.iam.DefaultIamAsyncClient.listAccessKeys(DefaultIamAsyncClient.java:6632)
[error]         at software.amazon.awssdk.services.iam.paginators.ListAccessKeysPublisher$ListAccessKeysResponseFetcher.nextPage(ListAccessKeysPublisher.java:136)
[error]         at software.amazon.awssdk.services.iam.paginators.ListAccessKeysPublisher$ListAccessKeysResponseFetcher.nextPage(ListAccessKeysPublisher.java:127)
[error]         at software.amazon.awssdk.core.internal.pagination.async.ItemsSubscription.fetchNextPage(ItemsSubscription.java:81)
[error]         at software.amazon.awssdk.core.internal.pagination.async.ItemsSubscription.handleRequests(ItemsSubscription.java:68)
[error]         at software.amazon.awssdk.core.pagination.async.PaginationSubscription.request(PaginationSubscription.java:60)
[error]         at zio.interop.reactivestreams.Adapters$.$anonfun$process$1(Adapters.scala:73)
[error]         at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[error]         at zio.internal.FiberContext.evaluateNow(FiberContext.scala:398)
[error]         at zio.internal.FiberContext.$anonfun$evaluateLater$1(FiberContext.scala:776)
[error]         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[error]         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[error]         at java.lang.Thread.run(Thread.java:748)
[error] 01:26:31.027 TKD [zio-default-async-20] DEBUG s.a.a.a.c.AwsCredentialsProviderChain - Unable to load credentials from WebIdentityTokenCredentialsProvider(): Either the environment variable AWS_WEB_IDENTITY_TOKEN_FILE or the javaproperty aws.webIdentityTokenFile must be set.
[error] java.lang.IllegalStateException: Either the environment variable AWS_WEB_IDENTITY_TOKEN_FILE or the javaproperty aws.webIdentityTokenFile must be set.
[error]         at software.amazon.awssdk.utils.SystemSetting.lambda$getStringValueOrThrow$0(SystemSetting.java:67)
[error]         at java.util.Optional.orElseThrow(Optional.java:290)
[error]         at software.amazon.awssdk.utils.SystemSetting.getStringValueOrThrow(SystemSetting.java:65)
[error]         at software.amazon.awssdk.auth.credentials.WebIdentityTokenFileCredentialsProvider.<init>(WebIdentityTokenFileCredentialsProvider.java:49)
[error]         at software.amazon.awssdk.auth.credentials.WebIdentityTokenFileCredentialsProvider.<init>(WebIdentityTokenFileCredentialsProvider.java:36)
[error]         at software.amazon.awssdk.auth.credentials.WebIdentityTokenFileCredentialsProvider$BuilderImpl.build(WebIdentityTokenFileCredentialsProvider.java:165)
[error]         at software.amazon.awssdk.auth.credentials.WebIdentityTokenFileCredentialsProvider.create(WebIdentityTokenFileCredentialsProvider.java:79)
[error]         at software.amazon.awssdk.auth.credentials.DefaultCredentialsProvider.lambda$createChain$0(DefaultCredentialsProvider.java:75)
[error]         at software.amazon.awssdk.utils.Lazy.getValue(Lazy.java:42)
[error]         at software.amazon.awssdk.auth.credentials.internal.LazyAwsCredentialsProvider.resolveCredentials(LazyAwsCredentialsProvider.java:45)
[error]         at software.amazon.awssdk.auth.credentials.DefaultCredentialsProvider.resolveCredentials(DefaultCredentialsProvider.java:104)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsClientHandlerUtils.createExecutionContext(AwsClientHandlerUtils.java:79)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.createExecutionContext(AwsAsyncClientHandler.java:65)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.lambda$execute$1(BaseAsyncClientHandler.java:78)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.measureApiCallSuccess(BaseAsyncClientHandler.java:277)
[error]         at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:74)
[error]         at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52)
[error]         at software.amazon.awssdk.services.iam.DefaultIamAsyncClient.listAccessKeys(DefaultIamAsyncClient.java:6632)
[error]         at software.amazon.awssdk.services.iam.paginators.ListAccessKeysPublisher$ListAccessKeysResponseFetcher.nextPage(ListAccessKeysPublisher.java:136)
[error]         at software.amazon.awssdk.services.iam.paginators.ListAccessKeysPublisher$ListAccessKeysResponseFetcher.nextPage(ListAccessKeysPublisher.java:127)
[error]         at software.amazon.awssdk.core.internal.pagination.async.ItemsSubscription.fetchNextPage(ItemsSubscription.java:81)
[error]         at software.amazon.awssdk.core.internal.pagination.async.ItemsSubscription.handleRequests(ItemsSubscription.java:68)
[error]         at software.amazon.awssdk.core.pagination.async.PaginationSubscription.request(PaginationSubscription.java:60)
[error]         at zio.interop.reactivestreams.Adapters$.$anonfun$process$1(Adapters.scala:73)
[error]         at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[error]         at zio.internal.FiberContext.evaluateNow(FiberContext.scala:398)
[error]         at zio.internal.FiberContext.$anonfun$evaluateLater$1(FiberContext.scala:776)
[error]         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[error]         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[error]         at java.lang.Thread.run(Thread.java:748)
[error] 01:26:31.028 TKD [zio-default-async-20] DEBUG s.a.a.a.c.AwsCredentialsProviderChain - Loading credentials from ProfileCredentialsProvider(profileName=test-profile, profileFile=ProfileFile(profiles=[Profile(name=default, properties=[cli_pager, region]), Profile(name=redacted, properties=[output, region, aws_access_key_id, aws_session_token, aws_secret_access_key]), Profile(name=redacted, properties=[aws_access_key_id, region, aws_secret_access_key]), Profile(name=redacted, properties=[aws_access_key_id, region, aws_secret_access_key]), Profile(name=redacted, properties=[source_profile, role_arn, region]), Profile(name=redacted, properties=[aws_access_key_id, region, aws_secret_access_key]), Profile(name=redactd, properties=[source_profile, role_arn, region]), Profile(name=redacted, properties=[source_profile, role_arn, region]), Profile(name=redacted, properties=[region, aws_access_key_id, aws_secret_access_key]), Profile(name=redacted properties=[aws_security_token, aws_access_key_id, aws_session_token, aws_secret_access_key]), Profile(name=redacted, properties=[aws_security_token, aws_access_key_id, aws_session_token, aws_secret_access_key])]))
[error] 01:26:31.031 TKD [zio-default-async-20] DEBUG s.a.a.c.i.ExecutionInterceptorChain - Creating an interceptor chain that will apply interceptors in the following order: [software.amazon.awssdk.core.internal.interceptor.HttpChecksumRequiredInterceptor@57294831, software.amazon.awssdk.awscore.interceptor.HelpfulUnknownHostExceptionInterceptor@168da97b, software.amazon.awssdk.awscore.interceptor.GlobalServiceExecutionInterceptor@22a994f3, software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@47d38c16]
[error] 01:26:31.046 TKD [zio-default-async-20] DEBUG s.a.a.c.i.ExecutionInterceptorChain - Interceptor 'software.amazon.awssdk.protocols.query.interceptor.QueryParametersToBodyInterceptor@47d38c16' modified the message with its modifyHttpRequest method.
[error] 01:26:31.059 TKD [zio-default-async-20] DEBUG software.amazon.awssdk.request - Sending Request: DefaultSdkHttpFullRequest(httpMethod=POST, protocol=https, host=iam.us-east-1.amazonaws.com, encodedPath=, headers=[amz-sdk-invocation-id, Content-Length, Content-Type, User-Agent], queryParameters=[])
[error] 01:26:31.071 TKD [zio-default-async-20] DEBUG s.a.awssdk.auth.signer.Aws4Signer - AWS4 String to sign: AWS4-HMAC-SHA256
[error] 20210525T052631Z
[error] 20210525/us-east-1/iam/aws4_request
[error] 0de079c893ed9c7d22264185d18eb7a35633c7d4664964166be2fd4964c041fe
[error] 01:26:31.263 TKD [zio-default-async-23] DEBUG org.http4s.client.PoolManager - Requesting connection for https://iam.us-east-1.amazonaws.com: curAllocated=0 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
[error] 01:26:31.284 TKD [zio-default-async-23] DEBUG org.http4s.client.PoolManager - Active connection not found for https://iam.us-east-1.amazonaws.com. Creating new one. curAllocated=0 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
[error] 01:26:31.342 TKD [zio-default-async-28] DEBUG org.http4s.client.PoolManager - Disposing of connection for https://iam.us-east-1.amazonaws.com: curAllocated=1 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
^C <<<---- Hangs at this point until ctrl+c with http4s *****************************
[warn] Canceling execution...
Cancelled: runMain TestCase
[error] Cancelled: runMain TestCase
[error] Use 'last' for the full log.

I would expect in this error state, the behavior with the http4s client would be the same as with the netty client – the threads should shut down and the program should exit.

jmcclell avatar May 25 '21 05:05 jmcclell

I agree with the expected behavior. Will take a look.

vigoo avatar May 26 '21 07:05 vigoo

I've seen the same behaviour (never terminates) in my integration tests too. But I see this "hanging" problem with http4s 0.21.23 only. If I downgrade to 0.21.22, there is no problem. Since zio-k8s is still using 0.21.22, I thought perhaps zio-k8s needs to use 0.21.23 to work with http4s 0.21.23, hence my PR. I haven't looked beyond that. I can see the scala-steward PR for upgrading http4s also failed. There might be more than just version mismatch.

ithinkicancode avatar May 26 '21 12:05 ithinkicancode

http4s 0.22.24 is out now. Might as well use it as the target version :) I have tested zio-aws with http4s 0.22.24. The same issue persists, unfortunately.

ithinkicancode avatar May 27 '21 00:05 ithinkicancode

@vigoo @jmcclell Apparently a similar issue has been reported here: http4s/blaze#660

You can also find out more details on Typelevel's http4s room on Discord: https://discord.com/channels/632277896739946517/632286375311573032/847885930010640404

ithinkicancode avatar Jun 03 '21 03:06 ithinkicancode

Thanks for the info and sorry for the delay. I will try to look into this soon.

vigoo avatar Jun 03 '21 06:06 vigoo

In the meantime I updated to http4s 0.22. Did not check this issue though yet, but might be fixed.

vigoo avatar Jul 30 '21 19:07 vigoo

This issue still persist with zio-aws 6.20.78.1

VivienBudavolgyi avatar Jun 13 '23 06:06 VivienBudavolgyi