search

OpenVisualCloud / Media-Transport-Library

A real-time media transport(DPDK, AF_XDP, RDMA) stack for both raw and compressed video based on COTS hardware.
BSD 3-Clause "New" or "Revised" License
163 stars 52 forks source link

2022-7 testing with a prism #607

Closed sammirata closed 7 months ago

sammirata commented 9 months ago

We have implemented the library under linux and have it outputting 2022-7. We are monitoring with a prism for compliance. The output is valid for a single output but when we enable the second output, we are getting a small number of "rtp sequence errors" on the prism. They seem to coincide with the stats not showing the exact same number of packets transmitted on both interface on the stats.

My question is, per stats interval, are the number of tx packet supposed to be the same? or perhaps it needs to average over time?

For example:

@40000000656586e405a2f094 MT: 2023-11-28 06:21:14, M T D E V S T A T E @40000000656586e405c15da4 MT: 2023-11-28 06:21:14, DEV(0): Avr rate, tx: 1093.865350 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038765, rx: 0 @40000000656586e405f1dbb4 MT: 2023-11-28 06:21:14, DEV(1): Avr rate, tx: 1093.867466 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038768, rx: 0 @40000000656586e406021024 MT: 2023-11-28 06:21:14, CNI(0): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0 @40000000656586e406021bdc MT: 2023-11-28 06:21:14, CNI(1): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0 @40000000656586e406023734 MT: 2023-11-28 06:21:14, PTP(0): time 1701152474100802731, 2023-11-28 06:21:14 @40000000656586e406023f04 MT: 2023-11-28 06:21:14, PTP(1): time 1701152474100807187, 2023-11-28 06:21:14 @40000000656586e40602528c MT: 2023-11-28 06:21:14, TX_VIDEO_SESSION(0,0:TEST-VIDEO): fps 50.000083, frame 500 pkts 1029988:2057976 inflight 58245:54186 @40000000656586e406026614 MT: 2023-11-28 06:21:14, TX_VIDEO_SESSION(0,0): throughput 1089.061111 Mb/s: 1089.061111 Mb/s, cpu busy 77.527145 @40000000656586e406026de4 MT: 2023-11-28 06:21:14, TX_VIDEO_SESSION(0,0): dummy pkts 1000, burst 2000 @40000000656586e40602893c MT: 2023-11-28 06:21:14, TX_AUDIO_SESSION(0,0:Test Audio): fps 1000.001617 frame cnt 10000, pkt cnt 10000, inflight count 0: 0 @40000000656586e4060294f4 MT: 2023-11-28 06:21:14, TX_AUDIO_MGR(0), pkts burst 20000 @40000000656586e406029cc4 MT: 2023-11-28 06:21:14, E N D S T A T E

You can see that we have dev0 has 1038765 and dev1 has 1038768 ...

frankdjx commented 9 months ago

This is just a statistical error. Due to the large volume of data, the timing varies slightly when tallying the packets TX by each port.

For the logical of ST2022-7, in IMTL, the packet is cloned, then pushed to the TX queue of second device at the same time when the original packet pushed to the first device.

Do you know what the detail possible reasons to rtp sequence errors for Prism?

sammirata commented 9 months ago

I will find out ...

sammirata commented 9 months ago

From our QA team: "We always found it to be when the cpu or process could not keep up and buffers would not clear correctly. We had this on AMPP and other mellanox products until they fixed the senders and receivers. It was so bad at times it would overrun the switch buffers." So, to me, this means either packet loss or out of order packets. Also, regarding the stats anomaly ... It mostly seems to be missing tx packets on the same leg ... it does not average out to zero delta. And only once every 5 to 10 stats interval, the numbers match.

frankdjx commented 9 months ago

Can you do some experimental test to clarify the cause.

MTL still outputting 2022-7, config PRISM to monitor only one of these two streams to see if the single stream is compliant.

sammirata commented 9 months ago

We did ... first stream is fully compliant. Second stream is not.

frankdjx commented 9 months ago

It seems there might be packet loss or out-of-order packets on the redundant path. Could you share the JSON configuration and the log file? I can check for any issues on the MTL TX side.

Other users are also testing with Prism with the 2022-7, and no such issues have been reported. Regarding the second stream, is it VRX/CINST compliant?

gizahNL commented 9 months ago

These are the logs of the sending application @sammirata is talking about, since this is a custom application there isn't a json. This is running on E810 VF devices.

