8000 add profiling support by GorillaSapiens · Pull Request #2741 · cc65/cc65 · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

add profiling support #2741

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 10 commits into
base: master
Choose a base branch
from

Conversation

GorillaSapiens
Copy link
Contributor
@GorillaSapiens GorillaSapiens commented Jun 26, 2025
edited
Loading

possible alternative to #2049

to generate map file, compile with "--mapfile" and verbose map "-vm"

bin/cl65 -t sim6502 --mapfile map.txt -vm ~/profileme.c

run sim6502 with -p

bin/sim65 -p map.txt ~/profileme

output looks like this

function x0200 startup

	          clockticks ( total%) ( funcn%)
	 self :           47 (   0.0%) (   0.0%)
	child :     17915383 (  99.9%) (  99.9%)
	total :     17915430 ( 100.0%)

	       1 call  to x022d initlib
	       1 call  to x0c28 callmain
	       1 call  to x0c3f donelib
	       1 call  to x11ca zerobss

----------

function x021d initheap

	       1 call  from x022d initlib

	          clockticks ( total%) ( funcn%)
	 self :           26 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :           26 (   0.0%)

----------

function x022d initlib

	       1 call  from x0200 startup

	          clockticks ( total%) ( funcn%)
	 self :           67 (   0.0%) (  72.0%)
	child :           26 (   0.0%) (  27.9%)
	total :           93 (   0.0%)

	       1 call  to x021d initheap

----------

function x023b _bubble_sort

	       1 call  from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :      1448410 (   8.0%) (  17.7%)
	child :      6702188 (  37.4%) (  82.2%)
	total :      8150598 (  45.4%)

	   20184 calls to x0be7 tosaddax
	    5049 calls to x0c03 addeqysp
	   20184 calls to x0c20 shlax1
	    5149 calls to x0c4b decax1
	       1 call  to x0c5f decsp4
	    4950 calls to x0e7c tosgtax
	   10092 calls to x0eb0 incax1
	    2571 calls to x0ec6 incsp2
	       1 call  to x0ed9 incsp8
	   15042 calls to x0ee0 ldaxidx
	   58286 calls to x0eed ldaxysp
	    5149 calls to x0f0e tosltax
	   43046 calls to x10c1 pushax
	     100 calls to x112d staxysp
	    5142 calls to x1136 staxspidx
	    5049 calls to x1153 tossubax

----------

function x0365 _selection_sort

	       1 call  from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :       774028 (   4.3%) (  18.1%)
	child :      3489460 (  19.4%) (  81.8%)
	total :      4263488 (  23.7%)

	   10296 calls to x0be7 tosaddax
	    5049 calls to x0c03 addeqysp
	       1 call  to x0c13 addysp
	   10296 calls to x0c20 shlax1
	     100 calls to x0c4b decax1
	       1 call  to x0c79 decsp8
	      99 calls to x0eb0 incax1
	   10098 calls to x0ee0 ldaxidx
	   31510 calls to x0eed ldaxysp
	   10099 calls to x0f0e tosltax
	   20594 calls to x10c1 pushax
	     621 calls to x112d staxysp
	     198 calls to x1136 staxspidx

----------

function x0491 _insertion_sort

	       1 call  from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :       549489 (   3.0%) (  19.3%)
	child :      2290082 (  12.7%) (  80.6%)
	total :      2839571 (  15.8%)

	    8005 calls to x0be7 tosaddax
	      99 calls to x0c03 addeqysp
	       1 call  to x0c13 addysp
	    8005 calls to x0c20 shlax1
	      99 calls to x0c4b decax1
	       1 call  to x0c6c decsp6
	    2665 calls to x0e7c tosgtax
	    2670 calls to x0eb0 incax1
	    5335 calls to x0ee0 ldaxidx
	   21743 calls to x0eed ldaxysp
	     100 calls to x0f0e tosltax
	    2670 calls to x0f2b boolge
	   13441 calls to x10c1 pushax
	     199 calls to x112d staxysp
	    2670 calls to x1136 staxspidx
	    2571 calls to x1168 subeqysp

