expect-5.45.4出现异常spawn输出致字符串匹配失败，是否为Bug？

背景 #

在x86_64架构的SLES15 SP6系统中，用bash脚本结合expect-5.45.4自动化测试Perl程序./pwg.pl，核心验证程序是否输出特定字符串。大部分测试正常，但某案例中目标字符串明明存在却匹配失败。

正常执行示例 #

手动执行命令：

./pwg.pl --show-entropy --verbose=1 '{!/SG:25}ABCDEfghijKLMOP{T/S:R=1}'

输出：

parse_cookie({!/SG:25}ABCDEfghijKLMOP{T/S:R=1})
ABCDEfghijKLMOP
1 states, 0.0 bits

待匹配字符串为ABCDEfghijKLMOP，由Perl的print语句输出并尾随"\n"，所有输出写入STDOUT。

Expect脚本执行异常 #

跟踪Expect脚本时，发现命令被重复调用，且目标字符串匹配失败：

spawn ./pwg.pl --show-entropy --verbose=1 ./pwg.pl --show-entropy --verbose=1 {!/SG:25}ABCDEfghijKLMOP{T/S:R=1}
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {829}

expect: does "" (spawn_id exp6) match glob pattern "\r\nABCDEfghijKLMOP\r\n"? no
parse_cookie(./pwg.pl --show-entropy --verbose=1 {!/SG:25}ABCDEfghijKLMOP{T/S:R=1})

expect: does "parse_cookie(./pwg.pl --show-entropy --verbose=1 {!/SG:25}ABCDEfghijKLMOP{T/S:R=1})\r\n" (spawn_id exp6) match glob pattern "\r\nABCDEfghijKLMOP\r\n"? no
./pwg.pl --show-entropy --verbose=1 ABCDEfghijKLMOP

expect: does "parse_cookie(./pwg.pl --show-entropy --verbose=1 {!/SG:25}ABCDEfghijKLMOP{T/S:R=1})\r\n./pwg.pl --show-entropy --verbose=1 ABCDEfghijKLMOP\r\n" (spawn_id exp6) match glob pattern "\r\nABCDEfghijKLMOP\r\n"? no
1 states, 0.0 bits

expect: does "parse_cookie(./pwg.pl --show-entropy --verbose=1 {!/SG:25}ABCDEfghijKLMOP{T/S:R=1})\r\n./pwg.pl --show-entropy --verbose=1 ABCDEfghijKLMOP\r\n1 states, 0.0 bits\r\n" (spawn_id exp6) match glob pattern "\r\nABCDEfghijKLMOP\r\n"? no
expect: read eof
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "parse_cookie(./pwg.pl --show-entropy --verbose=1 {!/SG:25}ABCDEfghijKLMOP{T/S:R=1})\r\n./pwg.pl --show-entropy --verbose=1 ABCDEfghijKLMOP\r\n1 states, 0.0 bits\r\n"
FAILED
### FAILED

测试脚本 #

PWG='./pwg.pl --show-entropy --verbose=1'

# run command under expect
expect_output()
{
    typeset -r expected="$1"; shift
    expect <<EOI
        log_user 1
        exp_internal 1
        spawn $PWG "$@"
        expect {
            "$expected" {
                #puts "OK"
                exit 0
            }
            timeout {
                puts "No response"
                exit 1
            }
            eof {
                puts "FAILED"
                exit 1
            }
        }
EOI
    local EC=$?
    [ $EC -eq 0 ] && echo '### OK' || echo '### FAILED'
    return $EC
}

expect_output '\r\nABCDEfghijKLMOP\r\n' \
$PWG '{!/SG:25}ABCDEfghijKLMOP{T/S:R=1}'
exit

输出十六进制验证 #

./pwg.pl --show-entropy --verbose=1 '{!/SG:25}ABCDEfghijKLMOP{T/S:R=1}' | hexdump -C

输出：

00000000  70 61 72 73 65 5f 63 6f  6f 6b 69 65 28 7b 21 2f  |parse_cookie({!/|
00000010  53 47 3a 32 35 7d 41 42  43 44 45 66 67 68 69 6a  |SG:25}ABCDEfghij|
00000020  4b 4c 4d 4f 50 7b 54 2f  53 3a 52 3d 31 7d 29 0a  |KLMOP{T/S:R=1}).|
00000030  41 42 43 44 45 66 67 68  69 6a 4b 4c 4d 4f 50 0a  |ABCDEfghijKLMOP.|
00000040  31 20 73 74 61 74 65 73  2c 20 30 2e 30 20 62 69  |1 states, 0.0 bi|
00000050  74 73 0a                                          |ts.|
00000053

其中0a是换行符\n，无\r（0d）。

原因分析 #

这不是Expect的Bug，是脚本用法错误：

1. 命令重复问题：调用expect_output时，额外传了$PWG参数，而函数内部spawn $PWG "$@"会把这个参数再次拼接，导致最终执行的命令重复了一遍./pwg.pl --show-entropy --verbose=1，被测程序把重复的命令参数当成cookie解析输出，才出现异常内容。
2. 换行符匹配错误：实际输出的换行符是\n，但匹配模式写的是\r\n，导致无法匹配目标字符串。

修复方案 #

1. 修正expect_output调用，去掉重复的$PWG参数：

   expect_output '\nABCDEfghijKLMOP\n' \
   '{!/SG:25}ABCDEfghijKLMOP{T/S:R=1}'
   

2. 将匹配模式中的\r\n改为\n，或用正则模式增强灵活性（推荐加-re选项）：

   expect {
       -re {\nABCDEfghijKLMOP\n} {
           exit 0
       }
       timeout {
           puts "No response"
           exit 1
       }
       eof {
           puts "FAILED"
           exit 1
       }
   }
   

内容的提问来源于stack exchange，提问作者U. Windl