Re: Another wierd squid 1.0.5 problem

I've noticed that too. The work around is to set positive_dns_ttl to zero.
See
    Message-Id: <199608110217.TAA25744@nlanr.net>
    From: Duane Wessels <wessels@nlanr.net>
    Subject: Re: DNS lookup failures
in this list's archives

chris

In message <Pine.SUN.3.93.960820225922.23073A-100000@bolivar>you write:
>Occassionally, fails to connect to a site, and this persists forever. In
>the cache.log file, there are lines like:
>
>[20/Aug/1996:22:52:17 -0700] comm.c:372: connect: 127.0.0.1:35456: (146) Connection refused.
>
>In this case the URL was ftp://ftp.winsite.com/. If I run ftpget directly,
>it works fine. Here is a trace after sending a SIGUSR2:
>
>------------------------------------------------------------------------
>[20/Aug/1996:22:52:17 -0700] icp.c:1737: asciiProcessInput: size = 52
>[20/Aug/1996:22:52:17 -0700] icp.c:1564: parseHttpRequest: Method is 'GET'
>[20/Aug/1996:22:52:17 -0700] icp.c:1573: parseHttpRequest: Request is 'ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] icp.c:1585: parseHttpRequest: HTTP version is 'HTTP/1.0'
>[20/Aug/1996:22:52:17 -0700] icp.c:1601: parseHttpRequest: Request Header is
>---
>
>Accept: */*
>
>
>---
>[20/Aug/1996:22:52:17 -0700] icp.c:1685: parseHttpRequest: Complete request received
> (acl lines removed)
>[20/Aug/1996:22:52:17 -0700] acl.c:733: aclCheck: match found, returning 1
>[20/Aug/1996:22:52:17 -0700] mime.c:122: mime_get_header: looking for 'If-Modified-Since'
>[20/Aug/1996:22:52:17 -0700] mime.c:122: mime_get_header: looking for 'Pragma'
>[20/Aug/1996:22:52:17 -0700] mime.c:122: mime_get_header: looking for 'Authorization'
>[20/Aug/1996:22:52:17 -0700] icp.c:670: icp_hit_or_miss: GET <URL:ftp://ftp.winsite.com/>
>[20/Aug/1996:22:52:17 -0700] icp.c:697: icp_hit_or_miss: REQ_NOCACHE = NOT SET
>[20/Aug/1996:22:52:17 -0700] icp.c:699: icp_hit_or_miss: REQ_CACHABLE = SET
>[20/Aug/1996:22:52:17 -0700] icp.c:701: icp_hit_or_miss: REQ_HIERARCHICAL = SET
>[20/Aug/1996:22:52:17 -0700] store.c:608: storeGeneratePublicKey: type=1 ftp://ftp.winsite.com/
>[20/Aug/1996:22:52:17 -0700] store.c:573: storeGet: looking up ftp://ftp.winsite.com/
>[20/Aug/1996:22:52:17 -0700] icp.c:755: icp_hit_or_miss: TCP_MISS for 'ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] icp.c:820: icpProcessMISS: 'GET ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] icp.c:822: icpProcessMISS: request_hdr:
>
>Accept: */*
>
>
>[20/Aug/1996:22:52:17 -0700] store.c:717: storeCreateEntry: 'ftp://ftp.winsite.com/' icp flags=51
>[20/Aug/1996:22:52:17 -0700] store.c:1890: storeGetMemSpace: Starting...
>[20/Aug/1996:22:52:17 -0700] store.c:1925: storeGetMemSpace: Can't purge 28884 bytes: http://home.netscape.com/home/whats-cool.html
>[20/Aug/1996:22:52:17 -0700] store.c:1930: storeGetMemSpace: --> e->lock_count 1
>[20/Aug/1996:22:52:17 -0700] store.c:1933: storeGetMemSpace: Current size: 28884 bytes
>[20/Aug/1996:22:52:17 -0700] store.c:1934: storeGetMemSpace: High W Mark: 30198960 bytes
>[20/Aug/1996:22:52:17 -0700] store.c:1935: storeGetMemSpace: Low W Mark: 25165800 bytes
>[20/Aug/1996:22:52:17 -0700] store.c:1936: storeGetMemSpace: Entry count: 22943 items
>[20/Aug/1996:22:52:17 -0700] store.c:1937: storeGetMemSpace: Scanned: 1 items
>[20/Aug/1996:22:52:17 -0700] store.c:1938: storeGetMemSpace: In memory: 1 items
>[20/Aug/1996:22:52:17 -0700] store.c:1939: storeGetMemSpace: Hot vm count: 2 items
>[20/Aug/1996:22:52:17 -0700] store.c:1940: storeGetMemSpace: Expired: 0 items
>[20/Aug/1996:22:52:17 -0700] store.c:1941: storeGetMemSpace: Negative Cached: 0 items
>[20/Aug/1996:22:52:17 -0700] store.c:1942: storeGetMemSpace: Can't purge: 1 items
>[20/Aug/1996:22:52:17 -0700] store.c:1943: storeGetMemSpace: Can't purge size: 28884 bytes
>[20/Aug/1996:22:52:17 -0700] store.c:1944: storeGetMemSpace: Sorting LRU_list: 0 items
>[20/Aug/1996:22:52:17 -0700] store.c:1977: storeGetMemSpace: After freeing size: 28884 bytes
>[20/Aug/1996:22:52:17 -0700] store.c:1978: storeGetMemSpace: Purged: 0 items
>[20/Aug/1996:22:52:17 -0700] store.c:1979: storeGetMemSpace: Released: 0 items
>[20/Aug/1996:22:52:17 -0700] store.c:1985: storeGetMemSpace: Done.
>[20/Aug/1996:22:52:17 -0700] store.c:228: new_MemObject: returning 217de0
>[20/Aug/1996:22:52:17 -0700] store.c:241: new_StoreEntry: returning 241228
>[20/Aug/1996:22:52:17 -0700] store.c:595: storeGeneratePrivateKey: 'ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] store.c:339: storeHashInsert: Inserting Entry 241228 key '125486/GET/ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] store.c:295: new_MemObjectData: calling memInit()
>[20/Aug/1996:22:52:17 -0700] store.c:831: storeRegister: FD 21 '125486/GET/ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] proto.c:286: protoDispatch: GET URL: ftp://ftp.winsite.com/
>[20/Aug/1996:22:52:17 -0700] proto.c:287: request_hdr:
>Accept: */*
>
>
>[20/Aug/1996:22:52:17 -0700] comm.c:859: comm_add_close_handler: fd=21 handler=0x31e4c data=0xf17570
>[20/Aug/1996:22:52:17 -0700] proto.c:309: protoDispatch: inside_firewall = 2 (NO_FIREWALL)
>[20/Aug/1996:22:52:17 -0700] proto.c:312: protoDispatch: query_neighbors = 8192
>[20/Aug/1996:22:52:17 -0700] proto.c:313: protoDispatch: n_edges = 0
>[20/Aug/1996:22:52:17 -0700] proto.c:314: protoDispatch: single_parent = N/A
>[20/Aug/1996:22:52:17 -0700] ipcache.c:899: ipcache_nbgethostbyname: FD 21: Name 'ftp.winsite.com'.
>[20/Aug/1996:22:52:17 -0700] ipcache.c:924: ipcache_nbgethostbyname: HIT for 'ftp.winsite.com'
>[20/Aug/1996:22:52:17 -0700] proto.c:499: getFromCache: FD 21 <URL:ftp://ftp.winsite.com/>
>[20/Aug/1996:22:52:17 -0700] proto.c:500: getFromCache: --> type = GET
>[20/Aug/1996:22:52:17 -0700] proto.c:502: getFromCache: --> getting from 'source'
>[20/Aug/1996:22:52:17 -0700] proto.c:412: protoCancelTimeout: FD 21 <URL:ftp://ftp.winsite.com/>
>[20/Aug/1996:22:52:17 -0700] ftp.c:597: FtpStart: FD 21 <URL:ftp://ftp.winsite.com/>
>[20/Aug/1996:22:52:17 -0700] store.c:479: storeLockObject: locks 2: '125486/GET/ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] ftp.c:606: FtpStart: FD 21, host=ftp.winsite.com, path=/, user=anonymous, passwd=webmaster@parc.xerox.com
>[20/Aug/1996:22:52:17 -0700] comm.c:859: comm_add_close_handler: fd=23 handler=0x21c30 data=0x29010f0
>[20/Aug/1996:22:52:17 -0700] comm.c:372: connect: 127.0.0.1:35456: (146) Connection refused.
>[20/Aug/1996:22:52:17 -0700] store.c:1703: storeAbort: '125486/GET/ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] store.c:479: storeLockObject: locks 3: '125486/GET/ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] store.c:1020: storeAppend: appending 800 bytes for '125486/GET/ftp://ftp.winsite.com/'
>[20/Aug/1996:22:52:17 -0700] store.c:1025: storeAppend: growing store_mem_size by 800
>[20/Aug/1996:22:52:17 -0700] store.c:1026: storeAppend: store_mem_size = 29684
>[20/Aug/1996:22:52:17 -0700] stmem.c:212: memAppend: len 800
>[20/Aug/1996:22:52:17 -0700] store.c:1031: storeAppend: e_current_len = 800
>[20/Aug/1996:22:52:17 -0700] icp.c:478: icpHandleStore: FD 21: off 0: <URL:ftp://ftp.winsite.com/>
>[20/Aug/1996:22:52:17 -0700] icp.c:483: icpHandleStore: abort_code=19
>[20/Aug/1996:22:52:17 -0700] icp.c:372: icpSendERROR: code 4: port 8000: msg: 'HTTP/1.0 400 Cache Detected Error
>Server: squid/1.0.5
>Date: Wednesday, 21-Aug-96 05:52:17 GMT
>Expires: Wednesday, 21-Aug-96 05:57:17 GMT
>Last-Modified: Wednesday, 21-Aug-96 05:52:17 GMT
>Content-Type: text/html
>Content-Length: 565
>
>
><TITLE>ERROR: The requested URL could not be retrieved</TITLE>
><H2>The requested URL could not be retrieved</H2>
><HR>
><P>
>While trying to retrieve the URL:
>ftp://ftp.winsite.com/
><P>
>The following error was encountered:
><UL>
><LI><STRONG>Connection Failed</STRONG>
></UL>
><P>The system returned:
><PRE><I> (146) Connection refused</I></PRE>
><P>This means that:
><PRE>
> The remote site or server may be down. Please try again soon.
></PRE>
><P> <HR>
><ADDRESS>
>Generated by squid/1.0.5@wwwproxy0.parc.xerox.com
></ADDRESS>
>
>'
>[20/Aug/1996:22:52:17 -0700] comm.c:1362: comm_write: FD 21: sz 800: tout 30: hndl 273e4: data 27afd0.
>[20/Aug/1996:22:52:17 -0700] store.c:538: storeUnlockObject: key '125486/GET/ftp://ftp.winsite.com/' count=2
>[20/Aug/1996:22:52:17 -0700] comm.c:305: comm_set_fd_lifetime: FD 23 lft -1
>[20/Aug/1996:22:52:17 -0700] comm.c:471: comm_close: FD 23
>[20/Aug/1996:22:52:17 -0700] store.c:538: storeUnlockObject: key '125486/GET/ftp://ftp.winsite.com/' count=1
>[20/Aug/1996:22:52:17 -0700] ipcache.c:562: ipcache_call_pending: Called 1 handlers.
>------------------------------------------------------------------------
>Anyone seen this? I have to restart the server to clear this.
>
>Oh yes, this is on a SunOS 5.5 (Solaris) system.
>
>Edward Moy
>Xerox Palo Alto Research Center
>3333 Coyote Hill Rd.
>Palo Alto, CA 94304
>
>Email: moy@parc.xerox.com
>WWW: http://www.parc.xerox.com/moy/
>PGP key fingerprint: AA A1 12 00 9B 13 07 45 19 61 26 A1 AF AF 99 F3
>
Received on Wed Aug 21 1996 - 00:10:31 MDT