bugGNU Octave - Bugs: bug #64975, Octave for Windows extremely slow

 
 

bug #64975: Octave for Windows extremely slow

Submitter:  Markus Mützel <mmuetzel>
Submitted:  Mon 04 Dec 2023 07:32:39 AM UTC
   
 
Category:  Interpreter Severity:  5 - Blocker
Priority:  5 - Normal Item Group:  Regression
Status:  Fixed Assigned to:  None
Originator Name:  Open/Closed:  * Closed
Release:  * 9.0.90 Operating System:  * Microsoft Windows
Fixed Release:  9.1.0 Planned Release:  9.1.0
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Fri 12 Jan 2024 09:24:53 PM UTC, comment #32: 

Marking bug as Fixed and closing report.

Rik <rik5>
Group administrator
Wed 13 Dec 2023 07:00:02 PM UTC, comment #31: 

Thank you for testing.

I pushed a slightly modified version of the last patch to the stable branch:
https://hg.savannah.gnu.org/hgweb/octave/rev/89cfd9dc69d8

Markus Mützel <mmuetzel>
Group administrator
Mon 11 Dec 2023 07:11:38 PM UTC, comment #30: 

@Markus:

> Those test failed aren't regressions from this change for me. IIRC, they already failed before this change with the UCRT or musl C runtime libraries.

Sorry I didn't mean to suggest those FAILs are related :-) sloppy wording by me I suppose.
It's just that I noted them now. As Nick writes you already reported them on Discourse.
BTW a 10.0.0 version crossbuilt on Nov. 10 doesn't show these FAILs.

Philip Nienhuis <philipnienhuis>
Group Member
Mon 11 Dec 2023 06:49:37 PM UTC, comment #29: 

Yes, that change works to clear the warnings as well. But I have only built and tested on Linux, not Windows.

Arun Giridhar <arungiridhar>
Group Member
Mon 11 Dec 2023 06:01:25 PM UTC, comment #28: 

Thinking about it: That change doesn't actually allow to do copies.
Does the attached patch also work?


(file #55433)

Markus Mützel <mmuetzel>
Group administrator
Mon 11 Dec 2023 12:47:08 PM UTC, comment #27: 

@Markus: Yes, changing unique_ptr to shared_ptr also fixes the warnings:


diff -r 19f51c7fa341 liboctave/util/glob-match.h
--- a/liboctave/util/glob-match.h       Sun Dec 10 18:01:29 2023 +0100
+++ b/liboctave/util/glob-match.h       Mon Dec 11 07:45:28 2023 -0500
@@ -125,7 +125,7 @@ private:

   std::string m_pat;

-  std::unique_ptr<glob_match> m_glob;
+  std::shared_ptr<glob_match> m_glob;
 };

 #endif


Make check passes as before.

Arun Giridhar <arungiridhar>
Group Member
Mon 11 Dec 2023 05:13:10 AM UTC, comment #26: 

@Arun: jwe prefers keeping the copy constructors (see comment #18). Does using std::shared_ptr fix the issue?

@Philip: Those test failed aren't regressions from this change for me. IIRC, they already failed before this change with the UCRT or musl C runtime libraries.

Markus Mützel <mmuetzel>
Group administrator
Sun 10 Dec 2023 11:16:29 PM UTC, comment #25: 

I think mmuetzel reported those new inv fails (on more than just windows) over at discourse.  see https://octave.discourse.group/t/test-suite-results-of-octave-9/5077/6

Nicholas Jankowski <nrjank>
Group Member
Sun 10 Dec 2023 10:56:50 PM UTC, comment #24: 

FTR,
with the patch from comment #22, with Octave 10.0.0 on Windows (crossbuild) I now get:

>> t1 = cputime; my_t = tic; __run_test_suite__ ; toc(my_t); cputime() - t1
 :
 :
Elapsed time is 744.692 seconds.
ans = 399.75even

so that's even quite a bit faster than 9.0.0 (see comment #15).
__vm_enable__ (0) or __vm_enable__ (1) makes almost no difference.

I see 2 FAILs in inv.cc-tst I haven't seen before, I'll check that out later.

Philip Nienhuis <philipnienhuis>
Group Member
Sun 10 Dec 2023 07:03:10 PM UTC, comment #23: 

With Clang 16.0.6 on Linux, there are a large number of warnings like this, apparently because m_glob is a unique_ptr.

In file included from ../libinterp/corefcn/defun.h:35:
In file included from ../libinterp/corefcn/defun-int.h:33:
In file included from ../libinterp/octave-value/ov-builtin.h:35:
In file included from ../libinterp/octave-value/ov-fcn.h:39:
In file included from ../libinterp/corefcn/symscope.h:38:
../liboctave/util/glob-match.h:116:3: warning: explicitly defaulted copy constructor is implicitly deleted [-Wdefaulted-function-deleted]
  symbol_match (const symbol_match&) = default;
  ^
../liboctave/util/glob-match.h:128:31: note: copy constructor of 'symbol_match' is implicitly deleted because field 'm_glob' has a deleted copy constructor
  std::unique_ptr<glob_match> m_glob;
                              ^
/usr/include/c++/13.2.1/bits/unique_ptr.h:522:7: note: 'unique_ptr' has been explicitly marked deleted here
      unique_ptr(const unique_ptr&) = delete;
      ^
../liboctave/util/glob-match.h:116:40: note: replace 'default' with 'delete'
  symbol_match (const symbol_match&) = default;
                                       ^~~~~~~
                                       delete
../liboctave/util/glob-match.h:118:17: warning: explicitly defaulted copy assignment operator is implicitly deleted [-Wdefaulted-function-deleted]
  symbol_match& operator = (const symbol_match&) = default;
                ^
../liboctave/util/glob-match.h:128:31: note: copy assignment operator of 'symbol_match' is implicitly deleted because field 'm_glob' has a deleted copy assignment operator
  std::unique_ptr<glob_match> m_glob;
                              ^
/usr/include/c++/13.2.1/bits/unique_ptr.h:523:19: note: 'operator=' has been explicitly marked deleted here
      unique_ptr& operator=(const unique_ptr&) = delete;
                  ^
../liboctave/util/glob-match.h:118:52: note: replace 'default' with 'delete'
  symbol_match& operator = (const symbol_match&) = default;
                                                   ^~~~~~~
                                                   delete


Replacing `default` with `delete` in two places in liboctave/util/glob-match.h as the compiler says eliminates the warnings.


diff -r 19f51c7fa341 liboctave/util/glob-match.h
--- a/liboctave/util/glob-match.h       Sun Dec 10 18:01:29 2023 +0100
+++ b/liboctave/util/glob-match.h       Sun Dec 10 13:54:58 2023 -0500
@@ -113,9 +113,9 @@ public:

   symbol_match (const std::string& pattern);

-  symbol_match (const symbol_match&) = default;
+  symbol_match (const symbol_match&) = delete;

-  symbol_match& operator = (const symbol_match&) = default;
+  symbol_match& operator = (const symbol_match&) = delete;

   ~symbol_match () = default;


Pls verify if this change is OK across platforms.

Arun Giridhar <arungiridhar>
Group Member
Sun 10 Dec 2023 02:57:38 PM UTC, comment #22: 

I've added a sentence to the docstring of `clear` to describe the difference between the matching algorithm on Windows and other platforms. (The description for the matching rules of POSIX fnmatch is incomplete. But that is unrelated to this report.)

Pushed to the stable branch here:
https://hg.savannah.gnu.org/hgweb/octave/rev/e424a55bc9fb

If we'd like to have that done differently, we could follow up with more changes or revert and re-do. (I just wanted to get something in so that the CI no longer times out at `make check`.)

Marking as ready for test.

Markus Mützel <mmuetzel>
Group administrator
Fri 08 Dec 2023 04:47:51 PM UTC, comment #21: 

Thank you for the continuous review. See the attached patch where  I tried to address your feedback. (I hope I got it all.)

Still no documentation changes.


(file #55421)

Markus Mützel <mmuetzel>
Group administrator
Fri 08 Dec 2023 01:17:47 PM UTC, comment #20: 

Yeah, I looked at the fnmatch sources in gnulib to see whether there was a simple way to just have it use ASCII characters or whether there was a function we could borrow to have a more complete implementation, not just * and ? but it seems quite complicated and not something I'd want to add to Octave for us to maintain if possible.  So for now I guess it makes just do the quick matching that you've implemented.

If someone is interested in a future project:

I'm not sure of the complete list of functions that use this feature for matching patterns of symbols, but I see that clear and who(s) have a -regexp option so maybe we could add a -glob or -fnmatch option to perform full POSIX fnmatch globbing on Windows systems?  If we use the gnulib fnmatch function, then I think we can also get the extended matching capabilities described in the GNU libc manual for FNM_EXTMATCH.  All of that could be nice to have, but probably wouldn't see much use and is certainly not necessary.

John W. Eaton <jwe>
Group administrator
Fri 08 Dec 2023 12:54:48 PM UTC, comment #19: 

Thank you for the feedback. I'll try and update the patch.

Regarding the difference in pattern matching on Windows and on other platforms: Implementing the '*' and '?' wildcards was possible in a couple of lines. Implementing `[]` group and range matches from scratch (in a POSIX compatible way) is probably more tricky. See the complexity and performance of the implementation from gnulib. I was hoping we could avoid that complexity and use something simple but fast (given that this function will apparently be called thousands of times).

One option to have the same behavior on all platforms would be to use that manual matching function everywhere (not just on Windows).
But it might be that the implementation of fnmatch on Linux is actually more performant than the function that is added for Windows in this patch.
Alternatively: Is there a POSIX function that does efficient pattern matching with only '*' and '?' wildcard characters (no '[]' groups or ranges)?

The glob_match class has a member function `glob`. That member function doesn't make sense for the symbol_match class (imho).
I'm also unsure if we need the overloads for string_vector input or the second (optional) input argument for the constructors.
Other than that, I agree that it might be a good idea to keep the interfaces of the two classes similar and to move them to the same files in liboctave.

Markus Mützel <mmuetzel>
Group administrator
Thu 07 Dec 2023 07:44:37 PM UTC, comment #18: 

Since there are more functions than clear that use similar pattern matching, maybe the docstring for each one should just point to a common description of pattern matching?

We have glob_match defined in liboctave so it seems to me that symbol_match should be defined there as well.  Maybe it could be defined in the same liboctave/util/glob-match.{h,cc} files?

In the symbol_match class, maybe m_glob should be a unique_ptr<T> or shared_ptr<T> object?

It might also be good if the interfaces for glob_match and symbol_match were the same and they only difference was the method used for matching and handling of non-ascii symbols.  If I were using these classes and knew nothing of the history, I'd be surprised to find that copying is allowed for glob_match objects but not for symbol_match objects.  I might also be surprised that the type of pattern matching differs on Windows systems, but if it matters, we could probably fix that later.

John W. Eaton <jwe>
Group administrator
Thu 07 Dec 2023 06:46:18 PM UTC, comment #17: 

I'm attaching a patch with a next attempt.

It implements manual wildcard ('?' and '*') matching for Windows. It's still significantly faster than calling the gnulib function. (The main point of this change.)
I hope it does the job now. At least, `make check` shows no new errors for me, and some exploratory testing indicates that `clear` still does what it should for patterns with '?' or '*'.

The documentation change for `clear` is still missing.


(file #55418)

Markus Mützel <mmuetzel>
Group administrator
Thu 07 Dec 2023 04:57:29 PM UTC, comment #16: 

We can't use the patch from comment #2. File names on MS DOS are case-insensitive. And `PathNameSpecA` implements MS DOS wildcard matching.

However, Octave symbol names are case-sensitive. So, we need a different solution.

Markus Mützel <mmuetzel>
Group administrator
Wed 06 Dec 2023 10:55:50 PM UTC, comment #15: 

Just one more tic-toc post:
With Dmitri's hint I get:

v10.0.0:
Elapsed time is 3182.15 seconds.
ans = 2803.4

v9.0.0
Elapsed time is 1129.42 seconds.
ans = 780.72

which shows that tic-toc has no issues and Octave-for-Windows' slowness is well confirmed.

Philip Nienhuis <philipnienhuis>
Group Member
Wed 06 Dec 2023 04:16:13 PM UTC, comment #14: 

Could we please keep this report on topic and move all discussion about tic-toc somewhere else?

Markus Mützel <mmuetzel>
Group administrator
Tue 05 Dec 2023 11:15:47 PM UTC, comment #13: 

Running /usr/bin/time -v make check I see:

Command being timed: "make check"
        User time (seconds): 296.14
        System time (seconds): 53.60
        Percent of CPU this job got: 118%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 4:55.11
        Average shared text size (kbytes): 0
        Average unshared data size (kbytes): 0
        Average stack size (kbytes): 0
        Average total size (kbytes): 0
        Maximum resident set size (kbytes): 1069032
        Average resident set size (kbytes): 0
        Major (requiring I/O) page faults: 15
        Minor (reclaiming a frame) page faults: 14303738
        Voluntary context switches: 117257
        Involuntary context switches: 5267
        Swaps: 0
        File system inputs: 60168
        File system outputs: 95160
        Socket messages sent: 0
        Socket messages received: 0
        Signals delivered: 0
        Page size (bytes): 4096
        Exit status: 0


So, tic-toc is consistent with wall time.
Also while running "make check" top shows cpu load ~60% on average (why?); it looks like cputime() takes this into account.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 05 Dec 2023 11:06:11 PM UTC, comment #12: 

data.cc-tst has tic-toc pair, though with an id. It looks like it
resets the outside tic-toc (anonymous) pair anyway.

Try "t1 = cputime; my_t = tic; _run_test_suite_ ; toc(my_t); cputime() - t1"

I got

Elapsed time is 291.445 seconds.
ans = 176.63


(Which I do not quite understand)

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 05 Dec 2023 10:15:35 PM UTC, comment #11: 

BTW, is tic-toc called or reset somewhere in the test suite?

In "normal" use (outside test suite) its output seems quite reasonable to me.

Philip Nienhuis <philipnienhuis>
Group Member
Tue 05 Dec 2023 08:38:35 PM UTC, comment #10: 

As far as I know cputime is approximately tic/toc multiply by number of threads. tic/toc more like wall time.
E.g.:



$ OMP_NUM_THREADS=16 octave

octave:1> a = randn(5000);
octave:2> tic; inv(a)*a; toc
Elapsed time is 1.6827 seconds.
octave:3> t1= cputime(); inv(a)*a; t2=cputime();
octave:4> t2-t1
ans = 24.022
octave:5> 1.6827*16
ans = 26.923


Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 05 Dec 2023 08:30:25 PM UTC, comment #9: 

@Mmuetzel:
That's the output I got.
The factor 3 slower I got with cputime() for Octave-10.0.0 looks to fit my experience (I was doing other things while Octave ploughed thru the tests).
Could multithreading influence tic-toc? (Ryzen 7 has 16 "CPU's").

What can I do to test tic-toc before submitting a bug report?


Philip Nienhuis <philipnienhuis>
Group Member
Tue 05 Dec 2023 07:08:55 AM UTC, comment #8: 

@jwe: Oops. Forgot that. We should be explicit that we'd like to pass by reference and not implicitly rely on move semantics.

@pnienhuis: Is tic-toc also broken? That would deserve a separate report.

Markus Mützel <mmuetzel>
Group administrator
Mon 04 Dec 2023 09:05:37 PM UTC, comment #7: 

Hmmm, apologies I'm late to the party, but I can confirm this slowness since crossbuilding Octave-10.0.0 on Nov. 27 and then running the test suite in Windows 10 as follows:

t = cputime (); tic; __run_test_suite__ (); toc; cputime () - t

where I got the following results on my Ryzen 7 5800 laptop:

v10.0.0:
Elapsed time = 30.121 seconds.
ans = 2847.5

v.9.0.0 (built Nov 18):
Elapsed time = 23.1807 seconds.
ans = 816.06

I figured it would be a temporary issue so didn't react immediately (and I have little time these weeks) but it seems to be serious ...
BTW I have that 10.0.0 build installed at work and didn't note particularly slow performance there doing regular work (mostly data processing and graphics). That's on much slower (virtual) HW.

Philip Nienhuis <philipnienhuis>
Group Member
Mon 04 Dec 2023 06:56:00 PM UTC, comment #6: 


octave:1> aa = 1
aa = 1
octave:2> ab = 2
ab = 2
octave:3> ac = 3
ac = 3
octave:4> ad = 4
ad = 4
octave:5> ae = 5
ae = 5
octave:6> who
Variables visible from the current scope:

aa  ab  ac  ad  ae

octave:7> clear a[bcd]
octave:8> who
Variables visible from the current scope:

aa  ae


John W. Eaton <jwe>
Group administrator
Mon 04 Dec 2023 06:52:27 PM UTC, comment #5: 

Shouldn't the constructors use "const std::string&" instead of "const std::string"?  If there is no difference now because of move semantics, then maybe we should decide what our preferred style is and try to ensure that all of Octave uses it consistently.

John W. Eaton <jwe>
Group administrator
Mon 04 Dec 2023 06:51:30 PM UTC, comment #4: 

what exactly is the a[bcd] syntax supposed to do?  it looks like invalid syntax to me and even playing around with in now i can't seem to get it to do anything useful.  is it documented somewhere?

seems like a worthwhile sacrifice to me.

Nicholas Jankowski <nrjank>
Group Member
Mon 04 Dec 2023 06:50:29 PM UTC, comment #3: 

Are patterns like a[bcd] used anywhere in Octave or its test suite?

Otherwise, it seems reasonable to avoid the unnecessary locale issues.

John W. Eaton <jwe>
Group administrator
Mon 04 Dec 2023 06:32:03 PM UTC, comment #2: 

With the attached patch, running `make check` is down to approx. 10 minutes on UCRT64 for me again.

The change would probably lead to something like `clear a[bcd]` no longer working on Windows. (But that's an Octave extension that is not compatible with Matlab.)

Would it be ok to just document that difference between the `clear` function on Windows and on other platforms?

The performance difference is very significant. (To clarify: When I wrote "more than 45 minutes" in comment #0 I meant that I aborted `__run_test_suite__` because it hadn't finished after more than 45 minutes. IIRC, it was somewhere in the tests for the "plot" directory at that point...)


(file #55403)

Markus Mützel <mmuetzel>
Group administrator
Mon 04 Dec 2023 07:44:10 AM UTC, comment #1: 

Forgot to mention: The extreme slowdown when linking with the UCRT isn't limited to builds with MXE Octave, the same can be observed when building natively on Windows with MSYS2:
https://github.com/gnu-octave/octave/actions/runs/7076535934

Duration of `make check` when linking with MSVCRT: 11m 7s
Duration of `make check` when linking with UCRT: timeout after 1h 12s

Markus Mützel <mmuetzel>
Group administrator
Mon 04 Dec 2023 07:32:39 AM UTC, original submission:  

Current builds of Octave for Windows are extremely slow.
Running `__run_test_suite__` used to take about 10 minutes on my hardware. It is now taking more than 45 minutes.

That seems to be related to us switching from the (older) MSVCRT to the (newer) UCRT in MXE Octave and an update in gnulib during the last year. (See also: https://octave.discourse.group/t/merging-branches-for-octave-9/4978/38 )

Attaching a profiler indicates that a significant proportion of the execution is spent in `setlocale`. Most of those backtraces are coming through `octave::sys::fnmatch` → `octave::symbol_table::clear_function_pattern`. Every call of `octave::sys::fnmatch` seems to lead to `setlocale` being called 6 times.

Possible options are to revert to linking with the MSVCRT, or to directly call a similar Windows API function to do the function pattern matching.
A candidate for the latter might be `PathMatchSpecW` or `PathMatchSpecA`:
https://learn.microsoft.com/en-us/windows/win32/api/shlwapi/nf-shlwapi-pathmatchspecw

Markus Mützel <mmuetzel>
Group administrator

 

(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 arungiridhar (Posted a comment)
  • -email is unavailable- added by dasergatskov (Posted a comment)
  • -email is unavailable- added by nrjank (Posted a comment)
  • -email is unavailable- added by jwe (Posted a comment)
  • -email is unavailable- added by mmuetzel (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 11 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2024-01-12 rik5 StatusReady For Test Fixed
        Open/ClosedOpen Closed
        Fixed ReleaseNone 9.1.0
    2023-12-11 mmuetzel Attached File- Added bug64975-windows-symbol-matching-v4.patch, #55433
    2023-12-10 mmuetzel StatusIn Progress Ready For Test
    2023-12-08 mmuetzel Attached File- Added bug64975-windows-symbol-matching-v3.patch, #55421
    2023-12-07 mmuetzel Attached File- Added bug64975-windows-symbol-matching-v2.patch, #55418
        StatusNone In Progress
    2023-12-04 mmuetzel Attached File- Added bug64975-windows-symbol-matching.patch, #55403
    2023-12-04 mmuetzel Planned ReleaseNone 9.1.0
    2023-12-04 mmuetzel Severity3 - Normal 5 - Blocker

    Back to the top

    Powered by Savane 3.13-3e34.
    Corresponding source code