Shopify / shopify-api-ruby

ShopifyAPI is a lightweight gem for accessing the Shopify admin REST and GraphQL web services.
MIT License
1.05k stars 468 forks source link

app_not_installed error right after app uninstallation #1322

Open mironov opened 3 months ago

mironov commented 3 months ago

Issue summary

Before opening this issue, I have:

I believe this has started after switching to the new token exchange API.

When user uninstalls our app, that executes a background job that destroys the shop record. Shortly after, a request to our web app comes with the token of that shop:

/?embedded=1&hmac=[FILTERED]&host=[FILTERED]&id_token=[FILTERED]&locale=en-IN&session=[FILTERED]&shop=[FILTERED]&timestamp=1717860610

That results in the following error:

A 400 error (ShopifyAPI::Errors::HttpResponseError) occurred during the token exchange. Response: {"error"=>"app_not_installed", "error_description"=>"The application is not installed on this shop."}

I believe it is happening on the following lines: https://github.com/Shopify/shopify-api-ruby/blob/main/lib/shopify_api/auth/token_exchange.rb#L53-L68

However, it is not handled because error is not invalid_subject_token but app_not_installed. The error bubbles up to our controller.

If that is helpful, here is the id of the error: edf7bd5b-4f17-4bf8-a35e-0bba570eb2bd-1717860642.

Expected behavior

I think the error should be handled gracefully, and InvalidJwtTokenError should be bubbled up instead.

Actual behavior

Error is not handled.

Steps to reproduce the problem

I can't reliably reproduce this but from the logs I see the same order of steps is happening.

  1. Store deletes the app
  2. A new request is made on behalf of the app

Debug logs

2024-06-08T15:30:32.075385759Z stdout F 2024-06-08T15:30:32.075Z pid=1 tid=mld class=AppUninstalledJob jid=6dc42735a3e7905cbe9b146b INFO: start
2024-06-08T15:30:32.791104951Z stdout F 2024-06-08T15:30:32.790Z pid=1 tid=mld class=AppUninstalledJob jid=6dc42735a3e7905cbe9b146b INFO: AppUninstalledJob started for shop '[FILTERED]'
2024-06-08T15:30:32.82917927Z stdout F 2024-06-08T15:30:32.828Z pid=1 tid=mld class=AppUninstalledJob jid=6dc42735a3e7905cbe9b146b elapsed=0.754 INFO: done

2024-06-08T15:30:42.57039813Z stdout F I, [2024-06-08T15:30:42.570193 #1]  INFO -- : [90cf4e4db7f98c7a800c914cf24f27f2] Started GET "/?embedded=1&hmac=[FILTERED]&host=[FILTERED]&id_token=[FILTERED]&locale=en-IN&session=[FILTERED]&shop=[FILTERED]&timestamp=1717860610" for 10.244.0.236 at 2024-06-08 15:30:42 +0000
2024-06-08T15:30:42.571995737Z stdout F I, [2024-06-08T15:30:42.571796 #1]  INFO -- : [90cf4e4db7f98c7a800c914cf24f27f2] Processing by HomeController#index as HTML
2024-06-08T15:30:42.572186116Z stdout F I, [2024-06-08T15:30:42.571911 #1]  INFO -- : [90cf4e4db7f98c7a800c914cf24f27f2]   Parameters: {"embedded"=>"1", "hmac"=>"[FILTERED]", "host"=>"[FILTERED]", "id_token"=>"[FILTERED]", "locale"=>"en-IN", "session"=>"[FILTERED]", "shop"=>"[FILTERED]", "timestamp"=>"1717860610"}
2024-06-08T15:30:42.575700054Z stdout F I, [2024-06-08T15:30:42.575504 #1]  INFO -- : [90cf4e4db7f98c7a800c914cf24f27f2] [ ShopifyApp | INFO | Shop Not Found ] Performing Token Exchange for [[FILTERED]] - (Offline)
2024-06-08T15:30:42.731111381Z stdout F E, [2024-06-08T15:30:42.730768 #1] ERROR -- : [90cf4e4db7f98c7a800c914cf24f27f2] [ ShopifyApp | ERROR | Shop Not Found ] A 400 error (ShopifyAPI::Errors::HttpResponseError) occurred during the token exchange. Response: {"error"=>"app_not_installed", "error_description"=>"The application is not installed on this shop."}
2024-06-08T15:30:42.733025618Z stdout F E, [2024-06-08T15:30:42.732248 #1] ERROR -- : [90cf4e4db7f98c7a800c914cf24f27f2] {"error_reference":"If you report this error, please include this id: edf7bd5b-4f17-4bf8-a35e-0bba570eb2bd-1717860642."}
2024-06-08T15:30:43.024100912Z stdout F I, [2024-06-08T15:30:43.023860 #1]  INFO -- : [90cf4e4db7f98c7a800c914cf24f27f2] Completed 400 Bad Request in 451ms (Views: 1.9ms | ActiveRecord: 0.7ms | Allocations: 23613)
sle-c commented 2 months ago

Hi @mironov

Thank you for reporting this issue. I'm able to reproduce the issue by uninstalling the app and and close the setting page.

Screenshot 2024-07-15 at 5 52 02 PM

We'll look more into this issue to figure out why the page doesn't navigate away after app uninstallation.

Si