[mtl-2110]: Config:
  Ports:
    0000:18:11.0     10.101.1.130
    0000:18:01.0     10.101.1.142
  Video urls:
    239.29.11.50:5020
    239.79.11.50:5020
  Audio channels: 4
Streams:
  Stream 0:
    239.35.11.50:5030
    239.35.11.51:5030
MT: 2023-12-01 02:24:10, dev_eal_init(0), port_param: 0000:18:11.0
MT: 2023-12-01 02:24:10, dev_eal_init(1), port_param: 0000:18:01.0
MT: 2023-12-01 02:24:10, dev_eal_init, wait eal_init_thread done
EAL: Detected CPU lcores: 64
EAL: Detected NUMA nodes: 1
EAL: Detected shared linkage of DPDK
EAL: Selected IOVA mode 'VA'
EAL: 3712 hugepages of size 2097152 reserved, but no mounted hugetlbfs found for that size
EAL: No free 1048576 kB hugepages reported on node 0
EAL: VFIO support initialized
EAL: Using IOMMU type 1 (Type 1)
EAL: Probe PCI driver: net_iavf (8086:1889) device: 0000:18:01.0 (socket 0)
EAL: Probe PCI driver: net_iavf (8086:1889) device: 0000:18:11.0 (socket 0)
TELEMETRY: No legacy callbacks, legacy socket not created
MT: 2023-12-01 02:24:10, st version: 23.12.0 Sun Nov 19 21:36:58 2023 2022.11.1-1266-g9adda053-dirty gcc-12.2.0, dpdk version: DPDK 23.03.0
MT: 2023-12-01 02:24:10, Warn: mt_instance_init, connect to manager fail, assume single instance mode
MT: 2023-12-01 02:24:10, mtl_init(0), socket_id 0 port 0000:18:11.0
MT: 2023-12-01 02:24:10, mtl_init(1), socket_id 0 port 0000:18:01.0
MT: 2023-12-01 02:24:10, mt_stat_init, stat period 10s
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), use mt ptp source
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), user request queues tx 2 rx 0
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), deprecated sessions tx 0 rx 0
MT: 2023-12-01 02:24:10, stat_thread, start
MT: 2023-12-01 02:24:10, dev_config_port(0), tx_q(3 with 512 desc) rx_q (3 with 2048 desc)
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x11804fdf00 size 3.234375m n 1536 d 2048 for T_P0_SYS_0
MT: 2023-12-01 02:24:10, dev_if_init_tx_queues(0), tx_queues 3 malloc succ
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x1180afdf00 size 6.468750m n 3072 d 2048 for R_P0Q0_MBUF_1
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x11814fdf00 size 4.968750m n 3072 d 1536 for R_P0Q1_MBUF_2
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x1181cfdf00 size 4.968750m n 3072 d 1536 for R_P0Q2_MBUF_3
MT: 2023-12-01 02:24:10, dev_if_init_rx_queues(0), rx_queues 3 malloc succ
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), port_id 1 port_type 1 drv_type 3
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), dev_capa 0x0, offload 0x119fbf:0x9266f queue offload 0x0:0x0, rss : 0x3ffc
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), system_rx_queues_end 1 hdr_split_rx_queues_end 1
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), sip: 10.101.1.130
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), netmask: 255.255.255.0
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), gateway: 0.0.0.0
MT: 2023-12-01 02:24:10, mt_dev_if_init(0), mac: f6:1a:1b:e4:86:e7
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), use mt ptp source
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), user request queues tx 2 rx 0
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), deprecated sessions tx 0 rx 0
MT: 2023-12-01 02:24:10, dev_config_port(1), tx_q(3 with 512 desc) rx_q (3 with 2048 desc)
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(1), succ at 0x11824fdf00 size 3.234375m n 1536 d 2048 for T_P1_SYS_4
MT: 2023-12-01 02:24:10, dev_if_init_tx_queues(1), tx_queues 3 malloc succ
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(1), succ at 0x1182afdf00 size 6.468750m n 3072 d 2048 for R_P1Q0_MBUF_5
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(1), succ at 0x11834fdf00 size 4.968750m n 3072 d 1536 for R_P1Q1_MBUF_6
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(1), succ at 0x1183cfdf00 size 4.968750m n 3072 d 1536 for R_P1Q2_MBUF_7
MT: 2023-12-01 02:24:10, dev_if_init_rx_queues(1), rx_queues 3 malloc succ
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), port_id 0 port_type 1 drv_type 3
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), dev_capa 0x0, offload 0x119fbf:0x9266f queue offload 0x0:0x0, rss : 0x3ffc
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), system_rx_queues_end 1 hdr_split_rx_queues_end 1
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), sip: 10.101.1.142
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), netmask: 255.255.255.0
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), gateway: 0.0.0.0
MT: 2023-12-01 02:24:10, mt_dev_if_init(1), mac: 82:30:86:ea:73:cc
iavf_configure_queues(): request RXDID[22] in Queue[0]
iavf_configure_queues(): request RXDID[22] in Queue[1]
iavf_configure_queues(): request RXDID[22] in Queue[2]
MT: 2023-12-01 02:24:10, dev_start_port(0), rx_defer 0
MT: 2023-12-01 02:24:10, mt_eth_link_dump(1), link_speed 25g link_status 1 link_duplex 1 link_autoneg 1
MT: 2023-12-01 02:24:10, dev_rl_shaper_add(0), bps 134217728 on shaper 1
MT: 2023-12-01 02:24:10, dev_init_ratelimit_all(0), q 0 link to shaper id 1
MT: 2023-12-01 02:24:10, dev_init_ratelimit_all(0), q 1 link to shaper id 1
MT: 2023-12-01 02:24:10, dev_init_ratelimit_all(0), q 2 link to shaper id 1
MT: 2023-12-01 02:24:10, mt_dev_create(0), feature 0x30, tx pacing ratelimit
iavf_configure_queues(): request RXDID[22] in Queue[0]
iavf_configure_queues(): request RXDID[22] in Queue[1]
iavf_configure_queues(): request RXDID[22] in Queue[2]
MT: 2023-12-01 02:24:10, dev_start_port(1), rx_defer 0
MT: 2023-12-01 02:24:10, mt_eth_link_dump(0), link_speed 25g link_status 1 link_duplex 1 link_autoneg 1
MT: 2023-12-01 02:24:10, dev_rl_shaper_add(1), bps 134217728 on shaper 1
MT: 2023-12-01 02:24:10, dev_init_ratelimit_all(1), q 0 link to shaper id 1
MT: 2023-12-01 02:24:10, dev_init_ratelimit_all(1), q 1 link to shaper id 1
MT: 2023-12-01 02:24:10, dev_init_ratelimit_all(1), q 2 link to shaper id 1
MT: 2023-12-01 02:24:10, mt_dev_create(1), feature 0x30, tx pacing ratelimit
MT: 2023-12-01 02:24:10, sch_lcore_shm_init, clear shm as we are the first user
MT: 2023-12-01 02:24:10, sch_lcore_shm_init, shared memory attached at 0x7fec6f066000 nattch 1 shm_id 2 key 0x15050005
MT: 2023-12-01 02:24:10, mt_sch_mrg_init, succ with data quota 31068 M, nb_tasklets 16
MT: 2023-12-01 02:24:10, mt_sch_add_quota(0:0), quota 0 total now 0
MT: 2023-12-01 02:24:10, mt_dev_get_tx_queue(0), q 0 with speed 1.073742g bps
MT: 2023-12-01 02:24:10, mt_dev_get_tx_queue(1), q 0 with speed 1.073742g bps
MT: 2023-12-01 02:24:10, mt_mcast_init, report every 10 seconds
MT: 2023-12-01 02:24:10, mt_dev_get_rx_queue(0), q 0 ip 0.0.0.0 port 0
MT: 2023-12-01 02:24:10, cni_queues_init(0), rxq 0
MT: 2023-12-01 02:24:10, mt_dev_get_rx_queue(1), q 0 ip 0.0.0.0 port 0
MT: 2023-12-01 02:24:10, cni_queues_init(1), rxq 0
MT: 2023-12-01 02:24:10, mt_sch_register_tasklet(0), tasklet cni registered into slot 0
MT: 2023-12-01 02:24:10, cni_traffic_thread, start
MT: 2023-12-01 02:24:10, st_plugins_init, succ
MT: 2023-12-01 02:24:10, Warn: config_parse_json, open json file kahawai.json fail
MT: 2023-12-01 02:24:10, mt_ptp_port_id(1), port_number: 0100, clk_id: f6:1a:1b:ff:fe:e4:86:e7
MT: 2023-12-01 02:24:10, mt_ptp_port_id(0), port_number: 0000, clk_id: 82:30:86:ff:fe:ea:73:cc
MT: 2023-12-01 02:24:10, mt_main_create, succ
MT: 2023-12-01 02:24:10, mtl_init, succ, tsc_hz 2300000000
MT: 2023-12-01 02:24:10, mtl_init, simd level avx512_vbmi, flags 0x0
MT: 2023-12-01 02:24:10, st20p_tx_create, start for TEST-VIDEO
MT: 2023-12-01 02:24:10, st20_get_converter, plugin not found, input fmt: YUV422PLANAR10LE, output fmt: YUV422RFC4175PG2BE10
MT: 2023-12-01 02:24:10, tx_st20p_get_converter(0), use internal converter
MT: 2023-12-01 02:24:10, admin_thread, start
MT: 2023-12-01 02:24:10, tx_st20p_init_src_fbs(0), size 4147200 fmt 0 with 3 frames
MT: 2023-12-01 02:24:10, st20_tx_create, start for TEST-VIDEO
MT: 2023-12-01 02:24:10, mt_sch_add_quota(0:0), quota 1080 total now 1080
MT: 2023-12-01 02:24:10, mt_sch_get(0), succ with quota_mbs 1080
MT: 2023-12-01 02:24:10, mt_sch_register_tasklet(0), tasklet tx_video_sessions_mgr registered into slot 1
MT: 2023-12-01 02:24:10, tv_mgr_init(0), succ
MT: 2023-12-01 02:24:10, mt_sch_register_tasklet(0), tasklet video_transmitter registered into slot 2
MT: 2023-12-01 02:24:10, st_video_transmitter_init(0), succ
MT: 2023-12-01 02:24:10, tv_attach(0), st21_vrx_narrow: 8, st21_vrx_wide: 720
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x11850fdf00 size 0.281250m n 1024 d 128 for TV_M0S0P0_HDR_0_8
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(1), succ at 0x11852fdf00 size 0.281250m n 1024 d 128 for TV_M0S0P1_HDR_0_9
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x11854fdf00 size 0.125000m n 1024 d 0 for TV_M0S0_CHAIN_0_10
MT: 2023-12-01 02:24:10, dev_rl_shaper_add(0), bps 136033800 on shaper 2
MT: 2023-12-01 02:24:10, dev_tx_queue_set_rl_rate(0), q 1 link to shaper id 2(136033800)
MT: 2023-12-01 02:24:10, mt_dev_get_tx_queue(0), q 1 with speed 1.088270g bps
MT: 2023-12-01 02:24:10, tv_init_hw(0,0), port(l:0,p:0), queue 1, count 512
MT: 2023-12-01 02:24:10, tv_init_hw(0), type 0 number 1543 size 1322
MT: 2023-12-01 02:24:10, tv_init_hw(0), type 1 number 514 size 1328
MT: 2023-12-01 02:24:10, tv_init_hw(0), type 2 number 1 size 242
MT: 2023-12-01 02:24:10, dev_rl_shaper_add(1), bps 136033800 on shaper 2
MT: 2023-12-01 02:24:10, dev_tx_queue_set_rl_rate(1), q 1 link to shaper id 2(136033800)
MT: 2023-12-01 02:24:10, mt_dev_get_tx_queue(1), q 1 with speed 1.088270g bps
MT: 2023-12-01 02:24:10, tv_init_hw(0,0), port(l:1,p:1), queue 1, count 512
MT: 2023-12-01 02:24:10, tv_init_hw(0), type 0 number 1543 size 1322
MT: 2023-12-01 02:24:10, tv_init_hw(0), type 1 number 514 size 1328
MT: 2023-12-01 02:24:10, tv_init_hw(0), type 2 number 1 size 242
MT: 2023-12-01 02:24:10, tv_init_hdr(0,0), ip 239.29.11.50 port 5020:5020
MT: 2023-12-01 02:24:10, tv_init_hdr(0), mac: 01:00:5e:1d:0b:32, ssrc 1193040
MT: 2023-12-01 02:24:10, tv_init_hdr(0,1), ip 239.79.11.50 port 5020:5020
MT: 2023-12-01 02:24:10, tv_init_hdr(0), mac: 01:00:5e:4f:0b:32, ssrc 1193040
MT: 2023-12-01 02:24:10, tv_train_pacing(0), user static pad_interval 268
MT: 2023-12-01 02:24:10, tv_train_pacing(0), user static pad_interval 268
MT: 2023-12-01 02:24:10, tv_init_pacing[00], trs 9329.446064 trOffset 782222.222222 vrx 4 warm_pkts 66 frame time 20.000000ms fps 50.000000
MT: 2023-12-01 02:24:10, tv_attach(0), len 1260(1322) total 2058 each line 0 type 0 flags 0x10, interlace
MT: 2023-12-01 02:24:10, tv_attach(0), w 1920 h 1080 fmt ST20_FMT_YUV_422_10BIT packing 0 pt 112, pacing way: ratelimit
MT: 2023-12-01 02:24:10, st20_tx_create(0,0), succ on 0x11802b68c0
MT: 2023-12-01 02:24:10, st20p_tx_create(0), transport fmt ST20_FMT_YUV_422_10BIT, input fmt: YUV422PLANAR10LE
MT: 2023-12-01 02:24:10, st30_tx_create, start for Test Audio
MT: 2023-12-01 02:24:10, mt_sch_add_quota(0:0), quota 103 total now 1183
MT: 2023-12-01 02:24:10, mt_sch_get(0), succ with quota_mbs 103
MT: 2023-12-01 02:24:10, mt_sch_register_tasklet(0), tasklet tx_audio_sessions_build registered into slot 3
MT: 2023-12-01 02:24:10, mt_sch_register_tasklet(0), tasklet tx_audio_sessions_trans registered into slot 4
MT: 2023-12-01 02:24:10, tx_audio_sessions_mgr_init(0), succ
MT: 2023-12-01 02:24:10, mt_sch_register_tasklet(0), tasklet audio_transmitter registered into slot 5
MT: 2023-12-01 02:24:10, st_audio_transmitter_init(0), succ
MT: 2023-12-01 02:24:10, mt_dev_get_tx_queue(0), q 2 with speed 1.073742g bps
MT: 2023-12-01 02:24:10, tx_audio_sessions_mgr_init_hw(0,0), succ, queue 2
MT: 2023-12-01 02:24:10, mt_dev_get_tx_queue(1), q 2 with speed 1.073742g bps
MT: 2023-12-01 02:24:10, tx_audio_sessions_mgr_init_hw(0,1), succ, queue 2
MT: 2023-12-01 02:24:10, tx_audio_session_init_pacing[00], trs 1000000.000000 pkt_time_sampling 48.000000
MT: 2023-12-01 02:24:10, tx_audio_session_init_hdr(0,0), ip 239.35.11.50 port 5030:5030
MT: 2023-12-01 02:24:10, tx_audio_session_init_hdr(0), mac: 01:00:5e:23:0b:32, ssrc 2241616
MT: 2023-12-01 02:24:10, tx_audio_session_init_hdr(0,1), ip 239.35.11.51 port 5030:5030
MT: 2023-12-01 02:24:10, tx_audio_session_init_hdr(0), mac: 01:00:5e:23:0b:33, ssrc 2241616
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x1185e85180 size 0.421875m n 1536 d 128 for TA_M0S0P0_HDR_0_11
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(1), succ at 0x1185a85180 size 0.421875m n 1536 d 128 for TA_M0S0P1_HDR_0_12
MT: 2023-12-01 02:24:10, mt_mempool_create_by_ops(0), succ at 0x1185685180 size 1.125000m n 1536 d 640 for TA_M0S0_CHAIN_0_13
MT: 2023-12-01 02:24:10, tx_audio_session_init_trans_ring(0,0), trans_ring_thresh 10
MT: 2023-12-01 02:24:10, tx_audio_session_attach(0), pkt_len 576 frame_size 576 fps 1000.000000
MT: 2023-12-01 02:24:10, st30_tx_create(0,0), succ on 0x11802ba3c0
Setting framedur: 1080000
MT: 2023-12-01 02:24:11, mt_calibrate_tsc, tscHz 2299997951
MT: 2023-12-01 02:24:11, mt_sch_get_lcore, available lcore 6
MT: 2023-12-01 02:24:11, sch_tasklet_func(0), start with 6 tasklets
MT: 2023-12-01 02:24:11, sch_start(0), succ on lcore 6
MT: 2023-12-01 02:24:11, mt_dev_start, succ
MT: 2023-12-01 02:24:11, _mt_start, succ, avail ports 2
Encoding started
MT: 2023-12-01 02:24:11, cni_traffic_thread, stop
MT: 2023-12-01 02:24:11, video_trs_tasklet_start(0), succ
MT: 2023-12-01 02:24:11, st_audio_trs_tasklet_start(0), succ

