[erlang-questions] profiling network apps: fprof vs sequential tracing

Joel Reymont <>
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<>   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
      <>  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<>       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