213 lines
7.0 KiB
Mathematica
213 lines
7.0 KiB
Mathematica
|
function [t, TS] = plotReceiveTrace(filename, flat)
|
||
|
|
fid=fopen(filename);
|
||
|
|
%DEBUG ; ( 8:32:33:375 | 0) VIDEO:1 ; 5260; First packet of frame 1869537938
|
||
|
|
%DEBUG ; ( 8:32:33:375 | 0) VIDEO CODING:1 ; 5260; Decoding timestamp 1869534934
|
||
|
|
%DEBUG ; ( 8:32:33:375 | 0) VIDEO:1 ; 5260; Render frame 1869534934 at 20772610
|
||
|
|
%DEBUG ; ( 8:32:33:375 | 0) VIDEO CODING:-1 ; 5260; Frame decoded: timeStamp=1870511259 decTime=0 maxDecTime=0, at 19965
|
||
|
|
%DEBUG ; ( 7:59:42:500 | 0) VIDEO:-1 ; 2500; Received complete frame timestamp 1870514263 frame type 1 frame size 7862 at time 19965, jitter estimate was 130
|
||
|
|
%DEBUG ; ( 8: 5:51:774 | 0) VIDEO:-1 ; 3968; ExtrapolateLocalTime(1870967878)=24971 ms
|
||
|
|
|
||
|
|
if nargin == 1
|
||
|
|
flat = 0;
|
||
|
|
end
|
||
|
|
line = fgetl(fid);
|
||
|
|
estimatedArrivalTime = [];
|
||
|
|
packetTime = [];
|
||
|
|
firstPacketTime = [];
|
||
|
|
decodeTime = [];
|
||
|
|
decodeCompleteTime = [];
|
||
|
|
renderTime = [];
|
||
|
|
completeTime = [];
|
||
|
|
while ischar(line)%line ~= -1
|
||
|
|
if length(line) == 0
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
% Parse the trace line header
|
||
|
|
[tempres, count] = sscanf(line, 'DEBUG ; (%u:%u:%u:%u |%*lu)%13c:');
|
||
|
|
if count < 5
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
hr=tempres(1);
|
||
|
|
mn=tempres(2);
|
||
|
|
sec=tempres(3);
|
||
|
|
ms=tempres(4);
|
||
|
|
timeInMs=hr*60*60*1000 + mn*60*1000 + sec*1000 + ms;
|
||
|
|
label = tempres(5:end);
|
||
|
|
I = find(label ~= 32);
|
||
|
|
label = label(I(1):end); % remove white spaces
|
||
|
|
if ~strncmp(char(label), 'VIDEO', 5) & ~strncmp(char(label), 'VIDEO CODING', 12)
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
message = line(72:end);
|
||
|
|
|
||
|
|
% Parse message
|
||
|
|
[p, count] = sscanf(message, 'ExtrapolateLocalTime(%lu)=%lu ms');
|
||
|
|
if count == 2
|
||
|
|
estimatedArrivalTime = [estimatedArrivalTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
[p, count] = sscanf(message, 'Packet seqNo %u of frame %lu at %lu');
|
||
|
|
if count == 3
|
||
|
|
packetTime = [packetTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
[p, count] = sscanf(message, 'First packet of frame %lu at %lu');
|
||
|
|
if count == 2
|
||
|
|
firstPacketTime = [firstPacketTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
[p, count] = sscanf(message, 'Decoding timestamp %lu at %lu');
|
||
|
|
if count == 2
|
||
|
|
decodeTime = [decodeTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
[p, count] = sscanf(message, 'Render frame %lu at %lu. Render delay %lu, required delay %lu, max decode time %lu, min total delay %lu');
|
||
|
|
if count == 6
|
||
|
|
renderTime = [renderTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
[p, count] = sscanf(message, 'Frame decoded: timeStamp=%lu decTime=%d maxDecTime=%lu, at %lu');
|
||
|
|
if count == 4
|
||
|
|
decodeCompleteTime = [decodeCompleteTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
[p, count] = sscanf(message, 'Received complete frame timestamp %lu frame type %u frame size %*u at time %lu, jitter estimate was %lu');
|
||
|
|
if count == 4
|
||
|
|
completeTime = [completeTime; p'];
|
||
|
|
line = fgetl(fid);
|
||
|
|
continue;
|
||
|
|
end
|
||
|
|
|
||
|
|
line = fgetl(fid);
|
||
|
|
end
|
||
|
|
fclose(fid);
|
||
|
|
|
||
|
|
t = completeTime(:,3);
|
||
|
|
TS = completeTime(:,1);
|
||
|
|
|
||
|
|
figure;
|
||
|
|
subplot(211);
|
||
|
|
hold on;
|
||
|
|
slope = 0;
|
||
|
|
|
||
|
|
if sum(size(packetTime)) > 0
|
||
|
|
% Plot the time when each packet arrives
|
||
|
|
firstTimeStamp = packetTime(1,2);
|
||
|
|
x = (packetTime(:,2) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
firstTime = packetTime(1,3);
|
||
|
|
plot(x, packetTime(:,3) - firstTime - slope, 'b.');
|
||
|
|
else
|
||
|
|
% Plot the time when the first packet of a frame arrives
|
||
|
|
firstTimeStamp = firstPacketTime(1,1);
|
||
|
|
x = (firstPacketTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
firstTime = firstPacketTime(1,2);
|
||
|
|
plot(x, firstPacketTime(:,2) - firstTime - slope, 'b.');
|
||
|
|
end
|
||
|
|
|
||
|
|
% Plot the frame complete time
|
||
|
|
if prod(size(completeTime)) > 0
|
||
|
|
x = (completeTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
plot(x, completeTime(:,3) - firstTime - slope, 'ks');
|
||
|
|
end
|
||
|
|
|
||
|
|
% Plot the time the decode starts
|
||
|
|
if prod(size(decodeTime)) > 0
|
||
|
|
x = (decodeTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
plot(x, decodeTime(:,2) - firstTime - slope, 'r.');
|
||
|
|
end
|
||
|
|
|
||
|
|
% Plot the decode complete time
|
||
|
|
if prod(size(decodeCompleteTime)) > 0
|
||
|
|
x = (decodeCompleteTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
plot(x, decodeCompleteTime(:,4) - firstTime - slope, 'g.');
|
||
|
|
end
|
||
|
|
|
||
|
|
if prod(size(renderTime)) > 0
|
||
|
|
% Plot the wanted render time in ms
|
||
|
|
x = (renderTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
plot(x, renderTime(:,2) - firstTime - slope, 'c-');
|
||
|
|
|
||
|
|
% Plot the render time if there were no render delay or decoding delay.
|
||
|
|
x = (renderTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
plot(x, renderTime(:,2) - firstTime - slope - renderTime(:, 3) - renderTime(:, 5), 'c--');
|
||
|
|
|
||
|
|
% Plot the render time if there were no render delay.
|
||
|
|
x = (renderTime(:,1) - firstTimeStamp)/90;
|
||
|
|
if flat
|
||
|
|
slope = x;
|
||
|
|
end
|
||
|
|
plot(x, renderTime(:,2) - firstTime - slope - renderTime(:, 3) - renderTime(:, 5), 'b-');
|
||
|
|
end
|
||
|
|
|
||
|
|
%plot(x, 90*x, 'r-');
|
||
|
|
|
||
|
|
xlabel('RTP timestamp (in ms)');
|
||
|
|
ylabel('Time (ms)');
|
||
|
|
legend('Packet arrives', 'Frame complete', 'Decode', 'Decode complete', 'Time to render', 'Only jitter', 'Must decode');
|
||
|
|
|
||
|
|
% subplot(312);
|
||
|
|
% hold on;
|
||
|
|
% completeTs = completeTime(:, 1);
|
||
|
|
% arrivalTs = estimatedArrivalTime(:, 1);
|
||
|
|
% [c, completeIdx, arrivalIdx] = intersect(completeTs, arrivalTs);
|
||
|
|
% %plot(completeTs(completeIdx), completeTime(completeIdx, 3) - estimatedArrivalTime(arrivalIdx, 2));
|
||
|
|
% timeUntilComplete = completeTime(completeIdx, 3) - estimatedArrivalTime(arrivalIdx, 2);
|
||
|
|
% devFromAvgCompleteTime = timeUntilComplete - mean(timeUntilComplete);
|
||
|
|
% plot(completeTs(completeIdx) - completeTs(completeIdx(1)), devFromAvgCompleteTime);
|
||
|
|
% plot(completeTime(:, 1) - completeTime(1, 1), completeTime(:, 4), 'r');
|
||
|
|
% plot(decodeCompleteTime(:, 1) - decodeCompleteTime(1, 1), decodeCompleteTime(:, 2), 'g');
|
||
|
|
% plot(decodeCompleteTime(:, 1) - decodeCompleteTime(1, 1), decodeCompleteTime(:, 3), 'k');
|
||
|
|
% xlabel('RTP timestamp');
|
||
|
|
% ylabel('Time (ms)');
|
||
|
|
% legend('Complete time - Estimated arrival time', 'Desired jitter buffer level', 'Actual decode time', 'Max decode time', 0);
|
||
|
|
|
||
|
|
if prod(size(renderTime)) > 0
|
||
|
|
subplot(212);
|
||
|
|
hold on;
|
||
|
|
firstTime = renderTime(1, 1);
|
||
|
|
targetDelay = max(renderTime(:, 3) + renderTime(:, 4) + renderTime(:, 5), renderTime(:, 6));
|
||
|
|
plot(renderTime(:, 1) - firstTime, renderTime(:, 3), 'r-');
|
||
|
|
plot(renderTime(:, 1) - firstTime, renderTime(:, 4), 'b-');
|
||
|
|
plot(renderTime(:, 1) - firstTime, renderTime(:, 5), 'g-');
|
||
|
|
plot(renderTime(:, 1) - firstTime, renderTime(:, 6), 'k-');
|
||
|
|
plot(renderTime(:, 1) - firstTime, targetDelay, 'c-');
|
||
|
|
xlabel('RTP timestamp');
|
||
|
|
ylabel('Time (ms)');
|
||
|
|
legend('Render delay', 'Jitter delay', 'Decode delay', 'Extra delay', 'Min total delay');
|
||
|
|
end
|