MT: 2023-12-01 02:24:20, * *    M T    D E V   S T A T E   * * 
MT: 2023-12-01 02:24:20, DEV(0): Avr rate, tx: 913.616917 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 867615, rx: 0
MT: 2023-12-01 02:24:20, DEV(1): Avr rate, tx: 913.977363 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 867957, rx: 0
MT: 2023-12-01 02:24:20, CNI(0): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:20, CNI(1): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:20, PTP(0): time 1701357860676788770, 2023-12-01 02:24:20
MT: 2023-12-01 02:24:20, PTP(1): time 1701357860676793683, 2023-12-01 02:24:20
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0:TEST-VIDEO): fps 42.019892, frame 418 pkts 861504:1720315 inflight 48669:48658
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0): throughput 915.162035 Mb/s: 915.163098 Mb/s, cpu busy 77.542000
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0): dummy pkts 836, burst 1668
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0): mismatch epoch troffset 2
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0): epoch drop 29
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0): busy as no ready frame from user 2
MT: 2023-12-01 02:24:20, TX_VIDEO_SESSION(0,0): tx done for cleanup 1024
MT: 2023-12-01 02:24:20, TX_AUDIO_SESSION(0,0:Test Audio): fps 844.423349 frame cnt 8400, pkt cnt 8400, inflight count 0: 0
MT: 2023-12-01 02:24:20, TX_AUDIO_SESSION(0,0): epoch mismatch 2
MT: 2023-12-01 02:24:20, TX_AUDIO_SESSION(0,0): epoch drop 556
MT: 2023-12-01 02:24:20, TX_AUDIO_MGR(0), pkts burst 16784
MT: 2023-12-01 02:24:20, * *    E N D    S T A T E   * * 

