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

파이썬 pystack 소개 - 메모리 덤프로부터 콜 스택 열거

닷넷의 경험에 비춰 보면,

리눅스 환경의 .NET Core 3/5+ 메모리 덤프를 분석하는 방법 - 두 번째 이야기
; https://www.sysnet.pe.kr/2/0/13135

사후 분석을 위한 자료로써 메모리 덤프가 상당히 중요한 역할을 합니다. 사실, 현업에서 실 서버 운영자들은 서비스에 장애가 발생했을 때 보통은 서버 재시작을 하는데요, 그렇게 되면 나중에 개발자들이 문제를 찾기가 어렵습니다. 따라서, 해당 현상에 대한 재발 가능성은 여전한 상태로 남습니다.

바로 그런 상황에서, 협업이 잘 된 서버 운영자라면 문제가 된 프로세스의 메모리 덤프를 뜬 다음 서버 재시작을 할 수 있습니다. 그런 경우라면 개발자들이 덤프 분석을 통해 어떤 문제점이 있었는지 추적할 수 있고 운이 좋다면 원인을 찾아 버그 수정을 할 수 있을 것입니다.

그동안 Microsoft 환경에서만 있다 보니, 메모리 덤프는 그다지 어려운 작업이 아니었는데요, 이게 ^^; 리눅스로 와서는 문제가 좀 달라집니다.

예전에도 한 번 실습을 했듯이,

linux - lldb를 이용한 .NET Core 응용 프로그램의 메모리 덤프 분석 방법
; https://www.sysnet.pe.kr/2/0/12083

리눅스 역시 메모리 덤프 기능을 제공하지만, 기본적인 core 덤프는 크기가 너무 커서 부담스럽습니다. 닷넷 프로세스의 경우 일반적인 예제 코드 상황에서도 22GB가 넘는 크기의 덤프 파일이 생성되는데요, 그런 탓에 마이크로소프트는 닷넷 프로세스에 최적화된 dotnet-dump 전용 도구를 제공해 덤프 용량을 (59GB가 2GB로) 확 줄여줍니다.

아쉽게도 파이썬은 프레임워크 차원에서 제공하는 전용 덤프 도구가 없습니다. 게다가 (닷넷의 sos와 같은) 전용 분석 도구도 없습니다. 이에 대해 찾아보면,

How do I dump an entire Python process for later debugging inspection?
; https://stackoverflow.com/questions/141802/how-do-i-dump-an-entire-python-process-for-later-debugging-inspection

pystack 도구를 소개하는데,

bloomberg/pystack
; https://github.com/bloomberg/pystack

이것 역시 리눅스의 기본 (gdb의) gcore 덤프를 분석하는 것이라고 하니... 문제는 여전할 것 같습니다. 그래도, 혹시나 파이썬의 메모리 할당이 조직적이어서 크기가 좀 작지 않을까요? ^^

python:3.8-slim-buster 이미지의 Django 4.2.3 환경에서 간단한 예제 사이트를 만들어 올린 것을 gcore로 덤프 파일을 생성해 봤습니다.

# apt install gdb

# ps -aux
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root       140  1.0  0.1 1652836 178556 ?      Sl   Jul18  27:00 uwsgi ...[생략]...
...[생략]...

# gcore 140
[New LWP 162]
[New LWP 163]
[New LWP 167]
[New LWP 168]
[New LWP 169]
[New LWP 170]
[New LWP 171]
[New LWP 172]
[New LWP 173]
[New LWP 174]
[New LWP 175]
[New LWP 180]
[New LWP 181]
[New LWP 182]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
__lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:103
103     ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S: No such file or directory.
warning: target file /proc/140/cmdline contained unexpected null characters
Saved corefile core.140
[Inferior 1 (process 140) detached]

# ls -l core.140
-rw-r--r-- 1 root root 1380938936 Jul 20 01:17 core.140

