Never ending request

[rolios]

Description

I use PollyJS with Puppeteer to record and replay http requests in E2E test context. I have one never-ending http call, I'm trying to figure out why. I didn't managed to find the root cause of it and started to wonder if it could be a bug.

• Every other requests works as expected, only this one doesn't.
• the request is an http POST to a laravel backend to get an auth token: /oauth/token
• Based on body parameters, if username and password are invalid, the backend answer with an error and PollyJS behave correctly
• If username and password are valid, the backend answer code 200 with a token
• Request works as expected when Polly is not enabled and request interception is off

Manual tests in devtools

fetch(url, {
        method: 'POST',
        headers: {
	    accept: 'application/json',
            'content-type': 'application/json;charset=UTF-8',
        },
        body: JSON.stringify(credentials),
    }

Without polly

With polly

Details of the passthrough request:

I tried to understand what is happening by watching page events in the polly-puppeteer-adapter and have seen my request going through these events : request / response / request failed (timeout)

Dependencies

{
    "@pollyjs/adapter-puppeteer": "^2.6.0",
    "@pollyjs/core": "^2.6.0",
    "@pollyjs/persister-fs": "^2.6.0",
}

Config

new PollyJS('', {
      mode: 'passthrough',
      adapters: ['puppeteer'],
      persister: 'fs',
});

Environment

Node.js v11.5.0
darwin 18.7
6.10.2
1.17.3

[offirgolan]

@rolios any chance you can create a working reproduction that I can play around with?

[rolios]

@offirgolan ok, I'm preparing that 👍

[rodrigogs]

I'm havin the exact same problem:

    const { page } = this.helpers.Puppeteer;
    await page.setRequestInterception(true);

    const polly = new Polly(title, {
      mode: 'record',
      adapters: ['puppeteer'],
      persister: 'fs',
      adapterOptions: {
        puppeteer: { page },
      },
      persisterOptions: {
        fs: {
          recordingsDir: path.resolve(__dirname, '..', '..', 'e2e-output', 'requests'),
        },
      },
    });

[offirgolan]

@rodrigogs can you create a working reproduction that I can use to debug?

[rodrigogs]

@offirgolan turns out that the hanging problem was due to the persister-fs module, which is another problem. The following code is not working for me anyway:

const { Polly } = require('@pollyjs/core');
const PuppeteerAdapter = require('@pollyjs/adapter-puppeteer');
// const FSPersister = require('@pollyjs/persister-fs');
const puppeteer = require('puppeteer');

Polly.register(PuppeteerAdapter);
// Polly.register(FSPersister);

(async () => {
  try {
    const browser = await puppeteer.launch({ headless: false });
    const page = await browser.newPage();

    await page.setRequestInterception(true);

    new Polly('Test', {
      mode: 'record',
      adapters: ['puppeteer'],
      // persister: ['fs'],
      adapterOptions: {
        puppeteer: { page },
      },
    });

    await page.goto('https://accounts.google.com/ServiceLogin');
    await page.waitFor('input[name=identifier]');
    await page.$eval('input[name=identifier]', el => el.value = '[email protected]');
    await page.click('#identifierNext');
  } catch (err) {
    console.error(err);
  }
})();

When I'm intercepting requests with Polly, the password page fails to load, when I disable Polly, it works perfectly. If you uncomment the persister-fs code, will see that there's also a problem with adapter-puppeteer along with persister-fs.

[jasonmit]

@rodrigogs what version of puppeteer? I know this used to occur on an older version of puppeteer.

[rodrigogs]

@jasonmit version 1.19.0

[offirgolan]

@rodrigogs would you mind checking if this issue occurs for you on v1.10.0?

[rodrigogs]

https://gist.github.com/rodrigogs/7db680570b04b0d2808cf482b2b5548c

Same behavior. Tested with 1.10.0 and 1.20.0.

[jasonmit]

I'm able to reproduce this and see that a request is being iniatiated but not captured and responded to by Polly. Since await page.setRequestInterception(true); is set puppeteer is waiting to be told to continue for all requests. Polly never ends up responding to the request, for reasons that I need to investigate further, so the xhr request eventually times out.

[jasonmit]

More findings:

The passthrough request that Polly makes (the one immediately under the timed out request) occurs via fetch and the API responds back with an empty body and a 200 status code. This is likely why the original, non-passthrough, request times out. The intended request happens over xhr and does respond with a body. If you make the call over curl, the API responds also as expected as well

XHR and curl both return a response body:

let r = new XMLHttpRequest();
r.open('POST', 'https://accounts.google.com/_/signin/sl/lookup?hl=en&_reqid=48285&rt=j');
r.setRequestHeader('content-type', 'application/x-www-form-urlencoded;charset=UTF-8');
r.setRequestHeader('accept', '*/*');
r.setRequestHeader('cache-control', 'no-cache');
r.setRequestHeader('accept-language', 'en-US,en;q=0.9');
r.setRequestHeader('google-accounts-xsrf', '1');
r.setRequestHeader('pragma', 'no-cache');
r.setRequestHeader('x-same-domain', '1');
r.setRequestHeader('x-requested-with', 'XMLHttpRequest');
r.send("continue=https%3A%2F%2Faccounts.google.com%2FManageAccount&f.req=%5B%22rodrigo.smscom%40gmail.com%22%2C%22AEThLlwXT6X3O3MYWpGNFDxApgurgRBcN_jYwQ3DrSpQksgWnitsMNh5LZGAfJ0Y4rP4cZSUoBtQYrrAOboLTkyl--911UW_khvqIdaOSdsQSVMWl8QCidaYRb273lGhjGoaORGuIlQP6yJqkjyB3XwcC33B3_uArw%22%2C%5B%5D%2Cnull%2C%22US%22%2Cnull%2Cnull%2C2%2Cfalse%2Ctrue%2C%5Bnull%2Cnull%2C%5B2%2C1%2Cnull%2C1%2C%22https%3A%2F%2Faccounts.google.com%2FServiceLogin%22%2Cnull%2C%5B%5D%2C4%2C%5B%5D%2C%22GlifWebSignIn%22%2Cnull%2C%5B%5D%5D%2C1%2C%5Bnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2C%5B%5D%2C%5B%5D%5D%2Cnull%2Cnull%2Cnull%2Ctrue%5D%2C%22rodrigo.smscom%40gmail.com%22%5D&bgRequest=%5B%22identifier%22%2C%22!ycqlyutCujrIxjhjcUVE5R4Do4S9S7oCAAAAZlIAAAAfmQHjbVeNVPOADWdAKh29-5THCk-acSnGcomyKkRqP5iqXQ5NTxdiSrOmrY2nWAv-cGJas06KOJxjQqzvoL133Y23vUCnFpiEHOxogi_9VYA7pw2yH_uMa2wSHQTNpbdZtD0Bbiz7dyIEvNPNZXL0NlBxM5rFOCMU7MgH9Vr8Ax1VAUGY7ce8UGDE-hHkBbotgKUa5FkrgN_4_AEuxlAmUycPFLVofOYu8vLOZJanalNhJAGrmtXpwG8mplHTXgw1ht9ZbKtNTaKnEX6fSrg0E2bM9gsS5xN9CCIQF_JY2q_u9IF1s1uTdBLOBv3LJqedSl0uF6rtqJcR1L99ngz6j480NEIaocuK1A_aDkXFPPfg3-Z7qJy1yZwUh2nx4QU3vkbh4gydEx4qNAx6PEp8GMYe3UDrCrg58yBPMWgb3WZ03ysMRFKc6Y2tMo9DRRFaD2KdoH0nGGqbEiQCI1OH-QpDAHzGQd_UfaLjwlcwQ3sSMx_ager91C5fxc0nWt-VFW_i_STrYslwrZq4l1EpAr137t7_pguQ3jlsA_Zqv9G0JTDBjqG6vm9KE8kta8mgZ_9IaFtqM1_evNBDNLwWRoERxWATAeNgKSyhOH9kRJuCevc2YC-NwB0ExdQS3G5hOHn8W5S5%22%5D&azt=AFoagUW8aVhPPgpaqlRvNi8APp3m3jyeew%3A1569875082805&cookiesDisabled=false&deviceinfo=%5Bnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2C%22US%22%2Cnull%2Cnull%2C%5B%5D%2C%22GlifWebSignIn%22%2Cnull%2C%5Bnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2C%5B%5D%2C%5B%5D%5D%5D&gmscoreversion=undefined&checkConnection=youtube%3A239%3A1&checkedDomains=youtube&pstMsg=1&");

curl 'https://accounts.google.com/_/signin/sl/lookup?hl=en&_reqid=48638&rt=j' -H 'sec-fetch-mode: cors' -H 'x-same-domain: 1' -H 'origin: https://accounts.google.com' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'google-accounts-xsrf: 1' -H 'cookie: GAPS=1:YcZky8RGGT3hc5-dn7KVd6qzn4Qb3w:XZ5q_nMb2BKv3Upv; NID=188=e0ANccrXiW6lLypmPw1GsaPrI_oO3wOOQFvW-lDYvjBn2P9RFqR6dmEg-EOo0x3XoRY66YmbrHnk9AOTGCQsgJnJPYDqb77HKx4C3dxiaZPyb99Kgi-ehmPi2ZtStqaw0hXbW0EwxHTPILG8JFhTv9qY11B8z2hQ7UKEH-deGGU' -H 'user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3882.0 Safari/537.36' -H 'content-type: application/x-www-form-urlencoded;charset=UTF-8' -H 'accept: */*' -H 'referer: https://accounts.google.com/signin/v2/identifier?flowName=GlifWebSignIn&flowEntry=ServiceLogin' -H 'authority: accounts.google.com' -H 'sec-fetch-site: same-origin' --data $'continue=https%3A%2F%2Faccounts.google.com%2FManageAccount&f.req=%5B%22rodrigo.smscom%40gmail.com%22%2C%22AEThLlxAJoRFx4ODBE6Jliiw3z-gmcupSe0GqyuUE0bepwV7g3EQlZn2okDLZsaSNWQ1RJiaXwY2wCsNn5UxbyKkfs49uUaCe-wRo2ZWQ5xdFZ3feJU7aGl2rnjCjTt8sn0IKc-OafjPK3gcbI1lJQ2gSuY8XC7kIQZIi68fgBKzqIxDjO7bINM%22%2C%5B%5D%2Cnull%2C%22US%22%2Cnull%2Cnull%2C2%2Cfalse%2Ctrue%2C%5Bnull%2Cnull%2C%5B2%2C1%2Cnull%2C1%2C%22https%3A%2F%2Faccounts.google.com%2FServiceLogin%22%2Cnull%2C%5B%5D%2C4%2C%5B%5D%2C%22GlifWebSignIn%22%2Cnull%2C%5B%5D%5D%2C1%2C%5Bnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2C%5B%5D%2C%5B%5D%5D%2Cnull%2Cnull%2Cnull%2Ctrue%5D%2C%22rodrigo.smscom%40gmail.com%22%5D&bgRequest=%5B%22identifier%22%2C%22\u00211tWl1fRCNP26oHQOgqtEBAWQOemD7KkCAAAAjFIAAAAimQHTV7VFIkhaxbpSDe3t13Fz4gAoaN-qO-wrRQ37Q4u0nUN2CGQejZt_zEtpAIn0ejKDc_ntdymr1Z0brMHsIGU22q1jO6MIHEA7_3ifAly0eS1EeaGT7glQaH0gXRJIg1iLSqPuzizDnVrYjSufsZpKlh4fjxujZT4YCngqz-jp-DaH72FXaEevwdw-H8F3oQL8mYSmZGJjvh2N6h2eNn7mBV5aG7HgpKF6f6223OJTdDf2NE0uD_udt2nro1iHPEE_KAENu7dbpsEbbG1tC2OYvVkFDGLETi-XPVBJldjH_kFUl7mnGbmu2JaYIxAG_Ksyku8fbhtFOea8DIcyw59OEHI2GVT34jRpjXyT3LI3FzIUc9QlbVq75VkuzjsHsAqG5k51K4rjNUge2iDIZNhMZbT3oiDYCEWVP7kE6uX0nDiyC_mELWmNGvz0sPQ2FuzOuLKYNzO6YaqMNtyd-FDEZd2_L-x8nSRPu6oZhqXPBfegxW2sOgx5jIHuyoxpXb9gZJkAQLhmPHtX1p0QYXYJ6O6hmvDW7XqPvQ8M7lrVPAlFYtXRSoeQCeYsM-iYa29GthBFYy7Yql0SyjO__ot9osPOn11exPT7TwPwOHKjXg6OErM%22%5D&azt=AFoagUU-UO8OUr__aIRj5nDwX5xcRc-iRQ%3A1569875436127&cookiesDisabled=false&deviceinfo=%5Bnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2C%22US%22%2Cnull%2Cnull%2C%5B%5D%2C%22GlifWebSignIn%22%2Cnull%2C%5Bnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2C%5B%5D%2C%5B%5D%5D%5D&gmscoreversion=undefined&checkConnection=youtube%3A162%3A1&checkedDomains=youtube&pstMsg=1&' --compressed

Identical request over the native fetch however does not respond with a body:

fetch("https://accounts.google.com/_/signin/sl/lookup?hl=en&_reqid=48285&rt=j", {"credentials":"include","headers":{"accept":"*/*","accept-language":"en-US,en;q=0.9","cache-control":"no-cache","content-type":"application/x-www-form-urlencoded;charset=UTF-8","google-accounts-xsrf":"1","pragma":"no-cache","sec-fetch-mode":"cors","sec-fetch-site":"same-origin","x-same-domain":"1"},"referrer":"https://accounts.google.com/signin/v2/identifier?flowName=GlifWebSignIn&flowEntry=ServiceLogin","referrerPolicy":"no-referrer-when-downgrade","body":"continue=https%3A%2F%2Faccounts.google.com%2FManageAccount&f.req=%5B%22rodrigo.smscom%40gmail.com%22%2C%22AEThLlwXT6X3O3MYWpGNFDxApgurgRBcN_jYwQ3DrSpQksgWnitsMNh5LZGAfJ0Y4rP4cZSUoBtQYrrAOboLTkyl--911UW_khvqIdaOSdsQSVMWl8QCidaYRb273lGhjGoaORGuIlQP6yJqkjyB3XwcC33B3_uArw%22%2C%5B%5D%2Cnull%2C%22US%22%2Cnull%2Cnull%2C2%2Cfalse%2Ctrue%2C%5Bnull%2Cnull%2C%5B2%2C1%2Cnull%2C1%2C%22https%3A%2F%2Faccounts.google.com%2FServiceLogin%22%2Cnull%2C%5B%5D%2C4%2C%5B%5D%2C%22GlifWebSignIn%22%2Cnull%2C%5B%5D%5D%2C1%2C%5Bnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2C%5B%5D%2C%5B%5D%5D%2Cnull%2Cnull%2Cnull%2Ctrue%5D%2C%22rodrigo.smscom%40gmail.com%22%5D&bgRequest=%5B%22identifier%22%2C%22!ycqlyutCujrIxjhjcUVE5R4Do4S9S7oCAAAAZlIAAAAfmQHjbVeNVPOADWdAKh29-5THCk-acSnGcomyKkRqP5iqXQ5NTxdiSrOmrY2nWAv-cGJas06KOJxjQqzvoL133Y23vUCnFpiEHOxogi_9VYA7pw2yH_uMa2wSHQTNpbdZtD0Bbiz7dyIEvNPNZXL0NlBxM5rFOCMU7MgH9Vr8Ax1VAUGY7ce8UGDE-hHkBbotgKUa5FkrgN_4_AEuxlAmUycPFLVofOYu8vLOZJanalNhJAGrmtXpwG8mplHTXgw1ht9ZbKtNTaKnEX6fSrg0E2bM9gsS5xN9CCIQF_JY2q_u9IF1s1uTdBLOBv3LJqedSl0uF6rtqJcR1L99ngz6j480NEIaocuK1A_aDkXFPPfg3-Z7qJy1yZwUh2nx4QU3vkbh4gydEx4qNAx6PEp8GMYe3UDrCrg58yBPMWgb3WZ03ysMRFKc6Y2tMo9DRRFaD2KdoH0nGGqbEiQCI1OH-QpDAHzGQd_UfaLjwlcwQ3sSMx_ager91C5fxc0nWt-VFW_i_STrYslwrZq4l1EpAr137t7_pguQ3jlsA_Zqv9G0JTDBjqG6vm9KE8kta8mgZ_9IaFtqM1_evNBDNLwWRoERxWATAeNgKSyhOH9kRJuCevc2YC-NwB0ExdQS3G5hOHn8W5S5%22%5D&azt=AFoagUW8aVhPPgpaqlRvNi8APp3m3jyeew%3A1569875082805&cookiesDisabled=false&deviceinfo=%5Bnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2C%22US%22%2Cnull%2Cnull%2C%5B%5D%2C%22GlifWebSignIn%22%2Cnull%2C%5Bnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2Cnull%2C%5B%5D%2Cnull%2Cnull%2Cnull%2C%5B%5D%2C%5B%5D%5D%5D&gmscoreversion=undefined&checkConnection=youtube%3A239%3A1&checkedDomains=youtube&pstMsg=1&","method":"POST","mode":"cors"});

I'll need to compare the two and figure out why that is. I think perhaps the solution here is if the request happens over XHR - make the request over XHR and if it happens over fetch then make the request over fetch. The only thing I can think of is there is a registered XHR request event (i.e.,load, loadend, abort, etc.) that's not firing because we go over fetch. The body format of these responses are also not really human readable and the format name is called JSPB.

[witqq]

any workarounds?

[jasonmit]

Do you have a reproduction that doesn't involve a Google request? Have not triaged further and would appreciate any additional information.

[szymn]

I started to see a similar issue when I added Cache-Control: no-store header to the resource I was fetching while using pollyjs through codeceptjs.

Package versions:

  "@codeceptjs/mock-request": "0.3.0",
  "codeceptjs": "2.6.8",
  "puppeteer": "3.0.4",
  "@pollyjs/adapter-puppeteer": "4.3.0",
  "@pollyjs/core": "4.3.0",
  "@pollyjs/persister-fs": "4.3.0"