웹 서비스 HTTPS 연결시 소켓 끊김 현상 및 해결사례
과거에 https 연결해서 테스트한 적이 있었고, 그 이후에 쓰지 않다가 최근에 https로 사용해야 해서 https로 테스트하던 중에 발견되었습니다.
브라우져상의 에러
(크롬) : err_connection_reset 에러 발생
IE 쪽
Apache Http 서버의 설정파일이나 java 연결부분, 인증서 부분에도 특별한 문제점을 파악하지 못했습니다.
에러 로그에서도 특별한 징후를 찾을 수 없었습니다.
그래서 터미널에서 해당 서버에 로그인 한 후, openssl을 이용해서 디버깅을 해보았습니다.
localhost의 443포트에 접속해서 ssl 통신을 체크하였습니다.
# openssl s_client -host localhost -port 443 -state
CONNECTED(00000003)
SSL_connect:before/connect initialization
SSL_connect:SSLv2/v3 write client hello A
SSL_connect:error in SSLv2/v3 read server hello A
write:errno=104
ssl 통신은 최초 통신의 시작을 hello 라는 패킷을 client와 server 에 서로 전달하는데. 그 부분에서 에러가 발생한 것입니다. 저는 좀 더 상세한 정보를 보기 위해서 linux의 시스템 콜과 에러 내용에 대해서 정확히 분석하기 위해서 strace 라는 리눅스 명령어를 이용했습니다.
gettimeofday({1318989368, 765821}, NULL) = 0
poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}])
send(4, "\204\27\1\0\0\1\0\0\0\0\0\0\20_kerberos-master\4_u"..., 49, MSG_NOSIGNAL) = 49
poll([{fd=4, events=POLLIN}], 1, 1000) = 1 ([{fd=4, revents=POLLIN}])
recvfrom(4, "\204\27\205\203\0\1\0\0\0\1\0\0\20_kerberos-master\4_u"..., 2048, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.22.64.6")}, [16]) = 100
close(4) = 0
write(3, "\200t\1\3\1\0K\0\0\0 \0\0009\0\0008\0\0005\0\0\26\0\0\23\0\0\n\7\0\300"..., 118) = 118
write(2, "SSL_connect:SSLv2/v3 write clien"..., 42SSL_connect:SSLv2/v3 write client hello A
) = 42
read(3, 0x89bc4d0, 7) = -1 ECONNRESET (Connection reset by peer)
write(2, "SSL_connect:error in SSLv2/v3 re"..., 50SSL_connect:error in SSLv2/v3 read server hello A
) = 50
write(2, "write:errno=104\n", 16write:errno=104
) = 16
shutdown(3, 0 /* receive */) = -1 ENOTCONN (Transport endpoint is not connected)
close(3) = 0
exit_group(0) = ?
서버에서 접속을 끊었다는 ECONNRESET (error number 104) 이라는 에러가 발생되었음을 정확히 확인할 수 있었습니다.
ECONRESET 은 TCP 통신과 연관이 있습니다
A,B 노드가 있다고 가정하고, A가 Syn 패킷을 통해 connection을 시도했지만, 서버에서 port가 존재하지 않거나 중간에 소켓에 문제가 생겨 서버로부터 RST 패킷을 받게 됩니다. 이 때, -1이 리턴되고 ECONNRESET이 errono로 셋팅되며, Connection reset by peer 메시지를 보여 줍니다.
일반적인 케이스는 아파치 에러 로그(LogLevel debug 설정)에 보여지기도 하지만, 이번 경우는 에러 로그에 남지 않았습니다. 그 이유는 Http 단 연결이 아닌 TCP 단에서의 연결에서 종료되었기 때문입니다.
만약 정상적인 연결이었다면, 아래와 같이 SSL 통신하고 클라이언트에서 인증서를 받는 형태로 가게 됩니다.
CONNECTED(00000003)
SSL_connect:before/connect initialization
SSL_connect:SSLv2/v3 write client hello A
SSL_connect:SSLv3 read server hello A
depth=1 /C=US/O=VeriSign, Inc./OU=VeriSign Trust Network/OU=Terms of use at https://www.verisign.com/rpa (c)10/CN=VeriSign Class 3 Secure Server CA - G3
verify error:num=20:unable to get local issuer certificate
verify return:0
SSL_connect:SSLv3 read server certificate A
SSL_connect:SSLv3 read server key exchange A
SSL_connect:SSLv3 read server done A
SSL_connect:SSLv3 write client key exchange A
SSL_connect:SSLv3 write change cipher spec A
SSL_connect:SSLv3 write finished A
SSL_connect:SSLv3 flush data
SSL_connect:SSLv3 read finished A
---
Certificate chain
0 s:/C=KR/ST=adsfsdf/L=dddad/O=NHN/OU=GAT/OU=Terms of use at www.crosscert.com/rpa (c) 04/OU=Authenticated by KECA, Inc./OU=Member, VeriSign Trust Network/CN=google.com
i:/C=US/O=VeriSign, Inc./OU=VeriSign Trust Network/OU=Terms of use at https://www.verisign.com/rpa (c)10/CN=VeriSign Class 3 Secure Server CA - G3
1 s:/C=US/O=VeriSign, Inc./OU=VeriSign Trust Network/OU=Terms of use at https://www.verisign.com/rpa (c)10/CN=VeriSign Class 3 Secure Server CA - G3
i:/C=US/O=VeriSign, Inc./OU=VeriSign Trust Network/OU=(c) 2006 VeriSign, Inc. - For authorized use only/CN=VeriSign Class 3 Public Primary Certification Authority - G5
---
Server certificate
Server certificate
-----BEGIN CERTIFICATE-----
MIIFgDCCBGigAwIBAgIQFZkr7WyBWj+WqYaiWeajwzANBgkqhkiG9w0BAQUFADCB
tTELMAkGA1UEBhMCVVMxFzAVBgNVBAoTDlZlcmlTaWduLCBJbmMuMR8wHQYDVQQL
ExZWZXJpU2lnbiBUcnVzdCBOZXR3b3JrMTswOQYDVQQLEzJUZXJtcyBvZiB1c2Ug
YXQgaHR0cHM6Ly93d3cudmVyaXNpZ24uY29tL3JwYSAoYykxMDEvMC0GA1UEAxMm
VmVyaVNpZ24gQ2xhc3MgMyBTZWN1cmUgU2VydmVyIENBIC0gRzMwHhcNMTAxMjA2
MDAwMDAwWhcNMTIxMjA1MjM1OTU5WjCB7zELMAkGA1UEBhMCS1IxEDAOBgNVBAgT
B0t5dW5nZ2kxFDASBgNVBAcUC0p1bmdqYS1kb25nMQwwCgYDVQQKFANOSE4xDDAK
BgNVBAsUA0dBVDE1MDMGA1UECxMsVGVybXMgb2YgdXNlIGF0IHd3dy5jcm9zc2Nl
cnQuY29tL3JwYSAoYykgMDQxJDAiBgNVBAsTG0F1dGhlbnRpY2F0ZWQgYnkgS0VD
QSwgSW5jLjEnMCUGA1UECxMeTWVtYmVyLCBWZXJpU2lnbiBUcnVzdCBOZXR3b3Jr
MRYwFAYDVQQDFA15YTkubmF2ZXIuY29tMIGfMA0GCSqGSIb3DQEBAQUAA4GNADCB
iQKBgQDf6nldrBCfR7cgGBA7PcVkGT7xvF7X/KadRBzWtFYnba2rxd/dpQ4k5UkM
4wLr2xK6clCS1xodZp9mhLI0ig79qY6IloAghkJEmjz13Ui1c0o0ZincqbUsa7Rp
+VYSesEguUYdmj5FwWmtMC6do6TrRGjp1ExThvMEEiqMhi48FwIDAQABo4IB0jCC
Ac4wCQYDVR0TBAIwADALBgNVHQ8EBAMCBaAwRQYDVR0fBD4wPDA6oDigNoY0aHR0
cDovL1NWUlNlY3VyZS1HMy1jcmwudmVyaXNpZ24uY29tL1NWUlNlY3VyZUczLmNy
bDBFBgNVHSAEPjA8MDoGC2CGSAGG+EUBBxcDMCswKQYIKwYBBQUHAgEWHWh0dHBz
Oi8vd3d3LmNyb3NzY2VydC5jb20vcnBhMB0GA1UdJQQWMBQGCCsGAQUFBwMBBggr
BgEFBQcDAjAfBgNVHSMEGDAWgBQNRFwWU0TBgn4dIKsl9AFj2L55pTB2BggrBgEF
BQcBAQRqMGgwJAYIKwYBBQUHMAGGGGh0dHA6Ly9vY3NwLnZlcmlzaWduLmNvbTBA
BggrBgEFBQcwAoY0aHR0cDovL1NWUlNlY3VyZS1HMy1haWEudmVyaXNpZ24uY29t
L1NWUlNlY3VyZUczLmNlcjBuBggrBgEFBQcBDARiMGChXqBcMFowWDBWFglpbWFn
ZS9naWYwITAfMAcGBSsOAwIaBBRLa7kolgYMu9BSOJsprEsHiyEFGDAmFiRodHRw
Oi8vbG9nby52ZXJpc2lnbi5jb20vdnNsb2dvMS5naWYwDQYJKoZIhvcNAQEFBQAD
ggEBAFkByKz9YKlUV59kvdxMwwpvOLc4SNu4Q9mh1QKzQCyZ4oJoZ2FjNxJKU9rq
6YwkC5DrSZ5KZYzSt1CyoksVuWKNkU8E9Tr+np3Hl9inq8OBtUmMTujwtBW7DOK5
3VQfZIa9L4ftuLBBBrkchaIJAO+Wt6QOaxj8nPCdtFz6jE5+y0Tcegnh/37lgTvJ
A0FO+Q9flceQfXOhML/FSfqFTfTDZaXZsrNabSaZqmdbX28TTbsj8wPx71IsxdBs
yKbTF1oz5ywx9xNN6QYhCu0SyQQbxr62e0Oo3o5XFP/ljyjmzIoneWheo5UgsKvI
wDT/ZiM6lixt0CWxSHFNfm9m4yM=
-----END CERTIFICATE-----
subject=/C=KR/ST=Kyunggi/L=Jungja-dong/O=NHN/OU=GAT/OU=Terms of use at www.crosscert.com/rpa (c) 04/OU=Authenticated by KECA, Inc./OU=Member, VeriSign Trust Network/CN=google.com
issuer=/C=US/O=VeriSign, Inc./OU=VeriSign Trust Network/OU=Terms of use at https://www.verisign.com/rpa (c)10/CN=VeriSign Class 3 Secure Server CA - G3
---
No client certificate CA names sent
---
SSL handshake has read 3499 bytes and written 316 bytes
---
New, TLSv1/SSLv3, Cipher is DHE-RSA-AES256-SHA
Server public key is 1024 bit
Compression: NONE
Expansion: NONE
SSL-Session:
Protocol : TLSv1
Cipher : DHE-RSA-AES256-SHA
Session-ID: 8F2B9AB40A4AD05C46DE0F4F04D80355308840534ADAFE4C68FF3389B46981EB
Session-ID-ctx:
Master-Key: 5610D7F76F9BD9EE4896F5C9599323CBCA58111579FDECA32BDF05E570D159C65F395B030442E4BC432109B71A238DA5
Key-Arg : None
Krb5 Principal: None
Start Time: 1318991229
Timeout : 300 (sec)
Verify return code: 20 (unable to get local issuer certificate)
---
ssl 통신(handshaking) 은 다음과 같습니다.
1. Client(터미널에서 openssl 요청, 브라우져)가 Https를 이용해서 Server(google.com) URL로 통신을 시도한다. Hello 라는 통신인데, 지원 가능한 암호방식, 키 교환 방법, 압축 방식을 서로 의사소통합니다.
2. Server(google.com)가 인증서를 client에 전달합니다.
3. Client에서는 Server 인증서 public key 얻어옵니다. (기본적인 인증서에 대한 검증 절차를 거침. 인증서의 도메인과 실제 요청하는 도메인이 갖은지. CA가 정확하게 인증했는지 등등)
5. Client에서는 public key를 이용한 pre-master key(RSA 키교환) 를 생성하고 서버에 전달하여 상호간의 키를 교환하도록 합니다.. (key exchange)
6. Client에서 인증서 검증 정보를 보내고, SSL 통신에 의해 결정된 암호방식, 키교환 방법, 서명방식, 압축방식을 다음부터 적용할 것을 정합니다. (cipher spec)
6. Server는 Client로부터 받은 pre-master key(또는 pre master secret)를 private key로 디코딩하고 Session ticket으로 생성하고 Client에 전송합니다. (session ticket)
7. Server 에서는 Session Ticket를 이용하여 Server와 Client간의 발생하는 모든 통신은 암호화가 되게 합니다
통신 에러는 client->server 로 SSL Handshake 하는 첫번째 단계("1. Client(터미널에서 openssl 요청, 브라우져)가 Https를 이용해서 Server(google.com) URL로 통신을 시도한다. Hello 라는 통신인데, 지원 가능한 암호방식, 키 교환 방법, 압축 방식을 서로 의사소통합니다. ")에서 문제가 발생한 것이었습니다.
이에 대한 정확한 진단을 위해서 아파치 서버의 설정 파일을 수정하였습니다.
Prefork 설정에서 StartServer와 MaxClient를 1로 주어 리스타트를 하였습니다.
# vi /usr/local/apache/conf/httpd.conf
StartServer 1
MaxClient 1
# /usr/local/apache/bin/httpd -k restart
[프로세스 재시작]
# ps -ef | grep httpd
1111 root /usr/local/apache/bin/httpd
1112 www /usr/local/apache/bin/httpd
root 권한으로 동작하는 httpd 데몬과 www 권한으로 동작하는 httpd 데몬(worker)만이 리눅스에서 실행하게 됩니다.
Http 요청이 웹서버에 들어오면 1111 root 권한으로 실행되는 httpd 데몬이 1112 라는 httpd로 요청을 전달시킵니다.
그래서, www 권한으로 동작하는 httpd 데몬에다가 시스템 콜을 확인하는 strace를 붙여서 프로세스가 어떤 일을 하는지 확인합니다.
strace 로 프로세스를 띄우고, openssl로 https 패킷을 날리면 다음의 결과를 얻게 됩니다.
....
gettimeofday({1318989190, 741852}, NULL) = 0
writev(12, [{"HTTP/1.1 200 OK\r\nDate: Wed, 19 O"..., 289}, {"Total Accesses: 1\nTotal kBytes: "..., 396}], 2) = 685
gettimeofday({1318989190, 742236}, NULL) = 0
gettimeofday({1318989190, 742348}, NULL) = 0
write(15, "127.0.0.1 - - [19/Oct/2011:10:53"..., 128) = 128
gettimeofday({1318989190, 742594}, NULL) = 0
gettimeofday({1318989190, 742693}, NULL) = 0
times({tms_utime=0, tms_stime=0, tms_cutime=0, tms_cstime=0}) = -2134126829
gettimeofday({1318989190, 742955}, NULL) = 0
shutdown(12, 1 /* send */) = 0
poll([{fd=12, events=POLLIN}], 1, 2000) = 1 ([{fd=12, revents=POLLIN|POLLHUP}])
read(12, "", 512) = 0
close(12) = 0
read(6, 0xbfbe39c7, 1) = -1 EAGAIN (Resource temporarily unavailable)
gettimeofday({1318989190, 743670}, NULL) = 0
semop(21954565, 0x5a9898, 1) = 0
epoll_wait(8, {}, 2, 10000) = 0
epoll_wait(8, {}, 2, 10000) = 0
epoll_wait(8, {}, 2, 10000) = 0
epoll_wait(8, {}, 2, 10000) = 0
epoll_wait(8, {}, 2, 10000) = 0
epoll_wait(8, {}, 2, 10000) = 0
epoll_wait(8, {{EPOLLIN, {u32=137901384, u64=137901384}}}, 2, 10000) = 1
accept(5, {sa_family=AF_INET, sin_port=htons(51035), sin_addr=inet_addr("127.0.0.1")}, [16]) = 12
fcntl64(12, F_GETFD) = 0
fcntl64(12, F_SETFD, FD_CLOEXEC) = 0
semop(21954565, 0x5a98a4, 1) = 0
gettimeofday({1318989258, 992134}, NULL) = 0
getsockname(12, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
time(NULL) = 1318989258
fcntl64(12, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(12, F_SETFL, O_RDWR|O_NONBLOCK) = 0
gettimeofday({1318989258, 993069}, NULL) = 0
time(NULL) = 1318989258
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
chdir("/home/www/apps/httpd-2.2.21") = 0
rt_sigaction(SIGSEGV, {SIG_DFL, [], SA_INTERRUPT}, {SIG_DFL, [], SA_RESETHAND}, 8) = 0
kill(1112, SIGSEGV) = 0
sigreturn() = ? (mask now [])
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
Process 1112 detached
httpd 데몬에서 중간에 read 콜 이후에 Resource temporarily unavailable 이 일어나고.
나중에는 SIGSEGV (Segmentation fault)가 발생하게 되었습니다. 마지막에는 www 프로세스가 종료되었음을 확인할 수 있었습니다. (kill(1112, SIGSEGV))
즉, 요청이 들어올 때마다 www 프로세스(apache worker)가 동작하다가 Segment fault가 발생한 것이었습니다.
그리고, ps 명령어를 이용해서 프로세스 확인을 하니. 새로운 프로세스가 떠져 있는 것을 확인했습니다.
# ps -ef | grep httpd
1111 root /usr/local/apache/bin/httpd
1114 www /usr/local/apache/bin/httpd
아파치에 문제가 있는 것은 확인했습니다. 그 중의 어디서 문제가 있는지 확인을 해야 했습니다.
vhost.conf 설정 파일은 이런식으로 되어 있습니다.
먼저 회사에서 만든 특정 모듈을 읽고, mod_ssl을 읽는 구조로 되어 있습니다.
NameVirtualHost *:80
NameVirtualHost *:443
LoadModule session_auth_module modules/mod_auth.so
<IfModule mod_auth.c>
....
</IfModule>
#SSL Module
LoadModule ssl_module modules/mod_ssl.so
<IfModule mod_ssl.c>
SSLRandomSeed startup builtin
SSLRandomSeed connect builtin
Listen 443
AddType application/x-x509-ca-cert .crt
AddType application/x-pkcs7-crl .crl
SSLPassPhraseDialog exec:conf/sslcert.pass
SSLSessionCache dbm:/usr/local/apache/logs/ssl_scache
SSLSessionCacheTimeout 300
SSLMutex file:/usr/local/apache/logs/ssl_mutex
</IfModule>
<VirtualHost *:80>
..
</VirtualHost>
<VirtualHost *:443>
..
</VirtualHost>
좀 더 자세히 문제를 확인하기 위해서 httpd 데몬에 대해서 디버깅(gdb)를 하였습니다.
GNU gdb Fedora (6.8-27.el5)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu"...
(gdb) b ap_process_request
Breakpoint 1 at 0x80923f9: file http_request.c, line 276.
(gdb)
Note: breakpoint 1 also set at pc 0x80923f9.
Breakpoint 2 at 0x80923f9: file http_request.c, line 276.
(gdb) run -X -d /usr/local/apache
Starting program: /home/www/apps/httpd-2.2.21/bin/httpd -X -d /usr/local/apache
[Thread debugging using libthread_db enabled]
[New Thread 0xb7f85700 (LWP 8718)]
Detaching after fork from child process 8721.
Detaching after fork from child process 8722.
Detaching after fork from child process 8723.
Detaching after fork from child process 8724.
Detaching after fork from child process 8725.
Detaching after fork from child process 8726.
Detaching after fork from child process 8727.
Detaching after fork from child process 8728.
Detaching after fork from child process 8729.
Detaching after fork from child process 8730.
Detaching after fork from child process 8731.
Detaching after fork from child process 8732.
Detaching after fork from child process 8733.
Detaching after fork from child process 8734.
Detaching after fork from child process 8735.
(요청 날림, openssl s_client....)
Program received signal SIGSEGV, Segmentation fault.
0x003a91bd in ssl23_accept () from /lib/libssl.so.6
(gdb) bt
#0 0x001451bd in ssl23_accept () from /lib/libssl.so.6
#1 0x010c9341 in SSL_accept () from /usr/local/apache/modules/mod_auth-test.so
#2 0x00000000 in ?? ()
(gdb) n
Single stepping until exit from function ssl23_accept,
which has no line number information.
Program terminated with signal SIGSEGV, Segmentation fault.
The program no longer exists
.
회사에서 만든 특정 모듈의 SSL_accept 메소드에서 문제가 되었음을 확인할 수 있었습니다.
담당자분께 확인하니 auth모듈에서는 자체적인 ssl 인증 모듈을 static linking해서 가지고 있다고 합니다.
즉, mod_ssl을 쓰지 않고 auth 모듈을 사용하는 웹 서버를 위해서 만들어 진 것인데요. 이 부분이 저희가 사용하고 있는 mod_ssl의 ssl 버전과 충돌이 난 것입니다. 그래서 segmentation fault가 난 것입니다.
먼저 auth을 읽었고, mod_ssl을 읽는 구조에서 mod_ssl을 읽고, auth을 읽는 구조로 변경했더니 무사하게 동작되었습니다.
출처: http://knight76.tistory.com/entry/웹-서비스-HTTPS-연결시-소켓-끊김-현상-및-해결사례 [김용환 블로그(2004-2017)]