1,316MB면 1GB 약간 넘는 용량입니다. 오호~~~ 이 정도면 (비록 간단한 예제 사이트였지만) 현실적인 메모리 덤프 크기입니다.




자, 그럼 분석을 해볼까요? 상황을 간단하게 만들기 위해 덤프를 뜬 환경에 매뉴얼에 따라 pystack도 설치한 후,

$ git clone https://github.com/bloomberg/pystack.git

$ cd pystack

$ python3 -m pip install virtualenv

$ python3 -m venv ../pystack-env/

$ source ../pystack-env/bin/activate

(pystack-env) ~/pystack$ python3 -m pip install --upgrade pip

(pystack-env) ~/pystack$ python3 -m pip install -e .

(pystack-env) ~/pystack$ python3 -m pip install -r requirements-test.txt -r requirements-extra.txt

위에서 떠 두었던 core.140 덤프 파일을 지정하면 자동으로 다음과 같은 내용을 출력합니다.

# pystack core /core.140
Using executable found in the core file: /usr/local/bin/uwsgi

Core file information:
state: t zombie: True niceness: 0
pid: 140 ppid: 1 sid: 1
uid: 0 gid: 0 pgrp: 1
executable: uwsgi arguments: uwsgi 

The process died due receiving signal SIGSTOP
Traceback for thread 182 (uwsgi) [] (most recent call last):
    (Python) File "/usr/local/lib/python3.8/threading.py", line 890, in _bootstrap
        self._bootstrap_inner()
    (Python) File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
        self.run()
    (Python) File "/usr/local/lib/python3.8/threading.py", line 870, in run
        self._target(*self._args, **self._kwargs)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/periodic_executor.py", line 140, in _run
        time.sleep(self._min_interval)

Traceback for thread 181 (uwsgi) [] (most recent call last):
    (Python) File "/usr/local/lib/python3.8/threading.py", line 890, in _bootstrap
        self._bootstrap_inner()
    (Python) File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
        self.run()
    (Python) File "/usr/local/lib/python3.8/threading.py", line 870, in run
        self._target(*self._args, **self._kwargs)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/periodic_executor.py", line 140, in _run
        time.sleep(self._min_interval)

Traceback for thread 180 (uwsgi) [] (most recent call last):
    (Python) File "/usr/local/lib/python3.8/threading.py", line 890, in _bootstrap
        self._bootstrap_inner()
    (Python) File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
        self.run()
    (Python) File "/usr/local/lib/python3.8/threading.py", line 870, in run
        self._target(*self._args, **self._kwargs)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/periodic_executor.py", line 125, in _run
        if not self._target():
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/monitor.py", line 53, in target
        monitor._run()  # type:ignore[attr-defined]
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/monitor.py", line 173, in _run
        self._server_description = self._check_server()
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/monitor.py", line 214, in _check_server
        return self._check_once()
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/monitor.py", line 250, in _check_once
        response, round_trip_time = self._check_with_socket(sock_info)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/monitor.py", line 271, in _check_with_socket
        response = Hello(conn._next_reply(), awaitable=True)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/pool.py", line 811, in _next_reply
        reply = self.receive_message(None)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/pool.py", line 931, in receive_message
        return receive_message(self, request_id, self.max_message_size)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/network.py", line 217, in receive_message
        _receive_data_on_socket(sock_info, 16, deadline)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/network.py", line 293, in _receive_data_on_socket
        wait_for_read(sock_info, deadline)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/network.py", line 274, in wait_for_read
        readable = sock_info.socket_checker.select(sock, read=True, timeout=timeout)
    (Python) File "/usr/local/lib/python3.8/site-packages/pymongo/socket_checker.py", line 65, in select
        res = self._poller.poll(timeout_)

The frame stack for thread 175 is empty
The frame stack for thread 173 is empty
The frame stack for thread 174 is empty
The frame stack for thread 172 is empty
The frame stack for thread 171 is empty
The frame stack for thread 170 is empty
The frame stack for thread 169 is empty
The frame stack for thread 168 is empty
The frame stack for thread 167 is empty
The frame stack for thread 140 is empty

