1 /*
2  *  OpenVPN -- An application to securely tunnel IP networks
3  *             over a single TCP/UDP port, with support for SSL/TLS-based
4  *             session authentication and key exchange,
5  *             packet encryption, packet authentication, and
6  *             packet compression.
7  *
8  *  Copyright (C) 2002-2018 OpenVPN Inc <sales@openvpn.net>
9  *
10  *  This program is free software; you can redistribute it and/or modify
11  *  it under the terms of the GNU General Public License version 2
12  *  as published by the Free Software Foundation.
13  *
14  *  This program is distributed in the hope that it will be useful,
15  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
16  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
17  *  GNU General Public License for more details.
18  *
19  *  You should have received a copy of the GNU General Public License along
20  *  with this program; if not, write to the Free Software Foundation, Inc.,
21  *  51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
22  */
23 
24 #ifdef HAVE_CONFIG_H
25 #include "config.h"
26 #elif defined(_MSC_VER)
27 #include "config-msvc.h"
28 #endif
29 
30 #include "syshead.h"
31 
32 #include "perf.h"
33 
34 #ifdef ENABLE_PERFORMANCE_METRICS
35 
36 #include "error.h"
37 #include "otime.h"
38 
39 #include "memdbg.h"
40 
41 static const char *metric_names[] = {
42     "PERF_BIO_READ_PLAINTEXT",
43     "PERF_BIO_WRITE_PLAINTEXT",
44     "PERF_BIO_READ_CIPHERTEXT",
45     "PERF_BIO_WRITE_CIPHERTEXT",
46     "PERF_TLS_MULTI_PROCESS",
47     "PERF_IO_WAIT",
48     "PERF_EVENT_LOOP",
49     "PERF_MULTI_CREATE_INSTANCE",
50     "PERF_MULTI_CLOSE_INSTANCE",
51     "PERF_MULTI_SHOW_STATS",
52     "PERF_MULTI_BCAST",
53     "PERF_MULTI_MCAST",
54     "PERF_SCRIPT",
55     "PERF_READ_IN_LINK",
56     "PERF_PROC_IN_LINK",
57     "PERF_READ_IN_TUN",
58     "PERF_PROC_IN_TUN",
59     "PERF_PROC_OUT_LINK",
60     "PERF_PROC_OUT_TUN",
61     "PERF_PROC_OUT_TUN_MTCP"
62 };
63 
64 struct perf
65 {
66 #define PS_INITIAL            0
67 #define PS_METER_RUNNING      1
68 #define PS_METER_INTERRUPTED  2
69     int state;
70 
71     struct timeval start;
72     double sofar;
73     double sum;
74     double max;
75     double count;
76 };
77 
78 struct perf_set
79 {
80     int stack_len;
81     int stack[STACK_N];
82     struct perf perf[PERF_N];
83 };
84 
85 static struct perf_set perf_set;
86 
87 static void perf_print_state(int lev);
88 
89 static inline int
get_stack_index(int sdelta)90 get_stack_index(int sdelta)
91 {
92     const int sindex = perf_set.stack_len + sdelta;
93     if (sindex >= 0 && sindex < STACK_N)
94     {
95         return sindex;
96     }
97     else
98     {
99         return -1;
100     }
101 }
102 
103 static int
get_perf_index(int sdelta)104 get_perf_index(int sdelta)
105 {
106     const int sindex = get_stack_index(sdelta);
107     if (sindex >= 0)
108     {
109         const int pindex = perf_set.stack[sindex];
110         if (pindex >= 0 && pindex < PERF_N)
111         {
112             return pindex;
113         }
114         else
115         {
116             return -1;
117         }
118     }
119     else
120     {
121         return -1;
122     }
123 }
124 
125 static struct perf *
get_perf(int sdelta)126 get_perf(int sdelta)
127 {
128     const int pindex = get_perf_index(sdelta);
129     if (pindex >= 0)
130     {
131         return &perf_set.perf[pindex];
132     }
133     else
134     {
135         return NULL;
136     }
137 }
138 
139 static void
push_perf_index(int pindex)140 push_perf_index(int pindex)
141 {
142     const int sindex = get_stack_index(0);
143     const int newlen = get_stack_index(1);
144     if (sindex >= 0 && newlen >= 0
145         && pindex >= 0 && pindex < PERF_N)
146     {
147         int i;
148         for (i = 0; i < sindex; ++i)
149         {
150             if (perf_set.stack[i] == pindex)
151             {
152                 perf_print_state(M_INFO);
153                 msg(M_FATAL, "PERF: push_perf_index %s failed",
154                     metric_names [pindex]);
155             }
156         }
157 
158         perf_set.stack[sindex] = pindex;
159         perf_set.stack_len = newlen;
160     }
161     else
162     {
163         msg(M_FATAL, "PERF: push_perf_index: stack push error");
164     }
165 }
166 
167 static void
pop_perf_index(void)168 pop_perf_index(void)
169 {
170     const int newlen = get_stack_index(-1);
171     if (newlen >= 0)
172     {
173         perf_set.stack_len = newlen;
174     }
175     else
176     {
177         msg(M_FATAL, "PERF: pop_perf_index: stack pop error");
178     }
179 }
180 
181 static void
state_must_be(const struct perf * p,const int wanted)182 state_must_be(const struct perf *p, const int wanted)
183 {
184     if (p->state != wanted)
185     {
186         msg(M_FATAL, "PERF: bad state actual=%d wanted=%d",
187             p->state,
188             wanted);
189     }
190 }
191 
192 static void
update_sofar(struct perf * p)193 update_sofar(struct perf *p)
194 {
195     struct timeval current;
196     ASSERT(!gettimeofday(&current, NULL));
197     p->sofar += (double) tv_subtract(&current, &p->start, 600) / 1000000.0;
198     tv_clear(&p->start);
199 }
200 
201 static void
perf_start(struct perf * p)202 perf_start(struct perf *p)
203 {
204     state_must_be(p, PS_INITIAL);
205     ASSERT(!gettimeofday(&p->start, NULL));
206     p->sofar = 0.0;
207     p->state = PS_METER_RUNNING;
208 }
209 
210 static void
perf_stop(struct perf * p)211 perf_stop(struct perf *p)
212 {
213     state_must_be(p, PS_METER_RUNNING);
214     update_sofar(p);
215     p->sum += p->sofar;
216     if (p->sofar > p->max)
217     {
218         p->max = p->sofar;
219     }
220     p->count += 1.0;
221     p->sofar = 0.0;
222     p->state = PS_INITIAL;
223 }
224 
225 static void
perf_interrupt(struct perf * p)226 perf_interrupt(struct perf *p)
227 {
228     state_must_be(p, PS_METER_RUNNING);
229     update_sofar(p);
230     p->state = PS_METER_INTERRUPTED;
231 }
232 
233 static void
perf_resume(struct perf * p)234 perf_resume(struct perf *p)
235 {
236     state_must_be(p, PS_METER_INTERRUPTED);
237     ASSERT(!gettimeofday(&p->start, NULL));
238     p->state = PS_METER_RUNNING;
239 }
240 
241 void
perf_push(int type)242 perf_push(int type)
243 {
244     struct perf *prev;
245     struct perf *cur;
246 
247     ASSERT(SIZE(metric_names) == PERF_N);
248     push_perf_index(type);
249 
250     prev = get_perf(-2);
251     cur = get_perf(-1);
252 
253     ASSERT(cur);
254 
255     if (prev)
256     {
257         perf_interrupt(prev);
258     }
259     perf_start(cur);
260 }
261 
262 void
perf_pop(void)263 perf_pop(void)
264 {
265     struct perf *prev;
266     struct perf *cur;
267 
268     prev = get_perf(-2);
269     cur = get_perf(-1);
270 
271     ASSERT(cur);
272     perf_stop(cur);
273 
274     if (prev)
275     {
276         perf_resume(prev);
277     }
278 
279     pop_perf_index();
280 }
281 
282 void
perf_output_results(void)283 perf_output_results(void)
284 {
285     int i;
286     msg(M_INFO, "LATENCY PROFILE (mean and max are in milliseconds)");
287     for (i = 0; i < PERF_N; ++i)
288     {
289         struct perf *p = &perf_set.perf[i];
290         if (p->count > 0.0)
291         {
292             const double mean = p->sum / p->count;
293             msg(M_INFO, "%s n=%.0f mean=%.3f max=%.3f", metric_names[i], p->count, mean*1000.0, p->max*1000.0);
294         }
295     }
296 }
297 
298 static void
perf_print_state(int lev)299 perf_print_state(int lev)
300 {
301     struct gc_arena gc = gc_new();
302     int i;
303     msg(lev, "PERF STATE");
304     msg(lev, "Stack:");
305     for (i = 0; i < perf_set.stack_len; ++i)
306     {
307         const int j = perf_set.stack[i];
308         const struct perf *p = &perf_set.perf[j];
309         msg(lev, "[%d] %s state=%d start=%s sofar=%f sum=%f max=%f count=%f",
310             i,
311             metric_names[j],
312             p->state,
313             tv_string(&p->start, &gc),
314             p->sofar,
315             p->sum,
316             p->max,
317             p->count);
318     }
319     gc_free(&gc);
320 }
321 #endif /* ifdef ENABLE_PERFORMANCE_METRICS */
322