Remove crash debug information from streaming.
This commit is contained in:
John Preston
parent
b5ae492f5e
commit
2694cb76a7
|
|
@ -1602,7 +1602,6 @@ void ListWidget::paintEvent(QPaintEvent *e) {
|
|||
width(),
|
||||
std::min(st::msgMaxWidth / 2, width() / 2));
|
||||
|
||||
auto ms = crl::now();
|
||||
auto clip = e->rect();
|
||||
|
||||
auto from = std::lower_bound(begin(_items), end(_items), clip.top(), [this](auto &elem, int top) {
|
||||
|
|
|
|||
|
|
@ -12,15 +12,8 @@ https://github.com/telegramdesktop/tdesktop/blob/master/LEGAL
|
|||
#include "base/concurrent_timer.h"
|
||||
#include "core/crash_reports.h"
|
||||
|
||||
#include "zlib.h"
|
||||
#include <cfenv>
|
||||
|
||||
extern "C" {
|
||||
extern int __isa_available;
|
||||
}
|
||||
|
||||
#define TO_LOG(x) debugLog(QString x)
|
||||
|
||||
namespace Media {
|
||||
namespace Streaming {
|
||||
namespace {
|
||||
|
|
@ -174,9 +167,6 @@ private:
|
|||
|
||||
[[nodiscard]] TimePoint trackTime() const;
|
||||
|
||||
void debugAssertKnownTime(int step, crl::time time) const;
|
||||
void debugLog(const QString &entry) const;
|
||||
|
||||
const crl::weak_on_queue<VideoTrackObject> _weak;
|
||||
PlaybackOptions _options;
|
||||
|
||||
|
|
@ -204,8 +194,6 @@ private:
|
|||
// For initial frame skipping for an exact seek.
|
||||
FFmpeg::FramePointer _initialSkippingFrame;
|
||||
|
||||
mutable QStringList _debugLog;
|
||||
|
||||
};
|
||||
|
||||
VideoTrackObject::VideoTrackObject(
|
||||
|
|
@ -227,18 +215,6 @@ VideoTrackObject::VideoTrackObject(
|
|||
Expects(_stream.duration > 1);
|
||||
Expects(_ready != nullptr);
|
||||
Expects(_error != nullptr);
|
||||
|
||||
TO_LOG(("created,speed:%1,mode:%2,position:%3,sync:%4,"
|
||||
"loop:%5,wait:%6,duration:%7,initialized:%8,isa:%9"
|
||||
).arg(options.speed
|
||||
).arg(int(options.mode)
|
||||
).arg(options.position
|
||||
).arg(options.syncVideoByAudio ? "true" : "false"
|
||||
).arg(options.loop ? "true" : "false"
|
||||
).arg(options.waitForMarkAsShown ? "true" : "false"
|
||||
).arg(_stream.duration
|
||||
).arg(_shared->initialized() ? "true" : "false"
|
||||
).arg(__isa_available));
|
||||
}
|
||||
|
||||
rpl::producer<> VideoTrackObject::checkNextFrame() const {
|
||||
|
|
@ -260,11 +236,9 @@ void VideoTrackObject::process(std::vector<FFmpeg::Packet> &&packets) {
|
|||
return;
|
||||
}
|
||||
if (packets.front().empty()) {
|
||||
TO_LOG(("process,packets:%1,till_end").arg(packets.size()));
|
||||
Assert(packets.size() == 1);
|
||||
_readTillEnd = true;
|
||||
} else if (!_readTillEnd) {
|
||||
TO_LOG(("process,packets:%1,till:%2").arg(packets.size()).arg(durationByPacket(packets.back())));
|
||||
//for (const auto &packet : packets) {
|
||||
// // Maybe it is enough to count by list.back()?.. hope so.
|
||||
// accumulate_max(
|
||||
|
|
@ -283,7 +257,6 @@ void VideoTrackObject::process(std::vector<FFmpeg::Packet> &&packets) {
|
|||
}
|
||||
for (auto i = begin(packets), e = end(packets); i != e; ++i) {
|
||||
if (_shared->initialized()) {
|
||||
TO_LOG(("queueing_packets,count:%1").arg(e - i));
|
||||
_stream.queue.insert(
|
||||
end(_stream.queue),
|
||||
std::make_move_iterator(i),
|
||||
|
|
@ -291,7 +264,6 @@ void VideoTrackObject::process(std::vector<FFmpeg::Packet> &&packets) {
|
|||
queueReadFrames();
|
||||
break;
|
||||
} else if (!tryReadFirstFrame(std::move(*i))) {
|
||||
TO_LOG(("fail_read_first_frame"));
|
||||
fail(Error::InvalidData);
|
||||
break;
|
||||
}
|
||||
|
|
@ -315,106 +287,21 @@ int VideoTrackObject::durationByPacket(const FFmpeg::Packet &packet) {
|
|||
|
||||
void VideoTrackObject::queueReadFrames(crl::time delay) {
|
||||
if (delay > 0) {
|
||||
TO_LOG(("queue_with_delay:%1").arg(delay));
|
||||
_readFramesTimer.callOnce(delay);
|
||||
} else if (!_queued) {
|
||||
TO_LOG(("queue_without_delay"));
|
||||
_queued = true;
|
||||
_weak.with([](VideoTrackObject &that) {
|
||||
that.TO_LOG(("unqueued_without_delay"));
|
||||
that._queued = false;
|
||||
that.readFrames();
|
||||
});
|
||||
} else {
|
||||
TO_LOG(("queued_already"));
|
||||
}
|
||||
}
|
||||
|
||||
void VideoTrackObject::debugAssertKnownTime(int step, crl::time time) const {
|
||||
if (time < kTimeUnknown / 2) {
|
||||
CrashReports::SetAnnotation("DebugStep", QString::number(step));
|
||||
CrashReports::SetAnnotation("CheckedValue", QString::number(time));
|
||||
CrashReports::SetAnnotation(
|
||||
"_syncTimePoint.trackTime",
|
||||
QString::number(_syncTimePoint.trackTime));
|
||||
CrashReports::SetAnnotation(
|
||||
"_syncTimePoint.worldTime",
|
||||
QString::number(_syncTimePoint.worldTime));
|
||||
CrashReports::SetAnnotation(
|
||||
"_pausedTime",
|
||||
QString::number(_pausedTime));
|
||||
CrashReports::SetAnnotation(
|
||||
"_resumedTime",
|
||||
QString::number(_resumedTime));
|
||||
if (!_shared) {
|
||||
CrashReports::SetAnnotation("_shared", "NULL");
|
||||
} else {
|
||||
CrashReports::SetAnnotation(
|
||||
"_shared->initialized",
|
||||
_shared->initialized() ? "true" : "false");
|
||||
}
|
||||
CrashReports::SetAnnotation("Now", QString::number(crl::now()));
|
||||
|
||||
const auto log = _debugLog.join('\n').toUtf8();
|
||||
const auto compressed = [&] {
|
||||
auto result = QByteArray(log.size() + 1024, char(0));
|
||||
z_stream stream;
|
||||
stream.zalloc = nullptr;
|
||||
stream.zfree = nullptr;
|
||||
stream.opaque = nullptr;
|
||||
stream.avail_in = log.size();
|
||||
stream.next_in = reinterpret_cast<Bytef*>(const_cast<char*>(log.data()));
|
||||
stream.avail_out = result.size();
|
||||
stream.next_out = reinterpret_cast<Bytef*>(result.data());
|
||||
int res = deflateInit2(&stream, Z_BEST_COMPRESSION, Z_DEFLATED, -MAX_WBITS, MAX_MEM_LEVEL, Z_DEFAULT_STRATEGY);
|
||||
if (res != Z_OK) {
|
||||
CrashReports::SetAnnotation("Log", "deflatInit2:" + QString::number(res));
|
||||
return QByteArray();
|
||||
}
|
||||
{
|
||||
const auto guard = gsl::finally([&] { deflateEnd(&stream); });
|
||||
int res = deflate(&stream, Z_FINISH);
|
||||
if (res != Z_OK && res != Z_STREAM_END) {
|
||||
CrashReports::SetAnnotation("Log", "deflate:" + QString::number(res));
|
||||
return QByteArray();
|
||||
} else if (!stream.avail_out) {
|
||||
CrashReports::SetAnnotation("Log", "deflate:no_avail_out");
|
||||
return QByteArray();
|
||||
}
|
||||
}
|
||||
result.resize(result.size() - stream.avail_out);
|
||||
return result;
|
||||
}();
|
||||
if (!compressed.isEmpty()) {
|
||||
CrashReports::SetAnnotation("Log", QString::fromUtf8(compressed.toBase64()));
|
||||
}
|
||||
|
||||
Unexpected("Bad time value.");
|
||||
}
|
||||
}
|
||||
|
||||
void VideoTrackObject::debugLog(const QString &entry) const {
|
||||
constexpr auto kMaxEntries = 2048;
|
||||
if (_debugLog.size() >= kMaxEntries) {
|
||||
return;
|
||||
} else if (_debugLog.size() == kMaxEntries - 1) {
|
||||
_debugLog.push_back("...");
|
||||
return;
|
||||
}
|
||||
_debugLog.push_back("stp.worldTime:"
|
||||
+ QString::number(_syncTimePoint.worldTime)
|
||||
+ ";stp.trackTime:" + QString::number(_syncTimePoint.trackTime)
|
||||
+ ";fe:" + QString::number(std::fetestexcept(FE_ALL_EXCEPT))
|
||||
+ ";" + entry);
|
||||
}
|
||||
|
||||
void VideoTrackObject::readFrames() {
|
||||
if (interrupted()) {
|
||||
return;
|
||||
}
|
||||
auto time = trackTime().trackTime;
|
||||
TO_LOG(("reading_frames,time:%1").arg(time));
|
||||
debugAssertKnownTime(1, time);
|
||||
while (true) {
|
||||
const auto result = readEnoughFrames(time);
|
||||
v::match(result, [&](FrameResult result) {
|
||||
|
|
@ -425,7 +312,6 @@ void VideoTrackObject::readFrames() {
|
|||
const auto duration = computeDuration();
|
||||
Assert(duration != kDurationUnavailable);
|
||||
time -= duration;
|
||||
debugAssertKnownTime(2, time);
|
||||
}
|
||||
}, [&](Shared::PrepareNextCheck delay) {
|
||||
Expects(delay == kTimeUnknown || delay > 0);
|
||||
|
|
@ -443,7 +329,6 @@ void VideoTrackObject::readFrames() {
|
|||
|
||||
auto VideoTrackObject::readEnoughFrames(crl::time trackTime)
|
||||
-> ReadEnoughState {
|
||||
TO_LOG(("reading_enough_frames,time:%1").arg(trackTime));
|
||||
const auto dropStaleFrames = !_options.waitForMarkAsShown;
|
||||
const auto state = _shared->prepareState(trackTime, dropStaleFrames);
|
||||
return v::match(state, [&](Shared::PrepareFrame frame)
|
||||
|
|
@ -451,18 +336,13 @@ auto VideoTrackObject::readEnoughFrames(crl::time trackTime)
|
|||
while (true) {
|
||||
const auto result = readFrame(frame);
|
||||
if (result != FrameResult::Done) {
|
||||
TO_LOG(("read_enough_state,frame_result:%1").arg(int(result)));
|
||||
return result;
|
||||
} else if (!dropStaleFrames
|
||||
|| !VideoTrack::IsStale(frame, trackTime)) {
|
||||
TO_LOG(("read_enough_state,null"));
|
||||
return v::null;
|
||||
}
|
||||
}
|
||||
}, [&](Shared::PrepareNextCheck delay) -> ReadEnoughState {
|
||||
TO_LOG(("read_enough_state,delay:%1").arg(delay));
|
||||
Expects(delay == kTimeUnknown || delay > 0); // Debugging crash.
|
||||
|
||||
return delay;
|
||||
}, [&](v::null_t) -> ReadEnoughState {
|
||||
return FrameResult::Done;
|
||||
|
|
@ -472,7 +352,6 @@ auto VideoTrackObject::readEnoughFrames(crl::time trackTime)
|
|||
bool VideoTrackObject::loopAround() {
|
||||
const auto duration = computeDuration();
|
||||
if (duration == kDurationUnavailable) {
|
||||
TO_LOG(("loop_around,error_duration_unavailable"));
|
||||
LOG(("Streaming Error: "
|
||||
"Couldn't find out the real video stream duration."));
|
||||
return false;
|
||||
|
|
@ -480,7 +359,6 @@ bool VideoTrackObject::loopAround() {
|
|||
avcodec_flush_buffers(_stream.codec.get());
|
||||
_loopingShift += duration;
|
||||
_readTillEnd = false;
|
||||
TO_LOG(("loop_around,duration:%1,shift:%2").arg(duration).arg(_loopingShift));
|
||||
return true;
|
||||
}
|
||||
|
||||
|
|
@ -498,38 +376,31 @@ auto VideoTrackObject::readFrame(not_null<Frame*> frame) -> FrameResult {
|
|||
if (const auto error = ReadNextFrame(_stream)) {
|
||||
if (error.code() == AVERROR_EOF) {
|
||||
if (!_options.loop) {
|
||||
TO_LOG(("read_frame,error_eof"));
|
||||
frame->position = kFinishedPosition;
|
||||
frame->displayed = kTimeUnknown;
|
||||
return FrameResult::Finished;
|
||||
} else if (loopAround()) {
|
||||
TO_LOG(("read_frame,error_looped"));
|
||||
return FrameResult::Looped;
|
||||
} else {
|
||||
TO_LOG(("read_frame,error_bad_data"));
|
||||
fail(Error::InvalidData);
|
||||
return FrameResult::Error;
|
||||
}
|
||||
} else if (error.code() != AVERROR(EAGAIN) || _readTillEnd) {
|
||||
TO_LOG(("read_frame,error_bad_data:%1,till_end:%2").arg(error.code()).arg(_readTillEnd ? "true" : "false"));
|
||||
fail(Error::InvalidData);
|
||||
return FrameResult::Error;
|
||||
}
|
||||
TO_LOG(("read_frame,error_again"));
|
||||
Assert(_stream.queue.empty());
|
||||
_waitingForData.fire({});
|
||||
return FrameResult::Waiting;
|
||||
}
|
||||
const auto position = currentFramePosition();
|
||||
if (position == kTimeUnknown) {
|
||||
TO_LOG(("read_frame,error_current_position:%1").arg(position));
|
||||
fail(Error::InvalidData);
|
||||
return FrameResult::Error;
|
||||
}
|
||||
std::swap(frame->decoded, _stream.frame);
|
||||
frame->position = position;
|
||||
frame->displayed = kTimeUnknown;
|
||||
TO_LOG(("read_frame,current_position:%1").arg(position));
|
||||
return FrameResult::Done;
|
||||
}
|
||||
|
||||
|
|
@ -629,13 +500,11 @@ void VideoTrackObject::presentFrameIfNeeded() {
|
|||
}
|
||||
const auto dropStaleFrames = !_options.waitForMarkAsShown;
|
||||
const auto time = trackTime();
|
||||
TO_LOG(("present_frame_check,world:%1,track:%2").arg(time.worldTime).arg(time.trackTime));
|
||||
const auto presented = _shared->presentFrame(
|
||||
this,
|
||||
time,
|
||||
_options.speed,
|
||||
dropStaleFrames);
|
||||
TO_LOG(("present_frame_check,add:%1,position:%2,next:%3").arg(presented.addedWorldTimeDelay).arg(presented.displayPosition).arg(presented.nextCheckDelay));
|
||||
addTimelineDelay(presented.addedWorldTimeDelay);
|
||||
if (presented.displayPosition == kFinishedPosition) {
|
||||
interrupt();
|
||||
|
|
@ -653,7 +522,6 @@ void VideoTrackObject::presentFrameIfNeeded() {
|
|||
void VideoTrackObject::pause(crl::time time) {
|
||||
Expects(_syncTimePoint.valid());
|
||||
|
||||
TO_LOG(("pause,time:%1,paused:%2").arg(time).arg(_pausedTime));
|
||||
if (interrupted()) {
|
||||
return;
|
||||
} else if (_pausedTime == kTimeUnknown) {
|
||||
|
|
@ -664,8 +532,6 @@ void VideoTrackObject::pause(crl::time time) {
|
|||
void VideoTrackObject::resume(crl::time time) {
|
||||
Expects(_syncTimePoint.trackTime != kTimeUnknown);
|
||||
|
||||
TO_LOG(("resume,time:%1,paused:%2,resumed:%3").arg(time).arg(_pausedTime).arg(_resumedTime));
|
||||
|
||||
if (interrupted()) {
|
||||
return;
|
||||
}
|
||||
|
|
@ -686,15 +552,12 @@ void VideoTrackObject::resume(crl::time time) {
|
|||
}
|
||||
|
||||
void VideoTrackObject::setSpeed(float64 speed) {
|
||||
TO_LOG(("set_speed,speed:%1").arg(speed));
|
||||
if (interrupted()) {
|
||||
return;
|
||||
}
|
||||
if (_syncTimePoint.valid()) {
|
||||
const auto time = trackTime();
|
||||
TO_LOG(("set_speed_changing_time,world:%1,track:%2").arg(time.worldTime).arg(time.trackTime));
|
||||
_syncTimePoint = time;
|
||||
debugAssertKnownTime(3, _syncTimePoint.trackTime);
|
||||
}
|
||||
_options.speed = speed;
|
||||
}
|
||||
|
|
@ -703,23 +566,17 @@ void VideoTrackObject::setWaitForMarkAsShown(bool wait) {
|
|||
if (interrupted()) {
|
||||
return;
|
||||
}
|
||||
TO_LOG(("set_wait_for_mark,wait:%1").arg(wait ? "true" : "false"));
|
||||
_options.waitForMarkAsShown = wait;
|
||||
}
|
||||
|
||||
bool VideoTrackObject::interrupted() const {
|
||||
if (_shared == nullptr) {
|
||||
TO_LOG(("interruped_true"));
|
||||
return true;
|
||||
}
|
||||
return false;
|
||||
return !_shared;
|
||||
}
|
||||
|
||||
void VideoTrackObject::frameShown() {
|
||||
if (interrupted()) {
|
||||
return;
|
||||
}
|
||||
TO_LOG(("frame_shown"));
|
||||
queueReadFrames();
|
||||
}
|
||||
|
||||
|
|
@ -729,7 +586,6 @@ void VideoTrackObject::addTimelineDelay(crl::time delayed) {
|
|||
if (!delayed) {
|
||||
return;
|
||||
}
|
||||
TO_LOG(("adding_delay:%1").arg(delayed));
|
||||
_syncTimePoint.worldTime += delayed;
|
||||
}
|
||||
|
||||
|
|
@ -745,34 +601,26 @@ void VideoTrackObject::removeFrameRequest(const Instance *instance) {
|
|||
|
||||
bool VideoTrackObject::tryReadFirstFrame(FFmpeg::Packet &&packet) {
|
||||
if (ProcessPacket(_stream, std::move(packet)).failed()) {
|
||||
TO_LOG(("try_read_first_frame_process_failed"));
|
||||
return false;
|
||||
}
|
||||
TO_LOG(("try_read_first_frame"));
|
||||
while (true) {
|
||||
if (const auto error = ReadNextFrame(_stream)) {
|
||||
if (error.code() == AVERROR_EOF) {
|
||||
if (!_initialSkippingFrame) {
|
||||
TO_LOG(("try_read_first_frame_eof_bad"));
|
||||
return false;
|
||||
}
|
||||
// Return the last valid frame if we seek too far.
|
||||
_stream.frame = std::move(_initialSkippingFrame);
|
||||
TO_LOG(("try_read_first_frame_eof_to_initial"));
|
||||
return processFirstFrame();
|
||||
} else if (error.code() != AVERROR(EAGAIN) || _readTillEnd) {
|
||||
TO_LOG(("try_read_first_frame_error,end:%1").arg(_readTillEnd ? "true" : "false"));
|
||||
return false;
|
||||
} else {
|
||||
// Waiting for more packets.
|
||||
TO_LOG(("try_read_first_frame_waiting"));
|
||||
return true;
|
||||
}
|
||||
} else if (!fillStateFromFrame()) {
|
||||
TO_LOG(("try_read_first_frame_bad_state"));
|
||||
return false;
|
||||
} else if (_syncTimePoint.trackTime >= _options.position) {
|
||||
TO_LOG(("try_read_first_frame_process"));
|
||||
return processFirstFrame();
|
||||
}
|
||||
|
||||
|
|
@ -797,8 +645,6 @@ bool VideoTrackObject::processFirstFrame() {
|
|||
if (frame.isNull()) {
|
||||
return false;
|
||||
}
|
||||
debugAssertKnownTime(4, _syncTimePoint.trackTime);
|
||||
TO_LOG(("process_first_frame"));
|
||||
_shared->init(std::move(frame), _syncTimePoint.trackTime);
|
||||
callReady();
|
||||
queueReadFrames();
|
||||
|
|
@ -819,12 +665,9 @@ crl::time VideoTrackObject::currentFramePosition() const {
|
|||
bool VideoTrackObject::fillStateFromFrame() {
|
||||
const auto position = currentFramePosition();
|
||||
if (position == kTimeUnknown) {
|
||||
TO_LOG(("fill_state_from_frame_bad"));
|
||||
return false;
|
||||
}
|
||||
TO_LOG(("fill_state_from_frame,position:%1").arg(position));
|
||||
_syncTimePoint.trackTime = position;
|
||||
debugAssertKnownTime(5, _syncTimePoint.trackTime);
|
||||
return true;
|
||||
}
|
||||
|
||||
|
|
@ -847,51 +690,32 @@ void VideoTrackObject::callReady() {
|
|||
data.state.receivedTill = _readTillEnd
|
||||
? _stream.duration
|
||||
: _syncTimePoint.trackTime;
|
||||
TO_LOG(("call_ready,till:%1").arg(data.state.receivedTill));
|
||||
base::take(_ready)({ data });
|
||||
}
|
||||
|
||||
TimePoint VideoTrackObject::trackTime() const {
|
||||
debugAssertKnownTime(7, _syncTimePoint.trackTime);
|
||||
|
||||
auto result = TimePoint();
|
||||
result.worldTime = (_pausedTime != kTimeUnknown)
|
||||
? _pausedTime
|
||||
: crl::now();
|
||||
if (!_syncTimePoint) {
|
||||
result.trackTime = _syncTimePoint.trackTime;
|
||||
TO_LOG(("track_time,paused:%1,result_world:%2").arg(_pausedTime).arg(result.worldTime));
|
||||
return result;
|
||||
}
|
||||
debugAssertKnownTime(8, _syncTimePoint.worldTime);
|
||||
debugAssertKnownTime(9, result.worldTime);
|
||||
|
||||
Assert(_resumedTime != kTimeUnknown);
|
||||
if (_options.syncVideoByAudio && _audioId.externalPlayId()) {
|
||||
const auto mixer = Media::Player::mixer();
|
||||
const auto point = mixer->getExternalSyncTimePoint(_audioId);
|
||||
if (point && point.worldTime > _resumedTime) {
|
||||
TO_LOG(("track_time_sync,world:%1,track:%2,resumed:%3").arg(point.worldTime).arg(point.trackTime).arg(_resumedTime));
|
||||
_syncTimePoint = point;
|
||||
debugAssertKnownTime(6, _syncTimePoint.trackTime);
|
||||
debugAssertKnownTime(10, _syncTimePoint.worldTime);
|
||||
}
|
||||
}
|
||||
const auto adjust = (result.worldTime - _syncTimePoint.worldTime);
|
||||
const auto adjustSpeed = adjust * _options.speed;
|
||||
const auto roundAdjustSpeed = SafeRound(adjustSpeed);
|
||||
const auto timeRoundAdjustSpeed = crl::time(roundAdjustSpeed);
|
||||
const auto trackTime = _syncTimePoint.trackTime + timeRoundAdjustSpeed;
|
||||
TO_LOG(("track_time_adjusted,world:%1,adjust:%2,speed:%3,delta:%4,rounded:%5,casted:%6,final:%7"
|
||||
).arg(result.worldTime
|
||||
).arg(adjust
|
||||
).arg(_options.speed
|
||||
).arg(adjustSpeed
|
||||
).arg(roundAdjustSpeed
|
||||
).arg(timeRoundAdjustSpeed
|
||||
).arg(trackTime));
|
||||
result.trackTime = trackTime;
|
||||
debugAssertKnownTime(11, result.trackTime);
|
||||
result.trackTime = _syncTimePoint.trackTime + timeRoundAdjustSpeed;
|
||||
return result;
|
||||
}
|
||||
|
||||
|
|
|
|||
Loading…
Reference in New Issue