bug#21061: coreutils-8.24 - Partially reproducible failures of tests/misc/timeout-parameters.sh

[Pádraig Brady]

On 16/07/15 07:09, Peter Bray wrote:
> On 15/07/15 08:30 PM, Pádraig Brady wrote:
>> On 15/07/15 10:22, Peter Bray wrote:
>>> Greetings,
>>>
>>> N.B. This bug report is for reference only, and documents only a
>>>        partially reproducible check failure. No Action Requested.
>>>
>>> On Solaris 10 (Update 8 and Update 11) and Solaris 11.2 X86 VMs, and
>>> one Solaris 10 Update 10 (Non-VM) system, I see random "gmake check"
>>> failures for "tests/misc/timeout-parameters.sh".
>>>
>>> Running the test by itself (with the command line below) on the same
>>> VMs / real system will sometimes succeed and sometimes fail.
>>>
>>>     gmake check TESTS=tests/misc/timeout-parameters.sh VERBOSE=yes SUBDIRS=.
>>>
>>> Looking through the attached "failure.log" file, I extracted the
>>> following command line test, which may exhibit the failure without all
>>> the make(1) and test infrastructure code:
>>>
>>>     failures=0
>>>     for i in `./src/seq 1 100`
>>>     do
>>>       ./src/timeout 2.34e+5d sleep 0 \
>>>         || { echo fail; failures=`expr ${failures} + 1` }
>>>     done
>>>     echo "Total Failures: ${failures}"
>>>
>>> On a real hardware system (Xeon E3-1245v2) with a 64-bit kernel,
>>> failures are very rare (only 1 test harness failure seen, no failures
>>> of the sample code above even with 1..1000 runs).
>>>
>>> On virtual machines (also using Xeon E3-1245v2 running VMware ESXi
>>> 5.5d (latest patches) - two identical ESXi systems running similarly
>>> configured VMs), test harness failures and failures in the above
>>> command line check are rare for the 64-bit Solaris kernels.
>>>
>>> Failures on Solaris 10 32-bit kernels (on both of these ESXi servers),
>>> are easily reproduced and vary between 5% (common) and 45% (rare).
>>
>> Interesting. I'm not reproducing that in 5000 loops in the above test script
>> on 32 bit baremetal solaris 10 update 10.
>>
>> I presume the large timeout value is causing early timer firing
>> on your systems for some reason? What does this return?
>>
>>    time src/timeout 2.34e+5d sleep inf
>>
>> Note on 32 bit, the 234000 days will be truncated to a itimerspec of:
>>    { {0,0}, {2147483647,999999999} }
>>
>> A wild guess is that perhaps ntp is adjusting the system time
>> which causes the above timer to be adjusted in the kernel
>> and roll over to 0, thus triggering early?
>>
>> thanks,
>> Pádraig.
>>
> 
> Pádraig,
> 
> The additional information you requested, but unfortunately I have yet
> to install gdb(1), so I using system tools for this response. The
> installation of coreutils-8.24 has been completed on all compile
> server VMs, so the commands now have a 'g' prefix.
> 
> % gtimeout 2.34e+5d gsleep inf
> 
> No output and exit status of 124 [$?=124] (32-bit kernel S10U11 / GCC 4.9.3)

I was looking to get an indication of how long it waits
(I have a fair idea about what is sent to timer_settime().
To that end, the command above has a leading 'time' to
return how long it actually took. I.E. something like
this would be informative:

  for i in $(seq 20); do time gtimeout 2.34e+5d sleep inf; done

thanks,
Pádraig.