MT: 2023-12-01 02:24:30, * *    M T    D E V   S T A T E   * * 
MT: 2023-12-01 02:24:30, DEV(0): Avr rate, tx: 1093.897112 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038796, rx: 0
MT: 2023-12-01 02:24:30, DEV(1): Avr rate, tx: 1093.897117 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038796, rx: 0
MT: 2023-12-01 02:24:30, CNI(0): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:30, CNI(1): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:30, PTP(0): time 1701357870676863060, 2023-12-01 02:24:30
MT: 2023-12-01 02:24:30, PTP(1): time 1701357870676867905, 2023-12-01 02:24:30
MT: 2023-12-01 02:24:30, TX_VIDEO_SESSION(0,0:TEST-VIDEO): fps 49.999513, frame 500 pkts 1030004:2058008 inflight 58222:58252
MT: 2023-12-01 02:24:30, TX_VIDEO_SESSION(0,0): throughput 1089.065627 Mb/s: 1089.065627 Mb/s, cpu busy 77.532196
MT: 2023-12-01 02:24:30, TX_VIDEO_SESSION(0,0): dummy pkts 1000, burst 2000
MT: 2023-12-01 02:24:30, TX_AUDIO_SESSION(0,0:Test Audio): fps 999.992082 frame cnt 10000, pkt cnt 10000, inflight count 0: 0
MT: 2023-12-01 02:24:30, TX_AUDIO_MGR(0), pkts burst 20000
MT: 2023-12-01 02:24:30, * *    E N D    S T A T E   * * 

