Skip to content
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

[profiler] Enhancment: panic on wrong timer usage #1483

Merged
merged 1 commit into from
Jan 9, 2025

Conversation

anandbonde
Copy link
Contributor

Nesting async_timer!() within a timer!() scope causes reparenting issues in the profiler. To avoid such invalid uses in future, changing to panic if this happens. Also, removed all timers that violated this invariant.

@anandbonde anandbonde requested a review from iyzhang January 7, 2025 18:07
@anandbonde anandbonde self-assigned this Jan 7, 2025
Copy link

github-actions bot commented Jan 7, 2025

libos = catpowder
commit id = cf7e7b7

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once 19426961 695 280 11835250584 46 11829916157 85
bgc::inetstack::poll 9713480 1594 643 13771828382 53 1936577798 14
demikernel::new 1 100145416 40042492 100145416 0 100145416 1
ioc::network::libos::push 16145 3145 1282 48127768 0 48127768 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11049 420 168 5789586 0 5789586 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 5285 2613 1021 5424841 0 5422314 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11060 550 226 3822574 0 3822574 0
ioc::network::libos::pop 9029 518 212 3388868 0 3388868 0
bgc::inetstack::tcp::established::background 11060 1787 714 13747750 0 3242998 0
ioc::network::libos::pushto 679 4437 1846 3018261 0 3018261 0
ioc::network::libos::connect 42 46382 19074 1669430 0 1669430 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11007 978 375 892593 0 892593 0
demikernel::sgaalloc 6504 186 76 822819 0 822819 0
demikernel::sgafree 8749 119 49 772195 0 772195 0
bgc::inetstack::tcp::passiveopen::background 42 35687 14133 564599 0 564599 0
ioc::network::libos::close 48 6339 2570 273603 0 273603 0
ioc::network::libos::accept 39 2248 891 52183 0 52183 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 206 237 102 49696 0 49696 0
demikernel::bind 1 28700 11195 28700 0 28700 0
bgc::inetstack::arp::background 7 2348 938 17887 0 17887 0
demikernel::socket 10 2165 878 8945 0 8945 0
demikernel::listen 1 4339 1721 4339 0 4339 0
bgc::inetstack::icmp::background 1 3392 1362 3537 0 3537 0

Copy link

github-actions bot commented Jan 7, 2025

libos = catnip
commit id = cf7e7b7

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once;catnip::runtime::receive 29121201 203 83 5804383882 19 5804383882 40
bgc::inetstack::poll;inetstack::layer4::poll_once 29121201 362 148 9917887304 33 4109237316 28
bgc::inetstack::poll 14560601 925 379 12787287510 42 2869400206 20
demikernel::new 1 1762606774 720710242 1762606774 6 1762606774 12
ioc::network::libos::push 16145 1220 509 17272839 0 15020374 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11050 353 145 4914102 0 4913585 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 4541 2033 827 4338413 0 4320952 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11062 345 142 3019371 0 3016840 0
bgc::inetstack::tcp::established::background 11062 1146 469 11513002 0 2883769 0
ioc::network::libos::pop 9047 377 156 2762570 0 2762570 0
ioc::network::libos::push;catnip::runtime::transmit 8763 341 143 2445533 0 2445533 0
ioc::network::libos::pushto 1265 1269 544 1603008 0 1265908 0
ioc::network::libos::connect 42 31135 12787 1096658 0 1037276 0
demikernel::sgafree 8782 104 43 700897 0 700897 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11008 308 121 695760 0 685233 0
demikernel::sgaalloc 6539 165 69 677882 0 677882 0
ioc::network::libos::pushto;catnip::runtime::transmit 1265 267 114 337100 0 337100 0
bgc::inetstack::tcp::passiveopen::background 42 33687 13667 385675 0 330574 0
ioc::network::libos::close 50 6122 2493 279211 0 279211 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 542 234 100 134443 0 134443 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6832 2808 59381 0 59381 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 16967 6815 55101 0 55101 0
ioc::network::libos::accept 38 2043 835 45918 0 45918 0
bgc::inetstack::arp::background 7 2287 939 21985 0 21985 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 21 1306 548 20245 0 20245 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 23 622 253 11194 0 11194 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 580 237 10528 0 10528 0
demikernel::bind 1 10477 4331 10477 0 10477 0
demikernel::socket 10 2344 973 7594 0 7594 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 7 946 398 4139 0 4139 0
bgc::inetstack::icmp::background 1 2972 1214 3142 0 3142 0
demikernel::listen 1 2682 1097 2682 0 2682 0

