import { URL } from 'url' import { _since } from '@naturalcycles/js-lib' import got, { AfterResponseHook, BeforeErrorHook, BeforeRequestHook, BeforeRetryHook, Got, } from 'got' import { inspectAny } from '..' import { GetGotOptions, GotRequestContext } from './got.model' /** * Returns instance of Got with "reasonable defaults": * * 1. Error handler hook that prints helpful errors. * 2. Hooks that log start/end of request (optional, false by default). * 3. Reasonable defaults(tm), e.g non-infinite Timeout * 4. Preserves error stack traces (!) (experimental!) */ export function getGot(opt: GetGotOptions = {}): Got { opt.logger ||= console if (opt.debug) { opt.logStart = opt.logFinished = opt.logResponse = opt.logRequest = true } return got.extend({ // Most-important is to set to anything non-empty (so, requests don't "hang" by default). // Should be long enough to handle for slow responses from scaled cloud APIs in times of spikes // Ideally should be LESS than default Request timeout in backend-lib (so, it has a chance to error // before server times out with 503). // // UPD 2021-11-27 // There are 2 types/strategies for requests: // 1. Optimized to get result no matter what. E.g in Cron jobs, where otherwise there'll be a job failure // 2. Part of the Backend request, where we better retry quickly and fail on timeout before Backend aborts it with "503 Request timeout" // // Here it's hard to set the default timeout right for both use-cases. // So, if it's important, you should override it according to your use-cases: // - set it longer for Type 1 (e.g 120 seconds) // - set it shorter for Type 2 (e.g 10/20 seconds) // Please beware of default Retry strategy of Got: // by default it will retry 2 times (after first try) // First delay between tries will be ~1 second, then ~2 seconds // Each retry it'll wait up to `timeout` (so, up to 60 seconds by default). // So, for 3 tries it multiplies your timeout by 3 (+3 seconds between the tries). // So, e.g 60 seconds timeout with 2 retries becomes up to 183 seconds. // Which definitely doesn't fit into default "RequestTimeout" timeout: 60_000, ...opt, handlers: [ (options, next) => { options.context = { ...options.context, started: Date.now(), // This is to preserve original stack trace // https://github.com/sindresorhus/got/blob/main/documentation/async-stack-traces.md err: new Error('RequestError'), } as GotRequestContext return next(options) }, ], hooks: { ...opt.hooks, beforeError: [ ...(opt.hooks?.beforeError || []), // User hooks go BEFORE gotErrorHook(opt), ], beforeRequest: [ gotBeforeRequestHook(opt), // User hooks go AFTER ...(opt.hooks?.beforeRequest || []), ], beforeRetry: [ gotBeforeRetryHook(opt), // User hooks go AFTER ...(opt.hooks?.beforeRetry || []), ], afterResponse: [ ...(opt.hooks?.afterResponse || []), // User hooks go BEFORE gotAfterResponseHook(opt), ], }, }) } /** * Without this hook (default behaviour): * * HTTPError: Response code 422 (Unprocessable Entity) * at EventEmitter. (.../node_modules/got/dist/source/as-promise.js:118:31) * at processTicksAndRejections (internal/process/task_queues.js:97:5) { * name: 'HTTPError' * * * With this hook: * * HTTPError 422 GET http://a.com/err?q=1 in 8 ms * { * message: 'Reference already exists', * documentation_url: 'https://developer.github.com/v3/git/refs/#create-a-reference' * } * * Features: * 1. Includes original method and URL (including e.g searchParams) in the error message. * 2. Includes response.body in the error message (limited length). * 3. Auto-detects and parses JSON response body (limited length). * 4. Includes time spent (gotBeforeRequestHook must also be enabled). * UPD: excluded now to allow automatic Sentry error grouping */ function gotErrorHook(opt: GetGotOptions = {}): BeforeErrorHook { const { maxResponseLength = 10_000 } = opt return err => { const statusCode = err.response?.statusCode || 0 const { method, url, prefixUrl } = err.options const shortUrl = getShortUrl(opt, url, prefixUrl) const { started, retryCount } = (err.request?.options.context || {}) as GotRequestContext const body = err.response?.body ? inspectAny(err.response.body, { maxLen: maxResponseLength, colors: false, }) : err.message // We don't include Response/Body/Message in the log, because it's included in the Error thrown from here opt.logger!.log( [ ' <<', statusCode, method, shortUrl, retryCount && `(retry ${retryCount})`, 'error', started && 'in ' + _since(started), ] .filter(Boolean) .join(' '), ) // timings are not part of err.message to allow automatic error grouping in Sentry // Colors are not used, because there's high chance that this Error will be propagated all the way to the Frontend err.message = [[statusCode, method, shortUrl].filter(Boolean).join(' '), body] .filter(Boolean) .join('\n') const stack = (err.options.context as GotRequestContext)?.err?.stack if (stack) { const originalStack = err.stack.split('\n') let originalStackIndex = originalStack.findIndex(line => line.includes(' at ')) if (originalStackIndex === -1) originalStackIndex = originalStack.length - 1 // Skipping first line as it has RequestError: ... // Skipping second line as it's known to be from e.g at got_1.default.extend.handlers const syntheticStack = stack.split('\n').slice(2) let firstNonNodeModulesIndex = syntheticStack.findIndex( line => !line.includes('node_modules'), ) if (firstNonNodeModulesIndex === -1) firstNonNodeModulesIndex = 0 err.stack = [ // First lines of original error ...originalStack.slice(0, originalStackIndex), // Other lines from "Synthetic error" ...syntheticStack.slice(firstNonNodeModulesIndex), ].join('\n') // err.stack += '\n --' + stack.replace('Error: RequestError', '') } return err } } function gotBeforeRequestHook(opt: GetGotOptions): BeforeRequestHook { return options => { if (opt.logStart) { const { retryCount } = options.context as GotRequestContext const shortUrl = getShortUrl(opt, options.url, options.prefixUrl) opt.logger!.log( [' >>', options.method, shortUrl, retryCount && `(retry ${retryCount})`].join(' '), ) } if (opt.logRequest) { const body = options.json || options.body if (body) { opt.logger!.log(body) } } } } // Here we log always, because it's similar to ErrorHook - we always log errors // Because Retries are always result of some Error function gotBeforeRetryHook(opt: GetGotOptions): BeforeRetryHook { const { maxResponseLength = 10_000 } = opt return (options, err, retryCount) => { // opt.logger!.log('beforeRetry', retryCount) const statusCode = err?.response?.statusCode || 0 if (statusCode && statusCode < 300) { // todo: possibly remove the log message completely in the future // opt.logger!.log( // `skipping got.beforeRetry hook as statusCode is ${statusCode}, err.msg is ${err?.message}`, // ) return } const { method, url, prefixUrl } = options const shortUrl = getShortUrl(opt, url, prefixUrl) const { started } = options.context as GotRequestContext Object.assign(options.context, { retryCount }) const body = err?.response?.body ? inspectAny(err.response.body, { maxLen: maxResponseLength, colors: false, }) : err?.message // We don't include Response/Body/Message in the log, because it's included in the Error thrown from here opt.logger!.warn( [ [ ' <<', statusCode, method, shortUrl, retryCount && retryCount > 1 ? `(retry ${retryCount - 1})` : '(first try)', 'error', started && 'in ' + _since(started), ] .filter(Boolean) .join(' '), body, ] .filter(Boolean) .join('\n'), ) } } // AfterResponseHook is never called on Error // So, coloredHttpCode(resp.statusCode) is probably useless function gotAfterResponseHook(opt: GetGotOptions = {}): AfterResponseHook { return resp => { const success = resp.statusCode >= 200 && resp.statusCode < 400 // Errors are not logged here, as they're logged by gotErrorHook if (opt.logFinished && success) { const { started, retryCount } = resp.request.options.context as GotRequestContext const { url, prefixUrl, method } = resp.request.options const shortUrl = getShortUrl(opt, url, prefixUrl) opt.logger!.log( [ ' <<', resp.statusCode, method, shortUrl, retryCount && `(retry ${retryCount - 1})`, started && 'in ' + _since(started), ] .filter(Boolean) .join(' '), ) // console.log(`afterResp! ${resp.request.options.method} ${resp.url}`, { context: resp.request.options.context }) } // Error responses are not logged, cause they're included in Error message already if (opt.logResponse && success) { opt.logger!.log(inspectAny(resp.body, { maxLen: opt.maxResponseLength })) } return resp } } function getShortUrl(opt: GetGotOptions, url: URL, prefixUrl?: string): string { if (url.password) { url = new URL(url.toString()) // prevent original url mutation url.password = '[redacted]' } let shortUrl = url.toString() if (opt.logWithSearchParams === false) { shortUrl = shortUrl.split('?')[0]! } if (opt.logWithPrefixUrl === false && prefixUrl && shortUrl.startsWith(prefixUrl)) { shortUrl = shortUrl.slice(prefixUrl.length) } return shortUrl }