Re: [squid-users] TCP MISS 502

From: Ivan . <ivanhec_at_gmail.com>
Date: Tue, 30 Mar 2010 10:50:53 +1100

More odd tcp_miss

Only had a small portion of the site which would work. Works fine from
the primary, but fails on the secondary squid.

1269906612.412 5464 10.xxx.xxxx.xxx TCP_MISS/000 0 GET
http://www.internode.on.net/products/ - DIRECT/203.16.214.27 -
1269906612.930 17 10.xxx.xxxx.xxx TCP_MISS/200 851 GET
http://advisories.internode.on.net/images/menu2-on.gif -
DIRECT/192.231.203.146 image/gif
1269906613.075 9 10.xxx.xxxx.xxx TCP_REFRESH_MODIFIED/200 782 GET
http://advisories.internode.on.net/images/menu2.gif -
DIRECT/192.231.203.146 image/gif
1269906613.331 221 10.xxx.xxxx.xxx TCP_MISS/200 819 GET
http://advisories.internode.on.net/images/menu1-on.gif -
DIRECT/192.231.203.146 image/gif
1269906614.487 1865 10.xxx.xxxx.xxx TCP_MISS/000 0 GET
http://www.internode.on.net/ - DIRECT/203.16.214.27 -
1269906696.702 60903 10.xxx.xxxx.xxx TCP_MISS/000 0 GET
http://www.internode.on.net/products/ - DIRECT/203.16.214.27 -
1269906767.709 61004 10.xxx.xxxx.xxx TCP_MISS/000 0 GET
http://www.internode.on.net/products/ - DIRECT/203.16.214.27 -
1269906840.719 60299 10.xxx.xxxx.xxx TCP_MISS/000 0 GET
http://www.internode.on.net/products/broadband/plan_changes/ -
DIRECT/203.16.214.27 -
1269906911.707 60981 10.xxx.xxxx.xxx TCP_MISS/000 0 GET
http://www.internode.on.net/products/broadband/plan_changes/ -
DIRECT/203.16.214.27 -

