bugGNU Octave - Bugs: bug #54180, libinterp/corefcn/file-io.cc-tst...

 
 

bug #54180: libinterp/corefcn/file-io.cc-tst failure and weird output when test suite is run twice

Submitter:  Andrew Janke <apjanke>
Submitted:  Sun 24 Jun 2018 10:51:00 PM UTC
   
 
Category:  Test Suite Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Unexpected Error or Warning
Status:  Fixed Assigned to:  None
Originator Name:  Open/Closed:  * Closed
Release:  * 4.4.0 Operating System:  * Mac OS
Fixed Release:  None Planned Release:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Fri 29 Jun 2018 09:10:57 PM UTC, comment #20: 

This is fine.  Originally, I thought about using whos because there was extra information--specifically the global flag--which I thought might provide a way to ensure that no variables changed nature during the tests.  But the way you did it seems like it will be faster and have a smaller memory footprint.

If you create a global variable in the base workspace this is reported twice: 1) as a variable created in the base workspace, and 2) as a global variable created in the base workspace.  Could eliminate that by using setdiff one more time to subtract the global variables from the local variables.  But, it probably isn't worth it.  This shouldn't be happening very frequently and should be corrected immediately.


Rik <rik5>
Group administrator
Fri 29 Jun 2018 08:35:26 PM UTC, comment #19: 

I pushed a change that checks for global variables:

http://hg.savannah.gnu.org/hgweb/octave/rev/48a9bd2d0a20

I also changed the check for variables in the base workspace to just use "who" rather than "whos" and to only check whether the output of setdiff (new, old) is empty.  Rik, is there something that I'm not seeing that requires whos and size_equal?

Is there anything else we should be checking?

John W. Eaton <jwe>
Group administrator
Fri 29 Jun 2018 06:26:22 PM UTC, comment #18: 

