OpenSSL SSL_CTX_set_default_verify_paths Slow

[Jay Foster]

While migrating some applications from OpenSSL 1.0.2 (and 1.1.1) to 
3.0.0, I have noticed that the SSL_CTX_set_default_verify_paths() 
function is much slower in 3.0.0.  In 1.0.0 it would take about 0.1 
seconds and in 3.0.0 it takes over 3 seconds.

strace indicates that the extra time is during the actual reading of the 
cert.pem file.

OpenSSL 1.0.2u:
1583  17:41:43.233288 getuid32()        = 0
1583  17:41:43.234439 geteuid32()       = 0
1583  17:41:43.235379 getgid32()        = 0
1583  17:41:43.236314 getegid32()       = 0
1583  17:41:43.237285 open("/usr/local/ssl/cert.pem", 
O_RDONLY|O_LARGEFILE) = 4
1583  17:41:43.238790 fstat64(4, {st_mode=S_IFREG|0666, st_size=79902, 
...}) = 0
1583  17:41:43.241239 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f38000
1583  17:41:43.242257 read(4, "# Version: 1.51\n-----BEGIN CERTI"..., 
4096) = 4096
1583  17:41:43.244713 read(4, "NXozS7Gas44XRrIsQxzgHVGzbjHjhMM5"..., 
4096) = 4096
1583  17:41:43.249735 read(4, "hT37ha88HQfqDjrw43bAuEbFrskLMmrz"..., 
4096) = 4096
1583  17:41:43.258402 read(4, "vT0Lwdd8KkMaOIG+YD/is\nI19wKTakyY"..., 
4096) = 4096
1583  17:41:43.266628 read(4, "QQGEwJVUzEXMBUGA1UEChMOVmVyaVNpZ"..., 
4096) = 4096
1583  17:41:43.272394 read(4, "hG5QbutC+5yqHLkP88Oe\nLe3hwcyV07e"..., 
4096) = 4096
1583  17:41:43.280053 read(4, "wA3ekEzeOEz4vMQGn+H\nLL729fdC4uW/"..., 
4096) = 4096
1583  17:41:43.286542 read(4, "M48vCR85mLK4b19p71XZQvk/iXttmkQ3"..., 
4096) = 4096
1583  17:41:43.291246 read(4, "HdWdAgMBAAGjQjBA\nMA8GA1UdEwEB/wQ"..., 
4096) = 4096
1583  17:41:43.297614 read(4, "Lpyo7RJlbmr2EkRT\ncDCVw5wrWCs9CHR"..., 
4096) = 4096
1583  17:41:43.303533 read(4, "9IVVO5EFdkKrqeKM+2x\nLXY2JtwE65/3"..., 
4096) = 4096
1583  17:41:43.310932 read(4, "F8R+GuqSVzRmZTRouNjWwl2tVZi4Ut0\n"..., 
4096) = 4096
1583  17:41:43.316617 read(4, "WRJ2p\nmj6q1WZmAT7qSeaiNbz69t2Vjp"..., 
4096) = 4096
1583  17:41:43.322393 read(4, "R5B3LjiKY0QP6x93SGVvdh2azrsw\n/FQ"..., 
4096) = 4096
1583  17:41:43.329364 read(4, "TE1MDYzMDAwMDAwMFoXDTI1MDYyOTIzN"..., 
4096) = 4096
1583  17:41:43.334562 read(4, "oXkJKtv3\nL7IezMdeatiDh6GX70k1Pnc"..., 
4096) = 4096
1583  17:41:43.341086 read(4, "CAQ8AMIIBCgKCAQEA4jvhEXLeqKTTo1e"..., 
4096) = 4096
1583  17:41:43.347563 read(4, "gQ2VydGlmaWNhdGlvbiBBdXRob3JpdHk"..., 
4096) = 4096
1583  17:41:43.352496 read(4, "wQFMAMB\nAf8wDgYDVR0PAQH/BAQDAgGG"..., 
4096) = 4096
1583  17:41:43.359379 read(4, "Mk7BPZ7hm/ELNKjD+Jo2FR3qyH\nB5T0Y"..., 
4096) = 2078
1583  17:41:43.363656 read(4, "", 4096) = 0
1583  17:41:43.364918 close(4)          = 0
1583  17:41:43.365884 munmap(0xb6f38000, 4096) = 0
1583  17:41:43.371532 getuid32()        = 0
1583  17:41:43.372463 geteuid32()       = 0
1583  17:41:43.373396 getgid32()        = 0
1583  17:41:43.374531 getegid32()       = 0
1583  17:41:43.375540 timer_delete(0x1) = 0

