npm failing in CITGM across all platforms/versions

[BethGriggs]

npm is/has been a regular failure in CITGM across all platforms/versions for a while. It's probably an important one to try to fix so we can properly track regressions.

Recent reruns on npm-v8.6.0 fail on all platforms:

• v17.8.0 - https://ci.nodejs.org/job/citgm-smoker-nobuild/1167/testReport/
• v16.14.2 - https://ci.nodejs.org/job/citgm-smoker-nobuild/1168/testReport/

There are a few different failures, with some obscured by other problems.

1. On the majority of platforms the output is not easily readable in the Jenkins jobs as it contains the colour codes:

 added 517 packages, and changed 14 packages in 60s
 > [email protected] test
 > tap
 [0m[0m[1m[38;2;0;0;0m[42m PASS [0m[0m[0m test/bin/npm-cli.js[0m[37m[1m 1[22m[32m OK [0m[1m[38;2;170;170;170m683.401ms[39m[22m[0m[0m[42m[0m[0m[0m[0m[1m[32m[37m[0m[0m[1m[38;2;0;0;0m[42m[0m[0m[0m[0m[0m[1m[38;2;0;0;0m[42m[0m[0m[0m[0m[0m[0m[0m
 [0m[0m[1m[38;2;0;0;0m[42m PASS [0m[0m[0m test/bin/npx-cli.js[0m[37m[1m 7[22m[32m OK [0m[1m[38;2;170;170;170m1s[39m[22m[0m[0m[42m[0m[0m[0m[0m[1m[32m[37m[0m[0m[1m[38;2;0;0;0m[42m[0m[0m[0m[0m[0m[1m[38;2;0;0;0m[42m[0m[0m[0m[0m[0m[0m[0m
 [0m[0m[1m[38;2;255;255;255m[44m SKIP [0m[0m[0m test/bin/windows-shims.js > [36mtest only relevant on windows[0m[37m [0m[1m[38;2;170;170;170m3.385ms[39m[22m[0m[0m[1m[44m[0m[0m[0m[36m[0m[37m[0m[0m[1m[44m[0m[0m[0m[36m[0m[0m[1m[38;2;255;255;255m[44m[0m[0m[0m[0m[0m[0m[0m
 [0m[0m[1m[38;2;255;255;255m[44m SKIP [0m[0m[0m TAP[0m[0m[1m[38;2;255;255;255m[44m[0m[0m[0m[0m[0m[0m[0m

• Link - https://ci.nodejs.org/job/citgm-smoker-nobuild/nodes=ubuntu1804-64/1168/consoleFull

2. Multiple test failures can be found within the output, such as below:

01:17:59 error:                     | test: test/lib/utils/exit-handler.js handles unknown error with logs and debug  
01:17:59 error:                     | file                                                                            
01:17:59 error:                     | at:                                                                             
01:17:59 error:                     | line: 132                                                                       
01:17:59 error:                     | column: 9                                                                       
01:17:59 error:                     | file: test/lib/utils/exit-handler.js                                            
01:17:59 error:                     | stack: |                                                                        
01:17:59 error:                     | test/lib/utils/exit-handler.js:132:9                                            
01:17:59 error:                     | Array.forEach (<anonymous>)                                                     
01:17:59 error:                     | test/lib/utils/exit-handler.js:131:14                                           
01:17:59 error:                     | Array.forEach (<anonymous>)                                                     
01:17:59 error:                     | Test.<anonymous> (test/lib/utils/exit-handler.js:129:8)                         
01:17:59 error:                     |                                                                                 
01:17:59 error:                     | �[0m​�[0m�[1m�[41m�[38;2;255;255;255m FAIL �[0m�[0m​�[0m test/lib/utils/exit-handler.js�[0m�[0m�[1m�[41m�[38;2;255;255;255m�[0m�[0m�[0m�[0m�[0m�[0m�[0m                                           
01:17:59 error:                     | �[31m�[1m ✖ �[39m�[22mshould be equal                                                              
01:17:59 error:                     |                                                                                 
01:17:59 error:                     | .reduce((__, l) => parseInt(l.match(/^(\d+)\s/)[1]))                            
01:17:59 error:                     | t.equal(logs.length, lastLog + 1)                                               
01:17:59 error:                     | ----^                                                                           
01:17:59 error:                     | t.match(logs.error, [                                                           
01:17:59 error:                     | ['code', 'ECODE'],                                            

• Link - https://ci.nodejs.org/job/citgm-smoker-nobuild/nodes=ubuntu1804-64/1168/consoleFull

3. aix72-ppc64, rhel8-s390x, rhel7-s390x hit a different error early on:

 > tap
 ----------|---------|----------|---------|---------|-------------------
 File      | % Stmts | % Branch | % Funcs | % Lines | Uncovered Line #s 
 ----------|---------|----------|---------|---------|-------------------
 All files |       0 |        0 |       0 |       0 |                   
 ----------|---------|----------|---------|---------|-------------------
 /home/iojs/tmp/citgm_tmp/13a08f5e-0713-4513-983d-261f65768bac/npm/node_modules/tap/node_modules/yoga-layout-prebuilt/yoga-layout/build/Release/nbind.js:53
         throw ex;
         ^
 TypeError: Cannot read properties of undefined (reading 'match')
     at onError (/home/iojs/tmp/citgm_tmp/13a08f5e-0713-4513-983d-261f65768bac/npm/node_modules/tap/bin/run.js:864:15)
     at /home/iojs/tmp/citgm_tmp/13a08f5e-0713-4513-983d-261f65768bac/npm/node_modules/tap/bin/run.js:141:34

[Trott]

@nodejs/npm

[BethGriggs]

I spent a while yesterday trying to remove the colour codes from the output. I thought adding "envVar": { "TAP_COLORS": 0 } in the lookup would be enough (commit). But, it didn't work and I am not sure why.

[ljharb]

TERM=dumb might do it?

[wraithgar]

No the forced color output in tests is much deeper than that. I spent a few days on it. Ended up with a failed draft PR about a month ago that I never was able to come back to. I also started consolidating color output in npm itself: npm/cli#4781, which is a step in the right direction but this probably isn't going to be feasible until we are a little further down the path of fixing our tests to use the real npm object instead of a fake object.

[targos]

This could be a cool solution: https://plugins.jenkins.io/ansicolor/

[BethGriggs]

This could be a cool solution: https://plugins.jenkins.io/ansicolor/

Thoughts @nodejs/citgm @nodejs/build?

I know adding any more plugins is 'yet another thing to update'. But, the last release was 8 months ago so I'm hopeful it wouldn't be too noisy/cause too much additional work.

[BethGriggs]

Stripping the codes, one of the errors:

error:                     | ​ FAIL ​ test/lib/commands/config.js                                      
error:                     |  ✖ output matches snapshot                                              
error:                     |                                                                         
error:                     |   test/lib/commands/config.js                                           
error:                     |   105 |   await sandbox.run('config', ['list', '--json'])               
error:                     |   106 |                                                                 
error:                     | > 107 |   t.matchSnapshot(sandbox.output, 'output matches snapshot')    
error:                     |       | ----^                                                           
error:                     |   108 | })                                                              
error:                     |   109 |                                                                 
error:                     |   110 | t.test('config list with publishConfig', async t => {           
error:                     |                                                                         
error:                     | --- expected                                                            
error:                     | +++ actual                                                              
error:                     | @@ -137,9 +137,9 @@                                                     
error:                     |    "strict-ssl": true,                                                  
error:                     |    "tag": "latest",                                                     
error:                     |    "tag-version-prefix": "v",                                           
error: error:              |    "timing": false,                                      
error:                     | -  "tmp": "{TMP}",                                       
error:                     | +  "tmp": "{NPMDIR}_config_tmp",                         
error:                     |    "umask": 0,                                           
error:                     |    "unicode": false,                                     
error:                     |    "update-notifier": true,                              
error:                     |    "usage": false,                 

[MylesBorins]

@BethGriggs I've shared in the internal CLI chat to get someone to take a look.

[BethGriggs]

I'm guessing this could be more a CITGM side-effect - it's likely we're setting different tmp directories in CITGM runs and the test suite assumes a more specific location. I didn't look/explore in detail though

[MylesBorins]

it seems like this is indeed an environment issue rather than a legit failure.