在 bash 中使用连续附加的日志文件答案

【问题标题】：Working with continuously appended log file in bash在 bash 中使用连续附加的日志文件
【发布时间】：2017-04-05 05:42:22
【问题描述】：

我有一个连续附加的日志文件，如下所示。我的目的是每分钟查找 REJECT 计数。一个分钟的 cron 不能以恰好在 9:15:00 运行的方式同步，这是造成这个问题的棘手问题。

20160302-09:15:01.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:15:01.287619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:15:01.289619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:15:01.290619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:15:01.291619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:15:01.295619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:15:01.297619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:16:02.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:16:03.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:17:02.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:17:07.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:18:07.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274
20160302-09:19:06.283619074 ResponseType:ACCEPT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:10|TimeStamp:1490586301283617274
20160302-09:19:07.283619074 ResponseType:ACCEPT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:10|TimeStamp:1490586301283617274
20160302-09:19:07.283619075 ResponseType:ACCEPT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:10|TimeStamp:1490586301283617274
20160302-09:20:07.283619075 ResponseType:ACCEPT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:10|TimeStamp:1490586301283617274
20160302-09:21:07.283619075 ResponseType:ACCEPT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:10|TimeStamp:1490586301283617274
20160302-09:22:07.283619074 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274

预期输出

8 9:15 REJECT 7
10 9:16 REJECT 2
12 9:17 REJECT 2
#continue appending every 2 minutes or so by reading more logged lines eg. 9:19 then 9:22 and so on

我的代码：

#!/usr/bin/bash
today=$(date +%Y%m%d)
touch ${today}.log
counter=$(tail -1 ${today}.log | cut -d" " -f1) #get line number to tail from

re='^[0-9]+$'
if ! [[ $counter =~ $re ]] ; then
   counter=1
fi
echo "$counter"

echo "tail -n +$counter $1 | grep "ErrorCode:100107" |cut -d'|' -f1 | awk -F '[:-]' '{curr=$2":"$3} (prev!="") && (curr!=prev){print NR, prev, $NF, cnt; cnt=0} {cnt++; prev=curr}' >> ${today}.log"
tail -n +$counter $1 | grep "ErrorCode:100107" |cut -d'|' -f1 | awk -F '[:-]' '{curr=$2":"$3} (prev!="") && (curr!=prev){print NR, prev, $NF, cnt; cnt=0} {cnt++; prev=curr}' >> ${today}.log

我打算每 2 或 3 分钟运行一次此脚本（延迟记录暂时还可以）。但不想每次都重新读取整个文件（文件将以 GB 为单位），所以我尝试使用行号和尾部仅添加行。但这失败了，因为在第二次迭代期间，行号被重置。有没有办法只处理新添加的行。

更新1：生成连续的日志文件

while :; do echo "$(date +%Y%m%d-%H:%M:%S).21223 ResponseType:RMS_REJECT|OrderID:4000007|Symbol:-10|Side:S|Price:175|Quantity:10000|AccountID:BMW500  |ErrorCode:100107|TimeStamp:1490586301283617274";sleep $(shuf -i 5-20 -n 1);done >> test_log &

我以 test_log 作为参数运行脚本 ./myscript.sh test_log myscript.sh 的内容

#!/usr/bin/bash

inputfile=$1

tail -f $inputfile | grep "ErrorCode:100107" |cut -d'|' -f1 | awk '/RMS_REJECT/{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK]+1;delete a};LK=key}' FS='[-:]' #does not give output on teminal
# however this works=> cat $inputfile | grep "ErrorCode:100107" |cut -d'|' -f1 | awk '/RMS_REJECT/{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK]+1;delete a};LK=key}' FS='[-:]'

不知何故，这并没有给我终端上的连续输出

参考： Counting lines in a file during particular timestamps in bash

【问题讨论】：

我知道一种更简单的完全不同的方法。但这只能与systemd 结合使用。您使用 Linux 以及您从什么服务读取？
是的，我使用的是 Linux 机器，文件是从一个简单的日志文件中读取的，并附加了一个 cpp 二进制文件
使用 sleep 而不是 cron 并保持脚本运行。

标签： bash awk

【解决方案1】：

gawk 将在每次 timestamp 迭代中更新您的结果：

tail -f your_log_file|gawk '/RMS_REJECT/{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK];delete a[LK]};LK=key}' FS='[-:]'

简单且最小的内存开销。

说明

FS='[-:]'：Field Separator 使用regex 设置为- 和:。

/RMS_REJECT/：只考虑被拒绝的记录，所以我们寻找合适的模式，当行中不存在时什么都不做。

key=$2":"$3：根据第二个和第三个字段组成一个key。

a[key]++：将 key 存储在 associate 数组（一种散列）中，并累积看到该键的次数。

我们将暂时跳过 if 部分的解释。

