hci_dump.c (acb15818d50b860e14489f68a6237686091b95b9) hci_dump.c (5fa31a9940804989b94f828b5982860dcb81c77d)
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

--- 32 unchanged lines hidden (view full) ---

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 *
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

--- 32 unchanged lines hidden (view full) ---

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 * Created by Matthias Ringwald on 5/26/09.
50 */
51
52#include "btstack_config.h"
53
54// enable POSIX functions (needed for -std=c99)
55#define _POSIX_C_SOURCE 200809
56
57#include "hci_dump.h"

--- 6 unchanged lines hidden (view full) ---

64#ifdef HAVE_POSIX_FILE_IO
65#include <fcntl.h> // open
66#include <unistd.h> // write
67#include <time.h>
68#include <sys/time.h> // for timestamps
69#include <sys/stat.h> // for mode flags
70#endif
71
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"

--- 6 unchanged lines hidden (view full) ---

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"
73static char channel1_out[1024];
74#endif
75
72// BLUEZ hcidump - struct not used directly, but left here as documentation
73typedef struct {
74 uint16_t len;
75 uint8_t in;
76 uint8_t pad;
77 uint32_t ts_sec;
78 uint32_t ts_usec;
79 uint8_t packet_type;

--- 7 unchanged lines hidden (view full) ---

87 uint32_t ts_sec;
88 uint32_t ts_usec;
89 uint8_t type; // 0xfc for note
90}
91pktlog_hdr;
92#define PKTLOG_HDR_SIZE 13
93
94static int dump_file = -1;
76// BLUEZ hcidump - struct not used directly, but left here as documentation
77typedef 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;

--- 7 unchanged lines hidden (view full) ---

91 uint32_t ts_sec;
92 uint32_t ts_usec;
93 uint8_t type; // 0xfc for note
94}
95pktlog_hdr;
96#define PKTLOG_HDR_SIZE 13
97
98static int dump_file = -1;
95#ifdef HAVE_POSIX_FILE_IO
96static int dump_format;
99static int dump_format;
97static uint8_t header_bluez[HCIDUMP_HDR_SIZE];
98static uint8_t header_packetlogger[PKTLOG_HDR_SIZE];
100static 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
99static char time_string[40];
100static int max_nr_packets = -1;
101static int nr_packets = 0;
102static char log_message_buffer[256];
103#endif
104
105// levels: debug, info, error
106static int log_level_enabled[3] = { 1, 1, 1};
107
108void hci_dump_open(const char *filename, hci_dump_format_t format){
105static char time_string[40];
106static int max_nr_packets = -1;
107static int nr_packets = 0;
108static char log_message_buffer[256];
109#endif
110
111// levels: debug, info, error
112static int log_level_enabled[3] = { 1, 1, 1};
113
114void hci_dump_open(const char *filename, hci_dump_format_t format){
109#ifdef HAVE_POSIX_FILE_IO
115
110 dump_format = format;
116 dump_format = format;
117
118#ifdef HAVE_POSIX_FILE_IO
111 if (dump_format == HCI_DUMP_STDOUT) {
112 dump_file = fileno(stdout);
113 } else {
114
115 int oflags = O_WRONLY | O_CREAT | O_TRUNC;
116#ifdef _WIN32
117 oflags |= O_BINARY;
118#endif
119 if (dump_format == HCI_DUMP_STDOUT) {
120 dump_file = fileno(stdout);
121 } else {
122
123 int oflags = O_WRONLY | O_CREAT | O_TRUNC;
124#ifdef _WIN32
125 oflags |= O_BINARY;
126#endif
119
120 dump_file = open(filename, oflags, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH );
121 if (dump_file < 0){
122 printf("hci_dump_open: failed to open file %s\n", filename);
123 }
124 }
125#else
127 dump_file = open(filename, oflags, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH );
128 if (dump_file < 0){
129 printf("hci_dump_open: failed to open file %s\n", filename);
130 }
131 }
132#else
133
126 UNUSED(filename);
134 UNUSED(filename);
127 UNUSED(format);
135
136#ifdef ENABLE_SEGGER_RTT
137 switch (dump_format){
138 case HCI_DUMP_PACKETLOGGER:
139 case HCI_DUMP_BLUEZ:
140 // Configure up channel 1, options:
141 // - SEGGER_RTT_MODE_NO_BLOCK_SKIP
142 // - SEGGER_RTT_MODE_BLOCK_IF_FIFO_FULL
143 // Note: with SEGGER_RTT_MODE_BLOCK_IF_FIFO_FULL, firwmware will hang if RTT not supported/debug probe not connected
144 // Note: with SEGGER_RTT_MODE_NO_BLOCK_SKIP, there's a chance for log file corruption if second write (packet) is skipped
145 SEGGER_RTT_ConfigUpBuffer(1, "hci_dump", &channel1_out[0], sizeof(channel1_out), SEGGER_RTT_MODE_NO_BLOCK_SKIP) ;;
146 break;
147 default:
148 break;
149 }
150#endif
128
129 dump_file = 1;
130#endif
131}
132
133#ifdef HAVE_POSIX_FILE_IO
134void hci_dump_set_max_packets(int packets){
135 max_nr_packets = packets;
136}
137#endif
138
151
152 dump_file = 1;
153#endif
154}
155
156#ifdef HAVE_POSIX_FILE_IO
157void hci_dump_set_max_packets(int packets){
158 max_nr_packets = packets;
159}
160#endif
161
162static 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){
163 big_endian_store_32( buffer, 0, PKTLOG_HDR_SIZE - 4 + len);
164 big_endian_store_32( buffer, 4, tv_sec);
165 big_endian_store_32( buffer, 8, tv_us);
166 uint8_t packet_logger_type = 0;
167 switch (packet_type){
168 case HCI_COMMAND_DATA_PACKET:
169 packet_logger_type = 0x00;
170 break;
171 case HCI_ACL_DATA_PACKET:
172 packet_logger_type = in ? 0x03 : 0x02;
173 break;
174 case HCI_SCO_DATA_PACKET:
175 packet_logger_type = in ? 0x09 : 0x08;
176 break;
177 case HCI_EVENT_PACKET:
178 packet_logger_type = 0x01;
179 break;
180 case LOG_MESSAGE_PACKET:
181 packet_logger_type = 0xfc;
182 break;
183 default:
184 return;
185 }
186 buffer[12] = packet_logger_type;
187}
188
189static 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){
190 little_endian_store_16( buffer, 0, 1 + len);
191 buffer[2] = in;
192 buffer[3] = 0;
193 little_endian_store_32( buffer, 4, tv_sec);
194 little_endian_store_32( buffer, 8, tv_us);
195 buffer[12] = packet_type;
196}
197
139static void printf_packet(uint8_t packet_type, uint8_t in, uint8_t * packet, uint16_t len){
140 switch (packet_type){
141 case HCI_COMMAND_DATA_PACKET:
142 printf("CMD => ");
143 break;
144 case HCI_EVENT_PACKET:
145 printf("EVT <= ");
146 break;

--- 35 unchanged lines hidden (view full) ---

182 /* Compute milliseconds from microseconds. */
183 uint16_t milliseconds = curr_time.tv_usec / 1000;
184 /* Print the formatted time, in seconds, followed by a decimal point and the milliseconds. */
185 printf ("%s.%03u] ", time_string, milliseconds);
186#else
187 uint32_t time_ms = btstack_run_loop_get_time_ms();
188 int seconds = time_ms / 1000;
189 int minutes = seconds / 60;
198static void printf_packet(uint8_t packet_type, uint8_t in, uint8_t * packet, uint16_t len){
199 switch (packet_type){
200 case HCI_COMMAND_DATA_PACKET:
201 printf("CMD => ");
202 break;
203 case HCI_EVENT_PACKET:
204 printf("EVT <= ");
205 break;

--- 35 unchanged lines hidden (view full) ---

241 /* Compute milliseconds from microseconds. */
242 uint16_t milliseconds = curr_time.tv_usec / 1000;
243 /* Print the formatted time, in seconds, followed by a decimal point and the milliseconds. */
244 printf ("%s.%03u] ", time_string, milliseconds);
245#else
246 uint32_t time_ms = btstack_run_loop_get_time_ms();
247 int seconds = time_ms / 1000;
248 int minutes = seconds / 60;
190 unsigned int hours = minutes / 60;
249 unsigned int hours = minutes / 60;
191
192 uint16_t p_ms = time_ms - (seconds * 1000);
193 uint16_t p_seconds = seconds - (minutes * 60);
194 uint16_t p_minutes = minutes - (hours * 60);
195 printf("[%02u:%02u:%02u.%03u] ", hours, p_minutes, p_seconds, p_ms);
196#endif
197}
198
199void hci_dump_packet(uint8_t packet_type, uint8_t in, uint8_t *packet, uint16_t len) {
200
201 if (dump_file < 0) return; // not activated yet
202
203#ifdef HAVE_POSIX_FILE_IO
250
251 uint16_t p_ms = time_ms - (seconds * 1000);
252 uint16_t p_seconds = seconds - (minutes * 60);
253 uint16_t p_minutes = minutes - (hours * 60);
254 printf("[%02u:%02u:%02u.%03u] ", hours, p_minutes, p_seconds, p_ms);
255#endif
256}
257
258void hci_dump_packet(uint8_t packet_type, uint8_t in, uint8_t *packet, uint16_t len) {
259
260 if (dump_file < 0) return; // not activated yet
261
262#ifdef HAVE_POSIX_FILE_IO
204
205 // don't grow bigger than max_nr_packets
206 if (dump_format != HCI_DUMP_STDOUT && max_nr_packets > 0){
207 if (nr_packets >= max_nr_packets){
208 lseek(dump_file, 0, SEEK_SET);
209 // avoid -Wunused-result
210 int res = ftruncate(dump_file, 0);
211 UNUSED(res);
212 nr_packets = 0;
213 }
214 nr_packets++;
215 }
263 // don't grow bigger than max_nr_packets
264 if (dump_format != HCI_DUMP_STDOUT && max_nr_packets > 0){
265 if (nr_packets >= max_nr_packets){
266 lseek(dump_file, 0, SEEK_SET);
267 // avoid -Wunused-result
268 int res = ftruncate(dump_file, 0);
269 UNUSED(res);
270 nr_packets = 0;
271 }
272 nr_packets++;
273 }
216
274#endif
275
276 if (dump_format == HCI_DUMP_STDOUT){
277 printf_timestamp();
278 printf_packet(packet_type, in, packet, len);
279 return;
280 }
281
282 uint32_t tv_sec = 0;
283 uint32_t tv_us = 0;
284
217 // get time
285 // get time
286#ifdef HAVE_POSIX_FILE_IO
218 struct timeval curr_time;
219 gettimeofday(&curr_time, NULL);
287 struct timeval curr_time;
288 gettimeofday(&curr_time, NULL);
289 tv_sec = curr_time.tv_sec;
290 tv_us = curr_time.tv_usec;
291#else
292 uint32_t time_ms = btstack_run_loop_get_time_ms();
293 tv_us = time_ms * 1000;
294 tv_sec = 946728000UL + (time_ms / 1000);
295#endif
220
296
221 // avoid -Wunused-result
222 int res = 0;
297 uint16_t header_len = 0;
223 switch (dump_format){
298 switch (dump_format){
224 case HCI_DUMP_STDOUT: {
225 printf_timestamp();
226 printf_packet(packet_type, in, packet, len);
227 break;
228 }
229
230 case HCI_DUMP_BLUEZ:
299 case HCI_DUMP_BLUEZ:
231 little_endian_store_16( header_bluez, 0, 1 + len);
232 header_bluez[2] = in;
233 header_bluez[3] = 0;
234 little_endian_store_32( header_bluez, 4, (uint32_t) curr_time.tv_sec);
235 little_endian_store_32( header_bluez, 8, curr_time.tv_usec);
236 header_bluez[12] = packet_type;
237 res = write (dump_file, header_bluez, HCIDUMP_HDR_SIZE);
238 res = write (dump_file, packet, len );
300 hci_dump_bluez_setup_header(header.header_bluez, tv_sec, tv_us, packet_type, in, len);
301 header_len = HCIDUMP_HDR_SIZE;
239 break;
302 break;
240
241 case HCI_DUMP_PACKETLOGGER:
303 case HCI_DUMP_PACKETLOGGER:
242 big_endian_store_32( header_packetlogger, 0, PKTLOG_HDR_SIZE - 4 + len);
243 big_endian_store_32( header_packetlogger, 4, (uint32_t) curr_time.tv_sec);
244 big_endian_store_32( header_packetlogger, 8, curr_time.tv_usec);
245 switch (packet_type){
246 case HCI_COMMAND_DATA_PACKET:
247 header_packetlogger[12] = 0x00;
248 break;
249 case HCI_ACL_DATA_PACKET:
250 if (in) {
251 header_packetlogger[12] = 0x03;
252 } else {
253 header_packetlogger[12] = 0x02;
254 }
255 break;
256 case HCI_SCO_DATA_PACKET:
257 if (in) {
258 header_packetlogger[12] = 0x09;
259 } else {
260 header_packetlogger[12] = 0x08;
261 }
262 break;
263 case HCI_EVENT_PACKET:
264 header_packetlogger[12] = 0x01;
265 break;
266 case LOG_MESSAGE_PACKET:
267 header_packetlogger[12] = 0xfc;
268 break;
269 default:
270 return;
271 }
272 res = write (dump_file, &header_packetlogger, PKTLOG_HDR_SIZE);
273 res = write (dump_file, packet, len );
304 hci_dump_packetlogger_setup_header(header.header_packetlogger, tv_sec, tv_us, packet_type, in, len);
305 header_len = PKTLOG_HDR_SIZE;
274 break;
306 break;
275
276 default:
307 default:
277 break;
308 return;
278 }
309 }
279 UNUSED(res);
280#else
281
310
282 printf_timestamp();
283 printf_packet(packet_type, in, packet, len);
284
311#ifdef HAVE_POSIX_FILE_IO
312 // avoid -Wunused-result
313 int res = 0;
314 res = write (dump_file, &header, header_len);
315 res = write (dump_file, packet, len );
316 UNUSED(res);
285#endif
317#endif
318#ifdef ENABLE_SEGGER_RTT
319 SEGGER_RTT_Write(1, &header, header_len);
320 SEGGER_RTT_Write(1, packet, len);
321#endif
322 UNUSED(header_len);
286}
287
288static int hci_dump_log_level_active(int log_level){
289 if (log_level < HCI_DUMP_LOG_LEVEL_DEBUG) return 0;
290 if (log_level > HCI_DUMP_LOG_LEVEL_ERROR) return 0;
291 return log_level_enabled[log_level];
292}
293

--- 49 unchanged lines hidden --- 		323}
324
325static int hci_dump_log_level_active(int log_level){
326 if (log_level < HCI_DUMP_LOG_LEVEL_DEBUG) return 0;
327 if (log_level > HCI_DUMP_LOG_LEVEL_ERROR) return 0;
328 return log_level_enabled[log_level];
329}
330

--- 49 unchanged lines hidden ---