가만 보면 "pstree -p" 명령어로 출력된 스레드의 목록과 일치하는군요. ^^

# pstree -p
...[생략]...
        `-uwsgi(140)-+-{uwsgi}(167)
                     |-{uwsgi}(168)
                     |-{uwsgi}(169)
                     |-{uwsgi}(170)
                     |-{uwsgi}(171)
                     |-{uwsgi}(172)
                     |-{uwsgi}(173)
                     |-{uwsgi}(174)
                     |-{uwsgi}(175)
                     |-{uwsgi}(180)
                     |-{uwsgi}(181)
                     `-{uwsgi}(182) 

그런데, pystack의 분석은 이게 끝입니다. 닷넷의 sos가 다양한 명령어를 지원하는 것과는 달리 pystack은 오로지 스택 트레이스만 보여주고 있습니다.




사실, 위의 예제 환경은 너무 비현실적인 환경이긴 합니다. 파이썬의 특성상 --threads 보다는 --processes 옵션을 통해 서비스를 할 것이고, 그렇다면 문제가 발생한 프로세스의 정확한 PID를 판단해 core 덤프를 남겨야 한다는 불편함이 있습니다. 보통, 문제가 발생했다고 하면 서비스 중인 프로세스가 대개 1개인 경우는 거의 없을 것입니다. 적게는 몇 수십 개에서 많게는 몇 천 개까지 설정했을 수 있는데, 과연 그런 문제의 상황에서 정확한 덤프를 뜰 수 있는 침착한 서버 운영자가 얼마나 될 것이냐... 라는 것도 문제가 될 수 있습니다.

아마도 현업에서 pystack의 효용성은 거의 없다고 봐도 무방하지 않을까요? ^^;




아래와 같은 오류가 발생한다면?

(pystack-env) ~/pystack$ python3 -m pip install -e .

...[생략]...
      In file included from src/pystack/_pystack.cpp:1150:
      src/pystack/_pystack/elf_common.h:13:10: fatal error: elfutils/libdwelf.h: No such file or directory
         13 | #include <elfutils/libdwelf.h>
            |          ^~~~~~~~~~~~~~~~~~~~~
      compilation terminated.
...[생략]...
      !!
        cmd_obj.run()
      error: command '/usr/bin/x86_64-linux-gnu-gcc' failed with exit code 1
      [end of output]

  note: This error originates from a subprocess, and is likely not a problem with pip.
  ERROR: Failed building editable for pystack
Failed to build pystack
ERROR: Could not build wheels for pystack, which is required to install pyproject.toml-based projects

README.md를 잘 안 읽어서 그런 것입니다. ^^ 다음과 같이 빌드를 위해 필요한 구성 요소를 설치해야 합니다.

# apt-get install libdw-dev libelf-dev




무심코 실행한 명령어가 이런 오류를 낼 수도 있습니다. ^^;

# python3 ../pystack-env/bin/activate
  File "../pystack-env/bin/activate", line 4
    deactivate () {
                  ^}

잘 보시면, activate 스크립트는 python 파일이 아니므로 python 런타임으로 실행할 대상이 아닙니다. 다음의 명령어를 실수로 입력했을 것입니다. ^^

$ source ../pystack-env/bin/activate




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







[최초 등록일: ]
[최종 수정일: 7/22/2023]

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

비밀번호

댓글 작성자
 




