pyfa-org / Pyfa

Python fitting assistant, cross-platform fitting tool for EVE Online
GNU General Public License v3.0
1.6k stars 406 forks source link

ERROR: The JWT token has expired: Signature has expired. FIX #2402

Closed videxerion closed 2 years ago

videxerion commented 2 years ago

Bug Report

Expected behavior:

Login to ESI.

Actual behavior:

JWT token error, The JWT token has expired: Signature has expired

Detailed steps to reproduce:

1) Open 'PYFA' 2) Open 'Character' 3) Open 'Manage ESI Characters' 4) Click 'Add Character' 5) Enter ESI and get base64 string (Manual method) 6) Get local server startup error

Release or development git branch? Please note the release version or commit hash:

The version was obtained via 'git clone'.

Operating system and version (eg: Windows 10, OS X 10.9, OS X 10.11, Ubuntu 16.10):

5.16.2-arch1-1

Other relevant information:

When checking the token, the program considers it 'obsolete', after googling a little, I found out that the 'exp' parameter in the token itself is responsible for this. The check takes place in the 'esiAccess.py' file, 'services' folder. изображение

After a little searching, I realized that you use the 'python-jose' library to work with jwt tokens, by opening its code and finding the decode method, I found the '_validate_exp' method in which the token is checked for 'validity'.

изображение

As it turned out, the library developers use the current time zone of my computer (+3:00) and the time specified in the JWT token is in the zone (+0:00), which is why the token is immediately considered 'not valid'. изображение

A quick fix error on the user's side can be corrected by changing the clock, in my case it worked. On the part of the developer, you can refuse to check the token or rewrite everything to a new library for working with tokens, which allows you to specify the time zone when checking the 'exp' parameter. 'Python-jose' and 'PyJWT' don't provide this feature as far as I've been able to find.

blitzmann commented 2 years ago

Thanks for going one step further and diving into things, it make it much easier on us.

This is interesting, I would have assumed we would have heard about this long before now, as if it's a timezone issue there's got to be more than 1 person experiencing the issue. I'll try to reproduce this tonight. However, I have a few concerns. python-jose uses datetime.utcnow() which should give you a time that is in UTC (+0) regardless of your local time zone.

eg: I'm in EST (-5). My current local time is 3:35pm (15:35). Running datetime.utcnow() returns 8:35pm (20:34), which is what it currently is in +0. So it should always be returning the UTC time

Are you able to run the following on your computer, just as a sanity check:

from datetime import datetime
print(datetime.utcnow().utctimetuple())
print(datetime.now().timetuple())

This should show both local time and utc time.

I also see a thumbs up for this issue by @MoonOfTheWind, are you exhibiting the same issue?

videxerion commented 2 years ago

For me, it also seemed strange that these methods give out the time of my time zone, as we see on the screen, for some reason these two methods give me the same time. I'll dig into the datetime library and maybe find something. But this is very strange. изображение

blitzmann commented 2 years ago

Very strange, tm_isdst has a different value between the two commands, I wonder if that has anything to do with it.

Heres a couple more commands:

import time
offset = time.timezone if (time.localtime().tm_isdst == 0) else time.altzone
print(offset / 60 / 60 * -1)

Should print out what python interprets as the time zone (perhaps python is seeing a TZ that is different from your system time?)

import time
time.tzname

Should print out, well, tz name.

I hate dealing with time issues :/

videxerion commented 2 years ago

изображение изображение

blitzmann commented 2 years ago

Thanks for taking the time to help debug this, it's very helpful.

So python is showing that your local time is UTC, without any timezone offset.

Can you attempt to login again, and step through the code to print out the following:

exp value on the JWT now variable inside python-jose leeway variable inside python-jose

Basically what are the values associated with your runtime when you exhibit this issue? That would be helpful to have :)

Also, which linux distro are you using? nvm, just noticed you mentioned it as 5.16.2-arch1-1 in the OP. Can you print out your python package versioning information (I think pip freeze might do it but I'm not 100%)

videxerion commented 2 years ago

Sorry for the late reply, been very busy I'm use venv. pip freeze:

The exp parameter is in the token and there is nothing special about it, the screen can be seen a little higher up the branch, I don't think it has any value. I can't print the value directly from the library, but I have no doubt that the code inside the library works exactly the same as from the interpreter. I don’t think that something depends on you here, this is a specific bug that does not occur on all devices that depends on the datetime library, I think that if possible it is worth writing some kind of bug report for the developers responsible for this library, I think if you describe in detail problem, maybe they will come up with something and release a patch. It is also possible that this is the fault of those people who are responsible for the repositories of my distribution. But I'll still be happy to answer some of your questions and provide information that I can.

blitzmann commented 2 years ago

Seems like all the proper packages and versions.

I'm aware you posted a screenshot of the exp, but you never posted what now evaluated to, only that "the library developers use the current time zone of my computer (+3:00)". I have no doubt you checked this value for accuracy, but I would like literal values if possible. I assume you're familiar with the debugger as you've been able to get the JWT and help with troubleshooting; is it possible for you to set a breakpoint and let me know what now and exp are evaluating to? You can put a breakpoint on the jwt.decode() within pyfa's source files, then "step-into" that function to get to the library's code; from there you should be able to step into _validate_exp and then read what is evaluated for exp and now.

It seems that your python is doing something funky with timezones - your computer is supposedly set to +3, however python is showing +0, so I want to know what exactly is happening in this function.

For example, this is what mine looks like (my computer is set to UTC-5):

image

And for reference, human-readable times now: image

exp: image

So, at least for me, it is evaluating correctly; unfortunately it's super hard to give any sort of guidance when I can't reproduce myself.

I can try to get an Arch distro up and running and see if it's possible to reproduce on there. @DarkFenX you're much more experienced when it comes to Linux, you have any knowledge about python running on linux having some timezone issues?

blitzmann commented 2 years ago

Also, as a stop-gap, we might be able to introduce a setting that ignores JWT expiration validation just to get past the hump for now. I will look into that.

videxerion commented 2 years ago

I just edited the library code so that it outputs each time it decodes values ​​that are interesting to you. exp: 1644256349 leeway: 0 I managed to get around the problem by changing my time (+3:00) to the time in the token (+0:00), otherwise I just rolled back the time 3 hours ago. With the token, everything is the same as in this picture. изображение I think that disabling the check would help, but I thought that changing someone else's code with handles is not a good idea.

blitzmann commented 2 years ago

The latest release has an option to disable the expiration check.

I'm still baffled as to what the actual issue is here and why it looks like your particular time zone isn't being respected, but it seems to be a very niche problem local to only a few folks. For now, disable it in the preferences :)