MT: 2023-12-01 02:24:40, * *    M T    D E V   S T A T E   * * 
MT: 2023-12-01 02:24:40, DEV(0): Avr rate, tx: 1093.878051 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038779, rx: 0
MT: 2023-12-01 02:24:40, DEV(1): Avr rate, tx: 1093.878056 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038777, rx: 0
MT: 2023-12-01 02:24:40, CNI(0): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:40, CNI(1): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:40, PTP(0): time 1701357880676782370, 2023-12-01 02:24:40
MT: 2023-12-01 02:24:40, PTP(1): time 1701357880676787372, 2023-12-01 02:24:40
MT: 2023-12-01 02:24:40, TX_VIDEO_SESSION(0,0:TEST-VIDEO): fps 50.000285, frame 500 pkts 1029988:2057976 inflight 58220:58249
MT: 2023-12-01 02:24:40, TX_VIDEO_SESSION(0,0): throughput 1089.065501 Mb/s: 1089.065501 Mb/s, cpu busy 77.532585
MT: 2023-12-01 02:24:40, TX_VIDEO_SESSION(0,0): dummy pkts 1000, burst 2000
MT: 2023-12-01 02:24:40, TX_AUDIO_SESSION(0,0:Test Audio): fps 1000.005690 frame cnt 10000, pkt cnt 10000, inflight count 0: 0
MT: 2023-12-01 02:24:40, TX_AUDIO_MGR(0), pkts burst 20000
MT: 2023-12-01 02:24:40, * *    E N D    S T A T E   * * 