... [61]  62  63  64  65  66  67  68  69  70  71  72  73  74  75  ...
NoWriterDateCnt.TitleFile(s)
12117정성태1/15/202010835디버깅 기술: 159. C# - 디버깅 중인 프로세스를 강제로 다른 디버거에서 연결하는 방법파일 다운로드1
12116정성태1/15/202011307디버깅 기술: 158. Visual Studio로 디버깅 시 sos.dll 확장 명령어를 (비롯한 windbg의 다양한 기능을) 수행하는 방법
12115정성태1/14/202011079디버깅 기술: 157. C# - PEB.ProcessHeap을 이용해 디버깅 중인지 확인하는 방법파일 다운로드1
12114정성태1/13/202012927디버깅 기술: 156. C# - PDB 파일로부터 심벌(Symbol) 및 타입(Type) 정보 열거 [1]파일 다운로드3
12113정성태1/12/202013559오류 유형: 590. Visual C++ 빌드 오류 - fatal error LNK1104: cannot open file 'atls.lib' [1]
12112정성태1/12/202010101오류 유형: 589. PowerShell - 원격 Invoke-Command 실행 시 "WinRM cannot complete the operation" 오류 발생
12111정성태1/12/202013396디버깅 기술: 155. C# - KernelMemoryIO 드라이버를 이용해 실행 프로그램을 숨기는 방법(DKOM: Direct Kernel Object Modification) [16]파일 다운로드1
12110정성태1/11/202011987디버깅 기술: 154. Patch Guard로 인해 블루 스크린(BSOD)가 발생하는 사례 [5]파일 다운로드1
12109정성태1/10/20209888오류 유형: 588. Driver 프로젝트 빌드 오류 - Inf2Cat error -2: "Inf2Cat, signability test failed."
12108정성태1/10/20209948오류 유형: 587. Kernel Driver 시작 시 127(The specified procedure could not be found.) 오류 메시지 발생
12107정성태1/10/202010879.NET Framework: 877. C# - 프로세스의 모든 핸들을 열람 - 두 번째 이야기
12106정성태1/8/202012264VC++: 136. C++ - OSR Driver Loader와 같은 Legacy 커널 드라이버 설치 프로그램 제작 [1]
12105정성태1/8/202010963디버깅 기술: 153. C# - PEB를 조작해 로드된 DLL을 숨기는 방법
12104정성태1/7/202011640DDK: 9. 커널 메모리를 읽고 쓰는 NT Legacy driver와 C# 클라이언트 프로그램 [4]
12103정성태1/7/202014375DDK: 8. Visual Studio 2019 + WDK Legacy Driver 제작- Hello World 예제 [1]파일 다운로드2
12102정성태1/6/202011967디버깅 기술: 152. User 권한(Ring 3)의 프로그램에서 _ETHREAD 주소(및 커널 메모리를 읽을 수 있다면 _EPROCESS 주소) 구하는 방법
12101정성태1/5/202011295.NET Framework: 876. C# - PEB(Process Environment Block)를 통해 로드된 모듈 목록 열람
12100정성태1/3/20209327.NET Framework: 875. .NET 3.5 이하에서 IntPtr.Add 사용
12099정성태1/3/202011654디버깅 기술: 151. Windows 10 - Process Explorer로 확인한 Handle 정보를 windbg에서 조회 [1]
12098정성태1/2/202011229.NET Framework: 874. C# - 커널 구조체의 Offset 값을 하드 코딩하지 않고 사용하는 방법 [3]
12097정성태1/2/20209799디버깅 기술: 150. windbg - Wow64, x86, x64에서의 커널 구조체(예: TEB) 구조체 확인
12096정성태12/30/201911760디버깅 기술: 149. C# - DbgEng.dll을 이용한 간단한 디버거 제작 [1]
12095정성태12/27/201913188VC++: 135. C++ - string_view의 동작 방식
12094정성태12/26/201911368.NET Framework: 873. C# - 코드를 통해 PDB 심벌 파일 다운로드 방법
12093정성태12/26/201911423.NET Framework: 872. C# - 로딩된 Native DLL의 export 함수 목록 출력파일 다운로드1
12092정성태12/25/201910840디버깅 기술: 148. cdb.exe를 이용해 (ntdll.dll 등에 정의된) 커널 구조체 출력하는 방법
... [61]  62  63  64  65  66  67  68  69  70  71  72  73  74  75  ...