Setting termios VMIN > 0 and VTIME > 0 on non blocking file

Åke Rehnman ake.rehnman@gmail.com
Thu Mar 12 16:42:37 GMT 2020


On 2020-03-12 15:13, Corinna Vinschen wrote:
> On Mar 12 14:32, Åke Rehnman via Cygwin wrote:
>> On 2020-03-12 12:40, Corinna Vinschen wrote:
>>> For a start, can you please strace the problem with a simple
>>> testcase,like this:
>>>
>>>     $ strace -o serio.trace <yourtestcase>
>>>
>>> and send the source of your testcase as well as the serio.trace file
>>> here?  It may show at which point the error code is generated.
>> Should I post those files to the mailing list? I tried emailing them to you
>> directly but it bounced...
> Mailing list, please.

-------------- next part --------------
#include <stdio.h>
#include <error.h>
#include <errno.h>
#include <sys/select.h>
#include <fcntl.h>
#include <unistd.h>
#include <termios.h>
#include <sys/ioctl.h>

int main(int argc, char * argv[])
{
    fd_set rfds;
    struct timeval tv;
    char data[256];
    int retval;
    int fd;
    struct termios config;
    
    if (argc < 2)
        error(-1, 0, "need a port");
    fd = open(argv[1], O_RDWR | O_NONBLOCK | O_NOCTTY);
    if (fd < 0)
        error(-1, errno, "failed to open %s", argv[1]);

    if(tcgetattr(fd, &config) < 0)
        error(-1, errno, "tcgetattr failed");

    config.c_cc[VMIN]  = 100;
    config.c_cc[VTIME] = 2;
    
    if(tcsetattr(fd, TCSANOW, &config) < 0)
        error(-1, errno, "tcsetattr failed");

    while (1)
    {
        FD_ZERO(&rfds);
        FD_SET(fd, &rfds);
    
        tv.tv_sec = 1;
        tv.tv_usec = 0;
    
        retval = select(fd+1, &rfds, NULL, NULL, &tv);
    
        if (retval == -1)
            perror("select()");
        else if (retval)
        {
            int nb;
            retval = ioctl(fd, TIOCINQ, &nb);
            if (retval)
                error(-1, errno, "ioctl(TIOCINQ) failed");
            else
                fprintf(stdout,"nb=%d\n",nb);
       
            for (int i=0;i<10;i++)
            {
                retval = read(fd, data, 100);
                if (retval < 0 && errno == EAGAIN)
                {
                    fprintf(stdout,"read() returned EAGAIN\n");
                    usleep(100000);
                    continue;
                }
                else if (retval >= 0)
                {
                    retval = fwrite(data,1,retval,stdout);
                    break;
                }
                else
                {
                    error(-1, errno, "%d = read() failed", errno);
                }
            }
        }
        else
            printf("No data...\n");
    }
           
    close(fd);
    return 0;
}
-------------- next part --------------
$ strace -o log2.txt ./test2.exe /dev/ttyS27
nb=7
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
nb=28
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
nb=35
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
nb=35
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
read() returned EAGAIN
-------------- next part --------------
--- Process 43708 created
--- Process 43708 loaded C:\Windows\System32\ntdll.dll at 00000000776e0000
--- Process 43708 loaded C:\Windows\System32\kernel32.dll at 00000000775c0000
--- Process 43708 loaded C:\Windows\System32\KernelBase.dll at 000007fefd500000
--- Process 43708 loaded C:\cygwin64\bin\cygwin1.dll at 0000000180040000
    0       0 [main] test2 (43708) **********************************************
  258     258 [main] test2 (43708) Program name: C:\akre\TIOCINQtest\test2.exe (windows pid 43708)
  104     362 [main] test2 (43708) OS version:   Windows NT-6.1
   97     459 [main] test2 (43708) **********************************************
--- Process 43708 loaded C:\Windows\System32\advapi32.dll at 000007fefe240000
--- Process 43708 loaded C:\Windows\System32\msvcrt.dll at 000007fefe450000
--- Process 43708 loaded C:\Windows\System32\sechost.dll at 000007fefdb80000
--- Process 43708 loaded C:\Windows\System32\rpcrt4.dll at 000007fefe320000
--- Process 43708 loaded C:\Windows\System32\cryptbase.dll at 000007fefd0c0000
 3043    3502 [main] test2 (43708) sigprocmask: 0 = sigprocmask (0, 0x0, 0x180319EF0)
  399    3901 [main] test2 (43708) open_shared: name shared.5, n 5, shared 0x180030000 (wanted 0x180030000), h 0x84, *m 6
   68    3969 [main] test2 (43708) user_heap_info::init: heap base 0x800000000, heap top 0x800000000, heap size 0x20000000 (536870912)
   76    4045 [main] test2 (43708) open_shared: name S-1-5-21-2731407542-896203527-514956166-1000.1, n 1, shared 0x180020000 (wanted 0x180020000), h 0x80, *m 6
   37    4082 [main] test2 (43708) user_info::create: opening user shared for 'S-1-5-21-2731407542-896203527-514956166-1000' at 0x180020000
   60    4142 [main] test2 (43708) user_info::create: user shared version AB1FCCE8
   60    4202 [main] test2 (43708) fhandler_pipe::create: name \\.\pipe\cygwin-e022582115c10879-43708-sigwait, size 11440, mode PIPE_TYPE_MESSAGE
   76    4278 [main] test2 (43708) fhandler_pipe::create: pipe read handle 0x9C
   32    4310 [main] test2 (43708) fhandler_pipe::create: CreateFile: name \\.\pipe\cygwin-e022582115c10879-43708-sigwait
   59    4369 [main] test2 (43708) fhandler_pipe::create: pipe write handle 0xA0
   47    4416 [main] test2 (43708) dll_crt0_0: finished dll_crt0_0 initialization
