For completeness, the highlights of the new truss trace output after the echo.py change and only tracing the main process to avoid confusion from the interleaved output:
test_subprocess_interactive (test.test_asyncio.test_events.PollEventLoopTests) ...
socketpair(1, 1, 0, 0x2FF112F0) = 0
kfcntl(5, F_SETFD, 0x00000001) = 0
kfcntl(6, F_SETFD, 0x00000001) = 0
kfcntl(5, F_GETFL, 0x00000000) = 2
kioctl(5, -2147195266, 0x2FF12610, 0x00000000) = 0
kioctl(5, -2147195267, 0x2FF12610, 0x00000000) = 0
kfcntl(5, F_SETFL, 0x00000006) = 0
kfcntl(6, F_GETFL, 0x00000000) = 2
kioctl(6, -2147195266, 0x2FF12610, 0x00000000) = 0
kioctl(6, -2147195267, 0x2FF12610, 0x00000000) = 0
kfcntl(6, F_SETFL, 0x00000006) = 0
_poll(0x201A9B00, 1, 0) = 0
fstatx(6, 0x2FF0F0F0, 128, 010) = 0
sigprocmask(2, 0xF0296960, 0x2FF0F0A0) = 0
_sigaction(20, 0x2FF0F0F8, 0x2FF0F108) = 0
thread_setmymask_fast(0x00000000, 0x00000000, 0x00000000, 0x14260153, 0x00000003, 0x00000110, 0x00000000, 0x00000000) = 0x00000000
pipe(0x2FF0E2F0) = 0
kfcntl(7, F_SETFD, 0x00000001) = 0
kfcntl(8, F_SETFD, 0x00000001) = 0
pipe(0x2FF0E2F0) = 0
kfcntl(9, F_SETFD, 0x00000001) = 0
kfcntl(10, F_SETFD, 0x00000001) = 0
pipe(0x2FF0E2F0) = 0
kfcntl(11, F_SETFD, 0x00000001) = 0
kfcntl(12, F_SETFD, 0x00000001) = 0
fstatx(8, 0x2FF0E748, 128, 010) = 0
fstatx(8, 0x2FF0E748, 128, 010) = 0
kioctl(8, 22528, 0x00000000, 0x00000000) Err#25 ENOTTY
fstatx(9, 0x2FF0E748, 128, 010) = 0
fstatx(9, 0x2FF0E748, 128, 010) = 0
kioctl(9, 22528, 0x00000000, 0x00000000) Err#25 ENOTTY
fstatx(11, 0x2FF0E748, 128, 010) = 0
fstatx(11, 0x2FF0E748, 128, 010) = 0
kioctl(11, 22528, 0x00000000, 0x00000000) Err#25 ENOTTY
pipe(0x2FF0E1C0) = 0
kfcntl(13, F_SETFD, 0x00000001) = 0
kfcntl(14, F_SETFD, 0x00000001) = 0
sigprocmask(0, 0xF0296960, 0xF0296968) = 0
kfork() = 51773770
thread_setmymask_fast(0x00000000, 0x00000000, 0x00000000, 0xD0528F00, 0x00000000, 0x14260153, 0x14260153, 0x00000000) = 0x00000000
_getpid() = 65077750
close(14) = 0
close(7) = 0
close(10) = 0
close(12) = 0
kread(13, " � � � � � � � � � � � �".., 50000) = 0
close(13) = 0
fstatx(8, 0x2FF0DB58, 128, 010) = 0
kfcntl(8, F_GETFL, 0x00000000) = 1
kioctl(8, -2147195266, 0x2FF0CDD0, 0x00000000) = 0
kioctl(8, -2147195267, 0x2FF0CDD0, 0x00000000) = 0
kfcntl(8, F_SETFL, 0x00000005) = 0
_poll(0x204DBB90, 2, 0) = 0
_poll(0x204DBB90, 2, 0) = 0
kfcntl(9, F_GETFL, 0x00000000) = 0
kioctl(9, -2147195266, 0x2FF0C360, 0x00000000) = 0
kioctl(9, -2147195267, 0x2FF0C360, 0x00000000) = 0
kfcntl(9, F_SETFL, 0x00000004) = 0
_poll(0x204DBB90, 3, 0) = 0
_poll(0x204DBB90, 3, 0) = 0
kfcntl(11, F_GETFL, 0x00000000) = 0
kioctl(11, -2147195266, 0x2FF0C360, 0x00000000) = 0
kioctl(11, -2147195267, 0x2FF0C360, 0x00000000) = 0
kfcntl(11, F_SETFL, 0x00000004) = 0
_poll(0x2050B8C0, 4, 0) = 0
_poll(0x2050B8C0, 4, 0) = 0
_poll(0x2050B8C0, 4, 0) = 0
_poll(0x2050B8C0, 4, 0) = 0
kwrite(8, " P y t h o n ", 7) = 7
_poll(0x2050B8C0, 4, 0) = 1
_poll(0x2050B8C0, 3, 0) = 0
close(8) = 0
_poll(0x2050B8C0, 3, 0) = 0
_poll(0x2050B8C0, 3, -1) = 1
__libc_sbrk(0x00000000) = 0x20541130
kread(9, " P y t h o n � � � � �".., 262144) = 7
_poll(0x2050B8C0, 3, 0) = 0
_poll(0x2050B8C0, 3, 0) = 0
_poll(0x2050B8C0, 3, 0) = 0
_poll(0x2050B8C0, 3, 0) = 0
_poll(0x2050B8C0, 3, -1) = 2
kread(9, " � � � � � � � � � � � �".., 262144) = 0
kread(11, " � � � � � � � � � � � �".., 262144) = 0
_poll(0x2050B8C0, 1, 0) = 0
close(9) = 0
close(11) = 0
Received signal #20, SIGCHLD [caught]
_getpid() = 65077750
kwrite(6, "14", 1) = 1
ksetcontext_sigreturn(0x2FF11D70, 0x200868EC, 0x00000008, 0xD0528CA4, 0x00000000, 0x14260153, 0x2FF22FF8, 0x00000000)
_poll(0x2050B8C0, 1, 0) = 1
_erecv(5, 0x3075C820, 1, 0, 0x00000000) = 1
_poll(0x2050B8C0, 1, 0) = 0
kwaitpid(0x2FF12134, 0, 5, 0x00000000, 0x00000000) = 51773770
_poll(0x2050B8C0, 1, 0) = 0
_poll(0x2050B8C0, 1, -1) (sleeping...) |
➜