MT: 2023-12-01 02:24:50, * *    M T    D E V   S T A T E   * * 
MT: 2023-12-01 02:24:50, DEV(0): Avr rate, tx: 1093.897112 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038796, rx: 0
MT: 2023-12-01 02:24:50, DEV(1): Avr rate, tx: 1093.902410 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038801, rx: 0
MT: 2023-12-01 02:24:50, CNI(0): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:50, CNI(1): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:24:50, PTP(0): time 1701357890676872167, 2023-12-01 02:24:50
MT: 2023-12-01 02:24:50, PTP(1): time 1701357890676877427, 2023-12-01 02:24:50
MT: 2023-12-01 02:24:50, TX_VIDEO_SESSION(0,0:TEST-VIDEO): fps 49.999433, frame 500 pkts 1030020:2058040 inflight 58223:58251
MT: 2023-12-01 02:24:50, TX_VIDEO_SESSION(0,0): throughput 1089.080819 Mb/s: 1089.080819 Mb/s, cpu busy 77.532196
MT: 2023-12-01 02:24:50, TX_VIDEO_SESSION(0,0): dummy pkts 1000, burst 2000
MT: 2023-12-01 02:24:50, TX_AUDIO_SESSION(0,0:Test Audio): fps 999.988661 frame cnt 10000, pkt cnt 10000, inflight count 0: 0
MT: 2023-12-01 02:24:50, TX_AUDIO_MGR(0), pkts burst 20000
MT: 2023-12-01 02:24:50, * *    E N D    S T A T E   * * 

