Squid Proxy SSL Bump can not retrieve SSL session back to the client?

classic Classic list List threaded Threaded
16 messages Options
Reply | Threaded
Open this post in threaded view
|

Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen

Hi,

I’m new to this group. I just setup a squid ver 4.5 on my ubuntu machine. I configured this proxy to receive
https packets from another device on the same LAN, and modified the iptables to redirect the port 443 packets
to the squid proxy port 3130. 

I can see the client https packet has been received and the proxy is ready to do the ‘bump’, the fd to the client
connection is 13:

**
2019/12/07 20:48:59.586 kid1| 85,4| client_side_request.cc(1510) processRequest: CONNECT x.y.43.31:443
2019/12/07 20:48:59.586 kid1| 85,5| client_side_request.cc(1597) sslBumpStart: Confirming peek-bumped CONNECT tunnel on FD local=x.y..31:443 remote=192.168.1.25:39273 FD 13 flags=33
**


From the debug I can also see the proxy  connects towards the remote
server, and proxy has negotiated fine with the server. the proxy receives 3 certificates from the server,
and verification was fine to the server. But when the proxy trying to proceed with client negotiation, I got this error:

***
2019/12/07 20:48:59.760 kid1| 33,5| client_side.cc(2859) sslCrtdHandleReply: Certificate for x.y.43.31 was successfully recieved from ssl_crtd
2019/12/07 20:48:59.760 kid1| 33,5| client_side.cc(3335) doPeekAndSpliceStep: PeekAndSplice mode, proceed with client negotiation. Currrent state:SSLv2/v3 read client hello A
2019/12/07 20:48:59.760 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 13, type=2, handler=1, client_data=0x15beef8, timeout=0
2019/12/07 20:48:59.760 kid1| 84,5| helper.cc(1247) GetFirstAvailable: GetFirstAvailable: Running servers 5
2019/12/07 20:48:59.760 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall helperHandleRead constructed, this=0x1a37c50 [call827]
2019/12/07 20:48:59.760 kid1| 5,5| Read.cc(57) comm_read_base: comm_read, queueing read for local=[::] remote=[::] FD 10 flags=1; asynCall 0x1a37c50*1
2019/12/07 20:48:59.760 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 10, type=1, handler=1, client_data=0x155cce8, timeout=0
2019/12/07 20:48:59.760 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving helperHandleRead(local=[::] remote=[::] FD 10 flags=1, data=0x157f9a8, size=3384, buf=0x157fbd0)
2019/12/07 20:48:59.760 kid1| 83,5| bio.cc(612) squid_bio_ctrl: 0x1a5e140 6(0, 0x1a76c00)
2019/12/07 20:48:59.761 kid1| 83,5| Session.cc(347) get_session_cb: Request to search for SSL_SESSION of len: 321019023443:419801955
2019/12/07 20:48:59.761 kid1| 54,5| MemMap.cc(156) openForReading: trying to open slot for key 5310BD3C63AB0519C4F984A35A8DC1AE for reading in map [tls_session_cache]
2019/12/07 20:48:59.761 kid1| 54,5| MemMap.cc(177) openForReadingAt: trying to open slot at 18 for reading in map [tls_session_cache]
2019/12/07 20:48:59.761 kid1| 54,5| MemMap.cc(169) openForReading: failed to open slot for key 5310BD3C63AB0519C4F984A35A8DC1AE for reading in map [tls_session_cache]
2019/12/07 20:48:59.761 kid1| 83,5| Session.cc(362) get_session_cb: Failed to retrieve SSL_SESSION from cache
***

Here is my squid.conf:

#
acl localnet src 192.168.1.0/24
acl step1 at_step SslBump1
acl step2 at_step SslBump2
acl step3 at_step SslBump3

ssl_bump peek step1
ssl_bump stare step2
ssl_bump bump all

acl SSL_ports port 443
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 # https
acl Safe_ports port 70 # gopher
acl Safe_ports port 210 # wais
acl Safe_ports port 1025-65535 # unregistered ports
acl Safe_ports port 280 # http-mgmt
acl Safe_ports port 488 # gss-http
acl Safe_ports port 591 # filemaker
acl Safe_ports port 777 # multiling http
acl CONNECT method CONNECT
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access allow localhost manager
http_access deny manager
http_access allow localnet
http_access allow localhost
http_access deny all
http_port 3128
http_port 3129 intercept
https_port 3130 intercept ssl-bump cert=/usr/local/squid/etc/ssl_cert/myCA.pem generate-host-certificates=on dynamic_cert_mem_cache_size=4MB key=/usr/local/
squid/etc/ssl_cert/myCA.pem

sslcrtd_program /usr/local/squid/libexec/security_file_certgen -s /usr/local/squid/var/logs/ssl_db -M 4MB
coredump_dir /usr/local/squid/var/cache/squid
cache_dir ufs /usr/local/squid/var/cache/squid 1000 16 256 # 1GB as Cache

##

I’m wondering if this problem is a bug, my proxy config issue, or the client does not send the correct TLS parameters.
thanks for your help in advance.

Cheers,
- George


_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Amos Jeffries
Administrator
On 8/12/19 7:53 pm, George Sheng wrote:
>
> Hi,
>
> I’m new to this group. I just setup a squid ver 4.5 on my ubuntu

When using SSL-Bump one does need to use the latest release. Which is
4.9 now.

Since this is a custom build (4.5 has never been a release in Ubuntu)
you may find Squid-5 has even less issues for SSL-Bump.



...

> 2019/12/07 20:48:59.761 kid1| 83,5| Session.cc <http://Session.cc>(347)
> get_session_cb: Request to search for SSL_SESSION of
> len: 321019023443:419801955
> 2019/12/07 20:48:59.761 kid1| 54,5| MemMap.cc <http://MemMap.cc>(156)
> openForReading: trying to open slot for
> key 5310BD3C63AB0519C4F984A35A8DC1AE for reading in map [tls_session_cache]
> 2019/12/07 20:48:59.761 kid1| 54,5| MemMap.cc <http://MemMap.cc>(177)
> openForReadingAt: trying to open slot at 18 for reading in
> map [tls_session_cache]
> 2019/12/07 20:48:59.761 kid1| 54,5| MemMap.cc <http://MemMap.cc>(169)
> openForReading: failed to open slot for
> key 5310BD3C63AB0519C4F984A35A8DC1AE for reading in map [tls_session_cache]
> 2019/12/07 20:48:59.761 kid1| 83,5| Session.cc <http://Session.cc>(362)
> get_session_cb: Failed to retrieve SSL_SESSION from cache
> ***