@iyzhang iyzhang self-requested a review January 7, 2025 20:08
Copy link
Contributor

@iyzhang iyzhang left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

looks good

@anandbonde anandbonde force-pushed the ab-profiler-reduce-timers branch from cf7e7b7 to c1a7295 Compare January 7, 2025 22:16
Copy link

github-actions bot commented Jan 7, 2025

libos = catpowder
commit id = c1a7295

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once 19632971 677 275 11975107212 46 11969504340 85
bgc::inetstack::poll 9816485 1557 633 13892283318 53 1917176106 14
demikernel::new 1 99682891 40429347 99682891 0 99682891 1
ioc::network::libos::push 16145 3168 1337 48451168 0 48451168 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11058 413 168 5951753 0 5951753 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 5287 2488 980 5697836 0 5695814 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11068 508 201 3949947 0 3949947 0
ioc::network::libos::pop 9030 507 208 3489350 0 3489350 0
bgc::inetstack::tcp::established::background 11068 1713 683 14141747 0 3326789 0
ioc::network::libos::pushto 660 4687 1897 3170972 0 3170972 0
ioc::network::libos::connect 42 42981 17971 1707668 0 1707668 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11016 906 349 913259 0 913259 0
demikernel::sgaalloc 6502 205 86 907538 0 907538 0
demikernel::sgafree 8747 130 53 826588 0 826588 0
bgc::inetstack::tcp::passiveopen::background 42 33020 13517 482748 0 482748 0
ioc::network::libos::close 47 6587 2711 275494 0 275494 0
ioc::network::libos::accept 38 2130 868 50717 0 50717 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 195 218 90 39769 0 39769 0
demikernel::bind 1 26574 10518 26574 0 26574 0
bgc::inetstack::arp::background 7 2144 869 11485 0 11485 0
demikernel::socket 10 1926 778 7109 0 7109 0
bgc::inetstack::icmp::background 1 3236 1316 3349 0 3349 0
demikernel::listen 1 3293 1324 3293 0 3293 0

Copy link

github-actions bot commented Jan 7, 2025

libos = catnip
commit id = c1a7295

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once;catnip::runtime::receive 28742139 204 81 5846887519 19 5846887519 40
bgc::inetstack::poll;inetstack::layer4::poll_once 28742139 364 145 9944761541 33 4093595846 28
bgc::inetstack::poll 14371069 928 370 12744896533 42 2800134992 19
demikernel::new 1 1779024653 708072485 1779024653 6 1779024653 12
ioc::network::libos::push 16145 1217 493 17487719 0 15145588 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11055 352 140 4818254 0 4817540 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 4555 1810 714 4350688 0 4332931 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11066 324 129 3018714 0 3016503 0
bgc::inetstack::tcp::established::background 11066 1128 449 11425650 0 2888892 0
ioc::network::libos::pop 9046 381 152 2741986 0 2741986 0
ioc::network::libos::push;catnip::runtime::transmit 8763 352 144 2542885 0 2542885 0
ioc::network::libos::pushto 1228 1269 520 1567383 0 1233599 0
ioc::network::libos::connect 42 32253 13233 1202192 0 1142943 0
demikernel::sgafree 8780 97 39 698537 0 698537 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11013 310 120 699789 0 689113 0
demikernel::sgaalloc 6536 141 58 651595 0 651595 0
bgc::inetstack::tcp::passiveopen::background 42 34942 13801 393108 0 336772 0
ioc::network::libos::pushto;catnip::runtime::transmit 1228 270 111 333784 0 333784 0
ioc::network::libos::close 49 5772 2336 263810 0 263810 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 535 239 95 124497 0 124497 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6182 2548 59250 0 59250 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 19031 7530 56336 0 56336 0
ioc::network::libos::accept 38 2138 843 47766 0 47766 0
bgc::inetstack::arp::background 7 2454 967 22837 0 22837 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 13 1519 613 15482 0 15482 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 24 691 275 12038 0 12038 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 612 246 10676 0 10676 0
demikernel::bind 1 9879 3863 9879 0 9879 0
demikernel::socket 10 1900 753 7134 0 7134 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 15 399 161 5714 0 5714 0
demikernel::listen 1 3179 1238 3179 0 3179 0
bgc::inetstack::icmp::background 1 3011 1204 3179 0 3179 0

