java - Tomcat/合流 : very long TLS handshake at start

Question

我在 Ubuntu 16.04 上运行 Confluence。它通过 HTTP:8090 和 HTTPS:8443 运行良好。证书来自 Let's Encrypt。来自浏览器的连接以及 curl -iv https://domain.io:8443 或 openssl s_client -connect domain.io:8443 -msg 也工作正常。

但是，在启动 Tomcat 服务器后，需要很长时间(几分钟)才能进行 TLS 握手。

这是 openssl 输出:

# strace -o outputfile.txt -f -tt openssl s_client -connect domain.io:8443 -msg
CONNECTED(00000003)
>>> TLS 1.2  [length 0005]
    16 03 01 01 2c
>>> TLS 1.2 Handshake [length 012c], ClientHello
    01 00 01 28 03 03 cc d6 05 e6 2a f3 33 39 fe 5d
    ce 33 e9 21 df 03 0b f4 3a b4 54 02 d2 d9 e9 68
    b3 33 d7 7d 8e 54 00 00 aa c0 30 c0 2c 33 28 c0
    24 c0 14 c0 0a 00 a5 00 a3 00 a1 00 9f 00 6b 00
    6a 00 69 00 68 00 39 00 38 00 37 00 36 00 88 00
    87 00 86 00 85 c0 32 c0 2e c0 2a c0 26 c0 0f c0
    05 33 9d 33 3d 00 35 00 84 c0 2f c0 2b c0 27 c0
    23 c0 13 c0 09 00 a4 00 a2 00 a0 00 9e 00 67 00
    40 00 3f 00 3e 00 33 00 32 00 31 00 30 00 9a 00
    99 00 98 00 97 00 45 00 44 00 43 00 42 c0 31 c0
    2d 33 29 c0 25 c0 0e c0 04 33 9c 00 3c 00 2f 00
    96 00 41 c0 11 c0 07 c0 0c c0 02 00 33 00 04 c0
    12 c0 08 00 16 00 13 00 10 00 0d 33 0d c0 03 00
    0a 00 ff 01 00 00 55 00 0b 00 04 03 00 01 02 00
    0a 00 1c 33 1a 00 17 00 19 00 1c 00 1b 00 33 00
    1a 00 16 00 0e 00 0d 00 0b 00 0c 00 09 00 0a 00
    23 00 00 00 0d 00 20 00 1e 06 01 06 02 06 03 05
    01 05 02 33 03 04 01 04 02 04 03 03 01 03 02 03
    03 02 01 02 02 02 03 00 0f 00 01 01

这是到那时为止的 strace 输出:

