文章/答案/技术大牛

发布

社区首页 >问答首页 >Python -使用“可疑”时间对日志文件进行二进制搜索

问Python -使用“可疑”时间对日志文件进行二进制搜索
EN

Stack Overflow用户

提问于 2016-02-29 10:23:47

回答 1查看 379关注 0票数 2

是否有一种方法可以使用Python对日志文件中的“可疑时间”进行有效的二进制搜索？

我有一个日志文件，其条目如下所示：

02:38:18  0  RcvTxData - 11 : Telegram received and process completed - MCP35 Tx -24239
02:38:20  0  RcvNewTxNo - 3 : MCP36 Set receive trigger
02:38:21  0  RcvNewTxNo - 1 : 
02:38:21  0  RcvNewTxNo - 1 : MCP35 get new Tx 24241
02:38:23  0  RcvTxData - 11 : Telegram received and process completed - MCP36 Tx -13918
02:38:23  0  RcvNewTxNo - 3 : MCP36 Set receive trigger
02:38:24  0  RcvNewTxNo - 1 : 
02:38:24  0  RcvTxData - 11 : Telegram received and process completed - MCP35 Tx -24241
02:38:24  0  RcvNewTxNo - 3 : MCP35 Set receive trigger
02:38:27  0  RcvNewTxNo - 1 : 
02:38:27  0  RcvNewTxNo - 1 : MCP36 get new Tx 13920
09:44:54  0  RcvNewTxNo - 1 : 
09:44:54  0  RcvNewTxNo - 1 : MCP24 get new Tx 17702
09:44:54  0  RcvNewTxNo - 2 : MCP24 Read last Tx before new Tx 17702
09:44:56  0  RcvNewTxNo - 1 : 
09:45:00  0  RcvTxData - 7 :MCP24 Prepare normal TxData to DB
09:45:01  0  RcvTxData - 8 :MCP24 complete call GetTxData
09:45:02  0  RcvTxData - 11 : Telegram received and process completed - MCP10 Tx -9008
09:45:02  0  RcvNewTxNo - 3 : MCP10 Set receive trigger
09:45:04  0  RcvNewTxNo - 1 : 
09:45:04  0  RcvNewTxNo - 3 : MCP24 Set receive trigger
09:45:16  0  RcvNewTxNo - 1 : 
09:45:16  0  RcvNewTxNo - 1 : MCP19 get new Tx 9133
09:45:16  0  RcvNewTxNo - 2 : MCP19 Read last Tx before new Tx 9133
09:45:17  0  RcvTxData - 1 :MCP19 gwTx-9133 lastTx-9131 newTx-0
09:45:17  0  RcvTxData - 4 :MCP19 Adjusted newTxNo_Val-9132
09:45:17  0  RcvTxData - 4.1 :MCP19 FnCode PF
09:45:23  0  RcvTxData - 1 :MCP24 gwTx-17706 lastTx-17704 newTx-0

正如您从上面的示例中可以看到的那样，日志具有不递减的时间，并且时间可能会突然跳转：

02:38:27  0  RcvNewTxNo - 1 : MCP36 get new Tx 13920
09:44:54  0  RcvNewTxNo - 1 : #there is a big jump here

我的目标是检测这条可疑的线，返回它的行和索引。

我创建了一个函数来检测这个“可疑的时间”。但是，日志文件的大小大约是22,000到44,000行的每一行。因此，我的算法非常慢，因为我从一条线到另一条线：

f = open(fp, "r")
notEmpty = True
oldTime = None
while(notEmpty): #this can be executed 22,000 - 44,000 times
    l = f.readline()
    notEmpty = l != ""
    if not notEmpty:
        break
    t = datetime.datetime.strptime(l[0:8], fmt)
    if oldTime is None:
        oldTime = t
    else:
        tdelta = t - oldTime
        if tdelta.seconds > 3600: #more than 1 hour is suspicious
            print("suspicious time: " + str(t) + "\told time: " + str(oldTime))
        oldTime = t

有什么方法可以通过类似于Python中日志文件的二进制搜索来加速搜索吗？

(注:除二进制搜索外，任何替代搜索的建议，只要比蛮力搜索更好，也同样值得赞赏)

编辑：

我已经部分实现了Torxed的解决方案(并修复了一些错误)：

with open(fp, 'rb') as fh:
    prev_time = datetime.datetime.strptime(fh.readline()[0:5].decode('utf-8'), '%H:%M')
    index = 0
    for line in fh:
        if len(line) == 0: continue
        index += 1
        t = datetime.datetime.strptime(line[0:4].decode('utf-8'), '%H:%M')
        if (t - prev_time).total_seconds() > 3600:
            print('\tSuspicious time:', t, '\told time:', prev_time, '\tat: ', str(index))
        prev_time = t