@anandbonde anandbonde force-pushed the ab-profiler-reduce-timers branch from c1a7295 to d8ca288 Compare January 8, 2025 15:22
Copy link

github-actions bot commented Jan 8, 2025

libos = catpowder
commit id = d8ca288

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once 19671590 695 279 11968441085 46 11963188780 85
bgc::inetstack::poll 9835795 1593 639 13876177663 53 1907736579 14
demikernel::new 1 98386569 39267326 98386569 0 98386569 1
ioc::network::libos::push 16145 2994 1233 46443485 0 46443485 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11050 417 167 5746440 0 5746440 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 5283 2406 939 5341327 0 5339166 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11060 497 195 3791817 0 3791817 0
bgc::inetstack::tcp::established::background 11060 1777 700 13693792 0 3256464 0
ioc::network::libos::pop 9030 434 173 3242967 0 3242967 0
ioc::network::libos::pushto 661 4354 1841 2872973 0 2872973 0
ioc::network::libos::connect 42 38713 15658 1492292 0 1492292 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11008 1041 401 899070 0 899070 0
demikernel::sgaalloc 6501 169 70 852121 0 852121 0
demikernel::sgafree 8748 128 52 795340 0 795340 0
bgc::inetstack::tcp::passiveopen::background 42 32853 13081 464209 0 464209 0
ioc::network::libos::close 47 6379 2577 287980 0 287980 0
ioc::network::libos::accept 38 2172 861 51856 0 51856 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 193 244 104 42509 0 42509 0
demikernel::bind 1 24973 9754 24973 0 24973 0
bgc::inetstack::arp::background 7 2058 824 17451 0 17451 0
demikernel::socket 10 2080 826 7795 0 7795 0
demikernel::listen 1 3911 1531 3911 0 3911 0
bgc::inetstack::icmp::background 1 3270 1305 3428 0 3428 0

Copy link

github-actions bot commented Jan 8, 2025

libos = catnip
commit id = d8ca288

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once;catnip::runtime::receive 28919745 207 83 5790592128 19 5790592128 40
bgc::inetstack::poll;inetstack::layer4::poll_once 28919745 368 147 9968914205 33 4173908289 29
bgc::inetstack::poll 14459873 938 376 12776803597 42 2807889392 19
demikernel::new 1 1778805412 711381819 1778805412 6 1778805412 12
ioc::network::libos::push 16145 1206 492 16905168 0 14695078 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11052 371 149 4937881 0 4937217 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 4531 2510 981 4488598 0 4469967 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11064 330 133 3023018 0 3020843 0
bgc::inetstack::tcp::established::background 11064 1162 464 11528432 0 2870588 0
ioc::network::libos::pop 9045 372 149 2675396 0 2675396 0
ioc::network::libos::push;catnip::runtime::transmit 8763 357 147 2399526 0 2399526 0
ioc::network::libos::pushto 1174 1549 660 1789850 0 1398898 0
ioc::network::libos::connect 42 34689 14284 1217849 0 1156851 0
demikernel::sgaalloc 6532 191 79 763254 0 763254 0
demikernel::sgafree 8777 99 40 694640 0 694640 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11010 327 127 696945 0 685116 0
ioc::network::libos::pushto;catnip::runtime::transmit 1174 340 145 390952 0 390952 0
bgc::inetstack::tcp::passiveopen::background 42 35219 13778 425549 0 368915 0
ioc::network::libos::close 49 5806 2351 267450 0 267450 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 504 317 133 138138 0 138138 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6985 2892 60998 0 60998 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 17591 6871 56634 0 56634 0
ioc::network::libos::accept 38 2157 848 49021 0 49021 0
bgc::inetstack::arp::background 7 3148 1259 23167 0 23167 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 19 1076 442 17395 0 17395 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 23 697 278 12229 0 12229 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 624 250 11829 0 11829 0
demikernel::bind 1 9683 3827 9683 0 9683 0
demikernel::socket 10 2054 830 7830 0 7830 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 9 635 263 4649 0 4649 0
demikernel::listen 1 3971 1565 3971 0 3971 0
bgc::inetstack::icmp::background 1 3147 1258 3348 0 3348 0

