Shopify app review stuck – approving billing charge in loop

[bhr]

Issue summary

Shopify app review team can't proceed with our app review because they're stuck in a billing charge approval loop.

We can't reproduce the issue in any of our development stores, so we're a bit at odds end.

From the app insights, we can see that the subscription charge is activated, immediately, canceled, and activated again.

• @shopify/shopify-app-express version: 2.1.1
• Node version: Node 16.16
• Operating system: Docker, unix

Debug server logs

[shopify-app/DEBUG] Found a session for a different shop in the request | {currentShop: YYYYYYYYYY.myshopify.com, requestShop: XXXXXXXXX.myshopify.com}
[shopify-app/DEBUG] Redirecting to auth at /auth, with callback /auth/callback | {shop: XXXXXXXXX.myshopify.com, isOnline: false}"
[shopify-api/INFO] Beginning OAuth | {shop: XXXXXXXXX.myshopify.com, isOnline: false, callbackPath: /auth/callback}
[shopify-api/DEBUG] OAuth started, redirecting to https://XXXXXXXXX.myshopify.com/admin/oauth/authorize?client_id=6742acff0f7b3548cfc31c19135c96d4&scope=read_products%2Cread_orders%2Cwrite_script_tags%2Cwrite_discounts%2Cread_themes&redirect_uri=https%3A%2F%2F<#shop-app-domain#>%2Fauth%2Fcallback&state=504727424817739&grant_options%5B%5D= | {shop: XXXXXXXXX.myshopify.com, isOnline: false}
[shopify-app/INFO] Handling request to complete OAuth process
[shopify-api/INFO] Completing OAuth | {shop: XXXXXXXXX.myshopify.com}
[shopify-api/DEBUG] OAuth request is valid, requesting access token | {shop: XXXXXXXXX.myshopify.com}"
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/oauth/access_token  -  Headers: {\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"147\"]}  -  Body: \"{\\\"client_id\\\":\\\"6742acff0f7b3548cfc31c19135c96d4\\\\\\"client_secret\\\":\\\"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\\\\\\"code\\\":\\\"d6ae75dc90d68933cec4fa7e9af3db7a\\\"}\"
[shopify-api/DEBUG] Completed HTTP request, received 430 undefined
[shopify-app/ERROR] Failed to complete OAuth with error: Error: Received an error response (430 undefined) from Shopify:\nIf you report this error, please include this id: 244eebad-b6a6-4094-a6e7-20ee745d4ffc Error: [shopify-app/ERROR] Failed to complete OAuth with error: Error: Received an error response (430 undefined) from Shopify:\nIf you report this error, please include this id: 244eebad-b6a6-4094-a6e7-20ee745d4ffc\n    at console.error (/app/dist/packages/service-utils/lib/logging.js:50:37)\n    at Object.defaultLogFunction [as log] (/app/node_modules/@shopify/shopify-api/lib/config.js:99:21)\n    at /app/node_modules/@shopify/shopify-api/lib/logger/log.js:39:23\n    at /app/node_modules/@shopify/shopify-api/lib/logger/index.js:17:105\n    at Generator.next (<anonymous>)\n    at /app/node_modules/tslib/tslib.js:167:75\n    at new Promise (<anonymous>)\n    at Object.__awaiter (/app/node_modules/tslib/tslib.js:163:16)\n    at Object.error (/app/node_modules/@shopify/shopify-api/lib/logger/index.js:17:51)\n    at Object.error (/app/node_modules/@shopify/shopify-app-express/build/cjs/index.js:124:46)
[shopify-app/INFO] Running validateAuthenticatedSession"
[shopify-api/DEBUG] App is not embedded, looking for session id in cookies | {isOnline: false}
[shopify-app/DEBUG] Request session found and loaded | {shop: jk1427.myshopify.com}"
[shopify-app/DEBUG] Request session exists and is active | {shop: jk1427.myshopify.com}
[shopify-api/DEBUG] Making HTTP request  -  POST https://jk1427.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/graphql\"],\"Content-Length\":[\"26\"]}  -  Body: \"\\n{\\n  shop {\\n    name\\n  }\\n}\""
[shopify-api/DEBUG] Completed HTTP request, received 430 undefined
[shopify-api/INFO] version 7.1.0, environment Node v16.20.0"
"> Ready on localhost:8080 - env production"
[shopify-app/INFO] Running validateAuthenticatedSession
[shopify-api/DEBUG] App is not embedded, looking for session id in cookies | {isOnline: false}
[shopify-app/INFO] Session was not valid. Redirecting to /auth?shop=XXXXXXXXX.myshopify.com | {shop: XXXXXXXXX.myshopify.com}
[shopify-app/DEBUG] Redirecting: request is at top level, going to /auth?shop=XXXXXXXXX.myshopify.com  | {shop: XXXXXXXXX.myshopify.com}
[shopify-app/DEBUG] Redirecting to auth at /auth, with callback /auth/callback | {shop: XXXXXXXXX.myshopify.com, isOnline: false}
[shopify-api/INFO] Beginning OAuth | {shop: XXXXXXXXX.myshopify.com, isOnline: false, callbackPath: /auth/callback}
[shopify-api/DEBUG] OAuth started, redirecting to https://XXXXXXXXX.myshopify.com/admin/oauth/authorize?client_id=6742acff0f7b3548cfc31c19135c96d4&scope=read_products%2Cread_orders%2Cwrite_script_tags%2Cwrite_discounts%2Cread_themes&redirect_uri=https%3A%2F%2F<#shop-app-domain#>%2Fauth%2Fcallback&state=869159867137498&grant_options%5B%5D= | {shop: XXXXXXXXX.myshopify.com, isOnline: false}
[shopify-app/INFO] Handling request to complete OAuth process"
[shopify-api/INFO] Completing OAuth | {shop: XXXXXXXXX.myshopify.com}
[shopify-api/DEBUG] OAuth request is valid, requesting access token | {shop: XXXXXXXXX.myshopify.com}"
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/oauth/access_token  -  Headers: {\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"147\"]}  -  Body: \"{\\\"client_id\\\":\\\"6742acff0f7b3548cfc31c19135c96d4\\\\\\"client_secret\\\":\\\"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\\\\\\"code\\\":\\\"94b942158974163ece4063501046bd84\\\"}\""
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-api/INFO] Creating new session | {shop: XXXXXXXXX.myshopify.com, isOnline: false}
[shopify-app/DEBUG] Callback is valid, storing session | {shop: XXXXXXXXX.myshopify.com, isOnline: false}
[shopify-app/DEBUG] Registering webhooks | {shop: XXXXXXXXX.myshopify.com}
[shopify-api/INFO] Registering webhooks | {shop: XXXXXXXXX.myshopify.com}"
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/graphql\"],\"Content-Length\":[\"576\"]}  -  Body: \"{\\n  webhookSubscriptions(\\n    first: 250,\\n    after: null,\\n  ) {\\n    edges {\\n      node {\\n        id\\n        topic\\n        includeFields\\n        metafieldNamespaces\\n        privateMetafieldNamespaces\\n        endpoint {\\n          __typename\\n          ... on WebhookHttpEndpoint {\\n            callbackUrl\\n          }\\n          ... on WebhookEventBridgeEndpoint {\\n            arn\\n          }\\n          ... on WebhookPubSubEndpoint {\\n            pubSubProject\\n            pubSubTopic\\n          }\\n        }\\n      }\\n    }\\n    pageInfo {\\n      endCursor\\n      hasNextPage\\n    }\\n  }\\n}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-api/DEBUG] Existing topics: [] | {shop: XXXXXXXXX.myshopify.com}
[shopify-api/DEBUG] Running webhook mutation | {topic: APP_UNINSTALLED, operation: create}
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/graphql\"],\"Content-Length\":[\"254\"]}  -  Body: \"\\n  mutation webhookSubscription {\\n    webhookSubscriptionCreate(\\n      topic: APP_UNINSTALLED,\\n      webhookSubscription: {callbackUrl: \\\"https://sh<#op-app-domain#>/api/webhooks\\\"}\\n    ) {\\n      userErrors {\\n        field\\n        message\\n      }\\n    }\\n  }\\n\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-app/DEBUG] Completed OAuth callback | {shop: XXXXXXXXX.myshopify.com, isOnline: false}
Start checking billing
[shopify-api/DEBUG] REST client has a redundant API version override to the default 2023-04
[shopify-api/DEBUG] Making HTTP request  -  GET https://XXXXXXXXX.myshopify.com/admin/api/2023-04/shop.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"]}
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"479\"]}  -  Body: \"{\\\"query\\\":\\\"\\\\n  query appSubscription($endCursor: String) {\\\\n    currentAppInstallation {\\\\n      activeSubscriptions {\\\\n        name\\\\n        test\\\\n      }\\\\n\\\\n      oneTimePurchases(first: 250, sortKey: CREATED_AT, after: $endCursor) {\\\\n        edges {\\\\n          node {\\\\n            name\\\\n            test\\\\n            status\\\\n          }\\\\n        }\\\\n        pageInfo {\\\\n          hasNextPage\\\\n          endCursor\\\\n        }\\\\n      }\\\\n    }\\\\n  }\\\\n\\\\\\"variables\\\":{\\\"endCursor\\\":null}}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
XXXXXXXXX.myshopify.com has payment: false, test: false, plan: staff, staff
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"857\"]}  -  Body: \"{\\\"query\\\":\\\"\\\\n  mutation test(\\\\n    $name: String!\\\\n    $lineItems: [AppSubscriptionLineItemInput!]!\\\\n    $returnUrl: URL!\\\\n    $test: Boolean\\\\n    $trialDays: Int\\\\n    $replacementBehavior: AppSubscriptionReplacementBehavior\\\\n  ) {\\\\n    appSubscriptionCreate(\\\\n      name: $name\\\\n      lineItems: $lineItems\\\\n      returnUrl: $returnUrl\\\\n      test: $test\\\\n      trialDays: $trialDays\\\\n      replacementBehavior: $replacementBehavior\\\\n    ) {\\\\n      confirmationUrl\\\\n      userErrors {\\\\n        field\\\\n        message\\\\n      }\\\\n    }\\\\n  }\\\\n\\\\\\"variables\\\":{\\\"name\\\":\\\"Enterprise plan\\\\\\"returnUrl\\\":\\\"https://sh<#op-app-domain#>\\\\\\"test\\\":false,\\\"replacementBehavior\\\":\\\"APPLY_IMMEDIATELY\\\\\\"lineItems\\\":[{\\\"plan\\\":{\\\"appUsagePricingDetails\\\":{\\\"terms\\\":\\\"Vestico service charges as defined in supplied statement of work.\\\\\\"cappedAmount\\\":{\\\"amount\\\":24000,\\\"currencyCode\\\":\\\"USD\\\"}}}}]}}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK"
[shopify-app/INFO] Running validateAuthenticatedSession
[shopify-api/DEBUG] App is not embedded, looking for session id in cookies | {isOnline: false}"
[shopify-app/DEBUG] Request session found and loaded | {shop: XXXXXXXXX.myshopify.com}"
[shopify-app/DEBUG] Request session exists and is active | {shop: XXXXXXXXX.myshopify.com}"
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/graphql\"],\"Content-Length\":[\"26\"]}  -  Body: \"\\n{\\n  shop {\\n    name\\n  }\\n}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-app/INFO] Request session has a valid access token | {shop: XXXXXXXXX.myshopify.com}"
Start checking billing
[shopify-api/DEBUG] REST client has a redundant API version override to the default 2023-04
[shopify-api/DEBUG] Making HTTP request  -  GET https://XXXXXXXXX.myshopify.com/admin/api/2023-04/shop.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"]}"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"479\"]}  -  Body: \"{\\\"query\\\":\\\"\\\\n  query appSubscription($endCursor: String) {\\\\n    currentAppInstallation {\\\\n      activeSubscriptions {\\\\n        name\\\\n        test\\\\n      }\\\\n\\\\n      oneTimePurchases(first: 250, sortKey: CREATED_AT, after: $endCursor) {\\\\n        edges {\\\\n          node {\\\\n            name\\\\n            test\\\\n            status\\\\n          }\\\\n        }\\\\n        pageInfo {\\\\n          hasNextPage\\\\n          endCursor\\\\n        }\\\\n      }\\\\n    }\\\\n  }\\\\n\\\\\\"variables\\\":{\\\"endCursor\\\":null}}\""
[shopify-api/DEBUG] Completed HTTP request, received 200 OK"
XXXXXXXXX.myshopify.com has payment: false, test: false, plan: staff, staff
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"857\"]}  -  Body: \"{\\\"query\\\":\\\"\\\\n  mutation test(\\\\n    $name: String!\\\\n    $lineItems: [AppSubscriptionLineItemInput!]!\\\\n    $returnUrl: URL!\\\\n    $test: Boolean\\\\n    $trialDays: Int\\\\n    $replacementBehavior: AppSubscriptionReplacementBehavior\\\\n  ) {\\\\n    appSubscriptionCreate(\\\\n      name: $name\\\\n      lineItems: $lineItems\\\\n      returnUrl: $returnUrl\\\\n      test: $test\\\\n      trialDays: $trialDays\\\\n      replacementBehavior: $replacementBehavior\\\\n    ) {\\\\n      confirmationUrl\\\\n      userErrors {\\\\n        field\\\\n        message\\\\n      }\\\\n    }\\\\n  }\\\\n\\\\\\"variables\\\":{\\\"name\\\":\\\"Enterprise plan\\\\\\"returnUrl\\\":\\\"https://sh<#op-app-domain#>\\\\\\"test\\\":false,\\\"replacementBehavior\\\":\\\"APPLY_IMMEDIATELY\\\\\\"lineItems\\\":[{\\\"plan\\\":{\\\"appUsagePricingDetails\\\":{\\\"terms\\\":\\\"Vestico service charges as defined in supplied statement of work.\\\\\\"cappedAmount\\\":{\\\"amount\\\":24000,\\\"currencyCode\\\":\\\"USD\\\"}}}}]}}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-app/INFO] Running validateAuthenticatedSession
[shopify-api/DEBUG] App is not embedded, looking for session id in cookies | {isOnline: false}
[shopify-app/DEBUG] Request session found and loaded | {shop: XXXXXXXXX.myshopify.com}"
[shopify-app/DEBUG] Request session exists and is active | {shop: XXXXXXXXX.myshopify.com}
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/graphql\"],\"Content-Length\":[\"26\"]}  -  Body: \"\\n{\\n  shop {\\n    name\\n  }\\n}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK"
[shopify-app/INFO] Request session has a valid access token | {shop: XXXXXXXXX.myshopify.com}
Start checking billing
[shopify-api/DEBUG] REST client has a redundant API version override to the default 2023-04
[shopify-api/DEBUG] Making HTTP request  -  GET https://XXXXXXXXX.myshopify.com/admin/api/2023-04/shop.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"]}
[shopify-api/DEBUG] Completed HTTP request, received 200 OK"
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"479\"]}  -  Body: \"{\\\"query\\\":\\\"\\\\n  query appSubscription($endCursor: String) {\\\\n    currentAppInstallation {\\\\n      activeSubscriptions {\\\\n        name\\\\n        test\\\\n      }\\\\n\\\\n      oneTimePurchases(first: 250, sortKey: CREATED_AT, after: $endCursor) {\\\\n        edges {\\\\n          node {\\\\n            name\\\\n            test\\\\n            status\\\\n          }\\\\n        }\\\\n        pageInfo {\\\\n          hasNextPage\\\\n          endCursor\\\\n        }\\\\n      }\\\\n    }\\\\n  }\\\\n\\\\\\"variables\\\":{\\\"endCursor\\\":null}}\""
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
XXXXXXXXX.myshopify.com has payment: false, test: false, plan: staff, staff
[shopify-api/DEBUG] Making HTTP request  -  POST https://XXXXXXXXX.myshopify.com/admin/api/2023-04/graphql.json  -  Headers: {\"X-Shopify-Access-Token\":[\"shpat_XXXXXXXXXX\"],\"User-Agent\":[\"Shopify Express Library v2.1.1 | Shopify API Library v7.1.0 | Node v16.20.0\"],\"Content-Type\":[\"application/json\"],\"Content-Length\":[\"857\"]}  -  Body: \"{\\\"query\\\":\\\"\\\\n  mutation test(\\\\n    $name: String!\\\\n    $lineItems: [AppSubscriptionLineItemInput!]!\\\\n    $returnUrl: URL!\\\\n    $test: Boolean\\\\n    $trialDays: Int\\\\n    $replacementBehavior: AppSubscriptionReplacementBehavior\\\\n  ) {\\\\n    appSubscriptionCreate(\\\\n      name: $name\\\\n      lineItems: $lineItems\\\\n      returnUrl: $returnUrl\\\\n      test: $test\\\\n      trialDays: $trialDays\\\\n      replacementBehavior: $replacementBehavior\\\\n    ) {\\\\n      confirmationUrl\\\\n      userErrors {\\\\n        field\\\\n        message\\\\n      }\\\\n    }\\\\n  }\\\\n\\\\\\"variables\\\":{\\\"name\\\":\\\"Enterprise plan\\\\\\"returnUrl\\\":\\\"https://sh<#op-app-domain#>\\\\\\"test\\\":false,\\\"replacementBehavior\\\":\\\"APPLY_IMMEDIATELY\\\\\\"lineItems\\\":[{\\\"plan\\\":{\\\"appUsagePricingDetails\\\":{\\\"terms\\\":\\\"Vestico service charges as defined in supplied statement of work.\\\\\\"cappedAmount\\\":{\\\"amount\\\":24000,\\\"currencyCode\\\":\\\"USD\\\"}}}}]}}\"
[shopify-api/DEBUG] Completed HTTP request, received 200 OK
[shopify-api/INFO] version 7.1.0, environment Node v16.20.0

Expected behavior

After approving a charge, the user is redirected to the app

Actual behavior

After approving a charge, the user is redirected to approve the charge again

server.ts

export const requestBilling = async (req: Request, res: Response, next: NextFunction) => {
  console.debug('Start checking billing');

  const shopify = await getShopifyAPI();
  const plans = Object.keys(billingConfig);

  const session = res.locals.shopify.session;
  const shopInfo = await getShopInfo(session);
  const isTest = process.env.NODE_ENV !== 'production';

  const hasPayment = await shopify.api.billing
    .check({
      session,
      plans,
      isTest,
    });

  console.info(`${shopInfo.shopURI} has payment: ${hasPayment}, test: ${isTest}, plan: ${shopInfo.planName}, ${shopInfo.planDisplayName}`);

  if (hasPayment) {
    next();
  } else {
    res.redirect(
      await shopify.api.billing.request({
        session,
        plan: plans[0],
        isTest,
      })
    );
  }
};

export const getShopifyAPI = async () => {
  const { API_KEY: apiKey, API_SECRET_KEY: apiSecretKey } = await getShopifyAppSecret();
  const { restResources } = await import(`@shopify/shopify-api/rest/admin/${LATEST_API_VERSION}`);
  const hostName = await getHostname();
  return shopifyApp({
      api: {
        apiKey,
        apiSecretKey,
        scopes: ['read_products', 'read_orders', 'read_script_tags', 'write_script_tags', 'read_discounts', 'write_discounts', 'read_themes'],
        apiVersion: LATEST_API_VERSION,
        hostName,
        isEmbeddedApp: false,
        restResources,
        billing: billingConfig,
        logger: {
          httpRequests: true,
          level: LogSeverity.Debug,
        },
      },
      auth: {
        path: '/auth',
        callbackPath: '/auth/callback',
      },
      webhooks: {
        path: '/api/webhooks',
      },
      // This should be replaced with your preferred storage strategy
      sessionStorage: new MemorySessionStorage(),
    });
  }
};

