OLD | NEW |
| (Empty) |
1 function [t, TS] = plotReceiveTrace(filename, flat) | |
2 fid=fopen(filename); | |
3 %DEBUG ; ( 8:32:33:375 | 0) VIDEO:1 ; 5260; First pa
cket 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 f
rame 1869534934 at 20772610 | |
6 %DEBUG ; ( 8:32:33:375 | 0) VIDEO CODING:-1 ; 5260; Frame de
coded: 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; Extrapol
ateLocalTime(1870967878)=24971 ms | |
9 | |
10 if nargin == 1 | |
11 flat = 0; | |
12 end | |
13 line = fgetl(fid); | |
14 estimatedArrivalTime = []; | |
15 packetTime = []; | |
16 firstPacketTime = []; | |
17 decodeTime = []; | |
18 decodeCompleteTime = []; | |
19 renderTime = []; | |
20 completeTime = []; | |
21 while 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, req
uired 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 maxDec
Time=%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 ty
pe %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); | |
97 end | |
98 fclose(fid); | |
99 | |
100 t = completeTime(:,3); | |
101 TS = completeTime(:,1); | |
102 | |
103 figure; | |
104 subplot(211); | |
105 hold on; | |
106 slope = 0; | |
107 | |
108 if 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.'); | |
117 else | |
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.'); | |
126 end | |
127 | |
128 % Plot the frame complete time | |
129 if 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'); | |
135 end | |
136 | |
137 % Plot the time the decode starts | |
138 if 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.'); | |
144 end | |
145 | |
146 % Plot the decode complete time | |
147 if 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.'); | |
153 end | |
154 | |
155 if 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-'); | |
176 end | |
177 | |
178 %plot(x, 90*x, 'r-'); | |
179 | |
180 xlabel('RTP timestamp (in ms)'); | |
181 ylabel('Time (ms)'); | |
182 legend('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) - estimatedArrival
Time(arrivalIdx, 2)); | |
190 % timeUntilComplete = completeTime(completeIdx, 3) - estimatedArrivalTime(arriva
lIdx, 2); | |
191 % devFromAvgCompleteTime = timeUntilComplete - mean(timeUntilComplete); | |
192 % plot(completeTs(completeIdx) - completeTs(completeIdx(1)), devFromAvgCompleteT
ime); | |
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 | |
200 if prod(size(renderTime)) > 0 | |
201 subplot(212); | |
202 hold on; | |
203 firstTime = renderTime(1, 1); | |
204 targetDelay = max(renderTime(:, 3) + renderTime(:, 4) + renderTime(:, 5), re
nderTime(:, 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 t
otal delay'); | |
213 end | |
OLD | NEW |