1525444 - [tc-queue] dependency_test.js fails when run in parallel with other tests

Status: RESOLVED FIXED

(Taskcluster :: Services, defect)

Description

[Dustin J. Mitchell [:dustin] (he/him)]

https://tools.taskcluster.net/groups/D23nzAYOSDSMrMP9fNWjZA/tasks/NKBsFlS6TdOgGIXNFyxWUA/runs/0/logs/public%2Flogs%2Flive_backing.log

  1) /taskcluster/services/queue/test/dependency_test.js (real)
       taskA <- taskB, taskC, taskD, taskE:
     Unknown assertation failure occured, assumed `Set (3) {'sK-keNCFRdWEqLHqGeykbQ', 'xboWgu4HR-akjt96akRYOA', '_U77uEf3RguudzJ-zWfl2Q'}` to deeply equal `Set (4) {'sK-keNCFRdWEqLHqGeykbQ', '_U77uEf3RguudzJ-zWfl2Q', 'i0IZK2x2Rm-p_naV8Ty5Kg', 'xboWgu4HR-akjt96akRYOA'}`
  /taskcluster/services/queue/test/dependency_test.js
                                            v
      168.       .map(m => m.payload.status.taskId));
      169.     assume(nowPending).to.deeply.equal(new Set([taskIdB, taskIdC, taskIdD, taskIdE]));
      170. 
                                            ^
          at Assume.equal (/taskcluster/node_modules/assume/index.js:676:15)
          at Context.helper.runWithFakeTime (test/dependency_test.js:169:34)
  
  2) /taskcluster/services/queue/test/dependency_test.js (real)
       "before each" hook: cleanup for "taskA, taskB <- taskC && taskA <- taskD":
     ResourceNotFoundError: The specified resource does not exist.
RequestId:31cf0be6-9002-000e-3b96-bd8a8e000000
Time:2019-02-05T21:03:17.2059500Z
      at /taskcluster/node_modules/fast-azure-storage/lib/table.js:401:27
      at tryCallOne (/taskcluster/node_modules/promise/lib/core.js:37:12)
      at /taskcluster/node_modules/promise/lib/core.js:123:15
      at flush (/taskcluster/node_modules/asap/raw.js:50:29)
      at process._tickCallback (internal/process/next_tick.js:61:11)
  3) /taskcluster/services/queue/test/dependency_test.js (real)
       "after all" hook: cleanup:
     ResourceNotFoundError: The specified resource does not exist.
RequestId:668e4b8a-7002-00ea-0796-bd9984000000
Time:2019-02-05T21:03:17.2427669Z
      at /taskcluster/node_modules/fast-azure-storage/lib/table.js:401:27
      at tryCallOne (/taskcluster/node_modules/promise/lib/core.js:37:12)
      at /taskcluster/node_modules/promise/lib/core.js:123:15
      at flush (/taskcluster/node_modules/asap/raw.js:50:29)
      at process._tickCallback (internal/process/next_tick.js:61:11)

Comment 1

[Dustin J. Mitchell [:dustin] (he/him)]

This seems to now be causing hangs:

https://tools.taskcluster.net/groups/NcwhTQs3SvCKTM3CA-xI_w/tasks/MIUiQAUgQe-qOjGlOuN2tw/runs/0/logs/public%2Flogs%2Flive_backing.log

Comment 2

[Dustin J. Mitchell [:dustin] (he/him)]

We have testing.poll operations that look like this:

    await testing.poll(
      async () => {
        helper.checkNextMessage('task-pending', m => assert.equal(m.payload.status.taskId, taskIdB));
        assert.deepEqual(helper.monitor.messages.find(({Type}) => Type === 'task-pending'), {
          Logger: 'taskcluster.queue.root.dependency-tracker',
          Type: 'task-pending',
          Fields: {taskId: taskIdB, runId: 0, v: 1},
        });
      },
      Infinity);

the problem is that checkNextMessage removes the message from the list. So if on one iteration of this polling checkNextMessage succeeds, but the assertion about monitor.messages does not, then on the next iteration and all subsequent iterations, checkNextMessage will fail. And it will iterate to Infinity.

Comment 3

[Dustin J. Mitchell [:dustin] (he/him)]

I got a little carried away fixing this: I removed the delete-on-match attribute of checkNextMessage, which required changing all uses of that function, and then broadened the project by refactoring withPulse into a tc-lib-testing utility.

https://github.com/taskcluster/taskcluster/pull/545

Comment 4

[Dustin J. Mitchell [:dustin] (he/him)]

OK, I got quite a bit carried away. I narrowly avoided making this my "life's work" by filing bug 1542405.