Trace desktop stream stalls across playback and preview UI
This commit is contained in:
1 parent
b1112981fa
commit
7ce60ca0f2
3 files changed
+100
-23
No files matched your search
@@ -68,7 +68,7 @@ struct StreamPlayerWindow::Playback {
|
||||
uint64_t audioFrameStart = 0, shown = 0, underruns = 0, endFrames = UINT64_MAX;
|
||||
bool started = false, presenting = false, videoReady = false, ended = false, videoEnded = false;
|
||||
bool activeAudio = false, holdAudio = false, resync = false;
|
||||
int64_t audioFedAt = 0, audioFedPts = -1, workerAt = 0;
|
||||
int64_t audioFedAt = 0, audioFedPts = -1, workerAt = 0, guiAt = 0, guiGapMax = 0;
|
||||
~Playback() { stream_playback_audio_destroy(sound); }
|
||||
|
||||
uint64_t played(int64_t now) const {
|
||||
@@ -176,7 +176,10 @@ void StreamPlayerWindow::tick() {
|
||||
int64_t shownPts = -1, readyPts = -1, mediaPosition = -1, deviceLead = 0;
|
||||
{
|
||||
std::lock_guard<std::mutex> guard(p.lock);
|
||||
int64_t clock = p.clock(nowUs());
|
||||
int64_t now = nowUs();
|
||||
if (p.guiAt) p.guiGapMax = std::max(p.guiGapMax, now - p.guiAt);
|
||||
p.guiAt = now;
|
||||
int64_t clock = p.clock(now);
|
||||
while (p.started && !p.videos.empty() && p.videos.front().pts <= clock) {
|
||||
p.videoBytes -= static_cast<size_t>(p.videos.front().image.sizeInBytes());
|
||||
p.lastShownPts = p.videos.front().pts; image = std::move(p.videos.front().image); p.videos.pop_front();
|
||||
@@ -239,6 +242,13 @@ void StreamPlayerWindow::decode() {
|
||||
int64_t deadline = nowUs() + 10000000, report = nowUs(), decoderProgress = -1, lastInputAt = -1;
|
||||
uint64_t reportedGaps = 0;
|
||||
int64_t gapReportAt = 0;
|
||||
struct {
|
||||
uint64_t loops = 0, video = 0, audio = 0, empty = 0;
|
||||
int64_t codec = 0, codecMax = 0, convert = 0, convertMax = 0;
|
||||
int64_t audioFeed = 0, audioFeedMax = 0;
|
||||
int64_t pull = 0, pullMax = 0, sleep = 0, sleepMax = 0, loopMax = 0;
|
||||
} work;
|
||||
int64_t lastLoopAt = report;
|
||||
auto reset = [&](bool request) {
|
||||
avcodec_free_context(&decoder); av_packet_unref(packet); waitKey = true; finishing = eosSent = false;
|
||||
decoderProgress = lastInputAt = -1;
|
||||
@@ -285,7 +295,10 @@ void StreamPlayerWindow::decode() {
|
||||
if (!decoder) return;
|
||||
for (unsigned work = 0; work < 8 && p.running; work++) {
|
||||
{ std::lock_guard<std::mutex> guard(p.lock); if (p.videos.size() >= 2) return; }
|
||||
int64_t codecAt = nowUs();
|
||||
int result = avcodec_receive_frame(decoder, frame);
|
||||
int64_t codecUs = nowUs() - codecAt;
|
||||
work.codec += codecUs; work.codecMax = std::max(work.codecMax, codecUs);
|
||||
if (result == AVERROR(EAGAIN)) return;
|
||||
if (result == AVERROR_EOF) {
|
||||
std::lock_guard<std::mutex> guard(p.lock); p.videoEnded = true;
|
||||
@@ -312,6 +325,7 @@ void StreamPlayerWindow::decode() {
|
||||
(unsigned long long)p.id, (long long)pts, (long long)p.decoderLead, (long long)(nowUs() - p.createdAt),
|
||||
(long long)(p.firstInputAt ? nowUs() - p.firstInputAt : -1), (long long)(p.ready - pts)); }
|
||||
if (pts < p.clock(nowUs()) - 100000) { discarded++; continue; } }
|
||||
int64_t convertAt = nowUs();
|
||||
converter = sws_getCachedContext(converter, frame->width, frame->height, (AVPixelFormat)frame->format,
|
||||
frame->width, frame->height, AV_PIX_FMT_RGB24, SWS_BILINEAR, nullptr, nullptr, nullptr);
|
||||
QImage image = video_frame_image(frame->width, frame->height);
|
||||
@@ -322,6 +336,8 @@ void StreamPlayerWindow::decode() {
|
||||
fail(text("Stream video conversion failed")); p.running = false; return;
|
||||
}
|
||||
if (videoFormat.rotation) image = image.transformed(QTransform().rotate(videoFormat.rotation));
|
||||
int64_t convertUs = nowUs() - convertAt;
|
||||
work.convert += convertUs; work.convertMax = std::max(work.convertMax, convertUs);
|
||||
std::lock_guard<std::mutex> guard(p.lock);
|
||||
p.videoBytes += (size_t)image.sizeInBytes(); p.videos.push_back({std::move(image), pts});
|
||||
}
|
||||
@@ -329,6 +345,36 @@ void StreamPlayerWindow::decode() {
|
||||
if (!frame || !packet) fail(text("Stream decoder allocation failed"));
|
||||
else if (!gui_stream_open(p.id, p.group, p.source, p.epoch)) fail(text("Could not connect to the stream"));
|
||||
else while (p.running) {
|
||||
int64_t loopAt = nowUs();
|
||||
work.loops++; work.loopMax = std::max(work.loopMax, loopAt - lastLoopAt); lastLoopAt = loopAt;
|
||||
if (loopAt - report >= 1000000) {
|
||||
double seconds = (loopAt - report) / 1000000.0;
|
||||
std::lock_guard<std::mutex> guard(p.lock);
|
||||
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG,
|
||||
"desktop viewer work id=%llu interval_us=%lld loops=%llu video=%llu audio=%llu empty=%llu "
|
||||
"codec_us=%lld/%lld convert_us=%lld/%lld audio_feed_us=%lld/%lld pull_us=%lld/%lld sleep_us=%lld/%lld "
|
||||
"loop_max_us=%lld gui_gap_max_us=%lld gui_age_us=%lld decoded=%llu shown=%llu show_fps=%.1f "
|
||||
"clock_us=%lld ready_us=%lld videoQ=%zu hold=%d underruns=%llu timing=total/max",
|
||||
(unsigned long long)p.id, (long long)(loopAt - report), (unsigned long long)work.loops,
|
||||
(unsigned long long)work.video, (unsigned long long)work.audio, (unsigned long long)work.empty,
|
||||
(long long)work.codec, (long long)work.codecMax, (long long)work.convert, (long long)work.convertMax,
|
||||
(long long)work.audioFeed, (long long)work.audioFeedMax,
|
||||
(long long)work.pull, (long long)work.pullMax, (long long)work.sleep, (long long)work.sleepMax,
|
||||
(long long)work.loopMax, (long long)p.guiGapMax, (long long)(p.guiAt ? nowUs() - p.guiAt : -1),
|
||||
(unsigned long long)decoded, (unsigned long long)p.shown, (p.shown - reportedShown) / seconds,
|
||||
(long long)p.position, (long long)p.ready, p.videos.size(), p.holdAudio, (unsigned long long)p.underruns);
|
||||
DEBUG_DEBUG(DEBUG_CATEGORY_STREAM,
|
||||
"desktop viewer id=%llu decoded=%llu discarded=%llu shown=%llu showFps=%.1f videoQ=%zu "
|
||||
"clock=%lld reserve_us=%lld minimum_us=%lld tempo=%d lead_us=%lld underruns=%llu "
|
||||
"ready_us=%lld shown_pts=%lld display_lag_us=%lld decoder_lead_us=%lld hold=%d",
|
||||
(unsigned long long)p.id, (unsigned long long)decoded, (unsigned long long)discarded,
|
||||
(unsigned long long)p.shown, (p.shown - reportedShown) / seconds, p.videos.size(), (long long)p.position,
|
||||
(long long)p.timing.reserve_us, (long long)p.timing.minimum_us, p.timing.tempo_milli,
|
||||
(long long)p.deviceLead, (unsigned long long)p.underruns, (long long)p.ready,
|
||||
(long long)p.lastShownPts, (long long)(p.lastShownPts >= 0 ? p.position - p.lastShownPts : -1),
|
||||
(long long)p.decoderLead, p.holdAudio);
|
||||
work = {}; report = loopAt; reportedShown = p.shown; p.guiGapMax = 0;
|
||||
}
|
||||
bool resync;
|
||||
Playback::AudioGap gap;
|
||||
{ std::lock_guard<std::mutex> guard(p.lock); resync = p.resync; p.workerAt = nowUs(); gap = p.audioGap; }
|
||||
@@ -349,7 +395,10 @@ void StreamPlayerWindow::decode() {
|
||||
bool space;
|
||||
{ std::lock_guard<std::mutex> guard(p.lock); space = p.videos.size() < 2; }
|
||||
if (space && decoder && (packet->size || (finishing && !eosSent))) {
|
||||
int64_t codecAt = nowUs();
|
||||
int sent = avcodec_send_packet(decoder, packet->size ? packet : nullptr);
|
||||
int64_t codecUs = nowUs() - codecAt;
|
||||
work.codec += codecUs; work.codecMax = std::max(work.codecMax, codecUs);
|
||||
if (sent == 0) {
|
||||
if (packet->size) {
|
||||
std::lock_guard<std::mutex> guard(p.lock);
|
||||
@@ -395,10 +444,18 @@ void StreamPlayerWindow::decode() {
|
||||
}
|
||||
}
|
||||
StreamRecord record;
|
||||
if (finishing || !gui_stream_pull(p.id, record, position, wantVideo, audioAhead)) {
|
||||
int64_t pullAt = nowUs();
|
||||
bool received = !finishing && gui_stream_pull(p.id, record, position, wantVideo, audioAhead);
|
||||
int64_t pullUs = nowUs() - pullAt;
|
||||
work.pull += pullUs; work.pullMax = std::max(work.pullMax, pullUs);
|
||||
if (!received) {
|
||||
work.empty++;
|
||||
if (!gui_stream_ready()) { fail(text("Chat service is stopped")); break; }
|
||||
if ((!opened || waitKey) && nowUs() > deadline) { fail(text("Stream connection timed out")); break; }
|
||||
std::this_thread::sleep_for(std::chrono::milliseconds(5)); continue;
|
||||
int64_t sleepAt = nowUs();
|
||||
std::this_thread::sleep_for(std::chrono::milliseconds(5));
|
||||
int64_t sleepUs = nowUs() - sleepAt;
|
||||
work.sleep += sleepUs; work.sleepMax = std::max(work.sleepMax, sleepUs); continue;
|
||||
}
|
||||
if (record.kind == StreamRecordKind::Opened) { opened = true; continue; }
|
||||
if (record.kind == StreamRecordKind::Gap) { reset(false); continue; }
|
||||
@@ -417,15 +474,20 @@ void StreamPlayerWindow::decode() {
|
||||
observe();
|
||||
if (record.pts > INT64_MAX) { fail(text("Invalid stream timestamp")); break; }
|
||||
if (record.kind == StreamRecordKind::Audio) {
|
||||
work.audio++;
|
||||
int64_t audioAt = nowUs();
|
||||
int result = 0;
|
||||
{ std::lock_guard<std::mutex> guard(p.lock);
|
||||
if (p.sound) result = stream_playback_audio_feed(p.sound, (int64_t)record.pts,
|
||||
reinterpret_cast<const uint8_t*>(record.data.constData()), (size_t)record.data.size());
|
||||
if (p.sound && result == 0) { p.audioFedAt = nowUs(); p.audioFedPts = (int64_t)record.pts; } }
|
||||
int64_t audioUs = nowUs() - audioAt;
|
||||
work.audioFeed += audioUs; work.audioFeedMax = std::max(work.audioFeedMax, audioUs);
|
||||
if (result == -2) reset(true);
|
||||
else if (result < 0) { fail(text("Stream audio decoder failed")); break; }
|
||||
continue;
|
||||
}
|
||||
work.video++;
|
||||
if (revision != record.format.revision) {
|
||||
avcodec_free_context(&decoder); waitKey = true; revision = record.format.revision;
|
||||
decoderProgress = lastInputAt = -1;
|
||||
@@ -480,21 +542,6 @@ void StreamPlayerWindow::decode() {
|
||||
std::memcpy(packet->data, data, size);
|
||||
packet->pts = packet->dts = (int64_t)record.pts;
|
||||
if (lastInputAt < 0 || nowUs() - lastInputAt > 1000000) decoderProgress = nowUs();
|
||||
if (nowUs() - report >= 1000000) {
|
||||
int64_t now = nowUs(); double seconds = (now - report) / 1000000.0; report = now;
|
||||
std::lock_guard<std::mutex> guard(p.lock);
|
||||
DEBUG_DEBUG(DEBUG_CATEGORY_STREAM,
|
||||
"desktop viewer id=%llu decoded=%llu discarded=%llu shown=%llu showFps=%.1f videoQ=%zu "
|
||||
"clock=%lld reserve_us=%lld minimum_us=%lld tempo=%d lead_us=%lld underruns=%llu "
|
||||
"ready_us=%lld shown_pts=%lld display_lag_us=%lld decoder_lead_us=%lld hold=%d",
|
||||
(unsigned long long)p.id, (unsigned long long)decoded, (unsigned long long)discarded,
|
||||
(unsigned long long)p.shown, (p.shown - reportedShown) / seconds, p.videos.size(), (long long)p.position,
|
||||
(long long)p.timing.reserve_us, (long long)p.timing.minimum_us, p.timing.tempo_milli,
|
||||
(long long)p.deviceLead, (unsigned long long)p.underruns, (long long)p.ready,
|
||||
(long long)p.lastShownPts, (long long)(p.lastShownPts >= 0 ? p.position - p.lastShownPts : -1),
|
||||
(long long)p.decoderLead, p.holdAudio);
|
||||
reportedShown = p.shown;
|
||||
}
|
||||
}
|
||||
avcodec_free_context(&decoder); av_frame_free(&frame); av_packet_free(&packet);
|
||||
if (converter) sws_freeContext(converter);
|
||||
|
||||
Reference in new issue
Block a user