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 static char channel1_out[1024]; 74 #endif 75 76 // BLUEZ hcidump - struct not used directly, but left here as documentation 77 typedef struct { 78 uint16_t len; 79 uint8_t in; 80 uint8_t pad; 81 uint32_t ts_sec; 82 uint32_t ts_usec; 83 uint8_t packet_type; 84 } 85 hcidump_hdr; 86 #define HCIDUMP_HDR_SIZE 13 87 88 // APPLE PacketLogger - struct not used directly, but left here as documentation 89 typedef struct { 90 uint32_t len; 91 uint32_t ts_sec; 92 uint32_t ts_usec; 93 uint8_t type; // 0xfc for note 94 } 95 pktlog_hdr; 96 #define PKTLOG_HDR_SIZE 13 97 98 static int dump_file = -1; 99 static int dump_format; 100 static union { 101 uint8_t header_bluez[HCIDUMP_HDR_SIZE]; 102 uint8_t header_packetlogger[PKTLOG_HDR_SIZE]; 103 } header; 104 #ifdef HAVE_POSIX_FILE_IO 105 static char time_string[40]; 106 static int max_nr_packets = -1; 107 static int nr_packets = 0; 108 #endif 109 110 #if defined(HAVE_POSIX_FILE_IO) || defined (ENABLE_SEGGER_RTT) 111 static char log_message_buffer[256]; 112 #endif 113 114 // levels: debug, info, error 115 static int log_level_enabled[3] = { 1, 1, 1}; 116 117 void hci_dump_open(const char *filename, hci_dump_format_t format){ 118 119 dump_format = format; 120 121 #ifdef HAVE_POSIX_FILE_IO 122 if (dump_format == HCI_DUMP_STDOUT) { 123 dump_file = fileno(stdout); 124 } else { 125 126 int oflags = O_WRONLY | O_CREAT | O_TRUNC; 127 #ifdef _WIN32 128 oflags |= O_BINARY; 129 #endif 130 dump_file = open(filename, oflags, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH ); 131 if (dump_file < 0){ 132 printf("hci_dump_open: failed to open file %s\n", filename); 133 } 134 } 135 #else 136 137 UNUSED(filename); 138 139 #ifdef ENABLE_SEGGER_RTT 140 switch (dump_format){ 141 case HCI_DUMP_PACKETLOGGER: 142 case HCI_DUMP_BLUEZ: 143 // Configure up channel 1, options: 144 // - SEGGER_RTT_MODE_NO_BLOCK_SKIP 145 // - SEGGER_RTT_MODE_BLOCK_IF_FIFO_FULL 146 // Note: with SEGGER_RTT_MODE_BLOCK_IF_FIFO_FULL, firwmware will hang if RTT not supported/debug probe not connected 147 // Note: with SEGGER_RTT_MODE_NO_BLOCK_SKIP, there's a chance for log file corruption if second write (packet) is skipped 148 SEGGER_RTT_ConfigUpBuffer(1, "hci_dump", &channel1_out[0], sizeof(channel1_out), SEGGER_RTT_MODE_NO_BLOCK_SKIP) ;; 149 break; 150 default: 151 break; 152 } 153 #endif 154 155 dump_file = 1; 156 #endif 157 } 158 159 #ifdef HAVE_POSIX_FILE_IO 160 void hci_dump_set_max_packets(int packets){ 161 max_nr_packets = packets; 162 } 163 #endif 164 165 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){ 166 big_endian_store_32( buffer, 0, PKTLOG_HDR_SIZE - 4 + len); 167 big_endian_store_32( buffer, 4, tv_sec); 168 big_endian_store_32( buffer, 8, tv_us); 169 uint8_t packet_logger_type = 0; 170 switch (packet_type){ 171 case HCI_COMMAND_DATA_PACKET: 172 packet_logger_type = 0x00; 173 break; 174 case HCI_ACL_DATA_PACKET: 175 packet_logger_type = in ? 0x03 : 0x02; 176 break; 177 case HCI_SCO_DATA_PACKET: 178 packet_logger_type = in ? 0x09 : 0x08; 179 break; 180 case HCI_EVENT_PACKET: 181 packet_logger_type = 0x01; 182 break; 183 case LOG_MESSAGE_PACKET: 184 packet_logger_type = 0xfc; 185 break; 186 default: 187 return; 188 } 189 buffer[12] = packet_logger_type; 190 } 191 192 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){ 193 little_endian_store_16( buffer, 0, 1 + len); 194 buffer[2] = in; 195 buffer[3] = 0; 196 little_endian_store_32( buffer, 4, tv_sec); 197 little_endian_store_32( buffer, 8, tv_us); 198 buffer[12] = packet_type; 199 } 200 201 static void printf_packet(uint8_t packet_type, uint8_t in, uint8_t * packet, uint16_t len){ 202 switch (packet_type){ 203 case HCI_COMMAND_DATA_PACKET: 204 printf("CMD => "); 205 break; 206 case HCI_EVENT_PACKET: 207 printf("EVT <= "); 208 break; 209 case HCI_ACL_DATA_PACKET: 210 if (in) { 211 printf("ACL <= "); 212 } else { 213 printf("ACL => "); 214 } 215 break; 216 case HCI_SCO_DATA_PACKET: 217 if (in) { 218 printf("SCO <= "); 219 } else { 220 printf("SCO => "); 221 } 222 break; 223 case LOG_MESSAGE_PACKET: 224 printf("LOG -- %s\n", (char*) packet); 225 return; 226 default: 227 return; 228 } 229 printf_hexdump(packet, len); 230 } 231 232 static void printf_timestamp(void){ 233 #ifdef HAVE_POSIX_FILE_IO 234 struct tm* ptm; 235 struct timeval curr_time; 236 gettimeofday(&curr_time, NULL); 237 time_t curr_time_secs = curr_time.tv_sec; 238 /* Obtain the time of day, and convert it to a tm struct. */ 239 ptm = localtime (&curr_time_secs); 240 /* assert localtime was successful */ 241 if (!ptm) return; 242 /* Format the date and time, down to a single second. */ 243 strftime (time_string, sizeof (time_string), "[%Y-%m-%d %H:%M:%S", ptm); 244 /* Compute milliseconds from microseconds. */ 245 uint16_t milliseconds = curr_time.tv_usec / 1000; 246 /* Print the formatted time, in seconds, followed by a decimal point and the milliseconds. */ 247 printf ("%s.%03u] ", time_string, milliseconds); 248 #else 249 uint32_t time_ms = btstack_run_loop_get_time_ms(); 250 int seconds = time_ms / 1000; 251 int minutes = seconds / 60; 252 unsigned int hours = minutes / 60; 253 254 uint16_t p_ms = time_ms - (seconds * 1000); 255 uint16_t p_seconds = seconds - (minutes * 60); 256 uint16_t p_minutes = minutes - (hours * 60); 257 printf("[%02u:%02u:%02u.%03u] ", hours, p_minutes, p_seconds, p_ms); 258 #endif 259 } 260 261 void hci_dump_packet(uint8_t packet_type, uint8_t in, uint8_t *packet, uint16_t len) { 262 263 if (dump_file < 0) return; // not activated yet 264 265 #ifdef HAVE_POSIX_FILE_IO 266 // don't grow bigger than max_nr_packets 267 if (dump_format != HCI_DUMP_STDOUT && max_nr_packets > 0){ 268 if (nr_packets >= max_nr_packets){ 269 lseek(dump_file, 0, SEEK_SET); 270 // avoid -Wunused-result 271 int res = ftruncate(dump_file, 0); 272 UNUSED(res); 273 nr_packets = 0; 274 } 275 nr_packets++; 276 } 277 #endif 278 279 if (dump_format == HCI_DUMP_STDOUT){ 280 printf_timestamp(); 281 printf_packet(packet_type, in, packet, len); 282 return; 283 } 284 285 uint32_t tv_sec = 0; 286 uint32_t tv_us = 0; 287 288 // get time 289 #ifdef HAVE_POSIX_FILE_IO 290 struct timeval curr_time; 291 gettimeofday(&curr_time, NULL); 292 tv_sec = curr_time.tv_sec; 293 tv_us = curr_time.tv_usec; 294 #else 295 uint32_t time_ms = btstack_run_loop_get_time_ms(); 296 tv_us = time_ms * 1000; 297 tv_sec = 946728000UL + (time_ms / 1000); 298 #endif 299 300 uint16_t header_len = 0; 301 switch (dump_format){ 302 case HCI_DUMP_BLUEZ: 303 hci_dump_bluez_setup_header(header.header_bluez, tv_sec, tv_us, packet_type, in, len); 304 header_len = HCIDUMP_HDR_SIZE; 305 break; 306 case HCI_DUMP_PACKETLOGGER: 307 hci_dump_packetlogger_setup_header(header.header_packetlogger, tv_sec, tv_us, packet_type, in, len); 308 header_len = PKTLOG_HDR_SIZE; 309 break; 310 default: 311 return; 312 } 313 314 #ifdef HAVE_POSIX_FILE_IO 315 // avoid -Wunused-result 316 int res = 0; 317 res = write (dump_file, &header, header_len); 318 res = write (dump_file, packet, len ); 319 UNUSED(res); 320 #endif 321 #ifdef ENABLE_SEGGER_RTT 322 SEGGER_RTT_Write(1, &header, header_len); 323 SEGGER_RTT_Write(1, packet, len); 324 #endif 325 UNUSED(header_len); 326 } 327 328 static int hci_dump_log_level_active(int log_level){ 329 if (log_level < HCI_DUMP_LOG_LEVEL_DEBUG) return 0; 330 if (log_level > HCI_DUMP_LOG_LEVEL_ERROR) return 0; 331 return log_level_enabled[log_level]; 332 } 333 334 void hci_dump_log_va_arg(int log_level, const char * format, va_list argptr){ 335 if (!hci_dump_log_level_active(log_level)) return; 336 337 #if defined(HAVE_POSIX_FILE_IO) || defined (ENABLE_SEGGER_RTT) 338 if (dump_file >= 0){ 339 int len = vsnprintf(log_message_buffer, sizeof(log_message_buffer), format, argptr); 340 hci_dump_packet(LOG_MESSAGE_PACKET, 0, (uint8_t*) log_message_buffer, len); 341 return; 342 } 343 #endif 344 345 printf_timestamp(); 346 printf("LOG -- "); 347 vprintf(format, argptr); 348 printf("\n"); 349 } 350 351 void hci_dump_log(int log_level, const char * format, ...){ 352 va_list argptr; 353 va_start(argptr, format); 354 hci_dump_log_va_arg(log_level, format, argptr); 355 va_end(argptr); 356 } 357 358 #ifdef __AVR__ 359 void hci_dump_log_P(int log_level, PGM_P format, ...){ 360 if (!hci_dump_log_level_active(log_level)) return; 361 va_list argptr; 362 va_start(argptr, format); 363 printf_P(PSTR("LOG -- ")); 364 vfprintf_P(stdout, format, argptr); 365 printf_P(PSTR("\n")); 366 va_end(argptr); 367 } 368 #endif 369 370 void hci_dump_close(void){ 371 #ifdef HAVE_POSIX_FILE_IO 372 close(dump_file); 373 #endif 374 dump_file = -1; 375 } 376 377 void hci_dump_enable_log_level(int log_level, int enable){ 378 if (log_level < HCI_DUMP_LOG_LEVEL_DEBUG) return; 379 if (log_level > HCI_DUMP_LOG_LEVEL_ERROR) return; 380 log_level_enabled[log_level] = enable; 381 } 382 383