179662672Smatthias.ringwald /* 2a0c35809S[email protected] * Copyright (C) 2014 BlueKitchen GmbH 31713bceaSmatthias.ringwald * 41713bceaSmatthias.ringwald * Redistribution and use in source and binary forms, with or without 51713bceaSmatthias.ringwald * modification, are permitted provided that the following conditions 61713bceaSmatthias.ringwald * are met: 71713bceaSmatthias.ringwald * 81713bceaSmatthias.ringwald * 1. Redistributions of source code must retain the above copyright 91713bceaSmatthias.ringwald * notice, this list of conditions and the following disclaimer. 101713bceaSmatthias.ringwald * 2. Redistributions in binary form must reproduce the above copyright 111713bceaSmatthias.ringwald * notice, this list of conditions and the following disclaimer in the 121713bceaSmatthias.ringwald * documentation and/or other materials provided with the distribution. 131713bceaSmatthias.ringwald * 3. Neither the name of the copyright holders nor the names of 141713bceaSmatthias.ringwald * contributors may be used to endorse or promote products derived 151713bceaSmatthias.ringwald * from this software without specific prior written permission. 166b64433eSmatthias.ringwald * 4. Any redistribution, use, or modification is done solely for 176b64433eSmatthias.ringwald * personal benefit and not for any commercial purpose or for 186b64433eSmatthias.ringwald * monetary gain. 191713bceaSmatthias.ringwald * 20a0c35809S[email protected] * THIS SOFTWARE IS PROVIDED BY BLUEKITCHEN GMBH AND CONTRIBUTORS 211713bceaSmatthias.ringwald * ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 221713bceaSmatthias.ringwald * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS 231713bceaSmatthias.ringwald * FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL MATTHIAS 241713bceaSmatthias.ringwald * RINGWALD OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, 251713bceaSmatthias.ringwald * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, 261713bceaSmatthias.ringwald * BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS 271713bceaSmatthias.ringwald * OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED 281713bceaSmatthias.ringwald * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, 291713bceaSmatthias.ringwald * OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF 301713bceaSmatthias.ringwald * THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF 311713bceaSmatthias.ringwald * SUCH DAMAGE. 321713bceaSmatthias.ringwald * 33a0c35809S[email protected] * Please inquire about commercial licensing options at 34a0c35809S[email protected] * [email protected] 356b64433eSmatthias.ringwald * 361713bceaSmatthias.ringwald */ 371713bceaSmatthias.ringwald 38*ab2c6ae4SMatthias Ringwald #define __BTSTACK_FILE__ "hci_dump.c" 39*ab2c6ae4SMatthias Ringwald 401713bceaSmatthias.ringwald /* 4179662672Smatthias.ringwald * hci_dump.c 4279662672Smatthias.ringwald * 43fe1ed1b8Smatthias.ringwald * Dump HCI trace in various formats: 44fe1ed1b8Smatthias.ringwald * 45fe1ed1b8Smatthias.ringwald * - BlueZ's hcidump format 46fe1ed1b8Smatthias.ringwald * - Apple's PacketLogger 47fe1ed1b8Smatthias.ringwald * - stdout hexdump 4879662672Smatthias.ringwald * 4979662672Smatthias.ringwald * Created by Matthias Ringwald on 5/26/09. 5079662672Smatthias.ringwald */ 5179662672Smatthias.ringwald 527907f069SMatthias Ringwald #include "btstack_config.h" 53a1d7dd1fSmatthias.ringwald 5479662672Smatthias.ringwald #include "hci_dump.h" 5579662672Smatthias.ringwald #include "hci.h" 56c6448b67Smatthias.ringwald #include "hci_transport.h" 5756042629SMatthias Ringwald #include "hci_cmd.h" 5882636622SMatthias Ringwald #include "btstack_run_loop.h" 59198a9e1bS[email protected] #include <stdio.h> 6079662672Smatthias.ringwald 61eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 62d5ea8924S[email protected] #include <fcntl.h> // open 6379662672Smatthias.ringwald #include <unistd.h> // write 648adf0ddaSmatthias.ringwald #include <time.h> 658b658ebcSmatthias.ringwald #include <sys/time.h> // for timestamps 66c7b9c559Smatthias.ringwald #include <sys/stat.h> // for mode flags 6768e27c0fSmatthias.ringwald #endif 6879662672Smatthias.ringwald 691a1c8389SMatthias Ringwald // BLUEZ hcidump - struct not used directly, but left here as documentation 708b658ebcSmatthias.ringwald typedef struct { 718b658ebcSmatthias.ringwald uint16_t len; 728b658ebcSmatthias.ringwald uint8_t in; 738b658ebcSmatthias.ringwald uint8_t pad; 748b658ebcSmatthias.ringwald uint32_t ts_sec; 758b658ebcSmatthias.ringwald uint32_t ts_usec; 768b658ebcSmatthias.ringwald uint8_t packet_type; 776c5c6faaSmatthias.ringwald } 786c5c6faaSmatthias.ringwald hcidump_hdr; 79f3e036dcSMatthias Ringwald #define HCIDUMP_HDR_SIZE 13 8079662672Smatthias.ringwald 811a1c8389SMatthias Ringwald // APPLE PacketLogger - struct not used directly, but left here as documentation 828b658ebcSmatthias.ringwald typedef struct { 838b658ebcSmatthias.ringwald uint32_t len; 848b658ebcSmatthias.ringwald uint32_t ts_sec; 858b658ebcSmatthias.ringwald uint32_t ts_usec; 862df12229Smatthias.ringwald uint8_t type; // 0xfc for note 876c5c6faaSmatthias.ringwald } 886c5c6faaSmatthias.ringwald pktlog_hdr; 89f3e036dcSMatthias Ringwald #define PKTLOG_HDR_SIZE 13 908b658ebcSmatthias.ringwald 918b658ebcSmatthias.ringwald static int dump_file = -1; 92eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 938b658ebcSmatthias.ringwald static int dump_format; 94f3e036dcSMatthias Ringwald static uint8_t header_bluez[HCIDUMP_HDR_SIZE]; 95f3e036dcSMatthias Ringwald static uint8_t header_packetlogger[PKTLOG_HDR_SIZE]; 968adf0ddaSmatthias.ringwald static char time_string[40]; 972992c131Smatthias.ringwald static int max_nr_packets = -1; 989ae0c346Smatthias.ringwald static int nr_packets = 0; 99a1d7dd1fSmatthias.ringwald static char log_message_buffer[256]; 10068e27c0fSmatthias.ringwald #endif 1018b658ebcSmatthias.ringwald 1028a37b10aSMatthias Ringwald // levels: debug, info, error 1038a37b10aSMatthias Ringwald static int log_level_enabled[3] = { 1, 1, 1}; 1048a37b10aSMatthias Ringwald 105a225073eS[email protected] void hci_dump_open(const char *filename, hci_dump_format_t format){ 106eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 1078b658ebcSmatthias.ringwald dump_format = format; 1088adf0ddaSmatthias.ringwald if (dump_format == HCI_DUMP_STDOUT) { 1098adf0ddaSmatthias.ringwald dump_file = fileno(stdout); 1108adf0ddaSmatthias.ringwald } else { 111eb443d3dSMatthias Ringwald 1121e154302SMatthias Ringwald int oflags = O_WRONLY | O_CREAT | O_TRUNC; 113b52eaea5S[email protected] #ifdef _WIN32 1141e154302SMatthias Ringwald oflags |= O_BINARY; 115b52eaea5S[email protected] #endif 116eb443d3dSMatthias Ringwald 1171e154302SMatthias Ringwald dump_file = open(filename, oflags, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH ); 1181e154302SMatthias Ringwald if (dump_file < 0){ 1191e154302SMatthias Ringwald printf("hci_dump_open: failed to open file %s\n", filename); 1201e154302SMatthias Ringwald } 12179662672Smatthias.ringwald } 122eb443d3dSMatthias Ringwald #else 123d0662982SMatthias Ringwald UNUSED(filename); 124d0662982SMatthias Ringwald UNUSED(format); 125d0662982SMatthias Ringwald 126eb443d3dSMatthias Ringwald dump_file = 1; 12768e27c0fSmatthias.ringwald #endif 128d9659922Smatthias.ringwald } 12979662672Smatthias.ringwald 130eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 1312992c131Smatthias.ringwald void hci_dump_set_max_packets(int packets){ 1322992c131Smatthias.ringwald max_nr_packets = packets; 1332992c131Smatthias.ringwald } 1347c5f7483Smatthias.ringwald #endif 1352992c131Smatthias.ringwald 1368a37b10aSMatthias Ringwald static void printf_packet(uint8_t packet_type, uint8_t in, uint8_t * packet, uint16_t len){ 137198a9e1bS[email protected] switch (packet_type){ 138198a9e1bS[email protected] case HCI_COMMAND_DATA_PACKET: 139198a9e1bS[email protected] printf("CMD => "); 140198a9e1bS[email protected] break; 141198a9e1bS[email protected] case HCI_EVENT_PACKET: 142198a9e1bS[email protected] printf("EVT <= "); 143198a9e1bS[email protected] break; 144198a9e1bS[email protected] case HCI_ACL_DATA_PACKET: 145198a9e1bS[email protected] if (in) { 146198a9e1bS[email protected] printf("ACL <= "); 147198a9e1bS[email protected] } else { 148198a9e1bS[email protected] printf("ACL => "); 149198a9e1bS[email protected] } 150198a9e1bS[email protected] break; 1511e154302SMatthias Ringwald case HCI_SCO_DATA_PACKET: 1521e154302SMatthias Ringwald if (in) { 1531e154302SMatthias Ringwald printf("SCO <= "); 1541e154302SMatthias Ringwald } else { 1551e154302SMatthias Ringwald printf("SCO => "); 1561e154302SMatthias Ringwald } 1571e154302SMatthias Ringwald break; 158198a9e1bS[email protected] case LOG_MESSAGE_PACKET: 159198a9e1bS[email protected] printf("LOG -- %s\n", (char*) packet); 160198a9e1bS[email protected] return; 161198a9e1bS[email protected] default: 162198a9e1bS[email protected] return; 163198a9e1bS[email protected] } 164198a9e1bS[email protected] printf_hexdump(packet, len); 165198a9e1bS[email protected] } 166198a9e1bS[email protected] 167ad6274a7SMatthias Ringwald #ifndef HAVE_POSIX_FILE_IO 168ad6274a7SMatthias Ringwald static void printf_timestamp(void){ 169ad6274a7SMatthias Ringwald uint32_t time_ms = btstack_run_loop_get_time_ms(); 170ad6274a7SMatthias Ringwald int seconds = time_ms / 1000; 171ad6274a7SMatthias Ringwald int minutes = seconds / 60; 172f04a0c31SMatthias Ringwald unsigned int hours = minutes / 60; 173ad6274a7SMatthias Ringwald 174f04a0c31SMatthias Ringwald uint16_t p_ms = time_ms - (seconds * 1000); 175f04a0c31SMatthias Ringwald uint16_t p_seconds = seconds - (minutes * 60); 176f04a0c31SMatthias Ringwald uint16_t p_minutes = minutes - (hours * 60); 177ad6274a7SMatthias Ringwald printf("[%02u:%02u:%02u.%03u] ", hours, p_minutes, p_seconds, p_ms); 178ad6274a7SMatthias Ringwald } 179ad6274a7SMatthias Ringwald #endif 180ad6274a7SMatthias Ringwald 18179662672Smatthias.ringwald void hci_dump_packet(uint8_t packet_type, uint8_t in, uint8_t *packet, uint16_t len) { 18268e27c0fSmatthias.ringwald 1838b658ebcSmatthias.ringwald if (dump_file < 0) return; // not activated yet 1848b658ebcSmatthias.ringwald 185eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 186eb443d3dSMatthias Ringwald 1872992c131Smatthias.ringwald // don't grow bigger than max_nr_packets 1882992c131Smatthias.ringwald if (dump_format != HCI_DUMP_STDOUT && max_nr_packets > 0){ 1892992c131Smatthias.ringwald if (nr_packets >= max_nr_packets){ 1902992c131Smatthias.ringwald lseek(dump_file, 0, SEEK_SET); 1912992c131Smatthias.ringwald ftruncate(dump_file, 0); 1922992c131Smatthias.ringwald nr_packets = 0; 1932992c131Smatthias.ringwald } 1942992c131Smatthias.ringwald nr_packets++; 1952992c131Smatthias.ringwald } 1962992c131Smatthias.ringwald 1978b658ebcSmatthias.ringwald // get time 1988b658ebcSmatthias.ringwald struct timeval curr_time; 1998adf0ddaSmatthias.ringwald struct tm* ptm; 2008b658ebcSmatthias.ringwald gettimeofday(&curr_time, NULL); 201d5ea8924S[email protected] time_t curr_time_secs = curr_time.tv_sec; 2028b658ebcSmatthias.ringwald 2038b658ebcSmatthias.ringwald switch (dump_format){ 204a9cf4d77S[email protected] case HCI_DUMP_STDOUT: { 2058adf0ddaSmatthias.ringwald /* Obtain the time of day, and convert it to a tm struct. */ 206d5ea8924S[email protected] ptm = localtime (&curr_time_secs); 2077224be7eSMatthias Ringwald /* assert localtime was successful */ 2087224be7eSMatthias Ringwald if (!ptm) break; 2098adf0ddaSmatthias.ringwald /* Format the date and time, down to a single second. */ 2108adf0ddaSmatthias.ringwald strftime (time_string, sizeof (time_string), "[%Y-%m-%d %H:%M:%S", ptm); 2118adf0ddaSmatthias.ringwald /* Compute milliseconds from microseconds. */ 2128adf0ddaSmatthias.ringwald uint16_t milliseconds = curr_time.tv_usec / 1000; 2137224be7eSMatthias Ringwald /* Print the formatted time, in seconds, followed by a decimal point and the milliseconds. */ 2148adf0ddaSmatthias.ringwald printf ("%s.%03u] ", time_string, milliseconds); 215198a9e1bS[email protected] printf_packet(packet_type, in, packet, len); 2168adf0ddaSmatthias.ringwald break; 217a9cf4d77S[email protected] } 2180d79c710Smatthias.ringwald 2198b658ebcSmatthias.ringwald case HCI_DUMP_BLUEZ: 220f8fbdce0SMatthias Ringwald little_endian_store_16( header_bluez, 0, 1 + len); 2211a1c8389SMatthias Ringwald header_bluez[2] = in; 2221a1c8389SMatthias Ringwald header_bluez[3] = 0; 2237c959318SMatthias Ringwald little_endian_store_32( header_bluez, 4, (uint32_t) curr_time.tv_sec); 224f8fbdce0SMatthias Ringwald little_endian_store_32( header_bluez, 8, curr_time.tv_usec); 2251a1c8389SMatthias Ringwald header_bluez[12] = packet_type; 226f3e036dcSMatthias Ringwald write (dump_file, header_bluez, HCIDUMP_HDR_SIZE); 22779662672Smatthias.ringwald write (dump_file, packet, len ); 2288b658ebcSmatthias.ringwald break; 2290d79c710Smatthias.ringwald 2308b658ebcSmatthias.ringwald case HCI_DUMP_PACKETLOGGER: 231f8fbdce0SMatthias Ringwald big_endian_store_32( header_packetlogger, 0, PKTLOG_HDR_SIZE - 4 + len); 2327c959318SMatthias Ringwald big_endian_store_32( header_packetlogger, 4, (uint32_t) curr_time.tv_sec); 233f8fbdce0SMatthias Ringwald big_endian_store_32( header_packetlogger, 8, curr_time.tv_usec); 2348b658ebcSmatthias.ringwald switch (packet_type){ 2358b658ebcSmatthias.ringwald case HCI_COMMAND_DATA_PACKET: 2361a1c8389SMatthias Ringwald header_packetlogger[12] = 0x00; 2378b658ebcSmatthias.ringwald break; 2388b658ebcSmatthias.ringwald case HCI_ACL_DATA_PACKET: 2398b658ebcSmatthias.ringwald if (in) { 2401a1c8389SMatthias Ringwald header_packetlogger[12] = 0x03; 2418b658ebcSmatthias.ringwald } else { 2421a1c8389SMatthias Ringwald header_packetlogger[12] = 0x02; 2438b658ebcSmatthias.ringwald } 2448b658ebcSmatthias.ringwald break; 2458d675e3dS[email protected] case HCI_SCO_DATA_PACKET: 2468d675e3dS[email protected] if (in) { 2471a1c8389SMatthias Ringwald header_packetlogger[12] = 0x09; 2488d675e3dS[email protected] } else { 2491a1c8389SMatthias Ringwald header_packetlogger[12] = 0x08; 2508d675e3dS[email protected] } 2518d675e3dS[email protected] break; 2528b658ebcSmatthias.ringwald case HCI_EVENT_PACKET: 2531a1c8389SMatthias Ringwald header_packetlogger[12] = 0x01; 2548b658ebcSmatthias.ringwald break; 2550d79c710Smatthias.ringwald case LOG_MESSAGE_PACKET: 2561a1c8389SMatthias Ringwald header_packetlogger[12] = 0xfc; 2570d79c710Smatthias.ringwald break; 2588b658ebcSmatthias.ringwald default: 2598b658ebcSmatthias.ringwald return; 2608b658ebcSmatthias.ringwald } 261f3e036dcSMatthias Ringwald write (dump_file, &header_packetlogger, PKTLOG_HDR_SIZE); 2628b658ebcSmatthias.ringwald write (dump_file, packet, len ); 2630d79c710Smatthias.ringwald break; 2640d79c710Smatthias.ringwald 2650d79c710Smatthias.ringwald default: 2660d79c710Smatthias.ringwald break; 2678b658ebcSmatthias.ringwald } 268eb443d3dSMatthias Ringwald #else 269eb443d3dSMatthias Ringwald 270ad6274a7SMatthias Ringwald printf_timestamp(); 271eb443d3dSMatthias Ringwald printf_packet(packet_type, in, packet, len); 272eb443d3dSMatthias Ringwald 27368e27c0fSmatthias.ringwald #endif 27479662672Smatthias.ringwald } 27579662672Smatthias.ringwald 2768a37b10aSMatthias Ringwald static int hci_dump_log_level_active(int log_level){ 2778a37b10aSMatthias Ringwald if (log_level < 0) return 0; 2788a37b10aSMatthias Ringwald if (log_level > LOG_LEVEL_ERROR) return 0; 2798a37b10aSMatthias Ringwald return log_level_enabled[log_level]; 2808a37b10aSMatthias Ringwald } 2818a37b10aSMatthias Ringwald 28294be1a66SMatthias Ringwald void hci_dump_log_va_arg(int log_level, const char * format, va_list argptr){ 28394be1a66SMatthias Ringwald if (hci_dump_log_level_active(log_level)) { 284eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 285eb443d3dSMatthias Ringwald int len = vsnprintf(log_message_buffer, sizeof(log_message_buffer), format, argptr); 286eb443d3dSMatthias Ringwald hci_dump_packet(LOG_MESSAGE_PACKET, 0, (uint8_t*) log_message_buffer, len); 287eb443d3dSMatthias Ringwald #else 288ad6274a7SMatthias Ringwald printf_timestamp(); 2891df3b679S[email protected] printf("LOG -- "); 2901df3b679S[email protected] vprintf(format, argptr); 2911fd51e45S[email protected] printf("\n"); 292a1d7dd1fSmatthias.ringwald #endif 29394be1a66SMatthias Ringwald } 29494be1a66SMatthias Ringwald } 29594be1a66SMatthias Ringwald 29694be1a66SMatthias Ringwald void hci_dump_log(int log_level, const char * format, ...){ 29794be1a66SMatthias Ringwald va_list argptr; 29894be1a66SMatthias Ringwald va_start(argptr, format); 29994be1a66SMatthias Ringwald hci_dump_log_va_arg(log_level, format, argptr); 3001df3b679S[email protected] va_end(argptr); 301a1d7dd1fSmatthias.ringwald } 302a1d7dd1fSmatthias.ringwald 30320ea11b9S[email protected] #ifdef __AVR__ 3048a37b10aSMatthias Ringwald void hci_dump_log_P(int log_level, PGM_P format, ...){ 3058a37b10aSMatthias Ringwald if (!hci_dump_log_level_active(log_level)) return; 30620ea11b9S[email protected] va_list argptr; 30720ea11b9S[email protected] va_start(argptr, format); 30820ea11b9S[email protected] printf_P(PSTR("LOG -- ")); 30920ea11b9S[email protected] vfprintf_P(stdout, format, argptr); 31020ea11b9S[email protected] printf_P(PSTR("\n")); 31120ea11b9S[email protected] va_end(argptr); 31220ea11b9S[email protected] } 31320ea11b9S[email protected] #endif 31420ea11b9S[email protected] 31571de195eSMatthias Ringwald void hci_dump_close(void){ 316eb443d3dSMatthias Ringwald #ifdef HAVE_POSIX_FILE_IO 31779662672Smatthias.ringwald close(dump_file); 31868e27c0fSmatthias.ringwald #endif 319eb443d3dSMatthias Ringwald dump_file = -1; 32079662672Smatthias.ringwald } 32179662672Smatthias.ringwald 3228a37b10aSMatthias Ringwald void hci_dump_enable_log_level(int log_level, int enable){ 3238a37b10aSMatthias Ringwald if (log_level < 0) return; 3248a37b10aSMatthias Ringwald if (log_level > LOG_LEVEL_ERROR) return; 3258a37b10aSMatthias Ringwald log_level_enabled[log_level] = enable; 3268a37b10aSMatthias Ringwald } 3278a37b10aSMatthias Ringwald 328