Delay Jobs after getting 403 response codes from ESI

[jediefe]

• Problem: On every ESI update cycle hundreds of jobs fail due to hitting the error limit caused by 403 FORBIDDEN responses when querying structures. This is related to this issue: https://github.com/esi/esi-issues/issues/916
• Expected: Consider the X-Esi-Error-Limit-Remain and X-Esi-Error-Limit-Reset response headers and delay jobs, so the application won't run into error code 420 responses on hitting the limit.
• Logs / Screenshots / Proof: An excerpt from my eseye.log:

  [2019-03-16 20:02:53] eseye.ERROR: [http 403, forbidden] get -> https://esi.evetech.net/v2/universe/structures/1027847407689/?datasource=tranquility [t/e: 0.27s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.21s/]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847401936/?datasource=tranquility [t/e: 0.04s/0]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v3/characters/93777224/assets/?datasource=tranquility&page=2 [t/e: 0.05s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v2/characters/93777224/online/?datasource=tranquility [t/e: 0.42s/1]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847403476/?datasource=tranquility [t/e: 0.04s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.33s/]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v1/characters/93777224/wallet/?datasource=tranquility [t/e: 0.49s/1]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.31s/]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v3/characters/94032522/assets/?datasource=tranquility&page=1 [t/e: 0.18s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.20s/]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/calendar/?datasource=tranquility [t/e: 0.17s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.25s/]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v4/characters/93777224/wallet/journal/?datasource=tranquility&from_id=9223372036854775807&page=1 [t/e: 0.51s/1]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847401518/?datasource=tranquility [t/e: 0.05s/0]
  [2019-03-16 20:02:53] eseye.WARNING: A response contained a warning: 299 - This route is deprecated
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.22s/]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v1/characters/93777224/mail/lists/?datasource=tranquility [t/e: 0.55s/1]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.27s/]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847402233/?datasource=tranquility [t/e: 0.04s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v2/characters/93777224/bookmarks/?datasource=tranquility&page=1 [t/e: 0.53s/1]
  [2019-03-16 20:02:53] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/characters/94032522/blueprints/?datasource=tranquility&page=1 [t/e: 0.18s/0]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.23s/]
  [2019-03-16 20:02:53] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.21s/]
  [2019-03-16 20:02:54] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.17s/]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847409713/?datasource=tranquility [t/e: 0.05s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847403190/?datasource=tranquility [t/e: 0.05s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/characters/94032522/bookmarks/?datasource=tranquility&page=1 [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/agents_research/?datasource=tranquility [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/standings/?datasource=tranquility [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/medals/?datasource=tranquility [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.21s/]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/titles/?datasource=tranquility [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v4/characters/94032522/notifications/?datasource=tranquility [t/e: 0.17s/0]
  [2019-03-16 20:02:54] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.18s/]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/contracts/?datasource=tranquility&page=1 [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/industry/jobs/?datasource=tranquility&include_completed=1 [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/94032522/mining/?datasource=tranquility&page=1 [t/e: 0.18s/0]
  [2019-03-16 20:02:54] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v4/characters/93477753/wallet/journal/?datasource=tranquility&from_id=16513888403&page=6 [t/e: 0.04s/0]

• Version Info:

  | Vendor          | Package Name           | Installed Version |
  | --------------- | ---------------------- | ----------------- |
  | eveseat         | api                    | 3.0.6             |
  | eveseat         | console                | 3.0.3             |
  | eveseat         | eveapi                 | 3.0.10            |
  | eveseat         | notifications          | 3.0.3             |
  | eveseat         | services               | 3.0.5             |
  | eveseat         | web                    | 3.0.15            |
  | herpaderpaldent | seat-groups            | 1.6.9             |
  | warlof          | seat-discord-connector | 3.1.5             |
  | warlof          | seat-teamspeak         | 3.0.11            |

[warlof]

Hi @jediefe,

How many users and workers do you have on your setup?

Such things are normally properly handled by both eseye and job preflight.

[jediefe]

Hi @warlof my instance currently has around 760 users and 40 workers running.

[warlof]

Jesus Christ, can you lower your worker amount as an initial mitigation?

I don't think you need as much for such amount of users, really 😐

[jediefe]

I reduced to 16 and besides the fact that updating characters takes about 10 mins now (~40k jobs) i still receive a similar amount of errors. :man_shrugging:

[herpaderpaldent]

@warlof what would speak against retry=3 && if 420 hitted delay?

[warlof]

I'll build a stats board based on endpoint and remaining hits which will be more accurate.

The problem isn't the retry but the fact we're reaching the limit apparently (which is weird since it's normally supported properly with eseye).

That structure endpoint is really not helping at all to mitigate such issue.

@jediefe what's the last endpoint which return you an error before 420 start except the structure endpoint?

[herpaderpaldent]

We have a saying in german: "Das eine tun und das andere nicht lassen" which translates smth to: "'doing one thing without abandoning the other'" (réaliser l'un et ne pas lâcher l'autre) ... maybe we could think of delaying jobs which are not /universe/structure after a 420?

Yes it is very true and correct that we try to prevent hitting the error limit, but if it happens we could try to do it just a tiny little bit later?

Maybe to think of: 100 errors in 60 seconds. With 16 workers means roughly hitting 6 errors each in 60 seconds. Which could happen with a large set of unresolved structures or a 1-2 sets of missing refresh_tokens (which haven't been invalidated yet).

[jediefe]

Hey guys, just a short notice that I'm busy IRL at the moment and will come back later to you. Thanks for the feedback so far.

[jediefe]

Hey @warlof I've scraped through the last API fetch for this and found v2/universe/structures/<id> throwing a 403 error right before the first 420 kicks in.

Here are three lines from the log:

[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v2/characters/93187550/skillqueue/?datasource=tranquility [t/e: 0.24s/2]
[2019-03-28 15:01:36] eseye.ERROR: [http 403, forbidden] get -> https://esi.evetech.net/v2/universe/structures/1027847407689/?datasource=tranquility [t/e: 0.11s/1]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1021160190583/?datasource=tranquility [t/e: 0.18s/0]

[warlof]

Except the structure endpoint?

[jediefe]

Yep, this is the paste of further upcoming lines from the same log:

[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v2/characters/93187550/skillqueue/?datasource=tranquility [t/e: 0.24s/2]
[2019-03-28 15:01:36] eseye.ERROR: [http 403, forbidden] get -> https://esi.evetech.net/v2/universe/structures/1027847407689/?datasource=tranquility [t/e: 0.11s/1]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1021160190583/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93187550/wallet/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847404796/?datasource=tranquility [t/e: 0.04s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.15s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v1/characters/93187550/attributes/?datasource=tranquility [t/e: 0.32s/2]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.17s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1029833409281/?datasource=tranquility [t/e: 0.04s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847403190/?datasource=tranquility [t/e: 0.04s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.23s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1029851936015/?datasource=tranquility [t/e: 0.04s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1027847408745/?datasource=tranquility [t/e: 0.04s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.16s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/universe/structures/1029901670793/?datasource=tranquility [t/e: 0.04s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.22s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.29s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.24s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] get -> https://esi.evetech.net/v4/characters/93187550/skills/?datasource=tranquility [t/e: 0.43s/1]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.16s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.15s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.17s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v3/characters/93188039/clones/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.16s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v4/characters/93188039/notifications/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.19s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/calendar/?datasource=tranquility [t/e: 0.17s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.20s/]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.19s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/characters/93188039/fittings/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/contracts/?datasource=tranquility&page=1 [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/fatigue/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/characters/93188039/contacts/?datasource=tranquility&page=1 [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/mining/?datasource=tranquility&page=1 [t/e: 0.17s/0]
[2019-03-28 15:01:36] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.22s/]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/industry/jobs/?datasource=tranquility&include_completed=1 [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/killmails/recent/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:36] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v2/characters/93188039/online/?datasource=tranquility [t/e: 0.17s/0]
[2019-03-28 15:01:37] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/location/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:37] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.21s/]
[2019-03-28 15:01:37] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.21s/]
[2019-03-28 15:01:37] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/ship/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:37] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/mail/?datasource=tranquility [t/e: 0.18s/0]
[2019-03-28 15:01:37] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.17s/]
[2019-03-28 15:01:37] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.22s/]
[2019-03-28 15:01:37] eseye.INFO: [http 200, ok] post -> https://login.eveonline.com/oauth/token/?grant_type=refresh_token [t/e: 0.20s/]
[2019-03-28 15:01:37] eseye.ERROR: [http 420, status code 420] get -> https://esi.evetech.net/v1/characters/93188039/mail/lists/?datasource=tranquility [t/e: 0.18s/0]

Only the structure endpoints return 403, all other endpoints are working.

[warlof]

So prior to 15:01 you didn't have any single status starting with either 4 or 5?

[jediefe]

No, the structure endpoints throw 403 right from the start (at 15:00 in this case) for each requested structure the respective member lacks access rights for it in the game. So in theory this means, the more assets members have on structures with no access, the more errors are thrown.

Do you need more log?

[warlof]

It has been improved in SeAT 4.0.x with three job middlewares. One will check Tranquility status, the other will check check ESI status and Rate Limit.

https://github.com/eveseat/eveapi/blob/4.0.x/src/Jobs/Middleware/CheckEsiRateLimit.php https://github.com/eveseat/eveapi/blob/4.0.x/src/Jobs/Middleware/CheckEsiStatus.php https://github.com/eveseat/eveapi/blob/4.0.x/src/Jobs/Middleware/CheckServerStatus.php