本章介绍运行时事件跟踪系统,该系统能够以极低的开销从 OCaml 运行时持续提取性能信息。该系统和接口属于底层,与运行时实现紧密耦合,旨在让最终用户依赖工具来使用和可视化感兴趣的数据。
发出的数据包括:
可以声明和使用其他事件,为 OCaml 库提供更高级别的监控功能。它们被称为自定义事件。
运行时事件系统发出的事件主要分为三类:
运行时事件跟踪系统设计用于不同的上下文:
运行时事件跟踪系统将事件记录到环形缓冲区。因此,旧事件会被新事件覆盖。使用者可以连续使用事件,也可以选择仅在响应某些情况时使用事件,例如,如果特定查询或操作花费的时间比预期长。
运行时跟踪系统从概念上由两部分组成:1) 发出事件的事件源和 2) 摄取和传输这些事件的事件传输。
事件源是发出事件的点。在 OCaml 运行时系统中,有许多这样的源。这些源进一步分为两组:1) 始终可用的事件源和 2) 仅在检测运行时中可用的事件源。检测运行时中的事件源主要对 OCaml 运行时和垃圾收集器的开发人员感兴趣,目前仅包含主要堆分配大小计数器事件。
事件源发出的所有事件及其文档可以在模块 Runtime_events中找到。
系统的事件传输部分摄取事件源发出的事件,并使它们可供使用者使用。
事件使用称为环形缓冲区的数据结构传输。此数据结构包含指向线性后备数组的两个指针,尾指针指向可以写入新事件的位置,头指针指向缓冲区中可以读取的最旧事件。当后备数组中没有足够的空间来写入新事件时,头指针会向前移动,并且最旧的事件会被新事件覆盖。
运行时事件中使用的环形缓冲区实现一次最多只能由一个生产者写入,但可以由多个使用者同时读取,而无需生产者的协调。每个正在运行的域都有一个唯一的环形缓冲区,并且在域终止时,环形缓冲区可以重复用于新生成的域。仅在启用运行时事件时才会分配环形缓冲区(包括主域)。环形缓冲区本身存储在内存映射文件中,该文件以进程标识符作为名称,扩展名为.events,这使得它们可以从主 OCaml 进程外部读取。有关更多信息,请参阅Runtime_events。
运行时事件跟踪系统提供了基于光标和轮询驱动的 OCaml 和 C API。使用事件的高级过程如下:
我们从一个简单的示例开始,该示例打印运行时事件跟踪系统发出的事件的名称、开始和结束时间:
let runtime_begin _ ts phase = Printf.printf "Begin\t%s\t%Ld\n" (Runtime_events.runtime_phase_name phase) (Runtime_events.Timestamp.to_int64 ts) let runtime_end _ ts phase = Printf.printf "End\t%s\t%Ld\n" (Runtime_events.runtime_phase_name phase) (Runtime_events.Timestamp.to_int64 ts) let () = Runtime_events.start (); let cursor = Runtime_events.create_cursor None in let callbacks = Runtime_events.Callbacks.create ~runtime_begin ~runtime_end () in while true do let list_ref = ref [] in (* for later fake GC work *) for _ = 1 to 100 do (* here we do some fake GC work *) list_ref := []; for _ = 1 to 10 do list_ref := (Sys.opaque_identity(ref 42)) :: !list_ref done; Gc.full_major (); done; ignore(Runtime_events.read_poll cursor callbacks None); Unix.sleep 1 done
下一步是使用 runtime_events 库编译和链接程序。这可以通过以下方式完成:
ocamlopt -I +runtime_events -I +unix unix.cmxa runtime_events.cmxa example.ml -o example
使用dune构建系统时,可以按如下方式构建此示例:
(executable (name example) (modules example) (libraries unix runtime_events))
运行示例的编译二进制文件将产生类似于以下内容的输出:
Begin explicit_gc_full_major 24086187297852 Begin stw_leader 24086187298594 Begin minor 24086187299404 Begin minor_global_roots 24086187299807 End minor_global_roots 24086187331461 Begin minor_remembered_set 24086187331631 Begin minor_finalizers_oldify 24086187544312 End minor_finalizers_oldify 24086187544704 Begin minor_remembered_set_promote 24086187544879 End minor_remembered_set_promote 24086187606414 End minor_remembered_set 24086187606584 Begin minor_finalizers_admin 24086187606854 End minor_finalizers_admin 24086187607152 Begin minor_local_roots 24086187607329 Begin minor_local_roots_promote 24086187609699 End minor_local_roots_promote 24086187610539 End minor_local_roots 24086187610709 End minor 24086187611746 Begin minor_clear 24086187612238 End minor_clear 24086187612580 End stw_leader 24086187613209 ...
这是一个自我监控的示例,其中程序显式地开始侦听运行时事件并监控自身。
对于外部监控,程序不需要知道运行时事件的存在。可以通过环境变量OCAML_RUNTIME_EVENTS_START控制运行时事件,该变量如果设置,将在程序初始化时启动运行时跟踪系统。
我们可以从前面的示例中删除Runtime_events.start ();,并改为如下调用程序以产生相同的结果:
OCAML_RUNTIME_EVENTS_START=1 ./example
环境变量可用于控制运行时事件跟踪系统的不同方面。以下环境变量可用:
可以通过 OCAMLRUNPARAM 配置运行时事件环形缓冲区的大小,有关更多信息,请参阅第15.2节。
某些事件仅由检测运行时发出。要接收它们,OCaml 程序需要针对检测运行时进行编译和链接。对于我们之前的示例程序,这可以通过以下方式实现:
ocamlopt -runtime-variant i -I +runtime_events -I +unix unix.cmxa runtime_events.cmxa example.ml -o example
对于 dune:
(executable (name example) (modules example) (flags "-runtime-variant=i") (libraries unix runtime_events))
对事件进行编程访问主要用于可观察性库和最终用户工具的编写者。灵活的 API 使得能够将运行时事件中的性能数据用于日志记录和监控目的。
在本节中,我们介绍了 runtime_events_tools 包中的一些实用程序,这些实用程序提供了从运行时事件中提取和汇总数据的方法。特别是 trace 实用程序会生成与 OCaml 4.12 到 4.14 中可用的先前“eventlog”检测系统类似的数据。
首先,在 OCaml 5.0+ opam 切换中安装 runtime_events_tools
opam install runtime_events_tools
这应该会将 olly 工具安装到你的路径中。你现在可以使用 trace 子命令为使用 OCaml 5.0+ 编译的程序生成运行时跟踪:
olly trace trace.json 'your_program.exe .. args ..'
运行时跟踪数据将以 json 跟踪事件格式生成到 trace.json 中。然后可以将其加载到 Chrome 跟踪查看器或Perfetto中以可视化收集到的跟踪。
olly 实用程序还包含一个延迟子命令,该子命令使用运行时事件数据,并在程序完成时发出暂停持续时间的可解析直方图摘要。可以按如下方式运行它:
olly latency 'your_program.exe .. args ..'
这应该会产生类似于以下内容的输出:
GC latency profile: #[Mean (ms): 2.46, Stddev (ms): 3.87] #[Min (ms): 0.01, max (ms): 9.17] Percentile Latency (ms) 25.0000 0.01 50.0000 0.23 60.0000 0.23 70.0000 0.45 75.0000 0.45 80.0000 0.45 85.0000 0.45 90.0000 9.17 95.0000 9.17 96.0000 9.17 97.0000 9.17 98.0000 9.17 99.0000 9.17 99.9000 9.17 99.9900 9.17 99.9990 9.17 99.9999 9.17 100.0000 9.17
运行时事件系统支持定义自定义事件。它们由全局唯一名称标识,并使用内置 (unit、int、span) 和用户定义类型的有效负载发出。要了解自定义事件的操作,了解它们如何传输和存储很有用:它们的表示形式由名称字符串(实际上是所有自定义名称数组中的索引)和任意字节序列组成。自定义事件类型可以通过为字节序列提供编码和解码函数来注册,方法是使用函数Runtime_events.Type.register。
定义新的自定义事件(无论其有效负载是内置类型还是自定义类型)是通过另一个注册函数Runtime_events.User.register完成的。此函数记录自定义事件名称、其类型和标签之间的关联。然后在发出或使用自定义事件时使用该标签;它充当事件名称的简写。
注册事件后,使用Runtime_events.User.write发出该事件的值。
总而言之,要让用户使用自定义类型发出和使用自定义事件,他们需要
请注意,如果发出者和使用者是不同的程序,则两者都必须执行步骤 1 到 3 以注册自定义事件和自定义事件类型(如果有)。请注意,标签值在两个程序中不必相同;唯一应匹配的值是名称。
目前忽略用户定义类型的未注册事件。作为后备方案,内置类型的未注册自定义事件可用,但都标记为UNK(未知)。
因此,当接收事件时,使用者有三种情况
请注意,事件使用者将回调绑定到事件类型,因此它们可以作为通用侦听器来解释来自未注册事件的有效负载。由于这仅适用于内置类型的事件,因此可以将事件成对发出:一个自定义类型的事件和一个内置类型的事件,从而能够设计专门的使用者,同时与通用跟踪工具保持兼容。
以下程序使用Runtime_events.User和Runtime_events.Type模块声明两个提供span和int值的自定义事件。tag可扩展变体扩展了CustomSpan和CustomInt。
type Runtime_events.User.tag += CustomSpan | CustomInt let count_span = Runtime_events.User.register "count.span" CustomSpan Runtime_events.Type.span let count_value = Runtime_events.User.register "count.value" CustomInt Runtime_events.Type.int let count () = Runtime_events.User.write count_span Begin; for i = 1 to 5 do Runtime_events.User.write count_value i done; Runtime_events.User.write count_span End let () = Runtime_events.start (); for _ = 1 to 3 do count () done
在使用者端,可以使用提供的事件标签和类型来匹配相关事件。为完整起见,我们假设使用者是不同的程序,并重复定义新的标签构造函数以及自定义事件的注册。
type Runtime_events.User.tag += CustomSpan | CustomInt let count_span = Runtime_events.User.register "count.span" CustomSpan Runtime_events.Type.span let count_value = Runtime_events.User.register "count.value" CustomInt Runtime_events.Type.int let span_event_handler domain_id ts event value = (* we're only interested in our CustomSpan event *) match Runtime_events.User.tag event, value with | CustomSpan, Runtime_events.Type.Begin -> Printf.printf "> count begin\n" | CustomSpan, End -> Printf.printf "< count end\n" | _ -> () let int_event_handler domain_id ts event value = (* we're only interested in our CustomInt event *) match Runtime_events.User.tag event with | CustomInt -> Printf.printf "| count %d\n" value | _ -> () let () = let open Runtime_events in let cursor = create_cursor None in let callbacks = Callbacks.create () |> Callbacks.add_user_event Type.span span_event_handler |> Callbacks.add_user_event Type.int int_event_handler in for _ = 0 to 100 do ignore(read_poll cursor callbacks None) done
给出以下输出
> count begin | count 1 | count 2 | count 3 | count 4 | count 5 < count end > count begin | count 1 | count 2 [...]