bugGNU Octave - Bugs: bug #53713, test failure "speed.m"...

 
 

bug #53713: test failure "speed.m" in Octave 4.3.91

Submitted by:  Hartmut <hardy>
Submitted on:  Sat 21 Apr 2018 12:21:23 PM UTC  
 
Category:  Test Suite Severity:  2 - Minor
Priority:  5 - Normal Item Group:  Unexpected Error
Status:  Fixed Assigned to:  None
Originator Name:  Open/Closed:  Closed
Release:  4.3.91 Operating System:  Microsoft Windows

Add a New Comment (Rich Markup)
   

You are not logged in

Please log in, so followups can be emailed to you.

 

( Jump to the original submission)

Tue 24 Apr 2018 12:07:23 AM UTC, comment #16: 

I pushed the change to use tic/toc here http://hg.savannah.gnu.org/hgweb/octave/rev/65b4b04600c6.  Marking as fixed and closing report.

Rik <rik5>
Project Administrator
Mon 23 Apr 2018 09:12:55 PM UTC, comment #15: 

Thanks for testing.  I'll commit the changeover to tic/toc soon and then close this report.

Rik <rik5>
Project Administrator
Mon 23 Apr 2018 09:11:29 PM UTC, comment #14: 

I have put the alternativ speed.m file from comment #9 in my current Octave folder and run the loop code from comment #9 on my Win7 PC. The result was 10, so the new tests passed 10 times in a row, now.

Hartmut <hardy>
Mon 23 Apr 2018 09:05:52 PM UTC, comment #13: 

There is bug #52858 about increasing the resolution of the cputime function. However, the change proposed there will only affect POSIX systems. Windows systems will still be limited by the resolution of the GetProcessTimes system function, whatever that is.

It seems like the path forward is to see whether tic/toc fixes this test failure on older Windows systems in the short term, or whether this test should be skipped with a runtime hack like I proposed in comment #4. And maybe implement a Matlab compatible timeit function using tic/toc in the longer term.

Mike Miller <mtmiller>
Project Administrator
Mon 23 Apr 2018 08:17:07 PM UTC, comment #12: 

