Hello, Am 26.08.09 18:24, "John Doe" <jdmls@xxxxxxxxx> schrieb: > From: Maik Kündig <Maik.Kuendig@xxxxxxxxxxxxxx> >> auth_param basic program /usr/local/bin/my-auth.pl >> external_acl_type myAclType children=1 ttl=1 %SRC %LOGIN >> /usr/local/bin/foobar >> acl MyAcl external myAclType >> http_access allow MyAcl > > Maybe could you try with 'ttl=10'? > If it is still not working, could you try to set 'concurrency=0'? Don't work, I have attached the debug output. May this is a Problem? 2009/08/26 18:44:13| The reply for GET http://www.openbsd.org/ is ALLOWED, because it matched 'MyAcl' 2009/08/26 18:44:13| The request GET http://www.openbsd.org/ is DENIED, because it matched 'MyAcl' -----8<----- 2009/08/26 18:43:56| Starting Squid Cache version 2.7.STABLE3 for i386-debian-linux-gnu... 2009/08/26 18:43:56| Process ID 11308 2009/08/26 18:43:56| With 1024 file descriptors available 2009/08/26 18:43:56| Using epoll for the IO loop 2009/08/26 18:43:56| DNS Socket created at 0.0.0.0, port 37780, FD 6 2009/08/26 18:43:56| Adding domain localdomain from /etc/resolv.conf 2009/08/26 18:43:56| Adding domain localdomain from /etc/resolv.conf 2009/08/26 18:43:56| Adding nameserver 192.168.32.2 from /etc/resolv.conf 2009/08/26 18:43:56| helperOpenServers: Starting 5 'my-auth.pl' processes 2009/08/26 18:43:56| helperOpenServers: Starting 1 'foobar' processes 2009/08/26 18:43:56| User-Agent logging is disabled. 2009/08/26 18:43:56| Referer logging is disabled. 2009/08/26 18:43:56| logfileOpen: opening log /var/log/squid/access.log 2009/08/26 18:43:56| Unlinkd pipe opened on FD 17 2009/08/26 18:43:56| Swap maxSize 102400 KB, estimated 7876 objects 2009/08/26 18:43:56| Target number of buckets: 393 2009/08/26 18:43:56| Using 8192 Store buckets 2009/08/26 18:43:56| Max Mem size: 8192 KB 2009/08/26 18:43:56| Max Swap size: 102400 KB 2009/08/26 18:43:56| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec 2009/08/26 18:43:56| logfileOpen: opening log /var/log/squid/store.log 2009/08/26 18:43:56| Rebuilding storage in /var/spool/squid (CLEAN) 2009/08/26 18:43:56| Using Least Load store dir selection 2009/08/26 18:43:56| Set Current Directory to /var/spool/squid 2009/08/26 18:43:56| Loaded Icons. 2009/08/26 18:43:57| Accepting proxy HTTP connections at 0.0.0.0, port 3128, FD 19. 2009/08/26 18:43:57| Accepting ICP messages at 0.0.0.0, port 3130, FD 20. 2009/08/26 18:43:57| HTCP Disabled. 2009/08/26 18:43:57| WCCP Disabled. 2009/08/26 18:43:57| Ready to serve requests. 2009/08/26 18:43:57| Done reading /var/spool/squid swaplog (0 entries) 2009/08/26 18:43:57| Finished rebuilding storage from disk. 2009/08/26 18:43:57| 0 Entries scanned 2009/08/26 18:43:57| 0 Invalid entries. 2009/08/26 18:43:57| 0 With invalid flags. 2009/08/26 18:43:57| 0 Objects loaded. 2009/08/26 18:43:57| 0 Objects expired. 2009/08/26 18:43:57| 0 Objects cancelled. 2009/08/26 18:43:57| 0 Duplicate URLs purged. 2009/08/26 18:43:57| 0 Swapfile clashes avoided. 2009/08/26 18:43:57| Took 0.3 seconds ( 0.0 objects/sec). 2009/08/26 18:43:57| Beginning Validation Procedure 2009/08/26 18:43:57| Completed Validation Procedure 2009/08/26 18:43:57| Validated 0 Entries 2009/08/26 18:43:57| store_swap_size = 0k 2009/08/26 18:43:57| storeLateRelease: released 0 objects 2009/08/26 18:44:00| comm_select: timeout 472 2009/08/26 18:44:01| comm_select: time out 2009/08/26 18:44:01| comm_select: timeout 1 2009/08/26 18:44:01| comm_select: time out 2009/08/26 18:44:01| eventRun: RUN ID 19 2009/08/26 18:44:01| eventRun: Running 'MaintainSwapSpace', id 18 ... 2009/08/26 18:44:08| created entry 0x892d7d0: 'Server: squid/2.7.STABLE3' 2009/08/26 18:44:08| 0x892c788 adding entry: 47 at 0 2009/08/26 18:44:08| created entry 0x892d838: 'Date: Wed, 26 Aug 2009 16:44:08 GMT' 2009/08/26 18:44:08| 0x892c788 adding entry: 23 at 1 2009/08/26 18:44:08| created entry 0x892d858: 'Content-Type: text/html' 2009/08/26 18:44:08| 0x892c788 adding entry: 18 at 2 2009/08/26 18:44:08| created entry 0x892e1b0: 'Content-Length: 1330' 2009/08/26 18:44:08| 0x892c788 adding entry: 14 at 3 2009/08/26 18:44:08| created entry 0x892e1f8: 'Expires: Wed, 26 Aug 2009 16:44:08 GMT' 2009/08/26 18:44:08| 0x892c788 adding entry: 25 at 4 2009/08/26 18:44:08| created entry 0x892e240: 'X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0' 2009/08/26 18:44:08| 0x892c788 adding entry: 61 at 5 2009/08/26 18:44:08| authenticateFixHeader: headertype:38 authuser:(nil) 2009/08/26 18:44:08| authenticateFixErrorHeader: Sending type:38 header: 'Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:08| created entry 0x892e288: 'Proxy-Authenticate: Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:08| 0x892c788 adding entry: 38 at 6 2009/08/26 18:44:08| cleaning hdr: 0x892b618 owner: 3 2009/08/26 18:44:08| packing sline 0x892b608 using 0xbf84db50: 2009/08/26 18:44:08| HTTP/1.0 407 Proxy Authentication Required ... 2009/08/26 18:44:13| comm_select: timeout 1000 2009/08/26 18:44:13| comm_call_handlers(): got fd=19 read_event=1 write_event=0 F->read_handler=0x80666d0 F->write_handler=(nil) 2009/08/26 18:44:13| comm_call_handlers(): Calling read handler on fd=19 2009/08/26 18:44:13| commSetSelect: FD 19 type 1 2009/08/26 18:44:13| commSetEvents(fd=19) 2009/08/26 18:44:13| fd_open FD 18 HTTP Request 2009/08/26 18:44:13| httpAccept: FD 18: accepted port 3128 client 192.168.32.1:53074 2009/08/26 18:44:13| cbdataLock: 0x872d248 2009/08/26 18:44:13| comm_add_close_handler: FD 18, handler=0x806dd30, data=0x892aaa8 2009/08/26 18:44:13| cbdataLock: 0x892aaa8 2009/08/26 18:44:13| commSetTimeout: FD 18 timeout 300 2009/08/26 18:44:13| aclCheckFast: list: 0x872b7f0 2009/08/26 18:44:13| aclMatchAclList: checking all 2009/08/26 18:44:13| aclMatchAcl: checking 'acl all src all' 2009/08/26 18:44:13| aclMatchIp: '192.168.32.1' found 2009/08/26 18:44:13| aclMatchAclList: returning 1 2009/08/26 18:44:13| commSetSelect: FD 18 type 1 2009/08/26 18:44:13| commSetEvents(fd=18) 2009/08/26 18:44:13| comm_accept: FD 19: (11) Resource temporarily unavailable 2009/08/26 18:44:13| comm_select: timeout 485 2009/08/26 18:44:13| comm_call_handlers(): got fd=18 read_event=1 write_event=0 F->read_handler=0x806acf0 F->write_handler=(nil) 2009/08/26 18:44:13| comm_call_handlers(): Calling read handler on fd=18 2009/08/26 18:44:13| clientReadRequest: FD 18: reading request... 2009/08/26 18:44:13| cbdataLock: 0x892aaa8 2009/08/26 18:44:13| cbdataValid: 0x892aaa8 2009/08/26 18:44:13| Parser: retval 1: from 0->37: method 0->2; url 4->26; version 28->36 (1/1) 2009/08/26 18:44:13| parseHttpRequest: Method is 'GET' 2009/08/26 18:44:13| parseHttpRequest: URI is 'http://www.openbsd.org/' 2009/08/26 18:44:13| parseHttpRequest: req_hdr = {Host: www.openbsd.org User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9 Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5 Accept-Language: de-de Accept-Encoding: gzip, deflate Connection: keep-alive Proxy-Connection: keep-alive } 2009/08/26 18:44:13| parseHttpRequest: prefix_sz = 408, req_line_sz = 38 2009/08/26 18:44:13| parseHttpRequest: Request Header is Host: www.openbsd.org User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9 Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5 Accept-Language: de-de Accept-Encoding: gzip, deflate Connection: keep-alive Proxy-Connection: keep-alive 2009/08/26 18:44:13| parseHttpRequest: Complete request received 2009/08/26 18:44:13| commSetTimeout: FD 18 timeout 86400 2009/08/26 18:44:13| init-ing hdr: 0x8907f6c owner: 2 2009/08/26 18:44:13| parsing hdr: (0x8907f6c) Host: www.openbsd.org User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9 Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5 Accept-Language: de-de Accept-Encoding: gzip, deflate Connection: keep-alive Proxy-Connection: keep-alive 2009/08/26 18:44:13| creating entry 0x892f8b8: near 'Host: www.openbsd.org' 2009/08/26 18:44:13| created entry 0x892f8b8: 'Host: www.openbsd.org' 2009/08/26 18:44:13| 0x8907f6c adding entry: 27 at 0 2009/08/26 18:44:13| creating entry 0x892f810: near 'User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9' 2009/08/26 18:44:13| created entry 0x892f810: 'User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9' 2009/08/26 18:44:13| 0x8907f6c adding entry: 50 at 1 2009/08/26 18:44:13| creating entry 0x892f6e0: near 'Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5' 2009/08/26 18:44:13| created entry 0x892f6e0: 'Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5' 2009/08/26 18:44:13| 0x8907f6c adding entry: 0 at 2 2009/08/26 18:44:13| creating entry 0x892f698: near 'Accept-Language: de-de' 2009/08/26 18:44:13| created entry 0x892f698: 'Accept-Language: de-de' 2009/08/26 18:44:13| 0x8907f6c adding entry: 3 at 3 2009/08/26 18:44:13| creating entry 0x892f5c8: near 'Accept-Encoding: gzip, deflate' 2009/08/26 18:44:13| created entry 0x892f5c8: 'Accept-Encoding: gzip, deflate' 2009/08/26 18:44:13| 0x8907f6c adding entry: 2 at 4 2009/08/26 18:44:13| creating entry 0x892f580: near 'Connection: keep-alive' 2009/08/26 18:44:13| created entry 0x892f580: 'Connection: keep-alive' 2009/08/26 18:44:13| 0x8907f6c adding entry: 9 at 5 2009/08/26 18:44:13| creating entry 0x892f538: near 'Proxy-Connection: keep-alive' 2009/08/26 18:44:13| created entry 0x892f538: 'Proxy-Connection: keep-alive' 2009/08/26 18:44:13| 0x8907f6c adding entry: 41 at 6 2009/08/26 18:44:13| removing 408 bytes; conn->in.offset = 0 2009/08/26 18:44:13| 0x8907f6c lookup for 20 2009/08/26 18:44:13| clientSetKeepaliveFlag: http_ver = 1.1 2009/08/26 18:44:13| clientSetKeepaliveFlag: method = GET 2009/08/26 18:44:13| 0x8907f6c lookup for 41 2009/08/26 18:44:13| 0x8907f6c: joining for id 41 2009/08/26 18:44:13| 0x8907f6c: joined for id 41: keep-alive 2009/08/26 18:44:13| 0x8907f6c lookup for 52 2009/08/26 18:44:13| 0x8907f6c lookup for 41 2009/08/26 18:44:13| 0x8907f6c: joining for id 41 2009/08/26 18:44:13| 0x8907f6c: joined for id 41: keep-alive 2009/08/26 18:44:13| 0x8907f6c lookup for 59 2009/08/26 18:44:13| cbdataLock: 0x872b978 2009/08/26 18:44:13| cbdataLock: 0x892aaa8 2009/08/26 18:44:13| cbdataLock: 0x892ace8 2009/08/26 18:44:13| cbdataValid: 0x872b978 2009/08/26 18:44:13| aclCheck: checking 'http_access allow MyAcl' 2009/08/26 18:44:13| aclMatchAclList: checking MyAcl 2009/08/26 18:44:13| aclMatchAcl: checking 'acl MyAcl external myAclType' 2009/08/26 18:44:13| aclMatchExternal: acl="myAclType" 2009/08/26 18:44:13| authenticateValidateUser: Validating Auth_user request '(nil)'. 2009/08/26 18:44:13| authenticateValidateUser: Auth_user_request was NULL! 2009/08/26 18:44:13| authenticateAuthenticate: broken auth or no proxy_auth header. Requesting auth header. 2009/08/26 18:44:13| aclAuthenticated: returning 0 sending authentication challenge. 2009/08/26 18:44:13| aclMatchExternal: myAclType user not authenticated (-1) 2009/08/26 18:44:13| aclMatchAclList: no match, returning 0 2009/08/26 18:44:13| aclCheck: requiring Proxy Auth header. 2009/08/26 18:44:13| aclCheck: match found, returning 2 2009/08/26 18:44:13| cbdataUnlock: 0x872b978 2009/08/26 18:44:13| aclCheckCallback: answer=2 2009/08/26 18:44:13| cbdataValid: 0x892ace8 2009/08/26 18:44:13| The request GET http://www.openbsd.org/ is DENIED, because it matched 'MyAcl' 2009/08/26 18:44:13| Access Denied: http://www.openbsd.org/ 2009/08/26 18:44:13| AclMatchedName = MyAcl 2009/08/26 18:44:13| Proxy Auth Message = <null> 2009/08/26 18:44:13| storeCreateEntry: 'http://www.openbsd.org/' 2009/08/26 18:44:13| creating rep: 0x892c748 2009/08/26 18:44:13| init-ing hdr: 0x892c788 owner: 3 2009/08/26 18:44:13| 0x892c788 lookup for 41 2009/08/26 18:44:13| 0x892c788 lookup for 9 2009/08/26 18:44:13| 0x892c788 lookup for 41 2009/08/26 18:44:13| 0x892c788 lookup for 9 2009/08/26 18:44:13| 0x892c788 lookup for 25 2009/08/26 18:44:13| new_MemObject: returning 0x892b538 2009/08/26 18:44:13| new_StoreEntry: returning 0x892b500 2009/08/26 18:44:13| storeKeyPrivate: GET http://www.openbsd.org/ 2009/08/26 18:44:13| storeHashInsert: Inserting Entry 0x892b500 key 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| storeReleaseRequest: 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| storeLockObject: (store_client.c:122): key 'A83EE53AFB79EF45119733090C8AE2DF' count=2 2009/08/26 18:44:13| storeClientCopy: A83EE53AFB79EF45119733090C8AE2DF, seen 0, want 0, size 4096, cb 0x8071590, cbdata 0x892ace8 2009/08/26 18:44:13| cbdataLock: 0x892ace8 2009/08/26 18:44:13| cbdataLock: 0x892b698 2009/08/26 18:44:13| storeClientCopy2: A83EE53AFB79EF45119733090C8AE2DF 2009/08/26 18:44:13| storeClientCopy3: Waiting for more 2009/08/26 18:44:13| cbdataUnlock: 0x892b698 2009/08/26 18:44:13| storeLockObject: (errorpage.c:316): key 'A83EE53AFB79EF45119733090C8AE2DF' count=3 2009/08/26 18:44:13| creating rep: 0x892b5d8 2009/08/26 18:44:13| init-ing hdr: 0x892b618 owner: 3 2009/08/26 18:44:13| 0x892b618 lookup for 41 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| 0x892b618 lookup for 41 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| 0x892b618 lookup for 25 2009/08/26 18:44:13| errorConvert: %U --> 'http://www.openbsd.org/' 2009/08/26 18:44:13| errorConvert: %U --> 'http://www.openbsd.org/' 2009/08/26 18:44:13| errorConvert: %U --> 'http://www.openbsd.org/' 2009/08/26 18:44:13| errorConvert: %w --> 'webmaster' 2009/08/26 18:44:13| errorConvert: %h --> 'squid-ads.localdomain' 2009/08/26 18:44:13| errorConvert: %T --> 'Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| errorConvert: %h --> 'squid-ads.localdomain' 2009/08/26 18:44:13| errorConvert: %s --> 'squid/2.7.STABLE3' 2009/08/26 18:44:13| errorConvert: %S --> ' <BR clear="all"> <HR noshade size="1px"> <ADDRESS> Generated Wed, 26 Aug 2009 16:44:13 GMT by squid-ads.localdomain (squid/2.7.STABLE3) </ADDRESS> </BODY></HTML> ' 2009/08/26 18:44:13| created entry 0x892f4f0: 'Server: squid/2.7.STABLE3' 2009/08/26 18:44:13| 0x892b618 adding entry: 47 at 0 2009/08/26 18:44:13| created entry 0x892f4a8: 'Date: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| 0x892b618 adding entry: 23 at 1 2009/08/26 18:44:13| created entry 0x892f460: 'Content-Type: text/html' 2009/08/26 18:44:13| 0x892b618 adding entry: 18 at 2 2009/08/26 18:44:13| created entry 0x892f3d0: 'Content-Length: 1321' 2009/08/26 18:44:13| 0x892b618 adding entry: 14 at 3 2009/08/26 18:44:13| created entry 0x892b368: 'Expires: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| 0x892b618 adding entry: 25 at 4 2009/08/26 18:44:13| created entry 0x892b320: 'X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0' 2009/08/26 18:44:13| 0x892b618 adding entry: 61 at 5 2009/08/26 18:44:13| authenticateFixHeader: headertype:38 authuser:(nil) 2009/08/26 18:44:13| authenticateFixErrorHeader: Sending type:38 header: 'Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:13| created entry 0x892b278: 'Proxy-Authenticate: Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:13| 0x892b618 adding entry: 38 at 6 2009/08/26 18:44:13| cleaning hdr: 0x892c788 owner: 3 2009/08/26 18:44:13| packing sline 0x892c778 using 0xbf84db50: 2009/08/26 18:44:13| HTTP/1.0 407 Proxy Authentication Required 2009/08/26 18:44:13| storeAppend: appending 44 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 44 2009/08/26 18:44:13| packing hdr: (0x892c788) 2009/08/26 18:44:13| storeAppend: appending 6 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 6 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 17 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 17 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 4 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 4 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 29 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 29 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 12 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 12 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 9 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 9 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 14 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 14 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 4 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 4 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 7 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 7 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 29 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 29 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 13 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 13 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 25 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 25 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 18 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 18 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 44 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 44 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 2 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 2 2009/08/26 18:44:13| storeAppend: appending 1321 bytes for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| stmemAppend: len 1321 2009/08/26 18:44:13| storeExpireNow: 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| InvokeHandlers: A83EE53AFB79EF45119733090C8AE2DF 2009/08/26 18:44:13| InvokeHandlers: checking client #0 2009/08/26 18:44:13| cbdataLock: 0x892b698 2009/08/26 18:44:13| storeClientCopy2: A83EE53AFB79EF45119733090C8AE2DF 2009/08/26 18:44:13| storeClientCopy3: Copying from memory 2009/08/26 18:44:13| stmemCopy: offset 0: size 4096 2009/08/26 18:44:13| storeSwapOutMaintainMemObject: lowest_offset = 0 2009/08/26 18:44:13| cbdataValid: 0x892ace8 2009/08/26 18:44:13| clientSendHeaders: FD 18 'http://www.openbsd.org/' 2009/08/26 18:44:13| creating rep: 0x892b5d8 2009/08/26 18:44:13| init-ing hdr: 0x892b618 owner: 3 2009/08/26 18:44:13| 0x892b618 lookup for 41 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| 0x892b618 lookup for 41 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| 0x892b618 lookup for 25 2009/08/26 18:44:13| appending hdr: 0x892b618 += 0x892c788 2009/08/26 18:44:13| created entry 0x892b230: 'Server: squid/2.7.STABLE3' 2009/08/26 18:44:13| 0x892b618 adding entry: 47 at 0 2009/08/26 18:44:13| created entry 0x892b1e8: 'Date: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| 0x892b618 adding entry: 23 at 1 2009/08/26 18:44:13| created entry 0x892b140: 'Content-Type: text/html' 2009/08/26 18:44:13| 0x892b618 adding entry: 18 at 2 2009/08/26 18:44:13| created entry 0x892b120: 'Content-Length: 1321' 2009/08/26 18:44:13| 0x892b618 adding entry: 14 at 3 2009/08/26 18:44:13| created entry 0x892b090: 'Expires: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| 0x892b618 adding entry: 25 at 4 2009/08/26 18:44:13| created entry 0x892e288: 'X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0' 2009/08/26 18:44:13| 0x892b618 adding entry: 61 at 5 2009/08/26 18:44:13| created entry 0x892e240: 'Proxy-Authenticate: Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:13| 0x892b618 adding entry: 38 at 6 2009/08/26 18:44:13| 0x892b618 lookup for 41 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| 0x892b618 lookup for 41 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| 0x892b618 lookup for 25 2009/08/26 18:44:13| 0x892b618 del-by-id 41 2009/08/26 18:44:13| 0x892b618 del-by-id 68 2009/08/26 18:44:13| 0x892b618 del-by-id 21 2009/08/26 18:44:13| 0x892b618 del-by-id 20 2009/08/26 18:44:13| 0x892b618 del-by-id 49 2009/08/26 18:44:13| 0x892b618 lookup for 9 2009/08/26 18:44:13| created entry 0x892e1f8: 'X-Cache: MISS from squid-ads.localdomain' 2009/08/26 18:44:13| 0x892b618 adding entry: 57 at 7 2009/08/26 18:44:13| created entry 0x892e1b0: 'X-Cache-Lookup: NONE from squid-ads.localdomain:3128' 2009/08/26 18:44:13| 0x892b618 adding entry: 58 at 8 2009/08/26 18:44:13| clientBuildReplyHeader: Error, don't keep-alive 2009/08/26 18:44:13| 0x892b618: joining for id 52 2009/08/26 18:44:13| 0x892b618 del-by-id 52 2009/08/26 18:44:13| created entry 0x892d858: 'Via: 1.0 squid-ads.localdomain:3128 (squid/2.7.STABLE3)' 2009/08/26 18:44:13| 0x892b618 adding entry: 52 at 9 2009/08/26 18:44:13| created entry 0x892d838: 'Connection: close' 2009/08/26 18:44:13| 0x892b618 adding entry: 9 at 10 2009/08/26 18:44:13| clientSendHeaders: 305 bytes of headers 2009/08/26 18:44:13| The reply for GET http://www.openbsd.org/ is ALLOWED, because it matched 'MyAcl' 2009/08/26 18:44:13| packing sline 0x892b608 using 0xbf84d980: 2009/08/26 18:44:13| HTTP/1.0 407 Proxy Authentication Required 2009/08/26 18:44:13| packing hdr: (0x892b618) 2009/08/26 18:44:13| comm_write: FD 18: sz 477: hndl 0x806d4b0: data 0x892ace8. 2009/08/26 18:44:13| cbdataLock: 0x892ace8 2009/08/26 18:44:13| commSetSelect: FD 18 type 2 2009/08/26 18:44:13| commSetEvents(fd=18) 2009/08/26 18:44:13| cbdataUnlock: 0x892ace8 2009/08/26 18:44:13| cbdataUnlock: 0x892b698 2009/08/26 18:44:13| storeSwapOut: http://www.openbsd.org/ 2009/08/26 18:44:13| storeSwapOut: store_status = STORE_PENDING 2009/08/26 18:44:13| storeSwapOut: mem->inmem_lo = 0 2009/08/26 18:44:13| storeSwapOut: mem->inmem_hi = 1626 2009/08/26 18:44:13| storeSwapOut: swapout.queue_offset = 0 2009/08/26 18:44:13| storeSwapOutMaintainMemObject: lowest_offset = 0 2009/08/26 18:44:13| storeComplete: 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| storeEntryValidLength: Checking 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| storeEntryValidLength: object_len = 1626 2009/08/26 18:44:13| storeEntryValidLength: hdr_sz = 305 2009/08/26 18:44:13| storeEntryValidLength: content_length = 1321 2009/08/26 18:44:13| storeSwapOut: http://www.openbsd.org/ 2009/08/26 18:44:13| storeSwapOut: store_status = STORE_OK 2009/08/26 18:44:13| storeSwapOut: mem->inmem_lo = 0 2009/08/26 18:44:13| storeSwapOut: mem->inmem_hi = 1626 2009/08/26 18:44:13| storeSwapOut: swapout.queue_offset = 0 2009/08/26 18:44:13| storeSwapOutMaintainMemObject: lowest_offset = 0 2009/08/26 18:44:13| InvokeHandlers: A83EE53AFB79EF45119733090C8AE2DF 2009/08/26 18:44:13| InvokeHandlers: checking client #0 2009/08/26 18:44:13| storeUnlockObject: (errorpage.c:331): key 'A83EE53AFB79EF45119733090C8AE2DF' count=2 2009/08/26 18:44:13| cbdataFree: 0x892c6f8 2009/08/26 18:44:13| cbdataFree: Freeing 0x892c6f8 2009/08/26 18:44:13| cbdataUnlock: 0x892ace8 2009/08/26 18:44:13| cbdataUnlock: 0x892aaa8 2009/08/26 18:44:13| cbdataFree: 0x892b3e8 2009/08/26 18:44:13| cbdataFree: Freeing 0x892b3e8 2009/08/26 18:44:13| cbdataValid: 0x892aaa8 2009/08/26 18:44:13| cbdataValid: 0x892aaa8 2009/08/26 18:44:13| cbdataValid: 0x892aaa8 2009/08/26 18:44:13| cbdataUnlock: 0x892aaa8 2009/08/26 18:44:13| commSetSelect: FD 18 type 1 2009/08/26 18:44:13| commSetEvents(fd=18) 2009/08/26 18:44:13| comm_select: timeout 483 2009/08/26 18:44:13| comm_call_handlers(): got fd=18 read_event=0 write_event=4 F->read_handler=0x806acf0 F->write_handler=0x8072fb0 2009/08/26 18:44:13| commHandleWrite: FD 18: off 0, hd 0, sz 477. 2009/08/26 18:44:13| commHandleWrite: write() returns 477 2009/08/26 18:44:13| cbdataValid: 0x892ace8 2009/08/26 18:44:13| clientWriteComplete: FD 18, sz 477, err 0, off 305, len 1626 2009/08/26 18:44:13| storeClientCopy: A83EE53AFB79EF45119733090C8AE2DF, seen 305, want 305, size 4096, cb 0x806d8c0, cbdata 0x892ace8 2009/08/26 18:44:13| cbdataLock: 0x892ace8 2009/08/26 18:44:13| cbdataLock: 0x892b698 2009/08/26 18:44:13| storeClientCopy2: A83EE53AFB79EF45119733090C8AE2DF 2009/08/26 18:44:13| storeClientCopy3: Copying from memory 2009/08/26 18:44:13| stmemCopy: offset 305: size 4096 2009/08/26 18:44:13| storeSwapOutMaintainMemObject: lowest_offset = 305 2009/08/26 18:44:13| cbdataValid: 0x892ace8 2009/08/26 18:44:13| clientSendMoreData: http://www.openbsd.org/, 1321 bytes 2009/08/26 18:44:13| clientSendMoreData: FD 18 'http://www.openbsd.org/', out.offset=305 2009/08/26 18:44:13| comm_write: FD 18: sz 1321: hndl 0x806dcd0: data 0x892ace8. 2009/08/26 18:44:13| cbdataLock: 0x892ace8 2009/08/26 18:44:13| commSetSelect: FD 18 type 2 2009/08/26 18:44:13| commSetEvents(fd=18) 2009/08/26 18:44:13| cbdataUnlock: 0x892ace8 2009/08/26 18:44:13| cbdataUnlock: 0x892b698 2009/08/26 18:44:13| cbdataUnlock: 0x892ace8 2009/08/26 18:44:13| commSetEvents(fd=18) 2009/08/26 18:44:13| comm_select: timeout 483 2009/08/26 18:44:13| comm_call_handlers(): got fd=18 read_event=0 write_event=4 F->read_handler=0x806acf0 F->write_handler=0x8072fb0 2009/08/26 18:44:13| commHandleWrite: FD 18: off 0, hd 0, sz 1321. 2009/08/26 18:44:13| commHandleWrite: write() returns 1321 2009/08/26 18:44:13| cbdataValid: 0x892ace8 2009/08/26 18:44:13| clientWriteComplete: FD 18, sz 1321, err 0, off 1626, len 1626 2009/08/26 18:44:13| clientWriteComplete: FD 18 transfer is DONE 2009/08/26 18:44:13| comm_close: FD 18 2009/08/26 18:44:13| commCallCloseHandlers: FD 18 2009/08/26 18:44:13| commCallCloseHandlers: ch->handler=0x806dd30 2009/08/26 18:44:13| cbdataValid: 0x892aaa8 2009/08/26 18:44:13| connStateFree: FD 18 2009/08/26 18:44:13| httpRequestFree: http://www.openbsd.org/ 2009/08/26 18:44:13| httpRequestFree: al.url='http://www.openbsd.org/' 2009/08/26 18:44:13| cbdataLock: 0x872b978 2009/08/26 18:44:13| cbdataLock: 0x892aaa8 2009/08/26 18:44:13| cbdataUnlock: 0x892aaa8 2009/08/26 18:44:13| cbdataUnlock: 0x872b978 2009/08/26 18:44:13| cbdataFree: 0x892b3e8 2009/08/26 18:44:13| cbdataFree: Freeing 0x892b3e8 2009/08/26 18:44:13| storeClientUnregister: called for 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| storeSwapOut: http://www.openbsd.org/ 2009/08/26 18:44:13| storeSwapOut: store_status = STORE_OK 2009/08/26 18:44:13| storeSwapOut: mem->inmem_lo = 0 2009/08/26 18:44:13| storeSwapOut: mem->inmem_hi = 1626 2009/08/26 18:44:13| storeSwapOut: swapout.queue_offset = 0 2009/08/26 18:44:13| storeSwapOutMaintainMemObject: lowest_offset = 1627 2009/08/26 18:44:13| storeSwapOutMaintainMemObject: lowest_offset = 1627 2009/08/26 18:44:13| storePendingNClients: returning 0 2009/08/26 18:44:13| storeUnlockObject: (store_client.c:576): key 'A83EE53AFB79EF45119733090C8AE2DF' count=1 2009/08/26 18:44:13| cbdataFree: 0x892b698 2009/08/26 18:44:13| cbdataFree: Freeing 0x892b698 2009/08/26 18:44:13| storeUnlockObject: (client_side.c:1262): key 'A83EE53AFB79EF45119733090C8AE2DF' count=0 2009/08/26 18:44:13| storePendingNClients: returning 0 2009/08/26 18:44:13| storeRelease: Releasing: 'A83EE53AFB79EF45119733090C8AE2DF' 2009/08/26 18:44:13| destroy_StoreEntry: destroying 0x892b500 2009/08/26 18:44:13| ctx: enter level 0: 'http://www.openbsd.org/' 2009/08/26 18:44:13| destroy_MemObject: destroying 0x892b538 2009/08/26 18:44:13| destroying rep: 0x892c748 2009/08/26 18:44:13| cleaning hdr: 0x892c788 owner: 3 2009/08/26 18:44:13| destroying entry 0x892f4f0: 'Server: squid/2.7.STABLE3' 2009/08/26 18:44:13| destroying entry 0x892f4a8: 'Date: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| destroying entry 0x892f460: 'Content-Type: text/html' 2009/08/26 18:44:13| destroying entry 0x892f3d0: 'Content-Length: 1321' 2009/08/26 18:44:13| destroying entry 0x892b368: 'Expires: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| destroying entry 0x892b320: 'X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0' 2009/08/26 18:44:13| destroying entry 0x892b278: 'Proxy-Authenticate: Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:13| ctx: exit level 0 2009/08/26 18:44:13| cleaning hdr: 0x8907f6c owner: 2 2009/08/26 18:44:13| destroying entry 0x892f8b8: 'Host: www.openbsd.org' 2009/08/26 18:44:13| destroying entry 0x892f810: 'User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9' 2009/08/26 18:44:13| destroying entry 0x892f6e0: 'Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5' 2009/08/26 18:44:13| destroying entry 0x892f698: 'Accept-Language: de-de' 2009/08/26 18:44:13| destroying entry 0x892f5c8: 'Accept-Encoding: gzip, deflate' 2009/08/26 18:44:13| destroying entry 0x892f580: 'Connection: keep-alive' 2009/08/26 18:44:13| destroying entry 0x892f538: 'Proxy-Connection: keep-alive' 2009/08/26 18:44:13| destroying rep: 0x892b5d8 2009/08/26 18:44:13| cleaning hdr: 0x892b618 owner: 3 2009/08/26 18:44:13| destroying entry 0x892b230: 'Server: squid/2.7.STABLE3' 2009/08/26 18:44:13| destroying entry 0x892b1e8: 'Date: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| destroying entry 0x892b140: 'Content-Type: text/html' 2009/08/26 18:44:13| destroying entry 0x892b120: 'Content-Length: 1321' 2009/08/26 18:44:13| destroying entry 0x892b090: 'Expires: Wed, 26 Aug 2009 16:44:13 GMT' 2009/08/26 18:44:13| destroying entry 0x892e288: 'X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0' 2009/08/26 18:44:13| destroying entry 0x892e240: 'Proxy-Authenticate: Basic realm="Squid proxy-caching web server"' 2009/08/26 18:44:13| destroying entry 0x892e1f8: 'X-Cache: MISS from squid-ads.localdomain' 2009/08/26 18:44:13| destroying entry 0x892e1b0: 'X-Cache-Lookup: NONE from squid-ads.localdomain:3128' 2009/08/26 18:44:13| destroying entry 0x892d858: 'Via: 1.0 squid-ads.localdomain:3128 (squid/2.7.STABLE3)' 2009/08/26 18:44:13| destroying entry 0x892d838: 'Connection: close' 2009/08/26 18:44:13| cbdataFree: 0x892ace8 2009/08/26 18:44:13| cbdataFree: 0x892ace8 has 1 locks, not freeing 2009/08/26 18:44:13| cbdataFree: 0x892aaa8 2009/08/26 18:44:13| cbdataFree: 0x892aaa8 has 1 locks, not freeing 2009/08/26 18:44:13| cbdataUnlock: 0x892aaa8 2009/08/26 18:44:13| cbdataUnlock: Freeing 0x892aaa8 2009/08/26 18:44:13| fd_close FD 18 Reading next request 2009/08/26 18:44:13| commSetEvents(fd=18) 2009/08/26 18:44:13| cbdataUnlock: 0x892ace8 2009/08/26 18:44:13| cbdataUnlock: Freeing 0x892ace8 2009/08/26 18:44:13| comm_select: timeout 482 2009/08/26 18:44:14| comm_select: time out 2009/08/26 18:44:14| comm_select: timeout 41 2009/08/26 18:44:14| comm_select: time out 2009/08/26 18:44:14| eventRun: RUN ID 35 2009/08/26 18:44:14| eventRun: Running 'MaintainSwapSpace', id 34 2009/08/26 18:44:14| storeMaintainSwapSpace: f=0.000000, max_scan=100, max_remove=10 2009/08/26 18:44:14| cbdataFree: 0x892aa30 2009/08/26 18:44:14| cbdataFree: Freeing 0x892aa30 2009/08/26 18:44:14| storeUfsDirMaintain: /var/spool/squid removed 0/10 f=0.000 max_scan=100 2009/08/26 18:44:14| eventAdd: Adding 'MaintainSwapSpace', in 1.000000 seconds 2009/08/26 18:44:14| comm_select: timeout 1000 2009/08/26 18:44:15| comm_select: time out 2009/08/26 18:44:15| comm_select: timeout 45 2009/08/26 18:44:15| comm_select: time out 2009/08/26 18:44:15| eventRun: RUN ID 36 2009/08/26 18:44:15| eventRun: Running 'MaintainSwapSpace', id 35 2009/08/26 18:44:15| storeMaintainSwapSpace: f=0.000000, max_scan=100, max_remove=10 2009/08/26 18:44:15| cbdataFree: 0x892aa30 2009/08/26 18:44:15| cbdataFree: Freeing 0x892aa30 2009/08/26 18:44:15| storeUfsDirMaintain: /var/spool/squid removed 0/10 f=0.000 max_scan=100 2009/08/26 18:44:15| eventAdd: Adding 'MaintainSwapSpace', in 1.000000 seconds 2009/08/26 18:44:15| comm_select: timeout 1000 2009/08/26 18:44:16| comm_select: time out 2009/08/26 18:44:16| comm_select: timeout 48 2009/08/26 18:44:16| comm_select: time out 2009/08/26 18:44:16| eventRun: RUN ID 37 2009/08/26 18:44:16| eventRun: Running 'MaintainSwapSpace', id 36 2009/08/26 18:44:16| storeMaintainSwapSpace: f=0.000000, max_scan=100, max_remove=10 2009/08/26 18:44:16| cbdataFree: 0x892aa30 2009/08/26 18:44:16| cbdataFree: Freeing 0x892aa30 2009/08/26 18:44:16| storeUfsDirMaintain: /var/spool/squid removed 0/10 f=0.000 max_scan=100 2009/08/26 18:44:16| eventAdd: Adding 'MaintainSwapSpace', in 1.000000 seconds 2009/08/26 18:44:16| comm_select: timeout 952 2009/08/26 18:44:16| comm_call_handlers(): got fd=19 read_event=1 write_event=0 F->read_handler=0x80666d0 F->write_handler=(nil) 2009/08/26 18:44:16| comm_call_handlers(): Calling read handler on fd=19 2009/08/26 18:44:16| commSetSelect: FD 19 type 1 2009/08/26 18:44:16| commSetEvents(fd=19) 2009/08/26 18:44:16| fd_open FD 18 HTTP Request 2009/08/26 18:44:16| httpAccept: FD 18: accepted port 3128 client 192.168.32.1:53075 2009/08/26 18:44:16| cbdataLock: 0x872d248 2009/08/26 18:44:16| comm_add_close_handler: FD 18, handler=0x806dd30, data=0x892aaa8 2009/08/26 18:44:16| cbdataLock: 0x892aaa8 2009/08/26 18:44:16| commSetTimeout: FD 18 timeout 300 2009/08/26 18:44:16| aclCheckFast: list: 0x872b7f0 2009/08/26 18:44:16| aclMatchAclList: checking all 2009/08/26 18:44:16| aclMatchAcl: checking 'acl all src all' 2009/08/26 18:44:16| aclMatchIp: '192.168.32.1' found 2009/08/26 18:44:16| aclMatchAclList: returning 1 2009/08/26 18:44:16| commSetSelect: FD 18 type 1 2009/08/26 18:44:16| commSetEvents(fd=18) 2009/08/26 18:44:16| comm_accept: FD 19: (11) Resource temporarily unavailable 2009/08/26 18:44:17| comm_select: timeout 184 2009/08/26 18:44:17| comm_call_handlers(): got fd=18 read_event=1 write_event=0 F->read_handler=0x806acf0 F->write_handler=(nil) 2009/08/26 18:44:17| comm_call_handlers(): Calling read handler on fd=18 2009/08/26 18:44:17| clientReadRequest: FD 18: reading request... 2009/08/26 18:44:17| cbdataLock: 0x892aaa8 2009/08/26 18:44:17| cbdataValid: 0x892aaa8 2009/08/26 18:44:17| Parser: retval 1: from 0->37: method 0->2; url 4->26; version 28->36 (1/1) 2009/08/26 18:44:17| parseHttpRequest: Method is 'GET' 2009/08/26 18:44:17| parseHttpRequest: URI is 'http://www.openbsd.org/' 2009/08/26 18:44:17| parseHttpRequest: req_hdr = {Host: www.openbsd.org User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9 Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5 Accept-Language: de-de Accept-Encoding: gzip, deflate Proxy-Authorization: Basic Zm9vOmJhcg== Connection: keep-alive Proxy-Connection: keep-alive } 2009/08/26 18:44:17| parseHttpRequest: prefix_sz = 449, req_line_sz = 38 2009/08/26 18:44:17| parseHttpRequest: Request Header is Host: www.openbsd.org User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9 Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5 Accept-Language: de-de Accept-Encoding: gzip, deflate Proxy-Authorization: Basic Zm9vOmJhcg== Connection: keep-alive Proxy-Connection: keep-alive 2009/08/26 18:44:17| parseHttpRequest: Complete request received 2009/08/26 18:44:17| commSetTimeout: FD 18 timeout 86400 2009/08/26 18:44:17| init-ing hdr: 0x8907f6c owner: 2 2009/08/26 18:44:17| parsing hdr: (0x8907f6c) Host: www.openbsd.org User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9 Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5 Accept-Language: de-de Accept-Encoding: gzip, deflate Proxy-Authorization: Basic Zm9vOmJhcg== Connection: keep-alive Proxy-Connection: keep-alive 2009/08/26 18:44:17| creating entry 0x892d838: near 'Host: www.openbsd.org' 2009/08/26 18:44:17| created entry 0x892d838: 'Host: www.openbsd.org' 2009/08/26 18:44:17| 0x8907f6c adding entry: 27 at 0 2009/08/26 18:44:17| creating entry 0x892d858: near 'User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9' 2009/08/26 18:44:17| created entry 0x892d858: 'User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_5_8; de-de) AppleWebKit/531.9 (KHTML, like Gecko) Version/4.0.3 Safari/531.9' 2009/08/26 18:44:17| 0x8907f6c adding entry: 50 at 1 2009/08/26 18:44:17| creating entry 0x892e1b0: near 'Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5' 2009/08/26 18:44:17| created entry 0x892e1b0: 'Accept: application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image /png,*/*;q=0.5' 2009/08/26 18:44:17| 0x8907f6c adding entry: 0 at 2 2009/08/26 18:44:17| creating entry 0x892e1f8: near 'Accept-Language: de-de' 2009/08/26 18:44:17| created entry 0x892e1f8: 'Accept-Language: de-de' 2009/08/26 18:44:17| 0x8907f6c adding entry: 3 at 3 2009/08/26 18:44:17| creating entry 0x892e240: near 'Accept-Encoding: gzip, deflate' 2009/08/26 18:44:17| created entry 0x892e240: 'Accept-Encoding: gzip, deflate' 2009/08/26 18:44:17| 0x8907f6c adding entry: 2 at 4 2009/08/26 18:44:17| creating entry 0x892e288: near 'Proxy-Authorization: Basic Zm9vOmJhcg==' 2009/08/26 18:44:17| created entry 0x892e288: 'Proxy-Authorization: Basic Zm9vOmJhcg==' 2009/08/26 18:44:17| 0x8907f6c adding entry: 40 at 5 2009/08/26 18:44:17| creating entry 0x892b090: near 'Connection: keep-alive' 2009/08/26 18:44:17| created entry 0x892b090: 'Connection: keep-alive' 2009/08/26 18:44:17| 0x8907f6c adding entry: 9 at 6 2009/08/26 18:44:17| creating entry 0x892b120: near 'Proxy-Connection: keep-alive' 2009/08/26 18:44:17| created entry 0x892b120: 'Proxy-Connection: keep-alive' 2009/08/26 18:44:17| 0x8907f6c adding entry: 41 at 7 2009/08/26 18:44:17| removing 449 bytes; conn->in.offset = 0 2009/08/26 18:44:17| 0x8907f6c lookup for 20 2009/08/26 18:44:17| clientSetKeepaliveFlag: http_ver = 1.1 2009/08/26 18:44:17| clientSetKeepaliveFlag: method = GET 2009/08/26 18:44:17| 0x8907f6c lookup for 41 2009/08/26 18:44:17| 0x8907f6c: joining for id 41 2009/08/26 18:44:17| 0x8907f6c: joined for id 41: keep-alive 2009/08/26 18:44:17| 0x8907f6c lookup for 52 2009/08/26 18:44:17| 0x8907f6c lookup for 41 2009/08/26 18:44:17| 0x8907f6c: joining for id 41 2009/08/26 18:44:17| 0x8907f6c: joined for id 41: keep-alive 2009/08/26 18:44:17| 0x8907f6c lookup for 59 2009/08/26 18:44:17| cbdataLock: 0x872b978 2009/08/26 18:44:17| cbdataLock: 0x892aaa8 2009/08/26 18:44:17| cbdataLock: 0x892ace8 2009/08/26 18:44:17| cbdataValid: 0x872b978 2009/08/26 18:44:17| aclCheck: checking 'http_access allow MyAcl' 2009/08/26 18:44:17| aclMatchAclList: checking MyAcl 2009/08/26 18:44:17| aclMatchAcl: checking 'acl MyAcl external myAclType' 2009/08/26 18:44:17| aclMatchExternal: acl="myAclType" 2009/08/26 18:44:17| authenticateAuthenticate: header Basic Zm9vOmJhcg==. 2009/08/26 18:44:17| authenticateAuthenticate: This is a new checklist test on FD:18 2009/08/26 18:44:17| authenticateAuthenticate: no connection authentication type 2009/08/26 18:44:17| authenticateAuthUserRequestLock auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateAuthUserRequestLock auth_user request '0x892fdb0' now at '1'. 2009/08/26 18:44:17| authenticateDecodeAuth: header = 'Basic Zm9vOmJhcg==' 2009/08/26 18:44:17| authenticateBasicDecodeAuth: cleartext = 'foo:bar' 2009/08/26 18:44:17| authBasicAuthUserFindUsername: Looking for user 'foo' 2009/08/26 18:44:17| authBasicDecodeAuth: Creating new user 'foo' 2009/08/26 18:44:17| authenticateAuthUserLock auth_user '0x892fde0'. 2009/08/26 18:44:17| authenticateAuthUserLock auth_user '0x892fde0' now at '1'. 2009/08/26 18:44:17| authenticateAuthUserLock auth_user '0x892fde0'. 2009/08/26 18:44:17| authenticateAuthUserLock auth_user '0x892fde0' now at '2'. 2009/08/26 18:44:17| authenticateValidateUser: Validating Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateValidateUser: Validated Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateValidateUser: Validating Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateValidateUser: Validated Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| User not authenticated or credentials need rechecking. 2009/08/26 18:44:17| authenticateValidateUser: Validating Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateValidateUser: Validated Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| User not authenticated or credentials need rechecking. 2009/08/26 18:44:17| aclAuthenticated: returning 0 sending credentials to helper. 2009/08/26 18:44:17| aclMatchExternal: myAclType user not authenticated (-1) 2009/08/26 18:44:17| aclMatchAclList: no match, returning 0 2009/08/26 18:44:17| aclCheck: checking password via authenticator 2009/08/26 18:44:17| authenticateValidateUser: Validating Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateValidateUser: Validated Auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateStart: auth_user_request '0x892fdb0' 2009/08/26 18:44:17| authenticateStart: 'foo:bar' 2009/08/26 18:44:17| cbdataLock: 0x892b3e8 2009/08/26 18:44:17| authenticateAuthUserRequestLock auth_user request '0x892fdb0'. 2009/08/26 18:44:17| authenticateAuthUserRequestLock auth_user request '0x892fdb0' now at '2'. 2009/08/26 18:44:17| cbdataLock: 0x892feb0 2009/08/26 18:44:17| cbdataValid: 0x892feb0 2009/08/26 18:44:17| comm_write: FD 7: sz 8: hndl 0x808e530: data 0x87362c8. 2009/08/26 18:44:17| cbdataLock: 0x87362c8 2009/08/26 18:44:17| commSetSelect: FD 7 type 2 2009/08/26 18:44:17| commSetEvents(fd=7) 2009/08/26 18:44:17| helperDispatch: Request sent to basicauthenticator #1[0], 8 bytes 2009/08/26 18:44:17| helperSubmit: foo bar ----->8----- Best regards Maik Kündig
