Mit strace bekommt man einen Fehler nur, wenn man -f weglässt. Damit sieht man leider nicht, was in den Kindprozessen passiert, aber immerhin. Die letzten Zeilen:
...
13:35:18.882051 fcntl(13, F_SETFD, FD_CLOEXEC) = 0 <0.000009>
13:35:18.882080 fcntl(14, F_SETFD, FD_CLOEXEC) = 0 <0.000022>
13:35:18.882140 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0 <0.000009>
13:35:18.882181 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f06386a49d0) = 13563 <0.003322>
13:35:18.885560 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000010>
13:35:18.885632 close(14) = 0 <0.000010>
13:35:18.885720 read(13, "", 8192) = 0 <0.001494>
13:35:18.887310 close(13) = 0 <0.000014>
13:35:18.887393 close(3) = 0 <0.000010>
13:35:18.887445 close(10) = 0 <0.000010>
13:35:18.887499 close(12) = 0 <0.000010>
13:35:18.887627 write(4, "Ein Test", 8) = 8 <0.000025>
13:35:18.887675 close(4) = 0 <0.000010>
13:35:18.887707 fstat(9, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 <0.000010>
13:35:18.887741 read(9, "Ein Test", 8192) = 8 <0.000129>
13:35:18.887892 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=13563, si_status=0, si_utime=0, si_stime=0} ---
13:35:18.887912 read(9, "", 8192) = 0 <0.000010>
13:35:18.887941 close(9) = 0 <0.000011>
13:35:18.887976 fstat(11, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 <0.000010>
13:35:18.888009 read(11, "", 8192) = 0 <0.000010>
13:35:18.888041 close(11) = 0 <0.000010>
13:35:18.888080 wait4(13563, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 13563 <0.000013>
13:35:18.888576 write(5, "ok 2\n", 5) = 5 <0.000014>
13:35:18.888756 pipe([3, 4]) = 0 <0.000013>
13:35:18.888799 ioctl(3, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000010>
13:35:18.888830 lseek(3, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000010>
13:35:18.888859 ioctl(4, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000010>
13:35:18.888888 lseek(4, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000010>
13:35:18.888915 fcntl(3, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
13:35:18.888943 fcntl(4, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
13:35:18.888977 pipe([9, 10]) = 0 <0.000012>
13:35:18.889009 ioctl(9, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000010>
13:35:18.889038 lseek(9, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000009>
13:35:18.889067 ioctl(10, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000009>
13:35:18.889095 lseek(10, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000010>
13:35:18.889122 fcntl(9, F_SETFD, FD_CLOEXEC) = 0 <0.000009>
13:35:18.889149 fcntl(10, F_SETFD, FD_CLOEXEC) = 0 <0.000009>
13:35:18.889182 pipe([11, 12]) = 0 <0.000011>
13:35:18.889214 ioctl(11, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000009>
13:35:18.889242 lseek(11, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000010>
13:35:18.889270 ioctl(12, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000009>
13:35:18.889298 lseek(12, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000009>
13:35:18.889325 fcntl(11, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
13:35:18.889351 fcntl(12, F_SETFD, FD_CLOEXEC) = 0 <0.000009>
13:35:18.889382 pipe([13, 14]) = 0 <0.000011>
13:35:18.889412 ioctl(13, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000010>
13:35:18.889440 lseek(13, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000009>
13:35:18.889468 ioctl(14, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff77036860) = -1 EINVAL (Invalid argument) <0.000009>
13:35:18.889496 lseek(14, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000009>
13:35:18.889523 fcntl(13, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
13:35:18.889550 fcntl(14, F_SETFD, FD_CLOEXEC) = 0 <0.000009>
13:35:18.889589 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0 <0.000010>
13:35:18.889623 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f06386a49d0) = 13564 <0.002480>
13:35:18.892175 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000011>
13:35:18.892247 close(14) = 0 <0.000010>
13:35:18.892358 read(13, "", 8192) = 0 <0.001207>
13:35:18.893591 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=13564, si_status=1, si_utime=0, si_stime=0} ---
13:35:18.893632 close(13) = 0 <0.000012>
13:35:18.893707 close(3) = 0 <0.000011>
13:35:18.893747 close(10) = 0 <0.000010>
13:35:18.893788 close(12) = 0 <0.000011>
13:35:18.893912 write(4, "Ein Test", 8) = -1 EPIPE (Broken pipe) <0.000011>
13:35:18.893959 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=13562, si_uid=1023} ---
13:35:18.895255 +++ killed by SIGPIPE +++
On 2017-07-09 09:33:28, SREZIC wrote:
Show quoted text> Auf einem CentOS6-System:
>
> $ /opt/perl-5.22.3/bin/prove -v -Ilib t/bin/Prty/Ipc.t
> t/bin/Prty/Ipc.t ..
> 1..4
> ok 1 - use Prty::Ipc;
> ok 2
> Failed 2/4 subtests
>
> Test Summary Report
> -------------------
> t/bin/Prty/Ipc.t (Wstat: 13 Tests: 2 Failed: 0)
> Non-zero wait status: 13
> Parse errors: Bad plan. You planned 4 tests but ran 2.
> Files=1, Tests=2, 0 wallclock secs ( 0.02 usr 0.01 sys + 0.08 cusr
> 0.04 csys = 0.15 CPU)
> Result: FAIL
>
> Signal 13 ist SIGPIPE.
>
> Dummerweise ist es ein Heisenbug: sobald ich versuche, mit strace
> reinzuschauen, läuft der Test erfolgreich durch.
>
> Vermutlich ein Timing-Problem; eventuell läuft das externe Kommando zu
> langsam oder zu schnell.
>
> On 2017-07-09 07:20:01, fs@fseitz.de wrote:
> > Hallo Slaven,
> >
> > kannst du mir von einem dieser Systeme die Ausgabe
> > des folgenden Kommandos senden?
> >
> > $ prove -v -Ilib t/bin/Prty/Ipc.t
> >
> > Grüße
> > Frank
> >
> > On 07/09/2017 10:46 AM, Slaven_Rezic via RT wrote:
> > > Sun Jul 09 04:46:06 2017: Request 122402 was acted upon.
> > > Transaction: Ticket created by SREZIC
> > > Queue: Prty
> > > Subject: Ipc.t fails on some systems without diagnostics
> > > Broken in: 1.115
> > > Severity: (no value)
> > > Owner: Nobody
> > > Requestors: SREZIC@cpan.org
> > > Status: new
> > > Ticket <URL:
https://rt.cpan.org/Ticket/Display.html?id=122402 >
> > >
> > >
> > > On some of my smoker systems (centos6, debian jessie, freebsd) I
> > > see
> > > the following failure, without any further diagnostics:
> > >
> > > ...
> > > t/bin/Prty/Ipc.t ................................
> > > Failed 2/4 subtests
> > > ...