On Mon, Mar 29, 2010 at 5:56 PM, Ivan . <ivanhec_at_gmail.com> wrote:
> That is so odd, as I have two identical boxes, now running the same
> Squid version, going through the same infrastructure, one works, the
> other one doesn't?
>
> The only difference are the public addresses configured on each of the
> squid proxy systems.....
>
> The TCP stats on the interface on the squid box that won't access that
> site, don't look to bad at all
>
> [root_at_pcr-proxy ~]# netstat -s
> Ip:
>    1593488410 total packets received
>    17991 with invalid addresses
>    0 forwarded
>    0 incoming packets discarded
>    1593318874 incoming packets delivered
>    1413863445 requests sent out
>    193 reassemblies required
>    95 packets reassembled ok
> Icmp:
>    22106 ICMP messages received
>    0 input ICMP message failed.
>    ICMP input histogram:
>        destination unreachable: 16
>        echo requests: 22090
>    155761 ICMP messages sent
>    0 ICMP messages failed
>    ICMP output histogram:
>        destination unreachable: 133671
>        echo replies: 22090
> IcmpMsg:
>        InType3: 16
>        InType8: 22090
>        OutType0: 22090
>        OutType3: 133671
> Tcp:
>    27785486 active connections openings
>    78777077 passive connection openings
>    68247 failed connection attempts
>    560600 connection resets received
>    569 connections established
>    1589479495 segments received
>    1403833081 segments send out
>    6034370 segments retransmited
>    0 bad segments received.
>    626711 resets sent
> Udp:
>    3817253 packets received
>    20 packets to unknown port received.
>    0 packet receive errors
>    3840233 packets sent
> TcpExt:
>    217 invalid SYN cookies received
>    15888 resets received for embryonic SYN_RECV sockets
>    42765 packets pruned from receive queue because of socket buffer overrun
>    7282834 TCP sockets finished time wait in fast timer
>    3 active connections rejected because of time stamp
>    11427 packets rejects in established connections because of timestamp
>    8682907 delayed acks sent
>    1268 delayed acks further delayed because of locked socket
>    Quick ack mode was activated 1227980 times
>    36 packets directly queued to recvmsg prequeue.
>    14 packets directly received from prequeue
>    538829561 packets header predicted
>    492906318 acknowledgments not containing data received
>    190275750 predicted acknowledgments
>    372 times recovered from packet loss due to fast retransmit
>    348117 times recovered from packet loss due to SACK data
>    174 bad SACKs received
>    Detected reordering 71 times using FACK
>    Detected reordering 963 times using SACK
>    Detected reordering 25 times using reno fast retransmit
>    Detected reordering 998 times using time stamp
>    560 congestion windows fully recovered
>    10689 congestion windows partially recovered using Hoe heuristic
>    TCPDSACKUndo: 921
>    197231 congestion windows recovered after partial ack
>    1316789 TCP data loss events
>    TCPLostRetransmit: 22
>    3020 timeouts after reno fast retransmit
>    78970 timeouts after SACK recovery
>    10665 timeouts in loss state
>    743644 fast retransmits
>    1003156 forward retransmits
>    1884003 retransmits in slow start
>    1604549 other TCP timeouts
>    TCPRenoRecoveryFail: 150
>    31151 sack retransmits failed
>    4198383 packets collapsed in receive queue due to low socket buffer
>    814608 DSACKs sent for old packets
>    33462 DSACKs sent for out of order packets
>    65506 DSACKs received
>    266 DSACKs for out of order packets received
>    215231 connections reset due to unexpected data
>    10630 connections reset due to early user close
>    76801 connections aborted due to timeout
> IpExt:
>    InBcastPkts: 9199
>
>
> On Mon, Mar 29, 2010 at 5:47 PM, Amos Jeffries <squid3_at_treenet.co.nz> wrote:
>> Ivan . wrote:
>>>
>>> Some even more strange access.log entries?
>>>
>>> This is odd? Does that mean no DNS record? strange as both squid's use
>>> the same DNS setup, with a primary, secondary and tertiary setup.
>>> 1269833940.167      0 127.0.0.1 NONE/400 1868 GET
>>> www.environment.gov.au - NONE/- text/html
>>>
>>> 1269833960.464  60997 10.132.17.30 TCP_MISS/000 0 GET
>>> http://www.environment.gov.au/ - DIRECT/155.187.3.81 -
>>>
>>> 1269834108.182 120002 127.0.0.1 TCP_MISS/000 0 GET
>>> http://www.environment.gov.au - DIRECT/155.187.3.81 -
>>>
>>> This one is new?
>>> 1269842635.028 295660 10.143.254.22 TCP_MISS/502 2514 GET
>>> http://www.environment.gov.au/ - DIRECT/155.187.3.81 text/html
>>>
>>
>> The TCP_MISS/000 are another version of the READ_ERROR you are receiving as
>> TCP_MISS/502. The 000 ones are on the client facing side though, the TCP
>> link read failing before the request headers are finished being received
>> from the client.
>>  The first line is received (to get the URL) but not the rest of the request
>> headers.
>>
>> The NONE/400 might be yet another version of the read failing at some point
>> of processing. It's hard to say.
>>
>> Something is definitely very screwed at the TCP protocol level for those
>> requests.
>>
>> Amos
>>
>>>
>>>
>>> On Mon, Mar 29, 2010 at 4:56 PM, Ivan . <ivanhec_at_gmail.com> wrote:
>>>>
>>>> Hi Amos
>>>>
>>>> You can see the tcp_miss in the access.log here:-
>>>>
>>>> 1269834108.182 120002 127.0.0.1 TCP_MISS/000 0 GET
>>>> http://www.environment.gov.au - DIRECT/155.187.3.81 -
>>>>
>>>> Here is a tcpdump output from the connection. You can see the TCP
>>>> handshake setup and then the http session just hangs? I have confirmed
>>>> with the website admin these are no ddos type protection, which would
>>>> block multiple requests in quick succession.
>>>>
>>>> The tcp connection times out and then resets.
>>>>
>>>> [root_at_squid-proxy ~]# tcpdump net 155.187.3
>>>> tcpdump: verbose output suppressed, use -v or -vv for full protocol
>>>> decode
>>>> listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
>>>> 16:58:59.369482 IP xxx.xxxx.xxx.xxx.41338 > 155.187.3.81.http: S
>>>> 1781942738:1781942738(0) win 5840 <mss 1460,sackOK,timestamp
>>>> 1321171542 0,nop,wscale 7>
>>>> 16:58:59.418150 IP 155.187.3.81.http > xxx.xxxx.xxx.xxx.41338: S
>>>> 2343505326:2343505326(0) ack 1781942739 win 32768 <mss 1460,nop,wscale
>>>> 0,nop,nop,timestamp 234270252 1321171542,sackOK,eol>
>>>> 16:58:59.418167 IP xxx.xxxx.xxx.xxx.41338 > 155.187.3.81.http: . ack 1
>>>> win 46 <nop,nop,timestamp 1321171591 234270252>
>>>> 16:58:59.418213 IP xxx.xxxx.xxx.xxx.41338 > 155.187.3.81.http: P
>>>> 1:696(695) ack 1 win 46 <nop,nop,timestamp 1321171591 234270252>
>>>> 16:58:59.477692 IP 155.187.3.81.http > xxx.xxxx.xxx.xxx.41338: P
>>>> 2897:4081(1184) ack 696 win 33304 <nop,nop,timestamp 234270307
>>>> 1321171591>
>>>> 16:58:59.477700 IP xxx.xxxx.xxx.xxx.41338 > 155.187.3.81.http: . ack 1
>>>> win 46 <nop,nop,timestamp 1321171650 234270252,nop,nop,sack 1
>>>> {2897:4081}>
>>>>
>>>>
>>>> cheers
>>>> Ivan
>>>>
>>>> On Mon, Mar 29, 2010 at 3:59 PM, Amos Jeffries <squid3_at_treenet.co.nz>
>>>> wrote:
>>>>>
>>>>> Ivan . wrote:
>>>>>>
>>>>>> Hi,
>>>>>>
>>>>>> What would cause a TCP MISS 502, which would prevent a site from
>>>>>> loading? The site works on squidv3.0 but not on v2.6?
>>>>>>
>>>>> Any one of quite a few things. The ERR_READ_ERROR result means the
>>>>> remote
>>>>> server or network is closing the TCP link on you for some unknown
>>>>> reason.
>>>>>
>>>>> Why it works in 3.0 is as much a mystery as why it does not in 2.6 until
>>>>> details of the traffic on Squid->Server TCP link are known.
>>>>>
>>>>>
>>>>> Amos
>>>>> --
>>>>> Please be using
>>>>>  Current Stable Squid 2.7.STABLE8 or 3.0.STABLE25
>>>>>  Current Beta Squid 3.1.0.18
>>>>>
>>
>>
>> --
>> Please be using
>>  Current Stable Squid 2.7.STABLE8 or 3.0.STABLE25
>>  Current Beta Squid 3.1.0.18
>>
>
Received on Mon Mar 29 2010 - 23:51:02 MDT

This archive was generated by hypermail 2.2.0 : Tue Mar 30 2010 - 12:00:08 MDT