OpenSSL 3.0.0:
1580  17:19:03.601282 getuid32()        = 0
1580  17:19:03.602289 geteuid32()       = 0
1580  17:19:03.603231 getgid32()        = 0
1580  17:19:03.604166 getegid32()       = 0
1580  17:19:03.605141 open("/usr/lib/ssl-3/cert.pem", 
O_RDONLY|O_LARGEFILE) = 4
1580  17:19:03.606731 fstat64(4, {st_mode=S_IFREG|0666, st_size=79902, 
...}) = 0
1580  17:19:03.609420 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6ff1000
1580  17:19:03.610449 read(4, "# Version: 1.51\n-----BEGIN CERTI"..., 
4096) = 4096
1580  17:19:03.612808 read(4, "NXozS7Gas44XRrIsQxzgHVGzbjHjhMM5"..., 
4096) = 4096
1580  17:19:03.713691 read(4, "hT37ha88HQfqDjrw43bAuEbFrskLMmrz"..., 
4096) = 4096
1580  17:19:03.906236 read(4, "vT0Lwdd8KkMaOIG+YD/is\nI19wKTakyY"..., 
4096) = 4096
1580  17:19:04.098848 read(4, "QQGEwJVUzEXMBUGA1UEChMOVmVyaVNpZ"..., 
4096) = 4096
1580  17:19:04.197974 read(4, "hG5QbutC+5yqHLkP88Oe\nLe3hwcyV07e"..., 
4096) = 4096
1580  17:19:04.344133 read(4, "wA3ekEzeOEz4vMQGn+H\nLL729fdC4uW/"..., 
4096) = 4096
1580  17:19:04.490050 read(4, "M48vCR85mLK4b19p71XZQvk/iXttmkQ3"..., 
4096) = 4096
1580  17:19:04.589137 read(4, "HdWdAgMBAAGjQjBA\nMA8GA1UdEwEB/wQ"..., 
4096) = 4096
1580  17:19:04.736698 read(4, "Lpyo7RJlbmr2EkRT\ncDCVw5wrWCs9CHR"..., 
4096) = 4096
1580  17:19:04.836338 read(4, "9IVVO5EFdkKrqeKM+2x\nLXY2JtwE65/3"..., 
4096) = 4096
1580  17:19:04.985568 read(4, "F8R+GuqSVzRmZTRouNjWwl2tVZi4Ut0\n"..., 
4096) = 4096
1580  17:19:05.087120 read(4, "WRJ2p\nmj6q1WZmAT7qSeaiNbz69t2Vjp"..., 
4096) = 4096
1580  17:19:05.189130 read(4, "R5B3LjiKY0QP6x93SGVvdh2azrsw\n/FQ"..., 
4096) = 4096
1580  17:19:05.343106 read(4, "TE1MDYzMDAwMDAwMFoXDTI1MDYyOTIzN"..., 
4096) = 4096
1580  17:19:05.441340 read(4, "oXkJKtv3\nL7IezMdeatiDh6GX70k1Pnc"..., 
4096) = 4096
1580  17:19:05.588597 read(4, "CAQ8AMIIBCgKCAQEA4jvhEXLeqKTTo1e"..., 
4096) = 4096
1580  17:19:05.736050 read(4, "gQ2VydGlmaWNhdGlvbiBBdXRob3JpdHk"..., 
4096) = 4096
1580  17:19:05.896427 read(4, "wQFMAMB\nAf8wDgYDVR0PAQH/BAQDAgGG"..., 
4096) = 4096
1580  17:19:06.277284 read(4, "Mk7BPZ7hm/ELNKjD+Jo2FR3qyH\nB5T0Y"..., 
4096) = 2078
1580  17:19:06.473966 read(4, "", 4096) = 0
1580  17:19:06.475169 close(4)          = 0
1580  17:19:06.476206 munmap(0xb6ff1000, 4096) = 0
1580  17:19:06.492602 getuid32()        = 0
1580  17:19:06.493604 geteuid32()       = 0
1580  17:19:06.494605 getgid32()        = 0
1580  17:19:06.495607 getegid32()       = 0
1580  17:19:06.496665 getuid32()        = 0
1580  17:19:06.497666 geteuid32()       = 0
1580  17:19:06.508460 getgid32()        = 0
1580  17:19:06.509462 getegid32()       = 0
1580  17:19:06.510544 timer_delete(0x1) = 0


Why so slow?

Jay