npm@5 does not fail gracefully on malformed Vary response header from registry

[LINKIWI]

This issue was originally opened against npm/npm at npm/npm#18208 but I believe the scope of the problem applies only to make-fetch-happen, so I am moving it here.

Core problem
The npm v5 client fails on cached installs if the original response (which was stored in the cache) contains a malformed HTTP Vary header.

Symptom
Installations for any package will reliably fail on subsequent installs after its tarball response has been cached locally by npm on the first install.

0 info it worked if it ends with ok
1 verbose cli [ '/usr/local/bin/node',
1 verbose cli   '/usr/local/bin/npm',
1 verbose cli   'install',
1 verbose cli   'express' ]
2 info using [email protected]
3 info using [email protected]
4 verbose npm-session db7d4aaea503bc0c
5 silly install loadCurrentTree
6 silly install readLocalPackageData
7 silly fetchPackageMetaData error for express@latest User-Agent) is not a legal HTTP header name
8 verbose stack TypeError: User-Agent) is not a legal HTTP header name
8 verbose stack     at sanitizeName (/usr/local/lib/node_modules/npm/node_modules/pacote/node_modules/make-fetch-happen/node_modules/node-fetch-npm/src/headers.js:16:11)
8 verbose stack     at Headers.get (/usr/local/lib/node_modules/npm/node_modules/pacote/node_modules/make-fetch-happen/node_modules/node-fetch-npm/src/headers.js:106:28)
8 verbose stack     at vary.split.every.field (/usr/local/lib/node_modules/npm/node_modules/pacote/node_modules/make-fetch-happen/cache.js:229:34)
8 verbose stack     at Array.every (<anonymous>)
8 verbose stack     at matchDetails (/usr/local/lib/node_modules/npm/node_modules/pacote/node_modules/make-fetch-happen/cache.js:228:49)
8 verbose stack     at cacache.get.info.then.then.info (/usr/local/lib/node_modules/npm/node_modules/pacote/node_modules/make-fetch-happen/cache.js:49:36)
8 verbose stack     at tryCatcher (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/util.js:16:23)
8 verbose stack     at Promise._settlePromiseFromHandler (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:512:31)
8 verbose stack     at Promise._settlePromise (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:569:18)
8 verbose stack     at Promise._settlePromise0 (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:614:10)
8 verbose stack     at Promise._settlePromises (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:693:18)
8 verbose stack     at Promise._fulfill (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:638:18)
8 verbose stack     at Promise._resolveCallback (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:432:57)
8 verbose stack     at Promise._settlePromiseFromHandler (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:524:17)
8 verbose stack     at Promise._settlePromise (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:569:18)
8 verbose stack     at Promise._settlePromise0 (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promise.js:614:10)
9 verbose cwd /home/kiwi/Downloads/temp
10 verbose Linux 4.4.0-91-generic
11 verbose argv "/usr/local/bin/node" "/usr/local/bin/npm" "install" "express"
12 verbose node v8.4.0
13 verbose npm  v5.3.0
14 error User-Agent) is not a legal HTTP header name
15 verbose exit [ 1, true ]

Root cause flow
0. The registry in use is not registry.npmjs.org, but a self-hosted one; in this case, a Sinopia instance behind an Apache reverse proxy

1. When installing a package, the npm registry sends back an HTTP header Vary: Accept-Encoding,User-Agent) in the response for a request for a package tarball
2. The npm client successfully installs this package and places it in the local cache
3. On a subsequent install of the same package, when parsing the cached response payload from the local cache, make-fetch-happen ensures that each of the cached header values specified by Vary matches that in the request payload before attempting to use the cached response. This behavior is correct and in accordance with HTTP spec.
4. When reading the cached header value, node-fetch-npm throws because one of the comma-delimited header names, User-Agent), is malformed and invalid.
5. The npm client aborts installation with the error propagated to the highest level with the stack trace seen above.

Reproduction steps
Since this error surfaces only because of a self-hosted npm registry, the easiest way to reproduce this is to insert a proxy between the npm client and any registry (e.g. registry.npmjs.org) and forcefully inject/modify a malformed response header.

1. The intermediary proxy should be configured to modify the response Vary header to be Vary: Accept-Encoding,User-Agent)
2. npm cache clean --force
3. npm --proxy=http://localhost:<proxy port> install express - no errors!
4. npm --proxy=http://localhost:<proxy port> install express a second time - error User-Agent) is not a legal HTTP header name and exit nonzero.

"This is not a problem with npm, but a problem with your server"
Yes, I agree. Some unfortunate combination of my Apache version, Sinopia version, and various configuration files causes Apache to respond with a malformed response header.

However, it is still my opinion that the npm client should handle this condition gracefully, and not forcefully exit 1.

I would love to contribute to npm to fix this bug, but would appreciate guidance as to which level this fix should be performed. My opinion is that

make-fetch-happen/cache.js

Line 229 in 800a8e5

return cached.reqHeaders.get(field) === req.headers.get(field)

should safely req.headers.get - e.g. catching the possible TypeError and skipping the malformed header.

[zkat]

Thanks for the thorough report! Would you like to give a patch a shot? I'm not sure what the exact right place to fix this is, either. It's interesting that this only happens when you're dealing with cached stuff, which makes me suspect you're right -- otherwise, my prime suspect would be node-fetch-npm.

Your suggestion about catching things seems reasonable, though TypeError without any further checks feels a bit heavy-handed for this sort of task?

Anyway, give it a whirl, and thank you again!

[LINKIWI]

Hm, I agree that blind-catching a TypeError feels heavy handed, but the logic path invoked by req.headers.get is quite short and the scope for the try-catch seems limited. I think this is a reasonable solution. I'll give this patch a try and see what I can come up with. Thanks for your input!

[zkat]

@LINKIWI I'm more wondering why the heck Headers even errors on a read. It's just plain weird to me?

[LINKIWI]

@zkat Just a heads up - I've opened npm/node-fetch-npm#7 to address this, whenever you get a chance to take a look