Another data point, the closest Matlab function to speed is timeit (http://www.mathworks.com/help/matlab/ref/timeit.html).  The timeit function uses tic/toc and wall time for its measurements.

Rik <rik5>
Project Administrator
Mon 23 Apr 2018 06:37:21 PM UTC, comment #11: 

This function has always used wall time, so I don't know that we want to change it more right now.

I expect, however, that things would be worse using cputime.  The problem is already that some functions, like sum(), are so fast that the measured elapsed time is zero.  On my Linux machine, with high precision timers, I get zero for the sum() operation which is failing

octave:3> x = randn (100, 1);
octave:4> t1 = cputime; sum (x); t2 = cputime;
octave:5> t2 - t1
ans = 0

On a Windows machine this will definitely return 0.

Rik <rik5>
Project Administrator
Mon 23 Apr 2018 06:27:47 PM UTC, comment #10: 

If tic/toc works better, that's fine, but is wall clock time the best thing to be measuring here or should we be measuring CPU time?

John W. Eaton <jwe>
Project Administrator
Mon 23 Apr 2018 06:23:12 PM UTC, comment #9: 

@Hartmut: Thanks for the data.  It certainly illustrates the problem which is that the method of measuring elapsed time using the time function does not work.  But there is some hope here.  It seems that tic/toc uses a better mechanism.

I'm attaching a new speed.m file which uses tic/toc for timing.  Can you replace the file in your installation with this one and then try re-testing speed?

for i = 1:10
  bm(i) = test ("speed");
endfor
sum (bm)

(file #43995)

Rik <rik5>
Project Administrator
Mon 23 Apr 2018 05:58:54 PM UTC, comment #8: 

answers to comment #6:

  • __tnew is all zeros
  • __torig is 0.00099993, 0.00100017, 0.00099993, 0.00099993, 0.00199986, 0.00199986, 0.00300002, 0.00300002, 0.00399995, 0.00499988, 0.00600004, 0.00699997, 0.00799990, 0.00900006, 0.01099992
  • (after a couple of dbnext:) zidx is all ones

answers to comment #7:

for n=1:3
  n
  t1 = time; sum (randn (1e2, 1)); ta = time - t1
  t1 = time; sum (randn (1e3, 1)); tb = time - t1
  t1 = tic;  sum (randn (1e2, 1)); tc = toc (t1)
endfor

n =  1
ta =  0.00099993
tb = 0
tc =  0.0017788
n =  2
ta = 0
tb = 0
tc =  0.00077915
n =  3
ta = 0
tb = 0
tc =  0.0017791

Hartmut <hardy>
Mon 23 Apr 2018 05:28:38 AM UTC, comment #7: 

Also, the original test is using much smaller values than 1e5.  What does this return

for n=1:3
  n
  t1 = time; sum (randn (1e2, 1)); ta = time - t1
  t1 = time; sum (randn (1e3, 1)); tb = time - t1
  t1 = tic;  sum (randn (1e2, 1)); tc = toc (t1)
endfor

Rik <rik5>
Project Administrator
Mon 23 Apr 2018 05:06:32 AM UTC, comment #6: 

The warning message says that all times were zero.  Can you help debug that?  Try

dbstop speed 246
[order, n, T_f1, T_f2] = speed ("sum (x)", "", [100, 1000], "v = 0; for i = 1:length (x), v += x(i); endfor");

This will stop at line 246.  Type

__tnew
__torig

to inspect the two timings.  Are they really all zeros?  If not, do dbnext twice (maybe 3 times) until you have passed

    zidx = (__tnew < 100*eps | __torig < 100*eps);

type

zidx

Is this all ones?

If you can write back to this report the value of __tnew, __torig, and zidx we can investigate.

Rik <rik5>
Project Administrator
Sun 22 Apr 2018 08:55:01 PM UTC, comment #5: 

If have tested your suggestions from comment #3 on my Win7 machine.

Running this code:

for n=1:5
  n
  t1 = time; sum (rand (1e5, 1)); ta = time - t1
  t1 = time; sum (rand (3e5, 1)); tb = time - t1
  t1 = tic;  sum (rand (1e5, 1)); tc = toc (t1)
endfor

produces the following results:

n =  1
ta =  0.0050001
tb =  0.014001
tc =  0.0043731
n =  2
ta =  0.0039999
tb =  0.014001
tc =  0.0043750
n =  3
ta =  0.0039999
tb =  0.015001
tc =  0.0053759
n =  4
ta =  0.0040009
tb =  0.014000
tc =  0.0043781
n =  5
ta =  0.0039999
tb =  0.015001
tc =  0.0043790

So, no, the results are not very close to the "zero" of a floating point type. Is this some discrepancy to your current hypothesis?

And regarding your code on comment #4:

for n=1:10
  t0 = time (); pause (0.001); t = time () - t0
endfor

gives:

t =  0.0010002
t =  0.0010009
t =  0.0010002
t =  0.0019999
t =  0.0010002
t =  0.00099993
t =  0.0010002
t =  0.00099993
t =  0.00099993
t =  0.0010002

So a threshold at t<0.001 does NOT seem to be a good idea to me.

Hartmut <hardy>
Sun 22 Apr 2018 08:43:07 PM UTC, comment #4: 

If the time resolution is the issue on older Windows systems, then I think we can keep this test as is, and just add a simple prefix to break out of the test if the timer resolution is not good enough:

%! t0 = time (); pause (0.001); t = time () - t0;
%! if (t < 0.001); return; endif

Would that solve this on your system?

Mike Miller <mtmiller>
Project Administrator
Sun 22 Apr 2018 07:21:45 PM UTC, comment #3: 

So on your system, the following returns zero elapsed time?

t1 = time; sum (rand (1e5, 1)); t = time - t1

But this does not?

t1 = time; sum (rand (3e5, 1)); t = time - t1

What if you change this to use tic/toc, still zero?

t1 = tic; sum (rand (1e5, 1)); t = toc (t1)

I guess this is related to some minimum precision from system time values on certain Windows systems?

On Windows 8 and newer, it should be possible to have time values with microsecond precision, but on older systems it looks like the precision is rounded to increments of about 16 milliseconds.

Mike Miller <mtmiller>
Project Administrator
Sat 21 Apr 2018 09:36:33 PM UTC, comment #2: 

This is the current version (4.3.91) of the problematic line in the tests of speed.m:

[order, n, T_f1, T_f2] = speed ("sum (x)", "", [100, 1000], "v = 0; for i = 1:length (x), v += x(i); endfor");

On my Win7 PC it is NOT enough to increase the numbers to the following. This still errors out after 18 seconds:

[order, n, T_f1, T_f2] = speed ("sum (x)", "", [100000, 110000], "v = 0; for i = 1:length (x), v += x(i); endfor");

But those numbers do PASS the tests on my Win7 machine, but only after rougly 60 seconds:

[order, n, T_f1, T_f2] = speed ("sum (x)", "", [300000, 310000], "v = 0; for i = 1:length (x), v += x(i); endfor");

Would it be OK to take the last code line for all OSes? This would increase the run time of _run_test_suite_ by 1 minute for everybody. Or is it necessary to split this tests up for different OSes (as also mentioned in the FIXME text of speed.m)?

Hartmut <hardy>
Sat 21 Apr 2018 04:55:58 PM UTC, comment #1: 

In 4.3.90 this test was marked xtest, an expected failure. In 4.3.91 it is expected to pass.

Can you help change the test so that it passes on your system? There are some comments in a FIXME block just before the test.

Mike Miller <mtmiller>
Project Administrator
Sat 21 Apr 2018 12:21:23 PM UTC, original submission:  

I have installed the "official" Win64 installer of Octave 4.3.91 on Win7. All tests pass, except for one test failure:

>>>>> processing C:\Octave\OCTAVE~1.91\share\octave\4.3.91\m\testfun\speed.m
***** test
[order, n, T_f1, T_f2] = speed ("sum (x)", "", [100, 1000], "v = 0; for i = 1:length (x), v += x(i); endfor");
assert (isstruct (order));
assert (size (order), [1, 1]);
assert (fieldnames (order), {"p"; "a"});
assert (isnumeric (n));
assert (length (n) > 10);
assert (isnumeric (T_f1));
assert (size (T_f1), size (n));
assert (isnumeric (T_f2));
assert (length (T_f2) > 10);
!!!!! test failed
speed: All running times were zero.

This test still passed on the same Win7 PC in Octave 4.3.90 last week.

(PS: There is no "4.3.91" category in the Savannah "Release" pull down menu, yet.)

Hartmut <hardy>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #43995:  speed.m added by rik5 (15KiB - text/x-matlab)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by jwe (Posted a comment)
  • -email is unavailable- added by rik5 (Posted a comment)
  • -email is unavailable- added by mtmiller (Posted a comment)
  • -email is unavailable- added by hardy (Submitted the item)
  •  

    Do you think this task is very important?
    If so, you can add your encouragement to it.
    This task has 0 encouragements so far.

    Only project members can vote.

     

     

     

    Follow 9 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2018-04-24 rik5 StatusNeed Info => Fixed
        Open/ClosedOpen => Closed
    2018-04-23 rik5 Attached File- => Added speed.m, #43995
    2018-04-21 mtmiller CategoryOctave Function => Test Suite
    2018-04-21 mtmiller Severity3 - Normal => 2 - Minor
        Item GroupRegression => Unexpected Error
        StatusNone => Need Info
    2018-04-21 rik5 Carbon-CopyRemoved 72865 => -
    2018-04-21 rik5 Release4.3.90 => 4.3.91

    Back to the top


    Powered by Savane 3.5