[squid-users] Squid and Splash page

From: Daniel Shelton <dps218_at_yahoo.com>
Date: Mon, 25 Apr 2011 07:54:21 -0700 (PDT)

Hello again all,

First of all, thanks to Amos and Andrew for replying to my previous question. I have setup squid_session with the following in squid.conf. The result is attached below also. For whatever reason the squid sessions are crashing and I am not sure why. The goal would be to display a splash page to the user and then release them after that. ("Catch and Release")

Does anyone know why the sessions are exiting ?

Thanks,

----------------------------------
squid.conf
----------------------------------

external_acl_type session ttl=60 %SRC /usr/lib64/squid/squid_session -t 7200 -b /etc/squid/session.db

acl new_users external session

deny_info http://172.23.1.2/main.html new_users

http_access deny !new_users

----------------------------------
cache.log with some debugging
----------------------------------

2011/04/25 09:17:57.602| ACLList::matches: checking !new_users
2011/04/25 09:17:57.602| ACL::checklistMatches: checking 'new_users'
2011/04/25 09:17:57.602| aclMatchExternal: session("10.140.43.227") = lookup needed
2011/04/25 09:17:57.602| aclMatchExternal: "10.140.43.227": entry=@0, age=0
2011/04/25 09:17:57.602| aclMatchExternal: "10.140.43.227": queueing a call.
2011/04/25 09:17:57.602| aclMatchExternal: "10.140.43.227": return -1.
2011/04/25 09:17:57.602| ACL::ChecklistMatches: result for 'new_users' is -1
2011/04/25 09:17:57.602| ACLList::matches: result is false
2011/04/25 09:17:57.602| aclmatchAclList: 0xe1a9348 returning false (AND list entry failed to match)
2011/04/25 09:17:57.602| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 1
2011/04/25 09:17:57.602| externalAclLookup: lookup in 'session' for '10.140.43.227'
2011/04/25 09:17:57.602| externalAclLookup: looking up for '10.140.43.227' in 'session'.
2011/04/25 09:17:57.602| The AsyncCall SomeCommWriteHander constructed, this=0xe1aaf70 [call35]
2011/04/25 09:17:57.602| comm_write: FD 11: sz 14: asynCall 0xe1aaf70*1
2011/04/25 09:17:57.602| helperDispatch: Request sent to session #2, 14 bytes
2011/04/25 09:17:57.602| externalAclLookup: will wait for the result of '10.140.43.227' in 'session' (ch=0xe1a9348).
2011/04/25 09:17:57.602| aclmatchAclList: async=1 nodeMatched=0 async_in_progress=1 lastACLResult() = 0 finished() = 0
2011/04/25 09:17:57.602| WARNING: session #1 (FD 9) exited
2011/04/25 09:17:57.602| leaving SomeCloseHandler(FD 9, data=0xdf80008)
2011/04/25 09:17:57.602| entering comm_close_complete(FD 9)
2011/04/25 09:17:57.603| AsyncCall.cc(32) make: make call comm_close_complete [call34]
2011/04/25 09:17:57.603| fd_close FD 9 squid_session #1
2011/04/25 09:17:57.603| leaving comm_close_complete(FD 9)
2011/04/25 09:17:57.603| commHandleWrite: FD 11: off 0, sz 14.
2011/04/25 09:17:57.603| commHandleWrite: write() returns 14
2011/04/25 09:17:57.603| commio_finish_callback: called for FD 11 (0, 0)
2011/04/25 09:17:57.603| comm.cc(165) will call SomeCommWriteHander(FD 11, data=0xdf822d8, size=14, buf=0xe1a9c80) [call35]
2011/04/25 09:17:57.603| entering SomeCommWriteHander(FD 11, data=0xdf822d8, size=14, buf=0xe1a9c80)
2011/04/25 09:17:57.603| AsyncCall.cc(32) make: make call SomeCommWriteHander [call35]
2011/04/25 09:17:57.603| leaving SomeCommWriteHander(FD 11, data=0xdf822d8, size=14, buf=0xe1a9c80)
2011/04/25 09:17:57.603| comm_read_try: FD 11, size 8191, retval 0, errno 0
2011/04/25 09:17:57.603| commio_finish_callback: called for FD 11 (0, 0)
2011/04/25 09:17:57.603| comm.cc(165) will call SomeCommReadHandler(FD 11, data=0xdf822d8, size=0, buf=0xdf823a0) [call8]
2011/04/25 09:17:57.603| entering SomeCommReadHandler(FD 11, data=0xdf822d8, size=0, buf=0xdf823a0)
2011/04/25 09:17:57.603| AsyncCall.cc(32) make: make call SomeCommReadHandler [call8]
2011/04/25 09:17:57.603| helperHandleRead: 0 bytes from session #2
2011/04/25 09:17:57.603| comm_close: start closing FD 11
2011/04/25 09:17:57.603| The AsyncCall comm_close_start constructed, this=0xdf889b0 [call36]
2011/04/25 09:17:57.603| comm.cc(1611) will call comm_close_start(FD 11) [call36]
2011/04/25 09:17:57.603| comm.cc(1195) commSetTimeout: FD 11 timeout -1
2011/04/25 09:17:57.603| comm.cc(1206) commSetTimeout: FD 11 timeout -1
2011/04/25 09:17:57.603| commCallCloseHandlers: FD 11
2011/04/25 09:17:57.603| commCallCloseHandlers: ch->handler=0xdf7fe90*1
2011/04/25 09:17:57.603| comm.cc(1460) will call SomeCloseHandler(FD 11, data=0xdf822d8) [call7]
2011/04/25 09:17:57.603| The AsyncCall comm_close_complete constructed, this=0xdf6d870 [call37]
2011/04/25 09:17:57.603| comm.cc(1643) will call comm_close_complete(FD 11) [call37]
2011/04/25 09:17:57.603| leaving SomeCommReadHandler(FD 11, data=0xdf822d8, size=0, buf=0xdf823a0)
2011/04/25 09:17:57.603| entering comm_close_start(FD 11)
2011/04/25 09:17:57.603| AsyncCall.cc(32) make: make call comm_close_start [call36]
2011/04/25 09:17:57.603| leaving comm_close_start(FD 11)
2011/04/25 09:17:57.603| entering SomeCloseHandler(FD 11, data=0xdf822d8)
2011/04/25 09:17:57.603| AsyncCall.cc(32) make: make call SomeCloseHandler [call7]
2011/04/25 09:17:57.603| externalAclHandleReply: reply="
2011/04/25 09:17:57.603| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 0
2011/04/25 09:17:57.604| ACLChecklist::preCheck: 0xe1a9348 checking 'http_access deny !new_users'
2011/04/25 09:17:57.604| ACLList::matches: checking !new_users
2011/04/25 09:17:57.604| ACL::checklistMatches: checking 'new_users'
2011/04/25 09:17:57.604| aclMatchExternal: session("10.140.43.227") = lookup needed
2011/04/25 09:17:57.604| aclMatchExternal: "10.140.43.227": entry=@0, age=0
2011/04/25 09:17:57.604| aclMatchExternal: "10.140.43.227": queueing a call.
2011/04/25 09:17:57.604| aclMatchExternal: "10.140.43.227": return -1.
2011/04/25 09:17:57.604| ACL::ChecklistMatches: result for 'new_users' is -1
2011/04/25 09:17:57.604| ACLList::matches: result is false
2011/04/25 09:17:57.604| aclmatchAclList: 0xe1a9348 returning false (AND list entry failed to match)
2011/04/25 09:17:57.604| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 1
2011/04/25 09:17:57.604| externalAclLookup: lookup in 'session' for '10.140.43.227'
2011/04/25 09:17:57.604| externalAclLookup: looking up for '10.140.43.227' in 'session'.
2011/04/25 09:17:57.604| The AsyncCall SomeCommWriteHander constructed, this=0xe1aaf70 [call38]
2011/04/25 09:17:57.604| comm_write: FD 13: sz 14: asynCall 0xe1aaf70*1
2011/04/25 09:17:57.604| helperDispatch: Request sent to session #3, 14 bytes
2011/04/25 09:17:57.604| externalAclLookup: will wait for the result of '10.140.43.227' in 'session' (ch=0xe1a9348).
2011/04/25 09:17:57.604| aclmatchAclList: async=1 nodeMatched=0 async_in_progress=1 lastACLResult() = 0 finished() = 0
2011/04/25 09:17:57.604| WARNING: session #2 (FD 11) exited
2011/04/25 09:17:57.604| leaving SomeCloseHandler(FD 11, data=0xdf822d8)
2011/04/25 09:17:57.604| entering comm_close_complete(FD 11)
2011/04/25 09:17:57.604| AsyncCall.cc(32) make: make call comm_close_complete [call37]
2011/04/25 09:17:57.604| fd_close FD 11 squid_session #2
2011/04/25 09:17:57.604| leaving comm_close_complete(FD 11)
2011/04/25 09:17:57.604| commHandleWrite: FD 13: off 0, sz 14.
2011/04/25 09:17:57.604| commHandleWrite: write() returns 14
2011/04/25 09:17:57.604| commio_finish_callback: called for FD 13 (0, 0)
2011/04/25 09:17:57.604| comm.cc(165) will call SomeCommWriteHander(FD 13, data=0xdf84528, size=14, buf=0xe1aa5b0) [call38]
2011/04/25 09:17:57.604| entering SomeCommWriteHander(FD 13, data=0xdf84528, size=14, buf=0xe1aa5b0)
2011/04/25 09:17:57.604| AsyncCall.cc(32) make: make call SomeCommWriteHander [call38]
2011/04/25 09:17:57.604| leaving SomeCommWriteHander(FD 13, data=0xdf84528, size=14, buf=0xe1aa5b0)
2011/04/25 09:17:57.605| comm_read_try: FD 13, size 8191, retval 0, errno 0
2011/04/25 09:17:57.605| commio_finish_callback: called for FD 13 (0, 0)
2011/04/25 09:17:57.605| comm.cc(165) will call SomeCommReadHandler(FD 13, data=0xdf84528, size=0, buf=0xdf845f0) [call12]
2011/04/25 09:17:57.605| entering SomeCommReadHandler(FD 13, data=0xdf84528, size=0, buf=0xdf845f0)
2011/04/25 09:17:57.605| AsyncCall.cc(32) make: make call SomeCommReadHandler [call12]
2011/04/25 09:17:57.605| helperHandleRead: 0 bytes from session #3
2011/04/25 09:17:57.605| comm_close: start closing FD 13
2011/04/25 09:17:57.605| The AsyncCall comm_close_start constructed, this=0xdf889b0 [call39]
2011/04/25 09:17:57.605| comm.cc(1611) will call comm_close_start(FD 13) [call39]
2011/04/25 09:17:57.605| comm.cc(1195) commSetTimeout: FD 13 timeout -1
2011/04/25 09:17:57.605| comm.cc(1206) commSetTimeout: FD 13 timeout -1
2011/04/25 09:17:57.605| commCallCloseHandlers: FD 13
2011/04/25 09:17:57.605| commCallCloseHandlers: ch->handler=0xdf86600*1
2011/04/25 09:17:57.605| comm.cc(1460) will call SomeCloseHandler(FD 13, data=0xdf84528) [call11]
2011/04/25 09:17:57.605| The AsyncCall comm_close_complete constructed, this=0xdf7fe90 [call40]
2011/04/25 09:17:57.605| comm.cc(1643) will call comm_close_complete(FD 13) [call40]
2011/04/25 09:17:57.605| leaving SomeCommReadHandler(FD 13, data=0xdf84528, size=0, buf=0xdf845f0)
2011/04/25 09:17:57.605| entering comm_close_start(FD 13)
2011/04/25 09:17:57.605| AsyncCall.cc(32) make: make call comm_close_start [call39]
2011/04/25 09:17:57.605| leaving comm_close_start(FD 13)
2011/04/25 09:17:57.605| entering SomeCloseHandler(FD 13, data=0xdf84528)
2011/04/25 09:17:57.605| AsyncCall.cc(32) make: make call SomeCloseHandler [call11]
2011/04/25 09:17:57.605| externalAclHandleReply: reply="
2011/04/25 09:17:57.605| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 0
2011/04/25 09:17:57.605| ACLChecklist::preCheck: 0xe1a9348 checking 'http_access deny !new_users'
2011/04/25 09:17:57.605| ACLList::matches: checking !new_users
2011/04/25 09:17:57.605| ACL::checklistMatches: checking 'new_users'
2011/04/25 09:17:57.605| aclMatchExternal: session("10.140.43.227") = lookup needed
2011/04/25 09:17:57.605| aclMatchExternal: "10.140.43.227": entry=@0, age=0
2011/04/25 09:17:57.605| aclMatchExternal: "10.140.43.227": queueing a call.
2011/04/25 09:17:57.605| aclMatchExternal: "10.140.43.227": return -1.
2011/04/25 09:17:57.605| ACL::ChecklistMatches: result for 'new_users' is -1
2011/04/25 09:17:57.605| ACLList::matches: result is false
2011/04/25 09:17:57.605| aclmatchAclList: 0xe1a9348 returning false (AND list entry failed to match)
2011/04/25 09:17:57.605| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 1
2011/04/25 09:17:57.605| externalAclLookup: lookup in 'session' for '10.140.43.227'
2011/04/25 09:17:57.606| externalAclLookup: looking up for '10.140.43.227' in 'session'.
2011/04/25 09:17:57.606| The AsyncCall SomeCommWriteHander constructed, this=0xdf86670 [call41]
2011/04/25 09:17:57.606| comm_write: FD 15: sz 14: asynCall 0xdf86670*1
2011/04/25 09:17:57.606| helperDispatch: Request sent to session #4, 14 bytes
2011/04/25 09:17:57.606| externalAclLookup: will wait for the result of '10.140.43.227' in 'session' (ch=0xe1a9348).
2011/04/25 09:17:57.606| aclmatchAclList: async=1 nodeMatched=0 async_in_progress=1 lastACLResult() = 0 finished() = 0
2011/04/25 09:17:57.606| WARNING: session #3 (FD 13) exited
2011/04/25 09:17:57.606| leaving SomeCloseHandler(FD 13, data=0xdf84528)
2011/04/25 09:17:57.606| entering comm_close_complete(FD 13)
2011/04/25 09:17:57.606| AsyncCall.cc(32) make: make call comm_close_complete [call40]
2011/04/25 09:17:57.606| fd_close FD 13 squid_session #3
2011/04/25 09:17:57.606| leaving comm_close_complete(FD 13)
2011/04/25 09:17:57.606| commHandleWrite: FD 15: off 0, sz 14.
2011/04/25 09:17:57.606| commHandleWrite: write() returns 14
2011/04/25 09:17:57.606| commio_finish_callback: called for FD 15 (0, 0)
2011/04/25 09:17:57.606| comm.cc(165) will call SomeCommWriteHander(FD 15, data=0xdf867e8, size=14, buf=0xe1a9c80) [call41]
2011/04/25 09:17:57.606| entering SomeCommWriteHander(FD 15, data=0xdf867e8, size=14, buf=0xe1a9c80)
2011/04/25 09:17:57.606| AsyncCall.cc(32) make: make call SomeCommWriteHander [call41]
2011/04/25 09:17:57.606| leaving SomeCommWriteHander(FD 15, data=0xdf867e8, size=14, buf=0xe1a9c80)
2011/04/25 09:17:57.606| comm_read_try: FD 15, size 8191, retval 0, errno 0
2011/04/25 09:17:57.606| commio_finish_callback: called for FD 15 (0, 0)
2011/04/25 09:17:57.606| comm.cc(165) will call SomeCommReadHandler(FD 15, data=0xdf867e8, size=0, buf=0xdf868b0) [call16]
2011/04/25 09:17:57.606| entering SomeCommReadHandler(FD 15, data=0xdf867e8, size=0, buf=0xdf868b0)
2011/04/25 09:17:57.606| AsyncCall.cc(32) make: make call SomeCommReadHandler [call16]
2011/04/25 09:17:57.606| helperHandleRead: 0 bytes from session #4
2011/04/25 09:17:57.606| comm_close: start closing FD 15
2011/04/25 09:17:57.606| The AsyncCall comm_close_start constructed, this=0xdf889b0 [call42]
2011/04/25 09:17:57.606| comm.cc(1611) will call comm_close_start(FD 15) [call42]
2011/04/25 09:17:57.606| comm.cc(1195) commSetTimeout: FD 15 timeout -1
2011/04/25 09:17:57.606| comm.cc(1206) commSetTimeout: FD 15 timeout -1
2011/04/25 09:17:57.606| commCallCloseHandlers: FD 15
2011/04/25 09:17:57.607| commCallCloseHandlers: ch->handler=0xdf888c0*1
2011/04/25 09:17:57.607| comm.cc(1460) will call SomeCloseHandler(FD 15, data=0xdf867e8) [call15]
2011/04/25 09:17:57.607| The AsyncCall comm_close_complete constructed, this=0xdf7fe90 [call43]
2011/04/25 09:17:57.607| comm.cc(1643) will call comm_close_complete(FD 15) [call43]
2011/04/25 09:17:57.607| leaving SomeCommReadHandler(FD 15, data=0xdf867e8, size=0, buf=0xdf868b0)
2011/04/25 09:17:57.607| entering comm_close_start(FD 15)
2011/04/25 09:17:57.607| AsyncCall.cc(32) make: make call comm_close_start [call42]
2011/04/25 09:17:57.607| leaving comm_close_start(FD 15)
2011/04/25 09:17:57.607| entering SomeCloseHandler(FD 15, data=0xdf867e8)
2011/04/25 09:17:57.607| AsyncCall.cc(32) make: make call SomeCloseHandler [call15]
2011/04/25 09:17:57.607| externalAclHandleReply: reply="
2011/04/25 09:17:57.607| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 0
2011/04/25 09:17:57.607| ACLChecklist::preCheck: 0xe1a9348 checking 'http_access deny !new_users'
2011/04/25 09:17:57.607| ACLList::matches: checking !new_users
2011/04/25 09:17:57.607| ACL::checklistMatches: checking 'new_users'
2011/04/25 09:17:57.607| aclMatchExternal: session("10.140.43.227") = lookup needed
2011/04/25 09:17:57.607| aclMatchExternal: "10.140.43.227": entry=@0, age=0
2011/04/25 09:17:57.607| aclMatchExternal: "10.140.43.227": queueing a call.
2011/04/25 09:17:57.607| aclMatchExternal: "10.140.43.227": return -1.
2011/04/25 09:17:57.607| ACL::ChecklistMatches: result for 'new_users' is -1
2011/04/25 09:17:57.607| ACLList::matches: result is false
2011/04/25 09:17:57.607| aclmatchAclList: 0xe1a9348 returning false (AND list entry failed to match)
2011/04/25 09:17:57.607| ACLChecklist::asyncInProgress: 0xe1a9348 async set to 1
2011/04/25 09:17:57.607| externalAclLookup: lookup in 'session' for '10.140.43.227'
2011/04/25 09:17:57.607| externalAclLookup: looking up for '10.140.43.227' in 'session'.
2011/04/25 09:17:57.607| The AsyncCall SomeCommWriteHander constructed, this=0xe1aadc0 [call44]
2011/04/25 09:17:57.607| comm_write: FD 17: sz 14: asynCall 0xe1aadc0*1
2011/04/25 09:17:57.607| helperDispatch: Request sent to session #5, 14 bytes
2011/04/25 09:17:57.607| externalAclLookup: will wait for the result of '10.140.43.227' in 'session' (ch=0xe1a9348).
2011/04/25 09:17:57.607| aclmatchAclList: async=1 nodeMatched=0 async_in_progress=1 lastACLResult() = 0 finished() = 0
2011/04/25 09:17:57.607| WARNING: session #4 (FD 15) exited
2011/04/25 09:17:57.607| Too few session processes are running
2011/04/25 09:17:57.607| leave_suid: PID 9962 called
2011/04/25 09:17:57.607| storeDirWriteCleanLogs: Starting...
2011/04/25 09:17:57.607| Finished. Wrote 0 entries.
2011/04/25 09:17:57.607| Took 0.00 seconds ( 0.00 entries/sec).
FATAL: The session helpers are crashing too rapidly, need help!
Received on Mon Apr 25 2011 - 14:54:28 MDT

This archive was generated by hypermail 2.2.0 : Tue Apr 26 2011 - 12:00:03 MDT