몇 년 동안 저를 괴롭혔지만 몇 주 전까지 제대로 이해하지 못했던, 다소 마이너한 터미널 문제가 있어요. 예를 들어 로그 파일에서 특정 출력을 지켜보기 위해 이런 명령어를 실행한다고 해보죠.

tail -f /some/log/file | grep thing1 | grep thing2

로그 라인이 비교적 천천히 추가되는 상황이라면 제가 보게 되는 결과는… 아무것도 없어요! 로그 파일에 일치하는 내용이 있든 없든, 그냥 아무 출력도 보이지 않았어요.

저는 이걸 그냥 “어, 파이프가 가끔 멈춰서 출력을 안 보여주는 건가 보네, 이상하네” 정도로 받아들이고, 대신 grep thing1 /some/log/file | grep thing2 이렇게 실행하면 됐기 때문에 그렇게 넘어가곤 했어요.

그래서 지난 몇 달 동안 터미널을 깊게 파고들면서 이 현상의 정확한 이유를 마침내 알게 됐을 때 정말 신났어요.

왜 이런 일이 생길까: 버퍼링

“파이프가 멈추는” 현상이 가끔 일어나는 이유는 프로그램이 파이프나 파일에 쓰기 전에 출력을 버퍼링하는 경우가 아주 흔하기 때문이에요. 그러니까 파이프 자체는 정상적으로 동작하고 있는 거고, 문제는 프로그램이 애초에 데이터를 파이프에 쓰지 않았다는 거죠!

이건 성능 때문이에요. 출력이 생기는 즉시 바로바로 쓰는 건 시스템 콜을 더 많이 쓰게 되니까, 8KB 정도 데이터가 모일 때까지(혹은 프로그램이 종료될 때까지) 모아두었다가 한 번에 파이프에 쓰는 게 더 효율적이거든요.

이 예시에서는

tail -f /some/log/file | grep thing1 | grep thing2

grep thing1이 8KB가 모일 때까지 일치하는 결과를 계속 모아두는데, 그 양이 실제로는 절대 안 모일 수도 있다는 게 문제예요.

프로그램은 터미널에 쓸 때는 버퍼링하지 않아요

제가 이걸 그렇게 헷갈려 했던 이유 중 하나는 tail -f file | grep thing은 아주 잘 동작하는데, 거기에 grep을 하나 더 추가하면 갑자기 동작하지 않는다는 거였어요!! 이유는 grep이 버퍼링을 처리하는 방식이 터미널에 쓰고 있는지 아닌지에 따라 달라지기 때문이에요.

grep(그리고 다른 많은 프로그램)이 출력 버퍼링 방식을 결정하는 방법은 이래요:

• isatty 함수로 stdout이 터미널인지 아닌지 확인해요
  • 터미널이라면 라인 버퍼링을 사용해요 (한 줄이 완성되는 즉시 바로 출력해요)
  • 그렇지 않다면 “블록 버퍼링”을 사용해요 – 8KB 정도 데이터가 모여야 출력해요

그래서 grep이 터미널에 직접 쓰고 있다면 한 줄이 출력되자마자 바로 볼 수 있지만, 파이프에 쓰고 있다면 볼 수 없는 거예요.

물론 버퍼 크기가 모든 프로그램에서 항상 8KB인 건 아니고 구현에 따라 달라요. grep의 경우 버퍼링은 libc가 처리하고, libc의 버퍼 크기는 BUFSIZ 변수에 정의되어 있어요. glibc에서 정의된 위치는 여기예요.

(여담인데, “프로그램은 터미널에 쓸 때 8KB 출력 버퍼를 쓰지 않는다”는 게 무슨 터미널 물리 법칙 같은 건 아니에요. 프로그램이 원한다면 터미널에 출력할 때도 8KB 버퍼를 쓸 수 있지만, 그렇게 하면 엄청 이상할 거고 저는 그렇게 동작하는 프로그램을 본 적이 없어요)

버퍼링하는 명령어와 하지 않는 명령어

이 버퍼링 동작의 짜증나는 점 중 하나는 파이프에 쓸 때 어떤 명령어가 출력을 버퍼링하는지 일일이 기억해야 한다는 거예요.

출력을 버퍼링하지 않는 명령어 몇 가지는 이래요:

• tail
• cat
• tee

제 생각엔 거의 나머지 모든 명령어가 출력을 버퍼링할 거예요, 특히 배치 처리에 쓸 가능성이 높은 명령어라면 더 그렇고요. 파이프에 쓸 때 출력을 버퍼링하는 흔한 명령어들과 블록 버퍼링을 끄는 플래그를 정리해 봤어요.

• grep (--line-buffered)
• sed (-u)
• awk (there’s a fflush() function)
• tcpdump (-l)
• jq (-u)
• tr (-u)
• cut (can’t disable buffering)

