Menu

#8 Expect on Haiku fails to wait for end of file

open
nobody
None
5
2023-07-02
2023-06-30
No

Hello,
I am trying to run expect (5.45.4 with tcl 8.6.13) on the Haiku operating system, with this very simple script:

spawn echo
expect eof

On Linux, this works well and returns immediately. On Haiku, the end of file seems to not be detected and the expect blocks for 10 seconds (the default timeout). The problem is probably on Haiku side and I'm happy to fix whatever is needed there. However, I appreciate some help on how to investigate this, as I quickly got lost trying to understand the use of TCL channels and event loops.

Related

Support Requests: #8

Discussion

  • Nils Carlson

    Nils Carlson - 2023-07-01

    Hi,

    Normally (on Linux) the best way to debug these sorts of issues are with strace. I don't know if something similar is available on Haiku?

    Regards,
    Nils

    On 30 June 2023 at 22:49:22 +02:00, Adrien Destugues pulkomandy@users.sourceforge.net wrote:

    [support-requests:#8] https://sourceforge.net/p/expect/support-requests/8/ Expect on Haiku fails to wait for end of file

    Status: open
    Group:

    Created: Fri Jun 30, 2023 08:49 PM UTC by Adrien Destugues

    Last Updated: Fri Jun 30, 2023 08:49 PM UTC

    Owner: nobody

    Hello,
    I am trying to run expect (5.45.4 with tcl 8.6.13) on the Haiku operating system, with this very simple script:

    spawn echo
    expect eof

    On Linux, this works well and returns immediately. On Haiku, the end of file seems to not be detected and the expect blocks for 10 seconds (the default timeout). The problem is probably on Haiku side and I'm happy to fix whatever is needed there. However, I appreciate some help on how to investigate this, as I quickly got lost trying to understand the use of TCL channels and event loops.

    Sent from sourceforge.net because you indicated interest in https://sourceforge.net/p/expect/support-requests/8/
    To unsubscribe from further messages, please visit https://sourceforge.net/auth/subscriptions/

     

    Related

    Support Requests: #8

    • Don Libes

      Don Libes - 2023-07-01

      Tcl's channel system will use Expect's input handler (ExpInputProc in exp_chan.c) so verify whether ExpInputProc is even being called. The input handler basically just does a read() which should return immediately IF the pty has been properly configured.

      Pty misconfiguration is the most likely issue for a new port since every OS loves to have its own pty variant. Verify that configure is choosing the right implementation. If there is no right implementation, might require a comparison of other's ptys to Haiku's ptys to figure out how to add support for Haiku to Expect.

       
  • Adrien Destugues

    The PTY system is configured to use openpty and should behave similarly to the BSDs, but of course, there could be bugs. It seems to be working except for the end of file detection. For example if I do:

    spawn echo hi
    expect hi
    

    This is working fine.

    Yes, we have strace. Here is the trace on Haiku:

    [  3199] open(0xffffffff, "/dev/tty", O_RDWR, 0x0) = 0x3 (31 us)
    [  3199] ioctl(0x3, TCGETA, 0x1491b524560, 0x0) = 0x0 No error (14 us)
    [  3199] ioctl(0x3, TIOCGWINSZ, 0x1491b524170, 0x1d907acf8bc) = 0x0 No error (13 us)
    [  3199] ioctl(0x0, TCGETA, 0x7fba4419bb90, 0x20) = 0x0 No error (13 us)
    [  3199] ioctl(0x1, TCGETA, 0x7fba4419bb90, 0x20) = 0x0 No error (13 us)
    [  3199] ioctl(0x0, TCGETA, 0x7fba4419bb70, 0x20) = 0x0 No error (13 us)
    [  3199] seek(0x0, 0x0, 0x1) = 0xec78 (13 us)
    [  3199] ioctl(0x0, TCGETA, 0x7fba4419b9e0, 0x20) = 0x0 No error (13 us)
    [  3199] seek(0x1, 0x0, 0x1) = 0xed13 (13 us)
    [  3199] ioctl(0x1, TCGETA, 0x7fba4419b9e0, 0x20) = 0x0 No error (13 us)
    [  3199] seek(0x2, 0x0, 0x1) = 0xedae (13 us)
    [  3199] ioctl(0x2, TCGETA, 0x7fba4419b9e0, 0x20) = 0x0 No error (13 us)
    [  3199] ioctl(0x2, TCGETA, 0x7fba4419bb70, 0x20) = 0x0 No error (14 us)
    [  3199] fcntl(0x3, F_SETFD, 0x1) = 0x0 No error (13 us)
    [  3199] fcntl(0x3, F_GETFL, 0x3) = 0x2 (13 us)
    [  3199] fcntl(0x3, F_SETFL, O_RDWR|O_NONBLOCK) = 0x0 No error (13 us)
    [  3199] fcntl(0x3, F_GETFL, 0x82) = 0x82 (13 us)
    [  3199] sigaction(0x2, 0x7fba4419b910, 0x7fba4419b930) = 0x0 No error (14 us)
    [  3199] sigaction(0xf, 0x7fba4419b910, 0x7fba4419b930) = 0x0 No error (13 us)
    [  3199] ioctl(0x0, TCGETA, 0x7fba4419bb40, 0x20) = 0x0 No error (13 us)
    [  3199] open(0xffffffff, "/packages/expect-5.45.4-2/.self/lib/expect5.45.4/expect.rc", 0, 0x0) = 0x80006003 No such file or directory (27 us)
    [  3199] open(0xffffffff, "/boot/home/.expect.rc", 0, 0x0) = 0x80006003 No such file or directory (22 us)
    [  3199] resize_area(0x8015, 0x170000) = 0x0 No error (14 us)
    expect1.1> [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5b91898, 0xb) = 0xb (16 us)
    [  3199] spawn_thread(0x7fba4419b900) = 0xc81 (33 us)
    [  3199] resume_thread(0xc81) = 0x0 No error (14 us)
    [  3199] mutex_switch_lock(0xe91aedfb34 [B_USER_MUTEX_LOCKED], 0x0, 0xe91aedfb24 [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) = 0x0 No error (51 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (15 us)
    spawn echo hi
    [  3199] mutex_switch_lock(0xe91aedfb34 [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], 0x0, 0x10b1d5aff42c [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) = 0x0 No error (4957793 us)
    [  3199] read(0x0, 0xffffffffffffffff, 0x10b1d5b91898, 0x1000) = 0xe (124 us)
    [  3199] resize_area(0x8015, 0x180000) = 0x0 No error (174 us)
    [  3199] normalize_path("/packages/expect-5.45.4-2/.self/lib/expect5.45.4", true, 0x7fba4419b430) = 0x0 No error (199 us)
    [  3199] read_stat(0xffffffff, "/boot/system/lib/expect5.45.4", false, 0x7fba4419b270, 0x80) = 0x0 No error (44 us)
    [  3199] open(0xffffffff, "/boot/system/lib/expect5.45.4/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (24 us)
    [  3199] normalize_path("/packages/expect-5.45.4-2/.self/lib/expect5.45.4", true, 0x7fba4419b430) = 0x0 No error (31 us)
    [  3199] read_stat(0xffffffff, "/boot/system/lib/expect5.45.4", false, 0x7fba4419b270, 0x80) = 0x0 No error (43 us)
    [  3199] open(0xffffffff, "/boot/system/lib/expect5.45.4/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (29 us)
    [  3199] normalize_path("/lib", true, 0x7fba4419b430) = 0x0 No error (24 us)
    [  3199] read_stat(0xffffffff, "/lib", false, 0x7fba4419b270, 0x80) = 0x80006003 No such file or directory (22 us)
    [  3199] access(0xffffffff, "/lib", 0x0, false) = 0x80006003 No such file or directory (23 us)
    [  3199] open(0xffffffff, "/lib/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (20 us)
    [  3199] normalize_path("/packages/tcl-8.6.13-1/.self/lib", true, 0x7fba4419b430) = 0x0 No error (27 us)
    [  3199] read_stat(0xffffffff, "/boot/system/lib", false, 0x7fba4419b270, 0x80) = 0x0 No error (24 us)
    [  3199] open(0xffffffff, "/boot/system/lib/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (23 us)
    [  3199] normalize_path("/packages/tcl-8.6.13-1/.self/lib/tcl8.6", true, 0x7fba4419b430) = 0x0 No error (114 us)
    [  3199] read_stat(0xffffffff, "/boot/system/lib/tcl8.6", false, 0x7fba4419b270, 0x80) = 0x0 No error (130 us)
    [  3199] open(0xffffffff, "/boot/system/lib/tcl8.6/tclIndex", 0, 0x0) = 0x6 (32 us)
    [  3199] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (14 us)
    [  3199] ioctl(0x6, TCGETA, 0x7fba4419b8d0, 0x20) = 0x80000005 Invalid Argument (15 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5ba90f8, 0x1000) = 0x1000 (18 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5ba90f8, 0x1000) = 0x5a3 (13 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5ba90f8, 0x1000) = 0x0 No error (12 us)
    [  3199] resize_area(0x8015, 0x190000) = 0x0 No error (16 us)
    [  3199] close(0x6) = 0x0 No error (14 us)
    [  3199] normalize_path("/packages/tcl-8.6.13-1/.self/lib/tcl8.6", true, 0x7fba4419b440) = 0x0 No error (27 us)
    [  3199] read_stat(0xffffffff, "/boot/system/lib/tcl8.6", false, 0x7fba4419b280, 0x80) = 0x0 No error (22 us)
    [  3199] read_stat(0xffffffff, "/boot/system/lib/tcl8.6/history.tcl", true, 0x7fba4419b9b0, 0x80) = 0x0 No error (32 us)
    [  3199] open(0xffffffff, "/boot/system/lib/tcl8.6/history.tcl", 0, 0x0) = 0x6 (23 us)
    [  3199] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (12 us)
    [  3199] ioctl(0x6, TCGETA, 0x7fba4419b890, 0x20) = 0x80000005 Invalid Argument (14 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5ba90f8, 0x1000) = 0x1000 (14 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5ba90f8, 0x1000) = 0xedc (13 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5ba90f8, 0x1000) = 0x0 No error (13 us)
    [  3199] close(0x6) = 0x0 No error (12 us)
    spawn[  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x5) = 0x5 (18 us)
     [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x1) = 0x1 (14 us)
    echo[  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x4) = 0x4 (15 us)
     [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x1) = 0x1 (14 us)
    hi[  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x2) = 0x2 (14 us)
    
    [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x3) = 0x3 (14 us)
    [  3199] open(0xffffffff, "/dev/ptmx", O_RDWR, 0x0) = 0x6 (34 us)
    [  3199] ioctl(0x6, B_IOCTL_GRANT_TTY, (nil), 0x0) = 0x0 No error (19 us)
    [  3199] ioctl(0x6, B_IOCTL_GET_TTY_INDEX, 0x7fba4419b5ec, 0x4) = 0x0 No error (13 us)
    [  3199] open(0xffffffff, "/dev/tt/p1", O_RDWR|O_NOCTTY, 0x0) = 0x7 (27 us)
    [  3199] read_stat(0x7, (nil), false, 0x7fba4419b570, 0x80) = 0x0 No error (15 us)
    [  3199] ioctl(0x7, TCGETA, 0x7fba4419b540, 0x20) = 0x0 No error (14 us)
    [  3199] ioctl(0x7, B_GET_PATH_FOR_DEVICE, 0x1d907dbcde0, 0x400) = 0xa (14 us)
    [  3199] close(0x7) = 0x0 No error (14 us)
    [  3199] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (13 us)
    [  3199] create_pipe() = 0x0 No error ([0x7, 0x8]) (31 us)
    [  3199] create_pipe() = 0x0 No error ([0x9, 0xa]) (23 us)
    [  3199] create_pipe() = 0x0 No error ([0xb, 0xc]) (24 us)
    [  3199] fork() = 0xc82 (203 us)
    [  3199] close(0x8) = 0x0 No error (14 us)
    [  3199] close(0x9) = 0x0 No error (13 us)
    [  3199] close(0xc) = 0x0 No error (13 us)
    [  3199] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (14 us)
    [  3199] fcntl(0x6, F_GETFL, 0x6) = 0x2 (14 us)
    [  3199] fcntl(0x6, F_SETFL, O_RDWR|O_NONBLOCK) = 0x0 No error (14 us)
    [  3199] fcntl(0x6, F_GETFL, 0x82) = 0x82 (14 us)
    [  3199] read(0x7, 0xffffffffffffffff, 0x7fba4419b843, 0x1) = 0x1 (23250 us)
    [  3199] write(0xa, 0xffffffffffffffff, 0x1491b3178b3, 0x1) = 0x1 (24 us)
    [  3199] close(0x7) = 0x0 No error (33 us)
    [  3199] close(0xa) = 0x0 No error (24 us)
    [  3199] read(0xb, 0xffffffffffffffff, 0x7fba4419b844, 0x4) = 0x0 No error (320 us)
    [  3199] close(0xb) = 0x0 No error (24 us)
    3202[  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x4) = 0x4 (17 us)
    
    [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0x3) = 0x3 (16 us)
    expect1.2> [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5badb48, 0xb) = 0xb (17 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (17 us)
    [  3199] mutex_switch_lock(0xe91aedfb34 [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], 0x0, 0x10b1d5aff42c [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) = 0x8000000a Interrupted system call (8823 us)
    [  3201] --- SIGCHLD (Child exited) {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=3202, si_uid=0, si_status=0, si_value=(nil)} ---
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (33 us)
    [  3199] mutex_unblock(0xe91aedfb34 [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (31 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (17 us)
    expect eof
    [  3199] mutex_switch_lock(0xe91aedfb34 [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], 0x0, 0x10b1d5aff42c [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], "pthread condition", 0x0, 0x7fffffffffffffff) = 0x0 No error (2292800 us)
    [  3199] read(0x0, 0xffffffffffffffff, 0x10b1d5b91898, 0x1000) = 0xb (105 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (65 us)
    [  3199] mutex_switch_lock(0xe91aedfb34 [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], 0x0, 0x10b1d5aff42c [B_USER_MUTEX_LOCKED], "pthread condition", 0x50, 0x5ff68b7ec86ce) = 0x0 No error (88 us)
    [  3199] read(0x6, 0xffffffffffffffff, 0x10b1d5badb48, 0x1000) = 0x4 (17 us)
    hi
    [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5bab0f8, 0x4) = 0x4 (20 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (16 us)
    [  3199] mutex_switch_lock(0xe91aedfb34 [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], 0x0, 0x10b1d5aff42c [B_USER_MUTEX_LOCKED], "pthread condition", 0x50, 0x5ff68b7ec87bb) = 0x80000009 Operation timed out (10000066 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (125 us)
    [  3199] mutex_unblock(0xe91aedfb34 [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (76 us)
    expect1.3> [  3199] write(0x1, 0xffffffffffffffff, 0x10b1d5bab0f8, 0xb) = 0xb (73 us)
    [  3199] write(0x5, 0xffffffffffffffff, 0xe91ac9cd41, 0x1) = 0x1 (79 us)
    

    You can see that the "hi" output from echo is read by expect without problems, but then it waits for the end of file and this results in "Operation timed out" (10 seconds later, as that's the default timeout).

    openat(AT_FDCWD, "/dev/tty", O_RDWR)    = 3
    ioctl(3, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    ioctl(3, TIOCGWINSZ, {ws_row=56, ws_col=246, ws_xpixel=4536, ws_ypixel=0}) = 0
    ioctl(0, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    ioctl(1, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    getpid()                                = 939968
    ioctl(0, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    lseek(0, 0, SEEK_CUR)                   = -1 ESPIPE (Repérage non permis)
    ioctl(0, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    lseek(1, 0, SEEK_CUR)                   = -1 ESPIPE (Repérage non permis)
    ioctl(1, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    lseek(2, 0, SEEK_CUR)                   = -1 ESPIPE (Repérage non permis)
    ioctl(2, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    ioctl(2, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
    fcntl(3, F_GETFL)                       = 0x8002 (flags O_RDWR|O_LARGEFILE)
    fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK|O_LARGEFILE) = 0
    fcntl(3, F_GETFL)                       = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
    rt_sigaction(SIGINT, {sa_handler=0x7f0f078aa9c0, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f0f0743ef90}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
    rt_sigaction(SIGTERM, {sa_handler=0x7f0f078aa9c0, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f0f0743ef90}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
    ioctl(0, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    openat(AT_FDCWD, "/usr/lib/expect5.45.4/expect.rc", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    openat(AT_FDCWD, "/home/pulkomandy/.expect.rc", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    write(1, "expect1.1> ", 11expect1.1> )             = 11
    rt_sigaction(SIGRT_1, {sa_handler=0x7f0f07489540, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f0f0743ef90}, NULL, 8) = 0
    rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
    mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f0f068ee000
    mprotect(0x7f0f068ef000, 8388608, PROT_READ|PROT_WRITE) = 0
    rt_sigprocmask(SIG_BLOCK, ~[], [], 8)   = 0
    clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f0f070ee990, parent_tid=0x7f0f070ee990, exit_signal=0, stack=0x7f0f068ee000, stack_size=0x7fff80, tls=0x7f0f070ee6c0} => {parent_tid=[939969]}, 88) = 939969
    rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    write(5, "\0", 1)                       = 1
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 1
    futex(0x555f918e9ce0, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANYspawn echo hi
    ) = 0
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 0
    read(0, "spawn echo hi\n", 4096)        = 14
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/x86_64-linux-gnu", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/x86_64-linux-gnu/expect5.45.4", 0x7ffcc89c7660, 1023) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    access("/usr", F_OK)                    = 0
    access("/usr/lib", F_OK)                = 0
    access("/usr/lib/x86_64-linux-gnu", F_OK) = 0
    access("/usr/lib/x86_64-linux-gnu/expect5.45.4", F_OK) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/x86_64-linux-gnu", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/expect5.45.4/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/expect5.45.4", 0x7ffcc89c7660, 1023) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    access("/usr", F_OK)                    = 0
    access("/usr/lib", F_OK)                = 0
    access("/usr/lib/expect5.45.4", F_OK)   = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/lib/expect5.45.4/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/tcltk", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/tcltk/tcl8.6", 0x7ffcc89c7660, 1023) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    access("/usr", F_OK)                    = 0
    access("/usr/lib", F_OK)                = 0
    access("/usr/lib/tcltk", F_OK)          = 0
    access("/usr/lib/tcltk/tcl8.6", F_OK)   = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/tcltk", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/lib/tcltk/tcl8.6/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/tcltk", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/lib/tcltk/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/tcltk", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/lib/tcltk/x86_64-linux-gnu", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/lib/tcltk/x86_64-linux-gnu/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/local", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/local/share", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/local/share/tcltk", 0x7ffcc89c7660, 1023) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    access("/usr", F_OK)                    = 0
    access("/usr/local", F_OK)              = 0
    access("/usr/local/share", F_OK)        = 0
    access("/usr/local/share/tcltk", F_OK)  = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/local", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/local/share", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/local/share/tcltk/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/local", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/local/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/local/lib/tcltk", 0x7ffcc89c7660, 1023) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    access("/usr", F_OK)                    = 0
    access("/usr/local", F_OK)              = 0
    access("/usr/local/lib", F_OK)          = 0
    access("/usr/local/lib/tcltk", F_OK)    = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/local", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/local/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/local/lib/tcltk/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/lib", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/lib/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c7660, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/share", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/share/tcltk", 0x7ffcc89c7660, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/share/tcltk/tclIndex", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
    readlink("/usr", 0x7ffcc89c76c0, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/share", 0x7ffcc89c76c0, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/share/tcltk", 0x7ffcc89c76c0, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/share/tcltk/tcl8.6", 0x7ffcc89c76c0, 1023) = -1 EINVAL (Argument invalide)
    openat(AT_FDCWD, "/usr/share/tcltk/tcl8.6/tclIndex", O_RDONLY) = 6
    fcntl(6, F_SETFD, FD_CLOEXEC)           = 0
    ioctl(6, TCGETS, 0x7ffcc89c8c00)        = -1 ENOTTY (Ioctl() inapproprié pour un périphérique)
    read(6, "# Tcl autoload index file, versi"..., 4096) = 4096
    read(6, "liasLoad) [list source [file joi"..., 4096) = 1443
    read(6, "", 4096)                       = 0
    brk(0x555f919a8000)                     = 0x555f919a8000
    close(6)                                = 0
    readlink("/usr", 0x7ffcc89c76a0, 1023)  = -1 EINVAL (Argument invalide)
    readlink("/usr/share", 0x7ffcc89c76a0, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/share/tcltk", 0x7ffcc89c76a0, 1023) = -1 EINVAL (Argument invalide)
    readlink("/usr/share/tcltk/tcl8.6", 0x7ffcc89c76a0, 1023) = -1 EINVAL (Argument invalide)
    stat("/usr/share/tcltk/tcl8.6/history.tcl", {st_mode=S_IFREG|0644, st_size=7900, ...}) = 0
    openat(AT_FDCWD, "/usr/share/tcltk/tcl8.6/history.tcl", O_RDONLY) = 6
    fcntl(6, F_SETFD, FD_CLOEXEC)           = 0
    ioctl(6, TCGETS, 0x7ffcc89c8ba0)        = -1 ENOTTY (Ioctl() inapproprié pour un périphérique)
    read(6, "# history.tcl --\n#\n# Implementat"..., 4096) = 4096
    read(6, "tty-printed version of the histo"..., 4096) = 3804
    read(6, "", 4096)                       = 0
    close(6)                                = 0
    write(1, "spawn", 5spawn)                    = 5
    write(1, " ", 1 )                        = 1
    write(1, "echo", 4echo)                     = 4
    write(1, " ", 1 )                        = 1
    write(1, "hi", 2hi)                       = 2
    write(1, "\r\r\n", 3
    )                   = 3
    openat(AT_FDCWD, "/dev/ptmx", O_RDWR)   = 6
    ioctl(6, TIOCGPTN, [1])                 = 0
    ioctl(6, TIOCSPTLCK, [0])               = 0
    ioctl(6, TIOCGPTPEER, 0x102)            = 7
    ioctl(6, TIOCGPTN, [1])                 = 0
    ioctl(7, TCGETS, {B38400 opost isig icanon echo ...}) = 0
    ioctl(7, TCGETS, {B38400 opost isig icanon echo ...}) = 0
    newfstatat(7, "", {st_mode=S_IFCHR|0600, st_rdev=makedev(0x88, 0x1), ...}, AT_EMPTY_PATH) = 0
    readlink("/proc/self/fd/7", "/dev/pts/1", 4095) = 10
    newfstatat(AT_FDCWD, "/dev/pts/1", {st_mode=S_IFCHR|0600, st_rdev=makedev(0x88, 0x1), ...}, 0) = 0
    close(7)                                = 0
    fcntl(6, F_SETFD, FD_CLOEXEC)           = 0
    pipe2([7, 8], 0)                        = 0
    pipe2([9, 10], 0)                       = 0
    pipe2([11, 12], 0)                      = 0
    clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f0f073d8e50) = 939970
    close(8)                                = 0
    close(9)                                = 0
    close(12)                               = 0
    fcntl(6, F_SETFD, FD_CLOEXEC)           = 0
    fcntl(6, F_GETFL)                       = 0x8002 (flags O_RDWR|O_LARGEFILE)
    fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK|O_LARGEFILE) = 0
    fcntl(6, F_GETFL)                       = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
    read(7, " ", 1)                         = 1
    write(10, " ", 1)                       = 1
    close(7)                                = 0
    close(10)                               = 0
    read(11, "", 4)                         = 0
    close(11)                               = 0
    write(1, "939970", 6939970)                   = 6
    write(1, "\r\r\n", 3
    )                   = 3
    write(1, "expect1.2> ", 11expect1.2> )             = 11
    write(5, "\0", 1)                       = 1
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 1
    --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=939970, si_uid=1000, si_status=0, si_utime=0, si_stime=0} ---
    futex(0x555f918e9ce4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANYexpect eof
    ) = 0
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 0
    read(0, "expect eof\n", 4096)           = 11
    write(5, "\0", 1)                       = 1
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 1
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 0
    read(6, "hi\r\n", 4096)                 = 4
    write(1, "hi\r\n", 4hi
    )                   = 4
    write(5, "\0", 1)                       = 1
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 1
    futex(0x7f0f0788dce0, FUTEX_WAKE_PRIVATE, 1) = 0
    read(6, 0x555f91983068, 4096)           = -1 EIO (Erreur d'entrée/sortie)
    ioctl(6, TCGETS, {B19200 opost isig icanon echo ...}) = 0
    fcntl(6, F_GETFL)                       = 0x8802 (flags O_RDWR|O_NONBLOCK|O_LARGEFILE)
    fcntl(6, F_SETFL, O_RDWR|O_LARGEFILE)   = 0
    fcntl(6, F_GETFL)                       = 0x8002 (flags O_RDWR|O_LARGEFILE)
    close(6)                                = 0
    openat(AT_FDCWD, "/dev/null", O_RDONLY) = 6
    fcntl(6, F_SETFD, FD_CLOEXEC)           = 0
    fcntl(6, F_SETFD, FD_CLOEXEC)           = 0
    write(1, "expect1.3> ", 11expect1.3> )             = 11
    write(5, "\0", 1)                       = 1
    futex(0x555f918e9ce0, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY
    

    Here we see a FUTEX_WAKE_PRIVATE that does not block, followed by a read that returns EIO, which is detected as an end of file.

    So it looks like the problem happens before the input handler is called to read the end of file?

     
  • Adrien Destugues

    I have made some testing of PTY behavior in Haiku and I think I found a bug: https://dev.haiku-os.org/ticket/18486

    However, I am not sure where in expect or in tcl this would come into play, as I didn't find an use of select or poll (probably I just missed it because I don't know where to look).

     
    • Adrien Destugues

      I have now fixed that bug: closing the pty was not unblocking poll()/select() waiting for read events on the other side of it. However, that didn't help: expect is still not noticing when the pty is closed by the child exiting.

       
  • Adrien Destugues

    The previous strace output was missing spawned threads, here is a more complete one:

    [  3166] open(0xffffffff, "/dev/tty", O_RDWR, 0x0) = 0x3 (30 us)
    [  3166] ioctl(0x3, TCGETA, 0x1c322f83560, 0x0) = 0x0 No error (16 us)
    [  3166] ioctl(0x3, TIOCGWINSZ, 0x1c322f83170, 0xd40ccc888c) = 0x0 No error (14 us)
    [  3166] ioctl(0x0, TCGETA, 0x7f60df9cf360, 0x20) = 0x0 No error (14 us)
    [  3166] ioctl(0x1, TCGETA, 0x7f60df9cf360, 0x20) = 0x0 No error (13 us)
    [  3166] ioctl(0x0, TCGETA, 0x7f60df9cf340, 0x20) = 0x0 No error (13 us)
    [  3166] seek(0x0, 0x0, 0x1) = 0x69b9 (12 us)
    [  3166] ioctl(0x0, TCGETA, 0x7f60df9cf1b0, 0x20) = 0x0 No error (13 us)
    [  3166] seek(0x1, 0x0, 0x1) = 0x6a54 (12 us)
    [  3166] ioctl(0x1, TCGETA, 0x7f60df9cf1b0, 0x20) = 0x0 No error (14 us)
    [  3166] seek(0x2, 0x0, 0x1) = 0x6aef (20 us)
    [  3166] ioctl(0x2, TCGETA, 0x7f60df9cf1b0, 0x20) = 0x0 No error (14 us)
    [  3166] ioctl(0x2, TCGETA, 0x7f60df9cf340, 0x20) = 0x0 No error (13 us)
    [  3166] fcntl(0x3, F_SETFD, 0x1) = 0x0 No error (12 us)
    [  3166] fcntl(0x3, F_GETFL, 0x3) = 0x2 (13 us)
    [  3166] fcntl(0x3, F_SETFL, O_RDWR|O_NONBLOCK) = 0x0 No error (13 us)
    [  3166] fcntl(0x3, F_GETFL, 0x82) = 0x82 (12 us)
    [  3166] sigaction(0x2, 0x7f60df9cf0e0, 0x7f60df9cf100) = 0x0 No error (14 us)
    [  3166] sigaction(0xf, 0x7f60df9cf0e0, 0x7f60df9cf100) = 0x0 No error (12 us)
    [  3166] ioctl(0x0, TCGETA, 0x7f60df9cf310, 0x20) = 0x0 No error (13 us)
    [  3166] open(0xffffffff, "/packages/expect-5.45.4-2/.self/lib/expect5.45.4/expect.rc", 0, 0x0) = 0x80006003 No such file or directory (33 us)
    [  3166] open(0xffffffff, "/boot/home/.expect.rc", 0, 0x0) = 0x80006003 No such file or directory (32 us)
    [  3166] resize_area(0x7c10, 0x170000) = 0x0 No error (14 us)
    expect1.1> [  3166] write(0x1, 0xffffffffffffffff, 0x11119d106898, 0xb) = 0xb (16 us)
    [  3166] spawn_thread(0x7f60df9cf0d0) = 0xc60 (31 us)
    [  3166] resume_thread(0xc60) = 0x0 No error (14 us)
    [  3168] create_pipe() <unfinished ...>
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x19e6ee2db24 [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] <... create_pipe resumed>  = 0x0 No error ([0x4, 0x5]) (61 us)
    [  3168] fcntl(0x4, F_GETFL, (nil)) = 0x0 No error (14 us)
    [  3168] fcntl(0x4, F_SETFL, O_NONBLOCK) = 0x0 No error (14 us)
    [  3168] fcntl(0x5, F_GETFL, 0x80) = 0x1 (12 us)
    [  3168] fcntl(0x5, F_SETFL, O_WRONLY|O_NONBLOCK) = 0x0 No error (13 us)
    [  3168] fcntl(0x4, F_SETFD, 0x1) = 0x0 No error (11 us)
    [  3168] fcntl(0x5, F_SETFD, 0x1) = 0x0 No error (12 us)
    [  3168] mutex_unblock(0x19e6ee2db24 [B_USER_MUTEX_WAITING], 0x80000000) = 0x0 No error (19 us)
    [  3166] <... mutex_switch_lock resumed>  = 0x0 No error (249 us)
    [  3168] select(0x5, [4], [], [], 0xffffffffffffffff, (nil)) <unfinished ...>
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (46 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (53 us)
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) = 0x0 No error (42 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (12 us)
    spawn echo
    [  3168] select(0x5, [0 4], [], [0], 0xffffffffffffffff, (nil)) = 0x1 ([0], [], []) (12218468 us)
    [  3168] mutex_unblock(0x11119d07442c [B_USER_MUTEX_WAITING], 0x80000000) = 0x0 No error (33 us)
    [  3168] select(0x5, [4], [], [], 0xffffffffffffffff, (nil)) <unfinished ...>
    [  3166] <... mutex_switch_lock resumed>  = 0x0 No error (12218769 us)
    [  3166] read(0x0, 0xffffffffffffffff, 0x11119d106898, 0x1000) = 0xb (72 us)
    [  3166] resize_area(0x7c10, 0x180000) = 0x0 No error (97 us)
    [  3166] normalize_path("/packages/expect-5.45.4-2/.self/lib/expect5.45.4", true, 0x7f60df9cec00) = 0x0 No error (106 us)
    [  3166] read_stat(0xffffffff, "/boot/system/lib/expect5.45.4", false, 0x7f60df9cea40, 0x80) = 0x0 No error (80 us)
    [  3166] open(0xffffffff, "/boot/system/lib/expect5.45.4/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (21 us)
    [  3166] normalize_path("/packages/expect-5.45.4-2/.self/lib/expect5.45.4", true, 0x7f60df9cec00) = 0x0 No error (26 us)
    [  3166] read_stat(0xffffffff, "/boot/system/lib/expect5.45.4", false, 0x7f60df9cea40, 0x80) = 0x0 No error (22 us)
    [  3166] open(0xffffffff, "/boot/system/lib/expect5.45.4/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (18 us)
    [  3166] normalize_path("/lib", true, 0x7f60df9cec00) = 0x0 No error (18 us)
    [  3166] read_stat(0xffffffff, "/lib", false, 0x7f60df9cea40, 0x80) = 0x80006003 No such file or directory (17 us)
    [  3166] access(0xffffffff, "/lib", 0x0, false) = 0x80006003 No such file or directory (19 us)
    [  3166] open(0xffffffff, "/lib/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (18 us)
    [  3166] normalize_path("/packages/tcl-8.6.13-1/.self/lib", true, 0x7f60df9cec00) = 0x0 No error (32 us)
    [  3166] read_stat(0xffffffff, "/boot/system/lib", false, 0x7f60df9cea40, 0x80) = 0x0 No error (19 us)
    [  3166] open(0xffffffff, "/boot/system/lib/tclIndex", 0, 0x0) = 0x80006003 No such file or directory (19 us)
    [  3166] normalize_path("/packages/tcl-8.6.13-1/.self/lib/tcl8.6", true, 0x7f60df9cec00) = 0x0 No error (22 us)
    [  3166] read_stat(0xffffffff, "/boot/system/lib/tcl8.6", false, 0x7f60df9cea40, 0x80) = 0x0 No error (19 us)
    [  3166] open(0xffffffff, "/boot/system/lib/tcl8.6/tclIndex", 0, 0x0) = 0x6 (544 us)
    [  3166] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (13 us)
    [  3166] ioctl(0x6, TCGETA, 0x7f60df9cf0a0, 0x20) = 0x80000005 Invalid Argument (15 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d11e0f8, 0x1000) = 0x1000 (656 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d11e0f8, 0x1000) = 0x5a3 (16 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d11e0f8, 0x1000) = 0x0 No error (11 us)
    [  3166] resize_area(0x7c10, 0x190000) = 0x0 No error (15 us)
    [  3166] close(0x6) = 0x0 No error (11 us)
    [  3166] normalize_path("/packages/tcl-8.6.13-1/.self/lib/tcl8.6", true, 0x7f60df9cec10) = 0x0 No error (25 us)
    [  3166] read_stat(0xffffffff, "/boot/system/lib/tcl8.6", false, 0x7f60df9cea50, 0x80) = 0x0 No error (38 us)
    [  3166] read_stat(0xffffffff, "/boot/system/lib/tcl8.6/history.tcl", true, 0x7f60df9cf180, 0x80) = 0x0 No error (32 us)
    [  3166] open(0xffffffff, "/boot/system/lib/tcl8.6/history.tcl", 0, 0x0) = 0x6 (19 us)
    [  3166] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (12 us)
    [  3166] ioctl(0x6, TCGETA, 0x7f60df9cf060, 0x20) = 0x80000005 Invalid Argument (12 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d11e0f8, 0x1000) = 0x1000 (16 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d11e0f8, 0x1000) = 0xedc (15 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d11e0f8, 0x1000) = 0x0 No error (15 us)
    [  3166] close(0x6) = 0x0 No error (12 us)
    spawn[  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0x5) = 0x5 (16 us)
     [  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0x1) = 0x1 (15 us)
    echo[  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0x4) = 0x4 (15 us)
    
    [  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0x3) = 0x3 (15 us)
    [  3166] open(0xffffffff, "/dev/ptmx", O_RDWR, 0x0) = 0x6 (211 us)
    [  3166] ioctl(0x6, B_IOCTL_GRANT_TTY, (nil), 0x0) = 0x0 No error (22 us)
    [  3166] ioctl(0x6, B_IOCTL_GET_TTY_INDEX, 0x7f60df9cedbc, 0x4) = 0x0 No error (23 us)
    [  3166] open(0xffffffff, "/dev/tt/p1", O_RDWR|O_NOCTTY, 0x0) = 0x7 (23 us)
    [  3166] read_stat(0x7, (nil), false, 0x7f60df9ced40, 0x80) = 0x0 No error (13 us)
    [  3166] ioctl(0x7, TCGETA, 0x7f60df9ced10, 0x20) = 0x0 No error (13 us)
    [  3166] ioctl(0x7, B_GET_PATH_FOR_DEVICE, 0xd40cfb1a00, 0x400) = 0xa (13 us)
    [  3166] close(0x7) = 0x0 No error (14 us)
    [  3166] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (13 us)
    [  3166] create_pipe() = 0x0 No error ([0x7, 0x8]) (36 us)
    [  3166] create_pipe() = 0x0 No error ([0x9, 0xa]) (29 us)
    [  3166] create_pipe() = 0x0 No error ([0xb, 0xc]) (23 us)
    [  3166] fork() = 0xc61 (188 us)
    [  3166] close(0x8) = 0x0 No error (15 us)
    [  3166] close(0x9) = 0x0 No error (12 us)
    [  3166] close(0xc) = 0x0 No error (12 us)
    [  3166] fcntl(0x6, F_SETFD, 0x1) = 0x0 No error (13 us)
    [  3166] fcntl(0x6, F_GETFL, 0x6) = 0x2 (13 us)
    [  3166] fcntl(0x6, F_SETFL, O_RDWR|O_NONBLOCK) = 0x0 No error (16 us)
    [  3166] fcntl(0x6, F_GETFL, 0x82) = 0x82 (13 us)
    [  3166] read(0x7, 0xffffffffffffffff, 0x7f60df9cf013, 0x1) = 0x1 (23922 us)
    [  3166] write(0xa, 0xffffffffffffffff, 0x1c322d768b3, 0x1) = 0x1 (19 us)
    [  3166] close(0x7) = 0x0 No error (27 us)
    [  3166] close(0xa) = 0x0 No error (26 us)
    [  3166] read(0xb, 0xffffffffffffffff, 0x7f60df9cf014, 0x4) = 0x0 No error (820 us)
    [  3166] close(0xb) = 0x0 No error (28 us)
    3169[  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0x4) = 0x4 (17 us)
    
    [  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0x3) = 0x3 (14 us)
    expect1.2> [  3166] write(0x1, 0xffffffffffffffff, 0x11119d122b48, 0xb) = 0xb (15 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (15 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (31094 us)
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) = 0x0 No error (47 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (13 us)
    [  3168] select(0x5, [0 4], [], [0], 0xffffffffffffffff, (nil)) = 0xffffffff8000000a ([0 4], [], [0]) (8943 us)
    [  3166] <... mutex_switch_lock resumed>  = 0x8000000a Interrupted system call (9133 us)
    [  3168] --- SIGCHLD (Child exited) {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=3169, si_uid=0, si_status=0, si_value=(nil)} ---
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3166] <... write resumed>  = 0x1 (75 us)
    [  3166] mutex_unblock(0x19e6ee2db34 [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (22 us)
    [  3168] <... mutex_lock resumed>  = 0x0 No error (113 us)
    [  3166] mutex_lock(0x19e6ee2db34 [0], (nil), 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] select(0x5, [4], [], [], 0xffffffffffffffff, (nil)) <unfinished ...>
    [  3166] <... mutex_lock resumed>  = 0x0 No error (22 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (13 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (69 us)
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], "pthread condition", 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) = 0x0 No error (54 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (17 us)
    [  3168] select(0x5, [0 4], [], [0], 0xffffffffffffffff, (nil)) = 0x1 ([4], [], []) (36 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (13 us)
    expect eof
    [  3168] select(0x5, [0 4], [], [0], 0xffffffffffffffff, (nil)) = 0x1 ([0], [], []) (6688239 us)
    [  3168] mutex_unblock(0x11119d07442c [B_USER_MUTEX_WAITING], 0x80000000) = 0x0 No error (35 us)
    [  3168] select(0x5, [4], [], [], 0xffffffffffffffff, (nil)) <unfinished ...>
    [  3166] <... mutex_switch_lock resumed>  = 0x0 No error (6688749 us)
    [  3166] read(0x0, 0xffffffffffffffff, 0x11119d106898, 0x1000) = 0xb (92 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (74 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (504 us)
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED], "pthread condition", 0x50, 0x5ff7ed109d347) <unfinished ...>
    [  3168] <... mutex_lock resumed>  = 0x0 No error (103 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (14 us)
    [  3168] select(0x7, [4 6], [], [6], 0xffffffffffffffff, (nil)) = 0x1 ([6], [], []) (32 us)
    [  3168] mutex_unblock(0x11119d07442c [B_USER_MUTEX_WAITING], 0x80000000) = 0x0 No error (17 us)
    [  3168] select(0x7, [4], [], [], 0xffffffffffffffff, (nil)) <unfinished ...>
    [  3166] <... mutex_switch_lock resumed>  = 0x0 No error (261 us)
    [  3166] read(0x6, 0xffffffffffffffff, 0x11119d122b48, 0x1000) = 0x2 (17 us)
    
    [  3166] write(0x1, 0xffffffffffffffff, 0x11119d1200f8, 0x2) = 0x2 (15 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (14 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (202 us)
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED], "pthread condition", 0x50, 0x5ff7ed109d503) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) = 0x0 No error (36 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (13 us)
    
    (here is a 10 second pause)
    
    [  3168] select(0x7, [4 6], [], [6], 0xffffffffffffffff, (nil)) <unfinished ...>
    [  3166] <... mutex_switch_lock resumed>  = 0x80000009 Operation timed out (10000055 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (22 us)
    expect1.3> [  3166] write(0x1, 0xffffffffffffffff, 0x11119d1200f8, 0xb) = 0xb (19 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (10000141 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3166] <... write resumed>  = 0x1 (46 us)
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED|B_USER_MUTEX_WAITING], "pthread condition", 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] <... mutex_lock resumed>  = 0x0 No error (97 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (20 us)
    [  3168] select(0x7, [0 4 6], [], [0 6], 0xffffffffffffffff, (nil)) = 0x2 ([0 4], [], []) (82 us)
    [  3168] mutex_unblock(0x11119d07442c [B_USER_MUTEX_WAITING], 0x80000000) = 0x0 No error (24 us)
    [  3166] <... mutex_switch_lock resumed>  = 0x0 No error (295 us)
    [  3166] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] mutex_unblock(0x19e6ee2db34 [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (24 us)
    [  3166] <... mutex_lock resumed>  = 0x0 No error (45 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) <unfinished ...>
    [  3166] read(0x0, 0xffffffffffffffff, 0x11119d106898, 0x1000) <unfinished ...>
    [  3168] <... read resumed>  = 0x1 (16 us)
    [  3166] <... read resumed>  = 0x1 (22 us)
    [  3168] select(0x7, [4], [], [], 0xffffffffffffffff, (nil)) <unfinished ...>
    expect1.3> [  3166] write(0x1, 0xffffffffffffffff, 0x11119d1200f8, 0xb) = 0xb (17 us)
    [  3166] write(0x5, 0xffffffffffffffff, 0x19e6ebead41, 0x1) = 0x1 (13 us)
    [  3168] <... select resumed>  = 0x1 ([4], [], []) (86 us)
    [  3166] mutex_switch_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], 0x0, 0x11119d07442c [B_USER_MUTEX_LOCKED], "pthread condition", 0x0, 0x7fffffffffffffff) <unfinished ...>
    [  3168] mutex_lock(0x19e6ee2db34 [B_USER_MUTEX_LOCKED], (nil), 0x0, 0x7fffffffffffffff) = 0x0 No error (48 us)
    [  3168] read(0x4, 0xffffffffffffffff, 0x7f24eb2725f6, 0x1) = 0x1 (15 us)
    
     

Log in to post a comment.

Want the latest updates on software, tech news, and AI?
Get latest updates about software, tech news, and AI from SourceForge directly in your inbox once a month.