netstat -nlp 하면 가끔가다가 멈췄다가? 지연된건가 ? 하여튼 동영상 보면 알겠찌만 저런 서버들이 간혹있다.


동영상 처음올려보는데 뭔가 되게 더럽다 이상하게. 하여튼 보면 알겠지만
tcp        0      0 0.0.0.0:22                  0.0.0.0:*                   LISTEN      2983/sshd           

여기서 한번

tcp        0      0 :::22                       :::*                        LISTEN      2983/sshd           

여기서 한번 멈춘다.


이 다음껄 불러오는데 느려지는건가 아니면 저 ssh 를 불러오고난뒤?(혹은 불러오는과정이라 봐도 되나 ?)에서 느려지는건지 알아볼꺼다. strace를 이용해서 한번 찾아보자.


strace란     ##https://brunch.co.kr/@alden/12

시스템콜 시그널등을 추적하는 디버깅 툴

시스템콜이란    ##https://luckyyowu.tistory.com/133

커널단의기능을 사용자(os)가 사용할 수있게 해준다.


시그널이란   ##http://blog.naver.com/PostView.nhn?blogId=guy2648&logNo=10103891030

프로세스 구동중 예외상황(ex 컨트롤 씨로 멈춘다던가)에 발생하는 신호


주요 옵션이나 사용법등은 저기 위에 브런치 사이트에 다 있으니까 생략

-c 옵션 줘서 내용 보면

% time     seconds  usecs/call     calls    errors syscall

------ ----------- ----------- --------- --------- ----------------

 99.97    8.969419        2159      4154       377 read


리드하면서 시간도 오래걸리고 에러도 난다.



우선 netestat 명령어에 사용되는 C 함수들이 뭐뭐 있는지

~]# cat strace_netstat2  | awk '{print $3}' | awk -F "(" '{print $1}' | sort | uniq -c | sort -n

      1 +++

      1 access 파일 존재나 접근 권한을 확인

      1 arch_prctl

      1 execve 다른프로그램을 실행

      1 exit_group 프로세스 내의 모든 스레드 끝내기

      1 fcntl 파일을 전체나 파일의 일부를 다른 프로세스에서 사용하는 것을 제한

      1 statfs 파일시스템 정보 

      3 brk 데이터 세그먼트의 영역을 넓혀준다.

      7 mprotect 주어진 메모리 영역의 권한을 변경

      9 munmap 메모리 맵핑 제거

     13 fstat 열린 파일의 상태 및 정보 보기

     15 write 말그대로 write

     21 mmap 메모리매핑

   1082 close 말그대로 닫기

   1089 open 말그대로 열기

   1114 getdents 디렉토리 엔트리 불러오기

   1353 readlink 심볼릭링크된 파일을 읽기

   4308 read 일기



strace -s 65535 -f -t -o strace_netstat nestat -nlp



7127 12443 15:30:58 open("/proc/net/x25", O_RDONLY) = -1 ENOENT (No such file or directory)

7128 12443 15:30:58 open("/proc/net/nr", O_RDONLY) = -1 ENOENT (No such file or directory)

7129 12443 15:30:58 exit_group(0)            = ?

7130 12443 15:30:58 +++ exited with 0 +++


겁내 길다 하지만 진득하게 해보자


첫줄부터


   1 12443 15:30:53 execve("/bin/netstat", ["netstat", "-nlp"], [/* 23 vars */]) = 0

   2 12443 15:30:53 brk(0)                   = 0x1994000

   3 12443 15:30:53 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc359886000

   4 12443 15:30:53 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

   5 12443 15:30:53 open("/etc/ld.so.cache", O_RDONLY) = 3

   6 12443 15:30:53 fstat(3, {st_mode=S_IFREG|0644, st_size=30677, ...}) = 0


맨앞에필드는 12443는 PID다. netstat -nlp 입력했을 때의 PID 

[root@test ~]# ps -ef | grep netstat

root      9157 12279 23 14:30 pts/4    00:00:00 strace -s 65535 -f -t -o strace_netstat2 netstat -nlp

root      12443  9157  8 14:30 pts/4    00:00:00 netstat -nlp


세번째부터가 이제 어떤 시스템콜(C 함수들)이 이용됐는지가 나온다. execve brk mmap access open fstat 등등 각 함수들마다 구글링해보면 다 뭐 나온다. 뭐 변수가 어쩌고 확장이 어쩌고 저쩌고 ... 하여튼

execve 함수는 다른 프로그램을 실행하고 자신은 종료한댄다. 즉 netstat 명령어를 실행하면 execve 함수로 netstat를 실행하는듯~?

brk는 데이터 세그먼트의 영역을 넓혀준다.  라고 한다.