(async () => {
  try {
    const shopify = await getShopifyAPI();

    const server = express();

    server.get(shopify.config.auth.path, shopify.auth.begin());
    server.get(
      shopify.config.auth.callbackPath,
      shopify.auth.callback(),
      requestBilling,
      shopify.redirectToShopifyOrAppRoot()
    );
    server.post(shopify.config.webhooks.path, shopify.processWebhooks({ webhookHandlers: GDPRWebhookHandlers }));

    server.use('/api/*', shopify.validateAuthenticatedSession());
    server.use('/auth/*', shopify.validateAuthenticatedSession());

    // Bypassing authentication as our request is not authenticated at the moment
    server.get('/apiv0/shop/status', getShopRegistrationStatus);

    server.get('/error', (req, res) =>
      res
        .status(ResponseCode.instanceError)
        .set('Content-Type', 'text/html')
        .sendFile(join(`${process.cwd()}/dist/public`, 'error.html'))
    );

    server.use('/*', shopify.validateAuthenticatedSession(), requestBilling, (req, res) => {
      return res
        .status(200)
        .set('Content-Type', 'text/html')
        .sendFile(join(`${process.cwd()}/dist/public`, 'index.html'));
    });

    server.use(errors.express);

    server.listen(port, (err?: Error) => {
      if (err) {
        throw err;
      }
      console.info(`> Ready on localhost:${port} - env ${process.env.NODE_ENV}`);
    });
  } catch (e) {
    console.error(e);
    // skipcq JS-0263
    process.exit(1);
  }
})().catch((e) => console.error(e));

[bhr]

We check for billing status in requestBilling in two places:

    server.get(
      shopify.config.auth.callbackPath,
      shopify.auth.callback(),
      requestBilling,
      shopify.redirectToShopifyOrAppRoot()
    );

and

server.use('/*', shopify.validateAuthenticatedSession(), requestBilling,…

Could this be a timing issue where requestBilling is called too quickly after approving the charge causing hasPayment to return false?

[bhr]

Closing here as shopify-api-js is probably the library where the issue is.