[squid-users] SSL bumping without faked server certificates

Sat Nov 14 19:58:02 UTC 2015

Here is more information...

Squid's complete cache.log:
2015/11/10 19:22:10 kid1| Set Current Directory to /var/spool/squid
2015/11/10 19:22:10 kid1| Starting Squid Cache version 3.5.11 for x86_64-redhat-linux-gnu...
2015/11/10 19:22:10 kid1| Service Name: squid
2015/11/10 19:22:10 kid1| Process ID 15283
2015/11/10 19:22:10 kid1| Process Roles: worker
2015/11/10 19:22:10 kid1| With 1024 file descriptors available
2015/11/10 19:22:10 kid1| Initializing IP Cache...
2015/11/10 19:22:10 kid1| DNS Socket created at [::], FD 6
2015/11/10 19:22:10 kid1| DNS Socket created at 0.0.0.0, FD 7
2015/11/10 19:22:10 kid1| Adding domain galaxy.virtual from /etc/resolv.conf
2015/11/10 19:22:10 kid1| Adding nameserver 172.31.1.254 from /etc/resolv.conf
2015/11/10 19:22:10 kid1| Logfile: opening log daemon:/var/log/squid/access.log
2015/11/10 19:22:10 kid1| Logfile Daemon: opening log /var/log/squid/access.log
2015/11/10 19:22:10 kid1| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec
2015/11/10 19:22:10 kid1| Store logging disabled
2015/11/10 19:22:10 kid1| Swap maxSize 0 + 524288 KB, estimated 40329 objects
2015/11/10 19:22:10 kid1| Target number of buckets: 2016
2015/11/10 19:22:10 kid1| Using 8192 Store buckets
2015/11/10 19:22:10 kid1| Max Mem  size: 524288 KB
2015/11/10 19:22:10 kid1| Max Swap size: 0 KB
2015/11/10 19:22:10 kid1| Using Least Load store dir selection
2015/11/10 19:22:10 kid1| Set Current Directory to /var/spool/squid
2015/11/10 19:22:10 kid1| Finished loading MIME types and icons.
2015/11/10 19:22:10.830 kid1| 33,2| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x1df0a40 [call3]
2015/11/10 19:22:10.830 kid1| 33,2| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=[::]:3128 remote=[::] FD 12 flags=9, err=0, HTTP Socket port=0x1df0aa0) [call3]
2015/11/10 19:22:10.830 kid1| 33,2| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x1df0bd0 [call5]
2015/11/10 19:22:10.830 kid1| 33,2| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=10.0.0.1:3129 remote=[::] FD 13 flags=41, err=0, HTTP Socket port=0x1df0c30) [call5]
2015/11/10 19:22:10.830 kid1| 33,2| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x1df0e40 [call7]
2015/11/10 19:22:10.830 kid1| 33,2| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=10.0.0.1:3443 remote=[::] FD 14 flags=41, err=0, HTTPS Socket port=0x1df0ea0) [call7]
2015/11/10 19:22:10.830 kid1| HTCP Disabled.
2015/11/10 19:22:10.830 kid1| Squid plugin modules loaded: 0
2015/11/10 19:22:10.830 kid1| Adaptation support is off.
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=[::]:3128 remote=[::] FD 12 flags=9, err=0, HTTP Socket port=0x1df0aa0)
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call3]
2015/11/10 19:22:10.831 kid1| Accepting HTTP Socket connections at local=[::]:3128 remote=[::] FD 12 flags=9
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=[::]:3128 remote=[::] FD 12 flags=9, err=0, HTTP Socket port=0x1df0aa0)
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=10.0.0.1:3129 remote=[::] FD 13 flags=41, err=0, HTTP Socket port=0x1df0c30)
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call5]
2015/11/10 19:22:10.831 kid1| Accepting NAT intercepted HTTP Socket connections at local=10.0.0.1:3129 remote=[::] FD 13 flags=41
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=10.0.0.1:3129 remote=[::] FD 13 flags=41, err=0, HTTP Socket port=0x1df0c30)
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=10.0.0.1:3443 remote=[::] FD 14 flags=41, err=0, HTTPS Socket port=0x1df0ea0)
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call7]
2015/11/10 19:22:10.831 kid1| Accepting NAT intercepted SSL bumped HTTPS Socket connections at local=10.0.0.1:3443 remote=[::] FD 14 flags=41
2015/11/10 19:22:10.831 kid1| 33,2| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=10.0.0.1:3443 remote=[::] FD 14 flags=41, err=0, HTTPS Socket port=0x1df0ea0)
2015/11/10 19:22:11 kid1| storeLateRelease: released 0 objects
2015/11/10 19:24:30.007 kid1| 89,5| Intercept.cc(375) Lookup: address BEGIN: me/client= 10.0.0.1:3443, destination/me= 10.0.0.2:42825
2015/11/10 19:24:30.007 kid1| 89,5| Intercept.cc(151) NetfilterInterception: address NAT: local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33
2015/11/10 19:24:30.008 kid1| 33,4| client_side.cc(3920) httpsAccept: local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33 accepted, starting SSL negotiation.
2015/11/10 19:24:30.008 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::connStateClosed constructed, this=0x1df0a40 [call332]
2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(3938) postHttpsAccept: accept transparent connection: local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33
2015/11/10 19:24:30.008 kid1| 33,2| client_side.cc(3896) httpsSslBumpAccessCheckDone: sslBump needed for local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33 method 3
2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(3200) clientParseRequests: local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33: attempting to parse
2015/11/10 19:24:30.008 kid1| 33,3| client_side.cc(2258) parseHttpRequest: parseHttpRequest: req_hdr = {Host: 212.45.105.89:443^M
^M
}
2015/11/10 19:24:30.008 kid1| 33,3| client_side.cc(2262) parseHttpRequest: parseHttpRequest: end = {
}
2015/11/10 19:24:30.008 kid1| 33,3| client_side.cc(2266) parseHttpRequest: parseHttpRequest: prefix_sz = 63, req_line_sz = 36
2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(2282) parseHttpRequest: parseHttpRequest: Request Header is
Host: 212.45.105.89:443^M
^M

