Unhandled rejection TypeError: Cannot read property '0.0.3' of undefined

[lifeisfoo]

After a local node/npm update, it's impossible to use the register.

I'm using filesystem storage.

Current node/npm version:

$ node -v                                                                       
v8.1.2
$ npm -v
6.3.0

If I run a npm info command I receive an error:

$ npm info @my-org/npm-package-example --registry http://my-server-ip-address --verbose
npm info it worked if it ends with ok
npm verb cli [ '/Users/alessandro/.nvm/versions/node/v8.1.2/bin/node',
npm verb cli   '/Users/alessandro/.nvm/versions/node/v8.1.2/bin/npm',
npm verb cli   'info',
npm verb cli   '@my-org/npm-package-example',
npm verb cli   '--registry',
npm verb cli   'http://my-server-ip-address',
npm verb cli   '--verbose' ]
npm info using npm@6.3.0
npm info using node@v8.1.2
npm verb request uri http://my-server-ip-address/@my-org%2fnpm-package-example
npm verb request no auth needed
npm info attempt registry request try #1 at 17:52:14
npm verb request using bearer token for auth
npm verb request id 12629f31ea6a79ac
npm http request GET http://my-server-ip-address/@my-org%2fnpm-package-example
npm http 200 http://my-server-ip-address/@my-org%2fnpm-package-example
npm verb headers { 'x-powered-by': 'Express',
npm verb headers   etag: '0.7451181132695863',
npm verb headers   'cache-control': 'public, max-age=60',
npm verb headers   'content-type': 'application/json; charset=utf-8',
npm verb headers   vary: 'Accept-Encoding',
npm verb headers   'content-encoding': 'gzip',
npm verb headers   date: 'Wed, 08 Aug 2018 15:52:16 GMT',
npm verb headers   connection: 'keep-alive',
npm verb headers   'transfer-encoding': 'chunked' }
npm verb stack TypeError: Cannot read property '0.0.3' of undefined
npm verb stack     at BB.try (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:222:57)
npm verb stack     at tryCatcher (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/bluebird/js/release/util.js:16:23)
npm verb stack     at Function.Promise.attempt.Promise.try (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/bluebird/js/release/method.js:39:29)
npm verb stack     at prettyView (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:186:16)
npm verb stack     at BB.all.results.map (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:173:35)
npm verb stack     at Array.map (native)
npm verb stack     at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:173:24
npm verb stack     at f (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/once/once.js:25:25)
npm verb stack     at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:78:16
npm verb stack     at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:105:12
npm verb stack     at f (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/once/once.js:25:25)
npm verb stack     at RegClient.<anonymous> (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:311:12)
npm verb stack     at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:222:7
npm verb stack     at Gunzip.onEnd (zlib.js:130:5)
npm verb stack     at emitNone (events.js:110:20)
npm verb stack     at Gunzip.emit (events.js:207:7)
npm verb cwd /Users/alessandro/Dev/my-org/dashboard
npm verb Darwin 17.6.0
npm verb argv "/Users/alessandro/.nvm/versions/node/v8.1.2/bin/node" "/Users/alessandro/.nvm/versions/node/v8.1.2/bin/npm" "info" "@my-org/npm-package-example" "--registry" "http://my-server-ip-address" "--verbose"
npm verb node v8.1.2
npm verb npm  v6.3.0
npm ERR! Cannot read property '0.0.3' of undefined
npm verb exit [ 1, true ]
Unhandled rejection TypeError: Cannot read property '0.0.3' of undefined
    at BB.try (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:222:57)
    at tryCatcher (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/bluebird/js/release/util.js:16:23)
    at Function.Promise.attempt.Promise.try (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/bluebird/js/release/method.js:39:29)
    at prettyView (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:186:16)
    at BB.all.results.map (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:173:35)
    at Array.map (native)
    at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/lib/view.js:173:24
    at f (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/once/once.js:25:25)
    at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:78:16
    at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:105:12
    at f (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/once/once.js:25:25)
    at RegClient.<anonymous> (/Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:311:12)
    at /Users/alessandro/.nvm/versions/node/v8.1.2/lib/node_modules/npm/node_modules/npm-registry-client/lib/request.js:222:7
    at Gunzip.onEnd (zlib.js:130:5)
    at emitNone (events.js:110:20)
    at Gunzip.emit (events.js:207:7)

npm timing npm Completed in 2138ms