제가 생각나는 건 이 정도가 전부예요. 다른 유닉스 명령어들(예를 들어 sort)도 출력을 버퍼링할 수도 있고 안 할 수도 있지만, 어차피 sort는 입력을 다 받을 때까지 아무것도 할 수 없으니 상관없어요.

그리고 Mac OS 버전과 GNU 버전 둘 다 최대한 테스트해 봤지만 변형이 워낙 많아서 틀린 부분이 있을 수도 있어요.

기본 “print”가 버퍼링되는 프로그래밍 언어

그리고 기본 print 문이 파이프에 쓸 때 출력을 버퍼링하는 프로그래밍 언어 몇 가지와, 버퍼링을 끄는 방법도 정리해 봤어요:

• C (disable with setvbuf)
• Python (disable with python -u, or PYTHONUNBUFFERED=1, or sys.stdout.reconfigure(line_buffering=False), or print(x, flush=True))
• Ruby (disable with STDOUT.sync = true)
• Perl (disable with $| = 1)

이런 언어들이 이렇게 설계된 건 배치 처리를 할 때 기본 print 함수가 빠르게 동작하도록 하기 위해서라고 생각해요.

또 출력이 버퍼링되는지 여부는 어떻게 출력하느냐에 따라 달라질 수도 있어요. 예를 들어 C++에서는 cout << "hello\n"은 파이프에 쓸 때 버퍼링되지만 cout << "hello" << endl은 버퍼를 비워요.

파이프에서 Ctrl-C를 누르면 버퍼 내용이 사라져요

example.com으로 가는 DNS 요청을 보는 편법으로 이런 명령어를 실행했는데, tcpdump에 -l을 주는 걸 깜빡했다고 해보죠:

sudo tcpdump -ni any port 53 | grep example.com

이때 Ctrl-C를 누르면 어떻게 될까요? 마법 같은 완벽한 세상이라면 제가 바라는 건 tcpdump가 버퍼를 비우고, grep이 example.com을 검색해서, 놓친 출력을 전부 볼 수 있는 거예요.

하지만 현실에서는 모든 프로그램이 종료되면서 tcpdump 버퍼에 있던 출력이 사라져 버려요.

이 문제는 아마 피하기 어려울 것 같아요. strace로 동작을 좀 살펴봤는데 어차피 grep이 tcpdump보다 먼저 SIGINT를 받거든요. 그래서 tcpdump가 버퍼를 비우려고 해도 이미 grep은 죽은 상태예요.

좀 더 알아보니 우회 방법이 하나 있어요. tcpdump의 PID를 찾아서 kill -TERM $PID로 종료하면 tcpdump가 버퍼를 비워서 출력을 볼 수 있어요. 좀 번거롭긴 하지만 테스트해 보니 동작하더라고요.

파일로 리다이렉트해도 버퍼링돼요

파이프만 그런 게 아니고, 이런 경우도 버퍼링돼요:

sudo tcpdump -ni any port 53 > output.txt

다만 파일로 리다이렉트하는 경우에는 “Ctrl-C를 누르면 버퍼 내용이 완전히 사라진다”는 문제가 생기지 않아요. 제 경험상 프로그램이 종료되기 전에 버퍼 내용이 파일에 기록되는 식으로, 기대한 대로 동작하는 경우가 많더라고요. 이걸 항상 믿어도 되는지는 100% 확신할 수 없어요.

버퍼링을 피하는 여러 가지 방법

자, 이제 해결책을 이야기해 볼게요. 이런 명령어를 실행했다고 해보죠:

tail -f /some/log/file | grep thing1 | grep thing2

마스토돈에서 사람들에게 실제로는 어떻게 해결하는지 물어봤더니 기본적으로 5가지 접근법이 나왔어요. 소개해 볼게요:

방법 1: 빨리 끝나는 프로그램을 실행하기

예전까지 제가 써온 방법은 “파이프에 천천히 쓰는 명령어” 상황 자체를 아예 피하고, 대신 이렇게 빨리 끝나는 프로그램을 실행하는 거였어요:

cat /some/log/file | grep thing1 | grep thing2 | tail

원래 명령어와 똑같이 동작하는 건 아니지만, 이렇게 하면 이상한 버퍼링 문제를 고민하지 않아도 된다는 장점이 있어요.

(grep thing1 /some/log/file처럼 해도 되지만 전 쓸데없어 보이는 cat을 쓰는 걸 더 선호하는 편이에요)

방법 2: grep의 “라인 버퍼” 플래그를 기억하기

grep에 버퍼링을 피하는 플래그가 있다는 걸 기억해 두고 이렇게 쓰는 방법도 있어요:

tail -f /some/log/file | grep --line-buffered thing1 | grep thing2

