bugGNU Octave - Bugs: bug #53867, Octave startup is extremely slow

 
 

bug #53867: Octave startup is extremely slow

Submitter:  None
Submitted:  Wed 09 May 2018 06:44:23 AM UTC
   
 
Category:  Performance Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Performance
Status:  Works For Me Assigned to:  None
Originator Name:  Octave user Originator Email:  -email is unavailable-
Open/Closed:  * Closed Release:  * 4.4.0
Operating System:  * Microsoft Windows Fixed Release:  None
Planned Release:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Fri 12 May 2023 12:16:25 AM UTC, comment #10: 

( yes, 5 year old thread, but finding little else on the subject and probably no one else still using such old versions )

Startup time here (currently stuck with old CLI version 4.4.1) increases with file count of current working directory, especially with more than O(1e4) files. Interactive cd followed by similar delay. Seems like there's a mandatory directory contents read. Hopefully this has long since been fixed -- there must be a faster way to read directory contents -- or at least add an option to put off directory reading until actually needed.

So, likely solved in a more recent version, but leaving this here for anyone else similarly stuck in the dark ages puzzling why.

Mark ODell <emark>
Sat 18 Aug 2018 01:58:44 PM UTC, comment #9: 

The startup time can be reduced if the following line is added to cmdshell.bat:

set SYSTEMROOT=

In this case the delay is only three seconds instead of 20 seconds.

Anonymous
Tue 15 May 2018 10:20:19 AM UTC, comment #8: 

OK, it seems that the issue is not related to Octave itself because the delay occurs before Octave's main function is executed.


Octave-4.2.2
$ date '+%s';  printf "break main\nrun -f -W --eval \"x=pi\"\nprint time(0)\ncont\nquit\n" | gdb /bin/octave-cli.exe; date '+%s'
1526378996
GNU gdb (GDB) 8.0.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-w64-mingw32".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from C:/Octave/OCTAVE~1.2/bin/octave-cli.exe...(no debugging symbols found)...done.
(gdb) Breakpoint 1 at 0x402df1
(gdb) Starting program: C:\Octave\OCTAVE~1.2\bin\octave-cli.exe -f -W --eval "x=pi"
[New Thread 11000.0x2548]

Breakpoint 1, 0x0000000000402df1 in octave-cli!main ()
(gdb) $1 = 1526378998
(gdb) Continuing.
x =  3.1416
[Inferior 1 (process 11000) exited normally]
(gdb) 1526378999



Octave-4.4.0
$ date '+%s';  printf "break main\nrun -f -W --eval \"x=pi\"\nprint time(0)\ncont\nquit\n" | C:/Octave/Octave-4.2.2/bin/gdb.exe /bin/octave-cli.exe; date '+%s'
1526378846
GNU gdb (GDB) 8.0.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-w64-mingw32".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from C:/Octave/OCTAVE~1.0/bin/octave-cli.exe...(no debugging symbols found)...done.
(gdb) Breakpoint 1 at 0x402e01
(gdb) Starting program: C:\Octave\OCTAVE~1.0\bin\octave-cli.exe -f -W --eval "x=pi"
[New Thread 6660.0x2628]
[New Thread 6660.0x287c]
[New Thread 6660.0x2668]
[New Thread 6660.0x2978]
[New Thread 6660.0x22f8]
[New Thread 6660.0x16d4]
[New Thread 6660.0x26a8]
[New Thread 6660.0xc60]
warning: ERROR !!! HeapSetInformation failed to set g_Heap to LFH
warning: ERROR !!! HeapSetInformation failed to set g_SpyHeap to LFH
[New Thread 6660.0x2b08]
[New Thread 6660.0x1d44]

Thread 1 hit Breakpoint 1, 0x0000000000402e01 in octave-cli!main ()
(gdb) $1 = 1526378870
(gdb) Continuing.
[New Thread 6660.0x2468]
x =  3.1416
[Thread 6660.0x287c exited with code 0]
[Thread 6660.0x26a8 exited with code 0]
[Thread 6660.0x2468 exited with code 0]
[Thread 6660.0x1d44 exited with code 0]
[Thread 6660.0x2978 exited with code 0]
[Thread 6660.0x16d4 exited with code 0]
[Thread 6660.0xc60 exited with code 0]
[Thread 6660.0x22f8 exited with code 0]
[Thread 6660.0x2b08 exited with code 0]
[Thread 6660.0x2668 exited with code 0]
[Inferior 1 (process 6660) exited normally]
(gdb) 1526378871


                                               4.2.2                4.4
time before gdb starts:  t0                1526378996        1526378846
time before main starts: t1                1526378998        1526378870
time after gdb exits:    t2                1526378999        1526378871
time delay before main:  t1 - t0                 2              24
time delay within main:  t2 - t1                 1               1


Anonymous
Fri 11 May 2018 03:35:41 PM UTC, comment #7: 

I also can't reproduce this on a system running Windows 10.

To debug, I would run Octave with gdb and step through the startup code until I found the function call that shows the big delay.

John W. Eaton <jwe>
Group administrator
Thu 10 May 2018 06:25:23 PM UTC, comment #6: 

I didn't think there would be a difference, but thanks for confirming.  This is something system specific.  If it were under Linux you could use something like strace to determine what underlying timeout is causing the delay.  I don't know how to do the equivalent on Windows.

Rik <rik5>
Group administrator
Thu 10 May 2018 05:59:12 PM UTC, comment #5: 

No, there is no difference between an interactive session (started from octave.vbs) and a batch session. There is almost no difference between octave-cli and octave-gui. When starting the gui, startup is a little bit slower. The -W flag has no effect. When using the -x option with octave-4.4.0, the first octave command appears at the screen after about 20 seconds. So the problem seems to be related to C++ code.


$ time octave-cli-4.2.2 -f --eval "x = pi"
x =  3.1416

real    0m0.296s
user    0m0.000s
sys     0m0.015s



$ time octave-cli-4.4.0 -f --eval "x = pi"
x =  3.1416

real    0m20.441s
user    0m0.000s
sys     0m0.031s


octave-4.2.2

$ time octave-gui.exe --force-gui -f --eval "x = pi"

real    0m0.759s
user    0m0.000s
sys     0m0.031s


octave-4.4.0

$ time octave-gui -f --force-gui --eval "x = pi"

real    0m21.898s
user    0m0.000s
sys     0m0.015s


Anonymous
Thu 10 May 2018 04:22:01 PM UTC, comment #4: 

I tried Octave 4.4 in a Windows 7 VM and the eval test executes in less than a second for me.  So I also suspect access to some resource is timing out.

John W. Eaton <jwe>
Group administrator
Thu 10 May 2018 03:31:57 PM UTC, comment #3: 

We've seen behavior like this before.  It usually relates to mapped network drives which are not available.  The system has to wait for whatever network timeout has been configured, before continuing.  So you might check that.

It's a long shot, but you could also remove the '-W' option and see if that has any effect.

Finally, is the startup slow when you begin an interactive session versus a batch session?

Rik <rik5>
Group administrator
Thu 10 May 2018 07:33:31 AM UTC, comment #2: 

Well, there is not time.exe, but time is a builtin command of bash which is part of Octave.

Here are the results with your command line options:
octave-4.2.2

$ time octave-cli -f -W --eval "x = pi"
x =  3.1416

real    0m0.303s
user    0m0.000s
sys     0m0.015s


octave-4.4.0

$ time octave-cli -f -W --eval "x = pi"
x =  3.1416

real    0m20.331s
user    0m0.000s
sys     0m0.015s


Those commands are executed from within bash. But if you run them  from cmd.exe without "time", it takes approximately the same time.

Anonymous
Wed 09 May 2018 06:27:29 PM UTC, comment #1: 

Something is wrong here, it should never take 20 seconds to launch the program.  But we need some more information.

First, you reported that the operating system was Microsoft Windows, but there is no 'time' program that I know of from Microsoft.  And there is no time.exe in C:\Octave\Octave-4.4.0\bin so I don't know which executable it is actually picking up.

Second, there are a lot of redundancies.  The single option '-f' is enough to replace '--norc --noinit-file --no-site-file'.

Third, 'help' isn't a particularly good command to use when invoking Octave in batch mode since it is an interactive command.

Can you re-test with


cd C:\Octave\Octave-4.4.0\bin
time octave-cli -f -W --eval "x = pi"
cd C:\Octave\Octave-4.2.2\bin
time octave-cli -f -W --eval "x = pi"



Rik <rik5>
Group administrator
Wed 09 May 2018 06:44:23 AM UTC, original submission:  

If you run the following command with octave-4.2.2 you get:


time octave-cli -f --norc --no-window-system --no-init-file --no-site-file --eval help

real    0m0.404s
user    0m0.000s
sys     0m0.015s


With octave-4.4.0 you get:

time octave-cli -f --norc --no-window-system --no-init-file --no-site-file --eval help

real    0m20.462s
user    0m0.000s
sys     0m0.015s


That means starting octave is about 50 times slower in octave-4.4.0 and a startup time of 20 seconds is really significantly slower.

Anonymous

 

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

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by emark (Posted a comment)
  • -email is unavailable- added by jwe (Posted a comment)
  • -email is unavailable- added by rik5 (Posted a comment)
  •  

    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 4 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2018-05-14 rik5 StatusNeed Info Works For Me
        Open/ClosedOpen Closed
    2018-05-09 rik5 SummaryOctave startup is extremly slow Octave startup is extremely slow
    2018-05-09 rik5 StatusNone Need Info

    Back to the top

    Powered by Savane 3.13-02a9.
    Corresponding source code