PTY dynamic option test failing

[saleyn]

$ make test
===> Verifying dependencies...
===> Compiling c_src/ei++.cpp
===> Compiling c_src/exec.cpp
===> Compiling c_src/exec_impl.cpp
===> Linking /home/serge/projects/erl-libs/erlexec/priv/x86_64-pc-linux-gnu/exec-port
===> Analyzing applications...
===> Compiling erlexec
===> Performing EUnit tests...
.................FF
==> Test Concurrency: 900
.
Failures:

  1) exec:exec_test_/0:1400
     Failure/Error: ?assertMatch({ stdout , I3 , << "test" >> }, timeout)
       expected: = { stdout , I3 , << "test" >> }
            got: timeout
     %% eunit_proc.erl:570:in `eunit_proc:run_group/2`
     Output: 
     Output: 
  2) exec:exec_test_/0:1401
     Failure/Error: ?assertMatch({ stdout , I , << "test\r\n" >> }, timeout)
       expected: = { stdout , I , << "test\r\n" >> }
            got: timeout
     %% eunit_proc.erl:570:in `eunit_proc:run_group/2`
     Output: 
     Output: 

Finished in 23.408 seconds
20 tests, 2 failures
===> Error running tests
make: *** [Makefile:37: test] Error 1

[SteffenDE]

Interesting, I'm testing with Erlang 25.0.1 on Ubuntu 20.04 (Bash Shell):

steffen@f8d19e717ccb:~/erlexec$ make test
===> Verifying dependencies...
===> Analyzing applications...
===> Compiling erlexec
===> Performing EUnit tests...
...................
==> Test Concurrency: 900
.
Finished in 13.392 seconds
20 tests, 0 failures
steffen@f8d19e717ccb:~/erlexec$ stty
speed 38400 baud; line = 0;
-brkint -imaxbel

Which Erlang version and shell do you use? Are there any special tty options set by default (see stty output)?

[saleyn]

I have erlang 24.3.2. Notably, this bug doesn't manifest itself 100% of times. If you rerun make test many times, it might occasionally come up.

$ stty
speed 38400 baud; line = 0;
-brkint -imaxbel iutf8

[SteffenDE]

Ah yes, now it failed for me too. I'll try to find out why and fix it in the next days.

[saleyn]

I committed a branch error, in which I isolated the last pty test, which runs with debugging option. The Erlang command pipe gets broken, which could be an indication of an error in parsing commands sent from Erlang to the erlexec port process. Here's the output:

$ RUN_COUNT=1 make test                                      
===> Verifying dependencies...                                                                      
===> Analyzing applications...                                                                      
===> Compiling erlexec                                                                              
===> Performing EUnit tests...                                                                      
..................Initializing: uid=1000, userid=0, use-poll=1 [c_src/exec.cpp:618]                                                                                                                      
  Opened PTY master=6 [c_src/exec_impl.cpp:331]                                                     
  Redirecting [stdin -> pipe:{r=-1,w=6}] (PTY) [c_src/exec_impl.cpp:388]                            
  Redirecting [stdout -> pipe:{r=6,w=-1}] (PTY) [c_src/exec_impl.cpp:388]
  Redirecting [stderr -> stdout] [c_src/exec_impl.cpp:376]              
Starting child: 'echo started && cat' (euid=-1) [c_src/exec_impl.cpp:416]
  child  = (stdin=stdout, stdout=stdout, stderr=stdout)          
  parent = (stdin=fd:6, stdout=fd:6, stderr=none)
  Args[0]: /bin/bash               
  Args[1]: -c                                                                                       
  Args[2]: echo started && cat                                                                      
  Setup writing end of pid 3140325 stdin redirection (fd=6 [non-block]) [c_src/exec_impl.cpp:669]
  Setup reading end of pid 3140325 stdout redirection (fd=6 [non-block]) [c_src/exec_impl.cpp:669]
  Redirecting [stdin -> pipe:{r=7,w=6}] (PTY) [c_src/exec_impl.cpp:485]
  Redirecting [stdout -> pipe:{r=6,w=7}] (PTY) [c_src/exec_impl.cpp:485]
