[Davmail-users] debugging davmail deadlock
Brought to you by:
mguessan
From: John H. <a27...@sn...> - 2017-10-06 16:24:51
|
Occasionally, davmail gets into a deadlock state where it won't respond to incoming requests. Also it doesn't clean up after the socket that is opened for each request. netstat on the davmail server show a growing list of sockets in CLOSE_WAIT state [1], one per new connection (ESTABLISHED state while the client holds the socket open, then CLOSE_WAIT when the client is manually killed or times out). Kill / restart davmail resolves the condition until eventually (possibly days or weeks later after possibly 1000s of serviced IMAP requests), it happens again. This is with openjdk-7.80.15 on FreeBSD. It looks like threads are deadlocked on a mutex. System call trace shows something like this repeated pattern: . . 27611 java 1507303977.296917 CALL _umtx_op(0x80062c0c8,0xf,0,0,0x7fffff3f5b20) 27611 java 1507303977.356860 RET _umtx_op -1 errno 60 Operation timed out 27611 java 1507303977.356884 CALL clock_gettime(0x4,0x7fffff3f5c90) 27611 java 1507303977.356890 RET clock_gettime 0 27611 java 1507303977.356898 CALL gettimeofday(0x7fffff3f5c50,0) 27611 java 1507303977.356903 RET gettimeofday 0 27611 java 1507303977.356907 CALL clock_gettime(0x4,0x7fffff3f5c90) 27611 java 1507303977.356911 RET clock_gettime 0 27611 java 1507303977.356915 CALL gettimeofday(0x7fffff3f5bc0,0) 27611 java 1507303977.356919 RET gettimeofday 0 27611 java 1507303977.356924 CALL clock_gettime(0,0x7fffff3f5b30) 27611 java 1507303977.356928 RET clock_gettime 0 27611 java 1507303977.356932 CALL _umtx_op(0x80062c0c8,0xf,0,0,0x7fffff3f5b20) 27611 java 1507303977.416837 RET _umtx_op -1 errno 60 Operation timed out 27611 java 1507303977.416860 CALL clock_gettime(0x4,0x7fffff3f5c90) 27611 java 1507303977.416866 RET clock_gettime 0 27611 java 1507303977.416873 CALL gettimeofday(0x7fffff3f5c50,0) 27611 java 1507303977.416878 RET gettimeofday 0 27611 java 1507303977.416882 CALL clock_gettime(0x4,0x7fffff3f5c90) 27611 java 1507303977.416886 RET clock_gettime 0 27611 java 1507303977.416890 CALL gettimeofday(0x7fffff3f5bc0,0) 27611 java 1507303977.416894 RET gettimeofday 0 27611 java 1507303977.416899 CALL clock_gettime(0,0x7fffff3f5b30) 27611 java 1507303977.416903 RET clock_gettime 0 27611 java 1507303977.416907 CALL _umtx_op(0x80062c0c8,0xf,0,0,0x7fffff3f5b20) 27611 java 1507303977.476838 RET _umtx_op -1 errno 60 Operation timed out . . Has this been observed by others in the past? What's the best way to debug davmail to zero in on the lock problem. [1] 192.168.0.1 = server where davmail is running (made up IP) 192.168.0.2 = client sending IMAP requests to davmail tcp4 0 0 192.168.0.1.1143 192.168.0.2.24945 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.24944 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.24943 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.24942 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.24941 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.22171 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.61242 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.10853 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.10852 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.10845 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.59489 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.12174 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.43944 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.51586 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.56173 CLOSE_WAIT tcp4 0 0 192.168.0.1.1143 192.168.0.2.35585 CLOSE_WAIT tcp46 0 0 *.1143 *.* LISTEN |