I added a check that now new variables are created in the base workspace (http://hg.savannah.gnu.org/hgweb/octave/rev/90c8325c14be).  I benchmarked it briefly and it didn't seem to contribute much, if anything, to running time so I think its fine to have this check in all the time.

Rik <rik5>
Group administrator
Fri 29 Jun 2018 05:24:07 PM UTC, comment #17: 

If it is as short as the file-descriptor check, we could add the variable checks to the development branch.  If issues arise, they'll be recognized by developers in a short time and the changes could be backed out easy enough...or modify the test script to generate the required variables with each individual test.

Dan Sebald <sebald>
Fri 29 Jun 2018 04:49:27 PM UTC, comment #16: 

For the development branch, I pushed a cset (http://hg.savannah.gnu.org/hgweb/octave/rev/a87b4dca2ce3) that will emit a warning if a file has %!tests which leak file descriptors.

Do we want to do something similar for global variables?  How about for any variables?  I would think that the ideal tests are run in their own workspace and don't pollute the base workspace at all.  Normally, that would only mean checking for new globals, but since there are tests for evalin it is possible that local variables could also be created in the caller workspace which would be the base workspace.

Rik <rik5>
Group administrator
Wed 27 Jun 2018 04:39:21 AM UTC, comment #15: 

Great.  Marking as fixed and closing report.

Rik <rik5>
Group administrator
Wed 27 Jun 2018 02:36:11 AM UTC, comment #14: 

Looks fixed!

I built from Mercurial, and the error went away: I ran _run_test_suite_ repeatedly in the GUI, and libinterp/corefcn/file-io.cc-tst passed each time.

Andrew Janke <apjanke>
Tue 26 Jun 2018 04:24:25 PM UTC, comment #13: 

I committed Dan's cset here http://hg.savannah.gnu.org/hgweb/octave/rev/6aa29920a531.

@Andrew: Can you download the latest stable code from Mercurial and test whether the problem is cured?  Marking as "Ready for Test".

Rik <rik5>
Group administrator
Mon 25 Jun 2018 07:32:15 PM UTC, comment #12: 

Here's a new changeset that adds various unwind_protect blocks.  Let me know if it as least on the target somewhere.  In some cases the fclose() doesn't have any commands prior to it that will error, so those don't need to be protected.  There are a few others near the end for which the fclose could possibly moved earlier and avoid the need for an unwind_protect--in fact, those might use the same "nm = tempname (); ... unlink(nm)" approach to not leave the small temporary files hanging about.  But I do leave the temporary file around when there is an error in case someone needs to debug by looking at that file contents.

(file #44435)

Dan Sebald <sebald>
Mon 25 Jun 2018 05:13:05 PM UTC, comment #11: 

Concur with jwe.  If the patch is updated to use unwind/protect blocks it can be applied immediately to the stable branch.

On the dev branch, the test m-file could be augmented to use


FIDs = fopen ("all");
... run tests on file ...
FIDs = setdiff (fopen ("all"), FIDs);
if (! isempty (FIDs))
  error ("test: file XXX failed to close file descriptors");
endif



Rik <rik5>
Group administrator
Mon 25 Jun 2018 12:05:06 PM UTC, comment #10: 

Dan, your change is OK, but should probably use an unwind_protct block to also avoid leaks in case there is an error in the test.  I think that's what we use in other tests.

Checking for leaked resources in the function that runs tests for a given file seems like a good change.  Other than the things mentioned in comment #9, another thing to check for might be global variables.

I don't think you can check for leaked resources in a single %!test though, because multiple tests may share the same open file, global variable, or other resource.

Probably it should just be an error if there is a leak since it is an error in the test suite.  If that turns out to cause too much trouble, then we could make it something that is not fatal and is just reported in the summary like other test failures.

John W. Eaton <jwe>
Group administrator
Mon 25 Jun 2018 09:38:32 AM UTC, comment #9: 

I think this patch worked!

I rebuilt my Octave against it and ran _run_test_suite_ multiple times in a session; the `file-io.cc-test` failure did not recur.

I did get other failures during my reruns:


  libinterp/corefcn/graphics.cc-tst ........................... PASS     46/47
                                                                  FAIL    1
[...]

  image/getframe.m ............................................ PASS      1/2
                                                                  FAIL    1


From fntests.log:


>>>>> processing /Applications/Octave-4.4.0.app/Contents/Resources/usr/Cellar/octave-octave-app_4.4.0/4.4.0/share/octave/4.4.0/etc/tests/libinterp/corefcn/graphics.cc-tst
[...]
!!!!! test failed
ASSERT errors for:  assert (get (hf, "uicontextmenu"),[])

  Location  |  Observed  |  Expected  |  Reason
     .          O(1x1)       E(0x0)      Dimensions don't match
[...]
>>>>> processing /Applications/Octave-4.4.0.app/Contents/Resources/usr/Cellar/octave-octave-app_4.4.0/4.4.0/share/octave/4.4.0/m/image/getframe.m
***** testif HAVE_QT_OFFSCREEN; have_window_system ()
 hf = figure ("visible", "off");
 unwind_protect
   hax = axes ("visible", "off", "position", [0 0 1 1]);
   verts = [0 0; .5 0; 1 0; ...
            0 .5; .5 .5; 1 .5; ...
            0 1; .5 1; 1 1];
   faces = [1 2 5 4; 2 3 6 5; 4 5 8 7; 5 6 9 8];
   fvc = [1 0 0; 0 1 0; 0 0 1; 1 0 1];
   patch ("vertices", verts, "faces", faces, "facevertexcdata", fvc, ...
          "facecolor", "flat");

   kk = 1;
   pos = get (hf, "position");

   for jj = [0.05 0.55]
     for ii = [0.05 0.55]
       rect = [ii jj .4 .4].*[pos(3:4) pos(3:4)];
       frame = getframe (hax, rect).cdata;
       assert (frame(:,:,1) == fvc(kk,1)*255);
       assert (frame(:,:,2) == fvc(kk,2)*255);
       assert (frame(:,:,3) == fvc(kk,3)*255);
       kk++;
     endfor
   endfor
 unwind_protect_cleanup
   close (hf);
 end_unwind_protect
!!!!! test failed
getframe: unable to retrieve figure pixels


Those look related to graphics support, not file handles. And maybe they're because I was doing other things with my machine while the tests ran.

> Could you make that just one change within the test() function?


I will make a patch to do this if I find some time.

Are there other global resources we should check for leakage of? Figure handles? Open network ports?

Do you think it's appropriate to call error() to abort the tests in the case of leakage? Or introduce a new "ERROR: ..." output to report them? Or something else?

Andrew Janke <apjanke>
Mon 25 Jun 2018 07:40:43 AM UTC, comment #8: 

Here's a changeset.  (Yes, it does look like the lines you mentioned.)  This seems to pass the test.

Good idea about the leaked file descriptors.  Seems like a good thing to have.  Could you make that just one change within the test() function?  That seems the logical place to have the test.

(file #44433)

Dan Sebald <sebald>
Mon 25 Jun 2018 07:29:48 AM UTC, comment #7: 

Hey, look at io.tst lines 514 through 537.


%! nm = tempname ();
%! id = fopen (nm, "wb");
%! if (id > 0)
%!   for i = 1:n
%!     fwrite (id, i, type_list{i});
%!   endfor
%!
%!   fclose (id);
%!
%!   id = fopen (nm, "rb");
%!   if (id > 0)
%!     x = zeros (1, n);
%!     for i = 1:n
%!       x(i) = fread (id, [1, 1], type_list{i});
%!     endfor
%!
%!     if (x == 1:n)
%!       __printf_assert__ ("ok\n");
%!     endif
%!   endif
%! endif
%!
%! unlink (nm);
%! assert (__prog_output_assert__ ("ok"));


That `fopen (nm, "rb")` inside the loop looks like a dangling fopen() to me.

And then in lines 576 through 611:


%!test
%! nm = tempname ();
%! id = fopen (nm, "wb");
%! if (id > 0)
%!   fprintf (id, "%d\n", 1:100);
%!   fclose (id);
%!   id = fopen (nm, "rb");
%!   if (id > 0)
%!     for i = 1:101
%!       fgets (id);
%!     endfor
%!     if (feof (id))
%!       fclose (id);
%!       id = fopen (nm, "rb");
%!       pos_one = ftell (id);
%!       s_one = fgets (id);
%!       for i = 1:48
%!         s = fgets (id);
%!       endfor
%!       pos_fifty = ftell (id);
%!       s_fifty = fgets (id);
%!       fseek (id, pos_one, SEEK_SET);
%!       s_one_x = fgets (id);
%!       fseek (id, pos_fifty, SEEK_SET);
%!       s_fifty_x = fgets (id);
%!       if (s_one == s_one_x && s_fifty == s_fifty_x)
%!         frewind (id);
%!         s_one_x = fgets (id);
%!         if (s_one != s_one_x)
%!           error ("bombed!!");
%!         endif
%!       endif
%!     endif
%!   endif
%! endif
%! unlink (nm);


That `id = fopen (nm, "rb");` inside the loop at line 589 doesn't seem to have a corresponding fclose().

And that would account for the two leaked file descriptors.

Andrew Janke <apjanke>
Mon 25 Jun 2018 07:13:25 AM UTC, comment #6: 

Nice approach!

I modified your code to directly detect leaked file descriptors in the test. See attachment HACK-detect-leaked-file-descriptors-in-tests.patch.

Using this detection method, I declare `io.tst` to be the culprit.


  io.tst ......................................................STARTING TEST
fids_before_test =

   30   31

 PASS    151/154
                                             (run-time condition) SKIP    3
                                                   (reported bug) XFAIL   3
fids_after_test =

   30   31   40   41

fids_after_test: [30 31 40 41]
LEAKED FIDS: [40 41]


Andrew Janke <apjanke>
Mon 25 Jun 2018 06:23:30 AM UTC, comment #5: 

In the last post I didn't rewrite what I had intended as I was watching the original result.  The sentence

"Throughout the whole test suite there is no file-io.cc-tst fail on the first pass. On the second pass, it starts failing immediately:"

is incorrect and should have been rewritten something like:

The tests make it all the way to "Fixed test script" test/io.tst before file-io-.cc-tst starts failing.  See the following output (in comment #4) where I've snipped out many tests that passed successfully.

Dan Sebald <sebald>
Mon 25 Jun 2018 06:18:14 AM UTC, comment #4: 

I made a little mod to the scripts/testfun/__run_test_suite__.m (attached) which will run file-io.cc-tst after every test.  I wanted to see exactly at what point file-io.cc-tst starts failing.

Throughout the whole test suite there is no file-io.cc-tst fail on the first pass.  On the second pass, it starts failing immediately:


  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  time/is_leap_year.m ......................................... PASS      6/6
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  time/now.m .................................................. PASS      4/4
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  time/weekday.m .............................................. PASS     20/20
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90

Fixed test scripts:

  bug-35448.tst ............................................... PASS      2/2
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  bug-35881.tst ............................................... PASS      1/1
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  bug-36025.tst ............................................... PASS      1/1
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90

[snip]

  if.tst ...................................................... PASS     15/15
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  index.tst ................................................... PASS    180/180
  libinterp/corefcn/file-io.cc-tst ............................ PASS     90/90
  io.tst ...................................................... PASS    157/157
  libinterp/corefcn/file-io.cc-tst ............................ans =
{
  [1,1] = [](0x1)
}

 PASS     89/90
                                                                  FAIL    1
  jit.tst ..................................................... PASS      2/2
                                                (missing feature) SKIP   36
  libinterp/corefcn/file-io.cc-tst ............................ans =
{
  [1,1] = [](0x1)
}

 PASS     89/90
                                                                  FAIL    1
  leftdiv.tst ................................................. PASS      6/6
  libinterp/corefcn/file-io.cc-tst ............................ans =
{
  [1,1] = [](0x1)
}

 PASS     89/90


I believe there are one or two missing "fclose()" calls in the io.tst.  I've made some changes and started rerunning the test.  If it works I'll post a changeset.

(file #44430)

Dan Sebald <sebald>
Mon 25 Jun 2018 04:38:38 AM UTC, comment #3: 

Thanks; that helps narrows things down.

Running file-io.cc-tst on its own repeated without error is a clue...  I've managed to isolate and repeat the third case you cited.  The slightly more verbose result is


>> test file-io.cc-tst
ans =
{
  [1,1] = [](0x1)
}

***** error textscan (single (40))
!!!!! error failed.
Expected an error, but got no error


So this example is expecting textscan (single (40)) to fail, but it isn't failing.  That suggests to me that some test after file-io.cc-tst is opening a bunch of file, all the way up to file ID "40", without closing that file (probably many files).  Since file-io.cc-tst on its own is not failing, we need to find that later test which is opening files but not closing them.

Dan Sebald <sebald>
Mon 25 Jun 2018 01:01:32 AM UTC, comment #2: 


> exit the GUI, re-launch the GUI, run test
> exit the GUI, re-launch the GUI, run test
> exit the GUI, re-launch the GUI, run test


Did this. The failure did not appear. Sounds like there might be a GUI-session-scoped cleanup happening, as you suspect.

Another weird thing: Running just `file-io.cc-tst` on its own repeatedly in the GUI does not cause this failure:


>> cd /Applications/Octave-4.4.0.app/Contents/Resources/usr/Cellar/octave-octave-app_4.4.0/4.4.0/share/octave/4.4.0/etc/tests/libinterp/corefcn
>> test file-io.cc-tst
PASSES 90 out of 90 tests
>> test file-io.cc-tst
PASSES 90 out of 90 tests
>> test file-io.cc-tst
PASSES 90 out of 90 tests
>> test file-io.cc-tst
PASSES 90 out of 90 tests
>> test file-io.cc-tst
PASSES 90 out of 90 tests
>> test file-io.cc-tst
PASSES 90 out of 90 tests


Andrew Janke <apjanke>
Sun 24 Jun 2018 11:56:12 PM UTC, comment #1: 

Could you try

exit the GUI, re-launch the GUI, run test
exit the GUI, re-launch the GUI, run test
exit the GUI, re-launch the GUI, run test

and see if the failure appears.  Perhaps something files aren't being properly closed at the end of the test and another test has problems opening the file.  Exiting the GUI might close those files.  Just a guess.

The other odd thing is what looks like an incomplete summary of the error report.  The test indicates 1 failed test, and I suspect the data between curly brackets is the result, but there should be some columns indicating what test failed, what was expected and what was observed.  I wonder if Octave has those items going to a different I/O stream, whereas in the command line version both end up going to the shell terminal.

Dan Sebald <sebald>
Sun 24 Jun 2018 10:51:00 PM UTC, original submission:  

This is in Octave 4.4.0 on macOS 10.13.5, built with the Qt GUI.

When I run `__run_test_suite__` twice in a row inside the Qt GUI, the `libinterp/corefcn/file-io.cc-tst` produces some weird output and fails one test on the second and later runs.

From the second run:


  libinterp/corefcn/file-io.cc-tst ............................ans =
{
  [1,1] =

       2
       3
       4
       5
       6
       7
       8
       9
      10
      11
      12
      13
      14
      15
      16
      17
      18
      19
      20
      21
      22
      23
      24
      25
      26
      27
      28
      29
      30
      31
      32
      33
      34
      35
      36
      37
      38
      39
      40
      41
      42
      43
      44
      45
      46
      47
      48
      49
      50
      51
      52
      53
      54
      55
      56
      57
      58
      59
      60
      61
      62
      63
      64
      65
      66
      67
      68
      69
      70
      71
      72
      73
      74
      75
      76
      77
      78
      79
      80
      81
      82
      83
      84
      85
      86
      87
      88
      89
      90
      91
      92
      93
      94
      95
      96
      97
      98
      99
     100

}

 PASS     89/90
                                                                  FAIL    1


From the third and later runs:


  libinterp/corefcn/file-io.cc-tst ............................ans =
{
  [1,1] = [](0x1)
}

 PASS     89/90
                                                                  FAIL    1


This is only when running the test suite in the GUI; it doesn't seem to happen when run in command line mode.

Full test results (from the fourth run in a session) attached.

Andrew Janke <apjanke>

 

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

Attach Files:
   
   
Comment:
   

 

Depends on the following items: None found

Items that depend on this one: None found

 

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

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only group members can vote.

     

    Follow 8 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2018-06-27 rik5 StatusReady For Test Fixed
        Open/ClosedOpen Closed
    2018-06-26 rik5 StatusIn Progress Ready For Test
    2018-06-25 sebald Attached File- Added octave-fclose_missing_from_io_test-djs2018jun25.patch, #44435
    2018-06-25 rik5 StatusNone In Progress
    2018-06-25 sebald Attached File- Added octave-fclose_missing_from_io_test-djs2018jun24.patch, #44433
    2018-06-25 apjanke Attached File- Added HACK-detect-leaked-file-descriptors-in-tests.patch, #44432
    2018-06-25 sebald Attached File- Added run_file-io_test_after_every_test-djs2018jun24.diff, #44430

    Back to the top

    Powered by Savane 3.13-758e.
    Corresponding source code