npm ERR! A complete log of this run can be found in:
npm ERR!     /Users/alessandro/.npm/_logs/2018-08-08T15_52_16_232Z-debug.log

Server log

1|npm-regi | TypeError: Cannot read property 'code' of undefined
1|npm-regi |     at allowed (/usr/lib/node_modules/npm-register/node_modules/http-call/lib/http.js:240:22)
1|npm-regi |     at HTTP._maybeRetry (/usr/lib/node_modules/npm-register/node_modules/http-call/lib/http.js:246:13)
1|npm-regi |     at HTTP._request (/usr/lib/node_modules/npm-register/node_modules/http-call/lib/http.js:207:25)
1|npm-regi |     at <anonymous>
1|npm-regi |     at process._tickDomainCallback (internal/process/next_tick.js:228:7)

If I downgrade my local node/npm to 8.0.0/5.0.0, everything works:

$ npm info @my-org/npm-package-example --registry http://my-server-ip-address --verbose
npm info it worked if it ends with ok
npm verb cli [ '/Users/alessandro/.nvm/versions/node/v8.0.0/bin/node',
npm verb cli   '/Users/alessandro/.nvm/versions/node/v8.0.0/bin/npm',
npm verb cli   'info',
npm verb cli   '@my-org/npm-package-example',
npm verb cli   '--registry',
npm verb cli   'http://my-server-ip-address',
npm verb cli   '--verbose' ]
npm info using npm@5.0.0
npm info using node@v8.0.0
npm verb request uri http://my-server-ip-address/@my-org%2fnpm-package-example
npm verb request no auth needed
npm info attempt registry request try #1 at 13:02:01
npm verb request using bearer token for auth
npm verb request id 031db07bdc554fca
npm http request GET http://my-server-ip-address/@my-org%2fnpm-package-example
npm http 200 http://my-server-ip-address/@my-org%2fnpm-package-example
npm verb headers { 'x-powered-by': 'Express',
npm verb headers   etag: '0.7451181132695863',
npm verb headers   'cache-control': 'public, max-age=60',
npm verb headers   'content-type': 'application/json; charset=utf-8',
npm verb headers   vary: 'Accept-Encoding',
npm verb headers   'content-encoding': 'gzip',
npm verb headers   date: 'Thu, 09 Aug 2018 11:02:02 GMT',
npm verb headers   connection: 'keep-alive',
npm verb headers   'transfer-encoding': 'chunked' }
 
{ name: '@my-org/npm-package-example',
  description: 'Private npm package',
  'dist-tags': { latest: '0.0.3' },
  versions: 
   [ '0.0.3',
     '1.0.1',
     '2.0.0',
     '2.0.1',
     '2.1.0',
     '2.1.1',
     '2.1.2',
     '2.1.4',
     '2.1.5',
     '2.1.6' ],
  etag: '0.7451181132695863',
  version: '0.0.3',
  main: 'index.js',
  scripts: { test: 'echo "Error: no test specified" && exit 1' },
  repository: 
   { type: 'git',
     url: 'git+https://github.com/my-org-io/npm-package-example.git' },
  author: '',
  license: 'ISC',
  bugs: { url: 'https://github.com/my-org-io/npm-package-example/issues' },
  homepage: 'https://github.com/my-org-io/npm-package-example#readme',
  readme: 'npm-package-example readme content',
  readmeFilename: 'README.md',
  dist: 
   { integrity: 'sha512-20Z8vHSUHyjpBGM8Oi1xeUUWCQRtKLz0esqHCcqxmfHhOx5bgLcGY8Ez9pOdA/rfXpd2wMNk3dLI6vWJWHdB8g==',
     shasum: '69048f400957d07de39de4d6524143886dc434ac',
     tarball: 'http://my-server-ip-address/@my-org/npm-package-example/-/@my-org/npm-package-example-0.0.3/69048f400957d07de39de4d6524143886dc434ac.tgz' } }

npm verb exit [ 0, true ]
npm info ok 

[dgautsch]

@lifeisfoo i'll have to investigate this evening. thanks for surfacing.

[lifeisfoo]