--- Process 43708 thread 4468 created
  262    4678 [sig] test2 (43708) wait_sig: entering ReadFile loop, my_readsig 0x9C, my_sendsig 0xA0
  174    4852 [main] test2 (43708) time: 1584019100 = time(0x0)
   99    4951 [main] test2 (43708) mount_info::conv_to_posix_path: conv_to_posix_path (C:\akre\TIOCINQtest, 0x0, no-add-slash)
   56    5007 [main] test2 (43708) normalize_win32_path: C:\akre\TIOCINQtest = normalize_win32_path (C:\akre\TIOCINQtest)
   37    5044 [main] test2 (43708) mount_info::conv_to_posix_path: /cygdrive/c/akre/TIOCINQtest = conv_to_posix_path (C:\akre\TIOCINQtest)
  115    5159 [main] test2 (43708) sigprocmask: 0 = sigprocmask (0, 0x0, 0x800018130)
  144    5303 [main] test2 (43708) _cygwin_istext_for_stdio: fd 0: not open
   32    5335 [main] test2 (43708) _cygwin_istext_for_stdio: fd 1: not open
   33    5368 [main] test2 (43708) _cygwin_istext_for_stdio: fd 2: not open
  118    5486 [main] test2 (43708) open_shared: name cygpid.1974, n 1974, shared 0x180010000 (wanted 0x180010000), h 0xC8, *m 2
   44    5530 [main] test2 (43708) time: 1584019100 = time(0x0)
   61    5591 [main] test2 1974 pinfo::thisproc: myself dwProcessId 43708
   80    5671 [main] test2 1974 environ_init: GetEnvironmentStrings returned 0x313EA0
   74    7125 [main] test2 1974 parse_options: glob (called func)
   95    7220 [main] test2 1974 parse_options: returning
   55    7591 [main] test2 1974 getwinenv: can't set native for HOME= since no environ yet
   58    7649 [main] test2 1974 mount_info::conv_to_posix_path: conv_to_posix_path (C:\Users\ARE, 0x10000000, no-add-slash)
   37    7686 [main] test2 1974 normalize_win32_path: C:\Users\ARE = normalize_win32_path (C:\Users\ARE)
   42    7728 [main] test2 1974 mount_info::conv_to_posix_path: /cygdrive/c/Users/ARE = conv_to_posix_path (C:\Users\ARE)
   88    7816 [main] test2 1974 win_env::add_cache: posix /cygdrive/c/Users/ARE
   53    7869 [main] test2 1974 win_env::add_cache: native HOME=C:\Users\ARE
   36    7905 [main] test2 1974 posify_maybe: env var converted to HOME=/cygdrive/c/Users/ARE
   75    9822 [main] test2 1974 getwinenv: can't set native for PATH= since no environ yet
   60   16233 [main] test2 1974 getwinenv: can't set native for TEMP= since no environ yet
   37   16270 [main] test2 1974 mount_info::conv_to_posix_path: conv_to_posix_path (C:\cygwin64\tmp, 0x10000000, no-add-slash)
   39   16309 [main] test2 1974 normalize_win32_path: C:\cygwin64\tmp = normalize_win32_path (C:\cygwin64\tmp)
   61   16370 [main] test2 1974 mount_info::conv_to_posix_path: /tmp = conv_to_posix_path (C:\cygwin64\tmp)
   83   16453 [main] test2 1974 win_env::add_cache: posix /tmp
   36   16489 [main] test2 1974 win_env::add_cache: native TEMP=C:\cygwin64\tmp
   53   16542 [main] test2 1974 posify_maybe: env var converted to TEMP=/tmp
   61   16804 [main] test2 1974 getwinenv: can't set native for TMP= since no environ yet
   36   16840 [main] test2 1974 mount_info::conv_to_posix_path: conv_to_posix_path (C:\cygwin64\tmp, 0x10000000, no-add-slash)
   39   16879 [main] test2 1974 normalize_win32_path: C:\cygwin64\tmp = normalize_win32_path (C:\cygwin64\tmp)
   55   16934 [main] test2 1974 mount_info::conv_to_posix_path: /tmp = conv_to_posix_path (C:\cygwin64\tmp)
   83   17017 [main] test2 1974 win_env::add_cache: posix /tmp
   53   17070 [main] test2 1974 win_env::add_cache: native TMP=C:\cygwin64\tmp
   37   17107 [main] test2 1974 posify_maybe: env var converted to TMP=/tmp
   56   18335 [main] test2 1974 pinfo_init: Set nice to 0
   90   18425 [main] test2 1974 pinfo_init: pid 1974, pgid 1974, process_state 0x41
   46   18471 [main] test2 1974 App version:  3001.4, api: 0.340
   38   18509 [main] test2 1974 DLL version:  3001.5, api: 0.340
   35   18544 [main] test2 1974 DLL build:    2020-03-12 13:02
   54   18598 [main] test2 1974 dtable::extend: size 32, fds 0x180342E70
  186   18784 [main] test2 1974 __get_lcid_from_locale: LCID=0x0409
  462   19246 [main] test2 1974 transport_layer_pipes::connect: Try to connect to named pipe: \\.\pipe\cygwin-e022582115c10879-lpc
   71   19317 [main] test2 1974 transport_layer_pipes::connect: Error opening the pipe (2)
   55   19372 [main] test2 1974 client_request::make_request: cygserver un-available