LK=key:LK代表Last Key，所以我们使用这个变量来存储处理的last键。

if (LK && LK != key){print LK,a[LK];delete a[LK]}：当我们的 Last Key 有一个值并且其内容与当前的不同 (key var) 时，打印 Last Key 及其哈希value 并从数组中删除 de 键以避免内存开销。

示例

[klashxx]$ while :; do echo "$(date +%Y%m%d-%H:%M:%S).21223 ResponseType:RMS_REJECT";sleep $(shuf -i 5-20 -n 1);done >> test_log &
[1] 4040
[klashxx]$ tail -f test_log |gawk '/RMS_REJECT/{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK];delete a[LK]};LK=key}' FS='[-:]'
09:22 6
09:23 5
09:24 6
09:25 3
^C

（Control + C 按下）

[klashxx]$ cat test_log 
20170405-09:22:13.21223 ResponseType:RMS_REJECT
20170405-09:22:20.21223 ResponseType:RMS_REJECT
20170405-09:22:29.21223 ResponseType:RMS_REJECT
20170405-09:22:44.21223 ResponseType:RMS_REJECT
20170405-09:22:53.21223 ResponseType:RMS_REJECT
20170405-09:23:07.21223 ResponseType:RMS_REJECT
20170405-09:23:22.21223 ResponseType:RMS_REJECT
20170405-09:23:38.21223 ResponseType:RMS_REJECT
20170405-09:23:45.21223 ResponseType:RMS_REJECT
20170405-09:23:55.21223 ResponseType:RMS_REJECT
20170405-09:24:05.21223 ResponseType:RMS_REJECT
20170405-09:24:16.21223 ResponseType:RMS_REJECT
20170405-09:24:24.21223 ResponseType:RMS_REJECT
20170405-09:24:31.21223 ResponseType:RMS_REJECT
20170405-09:24:43.21223 ResponseType:RMS_REJECT
20170405-09:24:56.21223 ResponseType:RMS_REJECT
20170405-09:25:13.21223 ResponseType:RMS_REJECT
20170405-09:25:23.21223 ResponseType:RMS_REJECT
20170405-09:25:43.21223 ResponseType:RMS_REJECT
20170405-09:26:01.21223 ResponseType:RMS_REJECT

附言

不要grep 和cut，只用gawk 看看这个answer。

PS2

根据您的代码，最终结果应该是这样的：

#!/usr/bin/bash

inputfile=$1

tail -f $inputfile | gawk -v errorcode="100107" '/RMS_REJECT/ && $20 == errorcode{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK];delete a[LK]};LK=key}' FS='[-:|]'

【讨论】：

谢谢，但我得到09:16 2 09:17 2 09:18 1 运行你的命令
效果很好，但我需要完全理解它的工作原理（awk 的东西）我们创建一个 HH:MM 的密钥，然后。能否请您详细说明。顺便说一句，这非常简洁明了。谢谢
感谢您的解释，确实很有帮助。为什么a[LK]+1？同样，当我在 bash 脚本中使用相同的命令时，屏幕上没有输出（理想情况下，我希望在 stdout 上运行带有输出的 ./myscript 日志文件。如果我在脚本中使用 cat 而不是 tail -f，那么它运行良好。也许它必须与 tail -f 在 bash 脚本中的工作方式有关。
tail -f $inputfile | grep "ErrorCode:100107" |cut -d'|' -f1 | awk '/RMS_REJECT/{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK]+1;delete a};LK=key}' FS='[-:]' #这有效 cat $inputfile | grep "ErrorCode:100107" |cut -d'|' -f1 | awk '/RMS_REJECT/{key=$2":"$3;a[key]++;if (LK && LK != key){print LK,a[LK]+1;delete a};LK=key}' FS='[-:]'
是的，如果我简单地使用 awk..interesting 就可以了！让我阅读您分享的链接，如果我仍有疑问，请回复。仍然对这种经典方法感到不知所措:) 非常感谢

【解决方案2】：

解决问题的一种方法是使用stat 保存日志大小，使用dd 跳过日志中的旧信息，仅处理最后一分钟收到的REJECT 代码。您可以通过sleep使用sleep $((60 - $(date +%S))) 计算直到下一分钟的秒数（例如，:00 秒）来确定下一个循环在下一分钟精确开始的时间。

对于作为第一个参数（或默认为/path/to/logfile）给出的任何日志文件，一个简短的示例可能类似于以下内容。您需要添加 REJECT 逻辑：

#!/bin/bash

lfn=${1:-/path/to/logfile}

size=$(stat -c "%s" "$lfn")         ## save original log size

