Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Responses with delay hang forever with "got" #426

Closed
mikicho opened this issue Sep 17, 2023 · 11 comments · Fixed by #432
Closed

Responses with delay hang forever with "got" #426

mikicho opened this issue Sep 17, 2023 · 11 comments · Fixed by #432
Assignees

Comments

@mikicho
Copy link
Contributor

mikicho commented Sep 17, 2023

I'm not sure if it's a got error or mswjs/interceptors one.
This is working with axios and native fetch

const { BatchInterceptor } = require('@mswjs/interceptors')
const { default: nodeInterceptors } = require('@mswjs/interceptors/presets/node')
const got = require('got')
const axios = require('axios')

const interceptor = new BatchInterceptor({
    name: 'my-interceptor',
    interceptors: nodeInterceptors,
  })
interceptor.apply();
interceptor.on('request', function ({ request, requestId }) {
  return new Promise(resolve => {
    setTimeout(() => {
      console.log(request.url);
      request.respondWith(new Response('', { status: 200 }))
       resolve()
     },
    2000)
  })
})

(await got('http://example.test')).statusCode // stuck
(await axios.get('http://example.test')).status // work
@mikicho
Copy link
Contributor Author

mikicho commented Sep 17, 2023

This happens also with the async/await:
#425 (comment)

const { BatchInterceptor } = require('@mswjs/interceptors')
const { default: nodeInterceptors } = require('@mswjs/interceptors/presets/node')
const got = require('got')
const axios = require('axios')

const interceptor = new BatchInterceptor({
    name: 'my-interceptor',
    interceptors: nodeInterceptors,
  })
interceptor.apply();
interceptor.on('request', async function ({ request, requestId }) {
  await new Promise(resolve => setTimeout(resolve, 2000))
  console.log(request.url);
  request.respondWith(new Response('', { status: 200 }))
})

(await got('http://example.test')).statusCode // stuck
(await axios.get('http://example.test')).status // work

@kettanaito
Copy link
Member

kettanaito commented Sep 18, 2023

@mikicho, can you share what the logs tell us by running the test like this?

DEBUG=* <YOUR_TEST_COMMAND>

There will be more detailed steps of what Interceptors are doing. Expecting to see a line about "no mocks found" and that it completes the original request.

This may be a corner case if either of the libraries so let's dig deeper. We have basic automated tests with got but perhaps none of them feature a timeout + bypass? May as well be the case.

@mikicho
Copy link
Contributor Author

mikicho commented Sep 18, 2023

I'm not sure what it says or if I did something wrong. but It prints no debug stuff, just the URL (from the interceptor listener).

@mikicho
Copy link
Contributor Author

mikicho commented Sep 18, 2023

@kettanaito Seems like DEBUG must be either true or 1.
This is the output:

➜  nock git:(Michael/fetch-support) ✗ DEBUG=true node a.js
00:14:38:22 [http] constructing the interceptor...
00:14:38:113 [http:apply] applying the interceptor...
00:14:38:113 [async-event-emitter:activate] set state to: ACTIVE
00:14:38:113 [http:apply] activated the emiter! ACTIVE
00:14:38:114 [http] retrieved global instance: undefined
00:14:38:114 [http:apply] no running instance found, setting up a new instance...
00:14:38:114 [http:setup] native "http" module patched!
00:14:38:114 [http:setup] native "https" module patched!
00:14:38:114 [http] set global instance! http
00:14:38:115 [http:on] adding "request" event listener:
00:14:38:115 [async-event-emitter:on] adding "request" listener...
00:14:38:115 [async-event-emitter:emit] emitting "newListener" event...
00:14:38:121 [http request] request call (protocol "http"): ["http://example.test/",{"method":"GET","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}]
00:14:38:121 [http normalizeClientRequestArgs] arguments ["http://example.test/",{"method":"GET","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}]
00:14:38:121 [http normalizeClientRequestArgs] using default protocol: http:
00:14:38:121 [http normalizeClientRequestArgs] first argument is a URL: "http://example.test/"
00:14:38:122 [http normalizeClientRequestArgs] has custom RequestOptions! {"method":"GET","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}
00:14:38:122 [http normalizeClientRequestArgs] derived RequestOptions from the URL: {"method":"GET","protocol":"http:","hostname":"example.test","host":"example.test","path":"/"}
00:14:38:122 [http normalizeClientRequestArgs] cloning RequestOptions...
00:14:38:122 [cloneObject] cloning object: {"method":"GET","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}
00:14:38:123 [cloneObject] analyzing key-value pair: method GET
00:14:38:123 [cloneObject] is plain object? GET
00:14:38:123 [cloneObject] checking the object constructor: String
00:14:38:123 [cloneObject] analyzing key-value pair: retry {"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null}
00:14:38:123 [cloneObject] is plain object? {"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null}
00:14:38:123 [cloneObject] checking the object constructor: Object
00:14:38:123 [cloneObject] cloning object: {"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null}
00:14:38:123 [cloneObject] analyzing key-value pair: limit 2
00:14:38:123 [cloneObject] is plain object? 2
00:14:38:124 [cloneObject] checking the object constructor: Number
00:14:38:124 [cloneObject] analyzing key-value pair: methods ["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"]
00:14:38:124 [cloneObject] is plain object? ["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"]
00:14:38:124 [cloneObject] checking the object constructor: Array
00:14:38:124 [cloneObject] analyzing key-value pair: statusCodes [408,413,429,500,502,503,504,521,522,524]
00:14:38:124 [cloneObject] is plain object? [408,413,429,500,502,503,504,521,522,524]
00:14:38:124 [cloneObject] checking the object constructor: Array
00:14:38:124 [cloneObject] analyzing key-value pair: errorCodes ["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"]
00:14:38:124 [cloneObject] is plain object? ["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"]
00:14:38:124 [cloneObject] checking the object constructor: Array
00:14:38:124 [cloneObject] analyzing key-value pair: maxRetryAfter Infinity
00:14:38:124 [cloneObject] is plain object? Infinity
00:14:38:124 [cloneObject] checking the object constructor: Number
00:14:38:124 [cloneObject] analyzing key-value pair: calculateDelay ({ computedValue }) => computedValue
00:14:38:124 [cloneObject] is plain object? ({ computedValue }) => computedValue
00:14:38:124 [cloneObject] checking the object constructor: Function
00:14:38:125 [cloneObject] is plain object? {"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null}
00:14:38:125 [cloneObject] checking the object constructor: Object
00:14:38:125 [cloneObject] analyzing key-value pair: headers {"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"}
00:14:38:125 [cloneObject] is plain object? {"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"}
00:14:38:125 [cloneObject] checking the object constructor: Object
00:14:38:125 [cloneObject] cloning object: {"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"}
00:14:38:125 [cloneObject] analyzing key-value pair: user-agent got (https://github.com/sindresorhus/got)
00:14:38:125 [cloneObject] is plain object? got (https://github.com/sindresorhus/got)
00:14:38:125 [cloneObject] checking the object constructor: String
00:14:38:125 [cloneObject] analyzing key-value pair: accept-encoding gzip, deflate, br
00:14:38:125 [cloneObject] is plain object? gzip, deflate, br
00:14:38:125 [cloneObject] checking the object constructor: String
00:14:38:125 [cloneObject] is plain object? {"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"}
00:14:38:125 [cloneObject] checking the object constructor: Object
00:14:38:125 [cloneObject] analyzing key-value pair: hooks {"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]}
00:14:38:125 [cloneObject] is plain object? {"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]}
00:14:38:126 [cloneObject] checking the object constructor: Object
00:14:38:126 [cloneObject] cloning object: {"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]}
00:14:38:126 [cloneObject] analyzing key-value pair: init []
00:14:38:126 [cloneObject] is plain object? []
00:14:38:126 [cloneObject] checking the object constructor: Array
00:14:38:126 [cloneObject] analyzing key-value pair: beforeRequest []
00:14:38:126 [cloneObject] is plain object? []
00:14:38:126 [cloneObject] checking the object constructor: Array
00:14:38:126 [cloneObject] analyzing key-value pair: beforeRedirect []
00:14:38:126 [cloneObject] is plain object? []
00:14:38:126 [cloneObject] checking the object constructor: Array
00:14:38:126 [cloneObject] analyzing key-value pair: beforeRetry []
00:14:38:126 [cloneObject] is plain object? []
00:14:38:126 [cloneObject] checking the object constructor: Array
00:14:38:126 [cloneObject] analyzing key-value pair: beforeError []
00:14:38:126 [cloneObject] is plain object? []
00:14:38:126 [cloneObject] checking the object constructor: Array
00:14:38:126 [cloneObject] analyzing key-value pair: afterResponse []
00:14:38:126 [cloneObject] is plain object? []
00:14:38:126 [cloneObject] checking the object constructor: Array
00:14:38:126 [cloneObject] is plain object? {"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]}
00:14:38:126 [cloneObject] checking the object constructor: Object
00:14:38:126 [cloneObject] analyzing key-value pair: cache undefined
00:14:38:127 [cloneObject] is plain object? undefined
00:14:38:127 [cloneObject] given object is undefined, not a plain object...
00:14:38:127 [cloneObject] analyzing key-value pair: dnsCache undefined
00:14:38:127 [cloneObject] is plain object? undefined
00:14:38:127 [cloneObject] given object is undefined, not a plain object...
00:14:38:127 [cloneObject] analyzing key-value pair: decompress true
00:14:38:127 [cloneObject] is plain object? true
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:127 [cloneObject] analyzing key-value pair: throwHttpErrors true
00:14:38:127 [cloneObject] is plain object? true
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:127 [cloneObject] analyzing key-value pair: followRedirect true
00:14:38:127 [cloneObject] is plain object? true
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:127 [cloneObject] analyzing key-value pair: isStream false
00:14:38:127 [cloneObject] is plain object? false
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:127 [cloneObject] analyzing key-value pair: responseType text
00:14:38:127 [cloneObject] is plain object? text
00:14:38:127 [cloneObject] checking the object constructor: String
00:14:38:127 [cloneObject] analyzing key-value pair: resolveBodyOnly false
00:14:38:127 [cloneObject] is plain object? false
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:127 [cloneObject] analyzing key-value pair: maxRedirects 10
00:14:38:127 [cloneObject] is plain object? 10
00:14:38:127 [cloneObject] checking the object constructor: Number
00:14:38:127 [cloneObject] analyzing key-value pair: prefixUrl
00:14:38:127 [cloneObject] is plain object?
00:14:38:127 [cloneObject] checking the object constructor: String
00:14:38:127 [cloneObject] analyzing key-value pair: methodRewriting true
00:14:38:127 [cloneObject] is plain object? true
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:127 [cloneObject] analyzing key-value pair: ignoreInvalidCookies false
00:14:38:127 [cloneObject] is plain object? false
00:14:38:127 [cloneObject] checking the object constructor: Boolean
00:14:38:128 [cloneObject] analyzing key-value pair: http2 false
00:14:38:128 [cloneObject] is plain object? false
00:14:38:128 [cloneObject] checking the object constructor: Boolean
00:14:38:128 [cloneObject] analyzing key-value pair: allowGetBody false
00:14:38:128 [cloneObject] is plain object? false
00:14:38:128 [cloneObject] checking the object constructor: Boolean
00:14:38:128 [cloneObject] analyzing key-value pair: https undefined
00:14:38:128 [cloneObject] is plain object? undefined
00:14:38:128 [cloneObject] given object is undefined, not a plain object...
00:14:38:128 [cloneObject] analyzing key-value pair: pagination {"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true}
00:14:38:128 [cloneObject] is plain object? {"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true}
00:14:38:128 [cloneObject] checking the object constructor: Object
00:14:38:128 [cloneObject] cloning object: {"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true}
00:14:38:128 [cloneObject] analyzing key-value pair: transform (response) => {
                if (response.request.options.responseType === 'json') {
                    return response.body;
                }
                return JSON.parse(response.body);
            }
00:14:38:128 [cloneObject] is plain object? (response) => {
                if (response.request.options.responseType === 'json') {
                    return response.body;
                }
                return JSON.parse(response.body);
            }
00:14:38:128 [cloneObject] checking the object constructor: Function
00:14:38:128 [cloneObject] analyzing key-value pair: paginate response => {
                if (!Reflect.has(response.headers, 'link')) {
                    return false;
                }
                const items = response.headers.link.split(',');
                let next;
                for (const item of items) {
                    const parsed = item.split(';');
                    if (parsed[1].includes('next')) {
                        next = parsed[0].trimStart().trim();
                        next = next.slice(1, -1);
                        break;
                    }
                }
                if (next) {
                    const options = {
                        url: new url_1.URL(next)
                    };
                    return options;
                }
                return false;
            }
00:14:38:128 [cloneObject] is plain object? response => {
                if (!Reflect.has(response.headers, 'link')) {
                    return false;
                }
                const items = response.headers.link.split(',');
                let next;
                for (const item of items) {
                    const parsed = item.split(';');
                    if (parsed[1].includes('next')) {
                        next = parsed[0].trimStart().trim();
                        next = next.slice(1, -1);
                        break;
                    }
                }
                if (next) {
                    const options = {
                        url: new url_1.URL(next)
                    };
                    return options;
                }
                return false;
            }
00:14:38:128 [cloneObject] checking the object constructor: Function
00:14:38:128 [cloneObject] analyzing key-value pair: filter () => true
00:14:38:128 [cloneObject] is plain object? () => true
00:14:38:128 [cloneObject] checking the object constructor: Function
00:14:38:128 [cloneObject] analyzing key-value pair: shouldContinue () => true
00:14:38:128 [cloneObject] is plain object? () => true
00:14:38:128 [cloneObject] checking the object constructor: Function
00:14:38:128 [cloneObject] analyzing key-value pair: countLimit Infinity
00:14:38:128 [cloneObject] is plain object? Infinity
00:14:38:128 [cloneObject] checking the object constructor: Number
00:14:38:128 [cloneObject] analyzing key-value pair: backoff 0
00:14:38:128 [cloneObject] is plain object? 0
00:14:38:128 [cloneObject] checking the object constructor: Number
00:14:38:128 [cloneObject] analyzing key-value pair: requestLimit 10000
00:14:38:128 [cloneObject] is plain object? 10000
00:14:38:128 [cloneObject] checking the object constructor: Number
00:14:38:128 [cloneObject] analyzing key-value pair: stackAllItems true
00:14:38:128 [cloneObject] is plain object? true
00:14:38:128 [cloneObject] checking the object constructor: Boolean
00:14:38:128 [cloneObject] is plain object? {"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true}
00:14:38:128 [cloneObject] checking the object constructor: Object
00:14:38:129 [cloneObject] analyzing key-value pair: parseJson (text) => JSON.parse(text)
00:14:38:129 [cloneObject] is plain object? (text) => JSON.parse(text)
00:14:38:129 [cloneObject] checking the object constructor: Function
00:14:38:129 [cloneObject] analyzing key-value pair: stringifyJson (object) => JSON.stringify(object)
00:14:38:129 [cloneObject] is plain object? (object) => JSON.stringify(object)
00:14:38:129 [cloneObject] checking the object constructor: Function
00:14:38:129 [cloneObject] analyzing key-value pair: cacheOptions {}
00:14:38:129 [cloneObject] is plain object? {}
00:14:38:129 [cloneObject] checking the object constructor: Object
00:14:38:129 [cloneObject] cloning object: {}
00:14:38:129 [cloneObject] is plain object? {}
00:14:38:129 [cloneObject] checking the object constructor: Object
00:14:38:129 [cloneObject] analyzing key-value pair: url "http://example.test/"
00:14:38:129 [cloneObject] is plain object? "http://example.test/"
00:14:38:129 [cloneObject] checking the object constructor: URL
00:14:38:129 [cloneObject] analyzing key-value pair: username
00:14:38:129 [cloneObject] is plain object?
00:14:38:129 [cloneObject] checking the object constructor: String
00:14:38:129 [cloneObject] analyzing key-value pair: password
00:14:38:129 [cloneObject] is plain object?
00:14:38:129 [cloneObject] checking the object constructor: String
00:14:38:129 [cloneObject] analyzing key-value pair: shared undefined
00:14:38:129 [cloneObject] is plain object? undefined
00:14:38:129 [cloneObject] given object is undefined, not a plain object...
00:14:38:129 [cloneObject] analyzing key-value pair: cacheHeuristic undefined
00:14:38:129 [cloneObject] is plain object? undefined
00:14:38:129 [cloneObject] given object is undefined, not a plain object...
00:14:38:129 [cloneObject] analyzing key-value pair: immutableMinTimeToLive undefined
00:14:38:129 [cloneObject] is plain object? undefined
00:14:38:129 [cloneObject] given object is undefined, not a plain object...
00:14:38:129 [cloneObject] analyzing key-value pair: ignoreCargoCult undefined
00:14:38:129 [cloneObject] is plain object? undefined
00:14:38:130 [cloneObject] given object is undefined, not a plain object...
00:14:38:130 [cloneObject] is plain object? {"method":"GET","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}
00:14:38:130 [cloneObject] checking the object constructor: Object
00:14:38:130 [http normalizeClientRequestArgs] successfully cloned RequestOptions! {"method":"GET","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}
00:14:38:130 [http normalizeClientRequestArgs] derived request options: {"method":"GET","protocol":"http:","hostname":"example.test","host":"example.test","path":"/","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":""}
00:14:38:130 [http normalizeClientRequestArgs] resolved fallback agent: {"_events":{},"_eventsCount":2,"defaultPort":80,"protocol":"http:","options":{"noDelay":true,"path":null},"requests":{},"sockets":{},"freeSockets":{},"keepAliveMsecs":1000,"keepAlive":false,"maxSockets":null,"maxFreeSockets":256,"scheduling":"lifo","maxTotalSockets":null,"totalSocketCount":0}
00:14:38:130 [http normalizeClientRequestArgs] has no default agent, setting the default agent for "http:"
00:14:38:130 [http normalizeClientRequestArgs] successfully resolved url: http://example.test/
00:14:38:130 [http normalizeClientRequestArgs] successfully resolved options: {"method":"GET","protocol":"http:","hostname":"example.test","host":"example.test","path":"/","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":"","agent":{"_events":{},"_eventsCount":2,"defaultPort":80,"protocol":"http:","options":{"noDelay":true,"path":null},"requests":{},"sockets":{},"freeSockets":{},"keepAliveMsecs":1000,"keepAlive":false,"maxSockets":null,"maxFreeSockets":256,"scheduling":"lifo","maxTotalSockets":null,"totalSocketCount":0},"_defaultAgent":{"_events":{},"_eventsCount":2,"defaultPort":80,"protocol":"http:","options":{"keepAlive":true,"scheduling":"lifo","timeout":5000,"noDelay":true,"path":null},"requests":{},"sockets":{},"freeSockets":{},"keepAliveMsecs":1000,"keepAlive":true,"maxSockets":null,"maxFreeSockets":256,"scheduling":"lifo","maxTotalSockets":null,"totalSocketCount":0}}
00:14:38:130 [http normalizeClientRequestArgs] successfully resolved callback: undefined
00:14:38:135 [http:request GET http://example.test/] constructing ClientRequest using options: {"url":"http://example.test/","requestOptions":{"method":"GET","protocol":"http:","hostname":"example.test","host":"example.test","path":"/","retry":{"limit":2,"methods":["GET","PUT","HEAD","DELETE","OPTIONS","TRACE"],"statusCodes":[408,413,429,500,502,503,504,521,522,524],"errorCodes":["ETIMEDOUT","ECONNRESET","EADDRINUSE","ECONNREFUSED","EPIPE","ENOTFOUND","ENETUNREACH","EAI_AGAIN"],"maxRetryAfter":null},"headers":{"user-agent":"got (https://github.com/sindresorhus/got)","accept-encoding":"gzip, deflate, br"},"hooks":{"init":[],"beforeRequest":[],"beforeRedirect":[],"beforeRetry":[],"beforeError":[],"afterResponse":[]},"decompress":true,"throwHttpErrors":true,"followRedirect":true,"isStream":false,"responseType":"text","resolveBodyOnly":false,"maxRedirects":10,"prefixUrl":"","methodRewriting":true,"ignoreInvalidCookies":false,"http2":false,"allowGetBody":false,"pagination":{"countLimit":null,"backoff":0,"requestLimit":10000,"stackAllItems":true},"cacheOptions":{},"url":"http://example.test/","username":"","password":"","agent":{"_events":{},"_eventsCount":2,"defaultPort":80,"protocol":"http:","options":{"noDelay":true,"path":null},"requests":{},"sockets":{"example.test:80:":[{"connecting":true,"_hadError":false,"_parent":null,"_host":"example.test","_closeAfterHandlingError":false,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":null,"ended":false,"endEmitted":false,"reading":false,"constructed":true,"sync":true,"needReadable":false,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":true,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"dataEmitted":false,"decoder":null,"encoding":null},"_events":{},"_eventsCount":6,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":true,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"constructed":true,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":true,"errored":null,"closed":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null}]},"freeSockets":{},"keepAliveMsecs":1000,"keepAlive":false,"maxSockets":null,"maxFreeSockets":256,"scheduling":"lifo","maxTotalSockets":null,"totalSocketCount":1},"_defaultAgent":{"_events":{},"_eventsCount":2,"defaultPort":80,"protocol":"http:","options":{"keepAlive":true,"scheduling":"lifo","timeout":5000,"noDelay":true,"path":null},"requests":{},"sockets":{},"freeSockets":{},"keepAliveMsecs":1000,"keepAlive":true,"maxSockets":null,"maxFreeSockets":256,"scheduling":"lifo","maxTotalSockets":null,"totalSocketCount":0}}}
00:14:38:136 [http:request GET http://example.test/] end [null]
00:14:38:137 [utils getUrlByRequestOptions] arguments [null]
00:14:38:137 [utils getUrlByRequestOptions] normalized args [null,null,null]
00:14:38:137 [http:request GET http://example.test/] normalized arguments: {"chunk":null,"encoding":null}
00:14:38:151 [http:request GET http://example.test/] emitting the "request" event for 1 listener(s)...
00:14:38:151 [async-event-emitter:emit] emitting "request" event...
00:14:38:151 [async-event-emitter:openListenerQueue] opening "request" listeners queue...
00:14:38:151 [async-event-emitter:openListenerQueue] no queue found, creating one...
00:14:38:152 [async-event-emitter:emit] appending a one-time cleanup "request" listener...
00:14:38:152 [async-event-emitter:emit] emitting "newListener" event...
00:14:38:152 [async-event-emitter:openListenerQueue] opening "request" listeners queue...
00:14:38:152 [async-event-emitter:openListenerQueue] returning an exising queue: []
00:14:38:152 [async-event-emitter:on] awaiting the "request" listener...
00:14:38:153 [async-event-emitter:emit] emitting "removeListener" event...
00:14:38:154 [http:request GET http://example.test/] emit: socket
00:14:38:155 [async-event-emitter:emit] cleaned up "request" listeners queue!
00:14:38:157 [http:request GET http://example.test/] emit: error
00:14:38:157 [http:request GET http://example.test/] error:
 {"errno":-3008,"code":"ENOTFOUND","syscall":"getaddrinfo","hostname":"example.test"}
00:14:38:157 [http:request GET http://example.test/] captured the first error: {"errno":-3008,"code":"ENOTFOUND","syscall":"getaddrinfo","hostname":"example.test"}
00:14:38:159 [http:request GET http://example.test/] emit: close
http://example.test/
00:14:38:913 [async-event-emitter:on] "request" listener has resolved!
00:14:38:915 [http:request GET http://example.test/] event.respondWith called with: {}
00:14:38:915 [http:request GET http://example.test/] the listeners promise awaited!
00:14:38:916 [http:request GET http://example.test/] received mocked response: {}
00:14:38:929 [http:request GET http://example.test/] responding with a mocked response... {}
00:14:38:929 [http:request GET http://example.test/] emit: finish
00:14:38:930 [http:request GET http://example.test/] mocked response headers ready: {}
00:14:38:931 [http:request GET http://example.test/] emit: response
00:14:38:932 [http:request GET http://example.test/] found "response" event, cloning the response...
00:14:38:934 [http:request GET http://example.test/] emit: response-internal
00:14:38:934 [http:request GET http://example.test/] response successfully cloned, emitting "response" event...
00:14:38:937 [http:request GET http://example.test/] 200  (MOCKED)
00:14:38:938 [http:request GET http://example.test/] emit: upload-complete
00:14:38:938 [http:request GET http://example.test/] emitting the custom "response" event...
00:14:38:939 [async-event-emitter:emit] emitting "response" event...
00:14:38:939 [async-event-emitter:openListenerQueue] opening "response" listeners queue...
00:14:38:939 [async-event-emitter:openListenerQueue] no queue found, creating one...
00:14:38:939 [async-event-emitter:emit] appending a one-time cleanup "response" listener...
00:14:38:939 [async-event-emitter:emit] emitting "newListener" event...
00:14:38:939 [async-event-emitter:emit] emitting "removeListener" event...
00:14:38:940 [http:request GET http://example.test/] request (mock) is completed
00:14:38:945 [http:request GET http://example.test/] finished response stream!
00:14:38:946 [http:request GET http://example.test/] finalizing response...
00:14:38:948 [async-event-emitter:emit] cleaned up "response" listeners queue!

@kettanaito
Copy link
Member

The logs look okay. May be an improperly constructed test. Will look at it a bit later.

@mikicho
Copy link
Contributor Author

mikicho commented Sep 19, 2023

From what I see, this promise was never resolved:
https://github.com/sindresorhus/got/blob/main/source/as-promise/index.ts#L179

Update1:
For some reason, the request get aborted:
https://github.com/sindresorhus/got/blob/v11.8.6/source/as-promise/index.ts#L47

Update2:
I'm not sure if this is expected, but I see this;
image

Update3:
I found that if I'm using a real address (e.g., nowhere.com), everything is working as expected.
I suspect we missed some Socket mocking. Nock does some. Maybe we can learn from or copy/paste: here, and here.

@kettanaito
Copy link
Member

That error is expected. Interceptors actually tries to perform the request and captures any errors that occur. That way if there's no mock response for that request, it will then replay those errors.

@mikicho
Copy link
Contributor Author

mikicho commented Sep 19, 2023

@kettanaito
Also with respondWith? Maybe this is the root cause? Because got checks if the request is destroyed before moving forward (here). It also explains why it's working for true URLs

Update:
I think there is a race condition here.
When I put a breakpoint here, it is working normally, if I put after the await sleep (e.g. here) the request fails.

Another thing I noticed. I inject the request (this) into the msw's 'on request' listener (a in the function, sorry for the naming 😅):
image
image

Look at a.destroyed in the watch panel before and after the sleep.

@kettanaito
Copy link
Member

I'm tackling an issue that can be related to this race condition you've mentioned. I'd like to see if the Got issue still persists once I merge that one.

@kettanaito kettanaito changed the title async requests with got.js hang Responses with delay hang forever with "got" Sep 21, 2023
@kettanaito kettanaito self-assigned this Sep 21, 2023
@mikicho
Copy link
Contributor Author

mikicho commented Sep 21, 2023

@kettanaito amazing work! Thank you very much for the quick response! 🙏

@kettanaito
Copy link
Member

Released: v0.25.3 🎉

This has been released in v0.25.3!

Make sure to always update to the latest version (npm i @mswjs/interceptors@latest) to get the newest features and bug fixes.


Predictable release automation by @ossjs/release.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
2 participants