--- Process 43708 (pid: 1974) thread 37052 created
--- Process 43708 (pid: 1974) loaded C:\Windows\System32\netapi32.dll at 000007fefc610000
--- Process 43708 (pid: 1974) loaded C:\Windows\System32\netutils.dll at 000007fefc800000
--- Process 43708 (pid: 1974) loaded C:\Windows\System32\srvcli.dll at 000007fefce20000
--- Process 43708 (pid: 1974) loaded C:\Windows\System32\wkscli.dll at 000007fefc1d0000
--- Process 43708 (pid: 1974) loaded C:\Windows\System32\samcli.dll at 000007fefc1b0000
--- Process 43708 (pid: 1974) loaded C:\Windows\System32\samlib.dll at 000007fefb760000
--- Process 43708 (pid: 1974) thread 14456 created
  105   39200 [main] test2 1974 cygheap_user::ontherange: what 2, pw 0x180343170
   94   39294 [main] test2 1974 cygheap_user::ontherange: HOME is already in the environment /cygdrive/c/Users/ARE
  240   39534 [main] test2 1974 build_argv: argv[0] = 'C:\akre\TIOCINQtest\test2.exe'
   98   39632 [main] test2 1974 build_argv: argv[1] = '/dev/ttyS27'
   92   39724 [main] test2 1974 build_argv: argc 2
  232   39956 [main] test2 1974 mount_info::conv_to_posix_path: conv_to_posix_path (C:\akre\TIOCINQtest\test2.exe, 0x10000100, no-add-slash)
   79   40035 [main] test2 1974 normalize_win32_path: C:\akre\TIOCINQtest\test2.exe = normalize_win32_path (C:\akre\TIOCINQtest\test2.exe)
   65   40100 [main] test2 1974 mount_info::conv_to_posix_path: /cygdrive/c/akre/TIOCINQtest/test2.exe = conv_to_posix_path (C:\akre\TIOCINQtest\test2.exe)
  341   40441 [main] test2 1974 build_fh_pc: created an archetype (0x1803452B0) for /dev/pty0(136/0)
  134   40575 [main] test2 1974 build_fh_pc: fh 0x180344F40, dev 00880000
  193   40768 [main] test2 1974 fhandler_pipe::create: name \\.\pipe\cygwin-e022582115c10879-pty0-from-master, size 131072, mode PIPE_TYPE_MESSAGE
  175   40943 [main] test2 1974 fhandler_pipe::create: pipe busy
  189   41132 [main] test2 1974 tty::exists: exists 1
  332   41464 [main] test2 1974 set_posix_access: ACL-Size: 124
  172   41636 [main] test2 1974 set_posix_access: Created SD-Size: 200
   98   41734 [main] test2 1974 fhandler_pty_slave::open: (800): pty output_mutex (0x14C): waiting -1 ms
  221   41955 [main] test2 1974 fhandler_pty_slave::open: (800): pty output_mutex: acquired
  114   42069 [main] test2 1974 tty::create_inuse: cygtty.slave_alive.0 0x158
  100   42169 [main] test2 1974 fhandler_pty_slave::open: (803): pty output_mutex(0x14C) released
  200   42369 [main] test2 1974 open_shared: name cygpid.1934, n 1934, shared 0x2D0000 (wanted 0x0), h 0x15C, *m 6
  155   42524 [main] test2 1974 fhandler_pty_slave::open: dup handles directly since I'm the owner
  166   42690 [main] test2 1974 fhandler_pty_slave::open: duplicated from_master 0x244->0x15C from pty_owner
  119   42809 [main] test2 1974 fhandler_pty_slave::open: duplicated from_master_cyg 0x244->0x164 from pty_owner
  104   42913 [main] test2 1974 fhandler_pty_slave::open: duplicated to_master 0x258->0x168 from pty_owner
   99   43012 [main] test2 1974 fhandler_pty_slave::open: duplicated to_master_cyg 0x260->0x16C from pty_owner
  198   43210 [main] test2 1974 fhandler_console::need_invisible: invisible_console 0
  189   43399 [main] test2 1974 fhandler_base::open_with_arch: line 470:  /dev/pty0<0x1803452B0> usecount + 1 = 1
  116   43515 [main] test2 1974 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
  127   43642 [main] test2 1974 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
   96   43738 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
  181   43919 [main] test2 1974 _pinfo::set_ctty: old no ctty, ctty device number 0xFFFFFFFF, tc.ntty device number 0x880000 flags & O_NOCTTY 0x0
  214   44133 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty 0x0, archetype 0x1803452B0
  101   44234 [main] test2 1974 _pinfo::set_ctty: ctty was NULL
   94   44328 [main] test2 1974 _pinfo::set_ctty: line 541:  /dev/pty0<0x1803452B0> usecount + 1 = 2
   94   44422 [main] test2 1974 _pinfo::set_ctty: /dev/pty0 ctty, usecount 2
   97   44519 [main] test2 1974 _pinfo::set_ctty: attaching ctty /dev/pty0 sid 1974, pid 1974, pgid 1974, tty->pgid 1972, tty->sid 1935
  115   44634 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty now 0x1803452B0, archetype 0x1803452B0
   91   44725 [main] test2 1974 fhandler_pty_slave::open_setup: /dev/pty0 opened, usecount 2
   99   44824 [main] test2 1974 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
  216   45040 [main] test2 1974 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
  103   45143 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
   69   45212 [main] test2 1974 _pinfo::set_ctty: old ctty /dev/pty0, ctty device number 0x880000, tc.ntty device number 0x880000 flags & O_NOCTTY 0x0
   41   45253 [main] test2 1974 _pinfo::set_ctty: attaching ctty /dev/pty0 sid 1935, pid 1974, pgid 1974, tty->pgid 1974, tty->sid 1935
  161   45414 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty now 0x1803452B0, archetype 0x1803452B0
   98   45512 [main] test2 1974 fhandler_pty_slave::open_setup: /dev/pty0 opened, usecount 2
  205   45717 [main] test2 1974 build_fh_pc: found an archetype for (null)(136/0) io_handle 0x15C
  124   45841 [main] test2 1974 build_fh_pc: fh 0x180345690, dev 00880000
  114   45955 [main] test2 1974 fhandler_base::open_with_arch: line 490:  /dev/pty0<0x1803452B0> usecount + 1 = 3
  183   46138 [main] test2 1974 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
  101   46239 [main] test2 1974 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
   93   46332 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
   94   46426 [main] test2 1974 _pinfo::set_ctty: old ctty /dev/pty0, ctty device number 0x880000, tc.ntty device number 0x880000 flags & O_NOCTTY 0x0
  213   46639 [main] test2 1974 _pinfo::set_ctty: attaching ctty /dev/pty0 sid 1935, pid 1974, pgid 1974, tty->pgid 1974, tty->sid 1935
   84   46723 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty now 0x1803452B0, archetype 0x1803452B0
   94   46817 [main] test2 1974 fhandler_pty_slave::open_setup: /dev/pty0 opened, usecount 3
   98   46915 [main] test2 1974 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
  104   47019 [main] test2 1974 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
   99   47118 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
   85   47203 [main] test2 1974 _pinfo::set_ctty: old ctty /dev/pty0, ctty device number 0x880000, tc.ntty device number 0x880000 flags & O_NOCTTY 0x0
   35   47238 [main] test2 1974 _pinfo::set_ctty: attaching ctty /dev/pty0 sid 1935, pid 1974, pgid 1974, tty->pgid 1974, tty->sid 1935
   46   47284 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty now 0x1803452B0, archetype 0x1803452B0
  105   47389 [main] test2 1974 fhandler_pty_slave::open_setup: /dev/pty0 opened, usecount 3
  235   47624 [main] test2 1974 build_fh_pc: found an archetype for (null)(136/0) io_handle 0x15C
   86   47710 [main] test2 1974 build_fh_pc: fh 0x180345A00, dev 00880000
   75   47785 [main] test2 1974 fhandler_base::open_with_arch: line 490:  /dev/pty0<0x1803452B0> usecount + 1 = 4
   54   47839 [main] test2 1974 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
   69   47908 [main] test2 1974 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
   48   47956 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
   56   48012 [main] test2 1974 _pinfo::set_ctty: old ctty /dev/pty0, ctty device number 0x880000, tc.ntty device number 0x880000 flags & O_NOCTTY 0x0
  294   48306 [main] test2 1974 _pinfo::set_ctty: attaching ctty /dev/pty0 sid 1935, pid 1974, pgid 1974, tty->pgid 1974, tty->sid 1935
   97   48403 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty now 0x1803452B0, archetype 0x1803452B0
   94   48497 [main] test2 1974 fhandler_pty_slave::open_setup: /dev/pty0 opened, usecount 4
  102   48599 [main] test2 1974 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
   85   48684 [main] test2 1974 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
   54   48738 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
   57   48795 [main] test2 1974 _pinfo::set_ctty: old ctty /dev/pty0, ctty device number 0x880000, tc.ntty device number 0x880000 flags & O_NOCTTY 0x0
  162   48957 [main] test2 1974 _pinfo::set_ctty: attaching ctty /dev/pty0 sid 1935, pid 1974, pgid 1974, tty->pgid 1974, tty->sid 1935
   97   49054 [main] test2 1974 _pinfo::set_ctty: cygheap->ctty now 0x1803452B0, archetype 0x1803452B0
  126   49180 [main] test2 1974 fhandler_pty_slave::open_setup: /dev/pty0 opened, usecount 4
  231   49411 [main] test2 1974 __set_errno: void dll_crt0_1(void*):989 setting errno 0
 1029   50440 [main] test2 1974 open: open(/dev/ttyS27, 0xC002)
  118   50558 [main] test2 1974 normalize_posix_path: src /dev/ttyS27
  203   50761 [main] test2 1974 normalize_posix_path: /dev/ttyS27 = normalize_posix_path (/dev/ttyS27)
  101   50862 [main] test2 1974 mount_info::conv_to_win32_path: conv_to_win32_path (/dev/ttyS27)
  121   50983 [main] test2 1974 mount_info::conv_to_win32_path: src_path /dev/ttyS27, dst \??\COM28, flags 0x0, rc 0
  151   51134 [main] test2 1974 build_fh_pc: fh 0x180345F90, dev 0075001B
  207   51341 [main] test2 1974 fhandler_serial::open: fhandler_serial::open (/dev/ttyS27, 0xC002, 00)
  221   51562 [main] test2 1974 fhandler_base::open: (\??\COM28, 0xC002)