while :; do

    newsize=$(stat -c "%s" "$lfn")  ## get new log size
    if ((newsize > size)); then     ## if change, use new info

        ## use dd to skip over existing text to new text
        newtext=$(dd if="$lfn" bs="$size" skip=1 2>/dev/null)

        ## process newtext however you need
        printf "\n newtext: %s\n" "$newtext"


    elif ((newsize < size)); then   ## handle log truncation

        newtext=$(dd if="lfn" 2>/dev/null)
        if [ -n "$newtext" ]; then

            ## process newtext however you need
            printf "\n newtext: %s\n" "$newtext"

        fi

    fi

    size=$((newsize));              ## update size to newsize

    sleep $((60 - $(date +%S)))     ## sleep seconds until next min

done

您可以使用nrejects=$(grep -c RMS_REJECT <<<"$newtext") 之类的信息来获取每次迭代的拒绝次数。

【讨论】：

【解决方案3】：

我提出了一种完全不同的方法！

我还没有安装cpp，但是cpp依赖于libc，所以无论如何都应该使用journal。

我在网上找到this example设置编程代码。

然后我用this guide学习journalctl commands。

洞魔法......
您需要在systemd 中有一个service 才能读取。最简单的方法是致电systemctl list-units 并搜索您要读取的服务。

然后您可以使用Journalctl -f（类似于tail -f）打印出每个创建的新条目。您还可以指定输出。不再需要 awk 或类似名称，您可以使用 JSON 或任何您想要的。

我希望这对您未来的项目也有帮助！

【讨论】：

【解决方案4】：

嗯，一种方法是 tail -f 日志文件并将其输出重定向到一个 fifo 并在 fifo 上运行 awk，如下所示：

模拟日志文件：

$ while true ; do echo foo ; sleep 1 ; done > simulated_logfile

做一个先进先出：

$ mkfifo fifo

tail -f 日志文件并提供先进先出：

$ tail -f simulated_logfile > fifo

用 awk 连续处理输出：

$ awk '{print NR}' fifo

让您的 awk 脚本收集信息到哈希，直到分钟更改然后输出，重置 vars 并继续收集，因为一旦 awk 脚本退出，tail 进程也将停止。

【讨论】：

【解决方案5】：

你可以试试下面bash+awk来解决你的动态日志读取问题。

$ cat logappend.sh 
#!/bin/bash
start=1
end=$(wc -l < file)
while [ 1 ]
do
awk -v start=$start -v end=$end -F '[|:-]' '/ErrorCode:100107/ && (NR>=start && NR<= end) {curr=$2":"$3} (prev!="") && (curr!=prev){print NR, prev, $5, cnt; cnt=0} {cnt++; prev=curr}' file > output.txt
cat output.txt
sleep 20
start=$end
end=$(wc -l < file)
done

注意：您需要根据需要更改睡眠时间。

对于第一次运行，它将运行完整的文件，从第二次运行开始，它将仅检查通过更改开始和结束变量添加到现有文件中的新行。

处理中...第一次运行 -

$ ./logappend.sh 
8 09:15 RMS_REJECT 7
10 09:16 RMS_REJECT 2
11 09:17 RMS_REJECT 1
18 09:15 RMS_REJECT 7
20 09:16 RMS_REJECT 2
script is going to sleep for 20 sec

此脚本将等待 20 秒，然后通过将先前的结束值分配给开始变量并为结束变量设置新值来查找文件中的新更改。为了测试，我只将前 10 行文件复制到现有文件中

cp file tempfile
head tempfile >> file

### 将 10 行追加到文件中

与此同时，您的 20 秒将完成，您可以看到新的输出 -

21 09:17 RMS_REJECT 20
28 09:15 RMS_REJECT 7
30 09:16 RMS_REJECT 2
script is going to sleep for 20 sec

【讨论】：

【解决方案6】：

awk -F '[.|[:blank:]]+' -v FlushLast=0 '
   # assume first time for counter + init
   BEGIN {
      CounterFile = ARGV[ ARGC - 2]
      printf( "" ) >> CounterFile
      Count = 0
      }

   # Load last know reference
   FILENAME == CounterFile {
      Last = $1
      LastRef = 1
      next
      }

   # skip earlier stat
   $1 <= Last {
      next
      }

   # treat new date change
   Last != $1 {
      if( ! LastRef ) {
         print Last " " Count
         print Last " " Count >> CounterFile
         }
      LastRef = 0
      Last = $1
      Count = 0
      }

   # count reject
   $3 ~ /REJECT/ {
      Count++
      }

   # if you want the very last date also (if FlusLast==2 mean next cycle it s ommited )
   END {
      if( FlushLast ) {
         # printf( "flush: " )
         print Last " " Count
         if ( FlushLast > 1 ) print Last " " Count >> CounterFile
         }
      }
   ' ${today}.Counter ${today}.log

注意：

参数 FlushLast 允许打印最后一个“未完成”统计信息（1 只打印，2 打印 + 计数器，0 不统计）
创建了一个计数器文件（假设每个 today 名称，但也可以是 uniq 或其他任何地方）

【讨论】：