但是，正如他在回答中建议的一些“黑客”，我还想添加一些可能值得“黑”的文件的其他特性，以增加性能效益：

如果没有可疑的时间，整个文件的时间戳从第一个条目到最后一个条目都不会持续超过6个小时
在两个时间戳之间，如果没有可疑的时间，则在超过1小时内不存在差异。
可疑时间很可能发生在第20,000行之后和第30,000行之前(因此，很有可能跳过一些其他行)。

有没有办法在这里实施进一步的“黑客”？

python

logging

回答 1

Stack Overflow用户

回答已采纳

发布于 2016-02-29 12:19:11

从硬件+缓存的角度来看，这一切归结为重新分解代码，使其变得高效。

在进行读取操作时，我会考虑一些设计更改，并对代码进行优化，以避免创建或调用任何不必要的内容。

prev_time = None
with open(fp, 'rb') as fh:
    prev_time = datetime.datetime.strptime(fh.readline()[0:5].decode('utf-8'), '%H:%M')

    for line in fh:
        if len(line) == 0: continue

        t = datetime.datetime.strptime(line[0:5].decode('utf-8'), '%H:%M')
        if (t - prev_time).total_seconds() > 3600:
            print('Suspicious time:', t, '\told time:', prev_time)
        prev_time = t

首先，不尝试执行逻辑is old_time None?，我们只需获取第一行并在进入大的for ...循环之前在其中放一段时间。这样，我们为每一行的读取节省了几微秒，这最终会产生很多问题。

然后，我们也使用with open仅仅因为我们不想让任何文件句柄打开在最后。如果你要看很多文件，这很重要。

我们还跳过了is not notEmpty 3行逻辑和is this line empty, if so continue。

我们还缩短了转换到的时间(不包括秒)，这是一个次要的编辑，但最终可能会节省很多时间，因为我们只为您的操作使用了2/3的数据。

最后一个改进是，我们以二进制对象的形式打开文件，这意味着我们跳过了在binary -> hex/ascii代码中可能完成的任何自动binary -> hex/ascii转换。这将对处理速度产生巨大影响，唯一的缺点是strptime将需要一个类似对象的字符串。我的计算结果(我没有巨大的文本文件来源)是，5个字母的转换将比python内部将文档数据从二进制数据转换为字符串数据的总体速度更快。，我可能错了，

希望这能让你的时间有所改善。

哦，记住，这只会是单向的，这意味着，如果时差向后(它可能不会以顺序的时间日志格式表示)，则会得到一个负值。但你永远不会知道)

编辑：

寻黑

如果你能预测出每一行长度的粗略估计，实际上这样做会更快：

data = fh.read(5)
t = datetime.datetime ...
fh.seek(128) # Skip 128 bytes, hopefully this is enough to find a new line.:
data = fh.read(5) # again
                              # This just shows you the idea, obviously not perfect working code here hehe.

要获取00:00时间戳，显然需要对这个逻辑进行更多的分析，例如，您需要监视是否确实传递了线标记\r\n等，但由于\r\n不知道一行的长度，而是查找\r\n标记与您大致知道的和能够跳过大部分数据是时间搜索方面的巨大优势。因此，考虑一下这一点，因为跳过大多数数据和使用一个通用的操作函数总是更快。

请注意，我们在这里追求微秒，所以每一个疯狂的想法和体力劳动都会在这里得到回报。

使用seek的加法a黑客

假设您知道在一堆中会有足够多的类似时间戳，那么您可以轻松跳过几行：

for line in fh:
    if len(line) == 0: continue
    # Check the line

    fh.seek(56 * 10000) # Average length of a line is 56 characters (calculated this over a few of your lines, so give or take +-10 here)
                                     # And we multiply this with 10000, essentially skipping ~10k lines

如果这里有一个大跳转，您可以这样做：

    if diff > 3600:
        fh.seek(fh.tell() - 5000)

然后跳回5000行，检查时差是否仍然和10k行一样大，那么也许你确实有时差。您也可以使用它来缩小时差发生的范围(但我将由您来决定，有更好的方法来找到它，使用最少的手工劳动，而不占用处理能力)。

从本质上说，这可以归结为~4在最好的世界中寻找和手动执行for line in fh检查新的行尾等。就像这样：

from functools import partial
import datetime
jump_gap = 56 * 10000 # average row length * how many rows you want to jump

def f_jump(fh, jump_size):
    fh.seek(fh.tell() + jump_size)
    while fh.read(1) not in ('\n', ''):
        continue
    return True

