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

lefthook can swallow stdin from user typing at the terminal unexpectedly #588

Closed
technicalpickles opened this issue Nov 27, 2023 · 24 comments · Fixed by #590 or #638
Closed

lefthook can swallow stdin from user typing at the terminal unexpectedly #588

technicalpickles opened this issue Nov 27, 2023 · 24 comments · Fixed by #590 or #638
Labels
bug Something isn't working

Comments

@technicalpickles
Copy link
Contributor

🔧 Summary

consider a workflow like this:

$ git commit -m "She sells seashells by the sea shore"
<lefthook happens here>
$ git push
$ git checkout

Out of muscle memory, it's really easy to hit enter, and immediately start typing the next command while the first command is still running. It seems that lefthook ends up receiving that command you start typing though, so when the first command is finished, the input with the second command doesn't get to the shell.

For some additional context, I've gotten this complaint from a few people after migrating from committer to lefthook.

Lefthook version

1.5.2

Steps to reproduce

lefthook.yaml:

pre-commit:
  commands:
    sleep:
      run: sleep 2
  • make some change
  • type git commit -a -m "test"<enter>
  • while lefthook is running, type: git checkout main<enter>

Expected results

shell receives the input for the next command, ie git checkout main<enter>

Actual results

input with second command, git checkout main, isn't received by the shell.

Possible Solution

I think it should be possible to close stdin, so it doesn't receive any of the input from a user. I don't know if there are any cases where lefthook does read from stdin though.

Logs / Screenshots

CleanShot.2023-11-27.at.13.47.34.mp4
@technicalpickles technicalpickles added the bug Something isn't working label Nov 27, 2023
@skatenerd
Copy link

I have this issue too!

@noaelad
Copy link

noaelad commented Nov 27, 2023

I also have this issue!

@att14
Copy link

att14 commented Nov 28, 2023

Even with no_tty and a full skip_output I observe this issue.

no_tty: true

skip_output:
  - meta           # Skips lefthook version printing
  - summary        # Skips summary block (successful and failed steps) printing
  - empty_summary  # Skips summary heading when there are no steps to run
  - success        # Skips successful steps printing
  - failure        # Skips failed steps printing
  - execution      # Skips printing any execution logs (but prints if the execution failed)
  - execution_out  # Skips printing execution output (but still prints failed commands output)
  - execution_info # Skips printing `EXECUTE > ...` logging
  - skips          # Skips "skip" printing (i.e. no files matched)
  - meta           # Skips lefthook version printing

post-checkout:
  commands:
    sleep:
      run: sleep 2
$ git checkout
M       lefthook.yml
Your branch is up to date with 'origin/main'.
asdf asdf asdf asdf%
$ sdf asdf asdf

@mrexox
Copy link
Member

mrexox commented Nov 28, 2023

Hey! Thank you for reporting this issue. There are cases when lefthook expects something from STDIN. This is controlled by interactive option. Let me take a look at this issue

@mrexox
Copy link
Member

mrexox commented Nov 28, 2023

I've tried to reproduce this issue, but couldn't do that. The example config:

pre-commit:
  commands:
    sleep:
      run: sleep 2

I am not sure what the problem is. I use lefthook version 1.5.3, zsh 5.9.

Could you please try follow option, add LEFTHOOK_VERBOSE=1 and send the full log, so I could understand at what step the input is being swallowed. I tried to add sleep calls inside the hook too, but on my setup I don't have any input swallowed:

❯ git commit -m 'test'
[sleep called from hook script]
1234[sleep done]
5╭──────────────────────────────────────╮
│ 🥊 lefthook v1.5.3  hook: pre-commit │
╰──────────────────────────────────────╯
sync hooks: ✔️ (pre-commit)
6┃  sleep ❯

789
  ────────────────────────────────────
summary: (done in 2.50 seconds)
✔️  sleep
[main 3c7c0c1] test
 1 file changed, 1 insertion(+)
e
lh-test git:main  6s
❯ 123456789

@technicalpickles
Copy link
Contributor Author

I've tried to reproduce this issue, but couldn't do that.

