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

[runtime] Enhancement: add a custom logging initializer #1504

Merged
merged 1 commit into from
Feb 12, 2025

Conversation

kyleholohan
Copy link
Contributor

Add a custom logging initializer to runtime.logging mod. This allows clients to use non-stdio outputs. This also fixes a potential issue wherein the LoggingHandle is currently dropped. This is only a bug when a non-stdio logging output is used.

@kyleholohan kyleholohan force-pushed the enhancement-custom-logging branch from 3365808 to d9700c1 Compare February 11, 2025 22:25
Copy link

libos = catnap
commit id = d9700c1

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 13617130 3595 1487 6910848866 100 6910848866 100
ioc::network::libos::push 17600 517 215 7971115 0 7971115 0
ioc::network::libos::pop 15374 484 201 5851228 0 5851228 0
ioc::network::libos::connect 50 153252 63803 2741058 0 2741058 0
ioc::network::libos::pushto 6601 331 142 2207551 0 2207551 0
demikernel::sgaalloc 11391 127 53 1220375 0 1220375 0
demikernel::sgafree 11605 81 34 917317 0 917317 0
ioc::network::libos::accept 26 12842 5454 395677 0 395677 0
ioc::network::libos::close 18 24207 10111 340141 0 340141 0

Copy link

libos = catpowder
commit id = d9700c1

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 21088895 677 269 12148301841 46 12138331951 85
bgc::inetstack::poll 10544447 1561 620 14279058547 54 2130756706 15
ioc::network::libos::push 16145 3071 1230 48239174 0 48239174 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 6088 2983 1176 10138872 0 10136494 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11820 448 177 5951457 0 5951457 0
ioc::network::libos::pushto 1084 4184 1865 4536848 0 4536848 0
bgc::inetstack::tcp::established::background 11835 1933 764 13833956 0 3562064 0
ioc::network::libos::pop 9359 565 225 3550906 0 3550906 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11835 690 277 3333639 0 3333639 0
ioc::network::libos::connect 42 41827 16696 1635664 0 1635664 0
demikernel::sgaalloc 6546 169 68 1063716 0 1063716 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11776 1015 390 986796 0 986796 0
demikernel::sgafree 8771 135 54 725790 0 725790 0
bgc::inetstack::tcp::passiveopen::background 42 18957 7435 432327 0 432327 0
ioc::network::libos::close 47 6660 2634 307804 0 307804 0
ioc::network::libos::accept 39 2361 927 52170 0 52170 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 257 198 88 46759 0 46759 0
bgc::inetstack::arp::background 7 2165 859 14759 0 14759 0
bgc::inetstack::icmp::background 1 2536 1009 2808 0 2808 0

Copy link

libos = catnip
commit id = d9700c1

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 28166059 204 83 5680010440 20 5680010440 44
bgc::inetstack::poll;inetstack::layer4::poll_once 28166059 363 147 9887341936 35 4202603164 33
bgc::inetstack::poll 14083029 923 373 12797997126 45 2910655190 23
ioc::network::libos::push 16144 1203 498 17860169 0 15729361 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 2578 2593 1029 4808473 0 4788303 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11057 351 142 4605502 0 4604828 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11069 323 131 2897576 0 2894695 0
bgc::inetstack::tcp::established::background 11069 1123 452 11002981 0 2795828 0
ioc::network::libos::pop 9048 392 159 2617051 0 2617051 0
ioc::network::libos::push;catnip::runtime::transmit 8763 340 141 2313449 0 2313449 0
ioc::network::libos::pushto 1741 1411 612 2438574 0 1975953 0
ioc::network::libos::connect 42 41562 17024 1587175 0 1526191 0
demikernel::sgaalloc 6592 145 60 714667 0 714667 0
demikernel::sgafree 8809 95 39 695353 0 695353 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11015 328 127 704074 0 693288 0
ioc::network::libos::pushto;catnip::runtime::transmit 1741 282 122 462621 0 462621 0
bgc::inetstack::tcp::passiveopen::background 42 35533 14519 424318 0 369777 0
ioc::network::libos::close 49 5905 2409 261137 0 261137 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 586 312 135 161251 0 161251 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6740 2802 60984 0 60984 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 18088 7427 54541 0 54541 0
ioc::network::libos::accept 38 2218 902 45036 0 45036 0
bgc::inetstack::arp::background 7 2503 1014 21297 0 21297 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 18 1684 704 17930 0 17930 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 23 636 258 12612 0 12612 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 609 247 10786 0 10786 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 12 652 272 4724 0 4724 0
bgc::inetstack::icmp::background 1 2384 964 2552 0 2552 0

Copy link