with open('log.txt', 'rb') as fh:
    prev_time = datetime.datetime.strptime(fh.read(5).decode('utf-8'), '%H:%M')
    f_jump(fh, jump_gap) # Jump to the next jump since we got a starting time

    for chunk in iter(partial(fh.read, 5), ''): # <-- Note here! We only read 5 bytes
                                                                 # there for it's very important we check for new
                                                                 # rows manually and set the pointed at the start
                                                                 # of a new line, this is what `f_jump()` does later.
        if chunk == '':
            break # we clearly hit rock bottom

        t = datetime.datetime.strptime(chunk.decode('utf-8'), '%H:%M')
        if (t - prev_time).total_seconds() > 3600:
            print('\tSuspicious time:', t, '\ttold time:', prev_time, '\tat: ', fh.tell())

        prev_time = t
        f_jump(fh, jump_gap)

免责声明：有一个限制，我从不数行。但我向您提供了日志文件中发生这种情况的位置。

这很有用，因为您可以：

('\tSuspicious time:', datetime.datetime(1900, 1, 1, 9, 44), '\ttold time:', datetime.datetime(1900, 1, 1, 2, 38), '\tat: ', 636)

你采取636，这是文件的位置，

您可以这样将其输入到tail中：

[user@firefox ~]$ tail -c 636 log.txt 
ete call GetTxData
09:45:02  0  RcvTxData - 11 : Telegram received and process completed - MCP10 Tx -9008
09:45:02  0  RcvNewTxNo - 3 : MCP10 Set receive trigger

这向我显示了问题发生的ish行，现在我可以追溯这些东西了。

或者，我可以疯掉，扔一些Linux忍者魔法，然后做：

 x=`tail -c 636 log.txt -n 1`; grep -B 20 -A 3 "$x" log.txt

这给了我确切的数据，发生的东西，但之前的20行，所以我可以追溯一点点。

由于您想要行号(可能是针对老板或同事)，所以可以将-n添加到grep命令中，并以这种方式获得：

x=`tail -c 636 log.txt -n 1`; grep -B 20 -A 3 -n "$x" log.txt

[user@firefox ~]$ x=`tail -c 636 log.txt -n 1`; grep -B 20 -A 3 -n "$x" log.txt
8-02:38:24  0  RcvTxData - 11 : Telegram received and process completed - MCP35 Tx -24241
9-02:38:24  0  RcvNewTxNo - 3 : MCP35 Set receive trigger
10-02:38:27  0  RcvNewTxNo - 1 : 
11-02:38:27  0  RcvNewTxNo - 1 : MCP36 get new Tx 13920
12-09:44:54  0  RcvNewTxNo - 1 : 
13-09:44:54  0  RcvNewTxNo - 1 : MCP24 get new Tx 17702
14-09:44:54  0  RcvNewTxNo - 2 : MCP24 Read last Tx before new Tx 17702
15-09:44:56  0  RcvNewTxNo - 1 : 
16-09:45:00  0  RcvTxData - 7 :MCP24 Prepare normal TxData to DB
17-09:45:01  0  RcvTxData - 8 :MCP24 complete call GetTxData
18-09:45:02  0  RcvTxData - 11 : Telegram received and process completed - MCP10 Tx -9008
19-09:45:02  0  RcvNewTxNo - 3 : MCP10 Set receive trigger
20-09:45:04  0  RcvNewTxNo - 1 : 
21-09:45:04  0  RcvNewTxNo - 3 : MCP24 Set receive trigger
22-09:45:16  0  RcvNewTxNo - 1 : 
23-09:45:16  0  RcvNewTxNo - 1 : MCP19 get new Tx 9133
24-09:45:16  0  RcvNewTxNo - 2 : MCP19 Read last Tx before new Tx 9133
25-09:45:17  0  RcvTxData - 1 :MCP19 gwTx-9133 lastTx-9131 newTx-0
26-09:45:17  0  RcvTxData - 4 :MCP19 Adjusted newTxNo_Val-9132
27-09:45:17  0  RcvTxData - 4.1 :MCP19 FnCode PF
28:09:45:23  0  RcvTxData - 1 :MCP24 gwTx-17706 lastTx-17704 newTx-0

由于seek()攻击的本质，好的粒度处理可能有点困难，但在这个示例中，我在row 28上得到了成功，这并不是问题的实际所在，但它给了我一个很好的展示，而使用tail + grep，我可以相当快地将它追溯到row 12是错误的时差。

我希望这能帮到你。

票数 4

页面原文内容由Stack Overflow提供。腾讯云小微IT领域专用引擎提供翻译支持

原文链接：

https://stackoverflow.com/questions/35697111

复制

相似问题

问Python -使用“可疑”时间对日志文件进行二进制搜索
EN

回答 1

Stack Overflow用户

社区

活动

圈层

关于

腾讯云开发者

热门产品

热门推荐

更多推荐

问Python -使用“可疑”时间对日志文件进行二进制搜索EN

回答 1

Stack Overflow用户

社区

活动

圈层

关于

腾讯云开发者

热门产品

热门推荐

更多推荐

问Python -使用“可疑”时间对日志文件进行二进制搜索
EN