18369   69931 [main] test2 1974 fhandler_base::set_flags: flags 0xC002, supplied_bin 0x10000
  196   70127 [main] test2 1974 fhandler_base::set_flags: filemode set to binary
  107   70234 [main] test2 1974 fhandler_base::open: 0x0 = NtCreateFile (0x2B4, 0xC0000000, \??\COM28, io, NULL, 0x0, 0x7, 0x1, 0x4000, NULL, 0)
  235   70469 [main] test2 1974 fhandler_base::open: 1 = fhandler_base::open(\??\COM28, 0xC002)
  396   70865 [main] test2 1974 fhandler_serial::open: 0x100000001 = fhandler_serial::open (/dev/ttyS27, 0xC002, 00)
  226   71091 [main] test2 1974 open: 3 = open(/dev/ttyS27, 0xC002)
  156   71247 [main] test2 1974 fhandler_serial::tcgetattr: vmin_ 0, vtime_ 0
   74   71321 [main] test2 1974 tcgetattr: iflag 0x404, oflag 0x0, cflag 0x830, lflag 0x0, VMIN 0, VTIME 0
  106   71427 [main] test2 1974 fhandler_serial::tcsetattr: action 2
  480   71907 [main] test2 1974 fhandler_serial::tcsetattr: vtime 200, vmin 100
  119   72026 [main] test2 1974 fhandler_serial::tcsetattr: ReadTotalTimeoutConstant 0, ReadIntervalTimeout 200, ReadTotalTimeoutMultiplier 0
  135   72161 [main] test2 1974 __set_errno: int tcsetattr(int, int, const termios*):158 setting errno 0
  122   72283 [main] test2 1974 tcsetattr: iflag 0x404, oflag 0x0, cflag 0x830, lflag 0x0, VMIN 100, VTIME 2
   94   72377 [main] test2 1974 tcsetattr: 0 = tcsetattr(3, 2, 0xFFFFCA80)
  109   72486 [main] test2 1974 pselect: pselect (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20, 0x0)
  155   72641 [main] test2 1974 pselect: to->tv_sec 1, to->tv_nsec 0, us 1000000
  216   72857 [main] test2 1974 dtable::select_read: /dev/ttyS27 fd 3
  131   72988 [main] test2 1974 select: sel.always_ready 0