I've done some exploration of this bug and I've found that TypeError: Cannot read property 'code' of undefined in the error log above should not be related to this. This is the code from http-call lib:

    async _request() {
        this._debugRequest();
        try {
            this.response = await this._performRequest();
        }
        catch (err) {
            debug(err);
            return this._maybeRetry(err); <<<--- line 207
        }
        if (this._shouldParseResponseBody)
            await this._parse();
        this._debugResponse();
        if (this._responseRedirect)
            return this._redirect();
        if (!this._responseOK) {
            throw new HTTPError(this);
        }
        if (!this.partial)
            await this._getNextRange();
    }

    async _maybeRetry(err) {
        this._errorRetries++;
        const allowed = (err) => {
            if (this._errorRetries > 5)
                return false;
            if (!err.code)  <<<---- line 240
                return false;
            if (err.code === 'ENOTFOUND')
                return true;
            return require('is-retry-allowed')(err);
        };
        if (allowed(err)) {    <<<--- line 246
            let noise = Math.random() * 100;
            // tslint:disable-next-line
            await this._wait((1 << this._errorRetries) * 100 + noise);
            await this._request();
            return;
        }
        throw err;
    }

Yes, it's strange that the err object doesn't have the code property, maybe it's related to #99 ?
Probably this error arise when the registry receive wrong/malformed/bot requests, but this is only a speculation.

The real bug

What I've found is that the npm cli lib with this commit replaced the printData function with the new prettyView.

Inside this function the package object is referenced by the packument variable, and the actual error is thrown by this line:

modified: color.yellow(relativeDate(packument.time[packument.version])),

This is caused by the time field available in the official npm registry but that is missing in npm-register hosted packages:

npm-register package object inside the prettyView function:

{ _id: '@my-org/npm-package-example',
  name: '@my-org/npm-package-example',
  description: 'Private package',
  'dist-tags': { latest: '0.0.3' },
  versions: 
   [ '0.0.3',
     '1.0.1',
     '2.0.0',
     '2.0.1',
     '2.1.0',
     '2.1.1',
     '2.1.2',
     '2.1.4',
     '2.1.5',
     '2.1.6' ],
  etag: '0.7451181132695863',
  _etag: '0.7451181132695863',
  version: '2.1.6' }

official npm registry package object inside the prettyView function:

{ _id: 'hbs',
  _rev: '171-12c8a60348a0050ef874cbcacec403e7',
  name: 'hbs',
  description: 'Express.js template engine plugin for Handlebars',
  'dist-tags': { latest: '4.0.1' },
  versions: 
   [ '0.0.2-1',
     '0.0.2-2',
     '0.0.2-3',
     //... cut
     '3.1.1',
     '4.0.0',
     '4.0.1' ],
  maintainers: 
   [ { name: 'donpark', email: 'donpark@docuverse.com' },
     { name: 'defunctzombie', email: 'shtylman@gmail.com' } ],
  author: 
   { name: 'Don Park',
     email: 'donpark@docuverse.com',
     url: 'http://blog.docuverse.com' },
  time: 
   { modified: '2018-03-11T06:14:50.842Z',
     created: '2011-01-20T00:16:20.795Z',
     '0.0.2-1': '2011-01-20T00:16:20.795Z',
     '0.0.2-2': '2011-01-20T00:16:20.795Z',
     '0.0.2-3': '2011-01-20T00:16:20.795Z',
     '0.0.3': '2011-01-20T00:16:20.795Z',
     //... cut
     '3.1.1': '2015-09-11T19:05:20.412Z',
     '4.0.0': '2015-11-02T15:40:24.179Z',
     '4.0.1': '2016-09-18T20:35:23.622Z' },
  users: 
   { fgribreau: true,
     pid: true,
     //... cut
     },
  repository: { type: 'git', url: 'git://github.com/pillarjs/hbs.git' },
  readmeFilename: 'Readme.md',
  homepage: 'https://github.com/pillarjs/hbs',
  bugs: { url: 'https://github.com/pillarjs/hbs/issues' },
  license: 'MIT',
  _attachments: {},
  _etag: 'W/"1b870924c23e6d9f12be2e8dc6e04978"',
  _lastModified: 'Sun, 27 May 2018 03:37:01 GMT',
  version: '4.0.1' }

Workaround

As you can see from the commit diff above, it's actually possible to use the "old" printData function just changing the npm json config variaible:

npm config set json true

In this way npm will not try to prettyView the package but print it as raw json instead.

Registry response diff

I attach here the output from the npm-registry-client.get function: I hope thery're useful for further debugging.

npm-register

