From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 22185 invoked by alias); 18 Feb 2012 16:10:50 -0000 Received: (qmail 22174 invoked by uid 22791); 18 Feb 2012 16:10:46 -0000 X-SWARE-Spam-Status: No, hits=-1.6 required=5.0 tests=AWL,BAYES_00,RCVD_IN_DNSWL_NONE X-Spam-Check-By: sourceware.org Received: from smtpout.karoo.kcom.com (HELO smtpout.karoo.kcom.com) (212.50.160.34) by sourceware.org (qpsmtpd/0.43rc1) with ESMTP; Sat, 18 Feb 2012 16:10:30 +0000 Received: from 213-152-38-55.dsl.eclipse.net.uk (HELO [192.168.1.105]) ([213.152.38.55]) by smtpout.karoo.kcom.com with ESMTP; 18 Feb 2012 16:10:28 +0000 Message-ID: <4F3FCD74.6060101@dronecode.org.uk> Date: Sat, 18 Feb 2012 16:10:00 -0000 From: Jon TURNEY Reply-To: cygwin-xfree User-Agent: Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20120216 Thunderbird/10.0.2 MIME-Version: 1.0 To: cygwin-xfree@cygwin.com CC: jeffrey.l.bonggren@boeing.ksc.nasa.gov, cygwin@sipxx.com Subject: Re: XWin.exe: _XSERVTransSocketUNIXAccept: accept() failed References: <4F3EA2CF.7040701@dronecode.org.uk> In-Reply-To: <4F3EA2CF.7040701@dronecode.org.uk> Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Mailing-List: contact cygwin-xfree-help@cygwin.com; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: cygwin-xfree-owner@cygwin.com Reply-To: cygwin-xfree@cygwin.com Mail-Followup-To: cygwin-xfree@cygwin.com X-SW-Source: 2012-02/txt/msg00040.txt.bz2 On 17/02/2012 18:56, Jon TURNEY wrote: > On 15/02/2012 16:39, Bonggren, Jeffrey L wrote: >> I have recently noticed that XWin.exe is spinning and maxing out a CPU >> core. I checked the log and saw that it is spamming it with >> "_XSERVTransSocketUNIXAccept: accept() failed" messages at a rate of about >> one per millisecond. This is generating a very large log file! > > Thanks for reporting this. > > This seems to be related in some way to how you start the X server. Starting > it using startxwin.exe (the recommended method), I don't observe this problem, > but using your startxwin.bat, I can reproduce the problem. > > The obvious difference here between these two cases is that we don't have a > cygwin process as our immediate ancestor when started from a batch file, but > how that could make a difference is a bit mysterious. > > This seems to be some sort of regression introduced with the cygwin 1.7.10 > DLL, downgrading to 1.7.9 doesn't show the problem (although that is > problematic as base-files now depends on tzset introduced in 1.7.10) stracing this is enlightening... 281 23126144 [main] XWin 3084 cygwin_select: select(255, 0x5FDE80, 0x0, 0x0, 0x22CBB4) 35 23126179 [main] XWin 3084 dtable::select_read: fd 0 32 23126211 [main] XWin 3084 dtable::select_read: fd 1 171 23126382 [main] XWin 3084 dtable::select_read: /usr/adm/X0msgs fd 2 33 23126415 [main] XWin 3084 dtable::select_read: /dev/windows fd 5 32 23126447 [main] XWin 3084 dtable::select_read: fd 7 170 23126617 [main] XWin 3084 dtable::select_read: fd 9 32 23126649 [main] XWin 3084 dtable::select_read: fd 10 31 23126680 [main] XWin 3084 dtable::select_read: fd 12 166 23126846 [main] XWin 3084 cygwin_select: to->tv_sec 560, to->tv_usec 203000, ms 560203 21 23126867 [main] XWin 3084 cygwin_select: sel.always_ready 1 25 23126892 [main] XWin 3084 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0 21 23126913 [main] XWin 3084 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0 211 23127124 [main] XWin 3084 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0 25 23127149 [main] XWin 3084 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0 18 23127167 [main] XWin 3084 peek_windows: window 5(0x0) not ready 17 23127184 [main] XWin 3084 set_bits: me 0x20511260, testing fd 2 (/usr/adm/X0msgs) 206 23127390 [main] XWin 3084 set_bits: ready 1 25 23127415 [main] XWin 3084 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0 22 23127437 [main] XWin 3084 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0 17 23127454 [main] XWin 3084 cygwin_select: 1 = select(255, 0x5FDE80, 0x22CA10, 0x22C9E0, 0x22CBB4) 208 23127662 [main] XWin 3084 select_stuff::cleanup: calling cleanup routines 20 23127682 [main] XWin 3084 socket_cleanup: si 0x0 si->thread 0x0 17 23127699 [main] XWin 3084 socket_cleanup: si 0x0 si->thread 0x0 23 23127722 [main] XWin 3084 socket_cleanup: si 0x0 si->thread 0x0 17 23127739 [main] XWin 3084 socket_cleanup: si 0x0 si->thread 0x0 17 23127756 [main] XWin 3084 socket_cleanup: si 0x0 si->thread 0x0 278 23128034 [main] XWin 3084 socket_cleanup: si 0x0 si->thread 0x0 22 23128056 [main] XWin 3084 select_stuff::destroy: deleting select records 279 23128335 [main] XWin 3084 __set_errno: fhandler_socket* get(int):83 setting errno 108 20 23128355 [main] XWin 3084 cygwin_accept: -1 = accept(2, 0x22C92E, 0x22C99C), errno 108 92 23128447 [main] XWin 3084 write: write(3, 0x5F93A0, 13) 161 23128608 [main] XWin 3084 write: 13 = write(3, 0x5F93A0, 13) 236 23128844 [main] XWin 3084 write: write(3, 0x5F93A0, 11) 20 23128864 [main] XWin 3084 write: 11 = write(3, 0x5F93A0, 11) 964 23129828 [main] XWin 3084 write: 45 = write(2, 0x5FA880, 45) 191 23130019 [main] XWin 3084 write: write(3, 0x5F93A0, 34) 21 23130040 [main] XWin 3084 write: 34 = write(3, 0x5F93A0, 34) When started from a Windows parent process, stdin/stdout/stderr are closed, so the X server opens /usr/adm/X0msgs to write stderr output to. However, due to a bug in the X server, when doing that we can trample all over a socket listening on a well-known port, which has already been opened with fd 2. If that file fd ever shows as ready for reading, we will try to accept a connection on it, which is always going to fail :-) This can easily be reproduced using 'X 2>&-', which shows the same spinning behaviour. (In OsInit(), we check if fd 2 is writeable, and if not, assume stderr has been closed, and open /usr/adm/X0msgs for writing, and dup it on to fd 2. Unfortunately, this happens after CreateWellknownSockets() has opened the listener sockets, and that may use fd 2) This bug has been there a long time, I'm not sure why it's problem now, perhaps the cygwin DLL has changed behaviour so this fd is now always found ready to read? I've applied fix to address this, so hopefully this works better now. I've uploaded a snapshot at [1]. Perhaps you could try that out and see if that makes a difference? [1] ftp://cygwin.com/pub/cygwinx/XWin.20120218-git-c3b936a38812f88b.exe.bz2 -- Jon TURNEY Volunteer Cygwin/X X Server maintainer -- Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple Problem reports: http://cygwin.com/problems.html Documentation: http://x.cygwin.com/docs/ FAQ: http://x.cygwin.com/docs/faq/