gdb.base/siginfo-thread.exp: Increase timeout for 'gcore' command

  The following failed lines from running test case siginfo-thread:

FAIL: gdb.base/siginfo-thread.exp: save a core file (timeout)
FAIL: gdb.base/siginfo-thread.exp: extract si_addr
FAIL: gdb.base/siginfo-thread.exp: p ssi_addr

indicate the testsuite timed out when gdb was instructed to write the
core file. The patch below fixes the problem by simply increasing the
timeout by a factor of 2 to give gdb more time to generate core files.

Tested in sparc64-linux-gnu. No regressions.

gdb/testsuite/ChangeLog:
2017-02-22  Weimin Pan  <weimin.pan@oracle.com>

        * gdb.base/siginfo-thread.exp: Increase timeout by a factor of 2
        for the 'gcore command.
---
 gdb/testsuite/gdb.base/siginfo-thread.exp |   20 +++++++++++---------
 1 files changed, 11 insertions(+), 9 deletions(-)
  

Weimin Pan <weimin.pan@oracle.com> writes:

> The following failed lines from running test case siginfo-thread:
>
> FAIL: gdb.base/siginfo-thread.exp: save a core file (timeout)
> FAIL: gdb.base/siginfo-thread.exp: extract si_addr
> FAIL: gdb.base/siginfo-thread.exp: p ssi_addr
>
> indicate the testsuite timed out when gdb was instructed to write the
> core file. The patch below fixes the problem by simply increasing the
> timeout by a factor of 2 to give gdb more time to generate core files.
>
> Tested in sparc64-linux-gnu. No regressions.

Did you see timeout fails in all gcore related tests?  gdb_gcore_cmd is
used in many places in gdb testsuite.  Did you investigate why it is so
slow to generate coredump in gdb?
  

Yao Qi wrote:
> Weimin Pan <weimin.pan@oracle.com> writes:
>
>   
>> The following failed lines from running test case siginfo-thread:
>>
>> FAIL: gdb.base/siginfo-thread.exp: save a core file (timeout)
>> FAIL: gdb.base/siginfo-thread.exp: extract si_addr
>> FAIL: gdb.base/siginfo-thread.exp: p ssi_addr
>>
>> indicate the testsuite timed out when gdb was instructed to write the
>> core file. The patch below fixes the problem by simply increasing the
>> timeout by a factor of 2 to give gdb more time to generate core files.
>>
>> Tested in sparc64-linux-gnu. No regressions.
>>     
>
> Did you see timeout fails in all gcore related tests?  gdb_gcore_cmd is
> used in many places in gdb testsuite.  Did you investigate why it is so
> slow to generate coredump in gdb?
>
>   
No, only this test failed with timeout and did so consistently. The 
generated core file was fine.
We suspect the slow disk performance was the culprit.

Thanks.
  

On 03/16/2017 04:00 PM, Wei-min Pan wrote:
> Yao Qi wrote:

>> Did you see timeout fails in all gcore related tests?  gdb_gcore_cmd is
>> used in many places in gdb testsuite.  Did you investigate why it is so
>> slow to generate coredump in gdb?
>>
>>   
> No, only this test failed with timeout and did so consistently. The
> generated core file was fine.
> We suspect the slow disk performance was the culprit.

I agree with Yao, and I'm not convinced.  The generated core file is just
"8.6M" on my x86_64 Fedora 23 and the test runs in under 1s here.

$ time make check TESTS="*/siginfo-thread.exp"
...
real    0m0.781s
user    0m0.554s
sys     0m0.152s


What's the size of the core you get?  If you run the test manually,
do we notice any kind of slowness?

If you have a general slowness issue in your testing host, then
this should be affecting all gcore tests the same.  We have some
tests that generate big cores on purpose even.

Thanks,
Pedro Alves
  