@anandbonde anandbonde force-pushed the ab-profiler-reduce-timers branch from d8ca288 to 392c694 Compare January 8, 2025 19:12
Copy link

github-actions bot commented Jan 8, 2025

libos = catpowder
commit id = 392c694

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once 19542303 706 290 11877102869 46 11867995153 85
bgc::inetstack::poll 9771151 1615 662 13774003407 53 1896900538 14
demikernel::new 1 100287702 40693049 100287702 0 100287702 1
ioc::network::libos::push 16145 3002 1273 45902150 0 45902150 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 6160 2614 1075 9262085 0 9259076 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11949 394 161 5512564 0 5512564 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11959 523 217 3762263 0 3762263 0
ioc::network::libos::pushto 797 4261 1899 3409257 0 3409257 0
bgc::inetstack::tcp::established::background 11959 1689 688 13550003 0 3371439 0
ioc::network::libos::pop 9125 421 170 3085564 0 3085564 0
ioc::network::libos::connect 42 42224 17700 1661106 0 1661106 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11906 892 353 903738 0 903738 0
demikernel::sgaalloc 6511 147 64 826981 0 826981 0
demikernel::sgafree 8755 116 48 802036 0 802036 0
bgc::inetstack::tcp::passiveopen::background 42 30318 12059 431692 0 431692 0
ioc::network::libos::close 47 6204 2573 274890 0 274890 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 267 230 96 59169 0 59169 0
ioc::network::libos::accept 38 2119 849 48429 0 48429 0
demikernel::bind 1 25559 10387 25559 0 25559 0
bgc::inetstack::arp::background 7 2119 862 13594 0 13594 0
demikernel::socket 10 2746 1121 8126 0 8126 0
bgc::inetstack::icmp::background 1 3341 1358 3472 0 3472 0
demikernel::listen 1 3097 1230 3097 0 3097 0

Copy link

github-actions bot commented Jan 8, 2025

libos = catnip
commit id = 392c694

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once;catnip::runtime::receive 29159521 203 81 5837573450 19 5837573450 40
bgc::inetstack::poll;inetstack::layer4::poll_once 29159521 362 145 9954996209 33 4112874720 28
bgc::inetstack::poll 14579761 926 370 12791151575 42 2836155366 19
demikernel::new 1 1774568269 708648023 1774568269 6 1774568269 12
ioc::network::libos::push 16145 1153 466 16819074 0 14613017 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11246 359 143 4960399 0 4959899 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 4659 2014 789 4625124 0 4539310 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11257 329 130 3031949 0 3029617 0
bgc::inetstack::tcp::established::background 11257 1140 452 11620862 0 2922537 0
ioc::network::libos::pop 9152 381 152 2651628 0 2651628 0
ioc::network::libos::push;catnip::runtime::transmit 8763 310 126 2395147 0 2395147 0
ioc::network::libos::pushto 1287 1257 528 1629011 0 1282064 0
ioc::network::libos::connect 42 35297 14409 1168773 0 1109660 0
demikernel::sgaalloc 6539 183 75 732091 0 732091 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11203 315 123 705977 0 694255 0
demikernel::sgafree 8783 94 38 693134 0 693134 0
ioc::network::libos::pushto;catnip::runtime::transmit 1287 269 113 346947 0 346947 0
bgc::inetstack::tcp::passiveopen::background 42 35050 13951 392679 0 336034 0
ioc::network::libos::close 50 5683 2301 264237 0 264237 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 557 252 107 158292 0 158292 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 216 732 292 81931 0 81931 0
ioc::network::libos::connect;catnip::runtime::transmit 42 7009 2854 59114 0 59114 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 18522 7408 56645 0 56645 0
ioc::network::libos::accept 38 2110 838 46763 0 46763 0
bgc::inetstack::arp::background 7 2393 952 24030 0 24030 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 18 1351 536 18661 0 18661 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 612 244 11722 0 11722 0
demikernel::bind 1 10944 4310 10944 0 10944 0
demikernel::socket 10 1943 774 7500 0 7500 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 12 409 167 3994 0 3994 0
demikernel::listen 1 3984 1576 3984 0 3984 0
bgc::inetstack::icmp::background 1 3085 1231 3263 0 3263 0