--- Process 43708 (pid: 1974) thread 28796 created
  742   73730 [sersel] test2 1974 cygthread::stub: thread 'sersel', id 0x707C, stack_ptr 0xB7CCE0
   99   73829 [sersel] test2 1974 peek_serial: fh->overlapped_armed 0
  116   73945 [main] test2 1974 select_stuff::wait: m 4, us 1000000, wmfo_timeout -1
 9988   83933 [sersel] test2 1974 thread_serial: exiting
  107   84040 [main] test2 1974 select_stuff::wait: wait_ret 2, m = 4.  verifying
  234   84274 [main] test2 1974 set_bits: me 0x80003B2F0, testing fd 3 (/dev/ttyS27)
  133   84407 [main] test2 1974 set_bits: ready 1
  141   84548 [main] test2 1974 select_stuff::wait: res after verify 0
  107   84655 [main] test2 1974 select_stuff::wait: returning 0
   96   84751 [main] test2 1974 select: sel.wait returns 0
  107   84858 [main] test2 1974 peek_serial: fh->overlapped_armed 1
  104   84962 [main] test2 1974 peek_serial: already ready
  104   85066 [main] test2 1974 set_bits: me 0x80003B2F0, testing fd 3 (/dev/ttyS27)
  110   85176 [main] test2 1974 set_bits: ready 1
  106   85282 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
  217   85499 [main] test2 1974 select_stuff::destroy: deleting select records
  157   85656 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
  103   85759 [main] test2 1974 select_stuff::destroy: deleting select records
   94   85853 [main] test2 1974 pselect: 1 = select (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20)
  222   86075 [main] test2 1974 ioctl: ioctl(fd 3, cmd 0x541B)
  126   86201 [main] test2 1974 fhandler_serial::ioctl: 0 = ioctl(541B, 0xFFFFCA7C)
  122   86323 [main] test2 1974 ioctl: 0 = ioctl(3, 0x541B, ...)
  376   86699 [main] test2 1974 time: 1584019100 = time(0x0)
  186   89220 [main] test2 1974 stat64: entering
   55   89275 [main] test2 1974 normalize_posix_path: src /dev
   63   89338 [main] test2 1974 normalize_posix_path: /dev = normalize_posix_path (/dev)
   43   89381 [main] test2 1974 mount_info::conv_to_win32_path: conv_to_win32_path (/dev)
   69   89450 [main] test2 1974 mount_info::conv_to_win32_path: src_path /dev, dst C:\cygwin64\dev, flags 0x30008, rc 0
  116   89566 [main] test2 1974 symlink_info::check: 0x0 = NtCreateFile (\??\C:\cygwin64\dev)
   91   89657 [main] test2 1974 symlink_info::check: not a symlink
   38   89695 [main] test2 1974 symlink_info::check: 0 = symlink.check(C:\cygwin64\dev, 0xFFFFB200) (mount_flags 0x30008, path_flags 0x0)
  111   89806 [main] test2 1974 build_fh_pc: fh 0x180346408, dev 000000C1
   49   89855 [main] test2 1974 stat_worker: (\??\C:\cygwin64\dev, 0x180319D60, 0x180346408), file_attributes 16
  176   90031 [main] test2 1974 fhandler_base::fstat_helper: 0 = fstat (\??\C:\cygwin64\dev, 0x180319D60) st_size=0, st_mode=040755, st_ino=2251799815070549st_atim=58CCE806.BB0BC3C st_ctim=58CCE806.BB0BC3C st_mtim=58CCE806.BB0BC3C st_birthtim=58CCE723.25DBFA18
   50   90081 [main] test2 1974 stat_worker: 0 = (\??\C:\cygwin64\dev,0x180319D60)
   95   90176 [main] test2 1974 fstat64: 0 = fstat(1, 0xFFFFC550)
   70   90246 [main] test2 1974 isatty: 1 = isatty(1)
  320   90566 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 5)
   78   90644 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   45   90689 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   49   90738 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   47   90785 [main] test2 1974 write: 5 = write(1, 0x80004B450, 5)
  153   90938 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   85   91023 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
   72   91095 [main] test2 1974 fhandler_serial::raw_read: inq 100
   96   91191 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   57   91248 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   88   91336 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  243   91579 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   67   91646 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   80   91726 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   63   91789 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   82   91871 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  156   92027 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100135  192162 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  186  192348 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   83  192431 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  266  192697 [main] test2 1974 fhandler_serial::raw_read: inq 100
  262  192959 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  144  193103 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   45  193148 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  724  193872 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  158  194030 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  150  194180 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  165  194345 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  240  194585 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  280  194865 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100302  295167 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
   92  295259 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   29  295288 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
 8554  303842 [main] test2 1974 fhandler_serial::raw_read: inq 100
  165  304007 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   29  304036 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   25  304061 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  107  304168 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   36  304204 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   49  304253 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   32  304285 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   30  304315 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
   79  304394 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99778  404172 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  215  404387 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  172  404559 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  623  405182 [main] test2 1974 fhandler_serial::raw_read: inq 100
  162  405344 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  335  405679 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  188  405867 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  435  406302 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  105  406407 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   93  406500 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   89  406589 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   97  406686 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  252  406938 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99755  506693 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  197  506890 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  105  506995 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  384  507379 [main] test2 1974 fhandler_serial::raw_read: inq 100
   54  507433 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   68  507501 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   94  507595 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  340  507935 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  227  508162 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   37  508199 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   33  508232 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   32  508264 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  248  508512 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99662  608174 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  225  608399 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   43  608442 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  167  608609 [main] test2 1974 fhandler_serial::raw_read: inq 100
  377  608986 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  103  609089 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  122  609211 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  120  609331 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   41  609372 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   30  609402 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   40  609442 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   35  609477 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
   92  609569 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99659  709228 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  263  709491 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  170  709661 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  430  710091 [main] test2 1974 fhandler_serial::raw_read: inq 100
  272  710363 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   55  710418 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   29  710447 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  110  710557 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   38  710595 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  165  710760 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  140  710900 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  139  711039 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  462  711501 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100196  811697 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  240  811937 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   32  811969 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  204  812173 [main] test2 1974 fhandler_serial::raw_read: inq 100
   71  812244 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   66  812310 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   93  812403 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  532  812935 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  149  813084 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  155  813239 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  147  813386 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  161  813547 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  468  814015 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100225  914240 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  265  914505 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  164  914669 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  422  915091 [main] test2 1974 fhandler_serial::raw_read: inq 100
  165  915256 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  176  915432 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  144  915576 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  350  915926 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  102  916028 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   94  916122 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  110  916232 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  230  916462 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  324  916786 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99973 1016759 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  324 1017083 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  237 1017320 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  473 1017793 [main] test2 1974 fhandler_serial::raw_read: inq 100
  198 1017991 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  194 1018185 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  135 1018320 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  356 1018676 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  102 1018778 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   52 1018830 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   30 1018860 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   31 1018891 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  138 1019029 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99873 1118902 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  112 1119014 [main] test2 1974 pselect: pselect (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20, 0x0)
   30 1119044 [main] test2 1974 pselect: to->tv_sec 1, to->tv_nsec 0, us 1000000
   43 1119087 [main] test2 1974 dtable::select_read: /dev/ttyS27 fd 3
   28 1119115 [main] test2 1974 select: sel.always_ready 0
   71 1119186 [main] test2 1974 select_stuff::wait: m 4, us 1000000, wmfo_timeout -1
   40 1119226 [sersel] test2 1974 peek_serial: fh->overlapped_armed 0
  534 1119760 [sersel] test2 1974 thread_serial: exiting
   46 1119806 [main] test2 1974 select_stuff::wait: wait_ret 2, m = 4.  verifying
   39 1119845 [main] test2 1974 set_bits: me 0x80003B340, testing fd 3 (/dev/ttyS27)
   31 1119876 [main] test2 1974 set_bits: ready 1
   25 1119901 [main] test2 1974 select_stuff::wait: res after verify 0
   23 1119924 [main] test2 1974 select_stuff::wait: returning 0
   22 1119946 [main] test2 1974 select: sel.wait returns 0
   23 1119969 [main] test2 1974 peek_serial: fh->overlapped_armed 0
   24 1119993 [main] test2 1974 peek_serial: already ready
   23 1120016 [main] test2 1974 set_bits: me 0x80003B340, testing fd 3 (/dev/ttyS27)
   23 1120039 [main] test2 1974 set_bits: ready 1
   23 1120062 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
   52 1120114 [main] test2 1974 select_stuff::destroy: deleting select records
   36 1120150 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
   24 1120174 [main] test2 1974 select_stuff::destroy: deleting select records
   26 1120200 [main] test2 1974 pselect: 1 = select (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20)
   25 1120225 [main] test2 1974 ioctl: ioctl(fd 3, cmd 0x541B)
   30 1120255 [main] test2 1974 fhandler_serial::ioctl: 0 = ioctl(541B, 0xFFFFCA7C)
   26 1120281 [main] test2 1974 ioctl: 0 = ioctl(3, 0x541B, ...)
  101 1120382 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 6)
   33 1120415 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   27 1120442 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   29 1120471 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   28 1120499 [main] test2 1974 write: 6 = write(1, 0x80004B450, 6)
   81 1120580 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   27 1120607 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  288 1120895 [main] test2 1974 fhandler_serial::raw_read: inq 100
   45 1120940 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   28 1120968 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   32 1121000 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  102 1121102 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   28 1121130 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   26 1121156 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   30 1121186 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   27 1121213 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
   81 1121294 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99960 1221254 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  215 1221469 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  173 1221642 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  285 1221927 [main] test2 1974 fhandler_serial::raw_read: inq 100
  210 1222137 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  254 1222391 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  146 1222537 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  738 1223275 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  158 1223433 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   79 1223512 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   64 1223576 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   97 1223673 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  301 1223974 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