Pedro Alves wrote:
> On 03/16/2017 04:00 PM, Wei-min Pan wrote:
>   
>> Yao Qi wrote:
>>     
>
>   
>>> Did you see timeout fails in all gcore related tests?  gdb_gcore_cmd is
>>> used in many places in gdb testsuite.  Did you investigate why it is so
>>> slow to generate coredump in gdb?
>>>
>>>   
>>>       
>> No, only this test failed with timeout and did so consistently. The
>> generated core file was fine.
>> We suspect the slow disk performance was the culprit.
>>     
>
> I agree with Yao, and I'm not convinced.  The generated core file is just
> "8.6M" on my x86_64 Fedora 23 and the test runs in under 1s here.
>
> $ time make check TESTS="*/siginfo-thread.exp"
> ...
> real    0m0.781s
> user    0m0.554s
> sys     0m0.152s
>
>
> What's the size of the core you get?  If you run the test manually,
> do we notice any kind of slowness?
>   

The core size is a little over 9.0M but it took much longer to run this 
individual test:

% time make check TESTS="*/siginfo-thread.exp"
...
real    0m11.743s
user    0m3.892s
sys     0m7.572s

And I didn't notice any slowness if the test was run by hand.

> If you have a general slowness issue in your testing host, then
> this should be affecting all gcore tests the same.  We have some
> tests that generate big cores on purpose even.
>   

Like I said, only this test consistently failed and the core file 
generated was not that big.

Thanks.

> Thanks,
> Pedro Alves
>
>
  

On 03/16/2017 06:27 PM, Wei-min Pan wrote:
> Pedro Alves wrote:
>> On 03/16/2017 04:00 PM, Wei-min Pan wrote:
>>  
>>> Yao Qi wrote:
>>>     
>>
>>  
>>>> Did you see timeout fails in all gcore related tests?  gdb_gcore_cmd is
>>>> used in many places in gdb testsuite.  Did you investigate why it is so
>>>> slow to generate coredump in gdb?
>>>>
>>>>         
>>> No, only this test failed with timeout and did so consistently. The
>>> generated core file was fine.
>>> We suspect the slow disk performance was the culprit.
>>>     
>>
>> I agree with Yao, and I'm not convinced.  The generated core file is just
>> "8.6M" on my x86_64 Fedora 23 and the test runs in under 1s here.
>>
>> $ time make check TESTS="*/siginfo-thread.exp"
>> ...
>> real    0m0.781s
>> user    0m0.554s
>> sys     0m0.152s
>>
>>
>> What's the size of the core you get?  If you run the test manually,
>> do we notice any kind of slowness?
>>   
> 
> The core size is a little over 9.0M but it took much longer to run this
> individual test:
> 
> % time make check TESTS="*/siginfo-thread.exp"
> ...
> real    0m11.743s
> user    0m3.892s
> sys     0m7.572s
> 
> And I didn't notice any slowness if the test was run by hand.

You mean that by hand it went faster than that?
So what is GDB doing differently when run via make check
that makes it slower than running by hand?

>> If you have a general slowness issue in your testing host, then
>> this should be affecting all gcore tests the same.  We have some
>> tests that generate big cores on purpose even.
>>   
> 
> Like I said, only this test consistently failed and the core file
> generated was not that big.

Which suggests bumping the timeout is not the right thing to do.

Thanks,
Pedro Alves
  

Pedro Alves wrote:
> On 03/16/2017 06:27 PM, Wei-min Pan wrote:
>   
>> Pedro Alves wrote:
>>     
>>> On 03/16/2017 04:00 PM, Wei-min Pan wrote:
>>>  
>>>       
>>>> Yao Qi wrote:
>>>>     
>>>>         
>>>  
>>>       
>>>>> Did you see timeout fails in all gcore related tests?  gdb_gcore_cmd is
>>>>> used in many places in gdb testsuite.  Did you investigate why it is so
>>>>> slow to generate coredump in gdb?
>>>>>
>>>>>         
>>>>>           
>>>> No, only this test failed with timeout and did so consistently. The
>>>> generated core file was fine.
>>>> We suspect the slow disk performance was the culprit.
>>>>     
>>>>         
>>> I agree with Yao, and I'm not convinced.  The generated core file is just
>>> "8.6M" on my x86_64 Fedora 23 and the test runs in under 1s here.
>>>
>>> $ time make check TESTS="*/siginfo-thread.exp"
>>> ...
>>> real    0m0.781s
>>> user    0m0.554s
>>> sys     0m0.152s
>>>
>>>
>>> What's the size of the core you get?  If you run the test manually,
>>> do we notice any kind of slowness?
>>>   
>>>       
>> The core size is a little over 9.0M but it took much longer to run this
>> individual test:
>>
>> % time make check TESTS="*/siginfo-thread.exp"
>> ...
>> real    0m11.743s
>> user    0m3.892s
>> sys     0m7.572s
>>
>> And I didn't notice any slowness if the test was run by hand.
>>     
>
> You mean that by hand it went faster than that?
> So what is GDB doing differently when run via make check
> that makes it slower than running by hand?
>   