방법 3: awk 사용하기

여러 개의 grep을 쓰는 상황이라면 단일 awk로 고쳐 쓰겠다고 한 사람들도 있었어요. 이렇게요:

tail -f /some/log/file |  awk '/thing1/ && /thing2/'

혹은 이렇게 좀 더 복잡한 grep을 쓰기도 하고요:

tail -f /some/log/file |  grep -E 'thing1.*thing2'

(awk도 버퍼링을 하니까, 이렇게 하려면 awk가 파이프라인의 마지막 명령어여야 해요)

방법 4: stdbuf 사용하기

stdbuf는 LD_PRELOAD를 이용해 libc의 버퍼링을 끄는 도구예요. 이렇게 출력 버퍼링을 끌 수 있어요:

tail -f /some/log/file | stdbuf -o0 grep thing1 | grep thing2

다른 LD_PRELOAD 방식과 마찬가지로 좀 불안정한 면이 있어요. 정적으로 링크된 바이너리에서는 동작하지 않고, 프로그램이 libc의 버퍼링을 쓰고 있지 않으면 동작하지 않을 것 같고, Mac OS에서는 항상 잘 동작하지도 않아요. Harry Marr가 쓴 How stdbuf works라는 글이 정말 잘 설명해 줘요.

방법 5: unbuffer 사용하기

unbuffer program은 프로그램의 출력이 TTY인 것처럼 속이는 방식이에요. 그러면 TTY에서처럼 동작하게 되죠(버퍼링이 줄어들고, 컬러 출력이 되는 식으로요). 이 예시에서는 이렇게 쓸 수 있어요:

tail -f /some/log/file | unbuffer grep thing1 | grep thing2

stdbuf와 달리 항상 동작하지만, 원치 않는 부작용이 생길 수도 있어요. 예를 들어 grep thing1이 일치하는 부분에 색을 입히게 되는 식이죠.

unbuffer를 설치하고 싶다면 expect 패키지에 들어 있어요.

제가 아는 해결책은 여기까지예요!

어떤 방법이 “제일 좋다”고 말하기는 좀 어렵네요. 개인적으로는 항상 동작한다는 걸 아니까 unbuffer를 가장 많이 쓰게 될 것 같아요.

다른 해결책을 더 알게 되면 이 글에 추가해 보려고 해요.

이 문제가 얼마나 자주 생기는지는 잘 모르겠어요

제 경우에는 이렇게 파이프로 데이터가 천천히 조금씩 흘러 들어가는 경우가 그리 흔하지는 않은 것 같아요. 보통 파이프를 쓸 때는 많은 양의 데이터가 아주 빠르게 쓰이고, 파이프라인의 모든 단계에서 처리된 뒤 바로 종료되거든요. 지금 당장 떠오르는 예는 이것뿐이에요:

• tcpdump
• tail -f
• kubectl logs처럼 다른 방식으로 로그 파일을 지켜보는 경우
• 느린 연산의 출력

버퍼링을 끄는 환경 변수가 있다면 어떨까?

Python의 PYTHONUNBUFFERED처럼 버퍼링을 끄는 표준 환경 변수가 있으면 멋질 것 같아요. 이 아이디어는 2018년 Mark Dominus가 쓴 글 두 개에서 얻었어요. NO_COLOR처럼 NO_BUFFER 같은 건 어떨까요?

설계가 까다로울 것 같긴 해요. Mark는 NetBSD에 환경 변수 STDBUF, STDBUF1 등이 있어서 버퍼링을 아주 세밀하게 제어할 수 있다고 지적하는데, 대부분의 개발자가 비교적 사소한 엣지 케이스를 처리하려고 여러 환경 변수를 구현하고 싶어 하지는 않을 것 같아요.

또 출력 버퍼를 일정 시간(예를 들어 1초)이 지나면 자동으로 비워주는 프로그램이 있는지도 궁금해요. 이론상으로는 좋을 것 같은데, 그렇게 동작하는 프로그램이 하나도 떠오르지 않는 걸 보면 단점이 있을 것 같아요.

다루지 않은 내용

이 글에서 다루지 않은 내용도 몇 가지 있는데, 요즘 글이 점점 길어지고 있어서요. 솔직히 누가 버퍼링에 대해 3000자짜리 글을 정말 읽고 싶어 하겠어요?

• 라인 버퍼링과 완전히 버퍼링하지 않는 출력의 차이
• stderr로의 버퍼링이 stdout으로의 버퍼링과 어떻게 다른지
• 이 글은 프로그램 내부에서 일어나는 버퍼링에 대해서만 다뤘어요. 운영체제의 TTY 드라이버도 가끔 약간의 버퍼링을 하거든요
• “파이프에 쓰고 있다” 말고도 출력을 flush해야 하는 다른 이유들