108415 1332389 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  135 1332524 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   37 1332561 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  193 1332754 [main] test2 1974 fhandler_serial::raw_read: inq 100
   54 1332808 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   34 1332842 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   34 1332876 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  123 1332999 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   45 1333044 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   34 1333078 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   38 1333116 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   37 1333153 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  347 1333500 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99793 1433293 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  274 1433567 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  151 1433718 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  478 1434196 [main] test2 1974 fhandler_serial::raw_read: inq 100
  161 1434357 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  192 1434549 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  146 1434695 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  500 1435195 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   82 1435277 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  143 1435420 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  111 1435531 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  140 1435671 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  432 1436103 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100212 1536315 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  278 1536593 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  154 1536747 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  646 1537393 [main] test2 1974 fhandler_serial::raw_read: inq 100
  186 1537579 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  168 1537747 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  212 1537959 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  608 1538567 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  127 1538694 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  111 1538805 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  119 1538924 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   94 1539018 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  342 1539360 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99886 1639246 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  208 1639454 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   53 1639507 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  340 1639847 [main] test2 1974 fhandler_serial::raw_read: inq 100
   59 1639906 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   51 1639957 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   33 1639990 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  119 1640109 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   40 1640149 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   47 1640196 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   40 1640236 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   33 1640269 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  112 1640381 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99881 1740262 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  139 1740401 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   35 1740436 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  209 1740645 [main] test2 1974 fhandler_serial::raw_read: inq 100
  113 1740758 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   32 1740790 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   26 1740816 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  115 1740931 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   39 1740970 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   27 1740997 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   34 1741031 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   30 1741061 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
   85 1741146 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99688 1840834 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  273 1841107 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  166 1841273 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  547 1841820 [main] test2 1974 fhandler_serial::raw_read: inq 100
  158 1841978 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  193 1842171 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  192 1842363 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  520 1842883 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   97 1842980 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  121 1843101 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  115 1843216 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  139 1843355 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  345 1843700 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100152 1943852 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  269 1944121 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  177 1944298 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  564 1944862 [main] test2 1974 fhandler_serial::raw_read: inq 100
   68 1944930 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   84 1945014 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  142 1945156 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  661 1945817 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  103 1945920 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  155 1946075 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  164 1946239 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  123 1946362 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  128 1946490 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99856 2046346 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  216 2046562 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  190 2046752 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  424 2047176 [main] test2 1974 fhandler_serial::raw_read: inq 100
   64 2047240 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  125 2047365 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  144 2047509 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  652 2048161 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  145 2048306 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  129 2048435 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  105 2048540 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  136 2048676 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  276 2048952 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99930 2148882 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  153 2149035 [main] test2 1974 pselect: pselect (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20, 0x0)
   29 2149064 [main] test2 1974 pselect: to->tv_sec 1, to->tv_nsec 0, us 1000000
   43 2149107 [main] test2 1974 dtable::select_read: /dev/ttyS27 fd 3
   23 2149130 [main] test2 1974 select: sel.always_ready 0
  329 2149459 [main] test2 1974 select_stuff::wait: m 4, us 1000000, wmfo_timeout -1
  176 2149635 [sersel] test2 1974 peek_serial: fh->overlapped_armed 0
  622 2150257 [sersel] test2 1974 thread_serial: exiting
  104 2150361 [main] test2 1974 select_stuff::wait: wait_ret 2, m = 4.  verifying
   87 2150448 [main] test2 1974 set_bits: me 0x80003B340, testing fd 3 (/dev/ttyS27)
   59 2150507 [main] test2 1974 set_bits: ready 1
   95 2150602 [main] test2 1974 select_stuff::wait: res after verify 0
  105 2150707 [main] test2 1974 select_stuff::wait: returning 0
  105 2150812 [main] test2 1974 select: sel.wait returns 0
   95 2150907 [main] test2 1974 peek_serial: fh->overlapped_armed 0
   93 2151000 [main] test2 1974 peek_serial: already ready
  103 2151103 [main] test2 1974 set_bits: me 0x80003B340, testing fd 3 (/dev/ttyS27)
  105 2151208 [main] test2 1974 set_bits: ready 1
  119 2151327 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
  195 2151522 [main] test2 1974 select_stuff::destroy: deleting select records
  152 2151674 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
  103 2151777 [main] test2 1974 select_stuff::destroy: deleting select records
   88 2151865 [main] test2 1974 pselect: 1 = select (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20)
   76 2151941 [main] test2 1974 ioctl: ioctl(fd 3, cmd 0x541B)
   37 2151978 [main] test2 1974 fhandler_serial::ioctl: 0 = ioctl(541B, 0xFFFFCA7C)
   28 2152006 [main] test2 1974 ioctl: 0 = ioctl(3, 0x541B, ...)
  328 2152334 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 6)
  102 2152436 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  107 2152543 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  112 2152655 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  200 2152855 [main] test2 1974 write: 6 = write(1, 0x80004B450, 6)
  148 2153003 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   29 2153032 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  269 2153301 [main] test2 1974 fhandler_serial::raw_read: inq 100
  118 2153419 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  126 2153545 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  104 2153649 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  376 2154025 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  113 2154138 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  134 2154272 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  118 2154390 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  201 2154591 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  142 2154733 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100133 2254866 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  239 2255105 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  147 2255252 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  426 2255678 [main] test2 1974 fhandler_serial::raw_read: inq 100
  153 2255831 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  171 2256002 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  149 2256151 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  398 2256549 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  122 2256671 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  129 2256800 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  116 2256916 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  143 2257059 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  375 2257434 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99887 2357321 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  170 2357491 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   46 2357537 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  198 2357735 [main] test2 1974 fhandler_serial::raw_read: inq 100
  129 2357864 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   97 2357961 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   50 2358011 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  176 2358187 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  109 2358296 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   69 2358365 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   66 2358431 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   63 2358494 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  158 2358652 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99726 2458378 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  180 2458558 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  139 2458697 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  485 2459182 [main] test2 1974 fhandler_serial::raw_read: inq 100
  150 2459332 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  117 2459449 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  120 2459569 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  404 2459973 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  130 2460103 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  123 2460226 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  154 2460380 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  100 2460480 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  341 2460821 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100079 2560900 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  281 2561181 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  151 2561332 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  622 2561954 [main] test2 1974 fhandler_serial::raw_read: inq 100
  159 2562113 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  191 2562304 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  178 2562482 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  404 2562886 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  229 2563115 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  119 2563234 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  121 2563355 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  123 2563478 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  321 2563799 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100166 2663965 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  273 2664238 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  114 2664352 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  465 2664817 [main] test2 1974 fhandler_serial::raw_read: inq 100
  174 2664991 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  100 2665091 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  105 2665196 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  373 2665569 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  129 2665698 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  113 2665811 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  119 2665930 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  120 2666050 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  352 2666402 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100057 2766459 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  216 2766675 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  184 2766859 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  430 2767289 [main] test2 1974 fhandler_serial::raw_read: inq 100
  161 2767450 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  187 2767637 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  192 2767829 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  165 2767994 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   67 2768061 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  106 2768167 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  314 2768481 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  148 2768629 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  374 2769003 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100094 2869097 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  288 2869385 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  178 2869563 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  430 2869993 [main] test2 1974 fhandler_serial::raw_read: inq 100
  138 2870131 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  215 2870346 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  180 2870526 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  549 2871075 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  227 2871302 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  114 2871416 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  113 2871529 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  133 2871662 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  352 2872014 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99939 2971953 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  281 2972234 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  140 2972374 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  413 2972787 [main] test2 1974 fhandler_serial::raw_read: inq 100
  171 2972958 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  187 2973145 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  188 2973333 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  503 2973836 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  124 2973960 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  119 2974079 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  107 2974186 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  136 2974322 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  338 2974660 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99806 3074466 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  238 3074704 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  226 3074930 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  488 3075418 [main] test2 1974 fhandler_serial::raw_read: inq 100
  113 3075531 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
   28 3075559 [main] test2 1974 fhandler_base::read: returning -1, binary mode
   65 3075624 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  729 3076353 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  143 3076496 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  129 3076625 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  100 3076725 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  110 3076835 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  257 3077092 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99865 3176957 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  267 3177224 [main] test2 1974 pselect: pselect (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20, 0x0)
  104 3177328 [main] test2 1974 pselect: to->tv_sec 1, to->tv_nsec 0, us 1000000
  209 3177537 [main] test2 1974 dtable::select_read: /dev/ttyS27 fd 3
  152 3177689 [main] test2 1974 select: sel.always_ready 0
  311 3178000 [sersel] test2 1974 peek_serial: fh->overlapped_armed 0
   68 3178068 [main] test2 1974 select_stuff::wait: m 4, us 1000000, wmfo_timeout -1
  652 3178720 [sersel] test2 1974 thread_serial: exiting
  188 3178908 [main] test2 1974 select_stuff::wait: wait_ret 2, m = 4.  verifying
   80 3178988 [main] test2 1974 set_bits: me 0x80003B340, testing fd 3 (/dev/ttyS27)
   59 3179047 [main] test2 1974 set_bits: ready 1
   61 3179108 [main] test2 1974 select_stuff::wait: res after verify 0
   44 3179152 [main] test2 1974 select_stuff::wait: returning 0
   46 3179198 [main] test2 1974 select: sel.wait returns 0
   55 3179253 [main] test2 1974 peek_serial: fh->overlapped_armed 0
   65 3179318 [main] test2 1974 peek_serial: already ready
  165 3179483 [main] test2 1974 set_bits: me 0x80003B340, testing fd 3 (/dev/ttyS27)
   42 3179525 [main] test2 1974 set_bits: ready 1
   51 3179576 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
  158 3179734 [main] test2 1974 select_stuff::destroy: deleting select records
  220 3179954 [main] test2 1974 select_stuff::cleanup: calling cleanup routines
  211 3180165 [main] test2 1974 select_stuff::destroy: deleting select records
  197 3180362 [main] test2 1974 pselect: 1 = select (4, 0xFFFFCBC8, 0x0, 0x0, 0xFFFFCA20)
  103 3180465 [main] test2 1974 ioctl: ioctl(fd 3, cmd 0x541B)
  111 3180576 [main] test2 1974 fhandler_serial::ioctl: 0 = ioctl(541B, 0xFFFFCA7C)
  220 3180796 [main] test2 1974 ioctl: 0 = ioctl(3, 0x541B, ...)
  426 3181222 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 6)
  112 3181334 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  116 3181450 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
   97 3181547 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
   70 3181617 [main] test2 1974 write: 6 = write(1, 0x80004B450, 6)
  152 3181769 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   56 3181825 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  323 3182148 [main] test2 1974 fhandler_serial::raw_read: inq 100
  118 3182266 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  122 3182388 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  189 3182577 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  224 3182801 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
   60 3182861 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
   47 3182908 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  142 3183050 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  231 3183281 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  312 3183593 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99848 3283441 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  190 3283631 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  206 3283837 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  530 3284367 [main] test2 1974 fhandler_serial::raw_read: inq 100
  166 3284533 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  199 3284732 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  201 3284933 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  610 3285543 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  124 3285667 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  230 3285897 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  117 3286014 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  155 3286169 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  349 3286518 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