Wrote 5/5 bytes to stdin (fd=6) of pid 3140325 [c_src/exec_impl.cpp:248]
Wrote 1/1 bytes to stdin (fd=6) of pid 3140325 [c_src/exec_impl.cpp:248]
Wrote 1/1 bytes to stdin (fd=6) of pid 3140325 [c_src/exec_impl.cpp:248]
tty mode ECHO enabled [c_src/ttymodes.hpp:77]
set tty_char VINTR [c_src/ttymodes.hpp:8]                                                           
Wrote 5/5 bytes to stdin (fd=6) of pid 3140325 [c_src/exec_impl.cpp:248]

Broken Erlang command pipe (0): Success (-1) [c_src/exec.cpp:313]         <---- !!!!!!!!!!!!!!!!
Setting alarm to 15 seconds [c_src/exec.cpp:697]
Got signal: 15 [c_src/exec.hpp:435]
Request to stop pid 3140325 [c_src/exec_impl.cpp:704]
Called kill(pid=3140325, sig=15) -> 0 [c_src/exec_impl.cpp:822] [c_src/exec_impl.cpp:1147]
Sent SIGTERM to pid 3140325 (timeout=5s) [c_src/exec_impl.cpp:750]
FChild process 3140325 exited [c_src/exec.hpp:424]

==> Test Concurrency: 1
.
Failures:

  1) exec:exec_pty_test_/0:1414
     Failure/Error: ?assertMatch({ stdout , I , << "test\r\n" >> }, timeout)
       expected: = { stdout , I , << "test\r\n" >> }
            got: timeout
     %% eunit_proc.erl:570:in `eunit_proc:run_group/2`
     Output: 
     Output: 

Finished in 6.999 seconds
20 tests, 1 failures
===> Error running tests
make: *** [Makefile:37: test] Error 1

[SteffenDE]

Okay running on macOS, I managed to get a different error (line numbers differ as I'm on another branch):

Opened PTY master=6 [c_src/exec_impl.cpp:373]
  Redirecting [stdin -> pipe:{r=-1,w=6}] (PTY) [c_src/exec_impl.cpp:431]
  Redirecting [stdout -> pipe:{r=6,w=-1}] (PTY) [c_src/exec_impl.cpp:431]
  Redirecting [stderr -> stdout] [c_src/exec_impl.cpp:419]
Starting child: 'echo started && cat' (euid=-1) [c_src/exec_impl.cpp:460]
  child  = (stdin=stdout, stdout=stdout, stderr=stdout)
  parent = (stdin=fd:6, stdout=fd:6, stderr=none)
  Args[0]: /bin/sh
  Args[1]: -c
  Args[2]: echo started && cat
  Setup writing end of pid 87799 stdin redirection (fd=6 [non-block]) [c_src/exec_impl.cpp:713]
  Setup reading end of pid 87799 stdout redirection (fd=6 [non-block]) [c_src/exec_impl.cpp:713]
  Redirecting [stdin -> pipe:{r=7,w=6}] (PTY) [c_src/exec_impl.cpp:528]
  Redirecting [stdout -> pipe:{r=6,w=7}] (PTY) [c_src/exec_impl.cpp:528]
Wrote 5/5 bytes to stdin (fd=6) of pid 87799 [c_src/exec_impl.cpp:291]
Wrote 1/1 bytes to stdin (fd=6) of pid 87799 [c_src/exec_impl.cpp:291]
Wrote 1/1 bytes to stdin (fd=6) of pid 87799 [c_src/exec_impl.cpp:291]
tty mode ECHO enabled
 [c_src/ttymodes.hpp:77]
set tty_char VINTR
 [c_src/ttymodes.hpp:8]
Wrote 5/5 bytes to stdin (fd=6) of pid 87799 [c_src/exec_impl.cpp:291]
FBroken Erlang command pipe (25): Inappropriate ioctl for device [c_src/exec.cpp:315] <---- !!!!!!!!!!!!!!!!

[SteffenDE]

Okay I know why it's failing... Sometimes we receive both "test\r\n" in one message.. Will send a PR that fixes this.