Yes, but not by much faster:

% cat in
run
gcore tmp.gcore
quit

% time my_gdb siginfo-thread -x in
...
real    0m13.327s
user    0m3.504s
sys     0m7.572s

Thanks.
>   
>>> If you have a general slowness issue in your testing host, then
>>> this should be affecting all gcore tests the same.  We have some
>>> tests that generate big cores on purpose even.
>>>   
>>>       
>> Like I said, only this test consistently failed and the core file
>> generated was not that big.
>>     
>
> Which suggests bumping the timeout is not the right thing to do.
>
> Thanks,
> Pedro Alves
>
>
  

On 03/16/2017 07:10 PM, Wei-min Pan wrote:

>> You mean that by hand it went faster than that?
>> So what is GDB doing differently when run via make check
>> that makes it slower than running by hand?
>>   
> 
> Yes, but not by much faster:
> 
> % cat in
> run
> gcore tmp.gcore
> quit
> 
> % time my_gdb siginfo-thread -x in
> ...
> real    0m13.327s
> user    0m3.504s
> sys     0m7.572s

Either I'm missing something, or that was _slower_ than then
number you shown of running via the testsuite, not faster...

So WDT is GDB doing that takes that long?  Is that writing
the core to a slow NFS mount or something?

Here that takes:

 real    0m0.120s
 user    0m0.090s
 sys     0m0.033s

and this is not a state-of-the-art machine.

Can you guess the next question?

Pick any other core test in the testsuite, do the
same and compare the numbers.

And if they're different, the next question would
then be, "what's different in this test, why's
it slower?".

If they're similar, then, well, the same question.  :-)

Thanks,
Pedro Alves
  

Pedro Alves wrote:
> On 03/16/2017 07:10 PM, Wei-min Pan wrote:
>
>   
>>> You mean that by hand it went faster than that?
>>> So what is GDB doing differently when run via make check
>>> that makes it slower than running by hand?
>>>   
>>>       
>> Yes, but not by much faster:
>>
>> % cat in
>> run
>> gcore tmp.gcore
>> quit
>>
>> % time my_gdb siginfo-thread -x in
>> ...
>> real    0m13.327s
>> user    0m3.504s
>> sys     0m7.572s
>>     
>
> Either I'm missing something, or that was _slower_ than then
> number you shown of running via the testsuite, not faster...
>   

Sorry, you didn't miss anything. I misspoke :)
> So WDT is GDB doing that takes that long?  Is that writing
> the core to a slow NFS mount or something?
>
> Here that takes:
>
>  real    0m0.120s
>  user    0m0.090s
>  sys     0m0.033s
>
> and this is not a state-of-the-art machine.
>
> Can you guess the next question?
>
> Pick any other core test in the testsuite, do the
> same and compare the numbers.
>
> And if they're different, the next question would
> then be, "what's different in this test, why's
> it slower?".
>   
OK, just tried a different test which is similar to siginfo-thread:

% time make check TESTS="*/siginfo-obj.exp"
...
real    0m1.282s
user    0m0.736s
sys     0m0.400s

Looks like the slowness had something to do with the pthread libs.
Will investigate. Thanks.
> If they're similar, then, well, the same question.  :-)
>
> Thanks,
> Pedro Alves
>
>