Microsoft MVP성태의 닷넷 이야기
글쓴 사람
정성태 (techsharer at outlook.com)
홈페이지
첨부 파일

제니퍼 닷넷 적용 사례 (5) - RestSharp 라이브러리의 CPU High 현상

고객사의 웹 사이트가 CPU High 현상으로 서비스가 일시적으로 불능 상태에 빠졌습니다. 평소에는 문제가 없었는데 특정 시간대에 갑자기 사용자가 몰리면서 문제가 표면으로 나타난 것입니다.

제니퍼 제품의 XView를 통해 보니 대략 다음과 같은 패턴으로 장애가 나타났는데요. (실제로는 이보다 더 심각했습니다.)

restsharp_poor_perf_1.png

위의 화면을 보면, 10초 시간 대에 빨간색 점으로 나타나는데 모두 자체적으로 정의된 10초 time-out에 걸려 오류가 발생한 것들입니다.

제니퍼 분석 결과, 해당 시간대에 CPU를 가장 많이 소비한 응용 프로그램이 밝혀졌고 이를 "test.aspx"라고 가정하겠습니다. 해당 페이지의 응답 기록을 보니 평소에도 2,000ms 정도가 걸렸고 특이하게도 그 응답 시간 동안 CPU 소비량이 1,800ms로 90% 정도가 CPU-intensive한 작업을 하고 있었습니다.

일단 범인은 밝혀졌으므로 이젠 관심사가 test.aspx 소스코드의 어떤 부분에서 잘못된 것인지로 옮겨갔습니다.

다행히, 해당 웹 애플리케이션 서비스 장애가 발생한 시점에 남겨진 "서비스 덤프"를 통해 쉽게 문제에 접근할 수 있었습니다. 지난번 사례에서도 "서비스 덤프"가 장애 원인을 밝히는 데 결정적인 역할을 했었는데... 이번에도 그랬습니다. ^^

제니퍼 닷넷 적용 사례 (2) - 웹 애플리케이션 hang 의 원인을 알려주다.
; https://www.sysnet.pe.kr/2/0/1117

이번 고객사의 서비스 덤프 내용을 보니, test.aspx 페이지의 경우 대부분 다음과 같이 RestSharp.Deserializers.JsonDeserializer, System.Text.RegularExpressions 쪽의 호출 스택을 갖고 있다는 것이었습니다.

D:192.168.0.5:20151005/134415:2153:52.0%:LA1:TXEXED:/test.aspx::WebReq.http://mytestsrv/test.asmx:::::-5268713217693983903::-5268713217693983903
   위치: System.Threading.Monitor.Enter(Object obj)
   위치: System.Text.RegularExpressions.Regex.LookupCachedAndUpdate(String key)
   위치: System.Text.RegularExpressions.Regex..ctor(String pattern, RegexOptions options, TimeSpan matchTimeout, Boolean useCache)
   위치: RestSharp.Extensions.StringExtensions.AddUnderscores(String pascalCasedWord)
   위치: RestSharp.Extensions.StringExtensions.<GetNameVariants>d__0.MoveNext()
   위치: System.Linq.Enumerable.Contains[TSource](IEnumerable`1 source, TSource value, IEqualityComparer`1 comparer)
   위치: System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source, Func`2 predicate)
   위치: RestSharp.Extensions.ReflectionExtensions.FindEnumValue(Type type, String value, CultureInfo culture)
   위치: RestSharp.Deserializers.JsonDeserializer.ConvertValue(Type type, Object value)
   위치: RestSharp.Deserializers.JsonDeserializer.Map(Object target, IDictionary`2 data)
   위치: RestSharp.Deserializers.JsonDeserializer.CreateAndMap(Type type, Object element)
   위치: RestSharp.Deserializers.JsonDeserializer.ConvertValue(Type type, Object value)
...[이하 생략]...

JSON 관련 직렬화(Serialization) 작업에 정규 표현식(Regular Expression)을 사용했다면 왠지 모르게 CPU 100% 현상의 주요 원인이었음을 짐작케 해줍니다.

이 사실을 고객 측과 공유했고 현재 관련 라이브러리를 제거하고 정상적인 서비스에 들어갔다고 합니다. ^^




