From randy@stat.tamu.edu Sat Mar 18 14:27:35 1995 >From randy@stat.tamu.edu Sat Mar 18 14:27:35 1995 Received: from picard.tamu.edu (PICARD.TAMU.EDU [165.91.112.177]) by linc.cis.upenn.edu (8.6.10/UPenn 1.4) with SMTP id OAA16368 for ; Sat, 18 Mar 1995 14:27:34 -0500 Posted-Date: Sat, 18 Mar 1995 14:27:34 -0500 Received-Date: Sat, 18 Mar 1995 14:27:34 -0500 Received: by picard.tamu.edu (AA09722); Sat, 18 Mar 95 13:26:06 CST Date: Sat, 18 Mar 95 13:26:06 CST From: randy@PICARD.tamu.edu (Randy Hutson) Message-Id: <9503181926.AA09722@picard.tamu.edu> To: benh@linc.cis.upenn.edu Subject: Profiling results Status: R OK, I profiled Angband 2.7.4-B with 3 setups: 1) Same situation as last profile: moving back and forth below an orc pit with pre-compute viewable region on. 2) Same as above, but with pre-compute viewable region off. 3) "Actual" play for about 20 minutes with both of the new monster flow options on. For all profiles, I've only included actual game functions and not system functions (read(), write(), etc.) I've also only listed the functions which accounted for at least 1% of the CPU time. 1) Below orc pit just moving back and forth for 1000 turns pre-compute on; no ESP; no monster flow % time seconds cumsec calls function 14.09 3.05 3.05 1810715 floor_grid 13.08 2.83 5.88 9799 process_monsters 9.57 2.07 7.95 74994 make_move 6.01 1.30 9.25 589008 update_view_aux 5.08 1.10 10.35 362643 mmove 3.70 0.80 11.15 122168 update_mon 3.37 0.73 11.88 123845 map_info 3.19 0.69 12.57 1002 update_view 3.10 0.67 13.24 290456 player_has_los 2.82 0.61 13.85 74994 mon_move 2.59 0.56 14.41 122838 map_info_aux 2.03 0.44 14.85 74587 mon_will_run 1.76 0.38 15.23 123845 QueueAttrChar 1.76 0.38 15.61 74587 get_moves 1.62 0.35 15.96 123845 mh_print 1.57 0.34 16.30 157578 update_map 1.48 0.32 16.62 124832 random_hack 1.34 0.29 16.91 232058 flavor_p 1.16 0.25 17.16 157578 lite_spot 1.02 0.22 17.38 123845 mh_print_rel Total CPU time used by game code: 21.64 seconds 2) Below orc pit just moving back and forth for 1000 turns pre-compute off; no ESP; no monster flow % time seconds cumsec calls function 14.62 3.79 3.79 9802 process_monsters 10.49 2.72 6.51 1437755 floor_grid 9.33 2.42 8.93 75015 make_move 6.90 1.79 10.72 282367 los 4.59 1.19 11.91 1266265 cave_seen_room_aux 4.20 1.09 13.00 128713 update_mon 3.78 0.98 13.98 298794 player_has_los 3.59 0.93 14.91 363051 mmove 2.43 0.63 15.54 457556 distance 2.43 0.63 16.17 123023 map_info 2.31 0.60 16.77 122019 map_info_aux 2.20 0.57 17.34 1001 check_view 2.12 0.55 17.89 123023 QueueAttrChar 2.08 0.54 18.43 75015 mon_move 2.01 0.52 18.95 74630 mon_will_run 1.77 0.46 19.41 74630 get_moves 1.74 0.45 19.86 123023 mh_print 1.70 0.44 20.30 115187 inven_char 1.58 0.41 20.71 133356 random_hack 1.47 0.38 21.09 305290 cave_seen_add 1.43 0.37 21.46 163500 lite_spot 1.39 0.36 21.82 1001 cave_seen_room_init 1.16 0.30 22.12 230408 inven_aware_p Total CPU time used by game code: 25.93 seconds 3) "real" playing for about 20 minutes (4179 moves) There weren't many monsters on the level - the level had already been cleared out. I just kept circling the level and killing whatever moved! Note that process_monsters uses much less CPU time in this case. pre-compute on, monster flow on, ESP % time seconds cumsec calls function 24.07 14.00 14.00 8361707 update_flow_aux 12.96 7.54 21.54 4373049 floor_grid 11.17 6.50 28.04 3563 update_flow 7.91 4.60 32.64 1884039 update_view_aux 4.37 2.54 35.18 3563 update_view 3.49 2.03 37.21 31690 FlushOutputRow 2.25 1.31 38.52 21675 process_monsters 2.23 1.30 39.82 9381 EraseScreen 2.05 1.19 41.01 304619 map_info 2.01 1.17 42.18 300956 map_info_aux 1.86 1.08 43.26 282680 QueueAttrChar 1.38 0.80 44.06 460721 cave_seen_add 1.29 0.75 44.81 1 dungeon 1.27 0.74 45.55 326744 cave_view 1.07 0.62 46.17 3563 cave_seen_grab_view 1.03 0.60 46.77 279360 mh_print Total CPU time used by game code: 58.17 seconds Conclusions: I think the previous problem of the game bogging down when a level contained many monsters has been satisfactorily resolved. floor_grid() should obviously be made as fast as possible. However, I don't see much potential for optimization there, so I suppose the goal should be to reduce the number of calls to it (if possible). The monster flow code is now using at least 35% of the CPU time! (I do like it though.) Randy