I use fish on macOS in iTerm2. I've tested against zsh and bash, and get the same result.

Interestingly, I tried making a script to reproduce, but it does not reproduce:

#!/usr/bin/env bash
echo "# noise" >> lefthook.yml
printf "git commit -a -m 'test'\necho hello world" | bash

Might be having to do with it being one command and multiple lines, but I'll keep experimenting.

Could you please try follow option, add LEFTHOOK_VERBOSE=1 and send the full log, so I could understand at what step the input is being swallowed.

Sure, here you go! echo sup is the command I typed while it is running.

❯ LEFTHOOK_VERBOSE=1 git commit -a -m "test"
│ [lefthook] cmd: [git rev-parse --show-toplevel]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: /Users/josh.nichols/workspace/lefthook-test

│ [lefthook] cmd: [git rev-parse --git-path hooks]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: .git/hooks

│ [lefthook] cmd: [git rev-parse --git-path info]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: .git/info

│ [lefthook] cmd: [git rev-parse --git-dir]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: .git

╭──────────────────────────────────────╮
│ 🥊 lefthook v1.5.2  hook: pre-commit │
╰──────────────────────────────────────╯
sync hooks: ✔️ (pre-commit)
│ [lefthook] cmd: [sh -c git status --short]
│ [lefthook] dir: /Users/josh.nichols/workspace/lefthook-test
│ [lefthook] err: <nil>
│ [lefthook] out: M  lefthook.yml
?? reproduce.sh

│ [lefthook] cmd: [sh -c git diff --name-only --cached --diff-filter=ACMR]
│ [lefthook] dir: /Users/josh.nichols/workspace/lefthook-test
│ [lefthook] err: <nil>
│ [lefthook] out: lefthook.yml

│ [lefthook] files before filters:
[lefthook.yml]
│ [lefthook] files after filters:
[lefthook.yml]
┃  sleep ❯

echo sup
│ [lefthook] cmd: [sh -c git stash list]
│ [lefthook] dir: /Users/josh.nichols/workspace/lefthook-test
│ [lefthook] err: <nil>
│ [lefthook] out:

  ────────────────────────────────────
summary: (done in 2.08 seconds)
✔️  sleep
│ [lefthook] cmd: [git rev-parse --show-toplevel]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: /Users/josh.nichols/workspace/lefthook-test

│ [lefthook] cmd: [git rev-parse --git-path hooks]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: .git/hooks

│ [lefthook] cmd: [git rev-parse --git-path info]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: .git/info

│ [lefthook] cmd: [git rev-parse --git-dir]
│ [lefthook] dir:
│ [lefthook] err: <nil>
│ [lefthook] out: .git

╭──────────────────────────────────────────────╮
│ 🥊 lefthook v1.5.2  hook: prepare-commit-msg │
╰──────────────────────────────────────────────╯
│ [lefthook] skip: Hook prepare-commit-msg doesn't exist in the config
[test-branch 4fcb833] test
 1 file changed, 1 insertion(+)

@technicalpickles technicalpickles changed the title lefthook swallows stdin lefthook can stdin from user typing at the terminal unexpectedly Nov 28, 2023
@technicalpickles technicalpickles changed the title lefthook can stdin from user typing at the terminal unexpectedly lefthook can swallow stdin from user typing at the terminal unexpectedly Nov 28, 2023
@technicalpickles
Copy link
Contributor Author

I was able to reproduce stdin not being swallowed when using a plain .git/hooks/pre-commit:

#!/usr/bin/env bash
echo "[sleep from $0]"
sleep 2
CleanShot.2023-11-29.at.09.31.52.mp4

Something I was wondering is, would it be possible to defer opening/attaching stdin until something explicitly uses it? ie interactive: true or use_stdin: true?

@mrexox
Copy link
Member

mrexox commented Nov 30, 2023

@technicalpickles , so stdin still gets swallowed even if you run lefthook from the console? Like lefthook run pre-commit, right?

@technicalpickles
Copy link
Contributor Author

Just tested, and it looks like it! One interesting observation though:

  • lefthook run pre-commit, you see the input, and you see a copy the input echo'd back
  • git commit, you see the input, but not a copy

