757193 - RelEng slaves in mtv1 have connectivity issues - connections open but no further traffic

Status: RESOLVED FIXED

(Infrastructure & Operations Graveyard :: NetOps, task)

Description

[Nick Thomas [:nthomas] (UTC+12)]

(Or Server Ops: ACL Request as appropriate)

There are many machines in mtv1 for RelEng but take these as examples
 moz2-darwin10-slave47.build.mozilla.org
 mv-moz2-linux-ix-slave12.build.mozilla.org

trying to reach machines in scl1, eg
 buildbot-master25.build.scl1.mozilla.com on port 8001
 slavealloc.build.mozilla.org on port 80

moz2-darwin10-slave47:slave cltbld$ curl -v -m 60 http://slavealloc.build.mozilla.org/gettac/moz2-darwin10-slave47
* About to connect() to slavealloc.build.mozilla.org port 80 (#0)
*   Trying 10.12.48.17... connected
* Connected to slavealloc.build.mozilla.org (10.12.48.17) port 80 (#0)
> GET /gettac/moz2-darwin10-slave47 HTTP/1.1
> User-Agent: curl/7.19.4 (universal-apple-darwin10.0) libcurl/7.19.4 OpenSSL/0.9.8k zlib/1.2.3
> Host: slavealloc.build.mozilla.org
> Accept: */*
> 
* Operation timed out after 60000 milliseconds with 0 bytes received
* Closing connection #0
curl: (28) Operation timed out after 60000 milliseconds with 0 bytes received

We see a similar problem with buildbot-master25 - both sides see a connection open (as does nc) but they don't pass any data to complete the signon of the build slave to the master.

Connectivity to scl3 is OK.

Comment 1

[Amy Rich [:arr] [:arich]]

This started happening on Thursday afternoon, so I strongly suspect it's related to the scl1 network work that happened then.  Perhaps an acl or timeout value somewhere didn't get copied?

Comment 2

[Dustin J. Mitchell [:dustin] (he/him)]

Here's a tcpdump on both sides.

moz2-darwin10-slave44:~ root# wget http://slavealloc.build.mozilla.org/gettac/moz2-darwin10-slave44
--14:00:01--  http://slavealloc.build.mozilla.org/gettac/moz2-darwin10-slave44
           => `moz2-darwin10-slave44'
Resolving slavealloc.build.mozilla.org... 10.12.48.17
Connecting to slavealloc.build.mozilla.org|10.12.48.17|:80... connected.
HTTP request sent, awaiting response... 14:00:01.619681 IP 10.250.50.155.49193 > 10.12.48.17.80: Flags [S], seq 3194031526, win 65535, options [mss 1460,nop,wscale 3,nop,nop,TS val 787370325 ecr 0,sackOK,eol], length 0
14:00:01.646666 IP 10.12.48.17.80 > 10.250.50.155.49193: Flags [S.], seq 1355369097, ack 3194031527, win 5792, options [mss 1460,sackOK,TS val 786414276 ecr 787370325,nop,wscale 4], length 0
14:00:01.646704 IP 10.250.50.155.49193 > 10.12.48.17.80: Flags [.], ack 1, win 65535, options [nop,nop,TS val 787370325 ecr 786414276], length 0
14:00:01.646777 IP 10.250.50.155.49193 > 10.12.48.17.80: Flags [P.], seq 1:145, ack 1, win 65535, options [nop,nop,TS val 787370325 ecr 786414276], length 144
14:00:01.653073 IP 10.12.48.17.80 > 10.250.50.155.49193: Flags [.], ack 145, win 429, options [nop,nop,TS val 786414282 ecr 787370325], length 0
14:00:01.691739 IP 10.12.48.17.80 > 10.250.50.155.49193: Flags [P.], seq 1449:1560, ack 145, win 429, options [nop,nop,TS val 786414321 ecr 787370325], length 111
14:00:01.691743 IP 10.12.48.17.80 > 10.250.50.155.49193: Flags [F.], seq 1560, ack 145, win 429, options [nop,nop,TS val 786414321 ecr 787370325], length 0
14:00:01.691778 IP 10.250.50.155.49193 > 10.12.48.17.80: Flags [.], ack 1, win 65535, options [nop,nop,TS val 787370326 ecr 786414282,nop,nop,sack 1 {1449:1560}], length 0
14:00:01.691798 IP 10.250.50.155.49193 > 10.12.48.17.80: Flags [.], ack 1, win 65535, options [nop,nop,TS val 787370326 ecr 786414282,nop,nop,sack 1 {1449:1560}], length 0




tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes
14:00:01.129832 IP 10.250.50.155.49193 > 10.12.48.17.http: Flags [S], seq 3194031526, win 65535, options [mss 1460,nop,wscale 3,nop,nop,TS val 787370325 ecr 0,sackOK,eol], length 0
14:00:01.129855 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [S.], seq 1355369097, ack 3194031527, win 5792, options [mss 1460,sackOK,TS val 786414276 ecr 787370325,nop,wscale 4], length 0
14:00:01.135769 IP 10.250.50.155.49193 > 10.12.48.17.http: Flags [.], ack 1, win 65535, options [nop,nop,TS val 787370325 ecr 786414276], length 0
14:00:01.135901 IP 10.250.50.155.49193 > 10.12.48.17.http: Flags [P.], seq 1:145, ack 1, win 65535, options [nop,nop,TS val 787370325 ecr 786414276], length 144
14:00:01.135916 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], ack 145, win 429, options [nop,nop,TS val 786414282 ecr 787370325], length 0
14:00:01.174790 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786414321 ecr 787370325], length 1448
14:00:01.174861 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [P.], seq 1449:1560, ack 145, win 429, options [nop,nop,TS val 786414321 ecr 787370325], length 111
14:00:01.174991 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [F.], seq 1560, ack 145, win 429, options [nop,nop,TS val 786414321 ecr 787370325], length 0
14:00:01.180803 IP 10.250.50.155.49193 > 10.12.48.17.http: Flags [.], ack 1, win 65535, options [nop,nop,TS val 787370326 ecr 786414282,nop,nop,sack 1 {1449:1560}], length 0
14:00:01.181377 IP 10.250.50.155.49193 > 10.12.48.17.http: Flags [.], ack 1, win 65535, options [nop,nop,TS val 787370326 ecr 786414282,nop,nop,sack 1 {1449:1560}], length 0
14:00:01.380832 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786414527 ecr 787370326], length 1448
14:00:01.792765 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786414939 ecr 787370326], length 1448
14:00:02.616773 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786415763 ecr 787370326], length 1448
14:00:04.264825 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786417411 ecr 787370326], length 1448
14:00:07.560867 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786420707 ecr 787370326], length 1448
14:00:09.360776 IP 10.12.48.17.http > 10.250.50.155.49192: Flags [.], seq 649333336:649334784, ack 407577240, win 429, options [nop,nop,TS val 786422507 ecr 787370186], length 1448
14:00:14.152783 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786427299 ecr 787370326], length 1448
14:00:27.336791 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786440483 ecr 787370326], length 1448
14:00:53.704776 IP 10.12.48.17.http > 10.250.50.155.49193: Flags [.], seq 1:1449, ack 145, win 429, options [nop,nop,TS val 786466851 ecr 787370326], length 1448


That the large packets are being lost strongly suggests MTU problems.

Comment 3

[casey ransom [:casey]]

Part of the work done on thursday was swinging SCL1 over to our internal MPLS fabric.  One of the side effects of that (due to a provider delay on a real circuit, iirc) is that the MPLS fabric connects to SJC1 via a virtual GRE tunnel to SCL3.  In relation, to get from MTV1 to SCL1, one has to go from MTV1 -> SCL2 -> SJC1 -> SCL3 -> SCL1 at the moment.  One of the downsides is that this impacts full frame packets (normally 1476 bytes) and what you saw here was the inability to negotiate a working max-size packet.  This will be solved once we are off this GRE tunnel, however, until then I've set fw1.scl1 to limit the maximum segment size used in tcp setup and the above curl now works.  

We have a circuit ready to get MTV1 into our MPLS cloud and we'll be preparing to get that into service in the next few days to eliminate that trip around the bay. But for now, you should be up and running again and I've verified that curl is working properly.