[erlang-questions] profiling network apps: fprof vs sequential tracing
Joel Reymont
joelr1@REDACTED
Mon Sep 20 16:32:20 CEST 2010
Here's another try...
It seems that run queue has the most collisions and so does the alcu (what's this?) allocator.
Inspecting run_queue does not reveal much, same for port_lock. Inspecting alcu_allocator is a bit more informative (see bottom of this message).
What is sl_alloc in alcu_allocator?
What else can you tell from the output below?
Thanks, Joel
---
4> lcnt:conflicts().
lock id #tries #collisions collisions [%] time [us] duration [%]
----- --- ------- ------------ --------------- ---------- -------------
run_queue 4 10487093 231528 2.2077 2938951 3.5419
alcu_allocator 26 97202142 351907 0.3620 2862881 3.4503
pix_lock 256 10015157 17007 0.1698 1354482 1.6324
pollset 1 1040351 25264 2.4284 994662 1.1987
timeofday 1 4047854 22195 0.5483 506510 0.6104
db_tab 51 7178614 2379 0.0331 141460 0.1705
timer_wheel 1 1353739 5456 0.4030 121754 0.1467
port_lock 6 174978 7006 4.0039 117303 0.1414
proc_msgq 118 2289433 4009 0.1751 69833 0.0842
proc_status 118 5119297 7218 0.1410 55563 0.0670
drv_ev_state 16 678154 576 0.0849 48590 0.0586
fix_alloc 11 4477982 15539 0.3470 36026 0.0434
proc_main 118 2193895 34621 1.5781 28330 0.0341
proc_link 118 1379852 2468 0.1789 28017 0.0338
make_ref 1 1117599 1310 0.1172 7732 0.0093
message_pre_alloc_lock 4 6024214 2838 0.0471 7478 0.0090
run_queue_sleep_list 4 3670712 152 0.0041 6047 0.0073
asyncq 4 2289643 99 0.0043 4476 0.0054
gc_info 1 495809 231 0.0466 2017 0.0024
driver_list 1 763813 126 0.0165 1243 0.0015
ok
5> lcnt:swap_pid_keys().
ok
6> lcnt:conflicts([{print, [name, tries, ratio, time]}]).
lock #tries collisions [%] time [us]
----- ------- --------------- ----------
run_queue 10487093 2.2077 2938951
alcu_allocator 97202142 0.3620 2862881
pix_lock 10015157 0.1698 1354482
pollset 1040351 2.4284 994662
timeofday 4047854 0.5483 506510
db_tab 7178614 0.0331 141460
timer_wheel 1353739 0.4030 121754
#Port<nonode@REDACTED> 171730 4.0360 117111
couch_server 1822575 0.4158 67427
couch_httpd_vhost 1661330 0.4809 53325
drv_ev_state 678154 0.0849 48590
fix_alloc 4477982 0.3470 36026
error_logger 2957617 0.8027 31324
<nonode@REDACTED> 1882295 0.4172 20830
make_ref 1117599 0.1172 7732
message_pre_alloc_lock 6024214 0.0471 7478
run_queue_sleep_list 3670712 0.0041 6047
code_server 738174 0.0646 5178
asyncq 2289643 0.0043 4476
user_drv 803014 0.0321 2586
ok
7> lcnt:conflicts([{combine, false}, {print, [name, id, tries, ratio, time]}]).
lock id #tries collisions [%] time [us]
----- --- ------- --------------- ----------
alcu_allocator sl_alloc 22038182 1.0851 1713952
run_queue 1 2634529 2.5435 1070317
pollset undefined 1040351 2.4284 994662
pix_lock 155 2745777 0.5145 830022
run_queue 2 2588360 2.2875 764836
run_queue 3 2647046 2.0890 631155
timeofday undefined 4047854 0.5483 506510
run_queue 4 2617158 1.9110 472643
alcu_allocator sl_alloc 21125298 0.2046 310092
pix_lock 159 781355 0.1273 283931
alcu_allocator binary_alloc 1731685 0.3971 127924
timer_wheel undefined 1353739 0.4030 121754
alcu_allocator binary_alloc 1722667 0.3959 117874
alcu_allocator binary_alloc 1661971 0.3650 117487
#Port<nonode@REDACTED> port_lock 171730 4.0360 117111
alcu_allocator binary_alloc 1708185 0.3724 106316
db_tab stats_hit_table 343547 0.6235 94918
alcu_allocator sl_alloc 21293832 0.0899 94616
alcu_allocator sl_alloc 20218634 0.0769 87777
alcu_allocator eheap_alloc 805310 0.5648 66938
ok
8>
10> lcnt:inspect(alcu_allocator, [{print, [name, id, tries, colls, ratio, duration]}]).
lock id #tries #collisions collisions [%] duration [%]
----- --- ------- ------------ --------------- -------------
alcu_allocator sl_alloc 22038182 239134 1.0851 2.0656
alcu_allocator sl_alloc 21125298 43221 0.2046 0.3737
alcu_allocator binary_alloc 1731685 6876 0.3971 0.1542
alcu_allocator binary_alloc 1722667 6820 0.3959 0.1421
alcu_allocator binary_alloc 1661971 6067 0.3650 0.1416
alcu_allocator binary_alloc 1708185 6362 0.3724 0.1281
alcu_allocator sl_alloc 21293832 19142 0.0899 0.1140
alcu_allocator sl_alloc 20218634 15541 0.0769 0.1058
alcu_allocator eheap_alloc 805310 4548 0.5648 0.0807
alcu_allocator eheap_alloc 468005 970 0.2073 0.0473
alcu_allocator eheap_alloc 479774 1035 0.2157 0.0412
alcu_allocator eheap_alloc 476197 949 0.1993 0.0405
alcu_allocator driver_alloc 565863 771 0.1363 0.0081
alcu_allocator driver_alloc 398542 141 0.0354 0.0019
alcu_allocator driver_alloc 380875 133 0.0349 0.0014
alcu_allocator ets_alloc 86067 20 0.0232 0.0013
alcu_allocator ets_alloc 87458 22 0.0252 0.0009
alcu_allocator driver_alloc 396137 131 0.0331 0.0007
alcu_allocator ets_alloc 85320 8 0.0094 0.0007
alcu_allocator ets_alloc 88007 12 0.0136 0.0004
ok
---
http://twitter.com/wagerlabs
More information about the erlang-questions
mailing list