99942 3386460 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  175 3386635 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
   84 3386719 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  380 3387099 [main] test2 1974 fhandler_serial::raw_read: inq 100
  153 3387252 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  135 3387387 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  144 3387531 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  477 3388008 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  112 3388120 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  216 3388336 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  108 3388444 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  107 3388551 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  264 3388815 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
100175 3488990 [main] test2 1974 clock_nanosleep: 0 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  251 3489241 [main] test2 1974 read: read(3, 0xFFFFCAB0, 100) nonblocking
  149 3489390 [main] test2 1974 fhandler_serial::raw_read: ulen 100, vmin_ 100, vtime_ 200, hEvent 0x160
  513 3489903 [main] test2 1974 fhandler_serial::raw_read: inq 100
  151 3490054 [main] test2 1974 __set_errno: virtual void fhandler_serial::raw_read(void*, size_t&):135 setting errno 11
  187 3490241 [main] test2 1974 fhandler_base::read: returning -1, binary mode
  186 3490427 [main] test2 1974 read: -1 = read(3, 0xFFFFCAB0, -1), errno 11
  570 3490997 [main] test2 1974 fhandler_pty_slave::write: pty0, write(0x80004B450, 23)
  112 3491109 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex (0x14C): waiting -1 ms
  128 3491237 [main] test2 1974 fhandler_pty_slave::write: (1507): pty output_mutex: acquired
  114 3491351 [main] test2 1974 fhandler_pty_slave::write: (1522): pty output_mutex(0x14C) released
  123 3491474 [main] test2 1974 write: 23 = write(1, 0x80004B450, 23)
  139 3491613 [main] test2 1974 clock_nanosleep: clock_nanosleep (0.100000000)