@anandbonde anandbonde force-pushed the ab-profiler-reduce-timers branch from 392c694 to a249178 Compare January 8, 2025 20:33
Copy link

github-actions bot commented Jan 8, 2025

libos = catpowder
commit id = a249178

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once 19665973 682 274 12025501923 46 12019473708 85
bgc::inetstack::poll 9832986 1567 629 13935267971 53 1909766048 14
demikernel::new 1 97333719 39002700 97333719 0 97333719 1
ioc::network::libos::push 16145 3092 1278 47658818 0 47658818 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 5428 2331 916 6130388 0 6128516 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11194 418 168 5727599 0 5727599 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11205 547 215 3716648 0 3716648 0
bgc::inetstack::tcp::established::background 11205 1734 686 13717437 0 3354590 0
ioc::network::libos::pop 9092 481 195 3269283 0 3269283 0
ioc::network::libos::pushto 591 4786 1884 2813419 0 2813419 0
ioc::network::libos::connect 42 40576 16561 1600763 0 1600763 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11151 887 343 918600 0 918600 0
demikernel::sgaalloc 6495 159 65 863719 0 863719 0
demikernel::sgafree 8744 121 49 794340 0 794340 0
bgc::inetstack::tcp::passiveopen::background 42 31951 13073 445885 0 445885 0
ioc::network::libos::close 47 6520 2622 288372 0 288372 0
ioc::network::libos::accept 38 2113 861 50360 0 50360 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 178 223 87 36821 0 36821 0
demikernel::bind 1 27214 10692 27214 0 27214 0
demikernel::socket 10 2535 1031 24178 0 24178 0
bgc::inetstack::arp::background 7 2205 886 9972 0 9972 0
demikernel::listen 1 3660 1478 3660 0 3660 0
bgc::inetstack::icmp::background 1 3107 1246 3233 0 3233 0

Copy link

github-actions bot commented Jan 8, 2025

libos = catnap
commit id = a249178

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::catnap::transport::epoll 13313190 1916 794 7170373967 100 7170373967 100
ioc::network::libos::push 17600 513 212 8628448 0 8628448 0
ioc::network::libos::pop 12259 519 216 5236163 0 5236163 0
ioc::network::libos::connect 50 52018 21744 2116416 0 2116416 0
demikernel::sgaalloc 11283 138 58 1464718 0 1464718 0
demikernel::sgafree 11536 81 34 924448 0 924448 0
demikernel::socket 10 155822 63393 551849 0 551849 0
ioc::network::libos::accept 27 17613 7300 494106 0 494106 0
ioc::network::libos::pushto 1185 346 139 401884 0 401884 0
ioc::network::libos::close 18 23610 9799 358974 0 358974 0
demikernel::new 1 248378 103533 248378 0 248378 0
demikernel::bind 1 28100 11616 28100 0 28100 0
demikernel::listen 1 14716 6117 14716 0 14716 0

Copy link

github-actions bot commented Jan 8, 2025

