travis-ci/travis-ci

`npm install` step doesn't show any output.

Qix- opened this issue Β· 36 comments

Qix- commented

So something changed in Travis recently and broke a lot of Chalk's builds. I'm trying to remediate the situation, but I can't see any of the package versions that were installed.

screen shot 2017-06-28 at 11 29 08 pm

As it stands, all of our tests are inexplicably broken with very little information to go on. We can't reproduce locally and the first step is checking package versions.

I'm going to revert using the group: workaround as an emergency fix, but could we get some warning and an opt-in next time? I just wasted a few hours trying to figure out why the unchanged tests that shouldn't have been affected by a PR are all of a sudden breaking on CI.

Qix- commented

Welp, the group: setting didn't work.

Do you have a build log URL that shows the problem you are describing here?

"npm WARN depcreated …" is coming from npm install, so I am unsure what you think is missing.

Qix- commented

@BanzaiMan The entire list of packages that should be showing up between lines 127 and 128 in the screenshot.

https://travis-ci.org/chalk/chalk/jobs/248230015 - expand npm install and you'll see what's in the screenshot.

So, https://travis-ci.org/chalk/chalk/jobs/248527902#L127 shows that the output is there for Node.js 6.11.0, but not for Node.js 8.1.3 (https://travis-ci.org/chalk/chalk/jobs/248527901#L125). This seems like a change in Node.js 8, so I suggest talking to them instead.

Qix- commented

@BanzaiMan This hasn't anything to do with Node versions. If anything, it's NPM. Either way, this is something you need to figure out on your end..

Apologies for being curt, but this is almost definitely a Travis CI issue.

I just tested this on my Mac.

strokkur[~/Development/tmp]$ uname -a
Darwin strokkur 15.6.0 Darwin Kernel Version 15.6.0: Tue Apr 11 16:00:51 PDT 2017; root:xnu-3248.60.11.5.3~1/RELEASE_X86_64 x86_64
strokkur[~/Development/tmp]$ git clone --depth=50 --branch=tags https://github.com/chalk/chalk.git chalk/chalk
Cloning into 'chalk/chalk'...
remote: Counting objects: 206, done.
remote: Compressing objects: 100% (131/131), done.
remote: Total 206 (delta 123), reused 148 (delta 72), pack-reused 0
Receiving objects: 100% (206/206), 93.51 KiB | 0 bytes/s, done.
Resolving deltas: 100% (123/123), done.
Checking connectivity... done.
strokkur[~/Development/tmp]$ cd chalk/chalk
strokkur[~/Development/tmp/chalk/chalk]$ nvm install 8
VERSION_PATH=''
######################################################################## 100.0%
Computing checksum with shasum -a 256
Checksums matched!
Now using node v8.1.3 (npm v5.0.3)
strokkur[~/Development/tmp/chalk/chalk]$ npm --version
5.0.3
strokkur[~/Development/tmp/chalk/chalk]$ npm install
npm WARN deprecated electron@0.4.1: The original electron project has been moved. Visit github.com/logicalparadox/electron for more details.
npm notice created a lockfile as package-lock.json. You should commit this file.
added 610 packages in 37.684s

I don't get the output with Node.js 8.

You are right about npm version, though. If I start out with Node.js 7 and npm 4.1.2, I get the dependency output, but if I update npm to 5.0.4, the dependency tree disappears.

https://github.com/npm/npm/blob/latest/CHANGELOG.md

  • npm no longer blasts your screen with the whole installed tree. Instead, you'll see a summary report of the install that is much kinder on your shell real-estate. Specially for large projects.
Qix- commented

You need to add the npm ls command after you run npm install on Travis. Please re-open this.

I updated the change log item that I initially pasted incorrectly.

I believe this is an npm issue.

Qix- commented

This is not an NPM issue. They explicitly removed the package listing upon install. It was an intentional change.

Travis should list the packages it installs. It is invaluable to debugging when unexpected errors occur. I need to know what Travis is installing when it pulls packages down to run my tests.

Travis should have different prioritizes than npm defaults. npm by default targets end-users. Travis should, as @Qix- said, be as easily debuggable as possible.

I see. You are asking to override the default NPM 5 behavior.

Qix- commented

Please just add one more step after npm install that runs npm ls.

If that is "just" what you want, you can always add that yourself. The general solution would be a little more complex, I'm afraid.

Thanks for the report.

Qix- commented

You're missing the point here, @BanzaiMan. We shouldn't have to add these things. This is functionality we relied upon in Travis to do our job, across the board. This is information that should always be included.

If you decide not to add this I'll have no choice but to move my packages to another CI solution.

I think Travis just needs to change the log level to verbose: https://docs.npmjs.com/misc/config#loglevel

