时钟点击和unixepoch('now','subsec')

Question

我正在尝试记录某些程序处理所需的时间；但实际上，通过比较不同的代码方法来生成相同的输出并确定哪种方法最有效，这并不是真正意义上的性能测试。

我只需要向用户与应用程序交互时构建的日志添加一些间隔。现在，我想了解两个涉及时间的主要项目。一是我正在记录是否需要搜索来满足请求，如果需要，则需要多少步骤才能找到项目。我想知道执行搜索需要多长时间。然后，搜索完成后，我想知道对该信息执行操作以满足请求需要多长时间。

看来 Tcl 中的

clock clicks

可能是标记起点和沿途点的正确值。这项工作的大部分涉及将数据写入内存 SQLite 数据库，也可以使用

unixepoch('now','subsec')

。

其中一种方法比另一种更可取，还是有更好的方法？

如果相关，我的目标之一（如果可能）是记录请求以便再次运行它们并构建相同的日志并比较代码的更改是否对是否需要搜索产生任何影响，数量搜索步骤、时间等。

感谢您考虑我的问题。

Answer 1

这就是我用于你似乎想要的东西类型的方法：

proc log_duration {msg script} {
    set cmds        [info cmdcount]
    set before      [clock microseconds]
    set code        [catch {uplevel 1 $script} res options]
    set elapsed     [expr {([clock microseconds] - $before) / 1e6}]
    set cmdcount    [expr {[info cmdcount] - $cmds - 12}]   ;# -12: compensate for measurement overhead
    set codename    [switch -- $code {
        0       {string cat OK}
        1       {string cat ERROR}
        2       {string cat RETURN}
        3       {string cat BREAK}
        4       {string cat CONTINUE}
        default {set code}
    }]
    puts "$msg, $codename: [format %.6f $elapsed] seconds, $cmdcount Tcl commands"
    dict incr options -level 1
    return -options $options $res
}

log_duration "Lookup the user details" {
    db eval {select id from users where name=:username}
}

我使用

clock microseconds

而不是

clock clicks

有几个原因：

• clock clicks

  的分辨率对于脚本来说是未知的，因此报告有意义的持续时间很困难。它也与任何指定的时间点无关，这意味着它不能以人类有意义的方式格式化。
• 在与我相关的最快硬件上，单个字节编码 Tcl 命令所花费的最短时间约为 0.1 微秒，并且可靠地测量接近该限制的任何内容取决于其他影响，例如处理器频率缩放（提升和节流以满足热预算）、SMT 和非对称核心调度、缓存状态、上下文切换以及一系列其他影响，这些影响使得对小间隔进行有意义的测量非常具有挑战性。
• 在涉及多个主机的情况下，至少希望

  clock microseconds

  返回的绝对值具有可比性（至少在平台时间同步能够达到的程度）。
• 使用 CPU 周期计数进行测量（或任何其他

  clock clicks

  恰好可用的东西）的想法在频率缩放、睡眠状态、多核和核迁移、乱序执行、深度学习之前的日子里更有意义。管道等

为了测量被测脚本的子部分，我通常只使用嵌套的

log_duration

调用。如果我在测量部分内移动探头，或者

log_duration

本身的开销成为问题，那么我通常会这样做：

proc ts label {
    global _timestamps
    lappend _timestamps [clock microseconds] $label
}

set ::_timestamps   {}
set start           [clock microseconds]

# ... some commands ...
ts foo
# ... some others ...
ts bar
# ... still more ...
ts baz
# ... you get the point ...

set last    $start
puts [join [lmap {ts label} $::_timestamps {
    try {
        format {%6d, %6d %s} [expr {$ts-$start}] [expr {$ts-$last}] $label
    } finally {
        set last   $ts
    }
}] \n]

在

puts

上构建单个

lmap

的结构有点尴尬，因为当我要优化的事情之一是最小化日志调用时，我通常会使用这种方法 - 通常这会在以下位置创建单个条目： AWS CloudWatch 包含整个计时报告。

满足重放和比较测量结果的要求将取决于记录与运行相关的输入数据，这当然超出了测量代码的范围，除了使测量框架的输出适合于那个比较。

clock microseconds

通过测量一致的事物来做到这一点，并且这些示例输出相对数量，这些数量在运行之间应该可以直接比较。

如果这些简单的方法不能完全解决问题，并且您需要诸如在网络分布式设置中集中可视化时间戳事件之类的东西，那么您可能会在我前段时间编写的 evlog 包中找到一些有用的位。再次运行可能并不困难（Tcl 在这方面非常棒），大约 13 年前我将它从 Itcl / Tk 转换为 TclOO，但我知道它使用 blt 的

table

几何管理器，该管理器早已不复存在了。我将 blt 包的该组件拆分出来，并将其作为独立包发布在某个地方，并对较新的 Tk 进行了一些修复，但我不记得在哪里（可能是 Sourceforge）。将 UI 转换为使用

grid

可能比寻找它更容易。但它也可能希望您引入整个

m2

框架，这可能比其价值更多的工作，但可能值得搜索想法来源。