All right, now it was with --opengl=1, results are bit different, though for AI there is no significant difference (8 % now), but the game was shorter.
In one of my earlier emails I mentioned cmd_queue and it is here indeed - taking 30%. Main part of this cmd_queue is related to bobs, it seems. [1]_____97.1____0.00__124.97_________________main_[1] [2]_____97.1____0.00__124.95_______1_________WLApplication::run()_[2] [3]_____95.2____0.01__122.48______10_________UI::Panel::run()_[3] [4]_____87.2____0.00__112.22_______1_________WLApplication::mainmenu()_[4] [5]_____68.1____0.00___87.68_______1_________WLApplication::mainmenu_multiplayer()_[5] [6]_____55.6____3.52___68.02___29578+4054464_<cycle_4_as_a_whole>_[6] [7]_____39.5____0.01___50.86_______1_________NetHost::run()_[7] [8]_____39.5____0.01___50.79___12715+365532__UI::Panel::do_think()_[8] [9]_____38.9____0.00___50.06___12325_________Interactive_Base::think()_[9] [10]____38.8____0.00___49.95___12325_________Widelands::Game::think()_[10] [11]____30.8____0.33___39.27___12325_________Widelands::Cmd_Queue::run_queue()_[11] [12]____26.2____0.18___33.52_2975615_________Widelands::Cmd_Act::execute()_[12] [13]____24.8____0.07___31.84_2576025_________Widelands::Bob::act()_[13] [14]____24.7____0.30___31.47_2530010_________Widelands::Bob::do_act()_[14] [15]____22.6____3.01___26.12___12325_________GameRenderer::draw_objects()_<cycle_4>_[15] [16]____19.2____0.00___24.70_______1_________Fullscreen_Menu_LaunchMPG::Fullscreen_Menu_LaunchMPG()_[16] [17]____19.1____0.00___24.52_______1_________Fullscreen_Menu_LaunchMPG::change_map_or_save()_[17] [18]____17.7____2.24___20.59_9833290+60076979_<cycle_9_as_a_whole>_[18] [19]____17.2____0.02___22.14___12325_________GameRendererGL::draw()_<cycle_4>_[19] [20]____15.3____0.68___18.98_7385892_________RenderTarget::drawanim()_[20] [21]____15.1____1.79___17.60__244640_________void_Widelands::Map::find_reachable<Widelands::FindImmovablesCallback>(Widelands [22]____13.4____0.52___16.78_5059151_________()_c [23]____12.4____0.27___15.69__134647_________Widelands::Map::findpath(Widelands::Coords,_Widelands::Coords,_int,_Widelands::P [24]____12.0____3.27___12.12_2225850789_________std::unique_ptr<Widelands::Field_[],_std::default_delete<Widelands::Field_[]> [25]____11.8____0.02___15.21__125059_________Widelands::Bob::start_task_movepath() [26]____10.9____0.01___14.03___12325_________GameRendererGL::prepare_terrain_dither()_[26] [27]____10.9____1.14___12.83___24650_________GameRendererGL::collect_terrain_dither()_[27] [28]____10.5____0.21___13.29_5091607_________()_const_[28] [29]____10.2____0.01___13.08_______1_________Widelands::Game::run()_[29] [30]____10.1____0.40___12.58_3276377_________ImageTransformations::player_colored()_[30] [31]____10.1____0.02___12.93__201687_________Widelands::Critter::roam_update()_[31] [32]_____9.5____0.00___12.27_______1_________Fullscreen_Menu_LaunchMPG::select_map()_[32] [33]_____9.4____3.07____9.05_2225850789______ZSt3getILj0EJPN9Widelands5FieldESt14default_deleteIA_S1_EEENSt11__add_c_refI [34]_____8.4____0.90____9.85_217827528_______Widelands::Map::get_neighbour()_const_[34] [35]_____8.3____0.00___10.70___12754_________UI::Panel::handle_tooltip()_[35] [36]_____8.3____0.00___10.70___12565+15430___UI::Panel::do_tooltip()_[36] [37]_____8.3____0.00___10.69___12754_________UI::Panel::draw_tooltip()_[37] [38]_____8.1____0.01___10.37___12517_________NetHost::think()_[38] [39]_____8.0____0.01___10.33___24650_________DefaultAI::think()_[39] As for compilation flags, I am using this: (INSDIR is custom target directory) cmake ../.. -DCMAKE_BUILD_TYPE=Debug \ -DCMAKE_INSTALL_PREFIX=$INSDIR \ -DWL_INSTALL_PREFIX=$INSDIR \ -DWL_INSTALL_DATADIR=share/widelands \ -DWL_INSTALL_BINDIR=bin' -DCMAKE_C_FLAGS=-pg -DCMAKE_CXX_FLAGS=-pg What should I change here for more accurate profiling? 2014-09-11 15:26 GMT+02:00 Holger Rapp <holgerr...@gmx.net>: > you should probably start out by using opengl instead of the software > renderer - it is swamping your profile. Then, you should sort by “self”, > not by “all” or “time”. That is the information which function takes the > most time, not how much time is spend inside a function in total. > > Also, I think you are using a debug build (due to the many seconds spend > in unique_ptr<> delete). For profiling you want to have an optimized (but > non-stripped) build. > > Cheers, > Holger > > On 11.09.2014, at 06:22, Tibor Bamhor <tibor...@gmail.com> wrote: > > So I opted for gprof and bellow are the results. They are from 3 > hours-long game (AI only) on Crater map (red player was eliminated by blue > one). You can look at it, what is interested for me is that DefaultAI (line > 43) - the main AI function - takes only 6.3 % of total CPU if gprof is > correct. > > If somebody want raw data (txt file) let me know. > > I believe that proportion of functions changes with size of map. > > ==================== Call graph () ==================== > [see second column - % time] > > > index_%_time____self__children____called_____name > > [1]_____99.4____0.00_1696.26_________________main_[1] > [2]_____99.4____0.01_1696.18_______1_________WLApplication::run()_[2] > [3]_____99.0____0.03_1689.50______10_________UI::Panel::run()_[3] > [4]_____89.4____0.00_1525.92_______1_________WLApplication::mainmenu()_[4] > [5]_____71.7___14.77_1208.34__123188+10361143_<cycle_3_as_a_whole>_[5] > > [6]_____69.6____0.00_1187.91_______1_________WLApplication::mainmenu_multiplayer()_[6] > > [7]_____53.6____0.02__914.58___61226_________GameRendererSDL::draw()_<cycle_3>_[7] > > [8]_____53.6____2.27__912.31___61226_________GameRendererSDL::draw_terrain()_[8] > > [9]_____52.5____0.64__894.67_63185232________GameRendererSDL::draw_field()_[9] > > [10]____52.3____1.87__891.10_63185232________void_draw_field_int<unsigned_int>()_[10] > [11]____39.9____0.00__680.96_______1_________NetHost::run()_[11] > > [12]____31.2___16.13__515.46_126370464_______void_render_triangle<unsigned_int>()_[12] > > [13]____30.2__407.08__107.54_126370464_______void_render_edge_lists<unsigned_int>()_[13] > > [14]____29.3__114.19__385.34_271118424_______std::unique_ptr<Widelands::Field_[],_std::default_delete<Widelands::Field_[]>_ > [15]____27.3____0.04__465.86___61569+2233150_UI::Panel::do_think()_[15] > [16]____27.2____0.03__463.78___61226_________Interactive_Base::think()_[16] > [17]____27.2____0.05__463.44___61226_________Widelands::Game::think()_[17] > > [18]____22.6__101.56__283.78_271118424_______ZSt3getILj0EJPN9Widelands5FieldESt14default_deleteIA_S1_EEENSt11__add_c_refIN > > [19]____20.8____0.68__353.99___61226_________Widelands::Cmd_Queue::run_queue()_[19] > > [20]____19.9____0.25__339.93_5582271_________Widelands::Cmd_Act::execute()_[20] > [21]____19.9____4.48__334.90_17335297+131869067_<cycle_8_as_a_whole>_[21] > > [22]____19.8____0.00__338.65_______1_________Fullscreen_Menu_LaunchMPG::Fullscreen_Menu_LaunchMPG()_[22] > > [23]____19.8____0.00__337.97_______1_________Fullscreen_Menu_LaunchMPG::change_map_or_save()_[23] > [24]____19.7____0.20__336.18_4731494_________Widelands::Bob::act()_[24] > [25]____19.7____0.49__335.58_4618069_________Widelands::Bob::do_act()_[25] > > [26]____19.6__334.54____0.00_896797820_______SDLSurface::get_pixels()_const_[26] > > [27]____19.3____4.02__325.94__638674_________void_Widelands::Map::find_reachable<Widelands::FindImmovablesCallback>()_<cycle_ > > [28]____16.6__103.91__179.87_271118424_______std::__add_c_ref<Widelands::Field*>::type_std::__get_helper<0u,_Widelands::Fie > > [29]____15.2____2.26__256.88_564713957_______Widelands::Map::get_neighbour()_const_[29] > > [30]____12.4___13.32__198.39___61226_________GameRenderer::draw_objects()_<cycle_3>_[30] > > [31]____12.0____0.54__203.58__213382_________Widelands::Map::findpath()_[31] > > [32]____11.1____0.03__189.65__197613_________Widelands::Bob::start_task_movepath()__[32] > > [33]____10.5__101.56___78.31_271118424_______ZNSt11_Tuple_implILj0EJPN9Widelands5FieldESt14default_deleteIA_S1_EEE7_M_head > [34]____10.0____0.00__171.01_______1_________Widelands::Game::run()_[34] > > [35]_____9.9____0.00__169.01_______1_________Fullscreen_Menu_LaunchMPG::select_map()_[35] > > [36]_____8.5___11.77__132.94_17897783________void_render_road_vert<unsigned_int>()_[36] > > [37]_____8.2____0.03__140.70__279850_________Widelands::Critter::roam_update()_[37] > > [38]_____8.0____0.02__135.69__199605_________Widelands::Worker::program_update()_[38] > > [39]_____6.7____9.60__104.72_7781675_________void_render_road_horiz<unsigned_int>()_[39] > > [40]_____6.6____0.00__111.96___14488_________Widelands::Map::find_reachable_fields()_[40] > > [41]_____6.6____0.30__111.67___14488_________void_Widelands::Map::find_reachable<Widelands::FindNodesCallback>()_[41] > [42]_____6.3____0.07__106.93___61424_________NetHost::think()_[42] > [43]_____6.3____0.01__106.74__122452_________DefaultAI::think()_[43] > > > > > __index______A_unique_number_given_to_each_element_of_the_table. > ____________Index_numbers_are_sorted_numerically. > ____________The_index_number_is_printed_next_to_every_function_name_so > ____________it_is_easier_to_look_up_where_the_function_in_the_table. > > %_time______This_is_the_percentage_of_the_`total'_time_that_was_spent > ____________in_this_function_and_its_children.__Note_that_due_to > ____________different_viewpoints,_functions_excluded_by_options,_etc, > ____________these_numbers_will_NOT_add_up_to_100%. > > ___self______This_is_the_total_amount_of_time_spent_in_this_function. > > children______This_is_the_total_amount_of_time_propagated_into_this > ____________function_by_its_children. > > _called______This_is_the_number_of_times_the_function_was_called. > ____________If_the_function_called_itself_recursively,_the_number > ____________only_includes_non-recursive_calls,_and_is_followed_by > ____________a_`+'_and_the_number_of_recursive_calls. > > __name_____The_name_of_the_current_function.__The_index_number_is > ____________printed_after_it.__If_the_function_is_a_member_of_a > ____________cycle,_the_cycle_number_is_printed_between_the > ____________function's_name_and_the_index_number. > > > ================ top functions sorted by "self" column ============== > > > > [13]____30.2__407.08__107.54_126370464_________void_render_edge_lists<unsigned_int>()_[13] > > [26]____19.6__334.54____0.00_896797820_________SDLSurface::get_pixels()_const_[26] > > [14]____29.3__114.19__385.34_271118424_________std::unique_ptr<Widelands::Field_[],_std::default_delete<Widelands::Field_[]>_ > > [28]____16.6__103.91__179.87_271118424_________std::__add_c_ref<Widelands::Field*>::type_std::__get_helper<0u,_Widelands::Fie > > [33]____10.5__101.56___78.31_271118424_________ZNSt11_Tuple_implILj0EJPN9Widelands5FieldESt14default_deleteIA_S1_EEE7_M_head > > [18]____22.6__101.56__283.78_271118424_________ZSt3getILj0EJPN9Widelands5FieldESt14default_deleteIA_S1_EEENSt11__add_c_refIN > > [45]_____4.6___78.31____0.00_271118424_________std::_Head_base<0u,_Widelands::Field*,_false>::_M_head()_[45] > > > > > ---------- Forwarded message ---------- > From: Tibor Bamhor <tibor...@gmail.com> > Date: 2014-09-10 15:45 GMT+02:00 > Subject: Re: [Widelands-dev] performance question > To: Holger Rapp <holgerr...@gmx.net> > Cc: widelands-dev@lists.launchpad.net > > > any volunteer? :) > > It would be ideal if profiling could be done within some late interval, I > mean skipping like first 2 hours and then profile for 10 minutes. > > But from my random testing of backtrace (stopping of the game in random > time), it seems that "cmd_queue" is taking quite a long of time during game > near-freezes. > > Perhaps it relates to number of bobs or non-player objects. > > I googled for some fiendly profiler, but it is not that simple... > > 2014-09-10 15:35 GMT+02:00 Holger Rapp <holgerr...@gmx.net>: > >> >> On 10.09.2014, at 00:50, Tibor Bamhor <tibor...@gmail.com> wrote: >> >> > Hi, >> > >> > when working on AI I look on performance as well. >> > >> > I also encountered game sudden slow-downs when fps drops below 1 or so. >> Using printfs I found that in such situation AI is not called for few >> seconds at all. So it seems it is not a culprit. >> > >> > But my question is about other observation - the game with big map >> 512x512 - PAUSED and fps still shows ~13 fps - instead of expected 25.0. No >> movement on screen of course. So what can the game be doing so cpu >> intensive when paused? >> >> No one can tell without profiling. You need to profile. >> >> >> > >> > Regards >> > _______________________________________________ >> > Mailing list: https://launchpad.net/~widelands-dev >> > Post to : widelands-dev@lists.launchpad.net >> > Unsubscribe : https://launchpad.net/~widelands-dev >> > More help : https://help.launchpad.net/ListHelp >> >> > > _______________________________________________ > Mailing list: https://launchpad.net/~widelands-dev > Post to : widelands-dev@lists.launchpad.net > Unsubscribe : https://launchpad.net/~widelands-dev > More help : https://help.launchpad.net/ListHelp > > >
_______________________________________________ Mailing list: https://launchpad.net/~widelands-dev Post to : widelands-dev@lists.launchpad.net Unsubscribe : https://launchpad.net/~widelands-dev More help : https://help.launchpad.net/ListHelp