Relay: viewers keep the file size (headers within 4 s, connection: close), retries back off, 412 re-resolves
Two server behaviours left ffmpeg (8.1/9.0) without the file size, after which every seek failed with "size -38" until a reload: - dart:io holds response headers until body bytes exist: a stalled source meant no headers within mpv's 5 s timeout. Relay byte responses are now written on the raw connection, headers with the first bytes or after 4 s, and a swap ends waiting reads with a plain close. - every response closed its socket without saying connection: close, so ffmpeg 8.x reused a dead connection for its next seek (pol's X clips). The server now says it whenever the request asks. A failed pull waits 250 ms doubling to 8 s instead of re-pulling at once (the ~130 ms storm that drew Bilibili's 412/403); 412 counts as an expired URL and re-resolves the page, at most once per 60 s. The app reloads a player once per media when ffmpeg reports the lost size anyway. P37: a read that waits past ffmpeg's retry budget still ends the file early. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
1 parent
5e3834e6ba
commit
e91539d113
17 files changed
+575
-63
No files matched your search
@@ -249,3 +249,23 @@ MimeType _mimeOf(String? contentType) {
|
||||
return MimeType.octetStream;
|
||||
}
|
||||
}
|
||||
|
||||
/// Says `connection: close` on a response to a request that asked for it
|
||||
/// (ffmpeg always does). dart:io closes such a connection after the
|
||||
/// response but, behind relic, without saying so; ffmpeg (8.x) then sends
|
||||
/// its next seek on that dead connection after reading a range to its end
|
||||
/// (an mp4's tail) and the seek fails for good ("size -38").
|
||||
Handler closeWhenAsked(Handler next) => (req) async {
|
||||
final res = await next(req);
|
||||
if (res is! Response) return res;
|
||||
bool asked;
|
||||
try {
|
||||
asked = req.headers.connection?.isClose ?? false;
|
||||
} catch (_) {
|
||||
asked = false;
|
||||
}
|
||||
if (!asked) return res;
|
||||
return res.copyWith(
|
||||
headers: res.headers.transform(
|
||||
(h) => h.connection = const ConnectionHeader.directives([ConnectionHeaderType.close])));
|
||||
};
|
||||
@@ -81,6 +81,7 @@ class PieceBuffer implements TrackBuffer {
|
||||
/// null before a minute of it has arrived.
|
||||
double? get bytesPerSec => _knownSecs >= 60 ? _knownBytes / _knownSecs : null;
|
||||
DateTime? _retryAt;
|
||||
var _failures = 0; // failed pulls in a row (backoff)
|
||||
var _disposed = false;
|
||||
Completer<void> _kick = Completer();
|
||||
final Completer<void> _ready = Completer();
|
||||
@@ -167,6 +168,7 @@ class PieceBuffer implements TrackBuffer {
|
||||
final pl = _pull;
|
||||
if (pl == null || pl.id != id || _disposed) return;
|
||||
_pull = null;
|
||||
_failures = 0;
|
||||
final data = pl.buf.takeBytes();
|
||||
final i = pl.piece;
|
||||
_pieces[i] = data;
|
||||
@@ -182,12 +184,18 @@ class PieceBuffer implements TrackBuffer {
|
||||
_wake();
|
||||
}
|
||||
|
||||
static final _pullFailThrottle = LogThrottle(burst: 3);
|
||||
|
||||
@override
|
||||
void feedFail(int id, String reason) {
|
||||
if (_pull?.id != id) return;
|
||||
_log.warning('relay piece pull $id failed: $reason');
|
||||
_pull = null;
|
||||
_retryAt = DateTime.now().add(const Duration(seconds: 1));
|
||||
final delay = relayRetryDelay(++_failures);
|
||||
_retryAt = DateTime.now().add(delay);
|
||||
final pass = _pullFailThrottle.allow('${identityHashCode(this)}');
|
||||
if (pass != null) {
|
||||
_log.warning('${pass}relay piece pull $id failed ($_failures in a row, next in ${delay.inMilliseconds} ms): $reason');
|
||||
}
|
||||
_wake();
|
||||
}
|
||||
|
||||
|
||||
@@ -9,6 +9,21 @@ import 'relay_stats.dart';
|
||||
|
||||
final _log = createLogger('relay');
|
||||
|
||||
/// A viewer's read ended because its relay went (a swap, server stop):
|
||||
/// not a failure, the response just ends.
|
||||
class RelayEnded implements Exception {
|
||||
const RelayEnded();
|
||||
@override
|
||||
String toString() => 'relay ended';
|
||||
}
|
||||
|
||||
/// The wait before the next pull after [failures] failed ones in a row:
|
||||
/// 250 ms doubling to [RelayConstants.relayRetryMaxMs] (a source whose
|
||||
/// upstream keeps failing must not be asked again and again at once).
|
||||
Duration relayRetryDelay(int failures) => failures <= 0
|
||||
? Duration.zero
|
||||
: Duration(milliseconds: min(RelayConstants.relayRetryMaxMs, 250 * (1 << min(failures - 1, 10))));
|
||||
|
||||
/// One track's buffer on the server: a byte stream ([RelayBuffer]) or
|
||||
/// pieces ([PieceBuffer]).
|
||||
abstract interface class TrackBuffer {
|
||||
@@ -209,6 +224,9 @@ class RelayBuffer implements TrackBuffer {
|
||||
|
||||
var _reqSeq = 0;
|
||||
var _disposed = false;
|
||||
// Failed pulls in a row, and when the next pull may start (backoff).
|
||||
var _failures = 0;
|
||||
DateTime? _retryAt;
|
||||
Completer<void> _kick = Completer();
|
||||
final Completer<void> _ready = Completer();
|
||||
|
||||
@@ -292,7 +310,11 @@ class RelayBuffer implements TrackBuffer {
|
||||
off += take;
|
||||
pl.pos += take;
|
||||
final done = pl.pos == _sliceEnd(s) + 1;
|
||||
if (done) _slices[s] = pl.takeSlice();
|
||||
if (done) {
|
||||
_slices[s] = pl.takeSlice();
|
||||
// A whole slice came: the source works again.
|
||||
_failures = 0;
|
||||
}
|
||||
// Whole, or more of it: whoever waits on it reads on.
|
||||
for (final c in _waiters.remove(s) ?? const <Completer<void>>[]) {
|
||||
c.complete();
|
||||
@@ -309,17 +331,27 @@ class RelayBuffer implements TrackBuffer {
|
||||
final pl = _pull;
|
||||
if (pl != null && pl.id == id) {
|
||||
_pull = null;
|
||||
_failures = 0;
|
||||
_wake();
|
||||
}
|
||||
}
|
||||
|
||||
@override
|
||||
void feedFail(int id, String reason) {
|
||||
if (_pull?.id != id) return;
|
||||
_log.warning('relay pull $id failed: $reason');
|
||||
feedEnd(id);
|
||||
final pl = _pull;
|
||||
if (pl == null || pl.id != id) return;
|
||||
_pull = null;
|
||||
final delay = relayRetryDelay(++_failures);
|
||||
_retryAt = DateTime.now().add(delay);
|
||||
final pass = _pullFailThrottle.allow('${identityHashCode(this)}');
|
||||
if (pass != null) {
|
||||
_log.warning('${pass}relay pull $id failed ($_failures in a row, next in ${delay.inMilliseconds} ms): $reason');
|
||||
}
|
||||
_wake();
|
||||
}
|
||||
|
||||
static final _pullFailThrottle = LogThrottle(burst: 3);
|
||||
|
||||
// ------------------------------------------------------------- scheduling
|
||||
|
||||
bool _shouldStop(_Pull pl, int done) {
|
||||
@@ -412,6 +444,12 @@ class RelayBuffer implements TrackBuffer {
|
||||
await _sleep();
|
||||
continue;
|
||||
}
|
||||
final retry = _retryAt;
|
||||
if (retry != null && DateTime.now().isBefore(retry)) {
|
||||
await _sleep(retry.difference(DateTime.now()));
|
||||
continue;
|
||||
}
|
||||
_retryAt = null;
|
||||
_evict();
|
||||
final s = _nextMissing();
|
||||
if (s == null) {
|
||||
@@ -431,10 +469,10 @@ class RelayBuffer implements TrackBuffer {
|
||||
}
|
||||
}
|
||||
|
||||
Future<void> _sleep() async {
|
||||
Future<void> _sleep([Duration limit = const Duration(seconds: 5)]) async {
|
||||
_kick = Completer();
|
||||
// Also wake periodically: viewers age out of [_active].
|
||||
await _kick.future.timeout(const Duration(seconds: 5), onTimeout: () {});
|
||||
await _kick.future.timeout(limit, onTimeout: () {});
|
||||
}
|
||||
|
||||
/// The bytes of slice [s] from [from] (offset in the slice) as soon as
|
||||
@@ -499,7 +537,7 @@ class RelayBuffer implements TrackBuffer {
|
||||
|
||||
/// Streams [start]..[end] to [viewer]. Cancelling the subscription (the
|
||||
/// viewer went away) ends it; a slice that never arrives ends it with an
|
||||
/// error after [waitLimit].
|
||||
/// error after [waitLimit]; the buffer's [dispose] with [RelayEnded].
|
||||
Stream<Uint8List> read(String viewer, int start, int end, {void Function(int n)? onSent}) async* {
|
||||
final v = _viewers.putIfAbsent(viewer, _Viewer.new);
|
||||
final tail = start >= size - pin;
|
||||
@@ -520,6 +558,7 @@ class RelayBuffer implements TrackBuffer {
|
||||
while (off <= end) {
|
||||
final s = off ~/ slice;
|
||||
final data = await _waitBytes(v, s, off - s * slice, me, () => tail || v.newest == me);
|
||||
if (_disposed) throw const RelayEnded();
|
||||
if (data == null) throw StateError('relay: bytes at $off did not arrive');
|
||||
final n = min(data.length, end - off + 1);
|
||||
if (n <= 0) continue;
|
||||
|
||||
@@ -1,5 +1,6 @@
|
||||
import 'dart:async';
|
||||
import 'dart:convert';
|
||||
import 'dart:io' show HttpDate, IOSink, Socket;
|
||||
import 'dart:math';
|
||||
import 'dart:typed_data';
|
||||
|
||||
@@ -491,7 +492,7 @@ void mountRelayRoutes(
|
||||
});
|
||||
});
|
||||
|
||||
Future<Response> viewer(Request req, {required bool tracked, bool piece = false}) async {
|
||||
Future<Result> viewer(Request req, {required bool tracked, bool piece = false}) async {
|
||||
final stopwatch = Stopwatch()..start();
|
||||
final sid = req.pathParameters.raw[#sid] ?? '';
|
||||
final token = req.pathParameters.raw[#token] ?? '';
|
||||
@@ -506,17 +507,18 @@ void mountRelayRoutes(
|
||||
}
|
||||
// Every outcome goes to the log (throttled per member there); a 503
|
||||
// after a long wait is a source that never came up.
|
||||
void note(int status, {int bytes = 0}) => onLog?.call(
|
||||
token,
|
||||
MediaLog(
|
||||
method: req.method.name,
|
||||
path: '/r/$sid/$key/${track == null ? '' : '$track/'}${pieceIndex == null ? '' : 'p/$pieceIndex'}',
|
||||
rangeHeader: rangeHeader,
|
||||
status: status,
|
||||
bytesWritten: bytes,
|
||||
durationMs: stopwatch.elapsedMilliseconds,
|
||||
));
|
||||
Response logged(Response res, {int bytes = 0}) {
|
||||
onLog?.call(
|
||||
token,
|
||||
MediaLog(
|
||||
method: req.method.name,
|
||||
path: '/r/$sid/$key/${track == null ? '' : '$track/'}${pieceIndex == null ? '' : 'p/$pieceIndex'}',
|
||||
rangeHeader: rangeHeader,
|
||||
status: res.statusCode,
|
||||
bytesWritten: bytes,
|
||||
durationMs: stopwatch.elapsedMilliseconds,
|
||||
));
|
||||
note(res.statusCode, bytes: bytes);
|
||||
return res;
|
||||
}
|
||||
|
||||
@@ -571,24 +573,17 @@ void mountRelayRoutes(
|
||||
return logged(Response(res.status, body: Body.fromString('status ${res.status}'), headers: headers));
|
||||
}
|
||||
final end = res.end ?? size - 1;
|
||||
final Stream<Uint8List> body = buffer
|
||||
.read(token, res.start, end, onSent: (n) => session.addBytes(token, n))
|
||||
.transform(StreamTransformer.fromHandlers(handleError: (e, st, sink) {
|
||||
_readFails(token, '${r.name} track ${track ?? 0} from ${res.start}: $e');
|
||||
sink.addError(e, st);
|
||||
}));
|
||||
MimeType mime;
|
||||
try {
|
||||
mime = MimeType.parse(res.headers['content-type'] ?? '');
|
||||
} catch (_) {
|
||||
mime = MimeType.octetStream;
|
||||
}
|
||||
return logged(
|
||||
Response(res.status,
|
||||
body: Body.fromDataStream(body, mimeType: mime, contentLength: end - res.start + 1),
|
||||
headers: headers),
|
||||
bytes: end - res.start + 1);
|
||||
}
|
||||
final length = end - res.start + 1;
|
||||
note(res.status, bytes: length);
|
||||
final what = '${r.name} track ${track ?? 0} from ${res.start}';
|
||||
return _rangeResponse(res.status, res.headers, length,
|
||||
req.method == Method.head
|
||||
? null
|
||||
: buffer.read(token, res.start, end, onSent: (n) => session.addBytes(token, n)),
|
||||
onBroke: (e) => e is RelayEnded
|
||||
? _log.fine('relay ended under a viewer\'s read: $what')
|
||||
: _readFails(token, '$what: $e'));
|
||||
}
|
||||
|
||||
// `:seg` is the name of a single file, the track of several (the router
|
||||
// wants one parameter name per level).
|
||||
@@ -597,6 +592,74 @@ void mountRelayRoutes(
|
||||
app.get('/r/:sid/:token/:mediaId/:seg/p/:piece', (final req) => viewer(req, tracked: true, piece: true));
|
||||
}
|
||||
|
||||
/// A relayed byte range written on the raw connection: the status line
|
||||
/// and headers go out with the first body bytes, or after [headerWait]
|
||||
/// without them (dart:io would hold them until body bytes come, and an
|
||||
/// ffmpeg whose request gets no headers within its 5 s timeout has lost
|
||||
/// the file's size: every later seek fails with "size -38"). Then the
|
||||
/// body as the buffer has it; a read waiting on missing bytes keeps the
|
||||
/// connection open meanwhile. Always `connection: close` and closed after
|
||||
/// the body: ffmpeg asks for close, and one that is not told so reuses the
|
||||
/// connection the server closed for its next seek and fails it the same
|
||||
/// way. A relay that ends ([RelayEnded]) closes the connection plainly;
|
||||
/// any other failure ([onBroke]) resets it. The client going away cancels
|
||||
/// the read.
|
||||
Hijack _rangeResponse(int status, Map<String, String> headers, int length, Stream<Uint8List>? body,
|
||||
{required void Function(Object e) onBroke, Duration headerWait = const Duration(milliseconds: RelayConstants.relayHeaderWaitMs)}) {
|
||||
return Hijack((ch) async {
|
||||
final out = ch.sink;
|
||||
final head = StringBuffer('HTTP/1.1 $status ${status == 206 ? 'Partial Content' : 'OK'}\r\n')
|
||||
..write('date: ${HttpDate.format(DateTime.now())}\r\n');
|
||||
headers.forEach((k, v) {
|
||||
if (k != 'content-length' && k != 'connection') head.write('$k: $v\r\n');
|
||||
});
|
||||
head.write('content-length: $length\r\nconnection: close\r\n\r\n');
|
||||
final it = body == null ? null : StreamIterator(body);
|
||||
// A read cancelled while it waits ends with what it was waiting for
|
||||
// (its relay ending, say): moot then.
|
||||
Future<void> stop() async => it?.cancel().catchError((_) {});
|
||||
// The client closing (a seek elsewhere, the player gone) ends the read.
|
||||
final input = ch.stream.listen(null,
|
||||
onDone: () => unawaited(stop()), onError: (_) => unawaited(stop()), cancelOnError: true);
|
||||
var reset = false;
|
||||
// The first bytes go out with the headers when they come in time.
|
||||
Future<bool>? first = it?.moveNext();
|
||||
if (first != null) {
|
||||
await Future.any([first.then((_) {}, onError: (_) {}), Future<void>.delayed(headerWait)]);
|
||||
}
|
||||
try {
|
||||
out.add(latin1.encode('$head'));
|
||||
if (out is IOSink) await out.flush();
|
||||
while (it != null) {
|
||||
final bool more;
|
||||
try {
|
||||
final next = first ?? it.moveNext();
|
||||
first = null;
|
||||
more = await next;
|
||||
} catch (e) {
|
||||
onBroke(e);
|
||||
reset = e is! RelayEnded;
|
||||
break;
|
||||
}
|
||||
if (!more) break;
|
||||
out.add(it.current);
|
||||
if (out is IOSink) await out.flush();
|
||||
}
|
||||
} catch (_) {
|
||||
// The client went away mid-write: nothing to say.
|
||||
reset = true;
|
||||
} finally {
|
||||
await input.cancel().catchError((_) {});
|
||||
await stop();
|
||||
if (reset && out is Socket) {
|
||||
out.destroy();
|
||||
} else {
|
||||
await out.close().catchError((_) {});
|
||||
}
|
||||
}
|
||||
});
|
||||
}
|
||||
|
||||
Response _plain(int status) => Response(status, body: Body.fromString('status $status'));
|
||||
|
||||
final _readFailThrottle = LogThrottle(burst: 3);
|
||||
|
||||
@@ -121,6 +121,7 @@ class SyncServer {
|
||||
})),
|
||||
);
|
||||
});
|
||||
_app.use('/', closeWhenAsked);
|
||||
final requests = MediaRequestLog();
|
||||
void logRequest(String token, MediaLog log) => requests(hub.who(token), log);
|
||||
mountSessionMediaRoute(_app, sessions, onLog: logRequest);
|
||||
|
||||
Reference in new issue
Block a user