X-Recipient: archive-cygwin AT delorie DOT com DomainKey-Signature: a=rsa-sha1; c=nofws; d=sourceware.org; h=list-id :list-unsubscribe:list-subscribe:list-archive:list-post :list-help:sender:mime-version:from:date:message-id:subject:to :content-type; q=dns; s=default; b=kOiwahthdhh+B8KSj128J5EEyBk5B rBTyyqfSysa+4FE47r3dg9Or2Js/9ghawtj89DV7XtLC7pa6GPy/5b6nPXTt26bs KHSBAi5YsDnXc5C7k83QUGLWTvf0ZwcRfmDHmd8UZdT+Mc4TmcbkN3SfWqh6lUXC JISsqQTapRZT2s= DKIM-Signature: v=1; a=rsa-sha1; c=relaxed; d=sourceware.org; h=list-id :list-unsubscribe:list-subscribe:list-archive:list-post :list-help:sender:mime-version:from:date:message-id:subject:to :content-type; s=default; bh=1MFEQ7bQNsQcxYBvTLDEl9vbOfQ=; b=lI6 in54eLMVdFckKFmbYyUQHseYkljzufPXzpdrapNBDyvgCW8YNKz/y91q5I3gptGr KLmZD0Pzqal2woihT+I3VAgqQw2ypiJZT0RfJL+59OGu2PeNyXe2xdf/eawcZpqh +VDGLDzpZjuuR2MqK18WRycNuUeTo6OMWvRAMqbY= Mailing-List: contact cygwin-help AT cygwin DOT com; run by ezmlm List-Id: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: cygwin-owner AT cygwin DOT com Mail-Followup-To: cygwin AT cygwin DOT com Delivered-To: mailing list cygwin AT cygwin DOT com Authentication-Results: sourceware.org; auth=none X-Virus-Found: No X-Spam-SWARE-Status: No, score=-1.3 required=5.0 tests=AWL,BAYES_00,FREEMAIL_FROM,RCVD_IN_DNSWL_NONE,RCVD_IN_SORBS_SPAM,SPF_PASS autolearn=no version=3.3.2 spammy=isatty, connects, Attached, socket X-HELO: mail-ua0-f179.google.com X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:from:date:message-id:subject:to; bh=1AzLPo8Jgj86yiavjw6DTZgfdFXpAz66mqnVHJgXL7E=; b=bEaCpCdK2ZGjQFoXn35D4MSYUcS3Ln3NGb7W1aMGOdI1BPwboWVc/qLk5TqPqqsVKc jpmTr2mfqPB6ms8Zz4R5RLUYRFIdwDZUzhuZa2WO7TuFLO+trYB79YUmauDhNeVikRI6 VsZY+4wI7hm2nPHKmVFF9So6pgpWQ0V2aTiOojRbg4l5/p31aZQ5WNqLCfBHQImf9v6+ o1Z7RpPS/VH9fskRJy40pPXOu9uv2DY1fhVn9B6ovimK97lRFRORIfGSNsyCZQ2blpd2 pIbEHX34Kd2+5526tQgNyjDD8OB97Dm6Q7IJe/f356w7YtbjddUZ/QvIdvDaTzG5lDdg yksg== X-Gm-Message-State: AIkVDXIMRIpPinBT1OUh8AG3trjXlY9/BjfDZco1IA2tVbhmhYI2XYedxrGBa+N8bPB129J3SuYyGLBGO4Ad2w== X-Received: by 10.176.84.150 with SMTP id p22mr57727348uaa.50.1483702836454; Fri, 06 Jan 2017 03:40:36 -0800 (PST) MIME-Version: 1.0 From: Erik Bray Date: Fri, 6 Jan 2017 12:40:35 +0100 Message-ID: Subject: Cygwin hanging in pselect To: cygwin AT cygwin DOT com Content-Type: multipart/mixed; boundary=94eb2c1b110285117805456b7c13 X-IsSubscribed: yes --94eb2c1b110285117805456b7c13 Content-Type: text/plain; charset=UTF-8 Hello, and happy new-ish year, I've been working on and off over the past few months on bringing Python's compatibility with Cygwin up to snuff, including having all pertinent tests passing. I've noticed that there are several tests (which I currently skip) that cause the process to hang indefinitely, and not respond to any signals from Cygwin (it can only be killed from Windows). This is Cygwin 64-bit--I have not tested 32-bit. I finally looked into this problem and found the lockup to be in pselect() somewhere. Attached I've provided the most minimal example I've been able to come up with so far that reproduces the problem, which I'll describe in a bit more detail next. I would attach a cygcheck output if requested, but I was also able to reproduce this on a recent build from source. So far as I've been able to tell, the problem only occurs with AF_UNIX sockets. In the example I have a 'server' socket and a 'client' socket both set to non-blocking. The client connects to the socket, returning errno EINPROGRESS as expected. Then I do a pselect on the client socket to wait until it is ready to be read from. The hang only happens when I pselect on the client socket, and not on the server socket. It doesn't seem to make a difference what the timeout is. One thing I have no tried is if the client and server are actually different processes, but the example from the Python tests this is reproducing is where they are both in the same process. Below is (I think) the most relevant output from strace on the test case. It seems to hang somewhere in socket_cleanup, but I haven't investigated any further than that. Thanks, Erik 261 14732 [main] poll_test 79200 cygwin_socket: socket (1, 1 (flags 0x0), 0) --- Process 79200 loaded C:\Windows\System32\ws2_32.dll at 00007FFF8D5D0000 985 15717 [main] poll_test 79200 wsock_init: res 0 21 15738 [main] poll_test 79200 wsock_init: wVersion 514 15 15753 [main] poll_test 79200 wsock_init: wHighVersion 514 12 15765 [main] poll_test 79200 wsock_init: szDescription WinSock 2.0 13 15778 [main] poll_test 79200 wsock_init: szSystemStatus Running 17 15795 [main] poll_test 79200 wsock_init: iMaxSockets 0 16 15811 [main] poll_test 79200 wsock_init: iMaxUdpDg 0 --- Process 79200 loaded C:\Windows\System32\mswsock.dll at 00007FFF89540000 557 16368 [main] poll_test 79200 build_fh_pc: fh 0x18030BE70, dev 001E0079 87 16455 [main] poll_test 79200 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0 18 16473 [main] poll_test 79200 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000 15 16488 [main] poll_test 79200 fhandler_base::set_flags: filemode set to binary 15 16503 [main] poll_test 79200 fdsock: fd 3, name '', soc 0x180 21 16524 [main] poll_test 79200 cygwin_socket: 3 = socket(1, 1 (flags 0x0), 0) 15 16539 [main] poll_test 79200 fcntl64: fcntl(3, 3, ...) 17 16556 [main] poll_test 79200 fhandler_base::fcntl: GETFL: 0x10002 15 16571 [main] poll_test 79200 fcntl64: 65538 = fcntl(3, 3, 0x0) 16 16587 [main] poll_test 79200 fcntl64: fcntl(3, 4, ...) 22 16609 [main] poll_test 79200 fhandler_socket::ioctl: socket is now nonblocking 22 16631 [main] poll_test 79200 fhandler_socket::ioctl: 0 = ioctl_socket(8004667E, 0xFFFFC9FC) 17 16648 [main] poll_test 79200 fhandler_base::set_flags: flags 0x14002, supplied_bin 0x0 18 16666 [main] poll_test 79200 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000 15 16681 [main] poll_test 79200 fhandler_base::set_flags: filemode set to binary 15 16696 [main] poll_test 79200 fcntl64: 0 = fcntl(3, 4, 0x14002) 21 16717 [main] poll_test 79200 normalize_posix_path: src @test.sock ... snip path checking stuff... 19 17118 [main] poll_test 79200 path_conv::check: this->path(C:\Users\Erik M. Bray\src\python\cpython\@test.sock), has_acls(1) 70 17188 [main] poll_test 79200 fhandler_socket::bind: AF_LOCAL: socket bound to port 55085 298 17486 [main] poll_test 79200 set_posix_access: ACL-Size: 100 37 17523 [main] poll_test 79200 set_posix_access: Created SD-Size: 176 --- Process 79200 loaded C:\Windows\System32\cryptbase.dll at 00007FFF898B0000 --- Process 79200 loaded C:\Windows\System32\bcryptprimitives.dll at 00007FFF8AE30000 3492 21015 [main] poll_test 79200 cygwin_bind: 0 = bind(3, 0xFFFFCB10, 110) 112 21127 [main] poll_test 79200 getpid: 79200 = getpid() 27 21154 [main] poll_test 79200 cygwin_listen: 0 = listen(3, 5) 21 21175 [main] poll_test 79200 cygwin_socket: socket (1, 1 (flags 0x0), 0) 68 21243 [main] poll_test 79200 build_fh_pc: fh 0x18030C310, dev 001E0079 44 21287 [main] poll_test 79200 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0 15 21302 [main] poll_test 79200 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000 13 21315 [main] poll_test 79200 fhandler_base::set_flags: filemode set to binary 13 21328 [main] poll_test 79200 fdsock: fd 4, name '', soc 0x188 20 21348 [main] poll_test 79200 cygwin_socket: 4 = socket(1, 1 (flags 0x0), 0) 16 21364 [main] poll_test 79200 fcntl64: fcntl(4, 3, ...) 15 21379 [main] poll_test 79200 fhandler_base::fcntl: GETFL: 0x10002 13 21392 [main] poll_test 79200 fcntl64: 65538 = fcntl(4, 3, 0x0) 17 21409 [main] poll_test 79200 fcntl64: fcntl(4, 4, ...) 14 21423 [main] poll_test 79200 fhandler_socket::ioctl: socket is now nonblocking 14 21437 [main] poll_test 79200 fhandler_socket::ioctl: 0 = ioctl_socket(8004667E, 0xFFFFC9FC) 13 21450 [main] poll_test 79200 fhandler_base::set_flags: flags 0x14002, supplied_bin 0x0 13 21463 [main] poll_test 79200 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000 13 21476 [main] poll_test 79200 fhandler_base::set_flags: filemode set to binary 12 21488 [main] poll_test 79200 fcntl64: 0 = fcntl(4, 4, 0x14002) 20 21508 [main] poll_test 79200 normalize_posix_path: src @test.sock ... 76 21922 [main] poll_test 79200 getpid: 79200 = getpid() --- Process 79200 thread 18528 created 350 22272 [main] poll_test 79200 __set_errno: void __set_winsock_errno(const char*, int):224 setting errno 119 26 22298 [main] poll_test 79200 __set_winsock_errno: connect:1232 - winsock error 10036 -> errno 119 17 22315 [main] poll_test 79200 cygwin_connect: -1 = connect(4, 0xFFFFCB10, 110), errno 119 100 22415 [main] poll_test 79200 time: 1483702462 = time(0x0) 731 23146 [main] poll_test 79200 pwdgrp::fetch_account_from_windows: line: 108 23254 [main] poll_test 79200 stat64: entering 32 23286 [main] poll_test 79200 normalize_posix_path: src /dev 30 23316 [main] poll_test 79200 normalize_posix_path: /dev = normalize_posix_path (/dev) 26 23342 [main] poll_test 79200 mount_info::conv_to_win32_path: conv_to_win32_path (/dev) 27 23369 [main] poll_test 79200 set_flags: flags: binary (0x2) 23 23392 [main] poll_test 79200 mount_info::conv_to_win32_path: src_path /dev, dst C:\cygwin64\dev, flags 0x3000A, rc 0 54 23446 [main] poll_test 79200 symlink_info::check: 0x0 = NtCreateFile (\??\C:\cygwin64\dev) 37 23483 [main] poll_test 79200 symlink_info::check: not a symlink 29 23512 [main] poll_test 79200 symlink_info::check: 0 = symlink.check(C:\cygwin64\dev, 0xFFFFB250) (0x43000A) 39 23551 [main] poll_test 79200 build_fh_pc: fh 0x18030C700, dev 000000C1 30 23581 [main] poll_test 79200 stat_worker: (\??\C:\cygwin64\dev, 0x1802E2A20, 0x18030C700), file_attributes 16 194 23775 [main] poll_test 79200 fhandler_base::fstat_helper: 0 = fstat (\??\C:\cygwin64\dev, 0x1802E2A20) st_size=0, st_mode=040755, st_ino=562949953536516st_atim=57696141.1B43B4B0 st_ctim=57696141.1B43B4B0 st_mtim=57696141.1B43B4B0 st_birthtim=5769612C.1F3F08BC 44 23819 [main] poll_test 79200 stat_worker: 0 = (\??\C:\cygwin64\dev,0x1802E2A20) 38 23857 [main] poll_test 79200 fstat64: 0 = fstat(1, 0xFFFFC580) 48 23905 [main] poll_test 79200 isatty: 1 = isatty(1) 154 24059 [main] poll_test 79200 fhandler_pty_slave::write: pty9, write(0x6000426B0, 40) 51 24110 [main] poll_test 79200 fhandler_pty_common::process_opost_output: (1901): pty output_mutex (0x140): waiting -1 ms 47 24157 [main] poll_test 79200 fhandler_pty_common::process_opost_output: (1901): pty output_mutex: acquired 23 24180 [main] poll_test 79200 fhandler_pty_common::process_opost_output: (1940): pty output_mutex(0x140) released Ret from client connect: -1; errno: 119 23 24203 [main] poll_test 79200 write: 40 = write(1, 0x6000426B0, 40) 99 24302 [main] poll_test 79200 pselect: pselect (5, 0xFFFFCB90, 0x0, 0x0, 0xFFFFCB80, 0x0) 20 24322 [main] poll_test 79200 pselect: to->tv_sec 1, to->tv_nsec 0, us 1000000 41 24363 [main] poll_test 79200 dtable::select_read: fd 4 33 24396 [main] poll_test 79200 select: sel.always_ready 0 97 24493 [main] poll_test 79200 start_thread_socket: stuff_start 0xFFFFC8E8 --- Process 79200 thread 46528 created 172 24665 [socksel] poll_test 79200 cygthread::stub: thread 'socksel', id 0xB5C0, stack_ptr 0x12ECCD0 24 24689 [socksel] poll_test 79200 thread_socket: stuff_start 0xFFFFC8E8, timeout 4294967295 23 24712 [main] poll_test 79200 select_stuff::wait: m 4, us 1000000, wmfo_timeout -1 31 24743 [socksel] poll_test 79200 fhandler_socket::af_local_connect: af_local_connect called, no_getpeereid=0 106 24849 [socksel] poll_test 79200 fhandler_socket::af_local_send_secret: Sending af_local secret succeeded 999984 1024833 [main] poll_test 79200 select_stuff::wait: wait_ret 3, m = 4. verifying 65 1024898 [main] poll_test 79200 select_stuff::wait: timed out 38 1024936 [main] poll_test 79200 select_stuff::wait: returning 1 31 1024967 [main] poll_test 79200 select: sel.wait returns 1 18 1024985 [main] poll_test 79200 select_stuff::cleanup: calling cleanup routines 16 1025001 [main] poll_test 79200 socket_cleanup: si 0x6000526C0 si->thread 0x1801FE758 --94eb2c1b110285117805456b7c13 Content-Type: text/x-csrc; charset=US-ASCII; name="poll_test.c" Content-Disposition: attachment; filename="poll_test.c" Content-Transfer-Encoding: base64 X-Attachment-Id: f_ixlqcunl0 I2luY2x1ZGUgPGFycGEvaW5ldC5oPgojaW5jbHVkZSA8c3lzL3NvY2tldC5o PgojaW5jbHVkZSA8c3RyaW5nLmg+CiNpbmNsdWRlIDxzdGRpby5oPgojaW5j bHVkZSA8ZmNudGwuaD4KI2luY2x1ZGUgPHN5cy90aW1lLmg+CiNpbmNsdWRl IDxzeXMvdW4uaD4KI2luY2x1ZGUgPGVycm5vLmg+CgoKI2RlZmluZSBTRVRf Tk9OQkxPQ0tJTkcoc29jaykgZmNudGwoc29jaywgRl9TRVRGTCwgZmNudGwo c29jaywgRl9HRVRGTCwgMCkgfCBPX05PTkJMT0NLKTsKCgppbnQgbWFpbih2 b2lkKSB7CiAgICBmZF9zZXQgcmZkczsKICAgIHN0cnVjdCB0aW1lc3BlYyB0 djsKICAgIGludCBzb2NrX3NlcnZlciwgc29ja19jbGllbnQ7CiAgICBpbnQg cmV0dmFsOwogICAgc3RydWN0IHNvY2thZGRyX3VuIGFkZHI7IFwKCiAgICBt ZW1zZXQoJmFkZHIsIDAsIHNpemVvZihhZGRyKSk7IFwKICAgIGFkZHIuc3Vu X2ZhbWlseSA9IEFGX1VOSVg7IFwKICAgIHN0cmNweShhZGRyLnN1bl9wYXRo LCAiQHRlc3Quc29jayIpOwoKICAgIHNvY2tfc2VydmVyID0gc29ja2V0KEFG X1VOSVgsIFNPQ0tfU1RSRUFNLCAwKTsKICAgIFNFVF9OT05CTE9DS0lORyhz b2NrX3NlcnZlcik7CiAgICBpZiAoYmluZChzb2NrX3NlcnZlciwgKHN0cnVj dCBzb2NrYWRkciopJmFkZHIsIHNpemVvZihhZGRyKSkpIHsKICAgICAgICBw cmludGYoImJpbmRpbmcgc2VydmVyIHNvY2tldCBmYWlsZWQiKTsKICAgICAg ICByZXR1cm4gMTsKICAgIH0KICAgIGxpc3Rlbihzb2NrX3NlcnZlciwgNSk7 CgogICAgc29ja19jbGllbnQgPSBzb2NrZXQoQUZfVU5JWCwgU09DS19TVFJF QU0sIDApOwogICAgU0VUX05PTkJMT0NLSU5HKHNvY2tfY2xpZW50KTsKICAg IHJldHZhbCA9IGNvbm5lY3Qoc29ja19jbGllbnQsIChzdHJ1Y3Qgc29ja2Fk ZHIqKSZhZGRyLCBzaXplb2YoYWRkcikpOwogICAgcHJpbnRmKCJSZXQgZnJv bSBjbGllbnQgY29ubmVjdDogJWQ7IGVycm5vOiAlZFxuIiwgcmV0dmFsLCBl cnJubyk7CgogICAgRkRfWkVSTygmcmZkcyk7CiAgICBGRF9TRVQoc29ja19j bGllbnQsICZyZmRzKTsKICAgIHR2LnR2X3NlYyA9IDE7CiAgICB0di50dl9u c2VjID0gMDsKCiAgICByZXR2YWwgPSBwc2VsZWN0KHNvY2tfY2xpZW50ICsg MSwgJnJmZHMsIE5VTEwsIE5VTEwsICZ0diwgTlVMTCk7CgogICAgcmV0dXJu IDA7Cn0K --94eb2c1b110285117805456b7c13 Content-Type: text/plain; charset=us-ascii -- Problem reports: http://cygwin.com/problems.html FAQ: http://cygwin.com/faq/ Documentation: http://cygwin.com/docs.html Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple --94eb2c1b110285117805456b7c13--