Clojurians Log v2

repro is very simple, make any call w/ and w/o snapstart enabled

what are the “log” it refers to? I don’t see any extra log details

I’m digging through the lib source now to try and figure it out. must be some kind of state that is captured by the snapshot

Can you share the actual error?

Can you share how you do a call to AWS? Do you maybe initialize cognitect AWS lib in def (static initializer)?

2022-12-14T08:36:53.060+11:00 START RequestId: ce6a4dab-b20b-4466-b406-0b99010b1789 Version: 31 2022-12-14T08:36:53.102+11:00 {:cognitect.anomalies/category :cognitect.anomalies/fault, :cognitect.anomalies/message “Unable to fetch credentials. See log for more details.“} 2022-12-14T08:36:53.103+11:00 END RequestId: ce6a4dab-b20b-4466-b406-0b99010b1789 2022-12-14T08:36:53.103+11:00 REPORT RequestId: ce6a4dab-b20b-4466-b406-0b99010b1789 Duration

that is a warm start but the same error happens on cold start with snapshot restore

I have no static init code. client is created new for every call

no custom stuff so http client will be the default shared client

I suspect the credentials provider caching mechanism

Looking into which creds provider is used in the lambda env and then passing an instance expliciltely at runtime instead of relying on the cache i.e. try to disable the cache

is that a good direction I wonder?

here’s the fn that breaks….

(defn send-message!
  [{:keys [domain-name stage message connection-id]}]
  (let [client (-> {:api               :apigatewaymanagementapi
                    :endpoint-override {:hostname domain-name
                                        :path     (format "/%s/@connections/" stage)}}
                   (aws/client))]
    ;(aws/validate-requests client)
    (->> {:op      :PostToConnection
          :request {:ConnectionId connection-id
                    :Data         (.getBytes message)}}
         (aws/invoke client))))

haven’t tried other apis (yet) but can if it helps

using latest aws-api release

fwiw the value of snapstart is big in this env. without it a cold start is 5+ secs. with it enabled the restore is an extra 300ms

obvs I’m using them for websockets and the cold start is not noticeable for a WSS connection or messages either way using snapstart. such a nice new feature

worst case I can workaround this using java sdk and interop but I prefer the clj api. “this is the way”

Then I don’t have a clue what potentially could go wrong here. Snapstart is a new beast for me.

Thanks for pointing it out. I'd included the fix to the parsing bug you pointed out, but not the new header. I'll get that taken care of today.

Released in https://github.com/cognitect-labs/aws-api/blob/main/CHANGES.md#08641--2023-01-17

Sorry about the confusion. I'd noted errantly in https://github.com/cognitect-labs/aws-api/issues/225#issuecomment-1366817773 that it was part of the 635 release, but I think that, in haste, I confused that issue with the URI parsing bug, for which there was no github issue.

Sorry, I don't. Please submit an issue to https://github.com/cognitect-labs/aws-api/issues and we'll add it to our backlog to investigate what we can do within the library. Judging from that aws-sdk-java-v2 issue, it seems like there's no way to get the first call as fast as subsequent calls, but maybe we can get closer.

ok, thanks. I’ve got a few things to try first but I’ll log the issue for the http-client if I strike out on them all

strictly speaking the issue would be on the http-client. does it have it’s own repo? I can’t find it

Sorry. I missed the part where you used a non-shared provider for the pings. That seems like a reasonable approach, and definitely preferable over offering a non-caching version.

Dynamodb added to my snapstart lambdas. working well. the only feature I’m missing is x-ray. Not currently supported by snapstart

@dchelimsky I’ve noticed that first aws api calls are always slow. seems to be due to https handshake according to this https://github.com/aws/aws-sdk-java-v2/issues/1340. Any tips on optimising the http(s) client used by clj aws lib?

For anybody following along, I've got a fix on the dc/container-credentials-auth-header branch of https://github.com/cognitect-labs/aws-api/. Not releasing yet, but @steveb8n says https://github.com/cognitect-labs/aws-api/issues/225#issuecomment-1353787712 and I welcome feedback from anybody who wants to build it locally from that branch and give it a try.

I can confirm it’s working for my WSS use-case. haven’t tested any other apis yet but will be adding Dynamodb, S3 and Lambda in the coming days so will report any issues here

The repo isn't public, but you can access the source directly from the jar.

Yeah it's bleeding edge but I think it's worth a few growing pains. I'll stick with it

