xref: /btstack/src/hci_dump.c (revision f9f2075ceac5e9dc08e9abea437e43d733a3a0ea)
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 /*
39  *  hci_dump.c
40  *
41  *  Dump HCI trace in various formats:
42  *
43  *  - BlueZ's hcidump format
44  *  - Apple's PacketLogger
45  *  - stdout hexdump
46  *
47  *  Created by Matthias Ringwald on 5/26/09.
48  */
49 
50 #include "btstack_config.h"
51 
52 #include "hci_dump.h"
53 #include "hci.h"
54 #include "hci_transport.h"
55 #include "hci_cmd.h"
56 #include "btstack_run_loop.h"
57 #include <stdio.h>
58 
59 #ifdef HAVE_POSIX_FILE_IO
60 #include <fcntl.h>        // open
61 #include <unistd.h>       // write
62 #include <time.h>
63 #include <sys/time.h>     // for timestamps
64 #include <sys/stat.h>     // for mode flags
65 #endif
66 
67 // BLUEZ hcidump - struct not used directly, but left here as documentation
68 typedef struct {
69     uint16_t    len;
70     uint8_t     in;
71     uint8_t     pad;
72     uint32_t    ts_sec;
73     uint32_t    ts_usec;
74     uint8_t     packet_type;
75 }
76 hcidump_hdr;
77 #define HCIDUMP_HDR_SIZE 13
78 
79 // APPLE PacketLogger - struct not used directly, but left here as documentation
80 typedef struct {
81     uint32_t    len;
82     uint32_t    ts_sec;
83     uint32_t    ts_usec;
84     uint8_t     type;   // 0xfc for note
85 }
86 pktlog_hdr;
87 #define PKTLOG_HDR_SIZE 13
88 
89 static int dump_file = -1;
90 #ifdef HAVE_POSIX_FILE_IO
91 static int dump_format;
92 static uint8_t header_bluez[HCIDUMP_HDR_SIZE];
93 static uint8_t header_packetlogger[PKTLOG_HDR_SIZE];
94 static char time_string[40];
95 static int  max_nr_packets = -1;
96 static int  nr_packets = 0;
97 static char log_message_buffer[256];
98 #endif
99 
100 // levels: debug, info, error
101 static int log_level_enabled[3] = { 1, 1, 1};
102 
103 void hci_dump_open(const char *filename, hci_dump_format_t format){
104 #ifdef HAVE_POSIX_FILE_IO
105     dump_format = format;
106     if (dump_format == HCI_DUMP_STDOUT) {
107         dump_file = fileno(stdout);
108     } else {
109 
110         int oflags = O_WRONLY | O_CREAT | O_TRUNC;
111 #ifdef _WIN32
112         oflags |= O_BINARY;
113 #endif
114 
115         dump_file = open(filename, oflags, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH );
116         if (dump_file < 0){
117             printf("hci_dump_open: failed to open file %s\n", filename);
118         }
119     }
120 #else
121     UNUSED(filename);
122     UNUSED(format);
123 
124     dump_file = 1;
125 #endif
126 }
127 
128 #ifdef HAVE_POSIX_FILE_IO
129 void hci_dump_set_max_packets(int packets){
130     max_nr_packets = packets;
131 }
132 #endif
133 
134 static void printf_packet(uint8_t packet_type, uint8_t in, uint8_t * packet, uint16_t len){
135     switch (packet_type){
136         case HCI_COMMAND_DATA_PACKET:
137             printf("CMD => ");
138             break;
139         case HCI_EVENT_PACKET:
140             printf("EVT <= ");
141             break;
142         case HCI_ACL_DATA_PACKET:
143             if (in) {
144                 printf("ACL <= ");
145             } else {
146                 printf("ACL => ");
147             }
148             break;
149         case HCI_SCO_DATA_PACKET:
150             if (in) {
151                 printf("SCO <= ");
152             } else {
153                 printf("SCO => ");
154             }
155             break;
156         case LOG_MESSAGE_PACKET:
157             printf("LOG -- %s\n", (char*) packet);
158             return;
159         default:
160             return;
161     }
162     printf_hexdump(packet, len);
163 }
164 
165 #ifndef HAVE_POSIX_FILE_IO
166 static void printf_timestamp(void){
167     uint32_t time_ms = btstack_run_loop_get_time_ms();
168     int      seconds = time_ms / 1000;
169     int      minutes = seconds / 60;
170     unsigned int hours   = minutes / 60;
171 
172     uint16_t p_ms      = time_ms - (seconds * 1000);
173     uint16_t p_seconds = seconds - (minutes * 60);
174     uint16_t p_minutes = minutes - (hours   * 60);
175     printf("[%02u:%02u:%02u.%03u] ", hours, p_minutes, p_seconds, p_ms);
176 }
177 #endif
178 
179 void hci_dump_packet(uint8_t packet_type, uint8_t in, uint8_t *packet, uint16_t len) {
180 
181     if (dump_file < 0) return; // not activated yet
182 
183 #ifdef HAVE_POSIX_FILE_IO
184 
185     // don't grow bigger than max_nr_packets
186     if (dump_format != HCI_DUMP_STDOUT && max_nr_packets > 0){
187         if (nr_packets >= max_nr_packets){
188             lseek(dump_file, 0, SEEK_SET);
189             ftruncate(dump_file, 0);
190             nr_packets = 0;
191         }
192         nr_packets++;
193     }
194 
195     // get time
196     struct timeval curr_time;
197     struct tm* ptm;
198     gettimeofday(&curr_time, NULL);
199     time_t curr_time_secs = curr_time.tv_sec;
200 
201     switch (dump_format){
202         case HCI_DUMP_STDOUT: {
203             /* Obtain the time of day, and convert it to a tm struct. */
204             ptm = localtime (&curr_time_secs);
205             /* assert localtime was successful */
206             if (!ptm) break;
207             /* Format the date and time, down to a single second. */
208             strftime (time_string, sizeof (time_string), "[%Y-%m-%d %H:%M:%S", ptm);
209             /* Compute milliseconds from microseconds. */
210             uint16_t milliseconds = curr_time.tv_usec / 1000;
211             /* Print the formatted time, in seconds, followed by a decimal point and the milliseconds. */
212             printf ("%s.%03u] ", time_string, milliseconds);
213             printf_packet(packet_type, in, packet, len);
214             break;
215         }
216 
217         case HCI_DUMP_BLUEZ:
218             little_endian_store_16( header_bluez, 0, 1 + len);
219             header_bluez[2] = in;
220             header_bluez[3] = 0;
221             little_endian_store_32( header_bluez, 4, (uint32_t) curr_time.tv_sec);
222             little_endian_store_32( header_bluez, 8,            curr_time.tv_usec);
223             header_bluez[12] = packet_type;
224             write (dump_file, header_bluez, HCIDUMP_HDR_SIZE);
225             write (dump_file, packet, len );
226             break;
227 
228         case HCI_DUMP_PACKETLOGGER:
229             big_endian_store_32( header_packetlogger, 0, PKTLOG_HDR_SIZE - 4 + len);
230             big_endian_store_32( header_packetlogger, 4,  (uint32_t) curr_time.tv_sec);
231             big_endian_store_32( header_packetlogger, 8, curr_time.tv_usec);
232             switch (packet_type){
233                 case HCI_COMMAND_DATA_PACKET:
234                     header_packetlogger[12] = 0x00;
235                     break;
236                 case HCI_ACL_DATA_PACKET:
237                     if (in) {
238                         header_packetlogger[12] = 0x03;
239                     } else {
240                         header_packetlogger[12] = 0x02;
241                     }
242                     break;
243                 case HCI_SCO_DATA_PACKET:
244                     if (in) {
245                         header_packetlogger[12] = 0x09;
246                     } else {
247                         header_packetlogger[12] = 0x08;
248                     }
249                     break;
250                 case HCI_EVENT_PACKET:
251                     header_packetlogger[12] = 0x01;
252                     break;
253                 case LOG_MESSAGE_PACKET:
254                     header_packetlogger[12] = 0xfc;
255                     break;
256                 default:
257                     return;
258             }
259             write (dump_file, &header_packetlogger, PKTLOG_HDR_SIZE);
260             write (dump_file, packet, len );
261             break;
262 
263         default:
264             break;
265     }
266 #else
267 
268     printf_timestamp();
269     printf_packet(packet_type, in, packet, len);
270 
271 #endif
272 }
273 
274 static int hci_dump_log_level_active(int log_level){
275     if (log_level < 0) return 0;
276     if (log_level > LOG_LEVEL_ERROR) return 0;
277     return log_level_enabled[log_level];
278 }
279 
280 void hci_dump_log_va_arg(int log_level, const char * format, va_list argptr){
281     if (hci_dump_log_level_active(log_level)) {
282 #ifdef HAVE_POSIX_FILE_IO
283         int len = vsnprintf(log_message_buffer, sizeof(log_message_buffer), format, argptr);
284         hci_dump_packet(LOG_MESSAGE_PACKET, 0, (uint8_t*) log_message_buffer, len);
285 #else
286         printf_timestamp();
287         printf("LOG -- ");
288         vprintf(format, argptr);
289         printf("\n");
290 #endif
291     }
292 }
293 
294 void hci_dump_log(int log_level, const char * format, ...){
295     va_list argptr;
296     va_start(argptr, format);
297     hci_dump_log_va_arg(log_level, format, argptr);
298     va_end(argptr);
299 }
300 
301 #ifdef __AVR__
302 void hci_dump_log_P(int log_level, PGM_P format, ...){
303     if (!hci_dump_log_level_active(log_level)) return;
304     va_list argptr;
305     va_start(argptr, format);
306     printf_P(PSTR("LOG -- "));
307     vfprintf_P(stdout, format, argptr);
308     printf_P(PSTR("\n"));
309     va_end(argptr);
310 }
311 #endif
312 
313 void hci_dump_close(void){
314 #ifdef HAVE_POSIX_FILE_IO
315     close(dump_file);
316 #endif
317     dump_file = -1;
318 }
319 
320 void hci_dump_enable_log_level(int log_level, int enable){
321     if (log_level < 0) return;
322     if (log_level > LOG_LEVEL_ERROR) return;
323     log_level_enabled[log_level] = enable;
324 }
325 
326