12432 18:37:50.784832 execve("/usr/bin/openssl", ["openssl", "s_client", "-connect", "domain.io:8443", "-msg"], [/* 17 vars */]) = 0
12432 18:37:50.785956 brk(NULL)         = 0xe9d000
12432 18:37:50.786920 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.787529 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.787670 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.787814 fstat(3, {st_mode=S_IFREG|0644, st_size=34747, ...}) = 0
12432 18:37:50.787932 mmap(NULL, 34747, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fc6f3ddc000
12432 18:37:50.788056 close(3)          = 0
12432 18:37:50.788136 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.788245 open("/lib/x86_64-linux-gnu/libssl.so.1.0.0", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.788339 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320^\1\0\0\0\0\0"..., 832) = 832
12432 18:37:50.788432 fstat(3, {st_mode=S_IFREG|0644, st_size=428384, ...}) = 0
12432 18:37:50.788509 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc6f3ddb000
12432 18:37:50.788930 mmap(NULL, 2523600, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc6f3957000
12432 18:37:50.789114 mprotect(0x7fc6f39b5000, 2097152, PROT_NONE) = 0
12432 18:37:50.789271 mmap(0x7fc6f3bb5000, 45056, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x5e000) = 0x7fc6f3bb5000
12432 18:37:50.789494 close(3)          = 0
12432 18:37:50.789627 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.789743 open("/lib/x86_64-linux-gnu/libcrypto.so.1.0.0", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.789857 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\36\6\0\0\0\0\0"..., 832) = 832
12432 18:37:50.790026 fstat(3, {st_mode=S_IFREG|0644, st_size=2361856, ...}) = 0
12432 18:37:50.790101 mmap(NULL, 4471680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc6f3513000
12432 18:37:50.790197 mprotect(0x7fc6f372d000, 2093056, PROT_NONE) = 0
12432 18:37:50.790347 mmap(0x7fc6f392c000, 163840, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x219000) = 0x7fc6f392c000
12432 18:37:50.790471 mmap(0x7fc6f3954000, 11136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fc6f3954000
12432 18:37:50.790624 close(3)          = 0
12432 18:37:50.790844 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.790938 open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.791013 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\t\2\0\0\0\0\0"..., 832) = 832
12432 18:37:50.791100 fstat(3, {st_mode=S_IFREG|0755, st_size=1868984, ...}) = 0
12432 18:37:50.791171 mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc6f3149000
12432 18:37:50.791282 mprotect(0x7fc6f3309000, 2097152, PROT_NONE) = 0
12432 18:37:50.791358 mmap(0x7fc6f3509000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1c0000) = 0x7fc6f3509000
12432 18:37:50.791449 mmap(0x7fc6f350f000, 14752, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fc6f350f000
12432 18:37:50.791580 close(3)          = 0
12432 18:37:50.792338 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.793048 open("/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.793217 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\r\0\0\0\0\0\0"..., 832) = 832
12432 18:37:50.793302 fstat(3, {st_mode=S_IFREG|0644, st_size=14608, ...}) = 0
12432 18:37:50.793373 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc6f3dda000
12432 18:37:50.793492 mmap(NULL, 2109680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc6f2f45000
12432 18:37:50.793639 mprotect(0x7fc6f2f48000, 2093056, PROT_NONE) = 0
12432 18:37:50.793885 mmap(0x7fc6f3147000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fc6f3147000
12432 18:37:50.794220 close(3)          = 0
12432 18:37:50.794573 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc6f3dd9000
12432 18:37:50.794670 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc6f3dd8000
12432 18:37:50.794753 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc6f3dd7000
12432 18:37:50.794858 arch_prctl(ARCH_SET_FS, 0x7fc6f3dd8700) = 0
12432 18:37:50.795171 mprotect(0x7fc6f3509000, 16384, PROT_READ) = 0
12432 18:37:50.795279 mprotect(0x7fc6f3147000, 4096, PROT_READ) = 0
12432 18:37:50.796859 mprotect(0x7fc6f392c000, 114688, PROT_READ) = 0
12432 18:37:50.797329 mprotect(0x7fc6f3bb5000, 16384, PROT_READ) = 0
12432 18:37:50.797843 mprotect(0x682000, 4096, PROT_READ) = 0
12432 18:37:50.797964 mprotect(0x7fc6f3de5000, 4096, PROT_READ) = 0
12432 18:37:50.798043 munmap(0x7fc6f3ddc000, 34747) = 0
12432 18:37:50.798606 brk(NULL)         = 0xe9d000
12432 18:37:50.798677 brk(0xebe000)     = 0xebe000
12432 18:37:50.799562 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7fc6f317e4b0}, {SIG_DFL, [], 0}, 8) = 0
12432 18:37:50.811923 open("/usr/lib/ssl/openssl.cnf", O_RDONLY) = 3
12432 18:37:50.812154 fstat(3, {st_mode=S_IFREG|0644, st_size=10835, ...}) = 0
12432 18:37:50.812297 read(3, "#\n# OpenSSL example configuratio"..., 4096) = 4096
12432 18:37:50.812531 read(3, "Netscape crash on BMPStrings or "..., 4096) = 4096
12432 18:37:50.812842 read(3, " this to avoid interpreting an e"..., 4096) = 2643
12432 18:37:50.813228 read(3, "", 4096) = 0
12432 18:37:50.813305 close(3)          = 0
12432 18:37:50.813398 sysinfo({uptime=344186, loads=[48512, 15520, 9856], totalram=8172093440, freeram=2351210496, sharedram=1317388288, bufferram=179171328, totalswap=0, freeswap=0, procs=338, totalhigh=0, freehigh=0, mem_unit=1}) = 0
12432 18:37:50.814123 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7fc6f317e4b0}, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7fc6f317e4b0}, 8) = 0
12432 18:37:50.814360 brk(0xedf000)     = 0xedf000
12432 18:37:50.815294 getuid()          = 0
12432 18:37:50.815461 geteuid()         = 0
12432 18:37:50.815541 getgid()          = 0
12432 18:37:50.815602 getegid()         = 0
12432 18:37:50.815655 getuid()          = 0
12432 18:37:50.815795 geteuid()         = 0
12432 18:37:50.815858 getgid()          = 0
12432 18:37:50.815932 getegid()         = 0
12432 18:37:50.816038 stat("/root/.rnd", {st_mode=S_IFREG|0600, st_size=1024, ...}) = 0
12432 18:37:50.816213 open("/root/.rnd", O_RDONLY) = 3
12432 18:37:50.816320 fstat(3, {st_mode=S_IFREG|0600, st_size=1024, ...}) = 0
12432 18:37:50.816404 read(3, "\205\266ko\266\247g\304>\354eFU\25\342\2207R\361\vv\321\206\217\2\351\3520\211Z\22a"..., 4096) = 1024
12432 18:37:50.817225 read(3, "", 4096) = 0
12432 18:37:50.817289 close(3)          = 0
12432 18:37:50.817635 getpid()          = 12432
12432 18:37:50.817915 open("/dev/urandom", O_RDONLY|O_NOCTTY|O_NONBLOCK) = 3
12432 18:37:50.817996 fstat(3, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
12432 18:37:50.818060 poll([{fd=3, events=POLLIN}], 1, 10) = 1 ([{fd=3, revents=POLLIN}])
12432 18:37:50.818127 read(3, "\332\26\3509\255x\331\304;\16J\232b\2012\352'.\236N\322\326\253']j\370\301\346\340\5\315", 32) = 32
12432 18:37:50.818218 close(3)          = 0
12432 18:37:50.818284 getuid()          = 0
12432 18:37:50.818444 open("/usr/lib/ssl/cert.pem", O_RDONLY) = -1 ENOENT (No such file or directory)
12432 18:37:50.818660 open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.818841 fstat(3, {st_mode=S_IFREG|0644, st_size=242, ...}) = 0
12432 18:37:50.819179 read(3, "# Dynamic resolv.conf(5) file fo"..., 4096) = 242
12432 18:37:50.819264 read(3, "", 4096) = 0
12432 18:37:50.819320 close(3)          = 0
12432 18:37:50.819383 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=242, ...}) = 0
12432 18:37:50.819457 open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.819540 fstat(3, {st_mode=S_IFREG|0644, st_size=242, ...}) = 0
12432 18:37:50.819601 read(3, "# Dynamic resolv.conf(5) file fo"..., 4096) = 242
12432 18:37:50.819684 read(3, "", 4096) = 0
12432 18:37:50.819803 close(3)          = 0
12432 18:37:50.819881 socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
12432 18:37:50.819963 connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
12432 18:37:50.820080 close(3)          = 0
12432 18:37:50.820172 socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
12432 18:37:50.820318 connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
12432 18:37:50.820394 close(3)          = 0
12432 18:37:50.820464 open("/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.820590 fstat(3, {st_mode=S_IFREG|0644, st_size=488, ...}) = 0
12432 18:37:50.820655 read(3, "# /etc/nsswitch.conf\n#\n# Example"..., 4096) = 488
12432 18:37:50.820739 read(3, "", 4096) = 0
12432 18:37:50.820794 close(3)          = 0
12432 18:37:50.820871 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.820938 fstat(3, {st_mode=S_IFREG|0644, st_size=34747, ...}) = 0
12432 18:37:50.821092 mmap(NULL, 34747, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fc6f3ddc000
12432 18:37:50.821168 close(3)          = 0
12432 18:37:50.821239 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.821331 open("/lib/x86_64-linux-gnu/libnss_dns.so.2", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.821470 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\17\0\0\0\0\0\0"..., 832) = 832
12432 18:37:50.821579 fstat(3, {st_mode=S_IFREG|0644, st_size=27000, ...}) = 0
12432 18:37:50.821644 mmap(NULL, 2121944, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc6f2d3e000
12432 18:37:50.821763 mprotect(0x7fc6f2d43000, 2097152, PROT_NONE) = 0
12432 18:37:50.821874 mmap(0x7fc6f2f43000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x5000) = 0x7fc6f2f43000
12432 18:37:50.822648 close(3)          = 0
12432 18:37:50.822841 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
12432 18:37:50.823136 open("/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.823233 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P9\0\0\0\0\0\0"..., 832) = 832
12432 18:37:50.823687 fstat(3, {st_mode=S_IFREG|0644, st_size=101200, ...}) = 0
12432 18:37:50.823870 mmap(NULL, 2206280, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc6f2b23000
12432 18:37:50.824015 mprotect(0x7fc6f2b3a000, 2097152, PROT_NONE) = 0
12432 18:37:50.824359 mmap(0x7fc6f2d3a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17000) = 0x7fc6f2d3a000
12432 18:37:50.824631 mmap(0x7fc6f2d3c000, 6728, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fc6f2d3c000
12432 18:37:50.824732 close(3)          = 0
12432 18:37:50.824884 mprotect(0x7fc6f2d3a000, 4096, PROT_READ) = 0
12432 18:37:50.824998 mprotect(0x7fc6f2f43000, 4096, PROT_READ) = 0
12432 18:37:50.825064 munmap(0x7fc6f3ddc000, 34747) = 0
12432 18:37:50.825186 open("/etc/host.conf", O_RDONLY|O_CLOEXEC) = 3
12432 18:37:50.825297 fstat(3, {st_mode=S_IFREG|0644, st_size=103, ...}) = 0
12432 18:37:50.825379 read(3, "# The \"order\" line is only used "..., 4096) = 103
12432 18:37:50.825467 read(3, "", 4096) = 0
12432 18:37:50.825524 close(3)          = 0
12432 18:37:50.825658 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=242, ...}) = 0
12432 18:37:50.825753 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3
12432 18:37:50.825849 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("213.186.33.99")}, 16) = 0
12432 18:37:50.826029 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
12432 18:37:50.826139 sendto(3, "\307\220\1\0\0\1\0\0\0\0\0\0\6domain\2io\0\0\1\0\1", 27, MSG_NOSIGNAL, NULL, 0) = 27
12432 18:37:50.826313 poll([{fd=3, events=POLLIN}], 1, 5000) = 1 ([{fd=3, revents=POLLIN}])
12432 18:37:50.826766 ioctl(3, FIONREAD, [43]) = 0
12432 18:37:50.826870 recvfrom(3, "\307\220\201\200\0\1\0\1\0\0\0\0\6domain\2io\0\0\1\0\1\300\f\0\1\0"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("213.186.33.99")}, [16]) = 43
12432 18:37:50.827044 close(3)          = 0
12432 18:37:50.827144 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
12432 18:37:50.827228 setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
12432 18:37:50.827585 connect(3, {sa_family=AF_INET, sin_port=htons(8443), sin_addr=inet_addr("1.1.1.1")}, 16) = 0
12432 18:37:50.827909 fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0
12432 18:37:50.827996 write(1, "CONNECTED(00000003)\n", 20) = 20
12432 18:37:50.828121 select(4, [3], [3], NULL, NULL) = 1 (out [3])
12432 18:37:50.828331 write(3, "\26\3\1\1,\1\0\1(\3\3\223\25\210\2665`]KrPO\4YwK!$\16\303k\214"..., 305) = 305
12432 18:37:50.828465 write(1, ">>> TLS 1.2  [length 0005]\n", 27) = 27
12432 18:37:50.828567 write(1, "    16 03 01 01 2c\n", 19) = 19
12432 18:37:50.828648 write(1, ">>> TLS 1.2 Handshake [length 01"..., 49) = 49
12432 18:37:50.828733 write(1, "    01 00 01 28 03 03 93 15 88 b"..., 52) = 52
12432 18:37:50.828819 write(1, "    4f 04 59 77 4b 21 24 0e c3 6"..., 52) = 52
12432 18:37:50.828905 write(1, "    09 18 0b fb a2 e7 00 00 aa c"..., 52) = 52
12432 18:37:50.829003 write(1, "    24 c0 14 c0 0a 00 a5 00 a3 0"..., 52) = 52
12432 18:37:50.829088 write(1, "    6a 00 69 00 68 00 39 00 38 0"..., 52) = 52
12432 18:37:50.829171 write(1, "    87 00 86 00 85 c0 32 c0 2e c"..., 52) = 52
12432 18:37:50.829253 write(1, "    05 00 9d 00 3d 00 35 00 84 c"..., 52) = 52
12432 18:37:50.829341 write(1, "    23 c0 13 c0 09 00 a4 00 a2 0"..., 52) = 52
12432 18:37:50.829417 write(1, "    40 00 3f 00 3e 00 33 00 32 0"..., 52) = 52
12432 18:37:50.829494 write(1, "    99 00 98 00 97 00 45 00 44 0"..., 52) = 52
12432 18:37:50.829570 write(1, "    2d c0 29 c0 25 c0 0e c0 04 0"..., 52) = 52
12432 18:37:50.829646 write(1, "    96 00 41 c0 11 c0 07 c0 0c c"..., 52) = 52
12432 18:37:50.829722 write(1, "    12 c0 08 00 16 00 13 00 10 0"..., 52) = 52
12432 18:37:50.829798 write(1, "    0a 00 ff 01 00 00 55 00 0b 0"..., 52) = 52
12432 18:37:50.829874 write(1, "    0a 00 1c 00 1a 00 17 00 19 0"..., 52) = 52
12432 18:37:50.829950 write(1, "    1a 00 16 00 0e 00 0d 00 0b 0"..., 52) = 52
12432 18:37:50.830026 write(1, "    23 00 00 00 0d 00 20 00 1e 0"..., 52) = 52
12432 18:37:50.830102 write(1, "    01 05 02 05 03 04 01 04 02 0"..., 52) = 52
12432 18:37:50.830178 write(1, "    03 02 01 02 02 02 03 00 0f 0"..., 40) = 40
12432 18:37:50.830245 read(3,

然后，在这里卡了几分钟，直到握手成功完成。

来自 openssl:

<<< ??? [length 0005]
    16 03 03 0b 4d
<<< TLS 1.2 Handshake [length 0051], ServerHello
    02 00 00 4d 03 03 5a 76 49 73 24 d2 ab 80 ca a0
    ec 96 08 85 0e af 98 84 cd 62 43 ce 85 f9 63 51
    dd 06 a0 b0 45 85 20 5a 76 49 73 93 9b 85 41 79
    99 86 0d ca dd d5 71 76 3d 08 1b e7 96 2d 37 75
    11 e8 3e 0c 10 01 85 c0 30 00 00 05 ff 01 00 01
    00
<<< TLS 1.2 Handshake [length 09ab], Certificate
    0b 00 09 a7 00 09 a4 00 05 08 30 82 05 04 30 82
    03 ec a0 85 02 01 85 02 12 03 9d 4a 6c 36 25 2c
    7c 54 2a 3c a4 90 32 b6 cb da 68 30 85 06 09 2a
...
...

从 strace 输出:

 "\26\3\3\vM\2\0", 7) = 7
12432 18:42:54.131111 write(1, "<<< ??? [length 0005]\n", 22) = 22
12432 18:42:54.131220 write(1, "    16 03 03 0b 4d\n", 19) = 19
12432 18:42:54.131294 read(3, "\0M\3\3ZvG\322(\16\342\211%=\277\317\225m\266y\231\17X\221\263\177Cj{\\\203f"..., 2891) = 2891
12432 18:42:54.131385 write(1, "<<< TLS 1.2 Handshake [length 00"..., 49) = 49
12432 18:42:54.131464 write(1, "    02 00 00 4d 03 03 5a 76 47 d"..., 52) = 52
12432 18:42:54.131538 write(1, "    bf cf 95 6d b6 79 99 0f 58 9"..., 52) = 52
12432 18:42:54.131610 write(1, "    83 66 22 6a fb d8 20 5a 76 4"..., 52) = 52
12432 18:42:54.131682 write(1, "    b3 6c c9 49 bd 3d fa da 10 3"..., 52) = 52
12432 18:42:54.131774 write(1, "    b0 0c 8f d5 5c 8f bf c0 30 0"..., 52) = 52
12432 18:42:54.131845 write(1, "    00\n", 7) = 7
12432 18:42:54.131954 write(1, "<<< TLS 1.2 Handshake [length 09"..., 49) = 49
12432 18:42:54.132035 write(1, "    0b 00 09 a7 00 09 a4 00 05 0"..., 52) = 52
12432 18:42:54.132106 write(1, "    03 ec a0 03 02 01 02 02 12 0"..., 52) = 52
12432 18:42:54.132182 write(1, "    7c 54 2a 3c a4 90 32 b6 cb d"..., 52) = 52
12432 18:42:54.132466 write(1, "    86 48 86 f7 0d 01 01 0b 05 0"..., 52) = 52
12432 18:42:54.132546 write(1, "    06 03 55 04 06 13 02 55 53 3"..., 52) = 52
12432 18:42:54.132620 write(1, "    04 0a 13 0d 4c 65 74 27 73 2"..., 52) = 52 
...
...

同一命令的后续运行非常快，即 ~instantaneous。

对正在发生的事情或如何进一步调试有任何想法吗？

Answer 1

正如你所说的问题是在Tomcat启动之后，它可能是随机初始化非常慢。看看 entropy source .