h5: use log_debug[_hexdump] for debug level output

This commit is contained in:
Matthias Ringwald 2017-04-07 22:34:20 +02:00
parent cb42147ab2
commit b304e673c2

View File

@ -193,7 +193,7 @@ static uint16_t crc16_calc_for_slip_frame(const uint8_t * header, const uint8_t
// ----------------------------- // -----------------------------
static void hci_transport_inactivity_timeout_handler(btstack_timer_source_t * ts){ static void hci_transport_inactivity_timeout_handler(btstack_timer_source_t * ts){
log_info("h5: inactivity timeout. link state %d, peer asleep %u, actions 0x%02x, outgoing packet %u", log_info("inactivity timeout. link state %d, peer asleep %u, actions 0x%02x, outgoing packet %u",
link_state, link_peer_asleep, hci_transport_link_actions, hci_transport_link_have_outgoing_packet()); link_state, link_peer_asleep, hci_transport_link_actions, hci_transport_link_have_outgoing_packet());
if (hci_transport_link_have_outgoing_packet()) return; if (hci_transport_link_have_outgoing_packet()) return;
if (link_state != LINK_ACTIVE) return; if (link_state != LINK_ACTIVE) return;
@ -235,7 +235,7 @@ static void hci_transport_slip_encode_chunk_and_send(int pos){
slip_outgoing_buffer[pos++] = BTSTACK_SLIP_SOF; slip_outgoing_buffer[pos++] = BTSTACK_SLIP_SOF;
} }
slip_write_active = 1; slip_write_active = 1;
log_info("hci_transport_slip: send %d bytes", pos); log_debug("slip: send %d bytes", pos);
btstack_uart->send_block(slip_outgoing_buffer, pos); btstack_uart->send_block(slip_outgoing_buffer, pos);
} }
@ -298,43 +298,43 @@ static void hci_transport_link_send_control(const uint8_t * message, int message
if (link_peer_supports_data_integrity_check){ if (link_peer_supports_data_integrity_check){
data_integrity_check = crc16_calc_for_slip_frame(header, message, message_len); data_integrity_check = crc16_calc_for_slip_frame(header, message, message_len);
} }
log_info("hci_transport_link_send_control: size %u, append dic %u", message_len, link_peer_supports_data_integrity_check); log_debug("hci_transport_link_send_control: size %u, append dic %u", message_len, link_peer_supports_data_integrity_check);
log_info_hexdump(message, message_len); log_debug_hexdump(message, message_len);
hci_transport_slip_send_frame(header, message, message_len, data_integrity_check); hci_transport_slip_send_frame(header, message, message_len, data_integrity_check);
} }
static void hci_transport_link_send_sync(void){ static void hci_transport_link_send_sync(void){
log_info("link: send sync"); log_debug("link send sync");
hci_transport_link_send_control(link_control_sync, sizeof(link_control_sync)); hci_transport_link_send_control(link_control_sync, sizeof(link_control_sync));
} }
static void hci_transport_link_send_sync_response(void){ static void hci_transport_link_send_sync_response(void){
log_info("link: send sync response"); log_debug("link send sync response");
hci_transport_link_send_control(link_control_sync_response, sizeof(link_control_sync_response)); hci_transport_link_send_control(link_control_sync_response, sizeof(link_control_sync_response));
} }
static void hci_transport_link_send_config(void){ static void hci_transport_link_send_config(void){
log_info("link: send config"); log_debug("link send config");
hci_transport_link_send_control(link_control_config, sizeof(link_control_config)); hci_transport_link_send_control(link_control_config, sizeof(link_control_config));
} }
static void hci_transport_link_send_config_response(void){ static void hci_transport_link_send_config_response(void){
log_info("link: send config response"); log_debug("link send config response");
hci_transport_link_send_control(link_control_config_response, sizeof(link_control_config_response)); hci_transport_link_send_control(link_control_config_response, sizeof(link_control_config_response));
} }
static void hci_transport_link_send_woken(void){ static void hci_transport_link_send_woken(void){
log_info("link: send woken"); log_debug("link send woken");
hci_transport_link_send_control(link_control_woken, sizeof(link_control_woken)); hci_transport_link_send_control(link_control_woken, sizeof(link_control_woken));
} }
static void hci_transport_link_send_wakeup(void){ static void hci_transport_link_send_wakeup(void){
log_info("link: send wakeup"); log_debug("link send wakeup");
hci_transport_link_send_control(link_control_wakeup, sizeof(link_control_wakeup)); hci_transport_link_send_control(link_control_wakeup, sizeof(link_control_wakeup));
} }
static void hci_transport_link_send_sleep(void){ static void hci_transport_link_send_sleep(void){
log_info("link: send sleep"); log_debug("link send sleep");
hci_transport_link_send_control(link_control_sleep, sizeof(link_control_sleep)); hci_transport_link_send_control(link_control_sleep, sizeof(link_control_sleep));
} }
@ -347,8 +347,8 @@ static void hci_transport_link_send_queued_packet(void){
if (link_peer_supports_data_integrity_check){ if (link_peer_supports_data_integrity_check){
data_integrity_check = crc16_calc_for_slip_frame(header, hci_packet, hci_packet_size); data_integrity_check = crc16_calc_for_slip_frame(header, hci_packet, hci_packet_size);
} }
log_info("hci_transport_link_send_queued_packet: seq %u, ack %u, size %u. Append dic %u, dic = 0x%04x", link_seq_nr, link_ack_nr, hci_packet_size, link_peer_supports_data_integrity_check, data_integrity_check); log_debug("hci_transport_link_send_queued_packet: seq %u, ack %u, size %u. Append dic %u, dic = 0x%04x", link_seq_nr, link_ack_nr, hci_packet_size, link_peer_supports_data_integrity_check, data_integrity_check);
log_info_hexdump(hci_packet, hci_packet_size); log_debug_hexdump(hci_packet, hci_packet_size);
hci_transport_slip_send_frame(header, hci_packet, hci_packet_size, data_integrity_check); hci_transport_slip_send_frame(header, hci_packet, hci_packet_size, data_integrity_check);
@ -358,7 +358,7 @@ static void hci_transport_link_send_queued_packet(void){
static void hci_transport_link_send_ack_packet(void){ static void hci_transport_link_send_ack_packet(void){
// Pure ACK package is without DIC as there is no payload either // Pure ACK package is without DIC as there is no payload either
log_info("link: send ack %u", link_ack_nr); log_debug("send ack %u", link_ack_nr);
uint8_t header[4]; uint8_t header[4];
hci_transport_link_calc_header(header, 0, link_ack_nr, 0, 0, LINK_ACKNOWLEDGEMENT_TYPE, 0); hci_transport_link_calc_header(header, 0, link_ack_nr, 0, 0, LINK_ACKNOWLEDGEMENT_TYPE, 0);
hci_transport_slip_send_frame(header, NULL, 0, 0); hci_transport_slip_send_frame(header, NULL, 0, 0);
@ -492,7 +492,7 @@ static void hci_transport_h5_emit_sleep_state(int sleep_active){
if (sleep_active == last_state) return; if (sleep_active == last_state) return;
last_state = sleep_active; last_state = sleep_active;
log_info("hci_transport_h5_emit_sleep_state: %u", sleep_active); log_info("emit_sleep_state: %u", sleep_active);
uint8_t event[3]; uint8_t event[3];
event[0] = HCI_EVENT_TRANSPORT_SLEEP_MODE; event[0] = HCI_EVENT_TRANSPORT_SLEEP_MODE;
event[1] = sizeof(event) - 2; event[1] = sizeof(event) - 2;
@ -515,15 +515,15 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
uint8_t link_packet_type = slip_header[1] & 0x0f; uint8_t link_packet_type = slip_header[1] & 0x0f;
uint16_t link_payload_len = (slip_header[1] >> 4) | (slip_header[2] << 4); uint16_t link_payload_len = (slip_header[1] >> 4) | (slip_header[2] << 4);
log_info("hci_transport_h5_process_frame, reliable %u, packet type %u, seq_nr %u, ack_nr %u , dic %u", reliable_packet, link_packet_type, seq_nr, ack_nr, data_integrity_check_present); log_debug("process_frame, reliable %u, packet type %u, seq_nr %u, ack_nr %u , dic %u", reliable_packet, link_packet_type, seq_nr, ack_nr, data_integrity_check_present);
log_info_hexdump(slip_header, 4); log_debug_hexdump(slip_header, 4);
log_info_hexdump(slip_payload, frame_size_without_header); log_debug_hexdump(slip_payload, frame_size_without_header);
// CSR 8811 does not seem to auto-detect H5 mode and sends data with even parity. // CSR 8811 does not seem to auto-detect H5 mode and sends data with even parity.
// if this byte sequence is detected, just enable even parity // if this byte sequence is detected, just enable even parity
const uint8_t sync_response_bcsp[] = {0x01, 0x7a, 0x06, 0x10}; const uint8_t sync_response_bcsp[] = {0x01, 0x7a, 0x06, 0x10};
if (memcmp(sync_response_bcsp, slip_header, 4) == 0){ if (memcmp(sync_response_bcsp, slip_header, 4) == 0){
log_info("h5: detected BSCP SYNC sent with Even Parity -> discard frame and enable Even Parity"); log_info("detected BSCP SYNC sent with Even Parity -> discard frame and enable Even Parity");
btstack_uart->set_parity(1); btstack_uart->set_parity(1);
return; return;
} }
@ -531,7 +531,7 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
// validate header checksum // validate header checksum
uint8_t header_checksum = slip_header[0] + slip_header[1] + slip_header[2] + slip_header[3]; uint8_t header_checksum = slip_header[0] + slip_header[1] + slip_header[2] + slip_header[3];
if (header_checksum != 0xff){ if (header_checksum != 0xff){
log_info("h5: header checksum 0x%02x (instead of 0xff)", header_checksum); log_info("header checksum 0x%02x (instead of 0xff)", header_checksum);
return; return;
} }
@ -539,7 +539,7 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
int data_integrity_len = data_integrity_check_present ? 2 : 0; int data_integrity_len = data_integrity_check_present ? 2 : 0;
uint16_t received_payload_len = frame_size_without_header - data_integrity_len; uint16_t received_payload_len = frame_size_without_header - data_integrity_len;
if (link_payload_len != received_payload_len){ if (link_payload_len != received_payload_len){
log_info("h5: expected payload len %u but got %u", link_payload_len, received_payload_len); log_info("expected payload len %u but got %u", link_payload_len, received_payload_len);
return; return;
} }
@ -548,7 +548,7 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
uint16_t dic_packet = big_endian_read_16(slip_payload, received_payload_len); uint16_t dic_packet = big_endian_read_16(slip_payload, received_payload_len);
uint16_t dic_calculate = crc16_calc_for_slip_frame(slip_header, slip_payload, received_payload_len); uint16_t dic_calculate = crc16_calc_for_slip_frame(slip_header, slip_payload, received_payload_len);
if (dic_packet != dic_calculate){ if (dic_packet != dic_calculate){
log_info("h5: expected dic value 0x%04x but got 0x%04x", dic_calculate, dic_packet); log_info("expected dic value 0x%04x but got 0x%04x", dic_calculate, dic_packet);
return; return;
} }
} }
@ -557,11 +557,11 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
case LINK_UNINITIALIZED: case LINK_UNINITIALIZED:
if (link_packet_type != LINK_CONTROL_PACKET_TYPE) break; if (link_packet_type != LINK_CONTROL_PACKET_TYPE) break;
if (memcmp(slip_payload, link_control_sync, sizeof(link_control_sync)) == 0){ if (memcmp(slip_payload, link_control_sync, sizeof(link_control_sync)) == 0){
log_info("link: received sync"); log_debug("link received sync");
hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_SYNC_RESPONSE; hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_SYNC_RESPONSE;
} }
if (memcmp(slip_payload, link_control_sync_response, sizeof(link_control_sync_response)) == 0){ if (memcmp(slip_payload, link_control_sync_response, sizeof(link_control_sync_response)) == 0){
log_info("link: received sync response"); log_debug("link received sync response");
link_state = LINK_INITIALIZED; link_state = LINK_INITIALIZED;
btstack_run_loop_remove_timer(&link_timer); btstack_run_loop_remove_timer(&link_timer);
log_info("link initialized"); log_info("link initialized");
@ -573,17 +573,17 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
case LINK_INITIALIZED: case LINK_INITIALIZED:
if (link_packet_type != LINK_CONTROL_PACKET_TYPE) break; if (link_packet_type != LINK_CONTROL_PACKET_TYPE) break;
if (memcmp(slip_payload, link_control_sync, sizeof(link_control_sync)) == 0){ if (memcmp(slip_payload, link_control_sync, sizeof(link_control_sync)) == 0){
log_info("link: received sync"); log_debug("link received sync");
hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_SYNC_RESPONSE; hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_SYNC_RESPONSE;
} }
if (memcmp(slip_payload, link_control_config, link_control_config_prefix_len) == 0){ if (memcmp(slip_payload, link_control_config, link_control_config_prefix_len) == 0){
log_info("link: received config, 0x%02x", slip_payload[2]); log_debug("link received config, 0x%02x", slip_payload[2]);
hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_CONFIG_RESPONSE; hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_CONFIG_RESPONSE;
} }
if (memcmp(slip_payload, link_control_config_response, link_control_config_response_prefix_len) == 0){ if (memcmp(slip_payload, link_control_config_response, link_control_config_response_prefix_len) == 0){
uint8_t config = slip_payload[2]; uint8_t config = slip_payload[2];
link_peer_supports_data_integrity_check = (config & 0x10) != 0; link_peer_supports_data_integrity_check = (config & 0x10) != 0;
log_info("link: received config response 0x%02x, data integrity check supported %u", config, link_peer_supports_data_integrity_check); log_info("link received config response 0x%02x, data integrity check supported %u", config, link_peer_supports_data_integrity_check);
link_state = LINK_ACTIVE; link_state = LINK_ACTIVE;
btstack_run_loop_remove_timer(&link_timer); btstack_run_loop_remove_timer(&link_timer);
log_info("link activated"); log_info("link activated");
@ -614,7 +614,7 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
// our packet is good if the remote expects our seq nr + 1 // our packet is good if the remote expects our seq nr + 1
int next_seq_nr = hci_transport_link_inc_seq_nr(link_seq_nr); int next_seq_nr = hci_transport_link_inc_seq_nr(link_seq_nr);
if (hci_transport_link_have_outgoing_packet() && next_seq_nr == ack_nr){ if (hci_transport_link_have_outgoing_packet() && next_seq_nr == ack_nr){
log_info("h5: outoing packet with seq %u ack'ed", link_seq_nr); log_debug("outoing packet with seq %u ack'ed", link_seq_nr);
link_seq_nr = next_seq_nr; link_seq_nr = next_seq_nr;
hci_transport_link_clear_queue(); hci_transport_link_clear_queue();
@ -627,12 +627,12 @@ static void hci_transport_h5_process_frame(uint16_t frame_size){
switch (link_packet_type){ switch (link_packet_type){
case LINK_CONTROL_PACKET_TYPE: case LINK_CONTROL_PACKET_TYPE:
if (memcmp(slip_payload, link_control_config, sizeof(link_control_config)) == 0){ if (memcmp(slip_payload, link_control_config, sizeof(link_control_config)) == 0){
log_info("link: received config"); log_debug("link received config");
hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_CONFIG_RESPONSE; hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_CONFIG_RESPONSE;
break; break;
} }
if (memcmp(slip_payload, link_control_sync, sizeof(link_control_sync)) == 0){ if (memcmp(slip_payload, link_control_sync, sizeof(link_control_sync)) == 0){
log_info("link: received sync in ACTIVE STATE!"); log_debug("link received sync in ACTIVE STATE!");
// TODO sync during active indicates peer reset -> full upper layer reset necessary // TODO sync during active indicates peer reset -> full upper layer reset necessary
break; break;
} }
@ -697,7 +697,7 @@ static void hci_transport_link_update_resend_timeout(uint32_t baudrate){
static uint8_t hci_transport_link_read_byte; static uint8_t hci_transport_link_read_byte;
static void hci_transport_h5_read_next_byte(void){ static void hci_transport_h5_read_next_byte(void){
log_debug("h5: rx nxt"); log_debug("rx nxt");
btstack_uart->receive_block(&hci_transport_link_read_byte, 1); btstack_uart->receive_block(&hci_transport_link_read_byte, 1);
} }
@ -769,7 +769,7 @@ static int hci_transport_h5_open(void){
// //
if (hci_transport_bcsp_mode){ if (hci_transport_bcsp_mode){
log_info("H5: enable even parity for BCSP mode"); log_info("enable even parity for BCSP mode");
btstack_uart->set_parity(1); btstack_uart->set_parity(1);
} }
@ -780,10 +780,10 @@ static int hci_transport_h5_open(void){
supported_sleep_modes = btstack_uart->get_supported_sleep_modes(); supported_sleep_modes = btstack_uart->get_supported_sleep_modes();
} }
if (supported_sleep_modes & BTSTACK_UART_SLEEP_MASK_RTS_LOW_WAKE_ON_RX_EDGE){ if (supported_sleep_modes & BTSTACK_UART_SLEEP_MASK_RTS_LOW_WAKE_ON_RX_EDGE){
log_info("H5: using wake on RX"); log_info("using wake on RX");
btstack_uart_sleep_mode = BTSTACK_UART_SLEEP_RTS_LOW_WAKE_ON_RX_EDGE; btstack_uart_sleep_mode = BTSTACK_UART_SLEEP_RTS_LOW_WAKE_ON_RX_EDGE;
} else { } else {
log_info("H5: UART driver does not provide compatible sleep mode"); log_info("UART driver does not provide compatible sleep mode");
} }
// setup resend timeout // setup resend timeout
@ -812,7 +812,7 @@ static void hci_transport_h5_register_packet_handler(void (*handler)(uint8_t pac
static int hci_transport_h5_can_send_packet_now(uint8_t packet_type){ static int hci_transport_h5_can_send_packet_now(uint8_t packet_type){
int res = !hci_transport_link_have_outgoing_packet() && link_state == LINK_ACTIVE; int res = !hci_transport_link_have_outgoing_packet() && link_state == LINK_ACTIVE;
// log_info("hci_transport_h5_can_send_packet_now: %u", res); // log_info("can_send_packet_now: %u", res);
return res; return res;
} }
@ -829,7 +829,7 @@ static int hci_transport_h5_send_packet(uint8_t packet_type, uint8_t *packet, in
if (link_peer_asleep){ if (link_peer_asleep){
hci_transport_h5_emit_sleep_state(0); hci_transport_h5_emit_sleep_state(0);
if (btstack_uart_sleep_mode){ if (btstack_uart_sleep_mode){
log_info("h5: disable UART sleep"); log_info("disable UART sleep");
btstack_uart->set_sleep(BTSTACK_UART_SLEEP_OFF); btstack_uart->set_sleep(BTSTACK_UART_SLEEP_OFF);
} }
hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_WAKEUP; hci_transport_link_actions |= HCI_TRANSPORT_LINK_SEND_WAKEUP;
@ -844,7 +844,7 @@ static int hci_transport_h5_send_packet(uint8_t packet_type, uint8_t *packet, in
static int hci_transport_h5_set_baudrate(uint32_t baudrate){ static int hci_transport_h5_set_baudrate(uint32_t baudrate){
log_info("hci_transport_h5_set_baudrate %u", baudrate); log_info("set_baudrate %u", baudrate);
int res = btstack_uart->set_baudrate(baudrate); int res = btstack_uart->set_baudrate(baudrate);
if (res) return res; if (res) return res;
@ -854,7 +854,7 @@ static int hci_transport_h5_set_baudrate(uint32_t baudrate){
static void hci_transport_h5_reset_link(void){ static void hci_transport_h5_reset_link(void){
log_info("hci_transport_h5_reset_link"); log_info("reset_link");
// clear outgoing queue // clear outgoing queue
hci_transport_link_clear_queue(); hci_transport_link_clear_queue();