This is talking about Squid's internal cache of TLS sessions that
clients have negotiated previously with this Squid. It means the client
is attempting to use/resume a TLS session ID that does not exist. There
is nothing anyone can do about that.


>
> Here is my squid.conf:
>
...
> https_port 3130 intercept ssl-bump
> cert=/usr/local/squid/etc/ssl_cert/myCA.pem
> generate-host-certificates=on dynamic_cert_mem_cache_size=4MB
> key=/usr/local/
> squid/etc/ssl_cert/myCA.pem
>

FYI: with cert= and key= pointing at the same file you do not need the
key= option.


> ##
>
> I’m wondering if this problem is a bug, my proxy config issue, or the
> client does not send the correct TLS parameters.
> thanks for your help in advance.
>

The problem is most likely the client.

If the session ID actually was negotiated previously with this Squid
there may be shared-memory issues on your machine. Even with only one
worker this cache uses SMP functionality

If you only just started this Squid, the session may have been
negotiated with the origin or previous Squid instance. In that case it
is normal to get at least a few of these until they timeout and/or get
renegotiated.


Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen
Hi Amos,

thanks for the comments. I'll first try the later version as you pointed out
4.9 and see if I get the issues. Will report back.
thanks.

- George



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen
Hi Amos,

i downloaded the 4.9 latest, and compiled with "./configure
--with-default-user=proxy --with-openssl --enable-ssl-crtd", not redo the
openssl and proxy certificate part, start squid with 4.9, still seeing
failure. Have not debugged in detail.
Quick question, when compile for the bump usage case, do i need to use the
with-gnutls option also?
just wondering.

thanks.
- George



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Amos Jeffries
Administrator
On 9/12/19 10:41 am, GeorgeShen wrote:
> Hi Amos,
>
> i downloaded the 4.9 latest, and compiled with "./configure
> --with-default-user=proxy --with-openssl --enable-ssl-crtd", not redo the
> openssl and proxy certificate part, start squid with 4.9, still seeing
> failure. Have not debugged in detail.
> Quick question, when compile for the bump usage case, do i need to use the
> with-gnutls option also?

No, GnuTLS is just an alternative to OpenSSL for those where the OpenSSL
license vs GPL incompatibility matters (anyone distributing both OPenSSL
and Squid packages - eg Ubuntu itself).

It still lacks most of the the SSL-Bump features. So eventually you
might be able to choose between them, but right now OpenSSL is needed to
do interception of HTTPS.

Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen
In reply to this post by GeorgeShen

the version 4.9 has the same behavior, can not finish negotiate with the
client.
I have setup two different client machines, one is macOS, the other alpine
linux.

I finally got the macOS wget https to work through the squid 4.9 proxy with
ssl-bump.
So the squid config is ok.

The alpine linux, using the wget https, got error message ssl_client:
handshake failed: error:14004410:SSL routines:CONNECT_CR_SRVR_HELLO:sslv3
alert handshake failure (on the proxy log, it is the same thing, can not
somehow retrieve the ssl session, probably due to some TLS mismatch)

I'm wondering if you know normally what kind of mismatch this is between the
client and proxy.
if i'm using wget https for testing, what kind of parameters I need to
change to match them.

thanks.
- George



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Alex Rousskov
In reply to this post by GeorgeShen
On 12/8/19 1:53 AM, George Sheng wrote:

> From the debug I can also see the proxy  connects towards the remote
> server, and proxy has negotiated fine with the server. the proxy
> receives 3 certificates from the server,
> and verification was fine to the server. But when the proxy trying to
> proceed with client negotiation, I got this error:

> 2019/12/07 20:48:59.761 kid1| 83,5| Session.cc(362)
> get_session_cb: Failed to retrieve SSL_SESSION from cache

As Amos has said, this failure to find a cached session is not an error
in itself. It is a cache miss. Look for problems after this log line.


> The alpine linux, using the wget https, got error message ssl_client:
> handshake failed: error:14004410:SSL routines:CONNECT_CR_SRVR_HELLO:sslv3
> alert handshake failure

OK.


> (on the proxy log, it is the same thing, can not
> somehow retrieve the ssl session, probably due to some TLS mismatch)

What happens on Squid side _after_ the TLS session is not found in the
cache?

Alex.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen

Hi Alex,

this time I tried, a little different, this is the log from got the server
certs to colose the
SSL with error, and at the end, it is also saying security_file_certgen
crashes rapidly!!!

below the output of log
thanks.
- George


geyBC5spVGniTZ9g4/4EALHmrmP0d4vcbw0FJugljU7jWmdiUQEpoZZCovZY+lyX
IGRmShEZ6Enq77nr6xgMpW080lJojSBBE0bG7tJj8sUeU03xVyHJZJ4cNX7VD/Dn
g0KNg0PA4UvJLMoKal8UqHzxNXjZZ778O7mOOyvdHfkHgUsFdp9a25/nzduUFQ4R
8faCm0U26P8C
-----END CERTIFICATE-----

2019/12/09 09:39:32.243 kid1| 83,5| helper.cc(136) Submit: request from
0x256a4a8 as crtGenRq12500/1
2019/12/09 09:39:32.243 kid1| 84,5| helper.cc(1247) GetFirstAvailable:
GetFirstAvailable: Running servers 5
2019/12/09 09:39:32.243 kid1| 5,5| AsyncCall.cc(26) AsyncCall: The AsyncCall
helperDispatchWriteDone constructed, this=0x2557fe0 [call2906]
2019/12/09 09:39:32.243 kid1| 5,5| Write.cc(35) Write: local=[::]
remote=[::] FD 10 flags=1: sz 5266: asynCall 0x2557fe0*1
2019/12/09 09:39:32.243 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 10,
type=2, handler=1, client_data=0x2091e30, timeout=0
2019/12/09 09:39:32.243 kid1| 84,5| helper.cc(1379) helperDispatch:
helperDispatch: Request sent to
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr1, 5266 bytes
2019/12/09 09:39:32.243 kid1| 17,4| AsyncJob.cc(154) callEnd: Http1::Server
status out: [ job203]
2019/12/09 09:39:32.243 kid1| 17,4| AsyncCallQueue.cc(57) fireNext: leaving
ConnStateData::ConnStateData::httpsPeeked(local=192.168.1.35:46896
remote=X.Y.82.162:443 FD 15 flags=1, request=0x20fb630*3)
2019/12/09 09:39:32.243 kid1| 93,5| AsyncCallQueue.cc(55) fireNext: entering
Initiate::noteInitiatorAborted()
2019/12/09 09:39:32.243 kid1| 93,5| AsyncCall.cc(38) make: make call
Initiate::noteInitiatorAborted [call2905]
2019/12/09 09:39:32.243 kid1| 93,5| AsyncCall.cc(56) cancel: will not call
Initiate::noteInitiatorAborted [call2905] because job gone
2019/12/09 09:39:32.243 kid1| 93,5| AsyncCall.cc(48) make: will not call
Initiate::noteInitiatorAborted [call2905] because of job gone
2019/12/09 09:39:32.243 kid1| 93,5| AsyncCallQueue.cc(57) fireNext: leaving
Initiate::noteInitiatorAborted()
2019/12/09 09:39:32.243 kid1| 50,3| ModDaemon.cc(110) logfileHandleWrite:
daemon:/usr/local/squid/var/logs/access.log: write returned 106
2019/12/09 09:39:32.243 kid1| 5,5| Write.cc(66) HandleWrite: local=[::]
remote=[::] FD 10 flags=1: off 0, sz 5266.
2019/12/09 09:39:32.243 kid1| 5,5| Write.cc(108) HandleWrite: write()
returns 5266
2019/12/09 09:39:32.243 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 10 flags=1 (0, 0)
2019/12/09 09:39:32.243 kid1| 5,5| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperDispatchWriteDone(local=[::] remote=[::]
FD 10 flags=1, data=0x20b4b18, size=5266, buf=0x20ea960) [call2906]
2019/12/09 09:39:32.243 kid1| 5,5| AsyncCallQueue.cc(55) fireNext: entering
helperDispatchWriteDone(local=[::] remote=[::] FD 10 flags=1,
data=0x20b4b18, size=5266, buf=0x20ea960)
2019/12/09 09:39:32.243 kid1| 5,5| AsyncCall.cc(38) make: make call
helperDispatchWriteDone [call2906]
2019/12/09 09:39:32.243 kid1| 5,5| AsyncCallQueue.cc(57) fireNext: leaving
helperDispatchWriteDone(local=[::] remote=[::] FD 10 flags=1,
data=0x20b4b18, size=5266, buf=0x20ea960)
2019/12/09 09:39:32.243 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 20,
type=2, handler=0, client_data=0, timeout=0
2019/12/09 09:39:32.243 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 10,
type=2, handler=0, client_data=0, timeout=0
2019/12/09 09:39:32.244 kid1| 5,3| Read.cc(145) HandleRead: FD 10, size
32767, retval 3401, errno 0
2019/12/09 09:39:32.244 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 10 flags=1 (0, 0)
2019/12/09 09:39:32.244 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperHandleRead(local=[::] remote=[::] FD 10
flags=1, data=0x20b4b18, size=3401, buf=0x20b4d40) [call2841]
2019/12/09 09:39:32.244 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperHandleRead(local=[::] remote=[::] FD 10 flags=1, data=0x20b4b18,
size=3401, buf=0x20b4d40)
2019/12/09 09:39:32.244 kid1| 5,4| AsyncCall.cc(38) make: make call
helperHandleRead [call2841]
2019/12/09 09:39:32.244 kid1| 84,5| helper.cc(963) helperHandleRead:
helperHandleRead: 3401 bytes from
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr1
2019/12/09 09:39:32.244 kid1| 84,3| helper.cc(991) helperHandleRead:
helperHandleRead: end of reply found
2019/12/09 09:39:32.244 kid1| 84,3| Reply.cc(41) finalize: Parsing helper
buffer
2019/12/09 09:39:32.244 kid1| 84,3| Reply.cc(59) finalize: Buff length is
larger than 2
2019/12/09 09:39:32.244 kid1| 84,3| Reply.cc(63) finalize: helper Result =
OK
2019/12/09 09:39:32.244 kid1| 83,5| helper.cc(158) HandleGeneratorReply: to
0x256a4a8 in crtGenRq12500/1
2019/12/09 09:39:32.244 kid1| 33,5| client_side.cc(2870) sslCrtdHandleReply:
Certificate for X.Y.82.162 was successfully recieved from ssl_crtd
2019/12/09 09:39:32.245 kid1| 33,5| client_side.cc(3358)
doPeekAndSpliceStep: PeekAndSplice mode, proceed with client negotiation.
Currrent state:SSLv2/v3 read client hello A
2019/12/09 09:39:32.245 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 13,
type=2, handler=1, client_data=0x256a4a8, timeout=0
2019/12/09 09:39:32.245 kid1| 84,5| helper.cc(1247) GetFirstAvailable:
GetFirstAvailable: Running servers 5
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
helperHandleRead constructed, this=0x258f150 [call2907]
2019/12/09 09:39:32.245 kid1| 5,5| Read.cc(57) comm_read_base: comm_read,
queueing read for local=[::] remote=[::] FD 10 flags=1; asynCall 0x258f150*1
2019/12/09 09:39:32.245 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 10,
type=1, handler=1, client_data=0x2091df8, timeout=0
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
helperHandleRead(local=[::] remote=[::] FD 10 flags=1, data=0x20b4b18,
size=3401, buf=0x20b4d40)
2019/12/09 09:39:32.245 kid1| 83,5| bio.cc(612) squid_bio_ctrl: 0x20d61f0
6(0, 0x2592b20)
2019/12/09 09:39:32.245 kid1| 83,5| bio.cc(113) write: FD 13 wrote 7 <= 7
2019/12/09 09:39:32.245 kid1| 83,5| bio.cc(612) squid_bio_ctrl: 0x20d61f0
11(0, 0)
2019/12/09 09:39:32.245 kid1| *Error negotiating SSL connection on FD 13:
error:00000001:lib(0):func(0):reason(1) (1/-1)*
2019/12/09 09:39:32.245 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 13
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
commStartTlsClose constructed, this=0x25983a0 [call2908]
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(892) will call commStartTlsClose(FD 13) [call2908]
2019/12/09 09:39:32.245 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 13
2019/12/09 09:39:32.245 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 13
2019/12/09 09:39:32.245 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x256df80*1
2019/12/09 09:39:32.245 kid1| 33,5| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call ConnStateData::connStateClosed(FD -1, data=0x256a4a8)
[call2864]
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x256d600 [call2909]
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 13) [call2909]
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
commStartTlsClose(FD 13)
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCall.cc(38) make: make call
commStartTlsClose [call2908]
2019/12/09 09:39:32.245 kid1| 83,5| Session.cc(202) SessionSendGoodbye:
session=0x259dbd0
2019/12/09 09:39:32.245 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
commStartTlsClose(FD 13)
2019/12/09 09:39:32.245 kid1| 33,5| AsyncCallQueue.cc(55) fireNext: entering
ConnStateData::connStateClosed(FD -1, data=0x256a4a8)
2019/12/09 09:39:32.246 kid1| 33,5| AsyncCall.cc(38) make: make call
ConnStateData::connStateClosed [call2864]
2019/12/09 09:39:32.246 kid1| 33,5| AsyncJob.cc(123) callStart:
Http1::Server status in: [ job203]
2019/12/09 09:39:32.246 kid1| 93,4| AsyncJob.cc(55) deleteThis:
Http1::Server will NOT delete in-call job, reason:
ConnStateData::connStateClosed
2019/12/09 09:39:32.246 kid1| 93,5| AsyncJob.cc(139) callEnd:
ConnStateData::connStateClosed(FD -1, data=0x256a4a8) ends job [Stopped,
reason:ConnStateData::connStateClosed job203]
2019/12/09 09:39:32.246 kid1| 33,2| client_side.cc(582) swanSong:
local=X.Y.82.162:443 remote=192.168.1.25:53556 flags=33
2019/12/09 09:39:32.246 kid1| 33,3| client_side.cc(4118) unpinConnection:
local=192.168.1.35:46896 remote=X.Y.82.162:443 FD 15 flags=1
2019/12/09 09:39:32.246 kid1| 5,5| comm.cc(1030) comm_remove_close_handler:
comm_remove_close_handler: FD 15, AsyncCall=0x25b4d10*2
2019/12/09 09:39:32.246 kid1| 33,5| AsyncCall.cc(56) cancel: will not call
ConnStateData::clientPinnedConnectionClosed [call2903] because
comm_remove_close_handler
2019/12/09 09:39:32.246 kid1| 33,3| AsyncCall.cc(56) cancel: will not call
ConnStateData::clientPinnedConnectionRead [call2904] because
comm_read_cancel
2019/12/09 09:39:32.246 kid1| 33,3| AsyncCall.cc(56) cancel: will not call
ConnStateData::clientPinnedConnectionRead [call2904] also because
comm_read_cancel
2019/12/09 09:39:32.246 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 15,
type=1, handler=0, client_data=0, timeout=0
2019/12/09 09:39:32.246 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 15
2019/12/09 09:39:32.246 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
commStartTlsClose constructed, this=0x25983a0 [call2910]
2019/12/09 09:39:32.246 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(892) will call commStartTlsClose(FD 15) [call2910]
2019/12/09 09:39:32.246 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 15
2019/12/09 09:39:32.246 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 15
2019/12/09 09:39:32.246 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x2598420 [call2911]
2019/12/09 09:39:32.246 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 15) [call2911]
2019/12/09 09:39:32.246 kid1| 33,3| client_side.cc(612) ~ConnStateData:
local=X.Y.82.162:443 remote=192.168.1.25:53556 flags=33
2019/12/09 09:39:32.246 kid1| 33,4| ServerBump.cc(46) ~ServerBump:
destroying
2019/12/09 09:39:32.246 kid1| 33,4| ServerBump.cc(48) ~ServerBump:
e:=sp2XIV/0x25617e0*1
2019/12/09 09:39:32.246 kid1| 90,3| store_client.cc(651) storeUnregister:
storeUnregister: called for '41000000000000000E11000001000000'
2019/12/09 09:39:32.246 kid1| 20,3| store_swapout.cc(347) mayStartSwapOut:
already rejected
2019/12/09 09:39:32.246 kid1| 20,2| store.cc(986) checkCachable:
StoreEntry::checkCachable: NO: not cachable
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(444) lock: storeUnregister
locked key 41000000000000000E11000001000000 e:=sp2XIV/0x25617e0*2
2019/12/09 09:39:32.246 kid1| 90,3| store_client.cc(764)
CheckQuickAbortIsReasonable: entry=e:=sp2XIV/0x25617e0*2
2019/12/09 09:39:32.246 kid1| 90,3| store_client.cc(755)
storePendingNClients: storePendingNClients: returning 0
2019/12/09 09:39:32.246 kid1| 90,3| store_client.cc(777)
CheckQuickAbortIsReasonable: quick-abort? NO store_status != STORE_PENDING
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(469) unlock: storeUnregister
unlocking key 41000000000000000E11000001000000 e:=sp2XIV/0x25617e0*2
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(469) unlock: Ssl::ServerBump
unlocking key 41000000000000000E11000001000000 e:=sp2XIV/0x25617e0*1
2019/12/09 09:39:32.246 kid1| 20,5| store.cc(485) doAbandon:
e:=sp2XIV/0x25617e0*0 via Ssl::ServerBump
2019/12/09 09:39:32.246 kid1| 90,3| store_client.cc(755)
storePendingNClients: storePendingNClients: returning 0
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(1216) release: 0
e:=sp2XIV/0x25617e0*0 41000000000000000E11000001000000
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(379) destroyMemObject:
0x256a240 in e:=sp2XIV/0x25617e0*0
2019/12/09 09:39:32.246 kid1| 20,3| MemObject.cc(110) ~MemObject: MemObject
destructed, this=0x256a240
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(397) destroyStoreEntry:
destroyStoreEntry: destroying 0x25617e8
2019/12/09 09:39:32.246 kid1| 20,3| store.cc(379) destroyMemObject: 0 in
e:=sp2XIV/0x25617e0*0
2019/12/09 09:39:32.246 kid1| 20,5| store.cc(352) ~StoreEntry: StoreEntry
destructed, this=0x25617e0
2019/12/09 09:39:32.246 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob
destructed, this=0x256a788 type=Http1::Server [job203]
2019/12/09 09:39:32.246 kid1| 93,6| AsyncJob.cc(149) callEnd:
ConnStateData::connStateClosed(FD -1, data=0x256a4a8) ended 0x256a788
2019/12/09 09:39:32.246 kid1| 33,5| AsyncCallQueue.cc(57) fireNext: leaving
ConnStateData::connStateClosed(FD -1, data=0x256a4a8)
2019/12/09 09:39:32.246 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
comm_close_complete(FD 13)
2019/12/09 09:39:32.246 kid1| 5,4| AsyncCall.cc(38) make: make call
comm_close_complete [call2909]
2019/12/09 09:39:32.246 kid1| 83,5| Session.cc(100) operator(): SSL_free
session=0x259dbd0
2019/12/09 09:39:32.246 kid1| 83,5| bio.cc(612) squid_bio_ctrl: 0x20d61f0
7(0, 0x2592b20)
2019/12/09 09:39:32.246 kid1| 83,5| ../../src/security/PeerOptions.h(112)
operator(): SSL_CTX destruct, this=0x25a0570
2019/12/09 09:39:32.246 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 13
client https start
2019/12/09 09:39:32.246 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 13,
type=3, handler=0, client_data=0, timeout=0
2019/12/09 09:39:32.247 kid1| 5,5| AcceptLimiter.cc(47) kick: size=0
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
comm_close_complete(FD 13)
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
commStartTlsClose(FD 15)
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCall.cc(38) make: make call
commStartTlsClose [call2910]
2019/12/09 09:39:32.247 kid1| 83,5| Session.cc(202) SessionSendGoodbye:
session=0x257cb00
2019/12/09 09:39:32.247 kid1| 83,5| bio.cc(113) write: FD 15 wrote 31 <= 31
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
commStartTlsClose(FD 15)
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
comm_close_complete(FD 15)
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCall.cc(38) make: make call
comm_close_complete [call2911]
2019/12/09 09:39:32.247 kid1| 83,5| Session.cc(100) operator(): SSL_free
session=0x257cb00
2019/12/09 09:39:32.247 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 15
X.Y.82.162 pinned connection for 192.168.1.25:53556 (13)
2019/12/09 09:39:32.247 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 15,
type=3, handler=0, client_data=0, timeout=0
2019/12/09 09:39:32.247 kid1| 5,5| AcceptLimiter.cc(47) kick: size=0
2019/12/09 09:39:32.247 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
comm_close_complete(FD 15)
2019/12/09 09:39:32.800 kid1| 41,5| AsyncCall.cc(26) AsyncCall: The
AsyncCall ipcache_purgelru constructed, this=0x255e980 [call2912]
2019/12/09 09:39:32.800 kid1| 41,5| AsyncCall.cc(93) ScheduleCall:
event.cc(241) will call ipcache_purgelru() [call2912]
2019/12/09 09:39:32.800 kid1| 41,5| AsyncCallQueue.cc(55) fireNext: entering
ipcache_purgelru()
2019/12/09 09:39:32.800 kid1| 41,5| AsyncCall.cc(38) make: make call
ipcache_purgelru [call2912]
2019/12/09 09:39:32.800 kid1| 41,5| AsyncCallQueue.cc(57) fireNext: leaving
ipcache_purgelru()
2019/12/09 09:39:33.096 kid1| 41,5| AsyncCall.cc(26) AsyncCall: The
AsyncCall logfileFlush constructed, this=0x255e980 [call2913]
2019/12/09 09:39:33.097 kid1| 41,5| AsyncCall.cc(93) ScheduleCall:
event.cc(241) will call logfileFlush(0x20f1eb8*?) [call2913]
2019/12/09 09:39:33.097 kid1| 41,5| AsyncCallQueue.cc(55) fireNext: entering
logfileFlush(0x20f1eb8*?)
2019/12/09 09:39:33.097 kid1| 41,5| AsyncCall.cc(38) make: make call
logfileFlush [call2913]
2019/12/09 09:39:33.097 kid1| 41,5| AsyncCallQueue.cc(57) fireNext: leaving
logfileFlush(0x20f1eb8*?)
2019/12/09 09:39:33.171 kid1| 41,5| AsyncCall.cc(26) AsyncCall: The
AsyncCall MaintainSwapSpace constructed, this=0x255e980 [call2914]
2019/12/09 09:39:33.171 kid1| 41,5| AsyncCall.cc(93) ScheduleCall:
event.cc(241) will call MaintainSwapSpace() [call2914]
2019/12/09 09:39:33.171 kid1| 41,5| AsyncCallQueue.cc(55) fireNext: entering
MaintainSwapSpace()
2019/12/09 09:39:33.171 kid1| 41,5| AsyncCall.cc(38) make: make call
MaintainSwapSpace [call2914]
2019/12/09 09:39:33.171 kid1| 47,5| ufs/UFSSwapDir.cc(445) maintain: space
still available in /usr/local/squid/var/cache/squid
2019/12/09 09:39:33.171 kid1| 41,5| AsyncCallQueue.cc(57) fireNext: leaving
MaintainSwapSpace()
^C2019/12/09 09:39:33.337| 1,2| main.cc(1788) masterShutdownStart: received
shutdown command
2019/12/09 09:39:33.337 kid1| 5,3| Read.cc(145) HandleRead: FD 14, size
32767, retval 0, errno 0
2019/12/09 09:39:33.337 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 14 flags=1 (0, 0)
2019/12/09 09:39:33.337 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperHandleRead(local=[::] remote=[::] FD 14
flags=1, data=0x20c5848, size=0, buf=0x20c5b50) [call9]
2019/12/09 09:39:33.337 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 14,
type=2, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.337 kid1| 5,3| Read.cc(145) HandleRead: FD 18, size
32767, retval 0, errno 0
2019/12/09 09:39:33.337 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 18 flags=1 (0, 0)
2019/12/09 09:39:33.337 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperHandleRead(local=[::] remote=[::] FD 18
flags=1, data=0x20d6288, size=0, buf=0x20d6590) [call15]
2019/12/09 09:39:33.337 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 18,
type=2, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.337 kid1| 5,3| Read.cc(145) HandleRead: FD 16, size
32767, retval 0, errno 0
2019/12/09 09:39:33.337 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 16 flags=1 (0, 0)
2019/12/09 09:39:33.337 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperHandleRead(local=[::] remote=[::] FD 16
flags=1, data=0x20cdd68, size=0, buf=0x20ce070) [call12]
2019/12/09 09:39:33.338 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 16,
type=2, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.338 kid1| 5,3| Read.cc(145) HandleRead: FD 12, size
32767, retval 0, errno 0
2019/12/09 09:39:33.338 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 12 flags=1 (0, 0)
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperHandleRead(local=[::] remote=[::] FD 12
flags=1, data=0x20bd328, size=0, buf=0x20bd630) [call6]
2019/12/09 09:39:33.338 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 12,
type=2, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperHandleRead(local=[::] remote=[::] FD 14 flags=1, data=0x20c5848,
size=0, buf=0x20c5b50)
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(38) make: make call
helperHandleRead [call9]
2019/12/09 09:39:33.338 kid1| 84,5| helper.cc(963) helperHandleRead:
helperHandleRead: 0 bytes from
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr3
2019/12/09 09:39:33.338 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 14
2019/12/09 09:39:33.338 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 14
2019/12/09 09:39:33.338 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 14
2019/12/09 09:39:33.338 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x20cdb60*1
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call helperServerFree(0x20c5848/0x20c5848) [call8]
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x2598420 [call2915]
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 14) [call2915]
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
helperHandleRead(local=[::] remote=[::] flags=1, data=0x20c5848, size=0,
buf=0x20c5b50)
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperHandleRead(local=[::] remote=[::] FD 18 flags=1, data=0x20d6288,
size=0, buf=0x20d6590)
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(38) make: make call
helperHandleRead [call15]
2019/12/09 09:39:33.338 kid1| 84,5| helper.cc(963) helperHandleRead:
helperHandleRead: 0 bytes from
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr5
2019/12/09 09:39:33.338 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 18
2019/12/09 09:39:33.338 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 18
2019/12/09 09:39:33.338 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 18
2019/12/09 09:39:33.338 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x20de5a0*1
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call helperServerFree(0x20d6288/0x20d6288) [call14]
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x25b1b30 [call2916]
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 18) [call2916]
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
helperHandleRead(local=[::] remote=[::] flags=1, data=0x20d6288, size=0,
buf=0x20d6590)
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperHandleRead(local=[::] remote=[::] FD 16 flags=1, data=0x20cdd68,
size=0, buf=0x20ce070)
2019/12/09 09:39:33.338 kid1| 5,4| AsyncCall.cc(38) make: make call
helperHandleRead [call12]
2019/12/09 09:39:33.338 kid1| 84,5| helper.cc(963) helperHandleRead:
helperHandleRead: 0 bytes from
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr4
2019/12/09 09:39:33.338 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 16
2019/12/09 09:39:33.338 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 16
2019/12/09 09:39:33.338 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 16
2019/12/09 09:39:33.338 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x20d6080*1
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call helperServerFree(0x20cdd68/0x20cdd68) [call11]
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x2564110 [call2917]
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 16) [call2917]
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
helperHandleRead(local=[::] remote=[::] flags=1, data=0x20cdd68, size=0,
buf=0x20ce070)
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperHandleRead(local=[::] remote=[::] FD 12 flags=1, data=0x20bd328,
size=0, buf=0x20bd630)
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(38) make: make call
helperHandleRead [call6]
2019/12/09 09:39:33.339 kid1| 84,5| helper.cc(963) helperHandleRead:
helperHandleRead: 0 bytes from
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr2
2019/12/09 09:39:33.339 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 12
2019/12/09 09:39:33.339 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 12
2019/12/09 09:39:33.339 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 12
2019/12/09 09:39:33.339 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x20c5640*1
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call helperServerFree(0x20bd328/0x20bd328) [call5]
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x25b3490 [call2918]
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 12) [call2918]
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
helperHandleRead(local=[::] remote=[::] flags=1, data=0x20bd328, size=0,
buf=0x20bd630)
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperServerFree(0x20c5848/0x20c5848)
2019/12/09 09:39:33.339 kid1| 5,4| AsyncCall.cc(38) make: make call
helperServerFree [call8]
2019/12/09 09:39:33.339 kid1| WARNING:
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr3 exited
2019/12/09 09:39:33.339 kid1| Too few
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB processes are running (need 1/32)
2019/12/09 09:39:33.339 kid1| Starting new helpers
2019/12/09 09:39:33.339 kid1| helperOpenServers: Starting 1/32
'security_file_certgen' processes
2019/12/09 09:39:33.339 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 13 IPC
UNIX STREAM Parent
2019/12/09 09:39:33.339 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 15 IPC
UNIX STREAM Parent
2019/12/09 09:39:33.339 kid1| 54,3| ipc.cc(204) ipcCreate: ipcCreate: prfd
FD 13
2019/12/09 09:39:33.339 kid1| 54,3| ipc.cc(205) ipcCreate: ipcCreate: pwfd
FD 13
2019/12/09 09:39:33.339 kid1| 54,3| ipc.cc(206) ipcCreate: ipcCreate: crfd
FD 15
2019/12/09 09:39:33.339 kid1| 54,3| ipc.cc(207) ipcCreate: ipcCreate: cwfd
FD 15
2019/12/09 09:39:33.340 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 15
2019/12/09 09:39:33.340 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 15
2019/12/09 09:39:33.340 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 15
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x256a970 [call2919]
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 15) [call2919]
2019/12/09 09:39:33.340 kid1| 21,3| tools.cc(506) leave_suid: leave_suid:
PID 4394 called
2019/12/09 09:39:33.340 kid1| 21,3| tools.cc(606) no_suid: no_suid: PID 4394
giving up root privileges forever
2019/12/09 09:39:33.340 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 13
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
helperServerFree constructed, this=0x255e980 [call2920]
2019/12/09 09:39:33.340 kid1| 5,5| comm.cc(985) comm_add_close_handler:
comm_add_close_handler: FD 13, AsyncCall=0x255e980*1
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
helperHandleRead constructed, this=0x254d4c0 [call2921]
2019/12/09 09:39:33.340 kid1| 5,5| Read.cc(57) comm_read_base: comm_read,
queueing read for local=[::] remote=[::] FD 13 flags=1; asynCall 0x254d4c0*1
2019/12/09 09:39:33.340 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 13,
type=1, handler=1, client_data=0x2091f60, timeout=0
2019/12/09 09:39:33.340 kid1| 84,5| helper.cc(1247) GetFirstAvailable:
GetFirstAvailable: Running servers 5
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
helperServerFree(0x20c5848/0x20c5848)
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
comm_close_complete(FD 14)
2019/12/09 09:39:33.340 kid1| 5,4| AsyncCall.cc(38) make: make call
comm_close_complete [call2915]
2019/12/09 09:39:33.340 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 14
security_file_certgen #3
2019/12/09 09:39:33.340 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 14,
type=3, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.341 kid1| 5,5| AcceptLimiter.cc(47) kick: size=0
2019/12/09 09:39:33.341 kid1| 5,4| AsyncCallQueue.cc(57) fireNext: leaving
comm_close_complete(FD 14)
2019/12/09 09:39:33.341 kid1| 5,4| AsyncCallQueue.cc(55) fireNext: entering
helperServerFree(0x20d6288/0x20d6288)
2019/12/09 09:39:33.341 kid1| 5,4| AsyncCall.cc(38) make: make call
helperServerFree [call14]
2019/12/09 09:39:33.341 kid1| WARNING:
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr5 exited
2019/12/09 09:39:33.341 kid1| Too few
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB processes are running (need 1/32)
2019/12/09 09:39:33.341 kid1| Closing HTTP(S) port [::]:3128
2019/12/09 09:39:33.341 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 28
2019/12/09 09:39:33.341 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 28
2019/12/09 09:39:33.341 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 28
2019/12/09 09:39:33.341 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x20ff240*2
2019/12/09 09:39:33.341 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call Comm::TcpAcceptor::handleClosure(FD -1,
data=0x2539878) [call29]
2019/12/09 09:39:33.341 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x2598420 [call2922]
2019/12/09 09:39:33.341 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 28) [call2922]
2019/12/09 09:39:33.341 kid1| Closing HTTP(S) port [::]:3129
2019/12/09 09:39:33.341 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 29
2019/12/09 09:39:33.341 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 29
2019/12/09 09:39:33.341 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 29
2019/12/09 09:39:33.341 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x23dd590*2
2019/12/09 09:39:33.342 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call Comm::TcpAcceptor::handleClosure(FD -1,
data=0x2539d18) [call30]
2019/12/09 09:39:33.342 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x254cdd0 [call2923]
2019/12/09 09:39:33.342 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 29) [call2923]
2019/12/09 09:39:33.342 kid1| Closing HTTP(S) port [::]:3130
2019/12/09 09:39:33.342 kid1| 5,3| comm.cc(859) _comm_close: comm_close:
start closing FD 30
2019/12/09 09:39:33.342 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove
timeout for FD 30
2019/12/09 09:39:33.342 kid1| 5,5| comm.cc(727) commCallCloseHandlers:
commCallCloseHandlers: FD 30
2019/12/09 09:39:33.342 kid1| 5,5| comm.cc(735) commCallCloseHandlers:
commCallCloseHandlers: ch->handler=0x23dd620*2
2019/12/09 09:39:33.342 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(736) will call Comm::TcpAcceptor::handleClosure(FD -1,
data=0x2539d88) [call31]
2019/12/09 09:39:33.342 kid1| 5,4| AsyncCall.cc(26) AsyncCall: The AsyncCall
comm_close_complete constructed, this=0x2592b20 [call2924]
2019/12/09 09:39:33.342 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
comm.cc(930) will call comm_close_complete(FD 30) [call2924]
2019/12/09 09:39:33.342 kid1| 21,3| tools.cc(506) leave_suid: leave_suid:
PID 4366 called
2019/12/09 09:39:33.342 kid1| storeDirWriteCleanLogs: Starting...
2019/12/09 09:39:33.342 kid1| 6,5| fs_io.cc(65) file_open: FD 14
2019/12/09 09:39:33.342 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 14
/usr/local/squid/var/cache/squid/swap.state.clean
2019/12/09 09:39:33.343 kid1| 47,3| ufs/UFSSwapDir.cc(959) writeCleanStart:
opened /usr/local/squid/var/cache/squid/swap.state.clean, FD 14
2019/12/09 09:39:33.343 kid1| 6,5| fs_io.cc(120) file_close: file_close: FD
11 really closing
2019/12/09 09:39:33.343 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 11
/usr/local/squid/var/cache/squid/swap.state
2019/12/09 09:39:33.343 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 11,
type=3, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.343 kid1| 47,3| ufs/UFSSwapDir.cc(764) closeLog: Cache
Dir #0 log closed on FD 11
2019/12/09 09:39:33.343 kid1| 21,2| fs_io.cc(510) FileRename: renaming
/usr/local/squid/var/cache/squid/swap.state.clean to
/usr/local/squid/var/cache/squid/swap.state
2019/12/09 09:39:33.344 kid1| 6,5| fs_io.cc(65) file_open: FD 11
2019/12/09 09:39:33.344 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 11
/usr/local/squid/var/cache/squid/swap.state.last-clean
2019/12/09 09:39:33.344 kid1| 6,5| fs_io.cc(120) file_close: file_close: FD
11 really closing
2019/12/09 09:39:33.344 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 11
/usr/local/squid/var/cache/squid/swap.state.last-clean
2019/12/09 09:39:33.344 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 11,
type=3, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.344 kid1| 6,5| fs_io.cc(120) file_close: file_close: FD
14 really closing
2019/12/09 09:39:33.344 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 14
/usr/local/squid/var/cache/squid/swap.state.clean
2019/12/09 09:39:33.344 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 14,
type=3, handler=0, client_data=0, timeout=0
2019/12/09 09:39:33.344 kid1|   Finished.  Wrote 213 entries.
2019/12/09 09:39:33.344 kid1|   Took 0.00 seconds (105445.54 entries/sec).
2019/12/09 09:39:33.344 kid1| *FATAL: The
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB helpers are crashing too rapidly,
need help!*






--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen

I'm wondering if this issue reported last year is fixed:
http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-4-4-security-file-certgen-helpers-crashing-td4687098.html

or is there a work around.
thanks.

- George



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Amos Jeffries
Administrator
On 10/12/19 6:46 pm, GeorgeShen wrote:
>
> I'm wondering if this issue reported last year is fixed:
> http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-4-4-security-file-certgen-helpers-crashing-td4687098.html
>

That question implies that you are not using the latest Squid release,
or you already have the answer. When using SSL-Bump features (cert
generation being one) it is best to follow the updates.


Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Alex Rousskov
In reply to this post by GeorgeShen
On 12/9/19 12:56 PM, GeorgeShen wrote:

> and at the end, it is also saying security_file_certgen crashes rapidly!!!

I would ignore anything that happens _after_ you press ^C (i.e. send
Squid a shutdown signal). While a shutdown should not "crash" any
helpers, that is not the problem you are currently trying to solve.

As for your primary problem, I see nothing interesting in the provided
logs (which does not necessarily mean there is nothing there). As Amos
has said, when dealing with SslBump problems, please make sure you are
running Squid v4.9 (or even master).


> ^C2019/12/09 09:39:33.337| 1,2| main.cc(1788) masterShutdownStart: received
> shutdown command

Alex.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen
I'm running the squid latest from download site. 4.9
Ok, i suspect that was related to my ^C running the process in foreground,
but I also see before that there are warning messages in the log:
2019/12/09 19:23:12.116 kid1| WARNING:
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr5 exited
2019/12/09 19:23:12.118 kid1| WARNING:
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr1 exited
2019/12/09 19:23:12.123 kid1| WARNING:
/usr/local/squid/libexec/security_file_certgen -s
/usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr3 exited

it could be related also to my ^C, but not sure.

the other program, I have found it is related to my golang program set the
ciphersuite to some more secured cipher algorithm:
tls.TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, and
tls.TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256. After removed those cipher
restrictions, the ssl-bump does work.

thanks.
- George



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Amos Jeffries
Administrator
On 11/12/19 4:00 pm, GeorgeShen wrote:

> I'm running the squid latest from download site. 4.9
> Ok, i suspect that was related to my ^C running the process in foreground,
> but I also see before that there are warning messages in the log:
> 2019/12/09 19:23:12.116 kid1| WARNING:
> /usr/local/squid/libexec/security_file_certgen -s
> /usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr5 exited
> 2019/12/09 19:23:12.118 kid1| WARNING:
> /usr/local/squid/libexec/security_file_certgen -s
> /usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr1 exited
> 2019/12/09 19:23:12.123 kid1| WARNING:
> /usr/local/squid/libexec/security_file_certgen -s
> /usr/local/squid/var/logs/ssl_db -M 4MB #Hlpr3 exited
>
> it could be related also to my ^C, but not sure.
>
> the other program, I have found it is related to my golang program set the
> ciphersuite to some more secured cipher algorithm:
> tls.TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, and
> tls.TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256. After removed those cipher
> restrictions, the ssl-bump does work.

That implies that your proxy is configured in such a way that these
ciphers are not usable - and/or that the origin servers being contacted
cannot handle them.

You may want to fix that for at least Squid. To do so set the tls-dh=
option with a preference EC curve name and DHE parameters file.


Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen

did a 'openssl dhparam -out dhparams.pem 4096' to generate the dhparams.pem
file, and added those into the squid.conf:

http_port 3129 ssl-bump cert=/usr/local/squid/etc/ssl_cert/myCA.pem
generate-host-certificates=on dynamic_cert_mem_cache_size=4MB
*options=SINGLE_DH_USE:SINGLE_ECDH_USE
tls-dh=/usr/local/squid/etc/dhparams.pem*

when the client software include the ciphersuites of the above mentioned,
still fail the TLS negotiation. Do I configured this incorrectly?

thanks.
- George




--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

Amos Jeffries
Administrator
On 12/12/19 11:38 am, GeorgeShen wrote:

>
> did a 'openssl dhparam -out dhparams.pem 4096' to generate the dhparams.pem
> file, and added those into the squid.conf:
>
> http_port 3129 ssl-bump cert=/usr/local/squid/etc/ssl_cert/myCA.pem
> generate-host-certificates=on dynamic_cert_mem_cache_size=4MB
> *options=SINGLE_DH_USE:SINGLE_ECDH_USE
> tls-dh=/usr/local/squid/etc/dhparams.pem*
>
> when the client software include the ciphersuites of the above mentioned,
> still fail the TLS negotiation. Do I configured this incorrectly?

What you have so far enables the DH ciphers and algorithms, but not yet
the curve parts. For that you need to add the curve name to tls-dh option.



Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid Proxy SSL Bump can not retrieve SSL session back to the client?

GeorgeShen
Right. that works now.

thanks.
- George



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users