2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(2303) parseHttpRequest: Prepare absolute URL from intercept
2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(2342) parseHttpRequest: parseHttpRequest: Complete request received
2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(3221) clientParseRequests: local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33: done parsing a request
2015/11/10 19:24:30.008 kid1| 33,3| client_side.cc(873) clientSetKeepaliveFlag: http_ver = HTTP/1.1
2015/11/10 19:24:30.008 kid1| 33,3| client_side.cc(874) clientSetKeepaliveFlag: method = CONNECT
2015/11/10 19:24:30.008 kid1| 33,3| client_side.h(96) mayUseConnection: This 0x19d3428 marked 1
2015/11/10 19:24:30.008 kid1| 33,5| client_side.cc(2422) consumeInput: in.buf has 0 unused bytes
2015/11/10 19:24:30.008 kid1| 83,3| client_side_request.cc(1684) doCallouts: Doing calloutContext->hostHeaderVerify()
2015/11/10 19:24:30.009 kid1| 83,3| client_side_request.cc(1691) doCallouts: Doing calloutContext->clientAccessCheck()
2015/11/10 19:24:30.009 kid1| 83,3| AccessCheck.cc(42) Start: adaptation off, skipping
2015/11/10 19:24:30.009 kid1| 83,3| client_side_request.cc(1720) doCallouts: Doing calloutContext->clientAccessCheck2()
2015/11/10 19:24:30.009 kid1| 83,3| client_side_request.cc(1739) doCallouts: Doing clientInterpretRequestHeaders()
2015/11/10 19:24:30.009 kid1| 83,3| client_side_request.cc(1528) sslBumpNeed: sslBump required: peek
2015/11/10 19:24:30.009 kid1| 83,3| client_side_request.cc(1830) doCallouts: calling processRequest()
2015/11/10 19:24:30.009 kid1| 33,3| client_side.cc(3233) clientParseRequests: Not parsing new requests, as this request may need the connection
2015/11/10 19:24:30.009 kid1| 33,5| client_side.cc(4237) switchToHttps: converting local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33 to SSL
2015/11/10 19:24:30.009 kid1| 33,4| ServerBump.cc(27) ServerBump: will peek at 212.45.105.89:443
2015/11/10 19:24:30.029 kid1| 83,5| bio.cc(576) squid_bio_ctrl: 0x1eba7b0 104(6000, 0x7fff5116f66c)
2015/11/10 19:24:30.030 kid1| 33,5| client_side.cc(3693) httpsCreate: will negotate SSL on local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33
2015/11/10 19:24:30.093 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.093 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.093 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 11 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 11 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 11 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4267) clientPeekAndSpliceSSL: Start peek and splice on FD 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(118) read: FD 11 read 9 <= 11
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(144) readAndBuffer: read 9 out of 11 bytes
2015/11/10 19:24:30.094 kid1| 83,5| bio.cc(148) readAndBuffer: recorded 9 bytes of TLS client Hello
2015/11/10 19:24:30.094 kid1| 83,2| client_side.cc(4270) clientPeekAndSpliceSSL: SSL_accept failed.
2015/11/10 19:24:30.094 kid1| 83,5| client_side.cc(4284) clientPeekAndSpliceSSL: I got hello. Start forwarding the request!!!
2015/11/10 19:24:30.095 kid1| 33,5| client_side.cc(4322) httpsSslBumpStep2AccessCheckDone: Answer: ALLOWED kind:5
2015/11/10 19:24:30.117 kid1| 83,5| bio.cc(576) squid_bio_ctrl: 0x1f0bc00 104(6001, 0x7fff5116f7bc)
2015/11/10 19:24:30.117 kid1| 83,5| bio.cc(95) write: FD 15 wrote 293 <= 293
2015/11/10 19:24:30.117 kid1| 83,5| bio.cc(118) read: FD 15 read -1 <= 7
2015/11/10 19:24:30.117 kid1| 83,5| bio.cc(123) read: error: 11 ignored: 1
2015/11/10 19:24:30.144 kid1| 83,5| bio.cc(118) read: FD 15 read 7 <= 7
2015/11/10 19:24:30.144 kid1| 83,5| bio.cc(576) squid_bio_ctrl: 0x1f0bc00 6(0, 0x1f1a030)
2015/11/10 19:24:30.144 kid1| 83,5| bio.cc(118) read: FD 15 read 83 <= 83
2015/11/10 19:24:30.145 kid1| 83,5| bio.cc(118) read: FD 15 read 5 <= 5
2015/11/10 19:24:30.145 kid1| 83,5| bio.cc(118) read: FD 15 read 1353 <= 3427
2015/11/10 19:24:30.145 kid1| 83,5| bio.cc(118) read: FD 15 read -1 <= 2074
2015/11/10 19:24:30.145 kid1| 83,5| bio.cc(123) read: error: 11 ignored: 1
2015/11/10 19:24:30.156 kid1| 83,5| bio.cc(118) read: FD 15 read 2074 <= 2074
2015/11/10 19:24:30.156 kid1| 83,5| support.cc(257) ssl_verify_cb: SSL Certificate signature OK: /C=DE/ST=Berlin/L=Berlin/O=bettermarks GmbH/CN=*.bettermarks.com
2015/11/10 19:24:30.156 kid1| 83,5| support.cc(257) ssl_verify_cb: SSL Certificate signature OK: /C=DE/ST=Berlin/L=Berlin/O=bettermarks GmbH/CN=*.bettermarks.com
2015/11/10 19:24:30.157 kid1| 83,5| support.cc(257) ssl_verify_cb: SSL Certificate signature OK: /C=DE/ST=Berlin/L=Berlin/O=bettermarks GmbH/CN=*.bettermarks.com
2015/11/10 19:24:30.157 kid1| 83,5| support.cc(257) ssl_verify_cb: SSL Certificate signature OK: /C=DE/ST=Berlin/L=Berlin/O=bettermarks GmbH/CN=*.bettermarks.com
2015/11/10 19:24:30.157 kid1| 83,4| support.cc(211) check_domain: Verifying server domain school.bettermarks.com to certificate name/subjectAltName *.bettermarks.com
2015/11/10 19:24:30.157 kid1| 83,5| bio.cc(118) read: FD 15 read 5 <= 5
2015/11/10 19:24:30.157 kid1| 83,5| bio.cc(118) read: FD 15 read 4 <= 4
2015/11/10 19:24:30.157 kid1| 83,5| bio.cc(95) write: FD 15 wrote 358 <= 358
2015/11/10 19:24:30.157 kid1| 83,5| bio.cc(576) squid_bio_ctrl: 0x1f0bc00 11(0, 0)
2015/11/10 19:24:30.157 kid1| 83,5| bio.cc(118) read: FD 15 read -1 <= 5
2015/11/10 19:24:30.157 kid1| 83,5| bio.cc(123) read: error: 11 ignored: 1
2015/11/10 19:24:30.180 kid1| 83,5| bio.cc(118) read: FD 15 read 5 <= 5
2015/11/10 19:24:30.180 kid1| 83,5| bio.cc(118) read: FD 15 read 1 <= 1
2015/11/10 19:24:30.180 kid1| 83,5| bio.cc(118) read: FD 15 read 5 <= 5
2015/11/10 19:24:30.180 kid1| 83,5| bio.cc(118) read: FD 15 read 80 <= 80
2015/11/10 19:24:30.180 kid1| 83,5| bio.cc(576) squid_bio_ctrl: 0x1f0bc00 7(0, 0x1f1a030)
2015/11/10 19:24:30.180 kid1| 83,5| PeerConnector.cc(304) serverCertificateVerified: HTTPS server CN: *.bettermarks.com bumped: local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1
2015/11/10 19:24:30.180 kid1| 83,5| PeerConnector.cc(58) ~PeerConnector: Peer connector 0x1f0ace8 gone
2015/11/10 19:24:30.180 kid1| 33,3| client_side.cc(5060) unpinConnection:
2015/11/10 19:24:30.180 kid1| 33,3| client_side.cc(4938) pinNewConnection: local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1
2015/11/10 19:24:30.180 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::clientPinnedConnectionClosed constructed, this=0x1f0ac40 [call348]
2015/11/10 19:24:30.180 kid1| 33,3| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::clientPinnedConnectionRead constructed, this=0x1f0a130 [call349]
2015/11/10 19:24:30.180 kid1| 33,5| client_side.cc(4409) httpsPeeked: bumped HTTPS server: 212.45.105.89
2015/11/10 19:24:30.180 kid1| 33,3| client_side_request.cc(246) ~ClientHttpRequest: httpRequestFree: 212.45.105.89:443
2015/11/10 19:24:30.180 kid1| 33,5| client_side.cc(576) logRequest: logging half-baked transaction: 212.45.105.89:443
2015/11/10 19:24:30.180 kid1| 33,5| client_side.cc(4205) getSslContextDone: Using static ssl context.
2015/11/10 19:24:30.181 kid1| 83,5| bio.cc(576) squid_bio_ctrl: 0x1f09ea0 104(6000, 0x7fff5116f4dc)
2015/11/10 19:24:30.181 kid1| 33,5| client_side.cc(3693) httpsCreate: will negotate SSL on local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33
2015/11/10 19:24:30.181 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The AsyncCall ConnStateData::requestTimeout constructed, this=0x1f0b060 [call351]
2015/11/10 19:25:30.016 kid1| 33,3| AsyncCall.cc(93) ScheduleCall: IoCallback.cc(135) will call ConnStateData::clientPinnedConnectionRead(local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1, flag=-10, data=0x19ced08) [call349]
2015/11/10 19:25:30.016 kid1| 33,5| AsyncCall.cc(93) ScheduleCall: comm.cc(730) will call ConnStateData::clientPinnedConnectionClosed(local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1, data=0x19ced08) [call348]
2015/11/10 19:25:30.017 kid1| 83,5| bio.cc(95) write: FD 15 wrote 69 <= 69
2015/11/10 19:25:30.017 kid1| 33,3| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::clientPinnedConnectionRead(local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1, flag=-10, data=0x19ced08)
2015/11/10 19:25:30.017 kid1| 33,3| AsyncCall.cc(38) make: make call ConnStateData::clientPinnedConnectionRead [call349]
2015/11/10 19:25:30.017 kid1| 33,3| AsyncJob.cc(123) callStart: Http::Server status in: [ job4]
2015/11/10 19:25:30.017 kid1| 33,3| AsyncJob.cc(152) callEnd: Http::Server status out: [ job4]
2015/11/10 19:25:30.017 kid1| 33,3| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::clientPinnedConnectionRead(local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1, flag=-10, data=0x19ced08)
2015/11/10 19:25:30.017 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::clientPinnedConnectionClosed(local=172.31.1.15:49421 remote=212.45.105.89:443 FD 15 flags=1, data=0x19ced08)
2015/11/10 19:25:30.017 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::clientPinnedConnectionClosed [call348]
2015/11/10 19:25:30.017 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job4]
2015/11/10 19:25:30.017 kid1| 33,3| client_side.cc(5060) unpinConnection: local=172.31.1.15:49421 remote=212.45.105.89:443 flags=1
2015/11/10 19:25:30.017 kid1| 33,5| AsyncJob.cc(152) callEnd: Http::Server status out: [ job4]
2015/11/10 19:25:30.017 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::clientPinnedConnectionClosed(local=172.31.1.15:49421 remote=212.45.105.89:443 flags=1, data=0x19ced08)
2015/11/10 19:29:30.299 kid1| 33,5| AsyncCall.cc(93) ScheduleCall: comm.cc(1579) will call ConnStateData::requestTimeout(local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33, data=0x19ced08) [call351]
2015/11/10 19:29:30.299 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::requestTimeout(local=212.45.105.89:443 remote=10.0.0.2:42825 FD 11 flags=33, data=0x19ced08)
2015/11/10 19:29:30.299 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::requestTimeout [call351]
2015/11/10 19:29:30.299 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job4]
2015/11/10 19:29:30.299 kid1| 33,3| client_side.cc(3512) requestTimeout: requestTimeout: FD -1: lifetime is expired.
2015/11/10 19:29:30.299 kid1| 33,5| AsyncCall.cc(93) ScheduleCall: comm.cc(730) will call ConnStateData::connStateClosed(FD -1, data=0x19ced08) [call332]
2015/11/10 19:29:30.300 kid1| 33,5| AsyncJob.cc(152) callEnd: Http::Server status out: [ job4]
2015/11/10 19:29:30.300 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::requestTimeout(local=212.45.105.89:443 remote=10.0.0.2:42825 flags=33, data=0x19ced08)
2015/11/10 19:29:30.300 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering ConnStateData::connStateClosed(FD -1, data=0x19ced08)
2015/11/10 19:29:30.300 kid1| 33,5| AsyncCall.cc(38) make: make call ConnStateData::connStateClosed [call332]
2015/11/10 19:29:30.300 kid1| 33,5| AsyncJob.cc(123) callStart: Http::Server status in: [ job4]
2015/11/10 19:29:30.300 kid1| 33,2| client_side.cc(815) swanSong: local=212.45.105.89:443 remote=10.0.0.2:42825 flags=33
2015/11/10 19:29:30.300 kid1| 33,3| client_side.cc(5060) unpinConnection: local=172.31.1.15:49421 remote=212.45.105.89:443 flags=1
2015/11/10 19:29:30.300 kid1| 33,3| client_side.cc(846) ~ConnStateData: local=212.45.105.89:443 remote=10.0.0.2:42825 flags=33
2015/11/10 19:29:30.300 kid1| 33,4| ServerBump.cc(44) ~ServerBump: destroying
2015/11/10 19:29:30.300 kid1| 33,4| ServerBump.cc(46) ~ServerBump: e:=sp2XDIV/0x19d6b20*1
2015/11/10 19:29:30.300 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving ConnStateData::connStateClosed(FD -1, data=0x19ced08)

