Falling Down the Rabbit Hole: 하나의 바니시 재부팅 오류 이야기 - 1부

고스티누샨카, 마치 그의 목숨이 달려있는 것처럼 지난 20 분 동안 버튼을 두드린 후 그의 눈에 반 거친 표정과 교활한 미소를 지으며 "Dude, 내가 이해하는 것 같아요."

"여기를 보세요." 그가 화면의 기호 중 하나를 가리키며 말합니다.

조금 의아하고 피곤해서 그동안 작업했던 sed 문을 변경하고 파일을 저장하고 실행합니다. systemctl varnish reload. 오류 메시지가 사라졌습니다...

"내가 후보자와 주고받은 이메일" 내 동료는 그의 미소가 기쁨으로 가득 찬 진정한 미소로 바뀌면서 계속 말했습니다. "갑자기 이것이 정확히 같은 문제라는 생각이 들었습니다!"

모든 것이 어떻게 시작 되었습니까?

이 기사는 bash, awk, sed 및 systemd 작동 방식을 이해하고 있다고 가정합니다. 바니시에 대한 지식이 있으면 좋겠지만 필수는 아닙니다.
스니펫의 타임스탬프가 변경되었습니다.
로 작성 고스티누샨카.
이 텍스트는 XNUMX주 전에 영어로 출판된 원본을 번역한 것입니다. 번역 보이코덴.

또 다른 따뜻한 가을 아침에 탁 트인 창문을 통해 햇살이 비치고, 갓 내린 카페인 음료 한 잔이 키보드에서 떨어져 있고, 좋아하는 교향곡이 헤드폰에 있는 기계식 키보드의 바스락거리는 소리 위로 연주되고, 칸반 보드의 백로그 티켓 목록의 첫 번째 항목이 "Investigate varnishreload sh: echo: I/O error in stage"라는 운명적인 제목과 함께 장난스럽게 빛납니다(스테이지에서 "varnishreload sh: echo: I/O 오류 조사"). 바니쉬에 관해서는 이 경우처럼 문제가 발생하지 않더라도 실수가 없으며 오류가 있을 수 없습니다.

익숙하지 않은 분들을 위해 바니시 재장전, 이것은 구성을 다시 로드하는 데 사용되는 간단한 셸 스크립트입니다. 광택 -VCL이라고도 합니다.

티켓의 제목에서 알 수 있듯이 스테이지에 있는 서버 중 하나에서 오류가 발생했으며 스테이지에서 바니쉬의 라우팅이 제대로 작동하고 있다고 확신했기 때문에 이것이 사소한 실수일 것이라고 생각했습니다. 따라서 이미 닫힌 출력 스트림에 들어간 메시지일 뿐입니다. 나는 30분도 안 되어 준비가 된 것으로 표시하고, 보드에서 다음 정크를 치우고 더 중요한 일로 돌아갈 수 있도록 어깨를 두드리며 자신 있게 티켓을 받습니다.

시속 200km로 벽에 충돌

파일 열기 varnishreload, Debian Stretch를 실행하는 서버 중 하나에서 200줄 미만의 셸 스크립트를 보았습니다.

스크립트를 실행하면서 터미널에서 직접 여러 번 실행할 때 문제를 일으킬 수 있는 것을 보지 못했습니다.

결국 이것은 무대입니다. 깨지더라도 아무도 불평하지 않을 것입니다. 스크립트를 실행하고 터미널에 무엇이 기록되는지 확인하지만 오류는 더 이상 표시되지 않습니다.

추가 노력 없이 오류를 재현할 수 없도록 몇 번 더 실행하고 이 스크립트를 변경하고 여전히 오류를 발생시키는 방법을 알아내기 시작합니다.

스크립트가 STDOUT을 차단할 수 있습니까(사용 > &-)? 아니면 STDERR? 결국 둘 다 작동하지 않았습니다.

분명히 systemd는 어떤 식으로든 실행 환경을 변경하지만 어떻게, 왜?
나는 vim을 켜고 편집 varnishreload, 추가 set -x shebang 바로 아래에서 스크립트 출력을 디버깅하면 약간의 빛이 비춰지기를 바랍니다.