CleanShot 2023-11-30 at 09 07 10@2x

@mrexox
Copy link
Member

mrexox commented Nov 30, 2023

Oh, I see. It looks like you type echo sup<Enter>, and then it is being swallowed. I have typed echo sup without Enter, and the text was displayed after the lefthook call.

I'll try to fix this, but it feels like a complicated thing, since lefthook doesn't know about stdin usage until config is parsed and a command is being run.

@skatenerd
Copy link

Right, the use case here is, I have a bunch of things I want to accomplish, and the first one is slow. So I type in all of the commands and then go focus on something else. And I am hoping to come back later, seeing that all of the commands I typed in are ones that ran or at least were attempted.

@mrexox
Copy link
Member

mrexox commented Nov 30, 2023

The fix will be soon released in version 1.5.5

@technicalpickles
Copy link
Contributor Author

It looks like you type echo sup, and then it is being swallowed. I have typed echo sup without Enter, and the text was displayed after the lefthook call.

That's right, it includes hitting <enter>. However, I see the same behavior with or without <enter>.

I tried out 1.5.5, and still see the same behavior 🤔 My current test file:

pre-commit:
  follow: true
  commands:
    sleep:
      interactive: false
      use_stdin: false
      run: sleep 2

I'm still working on an automated reproduction. Thinking to try something like expect. I'm also working on a reproduction case to show how committer works.

@mrexox
Copy link
Member

mrexox commented Dec 4, 2023

Ok, I could reproduce this with iTerm2. Usually I use tmux session and this issues doesn't reproduce inside tmux, but it does without tmux.

I will need some extra time to dig into this. But It feels like to fix this I need to close STDIN before running any command, and this is usually not a good idea, and many things could stop working. But I'll come back later after some testing.

@technicalpickles
Copy link
Contributor Author

Oh! That makes a lot of sense that tmux would affect it. Do you mind re-opening while its still happening?

But It feels like to fix this I need to close STDIN before running any command

That was my thought too originally. I'm not actually sure what the default behavior is re-stdin. I can't think of times I've had to explicitly close it, for example, just open it when its needed.

For example, consider this bash script:

echo "so sleepy"
sleep 5
echo "huh what did I miss"

You can see this doesn't do anything with stdin, and it also doesn't capture the stdin if you type it while it's running. I looked at our previous tool we've been comparing too (committer) and it doesn't do anything specific to stdin.

Do you think one of the libraries we're using could be doing something?

@technicalpickles
Copy link
Contributor Author

Similarly, this go script doesn't capture input:

package main

import (
	"fmt"
	"time"
)

func main() {
	fmt.Println("So sleepy")

	time.Sleep(5 * time.Second)
	fmt.Println("huh what did I miss")
}

@mrexox mrexox reopened this Dec 11, 2023
@att14
Copy link

att14 commented Dec 11, 2023

Usually I use tmux session and this issues doesn't reproduce inside tmux, but it does without tmux.

FWIW I use tmux and am able to repro this in tmux.

@technicalpickles
Copy link
Contributor Author

I think I've tracked down where the input gets swallowed:

go func() { _, _ = io.Copy(p, args.in) }()

In slightly larger context, this is in conditional logic when the command is NOT (interactive OR using stdin). If that is the case, I don't think we need to be doing that. If we aren't using stdin, then why do we need the input?

if args.interactive || args.useStdin {
command.Stdout = args.out
command.Stdin = args.in
command.Stderr = os.Stderr
err := command.Start()
if err != nil {
return err
}
} else {
p, err := pty.Start(command)
if err != nil {
return err
}
defer func() { _ = p.Close() }()
go func() { _, _ = io.Copy(p, args.in) }()
_, _ = io.Copy(args.out, p)
}

I tested by commenting the offending line out, and building with goreleaser build --clean --snapshot --single-target. With that, I was able to echo test during lefthook, and see it on the shell afterwards:

CleanShot 2024-02-23 at 11 28 43

I've been looking at the code in Execute that ends up assigning to executeArgs, and with some debug logging, I'm pretty sure args.in is still a nullReader. I don't see why copying from that would affect stdin though 😕

