Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

npm logging is too verbose / hard to parse #3295

Closed
tomquas opened this Issue · 3 comments

4 participants

@tomquas

if you look at the output below, i wonder how anybody could easily figure out a) that something went wrong, b) what went wrong.

$ npm install spdyproxy
npm http GET https://registry.npmjs.org/spdyproxy
npm http 200 https://registry.npmjs.org/spdyproxy
npm http GET https://registry.npmjs.org/spdyproxy/-/spdyproxy-0.2.4.tgz
npm http 200 https://registry.npmjs.org/spdyproxy/-/spdyproxy-0.2.4.tgz
npm http GET https://registry.npmjs.org/radius
npm http GET https://registry.npmjs.org/memory-cache
npm http GET https://registry.npmjs.org/spdy
npm http GET https://registry.npmjs.org/optimist
npm http GET https://registry.npmjs.org/colors
npm http 304 https://registry.npmjs.org/spdy
npm http 304 https://registry.npmjs.org/colors
npm http 200 https://registry.npmjs.org/memory-cache
npm http GET https://registry.npmjs.org/memory-cache/-/memory-cache-0.0.5.tgz
npm http 200 https://registry.npmjs.org/optimist
npm http 200 https://registry.npmjs.org/radius
npm http GET https://registry.npmjs.org/radius/-/radius-0.1.5.tgz
npm http 200 https://registry.npmjs.org/memory-cache/-/memory-cache-0.0.5.tgz
npm http 200 https://registry.npmjs.org/radius/-/radius-0.1.5.tgz
npm WARN engine radius@0.1.5: wanted: {"node":"0.8.x"} (current: {"node":"v0.10.1","npm":"1.2.15"})
npm http GET https://registry.npmjs.org/wordwrap
npm http 304 https://registry.npmjs.org/wordwrap
spdyproxy@0.2.4 ../node_modules/spdyproxy
├── memory-cache@0.0.5
├── colors@0.6.0-1
├── spdy@1.5.0
├── radius@0.1.5
└── optimist@0.3.5 (wordwrap@0.0.2)

suggestion 1: IMO loglevel = 'warn' should really be the default. all those GET / 200 logs seem irrelevant for a regular run. if i need them, i'd prefer to pass a --verbose or --debug parameter.

suggestion 2: why draw fancy trees when you can list dependencies in a one-liner? output could be parsed so much easier, for example, by my software distribution scripts. example:

this...
spdyproxy@0.2.4 ../node_modules/spdyproxy
├── memory-cache@0.0.5
├── colors@0.6.0-1
├── spdy@1.5.0
├── radius@0.1.5
└── optimist@0.3.5 (wordwrap@0.0.2)

could be...
spdyproxy@0.2.4 - memory-cache@0.0.5, colors@0.6.0-1, ...

or may even include status for simple parsing...
[ok] spdyproxy@0.2.4 - memory-cache@0.0.5, colors@0.6.0-1, ...

what do you think?

@mfncooper
Collaborator

On suggestion 1, npm used to work that way. Then many people complained because it seemed like it just sat there, doing nothing, for a really long time in some cases, before finally saying it was done. With the default logging level set to 'http' the way it is now, people get feedback as npm downloads each package, so that they know exactly what's going on, and are not staring at a tool that could have just hung up on them.

On suggestion 2, people can make sense of trees, even when the trees are complex. Take a package like yeoman, for example. Here's the output from npm install yeoman today:

yeoman@0.9.6 node_modules/yeoman
├── which@1.0.5
├── open@0.0.2
├── colors@0.6.0-1
├── mkdirp@0.3.5
├── faye-websocket@0.4.4
├── shelljs@0.0.9
├── request@2.9.203
├── coffee-script@1.3.3
├── html-minifier@0.4.5
├── fstream@0.1.22 (graceful-fs@1.2.0, inherits@1.0.0)
├── requirejs@2.0.6
├── es6-collections@0.2.0
├── tar@0.1.17 (inherits@1.0.0, block-stream@0.0.6)
├── rimraf@2.0.3 (graceful-fs@1.1.14)
├── grunt-contrib-coffee@0.3.2 (grunt-lib-contrib@0.3.1)
├── fstream-ignore@0.0.5 (inherits@1.0.0, minimatch@0.2.11)
├── clean-css@0.3.3 (optimist@0.1.9)
├── connect@2.2.2 (debug@0.7.2, qs@0.4.2, mime@1.2.4, formidable@1.0.9, crc@0.1.0)
├── grunt-jasmine-task@0.2.3 (temporary@0.0.5)
├── grunt-mocha@0.1.7 (growl@1.7.0, temporary@0.0.5)
├── cheerio@0.9.2 (entities@0.2.0, underscore@1.4.4, htmlparser2@2.6.0, cheerio-select@0.0.3)
├── yeoman-generators@0.9.5 (mime@1.2.9, diff@1.0.4, cheerio@0.10.8)
├── prompt@0.1.12 (async@0.1.22, pkginfo@0.3.0, winston@0.5.11)
├── bower@0.3.2 (stable@0.1.3, archy@0.0.2, semver@1.1.4, tmp@0.0.16, async@0.1.22, glob@3.1.21, nopt@2.0.0, vows@0.6.4, request@2.11.4, hogan.js@2.0.0, lodash@0.9.2, rc@0.0.8, read-package-json@0.1.13)
└── grunt@0.4.0a (dateformat@1.0.2-1.2.3, semver@1.0.14, hooker@0.2.3, async@0.1.22, nopt@1.0.10, temporary@0.0.5, underscore@1.3.3, underscore.string@2.1.1, uglify-js@1.2.6, glob-whatev@0.1.8, jshint@0.7.3, gzip-js@0.3.1, nodeunit@0.7.4)