회사로 복귀한 후, "하지만, 정말 그게 원인일까???" 하는 의문이 생겼습니다. 왜냐하면 콜스택에 남았다고 해서 CPU 소비량이 크다는 증거가 아니기 때문입니다. 하필 콜스택을 남기는 순간에 그것이 실행되었을 수도 있으므로 확실한 증거를 얻기 위해 간단하게 테스트 코드를 작성해 보았습니다.

이를 위해 WCF Restful 서비스를 하는 서버 측 코드를 작성하고,

using System;
using System.ServiceModel;
using System.ServiceModel.Web;

namespace ConsoleApplication2
{
    // http://blog.sublogic.com/2010/07/15/making-a-wcf-rest-stand-alone-service-exe-from-scratch-part-1-of-4-creating-the-minimal-bare-service/
    [ServiceContract]
    public class MyService
    {
        [WebGet(UriTemplate = "say/{something}")]
        public string AnswerBack(string something)
        {
            return "You said: " + something;
        }
    }

    class Program
    {
        static void Main(string[] args)
        {
            using (var serviceHost = new ServiceHost(typeof(MyService)))
            {
                serviceHost.Open();
                Console.WriteLine("Hit Enter when done");
                Console.ReadLine();
            }            
        }
    }
}

다른 컴퓨터에 띄워놓은 후 다음의 RestSharp 클라이언트 측 코드를 작성해 실행해 보았습니다.

using System;
using System.Net;
using System.Threading;

namespace ConsoleApplication1
{
    class Program
    {
        static int _count = 0;

        static void Main(string[] args)
        {
            System.Net.ServicePointManager.DefaultConnectionLimit = 40000;

            int loadCount = (int)(Environment.ProcessorCount * 1.5);

            CreateTest(loadCount, restThreadFunc);
            
            ThreadPool.QueueUserWorkItem(Printthroughput);

            Console.ReadLine();
        }

        private static void Printthroughput(object obj)
        {
            int old = 0;

            while (true)
            {
                Thread.Sleep(1000);

                int current = _count;
                int reqPerSecond = current - old;
                Console.WriteLine("Req / Second: " + reqPerSecond);

                old = current;
            }
        }

        private static void CreateTest(int threadCount, ThreadStart action)
        {
            for (int i = 0; i < threadCount; i ++)
            {
                Thread t = new Thread(action);
                t.IsBackground = true;
                t.Start();
            }
        }

        private static void restThreadFunc()
        {
            while (true)
            {
                RestSharp.RestClient client = new RestSharp.RestClient("http://192.168.0.6:8077");
                RestSharp.RestRequest request = new RestSharp.RestRequest("/testing/say/hello", RestSharp.Method.GET);

                string result = client.Execute(request).Content;
                Interlocked.Increment(ref _count);
            }
        }
    }
}

제 컴퓨터가 하이퍼스레딩이 활성화된 상태에서 8개의 논리 코어가 있어 12개의 스레드를 생성해 위의 코드를 실행했더니 다음과 같은 결과를 얻었습니다.

restsharp_poor_perf_2.png

보시는 것처럼, 초당 2,500 ~ 3,200 사이의 처리량을 보였고 아주 단순한 유형의 Restful API를 호출한 것인데도 CPU는 완전히 100%를 전부 쓰고 있습니다. 고객사에 이 상황을 대입해 보면 장애 상황이 이해가 갑니다. test.aspx의 처리에 1,800ms 동안의 CPU 사용량을 보였으니 8개의 코어가 있다고 가정했을 때 겨우 8명의 사용자가 해당 페이지를 동시에 호출하기만 해도 대략 2초 동안은 CPU 점유율이 100%를 치기 때문에 서비스 불능 상황이 발생했던 것입니다.

비교를 위해 RestSharp.RestClient 호출을 닷넷의 WebClient로 바꿔 보았는데요. 결과는 다음과 같습니다.

restsharp_poor_perf_3.png

CPU 사용량이 20%로 안정화되었고 처리량이 8,500 ~ 9,000 사이를 보입니다. (제가 테스트한 네트워크 상태가 안좋아서 그 이상 나오질 않았습니다.)




결론은? RestSharp 라이브러리는 가능한 "클라이언트 측 응용 프로그램"에서만 사용하는 것이 좋습니다. 서비스 유형의 응용 프로그램에서 이를 사용하는 것은 권장되지 않습니다.

