Pádraig Brady <p...@draigbrady.com> [2023-01-31 21:47:43 +0000]:
> On 31/01/2023 19:48, Glenn Golden wrote:
> > Thanks, Pádraig.
> >
> > With the above patch (applied manually to coreutils 9.1 sources) the
> > 'illegal seek' no longer occurs, but it also doesn't follow the new file:
> > There is no output at all after tail announces that it is "following new
> > file."
> >
> > I did verify that the "new" instance of /dev/ttyMYDEV, when observed from
> > another independent process (via cat, less, more, tail, etc.) is indeed
> > sinking output from the device, as expected. But tail just isn't seeing it.
> >
> > Also fiddled about with --sleep-interval=N (with several values of N) and
> > --retry as well, but no joy.
>
> The output from `strace tail ...` would be useful I think to help diagnose.
>
Strace output attached, obtained via
$ strace -tt --decode-fds=dev,path \
tail_p1 --follow=name --lines=+0 /dev/ttyPSLOG 2> strace1.out
where "tail_p1" is the patched 9.1 executable (your patch from the other day).
Note that there's an interesting bit of headscratch on line 199, just after
issuance of the "following new file" message. Looks like strace itself may
have overwritten its own buffer or something.
I ran strace several times, invoking it exactly as shown above, just to see
if that little feature was present each time, and it is. I have no clue what
that is due to, or what strace output (if any) may have been lost there.
- Glenn
07:01:08.801596 execve("/home/gdg/bin/tail_p1", ["tail_p1", "--follow=name",
"--lines=+0", "/dev/ttyPSLOG"], 0x7ffe99f72f08 /* 61 vars */) = 0
07:01:08.802506 brk(NULL) = 0x55bf56bc9000
07:01:08.802670 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffff3cdfce0) = -1 EINVAL
(Invalid argument)
07:01:08.802832 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or
directory)
07:01:08.802915 openat(AT_FDCWD</home/gdg/src/pscon>, "/etc/ld.so.cache",
O_RDONLY|O_CLOEXEC) = 3</etc/ld.so.cache>
07:01:08.803091 newfstatat(3</etc/ld.so.cache>, "", {st_mode=S_IFREG|0644,
st_size=59151, ...}, AT_EMPTY_PATH) = 0
07:01:08.803174 mmap(NULL, 59151, PROT_READ, MAP_PRIVATE, 3</etc/ld.so.cache>,
0) = 0x7f12e308b000
07:01:08.803236 close(3</etc/ld.so.cache>) = 0
07:01:08.803301 openat(AT_FDCWD</home/gdg/src/pscon>, "/usr/lib/libc.so.6",
O_RDONLY|O_CLOEXEC) = 3</usr/lib/libc.so.6>
07:01:08.803374 read(3</usr/lib/libc.so.6>,
"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P4\2\0\0\0\0\0"..., 832) = 832
07:01:08.803433 pread64(3</usr/lib/libc.so.6>,
"\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) =
784
07:01:08.803549 newfstatat(3</usr/lib/libc.so.6>, "", {st_mode=S_IFREG|0755,
st_size=1953472, ...}, AT_EMPTY_PATH) = 0
07:01:08.803653 mmap(NULL, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f12e3089000
07:01:08.803731 pread64(3</usr/lib/libc.so.6>,
"\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) =
784
07:01:08.803818 mmap(NULL, 1994384, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE,
3</usr/lib/libc.so.6>, 0) = 0x7f12e2ea2000
07:01:08.803898 mmap(0x7f12e2ec4000, 1421312, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0x22000) =
0x7f12e2ec4000
07:01:08.803986 mmap(0x7f12e301f000, 356352, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0x17d000) =
0x7f12e301f000
07:01:08.804070 mmap(0x7f12e3076000, 24576, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib/libc.so.6>, 0x1d4000) =
0x7f12e3076000
07:01:08.804163 mmap(0x7f12e307c000, 52880, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f12e307c000
07:01:08.804253 close(3</usr/lib/libc.so.6>) = 0
07:01:08.804345 mmap(NULL, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f12e2e9f000
07:01:08.804418 arch_prctl(ARCH_SET_FS, 0x7f12e2e9f740) = 0
07:01:08.804474 set_tid_address(0x7f12e2e9fa10) = 8986
07:01:08.804527 set_robust_list(0x7f12e2e9fa20, 24) = 0
07:01:08.804579 rseq(0x7f12e2ea0060, 0x20, 0, 0x53053053) = 0
07:01:08.804743 mprotect(0x7f12e3076000, 16384, PROT_READ) = 0
07:01:08.804826 mprotect(0x55bf55bd4000, 4096, PROT_READ) = 0
07:01:08.804870 mprotect(0x7f12e30cb000, 8192, PROT_READ) = 0
07:01:08.804923 prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024,
rlim_max=RLIM64_INFINITY}) = 0
07:01:08.804972 munmap(0x7f12e308b000, 59151) = 0
07:01:08.805054 getrandom("\xf2\x64\x1b\xa7\x56\xe7\xee\xeb", 8, GRND_NONBLOCK)
= 8
07:01:08.805097 brk(NULL) = 0x55bf56bc9000
07:01:08.805128 brk(0x55bf56bea000) = 0x55bf56bea000
07:01:08.805168 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/locale-archive>
07:01:08.805233 newfstatat(3</usr/lib/locale/locale-archive>, "",
{st_mode=S_IFREG|0644, st_size=3716400, ...}, AT_EMPTY_PATH) = 0
07:01:08.805288 mmap(NULL, 3716400, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/locale-archive>, 0) = 0x7f12e2b13000
07:01:08.805341 close(3</usr/lib/locale/locale-archive>) = 0
07:01:08.805389 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) =
3</usr/share/locale/locale.alias>
07:01:08.805453 newfstatat(3</usr/share/locale/locale.alias>, "",
{st_mode=S_IFREG|0644, st_size=2998, ...}, AT_EMPTY_PATH) = 0
07:01:08.805512 read(3</usr/share/locale/locale.alias>, "# Locale name alias
data base.\n#"..., 4096) = 2998
07:01:08.805578 read(3</usr/share/locale/locale.alias>, "", 4096) = 0
07:01:08.805624 close(3</usr/share/locale/locale.alias>) = 0
07:01:08.805676 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_IDENTIFICATION>
07:01:08.805753 newfstatat(3</usr/lib/locale/C.UTF-8/LC_IDENTIFICATION>, "",
{st_mode=S_IFREG|0644, st_size=258, ...}, AT_EMPTY_PATH) = 0
07:01:08.805808 mmap(NULL, 258, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_IDENTIFICATION>, 0) = 0x7f12e3099000
07:01:08.805855 close(3</usr/lib/locale/C.UTF-8/LC_IDENTIFICATION>) = 0
07:01:08.805901 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/gconv/gconv-modules.cache", O_RDONLY) = -1 ENOENT (No such file or
directory)
07:01:08.805958 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/gconv/gconv-modules", O_RDONLY|O_CLOEXEC) =
3</usr/lib/gconv/gconv-modules>
07:01:08.806022 newfstatat(3</usr/lib/gconv/gconv-modules>, "",
{st_mode=S_IFREG|0644, st_size=3916, ...}, AT_EMPTY_PATH) = 0
07:01:08.806082 read(3</usr/lib/gconv/gconv-modules>, "# GNU libc iconv
configuration.\n"..., 4096) = 3916
07:01:08.806163 read(3</usr/lib/gconv/gconv-modules>, "", 4096) = 0
07:01:08.806210 close(3</usr/lib/gconv/gconv-modules>) = 0
07:01:08.806253 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/gconv/gconv-modules.d", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) =
3</usr/lib/gconv/gconv-modules.d>
07:01:08.806315 newfstatat(3</usr/lib/gconv/gconv-modules.d>, "",
{st_mode=S_IFDIR|0755, st_size=4096, ...}, AT_EMPTY_PATH) = 0
07:01:08.806377 getdents64(3</usr/lib/gconv/gconv-modules.d>, 0x55bf56bcce80 /*
3 entries */, 32768) = 96
07:01:08.806444 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf", O_RDONLY|O_CLOEXEC)
= 4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>
07:01:08.806513
newfstatat(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>, "",
{st_mode=S_IFREG|0644, st_size=53974, ...}, AT_EMPTY_PATH) = 0
07:01:08.806573
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>, "# GNU libc
iconv configuration.\n"..., 4096) = 4096
07:01:08.806663
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"B1002//\tJUS_I.B1.002//\nmodule\tJU"..., 4096) = 4096
07:01:08.806781
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"59-5//\nalias\tISO_8859-5//\t\tISO-8"..., 4096) = 4096
07:01:08.806899
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"59-16//\t\tINTERNAL\t\tISO8859-16\t1\n"..., 4096) = 4096
07:01:08.807025
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"-SE-A\t1\nmodule\tINTERNAL\t\tEBCDIC-"..., 4096) = 4096
07:01:08.807164
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"97\t\t1\n\n#\tfrom\t\t\tto\t\t\tmodule\t\tcos"..., 4096) = 4096
07:01:08.807317
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"1\n\n#\tfrom\t\t\tto\t\t\tmodule\t\tcost\nal"..., 4096) = 4096
07:01:08.807486
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"6//\t\tIBM1046//\nalias\tCP1046//\t\tI"..., 4096) = 4096
07:01:08.807650
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"\tto\t\t\tmodule\t\tcost\nalias\tRUSCII/"..., 4096) = 4096
07:01:08.807781 brk(0x55bf56c0b000) = 0x55bf56c0b000
07:01:08.807875
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"03//\nmodule\tCSN_369103//\t\tINTERN"..., 4096) = 4096
07:01:08.808055
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"\tmodule\t\tcost\nalias\tISO-IR-8-1//"..., 4096) = 4096
07:01:08.808258
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"IBM1156\t\t1\n\n#\tfrom\t\t\tto\t\t\tmodule"..., 4096) = 4096
07:01:08.808466
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"\t\tIBM1166//\nalias\tCP1166//\t\tIBM1"..., 4096) = 4096
07:01:08.808683
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>,
"alias\tROMAN9//\t\tHP-ROMAN9//\nalia"..., 4096) = 726
07:01:08.808774
read(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>, "", 4096) = 0
07:01:08.808823
close(4</usr/lib/gconv/gconv-modules.d/gconv-modules-extra.conf>) = 0
07:01:08.808868 getdents64(3</usr/lib/gconv/gconv-modules.d>, 0x55bf56bcce80 /*
0 entries */, 32768) = 0
07:01:08.808924 close(3</usr/lib/gconv/gconv-modules.d>) = 0
07:01:08.809027 futex(0x7f12e307b98c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
07:01:08.809072 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_MEASUREMENT", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_MEASUREMENT>
07:01:08.809136 newfstatat(3</usr/lib/locale/C.UTF-8/LC_MEASUREMENT>, "",
{st_mode=S_IFREG|0644, st_size=23, ...}, AT_EMPTY_PATH) = 0
07:01:08.809191 mmap(NULL, 23, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_MEASUREMENT>, 0) = 0x7f12e3098000
07:01:08.809238 close(3</usr/lib/locale/C.UTF-8/LC_MEASUREMENT>) = 0
07:01:08.809290 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_TELEPHONE", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_TELEPHONE>
07:01:08.809354 newfstatat(3</usr/lib/locale/C.UTF-8/LC_TELEPHONE>, "",
{st_mode=S_IFREG|0644, st_size=47, ...}, AT_EMPTY_PATH) = 0
07:01:08.809408 mmap(NULL, 47, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_TELEPHONE>, 0) = 0x7f12e3097000
07:01:08.809456 close(3</usr/lib/locale/C.UTF-8/LC_TELEPHONE>) = 0
07:01:08.809511 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_ADDRESS", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_ADDRESS>
07:01:08.809573 newfstatat(3</usr/lib/locale/C.UTF-8/LC_ADDRESS>, "",
{st_mode=S_IFREG|0644, st_size=127, ...}, AT_EMPTY_PATH) = 0
07:01:08.809627 mmap(NULL, 127, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_ADDRESS>, 0) = 0x7f12e3096000
07:01:08.809674 close(3</usr/lib/locale/C.UTF-8/LC_ADDRESS>) = 0
07:01:08.809726 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_NAME", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_NAME>
07:01:08.809790 newfstatat(3</usr/lib/locale/C.UTF-8/LC_NAME>, "",
{st_mode=S_IFREG|0644, st_size=62, ...}, AT_EMPTY_PATH) = 0
07:01:08.809846 mmap(NULL, 62, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_NAME>, 0) = 0x7f12e3095000
07:01:08.809901 close(3</usr/lib/locale/C.UTF-8/LC_NAME>) = 0
07:01:08.809957 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_PAPER", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_PAPER>
07:01:08.810021 newfstatat(3</usr/lib/locale/C.UTF-8/LC_PAPER>, "",
{st_mode=S_IFREG|0644, st_size=34, ...}, AT_EMPTY_PATH) = 0
07:01:08.810076 mmap(NULL, 34, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_PAPER>, 0) = 0x7f12e3094000
07:01:08.810123 close(3</usr/lib/locale/C.UTF-8/LC_PAPER>) = 0
07:01:08.810175 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_MESSAGES", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_MESSAGES>
07:01:08.810239 newfstatat(3</usr/lib/locale/C.UTF-8/LC_MESSAGES>, "",
{st_mode=S_IFDIR|0755, st_size=4096, ...}, AT_EMPTY_PATH) = 0
07:01:08.810294 close(3</usr/lib/locale/C.UTF-8/LC_MESSAGES>) = 0
07:01:08.810337 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_MESSAGES/SYS_LC_MESSAGES", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_MESSAGES/SYS_LC_MESSAGES>
07:01:08.810400
newfstatat(3</usr/lib/locale/C.UTF-8/LC_MESSAGES/SYS_LC_MESSAGES>, "",
{st_mode=S_IFREG|0644, st_size=48, ...}, AT_EMPTY_PATH) = 0
07:01:08.810454 mmap(NULL, 48, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_MESSAGES/SYS_LC_MESSAGES>, 0) = 0x7f12e3093000
07:01:08.810501 close(3</usr/lib/locale/C.UTF-8/LC_MESSAGES/SYS_LC_MESSAGES>) = 0
07:01:08.810554 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_MONETARY", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_MONETARY>
07:01:08.810617 newfstatat(3</usr/lib/locale/C.UTF-8/LC_MONETARY>, "",
{st_mode=S_IFREG|0644, st_size=270, ...}, AT_EMPTY_PATH) = 0
07:01:08.810671 mmap(NULL, 270, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_MONETARY>, 0) = 0x7f12e3092000
07:01:08.810719 close(3</usr/lib/locale/C.UTF-8/LC_MONETARY>) = 0
07:01:08.810771 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_COLLATE", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_COLLATE>
07:01:08.810835 newfstatat(3</usr/lib/locale/C.UTF-8/LC_COLLATE>, "",
{st_mode=S_IFREG|0644, st_size=1406, ...}, AT_EMPTY_PATH) = 0
07:01:08.810902 mmap(NULL, 1406, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_COLLATE>, 0) = 0x7f12e3091000
07:01:08.810951 close(3</usr/lib/locale/C.UTF-8/LC_COLLATE>) = 0
07:01:08.811038 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_NUMERIC", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_NUMERIC>
07:01:08.811103 newfstatat(3</usr/lib/locale/C.UTF-8/LC_NUMERIC>, "",
{st_mode=S_IFREG|0644, st_size=50, ...}, AT_EMPTY_PATH) = 0
07:01:08.811157 mmap(NULL, 50, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_NUMERIC>, 0) = 0x7f12e3090000
07:01:08.811205 close(3</usr/lib/locale/C.UTF-8/LC_NUMERIC>) = 0
07:01:08.811258 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/lib/locale/C.UTF-8/LC_CTYPE", O_RDONLY|O_CLOEXEC) =
3</usr/lib/locale/C.UTF-8/LC_CTYPE>
07:01:08.811321 newfstatat(3</usr/lib/locale/C.UTF-8/LC_CTYPE>, "",
{st_mode=S_IFREG|0644, st_size=353616, ...}, AT_EMPTY_PATH) = 0
07:01:08.811375 mmap(NULL, 353616, PROT_READ, MAP_PRIVATE,
3</usr/lib/locale/C.UTF-8/LC_CTYPE>, 0) = 0x7f12e2abc000
07:01:08.811422 close(3</usr/lib/locale/C.UTF-8/LC_CTYPE>) = 0
07:01:08.811494 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/local/share/locale/C.UTF-8/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
07:01:08.811551 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/local/share/locale/C.utf8/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
07:01:08.811604 openat(AT_FDCWD</home/gdg/src/pscon>,
"/usr/local/share/locale/C/LC_MESSAGES/coreutils.mo", O_RDONLY) = -1 ENOENT (No
such file or directory)
07:01:08.811663 openat(AT_FDCWD</home/gdg/src/pscon>, "/dev/ttyPSLOG",
O_RDONLY) = 3</dev/ttyACM0<char 166:0>>
07:01:08.812079 newfstatat(3</dev/ttyACM0<char 166:0>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:08.812144 read(3</dev/ttyACM0<char 166:0>>, "Device ID:
E660C0D1C7452B24\n", 8192) = 28
07:01:12.176935 newfstatat(1</dev/pts/0<char 136:0>>, "",
{st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}, AT_EMPTY_PATH) = 0
07:01:12.181698 write(1</dev/pts/0<char 136:0>>, "Device ID:
E660C0D1C7452B24\n", 28) = 28
07:01:12.182036 read(3</dev/ttyACM0<char 166:0>>, "$Id: basetest.c,v 1.4
2023/02/01"..., 8192) = 52
07:01:12.182285 write(1</dev/pts/0<char 136:0>>, "$Id: basetest.c,v 1.4
2023/02/01"..., 52) = 52
07:01:12.182440 read(3</dev/ttyACM0<char 166:0>>, "$Id: logger.c,v 1.2
2023/01/31 2"..., 8192) = 50
07:01:12.182640 write(1</dev/pts/0<char 136:0>>, "$Id: logger.c,v 1.2
2023/01/31 2"..., 50) = 50
07:01:12.182796 read(3</dev/ttyACM0<char 166:0>>, "Clocks:\n", 8192) = 8
07:01:12.184892 write(1</dev/pts/0<char 136:0>>, "Clocks:\n", 8) = 8
07:01:12.185142 read(3</dev/ttyACM0<char 166:0>>, " pll_sys: 125000 kHz\n",
8192) = 24
07:01:12.185364 write(1</dev/pts/0<char 136:0>>, " pll_sys: 125000 kHz\n",
24) = 24
07:01:12.185527 read(3</dev/ttyACM0<char 166:0>>, " pll_usb: 48000 kHz\n",
8192) = 24
07:01:12.185654 write(1</dev/pts/0<char 136:0>>, " pll_usb: 48000 kHz\n",
24) = 24
07:01:12.185756 read(3</dev/ttyACM0<char 166:0>>, " rosc: 5395 kHz\n",
8192) = 24
07:01:12.185837 write(1</dev/pts/0<char 136:0>>, " rosc: 5395 kHz\n",
24) = 24
07:01:12.185916 read(3</dev/ttyACM0<char 166:0>>, " clk_sys: 125000 kHz\n",
8192) = 24
07:01:12.185995 write(1</dev/pts/0<char 136:0>>, " clk_sys: 125000 kHz\n",
24) = 24
07:01:12.186135 read(3</dev/ttyACM0<char 166:0>>, " clk_peri: 125000 kHz\n",
8192) = 24
07:01:12.186231 write(1</dev/pts/0<char 136:0>>, " clk_peri: 125000 kHz\n",
24) = 24
07:01:12.186321 read(3</dev/ttyACM0<char 166:0>>, " clk_usb: 48000 kHz\n",
8192) = 24
07:01:12.186407 write(1</dev/pts/0<char 136:0>>, " clk_usb: 48000 kHz\n",
24) = 24
07:01:12.186491 read(3</dev/ttyACM0<char 166:0>>, " clk_adc: 48000 kHz\n",
8192) = 24
07:01:12.186572 write(1</dev/pts/0<char 136:0>>, " clk_adc: 48000 kHz\n",
24) = 24
07:01:12.186665 read(3</dev/ttyACM0<char 166:0>>, " clk_rtc: 46 kHz\n",
8192) = 24
07:01:12.186780 write(1</dev/pts/0<char 136:0>>, " clk_rtc: 46 kHz\n",
24) = 24
07:01:12.186939 read(3</dev/ttyACM0<char 166:0>>, "rtc: 00:00:00\n", 8192) = 14
07:01:12.187613 write(1</dev/pts/0<char 136:0>>, "rtc: 00:00:00\n", 14) = 14
07:01:12.187731 read(3</dev/ttyACM0<char 166:0>>, "iter: 0000 rtc: 00:00:00
Tr"..., 8192) = 52
07:01:12.188000 write(1</dev/pts/0<char 136:0>>, "iter: 0000 rtc: 00:00:00
Tr"..., 52) = 52
07:01:12.188121 read(3</dev/ttyACM0<char 166:0>>, "iter: 0001 rtc: 00:00:01
Tr"..., 8192) = 52
07:01:13.188406 write(1</dev/pts/0<char 136:0>>, "iter: 0001 rtc: 00:00:01
Tr"..., 52) = 52
07:01:13.188548 read(3</dev/ttyACM0<char 166:0>>, "iter: 0002 rtc: 00:00:02
Tr"..., 8192) = 52
07:01:14.188715 write(1</dev/pts/0<char 136:0>>, "iter: 0002 rtc: 00:00:02
Tr"..., 52) = 52
07:01:14.189021 read(3</dev/ttyACM0<char 166:0>>, "iter: 0003 rtc: 00:00:03
Tr"..., 8192) = 52
07:01:15.188843 write(1</dev/pts/0<char 136:0>>, "iter: 0003 rtc: 00:00:03
Tr"..., 52) = 52
07:01:15.188986 read(3</dev/ttyACM0<char 166:0>>, "iter: 0004 rtc: 00:00:04
Tr"..., 8192) = 52
07:01:16.189086 write(1</dev/pts/0<char 136:0>>, "iter: 0004 rtc: 00:00:04
Tr"..., 52) = 52
07:01:16.189395 read(3</dev/ttyACM0<char 166:0>>, "iter: 0005 rtc: 00:00:05
Tr"..., 8192) = 52
07:01:17.189106 write(1</dev/pts/0<char 136:0>>, "iter: 0005 rtc: 00:00:05
Tr"..., 52) = 52
07:01:17.189250 read(3</dev/ttyACM0<char 166:0>>, "iter: 0006 rtc: 00:00:06
Tr"..., 8192) = 52
07:01:18.189413 write(1</dev/pts/0<char 136:0>>, "iter: 0006 rtc: 00:00:06
Tr"..., 52) = 52
07:01:18.189671 read(3</dev/ttyACM0<char 166:0>>, "iter: 0007 rtc: 00:00:07
Tr"..., 8192) = 52
07:01:19.189656 write(1</dev/pts/0<char 136:0>>, "iter: 0007 rtc: 00:00:07
Tr"..., 52) = 52
07:01:19.189820 read(3</dev/ttyACM0<char 166:0>>, "iter: 0008 rtc: 00:00:08
Tr"..., 8192) = 52
07:01:20.189609 write(1</dev/pts/0<char 136:0>>, "iter: 0008 rtc: 00:00:08
Tr"..., 52) = 52
07:01:20.189746 read(3</dev/ttyACM0<char 166:0>>, "iter: 0009 rtc: 00:00:09
Tr"..., 8192) = 52
07:01:21.189731 write(1</dev/pts/0<char 136:0>>, "iter: 0009 rtc: 00:00:09
Tr"..., 52) = 52
07:01:21.189872 read(3</dev/ttyACM0<char 166:0>>, "iter: 0010 rtc: 00:00:10
Tr"..., 8192) = 52
07:01:22.190049 write(1</dev/pts/0<char 136:0>>, "iter: 0010 rtc: 00:00:10
Tr"..., 52) = 52
07:01:22.194383 read(3</dev/ttyACM0<char 166:0>>, "", 8192) = 0
07:01:23.088532 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:23.088783 fstatfs(3</dev/ttyACM0>(deleted), {f_type=TMPFS_MAGIC,
f_bsize=4096, f_blocks=473976, f_bfree=473976, f_bavail=473976, f_files=473976,
f_ffree=473382, f_fsid={val=[0xd679cd56, 0x6b783969]}, f_namelen=255,
f_frsize=4096, f_flags=ST_VALID|ST_NOSUID|ST_RELATIME}) = 0
07:01:23.088966 newfstatat(1</dev/pts/0<char 136:0>>, "",
{st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}, AT_EMPTY_PATH) = 0
07:01:23.089165 newfstatat(AT_FDCWD</home/gdg/src/pscon>, "/dev/ttyPSLOG",
{st_mode=S_IFLNK|0777, st_size=7, ...}, AT_SYMLINK_NOFOLLOW) = 0
07:01:23.089393 fcntl(3</dev/ttyACM0>(deleted), F_GETFL) = 0x8000 (flags
O_RDONLY|O_LARGEFILE)
07:01:23.089501 fcntl(3</dev/ttyACM0>(deleted), F_SETFL,
O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0
07:01:23.089600 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:23.089728 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:24.090145 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:24.090542 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:25.091033 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:25.091500 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:26.091967 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:26.092368 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:27.092809 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:27.093165 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:28.093582 newfstatat(3</dev/ttyACM0>(deleted), "", {st_mode=S_IFCHR|000,
st_rdev=makedev(0xa6, 0), ...}, AT_EMPTY_PATH) = 0
07:01:28.098005 openat(AT_FDCWD</home/gdg/src/pscon>, "/dev/ttyPSLOG",
O_RDONLY|O_NONBLOCK) = 4</dev/ttyACM1<char 166:1>>
07:01:28.098972 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:28.099180 fstatfs(4</dev/ttyACM1<char 166:1>>, {f_type=TMPFS_MAGIC,
f_bsize=4096, f_blocks=473976, f_bfree=473976, f_bavail=473976, f_files=473976,
f_ffree=473380, f_fsid={val=[0xd679cd56, 0x6b783969]}, f_namelen=255,
f_frsize=4096, f_flags=ST_VALID|ST_NOSUID|ST_RELATIME}) = 0
07:01:28.099358 write(2</home/gdg/src/pscon/strace.out>, "tail_p1: ", 9tail_p1:
) = 9
07:01:28.099501 write(2</home/gdg/src/pscon/strace.out>, "'/dev/ttyPSLOG' has
been replace"..., 54'/dev/ttyPSLOG' has been replaced; following new file) = 54
07:01:28.099625 write(2</home/gdg/src/pscon/strace.out>, "\n", 1
) = 1
07:01:28.099728 close(3</dev/ttyACM0>(deleted)) = 0
07:01:28.099909 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:29.100354 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:29.100740 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:30.101250 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:30.101695 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:31.102173 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:31.102595 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:32.103092 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:32.103431 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:33.103885 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:33.108314 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:34.108735 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:34.109075 openat(AT_FDCWD</home/gdg/src/pscon>, "/dev/ttyPSLOG",
O_RDONLY|O_NONBLOCK) = 3</dev/ttyACM1<char 166:1>>
07:01:34.110293 newfstatat(3</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:34.110454 fstatfs(3</dev/ttyACM1<char 166:1>>, {f_type=TMPFS_MAGIC,
f_bsize=4096, f_blocks=473976, f_bfree=473976, f_bavail=473976, f_files=473976,
f_ffree=473381, f_fsid={val=[0xd679cd56, 0x6b783969]}, f_namelen=255,
f_frsize=4096, f_flags=ST_VALID|ST_NOSUID|ST_RELATIME}) = 0
07:01:34.110563 close(3</dev/ttyACM1<char 166:1>>) = 0
07:01:34.110821 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:35.111253 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:35.111602 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:36.112040 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:36.112395 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:37.112857 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:37.113064 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:38.113457 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:38.117889 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
0x7ffff3cdfa80) = 0
07:01:39.118311 newfstatat(4</dev/ttyACM1<char 166:1>>, "",
{st_mode=S_IFCHR|0660, st_rdev=makedev(0xa6, 0x1), ...}, AT_EMPTY_PATH) = 0
07:01:39.118603 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0},
{tv_sec=0, tv_nsec=79917295}) = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
strace: Process 8986 detached
