1function [t, TS] = plotReceiveTrace(filename, flat)
2fid=fopen(filename);
3%DEBUG     ; ( 8:32:33:375 |    0)        VIDEO:1          ;      5260; First packet of frame 1869537938
4%DEBUG     ; ( 8:32:33:375 |    0) VIDEO CODING:1          ;      5260; Decoding timestamp 1869534934
5%DEBUG     ; ( 8:32:33:375 |    0)        VIDEO:1          ;      5260; Render frame 1869534934 at 20772610
6%DEBUG     ; ( 8:32:33:375 |    0) VIDEO CODING:-1         ;      5260; Frame decoded: timeStamp=1870511259 decTime=0 maxDecTime=0, at 19965
7%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
8%DEBUG     ; ( 8: 5:51:774 |    0)        VIDEO:-1         ;      3968; ExtrapolateLocalTime(1870967878)=24971 ms
9
10if nargin == 1
11    flat = 0;
12end
13line = fgetl(fid);
14estimatedArrivalTime = [];
15packetTime = [];
16firstPacketTime = [];
17decodeTime = [];
18decodeCompleteTime = [];
19renderTime = [];
20completeTime = [];
21while ischar(line)%line ~= -1
22    if length(line) == 0
23        line = fgetl(fid);
24        continue;
25    end
26    % Parse the trace line header
27    [tempres, count] = sscanf(line, 'DEBUG     ; (%u:%u:%u:%u |%*lu)%13c:');
28    if count < 5
29        line = fgetl(fid);
30        continue;
31    end
32    hr=tempres(1);
33    mn=tempres(2);
34    sec=tempres(3);
35    ms=tempres(4);
36    timeInMs=hr*60*60*1000 + mn*60*1000 + sec*1000 + ms;
37    label = tempres(5:end);
38    I = find(label ~= 32);
39    label = label(I(1):end); % remove white spaces
40    if ~strncmp(char(label), 'VIDEO', 5) & ~strncmp(char(label), 'VIDEO CODING', 12)
41        line = fgetl(fid);
42        continue;
43    end
44    message = line(72:end);
45
46    % Parse message
47    [p, count] = sscanf(message, 'ExtrapolateLocalTime(%lu)=%lu ms');
48    if count == 2
49        estimatedArrivalTime = [estimatedArrivalTime; p'];
50        line = fgetl(fid);
51        continue;
52    end
53
54    [p, count] = sscanf(message, 'Packet seqNo %u of frame %lu at %lu');
55    if count == 3
56        packetTime = [packetTime; p'];
57        line = fgetl(fid);
58        continue;
59    end
60
61    [p, count] = sscanf(message, 'First packet of frame %lu at %lu');
62    if count == 2
63        firstPacketTime = [firstPacketTime; p'];
64        line = fgetl(fid);
65        continue;
66    end
67
68    [p, count] = sscanf(message, 'Decoding timestamp %lu at %lu');
69    if count == 2
70        decodeTime = [decodeTime; p'];
71        line = fgetl(fid);
72        continue;
73    end
74
75    [p, count] = sscanf(message, 'Render frame %lu at %lu. Render delay %lu, required delay %lu, max decode time %lu, min total delay %lu');
76    if count == 6
77        renderTime = [renderTime; p'];
78        line = fgetl(fid);
79        continue;
80    end
81
82    [p, count] = sscanf(message, 'Frame decoded: timeStamp=%lu decTime=%d maxDecTime=%lu, at %lu');
83    if count == 4
84        decodeCompleteTime = [decodeCompleteTime; p'];
85        line = fgetl(fid);
86        continue;
87    end
88
89    [p, count] = sscanf(message, 'Received complete frame timestamp %lu frame type %u frame size %*u at time %lu, jitter estimate was %lu');
90    if count == 4
91        completeTime = [completeTime; p'];
92        line = fgetl(fid);
93        continue;
94    end
95
96    line = fgetl(fid);
97end
98fclose(fid);
99
100t = completeTime(:,3);
101TS = completeTime(:,1);
102
103figure;
104subplot(211);
105hold on;
106slope = 0;
107
108if sum(size(packetTime)) > 0
109    % Plot the time when each packet arrives
110    firstTimeStamp = packetTime(1,2);
111    x = (packetTime(:,2) - firstTimeStamp)/90;
112    if flat
113        slope = x;
114    end
115    firstTime = packetTime(1,3);
116    plot(x, packetTime(:,3) - firstTime - slope, 'b.');
117else
118    % Plot the time when the first packet of a frame arrives
119    firstTimeStamp = firstPacketTime(1,1);
120    x = (firstPacketTime(:,1) - firstTimeStamp)/90;
121    if flat
122        slope = x;
123    end
124    firstTime = firstPacketTime(1,2);
125    plot(x, firstPacketTime(:,2) - firstTime - slope, 'b.');
126end
127
128% Plot the frame complete time
129if prod(size(completeTime)) > 0
130    x = (completeTime(:,1) - firstTimeStamp)/90;
131    if flat
132        slope = x;
133    end
134    plot(x, completeTime(:,3) - firstTime - slope, 'ks');
135end
136
137% Plot the time the decode starts
138if prod(size(decodeTime)) > 0
139    x = (decodeTime(:,1) - firstTimeStamp)/90;
140    if flat
141        slope = x;
142    end
143    plot(x, decodeTime(:,2) - firstTime - slope, 'r.');
144end
145
146% Plot the decode complete time
147if prod(size(decodeCompleteTime)) > 0
148    x = (decodeCompleteTime(:,1) - firstTimeStamp)/90;
149    if flat
150        slope = x;
151    end
152    plot(x, decodeCompleteTime(:,4) - firstTime - slope, 'g.');
153end
154
155if prod(size(renderTime)) > 0
156    % Plot the wanted render time in ms
157    x = (renderTime(:,1) - firstTimeStamp)/90;
158    if flat
159        slope = x;
160    end
161    plot(x, renderTime(:,2) - firstTime - slope, 'c-');
162
163    % Plot the render time if there were no render delay or decoding delay.
164    x = (renderTime(:,1) - firstTimeStamp)/90;
165    if flat
166        slope = x;
167    end
168    plot(x, renderTime(:,2) - firstTime - slope - renderTime(:, 3) - renderTime(:, 5), 'c--');
169
170    % Plot the render time if there were no render delay.
171    x = (renderTime(:,1) - firstTimeStamp)/90;
172    if flat
173        slope = x;
174    end
175    plot(x, renderTime(:,2) - firstTime - slope - renderTime(:, 3) - renderTime(:, 5), 'b-');
176end
177
178%plot(x, 90*x, 'r-');
179
180xlabel('RTP timestamp (in ms)');
181ylabel('Time (ms)');
182legend('Packet arrives', 'Frame complete', 'Decode', 'Decode complete', 'Time to render', 'Only jitter', 'Must decode');
183
184% subplot(312);
185% hold on;
186% completeTs = completeTime(:, 1);
187% arrivalTs = estimatedArrivalTime(:, 1);
188% [c, completeIdx, arrivalIdx] = intersect(completeTs, arrivalTs);
189% %plot(completeTs(completeIdx), completeTime(completeIdx, 3) - estimatedArrivalTime(arrivalIdx, 2));
190% timeUntilComplete = completeTime(completeIdx, 3) - estimatedArrivalTime(arrivalIdx, 2);
191% devFromAvgCompleteTime = timeUntilComplete - mean(timeUntilComplete);
192% plot(completeTs(completeIdx) - completeTs(completeIdx(1)), devFromAvgCompleteTime);
193% plot(completeTime(:, 1) - completeTime(1, 1), completeTime(:, 4), 'r');
194% plot(decodeCompleteTime(:, 1) - decodeCompleteTime(1, 1), decodeCompleteTime(:, 2), 'g');
195% plot(decodeCompleteTime(:, 1) - decodeCompleteTime(1, 1), decodeCompleteTime(:, 3), 'k');
196% xlabel('RTP timestamp');
197% ylabel('Time (ms)');
198% legend('Complete time - Estimated arrival time', 'Desired jitter buffer level', 'Actual decode time', 'Max decode time', 0);
199
200if prod(size(renderTime)) > 0
201    subplot(212);
202    hold on;
203    firstTime = renderTime(1, 1);
204    targetDelay = max(renderTime(:, 3) + renderTime(:, 4) + renderTime(:, 5), renderTime(:, 6));
205    plot(renderTime(:, 1) - firstTime, renderTime(:, 3), 'r-');
206    plot(renderTime(:, 1) - firstTime, renderTime(:, 4), 'b-');
207    plot(renderTime(:, 1) - firstTime, renderTime(:, 5), 'g-');
208    plot(renderTime(:, 1) - firstTime, renderTime(:, 6), 'k-');
209    plot(renderTime(:, 1) - firstTime, targetDelay, 'c-');
210    xlabel('RTP timestamp');
211    ylabel('Time (ms)');
212    legend('Render delay', 'Jitter delay', 'Decode delay', 'Extra delay', 'Min total delay');
213end