Repository navigation
Excessive npm log output in 4.x #57
Description
Activity
Yes, here is my rationale for changing this in the
iojsDocker Image a while back: nodejs/docker-iojs#36We've recently run into this excessive output when we started using node 4.2.x containers. The change looks like it goes back to the initial prep work for node 4.x images done by @chorrell (see e763a10).
Personally, it seems undesirable to override any defaults here. The default
loglevelinnpmis"warn", and to have it overridden to be"info"is unexpected and requires us to override it again in our own Dockerfiles.Reacted by Alex EllisThat's a fair point.
I'm fine with removing the loglevel setting if everyone else is.
Thoughts from @nodejs/docker team?
I disagree. npm operates under the assumption that you can always get to the npm log file.
Having read the
docker-iojsPR that @Starefossen links to above, I would still advocate for user education in the case of a failed package installation over dumping unnecessary information into the CI logs of the overwhelming majority ofdocker build/docker runjobs in the wild.At least document clearly how you can get the default behaviour back. Simple "npm config set loglevel warn" did not work for me, because the
NPM_CONFIG_LOGLEVELset in this image was overriding it. Instead, to get the default log level of "warn" back, you need to add:ENV NPM_CONFIG_LOGLEVEL warnto your own Dockerfile.
Reacted by Andreas Opferkuch, Akshay Pratap Singh and mbowles-sis-us@Starefossen I'm 👍 on
warnsincenpm-debug.logwill be lost when the container stops.We should document possible workarounds for places where this may not be ideal.
For example:
npm install --loglevel=warn > /var/log/npm.log 2>&1 || cat /var/log/npm.log && falsewill only print the log if the install fails.Reacted by David Steiman, Hoat Le and Delta-T+1 for removing this setting and using npm's default behavior.
From long experience with linux, c, and makefiles you want your builds and installs to be as verbose as possible so that you could have a propper log to work with when things fail. Since almost all of the npm stuff is network dependent, and just recently added consistent unpacking, you are not guaranteed that things will fail the same way next time you run (with a more verbose log level).
I believe this is just as true for Docker since often you do not have access to the
npm.log, and many containers are run withdocker run --rmwhich deletes the container after it exits regardless of the exit code.I also do not buy the argument about not being the default setting and hence it should not be in the image. We must be free to optimise the settings for the Docker runtime and the ways Docker is used different form other platforms.
From my investigation this is only really an issue on Travis CI which has a 4MB output limit travis-ci/travis-ci#1382.
@HackAttack could you elaborate why you would like to change the npm log level?
We must be free to optimise the settings for the Docker runtime and the ways Docker is used different form other platforms.
This goes against what I want as a Docker user. I want things to work the same, not differently. If certain things behave differently in the Docker environment than outside (in this case, the output from npm commands), that violates the principle of least astonishment and works against my use case for running Docker. If I want verbose logs I can specify the setting myself in my Dockerfile, but I expect the official image to have the same default behavior as the software itself, and this setting violates that expectation.
I also don't think it's appropriate to assume that a) verbose logs would always be desired on CI servers, or b) Docker is only or primarily being run on CI servers. I run Docker locally and it is unpleasant to have these logs in my console when I didn't ask for them.
Reacted by Steven, Marius Lundgård, JR Reynolds and Jared DeckardI don't have a preference on which log verbosity we use.
Would it be an improvement to have a line like:
ENV NPM_CONFIG_LOGLEVEL info # increase verbosity of log. NPM defaults to warnSo that it is obvious that is what needs to be changed if the user wants default behavior?
Instead of the current
ONBUILD RUN npm install --loglevel infoThis goes against what I want as a Docker user. I want things to work the same, not differently. If certain things behave differently in the Docker environment than outside (in this case, the output from npm commands), that violates the principle of least astonishment and works against my use case for running Docker.
The purpose of Docker is consistency, not similarity to the host OS. Unless you are running Debian on your host machine the Node.js application in the Docker Container will never behave exactly the same as running it on your local machine, but it will behave the same each time you run the container (hence consistency).
8 remaining items
- added a commit that references this issue
on Mar 4, 2016 Maybe a way to make everybody happy is to provide a way to mount an external npm config file
If you have a file that you use that has all the settings you are used to, you could mount it, if not, the defaults are used.
This would address the environment variable taking precedence.
I think you can already do this by copying in an npmrc file.
For me the issue is not clarity around how the settings are changed, but rather the fact that I have to change them at all to restore what is documented to be npm’s default behavior. In my opinion, official images for software packages should do only what’s necessary to get that software running—no more, no less—and not also make opinionated configuration tweaks.
Reacted by André Gaul, John Clark, Jonathan Glasmeyer, Chris Shepherd and Tapani Moilanen- added a commit that references this issue
on Apr 18, 2016 This was unexpected behaviour for us, took us a while to track it down.
From @mhart on twitter:
Wanna pull some files out of that container you just exited?
docker export | tar -cz --include='somedir/*' @- > somedir.tar.gz
https://twitter.com/hichaelmart/status/735219853926223872
This might let us explore reverting back to normal log levels and documenting this solution for recovering
.npm-debugfrom failed builds.Reacted by Christopher Horrell, Steven and Frederik Nordahl Jul SabroeJust double check before you do – my tweet was aimed at cases for when you've run and exited a container (not during a build)
From long experience with linux, c, and makefiles you want your builds and installs to be as verbose as possible so that you could have a proper log to work with when things fail.
@Starefossen The "warn" log level already outputs useful information when things fail. It is much harder to tell if thing succeeded and why things failed when I have to sift through the excessive output of the "info" logging level. I am having a hard time finding my own logging output, which makes false positives much harder to catch.
Reacted by Michael Hackner, Eugen Kiss, Gajus Kuizinas, Mariusz 'koder' Chwalba, Andrew Shaw Care and Frederik Nordahl Jul Sabroe@Starefossen @retrohacker You can easily retrieve files from a stopped docker container. Docker also keeps the stopped container if a build fails. So getting the npm-debug.log file from the container after a failed build should not be a problem.
Here an working workflow for getting npm-debug.log out of a failed build:
> docker ps -a CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES > docker images REPOSITORY TAG IMAGE ID CREATED SIZE node 7.3.0 d1699fb7d2bf 18 hours ago 659.8 MB > ls Dockerfile > cat Dockerfile FROM node:7.3.0 ENV NPM_CONFIG_LOGLEVEL warn RUN npm install this-package-should-not-exist > docker build . Sending build context to Docker daemon 2.048 kB Step 1 : FROM node:7.3.0 ---> d1699fb7d2bf Step 2 : ENV NPM_CONFIG_LOGLEVEL warn ---> Running in e73cbd3342a2 ---> da9b250b0b65 Removing intermediate container e73cbd3342a2 Step 3 : RUN npm install this-package-should-not-exist ---> Running in 11f68b09bbfd npm ERR! Linux 4.4.0-53-generic npm ERR! argv "/usr/local/bin/node" "/usr/local/bin/npm" "install" "this-package-should-not-exist" npm ERR! node v7.3.0 npm ERR! npm v3.10.10 npm ERR! code E404 npm ERR! 404 Registry returned 404 for GET on https://registry.npmjs.org/this-package-should-not-exist npm ERR! 404 npm ERR! 404 'this-package-should-not-exist' is not in the npm registry. npm ERR! 404 You should bug the author to publish it (or use the name yourself!) npm ERR! 404 npm ERR! 404 Note that you can also install from a npm ERR! 404 tarball, folder, http url, or git url. npm ERR! Please include the following file with any support request: npm ERR! /npm-debug.log The command '/bin/sh -c npm install this-package-should-not-exist' returned a non-zero code: 1 > docker ps -a CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 11f68b09bbfd da9b250b0b65 "/bin/sh -c 'npm inst" 13 seconds ago Exited (1) 10 seconds ago sharp_lichterman > docker cp 11f68b09bbfd:/npm-debug.log . > ls Dockerfile npm-debug.log > cat npm-debug.log 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 'this-package-should-not-exist' ] 2 info using npm@3.10.10 3 info using node@v7.3.0 ...You could also use
docker cp 11f68b09bbfd:/npm-debug.log -to output the contents directly to stdout or pipe it into some other command.Reacted by Steven and Mateusz Soltysik
When running NPM in the 4.x version of the docker image, the image runs with
ENV NPM_CONFIG_LOGLEVEL infoIs there any reason why this is not "warn" as is usually the default?
The log output is enough for Travis-CI to complain that the log output is too long.