(첨부한 파일은 제가 테스트한 서버/클라이언트 측 코드입니다.)




[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]







[최초 등록일: ]
[최종 수정일: 6/27/2021]

Creative Commons License
이 저작물은 크리에이티브 커먼즈 코리아 저작자표시-비영리-변경금지 2.0 대한민국 라이센스에 따라 이용하실 수 있습니다.
by SeongTae Jeong, mailto:techsharer at outlook.com

비밀번호

댓글 작성자
 




[1]  2  3  4  5  6  7  8  9  10  11  12  13  14  15  ...
NoWriterDateCnt.TitleFile(s)
13607정성태4/25/2024185닷넷: 2248.C# - 인터페이스 타입의 다중 포인터를 인자로 갖는 C/C++ 함수 연동
13606정성태4/24/2024200닷넷: 2247. C# - tensorflow 연동 (MNIST 예제)파일 다운로드1
13605정성태4/23/2024361닷넷: 2246. C# - Python.NET을 이용한 파이썬 소스코드 연동파일 다운로드1
13604정성태4/22/2024399오류 유형: 901. Visual Studio - Unable to set the next statement. Set next statement cannot be used in '[Exception]' call stack frames.
13603정성태4/21/2024701닷넷: 2245. C# - IronPython을 이용한 파이썬 소스코드 연동파일 다운로드1
13602정성태4/20/2024801닷넷: 2244. C# - PCM 오디오 데이터를 연속(Streaming) 재생 (Windows Multimedia)파일 다운로드1
13601정성태4/19/2024850닷넷: 2243. C# - PCM 사운드 재생(NAudio)파일 다운로드1
13600정성태4/18/2024876닷넷: 2242. C# - 관리 스레드와 비관리 스레드
13599정성태4/17/2024868닷넷: 2241. C# - WAV 파일의 PCM 사운드 재생(Windows Multimedia)파일 다운로드1
13598정성태4/16/2024889닷넷: 2240. C# - WAV 파일 포맷 + LIST 헤더파일 다운로드2
13597정성태4/15/2024878닷넷: 2239. C# - WAV 파일의 PCM 데이터 생성 및 출력파일 다운로드1
13596정성태4/14/20241066닷넷: 2238. C# - WAV 기본 파일 포맷파일 다운로드1
13595정성태4/13/20241051닷넷: 2237. C# - Audio 장치 열기 (Windows Multimedia, NAudio)파일 다운로드1
13594정성태4/12/20241069닷넷: 2236. C# - Audio 장치 열람 (Windows Multimedia, NAudio)파일 다운로드1
13593정성태4/8/20241084닷넷: 2235. MSBuild - AccelerateBuildsInVisualStudio 옵션
13592정성태4/2/20241219C/C++: 165. CLion으로 만든 Rust Win32 DLL을 C#과 연동
13591정성태4/2/20241198닷넷: 2234. C# - WPF 응용 프로그램에 Blazor App 통합파일 다운로드1
13590정성태3/31/20241079Linux: 70. Python - uwsgi 응용 프로그램이 k8s 환경에서 OOM 발생하는 문제
13589정성태3/29/20241154닷넷: 2233. C# - 프로세스 CPU 사용량을 나타내는 성능 카운터와 Win32 API파일 다운로드1
13588정성태3/28/20241268닷넷: 2232. C# - Unity + 닷넷 App(WinForms/WPF) 간의 Named Pipe 통신 [2]파일 다운로드1
13587정성태3/27/20241170오류 유형: 900. Windows Update 오류 - 8024402C, 80070643
13586정성태3/27/20241335Windows: 263. Windows - 복구 파티션(Recovery Partition) 용량을 늘리는 방법
13585정성태3/26/20241131Windows: 262. PerformanceCounter의 InstanceName에 pid를 추가한 "Process V2"
13584정성태3/26/20241249개발 환경 구성: 708. Unity3D - C# Windows Forms / WPF Application에 통합하는 방법파일 다운로드1
13583정성태3/25/20241471Windows: 261. CPU Utilization이 100% 넘는 경우를 성능 카운터로 확인하는 방법
[1]  2  3  4  5  6  7  8  9  10  11  12  13  14  15  ...