Does anyone know what the previous default log level is? The documentation mentioned above says the valid values are silent, error, warn, http, info, verbose, silly, which warn being the default. Assuming that the later values mean more output, we should check http, info, verbose, silly. Unfortunately, using chalk/chalk as an example, none of these log levels match the previous default (https://travis-ci.org/chalk/chalk/jobs/248527902#L125).

The next level up (or down, depending on where you put the top) is http, which shows:

travis@989ed5c42367:~/chalk/chalk$ npm install --loglevel http 2>&1 | head -20
npm http fetch GET 200 https://registry.npmjs.org/nyc 119ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/escape-string-regexp 353ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/supports-color 349ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/coveralls 380ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/ansi-styles 372ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/matcha 389ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/resolve-from 388ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/archy 249ms (from cache)
npm http fetch GET 200 https://registry.npmjs.org/caching-transform 45ms (from cache)
npm http fetch GET 200 https://registry.npmjs.org/debug-log 59ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/import-fresh 539ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/mocha 543ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/arrify 161ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/xo 549ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/convert-source-map 160ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/find-up 158ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/default-require-extensions 184ms (from cache)
npm http fetch GET 200 https://registry.npmjs.org/md5-hex 19ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/glob 155ms (from cache)
npm http fetch GET 304 https://registry.npmjs.org/istanbul-lib-coverage 98ms (from cache)

NPM team confirms that there is no simple option to pass to npm to get the previous output.

Qix- commented

I'm not looking to match anything. I want debugging info in my continuous integration. Period. Why is there such resistance to npm ls being included? It's a fast command even on larger projects. Not having this information will make Travis less useful than other CI systems.

I don't work for Travis, so this is only the opinion of a random passer-by, but taking a look at the Chalk repo I can see that there is no npm shrinkwrap/package-lock.json, combined with wildcard devDependencies in package.json, which no doubt explains why you're seeing unexplained breakage.

Personally I'd use yarn and a yarn.lock over npm (docs), however if you want to try the new npm 5 package-lock.json support instead, see:
https://docs.npmjs.com/files/package-locks

In addition, your travis config doesn't define it's own install/script steps (ie is using the defaults) - which whilst handy to get started quickly, are IMO better replaced by explicitly defined commands, which could then easily have an npm ls call appended added to provide extra debugging info to help you resolve this in the meantime.

Example .travis.yml install step you could use:

...
install:
  - npm install
  - npm ls

Or alternatively, downgrade to npm 4 using the method here:
https://docs.travis-ci.com/user/languages/javascript-with-nodejs/#Using-a-specific-npm-version

Qix- commented

@edmorley The breakage was unrelated to dependencies. We are aware (and are purposeful) with our wildcard dev dependencies.

The problem is that it is invariably incorrect to add an install section to a travis configuration file that has no custom install sequence. Travis should be taking care of this - it is not better to define your own when the default install should be showing this already.

Seeing as how the travis devs fail to understand this and are dismissing us entirely I think we might switch to something else.

@Qix- - just so you know, this fix that you requested:

  1. was not required by most people
  2. broke a whole lot more peoples' builds than the original problem did
  3. is you asking travis to "fix" things npm did

npm ls has the behavior of faulting once it finds packages that aren't depended on. once npm ls was added, my build just started breaking out of the blue.

npm ls is slow, to boot. i don't actually want to have every one of my node8 builds wait to scan the registry on every single start. supporting your build expectations has added ~20 seconds to my builds, without giving me anything i want or need.

on top of that, npm ls isn't the correct answer. cating package-lock.json is.

the travis "fix" is to keep it in but ignore it when it breaks.

this means that:

  1. i still lose the time, and
  2. anyone relying on npm ls to fault is now screwed, because travis is going to ignore its faulting even

please be considerate. this was not a travis problem, and the correct fix was not for travis to alter its build path to accomodate your expectations. this was something you could have added to your .travis.yml with a one-liner. the changes you asked them to make global had consequences for many other people, and their fix will have consequences too.

@BanzaiMan - please consider taking npm ls back out. this isn't what npm ls is for, and suppressing that fault is a mistake. there are other, more appropriate ways to do this.

Qix- commented

@StoneCypher Relying on specific travis output is your problem. Not mine. Travis is a tool, and it lost a ton of functionality. I didn't 'break' anything of yours. Travis did. npm ls is cheap. All of your points are false.

The fact of the matter is that the builds breaking is either a Travis thing or a project-misusing-Travis thing. npm ls by itself wasn't the problem. If it exited with non-zero because your package.json isn't right, either have NPM change it or have Travis disregard the status code. It's quite simple.

Seeing as how I work with someone that boasts 33% of all NPM downloads with their packages alone, this is a problem we face all the time and relied upon that functionality across hundreds of packages.

Again, if npm ls broke your build, look in the mirror first. Not at me. Sorry to be harsh, but nothing you said is accurate or called for.

If anyone "broke" anything, it was npm; it changed the behavior with a new major version, and stopped providing the information it used to.

While there was a clear and reasonable (one that is recommended by the npm team) way to regain the functionality, @Qix- pushed for the change in Travis CI behavior. I agreed then, and I still think this is a reasonable thing to do.

While the behavior of npm ls under certain circumstances was unexpected (I apologize for not testing thoroughlyβ€”I do admit, however, that I have been unable to reproduce this error even after I learned that it could happen), I think the current behavior to ignore the exit status code is reasonable. If @StoneCypher has suggestions on how to improve this behavior, we are happy to consider them.

Finally, @Qix-, please be more civil. The comments such as "look in the mirror first" are not appreciated.

Qix- commented

My point was that I personally didn't break anyone's builds. I don't like being blamed as the cause for anyone breaking because it's simply untrue. I completely agree with what you said, @BanzaiMan. I apologize for being heated, but this is something that really affects development flows for a large portion of the community. It's a small change (not Travis' fault, but NPM's) that can make the difference between a few minutes of debugging to a few (potentially wasted) hours. It was less that it was output that wasn't exactly the same as it was before, but the fact it was missing information that played a very crucial role into the initial debugging of CI breaks.

Thank you for adding it back in.

@StoneCypher Is npm install any faster with npm 5 than with npm <=5? Is npm ls adding more time than the difference?

@BanzaiMan - I don't have enough metrics to reliably answer that. VMs vary widely in execution speed and I haven't measured.

What I do know is that my node 8 builds seem to be about 3.8 minutes on average, whereas previously they were about 3.4.

I'm okay with this; free tool, and all

Just saying, npm ls was never the right answer to this in the first place, and the right answer - cating package-lock.js - is much faster and much less break-y

(I've also seen precisely zero people on freenode or efnet complaining that this was missing. I didn't know anything was missing at all, and neither seemed to anyone else. The claim that "this is something that really affects development flows for a large portion of the community" seems extremely unlikely without supporting data, to me.)

Qix- commented

@StoneCypher but isn't cat-ing package-lock.json just as proprietary? I agree that you'd get the same (+ more) information as npm ls, but an .npmrc is going to break that.

The thing Travis would have to run is if [ ! -f .npmrc ] || [ cat .npmrc | grep package-lock=false | wc -l -eq 0 ]; then cat package-lock.json; else npm ls; fi. That's not only clunky and hack-ish, but it's also indeterministic output.

no, it isn't. catting is safe, does not hit the registry, is instantaneous, has correct behavior when someone wants the lockfile kept out of the registry, et cetera.

you seem to have confused the word "proprietary" with a valid technical criticism.

i'll go back to answering your questions when you're done hitting thumbs down on people saying "the thing you demanded that travis do caused us problems."

@BanzaiMan - the straight answer to improving this behavior is "just don't do it in the first place. nobody wants or needs this. you shouldn't impose any steps on your customers that you can't explain the purpose of."

nothing stops this guy from doing npm ls in his .travis.yml.

all that's going on here is he became dependant on a non-guaranteed behavior and wants to impose it on the rest of us so that he doesn't have to adjust.

there is no value here to almost any npm project, and there is mild consequence.

Qix- commented

Travis isn't guaranteed behavior. Embrace that. You should never model your tests around your CI. I'm not sure where you're missing that, @StoneCypher.

And I'm saying that package-lock.json isn't guaranteed to exist. You seemed to have missed that "technical criticism" in my previous comment. package-lock.json is proprietary and not guaranteed.

CI doesn't exist to just be a "did it work" - when it fails, how do you expect I debug e.g. an upstream dependency problem in Travis without npm ls output?

I'm not sure what you don't understand here.

  1. npm ls does not do things other developers need
  2. you demanded the addition of npm ls to model behaviors you expected from a package tool that were never guaranteed
  3. you wrote extensively about how necessary these behaviors were to the community, which they are not
  4. you talked the CI people into adding npm ls to the standard behavior of the CI tool, when it's something nobody but you needs
  5. there were consequences to others of adding npm ls for you
  6. the goal you were trying to suit, according to your own text, has a much better approach

please stop going off on tangents now

you asked the CI vendor to add an incorrect behavior, and as a result, tons of peoples' builds broke

this isn't complicated

duh, package-lock.json isn't guaranteed to exist. i pointed that out as a benefit. please actually read what's said to you before arguing.

literally everything about npm, including npm ls, is proprietary. your wrong solution is not an improvement on those grounds. there is nothing wrong with proprietary.

i won't respond to your next argument because it's clear you aren't actually considering what's being said to you

I think it is time to lock this issue. We may revisit this issue and drop npm ls.

Qix- commented

npm ls does not do things other developers need

What? Because you didn't need them, doesn't mean they have no value for debugging. If you've ever released a module that has millions of users a month and something breaks, you need to debug why it's breaking on Travis as quick as possible. A list of dependencies is required.

you demanded the addition of npm ls to model behaviors you expected from a package tool that were never guaranteed

I have no idea what you mean by this. I'm not asking for a specific format from npm ls. I'm not parsing it or using it other than to look at it.

you wrote extensively about how necessary these behaviors were to the community, which they are not

They are. You don't need them. But the community uses them all the time.

you talked the CI people into adding npm ls to the standard behavior of the CI tool, when it's something nobody but you needs

See points above. You're really not adding anything to an already weak argument.

there were consequences to others of adding npm ls for you

It wasn't "for me". And no, there weren't.