{ _id: '@my-org/npm-package-example',
  name: '@my-org/npm-package-example',
  description: 'private package...',
  'dist-tags': { latest: '0.0.3' },
  versions: 
   { //cut...
     '2.1.6': 
      { name: '@my-org/npm-package-example',
        version: '2.1.6',
        description: 'private package...',
        main: 'index.js',
        scripts: [Object],
        repository: [Object],
        author: '',
        license: 'ISC',
        bugs: [Object],
        homepage: 'https://github.com/my-org-io/npm-package-example#readme',
        readme: 'private package...',
        readmeFilename: 'README.md',
        _id: '@my-org/npm-package-example@2.1.6',
        _npmVersion: '5.6.0',
        _nodeVersion: '8.11.3',
        _npmUser: {},
        dist: [Object] },
     '0.0.3': 
      { name: '@my-org/npm-package-example',
        version: '0.0.3',
        description: 'Private package',
        main: 'index.js',
        scripts: [Object],
        repository: [Object],
        author: '',
        license: 'ISC',
        bugs: [Object],
        homepage: 'https://github.com/my-org-io/npm-package-example#readme',
        readme: 'my private package...',
        readmeFilename: 'README.md',
        _id: '@my-org/npm-package-example@0.0.3',
        _npmVersion: '5.6.0',
        _nodeVersion: '8.11.3',
        _npmUser: {},
        dist: [Object] } },
  readme: 'my private package...',
  etag: '0.7451181132695863',
  _etag: '0.7451181132695863' }

official npm registry

{ _id: 'hbs',
  _rev: '171-12c8a60348a0050ef874cbcacec403e7',
  name: 'hbs',
  description: 'Express.js template engine plugin for Handlebars',
  'dist-tags': { latest: '4.0.1' },
  versions: 
   { '0.0.2-1': 
      { name: 'hbs',
        description: 'Express.js template engine plugin for Handlebars',
        version: '0.0.2-1',
        homepage: 'https://github.com/donpark/hbs',
        author: [Object],
        directories: [Object],
        engines: [Object],
        _id: 'hbs@0.0.2-1',
        _nodeSupported: true,
        _npmVersion: '0.2.10',
        _nodeVersion: 'v0.3.1',
        dist: [Object] },
     // ... cut
     '4.0.1': 
      { name: 'hbs',
        description: 'Express.js template engine plugin for Handlebars',
        version: '4.0.1',
        homepage: 'https://github.com/pillarjs/hbs',
        author: [Object],
        main: 'lib/hbs.js',
        directories: [Object],
        dependencies: [Object],
        devDependencies: [Object],
        license: 'MIT',
        scripts: [Object],
        engines: [Object],
        repository: [Object],
        gitHead: '1047eb2cd67efbf1f50786f143853a37653ff7fb',
        bugs: [Object],
        _id: 'hbs@4.0.1',
        _shasum: '4bfd98650dc8c9dac44b3ca9adf9c098e8bc33b6',
        _from: '.',
        _npmVersion: '3.8.9',
        _nodeVersion: '6.2.0',
        _npmUser: [Object],
        dist: [Object],
        maintainers: [Array],
        _npmOperationalInternal: [Object] } },
  maintainers: 
   [ { name: 'donpark', email: 'donpark@docuverse.com' },
     { name: 'defunctzombie', email: 'shtylman@gmail.com' } ],
  author: 
   { name: 'Don Park',
     email: 'donpark@docuverse.com',
     url: 'http://blog.docuverse.com' },
  time: 
   { modified: '2018-03-11T06:14:50.842Z',
     created: '2011-01-20T00:16:20.795Z',
     '0.0.2-1': '2011-01-20T00:16:20.795Z',
     // ... cut
     '4.0.1': '2016-09-18T20:35:23.622Z' },
  users: 
   { fgribreau: true,
     pid: true,
     // .. cut
     },
  repository: { type: 'git', url: 'git://github.com/pillarjs/hbs.git' },
  readme: '.... cut',
  readmeFilename: 'Readme.md',
  homepage: 'https://github.com/pillarjs/hbs',
  bugs: { url: 'https://github.com/pillarjs/hbs/issues' },
  license: 'MIT',
  _attachments: {},
  _etag: 'W/"1b870924c23e6d9f12be2e8dc6e04978"',
  _lastModified: 'Sun, 27 May 2018 03:37:01 GMT' }

[dgautsch]

@lifeisfoo thanks for looking into this further, lots of fantastic info. I'm working my way through the issue queue and have this one in my sights.

[dgautsch]

@lifeisfoo this should be fixed with v2.8.1

[lifeisfoo]

Hi @dgautsch I've tested today v2.8.2, but I got the same error.