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