Am Dienstag, den 10.11.2015, 08:49 -0700 schrieb Alex Rousskov:
On 11/10/2015 07:05 AM, Stefan Kutzke wrote:

My assumption is that I have to use in Squid's config:

acl MYSITE ssl:server_name .mydomain.com
ssl_bump bump MYSITE
ssl_bump splice all

This results in tunneling all https traffic, nothing will be bumped and
cached.

Yes, probably because MYSITE (ssl::server_name) often needs SNI and SNI
is not available during step1 when MYSITE is evaluated in your config.
In other words, your config is equivalent to

  ssl_bump splice all

unless reverse DNS works perfectly well.

I'm a little bit confused about the documentation:

Under the headline "Processing steps":
*Step 2:*
 1. Get TLS clientHello info, including *SNI* where available.

Under the headline "Actions":
peek/stare Receive client *SNI (step1)*, ...

I know it is confusing, but I cannot find a better way to explain this
in brief documentation without pictures. Improvements are welcomed. The
key here is that ssl_bump rules are evaluated at the end of a step and
usually allow Squid to do something at the beginning of the next step.

For example, during step1, Squid does not have SNI. If a peek rule
matches during step1, then Squid proceeds to step2. At the beginning of
step2, Squid gets SNI. Thus, a step1 peek rule controls whether Squid
will get SNI (during step2).

Is it possible to achieve my goal with Squid in transparent mode?

I should be possible, but I do not know whether anybody has done exactly
that so there could be some minor bugs along the way. You need
configuration suggested by Sebastian and the latest Squid you can build.

HTH,

Alex.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20151114/c4c2e503/attachment-0001.html>