NinjaProfile
From Gnash Project Wiki
Test case: http://www.atomfilms.com/afassets/flash/nj_chapterninjai10_bb.swf
md5sum: a3d368108cadb2b6151d304b90911870 SWF: 5
This movie exposes a frustrating slowness in Gnash parser as of head 2007-08-24. In this page we'll try to find out why.
NEWS: running with -r1 (sound disabled) seems to speed up parsing a lot ! --Strk 12:08, 25 September 2007 (EDT);
Profile reports
Profile1
The following profile has been generated with gprof and loader thread disabled. As soon as parsing finishes the output window gets mapped and a screen prompting user for continuing playing gets rendered. At that point I quit (there should not be much rendering involved, due to invalidated ranges being NULL).
Flat profile:
Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 34.81 0.28 0.28 18522890 0.00 0.00 gnash::stream::read_uint(unsigned short) 21.52 0.45 0.17 2689 0.06 0.24 gnash::shape_character_def::read(gnash::stream*, int, bool, gnash::movie_definition*) 8.86 0.52 0.07 6521001 0.00 0.00 gnash::stream::read_sint(unsigned short) 6.33 0.57 0.05 608793 0.00 0.00 gnash::rgba::set_lerp(gnash::rgba const&, gnash::rgba const&, float) 3.80 0.60 0.03 652544 0.00 0.00 gnash::fill_style::sample_gradient(unsigned char) const
Excerpt from the graph:
0.00 0.00 6/18522890 gnash::SWF::tag_loaders::sound_stream_head_loader(gnash::stream*, gnash::SWF::tag_type, gnash::movie_definition*) [169]
0.00 0.00 8/18522890 gnash::font::readDefineFont2_or_3(gnash::stream*, gnash::movie_definition*) [69]
0.00 0.00 16/18522890 gnash::edit_text_character_def::read(gnash::stream*, int, gnash::movie_definition*) [59]
0.00 0.00 167/18522890 gnash::text_glyph_record::read(gnash::stream*, int, int, int) [117]
0.00 0.00 2649/18522890 gnash::rect::read(gnash::stream*) [42]
0.00 0.00 5685/18522890 gnash::cxform::read_rgba(gnash::stream*) [85]
0.00 0.00 161381/18522890 gnash::matrix::read(gnash::stream*) [57]
0.00 0.00 304424/18522890 gnash::SWF::PlaceObject2Tag::readPlaceObject2(gnash::stream*, int, bool) [41]
0.10 0.01 6521001/18522890 gnash::stream::read_sint(unsigned short) [8]
0.17 0.01 11527553/18522890 gnash::shape_character_def::read(gnash::stream*, int, bool, gnash::movie_definition*) [5]
[7] 37.2 0.28 0.02 18522890 gnash::stream::read_uint(unsigned short) [7]
0.02 0.00 8045860/8464384 gnash::std_read_func(void*, int, void*) [32]
Profile2
Obtained in the same way as Profile1, but with optimized multi-byte read in stream::read_uint. This optimization basically reduces calls to the tu_file reader. You can see we now have 6588352 calls to std_read_func, versus the 6923837 calls previously made with this optimization disabled (there's a macro in stream.cpp to remove the multi-byte optimization)
Flat profile:
Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 24.65 0.18 0.18 9876813 0.00 0.00 gnash::stream::read_uint(unsigned short) 14.08 0.28 0.10 2689 0.04 0.20 gnash::shape_character_def::read(gnash::stream*, int, bool, gnash::movie_definition*) 11.97 0.36 0.09 8646077 0.00 0.00 gnash::stream::read_bit() 4.93 0.40 0.04 6521001 0.00 0.00 gnash::stream::read_sint(unsigned short) 4.23 0.43 0.03 8128899 0.00 0.00 gnash::std_read_func(void*, int, void*)
Excerpt from the graph:
0.00 0.00 4/9876813 gnash::SWF::tag_loaders::sound_stream_head_loader(gnash::stream*, gnash::SWF::tag_type, gnash::movie_definition*) [130]
0.00 0.00 167/9876813 gnash::text_glyph_record::read(gnash::stream*, int, int, int) [112]
0.00 0.00 1895/9876813 gnash::cxform::read_rgba(gnash::stream*) [92]
0.00 0.00 2649/9876813 gnash::rect::read(gnash::stream*) [90]
0.00 0.00 89241/9876813 gnash::matrix::read(gnash::stream*) [66]
0.06 0.01 3261856/9876813 gnash::shape_character_def::read(gnash::stream*, int, bool, gnash::movie_definition*) [5]
0.12 0.02 6521001/9876813 gnash::stream::read_sint(unsigned short) [8]
[7] 28.1 0.18 0.02 9876813 gnash::stream::read_uint(unsigned short) [7]
0.02 0.00 6588352/8128899 gnash::std_read_func(void*, int, void*) [15]

