|
| 1 | +# RTMP Ingest CPU/Memory Profiling and Fixes |
| 2 | + |
| 3 | +Investigation date: 2026-05-27 |
| 4 | + |
| 5 | +## Symptom |
| 6 | + |
| 7 | +DevOps reported that a 2 vCPU instance saturated at roughly 20 concurrent RTMP |
| 8 | +publishers (plain RTMP, ~4-8 Mbps 1080p30, live fan-out to 1-5 subscribers each), |
| 9 | +which was lower throughput per core than expected. |
| 10 | + |
| 11 | +## Method |
| 12 | + |
| 13 | +The live system could not be profiled, so a local profiled reproduction was used: |
| 14 | + |
| 15 | +- Extracted Red5 server distribution, pinned to 2 cores (`taskset -c 0,1`) with |
| 16 | + `-XX:ActiveProcessorCount=2` and the default ZGC configuration, to model a 2 vCPU box. |
| 17 | +- Load generated with ffmpeg streaming a pre-encoded 1080p30 / 6 Mbps file using |
| 18 | + `-c copy` (no encode cost), publishers and subscribers pinned to the remaining cores |
| 19 | + so they could not contaminate Red5's two cores. |
| 20 | +- 20 publishers x 3 subscribers = 80 concurrent streams (~480 Mbps relayed). |
| 21 | +- CPU and allocation profiles captured with async-profiler using the `ctimer` engine |
| 22 | + (the host has `perf_event_paranoid=4`, so perf-based events are unavailable). |
| 23 | + |
| 24 | +A self-contained JMH-style micro-benchmark was also used to isolate the received-packet |
| 25 | +dispatch cost before profiling. |
| 26 | + |
| 27 | +## Findings (baseline CPU profile, inclusive) |
| 28 | + |
| 29 | +| Cost | % CPU | Nature | |
| 30 | +|-------------------------------------------------------|-------|--------------------------------| |
| 31 | +| Socket write syscalls (`SocketDispatcher.write0`) | ~29% | Inherent to relaying the bytes | |
| 32 | +| Socket read syscalls | ~14% | Inherent | |
| 33 | +| `String.format` inside `ChunkHeader.read` (trace log) | ~7.2% | Pure waste (fixed) | |
| 34 | +| Fan-out + per-subscriber encode | ~9% | Mostly necessary | |
| 35 | +| Received-packet dispatch (vthread + join) | ~5% | Overhead (fixed) | |
| 36 | +| ZGC | ~2.6% | Minor | |
| 37 | + |
| 38 | +Allocation profile: `byte[]` 61.5% (buffer copies, inherent), `RTMP$ChannelInfo` 12.2%, |
| 39 | +and `Matcher` + `Formatter` ~3.8% (the `ChunkHeader` `String.format` again). |
| 40 | + |
| 41 | +Headline conclusion: per-stream compute is small; the workload is dominated by socket |
| 42 | +I/O syscalls (~45%). The confirmed waste below is real but accounts for roughly 12% of |
| 43 | +compute, not a multiplier. |
| 44 | + |
| 45 | +## Fixes in this change |
| 46 | + |
| 47 | +### 1. `ChunkHeader.read` eager `String.format` in a disabled trace log |
| 48 | + |
| 49 | +`common/.../net/rtmp/message/ChunkHeader.java` |
| 50 | + |
| 51 | +`log.trace(...)` does not print in production (TRACE disabled), but its arguments are |
| 52 | +evaluated eagerly. `String.format("%02x", headerByte)` therefore ran on every chunk, |
| 53 | +parsing its format string via regex and allocating a `Formatter`/`Matcher`, only to |
| 54 | +discard the result. The call is now guarded with `log.isTraceEnabled()`. |
| 55 | + |
| 56 | +Impact: removes ~7% of CPU and ~3.8% of allocations on the decode path. |
| 57 | + |
| 58 | +### 2. Redundant per-packet virtual-thread dispatch |
| 59 | + |
| 60 | +`common/.../net/rtmp/RTMPConnection.java` (`handleMessageReceived`) |
| 61 | + |
| 62 | +Each received packet was wrapped in a `ReceivedMessageTask`, dispatched to a |
| 63 | +per-connection virtual-thread executor via `CompletableFuture.supplyAsync(...)`, and then |
| 64 | +immediately `join()`-ed. Because the single-threaded receiver loop blocks on the join, |
| 65 | +this provided no concurrency benefit while adding a virtual-thread spawn, a |
| 66 | +`CompletableFuture` allocation, and two context switches per packet. |
| 67 | + |
| 68 | +The task now runs inline (`task.get()`) on the per-connection receiver thread. Packet |
| 69 | +ordering is preserved because that loop is single-threaded. `ReceivedMessageTask.get()` |
| 70 | +already records handler exceptions via the connection `exception` attribute, so error |
| 71 | +handling is unchanged. |
| 72 | + |
| 73 | +Impact: removes the ~5% dispatch overhead and the associated context-switch and |
| 74 | +allocation churn (measured 3.6x throughput and 9x less allocation at saturation in an |
| 75 | +isolated micro-benchmark). |
| 76 | + |
| 77 | +## Verification |
| 78 | + |
| 79 | +Re-profiled under the identical 80-stream load after applying both fixes: |
| 80 | + |
| 81 | +| Frame | Before | After | |
| 82 | +|-----------------------------------------|--------|-------| |
| 83 | +| `ChunkHeader.read` / `String.format` | 7.3% | 0.0% | |
| 84 | +| regex | 4.6% | 0.0% | |
| 85 | +| `CompletableFuture` / `supplyAsync` | 12.5% | 0.0% | |
| 86 | +| RTMP decode path (total) | 12.2% | 3.7% | |
| 87 | + |
| 88 | +Both targeted paths were eliminated; nothing untouched disappeared. Overall CPU dropped |
| 89 | +single digits (the remainder is I/O-bound), giving roughly 10% more publisher headroom |
| 90 | +per core. |
| 91 | + |
| 92 | +Both targeted paths were eliminated; nothing untouched disappeared. |
| 93 | + |
| 94 | +## Follow-up: allocation and encode-path fixes |
| 95 | + |
| 96 | +After the two fixes above, profiling showed allocation (memory cost) dominated by `byte[]` |
| 97 | +(61.5%) and `RTMP$ChannelInfo` (12.2%). Three further fixes target the encode/decode path. |
| 98 | + |
| 99 | +### 3. `RTMP.getChannelInfo` allocated per call |
| 100 | + |
| 101 | +`common/.../net/rtmp/codec/RTMP.java` |
| 102 | + |
| 103 | +`getChannelInfo` used `channels.putIfAbsent(channelId, new ChannelInfo())`, which allocated a |
| 104 | +`ChannelInfo` on every call and discarded it whenever the channel already existed. The method |
| 105 | +is called several times per packet, so it was ~12% of all allocations. Replaced with a |
| 106 | +get-first idiom that allocates only when a channel is first seen. (A `computeIfAbsent` lambda |
| 107 | +was deliberately avoided: `ChannelInfo` is a non-static inner class, so its construction |
| 108 | +captures the enclosing instance and the lambda would itself be allocated per call.) |
| 109 | + |
| 110 | +### 4. Per-chunk temporary `byte[]` in the encoder |
| 111 | + |
| 112 | +`common/.../net/rtmp/codec/RTMPProtocolEncoder.java` |
| 113 | + |
| 114 | +The chunk-writing loop allocated `new byte[chunkSize]` and copied through it for every chunk |
| 115 | +of every outbound message. Replaced with a direct buffer-to-buffer copy (slice the source |
| 116 | +`IoBuffer` and `put` it), eliminating the per-chunk array allocation. |
| 117 | + |
| 118 | +### 5. Outbound chunk size raised 1024 -> 4096 |
| 119 | + |
| 120 | +`common/.../stream/consumer/ConnectionConsumer.java` |
| 121 | + |
| 122 | +The outbound RTMP chunk size sent to subscribing clients was 1024 (with a "not sure of the |
| 123 | +best value" TODO). Raised to 4096 (the de-facto standard used by FFmpeg, OBS and nginx-rtmp), |
| 124 | +cutting the per-message chunk count ~4x for typical video frames - fewer chunk headers, fewer |
| 125 | +copies, less encoder work - with no client compatibility impact. |
| 126 | + |
| 127 | +### 6. Per-chunk `Arrays.copyOfRange` in the decoder |
| 128 | + |
| 129 | +`common/.../net/rtmp/codec/RTMPProtocolDecoder.java` |
| 130 | + |
| 131 | +Chunk reassembly allocated `byte[] chunk = Arrays.copyOfRange(in.array(), ...)` for every chunk |
| 132 | +of every inbound packet, purely to transfer bytes from the input buffer into the packet buffer. |
| 133 | +Replaced with a direct buffer-to-buffer transfer (limit the source `IoBuffer` to the chunk and |
| 134 | +`buf.put(in)`), which also advances the input position so the prior explicit `skip` is removed. |
| 135 | +The per-chunk allocation is now only performed when TRACE logging is enabled. |
| 136 | + |
| 137 | +## Combined verification |
| 138 | + |
| 139 | +Re-profiled under the identical 80-stream load with all six fixes applied (allocation profiles |
| 140 | +are 15s windows; CPU samples are rate-normalized for comparison): |
| 141 | + |
| 142 | +| Metric | Baseline | Final | Change | |
| 143 | +|--------------------------------|----------|--------|--------| |
| 144 | +| Allocation (profiler samples) | 14308 | 8236 | -42% | |
| 145 | +| CPU (rate-normalized) | 52.7/s | 46.6/s | -12% | |
| 146 | +| `RTMP$ChannelInfo` allocation | 12.2% | 0% | gone | |
| 147 | +| RTMP decode path CPU | 12.2% | ~4% | gone | |
| 148 | +| `Arrays.copyOfRange` (decode) | present | 0% | gone | |
| 149 | +| ZGC CPU | 2.6% | 1.7% | less GC| |
| 150 | + |
| 151 | +The ~42% allocation reduction is the main memory win and lowers GC frequency; CPU drops ~12%, |
| 152 | +with the remainder being inherent socket I/O. The decoder change is an allocation reduction |
| 153 | +(its `copyOfRange` was only ~1-2% CPU). Remaining `byte[]` allocation is dominated by the |
| 154 | +necessary per-packet message buffers and MINA I/O buffers. RTMPChunkingTest, OriginEdgeChunkTest |
| 155 | +and RTMPExtendedTimestampTest pass, and 80 ffmpeg subscribers consumed the streams cleanly. |
| 156 | + |
| 157 | +## Remaining scaling levers (not addressed) |
| 158 | + |
| 159 | +- Socket read/write syscalls still dominate (~36-45% combined) and are largely inherent to |
| 160 | + per-frame low-latency relaying; coalescing writes would trade latency for fewer syscalls. |
0 commit comments