604283 - Intermittent mochitest-chrome failure from filling the log with "SSLTUNNEL(0x7f67280010b0): poll timeout, looping" starting in test_bug480619.html

Status: RESOLVED DUPLICATE of bug 542207

(Core :: Security: PSM, defect)

Description

[Phil Ringnalda (:philor)]

Not sure this is the place, or that I'm putting the blame anywhere near the right place. If my assumption that "SSLTUNNEL(0x7f67280010b0)" means "the particular instance started by a particular test" then

7401 INFO TEST-START | chrome://mochitests/content/chrome/security/ssl/bugs/test_bug480619.html
WARNING: Positioned frame that does not handle positioned kids; looking further up the parent chain: file /builds/slave/mozilla-central-linux64-debug/build/layout/base/nsCSSFrameConstructor.cpp, line 5563
WARNING: Positioned frame that does not handle positioned kids; looking further up the parent chain: file /builds/slave/mozilla-central-linux64-debug/build/layout/base/nsCSSFrameConstructor.cpp, line 5563
++DOMWINDOW == 111 (0x6cf2d68) [serial = 808] [outer = 0x24dffd0]
SSLTUNNEL(0x7f67280010b0): incoming connection csock(0)=0x7f67280009d0, ssock(1)=0x7f672c0008c0
SSLTUNNEL(0x7f67280010b0): polling flags csock(0)=R-, ssock(1)=R-
SSLTUNNEL(0x7f67280010b0): csock(0)=0x7f67280009d0 out_flags=1 :reading, read 144 bytes !! request is not tailed with CRLFCRLF but with 0 23 0 0 we have something for the other socket to write, but ssl has not been administered on it
SSLTUNNEL(0x7f67280010b0): polling flags csock(0)=R-, ssock(1)=R-
WARNING: Positioned frame that does not handle positioned kids; looking further up the parent chain: file /builds/slave/mozilla-central-linux64-debug/build/layout/base/nsCSSFrameConstructor.cpp, line 5563
WARNING: Positioned frame that does not handle positioned kids; looking further up the parent chain: file /builds/slave/mozilla-central-linux64-debug/build/layout/base/nsCSSFrameConstructor.cpp, line 5563
SSLTUNNEL(0x7f67280010b0): poll timeout, looping
SSLTUNNEL(0x7f67280010b0): polling flags csock(0)=R-, ssock(1)=R-

followed by some GC, success for that test, then occasional repeats of

SSLTUNNEL(0x7f67280010b0): poll timeout, looping
SSLTUNNEL(0x7f67280010b0): polling flags csock(0)=R-, ssock(1)=R-

until finally down in the extension manager tests there's nothing but a repeat of that over and over until the log decides it's had enough at 52428800 bytes and truncates it.

Comment 1

[Phil Ringnalda (:philor)]

Ah, and I forgot to mention that for added fun, that failure was on the compartments landing on mozilla-central, so even though it's probably unrelated since it never managed to happen while compartments was on the TraceMonkey tree, it still looks sort of suspicious.

Comment 2

[Robert Strong (they/them - no direct email)]

Not sure it is related but before the compartments landing I had a similar error with a mozilla-central try server mochitest-chrome run that reported a ton of
SSLTUNNEL(0x7f60780010b0): poll timeout, looping
SSLTUNNEL(0x7f60780010b0): polling flags csock(0)=--, ssock(1)=R-
etc.

The connection error was 0x804B0048 (2152398920) NS_ERROR_PROXY_CONNECTION_REFUSED

Comment 3

[Honza Bambas (:mayhemer)]

Can you give me reference to a log?

The timeout log itself is not actually an error, it means that ssltunnel is just waiting for connections.  I added that log and set so short timeout just to see that ssltunnel is alive.

Comment 4

[Phil Ringnalda (:philor)]

Oops, sorry, got distracted while copy-paste-filing.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1287026330.1287028366.11333.gz&fulltext=1

Comment 5

[Honza Bambas (:mayhemer)]

Ehm... so the problem here is that the box fails the test because of too long log file?  Because I don't see any failure in the log...

If this is just about the log that is produced by ssltunnel (two lines every second) then it is simple to fix.

Comment 6

[Phil Ringnalda (:philor)]

Dunno!

If there's no significance to what test 0x7f67280010b0 first appeared in, then yeah, I guess the problem is that an addon mgr test that wanted to time out didn't get to, because the log was so full of noise that it (and the whole rest of the run) couldn't get a word in edgewise. Or, maybe it didn't even time out, and the run was just called TEST-FAILED because the end of the log with the count of passed and failed was cut off.

Comment 7

[Honza Bambas (:mayhemer)]

OK, if this causes boxes to go orange, I'll work on it.  The work will be done in bug 542207.