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

Handle terminal signals #128

Merged
merged 10 commits into from
Nov 22, 2017
Merged

Handle terminal signals #128

merged 10 commits into from
Nov 22, 2017

Conversation

Doxterpepper
Copy link
Contributor

Adding signal handler for colorized output to prevent garbage from being printed to the screen.
#87

@sharkdp
Copy link
Owner

sharkdp commented Oct 18, 2017

Welcome and thank you very much!

Do you have a method to reproduce the original error (such that we can prove that it is now solved)?

@Doxterpepper
Copy link
Contributor Author

Yea I'm going to look into a good test for this, right now I'm just killing fd in the middle of output to try and trigger the scenario. The problem is quitting coloured output before the reset sequence is printed, so the following script should never have garbage printed to the screen or turn the prompt a different colour.

fd "" / --color always & fdpid=$! ; sleep 1 ; kill $fdpid

@sharkdp
Copy link
Owner

sharkdp commented Oct 19, 2017

For this kind of thing, I don't think we actually need an integration test (because this behavior is non-deterministic). I'm okay if there is just a simple command to try it out (like the one you provided). Thanks!

(actually, I didn't have any "luck" in reproducing this, yet 😄)

@jakwings
Copy link
Contributor

You can test with this command: fd "" / --type d --color=always

@sharkdp
Copy link
Owner

sharkdp commented Oct 25, 2017

Sorry for the late response. I still have trouble to reproduce the actual bug. What kind of terminal+shell combination do you use?

If I understand correctly, you run fd "" / --type d --color=always and press Ctrl+C while the search is still running. Then, this leads to a messed-up terminal (?)

@jakwings
Copy link
Contributor

I test with bash, without any method to reset the coloring state to normal (e.g. reset the color for every command prompt). Then you can try and see that the prompt has color blue after Ctrl-C.

Copy link
Contributor

@Detegr Detegr left a comment

Choose a reason for hiding this comment

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

Please check these.

src/walk.rs Outdated
@@ -60,6 +63,16 @@ pub fn scan(root: &Path, pattern: Arc<Regex>, config: Arc<FdOptions>) {
.threads(threads)
.build_parallel();

let wants_to_quit = Arc::new(AtomicBool::new(false));

match config.ls_colors {
Copy link
Contributor

Choose a reason for hiding this comment

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

Use if-let here.

Copy link
Owner

Choose a reason for hiding this comment

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

Agreed.

src/walk.rs Outdated
@@ -113,7 +126,8 @@ pub fn scan(root: &Path, pattern: Arc<Regex>, config: Arc<FdOptions>) {
if time::Instant::now() - start > max_buffer_time {
// Flush the buffer
for v in &buffer {
output::print_entry(v, &rx_config);
output::print_entry(&v, &rx_config, &wants_to_quit);
output::print_entry(v, &rx_config, &wants_to_quit);
Copy link
Contributor

Choose a reason for hiding this comment

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

Why is this line duplicated?

@Detegr
Copy link
Contributor

Detegr commented Oct 31, 2017

If I understand correctly, you run fd "" / --type d --color=always and press Ctrl+C while the search is still running. Then, this leads to a messed-up terminal (?)

I see in theory how this would happen but in practice it does not happen to me. Tested in zsh, bash, and sh.

@Doxterpepper
Copy link
Contributor Author

So here's a screenshot of it on my system using the latest master branch of fd. I ran fd '' /.
You can see it output garbage to the screen and changed my prompt color.

screenshot from 2017-11-01 00-14-46

@sharkdp
Copy link
Owner

sharkdp commented Nov 1, 2017

@Doxterpepper Sorry that this has been dragging on for some time now. I'd like to merge this. I still cannot reproduce the messed-up prompt, but I sometimes do see some 'garbage' character on the screen - and I see that it's potentially causing problems in your screenshot.

Could you please take @Detegr's comment into account and also rebase this on top of master (Let me know if you need any help)? Thank you very much!

@Doxterpepper
Copy link
Contributor Author

@sharkdp, it's no problem. This is definitely a hard one to reproduce, I've tried writing several scripts to detect it without success. I'll make that change recommended by Detger tonight.

@Detegr
Copy link
Contributor

Detegr commented Nov 3, 2017

Has anyone tested performance implications of this change? Ctrlc crate spawns a new thread (for now, work is ongoing to get rid of it) and AFAIK spawning threads on Windows can be quite slow. However it's only one thread at startup so maybe I'm just being paranoid.

@Doxterpepper
Copy link
Contributor Author

@Detegr, I haven't really tested performance yet. I can look into that if you like but I don't have a windows machine to test on.

@Doxterpepper
Copy link
Contributor Author

Okay, I finally did some simple bench marking on a windows virtual machine. I used a windows 10 virtual machine with vmware fusion to run fd and used haskell bench command line tool to benchmark the different branches of fd. Each was compiled on the virtual machine.

Test 1: searching the fd directory

fd '' .

Master branch

time                 59.57 ms   (47.20 ms .. 85.54 ms)
                     0.810 R²   (0.597 R² .. 0.996 R²)
mean                 59.36 ms   (54.68 ms .. 67.61 ms)
std dev              11.53 ms   (5.950 ms .. 17.54 ms)
variance introduced by outliers: 65% (severely inflated)
time                 51.45 ms   (48.23 ms .. 55.49 ms)
                     0.989 R²   (0.981 R² .. 0.997 R²)
mean                 51.06 ms   (50.08 ms .. 52.65 ms)
std dev              2.256 ms   (1.615 ms .. 3.024 ms)
variance introduced by outliers: 14% (moderately inflated)
time                 61.33 ms   (49.37 ms .. 77.89 ms)
                     0.911 R²   (0.861 R² .. 0.999 R²)
mean                 53.44 ms   (51.16 ms .. 61.70 ms)
std dev              6.874 ms   (1.053 ms .. 11.87 ms)
variance introduced by outliers: 48% (moderately inflated)

fix-ctrlc branch

time                 68.15 ms   (48.00 ms .. 82.09 ms)
                     0.930 R²   (0.883 R² .. 0.975 R²)
mean                 59.10 ms   (53.92 ms .. 66.02 ms)
std dev              10.41 ms   (8.065 ms .. 13.94 ms)
variance introduced by outliers: 65% (severely inflated)
time                 68.15 ms   (48.00 ms .. 82.09 ms)
                     0.930 R²   (0.883 R² .. 0.975 R²)
mean                 59.10 ms   (53.92 ms .. 66.02 ms)
std dev              10.41 ms   (8.065 ms .. 13.94 ms)
variance introduced by outliers: 65% (severely inflated)
time                 46.53 ms   (33.55 ms .. 54.63 ms)
                     0.865 R²   (0.627 R² .. 0.974 R²)
mean                 54.92 ms   (49.52 ms .. 63.53 ms)
std dev              12.18 ms   (6.815 ms .. 15.71 ms)
variance introduced by outliers: 74% (severely inflated)

fd 'walk.rs' .

Master branch

time                 69.42 ms   (63.17 ms .. 76.46 ms)
                     0.984 R²   (0.966 R² .. 0.999 R²)
mean                 65.26 ms   (63.44 ms .. 68.01 ms)
std dev              3.880 ms   (1.955 ms .. 6.708 ms)
variance introduced by outliers: 17% (moderately inflated)
time                 56.34 ms   (54.57 ms .. 58.94 ms)
                     0.994 R²   (0.983 R² .. 0.999 R²)
mean                 59.25 ms   (58.11 ms .. 61.11 ms)
std dev              2.395 ms   (1.472 ms .. 3.734 ms)
time                 56.34 ms   (54.57 ms .. 58.94 ms)
                     0.994 R²   (0.983 R² .. 0.999 R²)
mean                 59.25 ms   (58.11 ms .. 61.11 ms)
std dev              2.395 ms   (1.472 ms .. 3.734 ms)
variance introduced by outliers: 59% (severely inflated)

fix-ctrlc branch

time                 61.72 ms   (54.75 ms .. 66.84 ms)
                     0.983 R²   (0.956 R² .. 0.998 R²)
mean                 69.73 ms   (66.19 ms .. 79.91 ms)
std dev              9.232 ms   (2.800 ms .. 15.00 ms)
variance introduced by outliers: 44% (moderately inflated)
time                 70.42 ms   (60.60 ms .. 89.53 ms)
                     0.936 R²   (0.838 R² .. 0.995 R²)
mean                 73.76 ms   (69.89 ms .. 79.87 ms)
std dev              8.456 ms   (5.991 ms .. 11.17 ms)
variance introduced by outliers: 35% (moderately inflated)
time                 58.95 ms   (26.84 ms .. 72.01 ms)
                     0.738 R²   (0.271 R² .. 0.997 R²)
mean                 83.94 ms   (69.58 ms .. 114.0 ms)
std dev              30.46 ms   (3.136 ms .. 44.84 ms)
variance introduced by outliers: 89% (severely inflated)

Test 2: Searching C:\

fd '' C:\

Master branch

time                 50.93 ms   (47.50 ms .. 56.92 ms)
                     0.959 R²   (0.861 R² .. 0.999 R²)
mean                 54.09 ms   (52.22 ms .. 58.92 ms)
std dev              5.364 ms   (1.830 ms .. 9.366 ms)
variance introduced by outliers: 37% (moderately inflated)
time                 53.55 ms   (49.16 ms .. 59.18 ms)
                     0.979 R²   (0.957 R² .. 0.997 R²)
mean                 54.49 ms   (52.84 ms .. 56.78 ms)
std dev              3.425 ms   (2.227 ms .. 4.757 ms)
variance introduced by outliers: 21% (moderately inflated)
time                 49.75 ms   (44.75 ms .. 53.11 ms)
                     0.982 R²   (0.960 R² .. 0.996 R²)
mean                 55.99 ms   (53.57 ms .. 60.89 ms)
std dev              5.826 ms   (2.944 ms .. 9.086 ms)
variance introduced by outliers: 32% (moderately inflated)

fix-ctrlc branch

time                 95.75 ms   (78.88 ms .. 118.1 ms)
                     0.915 R²   (0.797 R² .. 0.982 R²)
mean                 85.72 ms   (74.29 ms .. 98.47 ms)
std dev              19.53 ms   (14.01 ms .. 26.83 ms)
variance introduced by outliers: 69% (severely inflated)
time                 84.97 ms   (50.87 ms .. 110.1 ms)
                     0.784 R²   (0.400 R² .. 0.982 R²)
mean                 77.88 ms   (65.06 ms .. 95.92 ms)
std dev              23.61 ms   (15.18 ms .. 35.02 ms)
variance introduced by outliers: 79% (severely inflated)
time                 57.15 ms   (46.70 ms .. 68.76 ms)
                     0.935 R²   (0.887 R² .. 0.992 R²)
mean                 58.27 ms   (55.16 ms .. 61.99 ms)
std dev              6.310 ms   (4.779 ms .. 8.408 ms)
variance introduced by outliers: 40% (moderately inflated)

fd 'walk.rs' C:\

Master branch

time                 69.49 ms   (63.57 ms .. 77.76 ms)
                     0.979 R²   (0.948 R² .. 0.998 R²)
mean                 68.42 ms   (66.32 ms .. 71.73 ms)
std dev              4.357 ms   (2.601 ms .. 6.269 ms)
variance introduced by outliers: 17% (moderately inflated)
time                 54.35 ms   (41.59 ms .. 62.60 ms)
                     0.917 R²   (0.777 R² .. 0.997 R²)
mean                 67.80 ms   (59.68 ms .. 85.29 ms)
std dev              19.43 ms   (2.297 ms .. 30.53 ms)
variance introduced by outliers: 82% (severely inflated)
time                 51.35 ms   (41.82 ms .. 62.02 ms)
                     0.933 R²   (0.845 R² .. 0.990 R²)
mean                 69.26 ms   (63.26 ms .. 78.42 ms)
std dev              12.58 ms   (7.876 ms .. 18.47 ms)
variance introduced by outliers: 62% (severely inflated)

fix-ctrlc branch

time                 84.69 ms   (63.69 ms .. 107.1 ms)
                     0.911 R²   (0.863 R² .. 0.986 R²)
mean                 67.13 ms   (61.92 ms .. 77.82 ms)
std dev              12.36 ms   (6.764 ms .. 19.16 ms)
variance introduced by outliers: 62% (severely inflated)
time                 76.45 ms   (63.58 ms .. 85.10 ms)
                     0.980 R²   (0.969 R² .. 0.997 R²)
mean                 65.40 ms   (62.14 ms .. 69.77 ms)
std dev              6.461 ms   (4.452 ms .. 8.969 ms)
variance introduced by outliers: 34% (moderately inflated)
time                 73.26 ms   (68.52 ms .. 82.91 ms)
                     0.982 R²   (0.963 R² .. 0.997 R²)
mean                 67.00 ms   (63.49 ms .. 71.23 ms)
std dev              6.424 ms   (4.447 ms .. 8.504 ms)
variance introduced by outliers: 34% (moderately inflated)

@Doxterpepper
Copy link
Contributor Author

@sharkdp, @Detegr

So I wasn't happy with those previous benchmarks, I gave three runs each because the timings were all over the place. Tonight I stopped all other applications on my laptop and set the confidence interval to 0.99 in bench which resulted in much more consistent results. I will only provide one output for each test now because the timings vary so little per test.

If you would like to run these yourself, feel free, but on my machine running windows 10 in vmware fusion there is no performance hit for using the ctrl-c library even though it spins up a separate thread for a signal handler.

Test 1: Searching the fd project

fd '' .

Master branch

time                 47.38 ms   (46.79 ms .. 48.34 ms, ci 0.990)
                     1.000 R²   (0.999 R² .. 1.000 R², ci 0.990)
mean                 46.95 ms   (46.84 ms .. 47.31 ms, ci 0.990)
std dev              341.1 us   (77.30 us .. 607.6 us, ci 0.990)

fix-ctrlc branch

time                 46.93 ms   (46.77 ms .. 47.11 ms, ci 0.990)
                     1.000 R²   (1.000 R² .. 1.000 R², ci 0.990)
mean                 46.86 ms   (46.75 ms .. 46.97 ms, ci 0.990)
std dev              156.2 us   (89.01 us .. 246.2 us, ci 0.990)

fd 'walk.rs' .

Master branch

time                 68.42 ms   (61.00 ms .. 76.30 ms, ci 0.990)
                     0.989 R²   (0.976 R² .. 1.000 R², ci 0.990)
mean                 63.99 ms   (62.47 ms .. 68.41 ms, ci 0.990)
std dev              3.122 ms   (152.6 us .. 3.987 ms, ci 0.990)

fix-ctrlc branch

time                 63.78 ms   (60.81 ms .. 67.72 ms, ci 0.990)
                     0.997 R²   (0.993 R² .. 1.000 R², ci 0.990)
mean                 63.45 ms   (62.50 ms .. 65.61 ms, ci 0.990)
std dev              1.828 ms   (534.0 us .. 2.616 ms, ci 0.990)

Test 2: Searching the whole file system

fd '' C:\

Master branch

time                 46.98 ms   (45.82 ms .. 49.39 ms, ci 0.990)
                     0.998 R²   (0.991 R² .. 1.000 R², ci 0.990)
mean                 47.07 ms   (46.81 ms .. 48.21 ms, ci 0.990)
std dev              835.0 us   (72.45 us .. 1.557 ms, ci 0.990)

fix-ctrlc branch

time                 46.87 ms   (45.90 ms .. 48.16 ms, ci 0.990)
                     0.999 R²   (0.997 R² .. 1.000 R², ci 0.990)
mean                 47.13 ms   (46.82 ms .. 47.93 ms, ci 0.990)
std dev              713.9 us   (141.2 us .. 1.187 ms, ci 0.990)

fd 'walk.rs' C:\

Master branch

time                 62.48 ms   (60.80 ms .. 64.06 ms, ci 0.990)
                     0.999 R²   (0.998 R² .. 1.000 R², ci 0.990)
mean                 62.92 ms   (62.50 ms .. 64.19 ms, ci 0.990)
std dev              978.7 us   (91.39 us .. 1.585 ms, ci 0.990)

fix-ctrlc branch

time                 61.56 ms   (60.01 ms .. 63.01 ms, ci 0.990)
                     0.999 R²   (0.996 R² .. 1.000 R², ci 0.990)
mean                 63.38 ms   (62.40 ms .. 65.62 ms, ci 0.990)
std dev              1.933 ms   (874.6 us .. 3.005 ms, ci 0.990)

@Detegr
Copy link
Contributor

Detegr commented Nov 22, 2017

Looks great! 👍

@sharkdp sharkdp merged commit c0bfc65 into sharkdp:master Nov 22, 2017
@sharkdp
Copy link
Owner

sharkdp commented Nov 22, 2017

@Doxterpepper Fantastic work! Thank you very much for these benchmarks (and for your patience).

I have also tested the performance on Linux and also could not measure any significant difference.


if wants_to_quit.load(Ordering::Relaxed) {
write!(handle, "\n")?;
process::exit(0);

Choose a reason for hiding this comment

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

Sorry to complain, since I likely won't have the time to contribute a fix myself, but I just noticed this while looking through the change log. According to the docs, it's generally not good practice to just process::exit in the middle of the program's execution.

Note that because this function never returns, and that it terminates the process, no destructors on the current stack or any other thread's stack will be run. If a clean shutdown is needed it is recommended to only call this function at a known point where there are no more destructors left to run.

That is, it should really be run at the very end of the main function. So rather than call process::exit here, it should return an error value of some kind that gets propagated all the way up to the main function.

Also, if you're going to handle signals, it's probably better to handle them in the general case, rather than just when there are colors. Messing up the terminal colors is obviously the more pressing case because it messes up the user's whole shell, but the program as a whole should handle exiting gracefully.

Also, this should probably not exit with code 0, which generally means success. Ctrl-C is usually an error condition for a program.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@dead10ck thanks for bringing this to our attention.

I was not aware of this behavior from process::exit, a quick fix to remove the process:exit(0) would be to replace it with something like return Err(Error::new(ErrorKind::Interrupted, "Interrupted"));. I'm just not sure if we need to do something similar in the other spawned thread though. What happens if a rust program exits with outstanding threads executing?

We could handle the terminal signal in the general case, but we handle SIGINT for tear down purposes. We don't have to tear down in the non-colorized case so there's no point in handling SIGINT at that point. We can just use the default SIGINT handling to exit when output is not colorized.

SIGINT is generally for graceful shutdown of a program, I would not say it is generally an error condition. The application handles SIGINT and exits in a known and expected fashion, this would be a successful execution of the program in my opinion.

Copy link

@dead10ck dead10ck Dec 12, 2017

Choose a reason for hiding this comment

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

I was not aware of this behavior from process::exit, a quick fix to remove the process:exit(0) would be to replace it with something like return Err(Error::new(ErrorKind::Interrupted, "Interrupted"));. I'm just not sure if we need to do something similar in the other spawned thread though. What happens if a rust program exits with outstanding threads executing?

I'm sorry, I don't actually have much experience with this in Rust; this is just a tidbit of information I happened to recall when glancing over the changes.

We could handle the terminal signal in the general case, but we handle SIGINT for tear down purposes. We don't have to tear down in the non-colorized case so there's no point in handling SIGINT at that point. We can just use the default SIGINT handling to exit when output is not colorized.

I haven't done my research here, but if I'm not mistaken, the default behavior is not graceful—it essentially just aborts the program in the middle, just like calling process::exit. In any case, though, I think if you're going to go to the trouble of handling graceful exiting, why not handle it everywhere, if it's not too much extra effort?

SIGINT is generally for graceful shutdown of a program, I would not say it is generally an error condition. The application handles SIGINT and exits in a known and expected fashion, this would be a successful execution of the program in my opinion.

I can understand your perspective, but this is not conventional. POSIX specifies that a process terminated by a signal should have an exit code greater than 128. You can test this for yourself with any other standard Linux utility, like find, grep, etc.

Choose a reason for hiding this comment

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

Moreover, it occurred to me that if you only handle the signal when there are colors, and exit with 0 in that case, fd will exit with 0 when there are colors and non-0 when there aren't:

~ fd '' / --color always
...
/proc/9/coredump_filter
^C
/
➜  ~ echo $?               
0
➜  ~ fd '' / --color never
...
/var/log/cups/page_log.3
/var/log/puppetlabs/puppet
/var/log/cups/access_log.4
/var/log/cups/access_log.2
/var/log/cups/page_log.1
/var/log/cu^C
➜  ~ echo $?
130

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@dead10ck, looks like you're right about the exit code.

It should also be noted that while process::exit does not call destructors on exit the memory is not going to really be leaked on any standard unix or windows operating system. The OS keeps track of all memory allocated by a program and will free that memory when the program exits. Only on specialized operating systems such as real-time operating systems do you run the chance of the OS not cleaning up memory after program exit.

For the time being I think we can just replace the exit code with 130 so fd reports it was killed by SIGINT correctly.

On the topic of general SIGINT handling, we have only one special case that requires delaying the exit until after the thread is done writing to the terminal. There's no need in delaying exit when terminal output is not colorized, hence custom shutdown only in the colorized case.

@sharkdp do you have any preferences on these matters?

Copy link
Owner

Choose a reason for hiding this comment

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

@dead10ck Thank you for pointing this out

@Doxterpepper In this case, exiting with 130 seems like a reasonable first step. However, we should maybe open a new ticket in order to refactor the code such that error handling like this would be easier.

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.

5 participants