Compare commits
4 Commits
20b2050706
...
main
| Author | SHA1 | Date | |
|---|---|---|---|
|
df7947c500 | ||
|
|
4b95d26f13 | ||
|
|
ed1cb20da8 | ||
|
|
9f64c9fc49 |
4
.gitignore
vendored
4
.gitignore
vendored
@@ -21,8 +21,4 @@ compile_commands.json
|
||||
# 忽略程序运行生成的日志文件（csv, log等）
|
||||
*.log
|
||||
*.csv
|
||||
# 忽略测试用的视频或大文件
|
||||
*.mp4
|
||||
*.avi
|
||||
*.dat
|
||||
*.jsonl
|
||||
113
README.md
113
README.md
@@ -211,3 +211,116 @@ put /path/to/file.bin
|
||||
- 该场景已经实现 `A -> C -> D -> B` 与 `B -> D -> C -> A` 的桥接转发
|
||||
- 但当前 `bridge` 仍是单下游、单身份模型，不是完整的多节点桥接网络
|
||||
|
||||
## 日志与指标
|
||||
|
||||
### 输出位置
|
||||
|
||||
- 终端文本日志：默认输出到 `stderr`，格式为 `key=value`
|
||||
- 结构化日志：默认追加到当前工作目录下的 `omni_logs.jsonl`
|
||||
- 性能快照统一写在 `component="perf"` 的 JSONL 记录里
|
||||
- 终端里会额外出现 `component=perf_udp_loss` 文本行；同一批 UDP 丢包字段已经合并写进对应的 `component="perf"` JSONL 行
|
||||
- 周期性性能快照大约每 `1s` 打一次；进程退出时会再打一条 `tag="final"`
|
||||
|
||||
### 当前文档口径
|
||||
|
||||
下面这些说法要以当前实现为准，不要再按旧文档理解：
|
||||
|
||||
- `processing / queue / transmission / propagation / end_to_end` 都是“当前实现下的本地观测值或估算值”，不是严格意义上的物理链路精确测量值。
|
||||
- `processing_*` 当前表示本地应用层处理耗时，主要来自文件分片封装、接收端写盘等路径；它不是“某一块硬件 CPU 的完整开销画像”。
|
||||
- `queue_*` 和 `transmission_*` 是基于最近活跃窗口的吞吐和缓冲/队列状态反推出来的估算值。最近没有足够流量样本、样本太小或者当前速率太低时，这两个值可能直接为 `0`。
|
||||
- `propagation_*` 当前来自 `min_rtt_ms / 2` 的估算；如果当前协议没有 RTT 样本，这组字段就是 `0`。
|
||||
- `end_to_end_*` 当前只在“最终接收文件的 peer”上有值，来源是发送端分片里的 `origin_ts_ms`。发送文件前会先做一次时钟同步，把发送端时间对齐到接收端时钟域；如果同步没建立，这组字段会保持 `0`，而不是给出误导性的跨机结果。
|
||||
- UDP 丢包统计只在 `UDP 文件接收侧 peer` 上有值；UDP 发送侧、Hub、Bridge 不会产出这组汇总。
|
||||
- `udp_retrans` 字段当前还没有实现应用层 UDP 重传统计，所以现在始终是 `0`。
|
||||
- `TCP/KCP` 当前记录的是重传次数/重传字节/累计发送分片，不直接记录“重传频率”这个单独字段。
|
||||
- `send_buffer_pct_*` / `recv_buffer_pct_*` 是占用率风格的指标，但不保证永远严格落在 `0-100`；尤其 KCP 等待队列超过窗口时，理论上可以大于 `100`。
|
||||
- `send_call_* / recv_call_* / proto_* / processing_*` 有时会是 `0`，常见原因不是没统计，而是当前时间分辨率是毫秒，很多本地操作小于 `1ms`。
|
||||
|
||||
### 基础与吞吐字段
|
||||
|
||||
| 文档含义 | JSONL 字段 | 单位 | 当前语义 | 什么时候有值 / 为什么会是 0 |
|
||||
| --- | --- | --- | --- | --- |
|
||||
| 时间戳 | `ts_ms` | ms | 这条日志写出的单调时间戳 | 始终有值 |
|
||||
| 日志分类 | `level` / `component` / `tag` | - | `component="perf"` 表示性能快照，`tag` 常见为 `peer_transport_send`、`peer_transport_recv`、`final` | 始终有值 |
|
||||
| 身份上下文 | `app` / `proto` / `mode` / `role` / `self_id` | - | 程序名、协议、模式、角色、逻辑 ID | `hub` 的 `self_id` 为空是正常的 |
|
||||
| 运行时长 | `elapsed_ms` | ms | 当前进程从启动到本次快照的时长 | 始终有值 |
|
||||
| 累计发送字节 | `bytes_sent` | bytes | 当前进程累计发送的协议帧总字节 | 无发送时为 `0` |
|
||||
| 累计接收字节 | `bytes_recv` | bytes | 当前进程累计接收的协议帧总字节 | 无接收时为 `0` |
|
||||
| 发送次数 | `send_count` | count | 当前进程累计发送帧次数 | 无发送时为 `0` |
|
||||
| 接收次数 | `recv_count` | count | 当前进程累计接收帧次数 | 无接收时为 `0` |
|
||||
| 瞬时发送带宽 | `tx_current_mbps` | Mbps | 最近一个统计窗口内的发送速率 | 当前窗口没流量时为 `0` |
|
||||
| 瞬时接收带宽 | `rx_current_mbps` | Mbps | 最近一个统计窗口内的接收速率 | 当前窗口没流量时为 `0` |
|
||||
| 平均发送带宽 | `tx_avg_mbps` | Mbps | 进程启动到当前的平均发送速率 | 从未发送时为 `0` |
|
||||
| 平均接收带宽 | `rx_avg_mbps` | Mbps | 进程启动到当前的平均接收速率 | 从未接收时为 `0` |
|
||||
| 传输进度字节 | `progress_bytes` | bytes | 当前文件传输已完成字节数 | 没有文件传输时为 `0` |
|
||||
| 总工作量 | `total_work_bytes` | bytes | 当前文件总大小 | 没有文件传输时为 `0` |
|
||||
| 传输进度百分比 | `progress_pct` | % | `progress_bytes / total_work_bytes * 100` | 没有文件传输时为 `0` |
|
||||
|
||||
### 调用耗时与延迟字段
|
||||
|
||||
| 文档含义 | JSONL 字段 | 单位 | 当前语义 | 什么时候有值 / 为什么会是 0 |
|
||||
| --- | --- | --- | --- | --- |
|
||||
| 应用层发送调用 | `send_call_last_ms` / `send_call_min_ms` / `send_call_max_ms` / `send_call_avg_ms` | ms | `peer_transport_send()` 调用耗时 | 没有发送，或每次发送都小于 `1ms` 时可能为 `0` |
|
||||
| 应用层接收调用 | `recv_call_last_ms` / `recv_call_min_ms` / `recv_call_max_ms` / `recv_call_avg_ms` | ms | `peer_transport_next_event()` 接收调用耗时 | 没有接收，或每次接收都小于 `1ms` 时可能为 `0` |
|
||||
| 协议层发送耗时 | `proto_send_avg_ms` | ms | TCP/UDP/KCP 实际 send 路径耗时 EWMA | 发送很快且小于 `1ms` 时常为 `0` |
|
||||
| 协议层接收耗时 | `proto_recv_avg_ms` | ms | TCP/UDP/KCP 实际 recv 路径耗时 EWMA | 接收很快且小于 `1ms` 时常为 `0` |
|
||||
| 本地处理耗时 | `processing_avg_ms` / `processing_min_ms` / `processing_max_ms` | ms | 当前进程内的分片封装、写盘等本地处理耗时 | 仅在文件发送/接收路径上采样；操作太快时可能为 `0` |
|
||||
| 排队延迟估算 | `queue_avg_ms` / `queue_min_ms` / `queue_max_ms` | ms | 根据发送/接收队列字节数和最近活跃窗口速率估算 | 没有足够活跃样本时为 `0`；小样本/低速率时可能偏保守 |
|
||||
| 传输延迟估算 | `transmission_avg_ms` / `transmission_min_ms` / `transmission_max_ms` | ms | 根据最近活跃窗口速率估算“这些字节推上链路需要多久” | 没有足够活跃样本时为 `0`；小样本/低速率时可能偏保守 |
|
||||
| 传播延迟估算 | `propagation_avg_ms` / `propagation_min_ms` / `propagation_max_ms` | ms | 基于 `min_rtt_ms / 2` 的估算 | 当前协议没有 RTT 样本时为 `0` |
|
||||
| 端到端延迟 | `end_to_end_avg_ms` / `end_to_end_min_ms` / `end_to_end_max_ms` | ms | 发送端分片 `origin_ts_ms` 对齐到接收端时钟后，到接收端处理完成时刻的差值 | 只在最终接收文件的 `peer` 上有值；若时钟同步未建立则为 `0` |
|
||||
|
||||
### 可靠性字段
|
||||
|
||||
| 文档含义 | JSONL 字段 | 单位 | 当前语义 | 什么时候有值 / 为什么会是 0 |
|
||||
| --- | --- | --- | --- | --- |
|
||||
| TCP 重传次数 | `tcp_retrans` | count | 内核 `TCP_INFO` 的累计重传次数 | 仅 TCP 有值；未重传或非 TCP 时为 `0` |
|
||||
| TCP 数据段数 | `tcp_data_segs_out` | count | TCP 累计发送数据段数 | 仅 TCP 有值；非 TCP 时为 `0` |
|
||||
| TCP 发送字节 | `tcp_data_bytes_sent` | bytes | TCP 累计发送数据字节 | 仅 TCP 有值；非 TCP 时为 `0` |
|
||||
| TCP 重传字节 | `tcp_retrans_bytes` | bytes | TCP 累计重传字节 | 仅 TCP 有值；未重传或非 TCP 时为 `0` |
|
||||
| UDP 重传次数 | `udp_retrans` | count | 预留字段，当前未实现 | 当前始终为 `0` |
|
||||
| KCP 重传次数 | `kcp_retrans` | count | KCP 内部累计重传分片数 | 仅 KCP 有值；未重传或非 KCP 时为 `0` |
|
||||
| KCP 数据分片数 | `kcp_data_segs_out` | count | KCP 累计发送分片数 | 仅 KCP 有值；非 KCP 时为 `0` |
|
||||
| KCP 发送字节 | `kcp_data_bytes_sent` | bytes | KCP 累计发送分片字节 | 仅 KCP 有值；非 KCP 时为 `0` |
|
||||
| KCP 重传字节 | `kcp_retrans_bytes` | bytes | KCP 累计重传字节 | 仅 KCP 有值；未重传或非 KCP 时为 `0` |
|
||||
| UDP 预期分片数 | `udp_expected_chunks` | count | UDP 文件接收端预期应收到的总分片数 | 仅 UDP 文件接收侧 `peer` 有值；其他角色为 `0` |
|
||||
| UDP 实收分片数 | `udp_received_chunks` | count | UDP 文件接收端实际收到的唯一分片数 | 仅 UDP 文件接收侧 `peer` 有值；其他角色为 `0` |
|
||||
| UDP 丢失分片数 | `udp_lost_chunks` | count | 根据 `seq` 推断的缺失分片数 | 完整收到时为 `0`；非 UDP 接收侧也为 `0` |
|
||||
| UDP 丢包率 | `udp_loss_rate_pct` | % | `udp_lost_chunks / udp_expected_chunks * 100` | 完整收到时为 `0`；非 UDP 接收侧也为 `0` |
|
||||
| UDP 连续丢包区间数 | `udp_loss_burst_count` | count | 丢包区间个数 | 无丢包时为 `0` |
|
||||
| UDP 最大连续丢包长度 | `udp_loss_burst_max_len` | count | 单个丢包区间的最大长度 | 无丢包时为 `0` |
|
||||
| UDP 丢包区间摘要 | `udp_loss_ranges` | csv string | 例如 `4-6,9,12-13` | 无丢包时为空串 |
|
||||
| UDP 丢失序号样本 | `udp_loss_seq_sample` | csv string | 最多记录一部分缺失 `seq` 样本 | 无丢包时为空串 |
|
||||
| UDP 接收窗口分布 | `udp_recv_window_dist` | csv string | `window_id:count`，例如 `0:3,1:28` | 仅 UDP 接收侧有值；没有样本时为空串 |
|
||||
|
||||
### 资源与算法字段
|
||||
|
||||
| 文档含义 | JSONL 字段 | 单位 | 当前语义 | 什么时候有值 / 为什么会是 0 |
|
||||
| --- | --- | --- | --- | --- |
|
||||
| 发送缓冲区占用 | `send_buffer_pct_last` / `send_buffer_pct_avg` / `send_buffer_pct_max` | % 风格值 | Socket 或 KCP 发送队列占用率样本 | 没有缓冲采样时为 `0`；KCP 拥塞时可能大于 `100` |
|
||||
| 接收缓冲区占用 | `recv_buffer_pct_last` / `recv_buffer_pct_avg` / `recv_buffer_pct_max` | % 风格值 | Socket 或 KCP 接收队列占用率样本 | 没有缓冲采样时为 `0` |
|
||||
| 拥塞窗口 | `cwnd_last` / `cwnd_avg` / `cwnd_max` | 协议窗口大小 | TCP/KCP 当前拥塞窗口样本 | UDP 没有拥塞窗口，因此为 `0` |
|
||||
| RTT | `last_rtt_ms` / `min_rtt_ms` / `max_rtt_ms` | ms | TCP `TCP_INFO` 或 KCP `rx_srtt` 的 RTT 样本 | UDP 当前没有 RTT 探测，因此为 `0` |
|
||||
|
||||
### 实测样本
|
||||
|
||||
以下值来自本仓库当前实现的本地回环测试，仅用于说明“字段已经能落到 JSONL 且当前名字是什么”，不是固定性能指标。
|
||||
|
||||
| 样本 | 关键字段 | 实测值 |
|
||||
| --- | --- | --- |
|
||||
| `TCP` 点对点直传发送端 | `progress_pct` / `cwnd_last` / `last_rtt_ms` / `tcp_data_bytes_sent` | `100` / `10` / `1` / `287984` |
|
||||
| `UDP` Hub 中转接收端 | `progress_pct` / `udp_expected_chunks` / `udp_received_chunks` / `udp_lost_chunks` / `udp_recv_window_dist` | `100` / `3` / `3` / `0` / `0:3` |
|
||||
| `KCP` Bridge 桥接节点 | `cwnd_last` / `last_rtt_ms` / `kcp_data_bytes_sent` / `queue_avg_ms` | `2` / `7` / `265` / `33991.342083` |
|
||||
| `KCP` 最终接收端 | `progress_pct` / `end_to_end_avg_ms` / `cwnd_last` | `100` / `121.333333` / `2` |
|
||||
|
||||
### 为什么有些字段“存在但没有值”
|
||||
|
||||
| 情况 | 典型字段 | 说明 |
|
||||
| --- | --- | --- |
|
||||
| 协议不适用 | `tcp_*` 出现在 UDP/KCP；`kcp_*` 出现在 TCP/UDP；`cwnd_*` 出现在 UDP | 字段统一保留，便于同一份 JSONL 脚本处理；不适用的协议就写 `0` |
|
||||
| 还没实现 | `udp_retrans` | 现在没有应用层 UDP 重传，所以这个字段只是预留 |
|
||||
| 当前角色不产出 | `udp_expected_chunks`、`udp_loss_*`、`end_to_end_*` | UDP 丢包统计只在最终接收文件的 UDP peer 上有值；`end_to_end_*` 也主要只在最终接收端有值 |
|
||||
| 没有采样到 RTT | `last_rtt_ms`、`propagation_*` | UDP 当前没有 RTT 探针；TCP/KCP 只有在拿到对应协议样本后才有值 |
|
||||
| 没有建立时钟同步 | `end_to_end_*` | 发送端尚未和接收端完成 `TIME_SYNC_*` 探测，或同步结果太旧/未到达 |
|
||||
| 时间分辨率太粗 | `send_call_*`、`proto_send_avg_ms`、`processing_*` | 当前很多路径按毫秒计时，本地回环下大量操作小于 `1ms`，所以会显示 `0` |
|
||||
| 当前没有任务 | `progress_*` | 只注册但没有文件传输时，这组字段自然是 `0` |
|
||||
|
||||
@@ -17,6 +17,10 @@ typedef struct OmniMetricSummary {
|
||||
double sum;
|
||||
} OmniMetricSummary;
|
||||
|
||||
#define OMNI_LOGGER_UDP_RANGES_SIZE 512u
|
||||
#define OMNI_LOGGER_UDP_SEQ_SAMPLE_SIZE 512u
|
||||
#define OMNI_LOGGER_UDP_WINDOW_DIST_SIZE 512u
|
||||
|
||||
/* 通过该结构体收集全局统计信息 */
|
||||
typedef struct OmniStats {
|
||||
uint64_t start_ms; /* 起始时间（毫秒） */
|
||||
@@ -27,6 +31,12 @@ typedef struct OmniStats {
|
||||
uint64_t bytes_recv; /* 接收总字节数 */
|
||||
uint64_t window_bytes_sent; /* 当前 1 秒窗口发送字节数 */
|
||||
uint64_t window_bytes_recv; /* 当前 1 秒窗口接收字节数 */
|
||||
uint64_t delay_window_start_send_ms; /* 延时估算使用的最近发送活跃窗口起点 */
|
||||
uint64_t delay_window_start_recv_ms; /* 延时估算使用的最近接收活跃窗口起点 */
|
||||
uint64_t delay_window_bytes_sent; /* 延时估算使用的最近发送活跃窗口字节数 */
|
||||
uint64_t delay_window_bytes_recv; /* 延时估算使用的最近接收活跃窗口字节数 */
|
||||
uint64_t last_send_activity_ms; /* 最近一次发送活跃时间 */
|
||||
uint64_t last_recv_activity_ms; /* 最近一次接收活跃时间 */
|
||||
|
||||
uint64_t send_count; /* 调用 omni_send 次数 */
|
||||
uint64_t recv_count; /* 调用 omni_recv 次数 */
|
||||
@@ -44,6 +54,15 @@ typedef struct OmniStats {
|
||||
uint64_t kcp_data_segs_out; /* KCP 累计发送的数据分片数（含重传） */
|
||||
uint64_t kcp_data_bytes_sent; /* KCP 累计发送的数据字节（含重传） */
|
||||
uint64_t kcp_retrans_bytes; /* KCP 累计重传的数据字节 */
|
||||
uint64_t udp_expected_chunks; /* UDP 文件接收侧预期分片数 */
|
||||
uint64_t udp_received_chunks; /* UDP 文件接收侧实际收到的分片数 */
|
||||
uint64_t udp_lost_chunks; /* UDP 文件接收侧推断丢失的分片数 */
|
||||
uint64_t udp_loss_burst_count; /* UDP 丢包区间数量 */
|
||||
uint64_t udp_loss_burst_max_len; /* UDP 最大连续丢包长度 */
|
||||
double udp_loss_rate_pct; /* UDP 丢包率（百分比） */
|
||||
char udp_loss_ranges[OMNI_LOGGER_UDP_RANGES_SIZE]; /* UDP 丢包区间摘要 */
|
||||
char udp_loss_seq_sample[OMNI_LOGGER_UDP_SEQ_SAMPLE_SIZE]; /* UDP 丢包序号样本 */
|
||||
char udp_recv_window_dist[OMNI_LOGGER_UDP_WINDOW_DIST_SIZE]; /* UDP 接收窗口分布 */
|
||||
|
||||
/* 延迟/耗时统计（单位：毫秒） */
|
||||
double send_call_avg_ms; /* omni_send 平均耗时（EWMA） */
|
||||
@@ -126,6 +145,15 @@ void logger_on_cwnd(double cwnd);
|
||||
/* 记录任务总量与当前进度。 */
|
||||
void logger_set_transfer_total(uint64_t total_bytes);
|
||||
void logger_set_progress(uint64_t progress_bytes);
|
||||
void logger_reset_transfer_observability(void);
|
||||
void logger_on_udp_loss_summary(uint64_t expected_chunks,
|
||||
uint64_t received_chunks,
|
||||
uint64_t lost_chunks,
|
||||
uint64_t burst_count,
|
||||
uint64_t burst_max_len,
|
||||
const char *ranges,
|
||||
const char *seq_sample,
|
||||
const char *recv_window_dist);
|
||||
|
||||
/* 计算当前吞吐量（返回：字节/秒） */
|
||||
double logger_calculate_throughput(void);
|
||||
|
||||
112
omni_logs.jsonl
112
omni_logs.jsonl
@@ -1,112 +0,0 @@
|
||||
{"ts_ms":60184657,"level":"INFO","component":"peer_transport","message":"open role=1 proto=tcp bind_port=9003 peer_ip=- peer_port=0"}
|
||||
{"ts_ms":60184657,"level":"INFO","component":"hub","message":"listening bind_ip=0.0.0.0 port=9003 proto=tcp"}
|
||||
{"ts_ms":60193231,"level":"INFO","component":"peer_transport","message":"open role=0 proto=tcp bind_port=0 peer_ip=127.0.0.1 peer_port=9003"}
|
||||
{"ts_ms":60193231,"level":"INFO","component":"peer_transport","message":"tcp_session_accepted remote=127.0.0.1:37670"}
|
||||
{"ts_ms":60193231,"level":"INFO","component":"peer_transport","message":"open role=1 proto=tcp bind_port=9004 peer_ip=- peer_port=0"}
|
||||
{"ts_ms":60193231,"level":"INFO","component":"bridge","message":"listening bind_ip=0.0.0.0 listen_port=9004 upstream=127.0.0.1:9003 proto=tcp client_id=jetson"}
|
||||
{"ts_ms":60193231,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":8574,"bytes_sent":0,"bytes_recv":52,"send_count":0,"recv_count":1,"tx_current_mbps":0.000000,"rx_current_mbps":0.000049,"tx_avg_mbps":0.000000,"rx_avg_mbps":0.000049,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":8574.000000,"transmission_min_ms":8574.000000,"transmission_max_ms":8574.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60193231,"level":"INFO","component":"hub","message":"client_registered client_id=jetson remote=127.0.0.1:37670"}
|
||||
{"ts_ms":60193231,"level":"WARN","component":"bridge","message":"downstream_forward_skipped type=10 len=168"}
|
||||
{"ts_ms":60224258,"level":"INFO","component":"peer_transport","message":"open role=0 proto=tcp bind_port=0 peer_ip=127.0.0.1 peer_port=9004"}
|
||||
{"ts_ms":60224277,"level":"INFO","component":"peer_transport","message":"tcp_session_accepted remote=127.0.0.1:39160"}
|
||||
{"ts_ms":60224277,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":31046,"bytes_sent":52,"bytes_recv":236,"send_count":1,"recv_count":2,"tx_current_mbps":0.000013,"rx_current_mbps":0.000061,"tx_avg_mbps":0.000013,"rx_avg_mbps":0.000061,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":6840.644068,"transmission_min_ms":6840.644068,"transmission_max_ms":6840.644068,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60231317,"level":"INFO","component":"peer_transport","message":"open role=0 proto=tcp bind_port=0 peer_ip=127.0.0.1 peer_port=9003"}
|
||||
{"ts_ms":60231317,"level":"INFO","component":"peer_transport","message":"tcp_session_accepted remote=127.0.0.1:51040"}
|
||||
{"ts_ms":60231317,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":46660,"bytes_sent":184,"bytes_recv":104,"send_count":1,"recv_count":2,"tx_current_mbps":0.000039,"rx_current_mbps":0.000011,"tx_avg_mbps":0.000032,"rx_avg_mbps":0.000018,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":18411.333333,"transmission_min_ms":8574.000000,"transmission_max_ms":38086.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60231317,"level":"INFO","component":"hub","message":"client_registered client_id=pc remote=127.0.0.1:51040"}
|
||||
{"ts_ms":60231317,"level":"INFO","component":"hub","message":"peer_bound client_id=pc peer_id=jetson"}
|
||||
{"ts_ms":60279607,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"pc","tag":"peer_transport_send","elapsed_ms":48290,"bytes_sent":208,"bytes_recv":368,"send_count":3,"recv_count":2,"tx_current_mbps":0.000034,"rx_current_mbps":0.000061,"tx_avg_mbps":0.000034,"rx_avg_mbps":0.000061,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":24145.000000,"transmission_min_ms":24145.000000,"transmission_max_ms":24145.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60279607,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":94950,"bytes_sent":552,"bytes_recv":260,"send_count":3,"recv_count":4,"tx_current_mbps":0.000061,"rx_current_mbps":0.000026,"tx_avg_mbps":0.000047,"rx_avg_mbps":0.000022,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":20266.285714,"transmission_min_ms":8574.000000,"transmission_max_ms":38086.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60279607,"level":"INFO","component":"hub","message":"forward_ok src_id=pc dst_id=jetson inner_type=3 payload_bytes=16"}
|
||||
{"ts_ms":60279607,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":86376,"bytes_sent":236,"bytes_recv":340,"send_count":2,"recv_count":3,"tx_current_mbps":0.000027,"rx_current_mbps":0.000015,"tx_avg_mbps":0.000022,"rx_avg_mbps":0.000031,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":28792.000000,"transmission_min_ms":6840.644068,"transmission_max_ms":55330.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60279608,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":55350,"bytes_sent":52,"bytes_recv":288,"send_count":1,"recv_count":2,"tx_current_mbps":0.000008,"rx_current_mbps":0.000042,"tx_avg_mbps":0.000008,"rx_avg_mbps":0.000042,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":6669.166667,"transmission_min_ms":1.000000,"transmission_max_ms":19987.500000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60312812,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"jetson","tag":"peer_transport_send","elapsed_ms":88554,"bytes_sent":104,"bytes_recv":288,"send_count":2,"recv_count":2,"tx_current_mbps":0.000013,"rx_current_mbps":0.000000,"tx_avg_mbps":0.000009,"rx_avg_mbps":0.000026,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":13302.875000,"transmission_min_ms":1.000000,"transmission_max_ms":33204.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60312861,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":119630,"bytes_sent":340,"bytes_recv":392,"send_count":3,"recv_count":4,"tx_current_mbps":0.000025,"rx_current_mbps":0.000013,"tx_avg_mbps":0.000023,"rx_avg_mbps":0.000026,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":23926.200000,"transmission_min_ms":1.000000,"transmission_max_ms":55330.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60312861,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":128204,"bytes_sent":656,"bytes_recv":312,"send_count":4,"recv_count":5,"tx_current_mbps":0.000025,"rx_current_mbps":0.000013,"tx_avg_mbps":0.000041,"rx_avg_mbps":0.000019,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":21130.116531,"transmission_min_ms":8574.000000,"transmission_max_ms":38086.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60312861,"level":"INFO","component":"hub","message":"peer_bound client_id=jetson peer_id=pc"}
|
||||
{"ts_ms":60324031,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"jetson","tag":"peer_transport_send","elapsed_ms":99773,"bytes_sent":206,"bytes_recv":472,"send_count":3,"recv_count":3,"tx_current_mbps":0.000073,"rx_current_mbps":0.000131,"tx_avg_mbps":0.000017,"rx_avg_mbps":0.000038,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":10746.583333,"transmission_min_ms":1.000000,"transmission_max_ms":33204.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60324079,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":130848,"bytes_sent":576,"bytes_recv":678,"send_count":5,"recv_count":6,"tx_current_mbps":0.000168,"rx_current_mbps":0.000204,"tx_avg_mbps":0.000035,"rx_avg_mbps":0.000041,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":23992.376519,"transmission_min_ms":1.000000,"transmission_max_ms":55330.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60324079,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":139422,"bytes_sent":840,"bytes_recv":414,"send_count":5,"recv_count":6,"tx_current_mbps":0.000131,"rx_current_mbps":0.000073,"tx_avg_mbps":0.000048,"rx_avg_mbps":0.000024,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":20861.075430,"transmission_min_ms":8574.000000,"transmission_max_ms":38086.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60324080,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=3 payload_bytes=14"}
|
||||
{"ts_ms":60324080,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"pc","tag":"peer_transport_recv","elapsed_ms":92763,"bytes_sent":208,"bytes_recv":470,"send_count":3,"recv_count":3,"tx_current_mbps":0.000000,"rx_current_mbps":0.000018,"tx_avg_mbps":0.000018,"rx_avg_mbps":0.000041,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":34309.000000,"transmission_min_ms":24145.000000,"transmission_max_ms":44473.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60427730,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"jetson","tag":"peer_transport_send","elapsed_ms":203472,"bytes_sent":1742,"bytes_recv":472,"send_count":4,"recv_count":3,"tx_current_mbps":0.000118,"rx_current_mbps":0.000000,"tx_avg_mbps":0.000068,"rx_avg_mbps":0.000019,"progress_bytes":0,"total_work_bytes":89600,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":24025.500000,"transmission_min_ms":1.000000,"transmission_max_ms":103699.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60427730,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":234499,"bytes_sent":678,"bytes_recv":2214,"send_count":6,"recv_count":7,"tx_current_mbps":0.000008,"rx_current_mbps":0.000119,"tx_avg_mbps":0.000023,"rx_avg_mbps":0.000076,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":30842.498728,"transmission_min_ms":1.000000,"transmission_max_ms":103651.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60427731,"level":"INFO","component":"peer","message":"file_send_done self_id=jetson dst_id=pc file=/tmp/input2.bin bytes=89600 chunks=64"}
|
||||
{"ts_ms":60427731,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":243074,"bytes_sent":942,"bytes_recv":1950,"send_count":6,"recv_count":7,"tx_current_mbps":0.000008,"rx_current_mbps":0.000119,"tx_avg_mbps":0.000031,"rx_avg_mbps":0.000064,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":25624.986903,"transmission_min_ms":1.000000,"transmission_max_ms":103652.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60427731,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60427731,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"pc","tag":"peer_transport_recv","elapsed_ms":196414,"bytes_sent":208,"bytes_recv":2006,"send_count":3,"recv_count":4,"tx_current_mbps":0.000000,"rx_current_mbps":0.000119,"tx_avg_mbps":0.000008,"rx_avg_mbps":0.000082,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":57423.000000,"transmission_min_ms":24145.000000,"transmission_max_ms":103651.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60427781,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60427831,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60427881,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60427931,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60427981,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428032,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428082,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428132,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428182,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428232,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428282,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428332,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428383,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428433,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428483,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428533,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428583,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428633,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428684,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428734,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":235503,"bytes_sent":31398,"bytes_recv":32934,"send_count":26,"recv_count":27,"tx_current_mbps":0.244781,"rx_current_mbps":0.244781,"tx_avg_mbps":0.001067,"rx_avg_mbps":0.001119,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":9878.127166,"transmission_min_ms":1.000000,"transmission_max_ms":162687.653117,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60428734,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":244077,"bytes_sent":31662,"bytes_recv":32670,"send_count":26,"recv_count":27,"tx_current_mbps":0.245025,"rx_current_mbps":0.245025,"tx_avg_mbps":0.001038,"rx_avg_mbps":0.001071,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":9162.620181,"transmission_min_ms":1.000000,"transmission_max_ms":150670.566586,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60428734,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428734,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"pc","tag":"peer_transport_recv","elapsed_ms":197417,"bytes_sent":208,"bytes_recv":32726,"send_count":3,"recv_count":24,"tx_current_mbps":0.000000,"rx_current_mbps":0.245025,"tx_avg_mbps":0.000008,"rx_avg_mbps":0.001326,"progress_bytes":28000,"total_work_bytes":89600,"progress_pct":31.250000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":7533.517894,"transmission_min_ms":50.000000,"transmission_max_ms":103651.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60428784,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428834,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428884,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428934,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60428985,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429035,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429085,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429135,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429185,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429235,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429285,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429336,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429386,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429436,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429486,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429536,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429587,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429637,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429687,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429737,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":236506,"bytes_sent":62118,"bytes_recv":63654,"send_count":46,"recv_count":47,"tx_current_mbps":0.245025,"rx_current_mbps":0.245025,"tx_avg_mbps":0.002101,"rx_avg_mbps":0.002153,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":5676.833756,"transmission_min_ms":1.000000,"transmission_max_ms":162687.653117,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60429737,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":245080,"bytes_sent":62382,"bytes_recv":63390,"send_count":46,"recv_count":47,"tx_current_mbps":0.245025,"rx_current_mbps":0.245025,"tx_avg_mbps":0.002036,"rx_avg_mbps":0.002069,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":5362.753952,"transmission_min_ms":1.000000,"transmission_max_ms":150670.566586,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60429737,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429737,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"pc","tag":"peer_transport_recv","elapsed_ms":198420,"bytes_sent":208,"bytes_recv":63446,"send_count":3,"recv_count":44,"tx_current_mbps":0.000000,"rx_current_mbps":0.245025,"tx_avg_mbps":0.000008,"rx_avg_mbps":0.002558,"progress_bytes":56000,"total_work_bytes":89600,"progress_pct":62.500000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":4052.873529,"transmission_min_ms":50.000000,"transmission_max_ms":103651.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60429787,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429838,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429888,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429938,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60429988,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430038,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430089,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430139,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430189,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430239,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430289,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430339,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430389,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430440,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430490,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430540,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430590,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430640,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430690,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430740,"level":"INFO","component":"perf","app":"bridge","proto":"tcp","mode":"bridge","role":"relay","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":237509,"bytes_sent":92838,"bytes_recv":94374,"send_count":66,"recv_count":67,"tx_current_mbps":0.245025,"rx_current_mbps":0.245025,"tx_avg_mbps":0.003127,"rx_avg_mbps":0.003179,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":4000.956462,"transmission_min_ms":1.000000,"transmission_max_ms":162687.653117,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60430741,"level":"INFO","component":"perf","app":"hub","proto":"tcp","mode":"hub","role":"server","self_id":"","tag":"peer_transport_recv","elapsed_ms":246084,"bytes_sent":93102,"bytes_recv":94110,"send_count":66,"recv_count":67,"tx_current_mbps":0.244781,"rx_current_mbps":0.244781,"tx_avg_mbps":0.003027,"rx_avg_mbps":0.003059,"progress_bytes":0,"total_work_bytes":0,"progress_pct":0.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":3807.918914,"transmission_min_ms":1.000000,"transmission_max_ms":150670.566586,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60430741,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430741,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"pc","tag":"peer_transport_recv","elapsed_ms":199424,"bytes_sent":208,"bytes_recv":94166,"send_count":3,"recv_count":64,"tx_current_mbps":0.000000,"rx_current_mbps":0.244781,"tx_avg_mbps":0.000008,"rx_avg_mbps":0.003778,"progress_bytes":84000,"total_work_bytes":89600,"progress_pct":93.750000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":2782.187738,"transmission_min_ms":50.000000,"transmission_max_ms":103651.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
{"ts_ms":60430791,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430841,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430891,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=1 payload_bytes=1448"}
|
||||
{"ts_ms":60430941,"level":"INFO","component":"hub","message":"forward_ok src_id=jetson dst_id=pc inner_type=2 payload_bytes=24"}
|
||||
{"ts_ms":60430941,"level":"INFO","component":"hub","message":"forward_ok src_id=pc dst_id=jetson inner_type=4 payload_bytes=32"}
|
||||
{"ts_ms":60430941,"level":"INFO","component":"perf","app":"peer","proto":"tcp","mode":"hub","role":"client","self_id":"jetson","tag":"peer_transport_recv","elapsed_ms":206683,"bytes_sent":98622,"bytes_recv":592,"send_count":68,"recv_count":4,"tx_current_mbps":0.241370,"rx_current_mbps":0.000299,"tx_avg_mbps":0.003817,"rx_avg_mbps":0.000023,"progress_bytes":89600,"total_work_bytes":89600,"progress_pct":100.000000,"send_call_last_ms":0,"send_call_min_ms":0,"send_call_max_ms":0,"send_call_avg_ms":0.000000,"recv_call_last_ms":0,"recv_call_min_ms":0,"recv_call_max_ms":0,"recv_call_avg_ms":0.000000,"proto_send_avg_ms":0.000000,"proto_recv_avg_ms":0.000000,"processing_avg_ms":0.000000,"processing_min_ms":0.000000,"processing_max_ms":0.000000,"queue_avg_ms":0.000000,"queue_min_ms":0.000000,"queue_max_ms":0.000000,"transmission_avg_ms":12456.503949,"transmission_min_ms":0.001156,"transmission_max_ms":103699.000000,"propagation_avg_ms":0.000000,"propagation_min_ms":0.000000,"propagation_max_ms":0.000000,"end_to_end_avg_ms":0.000000,"end_to_end_min_ms":0.000000,"end_to_end_max_ms":0.000000,"send_buffer_pct_last":0.000000,"send_buffer_pct_avg":0.000000,"send_buffer_pct_max":0.000000,"recv_buffer_pct_last":0.000000,"recv_buffer_pct_avg":0.000000,"recv_buffer_pct_max":0.000000,"cwnd_last":0.000000,"cwnd_avg":0.000000,"cwnd_max":0.000000,"last_rtt_ms":0,"min_rtt_ms":0,"max_rtt_ms":0,"tcp_retrans":0,"tcp_data_segs_out":0,"tcp_data_bytes_sent":0,"tcp_retrans_bytes":0,"kcp_retrans":0,"kcp_data_segs_out":0,"kcp_data_bytes_sent":0,"kcp_retrans_bytes":0}
|
||||
@@ -30,6 +30,9 @@
|
||||
#define PEER_MAX_PAYLOAD (PEER_TUNNEL_META_SIZE + 65536u)
|
||||
#define PEER_MAX_CHUNK_SIZE (65536u - TRANSFER_CHUNK_META_SIZE)
|
||||
#define PEER_OUTPUT_PATH_SIZE 512u
|
||||
#define PEER_TIME_SYNC_SAMPLES 4u
|
||||
#define PEER_TIME_SYNC_PROBE_TIMEOUT_MS 400u
|
||||
#define PEER_TIME_SYNC_MAX_AGE_MS 60000u
|
||||
|
||||
typedef enum PeerMode {
|
||||
PEER_MODE_HUB = 0,
|
||||
@@ -42,19 +45,45 @@ typedef struct PeerRecvFileState {
|
||||
uint32_t total_chunks;
|
||||
uint64_t total_bytes;
|
||||
uint64_t bytes_written;
|
||||
uint32_t received_chunks;
|
||||
uint32_t observed_windows;
|
||||
uint8_t *seq_seen;
|
||||
uint32_t *recv_window_counts;
|
||||
size_t recv_window_cap;
|
||||
} PeerRecvFileState;
|
||||
|
||||
typedef struct PeerTimeSyncPeer {
|
||||
struct PeerTimeSyncPeer *next;
|
||||
char peer_id[OMNI_PEER_ID_SIZE];
|
||||
int has_offset;
|
||||
int64_t peer_minus_local_offset_ms;
|
||||
uint64_t best_rtt_ms;
|
||||
uint32_t sample_count;
|
||||
uint64_t last_sync_local_ms;
|
||||
|
||||
int sync_in_progress;
|
||||
int pending_response;
|
||||
uint32_t next_probe_id;
|
||||
uint32_t pending_probe_id;
|
||||
uint64_t pending_send_ts_ms;
|
||||
int64_t sync_best_offset_ms;
|
||||
uint64_t sync_best_rtt_ms;
|
||||
uint32_t sync_success_count;
|
||||
} PeerTimeSyncPeer;
|
||||
|
||||
typedef struct PeerRuntime {
|
||||
PeerTransport *transport;
|
||||
PeerTransportSession *session;
|
||||
PeerMode mode;
|
||||
OmniRole role;
|
||||
OmniProtocol proto;
|
||||
int running;
|
||||
int direct_register_sent;
|
||||
char client_id[OMNI_PEER_ID_SIZE];
|
||||
char bound_peer[OMNI_PEER_ID_SIZE];
|
||||
char output_path[PEER_OUTPUT_PATH_SIZE];
|
||||
PeerRecvFileState rx_file;
|
||||
PeerTimeSyncPeer *time_sync_peers;
|
||||
} PeerRuntime;
|
||||
|
||||
typedef struct StartupActions {
|
||||
@@ -70,6 +99,10 @@ typedef struct StartupActions {
|
||||
|
||||
static volatile sig_atomic_t g_stop = 0;
|
||||
|
||||
static void handle_transport_event(PeerRuntime *rt,
|
||||
const PeerTransportEvent *event,
|
||||
const uint8_t *payload);
|
||||
|
||||
static void on_signal(int signo)
|
||||
{
|
||||
(void)signo;
|
||||
@@ -173,13 +206,329 @@ static void peer_set_bound_peer(PeerRuntime *rt, const char *peer_id)
|
||||
omni_copy_fixed_ascii(rt->bound_peer, sizeof(rt->bound_peer), peer_id);
|
||||
}
|
||||
|
||||
static void close_recv_file(PeerRuntime *rt)
|
||||
static PeerTimeSyncPeer *peer_time_sync_find(PeerRuntime *rt,
|
||||
const char *peer_id,
|
||||
int create)
|
||||
{
|
||||
if (!rt || !rt->rx_file.fp) {
|
||||
PeerTimeSyncPeer *peer;
|
||||
|
||||
if (!rt || !peer_id_is_valid(peer_id)) {
|
||||
return NULL;
|
||||
}
|
||||
|
||||
for (peer = rt->time_sync_peers; peer; peer = peer->next) {
|
||||
if (strcmp(peer->peer_id, peer_id) == 0) {
|
||||
return peer;
|
||||
}
|
||||
}
|
||||
if (!create) {
|
||||
return NULL;
|
||||
}
|
||||
|
||||
peer = (PeerTimeSyncPeer *)calloc(1, sizeof(*peer));
|
||||
if (!peer) {
|
||||
return NULL;
|
||||
}
|
||||
omni_copy_fixed_ascii(peer->peer_id, sizeof(peer->peer_id), peer_id);
|
||||
peer->next_probe_id = 1u;
|
||||
peer->next = rt->time_sync_peers;
|
||||
rt->time_sync_peers = peer;
|
||||
return peer;
|
||||
}
|
||||
|
||||
static void peer_time_sync_clear_transient(PeerTimeSyncPeer *peer)
|
||||
{
|
||||
if (!peer) {
|
||||
return;
|
||||
}
|
||||
peer->sync_in_progress = 0;
|
||||
peer->pending_response = 0;
|
||||
peer->pending_probe_id = 0;
|
||||
peer->pending_send_ts_ms = 0;
|
||||
peer->sync_best_offset_ms = 0;
|
||||
peer->sync_best_rtt_ms = 0;
|
||||
peer->sync_success_count = 0;
|
||||
}
|
||||
|
||||
static void peer_time_sync_free_all(PeerRuntime *rt)
|
||||
{
|
||||
PeerTimeSyncPeer *peer;
|
||||
PeerTimeSyncPeer *next;
|
||||
|
||||
if (!rt) {
|
||||
return;
|
||||
}
|
||||
for (peer = rt->time_sync_peers; peer; peer = next) {
|
||||
next = peer->next;
|
||||
free(peer);
|
||||
}
|
||||
rt->time_sync_peers = NULL;
|
||||
}
|
||||
|
||||
static int peer_time_sync_offset_is_fresh(const PeerTimeSyncPeer *peer, uint64_t now_ms)
|
||||
{
|
||||
if (!peer || !peer->has_offset || peer->last_sync_local_ms == 0) {
|
||||
return 0;
|
||||
}
|
||||
if (now_ms < peer->last_sync_local_ms) {
|
||||
return 0;
|
||||
}
|
||||
return now_ms - peer->last_sync_local_ms <= PEER_TIME_SYNC_MAX_AGE_MS;
|
||||
}
|
||||
|
||||
static int peer_time_sync_local_to_peer_ts(const PeerTimeSyncPeer *peer,
|
||||
uint64_t local_ts_ms,
|
||||
uint64_t *out_peer_ts_ms)
|
||||
{
|
||||
int64_t adjusted;
|
||||
|
||||
if (!peer || !peer->has_offset || !out_peer_ts_ms || local_ts_ms == 0) {
|
||||
return 0;
|
||||
}
|
||||
|
||||
adjusted = (int64_t)local_ts_ms + peer->peer_minus_local_offset_ms;
|
||||
if (adjusted <= 0) {
|
||||
return 0;
|
||||
}
|
||||
*out_peer_ts_ms = (uint64_t)adjusted;
|
||||
return 1;
|
||||
}
|
||||
|
||||
static void close_recv_file(PeerRuntime *rt)
|
||||
{
|
||||
if (!rt) {
|
||||
return;
|
||||
}
|
||||
if (rt->rx_file.fp) {
|
||||
fclose(rt->rx_file.fp);
|
||||
rt->rx_file.fp = NULL;
|
||||
}
|
||||
free(rt->rx_file.seq_seen);
|
||||
free(rt->rx_file.recv_window_counts);
|
||||
memset(&rt->rx_file, 0, sizeof(rt->rx_file));
|
||||
}
|
||||
|
||||
static int recv_file_prepare_tracking(PeerRecvFileState *state, uint32_t total_chunks)
|
||||
{
|
||||
if (!state) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
if (total_chunks == 0) {
|
||||
return OMNI_OK;
|
||||
}
|
||||
state->seq_seen = (uint8_t *)calloc((size_t)total_chunks + 1u, sizeof(uint8_t));
|
||||
if (!state->seq_seen) {
|
||||
return OMNI_ERR_GENERIC;
|
||||
}
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
static int recv_file_ensure_window_capacity(PeerRecvFileState *state, uint32_t window_id)
|
||||
{
|
||||
size_t need;
|
||||
size_t new_cap;
|
||||
uint32_t *new_counts;
|
||||
|
||||
if (!state) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
need = (size_t)window_id + 1u;
|
||||
if (need <= state->recv_window_cap) {
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
new_cap = (state->recv_window_cap == 0) ? 4u : state->recv_window_cap;
|
||||
while (new_cap < need) {
|
||||
new_cap *= 2u;
|
||||
}
|
||||
|
||||
new_counts = (uint32_t *)realloc(state->recv_window_counts,
|
||||
new_cap * sizeof(uint32_t));
|
||||
if (!new_counts) {
|
||||
return OMNI_ERR_GENERIC;
|
||||
}
|
||||
memset(new_counts + state->recv_window_cap,
|
||||
0,
|
||||
(new_cap - state->recv_window_cap) * sizeof(uint32_t));
|
||||
state->recv_window_counts = new_counts;
|
||||
state->recv_window_cap = new_cap;
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
static void recv_file_note_chunk(PeerRecvFileState *state,
|
||||
uint32_t seq,
|
||||
uint32_t window_id)
|
||||
{
|
||||
if (!state || seq == 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
if (recv_file_ensure_window_capacity(state, window_id) == OMNI_OK) {
|
||||
if ((size_t)window_id < state->recv_window_cap) {
|
||||
state->recv_window_counts[window_id]++;
|
||||
}
|
||||
if (window_id + 1u > state->observed_windows) {
|
||||
state->observed_windows = window_id + 1u;
|
||||
}
|
||||
}
|
||||
|
||||
if (!state->seq_seen) {
|
||||
state->received_chunks++;
|
||||
return;
|
||||
}
|
||||
if (state->seq_seen && seq <= state->total_chunks && !state->seq_seen[seq]) {
|
||||
state->seq_seen[seq] = 1;
|
||||
state->received_chunks++;
|
||||
}
|
||||
}
|
||||
|
||||
static void append_csv_uint(char *buf, size_t buf_sz, uint32_t value)
|
||||
{
|
||||
size_t len;
|
||||
|
||||
if (!buf || buf_sz == 0) {
|
||||
return;
|
||||
}
|
||||
len = strlen(buf);
|
||||
if (len >= buf_sz - 1u) {
|
||||
return;
|
||||
}
|
||||
snprintf(buf + len, buf_sz - len, "%s%u", len == 0 ? "" : ",", (unsigned)value);
|
||||
}
|
||||
|
||||
static void append_range(char *buf, size_t buf_sz, uint32_t start, uint32_t end)
|
||||
{
|
||||
size_t len;
|
||||
|
||||
if (!buf || buf_sz == 0) {
|
||||
return;
|
||||
}
|
||||
len = strlen(buf);
|
||||
if (len >= buf_sz - 1u) {
|
||||
return;
|
||||
}
|
||||
if (start == end) {
|
||||
snprintf(buf + len, buf_sz - len, "%s%u", len == 0 ? "" : ",", (unsigned)start);
|
||||
} else {
|
||||
snprintf(buf + len, buf_sz - len, "%s%u-%u",
|
||||
len == 0 ? "" : ",",
|
||||
(unsigned)start,
|
||||
(unsigned)end);
|
||||
}
|
||||
}
|
||||
|
||||
static void append_window_count(char *buf,
|
||||
size_t buf_sz,
|
||||
uint32_t window_id,
|
||||
uint32_t count)
|
||||
{
|
||||
size_t len;
|
||||
|
||||
if (!buf || buf_sz == 0) {
|
||||
return;
|
||||
}
|
||||
len = strlen(buf);
|
||||
if (len >= buf_sz - 1u) {
|
||||
return;
|
||||
}
|
||||
snprintf(buf + len, buf_sz - len, "%s%u:%u",
|
||||
len == 0 ? "" : ",",
|
||||
(unsigned)window_id,
|
||||
(unsigned)count);
|
||||
}
|
||||
|
||||
static void peer_record_udp_loss_summary(PeerRuntime *rt, uint32_t total_windows)
|
||||
{
|
||||
PeerRecvFileState *state;
|
||||
uint64_t lost_chunks;
|
||||
uint64_t burst_count = 0;
|
||||
uint64_t burst_max_len = 0;
|
||||
char ranges[OMNI_LOGGER_UDP_RANGES_SIZE];
|
||||
char seq_sample[OMNI_LOGGER_UDP_SEQ_SAMPLE_SIZE];
|
||||
char recv_window_dist[OMNI_LOGGER_UDP_WINDOW_DIST_SIZE];
|
||||
uint32_t sample_count = 0;
|
||||
|
||||
if (!rt || rt->proto != OMNI_PROTO_UDP) {
|
||||
return;
|
||||
}
|
||||
state = &rt->rx_file;
|
||||
if (state->total_chunks == 0 || !state->seq_seen) {
|
||||
return;
|
||||
}
|
||||
|
||||
ranges[0] = '\0';
|
||||
seq_sample[0] = '\0';
|
||||
recv_window_dist[0] = '\0';
|
||||
lost_chunks = 0;
|
||||
|
||||
for (uint32_t seq = 1; seq <= state->total_chunks; ++seq) {
|
||||
if (state->seq_seen[seq]) {
|
||||
continue;
|
||||
}
|
||||
|
||||
{
|
||||
uint32_t end = seq;
|
||||
|
||||
while (end + 1u <= state->total_chunks && !state->seq_seen[end + 1u]) {
|
||||
end++;
|
||||
}
|
||||
lost_chunks += (uint64_t)(end - seq + 1u);
|
||||
burst_count++;
|
||||
if ((uint64_t)(end - seq + 1u) > burst_max_len) {
|
||||
burst_max_len = (uint64_t)(end - seq + 1u);
|
||||
}
|
||||
append_range(ranges, sizeof(ranges), seq, end);
|
||||
for (uint32_t missing = seq; missing <= end && sample_count < 16u; ++missing) {
|
||||
append_csv_uint(seq_sample, sizeof(seq_sample), missing);
|
||||
sample_count++;
|
||||
}
|
||||
seq = end;
|
||||
}
|
||||
}
|
||||
|
||||
for (uint32_t window_id = 0;
|
||||
window_id < (uint32_t)state->recv_window_cap &&
|
||||
window_id < total_windows;
|
||||
++window_id) {
|
||||
if (state->recv_window_counts[window_id] == 0) {
|
||||
continue;
|
||||
}
|
||||
append_window_count(recv_window_dist,
|
||||
sizeof(recv_window_dist),
|
||||
window_id,
|
||||
state->recv_window_counts[window_id]);
|
||||
}
|
||||
|
||||
logger_on_udp_loss_summary(state->total_chunks,
|
||||
state->received_chunks,
|
||||
lost_chunks,
|
||||
burst_count,
|
||||
burst_max_len,
|
||||
ranges,
|
||||
seq_sample,
|
||||
recv_window_dist);
|
||||
}
|
||||
|
||||
static void peer_finalize_recv_observability(PeerRuntime *rt, uint32_t total_windows_hint)
|
||||
{
|
||||
uint32_t total_windows;
|
||||
|
||||
if (!rt || rt->proto != OMNI_PROTO_UDP) {
|
||||
return;
|
||||
}
|
||||
if (rt->rx_file.transfer_id == 0 || rt->rx_file.total_chunks == 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
total_windows = total_windows_hint;
|
||||
if (total_windows == 0) {
|
||||
total_windows = rt->rx_file.observed_windows;
|
||||
}
|
||||
if (total_windows == 0) {
|
||||
total_windows = 1;
|
||||
}
|
||||
|
||||
peer_record_udp_loss_summary(rt, total_windows);
|
||||
}
|
||||
|
||||
static uint64_t compute_file_size(FILE *fp)
|
||||
@@ -375,11 +724,338 @@ static int peer_send_transfer_ack(PeerRuntime *rt,
|
||||
TRANSFER_ACK_META_SIZE);
|
||||
}
|
||||
|
||||
static int peer_send_time_sync_probe(PeerRuntime *rt,
|
||||
const char *dst_id,
|
||||
PeerTimeSyncPeer *peer)
|
||||
{
|
||||
TimeSyncProbeMeta probe_meta;
|
||||
uint64_t now_ms;
|
||||
uint32_t probe_id;
|
||||
|
||||
if (!rt || !peer || !peer_id_is_valid(dst_id)) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
|
||||
now_ms = omni_now_ms();
|
||||
probe_id = peer->next_probe_id++;
|
||||
if (probe_id == 0u) {
|
||||
probe_id = peer->next_probe_id++;
|
||||
}
|
||||
|
||||
peer->pending_response = 1;
|
||||
peer->pending_probe_id = probe_id;
|
||||
peer->pending_send_ts_ms = now_ms;
|
||||
omni_time_sync_probe_meta_encode(&probe_meta, probe_id, now_ms);
|
||||
logger_log("DEBUG", "peer",
|
||||
"time_sync_probe_send peer_id=%s probe_id=%u",
|
||||
dst_id,
|
||||
(unsigned)probe_id);
|
||||
return peer_send_inner(rt,
|
||||
dst_id,
|
||||
MSG_TYPE_TIME_SYNC_REQ,
|
||||
&probe_meta,
|
||||
TIME_SYNC_PROBE_META_SIZE);
|
||||
}
|
||||
|
||||
static int peer_send_time_sync_report(PeerRuntime *rt,
|
||||
const char *dst_id,
|
||||
int64_t peer_minus_local_offset_ms,
|
||||
uint64_t best_rtt_ms,
|
||||
uint32_t sample_count)
|
||||
{
|
||||
TimeSyncReportMeta report_meta;
|
||||
|
||||
if (!rt || !peer_id_is_valid(dst_id)) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
|
||||
omni_time_sync_report_meta_encode(&report_meta,
|
||||
peer_minus_local_offset_ms,
|
||||
best_rtt_ms,
|
||||
sample_count);
|
||||
logger_log("DEBUG", "peer",
|
||||
"time_sync_report_send peer_id=%s offset_ms=%lld best_rtt_ms=%llu sample_count=%u",
|
||||
dst_id,
|
||||
(long long)peer_minus_local_offset_ms,
|
||||
(unsigned long long)best_rtt_ms,
|
||||
(unsigned)sample_count);
|
||||
return peer_send_inner(rt,
|
||||
dst_id,
|
||||
MSG_TYPE_TIME_SYNC_REPORT,
|
||||
&report_meta,
|
||||
TIME_SYNC_REPORT_META_SIZE);
|
||||
}
|
||||
|
||||
static int peer_wait_for_time_sync_probe(PeerRuntime *rt,
|
||||
PeerTimeSyncPeer *peer,
|
||||
uint64_t deadline_ms)
|
||||
{
|
||||
uint8_t payload[PEER_MAX_PAYLOAD];
|
||||
|
||||
if (!rt || !peer) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
|
||||
while (rt->running && !g_stop && peer->pending_response) {
|
||||
PeerTransportEvent event;
|
||||
uint64_t now_ms = omni_now_ms();
|
||||
int rc;
|
||||
int timeout_ms;
|
||||
|
||||
if (now_ms >= deadline_ms) {
|
||||
return OMNI_ERR_TIMEOUT;
|
||||
}
|
||||
|
||||
timeout_ms = (int)(deadline_ms - now_ms);
|
||||
if (timeout_ms > 50) {
|
||||
timeout_ms = 50;
|
||||
}
|
||||
rc = peer_transport_next_event(rt->transport,
|
||||
&event,
|
||||
payload,
|
||||
sizeof(payload),
|
||||
timeout_ms);
|
||||
if (rc < 0) {
|
||||
return rc;
|
||||
}
|
||||
if (rc > 0) {
|
||||
handle_transport_event(rt, &event, payload);
|
||||
}
|
||||
}
|
||||
|
||||
return peer->pending_response ? OMNI_ERR_TIMEOUT : OMNI_OK;
|
||||
}
|
||||
|
||||
static int peer_ensure_time_sync(PeerRuntime *rt, const char *dst_id)
|
||||
{
|
||||
PeerTimeSyncPeer *peer;
|
||||
uint64_t now_ms;
|
||||
int had_previous_offset = 0;
|
||||
int64_t previous_offset_ms = 0;
|
||||
uint64_t previous_best_rtt_ms = 0;
|
||||
uint32_t previous_sample_count = 0;
|
||||
|
||||
if (!rt || !peer_id_is_valid(dst_id)) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
|
||||
now_ms = omni_now_ms();
|
||||
peer = peer_time_sync_find(rt, dst_id, 1);
|
||||
if (!peer) {
|
||||
return OMNI_ERR_GENERIC;
|
||||
}
|
||||
if (peer_time_sync_offset_is_fresh(peer, now_ms)) {
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
had_previous_offset = peer->has_offset;
|
||||
previous_offset_ms = peer->peer_minus_local_offset_ms;
|
||||
previous_best_rtt_ms = peer->best_rtt_ms;
|
||||
previous_sample_count = peer->sample_count;
|
||||
|
||||
peer_time_sync_clear_transient(peer);
|
||||
peer->sync_in_progress = 1;
|
||||
peer->sync_best_rtt_ms = UINT64_MAX;
|
||||
|
||||
for (uint32_t i = 0; i < PEER_TIME_SYNC_SAMPLES && rt->running && !g_stop; ++i) {
|
||||
int rc;
|
||||
|
||||
rc = peer_send_time_sync_probe(rt, dst_id, peer);
|
||||
if (rc != OMNI_OK) {
|
||||
peer_time_sync_clear_transient(peer);
|
||||
return rc;
|
||||
}
|
||||
rc = peer_wait_for_time_sync_probe(rt,
|
||||
peer,
|
||||
omni_now_ms() + PEER_TIME_SYNC_PROBE_TIMEOUT_MS);
|
||||
if (rc != OMNI_OK) {
|
||||
peer->pending_response = 0;
|
||||
logger_log("WARN", "peer",
|
||||
"time_sync_probe_timeout peer_id=%s sample_index=%u",
|
||||
dst_id,
|
||||
(unsigned)i);
|
||||
}
|
||||
}
|
||||
|
||||
peer->sync_in_progress = 0;
|
||||
peer->pending_response = 0;
|
||||
peer->pending_probe_id = 0;
|
||||
peer->pending_send_ts_ms = 0;
|
||||
|
||||
if (peer->sync_success_count > 0 && peer->sync_best_rtt_ms != UINT64_MAX) {
|
||||
peer->has_offset = 1;
|
||||
peer->peer_minus_local_offset_ms = peer->sync_best_offset_ms;
|
||||
peer->best_rtt_ms = peer->sync_best_rtt_ms;
|
||||
peer->sample_count = peer->sync_success_count;
|
||||
peer->last_sync_local_ms = omni_now_ms();
|
||||
(void)peer_send_time_sync_report(rt,
|
||||
dst_id,
|
||||
peer->peer_minus_local_offset_ms,
|
||||
peer->best_rtt_ms,
|
||||
peer->sample_count);
|
||||
logger_log("INFO", "peer",
|
||||
"time_sync_ready peer_id=%s offset_ms=%lld best_rtt_ms=%llu sample_count=%u",
|
||||
dst_id,
|
||||
(long long)peer->peer_minus_local_offset_ms,
|
||||
(unsigned long long)peer->best_rtt_ms,
|
||||
(unsigned)peer->sample_count);
|
||||
peer->sync_best_offset_ms = 0;
|
||||
peer->sync_best_rtt_ms = 0;
|
||||
peer->sync_success_count = 0;
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
if (had_previous_offset) {
|
||||
peer->has_offset = 1;
|
||||
peer->peer_minus_local_offset_ms = previous_offset_ms;
|
||||
peer->best_rtt_ms = previous_best_rtt_ms;
|
||||
peer->sample_count = previous_sample_count;
|
||||
logger_log("WARN", "peer",
|
||||
"time_sync_refresh_failed_use_cached peer_id=%s offset_ms=%lld best_rtt_ms=%llu",
|
||||
dst_id,
|
||||
(long long)peer->peer_minus_local_offset_ms,
|
||||
(unsigned long long)peer->best_rtt_ms);
|
||||
peer->sync_best_offset_ms = 0;
|
||||
peer->sync_best_rtt_ms = 0;
|
||||
peer->sync_success_count = 0;
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
peer_time_sync_clear_transient(peer);
|
||||
logger_log("WARN", "peer", "time_sync_unavailable peer_id=%s", dst_id);
|
||||
return OMNI_ERR_TIMEOUT;
|
||||
}
|
||||
|
||||
static void handle_time_sync_request(PeerRuntime *rt,
|
||||
const PeerTunnelMeta *tunnel_meta,
|
||||
const uint8_t *payload,
|
||||
uint32_t payload_len)
|
||||
{
|
||||
TimeSyncProbeMeta probe_meta;
|
||||
TimeSyncReplyMeta reply_meta;
|
||||
uint64_t recv_ts_ms;
|
||||
uint64_t send_ts_ms;
|
||||
|
||||
if (payload_len < TIME_SYNC_PROBE_META_SIZE) {
|
||||
logger_log("WARN", "peer", "short_time_sync_req len=%u", (unsigned)payload_len);
|
||||
return;
|
||||
}
|
||||
if (!peer_id_is_valid(tunnel_meta->src_id)) {
|
||||
logger_log("WARN", "peer", "time_sync_req_missing_src");
|
||||
return;
|
||||
}
|
||||
|
||||
recv_ts_ms = omni_now_ms();
|
||||
omni_time_sync_probe_meta_decode((const TimeSyncProbeMeta *)payload, &probe_meta);
|
||||
send_ts_ms = omni_now_ms();
|
||||
omni_time_sync_reply_meta_encode(&reply_meta,
|
||||
probe_meta.probe_id,
|
||||
probe_meta.client_send_ts_ms,
|
||||
recv_ts_ms,
|
||||
send_ts_ms);
|
||||
(void)peer_send_inner(rt,
|
||||
tunnel_meta->src_id,
|
||||
MSG_TYPE_TIME_SYNC_RESP,
|
||||
&reply_meta,
|
||||
TIME_SYNC_REPLY_META_SIZE);
|
||||
}
|
||||
|
||||
static void handle_time_sync_response(PeerRuntime *rt,
|
||||
const PeerTunnelMeta *tunnel_meta,
|
||||
const uint8_t *payload,
|
||||
uint32_t payload_len)
|
||||
{
|
||||
PeerTimeSyncPeer *peer;
|
||||
TimeSyncReplyMeta reply_meta;
|
||||
uint64_t recv_ts_ms;
|
||||
uint64_t rtt_ms;
|
||||
int64_t offset_ms;
|
||||
|
||||
if (!rt || payload_len < TIME_SYNC_REPLY_META_SIZE) {
|
||||
logger_log("WARN", "peer", "short_time_sync_resp len=%u", (unsigned)payload_len);
|
||||
return;
|
||||
}
|
||||
if (!peer_id_is_valid(tunnel_meta->src_id)) {
|
||||
logger_log("WARN", "peer", "time_sync_resp_missing_src");
|
||||
return;
|
||||
}
|
||||
|
||||
peer = peer_time_sync_find(rt, tunnel_meta->src_id, 1);
|
||||
if (!peer || !peer->sync_in_progress || !peer->pending_response) {
|
||||
return;
|
||||
}
|
||||
|
||||
omni_time_sync_reply_meta_decode((const TimeSyncReplyMeta *)payload, &reply_meta);
|
||||
if (reply_meta.probe_id != peer->pending_probe_id ||
|
||||
reply_meta.client_send_ts_ms != peer->pending_send_ts_ms) {
|
||||
return;
|
||||
}
|
||||
|
||||
recv_ts_ms = omni_now_ms();
|
||||
if (recv_ts_ms < peer->pending_send_ts_ms) {
|
||||
peer->pending_response = 0;
|
||||
return;
|
||||
}
|
||||
|
||||
rtt_ms = recv_ts_ms - peer->pending_send_ts_ms;
|
||||
offset_ms = (((int64_t)reply_meta.server_recv_ts_ms - (int64_t)peer->pending_send_ts_ms) +
|
||||
((int64_t)reply_meta.server_send_ts_ms - (int64_t)recv_ts_ms)) / 2;
|
||||
if (peer->sync_success_count == 0 || rtt_ms < peer->sync_best_rtt_ms) {
|
||||
peer->sync_best_rtt_ms = rtt_ms;
|
||||
peer->sync_best_offset_ms = offset_ms;
|
||||
}
|
||||
peer->sync_success_count++;
|
||||
peer->pending_response = 0;
|
||||
logger_log("DEBUG", "peer",
|
||||
"time_sync_sample peer_id=%s probe_id=%u rtt_ms=%llu offset_ms=%lld",
|
||||
tunnel_meta->src_id,
|
||||
(unsigned)reply_meta.probe_id,
|
||||
(unsigned long long)rtt_ms,
|
||||
(long long)offset_ms);
|
||||
}
|
||||
|
||||
static void handle_time_sync_report(PeerRuntime *rt,
|
||||
const PeerTunnelMeta *tunnel_meta,
|
||||
const uint8_t *payload,
|
||||
uint32_t payload_len)
|
||||
{
|
||||
PeerTimeSyncPeer *peer;
|
||||
TimeSyncReportMeta report_meta;
|
||||
|
||||
if (!rt || payload_len < TIME_SYNC_REPORT_META_SIZE) {
|
||||
logger_log("WARN", "peer", "short_time_sync_report len=%u", (unsigned)payload_len);
|
||||
return;
|
||||
}
|
||||
if (!peer_id_is_valid(tunnel_meta->src_id)) {
|
||||
logger_log("WARN", "peer", "time_sync_report_missing_src");
|
||||
return;
|
||||
}
|
||||
|
||||
peer = peer_time_sync_find(rt, tunnel_meta->src_id, 1);
|
||||
if (!peer) {
|
||||
return;
|
||||
}
|
||||
|
||||
omni_time_sync_report_meta_decode((const TimeSyncReportMeta *)payload, &report_meta);
|
||||
peer->has_offset = 1;
|
||||
peer->peer_minus_local_offset_ms = -report_meta.server_minus_client_offset_ms;
|
||||
peer->best_rtt_ms = report_meta.best_rtt_ms;
|
||||
peer->sample_count = report_meta.sample_count;
|
||||
peer->last_sync_local_ms = omni_now_ms();
|
||||
logger_log("INFO", "peer",
|
||||
"time_sync_report_apply peer_id=%s offset_ms=%lld best_rtt_ms=%llu sample_count=%u",
|
||||
tunnel_meta->src_id,
|
||||
(long long)peer->peer_minus_local_offset_ms,
|
||||
(unsigned long long)peer->best_rtt_ms,
|
||||
(unsigned)peer->sample_count);
|
||||
}
|
||||
|
||||
static int peer_send_file(PeerRuntime *rt,
|
||||
const char *dst_id,
|
||||
const char *file_path,
|
||||
unsigned chunk_size)
|
||||
{
|
||||
PeerTimeSyncPeer *sync_peer = NULL;
|
||||
char effective_dst[OMNI_PEER_ID_SIZE];
|
||||
FILE *fp = NULL;
|
||||
uint8_t *chunk = NULL;
|
||||
@@ -389,6 +1065,8 @@ static int peer_send_file(PeerRuntime *rt,
|
||||
uint32_t total_chunks;
|
||||
uint32_t transfer_id;
|
||||
uint32_t total_windows = 1;
|
||||
uint64_t transfer_start_ms;
|
||||
uint32_t max_window_id = 0;
|
||||
int rc = OMNI_OK;
|
||||
|
||||
if (!file_path) {
|
||||
@@ -402,6 +1080,13 @@ static int peer_send_file(PeerRuntime *rt,
|
||||
if (peer_resolve_dst(rt, dst_id, effective_dst) != OMNI_OK) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
if (peer_ensure_time_sync(rt, effective_dst) == OMNI_OK) {
|
||||
sync_peer = peer_time_sync_find(rt, effective_dst, 0);
|
||||
} else {
|
||||
logger_log("WARN", "peer",
|
||||
"file_send_without_time_sync dst_id=%s end_to_end_will_be_zero",
|
||||
effective_dst);
|
||||
}
|
||||
|
||||
fp = fopen(file_path, "rb");
|
||||
if (!fp) {
|
||||
@@ -419,10 +1104,13 @@ static int peer_send_file(PeerRuntime *rt,
|
||||
goto out;
|
||||
}
|
||||
|
||||
logger_reset_transfer_observability();
|
||||
logger_set_transfer_total(total_bytes);
|
||||
logger_set_progress(0);
|
||||
transfer_start_ms = omni_now_ms();
|
||||
|
||||
for (uint32_t seq = 1; rt->running && !g_stop; ++seq) {
|
||||
uint64_t processing_t0 = omni_now_ms();
|
||||
size_t nread = fread(chunk, 1, chunk_size, fp);
|
||||
|
||||
if (nread == 0) {
|
||||
@@ -437,18 +1125,31 @@ static int peer_send_file(PeerRuntime *rt,
|
||||
|
||||
if (nread > 0) {
|
||||
TransferChunkMeta meta;
|
||||
uint64_t chunk_origin_local_ts_ms = omni_now_ms();
|
||||
uint64_t chunk_origin_peer_ts_ms = 0;
|
||||
uint32_t window_id = (uint32_t)((chunk_origin_local_ts_ms - transfer_start_ms) / 1000u);
|
||||
|
||||
if (sync_peer) {
|
||||
(void)peer_time_sync_local_to_peer_ts(sync_peer,
|
||||
chunk_origin_local_ts_ms,
|
||||
&chunk_origin_peer_ts_ms);
|
||||
}
|
||||
|
||||
omni_transfer_chunk_meta_encode(&meta,
|
||||
transfer_id,
|
||||
seq,
|
||||
total_chunks,
|
||||
0,
|
||||
window_id,
|
||||
total_bytes,
|
||||
offset,
|
||||
(uint32_t)nread,
|
||||
omni_now_ms());
|
||||
chunk_origin_peer_ts_ms);
|
||||
memcpy(payload, &meta, TRANSFER_CHUNK_META_SIZE);
|
||||
memcpy(payload + TRANSFER_CHUNK_META_SIZE, chunk, nread);
|
||||
if (window_id > max_window_id) {
|
||||
max_window_id = window_id;
|
||||
}
|
||||
logger_on_processing_latency((double)(omni_now_ms() - processing_t0));
|
||||
rc = peer_send_inner(rt,
|
||||
effective_dst,
|
||||
MSG_TYPE_FILE_CHUNK,
|
||||
@@ -465,6 +1166,7 @@ static int peer_send_file(PeerRuntime *rt,
|
||||
if (rc == OMNI_OK && rt->running && !g_stop) {
|
||||
TransferEndMeta end_meta;
|
||||
|
||||
total_windows = max_window_id + 1u;
|
||||
omni_transfer_end_meta_encode(&end_meta,
|
||||
transfer_id,
|
||||
total_chunks,
|
||||
@@ -587,6 +1289,7 @@ static int peer_open_recv_file(PeerRuntime *rt, const TransferChunkMeta *meta)
|
||||
}
|
||||
|
||||
if (!rt->rx_file.fp || rt->rx_file.transfer_id != meta->transfer_id) {
|
||||
peer_finalize_recv_observability(rt, 0);
|
||||
close_recv_file(rt);
|
||||
rt->rx_file.fp = fopen(rt->output_path, "wb+");
|
||||
if (!rt->rx_file.fp) {
|
||||
@@ -596,6 +1299,13 @@ static int peer_open_recv_file(PeerRuntime *rt, const TransferChunkMeta *meta)
|
||||
rt->rx_file.total_chunks = meta->total_chunks;
|
||||
rt->rx_file.total_bytes = meta->total_bytes;
|
||||
rt->rx_file.bytes_written = 0;
|
||||
if (recv_file_prepare_tracking(&rt->rx_file, meta->total_chunks) != OMNI_OK) {
|
||||
logger_log("WARN", "peer",
|
||||
"recv_tracking_alloc_failed transfer_id=%u total_chunks=%u",
|
||||
(unsigned)meta->transfer_id,
|
||||
(unsigned)meta->total_chunks);
|
||||
}
|
||||
logger_reset_transfer_observability();
|
||||
logger_set_transfer_total(meta->total_bytes);
|
||||
logger_set_progress(0);
|
||||
}
|
||||
@@ -608,6 +1318,8 @@ static void handle_file_chunk_message(PeerRuntime *rt,
|
||||
uint32_t payload_len)
|
||||
{
|
||||
TransferChunkMeta meta;
|
||||
uint64_t processing_t0 = omni_now_ms();
|
||||
uint64_t now_ms;
|
||||
|
||||
if (payload_len < TRANSFER_CHUNK_META_SIZE) {
|
||||
logger_log("WARN", "peer", "short_file_chunk_payload len=%u", (unsigned)payload_len);
|
||||
@@ -632,6 +1344,8 @@ static void handle_file_chunk_message(PeerRuntime *rt,
|
||||
return;
|
||||
}
|
||||
|
||||
recv_file_note_chunk(&rt->rx_file, meta.seq, meta.window_id);
|
||||
|
||||
if (fseeko(rt->rx_file.fp, (off_t)meta.offset_bytes, SEEK_SET) != 0) {
|
||||
logger_log("ERROR", "peer", "fseeko_failed offset=%llu errno=%d",
|
||||
(unsigned long long)meta.offset_bytes,
|
||||
@@ -645,6 +1359,11 @@ static void handle_file_chunk_message(PeerRuntime *rt,
|
||||
|
||||
rt->rx_file.bytes_written += meta.chunk_bytes;
|
||||
logger_set_progress(rt->rx_file.bytes_written);
|
||||
now_ms = omni_now_ms();
|
||||
logger_on_processing_latency((double)(now_ms - processing_t0));
|
||||
if (meta.origin_ts_ms > 0 && now_ms >= meta.origin_ts_ms) {
|
||||
logger_on_end_to_end_latency((double)(now_ms - meta.origin_ts_ms));
|
||||
}
|
||||
}
|
||||
|
||||
static void handle_file_end_message(PeerRuntime *rt,
|
||||
@@ -669,6 +1388,9 @@ static void handle_file_end_message(PeerRuntime *rt,
|
||||
total_chunks = rt->rx_file.total_chunks ? rt->rx_file.total_chunks : end_meta.total_chunks;
|
||||
total_bytes = rt->rx_file.total_bytes ? rt->rx_file.total_bytes : end_meta.total_bytes;
|
||||
}
|
||||
peer_finalize_recv_observability(rt,
|
||||
end_meta.total_windows > 0 ? end_meta.total_windows
|
||||
: rt->rx_file.observed_windows);
|
||||
|
||||
fprintf(stdout,
|
||||
"[file %s -> %s] transfer_id=%u bytes_written=%llu total_bytes=%llu total_chunks=%u output=%s\n",
|
||||
@@ -761,6 +1483,18 @@ static void handle_tunnel_message(PeerRuntime *rt, const uint8_t *payload, uint3
|
||||
handle_transfer_ack_message(&tunnel_meta, inner_payload, inner_len);
|
||||
return;
|
||||
}
|
||||
if (tunnel_meta.inner_type == MSG_TYPE_TIME_SYNC_REQ) {
|
||||
handle_time_sync_request(rt, &tunnel_meta, inner_payload, inner_len);
|
||||
return;
|
||||
}
|
||||
if (tunnel_meta.inner_type == MSG_TYPE_TIME_SYNC_RESP) {
|
||||
handle_time_sync_response(rt, &tunnel_meta, inner_payload, inner_len);
|
||||
return;
|
||||
}
|
||||
if (tunnel_meta.inner_type == MSG_TYPE_TIME_SYNC_REPORT) {
|
||||
handle_time_sync_report(rt, &tunnel_meta, inner_payload, inner_len);
|
||||
return;
|
||||
}
|
||||
|
||||
fprintf(stdout,
|
||||
"[peer %s -> %s] unsupported inner_type=%u payload_len=%u\n",
|
||||
@@ -955,6 +1689,8 @@ static void handle_transport_event(PeerRuntime *rt,
|
||||
rt->session = NULL;
|
||||
rt->direct_register_sent = 0;
|
||||
peer_set_bound_peer(rt, "");
|
||||
peer_time_sync_free_all(rt);
|
||||
peer_finalize_recv_observability(rt, 0);
|
||||
close_recv_file(rt);
|
||||
rt->rx_file.transfer_id = 0;
|
||||
rt->rx_file.total_chunks = 0;
|
||||
@@ -1114,6 +1850,7 @@ int main(int argc, char **argv)
|
||||
memset(&rt, 0, sizeof(rt));
|
||||
memset(&startup, 0, sizeof(startup));
|
||||
rt.mode = mode;
|
||||
rt.proto = proto;
|
||||
rt.role = (mode == PEER_MODE_DIRECT && listen_port > 0) ? OMNI_ROLE_SERVER : OMNI_ROLE_CLIENT;
|
||||
log_mode = (mode == PEER_MODE_DIRECT) ? "direct" : "hub";
|
||||
log_role = (rt.role == OMNI_ROLE_SERVER) ? "server" : "client";
|
||||
@@ -1220,7 +1957,9 @@ int main(int argc, char **argv)
|
||||
}
|
||||
}
|
||||
|
||||
peer_finalize_recv_observability(&rt, 0);
|
||||
close_recv_file(&rt);
|
||||
peer_time_sync_free_all(&rt);
|
||||
peer_transport_close(rt.transport);
|
||||
logger_print_performance_log("final");
|
||||
return 0;
|
||||
|
||||
@@ -29,6 +29,28 @@ static char g_ctx_mode[16];
|
||||
static char g_ctx_role[16];
|
||||
static char g_ctx_self_id[OMNI_PEER_ID_SIZE];
|
||||
|
||||
#define OMNI_DELAY_WINDOW_MS 1000u
|
||||
#define OMNI_DELAY_IDLE_RESET_MS 1000u
|
||||
|
||||
static void metric_reset(OmniMetricSummary *metric);
|
||||
|
||||
static void reset_transfer_observability_locked(void)
|
||||
{
|
||||
g_stats.total_work_bytes = 0;
|
||||
g_stats.progress_bytes = 0;
|
||||
metric_reset(&g_stats.processing_delay_ms);
|
||||
metric_reset(&g_stats.end_to_end_delay_ms);
|
||||
g_stats.udp_expected_chunks = 0;
|
||||
g_stats.udp_received_chunks = 0;
|
||||
g_stats.udp_lost_chunks = 0;
|
||||
g_stats.udp_loss_burst_count = 0;
|
||||
g_stats.udp_loss_burst_max_len = 0;
|
||||
g_stats.udp_loss_rate_pct = 0.0;
|
||||
g_stats.udp_loss_ranges[0] = '\0';
|
||||
g_stats.udp_loss_seq_sample[0] = '\0';
|
||||
g_stats.udp_recv_window_dist[0] = '\0';
|
||||
}
|
||||
|
||||
/* 对 common.h 的时间接口做一层薄包装，统一 logger 模块内部的调用入口。 */
|
||||
static uint64_t now_ms(void)
|
||||
{
|
||||
@@ -111,28 +133,66 @@ static double metric_min(const OmniMetricSummary *metric)
|
||||
return metric->min;
|
||||
}
|
||||
|
||||
static double derived_propagation_ms(uint64_t min_rtt_ms)
|
||||
{
|
||||
if (min_rtt_ms == 0 || min_rtt_ms == UINT64_MAX) {
|
||||
return 0.0;
|
||||
}
|
||||
return (double)min_rtt_ms / 2.0;
|
||||
}
|
||||
|
||||
static void delay_window_note_locked(uint64_t now, size_t bytes, int is_send)
|
||||
{
|
||||
uint64_t *window_start_ms = is_send ? &g_stats.delay_window_start_send_ms
|
||||
: &g_stats.delay_window_start_recv_ms;
|
||||
uint64_t *window_bytes = is_send ? &g_stats.delay_window_bytes_sent
|
||||
: &g_stats.delay_window_bytes_recv;
|
||||
uint64_t *last_activity_ms = is_send ? &g_stats.last_send_activity_ms
|
||||
: &g_stats.last_recv_activity_ms;
|
||||
|
||||
if (*window_start_ms == 0 ||
|
||||
(*last_activity_ms > 0 && now - *last_activity_ms > OMNI_DELAY_IDLE_RESET_MS) ||
|
||||
now - *window_start_ms > OMNI_DELAY_WINDOW_MS) {
|
||||
*window_start_ms = now;
|
||||
*window_bytes = 0;
|
||||
}
|
||||
|
||||
*window_bytes += (uint64_t)bytes;
|
||||
*last_activity_ms = now;
|
||||
}
|
||||
|
||||
/*
|
||||
* 基于当前窗口内流量和累计流量估算“此刻本机可提供的服务速率”。
|
||||
* 优先使用当前窗口速率；若窗口内尚无样本，则退化为全局平均速率。
|
||||
* 仅基于最近活跃窗口估算“当前本机可提供的服务速率”。
|
||||
* 最近一段时间没有流量时直接放弃估算，避免把长时间空转折算进时延。
|
||||
*/
|
||||
static double live_rate_mbps_locked(uint64_t now, int is_send)
|
||||
{
|
||||
uint64_t window_elapsed_ms = now - g_stats.window_start_ms;
|
||||
uint64_t total_elapsed_ms = now - g_stats.start_ms;
|
||||
uint64_t window_bytes = is_send ? g_stats.window_bytes_sent : g_stats.window_bytes_recv;
|
||||
uint64_t total_bytes = is_send ? g_stats.bytes_sent : g_stats.bytes_recv;
|
||||
uint64_t window_start_ms = is_send ? g_stats.delay_window_start_send_ms
|
||||
: g_stats.delay_window_start_recv_ms;
|
||||
uint64_t window_bytes = is_send ? g_stats.delay_window_bytes_sent
|
||||
: g_stats.delay_window_bytes_recv;
|
||||
uint64_t last_activity_ms = is_send ? g_stats.last_send_activity_ms
|
||||
: g_stats.last_recv_activity_ms;
|
||||
uint64_t window_elapsed_ms;
|
||||
|
||||
if (window_start_ms == 0 || window_bytes == 0 || last_activity_ms == 0) {
|
||||
return 0.0;
|
||||
}
|
||||
if (now < window_start_ms || now < last_activity_ms) {
|
||||
return 0.0;
|
||||
}
|
||||
if (now - last_activity_ms > OMNI_DELAY_IDLE_RESET_MS) {
|
||||
return 0.0;
|
||||
}
|
||||
|
||||
window_elapsed_ms = now - window_start_ms;
|
||||
if (window_elapsed_ms == 0) {
|
||||
return 0.0;
|
||||
}
|
||||
|
||||
if (window_elapsed_ms > 0 && window_bytes > 0) {
|
||||
return ((double)window_bytes * 8.0) /
|
||||
((double)window_elapsed_ms / 1000.0) /
|
||||
1000000.0;
|
||||
}
|
||||
if (total_elapsed_ms > 0 && total_bytes > 0) {
|
||||
return ((double)total_bytes * 8.0) /
|
||||
((double)total_elapsed_ms / 1000.0) /
|
||||
1000000.0;
|
||||
}
|
||||
return 0.0;
|
||||
}
|
||||
|
||||
/* 用本机当前服务速率把字节数换算成时延估计。 */
|
||||
@@ -240,6 +300,7 @@ void logger_init(void)
|
||||
metric_reset(&g_stats.send_buffer_pct);
|
||||
metric_reset(&g_stats.recv_buffer_pct);
|
||||
metric_reset(&g_stats.cwnd);
|
||||
reset_transfer_observability_locked();
|
||||
copy_context_field(g_ctx_app, sizeof(g_ctx_app), NULL, "unknown");
|
||||
copy_context_field(g_ctx_proto, sizeof(g_ctx_proto), NULL, "unknown");
|
||||
copy_context_field(g_ctx_mode, sizeof(g_ctx_mode), NULL, "unknown");
|
||||
@@ -291,9 +352,12 @@ void logger_set_context(const char *app,
|
||||
/* 记录一次发送事件，更新累计发送字节和窗口内发送字节。 */
|
||||
void logger_on_send(size_t bytes)
|
||||
{
|
||||
uint64_t now = now_ms();
|
||||
|
||||
pthread_mutex_lock(&g_mu);
|
||||
g_stats.bytes_sent += bytes;
|
||||
g_stats.window_bytes_sent += bytes;
|
||||
delay_window_note_locked(now, bytes, 1);
|
||||
g_stats.send_count++;
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
}
|
||||
@@ -301,14 +365,17 @@ void logger_on_send(size_t bytes)
|
||||
/* 记录一次接收事件，更新累计接收字节和窗口内接收字节。 */
|
||||
void logger_on_recv(size_t bytes)
|
||||
{
|
||||
uint64_t now = now_ms();
|
||||
|
||||
pthread_mutex_lock(&g_mu);
|
||||
g_stats.bytes_recv += bytes;
|
||||
g_stats.window_bytes_recv += bytes;
|
||||
delay_window_note_locked(now, bytes, 0);
|
||||
g_stats.recv_count++;
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
}
|
||||
|
||||
/* 更新最近一次 RTT 和历史最大 RTT。 */
|
||||
/* 更新最近一次 RTT 以及进程生命周期内的最小/最大 RTT。 */
|
||||
void logger_on_rtt(uint64_t rtt_ms)
|
||||
{
|
||||
if (rtt_ms == 0) {
|
||||
@@ -323,11 +390,6 @@ void logger_on_rtt(uint64_t rtt_ms)
|
||||
if (rtt_ms > g_stats.max_rtt_ms) {
|
||||
g_stats.max_rtt_ms = rtt_ms;
|
||||
}
|
||||
/*
|
||||
* 传播时延无法直接观测，这里统一采用 min RTT / 2 作为链路基线估算。
|
||||
* min RTT 更接近“基本无排队”时的往返时间，因此比 last RTT 更稳。
|
||||
*/
|
||||
metric_observe(&g_stats.propagation_delay_ms, (double)g_stats.min_rtt_ms / 2.0);
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
}
|
||||
|
||||
@@ -555,6 +617,43 @@ void logger_set_progress(uint64_t progress_bytes)
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
}
|
||||
|
||||
void logger_reset_transfer_observability(void)
|
||||
{
|
||||
pthread_mutex_lock(&g_mu);
|
||||
reset_transfer_observability_locked();
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
}
|
||||
|
||||
void logger_on_udp_loss_summary(uint64_t expected_chunks,
|
||||
uint64_t received_chunks,
|
||||
uint64_t lost_chunks,
|
||||
uint64_t burst_count,
|
||||
uint64_t burst_max_len,
|
||||
const char *ranges,
|
||||
const char *seq_sample,
|
||||
const char *recv_window_dist)
|
||||
{
|
||||
pthread_mutex_lock(&g_mu);
|
||||
g_stats.udp_expected_chunks = expected_chunks;
|
||||
g_stats.udp_received_chunks = received_chunks;
|
||||
g_stats.udp_lost_chunks = lost_chunks;
|
||||
g_stats.udp_loss_burst_count = burst_count;
|
||||
g_stats.udp_loss_burst_max_len = burst_max_len;
|
||||
g_stats.udp_loss_rate_pct = (expected_chunks > 0)
|
||||
? ((double)lost_chunks * 100.0) / (double)expected_chunks
|
||||
: 0.0;
|
||||
omni_copy_fixed_ascii(g_stats.udp_loss_ranges,
|
||||
sizeof(g_stats.udp_loss_ranges),
|
||||
ranges ? ranges : "");
|
||||
omni_copy_fixed_ascii(g_stats.udp_loss_seq_sample,
|
||||
sizeof(g_stats.udp_loss_seq_sample),
|
||||
seq_sample ? seq_sample : "");
|
||||
omni_copy_fixed_ascii(g_stats.udp_recv_window_dist,
|
||||
sizeof(g_stats.udp_recv_window_dist),
|
||||
recv_window_dist ? recv_window_dist : "");
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
}
|
||||
|
||||
/* 对外提供一个“当前总吞吐”的便捷计算接口。 */
|
||||
double logger_calculate_throughput(void)
|
||||
{
|
||||
@@ -601,11 +700,17 @@ void logger_print_performance_log(const char *tag)
|
||||
uint64_t now;
|
||||
OmniStats snapshot;
|
||||
double progress_pct;
|
||||
double propagation_avg_ms;
|
||||
double propagation_min_ms;
|
||||
double propagation_max_ms;
|
||||
char ctx_app[sizeof(g_ctx_app)];
|
||||
char ctx_proto[sizeof(g_ctx_proto)];
|
||||
char ctx_mode[sizeof(g_ctx_mode)];
|
||||
char ctx_role[sizeof(g_ctx_role)];
|
||||
char ctx_self_id[sizeof(g_ctx_self_id)];
|
||||
char udp_loss_ranges[sizeof(snapshot.udp_loss_ranges)];
|
||||
char udp_loss_seq_sample[sizeof(snapshot.udp_loss_seq_sample)];
|
||||
char udp_recv_window_dist[sizeof(snapshot.udp_recv_window_dist)];
|
||||
|
||||
pthread_mutex_lock(&g_mu);
|
||||
now = now_ms();
|
||||
@@ -626,13 +731,29 @@ void logger_print_performance_log(const char *tag)
|
||||
omni_copy_fixed_ascii(ctx_mode, sizeof(ctx_mode), g_ctx_mode);
|
||||
omni_copy_fixed_ascii(ctx_role, sizeof(ctx_role), g_ctx_role);
|
||||
omni_copy_fixed_ascii(ctx_self_id, sizeof(ctx_self_id), g_ctx_self_id);
|
||||
omni_copy_fixed_ascii(udp_loss_ranges, sizeof(udp_loss_ranges), snapshot.udp_loss_ranges);
|
||||
omni_copy_fixed_ascii(udp_loss_seq_sample, sizeof(udp_loss_seq_sample), snapshot.udp_loss_seq_sample);
|
||||
omni_copy_fixed_ascii(udp_recv_window_dist, sizeof(udp_recv_window_dist), snapshot.udp_recv_window_dist);
|
||||
pthread_mutex_unlock(&g_mu);
|
||||
|
||||
udp_loss_ranges[sizeof(udp_loss_ranges) - 1u] = '\0';
|
||||
udp_loss_seq_sample[sizeof(udp_loss_seq_sample) - 1u] = '\0';
|
||||
udp_recv_window_dist[sizeof(udp_recv_window_dist) - 1u] = '\0';
|
||||
|
||||
progress_pct = 0.0;
|
||||
if (snapshot.total_work_bytes > 0) {
|
||||
progress_pct = ((double)snapshot.progress_bytes * 100.0) /
|
||||
(double)snapshot.total_work_bytes;
|
||||
}
|
||||
if (snapshot.propagation_delay_ms.count > 0) {
|
||||
propagation_avg_ms = metric_avg(&snapshot.propagation_delay_ms);
|
||||
propagation_min_ms = metric_min(&snapshot.propagation_delay_ms);
|
||||
propagation_max_ms = snapshot.propagation_delay_ms.max;
|
||||
} else {
|
||||
propagation_avg_ms = derived_propagation_ms(snapshot.min_rtt_ms);
|
||||
propagation_min_ms = propagation_avg_ms;
|
||||
propagation_max_ms = propagation_avg_ms;
|
||||
}
|
||||
|
||||
{
|
||||
/* 人读友好的单行文本日志，适合终端直接观察。 */
|
||||
@@ -651,7 +772,7 @@ void logger_print_performance_log(const char *tag)
|
||||
"processing_avg_ms=%.3f queue_avg_ms=%.3f transmission_avg_ms=%.3f propagation_avg_ms=%.3f end_to_end_avg_ms=%.3f "
|
||||
"send_buffer_pct=%.2f recv_buffer_pct=%.2f cwnd=%.2f "
|
||||
"last_rtt_ms=%llu min_rtt_ms=%llu max_rtt_ms=%llu "
|
||||
"tcp_retrans=%llu tcp_data_segs_out=%llu tcp_data_bytes_sent=%llu tcp_retrans_bytes=%llu "
|
||||
"tcp_retrans=%llu udp_retrans=%llu tcp_data_segs_out=%llu tcp_data_bytes_sent=%llu tcp_retrans_bytes=%llu "
|
||||
"kcp_retrans=%llu kcp_data_segs_out=%llu kcp_data_bytes_sent=%llu kcp_retrans_bytes=%llu\n",
|
||||
ctx_app[0] ? ctx_app : "unknown",
|
||||
ctx_proto[0] ? ctx_proto : "unknown",
|
||||
@@ -684,7 +805,7 @@ void logger_print_performance_log(const char *tag)
|
||||
metric_avg(&snapshot.processing_delay_ms),
|
||||
metric_avg(&snapshot.queue_delay_ms),
|
||||
metric_avg(&snapshot.transmission_delay_ms),
|
||||
metric_avg(&snapshot.propagation_delay_ms),
|
||||
propagation_avg_ms,
|
||||
metric_avg(&snapshot.end_to_end_delay_ms),
|
||||
snapshot.send_buffer_pct.last,
|
||||
snapshot.recv_buffer_pct.last,
|
||||
@@ -693,6 +814,7 @@ void logger_print_performance_log(const char *tag)
|
||||
(unsigned long long)((snapshot.min_rtt_ms == UINT64_MAX) ? 0 : snapshot.min_rtt_ms),
|
||||
(unsigned long long)snapshot.max_rtt_ms,
|
||||
(unsigned long long)snapshot.tcp_retrans,
|
||||
(unsigned long long)snapshot.udp_retrans,
|
||||
(unsigned long long)snapshot.tcp_data_segs_out,
|
||||
(unsigned long long)snapshot.tcp_data_bytes_sent,
|
||||
(unsigned long long)snapshot.tcp_retrans_bytes,
|
||||
@@ -700,10 +822,39 @@ void logger_print_performance_log(const char *tag)
|
||||
(unsigned long long)snapshot.kcp_data_segs_out,
|
||||
(unsigned long long)snapshot.kcp_data_bytes_sent,
|
||||
(unsigned long long)snapshot.kcp_retrans_bytes);
|
||||
if (snapshot.udp_expected_chunks > 0 || snapshot.udp_lost_chunks > 0) {
|
||||
fprintf(fp,
|
||||
"ts=%llu level=INFO component=perf_udp_loss app=%s proto=%s mode=%s role=%s self_id=%s "
|
||||
"udp_expected_chunks=%llu udp_received_chunks=%llu udp_lost_chunks=%llu "
|
||||
"udp_loss_rate_pct=%.2f udp_loss_burst_count=%llu udp_loss_burst_max_len=%llu "
|
||||
"udp_loss_ranges=%s udp_loss_seq_sample=%s udp_recv_window_dist=%s\n",
|
||||
(unsigned long long)now,
|
||||
ctx_app[0] ? ctx_app : "unknown",
|
||||
ctx_proto[0] ? ctx_proto : "unknown",
|
||||
ctx_mode[0] ? ctx_mode : "unknown",
|
||||
ctx_role[0] ? ctx_role : "unknown",
|
||||
ctx_self_id[0] ? ctx_self_id : "-",
|
||||
(unsigned long long)snapshot.udp_expected_chunks,
|
||||
(unsigned long long)snapshot.udp_received_chunks,
|
||||
(unsigned long long)snapshot.udp_lost_chunks,
|
||||
snapshot.udp_loss_rate_pct,
|
||||
(unsigned long long)snapshot.udp_loss_burst_count,
|
||||
(unsigned long long)snapshot.udp_loss_burst_max_len,
|
||||
udp_loss_ranges[0] ? udp_loss_ranges : "-",
|
||||
udp_loss_seq_sample[0] ? udp_loss_seq_sample : "-",
|
||||
udp_recv_window_dist[0] ? udp_recv_window_dist : "-");
|
||||
}
|
||||
}
|
||||
|
||||
if (g_json_fp) {
|
||||
/* JSONL 输出便于后续脚本或可视化工具离线分析。 */
|
||||
char esc_udp_ranges[sizeof(snapshot.udp_loss_ranges) * 2u];
|
||||
char esc_udp_seq_sample[sizeof(snapshot.udp_loss_seq_sample) * 2u];
|
||||
char esc_udp_window_dist[sizeof(snapshot.udp_recv_window_dist) * 2u];
|
||||
|
||||
json_escape(udp_loss_ranges, esc_udp_ranges, sizeof(esc_udp_ranges));
|
||||
json_escape(udp_loss_seq_sample, esc_udp_seq_sample, sizeof(esc_udp_seq_sample));
|
||||
json_escape(udp_recv_window_dist, esc_udp_window_dist, sizeof(esc_udp_window_dist));
|
||||
fprintf(g_json_fp,
|
||||
"{\"ts_ms\":%llu,"
|
||||
"\"level\":\"INFO\","
|
||||
@@ -764,13 +915,23 @@ void logger_print_performance_log(const char *tag)
|
||||
"\"min_rtt_ms\":%llu,"
|
||||
"\"max_rtt_ms\":%llu,"
|
||||
"\"tcp_retrans\":%llu,"
|
||||
"\"udp_retrans\":%llu,"
|
||||
"\"tcp_data_segs_out\":%llu,"
|
||||
"\"tcp_data_bytes_sent\":%llu,"
|
||||
"\"tcp_retrans_bytes\":%llu,"
|
||||
"\"kcp_retrans\":%llu,"
|
||||
"\"kcp_data_segs_out\":%llu,"
|
||||
"\"kcp_data_bytes_sent\":%llu,"
|
||||
"\"kcp_retrans_bytes\":%llu}\n",
|
||||
"\"kcp_retrans_bytes\":%llu,"
|
||||
"\"udp_expected_chunks\":%llu,"
|
||||
"\"udp_received_chunks\":%llu,"
|
||||
"\"udp_lost_chunks\":%llu,"
|
||||
"\"udp_loss_rate_pct\":%.6f,"
|
||||
"\"udp_loss_burst_count\":%llu,"
|
||||
"\"udp_loss_burst_max_len\":%llu,"
|
||||
"\"udp_loss_ranges\":\"%s\","
|
||||
"\"udp_loss_seq_sample\":\"%s\","
|
||||
"\"udp_recv_window_dist\":\"%s\"}\n",
|
||||
(unsigned long long)now,
|
||||
ctx_app[0] ? ctx_app : "unknown",
|
||||
ctx_proto[0] ? ctx_proto : "unknown",
|
||||
@@ -809,9 +970,9 @@ void logger_print_performance_log(const char *tag)
|
||||
metric_avg(&snapshot.transmission_delay_ms),
|
||||
metric_min(&snapshot.transmission_delay_ms),
|
||||
snapshot.transmission_delay_ms.max,
|
||||
metric_avg(&snapshot.propagation_delay_ms),
|
||||
metric_min(&snapshot.propagation_delay_ms),
|
||||
snapshot.propagation_delay_ms.max,
|
||||
propagation_avg_ms,
|
||||
propagation_min_ms,
|
||||
propagation_max_ms,
|
||||
metric_avg(&snapshot.end_to_end_delay_ms),
|
||||
metric_min(&snapshot.end_to_end_delay_ms),
|
||||
snapshot.end_to_end_delay_ms.max,
|
||||
@@ -828,13 +989,23 @@ void logger_print_performance_log(const char *tag)
|
||||
(unsigned long long)((snapshot.min_rtt_ms == UINT64_MAX) ? 0 : snapshot.min_rtt_ms),
|
||||
(unsigned long long)snapshot.max_rtt_ms,
|
||||
(unsigned long long)snapshot.tcp_retrans,
|
||||
(unsigned long long)snapshot.udp_retrans,
|
||||
(unsigned long long)snapshot.tcp_data_segs_out,
|
||||
(unsigned long long)snapshot.tcp_data_bytes_sent,
|
||||
(unsigned long long)snapshot.tcp_retrans_bytes,
|
||||
(unsigned long long)snapshot.kcp_retrans,
|
||||
(unsigned long long)snapshot.kcp_data_segs_out,
|
||||
(unsigned long long)snapshot.kcp_data_bytes_sent,
|
||||
(unsigned long long)snapshot.kcp_retrans_bytes);
|
||||
(unsigned long long)snapshot.kcp_retrans_bytes,
|
||||
(unsigned long long)snapshot.udp_expected_chunks,
|
||||
(unsigned long long)snapshot.udp_received_chunks,
|
||||
(unsigned long long)snapshot.udp_lost_chunks,
|
||||
snapshot.udp_loss_rate_pct,
|
||||
(unsigned long long)snapshot.udp_loss_burst_count,
|
||||
(unsigned long long)snapshot.udp_loss_burst_max_len,
|
||||
esc_udp_ranges,
|
||||
esc_udp_seq_sample,
|
||||
esc_udp_window_dist);
|
||||
fflush(g_json_fp);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -7,9 +7,11 @@
|
||||
#include <errno.h>
|
||||
#include <netinet/in.h>
|
||||
#include <netinet/tcp.h>
|
||||
#include <stddef.h>
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <string.h>
|
||||
#include <sys/ioctl.h>
|
||||
#include <sys/select.h>
|
||||
#include <sys/socket.h>
|
||||
#include <sys/types.h>
|
||||
@@ -29,6 +31,8 @@ struct PeerTransportSession {
|
||||
socklen_t addr_len;
|
||||
ikcpcb *kcp;
|
||||
uint32_t kcp_conv;
|
||||
uint32_t *kcp_seg_xmit_seen;
|
||||
size_t kcp_seg_xmit_cap;
|
||||
char remote_ip[64];
|
||||
uint16_t remote_port;
|
||||
struct PeerTransportSession *next;
|
||||
@@ -44,6 +48,66 @@ struct PeerTransport {
|
||||
uint8_t *rx_frame;
|
||||
};
|
||||
|
||||
#ifdef __linux__
|
||||
struct OmniLinuxTcpInfo {
|
||||
uint8_t tcpi_state;
|
||||
uint8_t tcpi_ca_state;
|
||||
uint8_t tcpi_retransmits;
|
||||
uint8_t tcpi_probes;
|
||||
uint8_t tcpi_backoff;
|
||||
uint8_t tcpi_options;
|
||||
uint8_t tcpi_snd_wscale : 4, tcpi_rcv_wscale : 4;
|
||||
uint8_t tcpi_delivery_rate_app_limited : 1, tcpi_fastopen_client_fail : 2;
|
||||
uint32_t tcpi_rto;
|
||||
uint32_t tcpi_ato;
|
||||
uint32_t tcpi_snd_mss;
|
||||
uint32_t tcpi_rcv_mss;
|
||||
uint32_t tcpi_unacked;
|
||||
uint32_t tcpi_sacked;
|
||||
uint32_t tcpi_lost;
|
||||
uint32_t tcpi_retrans;
|
||||
uint32_t tcpi_fackets;
|
||||
uint32_t tcpi_last_data_sent;
|
||||
uint32_t tcpi_last_ack_sent;
|
||||
uint32_t tcpi_last_data_recv;
|
||||
uint32_t tcpi_last_ack_recv;
|
||||
uint32_t tcpi_pmtu;
|
||||
uint32_t tcpi_rcv_ssthresh;
|
||||
uint32_t tcpi_rtt;
|
||||
uint32_t tcpi_rttvar;
|
||||
uint32_t tcpi_snd_ssthresh;
|
||||
uint32_t tcpi_snd_cwnd;
|
||||
uint32_t tcpi_advmss;
|
||||
uint32_t tcpi_reordering;
|
||||
uint32_t tcpi_rcv_rtt;
|
||||
uint32_t tcpi_rcv_space;
|
||||
uint32_t tcpi_total_retrans;
|
||||
uint64_t tcpi_pacing_rate;
|
||||
uint64_t tcpi_max_pacing_rate;
|
||||
uint64_t tcpi_bytes_acked;
|
||||
uint64_t tcpi_bytes_received;
|
||||
uint32_t tcpi_segs_out;
|
||||
uint32_t tcpi_segs_in;
|
||||
uint32_t tcpi_notsent_bytes;
|
||||
uint32_t tcpi_min_rtt;
|
||||
uint32_t tcpi_data_segs_in;
|
||||
uint32_t tcpi_data_segs_out;
|
||||
uint64_t tcpi_delivery_rate;
|
||||
uint64_t tcpi_busy_time;
|
||||
uint64_t tcpi_rwnd_limited;
|
||||
uint64_t tcpi_sndbuf_limited;
|
||||
uint32_t tcpi_delivered;
|
||||
uint32_t tcpi_delivered_ce;
|
||||
uint64_t tcpi_bytes_sent;
|
||||
uint64_t tcpi_bytes_retrans;
|
||||
};
|
||||
|
||||
static int tcp_info_has_field(socklen_t len, size_t field_end)
|
||||
{
|
||||
return (size_t)len >= field_end;
|
||||
}
|
||||
#endif
|
||||
|
||||
static void peer_transport_note_send(size_t bytes)
|
||||
{
|
||||
logger_on_send(bytes);
|
||||
@@ -58,6 +122,203 @@ static void peer_transport_note_recv(size_t bytes)
|
||||
logger_maybe_print_performance_log("peer_transport_recv");
|
||||
}
|
||||
|
||||
static void sample_socket_buffers(int fd)
|
||||
{
|
||||
int sndbuf = 0;
|
||||
int rcvbuf = 0;
|
||||
socklen_t optlen = sizeof(int);
|
||||
int outq = 0;
|
||||
int inq = 0;
|
||||
double send_pct = 0.0;
|
||||
double recv_pct = 0.0;
|
||||
|
||||
if (fd < 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
if (getsockopt(fd, SOL_SOCKET, SO_SNDBUF, &sndbuf, &optlen) == 0 && sndbuf > 0) {
|
||||
#ifdef TIOCOUTQ
|
||||
if (ioctl(fd, TIOCOUTQ, &outq) == 0 && outq >= 0) {
|
||||
send_pct = ((double)outq * 100.0) / (double)sndbuf;
|
||||
logger_on_send_queue_bytes((size_t)outq);
|
||||
}
|
||||
#endif
|
||||
}
|
||||
|
||||
optlen = sizeof(int);
|
||||
if (getsockopt(fd, SOL_SOCKET, SO_RCVBUF, &rcvbuf, &optlen) == 0 && rcvbuf > 0) {
|
||||
if (ioctl(fd, FIONREAD, &inq) == 0 && inq >= 0) {
|
||||
recv_pct = ((double)inq * 100.0) / (double)rcvbuf;
|
||||
logger_on_recv_queue_bytes((size_t)inq);
|
||||
}
|
||||
}
|
||||
|
||||
logger_on_buffer_status(send_pct, recv_pct);
|
||||
}
|
||||
|
||||
static void sample_tcp_info(int fd)
|
||||
{
|
||||
#ifdef __linux__
|
||||
struct OmniLinuxTcpInfo ti;
|
||||
uint64_t total_retrans = 0;
|
||||
uint64_t data_segs_out = 0;
|
||||
uint64_t bytes_sent = 0;
|
||||
uint64_t bytes_retrans = 0;
|
||||
socklen_t len = sizeof(ti);
|
||||
|
||||
if (fd < 0) {
|
||||
return;
|
||||
}
|
||||
memset(&ti, 0, sizeof(ti));
|
||||
if (getsockopt(fd, IPPROTO_TCP, TCP_INFO, &ti, &len) != 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
if (tcp_info_has_field(len,
|
||||
offsetof(struct OmniLinuxTcpInfo, tcpi_total_retrans) +
|
||||
sizeof(ti.tcpi_total_retrans))) {
|
||||
total_retrans = (uint64_t)ti.tcpi_total_retrans;
|
||||
} else {
|
||||
total_retrans = (uint64_t)ti.tcpi_retrans;
|
||||
}
|
||||
if (tcp_info_has_field(len,
|
||||
offsetof(struct OmniLinuxTcpInfo, tcpi_data_segs_out) +
|
||||
sizeof(ti.tcpi_data_segs_out))) {
|
||||
data_segs_out = (uint64_t)ti.tcpi_data_segs_out;
|
||||
}
|
||||
if (tcp_info_has_field(len,
|
||||
offsetof(struct OmniLinuxTcpInfo, tcpi_bytes_sent) +
|
||||
sizeof(ti.tcpi_bytes_sent))) {
|
||||
bytes_sent = (uint64_t)ti.tcpi_bytes_sent;
|
||||
}
|
||||
if (tcp_info_has_field(len,
|
||||
offsetof(struct OmniLinuxTcpInfo, tcpi_bytes_retrans) +
|
||||
sizeof(ti.tcpi_bytes_retrans))) {
|
||||
bytes_retrans = (uint64_t)ti.tcpi_bytes_retrans;
|
||||
}
|
||||
|
||||
logger_on_rtt((ti.tcpi_rtt == 0u) ? 0u : (((uint64_t)ti.tcpi_rtt + 999u) / 1000u));
|
||||
logger_on_tcp_transport(total_retrans, data_segs_out, bytes_sent, bytes_retrans);
|
||||
logger_on_cwnd((double)ti.tcpi_snd_cwnd);
|
||||
sample_socket_buffers(fd);
|
||||
#else
|
||||
(void)fd;
|
||||
#endif
|
||||
}
|
||||
|
||||
static int kcp_ensure_seg_track_capacity(PeerTransportSession *session, uint32_t sn)
|
||||
{
|
||||
size_t need;
|
||||
size_t new_cap;
|
||||
uint32_t *new_seen;
|
||||
|
||||
if (!session) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
need = (size_t)sn + 1u;
|
||||
if (need <= session->kcp_seg_xmit_cap) {
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
new_cap = (session->kcp_seg_xmit_cap == 0) ? 64u : session->kcp_seg_xmit_cap;
|
||||
while (new_cap < need) {
|
||||
new_cap *= 2u;
|
||||
}
|
||||
|
||||
new_seen = (uint32_t *)realloc(session->kcp_seg_xmit_seen,
|
||||
new_cap * sizeof(uint32_t));
|
||||
if (!new_seen) {
|
||||
return OMNI_ERR_GENERIC;
|
||||
}
|
||||
memset(new_seen + session->kcp_seg_xmit_cap,
|
||||
0,
|
||||
(new_cap - session->kcp_seg_xmit_cap) * sizeof(uint32_t));
|
||||
session->kcp_seg_xmit_seen = new_seen;
|
||||
session->kcp_seg_xmit_cap = new_cap;
|
||||
return OMNI_OK;
|
||||
}
|
||||
|
||||
static void sample_kcp_session(PeerTransportSession *session)
|
||||
{
|
||||
struct IQUEUEHEAD *p;
|
||||
double send_pct = 0.0;
|
||||
double recv_pct = 0.0;
|
||||
|
||||
if (!session || !session->kcp) {
|
||||
return;
|
||||
}
|
||||
|
||||
for (p = session->kcp->snd_buf.next; p != &session->kcp->snd_buf; p = p->next) {
|
||||
struct IKCPSEG *segment = iqueue_entry(p, struct IKCPSEG, node);
|
||||
uint32_t prev_xmit;
|
||||
|
||||
if (!segment || segment->len == 0) {
|
||||
continue;
|
||||
}
|
||||
if (kcp_ensure_seg_track_capacity(session, segment->sn) != OMNI_OK) {
|
||||
return;
|
||||
}
|
||||
|
||||
prev_xmit = session->kcp_seg_xmit_seen[segment->sn];
|
||||
if (prev_xmit == 0 && segment->xmit > 0) {
|
||||
logger_on_kcp_tx(1u, (uint64_t)segment->len);
|
||||
prev_xmit = 1u;
|
||||
}
|
||||
if (segment->xmit > prev_xmit) {
|
||||
uint32_t delta = segment->xmit - prev_xmit;
|
||||
logger_on_kcp_retrans((uint64_t)delta,
|
||||
(uint64_t)delta * (uint64_t)segment->len);
|
||||
}
|
||||
session->kcp_seg_xmit_seen[segment->sn] = segment->xmit;
|
||||
}
|
||||
|
||||
if (session->kcp->rx_srtt > 0) {
|
||||
logger_on_rtt((uint64_t)session->kcp->rx_srtt);
|
||||
}
|
||||
logger_on_cwnd((double)session->kcp->cwnd);
|
||||
|
||||
if (session->kcp->snd_wnd > 0) {
|
||||
send_pct = ((double)ikcp_waitsnd(session->kcp) * 100.0) /
|
||||
(double)session->kcp->snd_wnd;
|
||||
logger_on_send_queue_bytes((size_t)ikcp_waitsnd(session->kcp) *
|
||||
(size_t)session->kcp->mss);
|
||||
}
|
||||
if (session->kcp->rcv_wnd > 0) {
|
||||
recv_pct = ((double)session->kcp->nrcv_que * 100.0) /
|
||||
(double)session->kcp->rcv_wnd;
|
||||
logger_on_recv_queue_bytes((size_t)session->kcp->nrcv_que *
|
||||
(size_t)session->kcp->mss);
|
||||
}
|
||||
logger_on_buffer_status(send_pct, recv_pct);
|
||||
}
|
||||
|
||||
static void peer_transport_sample_after_send(PeerTransport *transport,
|
||||
PeerTransportSession *session)
|
||||
{
|
||||
if (!transport || !session) {
|
||||
return;
|
||||
}
|
||||
switch (transport->proto) {
|
||||
case OMNI_PROTO_TCP:
|
||||
sample_tcp_info(session->fd);
|
||||
break;
|
||||
case OMNI_PROTO_UDP:
|
||||
sample_socket_buffers(transport->fd);
|
||||
break;
|
||||
case OMNI_PROTO_KCP:
|
||||
sample_kcp_session(session);
|
||||
break;
|
||||
default:
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
static void peer_transport_sample_after_recv(PeerTransport *transport,
|
||||
PeerTransportSession *session)
|
||||
{
|
||||
peer_transport_sample_after_send(transport, session);
|
||||
}
|
||||
|
||||
const char *peer_transport_proto_name(OmniProtocol proto)
|
||||
{
|
||||
switch (proto) {
|
||||
@@ -183,6 +444,7 @@ static void session_free(PeerTransportSession *session)
|
||||
if (session->kcp) {
|
||||
ikcp_release(session->kcp);
|
||||
}
|
||||
free(session->kcp_seg_xmit_seen);
|
||||
free(session);
|
||||
}
|
||||
|
||||
@@ -845,6 +1107,10 @@ int peer_transport_send(PeerTransport *transport,
|
||||
ssize_t n = -1;
|
||||
int rc = OMNI_OK;
|
||||
int raw_rc = 0;
|
||||
uint64_t call_t0;
|
||||
uint64_t proto_t0;
|
||||
uint64_t proto_t1;
|
||||
uint64_t call_t1;
|
||||
|
||||
if (!transport) {
|
||||
return OMNI_ERR_PARAM;
|
||||
@@ -856,11 +1122,13 @@ int peer_transport_send(PeerTransport *transport,
|
||||
return OMNI_ERR_IO;
|
||||
}
|
||||
|
||||
call_t0 = omni_now_ms();
|
||||
frame = alloc_frame(type, payload, payload_len, &frame_len);
|
||||
if (!frame) {
|
||||
return OMNI_ERR_GENERIC;
|
||||
}
|
||||
|
||||
proto_t0 = omni_now_ms();
|
||||
switch (transport->proto) {
|
||||
case OMNI_PROTO_TCP:
|
||||
n = write_n(session->fd, frame, frame_len);
|
||||
@@ -891,9 +1159,14 @@ int peer_transport_send(PeerTransport *transport,
|
||||
rc = OMNI_ERR_PARAM;
|
||||
break;
|
||||
}
|
||||
proto_t1 = omni_now_ms();
|
||||
call_t1 = proto_t1;
|
||||
logger_on_proto_send_latency(proto_t1 - proto_t0);
|
||||
logger_on_send_call_latency(call_t1 - call_t0);
|
||||
|
||||
if (rc == OMNI_OK) {
|
||||
peer_transport_note_send(frame_len);
|
||||
peer_transport_sample_after_send(transport, session);
|
||||
} else {
|
||||
logger_log("ERROR", "peer_transport",
|
||||
"send_failed proto=%s type=%u remote=%s:%u raw_rc=%d errno=%d",
|
||||
@@ -1088,21 +1361,39 @@ int peer_transport_next_event(PeerTransport *transport,
|
||||
size_t payload_cap,
|
||||
int timeout_ms)
|
||||
{
|
||||
int rc;
|
||||
uint64_t t0;
|
||||
uint64_t t1;
|
||||
|
||||
if (!transport || !event || !payload_buf) {
|
||||
return OMNI_ERR_PARAM;
|
||||
}
|
||||
|
||||
event_reset(event);
|
||||
t0 = omni_now_ms();
|
||||
switch (transport->proto) {
|
||||
case OMNI_PROTO_TCP:
|
||||
return tcp_next_event(transport, event, payload_buf, payload_cap, timeout_ms);
|
||||
rc = tcp_next_event(transport, event, payload_buf, payload_cap, timeout_ms);
|
||||
break;
|
||||
case OMNI_PROTO_UDP:
|
||||
return udp_next_event(transport, event, payload_buf, payload_cap, timeout_ms);
|
||||
rc = udp_next_event(transport, event, payload_buf, payload_cap, timeout_ms);
|
||||
break;
|
||||
case OMNI_PROTO_KCP:
|
||||
return kcp_next_event(transport, event, payload_buf, payload_cap, timeout_ms);
|
||||
rc = kcp_next_event(transport, event, payload_buf, payload_cap, timeout_ms);
|
||||
break;
|
||||
default:
|
||||
return OMNI_ERR_PARAM;
|
||||
rc = OMNI_ERR_PARAM;
|
||||
break;
|
||||
}
|
||||
t1 = omni_now_ms();
|
||||
if (rc > 0) {
|
||||
logger_on_proto_recv_latency(t1 - t0);
|
||||
logger_on_recv_call_latency(t1 - t0);
|
||||
if (event->session) {
|
||||
peer_transport_sample_after_recv(transport, event->session);
|
||||
}
|
||||
}
|
||||
return rc;
|
||||
}
|
||||
|
||||
void peer_transport_close_session(PeerTransport *transport,
|
||||
|
||||
@@ -100,6 +100,14 @@ static int tcp_info_has_field(socklen_t len, size_t field_end)
|
||||
{
|
||||
return (size_t)len >= field_end;
|
||||
}
|
||||
|
||||
static uint64_t tcp_info_rtt_us_to_ms(uint32_t rtt_us)
|
||||
{
|
||||
if (rtt_us == 0u) {
|
||||
return 0u;
|
||||
}
|
||||
return ((uint64_t)rtt_us + 999u) / 1000u;
|
||||
}
|
||||
#endif
|
||||
|
||||
struct TcpContext {
|
||||
@@ -168,9 +176,9 @@ static void tcp_log_info(int fd, const char *tag)
|
||||
return;
|
||||
}
|
||||
|
||||
/* 注意：tcpi_rtt 单位通常为微秒（Linux），这里转 ms 仅用于日志观察 */
|
||||
unsigned long long rtt_ms = (unsigned long long)(ti.tcpi_rtt / 1000u);
|
||||
unsigned long long rttvar_ms = (unsigned long long)(ti.tcpi_rttvar / 1000u);
|
||||
/* 注意：tcpi_rtt / tcpi_rttvar 单位通常为微秒（Linux），这里向上取整到 ms。 */
|
||||
unsigned long long rtt_ms = (unsigned long long)tcp_info_rtt_us_to_ms(ti.tcpi_rtt);
|
||||
unsigned long long rttvar_ms = (unsigned long long)tcp_info_rtt_us_to_ms(ti.tcpi_rttvar);
|
||||
|
||||
if (tcp_info_has_field(len, offsetof(struct OmniLinuxTcpInfo, tcpi_total_retrans) +
|
||||
sizeof(ti.tcpi_total_retrans))) {
|
||||
|
||||
Reference in New Issue
Block a user