뭐 netstat 가 어떤식으로 구동되는지까지 알필요는 없으니까... 느려지는 부분부터 한번 봐보자.


우선 netstat에 필요한 라이브러리들

~]# ldd /bin/netstat

        linux-vdso.so.1 =>  (0x00007ffc5d6f0000)

        libselinux.so.1 => /lib64/libselinux.so.1 (0x00007f4021263000)

        libc.so.6 => /lib64/libc.so.6 (0x00007f4020ecf000)

        libdl.so.2 => /lib64/libdl.so.2 (0x00007f4020cca000)

        /lib64/ld-linux-x86-64.so.2 (0x0000562a176ac000)


   1 21682 14:52:28 execve("/bin/netstat", ["netstat", "-nlp"], [/* 24 vars */]) = 0

   2 21682 14:52:28 brk(0)                   = 0x1914000

   3 21682 14:52:28 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc716503000

   4 21682 14:52:28 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

   5 21682 14:52:28 open("/etc/ld.so.cache", O_RDONLY) = 3

   6 21682 14:52:28 fstat(3, {st_mode=S_IFREG|0644, st_size=30677, ...}) = 0

   7 21682 14:52:28 mmap(NULL, 30677, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fc7164fb000

   8 21682 14:52:28 close(3)                 = 0

   9 21682 14:52:28 open("/lib64/libselinux.so.1", O_RDONLY) = 3


ldd로 나온 라이브러리들 순서대로 불러온다. libselinux.so.1 부터 llibdl.so.2 


근데 보는것처럼 linux-vdso.so.1 이건 없다. 아마 4번째 라인에 노써치파일이 아마 이게 아닐까 ?

그리고 /lib64/ld-linux-x86-64.so.2 이것도 없다.  근데 이건 no such file  에러도 없다.  아유 어쨋든..


대충 1~50라인까지는 라이브러리 불러오는거고 60라인쯤부터 1800 라인까지는 centos 구동시 기본으로 실행되는 데몬들 open 한다.

root      1986     2  0  2018 ?        00:01:26 [edac-poller]

root      2156     2  0  2018 ?        00:00:00 [kipmi0]

root      2684     2  0  2018 ?        00:00:00 [jbd2/sda1-8]

root      2685     2  0  2018 ?        00:00:00 [ext4-dio-unwrit]

root      2717     2  0  2018 ?        00:00:00 [kauditd]

root      2893  1787  0  2018 ?        00:00:00 /sbin/udevd -d

root      2894  1787  0  2018 ?        00:00:00 /sbin/udevd -d

root      2898     2  0  2018 ?        00:10:10 [flush-8:0]

root      2963     1  0  2018 ?        00:01:01 /sbin/rsyslogd -i /var/run/syslogd.pid -c 5

root      2983     1  0  2018 ?        00:00:25 /usr/sbin/sshd

root      2997     1  0  2018 ?        00:00:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf

root      3009     1  0  2018 ?        00:01:46 crond

nobody    3278     1  0  2018 ?        00:03:04 /usr/local/checker/sbin/thttpd -C /usr/local/checker/etc/thttpd.conf

root      3561     1  0  2018 ?        00:34:50 /opt/apache/bin/httpd -k start

root      4103     1  0  2018 tty1     00:00:00 /sbin/mingetty /dev/tty1

root      4105     1  0  2018 tty2     00:00:00 /sbin/mingetty /dev/tty2

root      4107     1  0  2018 tty3     00:00:00 /sbin/mingetty /dev/tty3

root      4109     1  0  2018 tty4     00:00:00 /sbin/mingetty /dev/tty4

root      4111     1  0  2018 tty5     00:00:00 /sbin/mingetty /dev/tty5

root      4113     1  0  2018 tty6     00:00:00 /sbin/mingetty /dev/tty6

daemon   11230  3561 36 15:29 ?        00:02:33 /opt/apache/bin/httpd -k start

root     11938     1  0 15:30 ?        00:00:00 /usr/bin/python -Es /usr/bin/fail2ban-server -s /var/run/fail2ban/fail2ban.sock -p /var/run/fail2ban/fail2ban.pid -x -b

daemon   12878  3561 36 15:31 ?        00:01:42 /opt/apache/bin/httpd -k start

daemon   12900  3561 35 15:31 ?        00:01:37 /opt/apache/bin/httpd -k start

daemon   12902  3561 36 15:31 ?        00:01:42 /opt/apache/bin/httpd -k start

daemon   13409  3561 36 15:32 ?        00:01:24 /opt/apache/bin/httpd -k start

daemon   13411  3561 37 15:32 ?        00:01:26 /opt/apache/bin/httpd -k start


위와같이 실행돼있는 프로세스들중

root      2894  1787  0  2018 ?        00:00:00 /sbin/udevd -d

root      2898     2  0  2018 ?        00:10:10 [flush-8:0]

root      2963     1  0  2018 ?        00:01:01 /sbin/rsyslogd -i /var/run/syslogd.pid -c 5

root      2983     1  0  2018 ?        00:00:25 /usr/sbin/sshd

여기까지가 아마 os 구동시 기본으로 구동되는 데몬이라고 생각할 수 있을것같다.


strace 파일 보면

1992 12443 15:30:53 open("/proc/2983/attr/current", O_RDONLY) = 5

1993 12443 15:30:53 read(5, 0x19a53e0, 4095) = -1 EINVAL (Invalid argument)

1994 12443 15:30:53 close(5)                 = 0

1995 12443 15:30:53 readlink("/proc/2983/fd/4", "socket:[12960]", 29) = 14

1996 12443 15:30:53 open("/proc/2983/attr/current", O_RDONLY) = 5

1997 12443 15:30:53 read(5, 0x19a5440, 4095) = -1 EINVAL (Invalid argument)

1998 12443 15:30:53 close(5)                 = 0

1999 12443 15:30:53 getdents(4, /* 0 entries */, 32768) = 0

2000 12443 15:30:53 close(4)                 = 0

2001 12443 15:30:53 open("/proc/2997/fd", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4

2002 12443 15:30:53 getdents(4, /* 3 entries */, 32768) = 72

2003 12443 15:30:53 readlink("/proc/2997/fd/3", "socket:[12989]", 29) = 14

2004 12443 15:30:53 open("/proc/2997/cmdline", O_RDONLY) = 5

2005 12443 15:30:53 read(5, "/usr/sbin/vsftpd\0/etc/vsftpd/vsftpd.conf\0", 511) = 41

2006 12443 15:30:53 close(5)                 = 0

2007 12443 15:30:53 open("/proc/2997/attr/current", O_RDONLY) = 5

이제 대충 어떤느낌인지 알겠다. 

netstat -nlp 하면 모든 프로세스들 불러오고 그중에 데몬 리스트를 pid랑 port랑 이런식으로 출력해주는거니까


1.netstat -nlp 입력시 netstat에 사용되는 라이브러리를 open mmap read close등을 진행 - 50라인쯤

2.OS에 올라와있는 모든 프로세스를 pid순으로 open/작업(getdents,read,readlink등)/close 진행 - 5400라인쯤

ㄴnetstat -nlp는 정보를 보는거니까 당연히 위와같은 디렉토리엔트리를 불러오거나 뭘 읽거나 하겠죠?

3.5400라인쯤부터 이제 netstat -nlp했을 때 나오는 문장들을 write 함수로 쓴다.

정확히는 12443 15:30:56 open("/proc/net/tcp6", O_RDONLY) = 3 이런식으로 /proc/net/tcp6 을 불러와서

12443 15:30:56 read(3, "  sl  local_address                         remote_address                        st tx_queue

위와같이 읽은다음 

12443 15:30:56 write(1, "tcp        0      0 :::5000                     :::*                        LISTEN      3278/thttpd         \n", 109) = 109

이렇게 실제로 write를 한다.



##########

여담

5392 12443 15:30:54 open("/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3

5393 12443 15:30:54 fstat(3, {st_mode=S_IFREG|0644, st_size=2512, ...}) = 0

5394 12443 15:30:54 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc359885000

5395 12443 15:30:54 read(3 어쩌구 저쩌구 /usr/share/locale/locale.alias 내용 나옴)

netstat -nlp 했는데 위 파일을 왜 열지 ? 궁금해서 이 파일 삭제하고서 netstat -nlp 실행해봤다.

1044 29673 16:02:34 open("/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

1045 29673 16:02:34 open("/usr/share/locale/en_US.UTF-8/LC_MESSAGES/net-tools.mo", O_RDONLY) = -1 ENOENT (No such file or directory)

1046 29673 16:02:34 open("/usr/share/locale/en_US.utf8/LC_MESSAGES/net-tools.mo", O_RDONLY) = -1 ENOENT (No such file or directory)

1047 29673 16:02:34 open("/usr/share/locale/en_US/LC_MESSAGES/net-tools.mo", O_RDONLY) = -1 ENOENT (No such file or directory)

그냥 에러나고 끝이다. 실행도 잘된다. 근데 내가 에러를 못찾은거일수도있다. 하고자 하는 말이뭐냐면... 그냥 뭐랄까 별에 별파일을 다 쓰는구나. 함부로 지우지말자.

#######

4.그리고 exit_group 끝





자 이글의 목적인 netstat -nlp 시 왜 특정구간(sshd 데몬쪽)에서 느려지는건지 이제 이유가 보인다.


6270 12443 15:30:56 write(1, "tcp        0      0 :::5000                     :::*                        LISTEN      3278/thttpd         \n", 109) = 109

6271 12443 15:30:56 write(1, "tcp        0      0 :::81                       :::*                        LISTEN      3561/httpd          \n", 109) = 109

6272 12443 15:30:56 write(1, "tcp        0      0 :::22                       :::*                        LISTEN      2983/sshd           \n", 109) = 109

6273 12443 15:30:56 read(3, "00000000000000FFFF00006F7926DA:0051 0000000000000000FFFF00006F7926DA:B4EE 06 00000000:00000000 03:00000000 00000000     0        0 0 3 ffff880c74c5a940\n   6: 0000000000000000FFFF00

     006F7926DA:0051 0000000000000000FFFF00006F7926DA:CFA8 06 00000000:00000000 03:0000115F 00000000     0        0 0 3 ffff880939ba0580\n   7: 0000000000000000FFFF00006F7926DA:0051 0000000000000000FFFF00006F79

     26DA:D73A 06 00000000:00000000 03:000016E8 00000000     0        0 0 3 ffff880814409840\n   8: 0000000000000000FFFF00006F7926DA:0051 0000000000000000FFFF00006F7926DA:A626 06 00000000:00000000 03:00000000 0

     0000000     0        0 0 3 ffff880c76532440\n   9: 0000000000000000FFFF00006F7926DA:0051 0000000000000000FFFF00006F7926DA:A708 06 00000000:00000000 03:00000000 00000000     0        0 0 3 ffff88086fff6200\

     n  10: 0000000000000000FFFF00006F7926DA:0051 0000000000000000FFFF00006F7926DA:D7A6 06 00000000:00000000 03:00001730 00000000     0        0 0 3 ffff880927c64200\n  11: 0000000000000000FFFF00006F7926DA:0051

      0000000000000000FFFF00006F79", 1024) = 1024




이런식으로 6273 같은 라인이 진짜 어~~~마무시하게 read가 많이 이루어진다.

거의 800라인 가까이 위와같은 read작업이 이루어진다. 다른 정상인 서버들은 저러지 않는다. 저 read작업이 뭔지 알면되겠다.


5418 12443 15:30:54 read(3, "                         \n   6: 6F7926DA:C56A 6F7926DA:0051 06 00000000:00000000 03:00000B1B 00000000     0        0 0 3 

ffff8808728b24c0                                      \n   7: 6F7926DA:0050 9158E6C0:A773 06 00000000:00000000 03:00000000 00000000     0        0 0 3 

ffff88086f41e280                                      \n   8: 6F7926DA:0050 2158E6C0:     E732 06 00000000:00000000 03:00000000 00000000     0        0 0 3 

ffff880871e65dc0                                      \n   9: 6F7926DA:D3A8 6F7926DA:0051 06 00000000:00000000 03:00001533 00000000     0        0 0 3 

ffff880c77a5bdc0                                      \n  10: 6F7926DA:C4D6 6F7926DA:0051 06 00000000:00000000 03:00000AB8 00000000     0        0 0 3 

ffff880c751e3cc0                                      \n  11: 6F7926DA:0050 0158E6C0:92FB 06 00000000:00000000 03:00000000 00000000     0        0 0 3 

ffff88087048b580                                      \n  12: 6F7926DA:CF10 6F7926DA:0051 06 00000000:00000000 03:00001205 00000000     0        0 0 3 fff", 1024) = 1024


netstat -nlp 했을 때/proc/net/tcp /proc/net/tcp6 두 파일을 베이스로 netstat는 출력하는 명령어다. (자세한건 https://www.joinc.co.kr/w/Site/system_programing/proc/NetState)

/proc/net/tcp 는 tcp 정보를 아스키형태로 저장된 파일임

netstat -nlp 했을 때 출력되는건 TIME_WAIT이 배제된채로 출력되지만 실제로는 /proc/net/tcp 이거를 전부 read 하게 된다.  /proc/net/tcp여기에는 TIME_WAIT 관련 정보까지 전부 저장되기 때문에 TIME_WAIT이 많은 서버들에서 대체로 netstat -nlp 가 오래걸린다.


처음에는 sshd 명령어 이후에 딜레이 되니까 ssh쪽이 뭐 문제인가 아니면 thttpd를 불러오는데 뭐가 문제인가 싶었는데 완전 틀렸다.









'job > linux' 카테고리의 다른 글

nodejs npm , socket.io 설치  (0) 2019.04.10
ionice  (1) 2019.04.09
php-fpm 메모리 사용률 확인하고 튜닝하기  (2) 2019.02.20
geoip iptables 설치  (2) 2019.02.15
rsync를 통한 파일 전송시 속도 테스트  (0) 2018.12.06

+ Recent posts