livekit-cli icon indicating copy to clipboard operation
livekit-cli copied to clipboard

The high packet loss rate in testing

Open zesun96 opened this issue 8 months ago • 0 comments

Describe I use livekit-cli to stress test the livekit-server, when the number of subscribers increases to over 200, it triggers the following warning log in livekit-server, along with an increase in packet loss rate.

livekit-cli: version: 2.4.9 cmd:

./lk load-test --url http://xxx:17880 \
  --api-key xxx \
  --api-secret xxx \
  --duration 10m \
  --room testaudio \
  --audio-publishers 5 \
  --subscribers 500

output:

......
│ Sub 325 │ TR_AMwrvAPqgrSEjd │ audio │ 11278 │ 7.2kbps │ 121 (1.061%) │
│         │ TR_AM6fSH2srJkRP9 │ audio │ 11253 │ 7.5kbps │ 155 (1.359%) │
│         │ TR_AM2kBkgNU7CV88 │ audio │ 11255 │ 6.9kbps │ 151 (1.324%) │
......
Total   │ 1500/1500 │ 10.4mbps (20.9kbps avg) │ 235025 (1.29%)  │      

livekit-server: version: v1.8.3 logs:

2025-05-22T07:48:57.850Z        WARN    livekit.pub.pub.sfu     buffer/buffer.go:661    could not get packet from bucket        {"room": "testaudio", "roomID": "RM_a47FRdbcnPhs", "participant": "enzta_pub_0", "pID": "PA_zUCgahqMK4jn", "remote": false, "trackID": "TR_AMRhg4ttYaoU6v", "relayed": false, "mime": "audio/opus", "layer": 0, "ssrc": 1713691964, "sn": 9539, "headSN": 9609, "count": 1, "rtpStats": {"startTime": "2025-05-22T07:48:13.902Z", "endTime": "0001-01-01T00:00:00.000Z", "elapsed": "43.947152582s", "packetsExpected": 2204, "packetsExpectedRate": 50.15114451129925, "packetsSeenPrimary": 2204, "packetsSeenPrimaryRate": 50.15114451129925, "bytes": 144477, "bitrate": 26300.133958471804, "packetsOutOfOrder": 0, "packetsLost": 0, "packetsLostRate": 0, "packetLostPercentage": 0, "nacks": 0, "nackAcks": 0, "nackMisses": 0, "nackRepeated": 0, "plis": 0, "lastPli": "0001-01-01T00:00:00.000Z", "firstTime": "2025-05-22T07:48:13.902Z", "firstTimeAdjustment": "293.602µs", "highestTime": "2025-05-22T07:48:57.842Z", "headerBytes": 26448, "packetsDuplicate": 0, "packetsDuplicateRate": 0, "bytesDuplicate": 0, "bitrateDuplicate": 0, "headerBytesDuplicate": 0, "packetsPadding": 0, "packetsPaddingRate": 0, "bytesPadding": 0, "bitratePadding": 0, "headerBytesPadding": 0, "frames": 2204, "frameRate": 50.15114451129925, "jitter": 10.159563710103079, "maxJitter": 386.752594166402, "firs": 0, "lastFir": "0001-01-01T00:00:00.000Z", "keyFrames": 0, "lastKeyFrame": "0001-01-01T00:00:00.000Z", "rtt": 12, "maxRtt": 16, "srFirst": {"RtpTimestamp": 1983274118, "RtpTimestampExt": 1983274118, "NtpTimestamp": "2025-05-22T07:48:14.855Z", "At": "2025-05-22T07:48:14.855Z", "AtAdjusted": "2025-05-22T07:48:14.855Z", "Packets": 48, "Octets": 2873}, "srNewest": {"RtpTimestamp": 1985290666, "RtpTimestampExt": 1985290666, "NtpTimestamp": "2025-05-22T07:48:56.865Z", "At": "2025-05-22T07:48:56.870Z", "AtAdjusted": "2025-05-22T07:48:56.866Z", "Packets": 2155, "Octets": 115132}, "packetDrift": {"StartTime": "2025-05-22T07:48:13.902Z", "EndTime": "2025-05-22T07:48:57.842Z", "Duration": 43.940275295, "StartTimestamp": 1983228427, "EndTimestamp": 1985337547, "RtpClockTicks": 2109120, "DriftSamples": -13, "DriftMs": -0.2708333333333333, "ClockRate": 47999.699269977005}, "ntpReportDrift": {"StartTime": "2025-05-22T07:48:14.855Z", "EndTime": "2025-05-22T07:48:56.865Z", "Duration": 42.01035881, "StartTimestamp": 1983274118, "EndTimestamp": 1985290666, "RtpClockTicks": 2016548, "DriftSamples": 51, "DriftMs": 1.0625, "ClockRate": 48001.20868094057}, "receivedReportDrift": {"StartTime": "2025-05-22T07:48:14.855Z", "EndTime": "2025-05-22T07:48:56.870Z", "Duration": 42.014297349, "StartTimestamp": 1983274118, "EndTimestamp": 1985290666, "RtpClockTicks": 2016548, "DriftSamples": -138, "DriftMs": -2.875, "ClockRate": 47996.70891194844}, "rebasedReportDrift": {"StartTime": "2025-05-22T07:48:14.855Z", "EndTime": "2025-05-22T07:48:56.866Z", "Duration": 42.010820398, "StartTimestamp": 1983274118, "EndTimestamp": 1985290666, "RtpClockTicks": 2016548, "DriftSamples": 29, "DriftMs": 0.6041666666666666, "ClockRate": 48000.68127438905}, "extStartSN": 7406, "extHighestSN": 9609, "extStartTS": 1983228427, "extHighestTS": 1985337547, "propagationDelayEstimator": {"lastSenderClockTimeNs": "2025-05-22T07:48:56.865Z", "lastPropagationDelayNs": "4.170993ms", "lastDeltaPropagationDelayNs": "3.863278ms", "estimatedPropagationDelayNs": "694.042µs", "longTermDeltaPropagationDelayNs": "878.978µs", "propagationDelayDeltaHighCount": 0, "propagationDelayDeltaHighStartTime": "0001-01-01T00:00:00.000Z", "propagationDelaySpikeNs": "0s"}}, "snRangeMap": {"numRanges": 1, "range[0]": {"start": 0, "end": 0, "value": 0}}, "error": "received packet too old, headSN 9609, sn 9539"}
2025-05-22T07:48:58.089Z        WARN    livekit.pub.pub.sfu     buffer/buffer.go:649    too much ext packets    {"room": "testaudio", "roomID": "RM_a47FRdbcnPhs", "participant": "enzta_pub_1", "pID": "PA_vVowmWoy2x6c", "remote": false, "trackID": "TR_AMEeaSmRE5BDrJ", "relayed": false, "mime": "audio/opus", "layer": 0, "ssrc": 4155317320, "count": 71}

linux shell output with top:

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                          
16035 root      20   0 3036732   1.7g  17692 S 250.5 11.1   5:42.73 lk                                                                                               
15903 root      20   0 2709104   1.1g  17956 S 167.1  7.0   4:35.50 livekit-server

machine Information

  • cpu: Architecture: x86_64 CPU op-mode(s): 32-bit, 64-bit Byte Order: Little Endian CPU(s): 8 On-line CPU(s) list: 0-7 Thread(s) per core: 1 Core(s) per socket: 2 Socket(s): 4 NUMA node(s): 1 Vendor ID: GenuineIntel CPU family: 6 Model: 63 Model name: Intel(R) Xeon(R) CPU E5-2683 v3 @ 2.00GHz
  • mem: 16G
  • os: CentOS Linux release 7.9.2009 (Core)

zesun96 avatar May 22 '25 09:05 zesun96