파일이 수정되었으므로 바니시를 다시로드하고 변경 사항이 모든 것을 완전히 깨뜨린 것을 확인했습니다 ... 배기 장치는 수많은 C와 유사한 코드가 포함 된 완전한 엉망입니다. 터미널에서 스크롤해도 시작 위치를 찾기에 충분하지 않습니다. 나는 완전히 혼란스러워. 디버그 모드가 스크립트에서 실행되는 프로그램 작업에 영향을 미칠 수 있습니까? 아니, 헛소리. 쉘의 버그? 몇 가지 가능한 시나리오가 서로 다른 방향으로 바퀴벌레처럼 내 머릿속을 날고 있습니다. 카페인이 가득한 음료수 한 잔은 즉시 비워지고, 재공급을 위해 부엌으로 빠르게 이동하고… 스크립트를 열고 shebang을 자세히 살펴봅니다. #!/bin/sh.

/bin/sh - 이것은 단지 bash 심볼릭 링크이므로 스크립트는 POSIX 호환 모드로 해석됩니다. 그것은 거기에 없었다! 데비안의 기본 쉘은 대시입니다. ~을 지칭하다 /bin/sh.

# ls -l /bin/sh
lrwxrwxrwx 1 root root 4 Jan 24  2017 /bin/sh -> dash

재판을 위해 shebang을 다음으로 변경했습니다. #!/bin/bash, 제거됨 set -x 그리고 다시 시도했다. 마지막으로, 이후에 바니시를 다시 로드하면 허용 가능한 오류가 출력에 나타납니다.

Jan 01 12:00:00 hostname varnishreload[32604]: /usr/sbin/varnishreload: line 124: echo: write error: Broken pipe
Jan 01 12:00:00 hostname varnishreload[32604]: VCL 'reload_20190101_120000_32604' compiled

124번 라인, 여기 있습니다!

114 find_vcl_file() {
115         VCL_SHOW=$(varnishadm vcl.show -v "$VCL_NAME" 2>&1) || :
116         VCL_FILE=$(
117                 echo "$VCL_SHOW" |
118                 awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' | {
119                         # all this ceremony to handle blanks in FILE
120                         read -r DELIM VCL_SHOW INDEX SIZE FILE
121                         echo "$FILE"
122                 }
123         ) || :
124
125         if [ -z "$VCL_FILE" ]
126         then
127                 echo "$VCL_SHOW" >&2
128                 fail "failed to get the VCL file name"
129         fi
130
131         echo "$VCL_FILE"
132 }

그러나 결과적으로 124행은 비어 있고 관심이 없습니다. 오류가 116행에서 시작하는 여러 줄의 일부로 발생했다고 가정할 수 밖에 없었습니다.
마지막으로 변수에 기록되는 내용 VCL_FILE 위의 하위 셸을 실행한 결과?

처음에는 변수의 내용을 보냅니다. VLC_SHOW, 파이프를 통해 다음 명령으로 115행에서 ​​생성됩니다. 그러면 그곳에서 무슨 일이 일어날까요?

첫째, 사용 varnishadm, 다시 시작하지 않고 광택을 구성하려면 광택 설치 패키지의 일부입니다.

하위 명령 vcl.show -v 에 지정된 전체 VCL 구성을 출력하는 데 사용됩니다. ${VCL_NAME}, STDOUT으로.

현재 활성 VCL 구성과 아직 메모리에 있는 여러 이전 버전의 바니시 라우팅 구성을 표시하려면 다음 명령을 사용할 수 있습니다. varnishadm vcl.list, 출력은 다음과 유사합니다.

discarded   cold/busy       1 reload_20190101_120000_11903
discarded   cold/busy       2 reload_20190101_120000_12068
discarded   cold/busy       16 reload_20190101_120000_12259
discarded   cold/busy       16 reload_20190101_120000_12299
discarded   cold/busy       28 reload_20190101_120000_12357
active      auto/warm       32 reload_20190101_120000_12397
available   auto/warm       0 reload_20190101_120000_12587

변수 값 ${VCL_NAME} 스크립트의 다른 부분에 설정 varnishreload 현재 활성 VCL의 이름(있는 경우). 이 경우 "reload_20190101_120000_12397"이 됩니다.

좋아, 변수. ${VCL_SHOW} 니스에 대한 완전한 구성을 포함하며 지금까지 명확합니다. 이제 마침내 왜 대시 출력이 set -x 너무 깨진 것으로 판명되었습니다. 결과 구성의 내용이 포함되었습니다.

