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를 불러오는데 뭐가 문제인가 싶었는데 완전 틀렸다.
끝