29210 3520823 [sig] test2 1974 sigpacket::process: signal 2 processing
  116 3520939 [sig] test2 1974 init_cygheap::find_tls: sig 2
   72 3521011 [sig] test2 1974 sigpacket::process: using tls 0xFFFFCE00
  315 3521326 [sig] test2 1974 sigpacket::process: signal 2, signal handler 0x180062F60
  109 3521435 [sig] test2 1974 sigpacket::setup_handler: controlled interrupt. stackptr 0xFFFFE460, stack 0xFFFFE458, stackptr[-1] 0x10040133E
  175 3521610 [sig] test2 1974 proc_subproc: args: 5, 1
  125 3521735 [main] test2 1974 clock_nanosleep: 4 = clock_nanosleep(1, 0, 0.100000000, 0.d)
  100 3521835 [sig] test2 1974 proc_subproc: clear waiting threads
  106 3521941 [sig] test2 1974 proc_subproc: finished clearing
   83 3522024 [sig] test2 1974 proc_subproc: returning 1
   53 3522077 [sig] test2 1974 _cygtls::interrupt_setup: armed signal_arrived 0x170, signal 2
   26 3522103 [sig] test2 1974 sigpacket::setup_handler: signal 2 delivered
   25 3522128 [sig] test2 1974 sigpacket::process: returning 1
   27 3522155 [main] test2 1974 __set_errno: unsigned int usleep(useconds_t):186 setting errno 4
   45 3522200 [main] test2 1974 set_process_mask_delta: oldmask 0, newmask 0, deltamask 0
   55 3522255 [main] test2 1974 signal_exit: exiting due to signal 2
   59 3522314 [main] test2 1974 signal_exit: about to call do_exit (2)
   57 3522371 [main] test2 1974 do_exit: do_exit (2), exit_state 2
   86 3522457 [main] test2 1974 void: 0x0 = signal (20, 0x1)
   56 3522513 [main] test2 1974 void: 0x0 = signal (1, 0x1)
   86 3522599 [main] test2 1974 void: 0x0 = signal (2, 0x1)
   90 3522689 [main] test2 1974 void: 0x0 = signal (3, 0x1)
  108 3522797 [main] test2 1974 fhandler_base::close_with_arch: line 1183:  /dev/pty0<0x1803452B0> usecount + -1 = 3
  131 3522928 [main] test2 1974 fhandler_base::close_with_arch: not closing archetype
   80 3523008 [main] test2 1974 fhandler_base::close_with_arch: line 1183:  /dev/pty0<0x1803452B0> usecount + -1 = 2
   93 3523101 [main] test2 1974 fhandler_base::close_with_arch: not closing archetype
  196 3523297 [main] test2 1974 fhandler_base::close_with_arch: line 1183:  /dev/pty0<0x1803452B0> usecount + -1 = 1
  199 3523496 [main] test2 1974 fhandler_base::close_with_arch: not closing archetype
   42 3523538 [main] test2 1974 fhandler_base::close: closing '/dev/ttyS27' handle 0x2B4
100057 3623595 [main] test2 1974 init_cygheap::close_ctty: closing cygheap->ctty 0x1803452B0
  219 3623814 [main] test2 1974 fhandler_base::close_with_arch: closing passed in archetype 0x0, usecount 0
  100 3623914 [main] test2 1974 fhandler_pty_slave::cleanup: /dev/pty0 closed, usecount 0
  106 3624020 [main] test2 1974 fhandler_pty_slave::close: closing last open /dev/pty0 handle
  467 3624487 [main] test2 1974 fhandler_console::free_console: freed console, res 1
   54 3624541 [main] test2 1974 fhandler_pty_common::close: pty0 <0x15C,0x168> closing
  116 3624657 [main] test2 1974 dtable::delete_archetype: deleting element 0 for /dev/pty0(136/0)
  204 3624861 [main] test2 1974 getpid: 1974 = getpid()
  176 3625037 [main] test2 1974 proc_terminate: nprocs 0
  186 3625223 [main] test2 1974 proc_terminate: leaving
  224 3625447 [main] test2 1974 pinfo::exit: Calling dlls.cleanup_forkables n 0x2, exitcode 0x200
  142 3625589 [main] test2 1974 pinfo::exit: Calling ExitProcess n 0x2, exitcode 0x200
--- Process 43708 (pid: 1974) thread 37764 exited with status 0x200
--- Process 43708 (pid: 1974) thread 28796 exited with status 0x200
--- Process 43708 (pid: 1974) thread 14456 exited with status 0x200
--- Process 43708 (pid: 1974) thread 4468 exited with status 0x200
--- Process 43708 (pid: 1974) exited with status 0x200


More information about the Cygwin mailing list