在并发过程中,每个viewer会产生一个对应的日志文件,日志文件名为:
viewer_channel_index_20250626_030943_145.log
viewer端日志比master端日志文件数量多,比例大概是5:1,有1个master就会有5个viewer,每个viewer对应一个日志文件。
我要统计的是从启动viewer到出第一帧视频和第一帧音频过程中各节点的时间,大概包括:
- viewer端启动时间点;
- 获取ICE配置时间;
- 连接信令服务时间;
- tls握手时间;
- 从offer发送到收到answer时间;
- dtls初始化完成时间;
- P2P打洞时间;
- 计算收到第一帧音频用时;
- 计算收到第一帧视频用时。
代码实现
#!/bin/bash
log_dir="./log/viewer"
output_csv="viewer_log_analysis.csv"
# 内网IP
# ip_addr=$(hostname -I | awk '{print $1}')
# 获取公网IP
TOKEN=$(curl -X PUT "http://169.254.169.254/latest/api/token" -H "X-aws-ec2-metadata-token-ttl-seconds: 21600" -s)
PUBLIC_IP=$(curl -s -H "X-aws-ec2-metadata-token: $TOKEN" http://169.254.169.254/latest/meta-data/public-ipv4)
# 输出 CSV 表头
echo "host,channel,index,start_time,get_ice_config_signaling_call,connect_signaling_client,tls_handshake_time,offer_sent_to_answer_received_time,dtls_initialization_completion,ice_hole_punching_time,first_audio_time,audio_latency_ms,first_video_time,video_latency_ms,pull_success,stable_audio,stable_video" > "$output_csv"
# 判断帧时间是否稳定(±20%)
is_stable() {
local expected_ms=$1
shift
local -a times=("$@")
local lower=$((expected_ms * 8 / 10))
local upper=$((expected_ms * 12 / 10))
for ((i = 1; i < ${#times[@]}; i++)); do
local diff=$((times[i] - times[i-1]))
if (( diff < lower || diff > upper )); then
return 1
fi
done
return 0
}
# 主分析流程
for log_file in "$log_dir"/viewer_*.log; do
filename=$(basename "$log_file")
channel=$(echo "$filename" | cut -d'_' -f2)
index=$(echo "$filename" | cut -d'_' -f3)
# 用 awk 处理大文件只读一次,提取时间戳
mapfile -t results < <(awk '
function to_millis(t) {
# 时间格式 2025-06-12 07:19:20.039
split(t, a, /[- :\.]/);
# mktime参数格式:YYYY MM DD HH MM SS
sec = mktime(a[1] " " a[2] " " a[3] " " a[4] " " a[5] " " a[6]);
ms = a[7];
return sec * 1000 + ms;
}
BEGIN {
audio_count = 0; video_count = 0;
}
# 记录起始时间和首帧时间(这里存原始时间字符串)
/Initializing WebRTC library/ && !start {
start = $1 " " $2;
start_ms = to_millis(start);
}
/Get ICE config signaling call/ && !ice_config {
match($0, /Time taken: ([0-9]+)/, m);
if (m[1]) ice_config = m[1];
}
/Connect signaling client/ && !signaling_connect {
match($0, /Time taken: ([0-9]+)/, m);
if (m[1]) signaling_connect = m[1];
}
/TLS handshake time/ && !tls_handshake {
match($0, /Time taken: ([0-9]+)/, m);
if (m[1]) tls_handshake = m[1];
}
/Offer Sent to Answer Received time/ && !sdp_answer_delay {
match($0, /Time taken: ([0-9]+)/, m);
if (m[1]) sdp_answer_delay = m[1];
}
/DTLS initialization completion/ && !dtls_init {
match($0, /Time taken: ([0-9]+)/, m);
if (m[1]) dtls_init = m[1];
}
/ICE Hole Punching Time/ && !ice_punching {
match($0, /Time taken: ([0-9]+)/, m);
if (m[1]) ice_punching = m[1];
}
/Audio Frame received/ && $0 !~ /Size: 0/ {
if (!audio_first) {
audio_first = $1 " " $2;
audio_first_ms = to_millis(audio_first);
}
if (audio_count < 30) {
audio_ms[audio_count++] = to_millis($1 " " $2);
}
}
/Video Frame received/ && $0 !~ /Size: 0/ {
if (!video_first) {
video_first = $1 " " $2;
video_first_ms = to_millis(video_first);
}
if (video_count < 30) {
video_ms[video_count++] = to_millis($1 " " $2);
}
}
END {
print start;
print ice_config + 0;
print signaling_connect + 0;
print tls_handshake + 0;
print sdp_answer_delay + 0;
print dtls_init + 0;
print ice_punching + 0;
print audio_first;
print video_first;
print start_ms;
print audio_first_ms;
print video_first_ms;
for (i = 0; i < audio_count; i++) print "A " audio_ms[i];
for (i = 0; i < video_count; i++) print "V " video_ms[i];
}'