mirror/btstack
1
0
Fork 0
mirror of https://github.com/bluekitchen/btstack.git synced 2025-04-09 21:45:54 +00:00
Code Issues Packages Projects Releases Wiki Activity

use log_info instead of printf, remove trailing newline from log calls

Browse Source
This commit is contained in:
mila@ringwald.ch 2014-08-15 21:26:50 +00:00
parent 1ed596972a
commit 9da54300b6
30 changed files with 380 additions and 385 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
CocoaTouch/src/BTstackManager.m
View File

@ -345,7 +345,7 @@ static void packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packe
break;
}
if (!found) {
// printf("Queried all devices, restart.\n");
// log_info("Queried all devices, restart.");
discoveryState = kInquiry;
bt_send_cmd(&hci_inquiry, HCI_INQUIRY_LAP, INQUIRY_INTERVAL, 0);
[self sendDiscoveryInquiry];
@ -461,7 +461,7 @@ static void packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packe
break;
case HCI_EVENT_INQUIRY_COMPLETE:
// printf("Inquiry scan done.\n");
// log_info("Inquiry scan done.");
discoveryState = kRemoteName;
discoveryDeviceIndex = 0;
[self discoveryRemoteName];

76
ble/att.c
View File

@ -38,18 +38,12 @@
#include <string.h>
#include "att.h"
#include "debug.h"
#include <btstack/utils.h>
// Buetooth Base UUID 00000000-0000-1000-8000-00805F9B34FB in little endian
static const uint8_t bluetooth_base_uuid[] = { 0xfb, 0x34, 0x9b, 0x5f, 0x80, 0x00, 0x00, 0x80, 0x00, 0x10, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 };
static void hexdump2(void const *data, int size){
int i;
for (i=0; i<size;i++){
printf("%02X ", ((uint8_t *)data)[i]);
}
printf("\n");
}
static int is_Bluetooth_Base_UUID(uint8_t const *uuid){
if (memcmp(&uuid[0], &bluetooth_base_uuid[0], 12)) return 0;
@ -206,18 +200,18 @@ void att_dump_attributes(void){
while (att_iterator_has_next(&it)){
att_iterator_fetch_next(&it);
if (it.handle == 0) {
printf("Handle: END\n");
log_info("Handle: END");
return;
}
printf("Handle: 0x%04x, flags: 0x%04x, uuid: ", it.handle, it.flags);
log_info("Handle: 0x%04x, flags: 0x%04x, uuid: ", it.handle, it.flags);
if (it.flags & ATT_PROPERTY_UUID128){
swap128(it.uuid, uuid128);
printUUID128(uuid128);
} else {
printf("%04x", READ_BT_16(it.uuid, 0));
log_info("%04x", READ_BT_16(it.uuid, 0));
}
printf(", value_len: %u, value: ", it.value_len);
hexdump2(it.value, it.value_len);
log_info(", value_len: %u, value: ", it.value_len);
hexdump(it.value, it.value_len);
}
}
@ -272,7 +266,7 @@ static inline uint16_t setup_error_invalid_offset(uint8_t * response_buffer, uin
static uint8_t att_validate_security(att_connection_t * att_connection, att_iterator_t * it){
int required_encryption_size = it->flags >> 12;
if (required_encryption_size) required_encryption_size++; // store -1 to fit into 4 bit
printf("att_validate_security. flags 0x%04x - req enc size %u, authorized %u, authenticated %u, encryption_key_size %u\n",
log_info("att_validate_security. flags 0x%04x - req enc size %u, authorized %u, authenticated %u, encryption_key_size %u",
it->flags, required_encryption_size, att_connection->authorized, att_connection->authenticated, att_connection->encryption_key_size);
if ((it->flags & ATT_PROPERTY_AUTHENTICATION_REQUIRED) && att_connection->authenticated == 0) {
return ATT_ERROR_INSUFFICIENT_AUTHENTICATION;
@ -314,7 +308,7 @@ static uint16_t handle_exchange_mtu_request(att_connection_t * att_connection, u
static uint16_t handle_find_information_request2(att_connection_t * att_connection, uint8_t * response_buffer, uint16_t response_buffer_size,
uint16_t start_handle, uint16_t end_handle){
printf("ATT_FIND_INFORMATION_REQUEST: from %04X to %04X\n", start_handle, end_handle);
log_info("ATT_FIND_INFORMATION_REQUEST: from %04X to %04X", start_handle, end_handle);
uint8_t request_type = ATT_FIND_INFORMATION_REQUEST;
if (start_handle > end_handle || start_handle == 0){
@ -332,7 +326,7 @@ static uint16_t handle_find_information_request2(att_connection_t * att_connecti
if (it.handle > end_handle) break;
if (it.handle < start_handle) continue;
// printf("Handle 0x%04x\n", it.handle);
// log_info("Handle 0x%04x", it.handle);
uint16_t this_uuid_len = (it.flags & ATT_PROPERTY_UUID128) ? 16 : 2;
@ -391,8 +385,8 @@ static uint16_t handle_find_by_type_value_request2(att_connection_t * att_connec
uint16_t start_handle, uint16_t end_handle,
uint16_t attribute_type, uint16_t attribute_len, uint8_t* attribute_value){
printf("ATT_FIND_BY_TYPE_VALUE_REQUEST: from %04X to %04X, type %04X, value: ", start_handle, end_handle, attribute_type);
hexdump2(attribute_value, attribute_len);
log_info("ATT_FIND_BY_TYPE_VALUE_REQUEST: from %04X to %04X, type %04X, value: ", start_handle, end_handle, attribute_type);
hexdump(attribute_value, attribute_len);
uint8_t request_type = ATT_FIND_BY_TYPE_VALUE_REQUEST;
if (start_handle > end_handle || start_handle == 0){
@ -415,7 +409,7 @@ static uint16_t handle_find_by_type_value_request2(att_connection_t * att_connec
if (in_group &&
(it.handle == 0 || att_iterator_match_uuid16(&it, GATT_PRIMARY_SERVICE_UUID) || att_iterator_match_uuid16(&it, GATT_SECONDARY_SERVICE_UUID))){
printf("End of group, handle 0x%04x\n", prev_handle);
log_info("End of group, handle 0x%04x", prev_handle);
bt_store_16(response_buffer, offset, prev_handle);
offset += 2;
in_group = 0;
@ -431,7 +425,7 @@ static uint16_t handle_find_by_type_value_request2(att_connection_t * att_connec
// does current attribute match
if (it.handle && att_iterator_match_uuid16(&it, attribute_type) && attribute_len == it.value_len && memcmp(attribute_value, it.value, it.value_len) == 0){
printf("Begin of group, handle 0x%04x\n", it.handle);
log_info("Begin of group, handle 0x%04x", it.handle);
bt_store_16(response_buffer, offset, it.handle);
offset += 2;
in_group = 1;
@ -460,8 +454,8 @@ static uint16_t handle_read_by_type_request2(att_connection_t * att_connection,
uint16_t start_handle, uint16_t end_handle,
uint16_t attribute_type_len, uint8_t * attribute_type){
printf("ATT_READ_BY_TYPE_REQUEST: from %04X to %04X, type: ", start_handle, end_handle);
hexdump2(attribute_type, attribute_type_len);
log_info("ATT_READ_BY_TYPE_REQUEST: from %04X to %04X, type: ", start_handle, end_handle);
hexdump(attribute_type, attribute_type_len);
uint8_t request_type = ATT_READ_BY_TYPE_REQUEST;
if (start_handle > end_handle || start_handle == 0){
@ -565,7 +559,7 @@ static uint16_t handle_read_by_type_request(att_connection_t * att_connection, u
//
static uint16_t handle_read_request2(att_connection_t * att_connection, uint8_t * response_buffer, uint16_t response_buffer_size, uint16_t handle){
printf("ATT_READ_REQUEST: handle %04x\n", handle);
log_info("ATT_READ_REQUEST: handle %04x", handle);
uint8_t request_type = ATT_READ_REQUEST;
att_iterator_t it;
@ -610,7 +604,7 @@ static uint16_t handle_read_request(att_connection_t * att_connection, uint8_t *
// MARK: ATT_READ_BLOB_REQUEST 0x0c
//
static uint16_t handle_read_blob_request2(att_connection_t * att_connection, uint8_t * response_buffer, uint16_t response_buffer_size, uint16_t handle, uint16_t value_offset){
printf("ATT_READ_BLOB_REQUEST: handle %04x, offset %u\n", handle, value_offset);
log_info("ATT_READ_BLOB_REQUEST: handle %04x, offset %u", handle, value_offset);
uint8_t request_type = ATT_READ_BLOB_REQUEST;
att_iterator_t it;
@ -659,7 +653,7 @@ uint16_t handle_read_blob_request(att_connection_t * att_connection, uint8_t * r
// MARK: ATT_READ_MULTIPLE_REQUEST 0x0e
//
static uint16_t handle_read_multiple_request2(att_connection_t * att_connection, uint8_t * response_buffer, uint16_t response_buffer_size, uint16_t num_handles, uint16_t * handles){
printf("ATT_READ_MULTIPLE_REQUEST: num handles %u\n", num_handles);
log_info("ATT_READ_MULTIPLE_REQUEST: num handles %u", num_handles);
uint8_t request_type = ATT_READ_MULTIPLE_REQUEST;
// TODO: figure out which error to respond with
@ -741,8 +735,8 @@ static uint16_t handle_read_by_group_type_request2(att_connection_t * att_connec
uint16_t start_handle, uint16_t end_handle,
uint16_t attribute_type_len, uint8_t * attribute_type){
printf("ATT_READ_BY_GROUP_TYPE_REQUEST: from %04X to %04X, buffer size %u, type: ", start_handle, end_handle, response_buffer_size);
hexdump2(attribute_type, attribute_type_len);
log_info("ATT_READ_BY_GROUP_TYPE_REQUEST: from %04X to %04X, buffer size %u, type: ", start_handle, end_handle, response_buffer_size);
hexdump(attribute_type, attribute_type_len);
uint8_t request_type = ATT_READ_BY_GROUP_TYPE_REQUEST;
if (start_handle > end_handle || start_handle == 0){
@ -770,12 +764,12 @@ static uint16_t handle_read_by_group_type_request2(att_connection_t * att_connec
if (it.handle && it.handle < start_handle) continue;
if (it.handle > end_handle) break; // (1)
// printf("Handle 0x%04x\n", it.handle);
// log_info("Handle 0x%04x", it.handle);
// close current tag, if within a group and a new service definition starts or we reach end of att db
if (in_group &&
(it.handle == 0 || att_iterator_match_uuid16(&it, GATT_PRIMARY_SERVICE_UUID) || att_iterator_match_uuid16(&it, GATT_SECONDARY_SERVICE_UUID))){
// printf("End of group, handle 0x%04x, val_len: %u\n", prev_handle, pair_len - 4);
// log_info("End of group, handle 0x%04x, val_len: %u", prev_handle, pair_len - 4);
bt_store_16(response_buffer, offset, group_start_handle);
offset += 2;
@ -795,7 +789,7 @@ static uint16_t handle_read_by_group_type_request2(att_connection_t * att_connec
prev_handle = it.handle;
// does current attribute match
// printf("compare: %04x == %04x\n", *(uint16_t*) context->attribute_type, *(uint16_t*) uuid);
// log_info("compare: %04x == %04x", *(uint16_t*) context->attribute_type, *(uint16_t*) uuid);
if (it.handle && att_iterator_match_uuid(&it, attribute_type, attribute_type_len)) {
// check if value has same len as last one
@ -806,7 +800,7 @@ static uint16_t handle_read_by_group_type_request2(att_connection_t * att_connec
}
}
// printf("Begin of group, handle 0x%04x\n", it.handle);
// log_info("Begin of group, handle 0x%04x", it.handle);
// first
if (offset == 1) {
@ -1056,11 +1050,11 @@ uint16_t att_handle_request(att_connection_t * att_connection,
handle_write_command(att_connection, request_buffer, request_len, response_buffer, response_buffer_size);
break;
case ATT_SIGNED_WRITE_COMMAND:
printf("handle_signed_write_command preprocessed by att_server.c\n");
log_info("handle_signed_write_command preprocessed by att_server.c");
break;
default:
printf("Unhandled ATT Command: %02X, DATA: ", request_buffer[0]);
hexdump2(&request_buffer[9], request_len-9);
log_info("Unhandled ATT Command: %02X, DATA: ", request_buffer[0]);
hexdump(&request_buffer[9], request_len-9);
break;
}
return response_len;
@ -1079,28 +1073,28 @@ int main(){
uint8_t uuid_1[] = { 0x00, 0x18};
acl_buffer_size = handle_find_by_type_value_request2(acl_buffer, 19, 0, 0xffff, 0x2800, 2, (uint8_t *) &uuid_1);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
uint8_t uuid_3[] = { 0x00, 0x2a};
acl_buffer_size = handle_read_by_type_request2(acl_buffer, 19, 0, 0xffff, 2, (uint8_t *) &uuid_3);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
acl_buffer_size = handle_find_by_type_value_request2(acl_buffer, 19, 0, 0xffff, 0x2800, 2, (uint8_t *) &uuid_1);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
uint8_t uuid_4[] = { 0x00, 0x28};
acl_buffer_size = handle_read_by_group_type_request2(acl_buffer, 20, 0, 0xffff, 2, (uint8_t *) &uuid_4);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
acl_buffer_size = handle_find_information_request2(acl_buffer, 20, 0, 0xffff);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
acl_buffer_size = handle_find_information_request2(acl_buffer, 20, 3, 0xffff);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
acl_buffer_size = handle_find_information_request2(acl_buffer, 20, 5, 0xffff);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
acl_buffer_size = handle_read_request2(acl_buffer, 19, 0x0003);
hexdump2(acl_buffer, acl_buffer_size);
hexdump(acl_buffer, acl_buffer_size);
return 0;
}

2
ble/att.h
View File

@ -199,7 +199,7 @@ void att_set_read_callback(att_read_callback_t callback);
void att_set_write_callback(att_write_callback_t callback);
/*
* @brief debug helper, dump ATT database to stdout using printf
* @brief debug helper, dump ATT database to stdout using log_info
*/
void att_dump_attributes(void);

22
ble/att_server.c
View File

@ -151,17 +151,17 @@ static void att_event_packet_handler (uint8_t packet_type, uint16_t channel, uin
break;
case SM_IDENTITY_RESOLVING_STARTED:
printf("SM_IDENTITY_RESOLVING_STARTED\n");
log_info("SM_IDENTITY_RESOLVING_STARTED");
att_ir_lookup_active = 1;
break;
case SM_IDENTITY_RESOLVING_SUCCEEDED:
att_ir_lookup_active = 0;
att_ir_central_device_db_index = ((sm_event_t*) packet)->central_device_db_index;
printf("SM_IDENTITY_RESOLVING_SUCCEEDED id %u\n", att_ir_central_device_db_index);
log_info("SM_IDENTITY_RESOLVING_SUCCEEDED id %u", att_ir_central_device_db_index);
att_run();
break;
case SM_IDENTITY_RESOLVING_FAILED:
printf("SM_IDENTITY_RESOLVING_FAILED\n");
log_info("SM_IDENTITY_RESOLVING_FAILED");
att_ir_lookup_active = 0;
att_ir_central_device_db_index = -1;
att_run();
@ -190,7 +190,7 @@ static void att_signed_write_handle_cmac_result(uint8_t hash[8]){
if (att_server_state != ATT_SERVER_W4_SIGNED_WRITE_VALIDATION) return;
if (memcmp(hash, &att_request_buffer[att_request_size-8], 8)){
printf("ATT Signed Write, invalid signature\n");
log_info("ATT Signed Write, invalid signature");
att_server_state = ATT_SERVER_IDLE;
return;
}
@ -209,14 +209,14 @@ static void att_run(void){
return;
case ATT_SERVER_REQUEST_RECEIVED:
if (att_request_buffer[0] == ATT_SIGNED_WRITE_COMMAND){
printf("ATT Signed Write!\n");
log_info("ATT Signed Write!");
if (!sm_cmac_ready()) {
printf("ATT Signed Write, sm_cmac engine not ready. Abort\n");
log_info("ATT Signed Write, sm_cmac engine not ready. Abort");
att_server_state = ATT_SERVER_IDLE;
return;
}
if (att_request_size < (3 + 12)) {
printf("ATT Signed Write, request to short. Abort.\n");
log_info("ATT Signed Write, request to short. Abort.");
att_server_state = ATT_SERVER_IDLE;
return;
}
@ -224,7 +224,7 @@ static void att_run(void){
return;
}
if (att_ir_central_device_db_index < 0){
printf("ATT Signed Write, CSRK not available\n");
log_info("ATT Signed Write, CSRK not available");
att_server_state = ATT_SERVER_IDLE;
return;
}
@ -232,9 +232,9 @@ static void att_run(void){
// check counter
uint32_t counter_packet = READ_BT_32(att_request_buffer, att_request_size-12);
uint32_t counter_db = central_device_db_counter_get(att_ir_central_device_db_index);
printf("ATT Signed Write, DB counter %u, packet counter %u\n", counter_db, counter_packet);
log_info("ATT Signed Write, DB counter %u, packet counter %u", counter_db, counter_packet);
if (counter_packet < counter_db){
printf("ATT Signed Write, db reports higher counter, abort\n");
log_info("ATT Signed Write, db reports higher counter, abort");
att_server_state = ATT_SERVER_IDLE;
return;
}
@ -243,7 +243,7 @@ static void att_run(void){
sm_key_t csrk;
central_device_db_csrk(att_ir_central_device_db_index, csrk);
att_server_state = ATT_SERVER_W4_SIGNED_WRITE_VALIDATION;
printf("Orig Signature: ");
log_info("Orig Signature: ");
hexdump( &att_request_buffer[att_request_size-8], 8);
sm_cmac_start(csrk, att_request_size - 8, att_request_buffer, att_signed_write_handle_cmac_result);
return;

16
ble/central_device_db_memory.c
View File

@ -38,6 +38,7 @@
#include <stdio.h>
#include <string.h>
#include "debug.h"
// Central Device db implemenation using static memory
typedef struct central_device_memory_db {
@ -68,9 +69,9 @@ void central_device_db_remove(int index){
int central_device_db_add(int addr_type, bd_addr_t addr, sm_key_t irk, sm_key_t csrk){
if (central_devices_count >= CENTRAL_DEVICE_MEMORY_SIZE) return -1;
printf("Central Device DB adding type %u - %s\n", addr_type, bd_addr_to_str(addr));
print_key("irk", irk);
print_key("csrk", csrk);
log_info("Central Device DB adding type %u - %s", addr_type, bd_addr_to_str(addr));
log_key("irk", irk);
log_key("csrk", csrk);
int index = central_devices_count;
central_devices_count++;
@ -109,12 +110,11 @@ void central_device_db_counter_set(int index, uint32_t counter){
}
void central_device_db_dump(){
printf("Central Device DB dump, devices: %u\n", central_devices_count);
log_info("Central Device DB dump, devices: %u", central_devices_count);
int i;
for (i=0;i<central_devices_count;i++){
printf("%u: %u ", i, central_devices[i].addr_type);
print_bd_addr(central_devices[i].addr);
print_key("irk", central_devices[i].irk);
print_key("csrk", central_devices[i].csrk);
log_info("%u: %u %s", i, central_devices[i].addr_type, bd_addr_to_str(central_devices[i].addr));
log_key("irk", central_devices[i].irk);
log_key("csrk", central_devices[i].csrk);
}
}

14
ble/gatt_client.c
View File

@ -333,11 +333,11 @@ static void report_gatt_services(gatt_client_t * peripheral, uint8_t * packet,
swap128(&packet[i+4], service.uuid128);
}
event.service = service;
// printf(" report_gatt_services 0x%02x : 0x%02x-0x%02x\n", service.uuid16, service.start_group_handle, service.end_group_handle);
// log_info(" report_gatt_services 0x%02x : 0x%02x-0x%02x", service.uuid16, service.start_group_handle, service.end_group_handle);
(*gatt_client_callback)((le_event_t*)&event);
}
// printf("report_gatt_services for %02X done\n", peripheral->handle);
// log_info("report_gatt_services for %02X done", peripheral->handle);
}
// helper
@ -573,7 +573,7 @@ static void gatt_client_run(){
if (!l2cap_can_send_fixed_channel_packet_now(peripheral->handle)) return;
// printf("- handle_peripheral_list, mtu state %u, client state %u\n", peripheral->mtu_state, peripheral->gatt_client_state);
// log_info("- handle_peripheral_list, mtu state %u, client state %u", peripheral->mtu_state, peripheral->gatt_client_state);
switch (peripheral->mtu_state) {
case SEND_MTU_EXCHANGE:{
@ -611,7 +611,7 @@ static void gatt_client_run(){
break;
}
// printf("gatt_client_state %u\n", peripheral->gatt_client_state);
// log_info("gatt_client_state %u", peripheral->gatt_client_state);
switch (peripheral->gatt_client_state){
case P_W2_SEND_SERVICE_QUERY:
peripheral->gatt_client_state = P_W4_SERVICE_QUERY_RESULT;
@ -1004,7 +1004,7 @@ static void gatt_client_att_packet_handler(uint8_t packet_type, uint16_t handle,
break;
default:
printf("ATT Handler, unhandled response type 0x%02x\n", packet[0]);
log_info("ATT Handler, unhandled response type 0x%02x", packet[0]);
break;
}
gatt_client_run();
@ -1029,7 +1029,7 @@ static void att_signed_write_handle_cmac_result(uint8_t hash[8]){
le_command_status_t gatt_client_signed_write_without_response(gatt_client_t * peripheral, uint16_t handle, uint16_t message_len, uint8_t * message, sm_key_t csrk, uint32_t sign_counter){
if (!gatt_client_is_ready(peripheral)) return BLE_PERIPHERAL_IN_WRONG_STATE;
if (!sm_cmac_ready()) {
printf("ATT Signed Write, sm_cmac engine not ready. Abort\n");
log_info("ATT Signed Write, sm_cmac engine not ready. Abort");
return BLE_PERIPHERAL_IN_WRONG_STATE;
}
@ -1230,7 +1230,7 @@ le_command_status_t gatt_client_write_client_characteristic_configuration(gatt_c
return BLE_CHARACTERISTIC_NOTIFICATION_NOT_SUPPORTED;
} else if ( (configuration & GATT_CLIENT_CHARACTERISTICS_CONFIGURATION_INDICATION) &&
(characteristic->properties & ATT_PROPERTY_INDICATE) == 0){
log_info("le_central_write_client_characteristic_configuration: BLE_CHARACTERISTIC_INDICATION_NOT_SUPPORTED\n");
log_info("le_central_write_client_characteristic_configuration: BLE_CHARACTERISTIC_INDICATION_NOT_SUPPORTED");
return BLE_CHARACTERISTIC_INDICATION_NOT_SUPPORTED;
}

6
ble/l2cap_le.c
View File

@ -117,11 +117,11 @@ int l2cap_send_prepared_connectionless(uint16_t handle, uint16_t cid, uint16_t l
}
if (!hci_can_send_prepared_acl_packet_now(handle)){
log_info("l2cap_send_prepared_connectionless handle %u,, cid %u, cannot send\n", handle, cid);
log_info("l2cap_send_prepared_connectionless handle %u,, cid %u, cannot send", handle, cid);
return BTSTACK_ACL_BUFFERS_FULL;
}
log_debug("l2cap_send_prepared_connectionless handle %u, cid %u\n", handle, cid);
log_debug("l2cap_send_prepared_connectionless handle %u, cid %u", handle, cid);
uint8_t *acl_buffer = hci_get_outgoing_packet_buffer();
@ -142,7 +142,7 @@ int l2cap_send_prepared_connectionless(uint16_t handle, uint16_t cid, uint16_t l
int l2cap_send_connectionless(uint16_t handle, uint16_t cid, uint8_t *data, uint16_t len){
if (!hci_can_send_acl_packet_now(handle)){
log_info("l2cap_send_connectionless cid %u, cannot send\n", cid);
log_info("l2cap_send_connectionless cid %u, cannot send", cid);
return BTSTACK_ACL_BUFFERS_FULL;
}

108
ble/sm.c
View File

@ -356,8 +356,8 @@ static const stk_generation_method_t stk_generation_method[5][5] = {
static void sm_run();
static void sm_notify_client(uint8_t type, uint8_t addr_type, bd_addr_t address, uint32_t passkey, uint16_t index);
static void print_hex16(const char * name, uint16_t value){
printf("%-6s 0x%04x\n", name, value);
static void log_info_hex16(const char * name, uint16_t value){
log_info("%-6s 0x%04x", name, value);
}
// @returns 1 if all bytes are 0
@ -399,7 +399,7 @@ static void sm_truncate_key(sm_key_t key, int max_encryption_size){
// established.
static void sm_2timeout_handler(timer_source_t * timer){
printf("SM timeout\n");
log_info("SM timeout");
connection->sm_engine_state = SM_GENERAL_TIMEOUT;
}
static void sm_2timeout_start(){
@ -425,13 +425,13 @@ static uint32_t gap_random_adress_update_period;
static void gap_random_address_trigger(){
if (rau_state != RAU_IDLE) return;
printf("gap_random_address_trigger\n");
log_info("gap_random_address_trigger");
rau_state = RAU_GET_RANDOM;
sm_run();
}
static void gap_random_address_update_handler(timer_source_t * timer){
printf("GAP Random Address Update due\n");
log_info("GAP Random Address Update due");
run_loop_set_timer(&gap_random_address_update_timer, gap_random_adress_update_period);
run_loop_add_timer(&gap_random_address_update_timer);
gap_random_address_trigger();
@ -498,15 +498,15 @@ static void sm_c1_t1(sm_key_t r, uint8_t preq[7], uint8_t pres[7], uint8_t iat,
swap56(preq, &p1[7]);
p1[14] = rat;
p1[15] = iat;
print_key("p1", p1);
print_key("r", r);
log_key("p1", p1);
log_key("r", r);
// t1 = r xor p1
int i;
for (i=0;i<16;i++){
t1[i] = r[i] ^ p1[i];
}
print_key("t1", t1);
log_key("t1", t1);
}
// calculate arguments for second AES128 operation in C1 function
@ -521,19 +521,19 @@ static void sm_c1_t3(sm_key_t t2, bd_addr_t ia, bd_addr_t ra, sm_key_t t3){
memset(p2, 0, 16);
memcpy(&p2[4], ia, 6);
memcpy(&p2[10], ra, 6);
print_key("p2", p2);
log_key("p2", p2);
// c1 = e(k, t2_xor_p2)
int i;
for (i=0;i<16;i++){
t3[i] = t2[i] ^ p2[i];
}
print_key("t3", t3);
log_key("t3", t3);
}
static void sm_s1_r_prime(sm_key_t r1, sm_key_t r2, sm_key_t r_prime){
print_key("r1", r1);
print_key("r2", r2);
log_key("r1", r1);
log_key("r2", r2);
memcpy(&r_prime[8], &r2[8], 8);
memcpy(&r_prime[0], &r1[8], 8);
}
@ -580,8 +580,8 @@ static void sm_setup_tk(){
// Requirements Flags shall be ignored when selecting the pairing method and the
// Out of Band pairing method shall be used.
if (setup->sm_m_preq.oob_data_flag && setup->sm_s_pres.oob_data_flag){
printf("SM: have OOB data");
print_key("OOB", setup->sm_tk);
log_info("SM: have OOB data");
log_key("OOB", setup->sm_tk);
setup->sm_stk_generation_method = OOB;
return;
}
@ -601,7 +601,7 @@ static void sm_setup_tk(){
// Otherwise the IO capabilities of the devices shall be used to determine the
// pairing method as defined in Table 2.4.
setup->sm_stk_generation_method = stk_generation_method[setup->sm_s_pres.io_capability][setup->sm_m_preq.io_capability];
printf("sm_setup_tk: master io cap: %u, slave io cap: %u -> method %u\n",
log_info("sm_setup_tk: master io cap: %u, slave io cap: %u -> method %u",
setup->sm_m_preq.io_capability, setup->sm_s_pres.io_capability, setup->sm_stk_generation_method);
}
@ -732,14 +732,14 @@ static void sm_cmac_handle_aes_engine_ready(){
for (i=0;i<16;i++){
y[i] = sm_cmac_x[i] ^ sm_cmac_m_last[i];
}
print_key("Y", y);
log_key("Y", y);
sm_cmac_block_current++;
sm_aes128_start(sm_cmac_k, y);
sm_cmac_next_state();
break;
}
default:
printf("sm_cmac_handle_aes_engine_ready called in state %u\n", sm_cmac_state);
log_info("sm_cmac_handle_aes_engine_ready called in state %u", sm_cmac_state);
break;
}
}
@ -760,9 +760,9 @@ static void sm_cmac_handle_encryption_result(sm_key_t data){
k2[15] ^= 0x87;
}
print_key("k", sm_cmac_k);
print_key("k1", k1);
print_key("k2", k2);
log_key("k", sm_cmac_k);
log_key("k1", k1);
log_key("k2", k2);
// step 4: set m_last
int i;
@ -796,11 +796,11 @@ static void sm_cmac_handle_encryption_result(sm_key_t data){
break;
case CMAC_W4_MLAST:
// done
print_key("CMAC", data);
log_key("CMAC", data);
sm_cmac_done_handler(data);
break;
default:
printf("sm_cmac_handle_encryption_result called in state %u\n", sm_cmac_state);
log_info("sm_cmac_handle_encryption_result called in state %u", sm_cmac_state);
break;
}
}
@ -911,7 +911,7 @@ static void sm_run(void){
}
return;
case RAU_SET_ADDRESS:
printf("New random address: %s\n", bd_addr_to_str(sm_random_address));
log_info("New random address: %s", bd_addr_to_str(sm_random_address));
hci_send_cmd(&hci_le_set_random_address, sm_random_address);
rau_state = RAU_IDLE;
return;
@ -921,16 +921,16 @@ static void sm_run(void){
// CSRK device lookup by public or resolvable private address
if (sm_central_device_test >= 0){
printf("Central Device Lookup: device %u/%u\n", sm_central_device_test, central_device_db_count());
log_info("Central Device Lookup: device %u/%u", sm_central_device_test, central_device_db_count());
while (sm_central_device_test < central_device_db_count()){
int addr_type;
bd_addr_t addr;
sm_key_t irk;
central_device_db_info(sm_central_device_test, &addr_type, addr, irk);
printf("device type %u, addr: %s\n", addr_type, bd_addr_to_str(addr));
log_info("device type %u, addr: %s", addr_type, bd_addr_to_str(addr));
if (sm_central_device_addr_type == addr_type && memcmp(addr, sm_central_device_address, 6) == 0){
printf("Central Device Lookup: found CSRK by { addr_type, address} \n");
log_info("Central Device Lookup: found CSRK by { addr_type, address} ");
sm_central_device_matched = sm_central_device_test;
sm_central_device_test = -1;
sm_key_t csrk;
@ -947,8 +947,8 @@ static void sm_run(void){
if (sm_aes128_state == SM_AES128_ACTIVE) break;
printf("Central Device Lookup: calculate AH\n");
print_key("IRK", irk);
log_info("Central Device Lookup: calculate AH");
log_key("IRK", irk);
sm_key_t r_prime;
sm_ah_r_prime(sm_central_device_address, r_prime);
@ -958,7 +958,7 @@ static void sm_run(void){
}
if (sm_central_device_test >= central_device_db_count()){
printf("Central Device Lookup: not found\n");
log_info("Central Device Lookup: not found");
sm_central_device_test = -1;
sm_notify_client(SM_IDENTITY_RESOLVING_FAILED, sm_central_device_addr_type, sm_central_device_address, 0, 0);
}
@ -1260,12 +1260,12 @@ static void sm_handle_encryption_result(uint8_t * data){
switch (dkg_state){
case DKG_W4_IRK:
swap128(data, sm_persistent_irk);
print_key("irk", sm_persistent_irk);
log_key("irk", sm_persistent_irk);
dkg_next_state();
return;
case DKG_W4_DHK:
swap128(data, sm_persistent_dhk);
print_key("dhk", sm_persistent_dhk);
log_key("dhk", sm_persistent_dhk);
dkg_next_state();
// SM INIT FINISHED, start application code - TODO untangle that
@ -1314,14 +1314,14 @@ static void sm_handle_encryption_result(uint8_t * data){
return;
case SM_PH2_C1_W4_ENC_B:
swap128(data, setup->sm_local_confirm);
print_key("c1!", setup->sm_local_confirm);
log_key("c1!", setup->sm_local_confirm);
connection->sm_engine_state = SM_PH2_C1_SEND_PAIRING_CONFIRM;
return;
case SM_PH2_C1_W4_ENC_D:
{
sm_key_t peer_confirm_test;
swap128(data, peer_confirm_test);
print_key("c1!", peer_confirm_test);
log_key("c1!", peer_confirm_test);
if (memcmp(setup->sm_peer_confirm, peer_confirm_test, 16) != 0){
setup->sm_pairing_failed_reason = SM_REASON_CONFIRM_VALUE_FAILED;
connection->sm_engine_state = SM_GENERAL_SEND_PAIRING_FAILED;
@ -1337,7 +1337,7 @@ static void sm_handle_encryption_result(uint8_t * data){
case SM_PH2_W4_STK:
swap128(data, setup->sm_ltk);
sm_truncate_key(setup->sm_ltk, connection->sm_actual_encryption_key_size);
print_key("stk", setup->sm_ltk);
log_key("stk", setup->sm_ltk);
if (connection->sm_role){
connection->sm_engine_state = SM_RESPONDER_PH2_SEND_LTK_REPLY;
} else {
@ -1348,10 +1348,10 @@ static void sm_handle_encryption_result(uint8_t * data){
sm_key_t y128;
swap128(data, y128);
setup->sm_local_y = READ_NET_16(y128, 14);
print_hex16("y", setup->sm_local_y);
log_info_hex16("y", setup->sm_local_y);
// PH3B3 - calculate EDIV
setup->sm_local_ediv = setup->sm_local_y ^ setup->sm_local_div;
print_hex16("ediv", setup->sm_local_ediv);
log_info_hex16("ediv", setup->sm_local_ediv);
// PH3B4 - calculate LTK - enc
// LTK = d1(ER, DIV, 0))
connection->sm_engine_state = SM_PH3_LTK_GET_ENC;
@ -1361,11 +1361,11 @@ static void sm_handle_encryption_result(uint8_t * data){
sm_key_t y128;
swap128(data, y128);
setup->sm_local_y = READ_NET_16(y128, 14);
print_hex16("y", setup->sm_local_y);
log_info_hex16("y", setup->sm_local_y);
// PH3B3 - calculate DIV
setup->sm_local_div = setup->sm_local_y ^ setup->sm_local_ediv;
print_hex16("ediv", setup->sm_local_ediv);
log_info_hex16("ediv", setup->sm_local_ediv);
// PH3B4 - calculate LTK - enc
// LTK = d1(ER, DIV, 0))
connection->sm_engine_state = SM_PH4_LTK_GET_ENC;
@ -1373,19 +1373,19 @@ static void sm_handle_encryption_result(uint8_t * data){
}
case SM_PH3_LTK_W4_ENC:
swap128(data, setup->sm_ltk);
print_key("ltk", setup->sm_ltk);
log_key("ltk", setup->sm_ltk);
// calc CSRK next
connection->sm_engine_state = SM_PH3_CSRK_GET_ENC;
return;
case SM_PH3_CSRK_W4_ENC:
swap128(data, setup->sm_local_csrk);
print_key("csrk", setup->sm_local_csrk);
log_key("csrk", setup->sm_local_csrk);
connection->sm_engine_state = SM_PH3_DISTRIBUTE_KEYS;
return;
case SM_PH4_LTK_W4_ENC:
swap128(data, setup->sm_ltk);
sm_truncate_key(setup->sm_ltk, connection->sm_actual_encryption_key_size);
print_key("ltk", setup->sm_ltk);
log_key("ltk", setup->sm_ltk);
connection->sm_engine_state = SM_PH4_SEND_LTK;
return;
default:
@ -1459,7 +1459,7 @@ static void sm_handle_random_result(uint8_t * data){
case SM_PH3_W4_DIV:
// use 16 bit from random value as div
setup->sm_local_div = READ_NET_16(data, 0);
print_hex16("div", setup->sm_local_div);
log_info_hex16("div", setup->sm_local_div);
connection->sm_engine_state = SM_PH3_Y_GET_ENC;
return;
default:
@ -1480,7 +1480,7 @@ static void sm_event_packet_handler (uint8_t packet_type, uint16_t channel, uint
case BTSTACK_EVENT_STATE:
// bt stack activated, get started
if (packet[2] == HCI_STATE_WORKING) {
printf("HCI Working!\n");
log_info("HCI Working!");
dkg_state = sm_persistent_irk_ready ? DKG_CALC_DHK : DKG_CALC_IRK;
sm_run();
@ -1492,13 +1492,13 @@ static void sm_event_packet_handler (uint8_t packet_type, uint16_t channel, uint
switch (packet[2]) {
case HCI_SUBEVENT_LE_CONNECTION_COMPLETE:
printf("sm: connected\n");
log_info("sm: connected");
if (packet[3]) return; // connection failed
// only single connection for peripheral
if (connection->sm_handle){
printf("Already connected, ignoring incoming connection\n");
log_info("Already connected, ignoring incoming connection");
return;
}
@ -1507,7 +1507,7 @@ static void sm_event_packet_handler (uint8_t packet_type, uint16_t channel, uint
connection->sm_peer_addr_type = packet[7];
bt_flip_addr(connection->sm_peer_address, &packet[8]);
printf("New connection, role %s\n", connection->sm_role ? "slave" : "master");
log_info("New connection, role %s", connection->sm_role ? "slave" : "master");
// reset security properties
connection->sm_connection_encrypted = 0;
@ -1537,7 +1537,7 @@ static void sm_event_packet_handler (uint8_t packet_type, uint16_t channel, uint
// master
hci_le_advertisement_address(&setup->sm_m_addr_type, &setup->sm_m_address);
printf("hci_le_advertisement_address type %u\n", setup->sm_m_addr_type);
log_info("hci_le_advertisement_address type %u", setup->sm_m_addr_type);
setup->sm_s_addr_type = packet[7];
bt_flip_addr(setup->sm_s_address, &packet[8]);
setup->sm_m_preq.io_capability = sm_io_capabilities;
@ -1581,7 +1581,7 @@ static void sm_event_packet_handler (uint8_t packet_type, uint16_t channel, uint
// assume that we don't have a LTK for ediv == 0 and random == null
if (setup->sm_local_ediv == 0 && sm_is_null_random(setup->sm_local_rand)){
printf("LTK Request: ediv & random are empty\n");
log_info("LTK Request: ediv & random are empty");
connection->sm_engine_state = SM_RESPONDER_SEND_LTK_REQUESTED_NEGATIVE_REPLY;
break;
}
@ -1673,7 +1673,7 @@ static void sm_packet_handler(uint8_t packet_type, uint16_t handle, uint8_t *pac
if (packet_type != SM_DATA_PACKET) return;
if (handle != connection->sm_handle){
printf("sm_packet_handler: packet from handle %u, but expecting from %u\n", handle, connection->sm_handle);
log_info("sm_packet_handler: packet from handle %u, but expecting from %u", handle, connection->sm_handle);
return;
}
@ -1718,7 +1718,7 @@ static void sm_packet_handler(uint8_t packet_type, uint16_t handle, uint8_t *pac
// decide on STK generation method
sm_setup_tk();
printf("SMP: generation method %u\n", setup->sm_stk_generation_method);
log_info("SMP: generation method %u", setup->sm_stk_generation_method);
// check if STK generation method is acceptable by client
if (!sm_validate_stk_generation_method()){
@ -1791,7 +1791,7 @@ static void sm_packet_handler(uint8_t packet_type, uint16_t handle, uint8_t *pac
// decide on STK generation method
sm_setup_tk();
printf("SMP: generation method %u\n", setup->sm_stk_generation_method);
log_info("SMP: generation method %u", setup->sm_stk_generation_method);
// check if STK generation method is acceptable by client
if (!sm_validate_stk_generation_method()){
@ -1891,7 +1891,7 @@ static void sm_packet_handler(uint8_t packet_type, uint16_t handle, uint8_t *pac
break;
default:
// Unexpected PDU
printf("Unexpected PDU %u in SM_PH3_RECEIVE_KEYS\n", packet[0]);
log_info("Unexpected PDU %u in SM_PH3_RECEIVE_KEYS", packet[0]);
break;
}
// done with key distribution?
@ -1906,7 +1906,7 @@ static void sm_packet_handler(uint8_t packet_type, uint16_t handle, uint8_t *pac
break;
default:
// Unexpected PDU
printf("Unexpected PDU %u in state %u\n", packet[0], connection->sm_engine_state);
log_info("Unexpected PDU %u in state %u", packet[0], connection->sm_engine_state);
break;
}
@ -2025,7 +2025,7 @@ authorization_state_t sm_authorization_state(uint8_t addr_type, bd_addr_t addres
// request authorization
void sm_request_authorization(uint8_t addr_type, bd_addr_t address){
printf("sm_request_authorization in role %u, state %u\n", connection->sm_role, connection->sm_engine_state);
log_info("sm_request_authorization in role %u, state %u", connection->sm_role, connection->sm_engine_state);
if (connection->sm_role){
// code has no effect so far
connection->sm_connection_authorization_state = AUTHORIZATION_PENDING;

4
ble/sm_minimal.c
View File

@ -125,7 +125,7 @@ static void sm_packet_handler(uint8_t packet_type, uint16_t handle, uint8_t *pac
if (packet_type != SM_DATA_PACKET) return;
if (handle != sm_response_handle){
printf("sm_packet_handler: packet from handle %u, but expecting from %u\n", handle, sm_response_handle);
log_info("sm_packet_handler: packet from handle %u, but expecting from %u", handle, sm_response_handle);
return;
}
@ -164,7 +164,7 @@ static void sm_event_packet_handler (void * connection, uint8_t packet_type, uin
case HCI_SUBEVENT_LE_CONNECTION_COMPLETE:
// only single connection for peripheral
if (sm_response_handle){
printf("Already connected, ignoring incoming connection\n");
log_info("Already connected, ignoring incoming connection");
return;
}
sm_response_handle = READ_BT_16(packet, 4);

3
chipset-csr/bt_control_csr.c
View File

@ -48,6 +48,7 @@
#include <string.h> /* memcpy */
#include "bt_control.h"
#include "debug.h"
#include <btstack/utils.h>
// minimal CSR init script
@ -105,7 +106,7 @@ static int bt_control_csr_next_cmd(void *config, uint8_t *hci_cmd_buffer){
// support for warm boot command
uint16_t varid = READ_BT_16(hci_cmd_buffer, 10);
printf("csr: varid 0x%04x\n", varid);
log_info("csr: varid 0x%04x", varid);
if (varid == 0x4002){
return 2;
}

4
include/btstack/utils.h
View File

@ -130,9 +130,9 @@ void swap56(const uint8_t src[7], uint8_t dst[7]);
void swap64(const uint8_t src[8], uint8_t dst[8]);
void swap128(const uint8_t src[16], uint8_t dst[16]);
void hexdump(void *data, int size);
void hexdump(const void *data, int size);
void printUUID128(uint8_t *uuid);
void print_key(const char * name, sm_key_t key);
void log_key(const char * name, sm_key_t key);
// @deprecated please use more convenient bd_addr_to_str
void print_bd_addr( bd_addr_t addr);

2
src/btstack.c
View File

@ -107,7 +107,7 @@ int bt_send_cmd(const hci_cmd_t *cmd, ...){
}
int btstack_packet_handler(connection_t *connection, uint16_t packet_type, uint16_t channel, uint8_t *data, uint16_t size){
// printf("BTstack client handler: packet type %u, data[0] %x\n", packet_type, data[0]);
// log_info("BTstack client handler: packet type %u, data[0] %x", packet_type, data[0]);
(*client_packet_handler)(packet_type, channel, data, size);
return 0;
}

2
src/daemon.c
View File

@ -700,7 +700,7 @@ static int btstack_command_handler(connection_t *connection, uint8_t *packet, ui
}
#endif
default:
log_error("Error: command %u not implemented\n:", READ_CMD_OCF(packet));
log_error("Error: command %u not implemented:", READ_CMD_OCF(packet));
break;
}

112
src/hci.c
View File

@ -235,7 +235,7 @@ static void dummy_handler(uint8_t packet_type, uint8_t *packet, uint16_t size){
uint8_t hci_number_outgoing_packets(hci_con_handle_t handle){
hci_connection_t * connection = hci_connection_for_handle(handle);
if (!connection) {
log_error("hci_number_outgoing_packets: connection for handle %u does not exist!\n", handle);
log_error("hci_number_outgoing_packets: connection for handle %u does not exist!", handle);
return 0;
}
return connection->num_acl_packets_sent;
@ -265,7 +265,7 @@ uint8_t hci_number_free_acl_slots_for_handle(hci_con_handle_t con_handle){
int free_slots_le = 0;
if (free_slots_classic < 0){
log_error("hci_number_free_acl_slots: outgoing classic packets (%u) > total classic packets (%u)\n", num_packets_sent_classic, hci_stack->acl_packets_total_num);
log_error("hci_number_free_acl_slots: outgoing classic packets (%u) > total classic packets (%u)", num_packets_sent_classic, hci_stack->acl_packets_total_num);
return 0;
}
@ -273,21 +273,21 @@ uint8_t hci_number_free_acl_slots_for_handle(hci_con_handle_t con_handle){
// if we have LE slots, they are used
free_slots_le = hci_stack->le_acl_packets_total_num - num_packets_sent_le;
if (free_slots_le < 0){
log_error("hci_number_free_acl_slots: outgoing le packets (%u) > total le packets (%u)\n", num_packets_sent_le, hci_stack->le_acl_packets_total_num);
log_error("hci_number_free_acl_slots: outgoing le packets (%u) > total le packets (%u)", num_packets_sent_le, hci_stack->le_acl_packets_total_num);
return 0;
}
} else {
// otherwise, classic slots are used for LE, too
free_slots_classic -= num_packets_sent_le;
if (free_slots_classic < 0){
log_error("hci_number_free_acl_slots: outgoing classic + le packets (%u + %u) > total packets (%u)\n", num_packets_sent_classic, num_packets_sent_le, hci_stack->acl_packets_total_num);
log_error("hci_number_free_acl_slots: outgoing classic + le packets (%u + %u) > total packets (%u)", num_packets_sent_classic, num_packets_sent_le, hci_stack->acl_packets_total_num);
return 0;
}
}
switch (address_type){
case BD_ADDR_TYPE_UNKNOWN:
log_error("hci_number_free_acl_slots: handle 0x%04x not in connection list\n", con_handle);
log_error("hci_number_free_acl_slots: handle 0x%04x not in connection list", con_handle);
return 0;
case BD_ADDR_TYPE_CLASSIC:
@ -409,7 +409,7 @@ int hci_send_acl_packet_buffer(int size){
// count packet
connection->num_acl_packets_sent++;
// log_info("hci_send_acl_packet - handle %u, sent %u\n", connection->con_handle, connection->num_acl_packets_sent);
// log_info("hci_send_acl_packet - handle %u, sent %u", connection->con_handle, connection->num_acl_packets_sent);
// send packet
int err = hci_stack->hci_transport->send_packet(HCI_ACL_DATA_PACKET, packet, size);
@ -434,7 +434,7 @@ static void acl_handler(uint8_t *packet, int size){
// ignore non-registered handle
if (!conn){
log_error( "hci.c: acl_handler called with non-registered handle %u!\n" , con_handle);
log_error( "hci.c: acl_handler called with non-registered handle %u!" , con_handle);
return;
}
@ -454,7 +454,7 @@ static void acl_handler(uint8_t *packet, int size){
// sanity check
if (conn->acl_recombination_pos == 0) {
log_error( "ACL Cont Fragment but no first fragment for handle 0x%02x\n", con_handle);
log_error( "ACL Cont Fragment but no first fragment for handle 0x%02x", con_handle);
return;
}
@ -462,7 +462,7 @@ static void acl_handler(uint8_t *packet, int size){
memcpy(&conn->acl_recombination_buffer[conn->acl_recombination_pos], &packet[4], acl_length );
conn->acl_recombination_pos += acl_length;
// log_error( "ACL Cont Fragment: acl_len %u, combined_len %u, l2cap_len %u\n", acl_length,
// log_error( "ACL Cont Fragment: acl_len %u, combined_len %u, l2cap_len %u", acl_length,
// conn->acl_recombination_pos, conn->acl_recombination_length);
// forward complete L2CAP packet if complete.
@ -479,14 +479,14 @@ static void acl_handler(uint8_t *packet, int size){
// sanity check
if (conn->acl_recombination_pos) {
log_error( "ACL First Fragment but data in buffer for handle 0x%02x\n", con_handle);
log_error( "ACL First Fragment but data in buffer for handle 0x%02x", con_handle);
return;
}
// peek into L2CAP packet!
uint16_t l2cap_length = READ_L2CAP_LENGTH( packet );
// log_info( "ACL First Fragment: acl_len %u, l2cap_len %u\n", acl_length, l2cap_length);
// log_info( "ACL First Fragment: acl_len %u, l2cap_len %u", acl_length, l2cap_length);
// compare fragment size to L2CAP packet size
if (acl_length >= l2cap_length + 4){
@ -505,7 +505,7 @@ static void acl_handler(uint8_t *packet, int size){
}
default:
log_error( "hci.c: acl_handler called with invalid packet boundary flags %u\n", acl_flags & 0x03);
log_error( "hci.c: acl_handler called with invalid packet boundary flags %u", acl_flags & 0x03);
return;
}
@ -514,7 +514,7 @@ static void acl_handler(uint8_t *packet, int size){
}
static void hci_shutdown_connection(hci_connection_t *conn){
log_info("Connection closed: handle 0x%x, %s\n", conn->con_handle, bd_addr_to_str(conn->address));
log_info("Connection closed: handle 0x%x, %s", conn->con_handle, bd_addr_to_str(conn->address));
run_loop_remove_timer(&conn->timeout);
@ -690,7 +690,7 @@ static void hci_initializing_event_handler(uint8_t * packet, uint16_t size){
}
static void hci_initializing_state_machine(){
// log_info("hci_init: substate %u\n", hci_stack->substate);
// log_info("hci_init: substate %u", hci_stack->substate);
if (hci_stack->substate % 2) {
// odd: waiting for command completion
return;
@ -728,7 +728,7 @@ static void hci_initializing_state_machine(){
hci_stack->substate = 4; // more init commands
break;
}
log_info("hci_run: init script done\n\r");
log_info("hci_run: init script done");
}
// otherwise continue
hci_send_cmd(&hci_read_bd_addr);
@ -846,13 +846,13 @@ static void event_handler(uint8_t *packet, int size){
hci_connection_t * conn;
int i;
// printf("HCI:EVENT:%02x\n", packet[0]);
// log_info("HCI:EVENT:%02x", packet[0]);
switch (packet[0]) {
case HCI_EVENT_COMMAND_COMPLETE:
// get num cmd packets
// log_info("HCI_EVENT_COMMAND_COMPLETE cmds old %u - new %u\n", hci_stack->num_cmd_packets, packet[2]);
// log_info("HCI_EVENT_COMMAND_COMPLETE cmds old %u - new %u", hci_stack->num_cmd_packets, packet[2]);
hci_stack->num_cmd_packets = packet[2];
if (COMMAND_COMPLETE_EVENT(packet, hci_read_buffer_size)){
@ -868,7 +868,7 @@ static void event_handler(uint8_t *packet, int size){
if (HCI_ACL_PAYLOAD_SIZE < hci_stack->acl_data_packet_length){
hci_stack->acl_data_packet_length = HCI_ACL_PAYLOAD_SIZE;
}
log_info("hci_read_buffer_size: used size %u, count %u\n",
log_info("hci_read_buffer_size: used size %u, count %u",
hci_stack->acl_data_packet_length, hci_stack->acl_packets_total_num);
}
}
@ -876,13 +876,13 @@ static void event_handler(uint8_t *packet, int size){
if (COMMAND_COMPLETE_EVENT(packet, hci_le_read_buffer_size)){
hci_stack->le_data_packets_length = READ_BT_16(packet, 6);
hci_stack->le_acl_packets_total_num = packet[8];
log_info("hci_le_read_buffer_size: size %u, count %u\n", hci_stack->le_data_packets_length, hci_stack->le_acl_packets_total_num);
log_info("hci_le_read_buffer_size: size %u, count %u", hci_stack->le_data_packets_length, hci_stack->le_acl_packets_total_num);
}
#endif
// Dump local address
if (COMMAND_COMPLETE_EVENT(packet, hci_read_bd_addr)) {
bt_flip_addr(hci_stack->local_bd_addr, &packet[OFFSET_OF_DATA_IN_COMMAND_COMPLETE + 1]);
log_info("Local Address, Status: 0x%02x: Addr: %s\n",
log_info("Local Address, Status: 0x%02x: Addr: %s",
packet[OFFSET_OF_DATA_IN_COMMAND_COMPLETE], bd_addr_to_str(hci_stack->local_bd_addr));
}
if (COMMAND_COMPLETE_EVENT(packet, hci_write_scan_enable)){
@ -908,7 +908,7 @@ static void event_handler(uint8_t *packet, int size){
case HCI_EVENT_COMMAND_STATUS:
// get num cmd packets
// log_info("HCI_EVENT_COMMAND_STATUS cmds - old %u - new %u\n", hci_stack->num_cmd_packets, packet[3]);
// log_info("HCI_EVENT_COMMAND_STATUS cmds - old %u - new %u", hci_stack->num_cmd_packets, packet[3]);
hci_stack->num_cmd_packets = packet[3];
break;
@ -922,11 +922,11 @@ static void event_handler(uint8_t *packet, int size){
conn = hci_connection_for_handle(handle);
if (!conn){
log_error("hci_number_completed_packet lists unused con handle %u\n", handle);
log_error("hci_number_completed_packet lists unused con handle %u", handle);
continue;
}
conn->num_acl_packets_sent -= num_packets;
// log_info("hci_number_completed_packet %u processed for handle %u, outstanding %u\n", num_packets, handle, conn->num_acl_packets_sent);
// log_info("hci_number_completed_packet %u processed for handle %u, outstanding %u", num_packets, handle, conn->num_acl_packets_sent);
}
break;
}
@ -934,7 +934,7 @@ static void event_handler(uint8_t *packet, int size){
bt_flip_addr(addr, &packet[2]);
// TODO: eval COD 8-10
link_type = packet[11];
log_info("Connection_incoming: %s, type %u\n", bd_addr_to_str(addr), link_type);
log_info("Connection_incoming: %s, type %u", bd_addr_to_str(addr), link_type);
if (link_type == 1) { // ACL
conn = hci_connection_for_bd_addr_and_type(&addr, BD_ADDR_TYPE_CLASSIC);
if (!conn) {
@ -958,7 +958,7 @@ static void event_handler(uint8_t *packet, int size){
case HCI_EVENT_CONNECTION_COMPLETE:
// Connection management
bt_flip_addr(addr, &packet[5]);
log_info("Connection_complete (status=%u) %s\n", packet[2], bd_addr_to_str(addr));
log_info("Connection_complete (status=%u) %s", packet[2], bd_addr_to_str(addr));
addr_type = BD_ADDR_TYPE_CLASSIC;
conn = hci_connection_for_bd_addr_and_type(&addr, addr_type);
if (conn) {
@ -971,7 +971,7 @@ static void event_handler(uint8_t *packet, int size){
run_loop_set_timer(&conn->timeout, HCI_CONNECTION_TIMEOUT_MS);
run_loop_add_timer(&conn->timeout);
log_info("New connection: handle %u, %s\n", conn->con_handle, bd_addr_to_str(conn->address));
log_info("New connection: handle %u, %s", conn->con_handle, bd_addr_to_str(conn->address));
hci_emit_nr_connections_changed();
} else {
@ -1010,7 +1010,7 @@ static void event_handler(uint8_t *packet, int size){
break;
case HCI_EVENT_LINK_KEY_REQUEST:
log_info("HCI_EVENT_LINK_KEY_REQUEST\n");
log_info("HCI_EVENT_LINK_KEY_REQUEST");
hci_add_connection_flags_for_flipped_bd_addr(&packet[2], RECV_LINK_KEY_REQUEST);
// non-bondable mode: link key negative reply will be sent by HANDLE_LINK_KEY_REQUEST
if (hci_stack->bondable && !hci_stack->remote_device_db) break;
@ -1167,7 +1167,7 @@ static void event_handler(uint8_t *packet, int size){
case HCI_EVENT_LE_META:
switch (packet[2]){
case HCI_SUBEVENT_LE_ADVERTISING_REPORT:
log_info("advertising report received\n");
log_info("advertising report received");
if (hci_stack->le_scanning_state != LE_SCANNING) break;
le_handle_advertisement_report(packet, size);
break;
@ -1175,7 +1175,7 @@ static void event_handler(uint8_t *packet, int size){
// Connection management
bt_flip_addr(addr, &packet[8]);
addr_type = (bd_addr_type_t)packet[7];
log_info("LE Connection_complete (status=%u) type %u, %s\n", packet[3], addr_type, bd_addr_to_str(addr));
log_info("LE Connection_complete (status=%u) type %u, %s", packet[3], addr_type, bd_addr_to_str(addr));
// LE connections are auto-accepted, so just create a connection if there isn't one already
conn = hci_connection_for_bd_addr_and_type(&addr, addr_type);
if (packet[3]){
@ -1207,12 +1207,12 @@ static void event_handler(uint8_t *packet, int size){
// run_loop_set_timer(&conn->timeout, HCI_CONNECTION_TIMEOUT_MS);
// run_loop_add_timer(&conn->timeout);
log_info("New connection: handle %u, %s\n", conn->con_handle, bd_addr_to_str(conn->address));
log_info("New connection: handle %u, %s", conn->con_handle, bd_addr_to_str(conn->address));
hci_emit_nr_connections_changed();
break;
// printf("LE buffer size: %u, count %u\n", READ_BT_16(packet,6), packet[8]);
// log_info("LE buffer size: %u, count %u", READ_BT_16(packet,6), packet[8]);
default:
break;
@ -1376,7 +1376,7 @@ static int hci_power_control_on(void){
err = (*hci_stack->control->on)(hci_stack->config);
}
if (err){
log_error( "POWER_ON failed\n");
log_error( "POWER_ON failed");
hci_emit_hci_open_failed();
return err;
}
@ -1384,7 +1384,7 @@ static int hci_power_control_on(void){
// open low-level device
err = hci_stack->hci_transport->open(hci_stack->config);
if (err){
log_error( "HCI_INIT failed, turning Bluetooth off again\n");
log_error( "HCI_INIT failed, turning Bluetooth off again");
if (hci_stack->control && hci_stack->control->off){
(*hci_stack->control->off)(hci_stack->config);
}
@ -1396,26 +1396,26 @@ static int hci_power_control_on(void){
static void hci_power_control_off(void){
log_info("hci_power_control_off\n");
log_info("hci_power_control_off");
// close low-level device
hci_stack->hci_transport->close(hci_stack->config);
log_info("hci_power_control_off - hci_transport closed\n");
log_info("hci_power_control_off - hci_transport closed");
// power off
if (hci_stack->control && hci_stack->control->off){
(*hci_stack->control->off)(hci_stack->config);
}
log_info("hci_power_control_off - control closed\n");
log_info("hci_power_control_off - control closed");
hci_stack->state = HCI_STATE_OFF;
}
static void hci_power_control_sleep(void){
log_info("hci_power_control_sleep\n");
log_info("hci_power_control_sleep");
#if 0
// don't close serial port during sleep
@ -1434,7 +1434,7 @@ static void hci_power_control_sleep(void){
static int hci_power_control_wake(void){
log_info("hci_power_control_wake\n");
log_info("hci_power_control_wake");
// wake on
if (hci_stack->control && hci_stack->control->wake){
@ -1445,7 +1445,7 @@ static int hci_power_control_wake(void){
// open low-level device
int err = hci_stack->hci_transport->open(hci_stack->config);
if (err){
log_error( "HCI_INIT failed, turning Bluetooth off again\n");
log_error( "HCI_INIT failed, turning Bluetooth off again");
if (hci_stack->control && hci_stack->control->off){
(*hci_stack->control->off)(hci_stack->config);
}
@ -1467,7 +1467,7 @@ static void hci_power_transition_to_initializing(void){
int hci_power_control(HCI_POWER_MODE power_mode){
log_info("hci_power_control: %u, current mode %u\n", power_mode, hci_stack->state);
log_info("hci_power_control: %u, current mode %u", power_mode, hci_stack->state);
int err = 0;
switch (hci_stack->state){
@ -1690,12 +1690,12 @@ void hci_run(){
case SEND_CREATE_CONNECTION:
switch(connection->address_type){
case BD_ADDR_TYPE_CLASSIC:
log_info("sending hci_create_connection\n");
log_info("sending hci_create_connection");
hci_send_cmd(&hci_create_connection, connection->address, hci_usable_acl_packet_types(), 0, 0, 0, 1);
break;
default:
#ifdef HAVE_BLE
log_info("sending hci_le_create_connection\n");
log_info("sending hci_le_create_connection");
hci_send_cmd(&hci_le_create_connection,
0x0060, // scan interval: 60 ms
0x0030, // scan interval: 30 ms
@ -1718,7 +1718,7 @@ void hci_run(){
return;
case RECEIVED_CONNECTION_REQUEST:
log_info("sending hci_accept_connection_request\n");
log_info("sending hci_accept_connection_request");
connection->state = ACCEPTED_CONNECTION_REQUEST;
hci_send_cmd(&hci_accept_connection_request, connection->address, 1);
return;
@ -1739,7 +1739,7 @@ void hci_run(){
}
if (connection->authentication_flags & HANDLE_LINK_KEY_REQUEST){
log_info("responding to link key request\n");
log_info("responding to link key request");
connectionClearAuthenticationFlags(connection, HANDLE_LINK_KEY_REQUEST);
link_key_t link_key;
link_key_type_t link_key_type;
@ -1755,7 +1755,7 @@ void hci_run(){
}
if (connection->authentication_flags & DENY_PIN_CODE_REQUEST){
log_info("denying to pin request\n");
log_info("denying to pin request");
connectionClearAuthenticationFlags(connection, DENY_PIN_CODE_REQUEST);
hci_send_cmd(&hci_pin_code_request_negative_reply, connection->address);
return;
@ -1827,7 +1827,7 @@ void hci_run(){
case HCI_STATE_HALTING:
log_info("HCI_STATE_HALTING\n");
log_info("HCI_STATE_HALTING");
// close all open connections
connection = (hci_connection_t *) hci_stack->connections;
if (connection){
@ -1835,27 +1835,27 @@ void hci_run(){
// send disconnect
if (!hci_can_send_command_packet_now()) return;
log_info("HCI_STATE_HALTING, connection %p, handle %u\n", connection, (uint16_t)connection->con_handle);
log_info("HCI_STATE_HALTING, connection %p, handle %u", connection, (uint16_t)connection->con_handle);
hci_send_cmd(&hci_disconnect, connection->con_handle, 0x13); // remote closed connection
// send disconnected event right away - causes higher layer connections to get closed, too.
hci_shutdown_connection(connection);
return;
}
log_info("HCI_STATE_HALTING, calling off\n");
log_info("HCI_STATE_HALTING, calling off");
// switch mode
hci_power_control_off();
log_info("HCI_STATE_HALTING, emitting state\n");
log_info("HCI_STATE_HALTING, emitting state");
hci_emit_state();
log_info("HCI_STATE_HALTING, done\n");
log_info("HCI_STATE_HALTING, done");
break;
case HCI_STATE_FALLING_ASLEEP:
switch(hci_stack->substate) {
case 0:
log_info("HCI_STATE_FALLING_ASLEEP\n");
log_info("HCI_STATE_FALLING_ASLEEP");
// close all open connections
connection = (hci_connection_t *) hci_stack->connections;
@ -1870,7 +1870,7 @@ void hci_run(){
// send disconnect
if (!hci_can_send_command_packet_now()) return;
log_info("HCI_STATE_FALLING_ASLEEP, connection %p, handle %u\n", connection, (uint16_t)connection->con_handle);
log_info("HCI_STATE_FALLING_ASLEEP, connection %p, handle %u", connection, (uint16_t)connection->con_handle);
hci_send_cmd(&hci_disconnect, connection->con_handle, 0x13); // remote closed connection
// send disconnected event right away - causes higher layer connections to get closed, too.
@ -1882,7 +1882,7 @@ void hci_run(){
// disable page and inquiry scan
if (!hci_can_send_command_packet_now()) return;
log_info("HCI_STATE_HALTING, disabling inq scans\n");
log_info("HCI_STATE_HALTING, disabling inq scans");
hci_send_cmd(&hci_write_scan_enable, hci_stack->connectable << 1); // drop inquiry scan but keep page scan
// continue in next sub state
@ -1892,7 +1892,7 @@ void hci_run(){
// fall through for ble-only chips
case 2:
log_info("HCI_STATE_HALTING, calling sleep\n");
log_info("HCI_STATE_HALTING, calling sleep");
#if defined(USE_POWERMANAGEMENT) && defined(USE_BLUETOOL)
// don't actually go to sleep, if H4 supports power management
if (bt_control_iphone_power_management_enabled()){
@ -1925,7 +1925,7 @@ int hci_send_cmd_packet(uint8_t *packet, int size){
// create_connection?
if (IS_COMMAND(packet, hci_create_connection)){
bt_flip_addr(addr, &packet[3]);
log_info("Create_connection to %s\n", bd_addr_to_str(addr));
log_info("Create_connection to %s", bd_addr_to_str(addr));
conn = hci_connection_for_bd_addr_and_type(&addr, BD_ADDR_TYPE_CLASSIC);
if (!conn){
@ -2051,7 +2051,7 @@ int hci_send_cmd(const hci_cmd_t *cmd, ...){
}
// for HCI INITIALIZATION
// printf("hci_send_cmd: opcode %04x\n", cmd->opcode);
// log_info("hci_send_cmd: opcode %04x", cmd->opcode);
hci_stack->last_cmd_opcode = cmd->opcode;
hci_reserve_packet_buffer();

4
src/hci_transport_h4.c
View File

@ -231,7 +231,7 @@ static void h4_statemachine(void){
bytes_to_read = HCI_ACL_HEADER_SIZE;
h4_state = H4_W4_ACL_HEADER;
} else {
log_error("h4_process: invalid packet type 0x%02x\n", hci_packet[0]);
log_error("h4_process: invalid packet type 0x%02x", hci_packet[0]);
read_pos = 0;
bytes_to_read = 1;
}
@ -262,7 +262,7 @@ static int h4_process(struct data_source *ds) {
// read up to bytes_to_read data in
ssize_t bytes_read = read(hci_transport_h4->uart_fd, &hci_packet[read_pos], read_now);
// printf("h4_process: bytes read %u\n", bytes_read);
// log_info("h4_process: bytes read %u", bytes_read);
if (bytes_read < 0) {
return bytes_read;
}

4
src/hci_transport_h4_dma.c
View File

@ -171,7 +171,7 @@ static void h4_block_received(void){
bytes_to_read = HCI_EVENT_HEADER_SIZE;
break;
default:
log_error("h4_process: invalid packet type 0x%02x\r\n", hci_packet[0]);
log_error("h4_process: invalid packet type 0x%02x", hci_packet[0]);
read_pos = 0;
h4_state = H4_W4_PACKET_TYPE;
bytes_to_read = 1;
@ -297,7 +297,7 @@ static int h4_send_packet(uint8_t packet_type, uint8_t *packet, int size){
}
static int h4_set_baudrate(uint32_t baudrate){
printf("h4_set_baudrate - set baud %lu\n\r", baudrate);
log_info("h4_set_baudrate - set baud %lu", baudrate);
return hal_uart_dma_set_baud(baudrate);
}

22
src/hci_transport_h4_ehcill_dma.c
View File

@ -196,7 +196,7 @@ static int h4_open(void *transport_config){
}
static int h4_set_baudrate(uint32_t baudrate){
log_info("h4_set_baudrate - set baud %lu\n", baudrate);
log_info("h4_set_baudrate - set baud %lu", baudrate);
return hal_uart_dma_set_baud(baudrate);
}
@ -241,7 +241,7 @@ static void h4_block_received(void){
bytes_to_read = 1;
break;
default:
log_error("h4_process: invalid packet type 0x%02x\n", hci_packet[0]);
log_error("h4_process: invalid packet type 0x%02x", hci_packet[0]);
read_pos = 0;
bytes_to_read = 1;
break;
@ -388,7 +388,7 @@ static void ehcill_schedule_ecill_command(uint8_t command){
static void ehcill_handle(uint8_t action){
int size;
// printf("ehcill_handle: %x, state %u, defer_rx %u \n\r", action, ehcill_state, ehcill_defer_rx_size);
// log_info("ehcill_handle: %x, state %u, defer_rx %u", action, ehcill_state, ehcill_defer_rx_size);
switch(ehcill_state){
case EHCILL_STATE_AWAKE:
switch(action){
@ -398,7 +398,7 @@ static void ehcill_handle(uint8_t action){
// 2. enable CTS - CTS always enabled
ehcill_state = EHCILL_STATE_SLEEP;
log_info("RX: EHCILL_GO_TO_SLEEP_IND\n");
log_info("RX: EHCILL_GO_TO_SLEEP_IND");
ehcill_schedule_ecill_command(EHCILL_GO_TO_SLEEP_ACK);
break;
@ -417,7 +417,7 @@ static void ehcill_handle(uint8_t action){
// UART needed again
hal_uart_dma_set_sleep(0);
log_info ("Re-activate rx\n");
log_info ("Re-activate rx");
size = ehcill_defer_rx_size;
ehcill_defer_rx_size = 0;
hal_uart_dma_receive_block(ehcill_defer_rx_buffer, size);
@ -426,7 +426,7 @@ static void ehcill_handle(uint8_t action){
case EHCILL_WAKE_UP_IND:
ehcill_state = EHCILL_STATE_AWAKE;
log_info("RX: EHCILL_GO_TO_SLEEP_IND\n");
log_info("RX: EHCILL_GO_TO_SLEEP_IND");
ehcill_schedule_ecill_command(EHCILL_WAKE_UP_ACK);
break;
@ -440,7 +440,7 @@ static void ehcill_handle(uint8_t action){
case EHCILL_WAKE_UP_IND:
case EHCILL_WAKE_UP_ACK:
log_info("RX: EHCILL_WAKE_UP_IND or ACK\n");
log_info("RX: EHCILL_WAKE_UP_IND or ACK");
tx_state = TX_W4_HEADER_SENT;
hal_uart_dma_send_block(&tx_packet_type, 1);
@ -459,7 +459,7 @@ static int ehcill_send_packet(uint8_t packet_type, uint8_t *packet, int size){
// write in progress
if (tx_state != TX_IDLE) {
log_error("h4_send_packet with tx_state = %u, type %u, data %02x %02x %02x\n", tx_state, packet_type, packet[0], packet[1], packet[2]);
log_error("h4_send_packet with tx_state = %u, type %u, data %02x %02x %02x", tx_state, packet_type, packet[0], packet[1], packet[2]);
return -1;
}
@ -486,13 +486,13 @@ static int ehcill_send_packet(uint8_t packet_type, uint8_t *packet, int size){
ehcill_state = EHCILL_STATE_W4_ACK;
// wake up
log_info("RX: SLEEP\n");
log_info("TX: EHCILL_WAKE_UP_IND\n");
log_info("RX: SLEEP");
log_info("TX: EHCILL_WAKE_UP_IND");
ehcill_command_to_send = EHCILL_WAKE_UP_IND;
hal_uart_dma_send_block(&ehcill_command_to_send, 1);
if (!ehcill_defer_rx_size){
log_error("ERROR: NO RX REQUEST PENDING\n");
log_error("ERROR: NO RX REQUEST PENDING");
return 0;
}

2
src/hci_transport_h4_iphone.c
View File

@ -296,7 +296,7 @@ static void h4_statemachine(void){
bytes_to_read = HCI_ACL_HEADER_SIZE;
h4_state = H4_W4_ACL_HEADER;
} else {
log_error("h4_process: invalid packet type 0x%02x\n", hci_packet[0]);
log_error("h4_process: invalid packet type 0x%02x", hci_packet[0]);
read_pos = 0;
bytes_to_read = 1;
}

54
src/l2cap.c
View File

@ -326,18 +326,18 @@ static int l2cap_security_level_0_allowed_for_PSM(uint16_t psm){
int l2cap_send_signaling_packet(hci_con_handle_t handle, L2CAP_SIGNALING_COMMANDS cmd, uint8_t identifier, ...){
if (!hci_can_send_acl_packet_now(handle)){
log_info("l2cap_send_signaling_packet, cannot send\n");
log_info("l2cap_send_signaling_packet, cannot send");
return BTSTACK_ACL_BUFFERS_FULL;
}
// log_info("l2cap_send_signaling_packet type %u\n", cmd);
// log_info("l2cap_send_signaling_packet type %u", cmd);
hci_reserve_packet_buffer();
uint8_t *acl_buffer = hci_get_outgoing_packet_buffer();
va_list argptr;
va_start(argptr, identifier);
uint16_t len = l2cap_create_signaling_classic(acl_buffer, handle, cmd, identifier, argptr);
va_end(argptr);
// log_info("l2cap_send_signaling_packet con %u!\n", handle);
// log_info("l2cap_send_signaling_packet con %u!", handle);
return hci_send_acl_packet_buffer(len);
}
@ -345,18 +345,18 @@ int l2cap_send_signaling_packet(hci_con_handle_t handle, L2CAP_SIGNALING_COMMAND
int l2cap_send_le_signaling_packet(hci_con_handle_t handle, L2CAP_SIGNALING_COMMANDS cmd, uint8_t identifier, ...){
if (!hci_can_send_acl_packet_now(handle)){
log_info("l2cap_send_signaling_packet, cannot send\n");
log_info("l2cap_send_signaling_packet, cannot send");
return BTSTACK_ACL_BUFFERS_FULL;
}
// log_info("l2cap_send_signaling_packet type %u\n", cmd);
// log_info("l2cap_send_signaling_packet type %u", cmd);
hci_reserve_packet_buffer();
uint8_t *acl_buffer = hci_get_outgoing_packet_buffer();
va_list argptr;
va_start(argptr, identifier);
uint16_t len = l2cap_create_signaling_le(acl_buffer, handle, cmd, identifier, argptr);
va_end(argptr);
// log_info("l2cap_send_signaling_packet con %u!\n", handle);
// log_info("l2cap_send_signaling_packet con %u!", handle);
return hci_send_acl_packet_buffer(len);
}
#endif
@ -383,23 +383,23 @@ int l2cap_send_prepared(uint16_t local_cid, uint16_t len){
l2cap_channel_t * channel = l2cap_get_channel_for_local_cid(local_cid);
if (!channel) {
log_error("l2cap_send_prepared no channel for cid 0x%02x\n", local_cid);
log_error("l2cap_send_prepared no channel for cid 0x%02x", local_cid);
return -1; // TODO: define error
}
if (channel->packets_granted == 0){
log_error("l2cap_send_prepared cid 0x%02x, no credits!\n", local_cid);
log_error("l2cap_send_prepared cid 0x%02x, no credits!", local_cid);
return -1; // TODO: define error
}
if (!hci_can_send_prepared_acl_packet_now(channel->handle)){
log_info("l2cap_send_prepared cid 0x%02x, cannot send\n", local_cid);
log_info("l2cap_send_prepared cid 0x%02x, cannot send", local_cid);
return BTSTACK_ACL_BUFFERS_FULL;
}
--channel->packets_granted;
log_debug("l2cap_send_prepared cid 0x%02x, handle %u, 1 credit used, credits left %u;\n",
log_debug("l2cap_send_prepared cid 0x%02x, handle %u, 1 credit used, credits left %u;",
local_cid, channel->handle, channel->packets_granted);
uint8_t *acl_buffer = hci_get_outgoing_packet_buffer();
@ -430,11 +430,11 @@ int l2cap_send_prepared_connectionless(uint16_t handle, uint16_t cid, uint16_t l
}
if (!hci_can_send_prepared_acl_packet_now(handle)){
log_info("l2cap_send_prepared_connectionless handle 0x%02x, cid 0x%02x, cannot send\n", handle, cid);
log_info("l2cap_send_prepared_connectionless handle 0x%02x, cid 0x%02x, cannot send", handle, cid);
return BTSTACK_ACL_BUFFERS_FULL;
}
log_debug("l2cap_send_prepared_connectionless handle %u, cid 0x%02x\n", handle, cid);
log_debug("l2cap_send_prepared_connectionless handle %u, cid 0x%02x", handle, cid);
uint8_t *acl_buffer = hci_get_outgoing_packet_buffer();
@ -460,12 +460,12 @@ int l2cap_send_internal(uint16_t local_cid, uint8_t *data, uint16_t len){
l2cap_channel_t * channel = l2cap_get_channel_for_local_cid(local_cid);
if (!channel) {
log_error("l2cap_send_internal no channel for cid 0x%02x\n", local_cid);
log_error("l2cap_send_internal no channel for cid 0x%02x", local_cid);
return -1; // TODO: define error
}
if (!hci_can_send_acl_packet_now(channel->handle)){
log_info("l2cap_send_internal cid 0x%02x, cannot send\n", local_cid);
log_info("l2cap_send_internal cid 0x%02x, cannot send", local_cid);
return BTSTACK_ACL_BUFFERS_FULL;
}
@ -480,7 +480,7 @@ int l2cap_send_internal(uint16_t local_cid, uint8_t *data, uint16_t len){
int l2cap_send_connectionless(uint16_t handle, uint16_t cid, uint8_t *data, uint16_t len){
if (!hci_can_send_acl_packet_now(handle)){
log_info("l2cap_send_internal cid 0x%02x, cannot send\n", cid);
log_info("l2cap_send_internal cid 0x%02x, cannot send", cid);
return BTSTACK_ACL_BUFFERS_FULL;
}
@ -585,7 +585,7 @@ void l2cap_run(void){
if (!hci_can_send_command_packet_now()) break;
if (!hci_can_send_acl_packet_now(channel->handle)) break;
// log_info("l2cap_run: state %u, var 0x%02x\n", channel->state, channel->state_var);
// log_info("l2cap_run: state %u, var 0x%02x", channel->state, channel->state_var);
switch (channel->state){
@ -995,7 +995,7 @@ static void l2cap_register_signaling_response(hci_con_handle_t handle, uint8_t c
static void l2cap_handle_connection_request(hci_con_handle_t handle, uint8_t sig_id, uint16_t psm, uint16_t source_cid){
// log_info("l2cap_handle_connection_request for handle %u, psm %u cid 0x%02x\n", handle, psm, source_cid);
// log_info("l2cap_handle_connection_request for handle %u, psm %u cid 0x%02x", handle, psm, source_cid);
l2cap_service_t *service = l2cap_get_service(psm);
if (!service) {
// 0x0002 PSM not supported
@ -1006,7 +1006,7 @@ static void l2cap_handle_connection_request(hci_con_handle_t handle, uint8_t sig
hci_connection_t * hci_connection = hci_connection_for_handle( handle );
if (!hci_connection) {
//
log_error("no hci_connection for handle %u\n", handle);
log_error("no hci_connection for handle %u", handle);
return;
}
@ -1022,7 +1022,7 @@ static void l2cap_handle_connection_request(hci_con_handle_t handle, uint8_t sig
// alloc structure
// log_info("l2cap_handle_connection_request register channel\n");
// log_info("l2cap_handle_connection_request register channel");
l2cap_channel_t * channel = (l2cap_channel_t*) btstack_memory_l2cap_channel_get();
if (!channel){
// 0x0004 No resources available
@ -1107,7 +1107,7 @@ void l2cap_signaling_handle_configure_request(l2cap_channel_t *channel, uint8_t
// MTU { type(8): 1, len(8):2, MTU(16) }
if (option_type == 1 && length == 2){
channel->remote_mtu = READ_BT_16(command, pos);
// log_info("l2cap cid 0x%02x, remote mtu %u\n", channel->local_cid, channel->remote_mtu);
// log_info("l2cap cid 0x%02x, remote mtu %u", channel->local_cid, channel->remote_mtu);
channelStateVarSetFlag(channel, L2CAP_CHANNEL_STATE_VAR_SEND_CONF_RSP_MTU);
}
// Flush timeout { type(8):2, len(8): 2, Flush Timeout(16)}
@ -1124,7 +1124,7 @@ void l2cap_signaling_handle_configure_request(l2cap_channel_t *channel, uint8_t
}
static int l2cap_channel_ready_for_open(l2cap_channel_t *channel){
// log_info("l2cap_channel_ready_for_open 0x%02x\n", channel->state_var);
// log_info("l2cap_channel_ready_for_open 0x%02x", channel->state_var);
if ((channel->state_var & L2CAP_CHANNEL_STATE_VAR_RCVD_CONF_RSP) == 0) return 0;
if ((channel->state_var & L2CAP_CHANNEL_STATE_VAR_SENT_CONF_RSP) == 0) return 0;
return 1;
@ -1137,7 +1137,7 @@ void l2cap_signaling_handler_channel(l2cap_channel_t *channel, uint8_t *command)
uint8_t identifier = command[L2CAP_SIGNALING_COMMAND_SIGID_OFFSET];
uint16_t result = 0;
log_info("L2CAP signaling handler code %u, state %u\n", code, channel->state);
log_info("L2CAP signaling handler code %u, state %u", code, channel->state);
// handle DISCONNECT REQUESTS seperately
if (code == DISCONNECTION_REQUEST){
@ -1257,7 +1257,7 @@ void l2cap_signaling_handler_channel(l2cap_channel_t *channel, uint8_t *command)
default:
break;
}
// log_info("new state %u\n", channel->state);
// log_info("new state %u", channel->state);
}
@ -1437,7 +1437,7 @@ void l2cap_register_service_internal(void *connection, btstack_packet_handler_t
// TODO: emit error event
l2cap_service_t *service = l2cap_get_service(psm);
if (service) {
log_error("l2cap_register_service_internal: PSM %u already registered\n", psm);
log_error("l2cap_register_service_internal: PSM %u already registered", psm);
l2cap_emit_service_registered(connection, L2CAP_SERVICE_ALREADY_REGISTERED, psm);
return;
}
@ -1446,7 +1446,7 @@ void l2cap_register_service_internal(void *connection, btstack_packet_handler_t
// TODO: emit error event
service = (l2cap_service_t *) btstack_memory_l2cap_service_get();
if (!service) {
log_error("l2cap_register_service_internal: no memory for l2cap_service_t\n");
log_error("l2cap_register_service_internal: no memory for l2cap_service_t");
l2cap_emit_service_registered(connection, BTSTACK_MEMORY_ALLOC_FAILED, psm);
return;
}
@ -1525,10 +1525,10 @@ void l2cap_register_fixed_channel(btstack_packet_handler_t packet_handler, uint1
// Request LE connection parameter update
int l2cap_le_request_connection_parameter_update(uint16_t handle, uint16_t interval_min, uint16_t interval_max, uint16_t slave_latency, uint16_t timeout_multiplier){
if (!hci_can_send_acl_packet_now(handle)){
log_info("l2cap_send_signaling_packet, cannot send\n");
log_info("l2cap_send_signaling_packet, cannot send");
return BTSTACK_ACL_BUFFERS_FULL;
}
// log_info("l2cap_send_signaling_packet type %u\n", cmd);
// log_info("l2cap_send_signaling_packet type %u", cmd);
hci_reserve_packet_buffer();
uint8_t *acl_buffer = hci_get_outgoing_packet_buffer();
uint16_t len = l2cap_le_create_connection_parameter_update_request(acl_buffer, handle, interval_min, interval_max, slave_latency, timeout_multiplier);

2
src/linked_list.c
View File

@ -130,7 +130,7 @@ void linked_list_iterator_init(linked_list_iterator_t * it, linked_list_t * head
}
int linked_list_iterator_has_next(linked_list_iterator_t * it){
// printf("linked_list_iterator_has_next: advance on next %u, it->prev %p, it->curr %p\n", it->advance_on_next, it->prev, it->curr);
// log_info("linked_list_iterator_has_next: advance on next %u, it->prev %p, it->curr %p", it->advance_on_next, it->prev, it->curr);
if (!it->advance_on_next){
return it->curr != NULL;
}

146
src/rfcomm.c
View File

@ -304,7 +304,7 @@ static uint16_t rfcomm_max_frame_size_for_l2cap_mtu(uint16_t l2cap_mtu){
max_frame_size--;
}
log_info("rfcomm_max_frame_size_for_l2cap_mtu: %u -> %u\n", l2cap_mtu, max_frame_size);
log_info("rfcomm_max_frame_size_for_l2cap_mtu: %u -> %u", l2cap_mtu, max_frame_size);
return max_frame_size;
}
@ -378,7 +378,7 @@ static void rfcomm_dump_channels(void){
int channels = 0;
for (it = (linked_item_t *) rfcomm_channels; it ; it = it->next){
rfcomm_channel_t * channel = (rfcomm_channel_t *) it;
log_info("Channel #%u: addr %p, state %u\n", channels, channel, channel->state);
log_info("Channel #%u: addr %p, state %u", channels, channel, channel->state);
channels++;
}
#endif
@ -435,7 +435,7 @@ static void rfcomm_channel_initialize(rfcomm_channel_t *channel, rfcomm_multiple
static rfcomm_channel_t * rfcomm_channel_create(rfcomm_multiplexer_t * multiplexer,
rfcomm_service_t * service, uint8_t server_channel){
log_info("rfcomm_channel_create for service %p, channel %u --- list of channels:\n", service, server_channel);
log_info("rfcomm_channel_create for service %p, channel %u --- list of channels:", service, server_channel);
rfcomm_dump_channels();
// alloc structure
@ -533,7 +533,7 @@ static int rfcomm_send_packet_for_multiplexer(rfcomm_multiplexer_t *multiplexer,
credits_taken++;
multiplexer->l2cap_credits--;
} else {
log_info( "rfcomm_send_packet addr %02x, ctrl %02x size %u without l2cap credits\n", address, control, pos);
log_info( "rfcomm_send_packet addr %02x, ctrl %02x size %u without l2cap credits", address, control, pos);
}
int err = l2cap_send_prepared(multiplexer->l2cap_cid, pos);
@ -811,7 +811,7 @@ static void rfcomm_multiplexer_finalize(rfcomm_multiplexer_t * multiplexer){
static void rfcomm_multiplexer_timer_handler(timer_source_t *timer){
rfcomm_multiplexer_t * multiplexer = (rfcomm_multiplexer_t *) linked_item_get_user( (linked_item_t *) timer);
if (!rfcomm_multiplexer_has_channels(multiplexer)){
log_info( "rfcomm_multiplexer_timer_handler timeout: shutting down multiplexer!\n");
log_info( "rfcomm_multiplexer_timer_handler timeout: shutting down multiplexer!");
rfcomm_multiplexer_finalize(multiplexer);
}
}
@ -832,7 +832,7 @@ static void rfcomm_multiplexer_prepare_idle_timer(rfcomm_multiplexer_t * multipl
}
static void rfcomm_multiplexer_opened(rfcomm_multiplexer_t *multiplexer){
log_info("Multiplexer up and running\n");
log_info("Multiplexer up and running");
multiplexer->state = RFCOMM_MULTIPLEXER_OPEN;
rfcomm_channel_event_t event = { CH_EVT_MULTIPLEXER_READY };
@ -903,7 +903,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
if (READ_BT_16(packet, 11) != PSM_RFCOMM) break;
status = packet[2];
log_info("L2CAP_EVENT_CHANNEL_OPENED for PSM_RFCOMM, status %u\n", status);
log_info("L2CAP_EVENT_CHANNEL_OPENED for PSM_RFCOMM, status %u", status);
// get multiplexer for remote addr
con_handle = READ_BT_16(packet, 9);
@ -911,7 +911,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
bt_flip_addr(event_addr, &packet[3]);
multiplexer = rfcomm_multiplexer_for_addr(&event_addr);
if (!multiplexer) {
log_error("L2CAP_EVENT_CHANNEL_OPENED but no multiplexer prepared\n");
log_error("L2CAP_EVENT_CHANNEL_OPENED but no multiplexer prepared");
return 1;
}
@ -940,7 +940,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
}
if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_CONNECT) {
log_info("L2CAP_EVENT_CHANNEL_OPENED: outgoing connection\n");
log_info("L2CAP_EVENT_CHANNEL_OPENED: outgoing connection");
// wrong remote addr
if (BD_ADDR_CMP(event_addr, multiplexer->remote_addr)) break;
multiplexer->l2cap_cid = l2cap_cid;
@ -963,7 +963,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
if (!multiplexer) break;
multiplexer->l2cap_credits += packet[4];
// log_info("L2CAP_EVENT_CREDITS: %u (now %u)\n", packet[4], multiplexer->l2cap_credits);
// log_info("L2CAP_EVENT_CREDITS: %u (now %u)", packet[4], multiplexer->l2cap_credits);
// new credits, continue with signaling
rfcomm_run();
@ -1019,7 +1019,7 @@ static int rfcomm_multiplexer_l2cap_packet_handler(uint16_t channel, uint8_t *pa
case BT_RFCOMM_SABM:
if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_SABM_0){
log_info("Received SABM #0\n");
log_info("Received SABM #0");
multiplexer->outgoing = 0;
multiplexer->state = RFCOMM_MULTIPLEXER_SEND_UA_0;
return 1;
@ -1029,7 +1029,7 @@ static int rfcomm_multiplexer_l2cap_packet_handler(uint16_t channel, uint8_t *pa
case BT_RFCOMM_UA:
if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_UA_0) {
// UA #0 -> send UA #0, state = RFCOMM_MULTIPLEXER_OPEN
log_info("Received UA #0 \n");
log_info("Received UA #0 ");
rfcomm_multiplexer_opened(multiplexer);
return 1;
}
@ -1037,30 +1037,30 @@ static int rfcomm_multiplexer_l2cap_packet_handler(uint16_t channel, uint8_t *pa
case BT_RFCOMM_DISC:
// DISC #0 -> send UA #0, close multiplexer
log_info("Received DISC #0, (ougoing = %u)\n", multiplexer->outgoing);
log_info("Received DISC #0, (ougoing = %u)", multiplexer->outgoing);
multiplexer->state = RFCOMM_MULTIPLEXER_SEND_UA_0_AND_DISC;
return 1;
case BT_RFCOMM_DM:
// DM #0 - we shouldn't get this, just give up
log_info("Received DM #0\n");
log_info("-> Closing down multiplexer\n");
log_info("Received DM #0");
log_info("-> Closing down multiplexer");
rfcomm_multiplexer_finalize(multiplexer);
return 1;
case BT_RFCOMM_UIH:
if (packet[payload_offset] == BT_RFCOMM_CLD_CMD){
// Multiplexer close down (CLD) -> close mutliplexer
log_info("Received Multiplexer close down command\n");
log_info("-> Closing down multiplexer\n");
log_info("Received Multiplexer close down command");
log_info("-> Closing down multiplexer");
rfcomm_multiplexer_finalize(multiplexer);
return 1;
}
switch (packet[payload_offset]){
case BT_RFCOMM_CLD_CMD:
// Multiplexer close down (CLD) -> close mutliplexer
log_info("Received Multiplexer close down command\n");
log_info("-> Closing down multiplexer\n");
log_info("Received Multiplexer close down command");
log_info("-> Closing down multiplexer");
rfcomm_multiplexer_finalize(multiplexer);
return 1;
@ -1130,7 +1130,7 @@ static void rfcomm_multiplexer_state_machine(rfcomm_multiplexer_t * multiplexer,
case RFCOMM_MULTIPLEXER_SEND_SABM_0:
switch (event) {
case MULT_EV_READY_TO_SEND:
log_info("Sending SABM #0 - (multi 0x%p)\n", multiplexer);
log_info("Sending SABM #0 - (multi 0x%p)", multiplexer);
multiplexer->state = RFCOMM_MULTIPLEXER_W4_UA_0;
rfcomm_send_sabm(multiplexer, 0);
break;
@ -1141,7 +1141,7 @@ static void rfcomm_multiplexer_state_machine(rfcomm_multiplexer_t * multiplexer,
case RFCOMM_MULTIPLEXER_SEND_UA_0:
switch (event) {
case MULT_EV_READY_TO_SEND:
log_info("Sending UA #0\n");
log_info("Sending UA #0");
multiplexer->state = RFCOMM_MULTIPLEXER_OPEN;
rfcomm_send_ua(multiplexer, 0);
rfcomm_multiplexer_opened(multiplexer);
@ -1155,11 +1155,11 @@ static void rfcomm_multiplexer_state_machine(rfcomm_multiplexer_t * multiplexer,
case MULT_EV_READY_TO_SEND:
// try to detect authentication errors: drop link key if multiplexer closed before first channel got opened
if (!multiplexer->at_least_one_connection){
log_info("TODO: no connections established - delete link key prophylactically\n");
log_info("TODO: no connections established - delete link key prophylactically");
// hci_send_cmd(&hci_delete_stored_link_key, multiplexer->remote_addr);
}
log_info("Sending UA #0\n");
log_info("Closing down multiplexer\n");
log_info("Sending UA #0");
log_info("Closing down multiplexer");
multiplexer->state = RFCOMM_MULTIPLEXER_CLOSED;
rfcomm_send_ua(multiplexer, 0);
rfcomm_multiplexer_finalize(multiplexer);
@ -1195,23 +1195,23 @@ static void rfcomm_hand_out_credits(void){
for (it = (linked_item_t *) rfcomm_channels; it ; it = it->next){
rfcomm_channel_t * channel = (rfcomm_channel_t *) it;
if (channel->state != RFCOMM_CHANNEL_OPEN) {
// log_info("RFCOMM_EVENT_CREDITS: multiplexer not open\n");
// log_info("RFCOMM_EVENT_CREDITS: multiplexer not open");
continue;
}
if (channel->packets_granted) {
// log_info("RFCOMM_EVENT_CREDITS: already packets granted\n");
// log_info("RFCOMM_EVENT_CREDITS: already packets granted");
continue;
}
if (!channel->credits_outgoing) {
// log_info("RFCOMM_EVENT_CREDITS: no outgoing credits\n");
// log_info("RFCOMM_EVENT_CREDITS: no outgoing credits");
continue;
}
if (!channel->multiplexer->l2cap_credits){
// log_info("RFCOMM_EVENT_CREDITS: no l2cap credits\n");
// log_info("RFCOMM_EVENT_CREDITS: no l2cap credits");
continue;
}
// channel open, multiplexer has l2cap credits and we didn't hand out credit before -> go!
// log_info("RFCOMM_EVENT_CREDITS: 1\n");
// log_info("RFCOMM_EVENT_CREDITS: 1");
channel->packets_granted += 1;
rfcomm_emit_credits(channel, 1);
}
@ -1226,7 +1226,7 @@ static void rfcomm_channel_send_credits(rfcomm_channel_t *channel, uint8_t credi
static void rfcomm_channel_opened(rfcomm_channel_t *rfChannel){
log_info("rfcomm_channel_opened!\n");
log_info("rfcomm_channel_opened!");
rfChannel->state = RFCOMM_CHANNEL_OPEN;
rfcomm_emit_channel_opened(rfChannel, 0);
@ -1261,7 +1261,7 @@ static void rfcomm_channel_packet_handler_uih(rfcomm_multiplexer_t *multiplexer,
// add them
uint16_t new_credits = packet[3+length_offset];
channel->credits_outgoing += new_credits;
log_info( "RFCOMM data UIH_PF, new credits: %u, now %u\n", new_credits, channel->credits_outgoing);
log_info( "RFCOMM data UIH_PF, new credits: %u, now %u", new_credits, channel->credits_outgoing);
// notify channel statemachine
rfcomm_channel_event_t channel_event = { CH_EVT_RCVD_CREDITS };
@ -1271,7 +1271,7 @@ static void rfcomm_channel_packet_handler_uih(rfcomm_multiplexer_t *multiplexer,
// contains payload?
if (size - 1 > payload_offset){
// log_info( "RFCOMM data UIH_PF, size %u, channel %p\n", size-payload_offset-1, rfChannel->connection);
// log_info( "RFCOMM data UIH_PF, size %u, channel %p", size-payload_offset-1, rfChannel->connection);
// decrease incoming credit counter
if (channel->credits_incoming > 0){
@ -1333,7 +1333,7 @@ static void rfcomm_channel_state_machine_2(rfcomm_multiplexer_t * multiplexer, u
// lookup existing channel
rfcomm_channel_t * channel = rfcomm_channel_for_multiplexer_and_dlci(multiplexer, dlci);
// log_info("rfcomm_channel_state_machine_2 lookup dlci #%u = 0x%08x - event %u\n", dlci, (int) channel, event->type);
// log_info("rfcomm_channel_state_machine_2 lookup dlci #%u = 0x%08x - event %u", dlci, (int) channel, event->type);
if (channel) {
rfcomm_channel_state_machine(channel, event);
@ -1342,7 +1342,7 @@ static void rfcomm_channel_state_machine_2(rfcomm_multiplexer_t * multiplexer, u
// service registered?
rfcomm_service_t * service = rfcomm_service_for_channel(dlci >> 1);
// log_info("rfcomm_channel_state_machine_2 service dlci #%u = 0x%08x\n", dlci, (int) service);
// log_info("rfcomm_channel_state_machine_2 service dlci #%u = 0x%08x", dlci, (int) service);
if (!service) {
// discard request by sending disconnected mode
multiplexer->send_dm_for_dlci = dlci;
@ -1401,13 +1401,13 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
case BT_RFCOMM_SABM:
event.type = CH_EVT_RCVD_SABM;
log_info("Received SABM #%u\n", frame_dlci);
log_info("Received SABM #%u", frame_dlci);
rfcomm_channel_state_machine_2(multiplexer, frame_dlci, &event);
break;
case BT_RFCOMM_UA:
event.type = CH_EVT_RCVD_UA;
log_info("Received UA #%u\n",frame_dlci);
log_info("Received UA #%u",frame_dlci);
rfcomm_channel_state_machine_2(multiplexer, frame_dlci, &event);
break;
@ -1434,7 +1434,7 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
event_pn.priority = packet[payload_offset+4];
event_pn.max_frame_size = READ_BT_16(packet, payload_offset+6);
event_pn.credits_outgoing = packet[payload_offset+9];
log_info("Received UIH Parameter Negotiation Command for #%u, credits %u\n",
log_info("Received UIH Parameter Negotiation Command for #%u, credits %u",
message_dlci, event_pn.credits_outgoing);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_pn);
break;
@ -1445,7 +1445,7 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
event_pn.priority = packet[payload_offset+4];
event_pn.max_frame_size = READ_BT_16(packet, payload_offset+6);
event_pn.credits_outgoing = packet[payload_offset+9];
log_info("Received UIH Parameter Negotiation Response max frame %u, credits %u\n",
log_info("Received UIH Parameter Negotiation Response max frame %u, credits %u",
event_pn.max_frame_size, event_pn.credits_outgoing);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_pn);
break;
@ -1454,14 +1454,14 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
message_dlci = packet[payload_offset+2] >> 2;
event_msc.super.type = CH_EVT_RCVD_MSC_CMD;
event_msc.modem_status = packet[payload_offset+3];
log_info("Received MSC CMD for #%u, \n", message_dlci);
log_info("Received MSC CMD for #%u, ", message_dlci);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_msc);
break;
case BT_RFCOMM_MSC_RSP:
message_dlci = packet[payload_offset+2] >> 2;
event.type = CH_EVT_RCVD_MSC_RSP;
log_info("Received MSC RSP for #%u\n", message_dlci);
log_info("Received MSC RSP for #%u", message_dlci);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event);
break;
@ -1469,12 +1469,12 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
message_dlci = packet[payload_offset+2] >> 2;
switch (message_len){
case 1:
log_info("Received Remote Port Negotiation Request for #%u\n", message_dlci);
log_info("Received Remote Port Negotiation Request for #%u", message_dlci);
event.type = CH_EVT_RCVD_RPN_REQ;
rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event);
break;
case 8:
log_info("Received Remote Port Negotiation Update for #%u\n", message_dlci);
log_info("Received Remote Port Negotiation Update for #%u", message_dlci);
event_rpn.super.type = CH_EVT_RCVD_RPN_CMD;
event_rpn.data = *(rfcomm_rpn_data_t*) &packet[payload_offset+3];
rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_rpn);
@ -1508,7 +1508,7 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
// case BT_RFCOMM_FCON_CMD:
// everything else is an not supported command
default: {
log_error("Received unknown UIH command packet - 0x%02x\n", packet[payload_offset]);
log_error("Received unknown UIH command packet - 0x%02x", packet[payload_offset]);
multiplexer->nsc_command = packet[payload_offset];
break;
}
@ -1516,7 +1516,7 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
break;
default:
log_error("Received unknown RFCOMM message type %x\n", packet[1]);
log_error("Received unknown RFCOMM message type %x", packet[1]);
break;
}
@ -1571,10 +1571,10 @@ void rfcomm_packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packe
static int rfcomm_channel_ready_for_open(rfcomm_channel_t *channel){
// note: exchanging MSC isn't neccessary to consider channel open
// note: having outgoing credits is also not necessary to consider channel open
// log_info("rfcomm_channel_ready_for_open state %u, flags needed %04x, current %04x, rf credits %u, l2cap credits %u \n", channel->state, RFCOMM_CHANNEL_STATE_VAR_RCVD_MSC_RSP|RFCOMM_CHANNEL_STATE_VAR_SENT_MSC_RSP|RFCOMM_CHANNEL_STATE_VAR_SENT_CREDITS, channel->state_var, channel->credits_outgoing, channel->multiplexer->l2cap_credits);
// log_info("rfcomm_channel_ready_for_open state %u, flags needed %04x, current %04x, rf credits %u, l2cap credits %u ", channel->state, RFCOMM_CHANNEL_STATE_VAR_RCVD_MSC_RSP|RFCOMM_CHANNEL_STATE_VAR_SENT_MSC_RSP|RFCOMM_CHANNEL_STATE_VAR_SENT_CREDITS, channel->state_var, channel->credits_outgoing, channel->multiplexer->l2cap_credits);
// if ((channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SENT_MSC_RSP) == 0) return 0;
// if (channel->credits_outgoing == 0) return 0;
log_info("rfcomm_channel_ready_for_open state %u, flags needed %04x, current %04x, rf credits %u, l2cap credits %u \n", channel->state, RFCOMM_CHANNEL_STATE_VAR_RCVD_MSC_RSP, channel->state_var, channel->credits_outgoing, channel->multiplexer->l2cap_credits);
log_info("rfcomm_channel_ready_for_open state %u, flags needed %04x, current %04x, rf credits %u, l2cap credits %u ", channel->state, RFCOMM_CHANNEL_STATE_VAR_RCVD_MSC_RSP, channel->state_var, channel->credits_outgoing, channel->multiplexer->l2cap_credits);
if ((channel->state_var & RFCOMM_CHANNEL_STATE_VAR_RCVD_MSC_RSP) == 0) return 0;
if ((channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SENT_CREDITS) == 0) return 0;
@ -1590,7 +1590,7 @@ inline static void rfcomm_channel_state_remove(rfcomm_channel_t *channel, RFCOMM
static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_channel_event_t *event){
// log_info("rfcomm_channel_state_machine: state %u, state_var %04x, event %u\n", channel->state, channel->state_var ,event->type);
// log_info("rfcomm_channel_state_machine: state %u, state_var %04x, event %u", channel->state, channel->state_var ,event->type);
rfcomm_multiplexer_t *multiplexer = channel->multiplexer;
@ -1603,8 +1603,8 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
// TODO: integrate in common switch
if (event->type == CH_EVT_RCVD_DM){
log_info("Received DM message for #%u\n", channel->dlci);
log_info("-> Closing channel locally for #%u\n", channel->dlci);
log_info("Received DM message for #%u", channel->dlci);
log_info("-> Closing channel locally for #%u", channel->dlci);
rfcomm_emit_channel_closed(channel);
rfcomm_channel_finalize(channel);
return;
@ -1648,13 +1648,13 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
// TODO: integrate in common swich
if (event->type == CH_EVT_READY_TO_SEND){
if (channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SEND_RPN_RSP){
log_info("Sending Remote Port Negotiation RSP for #%u\n", channel->dlci);
log_info("Sending Remote Port Negotiation RSP for #%u", channel->dlci);
rfcomm_channel_state_remove(channel, RFCOMM_CHANNEL_STATE_VAR_SEND_RPN_RSP);
rfcomm_send_uih_rpn_rsp(multiplexer, channel->dlci, &channel->rpn_data);
return;
}
if (channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SEND_MSC_RSP){
log_info("Sending MSC RSP for #%u\n", channel->dlci);
log_info("Sending MSC RSP for #%u", channel->dlci);
rfcomm_channel_state_remove(channel, RFCOMM_CHANNEL_STATE_VAR_SEND_MSC_RSP);
rfcomm_channel_state_add(channel, RFCOMM_CHANNEL_STATE_VAR_SENT_MSC_RSP);
rfcomm_send_uih_msc_rsp(multiplexer, channel->dlci, 0x8d); // ea=1,fc=0,rtc=1,rtr=1,ic=0,dv=1
@ -1687,14 +1687,14 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_CLOSED:
switch (event->type){
case CH_EVT_RCVD_SABM:
log_info("-> Inform app\n");
log_info("-> Inform app");
rfcomm_channel_state_add(channel, RFCOMM_CHANNEL_STATE_VAR_RCVD_SABM);
channel->state = RFCOMM_CHANNEL_INCOMING_SETUP;
rfcomm_emit_connection_request(channel);
break;
case CH_EVT_RCVD_PN:
rfcomm_channel_accept_pn(channel, event_pn);
log_info("-> Inform app\n");
log_info("-> Inform app");
rfcomm_channel_state_add(channel, RFCOMM_CHANNEL_STATE_VAR_RCVD_PN);
channel->state = RFCOMM_CHANNEL_INCOMING_SETUP;
rfcomm_emit_connection_request(channel);
@ -1721,12 +1721,12 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
break;
case CH_EVT_READY_TO_SEND:
if (channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SEND_PN_RSP){
log_info("Sending UIH Parameter Negotiation Respond for #%u\n", channel->dlci);
log_info("Sending UIH Parameter Negotiation Respond for #%u", channel->dlci);
rfcomm_channel_state_remove(channel, RFCOMM_CHANNEL_STATE_VAR_SEND_PN_RSP);
rfcomm_send_uih_pn_response(multiplexer, channel->dlci, channel->pn_priority, channel->max_frame_size);
}
else if (channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SEND_UA){
log_info("Sending UA #%u\n", channel->dlci);
log_info("Sending UA #%u", channel->dlci);
rfcomm_channel_state_remove(channel, RFCOMM_CHANNEL_STATE_VAR_SEND_UA);
rfcomm_send_ua(multiplexer, channel->dlci);
}
@ -1746,7 +1746,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_W4_MULTIPLEXER:
switch (event->type) {
case CH_EVT_MULTIPLEXER_READY:
log_info("Muliplexer opened, sending UIH PN next\n");
log_info("Muliplexer opened, sending UIH PN next");
channel->state = RFCOMM_CHANNEL_SEND_UIH_PN;
break;
default:
@ -1757,7 +1757,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_UIH_PN:
switch (event->type) {
case CH_EVT_READY_TO_SEND:
log_info("Sending UIH Parameter Negotiation Command for #%u (channel 0x%p)\n", channel->dlci, channel );
log_info("Sending UIH Parameter Negotiation Command for #%u (channel 0x%p)", channel->dlci, channel );
channel->state = RFCOMM_CHANNEL_W4_PN_RSP;
rfcomm_send_uih_pn_command(multiplexer, channel->dlci, channel->max_frame_size);
break;
@ -1785,7 +1785,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_SABM_W4_UA:
switch (event->type) {
case CH_EVT_READY_TO_SEND:
log_info("Sending SABM #%u\n", channel->dlci);
log_info("Sending SABM #%u", channel->dlci);
channel->state = RFCOMM_CHANNEL_W4_UA;
rfcomm_send_sabm(multiplexer, channel->dlci);
break;
@ -1818,14 +1818,14 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case CH_EVT_READY_TO_SEND:
if (channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SEND_MSC_CMD){
log_info("Sending MSC CMD for #%u\n", channel->dlci);
log_info("Sending MSC CMD for #%u", channel->dlci);
rfcomm_channel_state_remove(channel, RFCOMM_CHANNEL_STATE_VAR_SEND_MSC_CMD);
rfcomm_channel_state_add(channel, RFCOMM_CHANNEL_STATE_VAR_SENT_MSC_CMD);
rfcomm_send_uih_msc_cmd(multiplexer, channel->dlci , 0x8d); // ea=1,fc=0,rtc=1,rtr=1,ic=0,dv=1
break;
}
if (channel->state_var & RFCOMM_CHANNEL_STATE_VAR_SEND_CREDITS){
log_info("Providing credits for #%u\n", channel->dlci);
log_info("Providing credits for #%u", channel->dlci);
rfcomm_channel_state_remove(channel, RFCOMM_CHANNEL_STATE_VAR_SEND_CREDITS);
rfcomm_channel_state_add(channel, RFCOMM_CHANNEL_STATE_VAR_SENT_CREDITS);
@ -1875,7 +1875,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_DM:
switch (event->type) {
case CH_EVT_READY_TO_SEND:
log_info("Sending DM_PF for #%u\n", channel->dlci);
log_info("Sending DM_PF for #%u", channel->dlci);
// don't emit channel closed - channel was never open
channel->state = RFCOMM_CHANNEL_CLOSED;
rfcomm_send_dm_pf(multiplexer, channel->dlci);
@ -1912,7 +1912,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_UA_AFTER_DISC:
switch (event->type) {
case CH_EVT_READY_TO_SEND:
log_info("Sending UA after DISC for #%u\n", channel->dlci);
log_info("Sending UA after DISC for #%u", channel->dlci);
channel->state = RFCOMM_CHANNEL_CLOSED;
rfcomm_send_ua(multiplexer, channel->dlci);
rfcomm_channel_finalize(channel);
@ -1942,10 +1942,10 @@ static void rfcomm_run(void){
rfcomm_multiplexer_t * multiplexer = ((rfcomm_multiplexer_t *) it);
if (!l2cap_can_send_packet_now(multiplexer->l2cap_cid)) {
// log_info("rfcomm_run A cannot send l2cap packet for #%u, credits %u\n", multiplexer->l2cap_cid, multiplexer->l2cap_credits);
// log_info("rfcomm_run A cannot send l2cap packet for #%u, credits %u", multiplexer->l2cap_cid, multiplexer->l2cap_credits);
continue;
}
// log_info("rfcomm_run: multi 0x%08x, state %u\n", (int) multiplexer, multiplexer->state);
// log_info("rfcomm_run: multi 0x%08x, state %u", (int) multiplexer, multiplexer->state);
rfcomm_multiplexer_state_machine(multiplexer, MULT_EV_READY_TO_SEND);
}
@ -1958,7 +1958,7 @@ static void rfcomm_run(void){
rfcomm_multiplexer_t * multiplexer = channel->multiplexer;
if (!l2cap_can_send_packet_now(multiplexer->l2cap_cid)) {
// log_info("rfcomm_run B cannot send l2cap packet for #%u, credits %u\n", multiplexer->l2cap_cid, multiplexer->l2cap_credits);
// log_info("rfcomm_run B cannot send l2cap packet for #%u, credits %u", multiplexer->l2cap_cid, multiplexer->l2cap_credits);
continue;
}
@ -2010,7 +2010,7 @@ int rfcomm_send_internal(uint16_t rfcomm_cid, uint8_t *data, uint16_t len){
log_info("rfcomm_send_internal cid 0x%02x, aggregate flow off!", rfcomm_cid);
return RFCOMM_AGGREGATE_FLOW_OFF;
}
// log_info("rfcomm_send_internal: len %u... outgoing credits %u, l2cap credit %us, granted %u\n",
// log_info("rfcomm_send_internal: len %u... outgoing credits %u, l2cap credit %us, granted %u",
// len, channel->credits_outgoing, channel->multiplexer->l2cap_credits, channel->packets_granted);
@ -2027,11 +2027,11 @@ int rfcomm_send_internal(uint16_t rfcomm_cid, uint8_t *data, uint16_t len){
if (result != 0) {
channel->credits_outgoing++;
channel->packets_granted += packets_granted_decreased;
log_info("rfcomm_send_internal: error %d\n", result);
log_info("rfcomm_send_internal: error %d", result);
return result;
}
// log_info("rfcomm_send_internal: now outgoing credits %u, l2cap credit %us, granted %u\n",
// log_info("rfcomm_send_internal: now outgoing credits %u, l2cap credit %us, granted %u",
// channel->credits_outgoing, channel->multiplexer->l2cap_credits, channel->packets_granted);
rfcomm_hand_out_credits();
@ -2043,7 +2043,7 @@ int rfcomm_send_internal(uint16_t rfcomm_cid, uint8_t *data, uint16_t len){
int rfcomm_send_local_line_status(uint16_t rfcomm_cid, uint8_t line_status){
rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid);
if (!channel){
log_error("rfcomm_send_local_line_status cid 0x%02x doesn't exist!\n", rfcomm_cid);
log_error("rfcomm_send_local_line_status cid 0x%02x doesn't exist!", rfcomm_cid);
return 0;
}
return rfcomm_send_uih_rls_cmd(channel->multiplexer, channel->dlci, line_status);
@ -2053,7 +2053,7 @@ int rfcomm_send_local_line_status(uint16_t rfcomm_cid, uint8_t line_status){
int rfcomm_send_modem_status(uint16_t rfcomm_cid, uint8_t modem_status){
rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid);
if (!channel){
log_error("rfcomm_send_modem_status cid 0x%02x doesn't exist!\n", rfcomm_cid);
log_error("rfcomm_send_modem_status cid 0x%02x doesn't exist!", rfcomm_cid);
return 0;
}
return rfcomm_send_uih_msc_cmd(channel->multiplexer, channel->dlci, modem_status);
@ -2063,7 +2063,7 @@ int rfcomm_send_modem_status(uint16_t rfcomm_cid, uint8_t modem_status){
int rfcomm_send_port_configuration(uint16_t rfcomm_cid, rpn_baud_t baud_rate, rpn_data_bits_t data_bits, rpn_stop_bits_t stop_bits, rpn_parity_t parity, rpn_flow_control_t flow_control){
rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid);
if (!channel){
log_error("rfcomm_send_port_configuration cid 0x%02x doesn't exist!\n", rfcomm_cid);
log_error("rfcomm_send_port_configuration cid 0x%02x doesn't exist!", rfcomm_cid);
return 0;
}
rfcomm_rpn_data_t rpn_data;
@ -2081,7 +2081,7 @@ int rfcomm_send_port_configuration(uint16_t rfcomm_cid, rpn_baud_t baud_rate, rp
int rfcomm_query_port_configuration(uint16_t rfcomm_cid){
rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid);
if (!channel){
log_error("rfcomm_query_port_configuration cid 0x%02x doesn't exist!\n", rfcomm_cid);
log_error("rfcomm_query_port_configuration cid 0x%02x doesn't exist!", rfcomm_cid);
return 0;
}
return rfcomm_send_uih_rpn_req(channel->multiplexer, channel->dlci);
@ -2089,7 +2089,7 @@ int rfcomm_query_port_configuration(uint16_t rfcomm_cid){
void rfcomm_create_channel2(void * connection, bd_addr_t *addr, uint8_t server_channel, uint8_t incoming_flow_control, uint8_t initial_credits){
log_info("RFCOMM_CREATE_CHANNEL addr %s channel #%u flow control %u init credits %u\n", bd_addr_to_str(*addr), server_channel,
log_info("RFCOMM_CREATE_CHANNEL addr %s channel #%u flow control %u init credits %u", bd_addr_to_str(*addr), server_channel,
incoming_flow_control, initial_credits);
// create new multiplexer if necessary

6
src/run_loop.c
View File

@ -66,7 +66,7 @@ extern run_loop_t run_loop_cocoa;
void run_loop_assert(void){
#ifndef EMBEDDED
if (!the_run_loop){
log_error("ERROR: run_loop function called before run_loop_init!\n");
log_error("ERROR: run_loop function called before run_loop_init!");
exit(10);
}
#endif
@ -136,7 +136,7 @@ void run_loop_execute() {
void run_loop_init(RUN_LOOP_TYPE type){
#ifndef EMBEDDED
if (the_run_loop){
log_error("ERROR: run loop initialized twice!\n");
log_error("ERROR: run loop initialized twice!");
exit(10);
}
#endif
@ -158,7 +158,7 @@ void run_loop_init(RUN_LOOP_TYPE type){
#endif
default:
#ifndef EMBEDDED
log_error("ERROR: invalid run loop type %u selected!\n", type);
log_error("ERROR: invalid run loop type %u selected!", type);
exit(10);
#endif
break;

2
src/run_loop_embedded.c
View File

@ -105,7 +105,7 @@ static void embedded_add_timer(timer_source_t *ts){
for (it = (linked_item_t *) &timers; it->next ; it = it->next){
// don't add timer that's already in there
if ((timer_source_t *) it->next == ts){
log_error( "run_loop_timer_add error: timer to add already in list!\n");
log_error( "run_loop_timer_add error: timer to add already in list!");
return;
}
if (ts->timeout < ((timer_source_t *) it->next)->timeout) {

2
src/run_loop_posix.c
View File

@ -84,7 +84,7 @@ static void posix_add_timer(timer_source_t *ts){
linked_item_t *it;
for (it = (linked_item_t *) &timers; it->next ; it = it->next){
if ((timer_source_t *) it->next == ts){
log_error( "run_loop_timer_add error: timer to add already in list!\n");
log_error( "run_loop_timer_add error: timer to add already in list!");
return;
}
if (posix_timer_compare( (timer_source_t *) it->next, ts) > 0) {

12
src/sdp.c
View File

@ -141,7 +141,7 @@ uint32_t sdp_register_service_internal(void *connection, service_record_item_t *
// check for ServiceRecordHandle attribute, returns pointer or null
uint8_t * req_record_handle = sdp_get_attribute_value_for_attribute_id(record, SDP_ServiceRecordHandle);
if (!req_record_handle) {
log_error("SDP Error - record does not contain ServiceRecordHandle attribute\n");
log_error("SDP Error - record does not contain ServiceRecordHandle attribute");
return 0;
}
@ -182,7 +182,7 @@ static const uint8_t removeServiceRecordHandleAttributeIDList[] = { 0x36, 0x00,
uint32_t sdp_register_service_internal(void *connection, uint8_t * record){
// dump for now
// printf("Register service record\n");
// log_info("Register service record");
// de_dump_data_element(record);
// get user record handle
@ -234,7 +234,7 @@ uint32_t sdp_register_service_internal(void *connection, uint8_t * record){
// dump for now
// de_dump_data_element(newRecord);
// printf("reserved size %u, actual size %u\n", recordSize, de_get_len(newRecord));
// log_info("reserved size %u, actual size %u", recordSize, de_get_len(newRecord));
// add to linked list
linked_list_add(&sdp_service_records, (linked_item_t *) newRecordItem);
@ -475,7 +475,7 @@ int sdp_handle_service_search_attribute_request(uint8_t * packet, uint16_t remot
continuation_offset = READ_NET_16(continuationState, 3);
}
// printf("--> sdp_handle_service_search_attribute_request, cont %u/%u, max %u\n", continuation_service_index, continuation_offset, maximumAttributeByteCount);
// log_info("--> sdp_handle_service_search_attribute_request, cont %u/%u, max %u", continuation_service_index, continuation_offset, maximumAttributeByteCount);
// AttributeLists - starts at offset 7
uint16_t pos = 7;
@ -484,7 +484,7 @@ int sdp_handle_service_search_attribute_request(uint8_t * packet, uint16_t remot
if (continuation_service_index == 0 && continuation_offset == 0){
uint16_t total_response_size = sdp_get_size_for_service_search_attribute_response(serviceSearchPattern, attributeIDList);
de_store_descriptor_with_len(&sdp_response_buffer[pos], DE_DES, DE_SIZE_VAR_16, total_response_size);
// log_info("total response size %u\n", total_response_size);
// log_info("total response size %u", total_response_size);
pos += 3;
maximumAttributeByteCount -= 3;
}
@ -588,7 +588,7 @@ static void sdp_packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *p
remote_mtu = SDP_RESPONSE_BUFFER_SIZE;
}
// printf("SDP Request: type %u, transaction id %u, len %u, mtu %u\n", pdu_id, transaction_id, param_len, remote_mtu);
// log_info("SDP Request: type %u, transaction id %u, len %u, mtu %u", pdu_id, transaction_id, param_len, remote_mtu);
switch (pdu_id){
case SDP_ServiceSearchRequest:

36
src/sdp_client.c
View File

@ -136,15 +136,15 @@ static void try_to_send(uint16_t channel){
switch (err){
case 0:
// packet is sent prepare next one
// printf("l2cap_send_internal() -> OK\n\r");
// log_info("l2cap_send_internal() -> OK");
PDU_ID = SDP_Invalid;
sdp_client_state = W4_RESPONSE;
break;
case BTSTACK_ACL_BUFFERS_FULL:
log_info("l2cap_send_internal() ->BTSTACK_ACL_BUFFERS_FULL\n\r");
log_info("l2cap_send_internal() ->BTSTACK_ACL_BUFFERS_FULL");
break;
default:
log_error("l2cap_send_internal() -> err %d\n\r", err);
log_error("l2cap_send_internal() -> err %d", err);
break;
}
}
@ -159,7 +159,7 @@ static void parse_service_search_attribute_response(uint8_t* packet){
offset+=2;
if (attributeListByteCount > mtu){
log_error("Error parsing ServiceSearchAttributeResponse: Number of bytes in found attribute list is larger then the MaximumAttributeByteCount.\n");
log_error("Error parsing ServiceSearchAttributeResponse: Number of bytes in found attribute list is larger then the MaximumAttributeByteCount.");
return;
}
@ -171,14 +171,14 @@ static void parse_service_search_attribute_response(uint8_t* packet){
offset++;
if (continuationStateLen > 16){
log_error("Error parsing ServiceSearchAttributeResponse: Number of bytes in continuation state exceedes 16.\n");
log_error("Error parsing ServiceSearchAttributeResponse: Number of bytes in continuation state exceedes 16.");
return;
}
memcpy(continuationState, packet+offset, continuationStateLen);
offset+=continuationStateLen;
if (parameterLength != offset - 5){
log_error("Error parsing ServiceSearchAttributeResponse: wrong size of parameters, number of expected bytes%u, actual number %u.\n", parameterLength, offset);
log_error("Error parsing ServiceSearchAttributeResponse: wrong size of parameters, number of expected bytes%u, actual number %u.", parameterLength, offset);
}
}
@ -189,14 +189,14 @@ void sdp_packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packet,
uint16_t responseTransactionID = READ_NET_16(packet,1);
if ( responseTransactionID != transactionID){
log_error("Missmatching transaction ID, expected %u, found %u.\n", transactionID, responseTransactionID);
log_error("Missmatching transaction ID, expected %u, found %u.", transactionID, responseTransactionID);
return;
}
if (packet[0] != SDP_ServiceSearchAttributeResponse
&& packet[0] != SDP_ServiceSearchResponse
&& packet[0] != SDP_ServiceAttributeResponse){
log_error("Not a valid PDU ID, expected %u, %u or %u, found %u.\n", SDP_ServiceSearchResponse,
log_error("Not a valid PDU ID, expected %u, %u or %u, found %u.", SDP_ServiceSearchResponse,
SDP_ServiceAttributeResponse, SDP_ServiceSearchAttributeResponse, packet[0]);
return;
}
@ -222,7 +222,7 @@ void sdp_packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packet,
// continuation set or DONE?
if (continuationStateLen == 0){
// printf("DONE! All clients already notified.\n");
// log_info("DONE! All clients already notified.");
sdp_client_handle_done(0);
sdp_client_state = INIT;
return;
@ -243,14 +243,14 @@ void sdp_packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packet,
// data: event (8), len(8), status (8), address(48), handle (16), psm (16), local_cid(16), remote_cid (16), local_mtu(16), remote_mtu(16)
if (packet[2]) {
log_error("Connection failed.\n\r");
log_error("Connection failed.");
sdp_client_handle_done(packet[2]);
break;
}
sdp_cid = channel;
mtu = READ_BT_16(packet, 17);
// handle = READ_BT_16(packet, 9);
log_info("Connected, cid %x, mtu %u.\n\r", sdp_cid, mtu);
log_info("Connected, cid %x, mtu %u.", sdp_cid, mtu);
sdp_client_state = W2_SEND;
try_to_send(sdp_cid);
@ -260,7 +260,7 @@ void sdp_packet_handler(uint8_t packet_type, uint16_t channel, uint8_t *packet,
try_to_send(sdp_cid);
break;
case L2CAP_EVENT_CHANNEL_CLOSED:
log_info("Channel closed.\n\r");
log_info("Channel closed.");
if (sdp_client_state == INIT) break;
sdp_client_handle_done(SDP_QUERY_INCOMPLETE);
break;
@ -401,7 +401,7 @@ static void parse_service_search_response(uint8_t* packet){
offset+=2;
if (currentServiceRecordCount > totalServiceRecordCount){
log_error("CurrentServiceRecordCount is larger then TotalServiceRecordCount.\n");
log_error("CurrentServiceRecordCount is larger then TotalServiceRecordCount.");
return;
}
@ -413,14 +413,14 @@ static void parse_service_search_response(uint8_t* packet){
offset++;
if (continuationStateLen > 16){
log_error("Error parsing ServiceSearchResponse: Number of bytes in continuation state exceedes 16.\n");
log_error("Error parsing ServiceSearchResponse: Number of bytes in continuation state exceedes 16.");
return;
}
memcpy(continuationState, packet+offset, continuationStateLen);
offset+=continuationStateLen;
if (parameterLength != offset - 5){
log_error("Error parsing ServiceSearchResponse: wrong size of parameters, number of expected bytes%u, actual number %u.\n", parameterLength, offset);
log_error("Error parsing ServiceSearchResponse: wrong size of parameters, number of expected bytes%u, actual number %u.", parameterLength, offset);
}
}
@ -434,7 +434,7 @@ static void parse_service_attribute_response(uint8_t* packet){
offset+=2;
if (attributeListByteCount > mtu){
log_error("Error parsing ServiceSearchAttributeResponse: Number of bytes in found attribute list is larger then the MaximumAttributeByteCount.\n");
log_error("Error parsing ServiceSearchAttributeResponse: Number of bytes in found attribute list is larger then the MaximumAttributeByteCount.");
return;
}
@ -446,14 +446,14 @@ static void parse_service_attribute_response(uint8_t* packet){
offset++;
if (continuationStateLen > 16){
log_error("Error parsing ServiceAttributeResponse: Number of bytes in continuation state exceedes 16.\n");
log_error("Error parsing ServiceAttributeResponse: Number of bytes in continuation state exceedes 16.");
return;
}
memcpy(continuationState, packet+offset, continuationStateLen);
offset+=continuationStateLen;
if (parameterLength != offset - 5){
log_error("Error parsing ServiceAttributeResponse: wrong size of parameters, number of expected bytes%u, actual number %u.\n", parameterLength, offset);
log_error("Error parsing ServiceAttributeResponse: wrong size of parameters, number of expected bytes%u, actual number %u.", parameterLength, offset);
}
}

28
src/sdp_parser.c
View File

@ -87,9 +87,9 @@ int de_state_size(uint8_t eventByte, de_state_t *de_state){
if (de_state->addon_header_bytes == 0){
de_state->de_size = de_get_data_size(&eventByte);
if (de_state->de_size == 0) {
log_error(" ERROR: ID size is zero\n\r");
log_error(" ERROR: ID size is zero");
}
// printf("Data element payload is %d bytes.\n", de_state->de_size);
// log_info("Data element payload is %d bytes.", de_state->de_size);
return 1;
}
de_state->in_state_GET_DE_HEADER_LENGTH = 0;
@ -101,7 +101,7 @@ int de_state_size(uint8_t eventByte, de_state_t *de_state){
de_state->addon_header_bytes--;
}
if (de_state->addon_header_bytes > 0) return 0;
// printf("Data element payload is %d bytes.\n", de_state->de_size);
// log_info("Data element payload is %d bytes.", de_state->de_size);
de_state->in_state_GET_DE_HEADER_LENGTH = 1;
return 1;
}
@ -120,13 +120,13 @@ void parse(uint8_t eventByte){
list_offset++;
record_offset++;
// printf(" parse BYTE_RECEIVED %02x\n", eventByte);
// log_info(" parse BYTE_RECEIVED %02x", eventByte);
switch(state){
case GET_LIST_LENGTH:
if (!de_state_size(eventByte, &de_header_state)) break;
list_offset = de_header_state.de_offset;
list_size = de_header_state.de_size;
// printf("parser: List offset %u, list size %u\n", list_offset, list_size);
// log_info("parser: List offset %u, list size %u", list_offset, list_size);
record_counter = 0;
state = GET_RECORD_LENGTH;
@ -135,7 +135,7 @@ void parse(uint8_t eventByte){
case GET_RECORD_LENGTH:
// check size
if (!de_state_size(eventByte, &de_header_state)) break;
// printf("parser: Record payload is %d bytes.\n", de_header_state.de_size);
// log_info("parser: Record payload is %d bytes.", de_header_state.de_size);
record_offset = de_header_state.de_offset;
record_size = de_header_state.de_size;
state = GET_ATTRIBUTE_ID_HEADER_LENGTH;
@ -144,7 +144,7 @@ void parse(uint8_t eventByte){
case GET_ATTRIBUTE_ID_HEADER_LENGTH:
if (!de_state_size(eventByte, &de_header_state)) break;
attribute_id = 0;
// printf("ID data is stored in %d bytes.\n", de_header_state.de_size);
// log_info("ID data is stored in %d bytes.", de_header_state.de_size);
state = GET_ATTRIBUTE_ID;
break;
@ -152,7 +152,7 @@ void parse(uint8_t eventByte){
attribute_id = (attribute_id << 8) | eventByte;
de_header_state.de_size--;
if (de_header_state.de_size > 0) break;
// printf("parser: Attribute ID: %04x.\n", attribute_id);
// log_info("parser: Attribute ID: %04x.", attribute_id);
state = GET_ATTRIBUTE_VALUE_LENGTH;
attribute_bytes_received = 0;
@ -195,29 +195,29 @@ void parse(uint8_t eventByte){
(*sdp_query_callback)((sdp_query_event_t*)&attribute_value_event);
}
// printf("paser: attribute_bytes_received %u, attribute_value_size %u\n", attribute_bytes_received, attribute_value_size);
// log_info("paser: attribute_bytes_received %u, attribute_value_size %u", attribute_bytes_received, attribute_value_size);
if (attribute_bytes_received < attribute_value_size) break;
// printf("parser: Record offset %u, record size %u\n", record_offset, record_size);
// log_info("parser: Record offset %u, record size %u", record_offset, record_size);
if (record_offset != record_size){
state = GET_ATTRIBUTE_ID_HEADER_LENGTH;
// printf("Get next attribute\n");
// log_info("Get next attribute");
break;
}
record_offset = 0;
// printf("parser: List offset %u, list size %u\n", list_offset, list_size);
// log_info("parser: List offset %u, list size %u", list_offset, list_size);
if (list_size > 0 && list_offset != list_size){
record_counter++;
state = GET_RECORD_LENGTH;
// printf("parser: END_OF_RECORD\n\n");
// log_info("parser: END_OF_RECORD");
break;
}
list_offset = 0;
de_state_init(&de_header_state);
state = GET_LIST_LENGTH;
record_counter = 0;
// printf("parser: END_OF_RECORD & DONE\n\n\n");
// log_info("parser: END_OF_RECORD & DONE");
break;
default:
break;

26
src/sdp_query_rfcomm.c
View File

@ -102,14 +102,14 @@ void handleProtocolDescriptorListData(uint32_t attribute_value_length, uint32_t
pdl_state = GET_PROTOCOL_LIST_LENGTH;
}
// printf("handleProtocolDescriptorListData (%u,%u) %02x\n", attribute_value_length, data_offset, data);
// log_info("handleProtocolDescriptorListData (%u,%u) %02x", attribute_value_length, data_offset, data);
switch(pdl_state){
case GET_PROTOCOL_LIST_LENGTH:
if (!de_state_size(data, &de_header_state)) break;
// printf(" query: PD List payload is %d bytes.\n", de_header_state.de_size);
// printf(" query: PD List offset %u, list size %u\n", de_header_state.de_offset, de_header_state.de_size);
// log_info(" query: PD List payload is %d bytes.", de_header_state.de_size);
// log_info(" query: PD List offset %u, list size %u", de_header_state.de_offset, de_header_state.de_size);
pdl_state = GET_PROTOCOL_LENGTH;
break;
@ -117,7 +117,7 @@ void handleProtocolDescriptorListData(uint32_t attribute_value_length, uint32_t
case GET_PROTOCOL_LENGTH:
// check size
if (!de_state_size(data, &de_header_state)) break;
// printf(" query: PD Record payload is %d bytes.\n", de_header_state.de_size);
// log_info(" query: PD Record payload is %d bytes.", de_header_state.de_size);
// cache protocol info
protocol_offset = de_header_state.de_offset;
@ -132,7 +132,7 @@ void handleProtocolDescriptorListData(uint32_t attribute_value_length, uint32_t
protocol_id = 0;
protocol_id_bytes_to_read = de_header_state.de_size;
// printf(" query: ID data is stored in %d bytes.\n", protocol_id_bytes_to_read);
// log_info(" query: ID data is stored in %d bytes.", protocol_id_bytes_to_read);
pdl_state = GET_PROTOCOL_ID;
break;
@ -144,11 +144,11 @@ void handleProtocolDescriptorListData(uint32_t attribute_value_length, uint32_t
protocol_id_bytes_to_read--;
if (protocol_id_bytes_to_read > 0) break;
// printf(" query: Protocol ID: %04x.\n", protocol_id);
// log_info(" query: Protocol ID: %04x.", protocol_id);
if (protocol_offset >= protocol_size){
pdl_state = GET_PROTOCOL_LENGTH;
// printf(" query: Get next protocol\n");
// log_info(" query: Get next protocol");
break;
}
@ -170,17 +170,17 @@ void handleProtocolDescriptorListData(uint32_t attribute_value_length, uint32_t
protocol_offset++;
protocol_value_bytes_received++;
// printf(" query: protocol_value_bytes_received %u, protocol_value_size %u\n", protocol_value_bytes_received, protocol_value_size);
// log_info(" query: protocol_value_bytes_received %u, protocol_value_size %u", protocol_value_bytes_received, protocol_value_size);
if (protocol_value_bytes_received < protocol_value_size) break;
if (protocol_id == 0x0003){
// printf("\n\n ******* Data ***** %02x\n\n", data);
// log_info("\n\n ******* Data ***** %02x\n\n", data);
sdp_rfcom_channel_nr = data;
}
// printf(" query: protocol done\n");
// printf(" query: Protocol offset %u, protocol size %u\n", protocol_offset, protocol_size);
// log_info(" query: protocol done");
// log_info(" query: Protocol offset %u, protocol size %u", protocol_offset, protocol_size);
if (protocol_offset >= protocol_size) {
pdl_state = GET_PROTOCOL_LENGTH;
@ -188,7 +188,7 @@ void handleProtocolDescriptorListData(uint32_t attribute_value_length, uint32_t
}
pdl_state = GET_PROTOCOL_ID_HEADER_LENGTH;
// printf(" query: Get next protocol\n");
// log_info(" query: Get next protocol");
break;
default:
break;
@ -247,7 +247,7 @@ static void handle_sdp_parser_event(sdp_query_event_t * event){
switch (event->type){
case SDP_QUERY_ATTRIBUTE_VALUE:
ve = (sdp_query_attribute_value_event_t*) event;
// printf("handle_sdp_parser_event [ AID, ALen, DOff, Data] : [%x, %u, %u] BYTE %02x\n",
// log_info("handle_sdp_parser_event [ AID, ALen, DOff, Data] : [%x, %u, %u] BYTE %02x",
// ve->attribute_id, ve->attribute_length, ve->data_offset, ve->data);
switch (ve->attribute_id){

38
src/socket_connection.c
View File

@ -188,7 +188,7 @@ void static socket_connection_emit_nr_connections(void){
event[0] = DAEMON_NR_CONNECTIONS_CHANGED;
event[1] = nr_connections;
(*socket_connection_packet_callback)(NULL, DAEMON_EVENT_PACKET, 0, (uint8_t *) &event, 2);
// log_info("Nr connections changed,.. new %u\n", nr_connections);
// log_info("Nr connections changed,.. new %u", nr_connections);
}
int socket_connection_hci_process(struct data_source *ds) {
@ -238,7 +238,7 @@ int socket_connection_hci_process(struct data_source *ds) {
// "park" if dispatch failed
if (dispatch_err) {
log_info("socket_connection_hci_process dispatch failed -> park connection\n");
log_info("socket_connection_hci_process dispatch failed -> park connection");
run_loop_remove_data_source(ds);
linked_list_add_tail(&parked, (linked_item_t *) ds);
}
@ -252,18 +252,18 @@ int socket_connection_hci_process(struct data_source *ds) {
* pre: connections get parked iff packet was dispatched but could not be sent
*/
void socket_connection_retry_parked(){
// log_info("socket_connection_hci_process retry parked\n");
// log_info("socket_connection_hci_process retry parked");
linked_item_t *it = (linked_item_t *) &parked;
while (it->next) {
connection_t * conn = (connection_t *) it->next;
// dispatch packet !!! connection, type, channel, data, size
log_info("socket_connection_hci_process retry parked %p\n", conn);
log_info("socket_connection_hci_process retry parked %p", conn);
int dispatch_err = (*socket_connection_packet_callback)(conn, READ_BT_16( conn->buffer, 0), READ_BT_16( conn->buffer, 2),
&conn->buffer[sizeof(packet_header_t)], READ_BT_16( conn->buffer, 4));
// "un-park" if successful
if (!dispatch_err) {
log_info("socket_connection_hci_process dispatch succeeded -> un-park connection %p\n", conn);
log_info("socket_connection_hci_process dispatch succeeded -> un-park connection %p", conn);
it->next = it->next->next;
run_loop_add_data_source( (data_source_t *) conn);
} else {
@ -292,7 +292,7 @@ static int socket_connection_accept(struct data_source *socket_ds) {
// no sigpipe
socket_connection_set_no_sigpipe(fd);
log_info("socket_connection_accept new connection %u\n", fd);
log_info("socket_connection_accept new connection %u", fd);
connection_t * connection = socket_connection_register_new_connection(fd);
socket_connection_emit_connection_opened(connection);
@ -316,12 +316,12 @@ int socket_connection_create_tcp(int port){
// create tcp socket
if ((ds->fd = socket (PF_INET, SOCK_STREAM, 0)) < 0) {
log_error("Error creating socket ...(%s)\n", strerror(errno));
log_error("Error creating socket ...(%s)", strerror(errno));
free(ds);
return -1;
}
log_info ("Socket created for port %u\n", port);
log_info ("Socket created for port %u", port);
struct sockaddr_in addr;
addr.sin_family = AF_INET;
@ -332,20 +332,20 @@ int socket_connection_create_tcp(int port){
setsockopt(ds->fd, SOL_SOCKET, SO_REUSEADDR, &y, sizeof(int));
if (bind ( ds->fd, (struct sockaddr *) &addr, sizeof (addr) ) ) {
log_error("Error on bind() ...(%s)\n", strerror(errno));
log_error("Error on bind() ...(%s)", strerror(errno));
free(ds);
return -1;
}
if (listen (ds->fd, MAX_PENDING_CONNECTIONS)) {
log_error("Error on listen() ...(%s)\n", strerror(errno));
log_error("Error on listen() ...(%s)", strerror(errno));
free(ds);
return -1;
}
run_loop_add_data_source(ds);
log_info ("Server up and running ...\n");
log_info ("Server up and running ...");
return 0;
}
@ -361,7 +361,7 @@ void socket_connection_launchd_register_fd_array(launch_data_t listening_fd_arra
launch_data_t tempi = launch_data_array_get_index (listening_fd_array, i);
int listening_fd = launch_data_get_fd(tempi);
launch_data_free (tempi);
log_info("file descriptor = %u\n", listening_fd);
log_info("file descriptor = %u", listening_fd);
// create data_source_t for fd
data_source_t *ds = malloc( sizeof(data_source_t));
@ -425,7 +425,7 @@ int socket_connection_create_launchd(){
*/
listening_fd_array = launch_data_dict_lookup(sockets_dict, "Listeners");
if (listening_fd_array) {
// log_error("Listeners...\n");
// log_error("Listeners...");
socket_connection_launchd_register_fd_array( listening_fd_array );
}
@ -434,7 +434,7 @@ int socket_connection_create_launchd(){
*/
listening_fd_array = launch_data_dict_lookup(sockets_dict, "Listeners2");
if (listening_fd_array) {
// log_error("Listeners2...\n");
// log_error("Listeners2...");
socket_connection_launchd_register_fd_array( listening_fd_array );
}
@ -457,12 +457,12 @@ int socket_connection_create_unix(char *path){
// create unix socket
if ((ds->fd = socket (AF_UNIX, SOCK_STREAM, 0)) < 0) {
log_error( "Error creating socket ...(%s)\n", strerror(errno));
log_error( "Error creating socket ...(%s)", strerror(errno));
free(ds);
return -1;
}
log_info ("Socket created at %s\n", path);
log_info ("Socket created at %s", path);
struct sockaddr_un addr;
memset(&addr, 0, sizeof(addr));
@ -474,7 +474,7 @@ int socket_connection_create_unix(char *path){
setsockopt(ds->fd, SOL_SOCKET, SO_REUSEADDR, &y, sizeof(int));
if (bind ( ds->fd, (struct sockaddr *) &addr, sizeof (addr) ) ) {
log_error( "Error on bind() ...(%s)\n", strerror(errno));
log_error( "Error on bind() ...(%s)", strerror(errno));
free(ds);
return -1;
}
@ -485,14 +485,14 @@ int socket_connection_create_unix(char *path){
//
if (listen (ds->fd, MAX_PENDING_CONNECTIONS)) {
log_error( "Error on listen() ...(%s)\n", strerror(errno));
log_error( "Error on listen() ...(%s)", strerror(errno));
free(ds);
return -1;
}
run_loop_add_data_source(ds);
log_info ("Server up and running ...\n");
log_info ("Server up and running ...");
return 0;
}

6
src/utils.c
View File

@ -106,7 +106,7 @@ char char_for_nibble(int nibble){
return '?';
}
void hexdump(void *data, int size){
void hexdump(const void *data, int size){
char buffer[6*16+1];
int i, j;
@ -133,8 +133,8 @@ void hexdump(void *data, int size){
}
}
void print_key(const char * name, sm_key_t key){
printf("%-6s ", name);
void log_key(const char * name, sm_key_t key){
log_info("%-6s ", name);
hexdump(key, 16);
}