제니퍼 닷넷 적용 사례 (4) - GZIP 인코딩으로 인한 성능 하락
최근 고객사 방문에서 나온 문제점이었습니다.
해당 웹 응용 프로그램은 다른 IIS에서 호스팅 중인 WCF 웹 서비스를 호출하는 것이었는데요. 제니퍼를 통해 웹 응용 프로그램을 모니터링해 보면 2~4초 내에 모든 요청이 완료되는데 겉으로 보기에는 별다른 문제가 없어 보입니다.
실제로, 아래는 제가 해당 웹 사이트의 문제점을 재현한 테스트 웹 페이지의 X-View 결과를 보여줍니다.
UUID: 67993fb388ceed27(7465067897670266151) GUID: 67993fb388ceed27 서버 시간: 11:04:29 360(1377223469360)
에이전트: LA1 애플리케이션: /customBindingCall.aspx(-817313597)
클라이언트 아이디: 26f5920bb6cf1488(2807310521744692360) 클라이언트 IP: ::1 사용자 아이디:
호출 시간: 11:04:26 718 종료 시간: 11:04:29 360 응답 시간: 2,942
CPU 시간: 1,356 SQL 시간: 0 Fetch 시간: 0 TX 시간: 2,938
Http User-Agent: Mozilla/5.0 (compatible; MSIE 10.0; Windows NT 6.2; WOW64; Trident/6.0)
------------------------------------------------------------------------------------------------------------------------------------------------------------
[ NO ][ START_TIME ][ GAP][CPU_T]
------------------------------------------------------------------------------------------------------------------------------------------------------------
[0000][11:04:26 718][ 0][ 0] START
[0000][11:04:26 718][ 0][ 0] [native:490]
[0001][11:04:26 718][ 0][ 0] ASP.custombindingcall_aspx: C:\...\App_Web_qv3ulbbl.dll
[0004][11:04:26 730][ 12][ 0] SEND GUID=[67993fb388ceed27]
[0005][11:04:26 730][ 0][ 0] SOCKET[addr=192.168.50.2,port=8005,localport=13192] uid=34069859
[0006][11:04:27 896][1,466][ 0] SOCKET-CLOSE R=51612,W=222,uid=34069859
[0007][11:04:29 359][1,463][1,356] TX-CALL[WCF.WcfInterfaceLib.ICalculator.GetText] [2,938 ms]
[0008][11:04:29 359][ 0][ 0] TX-CALL[WCF.System.IDisposable.Dispose]
[0009][11:04:29 360][ 1][ 0] END
------------------------------------------------------------------------------------------------------------------------------------------------------------
TOTAL[2,942][1,356]
위의 호출 결과를 분석해 보면 다음과 같습니다.
1. aspx 페이지에서 ICalculator.GetText WCF 메서드를 호출
1.1 WCF를 호스팅하고 있는 또 다른 웹 서버로 SOCKET 연결
1.2 Socket을 통해 Read=51,612바이트, Write=222바이트 통신이 이뤄진 후 닫기(SOCKET-CLOSE)까지 1,466ms 시간이 걸리고,
1.3 읽혀진 바이트가 GetText 내부적으로 후처리 되는 시간이 1,463ms 걸리고, 그것을 처리하는 CPU가 1,356ms 할당됨.
==> 결과적으로 GetText 메서드의 호출로 걸린 시간은 2,938ms
가만 보니, 소켓 I/O 완료 후 후처리를 위해 걸린 시간이 눈에 띄는데요. CPU가 1.3초 걸릴 정도로 일을 하는 작업이 무엇인지 확인해 보니 해당 WCF는 통신에서 GZIP 압축을 수행하고 있었던 것입니다. 사실, 네트워크 I/O 대역폭이 낮다면 일면 수긍이 가는 구조입니다. 하지만 더욱 큰 문제가 있었는데, 다름 아닌 위의 코드가 실행되는 aspx 웹 페이지가 아래의 "중계 웹 서버"였다는 점입니다.
이 구조를 반영해 통신 경로를 따라가면서 시간 계산을 다시 한번 해볼까요? ^^
1. 사용자가 웹 브라우저로 http://.../test.aspx 웹 페이지 방문
2. test.aspx에서 back-end WCF 서비스 호출
2.1 (Read/Write 시간이 1,466 걸린 것에 미뤄 짐작했을때) back-end WCF 메서드 수행은 금방했으나, 메서드 압축에 1.4초 정도 소요
2.2 WCF 메서드의 압축 결과를 받은 test.aspx는 다시 그것을 압축 해제하는 데 1.4초 정도 소요
3. test.aspx는 단순한 중계 페이지였기 때문에 마찬가지로 GZIP 응답을 반환하도록 설정되어 있어,
다시 압축하는 데 1.4초 정도 소요될 것으로 예상
4. 사용자 웹 브라우저는 test.aspx의 호출 결과를 받고 다시 GZIP 압축 해제하는 데 1.4초 정도 소요 (서버와 동급 CPU라고 가정한 경우임)
따라서, 사용자 응답 시간을 높이기 위해 도입한 GZIP 인코딩으로 인해 "WCF 메서드 측의 압축(1.4초)" + "중계 페이지의 압축 해제(1.4초)" + "중계 페이지의 응답 압축(1.4초)" + "사용자 웹 브라우저 측의 압축 해제(1.4)" 시간이 발생하게 되어 거의 6초 가까운 시간이 순수하게 압축으로 인해 사용자 응답시간이 길어지는 결과를 가져온 것입니다. 또한, 부가적으로 CPU 사용률도 높아지는데 "WCF 서비스 머신의 1.3초 CPU 소비" + "중계 페이지의 압축 해제로 인한 1.3초 CPU 소비" + "중계 페이지의 응답 압축으로 인한 1.3초 CPU 소비" + "사용자 웹 브라우저 측의 압축 해제로 인한 CPU 소비"가 발생하는데 웹 서버가 다중 요청을 처리하는 것을 감안하면 순수하게 압축에만 이런 비용이 드는 것은 결코 적지 않은 수준입니다.
결과적으로 봤을 때, 만약 ajax 호출로 중계 웹 서버 측에 2번의 aspx를 호출했다면 그 결과를 받기 위해 최소 12초를 사용자가 대기할 수밖에 없었으므로 당연히 고객들의 불만이 커질 수밖에 없는 상황이었던 것입니다.
해결 방법은 2가지 정도가 있습니다.
하나는, 중계 서버를 .aspx로 가져가지 말고 포트 포워딩을 통해 곧바로 WCF 메서드를 호출하도록 하는 것입니다. 그래서 저번 글이 쓰여진 것입니다. ^^
윈도우 서버의 80 포트에 대한 port forwarding 설정 방법
; https://www.sysnet.pe.kr/2/0/1480
또 다른 해결 방법은 중계 서버와 WCF 메서드 간의 구간만이라도 압축을 해제하는 것입니다. 그럼, 5.6초에서 2.8초로 절반의 시간이 절약됩니다. 그런데, 사실 압축을 아예 해제하는 것도 방법일 수 있습니다. 압축 효율을 50%라고 가정했을 때, 나머지 50%의 네트워크 대역폭과 5.6초라는 시간 중 어떤 것이 더 효율적인지 테스트 해볼 가치는 있기 때문입니다.
암튼, 이런저런 문제를 해결하기 위해서는 모니터링을 해야만 알 수 있다는 것! ^^
참고로, 가끔 모니터링 제품으로 인해 서버가 더 부하를 받는 것 아니냐는 질문을 받곤 하는데요.
제니퍼 닷넷 적용 사례 (1) - DB Connection Pooling을 사용하지 않았을 때의 성능 저하를 알려주다.
; https://www.sysnet.pe.kr/2/0/1111
제니퍼 닷넷 적용 사례 (2) - 웹 애플리케이션 hang의 원인을 알려주다.
; https://www.sysnet.pe.kr/2/0/1117
제니퍼 닷넷 적용 사례 (3) - '닷넷'이 문제일까? '닷넷 개발자'가 문제일까?
; https://www.sysnet.pe.kr/2/0/1215
위의 사실을 감안하면, 대부분의 웹 사이트가 모니터링 없이 내재하고 있을 문제점과 비교했을 때 모니터링 제품 자체로 인해 발생하는 부하는 거의 무시해도 좋을 정도라는 것은 확실합니다. ^^ (
아~~~, 이 찐한 광고의 냄새.)
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]