[Sun Sep 23 22:53:46.032812 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(753): [client 172.16.1.101:51870] AH02255: Changed client verification type will force renegotiation
[Sun Sep 23 22:53:46.032822 2018] [ssl:info] [pid 3909:tid 140415005083392] [client 172.16.1.101:51870] AH02221: Requesting connection re-negotiation
[Sun Sep 23 22:53:46.032831 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 0/5 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8002d43]
[Sun Sep 23 22:53:46.032875 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(981): [client 172.16.1.101:51870] AH02260: Performing full renegotiation: complete handshake protocol (client does support secure renegotiation)
[Sun Sep 23 22:53:46.032919 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2185): [client 172.16.1.101:51870] OpenSSL: Handshake: start
[Sun Sep 23 22:53:46.032931 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSL negotiation finished successfully
[Sun Sep 23 22:53:46.032942 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: write 33/33 bytes to BIO#7fb4c8002950 [mem: 7fb4c8013580]
[Sun Sep 23 22:53:46.032979 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write hello request
[Sun Sep 23 22:53:46.032986 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2189): [client 172.16.1.101:51870] OpenSSL: Handshake: done
[Sun Sep 23 22:53:46.033085 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2238): [client 172.16.1.101:51870] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
[Sun Sep 23 22:53:46.033133 2018] [ssl:info] [pid 3909:tid 140415005083392] [client 172.16.1.101:51870] AH02226: Awaiting re-negotiation handshake
[Sun Sep 23 22:53:46.033243 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 5/5 bytes from BIO#7fb4c8002a10 [mem: 7fb4c800e423]
[Sun Sep 23 22:53:46.033252 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 273/273 bytes from BIO#7fb4c8002a10 [mem: 7fb4c800e428]
[Sun Sep 23 22:53:46.033258 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2185): [client 172.16.1.101:51870] OpenSSL: Handshake: start
[Sun Sep 23 22:53:46.033266 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSL negotiation finished successfully
[Sun Sep 23 22:53:46.033270 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSL negotiation finished successfully
[Sun Sep 23 22:53:46.033295 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2377): [client 172.16.1.101:51870] AH02645: Server name not provided via TLS extension (using default/first virtual host)
[Sun Sep 23 22:53:46.033352 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS read client hello
[Sun Sep 23 22:53:46.033396 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write server hello
[Sun Sep 23 22:53:46.033422 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write certificate
[Sun Sep 23 22:53:46.034205 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write key exchange
[Sun Sep 23 22:53:46.034245 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write certificate request
[Sun Sep 23 22:53:46.034254 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: write 1712/1712 bytes to BIO#7fb4c8002950 [mem: 7fb4c8013580]
[Sun Sep 23 22:53:46.034286 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write server done
[Sun Sep 23 22:53:46.047062 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 5/5 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8014593]
[Sun Sep 23 22:53:46.047106 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 1218/1218 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8014598]
[Sun Sep 23 22:53:46.047121 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write server done
[Sun Sep 23 22:53:46.047233 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(1753): [client 172.16.1.101:51870] AH02275: Certificate Verification, depth 1, CRL checking mode: none (0) [subject: OU=Engineering,O=Imaginary,L=Seattle,ST=Washington,CN=Unit Testing CA,C=US / issuer: OU=Engineering,O=Imaginary,L=Seattle,ST=Washington,CN=Unit Testing CA,C=US / serial: 1E02 / notbefore: Jul 25 12:42:23 2016 GMT / notafter: Jul 24 12:42:23 2026 GMT]
[Sun Sep 23 22:53:46.047377 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(1753): [client 172.16.1.101:51870] AH02275: Certificate Verification, depth 0, CRL checking mode: none (0) [subject: OU=Engineering,O=Imaginary,L=Seattle,ST=Washington,CN=Client Certificate for VM testing,C=US / issuer: OU=Engineering,O=Imaginary,L=Seattle,ST=Washington,CN=Unit Testing CA,C=US / serial: 8C97 / notbefore: Jul 25 12:42:23 2016 GMT / notafter: Jul 24 12:42:23 2026 GMT]
[Sun Sep 23 22:53:46.047448 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS read client certificate
[Sun Sep 23 22:53:46.047632 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS read client key exchange
[Sun Sep 23 22:53:46.047754 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 5/5 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8014593]
[Sun Sep 23 22:53:46.047777 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 25/25 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8014598]
[Sun Sep 23 22:53:46.047786 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS read certificate verify
[Sun Sep 23 22:53:46.047819 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 5/5 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8014593]
[Sun Sep 23 22:53:46.047826 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 40/40 bytes from BIO#7fb4c8002a10 [mem: 7fb4c8014598]
[Sun Sep 23 22:53:46.047830 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS read change cipher spec
[Sun Sep 23 22:53:46.047883 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS read finished
[Sun Sep 23 22:53:46.047911 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write change cipher spec
[Sun Sep 23 22:53:46.047998 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: write 75/75 bytes to BIO#7fb4c8002950 [mem: 7fb4c8013580]
[Sun Sep 23 22:53:46.048050 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2194): [client 172.16.1.101:51870] OpenSSL: Loop: SSLv3/TLS write finished
[Sun Sep 23 22:53:46.048078 2018] [ssl:trace3] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2189): [client 172.16.1.101:51870] OpenSSL: Handshake: done
[Sun Sep 23 22:53:46.048092 2018] [ssl:debug] [pid 3909:tid 140415005083392] ssl_engine_kernel.c(2238): [client 172.16.1.101:51870] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)

>>>>> 1 minute delay <<<<<< 

[Sun Sep 23 22:54:46.048986 2018] [ssl:trace4] [pid 3909:tid 140415005083392] ssl_engine_io.c(2213): [client 172.16.1.101:51870] OpenSSL: read 0/5 bytes from BIO#7fb4c8002a10 [mem: 7fb4c800a0e3]
[Sun Sep 23 22:54:46.049045 2018] [authz_core:debug] [pid 3909:tid 140415005083392] mod_authz_core.c(820): [client 172.16.1.101:51870] AH01626: authorization result of Require ssl-verify-client : granted
[Sun Sep 23 22:54:46.049051 2018] [authz_core:debug] [pid 3909:tid 140415005083392] mod_authz_core.c(820): [client 172.16.1.101:51870] AH01626: authorization result of <RequireAny>: granted
[Sun Sep 23 22:54:46.049055 2018] [core:trace3] [pid 3909:tid 140415005083392] request.c(304): [client 172.16.1.101:51870] request authorized without authentication by access_checker_ex hook: /index.html