I have a hard time imagining an even more condensed format than that, that is still readable and usable. A one-liner certainly wouldn't work.

Personally, I actually prefer the output from npm ls, since I can clearly see what I've got. However, given how verbose that is, I can understand why the output from install is rather more terse. With only yeoman installed, the output from npm ls looks like this:

/Users/me/somedir
└─┬ yeoman@0.9.6
  ├─┬ bower@0.3.2
  │ ├── archy@0.0.2
  │ ├── async@0.1.22
  │ ├─┬ glob@3.1.21
  │ │ ├── graceful-fs@1.2.0
  │ │ ├── inherits@1.0.0
  │ │ └─┬ minimatch@0.2.11
  │ │   ├── lru-cache@2.3.0
  │ │   └── sigmund@1.0.0
  │ ├── hogan.js@2.0.0
  │ ├── lodash@0.9.2
  │ ├─┬ nopt@2.0.0
  │ │ └── abbrev@1.0.4
  │ ├─┬ rc@0.0.8
  │ │ ├─┬ config-chain@0.3.3
  │ │ │ ├── ini@1.0.5
  │ │ │ └── proto-list@1.2.2
  │ │ └─┬ optimist@0.3.5
  │ │   └── wordwrap@0.0.2
  │ ├─┬ read-package-json@0.1.13
  │ │ ├── graceful-fs@1.2.0
  │ │ ├── lru-cache@2.0.4
  │ │ ├─┬ npmlog@0.0.2
  │ │ │ └── ansi@0.1.2
  │ │ └── slide@1.1.3
  │ ├─┬ request@2.11.4
  │ │ ├─┬ form-data@0.0.3
  │ │ │ ├── async@0.1.9
  │ │ │ └─┬ combined-stream@0.0.3
  │ │ │   └── delayed-stream@0.0.5
  │ │ └── mime@1.2.7
  │ ├── semver@1.1.4
  │ ├── stable@0.1.3
  │ ├── tmp@0.0.16
  │ └─┬ vows@0.6.4
  │   ├── diff@1.0.4
  │   └── eyes@0.1.8
  ├─┬ cheerio@0.9.2
  │ ├─┬ cheerio-select@0.0.3
  │ │ └─┬ CSSselect@0.3.1
  │ │   └── CSSwhat@0.1.1
  │ ├── entities@0.2.0
  │ ├─┬ htmlparser2@2.6.0
  │ │ ├── domelementtype@1.1.1
  │ │ ├── domhandler@2.0.2
  │ │ └── domutils@1.0.1
  │ └── underscore@1.4.4
  ├─┬ clean-css@0.3.3
  │ └── optimist@0.1.9
  ├── coffee-script@1.3.3
  ├── colors@0.6.0-1
  ├─┬ connect@2.2.2
  │ ├── crc@0.1.0
  │ ├── debug@0.7.2
  │ ├── formidable@1.0.9
  │ ├── mime@1.2.4
  │ └── qs@0.4.2
  ├── es6-collections@0.2.0
  ├── faye-websocket@0.4.4
  ├─┬ fstream@0.1.22
  │ ├── graceful-fs@1.2.0
  │ └── inherits@1.0.0
  ├─┬ fstream-ignore@0.0.5
  │ ├── inherits@1.0.0
  │ └─┬ minimatch@0.2.11
  │   ├── lru-cache@2.3.0
  │   └── sigmund@1.0.0
  ├─┬ grunt@0.4.0a
  │ ├── async@0.1.22
  │ ├── dateformat@1.0.2-1.2.3
  │ ├─┬ glob-whatev@0.1.8
  │ │ └─┬ minimatch@0.2.11
  │ │   ├── lru-cache@2.3.0
  │ │   └── sigmund@1.0.0
  │ ├─┬ gzip-js@0.3.1
  │ │ ├── crc32@0.2.2
  │ │ └── deflate-js@0.2.2
  │ ├── hooker@0.2.3
  │ ├─┬ jshint@0.7.3
  │ │ ├─┬ cli@0.4.3
  │ │ │ └─┬ glob@3.1.21
  │ │ │   ├── graceful-fs@1.2.0
  │ │ │   ├── inherits@1.0.0
  │ │ │   └─┬ minimatch@0.2.11
  │ │ │     ├── lru-cache@2.3.0
  │ │ │     └── sigmund@1.0.0
  │ │ └─┬ minimatch@0.0.5
  │ │   └── lru-cache@1.0.6
  │ ├─┬ nodeunit@0.7.4
  │ │ └─┬ tap@0.4.1
  │ │   ├── buffer-equal@0.0.0
  │ │   ├── deep-equal@0.0.0
  │ │   ├─┬ difflet@0.2.3
  │ │   │ ├── charm@0.0.8
  │ │   │ └── traverse@0.6.3
  │ │   ├─┬ glob@3.1.21
  │ │   │ ├── graceful-fs@1.2.0
  │ │   │ ├── inherits@1.0.0
  │ │   │ └─┬ minimatch@0.2.11
  │ │   │   ├── lru-cache@2.3.0
  │ │   │   └── sigmund@1.0.0
  │ │   ├── inherits@1.0.0
  │ │   ├─┬ nopt@2.1.1
  │ │   │ └── abbrev@1.0.4
  │ │   ├─┬ runforcover@0.0.2
  │ │   │ └─┬ bunker@0.1.2
  │ │   │   └─┬ burrito@0.2.12
  │ │   │     ├── traverse@0.5.2
  │ │   │     └── uglify-js@1.1.1
  │ │   ├── slide@1.1.3
  │ │   └── yamlish@0.0.5
  │ ├─┬ nopt@1.0.10
  │ │ └── abbrev@1.0.4
  │ ├── semver@1.0.14
  │ ├─┬ temporary@0.0.5
  │ │ └── package@1.0.1
  │ ├── uglify-js@1.2.6
  │ ├── underscore@1.3.3
  │ └── underscore.string@2.1.1
  ├─┬ grunt-contrib-coffee@0.3.2
  │ └── grunt-lib-contrib@0.3.1
  ├─┬ grunt-jasmine-task@0.2.3
  │ └─┬ temporary@0.0.5
  │   └── package@1.0.1
  ├─┬ grunt-mocha@0.1.7
  │ ├── growl@1.7.0
  │ └─┬ temporary@0.0.5
  │   └── package@1.0.1
  ├── html-minifier@0.4.5
  ├── mkdirp@0.3.5
  ├── open@0.0.2
  ├─┬ prompt@0.1.12
  │ ├── async@0.1.22
  │ ├── pkginfo@0.3.0
  │ └─┬ winston@0.5.11
  │   ├── eyes@0.1.8
  │   ├─┬ loggly@0.3.11
  │   │ └── timespan@2.2.0
  │   ├── pkginfo@0.2.3
  │   └── stack-trace@0.0.6
  ├── request@2.9.203
  ├── requirejs@2.0.6
  ├─┬ rimraf@2.0.3
  │ └── graceful-fs@1.1.14
  ├── shelljs@0.0.9
  ├─┬ tar@0.1.17
  │ ├── block-stream@0.0.6
  │ └── inherits@1.0.0
  ├── which@1.0.5
  └─┬ yeoman-generators@0.9.5
    ├─┬ cheerio@0.10.8
    │ ├─┬ cheerio-select@0.0.3
    │ │ └─┬ CSSselect@0.3.1
    │ │   └── CSSwhat@0.1.1
    │ ├── entities@0.2.0
    │ ├─┬ htmlparser2@2.6.0
    │ │ ├── domelementtype@1.1.1
    │ │ ├── domhandler@2.0.2
    │ │ └── domutils@1.0.1
    │ └── underscore@1.4.4
    ├── diff@1.0.4
    └── mime@1.2.9