dannyeei commented 1 year ago

This also happened to me. Wouldn't it be better to also have an optional leeway parameter? I imagine everyone will be (or should be) implementing that themselves anyway.

videxerion commented 1 year ago

This behavior is a mistake, so I personally understand why the authors did not take this into account. But what you are asking for has already been implemented, judging by this pull request. https://github.com/pyfa-org/Pyfa/pull/2424 After a long time, I discovered for myself what was the reason for such an error, when installing my Arch, I did not set the time correctly. I do not know how everything else worked, but the fact is that the time was knocked down 3 hours ago, as was said in my report above.

GaelC92 commented 1 year ago

Hello, I ran into such a problem today. In my case, it happened running pytests : I created a jwt with an exp set to utcnow() + timedelta(minutes=15) (and nbf to utcnow())

then I decode without checks to get the contents (for debugging purposes) payload = jwt.decode(token, "", options={'verify_signature': False, 'verify_exp': False, 'verify_aud': False, 'verify_iss': False, 'verify_nbf' : False}) SECURITY.critical(f"exp = {payload.get('exp')}") SECURITY.critical(f'utcnow() = {datetime.utcnow().timestamp()}') SECURITY.critical(f'now(timezone.utc) = {datetime.now(timezone.utc).timestamp()}') and finally : payload = jwt.decode(token, shared_secret)

-------------------------------------------------------------------------------- Captured log call -------------------------------------------------------------------------------- CRITICAL d:security:utils.py:140 exp = 1689333865.198437 CRITICAL d:security:utils.py:141 utcnow() = 1689332965.200101 CRITICAL d:security:utils.py:142 now(timezone.utc) = 1689340165.200138 WARNING d:security:utils.py:158 rejected attempt to connect with client_id xxxx due to Signature has expired.

it is really 15:12 local time, 13:12 UTC :

exp : GMT: Friday 14 July 2023 11:24:25.198 Your time zone: vendredi 14 juillet 2023 13:24:25.198 GMT+02:00 DST Relative: 2 hours ago

utcnow : GMT: Friday 14 July 2023 11:09:25.200 Your time zone: vendredi 14 juillet 2023 13:09:25.200 GMT+02:00 DST Relative: 2 hours ago

now(tz=utc) : GMT: Friday 14 July 2023 13:09:25.200 Your time zone: vendredi 14 juillet 2023 15:09:25.200 GMT+02:00 DST Relative: 4 minutes ago

Second attempt, calling pytest with "TZ=1 pytest" :

it is now really 15:20 (gmt+2), and 13:20 utc.

CRITICAL d:security:utils.py:140 exp = 1689345276.925914 CRITICAL d:security:utils.py:141 utcnow() = 1689344376.927357 CRITICAL d:security:utils.py:142 now(timezone.utc) = 1689340776.927392 WARNING d:security:utils.py:158 rejected attempt to connect with client_id xxxx due to The token is not yet valid (nbf)

exp : GMT: Friday 14 July 2023 14:34:36.925 Your time zone: vendredi 14 juillet 2023 16:34:36.925 GMT+02:00 DST Relative: In an hour

utcnow : GMT: Friday 14 July 2023 14:19:36.927 Your time zone: vendredi 14 juillet 2023 16:19:36.927 GMT+02:00 DST Relative: In an hour

GMT: Friday 14 July 2023 13:19:36.927 Your time zone: vendredi 14 juillet 2023 15:19:36.927 GMT+02:00 DST Relative: 4 minutes ago

So, the bottom line (for now) is that there is a strange behaviour of utcnow() which appears to be dependant on environment variables.

datetime.now(tz=utc), on the other hand appears to work consistently, and as expected.

=> I'll change my code to take this into account.

Maybe this could help someone else.

Edit : well, the warning in the pydoc was a hint... :)

Capture d’écran 2023-07-14 à 15 44 42