libos = catnap
commit id = d9700c1

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 13639670 3454 1466 6906062148 100 6906062148 100
ioc::network::libos::push 17600 519 214 7989511 0 7989511 0
ioc::network::libos::pop 15300 456 189 5829427 0 5829427 0
ioc::network::libos::connect 50 140655 57711 2553595 0 2553595 0
demikernel::sgaalloc 11285 130 54 1223403 0 1223403 0
demikernel::sgafree 11537 81 33 949728 0 949728 0
ioc::network::libos::pushto 1268 350 141 433068 0 433068 0
ioc::network::libos::accept 26 14177 5878 429273 0 429273 0
ioc::network::libos::close 18 22998 9539 328554 0 328554 0

Copy link

libos = catpowder
commit id = d9700c1

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 21269989 658 261 12216076443 46 12205664135 85
bgc::inetstack::poll 10634995 1523 603 14338970144 54 2122893702 15
ioc::network::libos::push 16145 3199 1281 49846905 0 49846905 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 6097 3064 1191 10588788 0 10586223 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11833 453 180 6025681 0 6025681 0
ioc::network::libos::pop 9340 534 211 3667475 0 3667475 0
bgc::inetstack::tcp::established::background 11845 1875 734 14022904 0 3600223 0
ioc::network::libos::pushto 687 5299 2176 3400383 0 3400383 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11845 632 247 3386787 0 3386787 0
ioc::network::libos::connect 42 44409 17680 1728506 0 1728506 0
demikernel::sgaalloc 6505 230 90 1054542 0 1054542 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11789 992 381 1010213 0 1010213 0
demikernel::sgafree 8749 120 48 698203 0 698203 0
bgc::inetstack::tcp::passiveopen::background 42 19327 7676 505805 0 505805 0
ioc::network::libos::close 46 6720 2645 301577 0 301577 0
ioc::network::libos::accept 38 2344 933 55467 0 55467 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 200 237 97 50444 0 50444 0
bgc::inetstack::arp::background 7 2327 924 13765 0 13765 0
bgc::inetstack::icmp::background 1 2656 1053 2969 0 2969 0

Copy link

libos = catnip
commit id = d9700c1

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 27915324 206 83 5625826129 20 5625826129 45
bgc::inetstack::poll;inetstack::layer4::poll_once 27915324 370 150 9742696596 35 4112138217 33
bgc::inetstack::poll 13957662 937 380 12538507414 45 2795810818 22
ioc::network::libos::push 16145 1242 512 17561753 0 15437871 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch 2569 3003 1189 4812457 0 4743897 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter 11231 351 142 4634928 0 4634000 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger 11242 310 127 2924210 0 2922333 0
bgc::inetstack::tcp::established::background 11242 1111 449 11145537 0 2872868 0
ioc::network::libos::pop 9082 391 159 2634773 0 2634773 0
ioc::network::libos::push;catnip::runtime::transmit 8763 366 152 2305930 0 2305930 0
ioc::network::libos::pushto 1301 1391 596 1810007 0 1452865 0
ioc::network::libos::connect 42 37075 14966 1462806 0 1403611 0
demikernel::sgaalloc 6541 152 63 712013 0 712013 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender 11189 317 123 713531 0 703078 0
demikernel::sgafree 8784 92 38 691604 0 691604 0
ioc::network::libos::pushto;catnip::runtime::transmit 1301 275 118 357143 0 357143 0
bgc::inetstack::tcp::passiveopen::background 42 33550 13626 350755 0 294879 0
ioc::network::libos::close 49 5621 2283 260852 0 260852 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;udp::receive 538 279 119 138663 0 138663 0
bgc::inetstack::poll;inetstack::layer4::poll_once;inetstack::layer4::receive_batch;catnip::runtime::transmit 197 649 262 64805 0 64805 0
ioc::network::libos::connect;catnip::runtime::transmit 42 6449 2622 59195 0 59195 0
bgc::inetstack::tcp::passiveopen::background;catnip::runtime::transmit 21 17780 7226 55876 0 55876 0
ioc::network::libos::accept 38 2350 953 46188 0 46188 0
bgc::inetstack::tcp::established::background;tcp::established::background::acknowledger;catnip::runtime::transmit 21 1386 593 21018 0 21018 0
bgc::inetstack::arp::background 7 2357 950 20791 0 20791 0
bgc::inetstack::tcp::established::background;tcp::established::background::sender;catnip::runtime::transmit 21 551 223 10453 0 10453 0
bgc::inetstack::tcp::established::background;tcp::established::background::retransmitter;catnip::runtime::transmit 16 677 289 6492 0 6492 0
bgc::inetstack::icmp::background 1 2361 953 2536 0 2536 0

Copy link
Contributor

@anandbonde anandbonde 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.

@kyleholohan kyleholohan merged commit f8aaa1c into dev Feb 12, 2025
14 checks passed
@kyleholohan kyleholohan deleted the enhancement-custom-logging branch February 12, 2025 17:43
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