[squid-users] Http upload problem with TCP_MISS/000 and ctx: enter/exit messages

From: Rodrigo Ferraz <Rodrigo.Ferraz_at_conceptnetservices.com>
Date: Fri, 6 Aug 2010 12:16:16 -0300

Hello

We've been struggling for a few days with a permanent problem on a newly installed squid 3.1.4 and those web form-based uploads, either using ASP, javascript or any other language behind.
Let me assure you guys, ALL uploads are failing, not with a few specific sites. It is just a matter of clicking an OK button to submit the file and the browser (IE or Firefox) instantly shows either its own error page (Page could not be opened) in 90% of the tries or squid's error page (Connection Reset by Peer) in the remaining 10%.

By configuring a remote client to use the proxy server through an external SSH tunnel (i.e. by excluding all the local network devices), we can reduce the error ratio to around 5% of the tries. So, when the upload works, it shows this:

1281099317.664 409638 127.0.0.1 TCP_MISS/200 1840 POST http://discovirtual.terra.com.br/vd.cgi administrator DIRECT/200.154.56.65 text/html

When it doesn't, it shows this:

1281102595.774 21086 127.0.0.1 TCP_MISS/000 0 POST http://discovirtual.terra.com.br/vd.cgi administrator DIRECT/200.154.56.65 -

Plus, cache.log has a lot of these messages which I don't understand:

2010/08/06 08:55:53| ctx: enter level 2: 'http://p2.trrsf.com.br/image/get?o=cf&w=296&h=222&src=http://sdp.terra.com.br/Thumbox/free/cnt314458_h300_aNoChange_Prison-Break-1-Temporada-Ep-12_20108611342.jpg'
2010/08/06 10:13:35| ctx: enter level 3: 'application/vnd.google.safebrowsing-chunk'
2010/08/06 10:13:35| ctx: enter level 4: 'application/vnd.google.safebrowsing-chunk'
2010/08/06 10:23:54.948| ctx: enter level 5: 'http://discovirtual.terra.com.br/vdexecup.html'
2010/08/06 10:23:54.948| ctx: exit level 5
2010/08/06 10:23:54.949| ctx: enter level 5: 'http://discovirtual.terra.com.br/vdexecup.html'
2010/08/06 10:23:54.949| ctx: exit level 5
2010/08/06 10:23:54.951| ctx: enter level 5: 'http://discovirtual.terra.com.br/vdexecup.html'
2010/08/06 10:23:54.951| ctx: exit level 5
2010/08/06 10:23:55.810| ctx: enter level 5: 'http://uv.terra.com.br/UV?c=discovirtual&ord=907532&REF=&SCRNSZ=1440x900&BRSRSZ=924x695&TIMEZONE=Fri%20Aug%206%2010%3A23%3A41%20UTC-0300%202010'
2010/08/06 10:23:55.810| ctx: exit level 5
2010/08/06 10:23:55.812| ctx: enter level 5: 'http://uv.terra.com.br/UV?c=discovirtual&ord=907532&REF=&SCRNSZ=1440x900&BRSRSZ=924x695&TIMEZONE=Fri%20Aug%206%2010%3A23%3A41%20UTC-0300%202010'
2010/08/06 10:23:55.812| ctx: exit level 5
2010/08/06 10:23:55.814| ctx: enter level 5: 'http://uv.terra.com.br/UV?c=discovirtual&ord=907532&REF=&SCRNSZ=1440x900&BRSRSZ=924x695&TIMEZONE=Fri%20Aug%206%2010%3A23%3A41%20UTC-0300%202010'
2010/08/06 10:23:55.814| ctx: exit level 5
2010/08/06 10:23:56.623| ctx: enter level 5: 'http://br.hits.e.cl/cert/hit.dll?sitio_id=300274&path=srv/enviando_arquivo&referer=&java=true&flash=10&cert_cachebuster=1034&descr=ENVIANDO'
2010/08/06 10:23:56.623| ctx: exit level 5
2010/08/06 10:23:56.625| ctx: enter level 5: 'http://br.hits.e.cl/cert/hit.dll?sitio_id=300274&path=srv/enviando_arquivo&referer=&java=true&flash=10&cert_cachebuster=1034&descr=ENVIANDO'
2010/08/06 10:23:56.625| ctx: exit level 5
2010/08/06 10:23:56.627| ctx: enter level 5: 'http://br.hits.e.cl/cert/hit.dll?sitio_id=300274&path=srv/enviando_arquivo&referer=&java=true&flash=10&cert_cachebuster=1034&descr=ENVIANDO'
2010/08/06 10:23:56.627| ctx: exit level 5
2010/08/06 10:23:56.807| ctx: enter level 5: 'http://terra.112.2o7.net/b/ss/terrabr/1/H.20.3/s03451603567267?AQB=1&ndh=1&t=6/7/2010%2010%3A23%3A41%205%20180&ce=ISO-8859-1&ns=terra&cdp=3&pageName=discovirtual.br/vdexecup.html&g=http%3A//discovirtual.terra.com.br/vdexecup.html&cc=USD&ch=br.produtoseservicos.discovirtual%7C300274&server=discovirtual.terra.com.br&events=event1&v1=br.produtoseservicos.discovirtual%7C300274&h1=productos_y_servicios%7Cdiscovirtual%7Cdiscovirtual%7C300274%7Csrv&c2=productos_y_servicios&v2=srv&h2=terra%7Cproductos_y_servicios%7Cdiscovirtual%7Cdiscovirtual%7C300274%7Csrv&c3=productos_y_servicios%7Cdiscovirtual&v3=300274&c4=300274&v4=discovirtual.br/vdexecup.html&c5=srv&c6=productos_y_servicios%7Cdiscovirtual%7Cdiscovirtual&c7=discovirtual&v7=terra&c8=discovirtual&c9=300274%7C%7Csrv&c10=discovirtual&c11=enviando_arquivo&c12=300274%7C&c15=terra&c16=productos_y_servicios%7Cdiscovirtual%7Cterra&v19=More%20than%2030%20days&c20=http%3A//stf.terra.com.br/metrics/inc/br/201007300000b.js&v20=New&v44=D%3DpageName&v45=D%3Dg&c47=New&c48=flash%2010&c49=silverlight%203.0&c50=Weekday%20%3A%20Friday%20%3A%2010%3A00AM&v50=Weekday%20%3A%20Friday%20%3A%2010%3A00AM&s=1440x900&c=32&j=1.5&v=Y&k=Y&bw=945&bh=699&ct=lan&hp=N&pid=discovirtual.br/vd.cgi&pidt=1&oid=functiononclick%28%29%7Bjan%3Djan.open%28%27./vdexecup.html%27%2C%27Uploading%27%2C%27toolbar%3D0%2Clocation%3D0%2Cdirectories%3D0%2Cmen&oidt=2&ot=IMAGE&oi=125&AQE=1'
2010/08/06 10:23:56.807| ctx: exit level 5
2010/08/06 10:23:56.810| ctx: enter level 5: 'http://terra.112.2o7.net/b/ss/terrabr/1/H.20.3/s03451603567267?AQB=1&ndh=1&t=6/7/2010%2010%3A23%3A41%205%20180&ce=ISO-8859-1&ns=terra&cdp=3&pageName=discovirtual.br/vdexecup.html&g=http%3A//discovirtual.terra.com.br/vdexecup.html&cc=USD&ch=br.produtoseservicos.discovirtual%7C300274&server=discovirtual.terra.com.br&events=event1&v1=br.produtoseservicos.discovirtual%7C300274&h1=productos_y_servicios%7Cdiscovirtual%7Cdiscovirtual%7C300274%7Csrv&c2=productos_y_servicios&v2=srv&h2=terra%7Cproductos_y_servicios%7Cdiscovirtual%7Cdiscovirtual%7C300274%7Csrv&c3=productos_y_servicios%7Cdiscovirtual&v3=300274&c4=300274&v4=discovirtual.br/vdexecup.html&c5=srv&c6=productos_y_servicios%7Cdiscovirtual%7Cdiscovirtual&c7=discovirtual&v7=terra&c8=discovirtual&c9=300274%7C%7Csrv&c10=discovirtual&c11=enviando_arquivo&c12=300274%7C&c15=terra&c16=productos_y_servicios%7Cdiscovirtual%7Cterra&v19=More%20than%2030%20days&c20=http%3A//stf.terra.com.br/metrics/inc/br/201007300000b.js&v20=New&v44=D%3DpageName&v45=D%3Dg&c47=New&c48=flash%2010&c49=silverlight%203.0&c50=Weekday%20%3A%20Friday%20%3A%2010%3A00AM&v50=Weekday%20%3A%20Friday%20%3A%2010%3A00AM&s=1440x900&c=32&j=1.5&v=Y&k=Y&bw=945&bh=699&ct=lan&hp=N&pid=discovirtual.br/vd.cgi&pidt=1&oid=functiononclick%28%29%7Bjan%3Djan.open%28%27./vdexecup.html%27%2C%27Uploading%27%2C%27toolbar%3D0%2Clocation%3D0%2Cdirectories%3D0%2Cmen&oidt=2&ot=IMAGE&oi=125&AQE=1'
2010/08/06 10:23:56.810| ctx: exit level 5
2010/08/06 10:23:56.812| ctx: enter level 5: 'http://terra.112.2o7.net/b/ss/terrabr/1/H.20.3/s03451603567267?AQB=1&ndh=1&t=6/7/2010%2010%3A23%3A41%205%20180&ce=ISO-8859-1&ns=terra&cdp=3&pageName=discovirtual.br/vdexecup.html&g=http%3A//discovirtual.terra.com.br/vdexecup.html&cc=USD&ch=br.produtoseservicos.discovirtual%7C300274&server=discovirtual.terra.com.br&events=event1&v1=br.produtoseservicos.discovirtual%7C300274&h1=productos_y_servicios%7Cdiscovirtual%7Cdiscovirtual%7C300274%7Csrv&c2=productos_y_servicios&v2=srv&h2=terra%7Cproductos_y_servicios%7Cdiscovirtual%7Cdiscovirtual%7C300274%7Csrv&c3=productos_y_servicios%7Cdiscovirtual&v3=300274&c4=300274&v4=discovirtual.br/vdexecup.html&c5=srv&c6=productos_y_servicios%7Cdiscovirtual%7Cdiscovirtual&c7=discovirtual&v7=terra&c8=discovirtual&c9=300274%7C%7Csrv&c10=discovirtual&c11=enviando_arquivo&c12=300274%7C&c15=terra&c16=productos_y_servicios%7Cdiscovirtual%7Cterra&v19=More%20than%2030%20days&c20=http%3A//stf.terra.com.br/metrics/inc/br/201007300000b.js&v20=New&v44=D%3DpageName&v45=D%3Dg&c47=New&c48=flash%2010&c49=silverlight%203.0&c50=Weekday%20%3A%20Friday%20%3A%2010%3A00AM&v50=Weekday%20%3A%20Friday%20%3A%2010%3A00AM&s=1440x900&c=32&j=1.5&v=Y&k=Y&bw=945&bh=699&ct=lan&hp=N&pid=discovirtual.br/vd.cgi&pidt=1&oid=functiononclick%28%29%7Bjan%3Djan.open%28%27./vdexecup.html%27%2C%27Uploading%27%2C%27toolbar%3D0%2Clocation%3D0%2Cdirectories%3D0%2Cmen&oidt=2&ot=IMAGE&oi=125&AQE=1'
2010/08/06 10:23:56.812| ctx: exit level 5
2010/08/06 10:23:57.892| ctx: enter level 5: 'http://b.scorecardresearch.com/p?c1=2&c2=6906546&c3=&c4=http%3A%2F%2Fdiscovirtual.terra.com.br%2Fvdexecup.html&c5=&c6=&c7=http%3A%2F%2Fdiscovirtual.terra.com.br%2Fvdexecup.html&c8=&c9=&c10=CERT&c15='
2010/08/06 10:23:57.892| ctx: exit level 5
2010/08/06 10:23:57.894| ctx: enter level 5: 'http://b.scorecardresearch.com/p?c1=2&c2=6906546&c3=&c4=http%3A%2F%2Fdiscovirtual.terra.com.br%2Fvdexecup.html&c5=&c6=&c7=http%3A%2F%2Fdiscovirtual.terra.com.br%2Fvdexecup.html&c8=&c9=&c10=CERT&c15='
2010/08/06 10:23:57.894| ctx: exit level 5
2010/08/06 10:23:57.896| ctx: enter level 5: 'http://b.scorecardresearch.com/p?c1=2&c2=6906546&c3=&c4=http%3A%2F%2Fdiscovirtual.terra.com.br%2Fvdexecup.html&c5=&c6=&c7=http%3A%2F%2Fdiscovirtual.terra.com.br%2Fvdexecup.html&c8=&c9=&c10=CERT&c15='
2010/08/06 10:23:57.896| ctx: exit level 5
2010/08/06 10:24:10.281| ctx: enter level 5: 'http://dnl-14.geo.kaspersky.com/bases/apu/apu-0607g.xml.dif'
2010/08/06 10:24:10.281| ctx: exit level 5
2010/08/06 10:24:10.282| ctx: enter level 5: 'http://dnl-14.geo.kaspersky.com/bases/apu/apu-0607g.xml.dif'
2010/08/06 10:24:10.283| ctx: exit level 5
2010/08/06 10:24:11.957| ctx: enter level 5: 'http://dnl-14.geo.kaspersky.com/bases/as/pas/pas-0607g.xml.dif'
2010/08/06 10:24:11.957| ctx: exit level 5
2010/08/06 10:24:11.959| ctx: enter level 5: 'http://dnl-14.geo.kaspersky.com/bases/as/pas/pas-0607g.xml.dif'
2010/08/06 10:24:11.959| ctx: exit level 5
2010/08/06 10:24:12.866| ctx: enter level 5: 'http://dnl-14.geo.kaspersky.com/bases/av/emu/emu-0607g.xml.dif'
2010/08/06 10:24:12.866| ctx: exit level 5
2010/08/06 10:24:12.867| ctx: enter level 5: 'http://dnl-14.geo.kaspersky.com/bases/av/emu/emu-0607g.xml.dif'
2010/08/06 10:24:12.867| ctx: exit level 5

Additional info:

* CentOS release 5.5 (Final), 32 bit
* squid3-3.1.4-1.el5.pp.i386.rpm (from http://www.pramberger.at/peter/services/repository/)
* No more than 5 simultaneous users
* Intel Core 2 Duo E7600, 4 GB RAM, Intel DG31PR motherboard
* Direct connections, without squid, always work.
* Resolv.conf points to 127.0.0.1, which is bind-9.3.6-4.P1.el5_4.2
* Tried with and without "half_closed_clients off".
* Already deleted and recreated /var/cache/squid.
* One of the cache.log files seem to be truncated or with binary characters preventing it to be properly read from the console.
* Found two occurrences of "Exception error:found data bewteen chunk end and CRLF" in cache.log.

My guesses are:

- It could be a hardware problem with the server specifically related to faulty NIC, I/O or bad memory, but there are no system wide errors being logged which would support this and all other server applications are working fine;
- It could be a hardware problem with the wan circuit or provider, but without the proxy server, going directly to Internet, the problem never happens.
- It could be a DNS problem. Unlikely, since the problem is only relates to upload (POST) operations to the same websites which were already resolved by its own named.
- It coud be a DoS launched from an internal infected workstation. Unlikely, squid is not crashing and server load stays at 0.00.
- It could be a squid bug or problem in face of an unknown condition? Unlikely, we have the same software setup (O.S., the same rpm and config of squid 3.1.4) in another remote office which works perfectly with these same upload websites.
- It could be a problem with all the upload websites tried? REALLY unlikely.

So I would like to kindly ask for any suggestions on diagnostics and troubleshooting of this problem.

--------

squid.conf

half_closed_clients off
range_offset_limit -1
maximum_object_size 200 MB
quick_abort_min -1
auth_param basic program /usr/libexec/squid/squid_radius_auth -f /etc/squid/radius.conf
auth_param basic children 5
auth_param basic realm Web-Proxy
auth_param basic credentialsttl 5 minute
auth_param basic casesensitive off
acl manager proto cache_object
acl localhost src 127.0.0.1/32
acl localhost src ::1/128
acl to_localhost dst 127.0.0.0/8 0.0.0.0/32
acl to_localhost dst ::1/128
acl localnet src 192.168.2.0/24
acl localnet src fc00::/7
acl localnet src fe80::/10
acl windowsupdate dstdomain windowsupdate.microsoft.com
acl windowsupdate dstdomain .update.microsoft.com
acl windowsupdate dstdomain download.windowsupdate.com
acl windowsupdate dstdomain redir.metaservices.microsoft.com
acl windowsupdate dstdomain images.metaservices.microsoft.com
acl windowsupdate dstdomain c.microsoft.com
acl windowsupdate dstdomain www.download.windowsupdate.com
acl windowsupdate dstdomain wustat.windows.com
acl windowsupdate dstdomain crl.microsoft.com
acl windowsupdate dstdomain sls.microsoft.com
acl windowsupdate dstdomain productactivation.one.microsoft.com
acl windowsupdate dstdomain ntservicepack.microsoft.com
acl StreamingRequest1 req_mime_type -i ^video/x-ms-asf$
acl StreamingRequest2 req_mime_type -i ^application/vnd.ms.wms-hdr.asfv1$
acl StreamingRequest3 req_mime_type -i ^application/x-mms-framed$
acl StreamingRequest4 req_mime_type -i ^audio/x-pn-realaudio$
acl StreamingReply1 rep_mime_type -i ^video/x-ms-asf$
acl StreamingReply2 rep_mime_type -i ^application/vnd.ms.wms-hdr.asfv1$
acl StreamingReply3 rep_mime_type -i ^application/x-mms-framed$
acl StreamingReply4 rep_mime_type -i ^audio/x-pn-realaudio$
acl SSL_ports port 443
acl Safe_ports port 80
acl Safe_ports port 21
acl Safe_ports port 443
acl Safe_ports port 70
acl Safe_ports port 210
acl Safe_ports port 1025-65535
acl Safe_ports port 280
acl Safe_ports port 488
acl Safe_ports port 591
acl Safe_ports port 777
acl CONNECT method CONNECT
acl wuCONNECT dstdomain www.update.microsoft.com
acl wuCONNECT dstdomain sls.microsoft.com
acl localsites dstdomain .company-xxx.local
acl sites_liberados url_regex -i "/etc/squid/sites.liberados"
acl radius_users proxy_auth REQUIRED
always_direct allow localsites
cache deny nocache
http_access allow manager localhost
http_access allow CONNECT wuCONNECT localnet
http_access allow CONNECT wuCONNECT localhost
http_access allow windowsupdate localnet
http_access allow windowsupdate localhost
http_access deny manager
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access deny StreamingRequest1 all
http_access deny StreamingRequest2 all
http_access deny StreamingRequest3 all
http_access deny StreamingRequest4 all
http_reply_access deny StreamingReply1 all
http_reply_access deny StreamingReply2 all
http_reply_access deny StreamingReply3 all
http_reply_access deny StreamingReply4 all
http_access allow sites_liberados
http_access allow radius_users
http_access deny all
http_port 3128
hierarchy_stoplist cgi-bin ?
cache_dir ufs /var/cache/squid 2500 16 256
coredump_dir /tmp
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern -i (/cgi-bin/|\?) 0 0% 0
refresh_pattern . 0 20% 4320

Rodrigo Ferraz

CONCEPT NETSERVICES
www.conceptnetservices.com
Qualidade. Do início ao fim.
+55 (51) 3355-8000
http://twitter.com/ConceptNetBR
Received on Fri Aug 06 2010 - 15:16:45 MDT

This archive was generated by hypermail 2.2.0 : Fri Aug 06 2010 - 12:00:02 MDT