Investigate flaky test-http-agent

[mscdex]

Example failure on pi2-raspbian-wheezy #1
Example failure on pi2-raspbian-wheezy #2

Similar issue here as in #5938?

Output:

# TIMEOUT
#0 200
#1 200
#2 200
#3 200
#4 200
#5 200
#6 200
#7 200
#8 200
#9 200
#10 200
#11 200
#12 200
#13 200
#14 200

[mscdex]

Ref: #5346

[Trott]

While looking at this test being flaky in February, it was discovered to fail always on a connection in the low 20s. In other words, if it failed, it failed on connection 22 or 23 or 24, but never on 16 or 36 or 46 or 59 or...

Which was very odd...

And now it seems that we're seeing that number creep lower resulting in increased flakiness on Pi 2 devices. I have no explanation. It's really weird.

/cc @nodejs/build @rvagg

[Trott]

Again: https://ci.nodejs.org/job/node-test-binary-arm/1681/RUN_SUBSET=3,nodes=pi2-raspbian-wheezy/tapTestReport/test.tap-53/

Ugh. Not sure what to do. Bringing it down to 12 or so would probably fix it, but it would seem that in another month, we'd likely be facing the same issue again.

[Trott]

cc @nodejs/testing

[mscdex]

Again: https://ci.nodejs.org/job/node-test-binary-arm/1727/RUN_SUBSET=2,nodes=pi2-raspbian-wheezy/console

[santigimeno]

While looking at this test being flaky in February, it was discovered to fail always on a connection in the low 20s. In other words, if it failed, it failed on connection 22 or 23 or 24, but never on 16 or 36 or 46 or 59 or...

@Trott Would it be worth stress testing the test with the source code we had in February, just to check whether it's a problem in the code or in the raspberry bots?

[Trott]

@santigimeno I suppose that's worth a shot.

And, another one: https://ci.nodejs.org/job/node-test-binary-arm/1728/RUN_SUBSET=2,nodes=pi2-raspbian-wheezy/tapTestReport/test.tap-53/

[Trott]

And another: https://ci.nodejs.org/job/node-test-binary-arm/1723/RUN_SUBSET=2,nodes=pi2-raspbian-wheezy/console

I suppose it's superfluous to document them all here as the test is now failing so often.

[Trott]

Per @santigimeno's suggestion, here are three CI stress tests:

• the previous version that uses 100 connections
• the current version in master that uses 16 connections
• a version with the connections reduced to 9

[Trott]

And one more, also at @santigimeno's suggestion:

• reverting everything since the commit in February that last made this test not flaky

[Trott]

Confounding results: Previous version of the test (that used 100 connections) failed, of course.

But no failures on any of the other stress tests, including current master.

Maybe its flakiness is dependent on other things going on on the network or something? I mean, it shouldn't be, right? Maybe confirm that the test is using localhost and not something odd like the machine's networked IP or (would this next one even work?) a broadcast address or something...

[Trott]

Continues to fail with alarming frequency. Running CI stress test against master. https://ci.nodejs.org/job/node-stress-single-test/596/nodes=pi2-raspbian-wheezy/console

[Trott]

Stress test on master is showing failures, so that's at least what we would expect.

Running a stress test on the code base as it existed in February right after the flakiness for this test was fixed the last time around: https://ci.nodejs.org/job/node-stress-single-test/597/nodes=pi2-raspbian-wheezy/console

In theory at least, if that shows lots of failures, then something is up with the devices/CI. If that stress test does not show failures, then that suggests something changed in the code base.

[Trott]

Hmmm...February run is not failing. Repeating for confirmation:

• master: https://ci.nodejs.org/job/node-stress-single-test/598/nodes=pi2-raspbian-wheezy/console
• february again: https://ci.nodejs.org/job/node-stress-single-test/599/nodes=pi2-raspbian-wheezy/console

[santigimeno]

master fails, and February passes, we should probably start bisecting

[Trott]

Bisecting begun. Will log each step here to someone else can pick it up if they want to as I definitely don't expect to get it done all in one sitting. (Running the CI stress test can take a loooong time depending on if a full build needs to happen or not...)

Current master is bad.

bbf4621 is good.

Stress test for 08085c4: https://ci.nodejs.org/job/node-stress-single-test/601/nodes=pi2-raspbian-wheezy/console

