Tristan Matthews | 0a329cc | 2013-07-17 13:20:14 -0400 | [diff] [blame] | 1 | /* $Id$ */ |
| 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 | |
| 31 | static 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 | |