mirror/btstack
1
0
Fork 0
mirror of https://github.com/bluekitchen/btstack.git synced 2025-02-21 03:40:47 +00:00
Code Issues Packages Projects Releases Wiki Activity

replace all log_dbg with log_info

Browse Source
This commit is contained in:
matthias.ringwald 2011-07-22 18:31:02 +00:00
parent 226b4bd38c
commit 7b5fbe1fe3
12 changed files with 198 additions and 198 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

24
src/bt_control_iphone.m
View File

@ -190,9 +190,9 @@ static void ioregistry_get_info() {
IOObjectRelease(bt_service); IOObjectRelease(bt_service);
// dump info // dump info
log_dbg("local-mac-address: "); log_info("local-mac-address: ");
print_bd_addr(local_mac_address); print_bd_addr(local_mac_address);
log_dbg("\ntransport-speed: %u\n", transport_speed); log_info("\ntransport-speed: %u\n", transport_speed);
#else #else
// use dummy addr if not on iphone/ipod touch // use dummy addr if not on iphone/ipod touch
int i = 0; int i = 0;
@ -397,7 +397,7 @@ static char *os4xBlueTool = "/usr/local/bin/BlueToolH4";
static int iphone_on (void *transport_config){ static int iphone_on (void *transport_config){
log_dbg("iphone_on: entered\n"); log_info("iphone_on: entered\n");
int err = 0; int err = 0;
@ -433,7 +433,7 @@ static int iphone_on (void *transport_config){
} }
// unload BTServer // unload BTServer
log_dbg("iphone_on: unload BTServer\n"); log_info("iphone_on: unload BTServer\n");
err = system ("launchctl unload /System/Library/LaunchDaemons/com.apple.BTServer.plist"); err = system ("launchctl unload /System/Library/LaunchDaemons/com.apple.BTServer.plist");
#if 0 #if 0
@ -446,7 +446,7 @@ static int iphone_on (void *transport_config){
// check for os version >= 4.0 // check for os version >= 4.0
int os4x = kCFCoreFoundationVersionNumber >= 550.32; int os4x = kCFCoreFoundationVersionNumber >= 550.32;
log_dbg("CFVersion %f, >= 4.0 %u\n", kCFCoreFoundationVersionNumber, os4x); log_info("CFVersion %f, >= 4.0 %u\n", kCFCoreFoundationVersionNumber, os4x);
// OS 4.0 // OS 4.0
char * bluetool = os3xBlueTool; char * bluetool = os3xBlueTool;
@ -507,7 +507,7 @@ static int iphone_on (void *transport_config){
while (1) { while (1) {
singlechar = fgetc(outputFile); singlechar = fgetc(outputFile);
if (singlechar == EOF) break; if (singlechar == EOF) break;
log_dbg("%c", singlechar); log_info("%c", singlechar);
}; };
err = pclose(outputFile); err = pclose(outputFile);
} }
@ -544,16 +544,16 @@ static int iphone_off (void *config){
} }
*/ */
// power off (all models) // power off (all models)
log_dbg("iphone_off: turn off using BlueTool\n"); log_info("iphone_off: turn off using BlueTool\n");
system ("echo \"power off\nquit\" | BlueTool"); system ("echo \"power off\nquit\" | BlueTool");
// kill Apple BTServer as it gets confused and fails to start anyway // kill Apple BTServer as it gets confused and fails to start anyway
// system("killall BTServer"); // system("killall BTServer");
// reload BTServer // reload BTServer
log_dbg("iphone_off: reload BTServer\n"); log_info("iphone_off: reload BTServer\n");
system ("launchctl load /System/Library/LaunchDaemons/com.apple.BTServer.plist"); system ("launchctl load /System/Library/LaunchDaemons/com.apple.BTServer.plist");
log_dbg("iphone_off: done\n"); log_info("iphone_off: done\n");
return 0; return 0;
} }
@ -574,7 +574,7 @@ static int iphone_wake(void *config){
static void MySleepCallBack( void * refCon, io_service_t service, natural_t messageType, void * messageArgument ) { static void MySleepCallBack( void * refCon, io_service_t service, natural_t messageType, void * messageArgument ) {
char data; char data;
log_dbg( "messageType %08lx, arg %08lx\n", (long unsigned int)messageType, (long unsigned int)messageArgument); log_info( "messageType %08lx, arg %08lx\n", (long unsigned int)messageType, (long unsigned int)messageArgument);
switch ( messageType ) { switch ( messageType ) {
case kIOMessageCanSystemSleep: case kIOMessageCanSystemSleep:
/* Idle sleep is about to kick in. This message will not be sent for forced sleep. /* Idle sleep is about to kick in. This message will not be sent for forced sleep.
@ -635,7 +635,7 @@ static int power_notification_process(struct data_source *ds) {
int bytes_read = read(power_notification_pipe_fds[0], &token, 1); int bytes_read = read(power_notification_pipe_fds[0], &token, 1);
if (bytes_read != 1) return -1; if (bytes_read != 1) return -1;
log_dbg("power_notification_process: %u\n", token); log_info("power_notification_process: %u\n", token);
power_notification_callback( (POWER_NOTIFICATION_t) token ); power_notification_callback( (POWER_NOTIFICATION_t) token );
@ -652,7 +652,7 @@ void iphone_register_for_power_notifications(void (*cb)(POWER_NOTIFICATION_t eve
io_object_t notifierObject = 0; // notifier object, used to deregister later io_object_t notifierObject = 0; // notifier object, used to deregister later
root_port = IORegisterForSystemPower(NULL, &notifyPortRef, MySleepCallBack, &notifierObject); root_port = IORegisterForSystemPower(NULL, &notifyPortRef, MySleepCallBack, &notifierObject);
if (!root_port) { if (!root_port) {
log_dbg("IORegisterForSystemPower failed\n"); log_info("IORegisterForSystemPower failed\n");
return; return;
} }

30
src/daemon.c
View File

@ -118,12 +118,12 @@ static remote_device_db_t * remote_device_db = NULL;
static int rfcomm_channel_generator = 1; static int rfcomm_channel_generator = 1;
static void dummy_bluetooth_status_handler(BLUETOOTH_STATE state){ static void dummy_bluetooth_status_handler(BLUETOOTH_STATE state){
log_dbg("Bluetooth status: %u\n", state); log_info("Bluetooth status: %u\n", state);
}; };
static void daemon_no_connections_timeout(struct timer *ts){ static void daemon_no_connections_timeout(struct timer *ts){
if (clients_require_power_on()) return; // false alarm :) if (clients_require_power_on()) return; // false alarm :)
log_dbg("No active client connection for %u seconds -> POWER OFF\n", DAEMON_NO_ACTIVE_CLIENT_TIMEOUT/1000); log_info("No active client connection for %u seconds -> POWER OFF\n", DAEMON_NO_ACTIVE_CLIENT_TIMEOUT/1000);
hci_power_control(HCI_POWER_OFF); hci_power_control(HCI_POWER_OFF);
} }
@ -186,7 +186,7 @@ static int btstack_command_handler(connection_t *connection, uint8_t *packet, ui
hci_discoverable_control(clients_require_discoverable()); hci_discoverable_control(clients_require_discoverable());
break; break;
case BTSTACK_SET_BLUETOOTH_ENABLED: case BTSTACK_SET_BLUETOOTH_ENABLED:
log_dbg("BTSTACK_SET_BLUETOOTH_ENABLED: %u\n", packet[3]); log_info("BTSTACK_SET_BLUETOOTH_ENABLED: %u\n", packet[3]);
if (packet[3]) { if (packet[3]) {
// global enable // global enable
@ -281,7 +281,7 @@ static int btstack_command_handler(connection_t *connection, uint8_t *packet, ui
} }
case SDP_REGISTER_SERVICE_RECORD: case SDP_REGISTER_SERVICE_RECORD:
log_dbg("SDP_REGISTER_SERVICE_RECORD size %u\n", size); log_info("SDP_REGISTER_SERVICE_RECORD size %u\n", size);
sdp_register_service_internal(connection, &packet[3]); sdp_register_service_internal(connection, &packet[3]);
break; break;
case SDP_UNREGISTER_SERVICE_RECORD: case SDP_UNREGISTER_SERVICE_RECORD:
@ -354,7 +354,7 @@ static int daemon_client_handler(connection_t *connection, uint16_t packet_type,
} }
break; break;
case DAEMON_NR_CONNECTIONS_CHANGED: case DAEMON_NR_CONNECTIONS_CHANGED:
log_dbg("Nr Connections changed, new %u\n",data[1]); log_info("Nr Connections changed, new %u\n",data[1]);
break; break;
default: default:
break; break;
@ -362,7 +362,7 @@ static int daemon_client_handler(connection_t *connection, uint16_t packet_type,
break; break;
} }
if (err) { if (err) {
log_dbg("Daemon Handler: err %d\n", err); log_info("Daemon Handler: err %d\n", err);
} }
return err; return err;
} }
@ -390,12 +390,12 @@ static void deamon_status_event_handler(uint8_t *packet, uint16_t size){
switch (packet[0]) { switch (packet[0]) {
case BTSTACK_EVENT_STATE: case BTSTACK_EVENT_STATE:
hci_state = packet[2]; hci_state = packet[2];
log_dbg("New state: %u\n", hci_state); log_info("New state: %u\n", hci_state);
update_status = 1; update_status = 1;
break; break;
case BTSTACK_EVENT_NR_CONNECTIONS_CHANGED: case BTSTACK_EVENT_NR_CONNECTIONS_CHANGED:
num_connections = packet[2]; num_connections = packet[2];
log_dbg("New nr connections: %u\n", num_connections); log_info("New nr connections: %u\n", num_connections);
update_status = 1; update_status = 1;
break; break;
default: default:
@ -477,12 +477,12 @@ static void daemon_sigint_handler(int param){
notify_post("ch.ringwald.btstack.stopped"); notify_post("ch.ringwald.btstack.stopped");
#endif #endif
log_dbg(" <= SIGINT received, shutting down..\n"); log_info(" <= SIGINT received, shutting down..\n");
hci_power_control( HCI_POWER_OFF); hci_power_control( HCI_POWER_OFF);
hci_close(); hci_close();
log_dbg("Good bye, see you.\n"); log_info("Good bye, see you.\n");
exit(0); exit(0);
} }
@ -561,10 +561,10 @@ static int clients_require_discoverable(void){
} }
static void usage(const char * name) { static void usage(const char * name) {
log_dbg("%s, BTstack background daemon\n", name); log_info("%s, BTstack background daemon\n", name);
log_dbg("usage: %s [-h|--help] [--tcp]\n", name); log_info("usage: %s [-h|--help] [--tcp]\n", name);
log_dbg(" -h|--help display this usage\n"); log_info(" -h|--help display this usage\n");
log_dbg(" --tcp use TCP server socket instead of local unix socket\n"); log_info(" --tcp use TCP server socket instead of local unix socket\n");
} }
#ifdef USE_BLUETOOL #ifdef USE_BLUETOOL
@ -673,7 +673,7 @@ int main (int argc, char * const * argv){
timeout.process = daemon_no_connections_timeout; timeout.process = daemon_no_connections_timeout;
#ifdef HAVE_RFCOMM #ifdef HAVE_RFCOMM
log_dbg("config.h: HAVE_RFCOMM\n"); log_info("config.h: HAVE_RFCOMM\n");
rfcomm_init(); rfcomm_init();
rfcomm_register_packet_handler(daemon_packet_handler); rfcomm_register_packet_handler(daemon_packet_handler);
#endif #endif

4
src/debug.h
View File

@ -39,7 +39,7 @@
#ifdef EMBEDDED #ifdef EMBEDDED
#define log_dbg(...) #define log_info(...)
#define log_err(...) #define log_err(...)
#define log_info(...) #define log_info(...)
@ -47,7 +47,7 @@
#include <stdio.h> #include <stdio.h>
#define log_dbg(format, ...) printf(format, ## __VA_ARGS__) #define log_info(format, ...) printf(format, ## __VA_ARGS__)
#define log_info(format, ...) printf(format, ## __VA_ARGS__) #define log_info(format, ...) printf(format, ## __VA_ARGS__)
#define log_err(format, ...) printf(format, ## __VA_ARGS__) #define log_err(format, ...) printf(format, ## __VA_ARGS__)

64
src/hci.c
View File

@ -240,7 +240,7 @@ int hci_send_acl_packet(uint8_t *packet, int size){
// count packet // count packet
connection->num_acl_packets_sent++; connection->num_acl_packets_sent++;
// log_dbg("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\n", connection->con_handle, connection->num_acl_packets_sent);
// send packet - ignore errors // send packet - ignore errors
hci_stack.hci_transport->send_packet(HCI_ACL_DATA_PACKET, packet, size); hci_stack.hci_transport->send_packet(HCI_ACL_DATA_PACKET, packet, size);
@ -332,9 +332,9 @@ static void acl_handler(uint8_t *packet, int size){
} }
static void hci_shutdown_connection(hci_connection_t *conn){ static void hci_shutdown_connection(hci_connection_t *conn){
log_dbg("Connection closed: handle %u, ", conn->con_handle); log_info("Connection closed: handle %u, ", conn->con_handle);
print_bd_addr( conn->address ); print_bd_addr( conn->address );
log_dbg("\n"); log_info("\n");
// cancel all l2cap connections // cancel all l2cap connections
hci_emit_disconnection_complete(conn->con_handle, 0x16); // terminated by local host hci_emit_disconnection_complete(conn->con_handle, 0x16); // terminated by local host
@ -362,7 +362,7 @@ static void event_handler(uint8_t *packet, int size){
case HCI_EVENT_COMMAND_COMPLETE: case HCI_EVENT_COMMAND_COMPLETE:
// get num cmd packets // get num cmd packets
// log_dbg("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\n", hci_stack.num_cmd_packets, packet[2]);
hci_stack.num_cmd_packets = packet[2]; hci_stack.num_cmd_packets = packet[2];
if (COMMAND_COMPLETE_EVENT(packet, hci_read_buffer_size)){ if (COMMAND_COMPLETE_EVENT(packet, hci_read_buffer_size)){
@ -374,7 +374,7 @@ static void event_handler(uint8_t *packet, int size){
hci_stack.total_num_acl_packets = packet[9]; hci_stack.total_num_acl_packets = packet[9];
// ignore: total num SCO packets // ignore: total num SCO packets
if (hci_stack.state == HCI_STATE_INITIALIZING){ if (hci_stack.state == HCI_STATE_INITIALIZING){
log_dbg("hci_read_buffer_size: size %u, count %u\n", hci_stack.acl_data_packet_length, hci_stack.total_num_acl_packets); log_info("hci_read_buffer_size: size %u, count %u\n", hci_stack.acl_data_packet_length, hci_stack.total_num_acl_packets);
} }
} }
if (COMMAND_COMPLETE_EVENT(packet, hci_write_scan_enable)){ if (COMMAND_COMPLETE_EVENT(packet, hci_write_scan_enable)){
@ -384,7 +384,7 @@ static void event_handler(uint8_t *packet, int size){
case HCI_EVENT_COMMAND_STATUS: case HCI_EVENT_COMMAND_STATUS:
// get num cmd packets // get num cmd packets
// log_dbg("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\n", hci_stack.num_cmd_packets, packet[3]);
hci_stack.num_cmd_packets = packet[3]; hci_stack.num_cmd_packets = packet[3];
break; break;
@ -398,7 +398,7 @@ static void event_handler(uint8_t *packet, int size){
continue; continue;
} }
conn->num_acl_packets_sent -= num_packets; conn->num_acl_packets_sent -= num_packets;
// log_dbg("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\n", num_packets, handle, conn->num_acl_packets_sent);
} }
break; break;
@ -406,7 +406,7 @@ static void event_handler(uint8_t *packet, int size){
bt_flip_addr(addr, &packet[2]); bt_flip_addr(addr, &packet[2]);
// TODO: eval COD 8-10 // TODO: eval COD 8-10
link_type = packet[11]; link_type = packet[11];
log_dbg("Connection_incoming: "); print_bd_addr(addr); log_dbg(", type %u\n", link_type); log_info("Connection_incoming: "); print_bd_addr(addr); log_info(", type %u\n", link_type);
if (link_type == 1) { // ACL if (link_type == 1) { // ACL
conn = connection_for_address(addr); conn = connection_for_address(addr);
if (!conn) { if (!conn) {
@ -423,7 +423,7 @@ static void event_handler(uint8_t *packet, int size){
case HCI_EVENT_CONNECTION_COMPLETE: case HCI_EVENT_CONNECTION_COMPLETE:
// Connection management // Connection management
bt_flip_addr(addr, &packet[5]); bt_flip_addr(addr, &packet[5]);
log_dbg("Connection_complete (status=%u)", packet[2]); print_bd_addr(addr); log_dbg("\n"); log_info("Connection_complete (status=%u)", packet[2]); print_bd_addr(addr); log_info("\n");
conn = connection_for_address(addr); conn = connection_for_address(addr);
if (conn) { if (conn) {
if (!packet[2]){ if (!packet[2]){
@ -435,9 +435,9 @@ static void event_handler(uint8_t *packet, int size){
run_loop_set_timer(&conn->timeout, HCI_CONNECTION_TIMEOUT_MS); run_loop_set_timer(&conn->timeout, HCI_CONNECTION_TIMEOUT_MS);
run_loop_add_timer(&conn->timeout); run_loop_add_timer(&conn->timeout);
#endif #endif
log_dbg("New connection: handle %u, ", conn->con_handle); log_info("New connection: handle %u, ", conn->con_handle);
print_bd_addr( conn->address ); print_bd_addr( conn->address );
log_dbg("\n"); log_info("\n");
hci_emit_nr_connections_changed(); hci_emit_nr_connections_changed();
} else { } else {
@ -454,7 +454,7 @@ static void event_handler(uint8_t *packet, int size){
break; break;
case HCI_EVENT_LINK_KEY_REQUEST: case HCI_EVENT_LINK_KEY_REQUEST:
log_dbg("HCI_EVENT_LINK_KEY_REQUEST\n"); log_info("HCI_EVENT_LINK_KEY_REQUEST\n");
hci_add_connection_flags_for_flipped_bd_addr(&packet[2], RECV_LINK_KEY_REQUEST); hci_add_connection_flags_for_flipped_bd_addr(&packet[2], RECV_LINK_KEY_REQUEST);
if (!hci_stack.remote_device_db) break; if (!hci_stack.remote_device_db) break;
hci_add_connection_flags_for_flipped_bd_addr(&packet[2], HANDLE_LINK_KEY_REQUEST); hci_add_connection_flags_for_flipped_bd_addr(&packet[2], HANDLE_LINK_KEY_REQUEST);
@ -645,26 +645,26 @@ static int hci_power_control_on(void){
static void hci_power_control_off(void){ static void hci_power_control_off(void){
log_dbg("hci_power_control_off\n"); log_info("hci_power_control_off\n");
// close low-level device // close low-level device
hci_stack.hci_transport->close(hci_stack.config); hci_stack.hci_transport->close(hci_stack.config);
log_dbg("hci_power_control_off - hci_transport closed\n"); log_info("hci_power_control_off - hci_transport closed\n");
// power off // power off
if (hci_stack.control && hci_stack.control->off){ if (hci_stack.control && hci_stack.control->off){
(*hci_stack.control->off)(hci_stack.config); (*hci_stack.control->off)(hci_stack.config);
} }
log_dbg("hci_power_control_off - control closed\n"); log_info("hci_power_control_off - control closed\n");
hci_stack.state = HCI_STATE_OFF; hci_stack.state = HCI_STATE_OFF;
} }
static void hci_power_control_sleep(void){ static void hci_power_control_sleep(void){
log_dbg("hci_power_control_sleep\n"); log_info("hci_power_control_sleep\n");
#if 0 #if 0
// don't close serial port during sleep // don't close serial port during sleep
@ -683,7 +683,7 @@ static void hci_power_control_sleep(void){
static int hci_power_control_wake(void){ static int hci_power_control_wake(void){
log_dbg("hci_power_control_wake\n"); log_info("hci_power_control_wake\n");
// wake on // wake on
if (hci_stack.control && hci_stack.control->wake){ if (hci_stack.control && hci_stack.control->wake){
@ -709,7 +709,7 @@ static int hci_power_control_wake(void){
int hci_power_control(HCI_POWER_MODE power_mode){ int hci_power_control(HCI_POWER_MODE power_mode){
log_dbg("hci_power_control: %u, current mode %u\n", power_mode, hci_stack.state); log_info("hci_power_control: %u, current mode %u\n", power_mode, hci_stack.state);
int err = 0; int err = 0;
switch (hci_stack.state){ switch (hci_stack.state){
@ -854,12 +854,12 @@ void hci_run(){
connection = (hci_connection_t *) it; connection = (hci_connection_t *) it;
if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) { if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) {
// log_dbg("hci_run: cannot send command packet\n"); // log_info("hci_run: cannot send command packet\n");
return; return;
} }
if (connection->state == RECEIVED_CONNECTION_REQUEST){ if (connection->state == RECEIVED_CONNECTION_REQUEST){
log_dbg("sending hci_accept_connection_request\n"); log_info("sending hci_accept_connection_request\n");
hci_send_cmd(&hci_accept_connection_request, connection->address, 1); hci_send_cmd(&hci_accept_connection_request, connection->address, 1);
connection->state = ACCEPTED_CONNECTION_REQUEST; connection->state = ACCEPTED_CONNECTION_REQUEST;
} }
@ -868,7 +868,7 @@ void hci_run(){
if (connection->authentication_flags & HANDLE_LINK_KEY_REQUEST){ if (connection->authentication_flags & HANDLE_LINK_KEY_REQUEST){
link_key_t link_key; link_key_t link_key;
log_dbg("responding to link key request\n"); log_info("responding to link key request\n");
if ( hci_stack.remote_device_db->get_link_key( &connection->address, &link_key)){ if ( hci_stack.remote_device_db->get_link_key( &connection->address, &link_key)){
hci_send_cmd(&hci_link_key_request_reply, connection->address, &link_key); hci_send_cmd(&hci_link_key_request_reply, connection->address, &link_key);
} else { } else {
@ -882,7 +882,7 @@ void hci_run(){
switch (hci_stack.state){ switch (hci_stack.state){
case HCI_STATE_INITIALIZING: case HCI_STATE_INITIALIZING:
// log_dbg("hci_init: substate %u\n", hci_stack.substate); // log_info("hci_init: substate %u\n", hci_stack.substate);
if (hci_stack.substate % 2) { if (hci_stack.substate % 2) {
// odd: waiting for command completion // odd: waiting for command completion
return; return;
@ -958,7 +958,7 @@ void hci_run(){
case HCI_STATE_HALTING: case HCI_STATE_HALTING:
log_dbg("HCI_STATE_HALTING\n"); log_info("HCI_STATE_HALTING\n");
// close all open connections // close all open connections
connection = (hci_connection_t *) hci_stack.connections; connection = (hci_connection_t *) hci_stack.connections;
if (connection){ if (connection){
@ -966,27 +966,27 @@ void hci_run(){
// send disconnect // send disconnect
if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) return; if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) return;
log_dbg("HCI_STATE_HALTING, connection %lu, handle %u\n", (uintptr_t) connection, (uint16_t)connection->con_handle); log_info("HCI_STATE_HALTING, connection %lu, handle %u\n", (uintptr_t) connection, (uint16_t)connection->con_handle);
hci_send_cmd(&hci_disconnect, connection->con_handle, 0x13); // remote closed connection 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. // send disconnected event right away - causes higher layer connections to get closed, too.
hci_shutdown_connection(connection); hci_shutdown_connection(connection);
return; return;
} }
log_dbg("HCI_STATE_HALTING, calling off\n"); log_info("HCI_STATE_HALTING, calling off\n");
// switch mode // switch mode
hci_power_control_off(); hci_power_control_off();
log_dbg("HCI_STATE_HALTING, emitting state\n"); log_info("HCI_STATE_HALTING, emitting state\n");
hci_emit_state(); hci_emit_state();
log_dbg("HCI_STATE_HALTING, done\n"); log_info("HCI_STATE_HALTING, done\n");
break; break;
case HCI_STATE_FALLING_ASLEEP: case HCI_STATE_FALLING_ASLEEP:
switch(hci_stack.substate) { switch(hci_stack.substate) {
case 0: case 0:
log_dbg("HCI_STATE_FALLING_ASLEEP\n"); log_info("HCI_STATE_FALLING_ASLEEP\n");
// close all open connections // close all open connections
connection = (hci_connection_t *) hci_stack.connections; connection = (hci_connection_t *) hci_stack.connections;
if (connection){ if (connection){
@ -994,7 +994,7 @@ void hci_run(){
// send disconnect // send disconnect
if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) return; if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) return;
log_dbg("HCI_STATE_FALLING_ASLEEP, connection %lu, handle %u\n", (uintptr_t) connection, (uint16_t)connection->con_handle); log_info("HCI_STATE_FALLING_ASLEEP, connection %lu, handle %u\n", (uintptr_t) connection, (uint16_t)connection->con_handle);
hci_send_cmd(&hci_disconnect, connection->con_handle, 0x13); // remote closed connection 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. // send disconnected event right away - causes higher layer connections to get closed, too.
@ -1005,7 +1005,7 @@ void hci_run(){
// disable page and inquiry scan // disable page and inquiry scan
if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) return; if (!hci_can_send_packet_now(HCI_COMMAND_DATA_PACKET)) return;
log_dbg("HCI_STATE_HALTING, disabling inq & page scans\n"); log_info("HCI_STATE_HALTING, disabling inq & page scans\n");
hci_send_cmd(&hci_write_scan_enable, 0); // none hci_send_cmd(&hci_write_scan_enable, 0); // none
// continue in next sub state // continue in next sub state
@ -1015,7 +1015,7 @@ void hci_run(){
// wait for command complete "hci_write_scan_enable" in event_handler(); // wait for command complete "hci_write_scan_enable" in event_handler();
break; break;
case 2: case 2:
log_dbg("HCI_STATE_HALTING, calling sleep\n"); log_info("HCI_STATE_HALTING, calling sleep\n");
// switch mode // switch mode
hci_power_control_sleep(); // changes hci_stack.state to SLEEP hci_power_control_sleep(); // changes hci_stack.state to SLEEP
hci_emit_state(); hci_emit_state();
@ -1037,7 +1037,7 @@ int hci_send_cmd_packet(uint8_t *packet, int size){
// create_connection? // create_connection?
if (IS_COMMAND(packet, hci_create_connection)){ if (IS_COMMAND(packet, hci_create_connection)){
bt_flip_addr(addr, &packet[3]); bt_flip_addr(addr, &packet[3]);
log_dbg("Create_connection to "); print_bd_addr(addr); log_dbg("\n"); log_info("Create_connection to "); print_bd_addr(addr); log_info("\n");
conn = connection_for_address(addr); conn = connection_for_address(addr);
if (conn) { if (conn) {
// if connection exists // if connection exists

42
src/hci_transport_usb.c
View File

@ -111,28 +111,28 @@ void scan_for_bt_endpoints() {
// get endpoints from interface descriptor // get endpoints from interface descriptor
struct libusb_config_descriptor *config_descriptor; struct libusb_config_descriptor *config_descriptor;
r = libusb_get_active_config_descriptor(dev, &config_descriptor); r = libusb_get_active_config_descriptor(dev, &config_descriptor);
log_dbg("configuration: %u interfaces\n", config_descriptor->bNumInterfaces); log_info("configuration: %u interfaces\n", config_descriptor->bNumInterfaces);
const struct libusb_interface *interface = config_descriptor->interface; const struct libusb_interface *interface = config_descriptor->interface;
const struct libusb_interface_descriptor * interface0descriptor = interface->altsetting; const struct libusb_interface_descriptor * interface0descriptor = interface->altsetting;
log_dbg("interface 0: %u endpoints\n", interface0descriptor->bNumEndpoints); log_info("interface 0: %u endpoints\n", interface0descriptor->bNumEndpoints);
const struct libusb_endpoint_descriptor *endpoint = interface0descriptor->endpoint; const struct libusb_endpoint_descriptor *endpoint = interface0descriptor->endpoint;
for (r=0;r<interface0descriptor->bNumEndpoints;r++,endpoint++){ for (r=0;r<interface0descriptor->bNumEndpoints;r++,endpoint++){
log_dbg("endpoint %x, attributes %x\n", endpoint->bEndpointAddress, endpoint->bmAttributes); log_info("endpoint %x, attributes %x\n", endpoint->bEndpointAddress, endpoint->bmAttributes);
if ((endpoint->bmAttributes & 0x3) == LIBUSB_TRANSFER_TYPE_INTERRUPT){ if ((endpoint->bmAttributes & 0x3) == LIBUSB_TRANSFER_TYPE_INTERRUPT){
event_in_addr = endpoint->bEndpointAddress; event_in_addr = endpoint->bEndpointAddress;
log_dbg("Using 0x%2.2X for HCI Events\n", event_in_addr); log_info("Using 0x%2.2X for HCI Events\n", event_in_addr);
} }
if ((endpoint->bmAttributes & 0x3) == LIBUSB_TRANSFER_TYPE_BULK){ if ((endpoint->bmAttributes & 0x3) == LIBUSB_TRANSFER_TYPE_BULK){
if (endpoint->bEndpointAddress & 0x80) { if (endpoint->bEndpointAddress & 0x80) {
acl_in_addr = endpoint->bEndpointAddress; acl_in_addr = endpoint->bEndpointAddress;
log_dbg("Using 0x%2.2X for ACL Data In\n", acl_in_addr); log_info("Using 0x%2.2X for ACL Data In\n", acl_in_addr);
} else { } else {
acl_out_addr = endpoint->bEndpointAddress; acl_out_addr = endpoint->bEndpointAddress;
log_dbg("Using 0x%2.2X for ACL Data Out\n", acl_out_addr); log_info("Using 0x%2.2X for ACL Data Out\n", acl_out_addr);
} }
} }
} }
@ -147,7 +147,7 @@ static libusb_device * scan_for_bt_device(libusb_device **devs) {
return 0; return 0;
} }
log_dbg("%04x:%04x (bus %d, device %d) - class %x subclass %x protocol %x \n", log_info("%04x:%04x (bus %d, device %d) - class %x subclass %x protocol %x \n",
desc.idVendor, desc.idProduct, desc.idVendor, desc.idProduct,
libusb_get_bus_number(dev), libusb_get_device_address(dev), libusb_get_bus_number(dev), libusb_get_device_address(dev),
desc.bDeviceClass, desc.bDeviceSubClass, desc.bDeviceProtocol); desc.bDeviceClass, desc.bDeviceSubClass, desc.bDeviceProtocol);
@ -159,7 +159,7 @@ static libusb_device * scan_for_bt_device(libusb_device **devs) {
// if (desc.bDeviceClass == 0xe0 && desc.bDeviceSubClass == 0x01 && desc.bDeviceProtocol == 0x01){ // if (desc.bDeviceClass == 0xe0 && desc.bDeviceSubClass == 0x01 && desc.bDeviceProtocol == 0x01){
if (desc.bDeviceClass == 0xE0 && desc.bDeviceSubClass == 0x01 if (desc.bDeviceClass == 0xE0 && desc.bDeviceSubClass == 0x01
&& desc.bDeviceProtocol == 0x01) { && desc.bDeviceProtocol == 0x01) {
log_dbg("BT Dongle found.\n"); log_info("BT Dongle found.\n");
return dev; return dev;
} }
} }
@ -170,7 +170,7 @@ static libusb_device * scan_for_bt_device(libusb_device **devs) {
static void async_callback(struct libusb_transfer *transfer) static void async_callback(struct libusb_transfer *transfer)
{ {
int r; int r;
//log_dbg("in async_callback %d\n", transfer->endpoint); //log_info("in async_callback %d\n", transfer->endpoint);
if (transfer->status == LIBUSB_TRANSFER_COMPLETED || if (transfer->status == LIBUSB_TRANSFER_COMPLETED ||
(transfer->status == LIBUSB_TRANSFER_TIMED_OUT && transfer->actual_length > 0)) { (transfer->status == LIBUSB_TRANSFER_TIMED_OUT && transfer->actual_length > 0)) {
@ -201,7 +201,7 @@ static int usb_process_ds(struct data_source *ds) {
struct timeval tv; struct timeval tv;
int r; int r;
//log_dbg("in usb_process_ds\n"); //log_info("in usb_process_ds\n");
if (libusb_state != LIB_USB_TRANSFERS_ALLOCATED) return -1; if (libusb_state != LIB_USB_TRANSFERS_ALLOCATED) return -1;
@ -212,7 +212,7 @@ static int usb_process_ds(struct data_source *ds) {
// Handle any packet in the order that they were received // Handle any packet in the order that they were received
while (handle_packet) { while (handle_packet) {
void * next = handle_packet->user_data; void * next = handle_packet->user_data;
//log_dbg("handle packet %x, endpoint", handle_packet, handle_packet->endpoint); //log_info("handle packet %x, endpoint", handle_packet, handle_packet->endpoint);
if (handle_packet->endpoint == event_in_addr) { if (handle_packet->endpoint == event_in_addr) {
hci_dump_packet( HCI_EVENT_PACKET, 1, handle_packet-> buffer, hci_dump_packet( HCI_EVENT_PACKET, 1, handle_packet-> buffer,
@ -253,7 +253,7 @@ void usb_process_ts(timer_source_t *timer) {
struct timeval tv, now; struct timeval tv, now;
long msec; long msec;
//log_dbg("in usb_process_ts\n"); //log_info("in usb_process_ts\n");
// Deactivate timer // Deactivate timer
run_loop_remove_timer(&usb_timer); run_loop_remove_timer(&usb_timer);
@ -312,7 +312,7 @@ static int usb_open(void *transport_config){
} }
#else #else
// Scan system for an appropriate device // Scan system for an appropriate device
log_dbg("Scanning for a device"); log_info("Scanning for a device");
cnt = libusb_get_device_list(NULL, &devs); cnt = libusb_get_device_list(NULL, &devs);
if (cnt < 0) { if (cnt < 0) {
usb_close(); usb_close();
@ -337,7 +337,7 @@ static int usb_open(void *transport_config){
} }
#endif #endif
log_dbg("libusb open %d, handle %xu\n", r, (int) handle); log_info("libusb open %d, handle %xu\n", r, (int) handle);
libusb_state = LIB_USB_OPENED; libusb_state = LIB_USB_OPENED;
// Detach OS driver (not possible for OS X) // Detach OS driver (not possible for OS X)
@ -357,12 +357,12 @@ static int usb_open(void *transport_config){
return r; return r;
} }
} }
log_dbg("libusb_detach_kernel_driver\n"); log_info("libusb_detach_kernel_driver\n");
#endif #endif
libusb_state = LIB_USB_KERNEL_DETACHED; libusb_state = LIB_USB_KERNEL_DETACHED;
// reserve access to device // reserve access to device
log_dbg("claiming interface 0...\n"); log_info("claiming interface 0...\n");
r = libusb_claim_interface(handle, 0); r = libusb_claim_interface(handle, 0);
if (r < 0) { if (r < 0) {
log_err(stderr, "Error claiming interface %d\n", r); log_err(stderr, "Error claiming interface %d\n", r);
@ -371,7 +371,7 @@ static int usb_open(void *transport_config){
} }
libusb_state = LIB_USB_INTERFACE_CLAIMED; libusb_state = LIB_USB_INTERFACE_CLAIMED;
log_dbg("claimed interface 0\n"); log_info("claimed interface 0\n");
#if !USB_VENDOR_ID || !USB_PRODUCT_ID #if !USB_VENDOR_ID || !USB_PRODUCT_ID
scan_for_bt_endpoints(); scan_for_bt_endpoints();
@ -418,7 +418,7 @@ static int usb_open(void *transport_config){
doing_pollfds = libusb_pollfds_handle_timeouts(NULL); doing_pollfds = libusb_pollfds_handle_timeouts(NULL);
if (doing_pollfds) { if (doing_pollfds) {
log_dbg("Async using pollfds:\n"); log_info("Async using pollfds:\n");
const struct libusb_pollfd ** pollfd = libusb_get_pollfds(NULL); const struct libusb_pollfd ** pollfd = libusb_get_pollfds(NULL);
for (r = 0 ; pollfd[r] ; r++) { for (r = 0 ; pollfd[r] ; r++) {
@ -426,10 +426,10 @@ static int usb_open(void *transport_config){
ds->fd = pollfd[r]->fd; ds->fd = pollfd[r]->fd;
ds->process = usb_process_ds; ds->process = usb_process_ds;
run_loop_add_data_source(ds); run_loop_add_data_source(ds);
log_dbg("%u: %x fd: %u, events %x\n", r, (unsigned int) pollfd[r], pollfd[r]->fd, pollfd[r]->events); log_info("%u: %x fd: %u, events %x\n", r, (unsigned int) pollfd[r], pollfd[r]->fd, pollfd[r]->events);
} }
} else { } else {
log_dbg("Async using timers:\n"); log_info("Async using timers:\n");
usb_timer.process = usb_process_ts; usb_timer.process = usb_process_ts;
run_loop_set_timer(&usb_timer, 100); run_loop_set_timer(&usb_timer, 100);
@ -532,7 +532,7 @@ static int usb_send_packet(uint8_t packet_type, uint8_t * packet, int size){
} }
static void usb_register_packet_handler(void (*handler)(uint8_t packet_type, uint8_t *packet, uint16_t size)){ static void usb_register_packet_handler(void (*handler)(uint8_t packet_type, uint8_t *packet, uint16_t size)){
log_dbg("registering packet handler\n"); log_info("registering packet handler\n");
packet_handler = handler; packet_handler = handler;
} }

26
src/l2cap.c
View File

@ -248,7 +248,7 @@ void l2cap_emit_connection_request(l2cap_channel_t *channel) {
void l2cap_emit_credits(l2cap_channel_t *channel, uint8_t credits) { void l2cap_emit_credits(l2cap_channel_t *channel, uint8_t credits) {
// track credits // track credits
channel->packets_granted += credits; channel->packets_granted += credits;
// log_dbg("l2cap_emit_credits for cid %u, credits given: %u (+%u)\n", channel->local_cid, channel->packets_granted, credits); // log_info("l2cap_emit_credits for cid %u, credits given: %u (+%u)\n", channel->local_cid, channel->packets_granted, credits);
uint8_t event[5]; uint8_t event[5];
event[0] = L2CAP_EVENT_CREDITS; event[0] = L2CAP_EVENT_CREDITS;
@ -305,12 +305,12 @@ uint16_t l2cap_get_remote_mtu_for_local_cid(uint16_t local_cid){
} }
int l2cap_send_signaling_packet(hci_con_handle_t handle, L2CAP_SIGNALING_COMMANDS cmd, uint8_t identifier, ...){ int l2cap_send_signaling_packet(hci_con_handle_t handle, L2CAP_SIGNALING_COMMANDS cmd, uint8_t identifier, ...){
// log_dbg("l2cap_send_signaling_packet type %u\n", cmd); // log_info("l2cap_send_signaling_packet type %u\n", cmd);
va_list argptr; va_list argptr;
va_start(argptr, identifier); va_start(argptr, identifier);
uint16_t len = l2cap_create_signaling_internal(sig_buffer, handle, cmd, identifier, argptr); uint16_t len = l2cap_create_signaling_internal(sig_buffer, handle, cmd, identifier, argptr);
va_end(argptr); va_end(argptr);
// log_dbg("l2cap_send_signaling_packet con %u!\n", handle); // log_info("l2cap_send_signaling_packet con %u!\n", handle);
return hci_send_acl_packet(sig_buffer, len); return hci_send_acl_packet(sig_buffer, len);
} }
@ -318,7 +318,7 @@ int l2cap_send_internal(uint16_t local_cid, uint8_t *data, uint16_t len){
// check for free places on BT module // check for free places on BT module
if (!hci_number_free_acl_slots()) { if (!hci_number_free_acl_slots()) {
log_dbg("l2cap_send_internal cid %u, BT module full <-----\n", local_cid); log_info("l2cap_send_internal cid %u, BT module full <-----\n", local_cid);
return BTSTACK_ACL_BUFFERS_FULL; return BTSTACK_ACL_BUFFERS_FULL;
} }
int err = 0; int err = 0;
@ -328,7 +328,7 @@ int l2cap_send_internal(uint16_t local_cid, uint8_t *data, uint16_t len){
if (channel) { if (channel) {
if (channel->packets_granted > 0){ if (channel->packets_granted > 0){
--channel->packets_granted; --channel->packets_granted;
// log_dbg("l2cap_send_internal cid %u, handle %u, 1 credit used, credits left %u;\n", // log_info("l2cap_send_internal cid %u, handle %u, 1 credit used, credits left %u;\n",
// local_cid, channel->handle, channel->packets_granted); // local_cid, channel->handle, channel->packets_granted);
} else { } else {
log_err("l2cap_send_internal cid %u, no credits!\n", local_cid); log_err("l2cap_send_internal cid %u, no credits!\n", local_cid);
@ -403,7 +403,7 @@ void l2cap_run(void){
l2cap_channel_t * channel = (l2cap_channel_t *) it; l2cap_channel_t * channel = (l2cap_channel_t *) it;
// log_dbg("l2cap_run: state %u, var 0x%02x\n", channel->state, channel->state_var); // log_info("l2cap_run: state %u, var 0x%02x\n", channel->state, channel->state_var);
switch (channel->state){ switch (channel->state){
@ -658,11 +658,11 @@ static void l2cap_handle_disconnect_request(l2cap_channel_t *channel, uint16_t i
static void l2cap_handle_connection_request(hci_con_handle_t handle, uint8_t sig_id, uint16_t psm, uint16_t source_cid){ static void l2cap_handle_connection_request(hci_con_handle_t handle, uint8_t sig_id, uint16_t psm, uint16_t source_cid){
// log_dbg("l2cap_handle_connection_request for handle %u, psm %u cid %u\n", handle, psm, source_cid); // log_info("l2cap_handle_connection_request for handle %u, psm %u cid %u\n", handle, psm, source_cid);
l2cap_service_t *service = l2cap_get_service(psm); l2cap_service_t *service = l2cap_get_service(psm);
if (!service) { if (!service) {
// 0x0002 PSM not supported // 0x0002 PSM not supported
// log_dbg("l2cap_handle_connection_request no PSM for psm %u/n", psm); // log_info("l2cap_handle_connection_request no PSM for psm %u/n", psm);
l2cap_send_signaling_packet(handle, CONNECTION_RESPONSE, sig_id, 0, 0, 0x0002, 0); l2cap_send_signaling_packet(handle, CONNECTION_RESPONSE, sig_id, 0, 0, 0x0002, 0);
return; return;
} }
@ -674,7 +674,7 @@ static void l2cap_handle_connection_request(hci_con_handle_t handle, uint8_t sig
return; return;
} }
// alloc structure // alloc structure
// log_dbg("l2cap_handle_connection_request register channel\n"); // log_info("l2cap_handle_connection_request register channel\n");
l2cap_channel_t * channel = malloc(sizeof(l2cap_channel_t)); l2cap_channel_t * channel = malloc(sizeof(l2cap_channel_t));
// TODO: emit error event // TODO: emit error event
if (!channel) return; if (!channel) return;
@ -745,14 +745,14 @@ void l2cap_signaling_handle_configure_request(l2cap_channel_t *channel, uint8_t
// MTU { type(8): 1, len(8):2, MTU(16) } // MTU { type(8): 1, len(8):2, MTU(16) }
if ((type & 0x7f) == 1 && length == 2){ if ((type & 0x7f) == 1 && length == 2){
channel->remote_mtu = READ_BT_16(command, pos); channel->remote_mtu = READ_BT_16(command, pos);
// log_dbg("l2cap cid %u, remote mtu %u\n", channel->local_cid, channel->remote_mtu); // log_info("l2cap cid %u, remote mtu %u\n", channel->local_cid, channel->remote_mtu);
} }
pos += length; pos += length;
} }
} }
static int l2cap_channel_ready_for_open(l2cap_channel_t *channel){ static int l2cap_channel_ready_for_open(l2cap_channel_t *channel){
// log_dbg("l2cap_channel_ready_for_open 0x%02x\n", channel->state_var); // log_info("l2cap_channel_ready_for_open 0x%02x\n", channel->state_var);
if ((channel->state_var & STATE_VAR_RCVD_CONF_RSP) == 0) return 0; if ((channel->state_var & STATE_VAR_RCVD_CONF_RSP) == 0) return 0;
if ((channel->state_var & STATE_VAR_SENT_CONF_RSP) == 0) return 0; if ((channel->state_var & STATE_VAR_SENT_CONF_RSP) == 0) return 0;
return 1; return 1;
@ -765,7 +765,7 @@ void l2cap_signaling_handler_channel(l2cap_channel_t *channel, uint8_t *command)
uint8_t identifier = command[L2CAP_SIGNALING_COMMAND_SIGID_OFFSET]; uint8_t identifier = command[L2CAP_SIGNALING_COMMAND_SIGID_OFFSET];
uint16_t result = 0; uint16_t result = 0;
log_dbg("signaling handler code %u, state %u\n", code, channel->state); log_info("signaling handler code %u, state %u\n", code, channel->state);
// handle DISCONNECT REQUESTS seperately // handle DISCONNECT REQUESTS seperately
if (code == DISCONNECTION_REQUEST){ if (code == DISCONNECTION_REQUEST){
@ -867,7 +867,7 @@ void l2cap_signaling_handler_channel(l2cap_channel_t *channel, uint8_t *command)
default: default:
break; break;
} }
// log_dbg("new state %u\n", channel->state); // log_info("new state %u\n", channel->state);
} }

4
src/remote_device_db_iphone.m
View File

@ -84,13 +84,13 @@ static void db_open(void){
[rfcomm_services setObject:serviceEntry forKey:key]; [rfcomm_services setObject:serviceEntry forKey:key];
} }
log_dbg("read prefs for %u devices\n", (unsigned int) [dict count]); log_info("read prefs for %u devices\n", (unsigned int) [dict count]);
[pool release]; [pool release];
} }
static void db_synchronize(void){ static void db_synchronize(void){
log_dbg("stored prefs for %u devices\n", (unsigned int) [remote_devices count]); log_info("stored prefs for %u devices\n", (unsigned int) [remote_devices count]);
// 3 different ways // 3 different ways

144
src/rfcomm.c
View File

@ -428,7 +428,7 @@ static void rfcomm_dump_channels(void){
int channels = 0; int channels = 0;
for (it = (linked_item_t *) rfcomm_channels; it ; it = it->next){ for (it = (linked_item_t *) rfcomm_channels; it ; it = it->next){
rfcomm_channel_t * channel = (rfcomm_channel_t *) it; rfcomm_channel_t * channel = (rfcomm_channel_t *) it;
log_dbg("Channel #%u: addr %p, state %u\n", channels, channel, channel->state); log_info("Channel #%u: addr %p, state %u\n", channels, channel, channel->state);
channels++; channels++;
} }
#endif #endif
@ -470,7 +470,7 @@ static void rfcomm_channel_initialize(rfcomm_channel_t *channel, rfcomm_multiple
static rfcomm_channel_t * rfcomm_channel_create(rfcomm_multiplexer_t * multiplexer, static rfcomm_channel_t * rfcomm_channel_create(rfcomm_multiplexer_t * multiplexer,
rfcomm_service_t * service, uint8_t server_channel){ rfcomm_service_t * service, uint8_t server_channel){
log_dbg("rfcomm_channel_create for service %p, channel %u --- begin\n", service, server_channel); log_info("rfcomm_channel_create for service %p, channel %u --- begin\n", service, server_channel);
rfcomm_dump_channels(); rfcomm_dump_channels();
// alloc structure // alloc structure
@ -563,7 +563,7 @@ static int rfcomm_send_packet_for_multiplexer(rfcomm_multiplexer_t *multiplexer,
credits_taken++; credits_taken++;
multiplexer->l2cap_credits--; multiplexer->l2cap_credits--;
} else { } else {
log_dbg( "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\n", address, control, pos);
} }
int err = l2cap_send_internal(multiplexer->l2cap_cid, rfcomm_out_buffer, pos); int err = l2cap_send_internal(multiplexer->l2cap_cid, rfcomm_out_buffer, pos);
@ -737,7 +737,7 @@ static void rfcomm_multiplexer_finalize(rfcomm_multiplexer_t * multiplexer){
static void rfcomm_multiplexer_timer_handler(timer_source_t *timer){ 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); rfcomm_multiplexer_t * multiplexer = (rfcomm_multiplexer_t *) linked_item_get_user( (linked_item_t *) timer);
if (!rfcomm_multiplexer_has_channels(multiplexer)){ if (!rfcomm_multiplexer_has_channels(multiplexer)){
log_dbg( "rfcomm_multiplexer_timer_handler timeout: shutting down multiplexer!\n"); log_info( "rfcomm_multiplexer_timer_handler timeout: shutting down multiplexer!\n");
rfcomm_multiplexer_finalize(multiplexer); rfcomm_multiplexer_finalize(multiplexer);
} }
} }
@ -758,7 +758,7 @@ static void rfcomm_multiplexer_prepare_idle_timer(rfcomm_multiplexer_t * multipl
} }
static void rfcomm_multiplexer_opened(rfcomm_multiplexer_t *multiplexer){ static void rfcomm_multiplexer_opened(rfcomm_multiplexer_t *multiplexer){
log_dbg("Multiplexer up and running\n"); log_info("Multiplexer up and running\n");
multiplexer->state = RFCOMM_MULTIPLEXER_OPEN; multiplexer->state = RFCOMM_MULTIPLEXER_OPEN;
rfcomm_channel_event_t event; rfcomm_channel_event_t event;
@ -796,14 +796,14 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
if (psm != PSM_RFCOMM) break; if (psm != PSM_RFCOMM) break;
l2cap_cid = READ_BT_16(packet, 12); l2cap_cid = READ_BT_16(packet, 12);
multiplexer = rfcomm_multiplexer_for_addr(&event_addr); multiplexer = rfcomm_multiplexer_for_addr(&event_addr);
log_dbg("L2CAP_EVENT_INCOMING_CONNECTION (l2cap_cid 0x%02x) for PSM_RFCOMM from ", l2cap_cid); log_info("L2CAP_EVENT_INCOMING_CONNECTION (l2cap_cid 0x%02x) for PSM_RFCOMM from ", l2cap_cid);
if (multiplexer) { if (multiplexer) {
log_dbg(" => decline\n"); log_info(" => decline\n");
// bt_send_cmd(&l2cap_decline_connection, l2cap_cid); // bt_send_cmd(&l2cap_decline_connection, l2cap_cid);
l2cap_decline_connection_internal(l2cap_cid, 0x13); l2cap_decline_connection_internal(l2cap_cid, 0x13);
} else { } else {
log_dbg(" => accept\n"); log_info(" => accept\n");
// bt_send_cmd(&l2cap_accept_connection, l2cap_cid); // bt_send_cmd(&l2cap_accept_connection, l2cap_cid);
l2cap_accept_connection_internal(l2cap_cid); l2cap_accept_connection_internal(l2cap_cid);
} }
@ -812,7 +812,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
// l2cap connection opened -> store l2cap_cid, remote_addr // l2cap connection opened -> store l2cap_cid, remote_addr
case L2CAP_EVENT_CHANNEL_OPENED: case L2CAP_EVENT_CHANNEL_OPENED:
if (READ_BT_16(packet, 11) != PSM_RFCOMM) break; if (READ_BT_16(packet, 11) != PSM_RFCOMM) break;
log_dbg("L2CAP_EVENT_CHANNEL_OPENED for PSM_RFCOMM\n"); log_info("L2CAP_EVENT_CHANNEL_OPENED for PSM_RFCOMM\n");
// get multiplexer for remote addr // get multiplexer for remote addr
con_handle = READ_BT_16(packet, 9); con_handle = READ_BT_16(packet, 9);
l2cap_cid = READ_BT_16(packet, 13); l2cap_cid = READ_BT_16(packet, 13);
@ -820,7 +820,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
multiplexer = rfcomm_multiplexer_for_addr(&event_addr); multiplexer = rfcomm_multiplexer_for_addr(&event_addr);
if (multiplexer) { if (multiplexer) {
if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_CONNECT) { if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_CONNECT) {
log_dbg("L2CAP_EVENT_CHANNEL_OPENED: outgoing connection A\n"); log_info("L2CAP_EVENT_CHANNEL_OPENED: outgoing connection A\n");
// wrong remote addr // wrong remote addr
if (BD_ADDR_CMP(event_addr, multiplexer->remote_addr)) break; if (BD_ADDR_CMP(event_addr, multiplexer->remote_addr)) break;
multiplexer->l2cap_cid = l2cap_cid; multiplexer->l2cap_cid = l2cap_cid;
@ -829,11 +829,11 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
multiplexer->state = RFCOMM_MULTIPLEXER_SEND_SABM_0; multiplexer->state = RFCOMM_MULTIPLEXER_SEND_SABM_0;
return 1; return 1;
} }
log_dbg("L2CAP_EVENT_CHANNEL_OPENED: multiplexer already exists\n"); log_info("L2CAP_EVENT_CHANNEL_OPENED: multiplexer already exists\n");
// single multiplexer per baseband connection // single multiplexer per baseband connection
break; break;
} }
log_dbg("L2CAP_EVENT_CHANNEL_OPENED: create incoming multiplexer for channel %02x\n", l2cap_cid); log_info("L2CAP_EVENT_CHANNEL_OPENED: create incoming multiplexer for channel %02x\n", l2cap_cid);
// create and inititialize new multiplexer instance (incoming) // create and inititialize new multiplexer instance (incoming)
// - Max RFCOMM header has 6 bytes (P/F bit is set, payload length >= 128) // - Max RFCOMM header has 6 bytes (P/F bit is set, payload length >= 128)
// - therefore, we set RFCOMM max frame size <= Local L2CAP MTU - 6 // - therefore, we set RFCOMM max frame size <= Local L2CAP MTU - 6
@ -853,7 +853,7 @@ static int rfcomm_multiplexer_hci_event_handler(uint8_t *packet, uint16_t size){
if (!multiplexer) break; if (!multiplexer) break;
multiplexer->l2cap_credits += packet[4]; multiplexer->l2cap_credits += packet[4];
// log_dbg("L2CAP_EVENT_CREDITS: %u (now %u)\n", packet[4], multiplexer->l2cap_credits); // log_info("L2CAP_EVENT_CREDITS: %u (now %u)\n", packet[4], multiplexer->l2cap_credits);
// new credits, continue with signaling // new credits, continue with signaling
rfcomm_run(); rfcomm_run();
@ -904,7 +904,7 @@ static int rfcomm_multiplexer_l2cap_packet_handler(uint16_t channel, uint8_t *pa
case BT_RFCOMM_SABM: case BT_RFCOMM_SABM:
if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_SABM_0){ if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_SABM_0){
log_dbg("Received SABM #0\n"); log_info("Received SABM #0\n");
multiplexer->outgoing = 0; multiplexer->outgoing = 0;
multiplexer->state = RFCOMM_MULTIPLEXER_SEND_UA_0; multiplexer->state = RFCOMM_MULTIPLEXER_SEND_UA_0;
return 1; return 1;
@ -914,7 +914,7 @@ static int rfcomm_multiplexer_l2cap_packet_handler(uint16_t channel, uint8_t *pa
case BT_RFCOMM_UA: case BT_RFCOMM_UA:
if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_UA_0) { if (multiplexer->state == RFCOMM_MULTIPLEXER_W4_UA_0) {
// UA #0 -> send UA #0, state = RFCOMM_MULTIPLEXER_OPEN // UA #0 -> send UA #0, state = RFCOMM_MULTIPLEXER_OPEN
log_dbg("Received UA #0 \n"); log_info("Received UA #0 \n");
rfcomm_multiplexer_opened(multiplexer); rfcomm_multiplexer_opened(multiplexer);
return 1; return 1;
} }
@ -922,22 +922,22 @@ static int rfcomm_multiplexer_l2cap_packet_handler(uint16_t channel, uint8_t *pa
case BT_RFCOMM_DISC: case BT_RFCOMM_DISC:
// DISC #0 -> send UA #0, close multiplexer // DISC #0 -> send UA #0, close multiplexer
log_dbg("Received DISC #0, (ougoing = %u)\n", multiplexer->outgoing); log_info("Received DISC #0, (ougoing = %u)\n", multiplexer->outgoing);
multiplexer->state = RFCOMM_MULTIPLEXER_SEND_UA_0_AND_DISC; multiplexer->state = RFCOMM_MULTIPLEXER_SEND_UA_0_AND_DISC;
return 1; return 1;
case BT_RFCOMM_DM: case BT_RFCOMM_DM:
// DM #0 - we shouldn't get this, just give up // DM #0 - we shouldn't get this, just give up
log_dbg("Received DM #0\n"); log_info("Received DM #0\n");
log_dbg("-> Closing down multiplexer\n"); log_info("-> Closing down multiplexer\n");
rfcomm_multiplexer_finalize(multiplexer); rfcomm_multiplexer_finalize(multiplexer);
return 1; return 1;
case BT_RFCOMM_UIH: case BT_RFCOMM_UIH:
if (packet[payload_offset] == BT_RFCOMM_CLD_CMD){ if (packet[payload_offset] == BT_RFCOMM_CLD_CMD){
// Multiplexer close down (CLD) -> close mutliplexer // Multiplexer close down (CLD) -> close mutliplexer
log_dbg("Received Multiplexer close down command\n"); log_info("Received Multiplexer close down command\n");
log_dbg("-> Closing down multiplexer\n"); log_info("-> Closing down multiplexer\n");
rfcomm_multiplexer_finalize(multiplexer); rfcomm_multiplexer_finalize(multiplexer);
return 1; return 1;
} }
@ -962,7 +962,7 @@ static void rfcomm_multiplexer_state_machine(rfcomm_multiplexer_t * multiplexer,
case RFCOMM_MULTIPLEXER_SEND_SABM_0: case RFCOMM_MULTIPLEXER_SEND_SABM_0:
switch (event) { switch (event) {
case MULT_EV_READY_TO_SEND: case MULT_EV_READY_TO_SEND:
log_dbg("Sending SABM #0 - (multi 0x%08x)\n", (int) multiplexer); log_info("Sending SABM #0 - (multi 0x%08x)\n", (int) multiplexer);
multiplexer->state = RFCOMM_MULTIPLEXER_W4_UA_0; multiplexer->state = RFCOMM_MULTIPLEXER_W4_UA_0;
rfcomm_send_sabm(multiplexer, 0); rfcomm_send_sabm(multiplexer, 0);
break; break;
@ -973,7 +973,7 @@ static void rfcomm_multiplexer_state_machine(rfcomm_multiplexer_t * multiplexer,
case RFCOMM_MULTIPLEXER_SEND_UA_0: case RFCOMM_MULTIPLEXER_SEND_UA_0:
switch (event) { switch (event) {
case MULT_EV_READY_TO_SEND: case MULT_EV_READY_TO_SEND:
log_dbg("Sending UA #0\n"); log_info("Sending UA #0\n");
multiplexer->state = RFCOMM_MULTIPLEXER_OPEN; multiplexer->state = RFCOMM_MULTIPLEXER_OPEN;
rfcomm_send_ua(multiplexer, 0); rfcomm_send_ua(multiplexer, 0);
rfcomm_multiplexer_opened(multiplexer); rfcomm_multiplexer_opened(multiplexer);
@ -985,14 +985,14 @@ static void rfcomm_multiplexer_state_machine(rfcomm_multiplexer_t * multiplexer,
case RFCOMM_MULTIPLEXER_SEND_UA_0_AND_DISC: case RFCOMM_MULTIPLEXER_SEND_UA_0_AND_DISC:
switch (event) { switch (event) {
case MULT_EV_READY_TO_SEND: case MULT_EV_READY_TO_SEND:
log_dbg("Sending UA #0\n"); log_info("Sending UA #0\n");
log_dbg("Closing down multiplexer\n"); log_info("Closing down multiplexer\n");
multiplexer->state = RFCOMM_MULTIPLEXER_CLOSED; multiplexer->state = RFCOMM_MULTIPLEXER_CLOSED;
rfcomm_send_ua(multiplexer, 0); rfcomm_send_ua(multiplexer, 0);
rfcomm_multiplexer_finalize(multiplexer); rfcomm_multiplexer_finalize(multiplexer);
// try to detect authentication errors: drop link key if multiplexer closed before first channel got opened // try to detect authentication errors: drop link key if multiplexer closed before first channel got opened
if (!multiplexer->at_least_one_connection){ if (!multiplexer->at_least_one_connection){
log_dbg("TODO: no connections established - delete link key prophylactically\n"); log_info("TODO: no connections established - delete link key prophylactically\n");
// hci_send_cmd(&hci_delete_stored_link_key, multiplexer->remote_addr); // hci_send_cmd(&hci_delete_stored_link_key, multiplexer->remote_addr);
} }
default: default:
@ -1011,23 +1011,23 @@ static void rfcomm_hand_out_credits(void){
for (it = (linked_item_t *) rfcomm_channels; it ; it = it->next){ for (it = (linked_item_t *) rfcomm_channels; it ; it = it->next){
rfcomm_channel_t * channel = (rfcomm_channel_t *) it; rfcomm_channel_t * channel = (rfcomm_channel_t *) it;
if (channel->state != RFCOMM_CHANNEL_OPEN) { if (channel->state != RFCOMM_CHANNEL_OPEN) {
// log_dbg("RFCOMM_EVENT_CREDITS: multiplexer not open\n"); // log_info("RFCOMM_EVENT_CREDITS: multiplexer not open\n");
continue; continue;
} }
if (channel->packets_granted) { if (channel->packets_granted) {
// log_dbg("RFCOMM_EVENT_CREDITS: already packets granted\n"); // log_info("RFCOMM_EVENT_CREDITS: already packets granted\n");
continue; continue;
} }
if (!channel->credits_outgoing) { if (!channel->credits_outgoing) {
// log_dbg("RFCOMM_EVENT_CREDITS: no outgoing credits\n"); // log_info("RFCOMM_EVENT_CREDITS: no outgoing credits\n");
continue; continue;
} }
if (!channel->multiplexer->l2cap_credits){ if (!channel->multiplexer->l2cap_credits){
// log_dbg("RFCOMM_EVENT_CREDITS: no l2cap credits\n"); // log_info("RFCOMM_EVENT_CREDITS: no l2cap credits\n");
continue; continue;
} }
// channel open, multiplexer has l2cap credits and we didn't hand out credit before -> go! // channel open, multiplexer has l2cap credits and we didn't hand out credit before -> go!
// log_dbg("RFCOMM_EVENT_CREDITS: 1\n"); // log_info("RFCOMM_EVENT_CREDITS: 1\n");
channel->packets_granted += 1; channel->packets_granted += 1;
rfcomm_emit_credits(channel, 1); rfcomm_emit_credits(channel, 1);
} }
@ -1055,7 +1055,7 @@ static void rfcomm_channel_provide_credits(rfcomm_channel_t *channel){
static void rfcomm_channel_opened(rfcomm_channel_t *rfChannel){ static void rfcomm_channel_opened(rfcomm_channel_t *rfChannel){
log_dbg("rfcomm_channel_opened!\n"); log_info("rfcomm_channel_opened!\n");
rfChannel->state = RFCOMM_CHANNEL_OPEN; rfChannel->state = RFCOMM_CHANNEL_OPEN;
rfcomm_emit_channel_opened(rfChannel, 0); rfcomm_emit_channel_opened(rfChannel, 0);
@ -1087,7 +1087,7 @@ static void rfcomm_channel_packet_handler_uih(rfcomm_multiplexer_t *multiplexer,
// handle new credits // handle new credits
uint16_t new_credits = packet[3+length_offset]; uint16_t new_credits = packet[3+length_offset];
rfChannel->credits_outgoing += new_credits; rfChannel->credits_outgoing += new_credits;
log_dbg( "RFCOMM data UIH_PF, new credits: %u, now %u\n", new_credits, rfChannel->credits_outgoing); log_info( "RFCOMM data UIH_PF, new credits: %u, now %u\n", new_credits, rfChannel->credits_outgoing);
// notify daemon -> might trigger re-try of parked connections // notify daemon -> might trigger re-try of parked connections
uint8_t event[1]; uint8_t event[1];
@ -1105,7 +1105,7 @@ static void rfcomm_channel_packet_handler_uih(rfcomm_multiplexer_t *multiplexer,
rfcomm_channel_provide_credits(rfChannel); rfcomm_channel_provide_credits(rfChannel);
if (size - 1 > payload_offset){ // don't send empty frames, -1 for header checksum at end if (size - 1 > payload_offset){ // don't send empty frames, -1 for header checksum at end
// log_dbg( "RFCOMM data UIH_PF, size %u, channel %x\n", size-payload_offset-1, (int) rfChannel->connection); // log_info( "RFCOMM data UIH_PF, size %u, channel %x\n", size-payload_offset-1, (int) rfChannel->connection);
(*app_packet_handler)(rfChannel->connection, RFCOMM_DATA_PACKET, rfChannel->rfcomm_cid, (*app_packet_handler)(rfChannel->connection, RFCOMM_DATA_PACKET, rfChannel->rfcomm_cid,
&packet[payload_offset], size-payload_offset-1); &packet[payload_offset], size-payload_offset-1);
} }
@ -1152,7 +1152,7 @@ static void rfcomm_channel_state_machine_2(rfcomm_multiplexer_t * multiplexer, u
// lookup existing channel // lookup existing channel
rfcomm_channel_t * channel = rfcomm_channel_for_multiplexer_and_dlci(multiplexer, dlci); rfcomm_channel_t * channel = rfcomm_channel_for_multiplexer_and_dlci(multiplexer, dlci);
// log_dbg("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\n", dlci, (int) channel, event->type);
if (channel) { if (channel) {
rfcomm_channel_state_machine(channel, event); rfcomm_channel_state_machine(channel, event);
@ -1161,7 +1161,7 @@ static void rfcomm_channel_state_machine_2(rfcomm_multiplexer_t * multiplexer, u
// service registered? // service registered?
rfcomm_service_t * service = rfcomm_service_for_channel(dlci >> 1); rfcomm_service_t * service = rfcomm_service_for_channel(dlci >> 1);
// log_dbg("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\n", dlci, (int) service);
if (!service) { if (!service) {
// discard request by sending disconnected mode // discard request by sending disconnected mode
multiplexer->send_dm_for_dlci = dlci; multiplexer->send_dm_for_dlci = dlci;
@ -1215,13 +1215,13 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
case BT_RFCOMM_SABM: case BT_RFCOMM_SABM:
event.type = CH_EVT_RCVD_SABM; event.type = CH_EVT_RCVD_SABM;
log_dbg("Received SABM #%u\n", frame_dlci); log_info("Received SABM #%u\n", frame_dlci);
rfcomm_channel_state_machine_2(multiplexer, frame_dlci, &event); rfcomm_channel_state_machine_2(multiplexer, frame_dlci, &event);
break; break;
case BT_RFCOMM_UA: case BT_RFCOMM_UA:
event.type = CH_EVT_RCVD_UA; event.type = CH_EVT_RCVD_UA;
log_dbg("Received UA #%u - channel opened\n",frame_dlci); log_info("Received UA #%u - channel opened\n",frame_dlci);
rfcomm_channel_state_machine_2(multiplexer, frame_dlci, &event); rfcomm_channel_state_machine_2(multiplexer, frame_dlci, &event);
break; break;
@ -1248,7 +1248,7 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
event_pn.priority = packet[payload_offset+4]; event_pn.priority = packet[payload_offset+4];
event_pn.max_frame_size = READ_BT_16(packet, payload_offset+6); event_pn.max_frame_size = READ_BT_16(packet, payload_offset+6);
event_pn.credits_outgoing = packet[payload_offset+9]; event_pn.credits_outgoing = packet[payload_offset+9];
log_dbg("Received UIH Parameter Negotiation Command for #%u\n", message_dlci); log_info("Received UIH Parameter Negotiation Command for #%u\n", message_dlci);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_pn); rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_pn);
break; break;
@ -1258,7 +1258,7 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
event_pn.priority = packet[payload_offset+4]; event_pn.priority = packet[payload_offset+4];
event_pn.max_frame_size = READ_BT_16(packet, payload_offset+6); event_pn.max_frame_size = READ_BT_16(packet, payload_offset+6);
event_pn.credits_outgoing = packet[payload_offset+9]; event_pn.credits_outgoing = packet[payload_offset+9];
log_dbg("UIH Parameter Negotiation Response max frame %u, credits %u\n", log_info("UIH Parameter Negotiation Response max frame %u, credits %u\n",
event_pn.max_frame_size, event_pn.credits_outgoing); event_pn.max_frame_size, event_pn.credits_outgoing);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_pn); rfcomm_channel_state_machine_2(multiplexer, message_dlci, (rfcomm_channel_event_t*) &event_pn);
break; break;
@ -1266,14 +1266,14 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
case BT_RFCOMM_MSC_CMD: case BT_RFCOMM_MSC_CMD:
message_dlci = packet[payload_offset+2] >> 2; message_dlci = packet[payload_offset+2] >> 2;
event.type = CH_EVT_RCVD_MSC_CMD; event.type = CH_EVT_RCVD_MSC_CMD;
log_dbg("Received MSC CMD for #%u, \n", message_dlci); log_info("Received MSC CMD for #%u, \n", message_dlci);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event); rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event);
break; break;
case BT_RFCOMM_MSC_RSP: case BT_RFCOMM_MSC_RSP:
message_dlci = packet[payload_offset+2] >> 2; message_dlci = packet[payload_offset+2] >> 2;
event.type = CH_EVT_RCVD_MSC_RSP; event.type = CH_EVT_RCVD_MSC_RSP;
log_dbg("Received MSC RSP for #%u\n", message_dlci); log_info("Received MSC RSP for #%u\n", message_dlci);
rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event); rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event);
break; break;
@ -1281,12 +1281,12 @@ void rfcomm_channel_packet_handler(rfcomm_multiplexer_t * multiplexer, uint8_t
message_dlci = packet[payload_offset+2] >> 2; message_dlci = packet[payload_offset+2] >> 2;
switch (message_len){ switch (message_len){
case 1: case 1:
log_dbg("Received Remote Port Negotiation for #%u\n", message_dlci); log_info("Received Remote Port Negotiation for #%u\n", message_dlci);
event.type = CH_EVT_RCVD_RPN_REQ; event.type = CH_EVT_RCVD_RPN_REQ;
rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event); rfcomm_channel_state_machine_2(multiplexer, message_dlci, &event);
break; break;
case 8: case 8:
log_dbg("Received Remote Port Negotiation (Info) for #%u\n", message_dlci); log_info("Received Remote Port Negotiation (Info) for #%u\n", message_dlci);
event_rpn.super.type = CH_EVT_RCVD_RPN_CMD; event_rpn.super.type = CH_EVT_RCVD_RPN_CMD;
event_rpn.data.baud_rate = packet[payload_offset+3]; event_rpn.data.baud_rate = packet[payload_offset+3];
event_rpn.data.flags = packet[payload_offset+4]; event_rpn.data.flags = packet[payload_offset+4];
@ -1361,7 +1361,7 @@ 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){ static int rfcomm_channel_ready_for_open(rfcomm_channel_t *channel){
// log_dbg("rfcomm_channel_ready_for_open state %u, flags needed %04x, current %04x, rf credits %u, l2cap credits %u \n", channel->state, STATE_VAR_RCVD_MSC_RSP|STATE_VAR_SENT_MSC_RSP|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 \n", channel->state, STATE_VAR_RCVD_MSC_RSP|STATE_VAR_SENT_MSC_RSP|STATE_VAR_SENT_CREDITS, channel->state_var, channel->credits_outgoing, channel->multiplexer->l2cap_credits);
if ((channel->state_var & STATE_VAR_RCVD_MSC_RSP) == 0) return 0; if ((channel->state_var & STATE_VAR_RCVD_MSC_RSP) == 0) return 0;
if ((channel->state_var & STATE_VAR_SENT_MSC_RSP) == 0) return 0; if ((channel->state_var & STATE_VAR_SENT_MSC_RSP) == 0) return 0;
if ((channel->state_var & STATE_VAR_SENT_CREDITS) == 0) return 0; if ((channel->state_var & STATE_VAR_SENT_CREDITS) == 0) return 0;
@ -1372,7 +1372,7 @@ static int rfcomm_channel_ready_for_open(rfcomm_channel_t *channel){
static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_channel_event_t *event){ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_channel_event_t *event){
// log_dbg("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\n", channel->state, channel->state_var ,event->type);
rfcomm_multiplexer_t *multiplexer = channel->multiplexer; rfcomm_multiplexer_t *multiplexer = channel->multiplexer;
@ -1385,8 +1385,8 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
// TODO: integrate in common switch // TODO: integrate in common switch
if (event->type == CH_EVT_RCVD_DM){ if (event->type == CH_EVT_RCVD_DM){
log_dbg("Received DM message for #%u\n", channel->dlci); log_info("Received DM message for #%u\n", channel->dlci);
log_dbg("-> Closing channel locally for #%u\n", channel->dlci); log_info("-> Closing channel locally for #%u\n", channel->dlci);
rfcomm_emit_channel_closed(channel); rfcomm_emit_channel_closed(channel);
rfcomm_channel_finalize(channel); rfcomm_channel_finalize(channel);
return; return;
@ -1427,7 +1427,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
// TODO: integrate in common swich // TODO: integrate in common swich
if (event->type == CH_EVT_READY_TO_SEND){ if (event->type == CH_EVT_READY_TO_SEND){
if (channel->state_var & STATE_VAR_SEND_RPN_RSP){ if (channel->state_var & STATE_VAR_SEND_RPN_RSP){
log_dbg("Sending Remote Port Negotiation RSP for #%u\n", channel->dlci); log_info("Sending Remote Port Negotiation RSP for #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_RPN_RSP; channel->state_var &= ~STATE_VAR_SEND_RPN_RSP;
rfcomm_send_uih_rpn_rsp(multiplexer, channel->dlci, &channel->rpn_data); rfcomm_send_uih_rpn_rsp(multiplexer, channel->dlci, &channel->rpn_data);
return; return;
@ -1440,14 +1440,14 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_CLOSED: case RFCOMM_CHANNEL_CLOSED:
switch (event->type){ switch (event->type){
case CH_EVT_RCVD_SABM: case CH_EVT_RCVD_SABM:
log_dbg("-> Inform app\n"); log_info("-> Inform app\n");
channel->state_var |= STATE_VAR_RCVD_SABM; channel->state_var |= STATE_VAR_RCVD_SABM;
channel->state = RFCOMM_CHANNEL_INCOMING_SETUP; channel->state = RFCOMM_CHANNEL_INCOMING_SETUP;
rfcomm_emit_connection_request(channel); rfcomm_emit_connection_request(channel);
break; break;
case CH_EVT_RCVD_PN: case CH_EVT_RCVD_PN:
rfcomm_channel_accept_pn(channel, event_pn); rfcomm_channel_accept_pn(channel, event_pn);
log_dbg("-> Inform app\n"); log_info("-> Inform app\n");
channel->state_var |= STATE_VAR_RCVD_PN; channel->state_var |= STATE_VAR_RCVD_PN;
channel->state = RFCOMM_CHANNEL_INCOMING_SETUP; channel->state = RFCOMM_CHANNEL_INCOMING_SETUP;
rfcomm_emit_connection_request(channel); rfcomm_emit_connection_request(channel);
@ -1474,12 +1474,12 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
break; break;
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
if (channel->state_var & STATE_VAR_SEND_PN_RSP){ if (channel->state_var & STATE_VAR_SEND_PN_RSP){
log_dbg("Sending UIH Parameter Negotiation Respond for #%u\n", channel->dlci); log_info("Sending UIH Parameter Negotiation Respond for #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_PN_RSP; channel->state_var &= ~STATE_VAR_SEND_PN_RSP;
rfcomm_send_uih_pn_response(multiplexer, channel->dlci, channel->pn_priority, channel->max_frame_size); rfcomm_send_uih_pn_response(multiplexer, channel->dlci, channel->pn_priority, channel->max_frame_size);
} }
else if (channel->state_var & STATE_VAR_SEND_UA){ else if (channel->state_var & STATE_VAR_SEND_UA){
log_dbg("Sending UA #%u\n", channel->dlci); log_info("Sending UA #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_UA; channel->state_var &= ~STATE_VAR_SEND_UA;
rfcomm_send_ua(multiplexer, channel->dlci); rfcomm_send_ua(multiplexer, channel->dlci);
} }
@ -1498,7 +1498,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_W4_MULTIPLEXER: case RFCOMM_CHANNEL_W4_MULTIPLEXER:
switch (event->type) { switch (event->type) {
case CH_EVT_MULTIPLEXER_READY: case CH_EVT_MULTIPLEXER_READY:
log_dbg("Muliplexer opened, sending UIH PN next\n"); log_info("Muliplexer opened, sending UIH PN next\n");
channel->state = RFCOMM_CHANNEL_SEND_UIH_PN; channel->state = RFCOMM_CHANNEL_SEND_UIH_PN;
break; break;
default: default:
@ -1509,7 +1509,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_UIH_PN: case RFCOMM_CHANNEL_SEND_UIH_PN:
switch (event->type) { switch (event->type) {
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
log_dbg("Sending UIH Parameter Negotiation Command for #%u (channel 0x%08x\n", channel->dlci, (int) channel ); log_info("Sending UIH Parameter Negotiation Command for #%u (channel 0x%08x\n", channel->dlci, (int) channel );
channel->state = RFCOMM_CHANNEL_W4_PN_RSP; channel->state = RFCOMM_CHANNEL_W4_PN_RSP;
rfcomm_send_uih_pn_command(multiplexer, channel->dlci, channel->max_frame_size); rfcomm_send_uih_pn_command(multiplexer, channel->dlci, channel->max_frame_size);
break; break;
@ -1537,7 +1537,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_SABM_W4_UA: case RFCOMM_CHANNEL_SEND_SABM_W4_UA:
switch (event->type) { switch (event->type) {
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
log_dbg("Sending SABM #%u\n", channel->dlci); log_info("Sending SABM #%u\n", channel->dlci);
channel->state = RFCOMM_CHANNEL_W4_UA; channel->state = RFCOMM_CHANNEL_W4_UA;
rfcomm_send_sabm(multiplexer, channel->dlci); rfcomm_send_sabm(multiplexer, channel->dlci);
break; break;
@ -1570,21 +1570,21 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
if (channel->state_var & STATE_VAR_SEND_MSC_CMD){ if (channel->state_var & STATE_VAR_SEND_MSC_CMD){
log_dbg("Sending MSC CMD for #%u\n", channel->dlci); log_info("Sending MSC CMD for #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_MSC_CMD; channel->state_var &= ~STATE_VAR_SEND_MSC_CMD;
channel->state_var |= STATE_VAR_SENT_MSC_CMD; channel->state_var |= 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 rfcomm_send_uih_msc_cmd(multiplexer, channel->dlci , 0x8d); // ea=1,fc=0,rtc=1,rtr=1,ic=0,dv=1
break; break;
} }
if (channel->state_var & STATE_VAR_SEND_MSC_RSP){ if (channel->state_var & STATE_VAR_SEND_MSC_RSP){
log_dbg("Sending MSC RSP for #%u\n", channel->dlci); log_info("Sending MSC RSP for #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_MSC_RSP; channel->state_var &= ~STATE_VAR_SEND_MSC_RSP;
channel->state_var |= STATE_VAR_SENT_MSC_RSP; channel->state_var |= 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 rfcomm_send_uih_msc_rsp(multiplexer, channel->dlci, 0x8d); // ea=1,fc=0,rtc=1,rtr=1,ic=0,dv=1
break; break;
} }
if (channel->state_var & STATE_VAR_SEND_CREDITS){ if (channel->state_var & STATE_VAR_SEND_CREDITS){
log_dbg("Providing credits for #%u\n", channel->dlci); log_info("Providing credits for #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_CREDITS; channel->state_var &= ~STATE_VAR_SEND_CREDITS;
channel->state_var |= STATE_VAR_SENT_CREDITS; channel->state_var |= STATE_VAR_SENT_CREDITS;
rfcomm_channel_provide_credits(channel); rfcomm_channel_provide_credits(channel);
@ -1609,7 +1609,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
break; break;
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
if (channel->state_var & STATE_VAR_SEND_MSC_RSP){ if (channel->state_var & STATE_VAR_SEND_MSC_RSP){
log_dbg("Sending MSC RSP for #%u\n", channel->dlci); log_info("Sending MSC RSP for #%u\n", channel->dlci);
channel->state_var &= ~STATE_VAR_SEND_MSC_RSP; channel->state_var &= ~STATE_VAR_SEND_MSC_RSP;
rfcomm_send_uih_msc_rsp(multiplexer, channel->dlci, 0x8d); // ea=1,fc=0,rtc=1,rtr=1,ic=0,dv=1 rfcomm_send_uih_msc_rsp(multiplexer, channel->dlci, 0x8d); // ea=1,fc=0,rtc=1,rtr=1,ic=0,dv=1
break; break;
@ -1623,7 +1623,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_DM: case RFCOMM_CHANNEL_SEND_DM:
switch (event->type) { switch (event->type) {
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
log_dbg("Sending DM_PF for #%u\n", channel->dlci); log_info("Sending DM_PF for #%u\n", channel->dlci);
// don't emit channel closed - channel was never open // don't emit channel closed - channel was never open
channel->state = RFCOMM_CHANNEL_CLOSED; channel->state = RFCOMM_CHANNEL_CLOSED;
rfcomm_send_dm_pf(multiplexer, channel->dlci); rfcomm_send_dm_pf(multiplexer, channel->dlci);
@ -1650,7 +1650,7 @@ static void rfcomm_channel_state_machine(rfcomm_channel_t *channel, rfcomm_chann
case RFCOMM_CHANNEL_SEND_UA_AFTER_DISC: case RFCOMM_CHANNEL_SEND_UA_AFTER_DISC:
switch (event->type) { switch (event->type) {
case CH_EVT_READY_TO_SEND: case CH_EVT_READY_TO_SEND:
log_dbg("Sending UA after DISC for #%u\n", channel->dlci); log_info("Sending UA after DISC for #%u\n", channel->dlci);
channel->state = RFCOMM_CHANNEL_CLOSED; channel->state = RFCOMM_CHANNEL_CLOSED;
rfcomm_send_ua(multiplexer, channel->dlci); rfcomm_send_ua(multiplexer, channel->dlci);
rfcomm_channel_finalize(channel); rfcomm_channel_finalize(channel);
@ -1680,10 +1680,10 @@ static void rfcomm_run(void){
rfcomm_multiplexer_t * multiplexer = ((rfcomm_multiplexer_t *) it); rfcomm_multiplexer_t * multiplexer = ((rfcomm_multiplexer_t *) it);
if (!l2cap_can_send_packet_now(multiplexer->l2cap_cid)) { if (!l2cap_can_send_packet_now(multiplexer->l2cap_cid)) {
// log_dbg("rfcomm_run cannot send l2cap packet for #%u, credits %u\n", multiplexer->l2cap_cid, multiplexer->l2cap_credits); // log_info("rfcomm_run cannot send l2cap packet for #%u, credits %u\n", multiplexer->l2cap_cid, multiplexer->l2cap_credits);
continue; continue;
} }
// log_dbg("rfcomm_run: multi 0x%08x, state %u\n", (int) multiplexer, multiplexer->state); // log_info("rfcomm_run: multi 0x%08x, state %u\n", (int) multiplexer, multiplexer->state);
rfcomm_multiplexer_state_machine(multiplexer, MULT_EV_READY_TO_SEND); rfcomm_multiplexer_state_machine(multiplexer, MULT_EV_READY_TO_SEND);
} }
@ -1728,16 +1728,16 @@ int rfcomm_send_internal(uint8_t rfcomm_cid, uint8_t *data, uint16_t len){
} }
if (!channel->credits_outgoing){ if (!channel->credits_outgoing){
log_dbg("rfcomm_send_internal cid %u, no rfcomm outgoing credits!\n", rfcomm_cid); log_info("rfcomm_send_internal cid %u, no rfcomm outgoing credits!\n", rfcomm_cid);
return RFCOMM_NO_OUTGOING_CREDITS; return RFCOMM_NO_OUTGOING_CREDITS;
} }
if (!channel->packets_granted){ if (!channel->packets_granted){
log_dbg("rfcomm_send_internal cid %u, no rfcomm credits granted!\n", rfcomm_cid); log_info("rfcomm_send_internal cid %u, no rfcomm credits granted!\n", rfcomm_cid);
// return RFCOMM_NO_OUTGOING_CREDITS; // return RFCOMM_NO_OUTGOING_CREDITS;
} }
// log_dbg("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\n",
// len, channel->credits_outgoing, channel->multiplexer->l2cap_credits, channel->packets_granted); // len, channel->credits_outgoing, channel->multiplexer->l2cap_credits, channel->packets_granted);
@ -1754,11 +1754,11 @@ int rfcomm_send_internal(uint8_t rfcomm_cid, uint8_t *data, uint16_t len){
if (result != 0) { if (result != 0) {
channel->credits_outgoing++; channel->credits_outgoing++;
channel->packets_granted += packets_granted_decreased; channel->packets_granted += packets_granted_decreased;
log_dbg("rfcomm_send_internal: error %d\n", result); log_info("rfcomm_send_internal: error %d\n", result);
return result; return result;
} }
// log_dbg("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\n",
// channel->credits_outgoing, channel->multiplexer->l2cap_credits, channel->packets_granted); // channel->credits_outgoing, channel->multiplexer->l2cap_credits, channel->packets_granted);
rfcomm_hand_out_credits(); rfcomm_hand_out_credits();
@ -1768,9 +1768,9 @@ int rfcomm_send_internal(uint8_t rfcomm_cid, uint8_t *data, uint16_t len){
void rfcomm_create_channel_internal(void * connection, bd_addr_t *addr, uint8_t server_channel){ void rfcomm_create_channel_internal(void * connection, bd_addr_t *addr, uint8_t server_channel){
log_dbg("rfcomm_create_channel_internal to "); log_info("rfcomm_create_channel_internal to ");
print_bd_addr(*addr); print_bd_addr(*addr);
log_dbg(" at channel #%02x\n", server_channel); log_info(" at channel #%02x\n", server_channel);
// create new multiplexer if necessary // create new multiplexer if necessary
@ -1855,7 +1855,7 @@ void rfcomm_unregister_service_internal(uint8_t service_channel){
} }
void rfcomm_accept_connection_internal(uint16_t rfcomm_cid){ void rfcomm_accept_connection_internal(uint16_t rfcomm_cid){
log_dbg("Received Accept Connction\n"); log_info("Received Accept Connction\n");
rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid); rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid);
if (!channel) return; if (!channel) return;
switch (channel->state) { switch (channel->state) {
@ -1875,7 +1875,7 @@ void rfcomm_accept_connection_internal(uint16_t rfcomm_cid){
} }
void rfcomm_decline_connection_internal(uint16_t rfcomm_cid){ void rfcomm_decline_connection_internal(uint16_t rfcomm_cid){
log_dbg("Received Decline Connction\n"); log_info("Received Decline Connction\n");
rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid); rfcomm_channel_t * channel = rfcomm_channel_for_rfcomm_cid(rfcomm_cid);
if (!channel) return; if (!channel) return;
switch (channel->state) { switch (channel->state) {

6
src/run_loop_embedded.c
View File

@ -84,7 +84,7 @@ void embedded_add_timer(timer_source_t *ts){
} }
ts->item.next = it->next; ts->item.next = it->next;
it->next = (linked_item_t *) ts; it->next = (linked_item_t *) ts;
// log_dbg("Added timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec); // log_info("Added timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec);
// embedded_dump_timer(); // embedded_dump_timer();
#endif #endif
} }
@ -94,7 +94,7 @@ void embedded_add_timer(timer_source_t *ts){
*/ */
int embedded_remove_timer(timer_source_t *ts){ int embedded_remove_timer(timer_source_t *ts){
#ifdef EMBEDDED #ifdef EMBEDDED
// log_dbg("Removed timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec); // log_info("Removed timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec);
return linked_list_remove(&timers, (linked_item_t *) ts); return linked_list_remove(&timers, (linked_item_t *) ts);
#else #else
return 0; return 0;
@ -107,7 +107,7 @@ void embedded_dump_timer(){
int i = 0; int i = 0;
for (it = (linked_item_t *) timers; it ; it = it->next){ for (it = (linked_item_t *) timers; it ; it = it->next){
timer_source_t *ts = (timer_source_t*) it; timer_source_t *ts = (timer_source_t*) it;
log_dbg("timer %u, timeout %u\n", i, (unsigned int) ts->timeout.tv_sec); log_info("timer %u, timeout %u\n", i, (unsigned int) ts->timeout.tv_sec);
} }
#endif #endif
} }

20
src/run_loop_posix.c
View File

@ -57,7 +57,7 @@ static linked_list_t timers;
*/ */
void posix_add_data_source(data_source_t *ds){ void posix_add_data_source(data_source_t *ds){
data_sources_modified = 1; data_sources_modified = 1;
// log_dbg("posix_add_data_source %x with fd %u\n", (int) ds, ds->fd); // log_info("posix_add_data_source %x with fd %u\n", (int) ds, ds->fd);
linked_list_add(&data_sources, (linked_item_t *) ds); linked_list_add(&data_sources, (linked_item_t *) ds);
} }
@ -66,7 +66,7 @@ void posix_add_data_source(data_source_t *ds){
*/ */
int posix_remove_data_source(data_source_t *ds){ int posix_remove_data_source(data_source_t *ds){
data_sources_modified = 1; data_sources_modified = 1;
// log_dbg("posix_remove_data_source %x\n", (int) ds); // log_info("posix_remove_data_source %x\n", (int) ds);
return linked_list_remove(&data_sources, (linked_item_t *) ds); return linked_list_remove(&data_sources, (linked_item_t *) ds);
} }
@ -86,7 +86,7 @@ void posix_add_timer(timer_source_t *ts){
} }
ts->item.next = it->next; ts->item.next = it->next;
it->next = (linked_item_t *) ts; it->next = (linked_item_t *) ts;
// log_dbg("Added timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec); // log_info("Added timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec);
// posix_dump_timer(); // posix_dump_timer();
} }
@ -94,7 +94,7 @@ void posix_add_timer(timer_source_t *ts){
* Remove timer from run loop * Remove timer from run loop
*/ */
int posix_remove_timer(timer_source_t *ts){ int posix_remove_timer(timer_source_t *ts){
// log_dbg("Removed timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec); // log_info("Removed timer %x at %u\n", (int) ts, (unsigned int) ts->timeout.tv_sec);
// posix_dump_timer(); // posix_dump_timer();
return linked_list_remove(&timers, (linked_item_t *) ts); return linked_list_remove(&timers, (linked_item_t *) ts);
} }
@ -104,7 +104,7 @@ void posix_dump_timer(void){
int i = 0; int i = 0;
for (it = (linked_item_t *) timers; it ; it = it->next){ for (it = (linked_item_t *) timers; it ; it = it->next){
timer_source_t *ts = (timer_source_t*) it; timer_source_t *ts = (timer_source_t*) it;
log_dbg("timer %u, timeout %u\n", i, (unsigned int) ts->timeout.tv_sec); log_info("timer %u, timeout %u\n", i, (unsigned int) ts->timeout.tv_sec);
} }
} }
@ -157,16 +157,16 @@ void posix_execute(void) {
// process data sources very carefully // process data sources very carefully
// bt_control.close() triggered from a client can remove a different data source // bt_control.close() triggered from a client can remove a different data source
// log_dbg("posix_execute: before ds check\n"); // log_info("posix_execute: before ds check\n");
data_sources_modified = 0; data_sources_modified = 0;
for (ds = (data_source_t *) data_sources; !data_sources_modified && ds != NULL; ds = (data_source_t *) ds->item.next){ for (ds = (data_source_t *) data_sources; !data_sources_modified && ds != NULL; ds = (data_source_t *) ds->item.next){
// log_dbg("posix_execute: check %x with fd %u\n", (int) ds, ds->fd); // log_info("posix_execute: check %x with fd %u\n", (int) ds, ds->fd);
if (FD_ISSET(ds->fd, &descriptors)) { if (FD_ISSET(ds->fd, &descriptors)) {
// log_dbg("posix_execute: process %x with fd %u\n", (int) ds, ds->fd); // log_info("posix_execute: process %x with fd %u\n", (int) ds, ds->fd);
ds->process(ds); ds->process(ds);
} }
} }
// log_dbg("posix_execute: after ds check\n"); // log_info("posix_execute: after ds check\n");
// process timers // process timers
// pre: 0 <= tv_usec < 1000000 // pre: 0 <= tv_usec < 1000000
@ -175,7 +175,7 @@ void posix_execute(void) {
ts = (timer_source_t *) timers; ts = (timer_source_t *) timers;
if (ts->timeout.tv_sec > current_tv.tv_sec) break; if (ts->timeout.tv_sec > current_tv.tv_sec) break;
if (ts->timeout.tv_sec == current_tv.tv_sec && ts->timeout.tv_usec > current_tv.tv_usec) break; if (ts->timeout.tv_sec == current_tv.tv_sec && ts->timeout.tv_usec > current_tv.tv_usec) break;
// log_dbg("posix_execute: process times %x\n", (int) ts); // log_info("posix_execute: process times %x\n", (int) ts);
// remove timer before processing it to allow handler to re-register with run loop // remove timer before processing it to allow handler to re-register with run loop
run_loop_remove_timer(ts); run_loop_remove_timer(ts);

22
src/socket_connection.c
View File

@ -181,7 +181,7 @@ void static socket_connection_emit_nr_connections(void){
event[0] = DAEMON_NR_CONNECTIONS_CHANGED; event[0] = DAEMON_NR_CONNECTIONS_CHANGED;
event[1] = nr_connections; event[1] = nr_connections;
(*socket_connection_packet_callback)(NULL, DAEMON_EVENT_PACKET, 0, (uint8_t *) &event, 2); (*socket_connection_packet_callback)(NULL, DAEMON_EVENT_PACKET, 0, (uint8_t *) &event, 2);
// log_dbg("Nr connections changed,.. new %u\n", nr_connections); // log_info("Nr connections changed,.. new %u\n", nr_connections);
} }
int socket_connection_hci_process(struct data_source *ds) { int socket_connection_hci_process(struct data_source *ds) {
@ -231,7 +231,7 @@ int socket_connection_hci_process(struct data_source *ds) {
// "park" if dispatch failed // "park" if dispatch failed
if (dispatch_err) { if (dispatch_err) {
log_dbg("socket_connection_hci_process dispatch failed -> park connection\n"); log_info("socket_connection_hci_process dispatch failed -> park connection\n");
run_loop_remove_data_source(ds); run_loop_remove_data_source(ds);
linked_list_add_tail(&parked, (linked_item_t *) ds); linked_list_add_tail(&parked, (linked_item_t *) ds);
} }
@ -245,18 +245,18 @@ int socket_connection_hci_process(struct data_source *ds) {
* pre: connections get parked iff packet was dispatched but could not be sent * pre: connections get parked iff packet was dispatched but could not be sent
*/ */
void socket_connection_retry_parked(){ void socket_connection_retry_parked(){
// log_dbg("socket_connection_hci_process retry parked\n"); // log_info("socket_connection_hci_process retry parked\n");
linked_item_t *it = (linked_item_t *) &parked; linked_item_t *it = (linked_item_t *) &parked;
while (it->next) { while (it->next) {
connection_t * conn = (connection_t *) it->next; connection_t * conn = (connection_t *) it->next;
// dispatch packet !!! connection, type, channel, data, size // dispatch packet !!! connection, type, channel, data, size
log_dbg("socket_connection_hci_process retry parked #0\n"); log_info("socket_connection_hci_process retry parked #0\n");
int dispatch_err = (*socket_connection_packet_callback)(conn, READ_BT_16( conn->buffer, 0), READ_BT_16( conn->buffer, 2), 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)); &conn->buffer[sizeof(packet_header_t)], READ_BT_16( conn->buffer, 4));
// "un-park" if successful // "un-park" if successful
if (!dispatch_err) { if (!dispatch_err) {
log_dbg("socket_connection_hci_process dispatch succeeded -> un-park connection\n"); log_info("socket_connection_hci_process dispatch succeeded -> un-park connection\n");
it->next = it->next->next; it->next = it->next->next;
run_loop_add_data_source( (data_source_t *) conn); run_loop_add_data_source( (data_source_t *) conn);
} else { } else {
@ -285,7 +285,7 @@ static int socket_connection_accept(struct data_source *socket_ds) {
// no sigpipe // no sigpipe
socket_connection_set_no_sigpipe(fd); socket_connection_set_no_sigpipe(fd);
log_dbg("socket_connection_accept new connection %u\n", fd); log_info("socket_connection_accept new connection %u\n", fd);
connection_t * connection = socket_connection_register_new_connection(fd); connection_t * connection = socket_connection_register_new_connection(fd);
socket_connection_emit_connection_opened(connection); socket_connection_emit_connection_opened(connection);
@ -314,7 +314,7 @@ int socket_connection_create_tcp(int port){
return -1; return -1;
} }
log_dbg ("Socket created for port %u\n", port); log_info ("Socket created for port %u\n", port);
struct sockaddr_in addr; struct sockaddr_in addr;
addr.sin_family = AF_INET; addr.sin_family = AF_INET;
@ -338,7 +338,7 @@ int socket_connection_create_tcp(int port){
run_loop_add_data_source(ds); run_loop_add_data_source(ds);
log_dbg ("Server up and running ...\n"); log_info ("Server up and running ...\n");
return 0; return 0;
} }
@ -354,7 +354,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); launch_data_t tempi = launch_data_array_get_index (listening_fd_array, i);
int listening_fd = launch_data_get_fd(tempi); int listening_fd = launch_data_get_fd(tempi);
launch_data_free (tempi); launch_data_free (tempi);
log_dbg("file descriptor = %u\n", listening_fd); log_info("file descriptor = %u\n", listening_fd);
// create data_source_t for fd // create data_source_t for fd
data_source_t *ds = malloc( sizeof(data_source_t)); data_source_t *ds = malloc( sizeof(data_source_t));
@ -455,7 +455,7 @@ int socket_connection_create_unix(char *path){
return -1; return -1;
} }
log_dbg ("Socket created at %s\n", path); log_info ("Socket created at %s\n", path);
struct sockaddr_un addr; struct sockaddr_un addr;
bzero(&addr, sizeof(addr)); bzero(&addr, sizeof(addr));
@ -480,7 +480,7 @@ int socket_connection_create_unix(char *path){
run_loop_add_data_source(ds); run_loop_add_data_source(ds);
log_dbg ("Server up and running ...\n"); log_info ("Server up and running ...\n");
return 0; return 0;
} }

10
src/utils.c
View File

@ -78,13 +78,13 @@ void bt_flip_addr(bd_addr_t dest, bd_addr_t src){
void hexdump(void *data, int size){ void hexdump(void *data, int size){
int i; int i;
for (i=0; i<size;i++){ for (i=0; i<size;i++){
log_dbg("%02X ", ((uint8_t *)data)[i]); log_info("%02X ", ((uint8_t *)data)[i]);
} }
log_dbg("\n"); log_info("\n");
} }
void printUUID(uint8_t *uuid) { void printUUID(uint8_t *uuid) {
log_dbg("%02x%02x%02x%02x-%02x%02x-%02x%02x-%02x%02x-%02x%02x%02x%02x%02x%02x", log_info("%02x%02x%02x%02x-%02x%02x-%02x%02x-%02x%02x-%02x%02x%02x%02x%02x%02x",
uuid[0], uuid[1], uuid[2], uuid[3], uuid[4], uuid[5], uuid[6], uuid[7], uuid[0], uuid[1], uuid[2], uuid[3], uuid[4], uuid[5], uuid[6], uuid[7],
uuid[8], uuid[9], uuid[10], uuid[11], uuid[12], uuid[13], uuid[14], uuid[15]); uuid[8], uuid[9], uuid[10], uuid[11], uuid[12], uuid[13], uuid[14], uuid[15]);
} }
@ -92,9 +92,9 @@ void printUUID(uint8_t *uuid) {
void print_bd_addr( bd_addr_t addr){ void print_bd_addr( bd_addr_t addr){
int i; int i;
for (i=0; i<BD_ADDR_LEN-1;i++){ for (i=0; i<BD_ADDR_LEN-1;i++){
log_dbg("%02X:", ((uint8_t *)addr)[i]); log_info("%02X:", ((uint8_t *)addr)[i]);
} }
log_dbg("%02X", ((uint8_t *)addr)[i]); log_info("%02X", ((uint8_t *)addr)[i]);
} }
#ifndef EMBEDDED #ifndef EMBEDDED