I'll push up a PR to see how tests look in any event.

technicalpickles added a commit to technicalpickles/lefthook that referenced this issue Feb 23, 2024
…ve and not using stdin

If I'm reading the code, this `args.in` should be a nullReader when
non-interactive and not using stdin. For some reason though, it ends up
capturing stdin. That is, any typing you do while lefthook is running
goes to lefthook, instead of the shell invoking it.

Fixes evilmartians#588
mrexox pushed a commit that referenced this issue Feb 26, 2024
If I'm reading the code, this `args.in` should be a nullReader when
non-interactive and not using stdin. For some reason though, it ends up
capturing stdin. That is, any typing you do while lefthook is running
goes to lefthook, instead of the shell invoking it.

Fixes #588
@technicalpickles
Copy link
Contributor Author

technicalpickles commented Feb 26, 2024

When I was testing #638 I was only testing in the test repo I had, not our main repo. I was testing in our main repo, and it seems there is still some window that stdin is still captured 😢

It definitely is a smaller window though! Specifically, sometimes it's capturing only e or ec when echo test is entered while git commit is running. I was able to reproduce eventually with my test repo, but it is much harder to catch:

CleanShot 2024-02-26 at 13 35 37

The easiest way to reproduce (but not to share) on a bigish repo is:

git checkout -b lefthook-test
git reset --hard @{1.week.ago} # or use something that merge is sufficiently long
git pull origin main

If you git status<enter> as soon as the pull happens, nothing happens after the pull completes. Doing the same thing, but with LEFTHOOK=0, you see the git status as expected.

It's worth noting this is specifically a post-checkout or post-merge hook. My other tests were pre-commit.

@technicalpickles
Copy link
Contributor Author

Interestingly, I see the behavior during git pull even when there aren't any post-checkout or post-merge commands defined. From that, I think we can infer that it doesn't have to do with how lefthook runs the hook commands, but something before that 🤔 🤔 🤔

@technicalpickles
Copy link
Contributor Author

Paired for a bit with @ngan, and did a bunch of bisecting... that is, commenting out code to see what causes and what doesn't cause it 😂 We managed to trace it down to:

return lefthook.Run(opts, runArgs, args[0], args[1:])

lefthook, err := initialize(opts)

repo, err := git.NewRepository(opts.Fs, git.NewOsExec())

rootPath, err := git.Cmd(cmdRootPath)

That is to say, as soon as lefthook tries to call git to gather information about the repository, that is when stdin is captured.

@technicalpickles
Copy link
Contributor Author

This is going to sound crazy, but I traced it further down to OsExec.rawExecArgs, when log.Debug is called 🙈 Interestingly, it doesn't matter if --verbose is enabled or not.

out, err := o.rawExecArgs(cmd)

log.Debug("[lefthook] cmd: ", args)

stdin is not captured when all the log.Debug lines are commented out.

Diving another layer into the logger...

std.Debug(color(GolorGray).Render(res))

Commenting out this line, stdin is not swallowed. changing it to std.Debug(res) still does swallow stdin, but if we also comment out....

leftBorder := lipgloss.NewStyle().
BorderStyle(lipgloss.NormalBorder()).
BorderLeft(true).
BorderForeground(colorBorder).
Render("")
l.Log(DebugLevel, append([]interface{}{leftBorder}, args...)...)

Taken together, it seems there is a problem down in lipgloss.Style.render 🤔

This was referenced Feb 27, 2024
@mrexox
Copy link
Member

mrexox commented Feb 28, 2024

Wooow, that's a huge catch! I will release the fix ASAP

@technicalpickles
Copy link
Contributor Author

Thank you, it was a wild one. I'd like to take a nap for the rest of the week if that's alright.

To summarize from the PRs, upgrading lipgloss seemed to fix the problem in #649 . It's not an official release, but I also noticed it was updating uniseg from 0.2.0 to 0.4.6. On a hunch, I tried upgrading just that, and it worked 🙃

And thank for merging & releasing #650 🎊 ❤️ 🎊

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
5 participants