> Andre Albsmeier wrote:
>
> some things that are delayed or run with a hour interval, but if this
> was the cause then your Squid should die with a interval of somewhat
> more than one hour, and not on the same time each hour..
>
> Check your crontabs (and cron log) some more. I still think you have
> something running that triggers something in Squid.
>
> Since it seems to die exactly on the hour, you could try to enable debug
> logging before it dies (squid -k debug). run squid -k debug at 2
> miniutes before full hour, and we should get a quite clear picture of
> what Squid was doing when it dies (if it does). If it doesn't die you
> can run squid -k debug again to return the logging to normal.
Thanks again for the hint! All people who wrote about the crontab were
partially right: There IS a crontab job but NOT on the squid machine.
There is some client who does periodically request a URL to see if
it has changed. This is done with a perl script. When this perl script
is run, squid dies immediately. I still have to find out what's
happening here but I think this perl script does something strange
which confuses squid and it dies.
This script was also running a long time with 1.1.20 and never caused
a problem; so I am really curious finding out what has changed from
version 1.1.20 --> 1.1.21 to cause this behaviour...
Attached below is the debug log which was enabled by "squid -k debug".
Maybe some of the squid hackers got an idea whats happening there.
1998/03/30 17:59:56| comm_select: time out: 891273596.
1998/03/30 17:59:56| eventRun: Running 'storeMaintain'
1998/03/30 17:59:56| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 17:59:56| Removed 0 of 0 objects from bucket 6645
1998/03/30 17:59:57| comm_select: 0 sockets ready at 891273597
1998/03/30 17:59:57| comm_select: time out: 891273597.
1998/03/30 17:59:57| eventRun: Running 'storeMaintain'
1998/03/30 17:59:57| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 17:59:57| Removed 0 of 0 objects from bucket 6645
1998/03/30 17:59:58| comm_select: 0 sockets ready at 891273598
1998/03/30 17:59:58| comm_select: time out: 891273598.
1998/03/30 17:59:58| eventRun: Running 'storeMaintain'
1998/03/30 17:59:58| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 17:59:58| Removed 0 of 11 objects from bucket 8905
1998/03/30 17:59:59| comm_select: 0 sockets ready at 891273599
1998/03/30 17:59:59| comm_select: time out: 891273599.
1998/03/30 17:59:59| eventRun: Running 'storeMaintain'
1998/03/30 17:59:59| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 17:59:59| Removed 0 of 0 objects from bucket 8905
1998/03/30 18:00:00| comm_select: 0 sockets ready at 891273600
1998/03/30 18:00:00| comm_select: time out: 891273600.
1998/03/30 18:00:00| eventRun: Running 'storeMaintain'
1998/03/30 18:00:00| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 18:00:00| Removed 0 of 0 objects from bucket 8905
1998/03/30 18:00:01| comm_select: 0 sockets ready at 891273601
1998/03/30 18:00:01| comm_select: time out: 891273601.
1998/03/30 18:00:01| eventRun: Running 'storeMaintain'
1998/03/30 18:00:01| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 18:00:01| Removed 0 of 0 objects from bucket 8905
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_set_fd_lifetime: FD 19 lft 12000
1998/03/30 18:00:02| asciiHandleConn: FD 19: accepted, lifetime 891285602
1998/03/30 18:00:02| comm_add_close_handler: FD 19, handler=0x17844, data=0x13c2e00
now the script starts running
1998/03/30 18:00:02| fqdncache_nbgethostbyaddr: FD -1: Name '192.168.48.48'.
1998/03/30 18:00:02| fqdncache_nbgethostbyaddr: MISS for '192.168.48.48'
1998/03/30 18:00:02| fqdncacheAddNew: Adding '192.168.48.48', status=P
1998/03/30 18:00:02| fqdncache_add_to_hash: name <192.168.48.48>
1998/03/30 18:00:02| comm_write: FD 5: sz 14: tout 0: hndl 0x0: data 0x0.
1998/03/30 18:00:02| fqdncache_dnsDispatch: Request sent to DNS server #1.
1998/03/30 18:00:02| eventRun: Running 'storeMaintain'
1998/03/30 18:00:02| eventAdd: Adding 'storeMaintain', in 1 seconds
1998/03/30 18:00:02| Removed 0 of 0 objects from bucket 8905
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 5 ready for writing
1998/03/30 18:00:02| commHandleWrite: FD 5: state=0x547760, off 0, sz 14.
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 19 ready for reading
1998/03/30 18:00:02| clientReadRequest: FD 19: reading request...
1998/03/30 18:00:02| clientReadRequest: len = 4095
1998/03/30 18:00:02| parseHttpRequest: Method is 'HEAD'
1998/03/30 18:00:02| parseHttpRequest: Request is 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| parseHttpRequest: HTTP version is 'HTTP/1.0
Host: walhalla.mchp.s'
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 5 ready for reading
1998/03/30 18:00:02| fqdncache_dnsHandleRead: Result from DNS ID 1 (97 bytes)
1998/03/30 18:00:02| fqdncache_parsebuffer: parsing:
$name 192.168.48.48
$h_name wallace.ofw.tld
$h_len 4
$ipcount 1
192.168.48.48
$aliascount 0
$end
1998/03/30 18:00:02| fqdncache_call_pending: Called 1 handlers.
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 19 ready for reading
1998/03/30 18:00:02| clientReadRequest: FD 19: reading request...
1998/03/30 18:00:02| clientReadRequest: len = 3995
1998/03/30 18:00:02| parseHttpRequest: Method is 'HEAD'
1998/03/30 18:00:02| parseHttpRequest: Request is 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| parseHttpRequest: HTTP version is 'HTTP/1.0
Host: walhalla.mchp.s'
1998/03/30 18:00:02| parseHttpRequest: Request Header is
Host: walhalla.mchp.siemens.de:8001
User-Agent: libwww-perl/5.20
1998/03/30 18:00:02| parseHttpRequest: Complete request received
1998/03/30 18:00:02| comm_add_close_handler: FD 23, handler=0x1b3f0, data=0x13c2e00
1998/03/30 18:00:02| comm_add_close_handler: FD 23, handler=0x96d4, data=0x547760
1998/03/30 18:00:02| ipcache_gethostbyname: '192.168.48.48', flags=1
1998/03/30 18:00:02| comm_set_fd_lifetime: FD 23 lft 120
1998/03/30 18:00:02| comm_connect_addr: FD 23 connection pending, lifetime 891273722
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 23 ready for writing
1998/03/30 18:00:02| comm_set_fd_lifetime: FD 23 lft 12000
1998/03/30 18:00:02| comm_connect_addr: FD 23 connected to 192.168.48.48:113, lifetime 891285602.
1998/03/30 18:00:02| comm_write: FD 23: sz 12: tout 5: hndl 0x1b54c: data 0x13c2e00.
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 23 ready for writing
1998/03/30 18:00:02| commHandleWrite: FD 23: state=0x19724c0, off 0, sz 12.
1998/03/30 18:00:02| identRequestComplete: FD 23: wrote 12 bytes
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 23 ready for reading
1998/03/30 18:00:02| identReadReply: FD 23: Read '1169 , 3128 : USERID : UNIX :franz'
1998/03/30 18:00:02| comm_close: FD 23
1998/03/30 18:00:02| commCallCloseHandlers: FD 23
1998/03/30 18:00:02| mime_get_header: looking for 'User-Agent'
1998/03/30 18:00:02| mime_get_header: checking 'User-Agent: libwww-perl/5.20'
1998/03/30 18:00:02| mime_get_header: returning 'libwww-perl/5.20'
the acl stuff
1998/03/30 18:00:02| aclCheck: checking 'http_access deny manager !localhost !MY_WWW_SERVER'
1998/03/30 18:00:02| aclMatchAclList: checking manager
1998/03/30 18:00:02| aclMatchAcl: checking 'acl manager proto cache_object'
1998/03/30 18:00:02| aclMatchAclList: returning 0
1998/03/30 18:00:02| aclCheck: checking 'http_access allow MY_WWW_SERVER MY_PROXY_SERVER'
1998/03/30 18:00:02| aclMatchAclList: checking MY_WWW_SERVER
1998/03/30 18:00:02| aclMatchAcl: checking 'acl MY_WWW_SERVER src www.top.tld'
1998/03/30 18:00:02| aclMatchIp: h = 192.168.48.48
1998/03/30 18:00:02| aclMatchIp: addr1 = 192.168.1.10
1998/03/30 18:00:02| aclMatchIp: addr2 = 0.0.0.0
1998/03/30 18:00:02| aclMatchIp: returning 0
1998/03/30 18:00:02| aclMatchAclList: returning 0
1998/03/30 18:00:02| aclCheck: checking 'http_access deny CONNECT !SSL_ports'
1998/03/30 18:00:02| aclMatchAclList: checking CONNECT
1998/03/30 18:00:02| aclMatchAcl: checking 'acl CONNECT method CONNECT'
1998/03/30 18:00:02| aclMatchAclList: returning 0
1998/03/30 18:00:02| aclCheck: checking 'http_access deny Dangerous_ports'
1998/03/30 18:00:02| aclMatchAclList: checking Dangerous_ports
1998/03/30 18:00:02| aclMatchAcl: checking 'acl Dangerous_ports port 7 9 19'
1998/03/30 18:00:02| aclMatchAclList: returning 0
1998/03/30 18:00:02| aclCheck: checking 'http_access deny MSEXPLORER'
1998/03/30 18:00:02| aclMatchAclList: checking MSEXPLORER
1998/03/30 18:00:02| aclMatchAcl: checking 'acl MSEXPLORER browser MSIE'
1998/03/30 18:00:02| aclMatchRegex: checking 'libwww-perl/5.20'
1998/03/30 18:00:02| aclMatchRegex: looking for 'MSIE'
1998/03/30 18:00:02| aclMatchAclList: returning 0
1998/03/30 18:00:02| aclCheck: checking 'http_access deny NORC5'
1998/03/30 18:00:02| aclMatchAclList: checking NORC5
1998/03/30 18:00:02| aclMatchAcl: checking 'acl NORC5 urlpath_regex rc5\.cgi$'
1998/03/30 18:00:02| aclMatchRegex: checking '/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| aclMatchRegex: looking for 'rc5\.cgi$'
1998/03/30 18:00:02| aclMatchAclList: returning 0
1998/03/30 18:00:02| aclCheck: checking 'http_access allow NIH_EXT'
1998/03/30 18:00:02| aclMatchAclList: checking NIH_EXT
some acl stuff deleted
1998/03/30 18:00:02| aclMatchIdent: looking for 'root'
1998/03/30 18:00:02| aclMatchIdent: looking for 'andre'
1998/03/30 18:00:02| aclMatchIdent: looking for 'clemens'
1998/03/30 18:00:02| aclMatchIdent: looking for 'franz'
1998/03/30 18:00:02| aclMatchAclList: returning 1
1998/03/30 18:00:02| aclCheck: match found, returning 1
this is the url that is being checked
1998/03/30 18:00:02| clientAccessCheckDone: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' answer=1
1998/03/30 18:00:02| redirectStart: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| comm_write: FD 10: sz 103: tout 0: hndl 0x0: data 0x0.
1998/03/30 18:00:02| redirectDispatch: Request sent to Redirector #1, 103 bytes
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 10 ready for writing
1998/03/30 18:00:02| commHandleWrite: FD 10: state=0x19724c0, off 0, sz 103.
1998/03/30 18:00:02| comm_select: 1 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 10 ready for reading
1998/03/30 18:00:02| redirectHandleRead: 1 bytes from Redirector #1.
1998/03/30 18:00:02| redirectHandleRead: reply: ''
1998/03/30 18:00:02| clientRedirectDone: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' result=
1998/03/30 18:00:02| mime_get_header: looking for 'If-Modified-Since'
1998/03/30 18:00:02| mime_get_header: looking for 'Pragma'
1998/03/30 18:00:02| mime_get_header: looking for 'Range'
1998/03/30 18:00:02| mime_get_header: looking for 'Request-Range'
1998/03/30 18:00:02| mime_get_header: looking for 'Authorization'
1998/03/30 18:00:02| mime_get_header: looking for 'Via'
1998/03/30 18:00:02| mime_get_header: looking for 'Cache-control'
1998/03/30 18:00:02| icpProcessRequest: HEAD 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| icpProcessRequest: REQ_NOCACHE = NOT SET
1998/03/30 18:00:02| icpProcessRequest: REQ_CACHABLE = SET
1998/03/30 18:00:02| icpProcessRequest: REQ_HIERARCHICAL = NOT SET
1998/03/30 18:00:02| storeGeneratePublicKey: type=1 http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm
1998/03/30 18:00:02| storeGet: looking up http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm
1998/03/30 18:00:02| refreshCheck: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| refreshCheck: Matched '^http:// 14400 40% 12096000'
1998/03/30 18:00:02| refreshCheck: age = 13142
1998/03/30 18:00:02| refreshCheck: NO: age < min
1998/03/30 18:00:02| storeLockObject: key 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' count=1
1998/03/30 18:00:02| storeLockObject: OK: swap_status is SWAP_OK
1998/03/30 18:00:02| new_MemObject: returning 0xc83380
1998/03/30 18:00:02| storeSwapInStart: initialized swap file '/usr/local/squid/cache/0F/25/0000825F' for 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| new_MemObjectData: calling memInit()
1998/03/30 18:00:02| icpProcessRequest: TCP_HIT for 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| icpSendMoreData: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' sz 28793: len 0: off 0.
1998/03/30 18:00:02| comm_write: FD 19: sz 0: tout 30: hndl 0x181e8: data 0x13c2e00.
1998/03/30 18:00:02| comm_select: 2 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 19 ready for writing
1998/03/30 18:00:02| commHandleWrite: FD 19: state=0x1972520, off 0, sz 0.
1998/03/30 18:00:02| clientWriteComplete: FD 19, sz 0, err 0, off 0, len 28793
1998/03/30 18:00:02| storeRegister: FD 19 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| comm_select: FD 23 ready for reading
1998/03/30 18:00:02| storeSwapInHandle: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| storeSwapInHandle: e->swap_offset = 0
1998/03/30 18:00:02| storeSwapInHandle: e->e_current_len = 0
1998/03/30 18:00:02| storeSwapInHandle: e->object_len = 28793
1998/03/30 18:00:02| httpParseReplyHeaders: HTTP/1.0 200 Document follows
1998/03/30 18:00:02| httpParseReplyHeaders: MIME-Version: 1.0
1998/03/30 18:00:02| httpParseReplyHeaders: Server: CERN/3.0
1998/03/30 18:00:02| httpParseReplyHeaders: Date: Tuesday, 10-Mar-98 16:19:45 GMT
1998/03/30 18:00:02| httpParseReplyHeaders: Content-Type: text/html
1998/03/30 18:00:02| httpParseReplyHeaders: Content-Length: 28588
1998/03/30 18:00:02| httpParseReplyHeaders: Last-Modified: Tuesday, 10-Mar-98 16:08:16 GMT
1998/03/30 18:00:02| storeAppend: appending 8192 bytes for 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| memAppend: len 8192
1998/03/30 18:00:02| icpHandleStore: FD 19 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| icpSendMoreData: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' sz 28793: len 8192: off 0.
1998/03/30 18:00:02| memCopy: offset 0: size 4096
1998/03/30 18:00:02| comm_write: FD 19: sz 205: tout 30: hndl 0x181e8: data 0x13c2e00.
1998/03/30 18:00:02| comm_select: 2 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 19 ready for writing
1998/03/30 18:00:02| commHandleWrite: FD 19: state=0x547760, off 0, sz 205.
1998/03/30 18:00:02| clientWriteComplete: FD 19, sz 205, err 0, off 8192, len 28793
1998/03/30 18:00:02| storeRegister: FD 19 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| comm_select: FD 23 ready for reading
1998/03/30 18:00:02| storeSwapInHandle: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| storeSwapInHandle: e->swap_offset = 8192
1998/03/30 18:00:02| storeSwapInHandle: e->e_current_len = 8192
1998/03/30 18:00:02| storeSwapInHandle: e->object_len = 28793
1998/03/30 18:00:02| storeAppend: appending 8192 bytes for 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| memAppend: len 8192
1998/03/30 18:00:02| icpHandleStore: FD 19 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| icpSendMoreData: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' sz 28793: len 16384: off 8192.
1998/03/30 18:00:02| memCopy: offset 8192: size 4096
1998/03/30 18:00:02| comm_write: FD 19: sz 4450: tout 30: hndl 0x181e8: data 0x13c2e00.
1998/03/30 18:00:02| comm_select: 2 sockets ready at 891273602
1998/03/30 18:00:02| comm_select: FD 19 ready for writing
1998/03/30 18:00:02| commHandleWrite: FD 19: state=0x547760, off 0, sz 4450.
1998/03/30 18:00:02| clientWriteComplete: FD 19, sz 4450, err 0, off 16384, len 28793
1998/03/30 18:00:02| storeRegister: FD 19 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| comm_select: FD 23 ready for reading
1998/03/30 18:00:02| storeSwapInHandle: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| storeSwapInHandle: e->swap_offset = 16384
1998/03/30 18:00:02| storeSwapInHandle: e->e_current_len = 16384
1998/03/30 18:00:02| storeSwapInHandle: e->object_len = 28793
1998/03/30 18:00:02| storeAppend: appending 8192 bytes for 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| memAppend: len 8192
1998/03/30 18:00:02| icpHandleStore: FD 19 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm'
1998/03/30 18:00:02| icpSendMoreData: 'http://walhalla.mchp.siemens.de:8001/ka-infothek/ka/ai/bv.htm' sz 28793: len 24576: off 16384.
and here, it crashes, I think
1998/03/30 18:00:02| memCopy: offset 16384: size 4096
FATAL: Received Segment Violation...dying.
shut down
1998/03/30 18:00:02| storeWriteCleanLog: Starting...
1998/03/30 18:00:02| 4096 lines written so far.
1998/03/30 18:00:02| 8192 lines written so far.
1998/03/30 18:00:02| 12288 lines written so far.
1998/03/30 18:00:02| 16384 lines written so far.
1998/03/30 18:00:03| 20480 lines written so far.
1998/03/30 18:00:03| 24576 lines written so far.
1998/03/30 18:00:03| 28672 lines written so far.
1998/03/30 18:00:03| 32768 lines written so far.
1998/03/30 18:00:03| 36864 lines written so far.
-- HP-UGs: The Microsoft Windows(tm) of the Unix(tm) world.Received on Mon Mar 30 1998 - 09:14:56 MST
This archive was generated by hypermail pre-2.1.9 : Tue Dec 09 2003 - 16:39:29 MST