완전한 VCL 구성이 종종 여러 파일에서 함께 뭉쳐질 수 있다는 것을 이해하는 것이 중요합니다. C 스타일 주석은 하나의 구성 파일이 다른 구성 파일에 포함된 위치를 정의하는 데 사용되며, 이것이 바로 다음 코드 스니펫 라인의 전부입니다.
포함된 파일을 설명하는 주석 구문의 형식은 다음과 같습니다.

// VCL.SHOW <NUM> <NUM> <FILENAME>

이 컨텍스트에서 숫자는 중요하지 않으며 파일 이름에 관심이 있습니다.

그렇다면 116행에서 시작하는 명령의 늪에서는 어떤 일이 벌어질까요?
알아 내자.
명령은 다음 네 부분으로 구성됩니다.

1. 단순한 echo, 변수의 값을 표시합니다. ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, 행(레코드)을 찾습니다. 여기서 텍스트 분할 후 첫 번째 필드는 "//"이고 두 번째 필드는 "VCL.SHOW"입니다.
   Awk는 이러한 패턴과 일치하는 첫 번째 줄을 작성한 다음 즉시 처리를 중지합니다.

   awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'

3. 공백으로 구분된 XNUMX개의 변수에 필드 값을 저장하는 코드 블록입니다. 다섯 번째 변수 FILE은 줄의 나머지 부분을 받습니다. 마지막으로 마지막 에코는 변수의 내용을 씁니다. ${FILE}.

   { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }

4. 1~3단계가 모두 서브쉘로 둘러싸여 있기 때문에 값의 출력은 $FILE 변수에 기록됩니다 VCL_FILE.

119행의 주석에서 알 수 있듯이 이것은 VCL이 이름에 공백 문자가 있는 파일을 참조하는 경우를 안정적으로 처리하는 유일한 목적을 제공합니다.

에 대한 원래 처리 논리를 주석 처리했습니다. ${VCL_FILE} 명령 순서를 변경하려고 시도했지만 아무런 결과가 없었습니다. 모든 것이 나에게 깔끔하게 작동했으며 서비스를 시작하는 경우 오류가 발생했습니다.

스크립트를 수동으로 실행하면 오류가 단순히 재현되지 않는 것 같습니다. 예상 30 분은 이미 XNUMX 번 종료되었으며 더 높은 우선 순위 작업이 나타나 나머지 사례를 제쳐두고 있습니다. 일주일의 나머지 시간은 다양한 작업으로 채워졌고 sed에 대한 대화와 후보자와의 인터뷰로 약간 희석되었습니다. 오류 문제 varnishreload 돌이킬 수 없는 시간의 모래 속에서 길을 잃었다.

당신의 소위 sed-fu... 실제로는... 쓰레기

그 다음 주에는 상당히 한가한 날이 있었기 때문에 이 티켓을 다시 받기로 결정했습니다. 나는 내 두뇌에서 어떤 백그라운드 프로세스가 항상이 문제에 대한 해결책을 찾고 있었고 이번에는 무엇이 잘못되었는지 확실히 이해하기를 바랐습니다.

지난 번에 코드만 바꿔도 소용이 없었기에 그냥 116번째 줄부터 다시 작성하기로 했습니다. 어쨌든 기존 코드는 어리석었습니다. 그리고 사용할 필요가 전혀 없습니다 read.

오류를 다시 살펴보면 다음과 같습니다.
sh: echo: broken pipe - 이 명령에서 echo는 두 위치에 있지만 첫 번째가 범인일 가능성이 더 높은 것 같습니다(글쎄, 또는 적어도 공범자). Awk도 자신감을 불러 일으키지 않습니다. 그리고 만약에 정말 awk | {read; echo} 디자인은 이러한 모든 문제를 초래합니다. 교체하지 않겠습니까? 이 한 줄 명령은 awk의 모든 기능을 사용하지 않으며 이 추가 기능도 사용하지 않습니다. read 부속물에.

지난 주부터 관련 보고가 있었습니다. sed새로 습득한 기술을 시도하고 단순화하고 싶었습니다. echo | awk | { read; echo} 더 이해하기 쉽게 echo | sed. 이것이 버그를 잡는 최선의 방법은 아니지만 적어도 sed-fu를 시도하고 문제에 대해 새로운 것을 배울 것이라고 생각했습니다. 그 과정에서 동료인 sed talk 작가에게 보다 효율적인 sed 스크립트를 만드는 데 도움을 요청했습니다.

내용을 버렸어요 varnishadm vcl.show -v "$VCL_NAME" 서비스를 다시 시작해야 하는 번거로움 없이 sed 스크립트 작성에 집중할 수 있습니다.

sed가 입력을 처리하는 방법에 대한 간략한 설명은 다음에서 찾을 수 있습니다. 그의 GNU 매뉴얼. sed 소스에서 기호 n 줄 구분 기호로 명시적으로 지정됩니다.

몇 번에 걸쳐 동료의 조언을 받아 원본 116행 전체와 동일한 결과를 제공하는 sed 스크립트를 작성했습니다.

다음은 입력 데이터가 포함된 샘플 파일입니다.

> cat vcl-example.vcl
Text
// VCL.SHOW 0 1578 file with 3 spaces.vcl
More text
// VCL.SHOW 0 1578 file.vcl
Even more text
// VCL.SHOW 0 1578 file with TWOspaces.vcl
Final text

위의 설명으로는 명확하지 않을 수 있지만 첫 번째 댓글에만 관심이 있습니다. // VCL.SHOW, 입력 데이터에 여러 개가 있을 수 있습니다. 이것이 원래 awk가 첫 번째 일치 후에 종료되는 이유입니다.

# шаг первый, вывести только строки с комментариями
# используя возможности sed, определяется символ-разделитель с помощью конструкции '#' вместо обычно используемого '/', за счёт этого не придётся экранировать косые в искомом комментарии
# определяется регулярное выражение “// VCL.SHOW”, для поиска строк с определенным шаблоном
# флаг -n позаботится о том, чтобы sed не выводил все входные данные, как он это делает по умолчанию (см. ссылку выше)
# -E позволяет использовать расширенные регулярные выражения
> cat vcl-processor-1.sed
#// VCL.SHOW#p
> sed -En -f vcl-processor-1.sed vcl-example.vcl
// VCL.SHOW 0 1578 file with 3 spaces.vcl
// VCL.SHOW 0 1578 file.vcl
// VCL.SHOW 0 1578 file with TWOspaces.vcl

# шаг второй, вывести только имя файла
# используя команду “substitute”, с группами внутри регулярных выражений, отображается только нужная группa
# и это делается только для совпадений, ранее описанного поиска
> cat vcl-processor-2.sed
#// VCL.SHOW# {
    s#.* [0-9]+ [0-9]+ (.*)$#1#
    p
}
> sed -En -f vcl-processor-2.sed vcl-example.vcl
file with 3 spaces.vcl
file.vcl
file with TWOspaces.vcl

# шаг третий, получить только первый из результатов
# как и в случае с awk, добавляется немедленное завершения после печати первого найденного совпадения
> cat vcl-processor-3.sed
#// VCL.SHOW# {
    s#.* [0-9]+ [0-9]+ (.*)$#1#
    p
    q
}
> sed -En -f vcl-processor-3.sed vcl-example.vcl
file with 3 spaces.vcl

# шаг четвертый, схлопнуть всё в однострочник, используя двоеточия для разделения команд
> sed -En -e '#// VCL.SHOW#{s#.* [0-9]+ [0-9]+ (.*)$#1#p;q;}' vcl-example.vcl
file with 3 spaces.vcl

따라서 varnishreload 스크립트의 내용은 다음과 같습니다.

VCL_FILE="$(echo "$VCL_SHOW" | sed -En '#// VCL.SHOW#{s#.*[0-9]+ [0-9]+ (.*)$#1#p;q;};')"

위의 논리는 다음과 같이 요약할 수 있습니다.
문자열이 정규 표현식과 일치하는 경우 // VCL.SHOW, 그런 다음 해당 줄에 두 숫자가 모두 포함된 텍스트를 탐욕스럽게 삼키고 이 작업 후에 남은 것은 무엇이든 저장합니다. 저장된 값을 발행하고 프로그램을 종료합니다.

간단하지 않나요?

우리는 sed 스크립트와 원본 코드를 모두 대체한다는 사실에 만족했습니다. 모든 테스트에서 원하는 결과를 얻었으므로 서버에서 "varnishreload"를 변경하고 다시 실행했습니다. systemctl reload varnish. 더러운 실수 echo: write error: Broken pipe 다시 우리 얼굴에 웃었다. 윙크하는 커서가 터미널의 어두운 빈 공간에서 새로운 명령이 입력되기를 기다리고 있었습니다...

출처 : habr.com