libos = catnip
commit id = a249178

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once;catnip::runtime::receive 29077098 203 81 5870786291 19 5870786291 40
bgc::inetstack::poll;inetstack::layer4::poll_once 29077098 362 145 10013554305 33 4138421673 28
bgc::inetstack::poll 14538549 925 369 12839275821 42 2825721516 19
demikernel::new 1 1768815083 705838750 1768815083 6 1768815083 12
ioc::network::libos::push 16145 1161 465 16933168 0 14640229 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11051 368 147 4858436 0 4857843 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 4536 2262 903 4420008 0 4402403 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11062 328 131 3050930 0 3049233 0
bgc::inetstack::tcp::established::background 11062 1152 459 11526019 0 2918213 0
ioc::network::libos::pop 9046 382 153 2548853 0 2548853 0
ioc::network::libos::push;catnip::runtime::transmit 8763 332 133 2489477 0 2489477 0
ioc::network::libos::pushto 1203 1237 518 1494899 0 1173325 0
ioc::network::libos::connect 42 32272 13350 1209502 0 1151273 0
demikernel::sgafree 8778 101 40 697422 0 697422 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11009 316 125 698440 0 688016 0
demikernel::sgaalloc 6533 141 57 646036 0 646036 0
bgc::inetstack::tcp::passiveopen::background 42 33913 13193 423371 0 368701 0
ioc::network::libos::pushto;catnip::runtime::transmit 1203 266 112 321574 0 321574 0
ioc::network::libos::close 49 5601 2252 260310 0 260310 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 527 260 110 142066 0 142066 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6297 2527 58229 0 58229 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 15468 6026 54670 0 54670 0
ioc::network::libos::accept 38 2055 804 45938 0 45938 0
bgc::inetstack::arp::background 7 2252 895 19269 0 19269 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 16 1832 744 19006 0 19006 0
demikernel::bind 1 11996 4738 11996 0 11996 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 22 644 255 10937 0 10937 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 592 236 10424 0 10424 0
demikernel::socket 10 1899 751 9335 0 9335 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 8 2246 1060 4745 0 4745 0
bgc::inetstack::icmp::background 1 3035 1210 3213 0 3213 0
demikernel::listen 1 2855 1118 2855 0 2855 0

Nesting async_timer!() within a timer!() scope causes reparenting issues
in the profiler. To avoid such invalid uses in future, changing to panic
if this happens. Also, removed all timers that violated this invariant.
@anandbonde anandbonde force-pushed the ab-profiler-reduce-timers branch from a249178 to 9ed2881 Compare January 8, 2025 21:33
Copy link

github-actions bot commented Jan 8, 2025

libos = catnap
commit id = 9ed2881

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::catnap::transport::epoll 13374664 2008 836 7187147472 100 7187147472 100
ioc::network::libos::push 17600 504 208 8345001 0 8345001 0
ioc::network::libos::pop 12221 509 210 5014348 0 5014348 0
ioc::network::libos::connect 50 50565 21030 2014626 0 2014626 0
demikernel::sgaalloc 11283 132 55 1433747 0 1433747 0
demikernel::sgafree 11536 79 33 912821 0 912821 0
demikernel::socket 10 155264 63221 546833 0 546833 0
ioc::network::libos::accept 27 18702 7674 509686 0 509686 0
ioc::network::libos::pushto 1207 355 145 422118 0 422118 0
ioc::network::libos::close 18 23893 9855 362486 0 362486 0
demikernel::new 1 247209 102244 247209 0 247209 0
demikernel::bind 1 28250 11585 28250 0 28250 0
demikernel::listen 1 15016 6174 15016 0 15016 0

Copy link

github-actions bot commented Jan 8, 2025

