TLS Client Certificate issue - Printable Version

TLS Client Certificate issue - Printable Version

+- iPXE discussion forum (https://forum.ipxe.org)
+-- Forum: iPXE user forums (/forumdisplay.php?fid=1)
+--- Forum: General (/forumdisplay.php?fid=2)
+--- Thread: TLS Client Certificate issue (/showthread.php?tid=11367)

TLS Client Certificate issue - Lemelisk - 2018-06-04 15:25

Hi everyone,

I've got an issue with tls certificate auth and am stuck, I could use some help on how to debug this.

Without cert auth chainloading an ipxe script works fine, but when I set Apache to "SSLVerifyClient require" the connection just stalls after ipxe sent it's client cert (tcpdump shows a tcp-ack from the server, then silence). Some seconds later Apache logs a timeout and closes the connection, then some more seconds later ipxe also times out, stating an error 0x420c6001.

In another thread I found the build-flags "DEBUG=tls,x509,validator", showing that after sending the client cert an ocsp check for the server cert is performed (successfully).

Any ideas?

I've attached the logs from that process:
apache debug log (with client cert)

Code:

[Mon Jun 04 13:57:18.056285 2018] [ssl:info] [pid 19386] [client 192.168.0.100:31612] AH01964: Connection to child 3 established (server servername.local:443)

[Mon Jun 04 13:57:18.057154 2018] [ssl:debug] [pid 19386] ssl_engine_kernel.c(1890): [client 192.168.0.100:31612] AH02043: SSL virtual host for servername servername.local found

[Mon Jun 04 13:57:18.495204 2018] [ssl:debug] [pid 19386] ssl_engine_kernel.c(1360): [client 192.168.0.100:31612] AH02275: Certificate Verification, depth 2, CRL checking mode: none [subject: CN=Root CA 1 / issuer: Root CA 1 / serial: 00 / notbefore: Feb 19 14:40:51 2015 GMT / notafter: Feb 16 14:40:51 2025 GMT]

[Mon Jun 04 13:57:18.495418 2018] [ssl:debug] [pid 19386] ssl_engine_kernel.c(1360): [client 192.168.0.100:31612] AH02275: Certificate Verification, depth 1, CRL checking mode: none [subject: CN=Issuing CA 1 / issuer: CN=Root CA 1 / serial: 01 / notbefore: Feb 19 14:46:05 2015 GMT / notafter: Feb 18 14:46:05 2020 GMT]

[Mon Jun 04 13:57:18.495525 2018] [ssl:debug] [pid 19386] ssl_engine_kernel.c(1360): [client 192.168.0.100:31612] AH02275: Certificate Verification, depth 0, CRL checking mode: none [subject: UID=12345,CN=testclient / issuer: CN=Issuing CA 1 / serial: 12345 / notbefore: Apr 26 11:46:41 2018 GMT / notafter: Feb 18 14:46:05 2020 GMT]

[Mon Jun 04 13:57:42.480812 2018] [reqtimeout:info] [pid 19386] [client 192.168.0.100:31612] AH01382: Request header read timeout

[Mon Jun 04 13:57:42.481005 2018] [ssl:debug] [pid 19386] ssl_engine_io.c(1202): (70007)The timeout specified has expired: [client 192.168.0.100:31612] AH02007: SSL handshake interrupted by system [Hint: Stop button pressed in browser?!]

[Mon Jun 04 13:57:42.481143 2018] [ssl:info] [pid 19386] [client 192.168.0.100:31612] AH01998: Connection closed to child 3 with abortive shutdown (server servername.local:443)

ipxe syslog (with client cert)

Code:

<6>servername.local ipxe: iPXE> 

<6>servername.local ipxe: iPXE> exit

<6>servername.local ipxe: Booting from https://servername.local/boot?mac=00:11:22:33:44:55&manufacturer=VMware,%20In

<6>servername.local ipxe: c.&product=VMware%20Virtual%20Platform&arch=x86_64

<6>servername.local ipxe: https://servername.local/boot...TLS 0xf8614 using protocol version 3.3

<6>servername.local ipxe: TLS 0xf8614 selected rsa-aes_cbc-128-sha256

<6>servername.local ipxe: TLS 0xf8614 pre-master-secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 client random bytes:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 server random bytes:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 generated master secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 TX MAC secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 RX MAC secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 TX key:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 RX key:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 TX IV:

    [redacted]

<6>servername.local ipxe: TLS 0xf8614 RX IV:

    [redacted]

<6>servername.local ipxe: X509 chain 0xf3694 added X509 0xf7674 "servername.local"

<6>servername.local ipxe: TLS 0xf8614 found certificate servername.local

<6>servername.local ipxe: X509 chain 0xf3694 added X509 0xf88f4 "Automated Issuing CA 1"

<6>servername.local ipxe: TLS 0xf8614 found certificate Automated Issuing CA 1

<6>servername.local ipxe: X509 chain 0xf3694 added X509 0x172ba8 "Root CA 1"

<6>servername.local ipxe: TLS 0xf8614 found certificate Root CA 1

<6>servername.local ipxe: TLS 0xf8614 sending client certificate testclient

<6>servername.local ipxe: X509 0x172ba8 "Root CA 1" is a root certificate

<6>servername.local ipxe: X509 0xf88f4 "Automated Issuing CA 1" successfully validated using issuer 0x172ba8 "Root CA 1"

<6>servername.local ipxe: X509 0xf7674 "servername.local" requires an OCSP check

<6>servername.local ipxe: VALIDATOR 0xf38b4 performing OCSP check at http://ocsp.domain.invalid/ocsp/issuingca1/[redacted]

<6>servername.local ipxe: X509 0xf5614 "KB_OCSP_LIVE_automatedissuingca1" successfully validated using issuer 0xf88f4 "Automated Issuing CA 1"

<6>servername.local ipxe: X509 0xf7674 "servername.local" successfully validated using issuer 0xf88f4 "Automated Issuing CA 1"

<6>servername.local ipxe: TLS 0xf8614 certificate validation succeeded

    [pause]

<3>servername.local ipxe: Download of "boot" failed: Error 0x420c6001 (http://ipxe.org/420c6001)

<6>servername.local ipxe:  Error 0x420c6001 (http://ipxe.org/420c6001)

<6>servername.local ipxe: Booting hhttps://servername.local/boot?mac=00:11:22:33:44:55&manufacturer=VMware,%20Inc.&pr

<6>servername.local ipxe: oduct=VMware%20Virtual%20Platform&arch=x86_64 failed, dropping to shell. Type reboot to reboot.

apache debug log (successful without cert)

Code:

[Mon Jun 04 13:53:51.413348 2018] [ssl:info] [pid 13904] [client 192.168.0.100:32283] AH01964: Connection to child 1 established (server servername.local:443)

[Mon Jun 04 13:53:51.414220 2018] [ssl:debug] [pid 13904] ssl_engine_kernel.c(1890): [client 192.168.0.100:32283] AH02043: SSL virtual host for servername servername.local found

[Mon Jun 04 13:53:51.955994 2018] [ssl:debug] [pid 13904] ssl_engine_kernel.c(1823): [client 192.168.0.100:32283] AH02041: Protocol: TLSv1.2, Cipher: AES128-SHA256 (128/128 bits)

[Mon Jun 04 13:53:51.956395 2018] [ssl:debug] [pid 13904] ssl_engine_kernel.c(225): [client 192.168.0.100:32283] AH02034: Initial (No.1) HTTPS request received for child 1 (server servername.local:443)

[Mon Jun 04 13:53:51.956637 2018] [authz_core:debug] [pid 13904] mod_authz_core.c(809): [client 192.168.0.100:32283] AH01626: authorization result of Require all granted: granted

[Mon Jun 04 13:53:51.956644 2018] [authz_core:debug] [pid 13904] mod_authz_core.c(809): [client 192.168.0.100:32283] AH01626: authorization result of <RequireAny>: granted

[Mon Jun 04 13:53:57.971199 2018] [ssl:info] [pid 13904] (70007)The timeout specified has expired: [client 192.168.0.100:32283] AH01991: SSL input filter read failed.

[Mon Jun 04 13:53:57.971289 2018] [ssl:debug] [pid 13904] ssl_engine_io.c(993): [client 192.168.0.100:32283] AH02001: Connection closed to child 1 with standard shutdown (server servername.local:443)

ipxe syslog (successful without cert)

Code:

<6>servername.local ipxe: iPXE> exit

<6>servername.local ipxe: Booting from https://servername.local/boot?mac=00:11:22:33:44:55&manufacturer=VMware,%20In

<6>servername.local ipxe: c.&product=VMware%20Virtual%20Platform&arch=x86_64

<6>servername.local ipxe: https://servername.local/boot...TLS 0xf6374 using protocol version 3.3

<6>servername.local ipxe: TLS 0xf6374 selected rsa-aes_cbc-128-sha256

<6>servername.local ipxe: TLS 0xf6374 pre-master-secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 client random bytes:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 server random bytes:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 generated master secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 TX MAC secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 RX MAC secret:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 TX key:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 RX key:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 TX IV:

    [redacted]

<6>servername.local ipxe: TLS 0xf6374 RX IV:

    [redacted]

<6>servername.local ipxe: X509 chain 0xf3694 added X509 0xf6654 "servername.local"

<6>servername.local ipxe: TLS 0xf6374 found certificate servername.local

<6>servername.local ipxe: X509 chain 0xf3694 added X509 0xf8e74 "Automated Issuing CA 1"

<6>servername.local ipxe: TLS 0xf6374 found certificate Automated Issuing CA 1

<6>servername.local ipxe: X509 chain 0xf3694 added X509 0x172ba8 "Root CA 1"

<6>servername.local ipxe: TLS 0xf6374 found certificate Root CA 1

<6>servername.local ipxe: X509 0x172ba8 "Root CA 1" is a root certificate

<6>servername.local ipxe: X509 0xf8e74 "Automated Issuing CA 1" successfully validated using issuer 0x172ba8 "Root CA 1"

<6>servername.local ipxe: X509 0xf6654 "servername.local" requires an OCSP check

<6>servername.local ipxe: VALIDATOR 0xf4614 performing OCSP check at http://ocsp.domain.invalid/ocsp/issuingca1/[redacted]

<6>servername.local ipxe: X509 0xf9434 "KB_OCSP_LIVE_automatedissuingca1" successfully validated using issuer 0xf8e74 "Automated Issuing CA 1"

<6>servername.local ipxe: X509 0xf6654 "servername.local" successfully validated using issuer 0xf8e74 "Automated Issuing CA 1"

<6>servername.local ipxe: TLS 0xf6374 certificate validation succeeded

<5>servername.local ipxe: .Downloaded "boot"

<6>servername.local ipxe:  ok

<5>servername.local ipxe: Executing "boot"

(hmm, apparently I can't attach a pcap file; if you need it I'll upload it somewhere)

RE: TLS Client Certificate issue - NiKiZe - 2018-06-04 18:42

I think this was solved on IRC
the key size was changed from 4096 bit to 2048 and it worked with a delay of 7 seconds.

RE: TLS Client Certificate issue - Lemelisk - 2018-06-13 13:12

Yes, exactly, had posted this here before asking in irc.

For the record/others affected by this: When using a 4096Bit Client Cert, iPXE took ~46 seconds for sending "TLS Client Verify" message in TLS Handshake; this caused apache to timeout (10s).

Extending the timeout to a minute led to successful file retrieval, and using a smaller 2048Bit-Key reduced the delay to 7 seconds.

I'm still curious though why this calculation takes so long here, and if it could be improved.