1 /******************************************************************************
2 *
3 * Copyright 2014 Google, Inc.
4 *
5 * Licensed under the Apache License, Version 2.0 (the "License");
6 * you may not use this file except in compliance with the License.
7 * You may obtain a copy of the License at:
8 *
9 * http://www.apache.org/licenses/LICENSE-2.0
10 *
11 * Unless required by applicable law or agreed to in writing, software
12 * distributed under the License is distributed on an "AS IS" BASIS,
13 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14 * See the License for the specific language governing permissions and
15 * limitations under the License.
16 *
17 ******************************************************************************/
18
19 #define LOG_TAG "bt_hci"
20
21 #include "hci_layer.h"
22
23 #include <base/bind.h>
24 #include <base/logging.h>
25 #include <base/run_loop.h>
26 #include <base/sequenced_task_runner.h>
27 #include <base/threading/thread.h>
28 #include <frameworks/proto_logging/stats/enums/bluetooth/hci/enums.pb.h>
29
30 #include <signal.h>
31 #include <string.h>
32 #include <sys/types.h>
33 #include <unistd.h>
34
35 #include <chrono>
36 #include <mutex>
37
38 #include "btcore/include/module.h"
39 #include "btif/include/btif_bqr.h"
40 #include "btsnoop.h"
41 #include "buffer_allocator.h"
42 #include "common/message_loop_thread.h"
43 #include "common/metrics.h"
44 #include "common/once_timer.h"
45 #include "common/stop_watch_legacy.h"
46 #include "hci_inject.h"
47 #include "hci_internals.h"
48 #include "hcidefs.h"
49 #include "hcimsgs.h"
50 #include "main/shim/shim.h"
51 #include "osi/include/alarm.h"
52 #include "osi/include/list.h"
53 #include "osi/include/log.h"
54 #include "osi/include/properties.h"
55 #include "osi/include/reactor.h"
56 #include "packet_fragmenter.h"
57
58 #define BT_HCI_TIMEOUT_TAG_NUM 1010000
59
60 using bluetooth::common::MessageLoopThread;
61 using bluetooth::common::OnceTimer;
62 using bluetooth::common::StopWatchLegacy;
63
64 extern void hci_initialize();
65 extern void hci_transmit(BT_HDR* packet);
66 extern void hci_close();
67 extern int hci_open_firmware_log_file();
68 extern void hci_close_firmware_log_file(int fd);
69 extern void hci_log_firmware_debug_packet(int fd, BT_HDR* packet);
70
71 static int hci_firmware_log_fd = INVALID_FD;
72
73 typedef struct {
74 uint16_t opcode;
75 future_t* complete_future;
76 command_complete_cb complete_callback;
77 command_status_cb status_callback;
78 void* context;
79 BT_HDR* command;
80 std::chrono::time_point<std::chrono::steady_clock> timestamp;
81 } waiting_command_t;
82
83 // Using a define here, because it can be stringified for the property lookup
84 // Default timeout should be less than BLE_START_TIMEOUT and
85 // having less than 3 sec would hold the wakelock for init
86 #define DEFAULT_STARTUP_TIMEOUT_MS 2900
87 #define STRING_VALUE_OF(x) #x
88
89 // Abort if there is no response to an HCI command.
90 static const uint32_t COMMAND_PENDING_TIMEOUT_MS = 2000;
91 static const uint32_t COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS = 500;
92 static const uint32_t COMMAND_TIMEOUT_RESTART_MS = 5000;
93 static const uint32_t ROOT_INFLAMMED_RESTART_MS = 5000;
94 [[maybe_unused]] constexpr int HCI_UNKNOWN_COMMAND_TIMED_OUT = 0x00ffffff;
95 [[maybe_unused]] constexpr int HCI_STARTUP_TIMED_OUT = 0x00eeeeee;
96
97 // Our interface
98 static bool interface_created;
99 static hci_t interface;
100
101 // Modules we import and callbacks we export
102 static const allocator_t* buffer_allocator;
103 static const btsnoop_t* btsnoop;
104 static const packet_fragmenter_t* packet_fragmenter;
105
106 static future_t* startup_future;
107 static MessageLoopThread hci_thread("bt_hci_thread");
108
109 static alarm_t* startup_timer;
110
111 // Outbound-related
112 static int command_credits = 1;
113 static std::mutex command_credits_mutex;
114 static std::queue<base::Closure> command_queue;
115
116 // Inbound-related
117 static alarm_t* command_response_timer;
118 static list_t* commands_pending_response;
119 static std::recursive_timed_mutex commands_pending_response_mutex;
120 static OnceTimer abort_timer;
121
122 // Root inflammation error codes
123 static uint8_t root_inflamed_error_code = 0;
124 static uint8_t root_inflamed_vendor_error_code = 0;
125
126 // The hand-off point for data going to a higher layer, set by the higher layer
127 static base::Callback<void(const base::Location&, BT_HDR*)> send_data_upwards;
128
129 static bool filter_incoming_event(BT_HDR* packet);
130 static waiting_command_t* get_waiting_command(command_opcode_t opcode);
131 static int get_num_waiting_commands();
132
133 static void hci_root_inflamed_abort();
134 static void hci_timeout_abort(void);
135 static void event_finish_startup(void* context);
136 static void startup_timer_expired(void* context);
137
138 static void enqueue_command(waiting_command_t* wait_entry);
139 static void event_command_ready(waiting_command_t* wait_entry);
140 static void enqueue_packet(void* packet);
141 static void event_packet_ready(void* packet);
142 static void command_timed_out(void* context);
143
144 static void update_command_response_timer(void);
145
146 static void transmit_fragment(BT_HDR* packet, bool send_transmit_finished);
147 static void dispatch_reassembled(BT_HDR* packet);
148 static void fragmenter_transmit_finished(BT_HDR* packet,
149 bool all_fragments_sent);
150 static bool filter_bqr_event(int16_t bqr_parameter_length,
151 uint8_t* p_bqr_event);
152
153 static const packet_fragmenter_callbacks_t packet_fragmenter_callbacks = {
154 transmit_fragment, dispatch_reassembled, fragmenter_transmit_finished};
155
initialization_complete()156 void initialization_complete() {
157 hci_thread.DoInThread(FROM_HERE, base::Bind(&event_finish_startup, nullptr));
158 }
159
hci_event_received(const base::Location & from_here,BT_HDR * packet)160 void hci_event_received(const base::Location& from_here, BT_HDR* packet) {
161 btsnoop->capture(packet, true);
162
163 if (!filter_incoming_event(packet)) {
164 send_data_upwards.Run(from_here, packet);
165 }
166 }
167
acl_event_received(BT_HDR * packet)168 void acl_event_received(BT_HDR* packet) {
169 btsnoop->capture(packet, true);
170 packet_fragmenter->reassemble_and_dispatch(packet);
171 }
172
sco_data_received(BT_HDR * packet)173 void sco_data_received(BT_HDR* packet) {
174 btsnoop->capture(packet, true);
175 packet_fragmenter->reassemble_and_dispatch(packet);
176 }
177
iso_data_received(BT_HDR * packet)178 void iso_data_received(BT_HDR* packet) {
179 btsnoop->capture(packet, true);
180 packet_fragmenter->reassemble_and_dispatch(packet);
181 }
182
hal_service_died()183 void hal_service_died() {
184 if (abort_timer.IsScheduled()) {
185 hci_timeout_abort();
186 return;
187 }
188 // The Bluetooth hal suddenly died and no root inflammation packet received.
189 // Record it with "Default" code.
190 bluetooth::common::LogBluetoothHalCrashReason(
191 RawAddress::kEmpty, 0x00 /*Default*/, 0x00 /*Default*/);
192 abort();
193 }
194
195 // Module lifecycle functions
196
197 static future_t* hci_module_shut_down();
198
hci_module_start_up(void)199 static future_t* hci_module_start_up(void) {
200 LOG_INFO("%s", __func__);
201
202 // The host is only allowed to send at most one command initially,
203 // as per the Bluetooth spec, Volume 2, Part E, 4.4 (Command Flow Control)
204 // This value can change when you get a command complete or command status
205 // event.
206 command_credits = 1;
207
208 // For now, always use the default timeout on non-Android builds.
209 uint64_t startup_timeout_ms = DEFAULT_STARTUP_TIMEOUT_MS;
210
211 // Grab the override startup timeout ms, if present.
212 char timeout_prop[PROPERTY_VALUE_MAX];
213 if (!osi_property_get("bluetooth.enable_timeout_ms", timeout_prop,
214 STRING_VALUE_OF(DEFAULT_STARTUP_TIMEOUT_MS)) ||
215 (startup_timeout_ms = atoi(timeout_prop)) < 100)
216 startup_timeout_ms = DEFAULT_STARTUP_TIMEOUT_MS;
217
218 startup_timer = alarm_new("hci.startup_timer");
219 if (!startup_timer) {
220 LOG_ERROR("%s unable to create startup timer.", __func__);
221 goto error;
222 }
223
224 command_response_timer = alarm_new("hci.command_response_timer");
225 if (!command_response_timer) {
226 LOG_ERROR("%s unable to create command response timer.", __func__);
227 goto error;
228 }
229
230 hci_thread.StartUp();
231 if (!hci_thread.IsRunning()) {
232 LOG_ERROR("%s unable to start thread.", __func__);
233 goto error;
234 }
235 if (!hci_thread.EnableRealTimeScheduling()) {
236 LOG_ERROR("%s unable to make thread RT.", __func__);
237 goto error;
238 }
239
240 commands_pending_response = list_new(NULL);
241 if (!commands_pending_response) {
242 LOG_ERROR("%s unable to create list for commands pending response.",
243 __func__);
244 goto error;
245 }
246
247 // Make sure we run in a bounded amount of time
248 future_t* local_startup_future;
249 local_startup_future = future_new();
250 startup_future = local_startup_future;
251 alarm_set(startup_timer, startup_timeout_ms, startup_timer_expired, NULL);
252
253 packet_fragmenter->init(&packet_fragmenter_callbacks);
254
255 hci_thread.DoInThread(FROM_HERE, base::Bind(&hci_initialize));
256
257 LOG_INFO("%s starting async portion", __func__);
258 return local_startup_future;
259
260 error:
261 hci_module_shut_down(); // returns NULL so no need to wait for it
262 return future_new_immediate(FUTURE_FAIL);
263 }
264
hci_module_shut_down()265 static future_t* hci_module_shut_down() {
266 LOG_INFO("%s", __func__);
267
268 // Free the timers
269 {
270 std::lock_guard<std::recursive_timed_mutex> lock(
271 commands_pending_response_mutex);
272 alarm_free(command_response_timer);
273 command_response_timer = NULL;
274 alarm_free(startup_timer);
275 startup_timer = NULL;
276 }
277
278 hci_thread.ShutDown();
279
280 // Close HCI to prevent callbacks.
281 hci_close();
282
283 {
284 std::lock_guard<std::recursive_timed_mutex> lock(
285 commands_pending_response_mutex);
286 list_free(commands_pending_response);
287 commands_pending_response = NULL;
288 }
289
290 packet_fragmenter->cleanup();
291
292 if (hci_firmware_log_fd != INVALID_FD) {
293 hci_close_firmware_log_file(hci_firmware_log_fd);
294 hci_firmware_log_fd = INVALID_FD;
295 }
296
297 return NULL;
298 }
299
300 EXPORT_SYMBOL extern const module_t hci_module = {
301 .name = HCI_MODULE,
302 .init = NULL,
303 .start_up = hci_module_start_up,
304 .shut_down = hci_module_shut_down,
305 .clean_up = NULL,
306 .dependencies = {BTSNOOP_MODULE, NULL}};
307
308 // Interface functions
309
set_data_cb(base::Callback<void (const base::Location &,BT_HDR *)> send_data_cb)310 static void set_data_cb(
311 base::Callback<void(const base::Location&, BT_HDR*)> send_data_cb) {
312 send_data_upwards = std::move(send_data_cb);
313 }
314
transmit_command(BT_HDR * command,command_complete_cb complete_callback,command_status_cb status_callback,void * context)315 static void transmit_command(BT_HDR* command,
316 command_complete_cb complete_callback,
317 command_status_cb status_callback, void* context) {
318 waiting_command_t* wait_entry = reinterpret_cast<waiting_command_t*>(
319 osi_calloc(sizeof(waiting_command_t)));
320
321 uint8_t* stream = command->data + command->offset;
322 STREAM_TO_UINT16(wait_entry->opcode, stream);
323 wait_entry->complete_callback = complete_callback;
324 wait_entry->status_callback = status_callback;
325 wait_entry->command = command;
326 wait_entry->context = context;
327
328 // Store the command message type in the event field
329 // in case the upper layer didn't already
330 command->event = MSG_STACK_TO_HC_HCI_CMD;
331
332 enqueue_command(wait_entry);
333 }
334
transmit_command_futured(BT_HDR * command)335 static future_t* transmit_command_futured(BT_HDR* command) {
336 waiting_command_t* wait_entry = reinterpret_cast<waiting_command_t*>(
337 osi_calloc(sizeof(waiting_command_t)));
338 future_t* future = future_new();
339
340 uint8_t* stream = command->data + command->offset;
341 STREAM_TO_UINT16(wait_entry->opcode, stream);
342 wait_entry->complete_future = future;
343 wait_entry->command = command;
344
345 // Store the command message type in the event field
346 // in case the upper layer didn't already
347 command->event = MSG_STACK_TO_HC_HCI_CMD;
348
349 enqueue_command(wait_entry);
350 return future;
351 }
352
transmit_downward(uint16_t type,void * data)353 static void transmit_downward(uint16_t type, void* data) {
354 if (type == MSG_STACK_TO_HC_HCI_CMD) {
355 // TODO(zachoverflow): eliminate this call
356 transmit_command((BT_HDR*)data, NULL, NULL, NULL);
357 LOG_WARN("%s legacy transmit of command. Use transmit_command instead.",
358 __func__);
359 } else {
360 enqueue_packet(data);
361 }
362 }
363
364 // Start up functions
365
event_finish_startup(UNUSED_ATTR void * context)366 static void event_finish_startup(UNUSED_ATTR void* context) {
367 LOG_INFO("%s", __func__);
368 std::lock_guard<std::recursive_timed_mutex> lock(
369 commands_pending_response_mutex);
370 alarm_cancel(startup_timer);
371 if (!startup_future) {
372 return;
373 }
374 future_ready(startup_future, FUTURE_SUCCESS);
375 startup_future = NULL;
376 }
377
startup_timer_expired(UNUSED_ATTR void * context)378 static void startup_timer_expired(UNUSED_ATTR void* context) {
379 LOG_ERROR("%s", __func__);
380
381 StopWatchLegacy::DumpStopWatchLog();
382
383 LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, HCI_STARTUP_TIMED_OUT);
384
385 hci_close();
386 if (abort_timer.IsScheduled()) {
387 LOG_ERROR("%s: waiting for abort_timer", __func__);
388 return;
389 }
390
391 abort();
392 }
393
394 // Command/packet transmitting functions
enqueue_command(waiting_command_t * wait_entry)395 static void enqueue_command(waiting_command_t* wait_entry) {
396 base::Closure callback = base::Bind(&event_command_ready, wait_entry);
397
398 std::lock_guard<std::mutex> command_credits_lock(command_credits_mutex);
399 if (command_credits > 0) {
400 if (!hci_thread.DoInThread(FROM_HERE, std::move(callback))) {
401 // HCI Layer was shut down or not running
402 buffer_allocator->free(wait_entry->command);
403 osi_free(wait_entry);
404 return;
405 }
406 command_credits--;
407 } else {
408 command_queue.push(std::move(callback));
409 }
410 }
411
event_command_ready(waiting_command_t * wait_entry)412 static void event_command_ready(waiting_command_t* wait_entry) {
413 {
414 /// Move it to the list of commands awaiting response
415 std::lock_guard<std::recursive_timed_mutex> lock(
416 commands_pending_response_mutex);
417 wait_entry->timestamp = std::chrono::steady_clock::now();
418 list_append(commands_pending_response, wait_entry);
419 }
420 // Send it off
421 packet_fragmenter->fragment_and_dispatch(wait_entry->command);
422
423 update_command_response_timer();
424 }
425
enqueue_packet(void * packet)426 static void enqueue_packet(void* packet) {
427 if (!hci_thread.DoInThread(FROM_HERE,
428 base::Bind(&event_packet_ready, packet))) {
429 // HCI Layer was shut down or not running
430 buffer_allocator->free(packet);
431 return;
432 }
433 }
434
event_packet_ready(void * pkt)435 static void event_packet_ready(void* pkt) {
436 // The queue may be the command queue or the packet queue, we don't care
437 BT_HDR* packet = (BT_HDR*)pkt;
438 packet_fragmenter->fragment_and_dispatch(packet);
439 }
440
441 // Callback for the fragmenter to send a fragment
transmit_fragment(BT_HDR * packet,bool send_transmit_finished)442 static void transmit_fragment(BT_HDR* packet, bool send_transmit_finished) {
443 btsnoop->capture(packet, false);
444
445 // HCI command packets are freed on a different thread when the matching
446 // event is received. Check packet->event before sending to avoid a race.
447 bool free_after_transmit =
448 (packet->event & MSG_EVT_MASK) != MSG_STACK_TO_HC_HCI_CMD &&
449 send_transmit_finished;
450
451 hci_transmit(packet);
452
453 if (free_after_transmit) {
454 buffer_allocator->free(packet);
455 }
456 }
457
fragmenter_transmit_finished(BT_HDR * packet,bool all_fragments_sent)458 static void fragmenter_transmit_finished(BT_HDR* packet,
459 bool all_fragments_sent) {
460 if (all_fragments_sent) {
461 buffer_allocator->free(packet);
462 } else {
463 // This is kind of a weird case, since we're dispatching a partially sent
464 // packet up to a higher layer.
465 // TODO(zachoverflow): rework upper layer so this isn't necessary.
466
467 send_data_upwards.Run(FROM_HERE, packet);
468 }
469 }
470
471 // Abort. The chip has had time to write any debugging information.
hci_timeout_abort(void)472 static void hci_timeout_abort(void) {
473 if (root_inflamed_vendor_error_code != 0 || root_inflamed_error_code != 0) {
474 hci_root_inflamed_abort();
475 return;
476 }
477
478 LOG_ERROR("%s restarting the Bluetooth process.", __func__);
479 hci_close_firmware_log_file(hci_firmware_log_fd);
480
481 // We shouldn't try to recover the stack from this command timeout.
482 // If it's caused by a software bug, fix it. If it's a hardware bug, fix it.
483 abort();
484 }
485
hci_root_inflamed_abort()486 static void hci_root_inflamed_abort() {
487 LOG(FATAL) << __func__
488 << ": error_code = " << std::to_string(root_inflamed_error_code)
489 << ", vendor_error_code = "
490 << std::to_string(root_inflamed_vendor_error_code);
491 }
492
command_timed_out_log_info(void * original_wait_entry)493 static void command_timed_out_log_info(void* original_wait_entry) {
494 LOG_ERROR("%s: %d commands pending response", __func__,
495 get_num_waiting_commands());
496
497 for (const list_node_t* node = list_begin(commands_pending_response);
498 node != list_end(commands_pending_response); node = list_next(node)) {
499 waiting_command_t* wait_entry =
500 reinterpret_cast<waiting_command_t*>(list_node(node));
501
502 int wait_time_ms =
503 std::chrono::duration_cast<std::chrono::milliseconds>(
504 std::chrono::steady_clock::now() - wait_entry->timestamp)
505 .count();
506 LOG_ERROR("%s: Waited %d ms for a response to opcode: 0x%x %s", __func__,
507 wait_time_ms, wait_entry->opcode,
508 (wait_entry == original_wait_entry) ? "*matches timer*" : "");
509
510 // Dump the length field and the first byte of the payload, if present.
511 uint8_t* command = wait_entry->command->data + wait_entry->command->offset;
512 if (wait_entry->command->len > 3) {
513 LOG_ERROR("%s: Size %d Hex %02x %02x %02x %02x", __func__,
514 wait_entry->command->len, command[0], command[1], command[2],
515 command[3]);
516 } else {
517 LOG_ERROR("%s: Size %d Hex %02x %02x %02x", __func__,
518 wait_entry->command->len, command[0], command[1], command[2]);
519 }
520
521 LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, wait_entry->opcode);
522 bluetooth::common::LogHciTimeoutEvent(wait_entry->opcode);
523 }
524 }
525
526 // Print debugging information and quit. Don't dereference original_wait_entry.
command_timed_out(void * original_wait_entry)527 static void command_timed_out(void* original_wait_entry) {
528 LOG_ERROR("%s", __func__);
529 StopWatchLegacy::DumpStopWatchLog();
530 std::unique_lock<std::recursive_timed_mutex> lock(
531 commands_pending_response_mutex, std::defer_lock);
532 if (!lock.try_lock_for(std::chrono::milliseconds(
533 COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS))) {
534 LOG_ERROR("%s: Cannot obtain the mutex", __func__);
535 LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, HCI_UNKNOWN_COMMAND_TIMED_OUT);
536 bluetooth::common::LogHciTimeoutEvent(android::bluetooth::hci::CMD_UNKNOWN);
537 } else {
538 command_timed_out_log_info(original_wait_entry);
539 lock.unlock();
540 }
541
542 // Don't request a firmware dump for multiple hci timeouts
543 if (hci_firmware_log_fd != INVALID_FD) {
544 return;
545 }
546
547 LOG_ERROR("%s: requesting a firmware dump.", __func__);
548
549 /* Allocate a buffer to hold the HCI command. */
550 BT_HDR* bt_hdr =
551 static_cast<BT_HDR*>(osi_malloc(sizeof(BT_HDR) + HCIC_PREAMBLE_SIZE));
552
553 bt_hdr->len = HCIC_PREAMBLE_SIZE;
554 bt_hdr->event = MSG_STACK_TO_HC_HCI_CMD;
555 bt_hdr->offset = 0;
556
557 uint8_t* hci_packet = reinterpret_cast<uint8_t*>(bt_hdr + 1);
558
559 UINT16_TO_STREAM(hci_packet, HCI_CONTROLLER_DEBUG_INFO);
560 UINT8_TO_STREAM(hci_packet, 0); // No parameters
561
562 hci_firmware_log_fd = hci_open_firmware_log_file();
563
564 transmit_fragment(bt_hdr, true);
565
566 osi_free(bt_hdr);
567 LOG_ERROR("%s: Setting a timer to restart.", __func__);
568
569 // alarm_default_callbacks thread post to hci_thread.
570 if (!abort_timer.Schedule(
571 hci_thread.GetWeakPtr(), FROM_HERE, base::Bind(hci_timeout_abort),
572 base::TimeDelta::FromMilliseconds(COMMAND_TIMEOUT_RESTART_MS))) {
573 LOG_ERROR("%s unable to create an abort timer.", __func__);
574 abort();
575 }
576 }
577
578 // Event/packet receiving functions
process_command_credits(int credits)579 void process_command_credits(int credits) {
580 std::lock_guard<std::mutex> command_credits_lock(command_credits_mutex);
581
582 if (!hci_thread.IsRunning()) {
583 // HCI Layer was shut down or not running
584 return;
585 }
586
587 // Subtract commands in flight.
588 command_credits = credits - get_num_waiting_commands();
589
590 while (command_credits > 0 && !command_queue.empty()) {
591 if (!hci_thread.DoInThread(FROM_HERE, std::move(command_queue.front()))) {
592 LOG(ERROR) << __func__ << ": failed to enqueue command";
593 }
594 command_queue.pop();
595 command_credits--;
596 }
597 }
598
hci_is_root_inflammation_event_received()599 bool hci_is_root_inflammation_event_received() {
600 return abort_timer.IsScheduled();
601 }
602
handle_root_inflammation_event()603 void handle_root_inflammation_event() {
604 LOG(ERROR)
605 << __func__
606 << ": Root inflammation event! setting timer to restart. error_code: "
607 << loghex(root_inflamed_error_code)
608 << " vendor _error_code: " << loghex(root_inflamed_vendor_error_code);
609 bluetooth::common::LogBluetoothHalCrashReason(
610 RawAddress::kEmpty, root_inflamed_error_code,
611 root_inflamed_vendor_error_code);
612 {
613 // Try to stop hci command and startup timers
614 std::unique_lock<std::recursive_timed_mutex> lock(
615 commands_pending_response_mutex, std::defer_lock);
616 if (lock.try_lock_for(std::chrono::milliseconds(
617 COMMAND_PENDING_MUTEX_ACQUIRE_TIMEOUT_MS))) {
618 if (alarm_is_scheduled(startup_timer)) {
619 alarm_cancel(startup_timer);
620 }
621 if (alarm_is_scheduled(command_response_timer)) {
622 alarm_cancel(command_response_timer);
623 }
624 // Cleanup the hci/startup timers so they will not be scheduled again and
625 // expire before the abort_timer.
626 alarm_free(command_response_timer);
627 command_response_timer = NULL;
628 alarm_free(startup_timer);
629 startup_timer = NULL;
630 } else {
631 LOG(ERROR) << __func__ << ": Failed to obtain mutex";
632 hci_root_inflamed_abort();
633 }
634 }
635
636 // HwBinder thread post to hci_thread
637 if (!hci_thread.IsRunning() ||
638 !abort_timer.Schedule(
639 hci_thread.GetWeakPtr(), FROM_HERE,
640 base::Bind(hci_root_inflamed_abort),
641 base::TimeDelta::FromMilliseconds(ROOT_INFLAMMED_RESTART_MS))) {
642 LOG(ERROR) << "Failed to schedule abort_timer or hci has already closed!";
643 hci_root_inflamed_abort();
644 }
645 }
646
647 // Returns true if the event was intercepted and should not proceed to
648 // higher layers. Also inspects an incoming event for interesting
649 // information, like how many commands are now able to be sent.
filter_incoming_event(BT_HDR * packet)650 static bool filter_incoming_event(BT_HDR* packet) {
651 waiting_command_t* wait_entry = NULL;
652 uint8_t* stream = packet->data;
653 uint8_t event_code;
654 uint8_t length;
655 int credits = 0;
656 command_opcode_t opcode;
657
658 STREAM_TO_UINT8(event_code, stream);
659 STREAM_TO_UINT8(length, stream);
660
661 if (event_code == HCI_COMMAND_COMPLETE_EVT) {
662 STREAM_TO_UINT8(credits, stream);
663 STREAM_TO_UINT16(opcode, stream);
664
665 wait_entry = get_waiting_command(opcode);
666
667 process_command_credits(credits);
668
669 if (!wait_entry) {
670 if (opcode != HCI_COMMAND_NONE) {
671 LOG_WARN(
672 "%s command complete event with no matching command (opcode: "
673 "0x%04x).",
674 __func__, opcode);
675 }
676 } else {
677 update_command_response_timer();
678 if (wait_entry->complete_callback) {
679 wait_entry->complete_callback(packet, wait_entry->context);
680 } else if (wait_entry->complete_future) {
681 future_ready(wait_entry->complete_future, packet);
682 }
683 }
684
685 goto intercepted;
686 } else if (event_code == HCI_COMMAND_STATUS_EVT) {
687 if (length < (sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint16_t))) {
688 LOG_WARN("%s Unexpected hci command status event length:%hhd", __func__,
689 length);
690 goto intercepted;
691 }
692 uint8_t status;
693 STREAM_TO_UINT8(status, stream);
694 STREAM_TO_UINT8(credits, stream);
695 STREAM_TO_UINT16(opcode, stream);
696
697 // If a command generates a command status event, it won't be getting a
698 // command complete event
699 wait_entry = get_waiting_command(opcode);
700
701 process_command_credits(credits);
702
703 if (!wait_entry) {
704 LOG_WARN(
705 "%s command status event with no matching command. opcode: 0x%04x",
706 __func__, opcode);
707 } else {
708 update_command_response_timer();
709 if (wait_entry->status_callback)
710 wait_entry->status_callback(status, wait_entry->command,
711 wait_entry->context);
712 }
713
714 goto intercepted;
715 } else if (event_code == HCI_VENDOR_SPECIFIC_EVT) {
716 uint8_t sub_event_code;
717 STREAM_TO_UINT8(sub_event_code, stream);
718
719 if (sub_event_code == HCI_VSE_SUBCODE_DEBUG_INFO_SUB_EVT) {
720 if (hci_firmware_log_fd == INVALID_FD)
721 hci_firmware_log_fd = hci_open_firmware_log_file();
722
723 if (hci_firmware_log_fd != INVALID_FD)
724 hci_log_firmware_debug_packet(hci_firmware_log_fd, packet);
725
726 buffer_allocator->free(packet);
727 return true;
728 } else if (sub_event_code == HCI_VSE_SUBCODE_BQR_SUB_EVT) {
729 // Excluding the HCI Event packet header and 1 octet sub-event code
730 int16_t bqr_parameter_length = packet->len - HCIE_PREAMBLE_SIZE - 1;
731 // The stream currently points to the BQR sub-event parameters
732 if (filter_bqr_event(bqr_parameter_length, stream)) {
733 buffer_allocator->free(packet);
734 return true;
735 }
736 }
737 }
738
739 return false;
740
741 intercepted:
742 if (wait_entry) {
743 // If it has a callback, it's responsible for freeing the packet
744 if (event_code == HCI_COMMAND_STATUS_EVT ||
745 (!wait_entry->complete_callback && !wait_entry->complete_future))
746 buffer_allocator->free(packet);
747
748 // If it has a callback, it's responsible for freeing the command
749 if (event_code == HCI_COMMAND_COMPLETE_EVT || !wait_entry->status_callback)
750 buffer_allocator->free(wait_entry->command);
751
752 osi_free(wait_entry);
753 } else {
754 buffer_allocator->free(packet);
755 }
756
757 return true;
758 }
759
760 // Callback for the fragmenter to dispatch up a completely reassembled packet
dispatch_reassembled(BT_HDR * packet)761 static void dispatch_reassembled(BT_HDR* packet) {
762 // Events should already have been dispatched before this point
763 CHECK((packet->event & MSG_EVT_MASK) != MSG_HC_TO_STACK_HCI_EVT);
764 CHECK(!send_data_upwards.is_null());
765
766 send_data_upwards.Run(FROM_HERE, packet);
767 }
768
769 // Misc internal functions
770
get_waiting_command(command_opcode_t opcode)771 static waiting_command_t* get_waiting_command(command_opcode_t opcode) {
772 std::lock_guard<std::recursive_timed_mutex> lock(
773 commands_pending_response_mutex);
774
775 for (const list_node_t* node = list_begin(commands_pending_response);
776 node != list_end(commands_pending_response); node = list_next(node)) {
777 waiting_command_t* wait_entry =
778 reinterpret_cast<waiting_command_t*>(list_node(node));
779
780 if (!wait_entry || wait_entry->opcode != opcode) continue;
781
782 list_remove(commands_pending_response, wait_entry);
783
784 return wait_entry;
785 }
786
787 return NULL;
788 }
789
get_num_waiting_commands()790 static int get_num_waiting_commands() {
791 std::lock_guard<std::recursive_timed_mutex> lock(
792 commands_pending_response_mutex);
793 return list_length(commands_pending_response);
794 }
795
update_command_response_timer(void)796 static void update_command_response_timer(void) {
797 std::lock_guard<std::recursive_timed_mutex> lock(
798 commands_pending_response_mutex);
799
800 if (command_response_timer == NULL) return;
801 if (list_is_empty(commands_pending_response)) {
802 alarm_cancel(command_response_timer);
803 } else {
804 alarm_set(command_response_timer, COMMAND_PENDING_TIMEOUT_MS,
805 command_timed_out, list_front(commands_pending_response));
806 }
807 }
808
809 // Returns true if the BQR event is handled and should not proceed to
810 // higher layers.
filter_bqr_event(int16_t bqr_parameter_length,uint8_t * p_bqr_event)811 static bool filter_bqr_event(int16_t bqr_parameter_length,
812 uint8_t* p_bqr_event) {
813 if (bqr_parameter_length <= 0) {
814 LOG(ERROR) << __func__ << ": Invalid parameter length : "
815 << std::to_string(bqr_parameter_length);
816 return true;
817 }
818
819 bool intercepted = false;
820 uint8_t quality_report_id = p_bqr_event[0];
821 switch (quality_report_id) {
822 case bluetooth::bqr::QUALITY_REPORT_ID_ROOT_INFLAMMATION:
823 if (bqr_parameter_length >=
824 bluetooth::bqr::kRootInflammationParamTotalLen) {
825 STREAM_TO_UINT8(quality_report_id, p_bqr_event);
826 STREAM_TO_UINT8(root_inflamed_error_code, p_bqr_event);
827 STREAM_TO_UINT8(root_inflamed_vendor_error_code, p_bqr_event);
828 handle_root_inflammation_event();
829 }
830 intercepted = true;
831 break;
832
833 case bluetooth::bqr::QUALITY_REPORT_ID_LMP_LL_MESSAGE_TRACE:
834 if (bqr_parameter_length >= bluetooth::bqr::kLogDumpParamTotalLen) {
835 bluetooth::bqr::DumpLmpLlMessage(bqr_parameter_length, p_bqr_event);
836 }
837 intercepted = true;
838 break;
839
840 case bluetooth::bqr::QUALITY_REPORT_ID_BT_SCHEDULING_TRACE:
841 if (bqr_parameter_length >= bluetooth::bqr::kLogDumpParamTotalLen) {
842 bluetooth::bqr::DumpBtScheduling(bqr_parameter_length, p_bqr_event);
843 }
844 intercepted = true;
845 break;
846
847 case bluetooth::bqr::QUALITY_REPORT_ID_CONTROLLER_DBG_INFO:
848 // TODO: Integrate with the HCI_VSE_SUBCODE_DEBUG_INFO_SUB_EVT
849 intercepted = true;
850 break;
851
852 case bluetooth::bqr::QUALITY_REPORT_ID_MONITOR_MODE:
853 case bluetooth::bqr::QUALITY_REPORT_ID_APPROACH_LSTO:
854 case bluetooth::bqr::QUALITY_REPORT_ID_A2DP_AUDIO_CHOPPY:
855 case bluetooth::bqr::QUALITY_REPORT_ID_SCO_VOICE_CHOPPY:
856 default:
857 break;
858 }
859
860 return intercepted;
861 }
862
init_layer_interface()863 static void init_layer_interface() {
864 if (!interface_created) {
865 // It's probably ok for this to live forever. It's small and
866 // there's only one instance of the hci interface.
867
868 interface.set_data_cb = set_data_cb;
869 interface.transmit_command = transmit_command;
870 interface.transmit_command_futured = transmit_command_futured;
871 interface.transmit_downward = transmit_downward;
872 interface_created = true;
873 }
874 }
875
hci_layer_cleanup_interface()876 void hci_layer_cleanup_interface() {
877 if (interface_created) {
878 send_data_upwards.Reset();
879
880 interface.set_data_cb = NULL;
881 interface.transmit_command = NULL;
882 interface.transmit_command_futured = NULL;
883 interface.transmit_downward = NULL;
884 interface_created = false;
885 }
886 }
887
888 namespace bluetooth {
889 namespace shim {
890 const hci_t* hci_layer_get_interface();
891 } // namespace shim
892 } // namespace bluetooth
893
hci_layer_get_interface_legacy()894 const hci_t* hci_layer_get_interface_legacy() {
895 buffer_allocator = buffer_allocator_get_interface();
896 btsnoop = btsnoop_get_interface();
897 packet_fragmenter = packet_fragmenter_get_interface();
898
899 init_layer_interface();
900
901 return &interface;
902 }
903
hci_layer_get_interface()904 const hci_t* hci_layer_get_interface() {
905 if (bluetooth::shim::is_gd_hci_enabled()) {
906 return bluetooth::shim::hci_layer_get_interface();
907 } else {
908 return hci_layer_get_interface_legacy();
909 }
910 }
911
hci_layer_get_test_interface(const allocator_t * buffer_allocator_interface,const btsnoop_t * btsnoop_interface,const packet_fragmenter_t * packet_fragmenter_interface)912 const hci_t* hci_layer_get_test_interface(
913 const allocator_t* buffer_allocator_interface,
914 const btsnoop_t* btsnoop_interface,
915 const packet_fragmenter_t* packet_fragmenter_interface) {
916 buffer_allocator = buffer_allocator_interface;
917 btsnoop = btsnoop_interface;
918 packet_fragmenter = packet_fragmenter_interface;
919
920 init_layer_interface();
921 return &interface;
922 }
923