ziti-tunnel-sdk-c
ziti-tunnel-sdk-c copied to clipboard
Published
20 hours ago •
openziti
openziti
ziti-edge-tunnel enroll "COULD_NOT_PROCESS_CSR" on Red Hat 9 / Rocky 9
~~I tried the 0.20.0 release binary and~~ I built ziti-edge-tunnel from source tag v0.20.0 on Rocky 9 and the enroll command always gets this error:
COULD_NOT_PROCESS_CSR
I was able to enroll with the same binary artifact running on another Linux system (not Red Hat 9) without encountering this error, and I was able to enroll the same JWT with the release binary 0.20.0 running on another Linux system, so it doesn't seem to be a problem with the controller or the JWT or the binary itself, except when it's running on Red Hat 9.
The release binary is built with Mbed-TLS, and I set USE_OPENSSL=ON when I built from source, so both TLS implementations have been tried.
[rocky@ip-172-31-4-195 ~]$ sudo ./ziti-edge-tunnel enroll -j /opt/openziti/etc/identities/rh9client2.jwt -i /opt/openziti/etc/identities/rh9client2.json
(15357)[ 0.520] ERROR ziti-sdk:ziti_enroll.c:227 enroll_cb() failed to enroll with controller: https://7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io:443 COULD_NOT_PROCESS_CSR (The supplied csr could not be processed)
(15357)[ 0.520] ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:1992 enroll_cb() enrollment failed: COULD_NOT_PROCESS_CSR(-3)
[rocky@ip-172-31-4-195 ~]$ ldd ./ziti-edge-tunnel
linux-vdso.so.1 (0x00007fffab524000)
libssl.so.3 => /lib64/libssl.so.3 (0x00007f5fa08ad000)
libcrypto.so.3 => /lib64/libcrypto.so.3 (0x00007f5fa0481000)
libatomic.so.1 => /lib64/libatomic.so.1 (0x00007f5fa0478000)
libm.so.6 => /lib64/libm.so.6 (0x00007f5fa039d000)
libresolv.so.2 => /lib64/libresolv.so.2 (0x00007f5fa0389000)
libc.so.6 => /lib64/libc.so.6 (0x00007f5fa017d000)
libz.so.1 => /lib64/libz.so.1 (0x00007f5fa0163000)
/lib64/ld-linux-x86-64.so.2 (0x00007f5fa0958000)
[rocky@ip-172-31-4-195 ~]$ cat /etc/os-release
NAME="Rocky Linux"
VERSION="9.0 (Blue Onyx)"
ID="rocky"
ID_LIKE="rhel centos fedora"
VERSION_ID="9.0"
PLATFORM_ID="platform:el9"
PRETTY_NAME="Rocky Linux 9.0 (Blue Onyx)"
ANSI_COLOR="0;32"
LOGO="fedora-logo-icon"
CPE_NAME="cpe:/o:rocky:rocky:9::baseos"
HOME_URL="https://rockylinux.org/"
BUG_REPORT_URL="https://bugs.rockylinux.org/"
ROCKY_SUPPORT_PRODUCT="Rocky-Linux-9"
ROCKY_SUPPORT_PRODUCT_VERSION="9.0"
REDHAT_SUPPORT_PRODUCT="Rocky Linux"
REDHAT_SUPPORT_PRODUCT_VERSION="9.0"
I ran the enroll command with strace and I see this message:
openat(AT_FDCWD, {ca certs}, O_RDONLY) = -1 ENAMETOOLONG (File name too long)
Same message showing the value of {ca certs}:
openat(AT_FDCWD, "-----BEGIN CERTIFICATE-----\nMIIGZTCCBE2gAwIBAgIJANt/M5zOuwqvMA0GCSqGSIb3DQEBCwUAMH4xCzAJBgNV\nBAYTAlVTMQswCQYDVQQIEwJOQzESMBAGA1UEBxMJQ2hhcmxvdHRlMR
MwEQYDVQQK\nEwpOZXRGb3VuZHJ5MRMwEQYDVQQDEwpOZXRGb3VuZHJ5MSQwIgYJKoZIhvcNAQkB\nFhVzdXBwb3J0QG5ldGZvdW5kcnkuaW8wHhcNMjIwMjE2MTg1NTM2WhcNMzIwMjE0\nMTg1NTM2WjB+MQswCQYDVQQ
GEwJVUzELMAkGA1UECBMCTkMxEjAQBgNVBAcTCUNo\nYXJsb3R0ZTETMBEGA1UEChMKTmV0Rm91bmRyeTETMBEGA1UEAxMKTmV0Rm91bmRy\neTEkMCIGCSqGSIb3DQEJARYVc3VwcG9ydEBuZXRmb3VuZHJ5LmlvMIICIj
ANBgkq\nhkiG9w0BAQEFAAOCAg8AMIICCgKCAgEA5G1OKFJh8/L8DhaGnzSWWMfL+paiH8NC\nij4EK3DFqPsYHJs4itdIySQ/fzrCCmjtkV/VmT++rP4fBkfXPG2QzoJVUCyT5uru\nG6IAM5NsSI7H8brmwIGYtMfiny7
8q9mzmTu8hiBTqs3Czk67pCh1j70/0dz+w95U\nbC7qvSdI+GwDg8cXgJP/UNwC+bncx6Y9SQNeNnkuZjRqkEWnkRrvpfrNXyKGGFsP\nyvQ3g+TjQQ+9rB3EdNstc150aym8nnRg6YJRnHsJMQiuWRGwNAiQmk0X1gxW1c
8S\niDVqRozdOAWonJoi/uJgDTo/MvD7fUUSSrnAfIF6RenTxBkcrZ21DT4KsrXGQaXk\naiKN7obXA4zFNeQkXkX45W6Os3TLooYSAyRVtRkIxZxmm3FdbZubxbvzKqZgzeuK\n52ZTvDxDrEYBbXyiq3PcoJBvKuUoITW
DwqtqDu8jM5TEJw0eTtM/6zeCacn57xqw\nKKYBD2dh0T8SAaYxnfAyoQIbPHIZN39YPqpAm8tfp1nw2b0w0D4WuQc9bf6MotXN\ny0xwhrDkF38csiUlnp6PfHc+bw05TSD/XdQxqI2653hq14ThvNDi0pj2nCcKa1MI\n
BOYEWtXelZvC0VCUd1XC/7NdNVrFb9b+nXGbECZgPiXWaB2Dmg877NgzTBAf/9fR\nwMFHHyz952sCAwEAAaOB5TCB4jAdBgNVHQ4EFgQUDyWo7MBYe8dgvrjPPs+nwVwo\nY4IwgbIGA1UdIwSBqjCBp4AUDyWo7MBYe8dgvrjPPs+nwVwoY4KhgYOkgYAwfjEL\nMAkGA1UEBhMCVVMxCzAJBgNVBAgTAk5DMRIwEAYDVQQHEwlDaGFybG90dGUxEzAR\nBgNVBAoTCk5ldEZvdW5kcnkxEzARBgNVBAMTCk5ldEZvdW5kcnkxJDAiBgkqhkiG\n9w0B
CQEWFXN1cHBvcnRAbmV0Zm91bmRyeS5pb4IJANt/M5zOuwqvMAwGA1UdEwQF\nMAMBAf8wDQYJKoZIhvcNAQELBQADggIBAHarh7o5Lxa5Bauyu5Mt6z+FwzYe0cTw\nHYO7bWJrSj1efJpkn/L252YaMwe5tDNz0LBVu0j
NL3S4QBDRQZ5Ae6kEe4FQRXZ4\nW4ZKEJXP0BVsHXkYKzQMU6FqOQjZoEYbIBSzAQ8hzGImncM3daMG9UNeLwGzicq4\nGyMW0cRZIDJRxBZUdi6uQ3TpikyhW25g6Ft1GB/qld/bmal982KfHtBreCXRphtV\nx01arzj+bh2cd3QsC9Vgkbyyyr8YjJT/WBZlUQjxownzOUz03KIythpwkqq/424K\n8J5qv3tvkgLWYhPLnQq0CRMWKzG1PBLAS+hiqhfEEznJQoE47YWZKjRAA5HyMhzR\ndvp+1IAx4QYTydSJpjT2FvEyYTjdYgV2kV+dDBMXNSV
Eu9nC28uYf2Lc1dznMVQO\nJyiAl5fVdLic2+mgH/dKJApTeIuJr7tRPdSUUQdxx38Y6Bk5LNfIYLsuR+Xd/MlO\nQ85zeBWj/Ow+uOnsRMOY17QrkG/zdyrYgqRpHzSYE0i28ezzrTyzxI0LYdyD7dEc\nEbrP1GkUSkeQ
zHSDKWJz0KjNo74GI3bgRkJqbWDRRc1O7tZbTh3RY6RClSvR4b/t\nq48sz/fp+qy2XHTSH28hHsgbZ/c7kScnagxJcQT2Nz3B7EfWietQLsGXDA6mcQzp\nDyrLkFnV8m41\n-----END CERTIFICATE-----\n-----B
EGIN CERTIFICATE-----\nMIIF5jCCA86gAwIBAgIJANInLNdZhtUyMA0GCSqGSIb3DQEBCwUAMH4xCzAJBgNV\nBAYTAlVTMQswCQYDVQQIEwJOQzESMBAGA1UEBxMJQ2hhcmxvdHRlMRMwEQYDVQQK\nEwpOZXRGb3Vu
ZHJ5MRMwEQYDVQQDEwpOZXRGb3VuZHJ5MSQwIgYJKoZIhvcNAQkB\nFhVzdXBwb3J0QG5ldGZvdW5kcnkuaW8wHhcNMjIwMjE2MTg1NjUyWhcNMzIwMjE0\nMTg1NjUyWjB/MQswCQYDVQQGEwJVUzELMAkGA1UECBMCTkM
xEzARBgNVBAoTCk5l\ndEZvdW5kcnkxKDAmBgNVBAMTH1ppdGkgQ29udHJvbGxlciBJbnRlcm1lZGlhdGUg\nQ0ExJDAiBgkqhkiG9w0BCQEWFXN1cHBvcnRAbmV0Zm91bmRyeS5pbzCCAiIwDQYJ\nKoZIhvcNAQEBBQAD
ggIPADCCAgoCggIBAOgy5pPfcfkWuHkJY3fXE1mKbNWxL0//\nMxvKLY1Gov1odxAlNqiqXSvZd2ZuftdQqNxQgDKePL92BB+uR5rxSt7hnIANf8g1\nJFrGCpiX1KaIz07HU6khoPJHQLNrPtQl+h3UKbZPI5DxjpAckaz
9uSO16Pjqy4Xm\nArBJnJSkAeLI9xp8BWvZM1VxdsmaGV7N5oC+/czmgtvRNQ+CzGWB5uBL05MGnsuf\nFYlpIwkHoB9azS52rot0qBPoBYnLF1pjIHkVm5/M6/qikiqnNok6WGyANawnpC+T\nfMpisLWSO4NYQui8P4gM
HlVHEcL5+0+heDyAvrtSZ54ZRNVPpzAphMfV9FfNp7Jh\nOOHdisOnXeaPPbsWBZMAGMwwO+Lj6J8N9EyZ+T09LgRzQTlPycherxuEFIvGCSTp\nCC/HjGyShy8I/jjMLX5CNgbqqy7Jd3UKXrJUNCyZwjHEDo1LU28jpyj
jKHjH9HAM\nFtouoRbpGWS7HQHzrkb6YTi3TVNE15yUqLWsQz4Tc/uGDYauCjIsHT69Or4CbFwP\nQmy40qvdR+B+0h4uTzGBFVjQ41xcievdIs/tPRrvMWxOKt17yyP0TpxhyQKmX663\nTZRMfV9hBN8giEOstv8rmKc6
r0NqN0gxga29pZKpTU4Zh53gpKFdnH9oVqWKlGnF\nXbUgUmjeb1dNAgMBAAGjZjBkMB0GA1UdDgQWBBQGLSNWuzuf9P2hbEvE2JV5jrZX\nfzAfBgNVHSMEGDAWgBQPJajswFh7x2C+uM8+z6fBXChjgjASBgNVHRMBAf8
ECDAG\nAQH/AgEAMA4GA1UdDwEB/wQEAwIBhjANBgkqhkiG9w0BAQsFAAOCAgEAyKH4eAKO\nnz6G3Ry27zx5CjWRhtJqtKbbfDCNh5jXnTpaIyCxAGxRkGASw0btq9URa8h+15tP\nK2g4Q4ZYaVenqKGDn0W2rMjL2D5z
m3u5R4ZJ0Iqb48tE6NgP//6X0F0V90hWg7pI\nKkQpaEZlZ6R88qh2Vu4cduBxvtOKy0NhsNoTTdIR4qt+G7dtFhkWX2bS5oBYiX6R\n+TEswibP1SpGNvlH+Wc9Gt6jogeI+Npj1Kbxk0gtFXJeX5HhQgduanTLeBmWoQo
8\nRtY0/eyQlgafzPJngeZJ0iMFTO12I2/7efjnF8k9kJMpCDtHD4GE9t3hMsFBfg6h\nOJjTSV6y5uf20riIzxR1fFGEZqiIlqV/2x4m3aaQxfCqn8xJeZMeY9lYALhSq1F2\nmiXNVFiqzaKbWjI+aagmoTzC9uafo5Sw
1y8"..., O_RDONLY) = -1 ENAMETOOLONG (File name too long)
This could point toward the problem with processing the CSR or it may be a red herring message having to do with strace printing long filenames.
I ran the enroll command with valgrind which reveals the context in which the failure occurs.
==20982== at 0x4ACCF46: ??? (in /usr/lib64/libcrypto.so.3.0.1)
==20982== by 0x4ACFCF9: PEM_read_bio_ex (in /usr/lib64/libcrypto.so.3.0.1)
==20982== by 0x4AD0866: ??? (in /usr/lib64/libcrypto.so.3.0.1)
==20982== by 0x4AD0D62: PEM_bytes_read_bio (in /usr/lib64/libcrypto.so.3.0.1)
==20982== by 0x4AD0FC3: PEM_ASN1_read_bio (in /usr/lib64/libcrypto.so.3.0.1)
==20982== by 0x16C4D3: load_certs (engine_openssl.c:196)
==20982== by 0x16D09B: init_ssl_context (engine_openssl.c:219)
==20982== by 0x16D09B: new_openssl_ctx (engine_openssl.c:175)
==20982== by 0x134BC4: well_known_certs_cb (ziti_enroll.c:168)
==20982== by 0x135CDF: ctrl_default_cb (ziti_ctrl.c:195)
==20982== by 0x136E27: ctrl_body_cb (ziti_ctrl.c:366)
==20982== by 0x169B2C: http_message_cb (http_req.c:260)
==20982== by 0x16DA81: http_parser_execute (http_parser.c:1918)
==20982==
--20982-- memcheck GC: 1074 nodes, 576 survivors (53.6%)
--20982-- memcheck GC: 1518 new table size (stepup)
--20982-- REDIR: 0x4f7aad0 (libc.so.6:__strcpy_chk) redirected to 0x484ec80 (__strcpy_chk)
--20982-- memcheck GC: 1518 nodes, 896 survivors (59.0%)
--20982-- memcheck GC: 2146 new table size (stepup)
(20982)[ 3.339] ERROR ziti-sdk:ziti_enroll.c:227 enroll_cb() failed to enroll with controller: https://7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoun
dry.io:443 COULD_NOT_PROCESS_CSR (The supplied csr could not be processed)
(20982)[ 3.339] ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:1992 enroll_cb() enrollment failed: COULD_NOT_PROCESS_CSR(-3)
that is a red herring. OpenSSL makes several tries loading certs from a byte buffer: file, PEM, DER
James and I both found that the redhat8 build is able to run the same enroll command successfully on redhat9. When I come back to this issue I'll try to reproduce the error with a redhat9 build and the main release build updated to 0.20.2.
I can not reproduce this issue with the release binary or RedHat 8 package 0.20.4 running on RedHat 9. It seems to only present when running the new RedHat 9 build. I will try to gain access to the controller log in hopes there is a more helpful error message emitted there. The main difference between the two builds is that we're running gcc 11 on Red Hat 9 instead of gcc 10 on Red Hat 8.
[rocky@ip-172-31-4-195 ~]$ /opt/openziti/bin/ziti-edge-tunnel enroll -j ./client8.jwt -i ./client8.json
(28800)[ 0.492] ERROR ziti-sdk:ziti_enroll.c:227 enroll_cb() failed to enroll with controller: https://7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io:443 COULD_NOT_PROCESS_CSR (The supplied csr could not be processed)
(28800)[ 0.492] ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:1994 enroll_cb() enrollment failed: COULD_NOT_PROCESS_CSR(-3)
[rocky@ip-172-31-4-195 ~]$ ldd /opt/openziti/bin/ziti-edge-tunnel
linux-vdso.so.1 (0x00007fffa2dfe000)
libssl.so.3 => /lib64/libssl.so.3 (0x00007facd17d3000)
libcrypto.so.3 => /lib64/libcrypto.so.3 (0x00007facd13a7000)
libatomic.so.1 => /lib64/libatomic.so.1 (0x00007facd139e000)
libm.so.6 => /lib64/libm.so.6 (0x00007facd12c3000)
libresolv.so.2 => /lib64/libresolv.so.2 (0x00007facd12af000)
libc.so.6 => /lib64/libc.so.6 (0x00007facd10a5000)
libz.so.1 => /lib64/libz.so.1 (0x00007facd1089000)
/lib64/ld-linux-x86-64.so.2 (0x00007facd187e000)
Built on RH9 OS with this command:
cmake \
-DCMAKE_BUILD_TYPE=Release \
-DCMAKE_TOOLCHAIN_FILE=./toolchains/default.cmake \
-DBUILD_DIST_PACKAGES=ON \
-DUSE_OPENSSL=ON \
-S . \
-B ./build
cmake \
--build ./build \
--target package \
--verbose
I found that I can set env var ZITI_LOG to see more log messages.
[rocky@ip-172-31-4-195 ~]$ ZITI_LOG=6 /opt/openziti/bin/ziti-edge-tunnel enroll -j ./client8.jwt -i ./client8.json
(28846)[ 0.000] INFO ziti-sdk:ziti_enroll.c:92 ziti_enroll() Ziti C SDK version 0.30.2 @040c4dd(HEAD) starting enrollment at (2022-10-18T22:2
6:01.411)
(28846)[ 0.000] DEBUG ziti-sdk:jwt.c:111 load_jwt() filename is: ./client8.jwt
(28846)[ 0.000] DEBUG ziti-sdk:jwt.c:77 load_jwt_file() reading JWT from file: ./client8.jwt
(28846)[ 0.000] DEBUG ziti-sdk:jwt.c:104 load_jwt_file() jwt file content is:
eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJlbSI6Im90dCIsImV4cCI6MTY2NjMwNDA3MiwiaXNzIjoiaHR0cHM6Ly83Y2U3ZTQyNC02YTkyLTRmZjItOTQ1OS1lYmJiYTMyMzQ2ZmEucHJvZH
VjdGlvbi5uZXRmb3VuZHJ5LmlvOjQ0MyIsImp0aSI6ImMzZTMyMjVjLWJjMDUtNGQxYy1iM2I3LWVmODllYjVhOTJlZiIsInN1YiI6Ikp2QlFkc2l5RCJ9.dCcSVDsUqM-kTHnA0rModTM7kqjqo7NT
pDhkshvdR3cgLQzO3bYTtNV-IVPpZMDi4HdXZCd6kUSrOm5HROWYCreq8zI-_GOzljS7E2T5zWOdSvTbcmWU-tGXh7jCRQGH6sDpgxhdaOU_WORkN2P64SFTvMr1ntillE4u4shUttw8yiWs8U55LEx
NAs4AGq8Ipw1nSW-ke9s0Nta-o2sQPGsMDLOpmhKRAqxCZix2OfWJGMbgapJkco1WIL9INLUUthT8hoozr2TRb448ifMoKjvLDDqz8y1AGxNnFQVUtz7EZUtsA9Ogids4NSLsdXq3KLPhJ7m6TpPgYc
77qEZkiApRF_vD-X1RobhTKSN64j2ukNffEr9G9X_qeCkAWFpdOPcT9iErJxecdXH0MwL6X0pFfXgPqfpxcLs1XkTz7nFYxTRRNDHaaBSlYGckjYcMQYAegZXXYrGNzU7Pe8ZW-ibNnfgdcuUVM1Avf
0nR3GEx69XHg1JaBAFEvnz_S-hdtf0VlJlbtuQD9Bpw3bmlZxHDLUisaSK91B9QRwfKbHhFzvyk-1SUe7M5Sf_XbYEVJEOLoa8PkHUrSNBm4liq_39GzAVSw54t5k7TA7Z5RJ40ARgwaaYdEpFn7Im_
Cg9tdJisdn8H4qL_4dQ4xIYgPBgIw8a-ShJRMpVAXo07xwI
(28846)[ 0.000] DEBUG ziti-sdk:jwt.c:41 parse_jwt_content() ecfg->jwt_signing_input is:
eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJlbSI6Im90dCIsImV4cCI6MTY2NjMwNDA3MiwiaXNzIjoiaHR0cHM6Ly83Y2U3ZTQyNC02YTkyLTRmZjItOTQ1OS1lYmJiYTMyMzQ2ZmEucHJvZH
VjdGlvbi5uZXRmb3VuZHJ5LmlvOjQ0MyIsImp0aSI6ImMzZTMyMjVjLWJjMDUtNGQxYy1iM2I3LWVmODllYjVhOTJlZiIsInN1YiI6Ikp2QlFkc2l5RCJ9
(28846)[ 0.000] INFO ziti-sdk:ziti_ctrl.c:401 ziti_ctrl_init() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] ziti contr
oller client initialized
(28846)[ 0.000] VERBOSE ziti-sdk:ziti_ctrl.c:131 start_request() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] starting GE
T[/.well-known/est/cacerts]
(28846)[ 0.158] INFO ziti-sdk:ziti_enroll.c:41 verify_controller_jwt() verifying JWT signature
(28846)[ 0.158] DEBUG ziti-sdk:ziti_enroll.c:69 verify_controller_jwt() JWT verification succeeded!
(28846)[ 0.226] VERBOSE ziti-sdk:ziti_ctrl.c:166 ctrl_resp_cb() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] received hea
ders GET[/.well-known/est/cacerts]
(28846)[ 0.291] DEBUG ziti-sdk:ziti_enroll.c:141 well_known_certs_cb() base64_encoded_pkcs7 is: MII9zAYJKoZIhvcNAQcCoII9vTCCPbkCAQExADALBgkqhkiG9w0BBwGggj2fMIIF
# ...snipped the well-know certs chain here...
(28846)[ 0.291] INFO ziti-sdk:ziti_ctrl.c:401 ziti_ctrl_init() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] ziti controller client initialized
(28846)[ 0.291] VERBOSE ziti-sdk:ziti_ctrl.c:131 start_request() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] starting POST[/enroll?method=ott&token=c3e3225c-bc05-4d1c-b3b7-ef89eb5a92ef]
(28846)[ 0.610] VERBOSE ziti-sdk:ziti_ctrl.c:166 ctrl_resp_cb() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] received headers POST[/enroll?method=ott&token=c3e3225c-bc05-4d1c-b3b7-ef89eb5a92ef]
(28846)[ 0.610] WARN ziti-sdk:ziti_ctrl.c:88 code_to_error() unmapped error code: COULD_NOT_PROCESS_CSR
(28846)[ 0.610] ERROR ziti-sdk:ziti_enroll.c:227 enroll_cb() failed to enroll with controller: https://7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io:443 COULD_NOT_PROCESS_CSR (The supplied csr could not be processed)
(28846)[ 0.610] ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:1994 enroll_cb() enrollment failed: COULD_NOT_PROCESS_CSR(-3)
The controller process is running at the default log level, and there were no messages emitted at the time of the failed enrollment.
Steps to reproduce
build ziti-edge-tunnel on RH9
git checkout issue-514-package-for-redhat9
(cd ./.github/actions/openziti-tunnel-build-action/redhat-9/ && docker buildx build -t rh9-builder . --load ; )
docker run --rm -ti -v "${PWD}:/github/workspace" rh9-builder
run ziti-edge-tunnel enroll on RH9
cat > /tmp/client10.jwt
# paste contents of JWT, press ctrl-D to send EOF
docker run -i --rm \
-v "${PWD}/build/programs/Release/ziti-edge-tunnel:/mnt" \
-e ZITI_LOG=4 docker.io/library/rockylinux:9 \
bash -c '{
dnf install -yq libatomic \
&& /mnt/ziti-edge-tunnel enroll \
--jwt - --identity /mnt/client10.json;
}' < /tmp/client10.jwt
This issue no longer occurs after adapting RH9 builder to the new VCPKG preset.
❯ docker run -i --rm \
-v "${PWD}/build:/mnt" \
-e ZITI_LOG=4 docker.io/library/rockylinux:9 \
bash -euxc '{
dnf install -yq /mnt/ziti-edge-tunnel-0.21.4-1.x86_64.rpm \
&& /opt/openziti/bin/ziti-edge-tunnel version \
&& /opt/openziti/bin/ziti-edge-tunnel enroll \
--jwt - --identity /mnt/client10.json;
}' < /tmp/rh9.jwt
+ dnf install -yq /mnt/ziti-edge-tunnel-0.21.4-1.x86_64.rpm
Importing GPG key 0x350D275D:
Userid : "Rocky Enterprise Software Foundation - Release key 2022 <[email protected]>"
Fingerprint: 21CB 256A E16F C54C 6E65 2949 702D 426D 350D 275D
From : /etc/pki/rpm-gpg/RPM-GPG-KEY-Rocky-9
Installed:
acl-2.3.1-3.el9.x86_64 dbus-1:1.12.20-7.el9_1.x86_64
dbus-broker-28-7.el9.x86_64 dbus-common-1:1.12.20-7.el9_1.noarch
iproute-6.1.0-1.el9.x86_64 kmod-libs-28-7.el9.x86_64
libatomic-11.3.1-4.3.el9.x86_64 libbpf-2:1.0.0-2.el9.x86_64
libmnl-1.0.4-15.el9.x86_64 libseccomp-2.5.2-2.el9.x86_64 psmisc-23.4-3.el9.x86_64 systemd-252-13.el9_2.x86_64
systemd-pam-252-13.el9_2.x86_64 systemd-rpm-macros-252-13.el9_2.noarch ziti-edge-tunnel-0.21.4-1.x86_64
+ /opt/openziti/bin/ziti-edge-tunnel version
v0.21.4-19-gd0c5eff-local
+ /opt/openziti/bin/ziti-edge-tunnel enroll --jwt - --identity /mnt/client10.json
(178)[ 0.000] INFO ziti-sdk:utils.c:188 ziti_log_set_level() set log level: root=4/DEBUG (178)[ 0.000] INFO ziti-sdk:utils.c:188 ziti_log_set_level() set log level: root=4/DEBUG
(178)[ 0.000] INFO ziti-sdk:ziti_enroll.c:90 ziti_enroll() Ziti C SDK version 0.32.6 @2fc3556(HEAD) starting enrollment at (2023-06-08T20:40:50.906)
(178)[ 0.000] DEBUG ziti-sdk:jwt.c:106 load_jwt() filename is: -
(178)[ 0.000] DEBUG ziti-sdk:jwt.c:69 load_jwt_file() reading JWT from standard input
(178)[ 0.000] DEBUG ziti-sdk:jwt.c:99 load_jwt_file() jwt file content is: eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJlbSI6Im90dCIsImV4cCI6MTY4NjQyODk1OSwiaXNzIjoiaHR0cHM6Ly83Y2U3ZTQyNC02YTkyLTRmZjItOTQ1OS1lYmJiYTMyMzQ2ZmEucHJvZHVjdGlvbi5uZXRmb3VuZHJ5LmlvOjQ0MyIsImp0aSI6IjdjZTU3OWQwLTFmNTYtNDZjZC05NjcyLTM1NmUyOWJiN
zAwZCIsInN1YiI6IjVQN0haQlN5cjkifQ.H2lLBrdUoIAoocPcAgRWKXoKyxR83tKsl65UeY6VJBt3a-ZNEYdgGDgLnTa8VyGBZ3HEUNRUq8gjx-0Wtg1JcmsGCOKCV_TT6LEy18uXk_pR5cHdHLeiVYoaNDSmXDaSJCz-SDMRPZDNmyQjY-Dydt6ewryOpnkAuvlAr3GpHcdZXKAO4BmeA7EdmCj_zjQey_3bgmBdSgD-
v6s4cToCJwuuPNvVqOImHD6Kb7TZBJPnFcnInzuBsnwUBOhGEzjbGnDGejRugrelT0qb-wBOi-tzGBethZIdJDUBQiYWu1A7EXj38WnEDrrc4V4j3uLMFDtSqBpkIfXdFxeckiftBNoMzS6LudVqWcn0w8lixMNrXoJE_5Wsxkg1p8exzVDwx15NymkqzNhzff7svsrSS-HiTZL8tZk7XLPwIk38T2a9SGzLnL5bPMpgb2
DtJBYSk_i4dyrzrTe9z45-RBswJRQ8iEiI3dN90CTK5opLTTQW-9ZlcNc-zvm721o4HAkGXEjjXq01ej-KE05HG15KEEsyREEpwa_r9ioXOOvW-djFA24m70R3bchIYqr0RPR4nq39Gwfj37vGoczJnCMKtn0x5--gk-w4FQLyL3_tflNq6gCDduJL8MxMrYXatlDBDA7yNGrtX5cnQBCwj5fh29yefjuHM5FMD230NPXx
hXY
(178)[ 0.000] DEBUG ziti-sdk:jwt.c:36 parse_jwt_content() ecfg->jwt_signing_input is:
eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJlbSI6Im90dCIsImV4cCI6MTY4NjQyODk1OSwiaXNzIjoiaHR0cHM6Ly83Y2U3ZTQyNC02YTkyLTRmZjItOTQ1OS1lYmJiYTMyMzQ2ZmEucHJvZHVjdGlvbi5uZXRmb3VuZHJ5LmlvOjQ0MyIsImp0aSI6IjdjZTU3OWQwLTFmNTYtNDZjZC05NjcyLTM1NmUyOWJiN
zAwZCIsInN1YiI6IjVQN0haQlN5cjkifQ
(178)[ 0.000] DEBUG ziti-sdk:ziti_ctrl.c:408 ziti_ctrl_init() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] ziti controller client initialized
(178)[ 0.084] DEBUG ziti-sdk:ziti_enroll.c:39 verify_controller_jwt() verifying JWT signature
(178)[ 0.084] DEBUG ziti-sdk:ziti_enroll.c:67 verify_controller_jwt() JWT verification succeeded!
(178)[ 0.160] DEBUG ziti-sdk:ziti_enroll.c:157 well_known_certs_cb() CA PEM len = 21925
(178)[ 0.160] DEBUG ziti-sdk:ziti_ctrl.c:408 ziti_ctrl_init() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] ziti controller client initialized
(178)[ 0.315] DEBUG ziti-sdk:ziti_ctrl.c:325 ctrl_body_cb() ctrl[7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io] completed POST[/enroll?method=ott&token=7ce579d0-1f56-46cd-9672-356e29bb700d] in 0.142 s
(178)[ 0.315] DEBUG ziti-sdk:ziti_enroll.c:242 enroll_cb() successfully enrolled with controller https://7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io:443
This issue is recurring with the RedHat9 release RPM v0.22.5.
Aug 22 20:41:22 rocky9 ziti-edge-tunnel.sh[412]: (412)[ 0.000] INFO ziti-sdk:ziti_enroll.c:90 ziti_enroll() Ziti C SDK version 0.33.4 @27bac90(HEAD) starting enrollment at (2023-08-22T20:41:22.579)
Aug 22 20:41:22 rocky9 ziti-edge-tunnel.sh[412]: (412)[ 0.208] WARN ziti-sdk:ziti_ctrl.c:89 code_to_error() unmapped error code: COULD_NOT_PROCESS_CSR
Aug 22 20:41:22 rocky9 ziti-edge-tunnel.sh[412]: (412)[ 0.208] ERROR ziti-sdk:ziti_enroll.c:234 enroll_cb() failed to enroll with controller: https://7ce7e424-6a92-4ff2-9459-ebbba32346fa.production.netfoundry.io:443 COULD_NOT_PROCESS_CSR (The supplied csr could not be processed)
Aug 22 20:41:22 rocky9 ziti-edge-tunnel.sh[412]: (412)[ 0.208] ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:2137 enroll_cb() enrollment failed: COULD_NOT_PROCESS_CSR(-3)
Aug 22 20:41:22 rocky9 ziti-edge-tunnel.sh[408]: ERROR: failed to enroll rocky9a.jwt in /opt/openziti/etc/identities
[root@rocky9 ~]# ldd /opt/openziti/bin/ziti-edge-tunnel
linux-vdso.so.1 (0x00007ffffd5de000)
libz.so.1 => /lib64/libz.so.1 (0x00007f4ce7fb5000)
libssl.so.3 => /lib64/libssl.so.3 (0x00007f4ce7f0f000)
libcrypto.so.3 => /lib64/libcrypto.so.3 (0x00007f4ce7a00000)
libatomic.so.1 => /lib64/libatomic.so.1 (0x00007f4ce7f06000)
libm.so.6 => /lib64/libm.so.6 (0x00007f4ce7925000)
libresolv.so.2 => /lib64/libresolv.so.2 (0x00007f4ce7ef2000)
libc.so.6 => /lib64/libc.so.6 (0x00007f4ce7600000)
/lib64/ld-linux-x86-64.so.2 (0x00007f4ce7fd4000)
The statically-linked release binary doesn't have this problem on RedHat9.
Possible cause addressed in https://github.com/openziti/ziti-sdk-c/pull/551
I reproduced this with a build against shared libssl v3 on the rocky9 CPack image on the v0.22.21 tag.
I built the RPM with this branch (link to pull request), which enables overriding the TLS library with an env var.
(
cd ./.github/actions/openziti-tunnel-build-action/redhat-9/ \
&& docker buildx build --platform linux/amd64 --tag rh9-builder . --load ;
)
Then, checkout the v0.22.21 tag and run the CPack builder image for RedHat 9 with the TLS library env var set openssl.
docker run \
--rm \
--platform linux\amd64 \
--volume "${PWD}:/github/workspace" --workdir "/github/workspace" \
--env TLSUV_TLSLIB=openssl \
rh9-builder ci-linux-x64 Release
Finally, attempt enrollment on a vanilla rocky9 image. I got the same result with the almalinux/9-base image.
docker run \
--network=host --rm --platform linux/amd64 \
--volume ./build/ziti-edge-tunnel-0.22.21-1.x86_64.rpm:/tmp/ziti-edge-tunnel.rpm \
--volume /tmp/miniziti-client.jwt:/tmp/ziti-id.jwt \
--entrypoint=/bin/bash rockylinux/rockylinux:9 \
-c 'dnf install -y /tmp/ziti-edge-tunnel.rpm && ldd /usr/bin/ziti-edge-tunnel && TLSUV_DEBUG=6 ZITI_LOG=6 ziti-edge-tunnel enroll --jwt /tmp/ziti-id.jwt --identity /tmp/ziti-id.json'
(1)[ 0.020] TRACE tlsuv:http.c:420 writing request >>> POST /enroll?method=ott&token=36bdd2b4-5844-4710-ae10-3edefdaf51b0 HTTP/1.1
Content-Length: 0
Content-Type: application/json
Host: miniziti-controller.192.168.49.2.sslip.io
Connection: keep-alive
Accept: application/json
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[73], larg[0]
(1)[ 0.020] TRACE tlsuv:tls_link.c:243 io buffering 251 bytes
(1)[ 0.020] TRACE tlsuv:tls_link.c:223 flushing 251 bytes
(1)[ 0.020] VERBOSE tlsuv:http.c:428 sending request[/enroll?method=ott&token=36bdd2b4-5844-4710-ae10-3edefdaf51b0] body
(1)[ 0.020] VERBOSE tlsuv:http.c:292 request write completed: 0
(1)[ 0.020] TRACE tlsuv:tls_link.c:75 TLS(0x32d05c0)[2]: 144
(1)[ 0.020] TRACE tlsuv:tls_link.c:118 TLS(0x32d05c0) processing 144 bytes
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] TRACE tlsuv:tls_link.c:281 read 5/144 bytes
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] TRACE tlsuv:tls_link.c:281 read 139/139 bytes
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] VERBOSE tlsuv:tls_link.c:132 TLS(0x32d05c0) produced 0 application byte (rc=-3)
(1)[ 0.020] TRACE tlsuv:tls_link.c:75 TLS(0x32d05c0)[2]: 472
(1)[ 0.020] TRACE tlsuv:tls_link.c:118 TLS(0x32d05c0) processing 472 bytes
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] TRACE tlsuv:tls_link.c:281 read 5/472 bytes
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] TRACE tlsuv:tls_link.c:281 read 467/467 bytes
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] WARN tlsuv:engine.c:1188 unknown cmd: BIO[0x32ce6f0], cmd[76], larg[0]
(1)[ 0.020] VERBOSE tlsuv:tls_link.c:132 TLS(0x32d05c0) produced 450 application byte (rc=0)
(1)[ 0.020] TRACE tlsuv:http_req.c:77 processing 450 bytes
HTTP/1.1 400 Bad Request
Content-Type: application/json
Server: ziti-controller/v0.32.2
Ziti-Instance-Id: clsntpi6900000dcb22v71a1o
Date: Thu, 15 Feb 2024 23:12:06 GMT
Content-Length: 254
{"error":{"cause":{"code":"UNHANDLED","message":"csrPem must not be null or empty"},"code":"COULD_NOT_PROCESS_CSR","message":"The supplied csr could not be processed","requestId":"5GxkqPOXN"},"meta":{"apiEnrollmentVersion":"0.0.1","apiVersion":"0.0.1"}}
(1)[ 0.020] VERBOSE tlsuv:http_req.c:359 status = 400 Bad Request
(1)[ 0.020] VERBOSE tlsuv:http_req.c:318 headers complete
(1)[ 0.020] VERBOSE ziti-sdk:ziti_ctrl.c:176 ctrl_resp_cb() ctrl[miniziti-controller.192.168.49.2.sslip.io] received headers POST[/enroll?method=ott&token=36bdd2b4-5844-4710-ae10-3edefdaf51b0]
(1)[ 0.020] VERBOSE tlsuv:http_req.c:369 message complete
(1)[ 0.020] WARN ziti-sdk:ziti_ctrl.c:89 code_to_error() unmapped error code: COULD_NOT_PROCESS_CSR
(1)[ 0.020] ERROR ziti-sdk:ziti_enroll.c:233 enroll_cb() failed to enroll with controller: https://miniziti-controller.192.168.49.2.sslip.io:443 COULD_NOT_PROCESS_CSR (The supplied csr could not be processed)
(1)[ 0.020] ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:2141 enroll_cb() enrollment failed: COULD_NOT_PROCESS_CSR(-3)
(1)[ 0.020] VERBOSE tlsuv:http_req.c:82 processed 450 of 450
(1)[ 0.020] VERBOSE tlsuv:http.c:389 no more requests, scheduling idle(0) close
(1)[ 0.020] VERBOSE tlsuv:http.c:374 idle timeout triggered
(1)[ 0.020] VERBOSE tlsuv:http.c:365 closing connection
(1)[ 0.020] TRACE tlsuv:tls_link.c:185 closing TLS link
@scareything I reproduced this with latest ZET 0.22.21 built w/ OpenSSL on Rocky 9 and Alma 9.
shared object links from the OpenSSL test build I created by running the RedHat9 CPack builder image with override TLS lib build param:
linux-vdso.so.1 (0x00007fffb5da1000)
libz.so.1 => /lib64/libz.so.1 (0x00007b6e537de000)
libssl.so.3 => /lib64/libssl.so.3 (0x00007b6e53738000)
libcrypto.so.3 => /lib64/libcrypto.so.3 (0x00007b6e53306000)
libatomic.so.1 => /lib64/libatomic.so.1 (0x00007b6e532fd000)
libm.so.6 => /lib64/libm.so.6 (0x00007b6e53222000)
libresolv.so.2 => /lib64/libresolv.so.2 (0x00007b6e5320e000)
libc.so.6 => /lib64/libc.so.6 (0x00007b6e53003000)
/lib64/ld-linux-x86-64.so.2 (0x00007b6e537fd000)
I found these versions of OpenSSL to be available for the shown container images from their respective, default repositories.
oraclelinux:7:
oraclelinux:8: OpenSSL 1.1.1k FIPS 25 Mar 2021
oraclelinux:9: OpenSSL 3.0.7 1 Nov 2022 (Library: OpenSSL 3.0.7 1 Nov 2022)
debian:buster: OpenSSL 1.1.1n 15 Mar 2022
debian:bullseye: OpenSSL 1.1.1w 11 Sep 2023
debian:bookworm: OpenSSL 3.0.11 19 Sep 2023 (Library: OpenSSL 3.0.11 19 Sep 2023)
registry.access.redhat.com/ubi8/ubi: OpenSSL 1.1.1k FIPS 25 Mar 2021
registry.access.redhat.com/ubi9/ubi: OpenSSL 3.0.7 1 Nov 2022 (Library: OpenSSL 3.0.7 1 Nov 2022)
ubuntu:bionic: OpenSSL 1.1.1 11 Sep 2018
ubuntu:focal: OpenSSL 1.1.1f 31 Mar 2020
ubuntu:jammy: OpenSSL 3.0.2 15 Mar 2022 (Library: OpenSSL 3.0.2 15 Mar 2022)
quay.io/centos/centos:7:
fedora:34: OpenSSL 1.1.1n FIPS 15 Mar 2022
fedora:35: OpenSSL 1.1.1q FIPS 5 Jul 2022
fedora:36: OpenSSL 3.0.8 7 Feb 2023 (Library: OpenSSL 3.0.8 7 Feb 2023)
fedora:37: OpenSSL 3.0.9 30 May 2023 (Library: OpenSSL 3.0.9 30 May 2023)
fedora:38: OpenSSL 3.0.9 30 May 2023 (Library: OpenSSL 3.0.9 30 May 2023)
fedora:39: OpenSSL 3.1.1 30 May 2023 (Library: OpenSSL 3.1.1 30 May 2023)
rockylinux/rockylinux:8: OpenSSL 1.1.1k FIPS 25 Mar 2021
rockylinux/rockylinux:9: OpenSSL 3.0.7 1 Nov 2022 (Library: OpenSSL 3.0.7 1 Nov 2022)
almalinux/8-base: OpenSSL 1.1.1k FIPS 25 Mar 2021
almalinux/9-base: OpenSSL 3.0.7 1 Nov 2022 (Library: OpenSSL 3.0.7 1 Nov 2022)
gcc:7: OpenSSL 1.1.1n 15 Mar 2022 (Library: OpenSSL 1.1.1d 10 Sep 2019)
gcc:8: OpenSSL 1.1.1n 15 Mar 2022
gcc:9: OpenSSL 1.1.1w 11 Sep 2023
gcc:10: OpenSSL 1.1.1w 11 Sep 2023
gcc:11: OpenSSL 1.1.1w 11 Sep 2023
gcc:12: OpenSSL 3.0.11 19 Sep 2023 (Library: OpenSSL 3.0.11 19 Sep 2023)
gcc:13: OpenSSL 3.0.11 19 Sep 2023 (Library: OpenSSL 3.0.11 19 Sep 2023)