[instr-redis] flaky test "duration covers create until server response"

[trentm]

Here is a test flake that I hit in https://github.com/open-telemetry/opentelemetry-js-contrib/actions/runs/20117049153/job/57729200786?pr=3288

  1) redis v4-v5
       multi (transactions) commands
         duration covers create until server response:

      AssertionError [ERR_ASSERTION]: diff of start time should be >= 10 and it's 8
      + expected - actual

      -false
      +true
      
      at Context.<anonymous> (test/v4-v5/redis.test.ts:604:14)
      at processTicksAndRejections (node:internal/process/task_queues:95:5)

more test log output

npm run --if-present test-all-versions -w @opentelemetry/instrumentation-redis

> @opentelemetry/instrumentation-redis@0.57.1 test-all-versions
> tav

-- required packages ["redis@5.10.0"]
-- installing ["redis@5.10.0"]
-- running test "npm run test" with redis (env: {})

> @opentelemetry/instrumentation-redis@0.57.1 test
> nyc --no-clean mocha --require '@opentelemetry/contrib-test-utils' 'test/v4-v5/*.test.ts' 'test/*.test.ts'



  redis v4-v5
    redis commands
      ✔ simple set and get
      ✔ send general command
      ✔ command with error
    client connect
      ✔ produces a span
      ✔ sets error status on connection failure
      ✔ omits basic auth from DB_CONNECTION_STRING span attribute
      ✔ omits user_pwd query parameter from DB_CONNECTION_STRING span attribute
      ✔ with empty string for client URL, there is no crash and no diag.error
    Redis client connect with malformed URL
      ✔ malformed URL should trigger diag error and reject connection
    multi (transactions) commands
      ✔ multi commands
      ✔ multi command with generic command
      ✔ multi command with error
      ✔ multi command that rejects
      1) duration covers create until server response
      ✔ response hook for multi commands
    config
      dbStatementSerializer
        ✔ custom dbStatementSerializer
        ✔ dbStatementSerializer throws
      responseHook
        ✔ valid response hook
        ✔ responseHook throws
      requireParentSpan
        ✔ set to true
    semconv stability configuration
      ✔ should emit only old attributes when semconvStability is OLD
      ✔ should emit only new attributes when semconvStability is STABLE
      ✔ should emit both old and new attributes when semconvStability is DUPLICATE
    pipeline commands
      ✔ should trace all commands in a pipeline with a mixed set of commands
      ✔ should trace all commands in a pipeline with a same set of commands

  redis
    ✔ Returns module definitions of sub-instrumentations


  25 passing (377ms)
  1 failing

  1) redis v4-v5
       multi (transactions) commands
         duration covers create until server response:

      AssertionError [ERR_ASSERTION]: diff of start time should be >= 10 and it's 8
      + expected - actual

      -false
      +true
      
      at Context.<anonymous> (test/v4-v5/redis.test.ts:604:14)
      at processTicksAndRejections (node:internal/process/task_queues:95:5)



---------------------|---------|----------|---------|---------|-------------------------------------
File                 | % Stmts | % Branch | % Funcs | % Lines | Uncovered Line #s                   
---------------------|---------|----------|---------|---------|-------------------------------------
All files            |    61.6 |    44.23 |   61.33 |   61.09 |                                     
 src                 |   80.48 |       50 |   85.71 |   80.48 |                                     
  redis.ts           |   76.47 |       50 |   85.71 |   76.47 | 74,85-95                            
  semconv.ts         |     100 |      100 |     100 |     100 |                                     
 src/v2-v3           |   22.34 |     9.67 |   13.63 |      20 |                                     
  instrumentation.ts |   18.91 |    10.34 |      20 |   19.17 | 83-268                              
  utils.ts           |      35 |        0 |       0 |   23.52 | 21-27,31-33,38-50                   
 src/v4-v5           |   76.11 |     59.7 |   80.43 |   75.75 |                                     
  instrumentation.ts |   73.48 |    56.45 |   79.54 |   73.03 | ...-240,259-283,294-297,309,487,492 
  utils.ts           |     100 |      100 |     100 |     100 |                                     
---------------------|---------|----------|---------|---------|-------------------------------------
npm error Lifecycle script `test` failed with error:
npm error code 1
npm error path /home/runner/work/opentelemetry-js-contrib/opentelemetry-js-contrib/packages/instrumentation-redis
npm error workspace @opentelemetry/instrumentation-redis@0.57.1
npm error location /home/runner/work/opentelemetry-js-contrib/opentelemetry-js-contrib/packages/instrumentation-redis
npm error command failed
npm error command sh -c nyc --no-clean mocha --require '@opentelemetry/contrib-test-utils' 'test/v4-v5/*.test.ts' 'test/*.test.ts'
-- detected failing command, flushing stdout...

-- fatal: Test exited with code 1
npm error Lifecycle script `test-all-versions` failed with error:
npm error code 1
npm error path /home/runner/work/opentelemetry-js-contrib/opentelemetry-js-contrib/packages/instrumentation-redis
npm error workspace @opentelemetry/instrumentation-redis@0.57.1
npm error location /home/runner/work/opentelemetry-js-contrib/opentelemetry-js-contrib/packages/instrumentation-redis
npm error command failed
npm error command sh -c tav

Pretty sure this is a test flake (I'm still re-running a second time to see if it passes).

Noting this here in case someone would like to try to improve the test to not be flaky.
The 10ms gap timing being used in that instr-redis test is too tight on timing for sometimes-very-slow GitHub CI runners.

[Farhan-Abbas]

I can take this. I agree that the hard-coded timing thresholds can be brittle on the CI. I’ll propose a fix that will avoid such wall-clock assumptions.