1276805 - Intermittent test_peerConnection_basicAudioNATSrflx.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from connected to failed

Status: RESOLVED FIXED

(Core :: WebRTC, defect, P2)

Description

[Phil Ringnalda (:philor)]

https://treeherder.mozilla.org/logviewer.html#?job_id=29045006&repo=mozilla-inbound
https://treeherder.mozilla.org/logviewer.html#?job_id=29049334&repo=mozilla-inbound
https://treeherder.mozilla.org/logviewer.html#?job_id=29049334&repo=mozilla-inbound

Comment 1

[Byron Campen [:bwc]]

Looks like consent refreshes are timing out. Looking closer.

Comment 2

[Byron Campen [:bwc]]

Hmm. Seeing signs that consent freshness checks aren't working at all for the NAT tests.

Comment 3

[Byron Campen [:bwc]]

This is _probably_ test only, because if consent freshness was straight-up broken on all connections using srflx or relay, we would have noticed.

Comment 4

[Intermittent Failures Robot]

20 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 9
* fx-team: 8
* try: 1
* mozilla-central: 1
* ash: 1

Platform breakdown:
* linux32: 20

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-02&endday=2016-06-02&tree=all

Comment 5

[Randell Jesup [:jesup] (needinfo me)]

Byron: this is starting to spike (perhaps due to perf or VM class changes or loading).  Can we extend or disable consent freshness (pref?) in automation until it works?

Comment 6

[Nils Ohlmeier [:drno]]

@jesup: there is no option to turn off consent freshness

Comment 7

[Nils Ohlmeier [:drno]]

Found this in the raw log of the first failed test run from comment #1:

10:41:12     INFO -  (generic/INFO) TestNrSocket IP4:10.134.157.154:37554/UDP received from IP4:10.134.157.154:40193/UDP via IP4:10.134.157.154:40561/UDP
10:41:12     INFO -  (ice/NOTICE) ICE(PC:1464630018674714 (id=2147483761 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicAudioNATSrf): Message does not correspond to any registered stun ctx

Looks like the NAT simulator lets something pass, which does not match any registered STUN ctx?! Is is possible that port assignments change in the NAT simulator over time? Or what else could explain this?

Comment 8

[Byron Campen [:bwc]]

Not sure. I suspect it is just an interaction between the NAT simulator and nICEr, but it could be a problem with real NATs too that is intermittent. I should be able to investigate today.

Comment 9

[Byron Campen [:bwc]]

It seems that this only happens on linux e10s, and mostly on debug. Might just be a performance problem?

Comment 10

[Intermittent Failures Robot]

104 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 58
* fx-team: 19
* try: 18
* mozilla-central: 6
* ash: 3

Platform breakdown:
* linux32: 83
* linux64: 11
* android-4-3-armv7-api15: 10

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-05-30&endday=2016-06-05&tree=all

Comment 11

[Intermittent Failures Robot]

25 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 14
* fx-team: 6
* mozilla-central: 4
* mozilla-aurora: 1

Platform breakdown:
* linux32: 25

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-06&endday=2016-06-06&tree=all

Comment 12

[Intermittent Failures Robot]

24 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 13
* try: 4
* mozilla-aurora: 3
* mozilla-central: 2
* fx-team: 2

Platform breakdown:
* linux32: 24

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-07&endday=2016-06-07&tree=all

Comment 13

[Intermittent Failures Robot]

25 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 13
* fx-team: 5
* try: 4
* mozilla-central: 1
* mozilla-aurora: 1
* autoland: 1

Platform breakdown:
* linux32: 25

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-08&endday=2016-06-08&tree=all

Comment 14

[Intermittent Failures Robot]

22 automation job failures were associated with this bug yesterday.

Repository breakdown:
* fx-team: 8
* try: 5
* mozilla-inbound: 5
* mozilla-central: 3
* mozilla-aurora: 1

Platform breakdown:
* linux32: 22

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-09&endday=2016-06-09&tree=all

Comment 15

[Intermittent Failures Robot]

26 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 12
* fx-team: 8
* ash: 3
* mozilla-central: 2
* try: 1

Platform breakdown:
* linux32: 26

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-10&endday=2016-06-10&tree=all

Comment 16

[Intermittent Failures Robot]

193 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 85
* fx-team: 40
* try: 34
* mozilla-central: 20
* mozilla-aurora: 9
* ash: 4
* autoland: 1

Platform breakdown:
* linux32: 189
* linux64: 4

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-06&endday=2016-06-12&tree=all

Comment 17

[Byron Campen [:bwc]]

I'd be willing to bet that we are simply bogging down these VMs with logging to the point that consent freshness times out. When the NAT simulator is active, we get a bunch more logging at INFO. Maybe if we move that to DEBUG we'll be fine.

Comment 18

[Byron Campen [:bwc]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=2044b376656f

Comment 19

[Intermittent Failures Robot]

15 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 8
* fx-team: 4
* mozilla-central: 2
* ash: 1

Platform breakdown:
* linux32: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-14&endday=2016-06-14&tree=all

Comment 20

[Byron Campen [:bwc]]

Attachment: Bug 1276805: Make TestNrSocket less chatty.

Review commit: https://reviewboard.mozilla.org/r/59284/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/59284/

Comment 21

[Nils Ohlmeier [:drno]]

Comment on attachment 8762809 [details]
Bug 1276805: Make TestNrSocket less chatty.

https://reviewboard.mozilla.org/r/59284/#review56296

LGTM

Comment 22

[Intermittent Failures Robot]

22 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 11
* fx-team: 8
* mozilla-central: 2
* ash: 1

Platform breakdown:
* linux32: 22

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-15&endday=2016-06-15&tree=all

Comment 23

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/5a88d105f01b
Make TestNrSocket less chatty. r=drno

Comment 24

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/5a88d105f01b

Comment 25

[Intermittent Failures Robot]

60 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 32
* fx-team: 19
* mozilla-central: 5
* try: 2
* ash: 2

Platform breakdown:
* linux32: 60

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1276805&startday=2016-06-13&endday=2016-06-19&tree=all

Comment 26

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/86463ff0610b