blob: 6643f9d49ee6dbf4528022103c41c34161a7beb5 [file] [log] [blame]
Tristan Matthews0a329cc2013-07-17 13:20:14 -04001/* $Id: siprtp_report.c 3553 2011-05-05 06:14:19Z nanang $ */
2/*
3 * Copyright (C) 2008-2011 Teluu Inc. (http://www.teluu.com)
4 * Copyright (C) 2003-2008 Benny Prijono <benny@prijono.org>
5 *
6 * This program is free software; you can redistribute it and/or modify
7 * it under the terms of the GNU General Public License as published by
8 * the Free Software Foundation; either version 2 of the License, or
9 * (at your option) any later version.
10 *
11 * This program is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14 * GNU General Public License for more details.
15 *
16 * You should have received a copy of the GNU General Public License
17 * along with this program; if not, write to the Free Software
18 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
19 */
20
21
22/*
23 * DO NOT COMPILE THIS FILE ON ITS OWN!
24 *
25 * This file is included by siprtp.c to implement the reporting capability
26 * to a separate file, so that user can implement different reporting
27 * functionality (such as writing to XML file).
28 */
29
30
31static void print_call(int call_index)
32{
33 struct call *call = &app.call[call_index];
34 int len;
35 pjsip_inv_session *inv = call->inv;
36 pjsip_dialog *dlg = inv->dlg;
37 struct media_stream *audio = &call->media[0];
38 char userinfo[128];
39 char duration[80], last_update[80];
40 char bps[16], ipbps[16], packets[16], bytes[16], ipbytes[16];
41 unsigned decor;
42 pj_time_val now;
43
44
45 decor = pj_log_get_decor();
46 pj_log_set_decor(PJ_LOG_HAS_NEWLINE);
47
48 pj_gettimeofday(&now);
49
50 if (app.report_filename)
51 puts(app.report_filename);
52
53 /* Print duration */
54 if (inv->state >= PJSIP_INV_STATE_CONFIRMED && call->connect_time.sec) {
55
56 PJ_TIME_VAL_SUB(now, call->connect_time);
57
58 sprintf(duration, " [duration: %02ld:%02ld:%02ld.%03ld]",
59 now.sec / 3600,
60 (now.sec % 3600) / 60,
61 (now.sec % 60),
62 now.msec);
63
64 } else {
65 duration[0] = '\0';
66 }
67
68
69
70 /* Call number and state */
71 PJ_LOG(3, (THIS_FILE,
72 "Call #%d: %s%s",
73 call_index, pjsip_inv_state_name(inv->state),
74 duration));
75
76
77
78 /* Call identification */
79 len = pjsip_hdr_print_on(dlg->remote.info, userinfo, sizeof(userinfo));
80 if (len < 0)
81 pj_ansi_strcpy(userinfo, "<--uri too long-->");
82 else
83 userinfo[len] = '\0';
84
85 PJ_LOG(3, (THIS_FILE, " %s", userinfo));
86
87
88 if (call->inv == NULL || call->inv->state < PJSIP_INV_STATE_CONFIRMED ||
89 call->connect_time.sec == 0)
90 {
91 pj_log_set_decor(decor);
92 return;
93 }
94
95
96 /* Signaling quality */
97 {
98 char pdd[64], connectdelay[64];
99 pj_time_val t;
100
101 if (call->response_time.sec) {
102 t = call->response_time;
103 PJ_TIME_VAL_SUB(t, call->start_time);
104 sprintf(pdd, "got 1st response in %ld ms", PJ_TIME_VAL_MSEC(t));
105 } else {
106 pdd[0] = '\0';
107 }
108
109 if (call->connect_time.sec) {
110 t = call->connect_time;
111 PJ_TIME_VAL_SUB(t, call->start_time);
112 sprintf(connectdelay, ", connected after: %ld ms",
113 PJ_TIME_VAL_MSEC(t));
114 } else {
115 connectdelay[0] = '\0';
116 }
117
118 PJ_LOG(3, (THIS_FILE,
119 " Signaling quality: %s%s", pdd, connectdelay));
120 }
121
122
123 PJ_LOG(3, (THIS_FILE,
124 " Stream #0: audio %.*s@%dHz, %dms/frame, %sB/s (%sB/s +IP hdr)",
125 (int)audio->si.fmt.encoding_name.slen,
126 audio->si.fmt.encoding_name.ptr,
127 audio->clock_rate,
128 audio->samples_per_frame * 1000 / audio->clock_rate,
129 good_number(bps, audio->bytes_per_frame * audio->clock_rate / audio->samples_per_frame),
130 good_number(ipbps, (audio->bytes_per_frame+32) * audio->clock_rate / audio->samples_per_frame)));
131
132 if (audio->rtcp.stat.rx.update_cnt == 0)
133 strcpy(last_update, "never");
134 else {
135 pj_gettimeofday(&now);
136 PJ_TIME_VAL_SUB(now, audio->rtcp.stat.rx.update);
137 sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
138 now.sec / 3600,
139 (now.sec % 3600) / 60,
140 now.sec % 60,
141 now.msec);
142 }
143
144 PJ_LOG(3, (THIS_FILE,
145 " RX stat last update: %s\n"
146 " total %s packets %sB received (%sB +IP hdr)%s\n"
147 " pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
148 " (msec) min avg max last\n"
149 " loss period: %7.3f %7.3f %7.3f %7.3f%s\n"
150 " jitter : %7.3f %7.3f %7.3f %7.3f%s",
151 last_update,
152 good_number(packets, audio->rtcp.stat.rx.pkt),
153 good_number(bytes, audio->rtcp.stat.rx.bytes),
154 good_number(ipbytes, audio->rtcp.stat.rx.bytes + audio->rtcp.stat.rx.pkt * 32),
155 "",
156 audio->rtcp.stat.rx.loss,
157 audio->rtcp.stat.rx.loss * 100.0 / (audio->rtcp.stat.rx.pkt + audio->rtcp.stat.rx.loss),
158 audio->rtcp.stat.rx.dup,
159 audio->rtcp.stat.rx.dup * 100.0 / (audio->rtcp.stat.rx.pkt + audio->rtcp.stat.rx.loss),
160 audio->rtcp.stat.rx.reorder,
161 audio->rtcp.stat.rx.reorder * 100.0 / (audio->rtcp.stat.rx.pkt + audio->rtcp.stat.rx.loss),
162 "",
163 audio->rtcp.stat.rx.loss_period.min / 1000.0,
164 audio->rtcp.stat.rx.loss_period.mean / 1000.0,
165 audio->rtcp.stat.rx.loss_period.max / 1000.0,
166 audio->rtcp.stat.rx.loss_period.last / 1000.0,
167 "",
168 audio->rtcp.stat.rx.jitter.min / 1000.0,
169 audio->rtcp.stat.rx.jitter.mean / 1000.0,
170 audio->rtcp.stat.rx.jitter.max / 1000.0,
171 audio->rtcp.stat.rx.jitter.last / 1000.0,
172 ""
173 ));
174
175
176 if (audio->rtcp.stat.tx.update_cnt == 0)
177 strcpy(last_update, "never");
178 else {
179 pj_gettimeofday(&now);
180 PJ_TIME_VAL_SUB(now, audio->rtcp.stat.tx.update);
181 sprintf(last_update, "%02ldh:%02ldm:%02ld.%03lds ago",
182 now.sec / 3600,
183 (now.sec % 3600) / 60,
184 now.sec % 60,
185 now.msec);
186 }
187
188 PJ_LOG(3, (THIS_FILE,
189 " TX stat last update: %s\n"
190 " total %s packets %sB sent (%sB +IP hdr)%s\n"
191 " pkt loss=%d (%3.1f%%), dup=%d (%3.1f%%), reorder=%d (%3.1f%%)%s\n"
192 " (msec) min avg max last\n"
193 " loss period: %7.3f %7.3f %7.3f %7.3f%s\n"
194 " jitter : %7.3f %7.3f %7.3f %7.3f%s",
195 last_update,
196 good_number(packets, audio->rtcp.stat.tx.pkt),
197 good_number(bytes, audio->rtcp.stat.tx.bytes),
198 good_number(ipbytes, audio->rtcp.stat.tx.bytes + audio->rtcp.stat.tx.pkt * 32),
199 "",
200 audio->rtcp.stat.tx.loss,
201 audio->rtcp.stat.tx.loss * 100.0 / (audio->rtcp.stat.tx.pkt + audio->rtcp.stat.tx.loss),
202 audio->rtcp.stat.tx.dup,
203 audio->rtcp.stat.tx.dup * 100.0 / (audio->rtcp.stat.tx.pkt + audio->rtcp.stat.tx.loss),
204 audio->rtcp.stat.tx.reorder,
205 audio->rtcp.stat.tx.reorder * 100.0 / (audio->rtcp.stat.tx.pkt + audio->rtcp.stat.tx.loss),
206 "",
207 audio->rtcp.stat.tx.loss_period.min / 1000.0,
208 audio->rtcp.stat.tx.loss_period.mean / 1000.0,
209 audio->rtcp.stat.tx.loss_period.max / 1000.0,
210 audio->rtcp.stat.tx.loss_period.last / 1000.0,
211 "",
212 audio->rtcp.stat.tx.jitter.min / 1000.0,
213 audio->rtcp.stat.tx.jitter.mean / 1000.0,
214 audio->rtcp.stat.tx.jitter.max / 1000.0,
215 audio->rtcp.stat.tx.jitter.last / 1000.0,
216 ""
217 ));
218
219
220 PJ_LOG(3, (THIS_FILE,
221 " RTT delay : %7.3f %7.3f %7.3f %7.3f%s\n",
222 audio->rtcp.stat.rtt.min / 1000.0,
223 audio->rtcp.stat.rtt.mean / 1000.0,
224 audio->rtcp.stat.rtt.max / 1000.0,
225 audio->rtcp.stat.rtt.last / 1000.0,
226 ""
227 ));
228
229 pj_log_set_decor(decor);
230}
231