[santigimeno]

08085c4 is good.

Stress test for 54a5287: https://ci.nodejs.org/job/node-stress-single-test/604/

[Trott]

08085c4 is good.

Now running a stress test on ef6c4c6: https://ci.nodejs.org/job/node-stress-single-test/605/nodes=pi2-raspbian-wheezy/console

[Trott]

ef6c4c6 is good as is 54a5287.

Now stress testing b743d82: https://ci.nodejs.org/job/node-stress-single-test/606/nodes=pi2-raspbian-wheezy/console

[Trott]

b743d82 is bad.

Now stress testing ba0b769: https://ci.nodejs.org/job/node-stress-single-test/607/nodes=pi2-raspbian-wheezy/console

[Trott]

ba0b769 is good.

Now stress testing ae2be27: https://ci.nodejs.org/job/node-stress-single-test/608/nodes=pi2-raspbian-wheezy/console

[Trott]

ae2be27 is good.

Now stress testing 757fbac: https://ci.nodejs.org/job/node-stress-single-test/609/nodes=pi2-raspbian-wheezy/console

[Trott]

757fbac is good.

Now stress testing 0a62f92: https://ci.nodejs.org/job/node-stress-single-test/610/nodes=pi2-raspbian-wheezy/console

[Trott]

0a62f92 is bad.

Now stress testing 3de9bc9: https://ci.nodejs.org/job/node-stress-single-test/611/nodes=pi2-raspbian-wheezy/console

[jbergstroem]

@Trott: Did a restart of jenkins in here somewhere; just want to give you a heads up in case the restart killed a job.

[Trott]

3de9bc9 is bad.

Now testing b85a50b: https://ci.nodejs.org/job/node-stress-single-test/612/nodes=pi2-raspbian-wheezy/console

[Trott]

b85a50b is good.

According to this process, the first bad commit is 3de9bc9.

That seems extremely unlikely. (Only things in that commit are a doc update and a readline test.)

This raises the frustrating specter that perhaps the CI flakiness itself is unpredictable. Like, maybe one time you run the test 100 times and it comes up fine every time, but you do it again and it fails 50 of those 100 times. Maybe depending on what device runs the test?

[Trott]

To test the "frustrating specter" possibility mentioned above, I'm running four more stress tests against b85a50b (which came up good when I ran just one stress test):

• https://ci.nodejs.org/job/node-stress-single-test/613/nodes=pi2-raspbian-wheezy/console
• https://ci.nodejs.org/job/node-stress-single-test/614/nodes=pi2-raspbian-wheezy/console Typo'ed when setting that one up.
• https://ci.nodejs.org/job/node-stress-single-test/615/nodes=pi2-raspbian-wheezy/console
• https://ci.nodejs.org/job/node-stress-single-test/616/nodes=pi2-raspbian-wheezy/console

And four more against 3de9bc9 (which came up bad):

• https://ci.nodejs.org/job/node-stress-single-test/617/nodes=pi2-raspbian-wheezy/console
• https://ci.nodejs.org/job/node-stress-single-test/618/nodes=pi2-raspbian-wheezy/console
• https://ci.nodejs.org/job/node-stress-single-test/619/nodes=pi2-raspbian-wheezy/console
• https://ci.nodejs.org/job/node-stress-single-test/620/nodes=pi2-raspbian-wheezy/console

[Trott]

Looks like the stress test will sometimes come up clean (100 successful runs, no failures) but fail frequently at other times. Never seems to fail just once or twice. Either success or a bunch of failures. Argh.

So b85a50b is bad after all. It comes up clean in some stress test runs (see https://ci.nodejs.org/job/node-stress-single-test/612/nodes=pi2-raspbian-wheezy/console and https://ci.nodejs.org/job/node-stress-single-test/615/nodes=pi2-raspbian-wheezy/console) but fails in others (see https://ci.nodejs.org/job/node-stress-single-test/613/nodes=pi2-raspbian-wheezy/console and https://ci.nodejs.org/job/node-stress-single-test/616/nodes=pi2-raspbian-wheezy/console).

I'm inclined to go back to the beginning with bbf4621 and confirm that it isn't flaky in the current CI by running the stress test a half dozen times or so.

[santigimeno]

Repeat last good: 757fbac 4 more times and confirming is good.

• https://ci.nodejs.org/job/node-stress-single-test/621/
• https://ci.nodejs.org/job/node-stress-single-test/622/
• https://ci.nodejs.org/job/node-stress-single-test/623/
• https://ci.nodejs.org/job/node-stress-single-test/624/

[santigimeno]

Next one: 6222e5b is bad. Failed 3 out of 4:

• https://ci.nodejs.org/job/node-stress-single-test/625/
• https://ci.nodejs.org/job/node-stress-single-test/626/
• https://ci.nodejs.org/job/node-stress-single-test/627/
• https://ci.nodejs.org/job/node-stress-single-test/628/

[santigimeno]

Next one: 31524d7 is also bad. Failed 3 out of 4:

• https://ci.nodejs.org/job/node-stress-single-test/633/
• https://ci.nodejs.org/job/node-stress-single-test/634/
• https://ci.nodejs.org/job/node-stress-single-test/635/
• https://ci.nodejs.org/job/node-stress-single-test/636/

[santigimeno]

Next one: 82d57d3 is also bad. Failed 3 out of 4:

• https://ci.nodejs.org/job/node-stress-single-test/637/
• https://ci.nodejs.org/job/node-stress-single-test/638/
• https://ci.nodejs.org/job/node-stress-single-test/639/
• https://ci.nodejs.org/job/node-stress-single-test/640/

[Trott]

Looks like @santigimeno also kicked off two jobs that confirm that 0d41463
is bad:

• https://ci.nodejs.org/job/node-stress-single-test/641/
• https://ci.nodejs.org/job/node-stress-single-test/642/

This would seem to flag b85a50b as the culprit, which is at least a lot more believable. Still, let's confirm by stress testing the immediate prior commit (757fbac) several times:

• https://ci.nodejs.org/job/node-stress-single-test/645/
• https://ci.nodejs.org/job/node-stress-single-test/646/
• https://ci.nodejs.org/job/node-stress-single-test/647/
• https://ci.nodejs.org/job/node-stress-single-test/648/
• https://ci.nodejs.org/job/node-stress-single-test/649/
• https://ci.nodejs.org/job/node-stress-single-test/650/

[Trott]

Tests confirm that 757fbac is the last good commit and b85a50b is the first bad one. Now the questions are:

• Is the problem one of configuration with the Pi2 devices?
• Or is the problem with the code change running on Pi2 (which is just Linux, right? and not that different from other Pi devices on which we're not seeing problems, right?)
• Or is the problem in the test somehow?

/cc @rvagg @cjihrig

[cjihrig]

Does this only happen on a specific subset of the Pi2s?

I'd think that the change in b85a50b would cause something to break completely, not in a flaky manner. That test also doesn't have a great track record.

[santigimeno]

FWIW. I run 4 stress test jobs with current master, reverting the suspect commit and they all passed:

• https://ci.nodejs.org/job/node-stress-single-test/651/
• https://ci.nodejs.org/job/node-stress-single-test/652/
• https://ci.nodejs.org/job/node-stress-single-test/653/
• https://ci.nodejs.org/job/node-stress-single-test/654/

[Trott]

@cjihrig asked:

Does this only happen on a specific subset of the Pi2s?

Nope, I'm afraid not, at least not as far as I've been able to tell.

[cjihrig]

Trying a partial revert of b85a50b. Stress test at https://ci.nodejs.org/job/node-stress-single-test/655/ with the ADDRCONFIG flag added back.

[santigimeno]

@cjihrig, it might be worth running multiple smaller (~100 times) jobs so it picks different pi2's, just to be sure it's fixed, as we have seen runs without failures before and maybe it's somehow dependent on the bot its running on.

[Trott]

Smaller series of stress tests on @cjihrig's partial revert per @santigimeno's suggestion:

• https://ci.nodejs.org/job/node-stress-single-test/656/
• https://ci.nodejs.org/job/node-stress-single-test/657/
• https://ci.nodejs.org/job/node-stress-single-test/658/
• https://ci.nodejs.org/job/node-stress-single-test/659/
• https://ci.nodejs.org/job/node-stress-single-test/660/
• https://ci.nodejs.org/job/node-stress-single-test/661/

[Trott]

They all came back green!