https://supertokens.com/ logo
Join Discord
Powered by
SuperTokens hanging express routes (supertokens-no...
# support-questions-legacy
p
SuperTokens hanging express routes (supertokens-node)
We have a transient issue appearing on our production server. All of our supertokens protected routes fail (timeout) after a while. They work fine initially, but after a series of login/logout the service eventually renders all protected routes non responsive. We can reproduce it fairly reliably.
r
Hey @pandapending
Is the timeout coming from querying the core?
p
Here is our 
index.ts
Copy code
const app = express();

  app.use(cors({
    origin: [websiteDomain, 'https://studio.apollographql.com'],
    allowedHeaders: ['content-type', ...SuperTokens.getAllCORSHeaders()],
    methods: ["GET", "PUT", "POST", "DELETE"],
    credentials: true,
  }));

  app.use(middleware());

 app.use(GraphQLEndPointsPath, verifySession({ sessionRequired: isProduction }));

  await apolloServer.start();

  apolloServer.applyMiddleware({
    app,
    path: GraphQLEndPointsPath,
    cors: false,
  });

  app.get('/', verifySession({ sessionRequired: false }), (_req, res) => {
    res.json({ message: "API Server" });
  });
r
When the protected routes start to fail, do api calls like sign out / sign in also not work anymore?
p
when the aforementioned issue arises, all graphql endpoints hang (as does 
/auth/signin
) while 
GET /
succeeds
yes
i did a diff of the http traces (outbound) on the server
it seems upon failure, there is a missing call to the handshake endpoint
restarting the server clears the error, and things work again for a little while
r
The handshake call just happens once per server start anyway
When things start to hang, you said the GET APIs continue to work?
Those GET APIs are also protected using verifySession?
p
yes. the GET to '/' where verifySession sessionrequired: false still works
r
Hmmm. Does session refreshing work?
Login, delete the sAccessToken from the cookie store, and call an api that uses verifySession
Does it refresh?
p
to be clear, when this thing happens, i can't login
so even in an anonymous browser window it fails signin
r
Hmmmm
This is really strange
After how much time do things stop working?
p
it's not time dependent as far as we can tell
r
And when u say restart, do you mean restart the node server or the supertokens core?
p
it's after logging in, performing a bunch of verifySessions, logging out, logging in, and verifying Sessions a few more times
at some point it will hang
we're using the managed supertokens
r
Right.
APIs that don’t use verifySession continue to work?
p
yes
r
Can you enable backend debug logs and show me the output when things hang?
p
i can. one sec
failed is the failed request to 
POST /graphql
success is immediately after a restart, the same request. (the handshake appears as it was after the restart, as I understand it)
r
Hmmm
Seems like some networking issue on your server.
How r u running your node app?
p
what makes you think that?
it's running in a docker container on ecs
with an alb in front of it
r
Cause it’s querying the core, but there are no errors from it. So either the request is not reaching the core or the response is not being read
Which node version are you using?
p
18.12
shouldn't the timeout of a request or response to core itself cause an exception?
r
It should.
Does ur dev env have any such issue?
p
when using default express logging, we can see the client request come in
and see it timeout
when we switched to winston middleware for logging
we don't even see the request come in
the application of middleware is first supertokens, then winston
so i don't think supertokens is handing off the failed request
r
It does. Cause other types of failed requests like when the core is not running, get propitiated as expected
When u query one of your APIs, the middleware doesn’t do anything. It shouldn’t be querying the core at all in that case
So in those cases, does the request get through winston?
p
the verifysession is done locally?
without outbound network requests?
r
Yes. Most of the time
Unless it doesn’t have the public keys from the handshake info
p
so in the 
failed.log
r
But the handshake happens right on server start and then the keys are stored in memory
p
that i attached, that was a failed request
in which winston did not log the client request
but supertokens did perform outbound network requests to core
r
So that would happen if you call one of supertokens APIs from the frontend.
Or rather it should happen like that
p
you can see in the success.log that it also queried core, but then logged the client request to /graphql
on line 
2568
of success
we're using the supertokens react library on the frontend
r
Can you please enable our backend SDK debug logs and show the output when this happens?
p
got it.
i will do that. might take a while to reproduce and capture logs. thanks for being so helpful already
r
Sure. I’m also happy to jump on a call sometime later today. Might be quicker
p
thanks ! let me grab these logs first.
Copy code
HTTP 8: SERVER new http connection
HTTP 8: outgoing message end.
HTTP 8: SERVER socketOnParserExecute 707
2022-12-16T04:12:04.121Z com.supertokens {t: "2022-12-16T04:12:04.121Z", message: "middleware: Started", file: "/usr/src/app/node_modules/supertokens-node/lib/build/supertokens.js:225:26" sdkVer: "12.1.3"}
2022-12-16T04:12:04.122Z com.supertokens {t: "2022-12-16T04:12:04.122Z", message: "middleware: requestRID is: thirdpartyemailpassword", file: "/usr/src/app/node_modules/supertokens-node/lib/build/supertokens.js:239:26" sdkVer: "12.1.3"}
2022-12-16T04:12:04.122Z com.supertokens {t: "2022-12-16T04:12:04.122Z", message: "middleware: Checking recipe ID for match: thirdpartyemailpassword", file: "/usr/src/app/node_modules/supertokens-node/lib/build/supertokens.js:248:34" sdkVer: "12.1.3"}
2022-12-16T04:12:04.122Z com.supertokens {t: "2022-12-16T04:12:04.122Z", message: "middleware: Matched with recipe ID: thirdpartyemailpassword", file: "/usr/src/app/node_modules/supertokens-node/lib/build/supertokens.js:261:30" sdkVer: "12.1.3"}




2022-12-16T04:12:04.122Z com.supertokens {t: "2022-12-16T04:12:04.122Z", message: "middleware: Request being handled by recipe. ID is: /signin", file: "/usr/src/app/node_modules/supertokens-node/lib/build/supertokens.js:273:30" sdkVer: "12.1.3"}

HTTP 8: SERVER socketOnParserExecute 944
that's the hanging occurring on signin
followed by a 
HTTP 8: server socket close
once the gateway timesout and returns a 504 to the client
no outbound http requests are being logged here either
r
hmm
can you please DM me your email ID that you used to sign up on our site?
I assume that you are not facing this issue when connecting to the dev instance?
p
i am not
r
And that too is using the same nodejs version?
p
yes
r
Ok. Let us investigate this issue on our end
p
appreciate it
r
Would it be possible for you to connect to the dev core in prod and see if this issue happens?
This way, we would know that it’s the prod core that’s causing the issue
p
ok i will give that a shot and get back to you
r
Ok thanks
p
this doesn't seem to be a problem with core right, if no outbound http request is coming from /auth/signin
then it's supertokens-node that isn't even querying core
r
Yea well. That would make sense, but the SDK is definitely querying. For example, your dev env doesn’t face this issue
p
prod does too,
until it doesn't
r
Yea. But you can’t replicate this in dev env.
And no other user of ours has had this issue
Therefore, it’s either the prod core, or your prod setup in the ec2 instance
Sometimes aws ec2 instances behave weirdly.
p
ok. let me swap out prod for dev
i'll keep you posted
r
Sure
p
seems i wasn't trying hard enough
managed to cause the dev instance to exhibit the same behavior
it took a lot more login/logouts for some reason
r
Right. I see.
And is this on a different ec2 instance or the same one?
p
different
completely different vpc in fact
still dockerized instance
in ecs
with an alb in front of it
r
Hmm
Can we get on a call sometime today?
How about in 2 hours from now?
p
sounds good
you can send an invite to my email
r
Sure.
p
thanks
talk soon
r
invite sent
hey @pandapending i am online now
p
we're able to actually reproduce it locally on node 16.4.2 using the self hosted core (docker)
it just takes a lot more logins/logouts
r
Hmmm. Interesting
p
we'll keep digging
r
Would be useful to get the console log info that we discussed
3 Views
PreviousNext
Powered by