Merge changes I90a48db4,I8b9815a0 into oc-dev (77e17714) · Commits · e / os / android_packages_modules_Bluetooth

system/hci/src/hci_layer.cc

+84 −18

Original line number	Diff line number	Diff line
		@@ -53,6 +53,11 @@
		extern void hci_initialize();
		extern void hci_transmit(BT_HDR* packet);
		extern void hci_close();
		extern int hci_open_firmware_log_file();
		extern void hci_close_firmware_log_file(int fd);
		extern void hci_log_firmware_debug_packet(int fd, BT_HDR* packet);

		static int hci_firmware_log_fd = INVALID_FD;

		typedef struct {
		uint16_t opcode;
		@@ -73,6 +78,7 @@ static const int BT_HCI_RT_PRIORITY = 1;

		// Abort if there is no response to an HCI command.
		static const uint32_t COMMAND_PENDING_TIMEOUT_MS = 2000;
		static const uint32_t COMMAND_TIMEOUT_RESTART_US = 500000;

		// Our interface
		static bool interface_created;
		@@ -106,6 +112,7 @@ static fixed_queue_t* upwards_data_queue;

		static bool filter_incoming_event(BT_HDR* packet);
		static waiting_command_t* get_waiting_command(command_opcode_t opcode);
		static int get_num_waiting_commands();

		static void event_finish_startup(void* context);
		static void startup_timer_expired(void* context);
		@@ -434,29 +441,69 @@ static void fragmenter_transmit_finished(BT_HDR* packet,
		}
		}

		static void command_timed_out(UNUSED_ATTR void* context) {
		// Print debugging information and quit. Don't dereference original_wait_entry.
		static void command_timed_out(void* original_wait_entry) {
		std::unique_lock<std::recursive_mutex> lock(commands_pending_response_mutex);

		if (list_is_empty(commands_pending_response)) {
		LOG_ERROR(LOG_TAG, "%s with no commands pending response", __func__);
		} else {
		waiting_command_t* wait_entry = reinterpret_cast<waiting_command_t*>(
		list_front(commands_pending_response));
		LOG_ERROR(LOG_TAG, "%s: %d commands pending response", __func__,
		get_num_waiting_commands());

		for (const list_node_t* node = list_begin(commands_pending_response);
		node != list_end(commands_pending_response); node = list_next(node)) {
		waiting_command_t* wait_entry =
		reinterpret_cast<waiting_command_t*>(list_node(node));

		int wait_time_ms =
		std::chrono::duration_cast<std::chrono::milliseconds>(
		std::chrono::steady_clock::now() - wait_entry->timestamp)
		.count();
		// We shouldn't try to recover the stack from this command timeout.
		// If it's caused by a software bug, fix it. If it's a hardware bug, fix it.
		LOG_ERROR(LOG_TAG, "%s: Waited %d ms for a response to opcode: 0x%x",
		__func__, wait_time_ms, wait_entry->opcode);
		LOG_ERROR(LOG_TAG, "%s: Waited %d ms for a response to opcode: 0x%x %s",
		__func__, wait_time_ms, wait_entry->opcode,
		(wait_entry == original_wait_entry) ? "matches timer" : "");

		// Dump the length field and the first byte of the payload, if present.
		uint8_t* command = wait_entry->command->data + wait_entry->command->offset;
		if (wait_entry->command->len > 3) {
		LOG_ERROR(LOG_TAG, "%s: Size %d Hex %02x %02x %02x %02x", __func__,
		wait_entry->command->len, command[0], command[1], command[2],
		command[3]);
		} else {
		LOG_ERROR(LOG_TAG, "%s: Size %d Hex %02x %02x %02x", __func__,
		wait_entry->command->len, command[0], command[1], command[2]);
		}

		LOG_EVENT_INT(BT_HCI_TIMEOUT_TAG_NUM, wait_entry->opcode);
		lock.unlock();
		}
		lock.unlock();

		LOG_ERROR(LOG_TAG, "%s: requesting a firmware dump.", __func__);

		/* Allocate a buffer to hold the HCI command. */
		BT_HDR* bt_hdr =
		static_cast<BT_HDR*>(osi_malloc(sizeof(BT_HDR) + HCIC_PREAMBLE_SIZE));

		bt_hdr->len = HCIC_PREAMBLE_SIZE;
		bt_hdr->event = MSG_STACK_TO_HC_HCI_CMD;
		bt_hdr->offset = 0;

		uint8_t* hci_packet = reinterpret_cast<uint8_t*>(bt_hdr + 1);

		UINT16_TO_STREAM(hci_packet,
		HCI_GRP_VENDOR_SPECIFIC \| HCI_CONTROLLER_DEBUG_INFO_OCF);
		UINT8_TO_STREAM(hci_packet, 0); // No parameters

		hci_firmware_log_fd = hci_open_firmware_log_file();

		LOG_ERROR(LOG_TAG, "%s restarting the bluetooth process.", __func__);
		usleep(10000);
		transmit_fragment(bt_hdr, true);

		osi_free(bt_hdr);

		LOG_ERROR(LOG_TAG, "%s restarting the Bluetooth process.", __func__);
		usleep(COMMAND_TIMEOUT_RESTART_US);
		hci_close_firmware_log_file(hci_firmware_log_fd);

		// We shouldn't try to recover the stack from this command timeout.
		// If it's caused by a software bug, fix it. If it's a hardware bug, fix it.
		abort();
		}

		@@ -469,7 +516,10 @@ void process_command_credits(int credits) {
		// HCI Layer was shut down
		return;
		}
		command_credits = credits;

		// Subtract commands in flight.
		command_credits = credits - get_num_waiting_commands();

		while (command_credits > 0 && command_queue.size() > 0) {
		message_loop_->task_runner()->PostTask(FROM_HERE,
		std::move(command_queue.front()));
		@@ -495,9 +545,10 @@ static bool filter_incoming_event(BT_HDR* packet) {
		STREAM_TO_UINT8(credits, stream);
		STREAM_TO_UINT16(opcode, stream);

		wait_entry = get_waiting_command(opcode);

		process_command_credits(credits);

		wait_entry = get_waiting_command(opcode);
		if (!wait_entry) {
		if (opcode != HCI_COMMAND_NONE) {
		LOG_WARN(LOG_TAG,
		@@ -521,11 +572,12 @@ static bool filter_incoming_event(BT_HDR* packet) {
		STREAM_TO_UINT8(credits, stream);
		STREAM_TO_UINT16(opcode, stream);

		process_command_credits(credits);

		// If a command generates a command status event, it won't be getting a
		// command complete event
		wait_entry = get_waiting_command(opcode);

		process_command_credits(credits);

		if (!wait_entry) {
		LOG_WARN(
		LOG_TAG,
		@@ -539,6 +591,15 @@ static bool filter_incoming_event(BT_HDR* packet) {
		}

		goto intercepted;
		} else if (event_code == HCI_VSE_SUBCODE_DEBUG_INFO_SUB_EVT) {
		if (hci_firmware_log_fd == INVALID_FD)
		hci_firmware_log_fd = hci_open_firmware_log_file();

		if (hci_firmware_log_fd != INVALID_FD)
		hci_log_firmware_debug_packet(hci_firmware_log_fd, packet);

		buffer_allocator->free(packet);
		return true;
		}

		return false;
		@@ -591,6 +652,11 @@ static waiting_command_t* get_waiting_command(command_opcode_t opcode) {
		return NULL;
		}

		static int get_num_waiting_commands() {
		std::lock_guard<std::recursive_mutex> lock(commands_pending_response_mutex);
		return list_length(commands_pending_response);
		}

		static void update_command_response_timer(void) {
		std::lock_guard<std::recursive_mutex> lock(commands_pending_response_mutex);

		@@ -599,7 +665,7 @@ static void update_command_response_timer(void) {
		alarm_cancel(command_response_timer);
		} else {
		alarm_set(command_response_timer, COMMAND_PENDING_TIMEOUT_MS,
		command_timed_out, NULL);
		command_timed_out, list_front(commands_pending_response));
		}
		}

system/hci/src/hci_layer_android.cc

+31 −0

Original line number	Diff line number	Diff line
		@@ -23,12 +23,17 @@
		#include <base/logging.h>
		#include "buffer_allocator.h"
		#include "osi/include/log.h"
		#include "sys/stat.h"
		#include "sys/types.h"

		#include <android/hardware/bluetooth/1.0/IBluetoothHci.h>
		#include <android/hardware/bluetooth/1.0/IBluetoothHciCallbacks.h>
		#include <android/hardware/bluetooth/1.0/types.h>
		#include <hwbinder/ProcessState.h>

		#define LOG_PATH "/data/misc/bluetooth/logs/firmware_events.log"
		#define LAST_LOG_PATH "/data/misc/bluetooth/logs/firmware_events.log.last"

		using android::hardware::bluetooth::V1_0::IBluetoothHci;
		using android::hardware::bluetooth::V1_0::IBluetoothHciCallbacks;
		using android::hardware::bluetooth::V1_0::HciPacket;
		@@ -133,3 +138,29 @@ void hci_transmit(BT_HDR* packet) {
		break;
		}
		}

		int hci_open_firmware_log_file() {
		if (rename(LOG_PATH, LAST_LOG_PATH) == -1 && errno != ENOENT) {
		LOG_ERROR(LOG_TAG, "%s unable to rename '%s' to '%s': %s", __func__,
		LOG_PATH, LAST_LOG_PATH, strerror(errno));
		}

		mode_t prevmask = umask(0);
		int logfile_fd = open(LOG_PATH, O_WRONLY \| O_CREAT \| O_TRUNC,
		S_IRUSR \| S_IWUSR \| S_IRGRP \| S_IWGRP \| S_IROTH);
		umask(prevmask);
		if (logfile_fd == INVALID_FD) {
		LOG_ERROR(LOG_TAG, "%s unable to open '%s': %s", __func__, LOG_PATH,
		strerror(errno));
		}

		return logfile_fd;
		}

		void hci_close_firmware_log_file(int fd) {
		if (fd != INVALID_FD) close(fd);
		}

		void hci_log_firmware_debug_packet(int fd, BT_HDR* packet) {
		TEMP_FAILURE_RETRY(write(fd, packet->data, packet->len));
		}

system/hci/src/hci_layer_linux.cc

+6 −0

Original line number	Diff line number	Diff line
		@@ -390,3 +390,9 @@ static int rfkill(int block) {
		close(fd);
		return 0;
		}

		int hci_open_firmware_log_file() { return INVALID_FD; }

		void hci_close_firmware_log_file(int fd) {}

		void hci_log_firmware_debug_packet(int fd, BT_HDR* packet) {}

system/stack/include/hcidefs.h

+3 −0

Original line number	Diff line number	Diff line
		@@ -423,6 +423,9 @@
		/* tracking sub event */
		#define HCI_VSE_SUBCODE_BLE_TRACKING_SUB_EVT 0x56 /* Tracking event */

		/* debug info sub event */
		#define HCI_VSE_SUBCODE_DEBUG_INFO_SUB_EVT 0x57

		/* LE supported states definition */
		#define HCI_LE_ADV_STATE 0x00000001
		#define HCI_LE_SCAN_STATE 0x00000002