1 /* 2 * Copyright (C) 2014 BlueKitchen GmbH 3 * 4 * Redistribution and use in source and binary forms, with or without 5 * modification, are permitted provided that the following conditions 6 * are met: 7 * 8 * 1. Redistributions of source code must retain the above copyright 9 * notice, this list of conditions and the following disclaimer. 10 * 2. Redistributions in binary form must reproduce the above copyright 11 * notice, this list of conditions and the following disclaimer in the 12 * documentation and/or other materials provided with the distribution. 13 * 3. Neither the name of the copyright holders nor the names of 14 * contributors may be used to endorse or promote products derived 15 * from this software without specific prior written permission. 16 * 4. Any redistribution, use, or modification is done solely for 17 * personal benefit and not for any commercial purpose or for 18 * monetary gain. 19 * 20 * THIS SOFTWARE IS PROVIDED BY BLUEKITCHEN GMBH AND CONTRIBUTORS 21 * ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 22 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS 23 * FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL MATTHIAS 24 * RINGWALD OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, 25 * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, 26 * BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS 27 * OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED 28 * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, 29 * OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF 30 * THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF 31 * SUCH DAMAGE. 32 * 33 * Please inquire about commercial licensing options at 34 * [email protected] 35 * 36 */ 37 38 #define BTSTACK_FILE__ "hci_dump.c" 39 40 /* 41 * hci_dump.c 42 * 43 * Dump HCI trace in various formats: 44 * 45 * - BlueZ's hcidump format 46 * - Apple's PacketLogger 47 * - stdout hexdump 48 * 49 */ 50 51 #include "btstack_config.h" 52 53 // enable POSIX functions (needed for -std=c99) 54 #define _POSIX_C_SOURCE 200809 55 56 #include "hci_dump.h" 57 #include "hci.h" 58 #include "hci_transport.h" 59 #include "hci_cmd.h" 60 #include "btstack_run_loop.h" 61 #include <stdio.h> 62 63 #ifdef HAVE_POSIX_FILE_IO 64 #include <fcntl.h> // open 65 #include <unistd.h> // write 66 #include <time.h> 67 #include <sys/time.h> // for timestamps 68 #include <sys/stat.h> // for mode flags 69 #endif 70 71 #ifdef ENABLE_SEGGER_RTT 72 #include "SEGGER_RTT.h" 73 74 // allow to configure mode, channel, up buffer size in btstack_config.h for binary HCI formats (PacketLogger/BlueZ) 75 76 #ifndef SEGGER_RTT_PACKETLOG_MODE 77 #define SEGGER_RTT_PACKETLOG_MODE SEGGER_RTT_MODE_DEFAULT 78 #endif 79 #ifndef SEGGER_RTT_PACKETLOG_BUFFER_SIZE 80 #define SEGGER_RTT_PACKETLOG_BUFFER_SIZE 1024 81 #endif 82 #ifndef SEGGER_RTT_PACKETLOG_CHANNEL 83 #define SEGGER_RTT_PACKETLOG_CHANNEL 1 84 #endif 85 86 static char segger_rtt_packetlog_buffer[SEGGER_RTT_PACKETLOG_BUFFER_SIZE]; 87 #endif 88 89 // BLUEZ hcidump - struct not used directly, but left here as documentation 90 typedef struct { 91 uint16_t len; 92 uint8_t in; 93 uint8_t pad; 94 uint32_t ts_sec; 95 uint32_t ts_usec; 96 uint8_t packet_type; 97 } 98 hcidump_hdr; 99 #define HCIDUMP_HDR_SIZE 13 100 101 // APPLE PacketLogger - struct not used directly, but left here as documentation 102 typedef struct { 103 uint32_t len; 104 uint32_t ts_sec; 105 uint32_t ts_usec; 106 uint8_t type; // 0xfc for note 107 } 108 pktlog_hdr; 109 #define PKTLOG_HDR_SIZE 13 110 111 static int dump_file = -1; 112 static int dump_format; 113 #ifdef HAVE_POSIX_FILE_IO 114 static char time_string[40]; 115 static int max_nr_packets = -1; 116 static int nr_packets = 0; 117 #endif 118 119 #if defined(HAVE_POSIX_FILE_IO) || defined (ENABLE_SEGGER_RTT) 120 static char log_message_buffer[256]; 121 #endif 122 123 // levels: debug, info, error 124 static int log_level_enabled[3] = { 1, 1, 1}; 125 126 void hci_dump_open(const char *filename, hci_dump_format_t format){ 127 128 dump_format = format; 129 130 #ifdef HAVE_POSIX_FILE_IO 131 if (dump_format == HCI_DUMP_STDOUT) { 132 dump_file = fileno(stdout); 133 } else { 134 135 int oflags = O_WRONLY | O_CREAT | O_TRUNC; 136 #ifdef _WIN32 137 oflags |= O_BINARY; 138 #endif 139 dump_file = open(filename, oflags, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH ); 140 if (dump_file < 0){ 141 printf("hci_dump_open: failed to open file %s\n", filename); 142 } 143 } 144 #else 145 146 UNUSED(filename); 147 148 #ifdef ENABLE_SEGGER_RTT 149 switch (dump_format){ 150 case HCI_DUMP_PACKETLOGGER: 151 case HCI_DUMP_BLUEZ: 152 SEGGER_RTT_ConfigUpBuffer(SEGGER_RTT_PACKETLOG_CHANNEL, "hci_dump", &segger_rtt_packetlog_buffer[0], SEGGER_RTT_PACKETLOG_BUFFER_SIZE, SEGGER_RTT_PACKETLOG_MODE); 153 break; 154 default: 155 break; 156 } 157 #endif 158 159 dump_file = 1; 160 #endif 161 } 162 163 #ifdef HAVE_POSIX_FILE_IO 164 void hci_dump_set_max_packets(int packets){ 165 max_nr_packets = packets; 166 } 167 #endif 168 169 static void hci_dump_packetlogger_setup_header(uint8_t * buffer, uint32_t tv_sec, uint32_t tv_us, uint8_t packet_type, uint8_t in, uint16_t len){ 170 big_endian_store_32( buffer, 0, PKTLOG_HDR_SIZE - 4 + len); 171 big_endian_store_32( buffer, 4, tv_sec); 172 big_endian_store_32( buffer, 8, tv_us); 173 uint8_t packet_logger_type = 0; 174 switch (packet_type){ 175 case HCI_COMMAND_DATA_PACKET: 176 packet_logger_type = 0x00; 177 break; 178 case HCI_ACL_DATA_PACKET: 179 packet_logger_type = in ? 0x03 : 0x02; 180 break; 181 case HCI_SCO_DATA_PACKET: 182 packet_logger_type = in ? 0x09 : 0x08; 183 break; 184 case HCI_EVENT_PACKET: 185 packet_logger_type = 0x01; 186 break; 187 case LOG_MESSAGE_PACKET: 188 packet_logger_type = 0xfc; 189 break; 190 default: 191 return; 192 } 193 buffer[12] = packet_logger_type; 194 } 195 196 static void hci_dump_bluez_setup_header(uint8_t * buffer, uint32_t tv_sec, uint32_t tv_us, uint8_t packet_type, uint8_t in, uint16_t len){ 197 little_endian_store_16( buffer, 0u, 1u + len); 198 buffer[2] = in; 199 buffer[3] = 0; 200 little_endian_store_32( buffer, 4, tv_sec); 201 little_endian_store_32( buffer, 8, tv_us); 202 buffer[12] = packet_type; 203 } 204 205 static void printf_packet(uint8_t packet_type, uint8_t in, uint8_t * packet, uint16_t len){ 206 switch (packet_type){ 207 case HCI_COMMAND_DATA_PACKET: 208 printf("CMD => "); 209 break; 210 case HCI_EVENT_PACKET: 211 printf("EVT <= "); 212 break; 213 case HCI_ACL_DATA_PACKET: 214 if (in) { 215 printf("ACL <= "); 216 } else { 217 printf("ACL => "); 218 } 219 break; 220 case HCI_SCO_DATA_PACKET: 221 if (in) { 222 printf("SCO <= "); 223 } else { 224 printf("SCO => "); 225 } 226 break; 227 case LOG_MESSAGE_PACKET: 228 printf("LOG -- %s\n", (char*) packet); 229 return; 230 default: 231 return; 232 } 233 printf_hexdump(packet, len); 234 } 235 236 static void printf_timestamp(void){ 237 #ifdef HAVE_POSIX_FILE_IO 238 struct tm* ptm; 239 struct timeval curr_time; 240 gettimeofday(&curr_time, NULL); 241 time_t curr_time_secs = curr_time.tv_sec; 242 /* Obtain the time of day, and convert it to a tm struct. */ 243 ptm = localtime (&curr_time_secs); 244 /* assert localtime was successful */ 245 if (!ptm) return; 246 /* Format the date and time, down to a single second. */ 247 strftime (time_string, sizeof (time_string), "[%Y-%m-%d %H:%M:%S", ptm); 248 /* Compute milliseconds from microseconds. */ 249 uint16_t milliseconds = curr_time.tv_usec / 1000; 250 /* Print the formatted time, in seconds, followed by a decimal point and the milliseconds. */ 251 printf ("%s.%03u] ", time_string, milliseconds); 252 #else 253 uint32_t time_ms = btstack_run_loop_get_time_ms(); 254 int seconds = time_ms / 1000u; 255 int minutes = seconds / 60; 256 unsigned int hours = minutes / 60; 257 258 uint16_t p_ms = time_ms - (seconds * 1000u); 259 uint16_t p_seconds = seconds - (minutes * 60); 260 uint16_t p_minutes = minutes - (hours * 60u); 261 printf("[%02u:%02u:%02u.%03u] ", hours, p_minutes, p_seconds, p_ms); 262 #endif 263 } 264 265 void hci_dump_packet(uint8_t packet_type, uint8_t in, uint8_t *packet, uint16_t len) { 266 267 static union { 268 uint8_t header_bluez[HCIDUMP_HDR_SIZE]; 269 uint8_t header_packetlogger[PKTLOG_HDR_SIZE]; 270 } header; 271 272 if (dump_file < 0) return; // not activated yet 273 274 #ifdef HAVE_POSIX_FILE_IO 275 // don't grow bigger than max_nr_packets 276 if (dump_format != HCI_DUMP_STDOUT && max_nr_packets > 0){ 277 if (nr_packets >= max_nr_packets){ 278 lseek(dump_file, 0, SEEK_SET); 279 // avoid -Wunused-result 280 int res = ftruncate(dump_file, 0); 281 UNUSED(res); 282 nr_packets = 0; 283 } 284 nr_packets++; 285 } 286 #endif 287 288 if (dump_format == HCI_DUMP_STDOUT){ 289 printf_timestamp(); 290 printf_packet(packet_type, in, packet, len); 291 return; 292 } 293 294 uint32_t tv_sec = 0; 295 uint32_t tv_us = 0; 296 297 // get time 298 #ifdef HAVE_POSIX_FILE_IO 299 struct timeval curr_time; 300 gettimeofday(&curr_time, NULL); 301 tv_sec = curr_time.tv_sec; 302 tv_us = curr_time.tv_usec; 303 #else 304 uint32_t time_ms = btstack_run_loop_get_time_ms(); 305 tv_us = time_ms * 1000u; 306 tv_sec = 946728000UL + (time_ms / 1000u); 307 #endif 308 309 #ifdef ENABLE_SEGGER_RTT 310 #if (SEGGER_RTT_PACKETLOG_MODE == SEGGER_RTT_MODE_NO_BLOCK_SKIP) 311 static const char rtt_warning[] = "RTT buffer full - packet(s) skipped"; 312 static bool rtt_packet_skipped = false; 313 if (rtt_packet_skipped){ 314 // try to write warning log message 315 rtt_packet_skipped = false; 316 packet_type = LOG_MESSAGE_PACKET; 317 packet = (uint8_t *) &rtt_warning[0]; 318 len = sizeof(rtt_warning)-1; 319 } 320 #endif 321 #endif 322 323 uint16_t header_len = 0; 324 switch (dump_format){ 325 case HCI_DUMP_BLUEZ: 326 hci_dump_bluez_setup_header(header.header_bluez, tv_sec, tv_us, packet_type, in, len); 327 header_len = HCIDUMP_HDR_SIZE; 328 break; 329 case HCI_DUMP_PACKETLOGGER: 330 hci_dump_packetlogger_setup_header(header.header_packetlogger, tv_sec, tv_us, packet_type, in, len); 331 header_len = PKTLOG_HDR_SIZE; 332 break; 333 default: 334 return; 335 } 336 337 #ifdef HAVE_POSIX_FILE_IO 338 // avoid -Wunused-result 339 int res = 0; 340 res = write (dump_file, &header, header_len); 341 res = write (dump_file, packet, len ); 342 UNUSED(res); 343 #endif 344 345 #ifdef ENABLE_SEGGER_RTT 346 347 #if (SEGGER_RTT_PACKETLOG_MODE == SEGGER_RTT_MODE_NO_BLOCK_SKIP) 348 // check available space in buffer to avoid writing header but not packet 349 unsigned space_free = SEGGER_RTT_GetAvailWriteSpace(SEGGER_RTT_PACKETLOG_CHANNEL); 350 if ((header_len + len) > space_free) { 351 rtt_packet_skipped = true; 352 return; 353 } 354 #endif 355 356 SEGGER_RTT_Write(SEGGER_RTT_PACKETLOG_CHANNEL, &header, header_len); 357 SEGGER_RTT_Write(SEGGER_RTT_PACKETLOG_CHANNEL, packet, len); 358 #endif 359 UNUSED(header_len); 360 } 361 362 static int hci_dump_log_level_active(int log_level){ 363 if (log_level < HCI_DUMP_LOG_LEVEL_DEBUG) return 0; 364 if (log_level > HCI_DUMP_LOG_LEVEL_ERROR) return 0; 365 return log_level_enabled[log_level]; 366 } 367 368 void hci_dump_log_va_arg(int log_level, const char * format, va_list argptr){ 369 if (!hci_dump_log_level_active(log_level)) return; 370 371 #if defined(HAVE_POSIX_FILE_IO) || defined (ENABLE_SEGGER_RTT) 372 if (dump_file >= 0){ 373 int len = vsnprintf(log_message_buffer, sizeof(log_message_buffer), format, argptr); 374 hci_dump_packet(LOG_MESSAGE_PACKET, 0, (uint8_t*) log_message_buffer, len); 375 return; 376 } 377 #endif 378 379 printf_timestamp(); 380 printf("LOG -- "); 381 vprintf(format, argptr); 382 printf("\n"); 383 } 384 385 void hci_dump_log(int log_level, const char * format, ...){ 386 va_list argptr; 387 va_start(argptr, format); 388 hci_dump_log_va_arg(log_level, format, argptr); 389 va_end(argptr); 390 } 391 392 #ifdef __AVR__ 393 void hci_dump_log_P(int log_level, PGM_P format, ...){ 394 if (!hci_dump_log_level_active(log_level)) return; 395 va_list argptr; 396 va_start(argptr, format); 397 printf_P(PSTR("LOG -- ")); 398 vfprintf_P(stdout, format, argptr); 399 printf_P(PSTR("\n")); 400 va_end(argptr); 401 } 402 #endif 403 404 void hci_dump_close(void){ 405 #ifdef HAVE_POSIX_FILE_IO 406 close(dump_file); 407 #endif 408 dump_file = -1; 409 } 410 411 void hci_dump_enable_log_level(int log_level, int enable){ 412 if (log_level < HCI_DUMP_LOG_LEVEL_DEBUG) return; 413 if (log_level > HCI_DUMP_LOG_LEVEL_ERROR) return; 414 log_level_enabled[log_level] = enable; 415 } 416 417