libos = catnip
commit id = 9ed2881

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once;catnip::runtime::receive 28439118 205 84 5712258399 19 5712258399 39
bgc::inetstack::poll;inetstack::layer4::poll_once 28439118 364 149 9887232112 33 4170387552 29
bgc::inetstack::poll 14219559 937 383 12801232782 42 2914000670 20
demikernel::new 1 1774913084 724690668 1774913084 6 1774913084 12
ioc::network::libos::push 16145 1166 485 17104417 0 14857936 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11319 351 143 4912392 0 4912025 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 4709 1949 798 4663893 0 4558964 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11330 312 124 3091235 0 3089562 0
bgc::inetstack::tcp::established::background 11330 1095 440 11688587 0 2970806 0
ioc::network::libos::pop 9197 361 147 2653679 0 2653679 0
ioc::network::libos::push;catnip::runtime::transmit 8763 322 134 2439037 0 2439037 0
ioc::network::libos::pushto 1410 1246 536 1762063 0 1389231 0
ioc::network::libos::connect 42 30582 12523 1182642 0 1123960 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11276 298 117 714154 0 704097 0
demikernel::sgafree 8790 91 37 703243 0 703243 0
demikernel::sgaalloc 6549 133 55 645454 0 645454 0
ioc::network::libos::pushto;catnip::runtime::transmit 1410 266 114 372831 0 372831 0
bgc::inetstack::tcp::passiveopen::background 42 33980 13996 406286 0 352327 0
ioc::network::libos::close 50 5759 2378 255052 0 255052 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 600 257 121 166149 0 166149 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 291 625 255 101650 0 101650 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6263 2590 58682 0 58682 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 16530 6833 53959 0 53959 0
ioc::network::libos::accept 38 2089 853 46689 0 46689 0
bgc::inetstack::arp::background 6 2344 958 20208 0 20208 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 19 1135 455 18741 0 18741 0
demikernel::bind 1 10900 4469 10900 0 10900 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 582 237 10057 0 10057 0
demikernel::socket 10 2453 1025 8212 0 8212 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 13 453 192 4116 0 4116 0
demikernel::listen 1 3355 1351 3355 0 3355 0
bgc::inetstack::icmp::background 1 3075 1254 3255 0 3255 0

Copy link

github-actions bot commented Jan 9, 2025

libos = catpowder
commit id = 9ed2881

collapsed_stack num_calls cycles_per_call nanoseconds_per_call total_duration percent_total_duration total_duration_exclusive percent_total_duration_exclusive
bgc::inetstack::poll;inetstack::layer4::poll_once 19173404 698 279 11726273546 46 11720435189 85
bgc::inetstack::poll 9586702 1602 639 13605890491 53 1879616946 14
demikernel::new 1 93987022 37349609 93987022 0 93987022 1
ioc::network::libos::push 16145 3046 1237 45623213 0 45623213 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 5455 2240 879 5937313 0 5935265 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11230 429 171 5786610 0 5786610 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11240 542 221 3758825 0 3758825 0
bgc::inetstack::tcp::established::background 11240 1783 711 13768776 0 3328128 0
ioc::network::libos::pop 9038 555 223 3141292 0 3141292 0
ioc::network::libos::pushto 673 4346 1724 2934921 0 2934921 0
ioc::network::libos::connect 42 45762 18578 1737536 0 1737536 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11188 943 365 895214 0 895214 0
demikernel::sgaalloc 6501 170 69 792289 0 792289 0
demikernel::sgafree 8748 121 49 788036 0 788036 0
bgc::inetstack::tcp::passiveopen::background 42 32450 12972 548389 0 548389 0
ioc::network::libos::close 47 6609 2648 298773 0 298773 0
ioc::network::libos::accept 39 2034 811 48826 0 48826 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 203 205 85 40275 0 40275 0
demikernel::bind 1 24227 9458 24227 0 24227 0
bgc::inetstack::arp::background 7 2241 890 10693 0 10693 0
demikernel::socket 10 2289 895 8106 0 8106 0
demikernel::listen 1 3276 1285 3276 0 3276 0
bgc::inetstack::icmp::background 1 3118 1240 3260 0 3260 0

@anandbonde anandbonde merged commit 87db761 into dev Jan 9, 2025
14 checks passed
@anandbonde anandbonde deleted the ab-profiler-reduce-timers branch January 9, 2025 04:48
anandbonde added a commit that referenced this pull request Jan 13, 2025
[profiler] Enhancment: panic on wrong timer usage
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants