[squid-users] Squid 4.0.19 SSLBump Crashes

Deniz Eren denizlist at denizeren.net
Wed May 10 14:32:58 UTC 2017


Hi,

I'm testing squid squid-4.0.19-20170508-r15031 when I enable ssl-bump
in intercept mode, after couple of SSL requests squid crashes in
"Parser::BinaryTokenizer::want(unsigned long long, char const*) const
()" function.

OS: CentOS 5
OpenSSL: 1.0.1e-51
g++: 4.8.2-15

I have attached part of debug log,core stack trace and squid.conf.(I
have migrated from 3.5, so there might be non-correct parts in my
squid.conf)

Does something wrong with my compilation or squid.conf; how can I
debug this issue.

Regards,
-------------- next part --------------
(gdb) bt
#0  0xf6f9fc80 in __kernel_vsyscall ()
#1  0xf6992b10 in raise () from /lib/libc.so.6
#2  0xf6994421 in abort () from /lib/libc.so.6
#3  0xf6bb2ab0 in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib/libstdc++.so.6
#4  0xf6bb0515 in __gxx_personality_v0 () from /usr/lib/libstdc++.so.6
#5  0xf6bb0552 in __gxx_personality_v0 () from /usr/lib/libstdc++.so.6
#6  0xf6bb068a in __cxa_rethrow () from /usr/lib/libstdc++.so.6
#7  0xf7443830 in Parser::BinaryTokenizer::want(unsigned long long, char const*) const ()
#8  0xf744571d in Parser::BinaryTokenizer::area(unsigned long long, char const*) ()
#9  0xf7445915 in Parser::BinaryTokenizer::pstring16(char const*) ()
#10 0xf73c8238 in Security::TLSPlaintext::TLSPlaintext(Parser::BinaryTokenizer&) ()
#11 0xf73c9fa9 in Security::HandshakeParser::parseModernRecord() ()
#12 0xf73ca70d in Security::HandshakeParser::parseRecord() ()
#13 0xf73ca780 in Security::HandshakeParser::parseHello(SBuf const&) ()
#14 0xf73e158c in Ssl::ServerBio::readAndParse(char*, int, bio_st*) ()
#15 0xf73e195a in Ssl::ServerBio::read(char*, int, bio_st*) ()
#16 0xf73de898 in ?? ()
#17 0xf6dd7271 in BIO_read () from /lib/libcrypto.so.10
#18 0xf6f0b98b in ssl23_read_bytes () from /lib/libssl.so.10
#19 0xf6f0a902 in ssl23_connect () from /lib/libssl.so.10
#20 0xf6f1e09a in SSL_connect () from /lib/libssl.so.10
#21 0xf73d1f4d in Security::PeerConnector::negotiate() ()
#22 0xf73d4735 in NullaryMemFunT<Security::PeerConnector>::doDial() ()
#23 0xf73d510f in JobDialer<Security::PeerConnector>::dial(AsyncCall&) ()
#24 0xf73d52d2 in AsyncCallT<NullaryMemFunT<Security::PeerConnector> >::fire() ()
#25 0xf73615fb in AsyncCall::make() ()
#26 0xf736616c in AsyncCallQueue::fireNext() ()
#27 0xf7366568 in AsyncCallQueue::fire() ()
#28 0xf7185114 in EventLoop::runOnce() ()
#29 0xf7185228 in EventLoop::run() ()
#30 0xf71fc9f9 in SquidMain(int, char**) ()
#31 0xf70ce209 in main ()
-------------- next part --------------
2017/05/10 16:07:57.917 kid1| 5,8| ModEpoll.cc(266) DoSelect: got FD 23 events=4 monitoring=1c F->read_handler=0 F->write_handler=1
2017/05/10 16:07:57.917 kid1| 5,8| ModEpoll.cc(288) DoSelect: Calling write handler on FD 23
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf959c078=6
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf959c078=7
2017/05/10 16:07:57.917 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall Comm::ConnOpener::doConnect constructed, this=0xf9791d88 [call1160]
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf959c078=8
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=7
2017/05/10 16:07:57.917 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=6
2017/05/10 16:07:57.917 kid1| 5,4| AsyncCall.cc(93) ScheduleCall: ConnOpener.cc(463) will call Comm::ConnOpener::doConnect() [call1160]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=5
2017/05/10 16:07:57.918 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering Comm::ConnOpener::doConnect()
2017/05/10 16:07:57.918 kid1| 5,4| AsyncCall.cc(38) make: make call Comm::ConnOpener::doConnect [call1160]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.918 kid1| 5,4| AsyncJob.cc(123) callStart: Comm::ConnOpener status in: [ job139]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.918 kid1| 5,9| comm.cc(608) comm_connect_addr: connecting socket FD 23 to 192.229.233.50:443 (want family: 2)
2017/05/10 16:07:57.918 kid1| 5,9| comm.cc(714) comm_connect_addr: comm_connect_addr: FD 23 connected to 192.229.233.50:443
2017/05/10 16:07:57.918 kid1| 5,5| ConnOpener.cc(350) doConnect: local=0.0.0.0 remote=192.229.233.50:443 flags=1: Comm::OK - connected
2017/05/10 16:07:57.918 kid1| 5,4| ConnOpener.cc(155) cleanFd: local=0.0.0.0 remote=192.229.233.50:443 flags=1 closing temp FD 23
2017/05/10 16:07:57.918 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 23, type=2, handler=0, client_data=0, timeout=0
2017/05/10 16:07:57.918 kid1| 5,4| AsyncCall.cc(56) cancel: will not call Comm::ConnOpener::timeout [call1125] because Comm::ConnOpener::cleanFd
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=4
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=3
2017/05/10 16:07:57.918 kid1| 5,5| comm.cc(1030) comm_remove_close_handler: comm_remove_close_handler: FD 23, AsyncCall=0xf960bad0*2
2017/05/10 16:07:57.918 kid1| 5,4| AsyncCall.cc(56) cancel: will not call Comm::ConnOpener::earlyAbort [call1124] because comm_remove_close_handler
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=2
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=1
2017/05/10 16:07:57.918 kid1| 5,6| ConnOpener.cc(423) lookupLocalAddress: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1
2017/05/10 16:07:57.918 kid1| 17,3| AsyncCall.cc(93) ScheduleCall: ConnOpener.cc(139) will call fwdConnectDoneWrapper(local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1, data=0xf94d5020) [call1119]
2017/05/10 16:07:57.918 kid1| 93,5| AsyncJob.cc(84) mustStop: Comm::ConnOpener will stop, reason: Comm::ConnOpener::connected
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf959c078
2017/05/10 16:07:57.918 kid1| 93,5| AsyncJob.cc(139) callEnd: Comm::ConnOpener::doConnect() ends job [Stopped, reason:Comm::ConnOpener::connected job139]
2017/05/10 16:07:57.918 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0xf959c078 type=Comm::ConnOpener [job139]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(309) cbdataInternalFree: 0xf959c078
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(321) cbdataInternalFree: 0xf959c078 has 1 locks, not freeing
2017/05/10 16:07:57.918 kid1| 93,6| AsyncJob.cc(149) callEnd: Comm::ConnOpener::doConnect() ended 0xf959c078
2017/05/10 16:07:57.918 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving Comm::ConnOpener::doConnect()
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf959c078=0
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(276) cbdataRealFree: Freeing 0xf959c078
2017/05/10 16:07:57.918 kid1| 17,3| AsyncCallQueue.cc(55) fireNext: entering fwdConnectDoneWrapper(local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1, data=0xf94d5020)
2017/05/10 16:07:57.918 kid1| 17,3| AsyncCall.cc(38) make: make call fwdConnectDoneWrapper [call1119]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf94d5020
2017/05/10 16:07:57.918 kid1| 17,3| FwdState.cc(704) connectDone: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1: '192.229.233.50:443'
2017/05/10 16:07:57.918 kid1| 5,5| comm.cc(974) comm_add_close_handler: comm_add_close_handler: FD 23, handler=1, data=0xf94d5020
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf94d5020=3
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf94d5020=4
2017/05/10 16:07:57.918 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall SomeCloseHandler constructed, this=0xf95402c8 [call1161]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf94d5020=5
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf94d5020=4
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf94d5020=3
2017/05/10 16:07:57.918 kid1| 5,5| comm.cc(985) comm_add_close_handler: comm_add_close_handler: FD 23, AsyncCall=0xf95402c8*1
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf94d5020=4
2017/05/10 16:07:57.918 kid1| 17,4| AsyncCall.cc(26) AsyncCall: The AsyncCall FwdState::ConnectedToPeer constructed, this=0xf95dc780 [call1162]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf94d5020
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf94d5020=5
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf94d5020=4
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(256) cbdataInternalAlloc: Allocating 0xf963ed50
2017/05/10 16:07:57.918 kid1| 93,5| AsyncJob.cc(34) AsyncJob: AsyncJob constructed, this=0xf963edac type=Ssl::PeekingPeerConnector [job148]
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(41) PeerConnector: Security::PeerConnector constructed, this=0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=1
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=2
2017/05/10 16:07:57.918 kid1| 93,5| AsyncCall.cc(26) AsyncCall: The AsyncCall AsyncJob::start constructed, this=0xf9791d88 [call1163]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=3
2017/05/10 16:07:57.918 kid1| 93,5| AsyncCall.cc(93) ScheduleCall: AsyncJob.cc(26) will call AsyncJob::start() [call1163]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=2
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=1
2017/05/10 16:07:57.918 kid1| 17,3| AsyncCallQueue.cc(57) fireNext: leaving fwdConnectDoneWrapper(local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1, data=0xf94d5020)
2017/05/10 16:07:57.918 kid1| 93,5| AsyncCallQueue.cc(55) fireNext: entering AsyncJob::start()
2017/05/10 16:07:57.918 kid1| 93,5| AsyncCall.cc(38) make: make call AsyncJob::start [call1163]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 93,5| AsyncJob.cc(123) callStart: Ssl::PeekingPeerConnector status in: [ FD 23 job148]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(61) start: this=0xf963ed50
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(88) prepareSocket: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1, this=0xf963ed50
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(94) prepareSocket: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=2
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=3
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=4
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=5
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=4
2017/05/10 16:07:57.918 kid1| 9,5| AsyncCall.cc(26) AsyncCall: The AsyncCall Security::PeerConnector::commCloseHandler constructed, this=0xf960bad0 [call1164]
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=5
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf963ed50=6
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=5
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=4
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=3
2017/05/10 16:07:57.918 kid1| 5,5| comm.cc(985) comm_add_close_handler: comm_add_close_handler: FD 23, AsyncCall=0xf960bad0*1
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(107) initialize: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1, ctx=0xf8fbef98
2017/05/10 16:07:57.918 kid1| 83,5| Session.cc(98) NewSessionObject: SSL_new session=0xf96c9e60
2017/05/10 16:07:57.918 kid1| 83,5| bio.cc(616) squid_bio_ctrl: 0xf9789ec0 104(6001, 0xff91f760)
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9711 created
2017/05/10 16:07:57.918 kid1| 83,7| bio.cc(100) Bio: Bio constructed, this=0xf9760508 FD 23
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9712 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9713 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9714 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9715 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9716 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9717 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9718 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9719 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9720 created from id SBuf9719
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9719 destructed
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9721 created
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9722 created from id SBuf9721
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9721 destructed
2017/05/10 16:07:57.918 kid1| 83,5| Session.cc(157) CreateSession: link FD 23 to TLS session=0xf96c9e60
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(123) initialize: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1, session=0xf96c9e60
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(256) cbdataInternalAlloc: Allocating 0xf96bbb48
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9723 created
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf8faabb0=4
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf9512480
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf9512480
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf9512480=7
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf9512480
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9724 created from id SBuf9295
2017/05/10 16:07:57.918 kid1| 24,7| SBuf.cc(150) rawSpace: reserving 1 for SBuf9724
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(908) cow: SBuf9724 new size:14
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(878) reAlloc: SBuf9724 new size: 14
2017/05/10 16:07:57.918 kid1| 24,9| MemBlob.cc(56) MemBlob: constructed, this=0xf960ba80 id=blob2074 reserveSize=14
2017/05/10 16:07:57.918 kid1| 24,8| MemBlob.cc(101) memAlloc: blob2074 memAlloc: requested=14, received=14
2017/05/10 16:07:57.918 kid1| 24,7| SBuf.cc(887) reAlloc: SBuf9724 new store capacity: 14
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(187) negotiate: SSL_connect session=0xf96c9e60
2017/05/10 16:07:57.918 kid1| 83,7| bio.cc(168) stateChanged: FD 23 now: 0x10 UNKWN  (before/connect initialization)
2017/05/10 16:07:57.918 kid1| 83,7| bio.cc(168) stateChanged: FD 23 now: 0x1001 UNKWN  (before/connect initialization)
2017/05/10 16:07:57.918 kid1| 83,5| bio.cc(117) write: FD 23 wrote 234 <= 234
2017/05/10 16:07:57.918 kid1| 83,7| bio.cc(168) stateChanged: FD 23 now: 0x1001 23WCHA (SSLv2/v3 write client hello A)
2017/05/10 16:07:57.918 kid1| 24,7| SBuf.cc(150) rawSpace: reserving 65535 for SBuf9711
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(908) cow: SBuf9711 new size:65535
2017/05/10 16:07:57.918 kid1| 24,8| SBuf.cc(878) reAlloc: SBuf9711 new size: 65535
2017/05/10 16:07:57.918 kid1| 24,9| MemBlob.cc(56) MemBlob: constructed, this=0xf9540350 id=blob2075 reserveSize=65535
2017/05/10 16:07:57.918 kid1| 24,8| MemBlob.cc(101) memAlloc: blob2075 memAlloc: requested=65535, received=65535
2017/05/10 16:07:57.918 kid1| 24,7| SBuf.cc(887) reAlloc: SBuf9711 new store capacity: 65535
2017/05/10 16:07:57.918 kid1| 83,5| bio.cc(140) read: FD 23 read -1 <= 65535
2017/05/10 16:07:57.918 kid1| 83,5| bio.cc(145) read: error: 11 ignored: 1
2017/05/10 16:07:57.918 kid1| 83,7| bio.cc(168) stateChanged: FD 23 now: 0x1002 23RSHA (SSLv2/v3 read server hello A)
2017/05/10 16:07:57.918 kid1| 83,5| PeerConnector.cc(451) noteWantRead: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1
2017/05/10 16:07:57.918 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=88.230.201.84:55332 remote=192.229.233.50:443 FD 23 flags=1 timeout 60
2017/05/10 16:07:57.918 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 23, type=1, handler=1, client_data=0xf963ed50, timeout=0
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf963ed50
2017/05/10 16:07:57.918 kid1| 93,5| AsyncJob.cc(154) callEnd: Ssl::PeekingPeerConnector status out: [ FD 23 job148]
2017/05/10 16:07:57.918 kid1| 93,5| AsyncCallQueue.cc(57) fireNext: leaving AsyncJob::start()
2017/05/10 16:07:57.918 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf963ed50=2
2017/05/10 16:07:57.918 kid1| 1,9| EventLoop.cc(42) checkEngine: Engine 0xff91fb48 is idle.
2017/05/10 16:07:57.918 kid1| 1,9| EventLoop.cc(42) checkEngine: Engine 0xff91fb4c is idle.
2017/05/10 16:07:57.921 kid1| 5,8| ModEpoll.cc(266) DoSelect: got FD 19 events=1 monitoring=19 F->read_handler=1 F->write_handler=0
2017/05/10 16:07:57.921 kid1| 5,8| ModEpoll.cc(272) DoSelect: Calling read handler on FD 19
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf967cd78=3
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf967cd78=4
2017/05/10 16:07:57.921 kid1| 83,7| AsyncCall.cc(26) AsyncCall: The AsyncCall Security::PeerConnector::negotiate constructed, this=0xf9791d88 [call1165]
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(351) cbdataInternalLock: 0xf967cd78=5
2017/05/10 16:07:57.921 kid1| 83,7| AsyncCall.cc(93) ScheduleCall: PeerConnector.cc(380) will call Security::PeerConnector::negotiate() [call1165]
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf967cd78=4
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(383) cbdataInternalUnlock: 0xf967cd78=3
2017/05/10 16:07:57.921 kid1| 83,7| AsyncCallQueue.cc(55) fireNext: entering Security::PeerConnector::negotiate()
2017/05/10 16:07:57.921 kid1| 83,7| AsyncCall.cc(38) make: make call Security::PeerConnector::negotiate [call1165]
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 83,7| AsyncJob.cc(123) callStart: Ssl::PeekingPeerConnector status in: [ FD 19 job147]
2017/05/10 16:07:57.921 kid1| 45,9| cbdata.cc(419) cbdataReferenceValid: 0xf967cd78
2017/05/10 16:07:57.921 kid1| 83,5| PeerConnector.cc(187) negotiate: SSL_connect session=0xf96df048
2017/05/10 16:07:57.921 kid1| 24,7| SBuf.cc(150) rawSpace: reserving 65535 for SBuf9697
2017/05/10 16:07:57.921 kid1| 24,7| SBuf.cc(157) rawSpace: SBuf9697 not growing
2017/05/10 16:07:57.921 kid1| 83,5| bio.cc(140) read: FD 19 read 2800 <= 65535
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(526) forceSize: SBuf9697 force grow to length=2800
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9725 created from id SBuf9697
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ?v2Hello.msg_head=5635 occupying 2 bytes @0 in 0xff91f708;
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ?v2Hello.msg_type=3 occupying 1 bytes @2 in 0xff91f708;
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9725 destructed
2017/05/10 16:07:57.921 kid1| 24,7| SBuf.cc(96) assign: assigning SBuf9706 from SBuf9697
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9726 created
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.type=22 occupying 1 bytes @0 in 0xf95aace4;
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.version.major=3 occupying 1 bytes @1 in 0xf95aace4;
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.version.minor=3 occupying 1 bytes @2 in 0xf95aace4;
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.fragment.length=96 occupying 2 bytes @3 in 0xf95aace4;
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9727 created from id SBuf9706
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(74) got: TLSPlaintext.fragment.octets= 0200005c0303fc0e81458ed8b121fefbcfd3703a2f681f069eeea7af7af9cd2843c3a830394300c02f00003400000000ff01000100000b0004030001020023000000050000000f0001013374001208687474702f312e3108687474702f312e30 occupying 96 bytes @5 in 0xf95aace4;
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9727 destructed
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(57) got: TLSPlaintext occupying 101 bytes @0 in 0xf95aace4;
2017/05/10 16:07:57.921 kid1| 24,7| SBuf.cc(96) assign: assigning SBuf9704 from SBuf9726
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9728 created from id SBuf9704
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9728 destructed
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9729 created
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: Handshake.msg_type=2 occupying 1 bytes @0 in 0xf95aad0c;
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: Handshake.msg_body.length=92 occupying 3 bytes @1 in 0xf95aad0c;
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9730 created from id SBuf9708
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(74) got: Handshake.msg_body.octets= 0303fc0e81458ed8b121fefbcfd3703a2f681f069eeea7af7af9cd2843c3a830394300c02f00003400000000ff01000100000b0004030001020023000000050000000f0001013374001208687474702f312e3108687474702f312e30 occupying 92 bytes @4 in 0xf95aad0c;
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9730 destructed
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(57) got: Handshake occupying 96 bytes @0 in 0xf95aad0c;
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9731 created from id SBuf9729
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ServerHello.version.major=3 occupying 1 bytes @0 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ServerHello.version.minor=3 occupying 1 bytes @1 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(82) skipped: ServerHello.random occupying 32 bytes @2 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ServerHello.session_id.length=0 occupying 1 bytes @34 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9732 created
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9732 destructed
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ServerHello.cipher_suite=49199 occupying 2 bytes @35 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ServerHello.compression_method=0 occupying 1 bytes @37 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: ServerHello.extensions.length=52 occupying 2 bytes @38 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9733 created from id SBuf9731
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(74) got: ServerHello.extensions.octets= 00000000ff01000100000b0004030001020023000000050000000f0001013374001208687474702f312e3108687474702f312e30 occupying 52 bytes @40 in 0xff91f5e8.
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9734 created from id SBuf9733
2017/05/10 16:07:57.921 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9735 created
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=0 occupying 2 bytes @0 in 0xff91f500.
2017/05/10 16:07:57.921 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=0 occupying 2 bytes @2 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9736 created
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9736 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 4 bytes @0 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9737 created
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9737 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9735 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9738 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=65281 occupying 2 bytes @4 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=1 occupying 2 bytes @6 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9739 created from id SBuf9734
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(74) got: Extension.data.octets= 00 occupying 1 bytes @8 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9739 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 5 bytes @4 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9738 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9740 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=11 occupying 2 bytes @9 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=4 occupying 2 bytes @11 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9741 created from id SBuf9734
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(74) got: Extension.data.octets= 03000102 occupying 4 bytes @13 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9741 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 8 bytes @9 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9740 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9742 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=35 occupying 2 bytes @17 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=0 occupying 2 bytes @19 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9743 created
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9743 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 4 bytes @17 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9742 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9744 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=5 occupying 2 bytes @21 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=0 occupying 2 bytes @23 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9745 created
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9745 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 4 bytes @21 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9744 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9746 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=15 occupying 2 bytes @25 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=1 occupying 2 bytes @27 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9747 created from id SBuf9734
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(74) got: Extension.data.octets= 01 occupying 1 bytes @29 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9747 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 5 bytes @25 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9746 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9748 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.type=13172 occupying 2 bytes @30 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: Extension.data.length=18 occupying 2 bytes @32 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(49) SBuf: SBuf9749 created from id SBuf9734
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(74) got: Extension.data.octets= 08687474702f312e3108687474702f312e30 occupying 18 bytes @34 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9749 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: Extension occupying 22 bytes @30 in 0xff91f500.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9748 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9734 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9733 destructed
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(57) got: ServerHello occupying 92 bytes @0 in 0xff91f5e8.
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9731 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9729 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(81) ~SBuf: SBuf9726 destructed
2017/05/10 16:07:57.922 kid1| 24,8| SBuf.cc(41) SBuf: SBuf9750 created
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.type=22 occupying 1 bytes @101 in 0xf95aace4;
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.version.major=3 occupying 1 bytes @102 in 0xf95aace4;
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.version.minor=3 occupying 1 bytes @103 in 0xf95aace4;
2017/05/10 16:07:57.922 kid1| 24,7| BinaryTokenizer.cc(65) got: TLSPlaintext.fragment.length=4575 occupying 2 bytes @104 in 0xf95aace4;
2017/05/10 16:07:57.922 kid1| 24,5| BinaryTokenizer.cc(47) want: 1881 more bytes for TLSPlaintext.fragment.octets occupying 4575 bytes @106 in 0xf95aace4;
-------------- next part --------------
A non-text attachment was scrubbed...
Name: squid.conf
Type: application/octet-stream
Size: 5062 bytes
Desc: not available
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20170510/e68c77b0/attachment-0001.obj>


More information about the squid-users mailing list