@Zearin

I also think loglevel should default to warn. If people complained that they thought npm wasn’t doing anything, there are better ways to resolve that than filling up the terminal with screens of :

...
info trying registry request attempt 1 at 11:27:27
http GET https://registry.npmjs.org/xxxxxxx
...

Suggestions

Just through out some ideas. Take some or all of them. Modify them. Season to taste. (Or not.)

Show a "spinner" for lengthy commands

Where | is the text "spinner" indicator (character that "animates" through the loop: |, /, -, \)

Print higher-level, more general info

Taking npm -g up as an example, npm prints something like the following:

npm checking for updates to 42 globally installed packages...

(Optionally add a "spinner" on the next line. I like them; they’re small and unobtrusive, but are super helpful to communicate that the program is busy doing something.)

Progress bar

Personally I’m not crazy about this idea, but maybe some people would like it…

Npm could display a progress bar (á la curl --progress), indicating the completed/pending status of the actions needed to run the currently executing command.

@isaacs
Owner

Well, there are some ok ideas here, some of which are incredibly hard to do since npm parallelizes a lot of things (unlike curl or apt-get), and some of which are not very hard, but non-trivial, and would not please everyone anyway.

So, I'll just say, "patches welcome", but the default won't change any time soon, mostly because there are much bigger problems to try to solve. The output is optimized for making my life easier when people report bugs and weird behavior, so any change would have to make that use case better (or at least, not worse).

@isaacs isaacs closed this
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.