aws-api uses https://github.com/clojure/tools.logging#configuration, so the log will be wherever you configure it to be.

From https://docs.aws.amazon.com/lambda/latest/dg/snapstart.html > Some functions download or initialize ephemeral data, such as temporary credentials or cached timestamps, during the initialization phase. Refresh ephemeral data in the function handler before using it, even when not using SnapStart.

So my guess is we need a way to force a reload of credentials.

Just as a test, try building the client with something like:

(require '[cognitect.aws.credentials :as credentials]
         '[cognitect.aws.client.api :as api]
         '[cognitect.aws.client.shared :as shared])

(defn send-message!
  [{:keys [domain-name stage message connection-id]}]
  (let [client (-> {:api               :apigatewaymanagementapi
                    :endpoint-override {:hostname domain-name
                                        :path     (format "/%s/@connections/" stage)}
                    :credentials-provider (credentials/default-credentials-provider (shared/http-client))}
                   
                   (aws/client))]
    ;(aws/validate-requests client)
    (->> {:op      :PostToConnection
          :request {:ConnectionId connection-id
                    :Data         (.getBytes message)}}
         (aws/invoke client))))

@dchelimsky thanks. I just tried your suggestion but no change to the behaviour i.e. same error

I’ll try turning up logging to get more info for us to diagnose

ok. figured out how to get logging working. here’s the results

; fail w/ snapstart
;2022-12-15T08:40:36.647+11:00 2022-12-14 21:40:36,629 DEBUG cognitect.aws.credentials Unable to fetch credentials from environment variables.
;2022-12-15T08:40:36.648+11:00 2022-12-14 21:40:36,647 DEBUG cognitect.aws.credentials Unable to fetch credentials from system properties.
;2022-12-15T08:40:37.666+11:00 {:cognitect.anomalies/category :cognitect.anomalies/fault, :cognitect.anomalies/message "Unable to fetch credentials. See log for more details."}

; success w/o snapstart
; 2022-12-15T09:05:58.196+11:00  2022-12-14 22:05:58,173 DEBUG cognitect.aws.credentials Fetched credentials from environment variables.

so the env variables creds provider is the one we need to de-cache when running snapstart

@dchelimsky this is with the :credentials-provider loaded the way you suggest above

I’ll try a reified creds provider using env without the cache

interesting. with this creds provider…

(defn send-message!
  [{:keys [domain-name stage message connection-id]}]
  (let [client (-> {:api                  :apigatewaymanagementapi
                    :endpoint-override    {:hostname domain-name
                                           :path     (format "/%s/@connections/" stage)}
                    :credentials-provider (reify CredentialsProvider
                                            (fetch [_]
                                              {:aws/access-key-id     (u/getenv "AWS_ACCESS_KEY_ID")
                                               :aws/secret-access-key (u/getenv "AWS_SECRET_ACCESS_KEY")
                                               :aws/session-token     (u/getenv "AWS_SESSION_TOKEN")}))}
                   (aws/client))]
    ;(aws/validate-requests client)
    (->> {:op      :PostToConnection
          :request {:ConnectionId connection-id
                    :Data         (.getBytes message)}}
         (aws/invoke client))))

I get 2022-12-15T09:28:53.467+11:00{:message “The security token included in the request is invalid.“, :cognitect.anomalies/category :cognitect.anomalies/forbidden}

maybe snapstart affects the env vars. I’ll dig deeper

That's what I was expecting.

Based on their docs.

snapstart docs?

Yes. What I posted/linked above: https://docs.aws.amazon.com/lambda/latest/dg/snapstart.html

They don't specify env vars, but it makes sense that they'd have been cached.

you mean the “Temporary data” section I guess

Right

I can dump the env to get the next level of info

Sure, but give me just a sec ....

odd that snapstart would affect env. that would break all IAM access

ok, holding…

no hurry 😉 it’s the start of my day so I’ve got time

End of mine 🙂

I’m aware. I don’t mind if you need to stop. I can disable snapstart to wait for new advice

near the end of mine!

I was only commenting, not complaining 😉

I've got time - hang tight

roger that

This may be something we need to address in aws-api. According to https://docs.aws.amazon.com/lambda/latest/dg/snapstart-activate.html: > When SnapStart is activated, the Java runtime automatically uses the container credentials (`AWS_CONTAINER_CREDENTIALS_FULL_URI` and AWS_CONTAINER_AUTHORIZATION_TOKEN) instead of the access key environment variables. This prevents credentials from expiring before the function is restored. aws-api does check AWS_CONTAINER_CREDENTIALS_FULL_URI , but not AWS_CONTAINER_AUTHORIZATION_TOKEN . Would you kindly file an issue (I'd do it, but if you do it then you can provide more context and follow it) just saying that aws-api can't find valid creds in a lambda with snapstart? We'll look into it soon.

no problem. I’ll create issue now

Thanks

likewise

good that we know where to focus now

if you need a quick test/repro, my CI pipeline can deploy in a few mins but probably faster to deploy your own

out of interest, is it plausible to create a different style of :cred-provider that uses these alternative env values?

In the mean time, one thing you might try is fetching AWS_ACCESS_KEY_ID , AWS_SECRET_ACCESS_KEY , and AWS_CONTAINER_AUTHORIZATION_TOKEN directly from the env and then make a home grown reification of CredentialsProvider, e.g.

(reify CredentialsProvider
    (fetch [_]
      {:aws/access-key-id     (System/getenv "AWS_ACCESS_KEY_ID")
       :aws/secret-access-key (System/getenv "AWS_SECRET_ACCESS_KEY")
       :aws/session-token     (System/getenv "AWS_CONTAINER_AUTHORIZATION_TOKEN"}))

I'm assuming the problem is the expired session token bound to AWS_SESSION_TOKEN

Might be wrong 🙂

cool. my thought exactly

I'm not set up right now to do these same experiments, or I'd do them myself!

I’ve had some experience with :cred-providers in bb tasks, using STS assume role and reify’ing

so I’m not a total noob

no probs, give me a few mins and I’ll test this idea

Thanks. I'll be ending my day soon, but I'll be curious to know how it works out.

CI running now. takes a couple of mins to build snapshot

no joy with that change…

{:message “The security token included in the request is invalid.“, :cognitect.anomalies/category :cognitect.anomalies/forbidden}

env keys are….

(AWS_CONTAINER_AUTHORIZATION_TOKEN AWS_CONTAINER_CREDENTIALS_FULL_URI AWS_DEFAULT_REGION AWS_EXECUTION_ENV AWS_LAMBDA_FUNCTION_MEMORY_SIZE AWS_LAMBDA_FUNCTION_NAME AWS_LAMBDA_FUNCTION_VERSION AWS_LAMBDA_INITIALIZATION_TYPE AWS_LAMBDA_LOG_GROUP_NAME AWS_LAMBDA_LOG_STREAM_NAME AWS_LAMBDA_RUNTIME_API AWS_REGION AWS_XRAY_CONTEXT_MISSING AWS_XRAY_DAEMON_ADDRESS LAMBDA_RUNTIME_DIR LAMBDA_TASK_ROOT LANG LD_LIBRARY_PATH NEXTDOC_STAGE PATH REGION TZ AWSXRAY_DAEMON_ADDRESS AWSXRAY_DAEMON_PORT HANDLER X_AMZN_TRACE_ID)

based on this https://docs.aws.amazon.com/sdkref/latest/guide/feature-container-credentials.html it looks like I could make a request for creds using those 2 values

I’ll log a case first and will play with that idea a bit

if it gets too messy, I’ll disable snapstart and workaround

https://github.com/cognitect-labs/aws-api/issues/225

I’ll try porting from https://github.com/aws/aws-sdk-java/blob/master/aws-java-sdk-core/src/main/java/com/amazonaws/auth/ContainerCredentialsProvider.java

In that case, maybe we can avoid the env var credential provider (which succeeds at getting stale creds) with this:

:credentials-provider (credentials/container-credentials-provider)

ok, I’ll try that now

{:cognitect.anomalies/category :cognitect.anomalies/fault, :cognitect.anomalies/message “Unable to fetch credentials. See log for more details.“}

no extra logging. here’s my log config

status = info
monitorInterval = 5

appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %date %level %logger %message%n%throwable

rootLogger.level = info
rootLogger.appenderRef.stdout.ref = STDOUT

logger.cogaws.name = cognitect.aws.credentials
logger.cogaws.level = debug

checking what other ns I need to log

adding explicit call to (println (pr-str (ec2/container-credentials (shared/http-client)))) to see the error

might be an IAM perm missing. I have them minimal

I need to stop now too. customer call

will keep digging into why the container creds request is failing and will update the issue

or send hi fives

have a nice evening and thanks for the pointers

@dchelimsky found a bug while testing

(.getScheme (URI. ""))

but the cognitect.aws.ec2-metadata-utils/request-map fn tests for :https i.e. keyword, not string

I’ve updated the bug with results from testing the underlying creds request. I’ll hold for the day and wait for your response. am I right about the ec2 vs snapstart conclusion?

I fixed the URI parsing bug in https://github.com/cognitect-labs/aws-api/commit/04c891dd4903fb1381b470fd6fe4524a8ffc9219. Not yet released - will wait to see if we need anything else to resolve the snapstart issue.

boom. got it working. deets in the issue

the 404 was a bad error code. when I added the token header it started returning 200. got pointed in right direction by looking and the java SDK provider

first request is a bit slow so I suspect you will be able to create a better impl than mine but at least we know it can/does work

very happy with this result. snapstart is a big step up. I can imagine the Datomic team switching back to this from cljs as well

@dchelimsky I’m broken with your latest release. I can’t find “AWS_CONTAINER_AUTHORIZATION_TOKEN” anywhere in the source. I also can’t find the commit where you added this so maybe you squashed and/or missed that commit when building the latest release?

It’s entirely possible I’m missing something but maybe you can point me in the right direction if so?

Ah, found the commit on the branch here https://github.com/cognitect-labs/aws-api/commit/5350994c6b8ac260fca4fa398dfcf495423c7a37

but it is not in the master branch/release

Which best practice doc?

According to https://docs.aws.amazon.com/lambda/latest/dg/snapstart-uniqueness.html, new execution envs get spawned from the original snapshot, so I'm not clear on the problem. Can you elaborate on "the captured token breaking after 24 hours would suggest that it’s not being flushed"?

detailed info in the adr attached to the issue https://github.com/cognitect-labs/aws-api/files/10300677/adr-0002-cold-starts.md

specifically this https://docs.aws.amazon.com/lambda/latest/dg/snapstart-best-practices.html

I noticed slow first api requests so I tried making api calls as part of namespace loading i.e. static. that made a huge difference to the first api call duration but 1 day later it started failing i.e. token capture without TTL refreshing it

eventually you will want to setup a lambda with snapstart as part of your CI for this lib. happy to help when you do

@steveb8n we released a new version w/ the snapstart compatibility fix: https://clojurians.slack.com/archives/C06MAR553/p1672249179394479. Thanks for your help in finding the problem and testing the solution!

@dchelimsky is the token TTL problem something we can ignore because lambdas don’t live long enough for the token to expire?

Haven't thought about it yet, but can't lambdas live for a long time if they're busy?

They can live for a long time when busy AFAIK.

yeah, that’s my concern. it’s easy enough to avoid capturing the token in snapstart init but the token could expire if the lambda is kept alive long enough

if the TTL/refresh for ec2 container tokens is not working then this could happen. I’m not sure if it’s broken but the captured token breaking after 24 hours would suggest that it’s not being flushed

unless the lambda env refreshes the token for each invocation, the the clj lib wouldn’t need to care about TTL. but in that case the captured token from snapstart wouldn’t have broken either

looking at the calculate-ttl fn, I think we’re ok. here’s my thought process…

snapstart captured the creds atom which includes the already calculated TTL

on cold start, 24 hours later, the token is expired but the TTL says it’s not. hence the problem

if the cache is not populated during the static init of the lambda (i.e. not captured) then the creds will be loaded/cached normally on first use by the default provider chain

in that case, the freshly calculated TTL will either be 5 mins (default) or the parsed value from the creds. in either case, a freshly calculated TTL will expire before the token expires

it means there’s a foot-gun when using snapstart. if you follow the best practice doc and statically load the aws api classes, you must avoid the default creds chain.

this probably warrants a docs update for the lib right?

The solution (in the ADR) combines api calls with static class loading, but the api calls result in stored state, which explicitly contradicts the https://docs.aws.amazon.com/lambda/latest/dg/snapstart-uniqueness.html. I'm not sure what to do about it, but we need to explore other options.

state is stored due to the cache behaviour of the default chain provider. avoiding the default chain for the static load addresses this. why is that not a good solution?

I suppose you could add a feature to disable caching but avoiding the default chain is a much simpler solution imho

if it is a satisfactory solution then it’s only a warning in the docs required