MT: 2023-12-01 02:25:00, * *    M T    D E V   S T A T E   * * 
MT: 2023-12-01 02:25:00, DEV(0): Avr rate, tx: 1093.879109 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038780, rx: 0
MT: 2023-12-01 02:25:00, DEV(1): Avr rate, tx: 1093.885469 Mb/s, rx: 0.000000 Mb/s, pkts, tx: 1038786, rx: 0
MT: 2023-12-01 02:25:00, CNI(0): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:25:00, CNI(1): eth_rx_rate 0.000000 Mb/s, eth_rx_cnt 0
MT: 2023-12-01 02:25:00, PTP(0): time 1701357900676804719, 2023-12-01 02:25:00
MT: 2023-12-01 02:25:00, PTP(1): time 1701357900676810331, 2023-12-01 02:25:00
MT: 2023-12-01 02:25:00, TX_VIDEO_SESSION(0,0:TEST-VIDEO): fps 50.000216, frame 500 pkts 1029988:2057976 inflight 58221:58250
MT: 2023-12-01 02:25:00, TX_VIDEO_SESSION(0,0): throughput 1089.063989 Mb/s: 1089.063989 Mb/s, cpu busy 77.532196
MT: 2023-12-01 02:25:00, TX_VIDEO_SESSION(0,0): dummy pkts 1000, burst 2000
MT: 2023-12-01 02:25:00, TX_AUDIO_SESSION(0,0:Test Audio): fps 1000.004259 frame cnt 10000, pkt cnt 10000, inflight count 0: 0
MT: 2023-12-01 02:25:00, TX_AUDIO_MGR(0), pkts burst 20000
MT: 2023-12-01 02:25:00, * *    E N D    S T A T E   * *
frankdjx commented 9 months ago

Thank you for sharing the log. The video transmission is operating smoothly on both ports.

Is it possible that the lost or out-of-order packets occur on the switch or receiver side? Perhaps you could run an MTL RX application targeting the second stream's destination address on a different node? The MTL framework offers extensive statistical information that could help confirm whether there are any lost or out-of-order packets.

sammirata commented 7 months ago

Thank you for the feedback. It was indeed a network issue. I will close this Issue