[squid-users] Squid Hangs

Hi,

I regularly get squid hangs (around once a month or so). When I say hang, I mean browsing through Squid runs very slowly and CPU utilisation is 100%.

I just restart squid to clear the hang.

I ran squid -k debug during the hang and I will past the output below.

Any ideas?

Thanks

Daniel

----------------
2013/08/04 01:45:47.867 kid1| AsyncCallQueue.cc(53) fireNext: leaving comm_close_complete(FD 688)
2013/08/04 01:45:47.867 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::clientReadRequest(local=108.160.163.45:80 remote=10.11.187.65 flags=17, errno=11, flag=-10, data=0x7f99ef0c3dc8, size=0, buf=0x7f99eca46750)
2013/08/04 01:45:47.867 kid1| AsyncCall.cc(30) make: make call ConnStateData::clientReadRequest [call1052636]
2013/08/04 01:45:47.867 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job15215]
2013/08/04 01:45:47.867 kid1| client_side.cc(2924) clientReadRequest: local=108.160.163.45:80 remote=10.11.187.65 flags=17 size 0
2013/08/04 01:45:47.867 kid1| client_side.cc(2931) clientReadRequest: local=108.160.163.45:80 remote=10.11.187.65 flags=17 closing Bailout.
2013/08/04 01:45:47.867 kid1| AsyncJob.cc(146) callEnd: ConnStateData status out: [ job15215]
2013/08/04 01:45:47.867 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::clientReadRequest(local=108.160.163.45:80 remote=10.11.187.65 flags=17, errno=11, flag=-10, data=0x7f99ef0c3dc8, size=0, buf=0x7f99eca46750)
2013/08/04 01:45:47.867 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x7f99ef0c3dc8)
2013/08/04 01:45:47.867 kid1| AsyncCall.cc(30) make: make call ConnStateData::connStateClosed [call1051337]
2013/08/04 01:45:47.867 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job15215]
2013/08/04 01:45:47.867 kid1| AsyncJob.cc(49) deleteThis: ConnStateData will NOT delete in-call job, reason: ConnStateData::connStateClosed
2013/08/04 01:45:47.867 kid1| AsyncJob.cc(131) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99ef0c3dc8) ends job [Stopped, reason:ConnStateData::connStateClosed job15215]
2013/08/04 01:45:47.867 kid1| client_side.cc(777) swanSong: local=108.160.163.45:80 remote=10.11.187.65 flags=17
2013/08/04 01:45:47.867 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99edba3af8
2013/08/04 01:45:47.867 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99edba3af8
2013/08/04 01:45:47.867 kid1| clientStream.cc(246) clientStreamDetach: clientStreamDetach: Calling 1 with cbdata 0x7f99ece97490
2013/08/04 01:45:47.867 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99eae3a568
2013/08/04 01:45:47.867 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99eae3a568
2013/08/04 01:45:47.867 kid1| store_client.cc(693) storeUnregister: storeUnregister: called for '6E498BCF45BBB7AC0519E3E7A1136DB6'
2013/08/04 01:45:47.867 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
2013/08/04 01:45:47.867 kid1| MemObject.cc(272) expectedReplySize: object_sz: 3283
2013/08/04 01:45:47.867 kid1| store_dir.cc(824) maybeTrimMemory: keepInLocalMemory: 1
2013/08/04 01:45:47.867 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:47.867 kid1| store.cc(570) unlock: StoreEntry::unlock: key '6E498BCF45BBB7AC0519E3E7A1136DB6' count=1
2013/08/04 01:45:47.867 kid1| client_side_request.cc(291) ~ClientHttpRequest: httpRequestFree: http://notify1.dropbox.com/subscribe?host_int=339437646&ns_map=164883234_35437940042530&user_id=101470670&nid=0&ts=1375577316
2013/08/04 01:45:47.867 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ed9989b8)
2013/08/04 01:45:47.867 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ed9989b8)
2013/08/04 01:45:47.867 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ef8c41d8)
2013/08/04 01:45:47.867 kid1| History.cc(40) processingTime: current total: 57138 0x7f99eb9e3550
2013/08/04 01:45:47.867 kid1| FilledChecklist.cc(77) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:47.867 kid1| Checklist.cc(334) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:47.868 kid1| store.cc(570) unlock: StoreEntry::unlock: key '6E498BCF45BBB7AC0519E3E7A1136DB6' count=0
2013/08/04 01:45:47.868 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:47.868 kid1| store.cc(1261) release: storeRelease: Releasing: '6E498BCF45BBB7AC0519E3E7A1136DB6'
2013/08/04 01:45:47.868 kid1| store.cc(466) destroyStoreEntry: destroyStoreEntry: destroying 0x7f99edc2bdf8
2013/08/04 01:45:47.868 kid1| store.cc(444) destroyMemObject: destroyMemObject 0x7f99eb6832e0
2013/08/04 01:45:47.868 kid1| MemObject.cc(111) ~MemObject: del MemObject 0x7f99eb6832e0
2013/08/04 01:45:47.868 kid1| ctx: enter level 0: 'http://notify1.dropbox.com/subscribe?host_int=339437646&ns_map=164883234_35437940042530&user_id=101470670&nid=0&ts=1375577316'
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6859b8 owner: 3
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6859b8 owner: 3
2013/08/04 01:45:47.868 kid1| ctx: exit level 0
2013/08/04 01:45:47.868 kid1| AsyncCall.cc(18) AsyncCall: The AsyncCall Initiate::noteInitiatorAborted constructed, this=0x7f99ec115370 [call1059580]
2013/08/04 01:45:47.868 kid1| AsyncCall.cc(85) ScheduleCall: Initiator.cc(34) will call Initiate::noteInitiatorAborted() [call1059580]
2013/08/04 01:45:47.868 kid1| client_side_request.cc(150) ~ClientRequestContext: 0x7f99eb7f1968 ClientRequestContext destructed
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6833f8 owner: 3
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6833f8 owner: 3
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ed9989b8 owner: 2
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ef8c4208 owner: 3
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ef8c41d8 owner: 3
2013/08/04 01:45:47.868 kid1| HttpRequest.cc(76) ~HttpRequest: destructed, this=0x7f99ed9989a0
2013/08/04 01:45:47.868 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ed9989b8 owner: 2
2013/08/04 01:45:47.868 kid1| AsyncJob.cc(34) ~AsyncJob: AsyncJob destructed, this=0x7f99f0948fc8 type=ClientHttpRequest [job15589]
2013/08/04 01:45:47.868 kid1| client_side.cc(4503) unpinConnection:
2013/08/04 01:45:47.868 kid1| client_side.cc(810) ~ConnStateData:
2013/08/04 01:45:47.868 kid1| AsyncJob.cc(34) ~AsyncJob: AsyncJob destructed, this=0x7f99ef0c3f38 type=ConnStateData [job15215]
2013/08/04 01:45:47.868 kid1| AsyncJob.cc(141) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99ef0c3dc8) ended 0x7f99ef0c3f38
2013/08/04 01:45:47.868 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::connStateClosed(FD -1, data=0x7f99ef0c3dc8)
2013/08/04 01:45:47.868 kid1| AsyncCallQueue.cc(51) fireNext: entering comm_close_complete(FD 695)
2013/08/04 01:45:47.868 kid1| AsyncCall.cc(30) make: make call comm_close_complete [call1058916]
2013/08/04 01:45:47.868 kid1| fd.cc(116) fd_close: fd_close FD 695 Reading next request
2013/08/04 01:45:47.868 kid1| ModEpoll.cc(139) SetSelect: FD 695, type=1, handler=0, client_data=0, timeout=0
2013/08/04 01:45:47.868 kid1| ModEpoll.cc(139) SetSelect: FD 695, type=2, handler=0, client_data=0, timeout=0
2013/08/04 01:45:47.868 kid1| AcceptLimiter.cc(47) kick: size=17733278
2013/08/04 01:45:48.248 kid1| AcceptLimiter.cc(52) kick: doing one.
2013/08/04 01:45:48.248 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=[::]:3129 remote=[::] FD 44 flags=25
2013/08/04 01:45:48.248 kid1| fd.cc(221) fd_open: fd_open() FD 688 HTTP Request
2013/08/04 01:45:48.248 kid1| Intercept.cc(364) Lookup: address BEGIN: me/client= 54.225.184.69:443, destination/me= 10.11.187.177:60318
2013/08/04 01:45:48.248 kid1| Intercept.cc(157) NetfilterTransparent: address TPROXY: local=54.225.184.69:443 remote=10.11.187.177 FD 688 flags=17
2013/08/04 01:45:48.248 kid1| TcpAcceptor.cc(264) acceptOne: Listener: local=[::]:3129 remote=[::] FD 44 flags=25 accepted new connection local=54.225.184.69:443 remote=10.11.187.177 FD 688 flags=17 handler Subscription: 0x7f99ead79460*1
2013/08/04 01:45:48.248 kid1| AsyncCall.cc(18) AsyncCall: The AsyncCall httpsAccept constructed, this=0x7f99ecc4d080 [call1059581]
2013/08/04 01:45:48.248 kid1| AsyncCall.cc(85) ScheduleCall: TcpAcceptor.cc(292) will call httpsAccept(local=54.225.184.69:443 remote=10.11.187.177 FD 688 flags=17, data=0x7f99ea6fc068) [call1059581]
2013/08/04 01:45:48.248 kid1| AsyncCallQueue.cc(53) fireNext: leaving comm_close_complete(FD 695)
2013/08/04 01:45:48.248 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::clientReadRequest(local=108.160.163.39:80 remote=10.11.187.65 flags=17, errno=11, flag=-10, data=0x7f99eb644c58, size=0, buf=0x7f99ec827bb0)
2013/08/04 01:45:48.248 kid1| AsyncCall.cc(30) make: make call ConnStateData::clientReadRequest [call1047385]
2013/08/04 01:45:48.248 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job13971]
2013/08/04 01:45:48.248 kid1| client_side.cc(2924) clientReadRequest: local=108.160.163.39:80 remote=10.11.187.65 flags=17 size 0
2013/08/04 01:45:48.248 kid1| client_side.cc(2931) clientReadRequest: local=108.160.163.39:80 remote=10.11.187.65 flags=17 closing Bailout.
2013/08/04 01:45:48.248 kid1| AsyncJob.cc(146) callEnd: ConnStateData status out: [ job13971]
2013/08/04 01:45:48.248 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::clientReadRequest(local=108.160.163.39:80 remote=10.11.187.65 flags=17, errno=11, flag=-10, data=0x7f99eb644c58, size=0, buf=0x7f99ec827bb0)
2013/08/04 01:45:48.248 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x7f99eb644c58)
2013/08/04 01:45:48.248 kid1| AsyncCall.cc(30) make: make call ConnStateData::connStateClosed [call1046065]
2013/08/04 01:45:48.248 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job13971]
2013/08/04 01:45:48.248 kid1| AsyncJob.cc(49) deleteThis: ConnStateData will NOT delete in-call job, reason: ConnStateData::connStateClosed
2013/08/04 01:45:48.248 kid1| AsyncJob.cc(131) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99eb644c58) ends job [Stopped, reason:ConnStateData::connStateClosed job13971]
2013/08/04 01:45:48.248 kid1| client_side.cc(777) swanSong: local=108.160.163.39:80 remote=10.11.187.65 flags=17
2013/08/04 01:45:48.248 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99ed9f68b8
2013/08/04 01:45:48.248 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99ed9f68b8
2013/08/04 01:45:48.248 kid1| clientStream.cc(246) clientStreamDetach: clientStreamDetach: Calling 1 with cbdata 0x7f99ed9f6880
2013/08/04 01:45:48.248 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99ec9f3878
2013/08/04 01:45:48.248 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99ec9f3878
2013/08/04 01:45:48.248 kid1| store_client.cc(693) storeUnregister: storeUnregister: called for 'E8D14570B0A5883523A8FB2819EC52F8'
2013/08/04 01:45:48.248 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
2013/08/04 01:45:48.248 kid1| MemObject.cc(272) expectedReplySize: object_sz: 3327
2013/08/04 01:45:48.248 kid1| store_dir.cc(824) maybeTrimMemory: keepInLocalMemory: 1
2013/08/04 01:45:48.248 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:48.248 kid1| store.cc(570) unlock: StoreEntry::unlock: key 'E8D14570B0A5883523A8FB2819EC52F8' count=1
2013/08/04 01:45:48.248 kid1| client_side_request.cc(291) ~ClientHttpRequest: httpRequestFree: http://notify6.dropbox.com/subscribe?host_int=608497221&ns_map=151069192_8096164422152,219395318_4870712308982&user_id=92734255&nid=0&ts=1375576776
2013/08/04 01:45:48.248 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ece0b0c8)
2013/08/04 01:45:48.248 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ece0b0c8)
2013/08/04 01:45:48.248 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ef8c45f8)
2013/08/04 01:45:48.248 kid1| History.cc(40) processingTime: current total: 138945 0x7f99ec55d4b0
2013/08/04 01:45:48.249 kid1| FilledChecklist.cc(77) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:48.249 kid1| Checklist.cc(334) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:48.249 kid1| store.cc(570) unlock: StoreEntry::unlock: key 'E8D14570B0A5883523A8FB2819EC52F8' count=0
2013/08/04 01:45:48.249 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:48.249 kid1| store.cc(1261) release: storeRelease: Releasing: 'E8D14570B0A5883523A8FB2819EC52F8'
2013/08/04 01:45:48.249 kid1| store.cc(466) destroyStoreEntry: destroyStoreEntry: destroying 0x7f99eaee0938
2013/08/04 01:45:48.249 kid1| store.cc(444) destroyMemObject: destroyMemObject 0x7f99eb6866d0
2013/08/04 01:45:48.249 kid1| MemObject.cc(111) ~MemObject: del MemObject 0x7f99eb6866d0
2013/08/04 01:45:48.249 kid1| ctx: enter level 0: 'http://notify6.dropbox.com/subscribe?host_int=608497221&ns_map=151069192_8096164422152,219395318_4870712308982&user_id=92734255&nid=0&ts=1375576776'
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6873a8 owner: 3
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6873a8 owner: 3
2013/08/04 01:45:48.249 kid1| ctx: exit level 0
2013/08/04 01:45:48.249 kid1| AsyncCall.cc(18) AsyncCall: The AsyncCall Initiate::noteInitiatorAborted constructed, this=0x7f99ed55b120 [call1059582]
2013/08/04 01:45:48.249 kid1| AsyncCall.cc(85) ScheduleCall: Initiator.cc(34) will call Initiate::noteInitiatorAborted() [call1059582]
2013/08/04 01:45:48.249 kid1| client_side_request.cc(150) ~ClientRequestContext: 0x7f99ed9f6fd8 ClientRequestContext destructed
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6867e8 owner: 3
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6867e8 owner: 3
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ece0b0c8 owner: 2
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ef8c4628 owner: 3
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ef8c45f8 owner: 3
2013/08/04 01:45:48.249 kid1| HttpRequest.cc(76) ~HttpRequest: destructed, this=0x7f99ece0b0b0
2013/08/04 01:45:48.249 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ece0b0c8 owner: 2
2013/08/04 01:45:48.249 kid1| AsyncJob.cc(34) ~AsyncJob: AsyncJob destructed, this=0x7f99ed9f4228 type=ClientHttpRequest [job14249]
2013/08/04 01:45:48.249 kid1| client_side.cc(4503) unpinConnection:
2013/08/04 01:45:48.249 kid1| client_side.cc(810) ~ConnStateData:
2013/08/04 01:45:48.249 kid1| AsyncJob.cc(34) ~AsyncJob: AsyncJob destructed, this=0x7f99eb644dc8 type=ConnStateData [job13971]
2013/08/04 01:45:48.249 kid1| AsyncJob.cc(141) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99eb644c58) ended 0x7f99eb644dc8
2013/08/04 01:45:48.249 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::connStateClosed(FD -1, data=0x7f99eb644c58)
2013/08/04 01:45:48.249 kid1| AsyncCallQueue.cc(51) fireNext: entering comm_close_complete(FD 458)
2013/08/04 01:45:48.249 kid1| AsyncCall.cc(30) make: make call comm_close_complete [call1058917]
2013/08/04 01:45:48.249 kid1| fd.cc(116) fd_close: fd_close FD 458 Reading next request
2013/08/04 01:45:48.249 kid1| ModEpoll.cc(139) SetSelect: FD 458, type=1, handler=0, client_data=0, timeout=0
2013/08/04 01:45:48.249 kid1| ModEpoll.cc(139) SetSelect: FD 458, type=2, handler=0, client_data=0, timeout=0
2013/08/04 01:45:48.249 kid1| AcceptLimiter.cc(47) kick: size=17733277
2013/08/04 01:45:48.629 kid1| AcceptLimiter.cc(52) kick: doing one.
2013/08/04 01:45:48.629 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=[::]:8080 remote=[::] FD 43 flags=9
2013/08/04 01:45:48.629 kid1| TcpAcceptor.cc(323) oldAccept: FD 43, [::] [Stopped, reason:Listener socket closed job4]: (11) Resource temporarily unavailable
2013/08/04 01:45:48.629 kid1| TcpAcceptor.cc(250) acceptOne: try later: local=[::]:8080 remote=[::] FD 43 flags=9 handler Subscription: 0x7f99ead79280*1
2013/08/04 01:45:48.629 kid1| ModEpoll.cc(139) SetSelect: FD 43, type=1, handler=1, client_data=0x7f99ead79178, timeout=0
2013/08/04 01:45:48.629 kid1| AsyncCallQueue.cc(53) fireNext: leaving comm_close_complete(FD 458)
2013/08/04 01:45:48.629 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::clientReadRequest(local=77.234.45.55:80 remote=10.242.141.232 flags=17, errno=11, flag=-10, data=0x7f99eee67c18, size=0, buf=0x7f99ed874d50)
2013/08/04 01:45:48.629 kid1| AsyncCall.cc(30) make: make call ConnStateData::clientReadRequest [call1047420]
2013/08/04 01:45:48.629 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job13992]
2013/08/04 01:45:48.629 kid1| client_side.cc(2924) clientReadRequest: local=77.234.45.55:80 remote=10.242.141.232 flags=17 size 0
2013/08/04 01:45:48.629 kid1| client_side.cc(2931) clientReadRequest: local=77.234.45.55:80 remote=10.242.141.232 flags=17 closing Bailout.
2013/08/04 01:45:48.629 kid1| AsyncJob.cc(146) callEnd: ConnStateData status out: [ job13992]
2013/08/04 01:45:48.629 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::clientReadRequest(local=77.234.45.55:80 remote=10.242.141.232 flags=17, errno=11, flag=-10, data=0x7f99eee67c18, size=0, buf=0x7f99ed874d50)
2013/08/04 01:45:48.629 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x7f99eee67c18)
2013/08/04 01:45:48.629 kid1| AsyncCall.cc(30) make: make call ConnStateData::connStateClosed [call1046114]
2013/08/04 01:45:48.629 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job13992]
2013/08/04 01:45:48.630 kid1| AsyncJob.cc(49) deleteThis: ConnStateData will NOT delete in-call job, reason: ConnStateData::connStateClosed
2013/08/04 01:45:48.630 kid1| AsyncJob.cc(131) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99eee67c18) ends job [Stopped, reason:ConnStateData::connStateClosed job13992]
2013/08/04 01:45:48.630 kid1| client_side.cc(777) swanSong: local=77.234.45.55:80 remote=10.242.141.232 flags=17
2013/08/04 01:45:48.630 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99eba07858
2013/08/04 01:45:48.630 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99eba07858
2013/08/04 01:45:48.630 kid1| clientStream.cc(246) clientStreamDetach: clientStreamDetach: Calling 1 with cbdata 0x7f99ed5e8f00
2013/08/04 01:45:48.630 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99ec10e628
2013/08/04 01:45:48.630 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99ec10e628
2013/08/04 01:45:48.630 kid1| store_client.cc(693) storeUnregister: storeUnregister: called for '2B66080D95F7F754D2B4289C8C2631F5'
2013/08/04 01:45:48.630 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
2013/08/04 01:45:48.630 kid1| MemObject.cc(272) expectedReplySize: object_sz: 3195
2013/08/04 01:45:48.630 kid1| store_dir.cc(824) maybeTrimMemory: keepInLocalMemory: 1
2013/08/04 01:45:48.630 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:48.630 kid1| store.cc(570) unlock: StoreEntry::unlock: key '2B66080D95F7F754D2B4289C8C2631F5' count=1
2013/08/04 01:45:48.630 kid1| client_side_request.cc(291) ~ClientHttpRequest: httpRequestFree: http://su.ff.avast.com/R/AzMKELla0Ii2KKdComhTKD_3Uw0SBAAZAxMY9wEiAf4qBAgDEAAqBwgEEIHU-xYqBAgFEAE=
2013/08/04 01:45:48.630 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ed5e8fb8)
2013/08/04 01:45:48.630 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ed5e8fb8)
2013/08/04 01:45:48.630 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ef8c4b18)
2013/08/04 01:45:48.630 kid1| History.cc(40) processingTime: current total: 183759 0x7f99ed5e9cd0
2013/08/04 01:45:48.630 kid1| FilledChecklist.cc(77) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:48.630 kid1| Checklist.cc(334) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:48.630 kid1| store.cc(570) unlock: StoreEntry::unlock: key '2B66080D95F7F754D2B4289C8C2631F5' count=0
2013/08/04 01:45:48.630 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:48.630 kid1| store.cc(1261) release: storeRelease: Releasing: '2B66080D95F7F754D2B4289C8C2631F5'
2013/08/04 01:45:48.630 kid1| store.cc(466) destroyStoreEntry: destroyStoreEntry: destroying 0x7f99eb35b788
2013/08/04 01:45:48.630 kid1| store.cc(444) destroyMemObject: destroyMemObject 0x7f99eb6880e0
2013/08/04 01:45:48.630 kid1| MemObject.cc(111) ~MemObject: del MemObject 0x7f99eb6880e0
2013/08/04 01:45:48.630 kid1| ctx: enter level 0: 'http://su.ff.avast.com/R/AzMKELla0Ii2KKdComhTKD_3Uw0SBAAZAxMY9wEiAf4qBAgDEAAqBwgEEIHU-xYqBAgFEAE='
2013/08/04 01:45:48.630 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb688318 owner: 3
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb688318 owner: 3
2013/08/04 01:45:48.631 kid1| ctx: exit level 0
2013/08/04 01:45:48.631 kid1| AsyncCall.cc(18) AsyncCall: The AsyncCall Initiate::noteInitiatorAborted constructed, this=0x7f99ed5e9a70 [call1059583]
2013/08/04 01:45:48.631 kid1| AsyncCall.cc(85) ScheduleCall: Initiator.cc(34) will call Initiate::noteInitiatorAborted() [call1059583]
2013/08/04 01:45:48.631 kid1| client_side_request.cc(150) ~ClientRequestContext: 0x7f99ed5e9b98 ClientRequestContext destructed
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6881f8 owner: 3
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb6881f8 owner: 3
2013/08/04 01:45:48.631 kid1| BodyPipe.cc(139) ~BodyPipe: destroying BodyPipe [0<=1898<=1898 1898+149 pipe0x7f99ed5e9af8]
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ed5e8fb8 owner: 2
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ef8c4b48 owner: 3
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ef8c4b18 owner: 3
2013/08/04 01:45:48.631 kid1| HttpRequest.cc(76) ~HttpRequest: destructed, this=0x7f99ed5e8fa0
2013/08/04 01:45:48.631 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99ed5e8fb8 owner: 2
2013/08/04 01:45:48.631 kid1| AsyncJob.cc(34) ~AsyncJob: AsyncJob destructed, this=0x7f99eba07d58 type=ClientHttpRequest [job14272]
2013/08/04 01:45:48.631 kid1| client_side.cc(4503) unpinConnection:
2013/08/04 01:45:48.631 kid1| client_side.cc(810) ~ConnStateData:
2013/08/04 01:45:48.631 kid1| AsyncJob.cc(34) ~AsyncJob: AsyncJob destructed, this=0x7f99eee67d88 type=ConnStateData [job13992]
2013/08/04 01:45:48.631 kid1| AsyncJob.cc(141) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99eee67c18) ended 0x7f99eee67d88
2013/08/04 01:45:48.631 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::connStateClosed(FD -1, data=0x7f99eee67c18)
2013/08/04 01:45:48.631 kid1| AsyncCallQueue.cc(51) fireNext: entering comm_close_complete(FD 187)
2013/08/04 01:45:48.631 kid1| AsyncCall.cc(30) make: make call comm_close_complete [call1058918]
2013/08/04 01:45:48.631 kid1| fd.cc(116) fd_close: fd_close FD 187 Reading next request
2013/08/04 01:45:48.631 kid1| ModEpoll.cc(139) SetSelect: FD 187, type=1, handler=0, client_data=0, timeout=0
2013/08/04 01:45:48.631 kid1| ModEpoll.cc(139) SetSelect: FD 187, type=2, handler=0, client_data=0, timeout=0
2013/08/04 01:45:48.631 kid1| AcceptLimiter.cc(47) kick: size=17733276
2013/08/04 01:45:49.017 kid1| AcceptLimiter.cc(52) kick: doing one.
2013/08/04 01:45:49.017 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=[::]:3128 remote=[::] FD 42 flags=25
2013/08/04 01:45:49.017 kid1| fd.cc(221) fd_open: fd_open() FD 187 HTTP Request
2013/08/04 01:45:49.017 kid1| Intercept.cc(364) Lookup: address BEGIN: me/client= 212.118.234.171:80, destination/me= 10.11.184.47:5060
2013/08/04 01:45:49.017 kid1| Intercept.cc(157) NetfilterTransparent: address TPROXY: local=212.118.234.171:80 remote=10.11.184.47 FD 187 flags=17
2013/08/04 01:45:49.017 kid1| TcpAcceptor.cc(264) acceptOne: Listener: local=[::]:3128 remote=[::] FD 42 flags=25 accepted new connection local=212.118.234.171:80 remote=10.11.184.47 FD 187 flags=17 handler Subscription: 0x7f99ead79130*1
2013/08/04 01:45:49.017 kid1| AsyncCall.cc(18) AsyncCall: The AsyncCall httpAccept constructed, this=0x7f99ec52b130 [call1059584]
2013/08/04 01:45:49.017 kid1| AsyncCall.cc(85) ScheduleCall: TcpAcceptor.cc(292) will call httpAccept(local=212.118.234.171:80 remote=10.11.184.47 FD 187 flags=17, data=0x7f99ea6fbd48) [call1059584]
2013/08/04 01:45:49.017 kid1| AsyncCallQueue.cc(53) fireNext: leaving comm_close_complete(FD 187)
2013/08/04 01:45:49.017 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::clientReadRequest(local=199.19.249.203:80 remote=10.242.141.232 flags=17, errno=11, flag=-10, data=0x7f99ebf32048, size=0, buf=0x7f99eb163890)
2013/08/04 01:45:49.017 kid1| AsyncCall.cc(30) make: make call ConnStateData::clientReadRequest [call1052527]
2013/08/04 01:45:49.017 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job15125]
2013/08/04 01:45:49.017 kid1| client_side.cc(2924) clientReadRequest: local=199.19.249.203:80 remote=10.242.141.232 flags=17 size 0
2013/08/04 01:45:49.018 kid1| client_side.cc(2931) clientReadRequest: local=199.19.249.203:80 remote=10.242.141.232 flags=17 closing Bailout.
2013/08/04 01:45:49.018 kid1| AsyncJob.cc(146) callEnd: ConnStateData status out: [ job15125]
2013/08/04 01:45:49.018 kid1| AsyncCallQueue.cc(53) fireNext: leaving ConnStateData::clientReadRequest(local=199.19.249.203:80 remote=10.242.141.232 flags=17, errno=11, flag=-10, data=0x7f99ebf32048, size=0, buf=0x7f99eb163890)
2013/08/04 01:45:49.018 kid1| AsyncCallQueue.cc(51) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x7f99ebf32048)
2013/08/04 01:45:49.018 kid1| AsyncCall.cc(30) make: make call ConnStateData::connStateClosed [call1051032]
2013/08/04 01:45:49.018 kid1| AsyncJob.cc(117) callStart: ConnStateData status in: [ job15125]
2013/08/04 01:45:49.018 kid1| AsyncJob.cc(49) deleteThis: ConnStateData will NOT delete in-call job, reason: ConnStateData::connStateClosed
2013/08/04 01:45:49.018 kid1| AsyncJob.cc(131) callEnd: ConnStateData::connStateClosed(FD -1, data=0x7f99ebf32048) ends job [Stopped, reason:ConnStateData::connStateClosed job15125]
2013/08/04 01:45:49.018 kid1| client_side.cc(777) swanSong: local=199.19.249.203:80 remote=10.242.141.232 flags=17
2013/08/04 01:45:49.018 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99ed603c88
2013/08/04 01:45:49.018 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99ed603c88
2013/08/04 01:45:49.018 kid1| clientStream.cc(246) clientStreamDetach: clientStreamDetach: Calling 1 with cbdata 0x7f99eaa59cd0
2013/08/04 01:45:49.018 kid1| clientStream.cc(225) clientStreamDetach: clientStreamDetach: Detaching node 0x7f99ef728a78
2013/08/04 01:45:49.018 kid1| clientStream.cc(310) clientStreamFree: Freeing clientStreamNode 0x7f99ef728a78
2013/08/04 01:45:49.018 kid1| store_client.cc(693) storeUnregister: storeUnregister: called for '350789C3765F31168A3F9DAFE7A78928'
2013/08/04 01:45:49.018 kid1| store_swapout.cc(375) mayStartSwapOut: already rejected
2013/08/04 01:45:49.018 kid1| MemObject.cc(272) expectedReplySize: object_sz: 3211
2013/08/04 01:45:49.018 kid1| store_dir.cc(824) maybeTrimMemory: keepInLocalMemory: 1
2013/08/04 01:45:49.018 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:49.018 kid1| store.cc(570) unlock: StoreEntry::unlock: key '350789C3765F31168A3F9DAFE7A78928' count=1
2013/08/04 01:45:49.018 kid1| client_side_request.cc(291) ~ClientHttpRequest: httpRequestFree: http://sp.cwfservice.net/1/R/K9BY957F48/K9-00006/0/GET/HTTP/download312.avast.com/80/iavs5x/prod-ais.vpx/
2013/08/04 01:45:49.018 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ecba98b8)
2013/08/04 01:45:49.018 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99ecba98b8)
2013/08/04 01:45:49.018 kid1| HttpHeader.cc(713) packInto: packing hdr: (0x7f99f132ae18)
2013/08/04 01:45:49.018 kid1| History.cc(40) processingTime: current total: 57137 0x7f99ee940000
2013/08/04 01:45:49.018 kid1| FilledChecklist.cc(77) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:49.018 kid1| Checklist.cc(334) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x7f99ec1bdeb8
2013/08/04 01:45:49.018 kid1| store.cc(570) unlock: StoreEntry::unlock: key '350789C3765F31168A3F9DAFE7A78928' count=0
2013/08/04 01:45:49.018 kid1| store_client.cc(782) storePendingNClients: storePendingNClients: returning 0
2013/08/04 01:45:49.018 kid1| store.cc(1261) release: storeRelease: Releasing: '350789C3765F31168A3F9DAFE7A78928'
2013/08/04 01:45:49.018 kid1| store.cc(466) destroyStoreEntry: destroyStoreEntry: destroying 0x7f99ef5d8268
2013/08/04 01:45:49.018 kid1| store.cc(444) destroyMemObject: destroyMemObject 0x7f99eb68aa60
2013/08/04 01:45:49.018 kid1| MemObject.cc(111) ~MemObject: del MemObject 0x7f99eb68aa60
2013/08/04 01:45:49.018 kid1| ctx: enter level 0: 'http://sp.cwfservice.net/1/R/K9BY957F48/K9-00006/0/GET/HTTP/download312.avast.com/80/iavs5x/prod-ais.vpx/'
2013/08/04 01:45:49.018 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb68b638 owner: 3
2013/08/04 01:45:49.018 kid1| HttpHeader.cc(437) clean: cleaning hdr: 0x7f99eb68b638 owner: 3
2013/08/04 01:45:49.018 kid1| ctx: exit level 0
Received on Sun Aug 04 2013 - 01:31:31 MDT