mutex에서 lock을 풀었는데 안 풀려요...
threadpoll 방식을 써서 채팅서버프로그램을 만들고 있습니다.
문제가 생겨서 그러는데요, 쓰레드가 이상없이 잘 돌다가 아무 때나 멈추버립니다. 작업 처리량이 많을 때 특히 잘 멈추고 작업이 없을 때에도 멈춥니다.
소스상의 에러나 로직상의 잘못이 있는지 아무리 찾아봐고 찾질 못하겠구요...
아래는 쓰레드가 멈출 당시의 stack입니다.
(gdb) info thread
* 32 Thread 30751 (LWP 14992) 0x4012390e in __select () from /lib/i686/libc.so.6
31 Thread 29726 (LWP 14991) 0x4012390e in __select () from /lib/i686/libc.so.6
30 Thread 28701 (LWP 14990) 0x4012390e in __select () from /lib/i686/libc.so.6
29 Thread 27676 (LWP 14989) 0x4012390e in __select () from /lib/i686/libc.so.6
28 Thread 26651 (LWP 14988) 0x4012390e in __select () from /lib/i686/libc.so.6
27 Thread 25626 (LWP 14987) 0x4012390e in __select () from /lib/i686/libc.so.6
26 Thread 24601 (LWP 14986) 0x4012390e in __select () from /lib/i686/libc.so.6
25 Thread 23576 (LWP 14985) 0x4012390e in __select () from /lib/i686/libc.so.6
24 Thread 22551 (LWP 14984) 0x4012390e in __select () from /lib/i686/libc.so.6
23 Thread 21526 (LWP 14983) 0x4012390e in __select () from /lib/i686/libc.so.6
22 Thread 20501 (LWP 14982) 0x4012390e in __select () from /lib/i686/libc.so.6
21 Thread 19476 (LWP 14981) 0x4012390e in __select () from /lib/i686/libc.so.6
20 Thread 18451 (LWP 14980) 0x400708a5 in __sigsuspend (set=0x4917196c) at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
19 Thread 17426 (LWP 14979) 0x4012390e in __select () from /lib/i686/libc.so.6
18 Thread 16401 (LWP 14978) 0x4012390e in __select () from /lib/i686/libc.so.6
17 Thread 15376 (LWP 14977) 0x4012390e in __select () from /lib/i686/libc.so.6
16 Thread 14351 (LWP 14976) 0x4012390e in __select () from /lib/i686/libc.so.6
15 Thread 13326 (LWP 14975) 0x4012390e in __select () from /lib/i686/libc.so.6
14 Thread 12301 (LWP 14974) 0x4012390e in __select () from /lib/i686/libc.so.6
13 Thread 11276 (LWP 14973) 0x4012390e in __select () from /lib/i686/libc.so.6
12 Thread 10251 (LWP 14972) 0x4012390e in __select () from /lib/i686/libc.so.6
11 Thread 9226 (LWP 14971) 0x4012390e in __select () from /lib/i686/libc.so.6
10 Thread 8201 (LWP 14970) 0x4012390e in __select () from /lib/i686/libc.so.6
9 Thread 7176 (LWP 14969) 0x4012390e in __select () from /lib/i686/libc.so.6
8 Thread 6151 (LWP 14968) 0x4012390e in __select () from /lib/i686/libc.so.6
7 Thread 5126 (LWP 14967) 0x4012390e in __select () from /lib/i686/libc.so.6
6 Thread 4101 (LWP 14966) 0x4012390e in __select () from /lib/i686/libc.so.6
5 Thread 3076 (LWP 14965) 0x4012390e in __select () from /lib/i686/libc.so.6
4 Thread 2051 (LWP 14964) 0x4012390e in __select () from /lib/i686/libc.so.6
3 Thread 1026 (LWP 14963) 0x4012390e in __select () from /lib/i686/libc.so.6
2 Thread 2049 (LWP 14962) 0x40122227 in __poll (fds=0x8c36a3c, nfds=1, timeout=2000) at ../sysdeps/unix/sysv/linux/poll.c:63
1 Thread 1024 (LWP 14961) 0x4012390e in __select () from /lib/i686/libc.so.6
위에서 보시면 쓰레드 하나가 멈춰있는 걸 보실 수 있을 겁니다. 제 프로그램은 쓰레드사이의 context switching을 위해 select()를 사용해서 sleep()대신 쓰고 있습니다. 그래서 모든 쓰레드가 select() 중에 있습니다.
(gdb) thr 20
[Switching to thread 20 (Thread 18451 (LWP 14980))]#0 0x400708a5 in __sigsuspend (set=0x4917196c)
at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
45 ../sysdeps/unix/sysv/linux/sigsuspend.c: No such file or directory.
in ../sysdeps/unix/sysv/linux/sigsuspend.c
(gdb) where
#0 0x400708a5 in __sigsuspend (set=0x4917196c) at ../sysdeps/unix/sysv/linux/sigsuspend.c:45
#1 0x400370d9 in __pthread_wait_for_restart_signal (self=0x49172c00) at pthread.c:934
#2 0x40038879 in __pthread_lock (lock=0x8aed664, self=0x49172c00) at restart.h:34
#3 0x40035ca6 in __pthread_mutex_lock (mutex=0x8aed654) at mutex.c:109
#4 0x080523db in GetCliReceivedPacket () at Common.cpp:2506
#5 0x08067e72 in ClientProcessingThread (pParam=0x70011) at ClientWork.cpp:2615
#6 0x40034bfd in pthread_start_thread (arg=0x49172c00) at manager.c:262
#7 0x40034cdf in pthread_start_thread_event (arg=0x49172c00) at manager.c:285
멈춰있는 쓰레드의 상태를 보면 pthread_mutex_lock를 호출한 후입니다. #4과 #5번이 제가 만든 함수 입니다. Threadpoll방식을 쓰므로 Queue를 사용해서 쓰레들 사이의 작업을 나누었습니다. ClientProcessingThread ()에서는 GetCliReceivedPacket()를 끊임없이 호출하여 Queue에 계속 접근해서 Queue에 처리할 자료가 있는지 없는지를 확인을 합니다.
이때 Queue에 접근하기전에 pthread_mutex_lock()을 이용하여 lock을 걸고 처리할 자료가 있으면 pthread_mutex_unlock()을 이용해서 lock을 풀고 index를 반환합니다. 처리할 자료가 없으면 mutex를 풀고 그냥 NULL을 반환합니다. 지금 위의 상황이 Queue에 접근하기전 mutex를 걸고 멈추어 있는 상황입니다.
일정 시점이나 일정 작업후에 이런 일이 있으면 그 부분만 집중적으로 디버깅하면 되니까 작업하기가 쉬울 텐데 그렇질 않고 한 동안 잘 돌다가 갑자기 이러니 그 이유를 알 수가 없을 뿐더러 답답히기가 그지 없네요.
참고로 서버머신의 사양과 리눅스버젼에 대한 정보는 아래와 같습니다.
[root@linux ChatServer_2.0.0.1_20030211]# uname -a
Linux linux 2.4.2-2wlsmp #1 SMP 금 6월 8 04:33:49 KST 2001 i686 unknown
[root@linux ChatServer_2.0.0.1_20030211]# cat /proc/cpuinfo
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 7
model name : Pentium III (Katmai)
stepping : 3
cpu MHz : 551.264
cache size : 512 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 2
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 mmx fxsr sse
bogomips : 1101.00
processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 7
model name : Pentium III (Katmai)
stepping : 3
cpu MHz : 551.264
cache size : 512 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 2
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 mmx fxsr sse
bogomips : 1101.00
[root@linux ChatServer_2.0.0.1_20030211]# cat /proc/meminfo
total: used: free: shared: buffers: cached:
Mem: 1052831744 925806592 127025152 0 221351936 522469376
Swap: 1850646528 0 1850646528
MemTotal: 1028156 kB
MemFree: 124048 kB
MemShared: 0 kB
Buffers: 216164 kB
Cached: 510224 kB
Active: 686472 kB
Inact_dirty: 36556 kB
Inact_clean: 3360 kB
Inact_target: 724 kB
HighTotal: 131008 kB
HighFree: 2036 kB
LowTotal: 897148 kB
LowFree: 122012 kB
SwapTotal: 1807272 kB
SwapFree: 1807272 kB
미리 답변에 감사드립니다.
mutex
누가 한녀석이 잠그고 안풀었을 때의 모습 같습니다.
mutex 로 제한하고 있는 크리티컬섹션의 모든 탈출구에 mutex를 푸는 녀석이 있는지 확인을 해보심이....
---
http://coolengineer.com
우선 답변에 감사드립니다.말씀하신대로 저의 실수로 mutex를 걸고
우선 답변에 감사드립니다.
말씀하신대로 저의 실수로 mutex를 걸고 안 풀었다면(물론 두 눈으로 셀수 없을 만큼 확인을 했습니다만) 일정한 동작중에 위와 같은 문제가 발생해야 한다고 봅니다. 하지만 위와 같은 문제는 일정치 않은 시점과 작업도중 일어난다는 것입니다.
condition을 써 보심이 어떨지.
stack을 보고는 감을 잡을 수가 없네요. :?
기계 사양을 보고서도 알수가 없구요. :-P
다만, Q가 비어 있을때도 lock걸고 접근을 한다음 할게 없으면 unlock하고 빠지는 것 보다는,
condition variable을 써서, 쓰레드들을 Q에 줄 세우는 것이 좋을 것 같습니다.
여담입니다만,
이런 문제는 원래 자기가 보면 잘 안보입니다.
옆에 아무라도 앉혀놓고 찬찬히 설명을 해 주면서 같이 보다보면 보일지도.. :)
문제의 해결과는 관련이 없지만 큐를 한개 두는것 보다 여러개 두는게 더
문제의 해결과는 관련이 없지만 큐를 한개 두는것 보다 여러개 두는게 더 좋지
않을까요?
큐에서 가져오는 소스를 올려줘 보심이 도움이 될듯 합니다.
screen + vim + ctags 좋아요~
[code:1]CVoidPacket* GetCliReceivedPacke
말씀하신 Q에 접근하는 함수입니다. mutex를 걸고, Q의 Index 하나를 할당 받았을 때 증가하는 g_nCliPacketQHead와 위 함수에서 현재 처리중임을 나타내기 위해 증가하는 g_nCliPacketQPtr가 다른 경우, 즉 Q에 처리할 자료가 있을 경우 while루프문안에 들어가게 됩니다. Q에 처리할 자료가 없을 경우 mutex를 풀고 NULL을 반환합니다.
참고로 아래는 CPacketQ_mutex를 인자로 mutex를 이용하는 Q관련 함수들입니다. 이 곳 외에서는 CPacketQ_mute를 인자로 이용하지 않습니다.
한가지 의심이 가는 것은 제가 Context Switching을 위해서 sleep()대신 쓴 select()라는 함수인데요, 이 함수를 timer로 썼다가 낭패를 봤다는 글을 외국의 뉴스그룹에서 봤습니다. mutex에서 안풀리는 저와 같은 문제요. 이게 문제가 된 건 아닐까요?
한 쓰레드가 lock 한뒤 혹시 다른 쓰레드에서 CPacketQ_mute
한 쓰레드가 lock 한뒤 혹시 다른 쓰레드에서 CPacketQ_mutex 위쯤에선언된 변수를 잘못 조작해 overflow 가 나서 mutex 정보를 망가뜨리고, unlock이 실패하는 경우가 있지않을까요?
모든 pthread_mutex_unlock 의 성공여부를 로그로 남겨 보시는 것은
어떨지요...
---
http://coolengineer.com
우선 답변에 감사드립니다.[quote="pynoos"]한 쓰레드가
우선 답변에 감사드립니다.
위에서 말씀하신 overflow가 나게 되더라도 mutex를 풀고 NULL을 반환합니다. 그리고 callstack를 보더라도 mutex를 걸고 멈춰있음을 확인 하실 수 있으실 겁니다. unlock에 실패했다는 것을요...
select 괜찮을 겁니다.
그렇게 써서 문제 없는 경험도 있었고,
glibc source를 보니까, sleep을 select로 구현한 부분이 있더군요.
[quote="김영훈"][code:1]CVoidPacket* GetCli
screen + vim + ctags 좋아요~
[quote="김충길"]gdb 출력을 보면 이 함수의 while을 못 빠
님께서 말씀하신 대로 계속 루프를 돈다면 아마 루프를 도는 쓰레드는 cpu를 100%점유해야 할 것입니다. GetCliReceivedPacket() 함수 그 어디에도 sleep()을 해주는 부분이 없으니까요. 하지만 쓰레드가 멈췄을 때 top이나 ps -aux등의 명령어로 cpu점유상태를 확인 해보면 전혀 점유를 하지 않습니다. 답변에 감사드립니다.
댓글 달기