1 /* Copyright (c) 2013 The Chromium OS Authors. All rights reserved.
2 * Use of this source code is governed by a BSD-style license that can be
3 * found in the LICENSE file.
4 */
5
6 #include <errno.h>
7 #include <math.h>
8 #include <stdio.h>
9 #include <string.h>
10 #include <syslog.h>
11
12 #ifdef CRAS_DBUS
13 #include "cras_bt_io.h"
14 #endif
15 #include "cras_iodev.h"
16 #include "cras_metrics.h"
17 #include "cras_main_message.h"
18 #include "cras_rstream.h"
19 #include "cras_server_metrics.h"
20 #include "cras_system_state.h"
21
22 #define METRICS_NAME_BUFFER_SIZE 100
23
24 const char kBusyloop[] = "Cras.Busyloop";
25 const char kBusyloopLength[] = "Cras.BusyloopLength";
26 const char kDeviceTypeInput[] = "Cras.DeviceTypeInput";
27 const char kDeviceTypeOutput[] = "Cras.DeviceTypeOutput";
28 const char kDeviceGain[] = "Cras.DeviceGain";
29 const char kDeviceVolume[] = "Cras.DeviceVolume";
30 const char kFetchDelayMilliSeconds[] = "Cras.FetchDelayMilliSeconds";
31 const char kHighestDeviceDelayInput[] = "Cras.HighestDeviceDelayInput";
32 const char kHighestDeviceDelayOutput[] = "Cras.HighestDeviceDelayOutput";
33 const char kHighestInputHardwareLevel[] = "Cras.HighestInputHardwareLevel";
34 const char kHighestOutputHardwareLevel[] = "Cras.HighestOutputHardwareLevel";
35 const char kMissedCallbackFirstTimeInput[] =
36 "Cras.MissedCallbackFirstTimeInput";
37 const char kMissedCallbackFirstTimeOutput[] =
38 "Cras.MissedCallbackFirstTimeOutput";
39 const char kMissedCallbackFrequencyInput[] =
40 "Cras.MissedCallbackFrequencyInput";
41 const char kMissedCallbackFrequencyOutput[] =
42 "Cras.MissedCallbackFrequencyOutput";
43 const char kMissedCallbackFrequencyAfterReschedulingInput[] =
44 "Cras.MissedCallbackFrequencyAfterReschedulingInput";
45 const char kMissedCallbackFrequencyAfterReschedulingOutput[] =
46 "Cras.MissedCallbackFrequencyAfterReschedulingOutput";
47 const char kMissedCallbackSecondTimeInput[] =
48 "Cras.MissedCallbackSecondTimeInput";
49 const char kMissedCallbackSecondTimeOutput[] =
50 "Cras.MissedCallbackSecondTimeOutput";
51 const char kNoCodecsFoundMetric[] = "Cras.NoCodecsFoundAtBoot";
52 const char kStreamCallbackThreshold[] = "Cras.StreamCallbackThreshold";
53 const char kStreamClientTypeInput[] = "Cras.StreamClientTypeInput";
54 const char kStreamClientTypeOutput[] = "Cras.StreamClientTypeOutput";
55 const char kStreamFlags[] = "Cras.StreamFlags";
56 const char kStreamEffects[] = "Cras.StreamEffects";
57 const char kStreamRuntime[] = "Cras.StreamRuntime";
58 const char kStreamSamplingFormat[] = "Cras.StreamSamplingFormat";
59 const char kStreamSamplingRate[] = "Cras.StreamSamplingRate";
60 const char kUnderrunsPerDevice[] = "Cras.UnderrunsPerDevice";
61 const char kHfpScoConnectionError[] = "Cras.HfpScoConnectionError";
62 const char kHfpBatteryIndicatorSupported[] =
63 "Cras.HfpBatteryIndicatorSupported";
64 const char kHfpBatteryReport[] = "Cras.HfpBatteryReport";
65 const char kHfpWidebandSpeechSupported[] = "Cras.HfpWidebandSpeechSupported";
66 const char kHfpWidebandSpeechPacketLoss[] = "Cras.HfpWidebandSpeechPacketLoss";
67 const char kHfpWidebandSpeechSelectedCodec[] =
68 "Cras.kHfpWidebandSpeechSelectedCodec";
69
70 /*
71 * Records missed callback frequency only when the runtime of stream is larger
72 * than the threshold.
73 */
74 const double MISSED_CB_FREQUENCY_SECONDS_MIN = 10.0;
75
76 const time_t CRAS_METRICS_SHORT_PERIOD_THRESHOLD_SECONDS = 600;
77 const time_t CRAS_METRICS_LONG_PERIOD_THRESHOLD_SECONDS = 3600;
78
get_timespec_period_str(struct timespec ts)79 static const char *get_timespec_period_str(struct timespec ts)
80 {
81 if (ts.tv_sec < CRAS_METRICS_SHORT_PERIOD_THRESHOLD_SECONDS)
82 return "ShortPeriod";
83 if (ts.tv_sec < CRAS_METRICS_LONG_PERIOD_THRESHOLD_SECONDS)
84 return "MediumPeriod";
85 return "LongPeriod";
86 }
87
88 /* Type of metrics to log. */
89 enum CRAS_SERVER_METRICS_TYPE {
90 BT_BATTERY_INDICATOR_SUPPORTED,
91 BT_BATTERY_REPORT,
92 BT_SCO_CONNECTION_ERROR,
93 BT_WIDEBAND_PACKET_LOSS,
94 BT_WIDEBAND_SUPPORTED,
95 BT_WIDEBAND_SELECTED_CODEC,
96 BUSYLOOP,
97 BUSYLOOP_LENGTH,
98 DEVICE_GAIN,
99 DEVICE_RUNTIME,
100 DEVICE_VOLUME,
101 HIGHEST_DEVICE_DELAY_INPUT,
102 HIGHEST_DEVICE_DELAY_OUTPUT,
103 HIGHEST_INPUT_HW_LEVEL,
104 HIGHEST_OUTPUT_HW_LEVEL,
105 LONGEST_FETCH_DELAY,
106 MISSED_CB_FIRST_TIME_INPUT,
107 MISSED_CB_FIRST_TIME_OUTPUT,
108 MISSED_CB_FREQUENCY_INPUT,
109 MISSED_CB_FREQUENCY_OUTPUT,
110 MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_INPUT,
111 MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_OUTPUT,
112 MISSED_CB_SECOND_TIME_INPUT,
113 MISSED_CB_SECOND_TIME_OUTPUT,
114 NUM_UNDERRUNS,
115 STREAM_CONFIG,
116 STREAM_RUNTIME
117 };
118
119 enum CRAS_METRICS_DEVICE_TYPE {
120 /* Output devices. */
121 CRAS_METRICS_DEVICE_INTERNAL_SPEAKER,
122 CRAS_METRICS_DEVICE_HEADPHONE,
123 CRAS_METRICS_DEVICE_HDMI,
124 CRAS_METRICS_DEVICE_HAPTIC,
125 CRAS_METRICS_DEVICE_LINEOUT,
126 /* Input devices. */
127 CRAS_METRICS_DEVICE_INTERNAL_MIC,
128 CRAS_METRICS_DEVICE_FRONT_MIC,
129 CRAS_METRICS_DEVICE_REAR_MIC,
130 CRAS_METRICS_DEVICE_KEYBOARD_MIC,
131 CRAS_METRICS_DEVICE_MIC,
132 CRAS_METRICS_DEVICE_HOTWORD,
133 CRAS_METRICS_DEVICE_POST_MIX_LOOPBACK,
134 CRAS_METRICS_DEVICE_POST_DSP_LOOPBACK,
135 /* Devices supporting input and output function. */
136 CRAS_METRICS_DEVICE_USB,
137 CRAS_METRICS_DEVICE_A2DP,
138 CRAS_METRICS_DEVICE_HFP,
139 CRAS_METRICS_DEVICE_HSP,
140 CRAS_METRICS_DEVICE_BLUETOOTH,
141 CRAS_METRICS_DEVICE_BLUETOOTH_NB_MIC,
142 CRAS_METRICS_DEVICE_NO_DEVICE,
143 CRAS_METRICS_DEVICE_NORMAL_FALLBACK,
144 CRAS_METRICS_DEVICE_ABNORMAL_FALLBACK,
145 CRAS_METRICS_DEVICE_SILENT_HOTWORD,
146 CRAS_METRICS_DEVICE_UNKNOWN,
147 CRAS_METRICS_DEVICE_BLUETOOTH_WB_MIC,
148 CRAS_METRICS_DEVICE_ALSA_LOOPBACK,
149 };
150
151 struct cras_server_metrics_stream_config {
152 enum CRAS_STREAM_DIRECTION direction;
153 unsigned cb_threshold;
154 unsigned flags;
155 unsigned effects;
156 int format;
157 unsigned rate;
158 enum CRAS_CLIENT_TYPE client_type;
159 };
160
161 struct cras_server_metrics_device_data {
162 enum CRAS_METRICS_DEVICE_TYPE type;
163 enum CRAS_STREAM_DIRECTION direction;
164 struct timespec runtime;
165 unsigned value;
166 };
167
168 struct cras_server_metrics_stream_data {
169 enum CRAS_CLIENT_TYPE client_type;
170 enum CRAS_STREAM_TYPE stream_type;
171 enum CRAS_STREAM_DIRECTION direction;
172 struct timespec runtime;
173 };
174
175 struct cras_server_metrics_timespec_data {
176 struct timespec runtime;
177 unsigned count;
178 };
179
180 union cras_server_metrics_data {
181 unsigned value;
182 struct cras_server_metrics_stream_config stream_config;
183 struct cras_server_metrics_device_data device_data;
184 struct cras_server_metrics_stream_data stream_data;
185 struct cras_server_metrics_timespec_data timespec_data;
186 };
187
188 /*
189 * Make sure the size of message in the acceptable range. Otherwise, it may
190 * be split into mutiple packets while sending.
191 */
192 static_assert(sizeof(union cras_server_metrics_data) <= 256,
193 "The size is too large.");
194
195 struct cras_server_metrics_message {
196 struct cras_main_message header;
197 enum CRAS_SERVER_METRICS_TYPE metrics_type;
198 union cras_server_metrics_data data;
199 };
200
init_server_metrics_msg(struct cras_server_metrics_message * msg,enum CRAS_SERVER_METRICS_TYPE type,union cras_server_metrics_data data)201 static void init_server_metrics_msg(struct cras_server_metrics_message *msg,
202 enum CRAS_SERVER_METRICS_TYPE type,
203 union cras_server_metrics_data data)
204 {
205 memset(msg, 0, sizeof(*msg));
206 msg->header.type = CRAS_MAIN_METRICS;
207 msg->header.length = sizeof(*msg);
208 msg->metrics_type = type;
209 msg->data = data;
210 }
211
212 static void handle_metrics_message(struct cras_main_message *msg, void *arg);
213
214 /* The wrapper function of cras_main_message_send. */
cras_server_metrics_message_send(struct cras_main_message * msg)215 static int cras_server_metrics_message_send(struct cras_main_message *msg)
216 {
217 /* If current function is in the main thread, call handler directly. */
218 if (cras_system_state_in_main_thread()) {
219 handle_metrics_message(msg, NULL);
220 return 0;
221 }
222 return cras_main_message_send(msg);
223 }
224
225 static inline const char *
metrics_device_type_str(enum CRAS_METRICS_DEVICE_TYPE device_type)226 metrics_device_type_str(enum CRAS_METRICS_DEVICE_TYPE device_type)
227 {
228 switch (device_type) {
229 case CRAS_METRICS_DEVICE_INTERNAL_SPEAKER:
230 return "InternalSpeaker";
231 case CRAS_METRICS_DEVICE_HEADPHONE:
232 return "Headphone";
233 case CRAS_METRICS_DEVICE_HDMI:
234 return "HDMI";
235 case CRAS_METRICS_DEVICE_HAPTIC:
236 return "Haptic";
237 case CRAS_METRICS_DEVICE_LINEOUT:
238 return "Lineout";
239 /* Input devices. */
240 case CRAS_METRICS_DEVICE_INTERNAL_MIC:
241 return "InternalMic";
242 case CRAS_METRICS_DEVICE_FRONT_MIC:
243 return "FrontMic";
244 case CRAS_METRICS_DEVICE_REAR_MIC:
245 return "RearMic";
246 case CRAS_METRICS_DEVICE_KEYBOARD_MIC:
247 return "KeyboardMic";
248 case CRAS_METRICS_DEVICE_MIC:
249 return "Mic";
250 case CRAS_METRICS_DEVICE_HOTWORD:
251 return "Hotword";
252 case CRAS_METRICS_DEVICE_POST_MIX_LOOPBACK:
253 return "PostMixLoopback";
254 case CRAS_METRICS_DEVICE_POST_DSP_LOOPBACK:
255 return "PostDspLoopback";
256 /* Devices supporting input and output function. */
257 case CRAS_METRICS_DEVICE_USB:
258 return "USB";
259 case CRAS_METRICS_DEVICE_A2DP:
260 return "A2DP";
261 case CRAS_METRICS_DEVICE_HFP:
262 return "HFP";
263 case CRAS_METRICS_DEVICE_HSP:
264 return "HSP";
265 case CRAS_METRICS_DEVICE_BLUETOOTH:
266 return "Bluetooth";
267 case CRAS_METRICS_DEVICE_BLUETOOTH_NB_MIC:
268 return "BluetoothNarrowBandMic";
269 case CRAS_METRICS_DEVICE_BLUETOOTH_WB_MIC:
270 return "BluetoothWideBandMic";
271 case CRAS_METRICS_DEVICE_NO_DEVICE:
272 return "NoDevice";
273 case CRAS_METRICS_DEVICE_ALSA_LOOPBACK:
274 return "AlsaLoopback";
275 /* Other fallback devices. */
276 case CRAS_METRICS_DEVICE_NORMAL_FALLBACK:
277 return "NormalFallback";
278 case CRAS_METRICS_DEVICE_ABNORMAL_FALLBACK:
279 return "AbnormalFallback";
280 case CRAS_METRICS_DEVICE_SILENT_HOTWORD:
281 return "SilentHotword";
282 case CRAS_METRICS_DEVICE_UNKNOWN:
283 return "Unknown";
284 default:
285 return "InvalidType";
286 }
287 }
288
289 static inline const char *
metrics_client_type_str(enum CRAS_CLIENT_TYPE client_type)290 metrics_client_type_str(enum CRAS_CLIENT_TYPE client_type)
291 {
292 switch (client_type) {
293 case CRAS_CLIENT_TYPE_UNKNOWN:
294 return "Unknown";
295 case CRAS_CLIENT_TYPE_LEGACY:
296 return "Legacy";
297 case CRAS_CLIENT_TYPE_TEST:
298 return "Test";
299 case CRAS_CLIENT_TYPE_PCM:
300 return "PCM";
301 case CRAS_CLIENT_TYPE_CHROME:
302 return "Chrome";
303 case CRAS_CLIENT_TYPE_ARC:
304 return "ARC";
305 case CRAS_CLIENT_TYPE_CROSVM:
306 return "CrOSVM";
307 case CRAS_CLIENT_TYPE_SERVER_STREAM:
308 return "ServerStream";
309 case CRAS_CLIENT_TYPE_LACROS:
310 return "LaCrOS";
311 case CRAS_CLIENT_TYPE_PLUGIN:
312 return "PluginVM";
313 case CRAS_CLIENT_TYPE_ARCVM:
314 return "ARCVM";
315 default:
316 return "InvalidType";
317 }
318 }
319
320 static inline const char *
metrics_stream_type_str(enum CRAS_STREAM_TYPE stream_type)321 metrics_stream_type_str(enum CRAS_STREAM_TYPE stream_type)
322 {
323 switch (stream_type) {
324 case CRAS_STREAM_TYPE_DEFAULT:
325 return "Default";
326 case CRAS_STREAM_TYPE_MULTIMEDIA:
327 return "Multimedia";
328 case CRAS_STREAM_TYPE_VOICE_COMMUNICATION:
329 return "VoiceCommunication";
330 case CRAS_STREAM_TYPE_SPEECH_RECOGNITION:
331 return "SpeechRecognition";
332 case CRAS_STREAM_TYPE_PRO_AUDIO:
333 return "ProAudio";
334 case CRAS_STREAM_TYPE_ACCESSIBILITY:
335 return "Accessibility";
336 default:
337 return "InvalidType";
338 }
339 }
340
341 static enum CRAS_METRICS_DEVICE_TYPE
get_metrics_device_type(struct cras_iodev * iodev)342 get_metrics_device_type(struct cras_iodev *iodev)
343 {
344 /* Check whether it is a special device. */
345 if (iodev->info.idx < MAX_SPECIAL_DEVICE_IDX) {
346 switch (iodev->info.idx) {
347 case NO_DEVICE:
348 syslog(LOG_ERR, "The invalid device has been used.");
349 return CRAS_METRICS_DEVICE_NO_DEVICE;
350 case SILENT_RECORD_DEVICE:
351 case SILENT_PLAYBACK_DEVICE:
352 if (iodev->active_node->type ==
353 CRAS_NODE_TYPE_FALLBACK_NORMAL)
354 return CRAS_METRICS_DEVICE_NORMAL_FALLBACK;
355 else
356 return CRAS_METRICS_DEVICE_ABNORMAL_FALLBACK;
357 case SILENT_HOTWORD_DEVICE:
358 return CRAS_METRICS_DEVICE_SILENT_HOTWORD;
359 }
360 }
361
362 switch (iodev->active_node->type) {
363 case CRAS_NODE_TYPE_INTERNAL_SPEAKER:
364 return CRAS_METRICS_DEVICE_INTERNAL_SPEAKER;
365 case CRAS_NODE_TYPE_HEADPHONE:
366 return CRAS_METRICS_DEVICE_HEADPHONE;
367 case CRAS_NODE_TYPE_HDMI:
368 return CRAS_METRICS_DEVICE_HDMI;
369 case CRAS_NODE_TYPE_HAPTIC:
370 return CRAS_METRICS_DEVICE_HAPTIC;
371 case CRAS_NODE_TYPE_LINEOUT:
372 return CRAS_METRICS_DEVICE_LINEOUT;
373 case CRAS_NODE_TYPE_MIC:
374 switch (iodev->active_node->position) {
375 case NODE_POSITION_INTERNAL:
376 return CRAS_METRICS_DEVICE_INTERNAL_MIC;
377 case NODE_POSITION_FRONT:
378 return CRAS_METRICS_DEVICE_FRONT_MIC;
379 case NODE_POSITION_REAR:
380 return CRAS_METRICS_DEVICE_REAR_MIC;
381 case NODE_POSITION_KEYBOARD:
382 return CRAS_METRICS_DEVICE_KEYBOARD_MIC;
383 case NODE_POSITION_EXTERNAL:
384 default:
385 return CRAS_METRICS_DEVICE_MIC;
386 }
387 case CRAS_NODE_TYPE_HOTWORD:
388 return CRAS_METRICS_DEVICE_HOTWORD;
389 case CRAS_NODE_TYPE_POST_MIX_PRE_DSP:
390 return CRAS_METRICS_DEVICE_POST_MIX_LOOPBACK;
391 case CRAS_NODE_TYPE_POST_DSP:
392 return CRAS_METRICS_DEVICE_POST_DSP_LOOPBACK;
393 case CRAS_NODE_TYPE_USB:
394 return CRAS_METRICS_DEVICE_USB;
395 case CRAS_NODE_TYPE_BLUETOOTH: {
396 #ifdef CRAS_DBUS
397 enum cras_bt_device_profile profile =
398 cras_bt_io_profile_to_log(iodev);
399 switch (profile) {
400 case CRAS_BT_DEVICE_PROFILE_A2DP_SOURCE:
401 return CRAS_METRICS_DEVICE_A2DP;
402 case CRAS_BT_DEVICE_PROFILE_HFP_AUDIOGATEWAY:
403 /* HFP narrow band has its own node type so we know
404 * this is wideband mic for sure. */
405 return (iodev->direction == CRAS_STREAM_INPUT) ?
406 CRAS_METRICS_DEVICE_BLUETOOTH_WB_MIC :
407 CRAS_METRICS_DEVICE_HFP;
408 case CRAS_BT_DEVICE_PROFILE_HSP_AUDIOGATEWAY:
409 return CRAS_METRICS_DEVICE_HSP;
410 default:
411 break;
412 }
413 #endif
414 return CRAS_METRICS_DEVICE_BLUETOOTH;
415 }
416 case CRAS_NODE_TYPE_BLUETOOTH_NB_MIC:
417 return CRAS_METRICS_DEVICE_BLUETOOTH_NB_MIC;
418 case CRAS_NODE_TYPE_ALSA_LOOPBACK:
419 return CRAS_METRICS_DEVICE_ALSA_LOOPBACK;
420 case CRAS_NODE_TYPE_UNKNOWN:
421 default:
422 return CRAS_METRICS_DEVICE_UNKNOWN;
423 }
424 }
425
426 /*
427 * Logs metrics for each group it belongs to. The UMA does not merge subgroups
428 * automatically so we need to log them separately.
429 *
430 * For example, if we call this function with argument (3, 48000,
431 * Cras.StreamSamplingRate, Input, Chrome), it will send 48000 to below
432 * metrics:
433 * Cras.StreamSamplingRate.Input.Chrome
434 * Cras.StreamSamplingRate.Input
435 * Cras.StreamSamplingRate
436 */
log_sparse_histogram_each_level(int num,int sample,...)437 static void log_sparse_histogram_each_level(int num, int sample, ...)
438 {
439 char metrics_name[METRICS_NAME_BUFFER_SIZE] = {};
440 va_list valist;
441 int i, len = 0;
442
443 va_start(valist, sample);
444
445 for (i = 0; i < num && len < METRICS_NAME_BUFFER_SIZE; i++) {
446 int metric_len =
447 snprintf(metrics_name + len,
448 METRICS_NAME_BUFFER_SIZE - len, "%s%s",
449 i ? "." : "", va_arg(valist, char *));
450 // Exit early on error or running out of bufferspace. Avoids
451 // logging partial or corrupted strings.
452 if (metric_len < 0 ||
453 metric_len > METRICS_NAME_BUFFER_SIZE - len)
454 break;
455 len += metric_len;
456 cras_metrics_log_sparse_histogram(metrics_name, sample);
457 }
458
459 va_end(valist);
460 }
461
log_histogram_each_level(int num,int sample,int min,int max,int nbuckets,...)462 static void log_histogram_each_level(int num, int sample, int min, int max,
463 int nbuckets, ...)
464 {
465 char metrics_name[METRICS_NAME_BUFFER_SIZE] = {};
466 va_list valist;
467 int i, len = 0;
468
469 va_start(valist, nbuckets);
470
471 for (i = 0; i < num && len < METRICS_NAME_BUFFER_SIZE; i++) {
472 int metric_len =
473 snprintf(metrics_name + len,
474 METRICS_NAME_BUFFER_SIZE - len, "%s%s",
475 i ? "." : "", va_arg(valist, char *));
476 // Exit early on error or running out of bufferspace. Avoids
477 // logging partial or corrupted strings.
478 if (metric_len < 0 ||
479 metric_len > METRICS_NAME_BUFFER_SIZE - len)
480 break;
481 len += metric_len;
482 cras_metrics_log_histogram(metrics_name, sample, min, max,
483 nbuckets);
484 }
485
486 va_end(valist);
487 }
488
cras_server_metrics_hfp_sco_connection_error(enum CRAS_METRICS_BT_SCO_ERROR_TYPE type)489 int cras_server_metrics_hfp_sco_connection_error(
490 enum CRAS_METRICS_BT_SCO_ERROR_TYPE type)
491 {
492 struct cras_server_metrics_message msg;
493 union cras_server_metrics_data data;
494 int err;
495
496 data.value = type;
497 init_server_metrics_msg(&msg, BT_SCO_CONNECTION_ERROR, data);
498
499 err = cras_server_metrics_message_send(
500 (struct cras_main_message *)&msg);
501 if (err < 0) {
502 syslog(LOG_ERR, "Failed to send metrics message: "
503 "BT_SCO_CONNECTION_ERROR");
504 return err;
505 }
506 return 0;
507 }
508
cras_server_metrics_hfp_battery_indicator(int battery_indicator_support)509 int cras_server_metrics_hfp_battery_indicator(int battery_indicator_support)
510 {
511 struct cras_server_metrics_message msg;
512 union cras_server_metrics_data data;
513 int err;
514
515 data.value = battery_indicator_support;
516 init_server_metrics_msg(&msg, BT_BATTERY_INDICATOR_SUPPORTED, data);
517
518 err = cras_server_metrics_message_send(
519 (struct cras_main_message *)&msg);
520 if (err < 0) {
521 syslog(LOG_ERR, "Failed to send metrics message: "
522 "BT_BATTERY_INDICATOR_SUPPORTED");
523 return err;
524 }
525 return 0;
526 }
527
cras_server_metrics_hfp_battery_report(int battery_report)528 int cras_server_metrics_hfp_battery_report(int battery_report)
529 {
530 struct cras_server_metrics_message msg;
531 union cras_server_metrics_data data;
532 int err;
533
534 data.value = battery_report;
535 init_server_metrics_msg(&msg, BT_BATTERY_REPORT, data);
536
537 err = cras_server_metrics_message_send(
538 (struct cras_main_message *)&msg);
539 if (err < 0) {
540 syslog(LOG_ERR, "Failed to send metrics message: "
541 "BT_BATTERY_REPORT");
542 return err;
543 }
544 return 0;
545 }
546
cras_server_metrics_hfp_packet_loss(float packet_loss_ratio)547 int cras_server_metrics_hfp_packet_loss(float packet_loss_ratio)
548 {
549 struct cras_server_metrics_message msg;
550 union cras_server_metrics_data data;
551 int err;
552
553 /* Percentage is too coarse for packet loss, so we use number of bad
554 * packets per thousand packets instead. */
555 data.value = (unsigned)(round(packet_loss_ratio * 1000));
556 init_server_metrics_msg(&msg, BT_WIDEBAND_PACKET_LOSS, data);
557
558 err = cras_server_metrics_message_send(
559 (struct cras_main_message *)&msg);
560 if (err < 0) {
561 syslog(LOG_ERR,
562 "Failed to send metrics message: BT_WIDEBAND_PACKET_LOSS");
563 return err;
564 }
565 return 0;
566 }
567
cras_server_metrics_hfp_wideband_support(bool supported)568 int cras_server_metrics_hfp_wideband_support(bool supported)
569 {
570 struct cras_server_metrics_message msg;
571 union cras_server_metrics_data data;
572 int err;
573
574 data.value = supported;
575 init_server_metrics_msg(&msg, BT_WIDEBAND_SUPPORTED, data);
576
577 err = cras_server_metrics_message_send(
578 (struct cras_main_message *)&msg);
579 if (err < 0) {
580 syslog(LOG_ERR,
581 "Failed to send metrics message: BT_WIDEBAND_SUPPORTED");
582 return err;
583 }
584 return 0;
585 }
586
cras_server_metrics_hfp_wideband_selected_codec(int codec)587 int cras_server_metrics_hfp_wideband_selected_codec(int codec)
588 {
589 struct cras_server_metrics_message msg;
590 union cras_server_metrics_data data;
591 int err;
592
593 data.value = codec;
594 init_server_metrics_msg(&msg, BT_WIDEBAND_SELECTED_CODEC, data);
595
596 err = cras_server_metrics_message_send(
597 (struct cras_main_message *)&msg);
598 if (err < 0) {
599 syslog(LOG_ERR, "Failed to send metrics message: "
600 "BT_WIDEBAND_SELECTED_CODEC");
601 return err;
602 }
603 return 0;
604 }
605
cras_server_metrics_device_runtime(struct cras_iodev * iodev)606 int cras_server_metrics_device_runtime(struct cras_iodev *iodev)
607 {
608 struct cras_server_metrics_message msg;
609 union cras_server_metrics_data data;
610 struct timespec now;
611 int err;
612
613 data.device_data.type = get_metrics_device_type(iodev);
614 data.device_data.direction = iodev->direction;
615 clock_gettime(CLOCK_MONOTONIC_RAW, &now);
616 subtract_timespecs(&now, &iodev->open_ts, &data.device_data.runtime);
617
618 init_server_metrics_msg(&msg, DEVICE_RUNTIME, data);
619
620 err = cras_server_metrics_message_send(
621 (struct cras_main_message *)&msg);
622 if (err < 0) {
623 syslog(LOG_ERR,
624 "Failed to send metrics message: DEVICE_RUNTIME");
625 return err;
626 }
627
628 return 0;
629 }
630
cras_server_metrics_device_gain(struct cras_iodev * iodev)631 int cras_server_metrics_device_gain(struct cras_iodev *iodev)
632 {
633 struct cras_server_metrics_message msg;
634 union cras_server_metrics_data data;
635 int err;
636
637 if (iodev->direction == CRAS_STREAM_OUTPUT)
638 return 0;
639
640 data.device_data.type = get_metrics_device_type(iodev);
641 data.device_data.value =
642 (unsigned)100 * iodev->active_node->ui_gain_scaler;
643
644 init_server_metrics_msg(&msg, DEVICE_GAIN, data);
645
646 err = cras_server_metrics_message_send(
647 (struct cras_main_message *)&msg);
648 if (err < 0) {
649 syslog(LOG_ERR, "Failed to send metrics message: DEVICE_GAIN");
650 return err;
651 }
652
653 return 0;
654 }
655
cras_server_metrics_device_volume(struct cras_iodev * iodev)656 int cras_server_metrics_device_volume(struct cras_iodev *iodev)
657 {
658 struct cras_server_metrics_message msg;
659 union cras_server_metrics_data data;
660 int err;
661
662 if (iodev->direction == CRAS_STREAM_INPUT)
663 return 0;
664
665 data.device_data.type = get_metrics_device_type(iodev);
666 data.device_data.value = iodev->active_node->volume;
667
668 init_server_metrics_msg(&msg, DEVICE_VOLUME, data);
669
670 err = cras_server_metrics_message_send(
671 (struct cras_main_message *)&msg);
672 if (err < 0) {
673 syslog(LOG_ERR,
674 "Failed to send metrics message: DEVICE_VOLUME");
675 return err;
676 }
677
678 return 0;
679 }
680
cras_server_metrics_highest_device_delay(unsigned int hw_level,unsigned int largest_cb_level,enum CRAS_STREAM_DIRECTION direction)681 int cras_server_metrics_highest_device_delay(
682 unsigned int hw_level, unsigned int largest_cb_level,
683 enum CRAS_STREAM_DIRECTION direction)
684 {
685 struct cras_server_metrics_message msg;
686 union cras_server_metrics_data data;
687 int err;
688
689 if (largest_cb_level == 0) {
690 syslog(LOG_ERR,
691 "Failed to record device delay: devided by zero");
692 return -1;
693 }
694
695 /*
696 * Because the latency depends on the callback threshold of streams, it
697 * should be calculated as dividing the highest hardware level by largest
698 * callback threshold of streams. For output device, this value should fall
699 * around 2 because CRAS 's scheduling maintain device buffer level around
700 * 1~2 minimum callback level. For input device, this value should be around
701 * 1 because the device buffer level is around 0~1 minimum callback level.
702 * Besides, UMA cannot record float so this ratio is multiplied by 1000.
703 */
704 data.value = hw_level * 1000 / largest_cb_level;
705
706 switch (direction) {
707 case CRAS_STREAM_INPUT:
708 init_server_metrics_msg(&msg, HIGHEST_DEVICE_DELAY_INPUT, data);
709 break;
710 case CRAS_STREAM_OUTPUT:
711 init_server_metrics_msg(&msg, HIGHEST_DEVICE_DELAY_OUTPUT,
712 data);
713 break;
714 default:
715 return 0;
716 }
717
718 err = cras_server_metrics_message_send(
719 (struct cras_main_message *)&msg);
720 if (err < 0) {
721 syslog(LOG_ERR,
722 "Failed to send metrics message: HIGHEST_DEVICE_DELAY");
723 return err;
724 }
725
726 return 0;
727 }
728
cras_server_metrics_highest_hw_level(unsigned hw_level,enum CRAS_STREAM_DIRECTION direction)729 int cras_server_metrics_highest_hw_level(unsigned hw_level,
730 enum CRAS_STREAM_DIRECTION direction)
731 {
732 struct cras_server_metrics_message msg;
733 union cras_server_metrics_data data;
734 int err;
735
736 data.value = hw_level;
737
738 switch (direction) {
739 case CRAS_STREAM_INPUT:
740 init_server_metrics_msg(&msg, HIGHEST_INPUT_HW_LEVEL, data);
741 break;
742 case CRAS_STREAM_OUTPUT:
743 init_server_metrics_msg(&msg, HIGHEST_OUTPUT_HW_LEVEL, data);
744 break;
745 default:
746 return 0;
747 }
748
749 err = cras_server_metrics_message_send(
750 (struct cras_main_message *)&msg);
751 if (err < 0) {
752 syslog(LOG_ERR,
753 "Failed to send metrics message: HIGHEST_HW_LEVEL");
754 return err;
755 }
756
757 return 0;
758 }
759
760 /* Logs longest fetch delay of a stream. */
cras_server_metrics_longest_fetch_delay(const struct cras_rstream * stream)761 int cras_server_metrics_longest_fetch_delay(const struct cras_rstream *stream)
762 {
763 struct cras_server_metrics_message msg;
764 union cras_server_metrics_data data;
765 int err;
766
767 data.stream_data.client_type = stream->client_type;
768 data.stream_data.stream_type = stream->stream_type;
769 data.stream_data.direction = stream->direction;
770
771 /*
772 * There is no delay when the sleep_interval_ts larger than the
773 * longest_fetch_interval.
774 */
775 if (!timespec_after(&stream->longest_fetch_interval,
776 &stream->sleep_interval_ts)) {
777 data.stream_data.runtime.tv_sec = 0;
778 data.stream_data.runtime.tv_nsec = 0;
779 } else {
780 subtract_timespecs(&stream->longest_fetch_interval,
781 &stream->sleep_interval_ts,
782 &data.stream_data.runtime);
783 }
784
785 init_server_metrics_msg(&msg, LONGEST_FETCH_DELAY, data);
786 err = cras_server_metrics_message_send(
787 (struct cras_main_message *)&msg);
788 if (err < 0) {
789 syslog(LOG_ERR,
790 "Failed to send metrics message: LONGEST_FETCH_DELAY");
791 return err;
792 }
793
794 return 0;
795 }
796
cras_server_metrics_num_underruns(unsigned num_underruns)797 int cras_server_metrics_num_underruns(unsigned num_underruns)
798 {
799 struct cras_server_metrics_message msg;
800 union cras_server_metrics_data data;
801 int err;
802
803 data.value = num_underruns;
804 init_server_metrics_msg(&msg, NUM_UNDERRUNS, data);
805 err = cras_server_metrics_message_send(
806 (struct cras_main_message *)&msg);
807 if (err < 0) {
808 syslog(LOG_ERR,
809 "Failed to send metrics message: NUM_UNDERRUNS");
810 return err;
811 }
812
813 return 0;
814 }
815
816 /* Logs the frequency of missed callback. */
817 static int
cras_server_metrics_missed_cb_frequency(const struct cras_rstream * stream)818 cras_server_metrics_missed_cb_frequency(const struct cras_rstream *stream)
819 {
820 struct cras_server_metrics_message msg;
821 union cras_server_metrics_data data;
822 struct timespec now, time_since;
823 double seconds, frequency;
824 int err;
825
826 clock_gettime(CLOCK_MONOTONIC_RAW, &now);
827 subtract_timespecs(&now, &stream->start_ts, &time_since);
828 seconds = (double)time_since.tv_sec + time_since.tv_nsec / 1000000000.0;
829
830 /* Ignore streams which do not have enough runtime. */
831 if (seconds < MISSED_CB_FREQUENCY_SECONDS_MIN)
832 return 0;
833
834 /* Compute how many callbacks are missed in a day. */
835 frequency = (double)stream->num_missed_cb * 86400.0 / seconds;
836 data.value = (unsigned)(round(frequency) + 1e-9);
837
838 if (stream->direction == CRAS_STREAM_INPUT)
839 init_server_metrics_msg(&msg, MISSED_CB_FREQUENCY_INPUT, data);
840 else
841 init_server_metrics_msg(&msg, MISSED_CB_FREQUENCY_OUTPUT, data);
842
843 err = cras_server_metrics_message_send(
844 (struct cras_main_message *)&msg);
845 if (err < 0) {
846 syslog(LOG_ERR,
847 "Failed to send metrics message: MISSED_CB_FREQUENCY");
848 return err;
849 }
850
851 /*
852 * If missed callback happened at least once, also record frequncy after
853 * rescheduling.
854 */
855 if (!stream->num_missed_cb)
856 return 0;
857
858 subtract_timespecs(&now, &stream->first_missed_cb_ts, &time_since);
859 seconds = (double)time_since.tv_sec + time_since.tv_nsec / 1000000000.0;
860
861 /* Compute how many callbacks are missed in a day. */
862 frequency = (double)(stream->num_missed_cb - 1) * 86400.0 / seconds;
863 data.value = (unsigned)(round(frequency) + 1e-9);
864
865 if (stream->direction == CRAS_STREAM_INPUT) {
866 init_server_metrics_msg(
867 &msg, MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_INPUT,
868 data);
869 } else {
870 init_server_metrics_msg(
871 &msg, MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_OUTPUT,
872 data);
873 }
874
875 err = cras_server_metrics_message_send(
876 (struct cras_main_message *)&msg);
877 if (err < 0) {
878 syslog(LOG_ERR,
879 "Failed to send metrics message: MISSED_CB_FREQUENCY");
880 return err;
881 }
882
883 return 0;
884 }
885
886 /*
887 * Logs the duration between stream starting time and the first missed
888 * callback.
889 */
890 static int
cras_server_metrics_missed_cb_first_time(const struct cras_rstream * stream)891 cras_server_metrics_missed_cb_first_time(const struct cras_rstream *stream)
892 {
893 struct cras_server_metrics_message msg;
894 union cras_server_metrics_data data;
895 struct timespec time_since;
896 int err;
897
898 subtract_timespecs(&stream->first_missed_cb_ts, &stream->start_ts,
899 &time_since);
900 data.value = (unsigned)time_since.tv_sec;
901
902 if (stream->direction == CRAS_STREAM_INPUT) {
903 init_server_metrics_msg(&msg, MISSED_CB_FIRST_TIME_INPUT, data);
904 } else {
905 init_server_metrics_msg(&msg, MISSED_CB_FIRST_TIME_OUTPUT,
906 data);
907 }
908 err = cras_server_metrics_message_send(
909 (struct cras_main_message *)&msg);
910 if (err < 0) {
911 syslog(LOG_ERR, "Failed to send metrics message: "
912 "MISSED_CB_FIRST_TIME");
913 return err;
914 }
915
916 return 0;
917 }
918
919 /* Logs the duration between the first and the second missed callback events. */
920 static int
cras_server_metrics_missed_cb_second_time(const struct cras_rstream * stream)921 cras_server_metrics_missed_cb_second_time(const struct cras_rstream *stream)
922 {
923 struct cras_server_metrics_message msg;
924 union cras_server_metrics_data data;
925 struct timespec now, time_since;
926 int err;
927
928 clock_gettime(CLOCK_MONOTONIC_RAW, &now);
929 subtract_timespecs(&now, &stream->first_missed_cb_ts, &time_since);
930 data.value = (unsigned)time_since.tv_sec;
931
932 if (stream->direction == CRAS_STREAM_INPUT) {
933 init_server_metrics_msg(&msg, MISSED_CB_SECOND_TIME_INPUT,
934 data);
935 } else {
936 init_server_metrics_msg(&msg, MISSED_CB_SECOND_TIME_OUTPUT,
937 data);
938 }
939 err = cras_server_metrics_message_send(
940 (struct cras_main_message *)&msg);
941 if (err < 0) {
942 syslog(LOG_ERR, "Failed to send metrics message: "
943 "MISSED_CB_SECOND_TIME");
944 return err;
945 }
946
947 return 0;
948 }
949
cras_server_metrics_missed_cb_event(struct cras_rstream * stream)950 int cras_server_metrics_missed_cb_event(struct cras_rstream *stream)
951 {
952 int rc = 0;
953
954 stream->num_missed_cb += 1;
955 if (stream->num_missed_cb == 1)
956 clock_gettime(CLOCK_MONOTONIC_RAW, &stream->first_missed_cb_ts);
957
958 /* Do not record missed cb if the stream has these flags. */
959 if (stream->flags & (BULK_AUDIO_OK | USE_DEV_TIMING | TRIGGER_ONLY))
960 return 0;
961
962 /* Only record the first and the second events. */
963 if (stream->num_missed_cb == 1)
964 rc = cras_server_metrics_missed_cb_first_time(stream);
965 else if (stream->num_missed_cb == 2)
966 rc = cras_server_metrics_missed_cb_second_time(stream);
967
968 return rc;
969 }
970
971 /* Logs the stream configurations from clients. */
972 static int
cras_server_metrics_stream_config(const struct cras_rstream_config * config)973 cras_server_metrics_stream_config(const struct cras_rstream_config *config)
974 {
975 struct cras_server_metrics_message msg;
976 union cras_server_metrics_data data;
977 int err;
978
979 data.stream_config.direction = config->direction;
980 data.stream_config.cb_threshold = (unsigned)config->cb_threshold;
981 data.stream_config.flags = (unsigned)config->flags;
982 data.stream_config.effects = (unsigned)config->effects;
983 data.stream_config.format = (int)config->format->format;
984 data.stream_config.rate = (unsigned)config->format->frame_rate;
985 data.stream_config.client_type = config->client_type;
986
987 init_server_metrics_msg(&msg, STREAM_CONFIG, data);
988 err = cras_server_metrics_message_send(
989 (struct cras_main_message *)&msg);
990 if (err < 0) {
991 syslog(LOG_ERR,
992 "Failed to send metrics message: STREAM_CONFIG");
993 return err;
994 }
995
996 return 0;
997 }
998
999 /* Logs runtime of a stream. */
cras_server_metrics_stream_runtime(const struct cras_rstream * stream)1000 int cras_server_metrics_stream_runtime(const struct cras_rstream *stream)
1001 {
1002 struct cras_server_metrics_message msg;
1003 union cras_server_metrics_data data;
1004 struct timespec now;
1005 int err;
1006
1007 data.stream_data.client_type = stream->client_type;
1008 data.stream_data.stream_type = stream->stream_type;
1009 data.stream_data.direction = stream->direction;
1010 clock_gettime(CLOCK_MONOTONIC_RAW, &now);
1011 subtract_timespecs(&now, &stream->start_ts, &data.stream_data.runtime);
1012
1013 init_server_metrics_msg(&msg, STREAM_RUNTIME, data);
1014
1015 err = cras_server_metrics_message_send(
1016 (struct cras_main_message *)&msg);
1017 if (err < 0) {
1018 syslog(LOG_ERR,
1019 "Failed to send metrics message: STREAM_RUNTIME");
1020 return err;
1021 }
1022
1023 return 0;
1024 }
1025
cras_server_metrics_stream_create(const struct cras_rstream_config * config)1026 int cras_server_metrics_stream_create(const struct cras_rstream_config *config)
1027 {
1028 return cras_server_metrics_stream_config(config);
1029 }
1030
cras_server_metrics_stream_destroy(const struct cras_rstream * stream)1031 int cras_server_metrics_stream_destroy(const struct cras_rstream *stream)
1032 {
1033 int rc;
1034 rc = cras_server_metrics_missed_cb_frequency(stream);
1035 if (rc < 0)
1036 return rc;
1037 rc = cras_server_metrics_stream_runtime(stream);
1038 if (rc < 0)
1039 return rc;
1040 return cras_server_metrics_longest_fetch_delay(stream);
1041 }
1042
cras_server_metrics_busyloop(struct timespec * ts,unsigned count)1043 int cras_server_metrics_busyloop(struct timespec *ts, unsigned count)
1044 {
1045 struct cras_server_metrics_message msg;
1046 union cras_server_metrics_data data;
1047 int err;
1048
1049 data.timespec_data.runtime = *ts;
1050 data.timespec_data.count = count;
1051
1052 init_server_metrics_msg(&msg, BUSYLOOP, data);
1053
1054 err = cras_server_metrics_message_send(
1055 (struct cras_main_message *)&msg);
1056 if (err < 0) {
1057 syslog(LOG_ERR, "Failed to send metrics message: BUSYLOOP");
1058 return err;
1059 }
1060 return 0;
1061 }
1062
cras_server_metrics_busyloop_length(unsigned length)1063 int cras_server_metrics_busyloop_length(unsigned length)
1064 {
1065 struct cras_server_metrics_message msg;
1066 union cras_server_metrics_data data;
1067 int err;
1068
1069 data.value = length;
1070
1071 init_server_metrics_msg(&msg, BUSYLOOP_LENGTH, data);
1072
1073 err = cras_server_metrics_message_send(
1074 (struct cras_main_message *)&msg);
1075 if (err < 0) {
1076 syslog(LOG_ERR,
1077 "Failed to send metrics message: BUSYLOOP_LENGTH");
1078 return err;
1079 }
1080 return 0;
1081 }
1082
metrics_device_runtime(struct cras_server_metrics_device_data data)1083 static void metrics_device_runtime(struct cras_server_metrics_device_data data)
1084 {
1085 char metrics_name[METRICS_NAME_BUFFER_SIZE];
1086
1087 snprintf(metrics_name, METRICS_NAME_BUFFER_SIZE,
1088 "Cras.%sDevice%sRuntime",
1089 data.direction == CRAS_STREAM_INPUT ? "Input" : "Output",
1090 metrics_device_type_str(data.type));
1091 cras_metrics_log_histogram(metrics_name, (unsigned)data.runtime.tv_sec,
1092 0, 10000, 20);
1093
1094 /* Logs the usage of each device. */
1095 if (data.direction == CRAS_STREAM_INPUT)
1096 cras_metrics_log_sparse_histogram(kDeviceTypeInput, data.type);
1097 else
1098 cras_metrics_log_sparse_histogram(kDeviceTypeOutput, data.type);
1099 }
1100
metrics_device_gain(struct cras_server_metrics_device_data data)1101 static void metrics_device_gain(struct cras_server_metrics_device_data data)
1102 {
1103 char metrics_name[METRICS_NAME_BUFFER_SIZE];
1104
1105 snprintf(metrics_name, METRICS_NAME_BUFFER_SIZE, "%s.%s", kDeviceGain,
1106 metrics_device_type_str(data.type));
1107 cras_metrics_log_histogram(metrics_name, data.value, 0, 2000, 20);
1108 }
1109
metrics_device_volume(struct cras_server_metrics_device_data data)1110 static void metrics_device_volume(struct cras_server_metrics_device_data data)
1111 {
1112 char metrics_name[METRICS_NAME_BUFFER_SIZE];
1113
1114 snprintf(metrics_name, METRICS_NAME_BUFFER_SIZE, "%s.%s", kDeviceVolume,
1115 metrics_device_type_str(data.type));
1116 cras_metrics_log_histogram(metrics_name, data.value, 0, 100, 20);
1117 }
1118
1119 static void
metrics_longest_fetch_delay(struct cras_server_metrics_stream_data data)1120 metrics_longest_fetch_delay(struct cras_server_metrics_stream_data data)
1121 {
1122 int fetch_delay_msec =
1123 data.runtime.tv_sec * 1000 + data.runtime.tv_nsec / 1000000;
1124 log_histogram_each_level(3, fetch_delay_msec, 0, 10000, 20,
1125 kFetchDelayMilliSeconds,
1126 metrics_client_type_str(data.client_type),
1127 metrics_stream_type_str(data.stream_type));
1128 }
1129
metrics_stream_runtime(struct cras_server_metrics_stream_data data)1130 static void metrics_stream_runtime(struct cras_server_metrics_stream_data data)
1131 {
1132 log_histogram_each_level(
1133 4, (int)data.runtime.tv_sec, 0, 10000, 20, kStreamRuntime,
1134 data.direction == CRAS_STREAM_INPUT ? "Input" : "Output",
1135 metrics_client_type_str(data.client_type),
1136 metrics_stream_type_str(data.stream_type));
1137 }
1138
metrics_busyloop(struct cras_server_metrics_timespec_data data)1139 static void metrics_busyloop(struct cras_server_metrics_timespec_data data)
1140 {
1141 char metrics_name[METRICS_NAME_BUFFER_SIZE];
1142
1143 snprintf(metrics_name, METRICS_NAME_BUFFER_SIZE, "%s.%s", kBusyloop,
1144 get_timespec_period_str(data.runtime));
1145
1146 cras_metrics_log_histogram(metrics_name, data.count, 0, 1000, 20);
1147 }
1148
1149 static void
metrics_stream_config(struct cras_server_metrics_stream_config config)1150 metrics_stream_config(struct cras_server_metrics_stream_config config)
1151 {
1152 const char *direction;
1153
1154 if (config.direction == CRAS_STREAM_INPUT)
1155 direction = "Input";
1156 else
1157 direction = "Output";
1158
1159 /* Logs stream callback threshold. */
1160 log_sparse_histogram_each_level(
1161 3, config.cb_threshold, kStreamCallbackThreshold, direction,
1162 metrics_client_type_str(config.client_type));
1163
1164 /* Logs stream flags. */
1165 log_sparse_histogram_each_level(
1166 3, config.flags, kStreamFlags, direction,
1167 metrics_client_type_str(config.client_type));
1168
1169 /* Logs stream effects. */
1170 log_sparse_histogram_each_level(
1171 3, config.effects, kStreamEffects, direction,
1172 metrics_client_type_str(config.client_type));
1173
1174 /* Logs stream sampling format. */
1175 log_sparse_histogram_each_level(
1176 3, config.format, kStreamSamplingFormat, direction,
1177 metrics_client_type_str(config.client_type));
1178
1179 /* Logs stream sampling rate. */
1180 log_sparse_histogram_each_level(
1181 3, config.rate, kStreamSamplingRate, direction,
1182 metrics_client_type_str(config.client_type));
1183
1184 /* Logs stream client type. */
1185 if (config.direction == CRAS_STREAM_INPUT)
1186 cras_metrics_log_sparse_histogram(kStreamClientTypeInput,
1187 config.client_type);
1188 else
1189 cras_metrics_log_sparse_histogram(kStreamClientTypeOutput,
1190 config.client_type);
1191 }
1192
handle_metrics_message(struct cras_main_message * msg,void * arg)1193 static void handle_metrics_message(struct cras_main_message *msg, void *arg)
1194 {
1195 struct cras_server_metrics_message *metrics_msg =
1196 (struct cras_server_metrics_message *)msg;
1197 switch (metrics_msg->metrics_type) {
1198 case BT_SCO_CONNECTION_ERROR:
1199 cras_metrics_log_sparse_histogram(kHfpScoConnectionError,
1200 metrics_msg->data.value);
1201 break;
1202 case BT_BATTERY_INDICATOR_SUPPORTED:
1203 cras_metrics_log_sparse_histogram(kHfpBatteryIndicatorSupported,
1204 metrics_msg->data.value);
1205 break;
1206 case BT_BATTERY_REPORT:
1207 cras_metrics_log_sparse_histogram(kHfpBatteryReport,
1208 metrics_msg->data.value);
1209 break;
1210 case BT_WIDEBAND_PACKET_LOSS:
1211 cras_metrics_log_histogram(kHfpWidebandSpeechPacketLoss,
1212 metrics_msg->data.value, 0, 1000,
1213 20);
1214 break;
1215 case BT_WIDEBAND_SUPPORTED:
1216 cras_metrics_log_sparse_histogram(kHfpWidebandSpeechSupported,
1217 metrics_msg->data.value);
1218 break;
1219 case BT_WIDEBAND_SELECTED_CODEC:
1220 cras_metrics_log_sparse_histogram(
1221 kHfpWidebandSpeechSelectedCodec,
1222 metrics_msg->data.value);
1223 break;
1224 case DEVICE_GAIN:
1225 metrics_device_gain(metrics_msg->data.device_data);
1226 break;
1227 case DEVICE_RUNTIME:
1228 metrics_device_runtime(metrics_msg->data.device_data);
1229 break;
1230 case DEVICE_VOLUME:
1231 metrics_device_volume(metrics_msg->data.device_data);
1232 break;
1233 case HIGHEST_DEVICE_DELAY_INPUT:
1234 cras_metrics_log_histogram(kHighestDeviceDelayInput,
1235 metrics_msg->data.value, 1, 10000,
1236 20);
1237 break;
1238 case HIGHEST_DEVICE_DELAY_OUTPUT:
1239 cras_metrics_log_histogram(kHighestDeviceDelayOutput,
1240 metrics_msg->data.value, 1, 10000,
1241 20);
1242 break;
1243 case HIGHEST_INPUT_HW_LEVEL:
1244 cras_metrics_log_histogram(kHighestInputHardwareLevel,
1245 metrics_msg->data.value, 1, 10000,
1246 20);
1247 break;
1248 case HIGHEST_OUTPUT_HW_LEVEL:
1249 cras_metrics_log_histogram(kHighestOutputHardwareLevel,
1250 metrics_msg->data.value, 1, 10000,
1251 20);
1252 break;
1253 case LONGEST_FETCH_DELAY:
1254 metrics_longest_fetch_delay(metrics_msg->data.stream_data);
1255 break;
1256 case MISSED_CB_FIRST_TIME_INPUT:
1257 cras_metrics_log_histogram(kMissedCallbackFirstTimeInput,
1258 metrics_msg->data.value, 0, 90000,
1259 20);
1260 break;
1261 case MISSED_CB_FIRST_TIME_OUTPUT:
1262 cras_metrics_log_histogram(kMissedCallbackFirstTimeOutput,
1263 metrics_msg->data.value, 0, 90000,
1264 20);
1265 break;
1266 case MISSED_CB_FREQUENCY_INPUT:
1267 cras_metrics_log_histogram(kMissedCallbackFrequencyInput,
1268 metrics_msg->data.value, 0, 90000,
1269 20);
1270 break;
1271 case MISSED_CB_FREQUENCY_OUTPUT:
1272 cras_metrics_log_histogram(kMissedCallbackFrequencyOutput,
1273 metrics_msg->data.value, 0, 90000,
1274 20);
1275 break;
1276 case MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_INPUT:
1277 cras_metrics_log_histogram(
1278 kMissedCallbackFrequencyAfterReschedulingInput,
1279 metrics_msg->data.value, 0, 90000, 20);
1280 break;
1281 case MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_OUTPUT:
1282 cras_metrics_log_histogram(
1283 kMissedCallbackFrequencyAfterReschedulingOutput,
1284 metrics_msg->data.value, 0, 90000, 20);
1285 break;
1286 case MISSED_CB_SECOND_TIME_INPUT:
1287 cras_metrics_log_histogram(kMissedCallbackSecondTimeInput,
1288 metrics_msg->data.value, 0, 90000,
1289 20);
1290 break;
1291 case MISSED_CB_SECOND_TIME_OUTPUT:
1292 cras_metrics_log_histogram(kMissedCallbackSecondTimeOutput,
1293 metrics_msg->data.value, 0, 90000,
1294 20);
1295 break;
1296 case NUM_UNDERRUNS:
1297 cras_metrics_log_histogram(kUnderrunsPerDevice,
1298 metrics_msg->data.value, 0, 1000,
1299 10);
1300 break;
1301 case STREAM_CONFIG:
1302 metrics_stream_config(metrics_msg->data.stream_config);
1303 break;
1304 case STREAM_RUNTIME:
1305 metrics_stream_runtime(metrics_msg->data.stream_data);
1306 break;
1307 case BUSYLOOP:
1308 metrics_busyloop(metrics_msg->data.timespec_data);
1309 break;
1310 case BUSYLOOP_LENGTH:
1311 cras_metrics_log_histogram(
1312 kBusyloopLength, metrics_msg->data.value, 0, 1000, 50);
1313 break;
1314 default:
1315 syslog(LOG_ERR, "Unknown metrics type %u",
1316 metrics_msg->metrics_type);
1317 break;
1318 }
1319 }
1320
cras_server_metrics_init()1321 int cras_server_metrics_init()
1322 {
1323 cras_main_message_add_handler(CRAS_MAIN_METRICS, handle_metrics_message,
1324 NULL);
1325 return 0;
1326 }
1327