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

Flush AsyncPoolSink on the current thread if tearing down #66

Merged
merged 2 commits into from
Mar 26, 2024

Conversation

SpriteOvO
Copy link
Owner

@SpriteOvO SpriteOvO commented Mar 21, 2024

Fixes #64.

I've figured out what happened with this bug. There are 2 things went wrong:

  1. crossbeam uses thread-local internally, which is not supported in atexit callback. This is the reason of panic use of std::thread::current() is not possible after the thread's local data has been destroyed.

    Fixed it by directly flushing the sinks on the current thread if the program is tearing down.

  2. The default logger just gets flushed in atexit callback, but not dropped. This results in the program not waiting for the asynchronous thread to finish but simply exiting after the task has been sent.

    Fixed it by changing the global variable with Option<T>, so that we could explicitly drop the default logger in atexit callback. Reverted, paragraph 3 addresses the problem.

  3. UPDATE: Destroying the thread pool before the final flush is required as well, otherwise pending log tasks may be lost.

    Fixing this by adding a RwLock to ThreadPool and explicitly destroy the thread pool before the final flush, but needs to be benchmarked to see if the performance change is acceptable.

    UPDATE: Changed to ArcSwapOption for a better performance.


Related discussion #63 #65, CC @MrCoco5921 @Bestfast

@SpriteOvO SpriteOvO force-pushed the fix-global-async-pool-sink branch from 15c674b to 9d7dafd Compare March 21, 2024 20:32
@SpriteOvO SpriteOvO changed the title Flush AsyncPoolSink on the current thread if tearing down Flush AsyncPoolSink on the current thread if tearing down, drop the default logger in atexit callback Mar 21, 2024
@SpriteOvO SpriteOvO force-pushed the fix-global-async-pool-sink branch 2 times, most recently from e5cc64d to e1f9a06 Compare March 22, 2024 13:39
@SpriteOvO
Copy link
Owner Author

Benchmark results

On ArchLinux, commit e1f9a06

Before

[info] --------------------------------------------
[info] Messages     : 1000000
[info] Threads      : 10
[info] Queue        : 8192 slots
[info] Queue memory : 8192 x 120 = 960 KB
[info] Total iters  : 3
[info] --------------------------------------------
[info] 
[info] ********************************************
[info] Queue Overflow Policy: Block
[info] ********************************************
[info] Elapsed: 0.355563435 secs         2812437/sec
[info] Elapsed: 0.392709661 secs         2546410/sec
[info] Elapsed: 0.350509562 secs         2852989/sec
[info] 
[info] ********************************************
[info] Queue Overflow Policy: DropIncoming
[info] ********************************************
[info] Elapsed: 0.080866536 secs         12366054/sec
[info] Elapsed: 0.077687493 secs         12872084/sec
[info] Elapsed: 0.075060614 secs         13322566/sec

After

[info] --------------------------------------------
[info] Messages     : 1000000
[info] Threads      : 10
[info] Queue        : 8192 slots
[info] Queue memory : 8192 x 120 = 960 KB
[info] Total iters  : 3
[info] --------------------------------------------
[info] 
[info] ********************************************
[info] Queue Overflow Policy: Block
[info] ********************************************
[info] Elapsed: 0.417248511 secs         2396653/sec
[info] Elapsed: 0.434975067 secs         2298982/sec
[info] Elapsed: 0.406287435 secs         2461311/sec
[info] 
[info] ********************************************
[info] Queue Overflow Policy: DropIncoming
[info] ********************************************
[info] Elapsed: 0.123620255 secs         8089289/sec
[info] Elapsed: 0.104598975 secs         9560323/sec
[info] Elapsed: 0.107852031 secs         9271962/sec

Guess the main reason for the worse is the new RwLock added to ThreadPool, I will try to see if there is a solution with better performance.

@SpriteOvO SpriteOvO force-pushed the fix-global-async-pool-sink branch from e1f9a06 to ecdc8e0 Compare March 22, 2024 14:12
@SpriteOvO
Copy link
Owner Author

If we use ArcSwapOption instead of RwLock, we could get a nice performance - almost no impact.

[info] --------------------------------------------
[info] Messages     : 1000000
[info] Threads      : 10
[info] Queue        : 8192 slots
[info] Queue memory : 8192 x 120 = 960 KB
[info] Total iters  : 3
[info] --------------------------------------------
[info] 
[info] ********************************************
[info] Queue Overflow Policy: Block
[info] ********************************************
[info] Elapsed: 0.339878523 secs         2942227/sec
[info] Elapsed: 0.388267234 secs         2575545/sec
[info] Elapsed: 0.357158248 secs         2799879/sec
[info] 
[info] ********************************************
[info] Queue Overflow Policy: DropIncoming
[info] ********************************************
[info] Elapsed: 0.071169735 secs         14050916/sec
[info] Elapsed: 0.075486378 secs         13247423/sec
[info] Elapsed: 0.074043964 secs         13505489/sec

@SpriteOvO SpriteOvO force-pushed the fix-global-async-pool-sink branch from ecdc8e0 to b6715fd Compare March 22, 2024 14:17
@SpriteOvO SpriteOvO force-pushed the fix-global-async-pool-sink branch 2 times, most recently from c241392 to 1a4b06d Compare March 22, 2024 14:32
@SpriteOvO
Copy link
Owner Author

Reverted commit Drop the default logger in atexit callback. We have explicitly destroyed the thread pool, so no longer need the drop function to wait for tasks to complete. Let's minimize the changes, keep the rule in Rust that global variables don't get dropped.

@SpriteOvO SpriteOvO changed the title Flush AsyncPoolSink on the current thread if tearing down, drop the default logger in atexit callback Flush AsyncPoolSink on the current thread if tearing down Mar 22, 2024
Copy link
Collaborator

@Lancern Lancern left a comment

Choose a reason for hiding this comment

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

LGTM.

@SpriteOvO SpriteOvO merged commit 049c638 into main-dev Mar 26, 2024
32 checks passed
@SpriteOvO SpriteOvO deleted the fix-global-async-pool-sink branch March 26, 2024 09:42
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