----------

function x05a1 _quick_sort

	     136 calls from x05a1 _quick_sort
	       1 call  from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :       163903 (   0.9%) (   4.4%)
	child :      3488835 (  19.4%) (  95.5%)
	total :      3652738 (  20.3%)

	     136 calls to x05a1 _quick_sort
	    2191 calls to x0be7 tosaddax
	     870 calls to x0c03 addeqysp
	     137 calls to x0c13 addysp
	    2191 calls to x0c20 shlax1
	      68 calls to x0c4b decax1
	     137 calls to x0c79 decsp8
	     137 calls to x0e72 tosgeax
	     136 calls to x0eb0 incax1
	      68 calls to x0eb7 incax2
	    1401 calls to x0ee0 ldaxidx
	    7033 calls to x0eed ldaxysp
	    1154 calls to x0f0e tosltax
	    4681 calls to x10c1 pushax
	     599 calls to x112d staxysp
	     790 calls to x1136 staxspidx

----------

function x0762 _merge

	      99 calls from x09dd _merge_sort

	          clockticks ( total%) ( funcn%)
	 self :       234583 (   1.3%) (  17.2%)
	child :      1128735 (   6.3%) (  82.7%)
	total :      1363318 (   7.6%)

	    2616 calls to x0be7 tosaddax
	    1344 calls to x0c03 addeqysp
	      99 calls to x0c13 addysp
	    3012 calls to x0c20 shlax1
	      99 calls to x0c6c decsp6
	     198 calls to x0c9b _free
	      99 calls to x0eb0 incax1
	      99 calls to x0eb7 incax2
	    1746 calls to x0ee0 ldaxidx
	    9635 calls to x0eed ldaxysp
	     537 calls to x0ef8 tosleax
	    1558 calls to x0f0e tosltax
	     198 calls to x0f40 _malloc
	     198 calls to x1050 _memcpy
	    6472 calls to x10c1 pushax
	     297 calls to x112d staxysp
	     672 calls to x1136 staxspidx
	     198 calls to x1153 tossubax

----------

function x09dd _merge_sort

	     198 calls from x09dd _merge_sort
	       1 call  from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :        33025 (   0.1%) (   0.4%)
	child :      7076398 (  39.4%) (  99.5%)
	total :      7109423 (  39.6%)

	      99 calls to x0762 _merge
	     198 calls to x09dd _merge_sort
	      99 calls to x0be7 tosaddax
	     199 calls to x0c52 decsp2
	      99 calls to x0c88 tosdivax
	     199 calls to x0e72 tosgeax
	      99 calls to x0eb0 incax1
	     199 calls to x0ed9 incsp8
	    1685 calls to x0eed ldaxysp
	    1388 calls to x10c1 pushax
	      99 calls to x112d staxysp
	      99 calls to x1153 tossubax

----------

function x0a7c _fill_random

	       1 call  from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :        11870 (   0.0%) (   8.2%)
	child :       131248 (   0.7%) (  91.7%)
	total :       143118 (   0.7%)

	     100 calls to x0be7 tosaddax
	     100 calls to x0c03 addeqysp
	     100 calls to x0c20 shlax1
	       1 call  to x0c52 decsp2
	       1 call  to x0ed4 incsp6
	     402 calls to x0eed ldaxysp
	     101 calls to x0f0e tosltax
	     100 calls to x108e tosmodax
	     402 calls to x10c1 pushax
	     100 calls to x10e3 _rand
	       1 call  to x112d staxysp
	     100 calls to x1136 staxspidx

----------

function x0adb _copy_array

	       5 calls from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :          330 (   0.0%) (   1.5%)
	child :        20840 (   0.1%) (  98.4%)
	total :        21170 (   0.1%)

	       5 calls to x0c20 shlax1
	       5 calls to x0ed4 incsp6
	      15 calls to x0eed ldaxysp
	       5 calls to x1050 _memcpy
	      15 calls to x10c1 pushax

----------

