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

bug: HTTP/TCP requests can take longer than configured timeout (due to Got's retry mechanism) #650

Open
RattleSN4K3 opened this issue Oct 4, 2024 · 0 comments
Labels

Comments

@RattleSN4K3
Copy link
Contributor

Describe the bug
When triggering an API call to a given backend/server, which might take longer than the configured socket timeout, the Got lib will attempt additional retries before GameDig's error logging/promise resolving takes place. This will lead to longer process time than expected (and adds additional overhead if a likely working request will be ignored due to the low socket timeout).

Steps To Reproduce

GameDig setup
import { GameDig } from '../lib/index.js'

async function testError () {
  const start = Date.now()
  await GameDig.query({
    debug: true,
    type: 'protocol-test',
    delay: 3000,
    socketTimeout: 1800
  }).then((state) => {
    console.log(state)
  }).catch((error) => {
    console.log(`Server is offline, error: ${error}`)
  }).finally(() => {
    console.log(`time taken: ${Date.now() - start}`)
  })
};

async function testSuccess () {
  const start = Date.now()
  await GameDig.query({
    debug: true,
    type: 'protocol-test',
    delay: 1000,
    socketTimeout: 10_000
  }).then((state) => {
    console.log(state)
  }).catch((error) => {
    console.log(`Server is offline, error: ${error}`)
  }).finally(() => {
    console.log(`time taken: ${Date.now() - start}`)
  })
}

(async () => {
  await testError()
  console.log('')
  await testSuccess()
})()
Test protocol
import Core from './core.js'

export default class test extends Core {
  constructor () {
    super()
    this.usedTcp = true
  }

  async run (state) {
    const response = await this.request({
      url: `https://httpstat.us/200?sleep=${this.options.delay}`,
      responseType: 'json'
    })

    state.raw.response = response
  }
}

Expected behavior
The runtime of the query should be somewhere near the configured timeout. With a single call to a single endpoint and having a timetout of 1800 ms, it should not take as long as it currently does (> 6000 ms).

Screenshots or Data

Q#0 Starting
Q#0 Protocol: test
Q#0 Options: {socketTimeout: 1800, attemptTimeout: 10000, maxRetries: 1, stripColors: true, portCache: true, …}
Q#0 https://httpstat.us/200?sleep=3000 HTTP-->
Q#0 Query failed with error RequestError: Timeout awaiting 'request' for 1800ms
    at ClientRequest.<anonymous> (node_modules/got/dist/source/core/index.js:792:61)
    at Object.onceWrapper (node:events:634:26)
    at ClientRequest.emit (node:events:531:35)
    at emitErrorEvent (node:_http_client:108:11)
    at TLSSocket.socketErrorListener (node:_http_client:511:5)
    at TLSSocket.emit (node:events:519:28)
    at emitErrorNT (node:internal/streams/destroy:169:8)
    at emitErrorCloseNT (node:internal/streams/destroy:128:3)
    at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
    at Timeout.timeoutHandler [as _onTimeout] (node_modules/got/dist/source/core/timed-out.js:42:25)
    at listOnTimeout (node:internal/timers:583:11)
    at process.processTimers (node:internal/timers:519:7)
Server is offline, error: Error: Failed all 1 attempts
time taken: 8508

Q#1 Starting
Q#1 Protocol: test
Q#1 Options: {socketTimeout: 10000, attemptTimeout: 10000, maxRetries: 1, stripColors: true, portCache: true, …}
Q#1 https://httpstat.us/200?sleep=1000 HTTP-->
Q#1 https://httpstat.us/200?sleep=1000 <--HTTP 200
Q#1 Size of players array: 0
Q#1 Size of bots array: 0
Q#1 Query was successful
Results {name: '', map: '', password: false, raw: {…}, version: '', …}
time taken: 1624

Additional context
A similar issue was reported with #611 and solved by #610 but the source of the problem might be the Got library with its retry mechanism.

For the first test of testError it will result into 3 outgoing calls to the API (which all return 200 within ~3000 ms, But the socketTimeout will prevent processing the response. The full process time of testError will be longer than triple the socketTimeout.

Adding retry.limit := 0 to the got call might solve reducing the timeout, but I would suggest increasing the default socket timeout value. An API request / server query might actually take longer than the configured socket timeout (for instance in #648 when providing no username). Having a low value (such as 2000ms) will take additional time due to the internal retry logic.

@RattleSN4K3 RattleSN4K3 added the bug label Oct 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant