View Issue Details

IDCategoryLast Update
0007045bugs2016-10-02 03:26
ReportertbrodelAssigned To 
Reproducibilityalways 
Status confirmedResolutionopen 
PlatformLinuxOSDebianOS Version8 (jessie)
Product Version5.3 
Fixed in Version 
Summary0007045: CPU 100% when selecting large midi files
DescriptionI am working with some large midi files exported from a pro-tools session. They are just under 500KB and roughly 45 minutes long. When selecting them in the import window the system hangs for several minutes with ardour consuming 100% of one core. This is prior to the actual import, which takes roughly the same amount of time.

Smaller files pose no significant issues.

This is particularly pronounced on smaller systems, where ardour can end up triggering a "Not Responding" notification in GNOME.

Tested with nightly debug build.
Steps To Reproduce* Prepare a large midi file.
* Open a terminal and launch `top'
* Launch ardour session and open import window.
* Navigate to directory containing midi file
* Attempt to select file
* Switch to terminal and watch the CPU get consumed by the ardour process
TagsMidi

Activities

timbyr

2016-09-28 00:25

developer   ~0018722

Is it possible for you to attach a MIDI file that causes this behaviour?

tbrodel

2016-09-28 01:26

reporter  

midi NotM1.mid (504,276 bytes)

tbrodel

2016-09-28 01:26

reporter   ~0018723

hi timbyr, please find `midi NotM1.mid' attached

timbyr

2016-10-01 23:48

developer   ~0018734

I can confirm this issue with official 5.4 build(linux 32 bit)

Selecting the file in browser causes a 0000033:0000015 second pause on this machine.

Does this file import correctly? What does it contain as it seems mostly empty here, timidity -Ol says it contains only 12 notes?

tbrodel

2016-10-02 00:44

reporter   ~0018735

hi timbyr, the vast majority of the file is control change automation, with only a few actual MIDI notes.

it imports correctly in ardour and plays back as expected. i briefly installed qtractor from the debian repos and it loaded the file immediately, so i don't believe the file is corrupt.

timbyr

2016-10-02 01:26

developer   ~0018737

Oh yes, I can see there is a lot of automation.

OK, well there is likely a performance issue and this file will be good for use in a unit test, if that is OK with you?

In saying that it may take some time for this issue to be looked into. It may improve over time as a result of other structural/internal changes etc.

timbyr

2016-10-02 01:28

developer  

ardour-5.3-bug7045-midi-import-hang-bt.txt (5,232 bytes)
Thread 1 (Thread 0xb2858940 (LWP 16401)):
#0  0xffffffff in Evoral::ControlList::add(double, double, bool, bool) (__last=..., __first=) at /usr/include/c++/4.9.2/bits/stl_iterator_base_funcs.h:83
#1  0xffffffff in Evoral::ControlList::add(double, double, bool, bool) (__last=, __first=...) at /usr/include/c++/4.9.2/bits/stl_iterator_base_funcs.h:118
#2  0xffffffff in Evoral::ControlList::add(double, double, bool, bool) (__comp=..., __val=<optimized out>, __last=..., __first=) at /usr/include/c++/4.9.2/bits/stl_algobase.h:958
#3  0xffffffff in Evoral::ControlList::add(double, double, bool, bool) (__comp=
---Type <return> to continue, or q <return> to quit---
    0xb74048b0 <Evoral::ControlList::time_comparator(Evoral::ControlEvent const*, Evoral::ControlEvent const*)>, __val=<optimized out>, __last=..., __first=...) at /usr/include/c++/4.9.2/bits/stl_algo.h:2036
#4  0xffffffff in Evoral::ControlList::add(double, double, bool, bool) (this=0x12a42fd8, when=1566.5, value=0, with_guards=true, with_initial=true) at ../libs/evoral/src/ControlList.cpp:642
#5  0xffffffff in Evoral::Sequence<Evoral::Beats>::append_control_unlocked(Evoral::Parameter const&, Evoral::Beats, double, int) (this=this@entry=0x11bddc20, param=..., time=..., value=0)
    at ../libs/evoral/src/Sequence.cpp:1050
#6  0xffffffff in Evoral::Sequence<Evoral::Beats>::append(Evoral::Event<Evoral::Beats> const&, int) (this=this@entry=0x11bddc20, event=..., evid=1374143) at ../libs/evoral/src/Sequence.cpp:931
#7  0xffffffff in ARDOUR::SMFSource::load_model(Glib::Threads::Mutex::Lock const&, bool) (this=0x11bd4ca0, lock=..., force_reload=true) at ../libs/ardour/smf_source.cc:720
#8  0xffffffff in ARDOUR::SourceFactory::createExternal(ARDOUR::DataType, ARDOUR::Session&, std::string const&, int, ARDOUR::Source::Flag, bool, bool) (type=..., type@entry=..., 
    s=..., path="/home/timbyr/Downloads/midi NotM1.mid", chn=chn@entry=0, flags=flags@entry=(unknown: 0), announce=announce@entry=false, defer_peaks=defer_peaks@entry=false)
    at ../libs/ardour/source_factory.cc:294
#9  0x0896e31a in SoundFileBox::setup_labels(std::string const&) (this=this@entry=0xdb2f518, filename="/home/timbyr/Downloads/midi NotM1.mid") at ../gtk2_ardour/sfdb_ui.cc:289
#10 0x0897013d in SoundFileBrowser::update_preview() (this=0xdb2f400) at ../gtk2_ardour/sfdb_ui.cc:899
#11 0xffffffff in Glib::SignalProxyNormal::slot0_void_callback(_GObject*, void*) () at /lib/libglibmm-2.4.so.1
#12 0xffffffff in g_cclosure_marshal_VOID__VOID () at /lib/libgobject-2.0.so.0
#13 0xffffffff in g_closure_invoke () at /lib/libgobject-2.0.so.0
#14 0xffffffff in signal_emit_unlocked_R () at /lib/libgobject-2.0.so.0
#15 0xffffffff in g_signal_emit_valist () at /lib/libgobject-2.0.so.0
#16 0xffffffff in g_signal_emit_by_name () at /lib/libgobject-2.0.so.0
#17 0xffffffff in delegate_update_preview () at /lib/libgtk-x11-2.0.so.0
#18 0xffffffff in g_cclosure_marshal_VOID__VOID () at /lib/libgobject-2.0.so.0
#19 0xffffffff in g_closure_invoke () at /lib/libgobject-2.0.so.0
#20 0xffffffff in signal_emit_unlocked_R () at /lib/libgobject-2.0.so.0
#21 0xffffffff in g_signal_emit_valist () at /lib/libgobject-2.0.so.0
#22 0xffffffff in g_signal_emit_by_name () at /lib/libgobject-2.0.so.0
#23 0xffffffff in check_preview_change () at /lib/libgtk-x11-2.0.so.0
#24 0xffffffff in list_selection_changed () at /lib/libgtk-x11-2.0.so.0
#25 0xffffffff in g_cclosure_marshal_VOID__VOID () at /lib/libgobject-2.0.so.0
#26 0xffffffff in g_closure_invoke () at /lib/libgobject-2.0.so.0
#27 0xffffffff in signal_emit_unlocked_R () at /lib/libgobject-2.0.so.0
#28 0xffffffff in g_signal_emit_valist () at /lib/libgobject-2.0.so.0
#29 0xffffffff in g_signal_emit () at /lib/libgobject-2.0.so.0
#30 0xffffffff in _gtk_tree_selection_internal_select_node () at /lib/libgtk-x11-2.0.so.0
#31 0xffffffff in gtk_tree_view_real_set_cursor () at /lib/libgtk-x11-2.0.so.0
#32 0xffffffff in gtk_tree_view_button_press () at /lib/libgtk-x11-2.0.so.0
#33 0xffffffff in _gtk_marshal_BOOLEAN__BOXED () at /lib/libgtk-x11-2.0.so.0
#34 0xffffffff in g_type_class_meta_marshal () at /lib/libgobject-2.0.so.0
#35 0xffffffff in g_closure_invoke () at /lib/libgobject-2.0.so.0
#36 0xffffffff in signal_emit_unlocked_R () at /lib/libgobject-2.0.so.0
#37 0xffffffff in g_signal_emit_valist () at /lib/libgobject-2.0.so.0
#38 0xffffffff in g_signal_emit () at /lib/libgobject-2.0.so.0
#39 0xffffffff in gtk_widget_event_internal () at /lib/libgtk-x11-2.0.so.0
#40 0xffffffff in gtk_propagate_event () at /lib/libgtk-x11-2.0.so.0
#41 0xffffffff in gtk_main_do_event () at /lib/libgtk-x11-2.0.so.0
#42 0xffffffff in gdk_event_dispatch () at /lib/libgdk-x11-2.0.so.0
#43 0xffffffff in g_main_context_dispatch () at /lib/libglib-2.0.so.0
#44 0xffffffff in g_main_context_iterate.isra () at /lib/libglib-2.0.so.0
#45 0xffffffff in g_main_loop_run () at /lib/libglib-2.0.so.0
#46 0xffffffff in gtk_main () at /lib/libgtk-x11-2.0.so.0
#47 0xffffffff in Gtk::Main::run() () at /lib/libgtkmm-2.4.so.1
#48 0xffffffff in Gtkmm2ext::UI::run(Receiver&) (this=this@entry=0x8fd2a18, old_receiver=...) at ../libs/gtkmm2ext/gtk_ui.cc:286
#49 0x082a0fac in main(int, char**) (argc=1, argv=0xbfffe2a4) at ../gtk2_ardour/main.cc:408
(gdb) 

timbyr

2016-10-02 01:30

developer   ~0018738

I've attached a backtrace of the relevant thread as a result of interrupting the process during the hang that gives an indication of where the time is being spent.

tbrodel

2016-10-02 03:26

reporter   ~0018740

thanks for looking into this, perfectly happy to use the file for testing.

and i fully understand that performance bugs are tough to solve, i'm not expecting a quick one-line fix.

i'm not familiar enough with the ardour source to make much of that backtrace, but i'll have a read and see if anything stands out. i expect that others will have a far better clue than me.

thanks for your efforts.

Issue History

Date Modified Username Field Change
2016-09-27 09:38 tbrodel New Issue
2016-09-28 00:25 timbyr Note Added: 0018722
2016-09-28 00:25 timbyr Status new => feedback
2016-09-28 01:26 tbrodel File Added: midi NotM1.mid
2016-09-28 01:26 tbrodel Note Added: 0018723
2016-09-28 01:26 tbrodel Status feedback => new
2016-09-28 01:27 tbrodel Tag Attached: Midi
2016-10-01 23:48 timbyr Note Added: 0018734
2016-10-01 23:48 timbyr Status new => confirmed
2016-10-01 23:49 timbyr Assigned To => timbyr
2016-10-01 23:49 timbyr Status confirmed => feedback
2016-10-02 00:44 tbrodel Note Added: 0018735
2016-10-02 00:44 tbrodel Status feedback => assigned
2016-10-02 01:03 timbyr Assigned To timbyr =>
2016-10-02 01:03 timbyr Status assigned => confirmed
2016-10-02 01:26 timbyr Note Added: 0018737
2016-10-02 01:28 timbyr File Added: ardour-5.3-bug7045-midi-import-hang-bt.txt
2016-10-02 01:30 timbyr Note Added: 0018738
2016-10-02 03:26 tbrodel Note Added: 0018740