掉进兔子洞:关于一个清漆重启错误的故事-第1部分

ghostinushanka在过去的20分钟里反复按了一下按钮,就好像他的生活取决于它一样。他转向我,眼神中充满半点狂野的表情,露出狡猾的笑容-“老兄,我想我明白。”


“看这里,”-他指着屏幕上的一个符号说-“我敢打赌,如果我们在这里添加我刚发送给您的内容,我会打赌”-指向另一段代码-“错误不再将显示。”


有点困惑和疲倦,我更改了我们已经使用了一段时间的sed表达式,保存了文件并运行systemctl varnish reload 。 错误消息已消失...


我的同事继续说,“我与候选人交换的邮件,”他的笑容变成了充满喜悦的真诚的微笑,“突然间,我突然意识到这是同样的问题!”


这一切是怎么开始的


本文假定您了解bash,awk,sed和systemd的工作方式。 欢迎提供清漆知识,但不是必需的。
代码段时间戳已更改。
ghostinushanka写。
本文是两周前用英语发表的原文的翻译。 boikoden翻译。


在另一个温暖的秋天早晨,阳光透过全景窗户照进来,一杯新鲜制备的含咖啡因的饮料不放在键盘上,耳机中最喜欢的声音交响乐,与机械键盘的沙沙声交叠,而标题为“ Investigate varnishre”的标题则调皮地照亮了看板板上积压工单清单上的第一个条目。 sh:echo:“ I / O错误在阶段”(在此阶段研究“ varnishreload sh:echo:I / O错误”)。 当涉及到清漆时,没有错误,也没有位置,即使在这种情况下它们不会转化为任何问题。


对于不熟悉varnishreload的用户 ,这是一个简单的shell脚本,用于重新加载varnishre配置-也称为VCL。


就像票证的名称所暗示的那样,舞台上的一台服务器上发生了错误,并且由于我确定舞台上的清漆布线正常,因此我认为这将是一个小错误。 因此,只有一条消息进入了已经关闭的输出流中。 我将票交给自己,完全有信心在不到30分钟的时间内将其标记为就绪,拍拍自己的肩膀以清理下一个垃圾箱中的木板,然后再处理更重要的事情。


以200 km / h的速度撞向墙壁


在运行Debian Stretch的其中一台服务器上打开varnishreload文件后,我看到了一个长度少于200行的shell脚本。


在运行脚本之后,当直接从终端运行多次时,我没有发现任何可能导致问题的东西。


最后,这是一个阶段,即使它破裂,也没有人会抱怨,嗯...不要太多。 我运行脚本并查看将写入终端的内容,但是看不到任何错误。


还有更多的人开始确保我不做任何额外的努力就无法重现该错误,并且我开始想出如何更改此脚本并使它仍然产生错误。


脚本可以覆盖STDOUT(使用> &- )吗? 还是STDERR? 结果没有人工作。


显然,systemd以某种方式修改了启动环境,但是如何,为什么?
我将vim varnishreload ,然后编辑varnishreload ,在shebang的正下方添加了set -x ,希望调试脚本输出会有所帮助。


该文件是固定的,因此我重新启动了清漆,然后看到更改完全破坏了所有内容……精疲力竭,其中有大量类似C的代码。 即使在终端中滚动也不足以找到其起点。 我完全感到困惑。 调试模式会影响脚本中启动的程序的工作吗? 不,废话 外壳中的错误? 几种可能的情况像蟑螂一样从不同的方向冲过我的头。 一杯咖啡因已满的饮料立即排空,然后快速去厨房补充食物,然后...开始吧。 我打开脚本并查看shebang: #!/bin/sh


/bin/sh只是bash符号链接,因此脚本是在POSIX兼容模式下解释的,对吗? 在那里! Debian中的默认外壳是破折号,这正是/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行开始的多行的一部分出现的。
由于执行了上述子shell,最终将什么写入VCL_FILE变量?


首先,它将通过管道将在第115行上创建的VLC_SHOW变量的内容发送给下一个命令。 然后会发生什么呢?


首先,它使用varnishadm (它是varnish安装软件包的一部分)来配置varnish,而无需重新启动。


vcl.show -v用于将${VCL_NAME}指定的整个VCL配置输出到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. 代码块,存储在五个用空格分隔的可变字段值中。 第五个FILE变量获取字符串的其余部分。 最后,最后一个回显将写出变量${FILE}
     { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" } 
  4. 由于所有第1步到第3步都包含在一个子外壳中,因此值$FILE的输出将被写入变量VCL_FILE

从第119行的注释中可以看出,这仅用于一个目的:可靠地处理VCL将引用名称中带有空格字符的文件的情况。


我注释了${VCL_FILE}的原始处理逻辑,并尝试更改命令的顺序,但这没有任何结果。 一切对我来说都很正常,在启动服务的情况下,出现了错误。


似乎,当您手动运行脚本时,错误根本无法再现,而预期的30分钟已经结束了六次,并且在附件中,出现了更高优先级的任务,将其余情况搁置了。 一周余下的时间里,他们完成了各种各样的任务,并且只得到了一份关于sed的报告和与候选人的面试,而被稍微稀释了一下。 varnishreload的问题在varnishreload中无法挽回。


您所谓的sed-fu ...真的...垃圾


下周原来是一个相当自由的一天,所以我再次决定购买这张票。 我一直希望自己的大脑一直在进行一些后台处理,以寻求解决此问题的方法,而这次我当然知道这是什么。


由于上次进行简单的代码更改无济于事,所以我决定从第116行开始重写它。 无论如何,现有的代码都是糟糕的。 并且绝对没有必要在其中使用read


再次查看错误:
sh: echo: broken pipe -在此命令中,echo在两个地方,但我怀疑第一个是罪魁祸首(嗯,至少是同伙)。 AWK也不可信。 如果真的是awk | {read; echo} awk | {read; echo} awk | {read; echo}构造会导致所有这些问题,为什么不替换呢? 此单行命令并未使用awk的所有功能,甚至没有使用附件中的额外read


既然上周有关于sed的报告,我想尝试一下我新获得的技能并简化echo | awk | { read; echo} echo | awk | { read; echo} echo | awk | { read; echo}变成更易于理解的echo | sed echo | sed 。 尽管这绝对不是检测错误的最佳方法,但我认为至少我会尝试使用sed-fu并可能从中学到一些新的问题。 在此过程中,我请我的同事(sed报告的作者)帮助我提出一个更有效的sed脚本。


varnishadm vcl.show -v "$VCL_NAME"内容varnishadm vcl.show -v "$VCL_NAME"到文件中,因此我可以集中精力编写sed脚本,而不会造成与重新加载服务有关的麻烦。


sed如何处理输入的简要说明可以在其GNU手册中找到。 在sed源中, \n字符被明确指定为行分隔符。


在我的同事的推荐下,经过几次尝试,我们编写了一个sed脚本,其结果与整个源代码行116相同。


以下是样本输入文件:


 > 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再次在我们的脸上大笑。 闪烁的光标正在等待在终端的空白处输入新命令...

Source: https://habr.com/ru/post/zh-CN477968/


All Articles