function x0be7 tosaddax

	   20184 calls from x023b _bubble_sort
	   10296 calls from x0365 _selection_sort
	    8005 calls from x0491 _insertion_sort
	    2191 calls from x05a1 _quick_sort
	    2616 calls from x0762 _merge
	      99 calls from x09dd _merge_sort
	     100 calls from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :      1957311 (  10.9%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :      1957311 (  10.9%)

----------

function x0c03 addeqysp

	    5049 calls from x023b _bubble_sort
	    5049 calls from x0365 _selection_sort
	      99 calls from x0491 _insertion_sort
	     870 calls from x05a1 _quick_sort
	    1344 calls from x0762 _merge
	     100 calls from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :       538573 (   3.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       538573 (   3.0%)

----------

function x0c13 addysp

	       1 call  from x0365 _selection_sort
	       1 call  from x0491 _insertion_sort
	     137 calls from x05a1 _quick_sort
	      99 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :         6332 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         6332 (   0.0%)

----------

function x0c20 shlax1

	   20184 calls from x023b _bubble_sort
	   10296 calls from x0365 _selection_sort
	    8005 calls from x0491 _insertion_sort
	    2191 calls from x05a1 _quick_sort
	    3012 calls from x0762 _merge
	     100 calls from x0a7c _fill_random
	       5 calls from x0adb _copy_array

	          clockticks ( total%) ( funcn%)
	 self :       832067 (   4.6%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       832067 (   4.6%)

----------

function x0c28 callmain

	       1 call  from x0200 startup

	          clockticks ( total%) ( funcn%)
	 self :          405 (   0.0%) (   0.0%)
	child :     17914844 (  99.9%) (  99.9%)
	total :     17915249 (  99.9%)

	       1 call  to x023b _bubble_sort
	       1 call  to x0365 _selection_sort
	       1 call  to x0491 _insertion_sort
	       1 call  to x05a1 _quick_sort
	       1 call  to x09dd _merge_sort
	       1 call  to x0a7c _fill_random
	       5 calls to x0adb _copy_array
	       6 calls to x0efe leaa0sp
	      20 calls to x10c1 pushax

----------

function x0c3f donelib

	       1 call  from x0200 startup

	          clockticks ( total%) ( funcn%)
	 self :           11 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :           11 (   0.0%)

----------

function x0c4b decax1

	    5149 calls from x023b _bubble_sort
	     100 calls from x0365 _selection_sort
	      99 calls from x0491 _insertion_sort
	      68 calls from x05a1 _quick_sort

	          clockticks ( total%) ( funcn%)
	 self :        70416 (   0.3%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :        70416 (   0.3%)

----------

function x0c52 decsp2

	     199 calls from x09dd _merge_sort
	       1 call  from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :         3600 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         3600 (   0.0%)

----------

function x0c5f decsp4

	       1 call  from x023b _bubble_sort

	          clockticks ( total%) ( funcn%)
	 self :           18 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :           18 (   0.0%)

----------

function x0c6c decsp6

	       1 call  from x0491 _insertion_sort
	      99 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :         1848 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         1848 (   0.0%)

----------

function x0c79 decsp8

	       1 call  from x0365 _selection_sort
	     137 calls from x05a1 _quick_sort

	          clockticks ( total%) ( funcn%)
	 self :         2484 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         2484 (   0.0%)

----------

function x0c88 tosdivax

	      99 calls from x09dd _merge_sort

	          clockticks ( total%) ( funcn%)
	 self :         2673 (   0.0%) (   5.1%)
	child :        49487 (   0.2%) (  94.8%)
	total :        52160 (   0.2%)

	      99 calls to x110b popsargsudiv16

----------

function x0c9b _free

	     198 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :        39600 (   0.2%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :        39600 (   0.2%)

----------

function x0e72 tosgeax

	     137 calls from x05a1 _quick_sort
	     199 calls from x09dd _merge_sort

	          clockticks ( total%) ( funcn%)
	 self :         7225 (   0.0%) (  27.4%)
	child :        19092 (   0.1%) (  72.5%)
	total :        26317 (   0.1%)

	     336 calls to x0e84 tosicmp

----------

function x0e7c tosgtax

	    4950 calls from x023b _bubble_sort
	    2665 calls from x0491 _insertion_sort

	          clockticks ( total%) ( funcn%)
	 self :       180287 (   1.0%) (  30.5%)
	child :       410210 (   2.2%) (  69.4%)
	total :       590497 (   3.2%)

	    7615 calls to x0e84 tosicmp

----------

function x0e84 tosicmp

	     336 calls from x0e72 tosgeax
	    7615 calls from x0e7c tosgtax
	     537 calls from x0ef8 tosleax
	   18161 calls from x0f0e tosltax

	          clockticks ( total%) ( funcn%)
	 self :      1484050 (   8.2%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :      1484050 (   8.2%)

----------

function x0eb0 incax1

	   10092 calls from x023b _bubble_sort
	      99 calls from x0365 _selection_sort
	    2670 calls from x0491 _insertion_sort
	     136 calls from x05a1 _quick_sort
	      99 calls from x0762 _merge
	      99 calls from x09dd _merge_sort

	          clockticks ( total%) ( funcn%)
	 self :       171540 (   0.9%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       171540 (   0.9%)

----------

function x0eb7 incax2

	      68 calls from x05a1 _quick_sort
	      99 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :         2171 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         2171 (   0.0%)

----------

function x0ebe popax

	     199 calls from x110b popsargsudiv16

	          clockticks ( total%) ( funcn%)
	 self :         7164 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         7164 (   0.0%)

----------

function x0ec6 incsp2

	    2571 calls from x023b _bubble_sort

	          clockticks ( total%) ( funcn%)
	 self :        51420 (   0.2%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :        51420 (   0.2%)

----------

function x0ed4 incsp6

	       1 call  from x0a7c _fill_random
	       5 calls from x0adb _copy_array

	          clockticks ( total%) ( funcn%)
	 self :          186 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :          186 (   0.0%)

----------

function x0ed9 incsp8

	       1 call  from x023b _bubble_sort
	     199 calls from x09dd _merge_sort

	          clockticks ( total%) ( funcn%)
	 self :         6328 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         6328 (   0.0%)

----------

function x0ee0 ldaxidx

	   15042 calls from x023b _bubble_sort
	   10098 calls from x0365 _selection_sort
	    5335 calls from x0491 _insertion_sort
	    1401 calls from x05a1 _quick_sort
	    1746 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :       874172 (   4.8%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       874172 (   4.8%)

----------

function x0eed ldaxysp

	   58286 calls from x023b _bubble_sort
	   31510 calls from x0365 _selection_sort
	   21743 calls from x0491 _insertion_sort
	    7033 calls from x05a1 _quick_sort
	    9635 calls from x0762 _merge
	    1685 calls from x09dd _merge_sort
	     402 calls from x0a7c _fill_random
	      15 calls from x0adb _copy_array

	          clockticks ( total%) ( funcn%)
	 self :      2611294 (  14.5%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :      2611294 (  14.5%)

----------

function x0ef8 tosleax

	     537 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :        12628 (   0.0%) (  30.3%)
	child :        28976 (   0.1%) (  69.6%)
	total :        41604 (   0.2%)

	     537 calls to x0e84 tosicmp

----------

function x0efe leaa0sp

	       6 calls from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :          162 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :          162 (   0.0%)

----------

function x0f0e tosltax

	    5149 calls from x023b _bubble_sort
	   10099 calls from x0365 _selection_sort
	     100 calls from x0491 _insertion_sort
	    1154 calls from x05a1 _quick_sort
	    1558 calls from x0762 _merge
	     101 calls from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :       394132 (   2.1%) (  27.7%)
	child :      1025772 (   5.7%) (  72.2%)
	total :      1419904 (   7.9%)

	   18161 calls to x0e84 tosicmp

----------

function x0f2b boolge

	    2670 calls from x0491 _insertion_sort

	          clockticks ( total%) ( funcn%)
	 self :        34705 (   0.1%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :        34705 (   0.1%)

----------

function x0f40 _malloc

	     198 calls from x0762 _merge

	          clockticks ( total%) ( funcn%)
	 self :        34852 (   0.1%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :        34852 (   0.1%)

----------

function x1050 _memcpy

	     198 calls from x0762 _merge
	       5 calls from x0adb _copy_array

	          clockticks ( total%) ( funcn%)
	 self :        54297 (   0.3%) (  76.3%)
	child :        16849 (   0.0%) (  23.6%)
	total :        71146 (   0.3%)

	     203 calls to x1079 memcpy_getparams

----------

function x1079 memcpy_getparams

	     203 calls from x1050 _memcpy

	          clockticks ( total%) ( funcn%)
	 self :         8120 (   0.0%) (  48.1%)
	child :         8729 (   0.0%) (  51.8%)
	total :        16849 (   0.0%)

	     203 calls to x10af popptr1

----------

function x108e tosmodax

	     100 calls from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :         2400 (   0.0%) (   3.2%)
	child :        71066 (   0.3%) (  96.7%)
	total :        73466 (   0.4%)

	     100 calls to x110b popsargsudiv16

----------

function x10af popptr1

	     203 calls from x1079 memcpy_getparams

	          clockticks ( total%) ( funcn%)
	 self :         8729 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         8729 (   0.0%)

----------

function x10c1 pushax

	   43046 calls from x023b _bubble_sort
	   20594 calls from x0365 _selection_sort
	   13441 calls from x0491 _insertion_sort
	    4681 calls from x05a1 _quick_sort
	    6472 calls from x0762 _merge
	    1388 calls from x09dd _merge_sort
	     402 calls from x0a7c _fill_random
	      15 calls from x0adb _copy_array
	      20 calls from x0c28 callmain

	          clockticks ( total%) ( funcn%)
	 self :      3963052 (  22.1%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :      3963052 (  22.1%)

----------

function x10e3 _rand

	     100 calls from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :         5800 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :         5800 (   0.0%)

----------

function x110b popsargsudiv16

	      99 calls from x0c88 tosdivax
	     100 calls from x108e tosmodax

	          clockticks ( total%) ( funcn%)
	 self :       113389 (   0.6%) (  94.0%)
	child :         7164 (   0.0%) (   5.9%)
	total :       120553 (   0.6%)

	     199 calls to x0ebe popax

----------

function x112d staxysp

	     100 calls from x023b _bubble_sort
	     621 calls from x0365 _selection_sort
	     199 calls from x0491 _insertion_sort
	     599 calls from x05a1 _quick_sort
	     297 calls from x0762 _merge
	      99 calls from x09dd _merge_sort
	       1 call  from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :        55564 (   0.3%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :        55564 (   0.3%)

----------

function x1136 staxspidx

	    5142 calls from x023b _bubble_sort
	     198 calls from x0365 _selection_sort
	    2670 calls from x0491 _insertion_sort
	     790 calls from x05a1 _quick_sort
	     672 calls from x0762 _merge
	     100 calls from x0a7c _fill_random

	          clockticks ( total%) ( funcn%)
	 self :       708328 (   3.9%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       708328 (   3.9%)

----------

function x1153 tossubax

	    5049 calls from x023b _bubble_sort
	     198 calls from x0762 _merge
	      99 calls from x09dd _merge_sort

	          clockticks ( total%) ( funcn%)
	 self :       331452 (   1.8%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       331452 (   1.8%)

----------

function x1168 subeqysp

	    2571 calls from x0491 _insertion_sort

	          clockticks ( total%) ( funcn%)
	 self :       120837 (   0.6%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :       120837 (   0.6%)

----------

function x11ca zerobss

	       1 call  from x0200 startup

	          clockticks ( total%) ( funcn%)
	 self :           30 (   0.0%) ( 100.0%)
	child :            0 (   0.0%) (   0.0%)
	total :           30 (   0.0%)

@GorillaSapiens
Copy link
Contributor Author
GorillaSapiens commented Jun 26, 2025

sample code i used for testing.
https://gist.github.com/GorillaSapiens/708029ad3e93d8574d7af4f8e02076f8

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants
0