Hi all, I've noticed that the response times for our python server endpoints using supertokens sessions were longer than expected. So I timed each part of our verify middleware and saw that

verify_session()

was taking around 200~300ms, taking up a majority of the response time. Is this normal? How long is

verify_session()

usually expected to take? I would like to know if there are ways to get this time way down. Here's the snippet:

start = time.time() * 1000
session_recipe = SessionRecipe.get_instance()
supertokens_session = await session_recipe.verify_session(
    request=base_req,
    anti_csrf_check=True,
    session_required=True,
    check_database=False,
    override_global_claim_validators=None,
    user_context=None,
)
end = time.time() * 1000

hey @leejinoodle this is unusual. SInce you have set check_database=False, it should be statelss and just 1-2 MS based on how much time it takes to veirfy the JWT signature. Are you self hosting the core?

Yes, that was my expectation so this was troubling me. And yes, I'm self-hosting the core. Would that make a difference?

it shouldn't, but you can check whats happening. Keep the logs of the core open in tail mode, and then call the API which calls

verify_session

. Do you see any calls to the core during that time?

In fact yes, it seems like

/recipe/user

endpoints are being called a bunch of times.

2023-08-09 14:23:52 09 Aug 2023 05:23:52:562 +0000 | INFO | pid: e88968e3-0228-44b4-97f3-77daf4bc8f1b | [http-nio-0.0.0.0-3567-exec-6] thread | io.supertokens.webserver.WebserverAPI.service(WebserverAPI.java:196) | API ended: /recipe/user. Method: GET
2023-08-09 14:23:52 
2023-08-09 14:23:52 09 Aug 2023 05:23:52:578 +0000 | INFO | pid: e88968e3-0228-44b4-97f3-77daf4bc8f1b | [http-nio-0.0.0.0-3567-exec-7] thread | io.supertokens.webserver.WebserverAPI.service(WebserverAPI.java:166) | API called: /recipe/user. Method: GET. Version: 2.21
2023-08-09 14:23:52 09 Aug 2023 05:23:52:640 +0000 | INFO | pid: e88968e3-0228-44b4-97f3-77daf4bc8f1b | [http-nio-0.0.0.0-3567-exec-2] thread | io.supertokens.webserver.WebserverAPI.service(WebserverAPI.java:196) | API ended: /recipe/session/regenerate. Method: POST

can you enable backend (python sdk) debug logs and show the output please?

Sure, thanks for the help. Here's the log:

seems like it's querying the core to check if the email verification is done or not.

Looking at the DB, the user is recorded in the

emailverification_verified_emails

table. However, the user was a local test user authenticated through the passwordless recipe, and I had

emailverification.init(mode="REQUIRED")

in init. Setting it to

emailverification.init(mode="OPTIONAL")

allowed me to bypass the email verification step.

Passwordless recipe should mark the email as verified

Yep, this is the access token:

eyJraWQiOiJkLTE2OTE1NDQ4MjcwMjQiLCJ0eXAiOiJKV1QiLCJ2ZXJzaW9uIjoiMyIsImFsZyI6IlJTMjU2In0.eyJzdWIiOiI3ZjliMjliNy01ODFjLTQxNjItYmE4OS00OTQ4NjFhOTVmYjYiLCJleHAiOjE3Mjc1NDQ4MjYsImlhdCI6MTY5MTU0NDgyNiwic2Vzc2lvbkhhbmRsZSI6ImZkMzgxNGZjLTMxNjItNGJjYS1iNjY4LWY4YjJkODI1NGM3YyIsInJlZnJlc2hUb2tlbkhhc2gxIjoiMzVjNDg0YzllYjZiNTZlZGJkNmRkY2YzOTM2ZjZkOGQwMzllNmY5N2I4ZDhmZjJlMjY2YTQ1ZTZiNGI3YmMwOCIsInBhcmVudFJlZnJlc2hUb2tlbkhhc2gxIjpudWxsLCJhbnRpQ3NyZlRva2VuIjpudWxsLCJpc3MiOiJodHRwOi8vbG9jYWxob3N0Ojg0MDAvYXV0aCIsInN0LWV2Ijp7InYiOnRydWUsInQiOjE2OTE1NDQ4MjY4Mzh9fQ.X-zWOSe4UsyFhz49i_y-C3ZvZtQg0jTW7NVNEg2LNrnw23srde7tbi6WaJ9166Yw8d3bZDRXUxxX2XfalG9RqG5LAWp1xqAYkUD-1DpZy6IO98x6wsVlPUR4oSu5ccrYsgIbgP24_VnvrlipHRFs4Dg3zU76W5YWrtC8CbuyQkRg7lcBlQuHalJzbDEq_lKSKaae3IQ083rFK-mHeiUR9rH2FqerwmskOeQUG2gcbbgmEOgFXTUHq2siFITVufVBNXnG3nvCUshXkDSlNx-3WrZX1z8k0dE2Tgit7KzoJmj9RP6kB1RMqpYY-L9SaEJsEwi-eNbGUGnGPmSn6bmsDA

right, so it has email verified as true (as expected)

I see, I'll post an issue there! On another note though, for actual users authenticated through thirdparty email, I'm seeing

verify_session()

time of around 40~50ms. It's better, but I guess still not optimal. Maybe this is another bug?

i don't think so that this is a bug. We will have to investigate this though. tagging @KShivendu here for help.

No, the token is issued and verified by the same server. I can confirm that the python server and supertokens core both have the correct system time.

hmm. Ok. Let us try and replicate this issue. If we can't replicate it, we will reach out to you here, and in the GH issue you make.

Sure, thanks a ton. I'll follow up with the issue.

one more thing, if you make email verification in required mode again, the verify_session call post third party login takes 200 MS again right (as opposed to 50MS)?

Well I think they were different issues, as the email verify is not run for the thirdparty authenticated users either way. But yes, I just switched on required mode for email verification and can see that

verify_session()

is taking >200ms.

email verification is run for third party users as well, the checks happen for all users. Which is also why it's query the core (unexpectedly).

aha I see. Let me know if you need any more info on this 🙂

yup. Thanks!

Working in <10ms after first hit. And it's not rechecking email verification.

@KShivendu do you have email verification in required mode?

yup.

ok. @leejinoodle can you try and replicate this issue with one of our example apps? You can get them using

npx create-supertokens-app@latest

.