Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 5300046f authored by Ugo Yu's avatar Ugo Yu Committed by William Escande
Browse files

Add more log for Bluetooth socket 

- Enable framework logs
- Add Bluetooth socket event log into dumpsys

Bug: 263323082
Bug: 248162762
Test: atest BluetoothInstrumentationTests
Change-Id: I0cbb18f1c221eaa7353b3867629affc09f1eb0a8
(cherry picked from commit 63c3fa677e15f1224e43dda1aee9d0d262aaab69)
(cherry picked from commit b6dc15a7)
Merged-In: I0cbb18f1c221eaa7353b3867629affc09f1eb0a8
parent 281d294d

framework/java/android/bluetooth/BluetoothServerSocket.java

+1 −1
Original line number Diff line number Diff line
@@ -75,7 +75,7 @@ import java.io.IOException; 
public final class BluetoothServerSocket implements Closeable {



    private static final String TAG = "BluetoothServerSocket";

    private static final boolean DBG = false;

    private static final boolean DBG = Log.isLoggable(TAG, Log.DEBUG);

    @UnsupportedAppUsage(publicAlternatives = "Use public {@link BluetoothServerSocket} API "

            + "instead.")

    /*package*/ final BluetoothSocket mSocket;

framework/java/android/bluetooth/BluetoothSocket.java

+3 −2
Original line number Diff line number Diff line
@@ -285,7 +285,7 @@ public final class BluetoothSocket implements Closeable { 
        BluetoothSocket as = new BluetoothSocket(this);

        as.mSocketState = SocketState.CONNECTED;

        FileDescriptor[] fds = mSocket.getAncillaryFileDescriptors();

        if (DBG) Log.d(TAG, "socket fd passed by stack fds: " + Arrays.toString(fds));

        if (DBG) Log.d(TAG, "acceptSocket: socket fd passed by stack fds:" + Arrays.toString(fds));

        if (fds == null || fds.length != 1) {

            Log.e(TAG, "socket fd passed from stack failed, fds: " + Arrays.toString(fds));

            as.close();
@@ -450,6 +450,7 @@ public final class BluetoothSocket implements Closeable { 
                    throw new IOException("bt socket closed");

                }

                mSocketState = SocketState.CONNECTED;

                if (DBG) Log.d(TAG, "connect(), socket connected");

            }

        } catch (RemoteException e) {

            Log.e(TAG, e.toString() + "\n" + Log.getStackTraceString(new Throwable()));
@@ -536,8 +537,8 @@ public final class BluetoothSocket implements Closeable { 
        if (mSocketState != SocketState.LISTENING) {

            throw new IOException("bt socket is not in listen state");

        }

        Log.d(TAG, "accept(), timeout (ms):" + timeout);

        if (timeout > 0) {

            Log.d(TAG, "accept() set timeout (ms):" + timeout);

            mSocket.setSoTimeout(timeout);

        }

        String RemoteAddr = waitSocketSignal(mSocketIS);

system/btif/include/btif_sock.h

+25 −1
Original line number Diff line number Diff line
@@ -18,11 +18,35 @@ 


#pragma once



#include <hardware/bt_sock.h>



#include "btif_uid.h"

#include "types/raw_address.h"



#include <hardware/bt_sock.h>

enum {

  SOCKET_CONNECTION_STATE_UNKNOWN,

  // Socket acts as a server waiting for connection

  SOCKET_CONNECTION_STATE_LISTENING,

  // Socket acts as a client trying to connect

  SOCKET_CONNECTION_STATE_CONNECTING,

  // Socket is connected

  SOCKET_CONNECTION_STATE_CONNECTED,

  // Socket tries to disconnect from remote

  SOCKET_CONNECTION_STATE_DISCONNECTING,

  // This socket is closed

  SOCKET_CONNECTION_STATE_DISCONNECTED,

};



enum {

  SOCKET_ROLE_UNKNOWN,

  SOCKET_ROLE_LISTEN,

  SOCKET_ROLE_CONNECTION,

};



const btsock_interface_t* btif_sock_get_interface(void);



bt_status_t btif_sock_init(uid_set_t* uid_set);

void btif_sock_cleanup(void);



void btif_sock_connection_logger(int state, int role, const RawAddress& addr);

void btif_sock_dump(int fd);

system/btif/src/bluetooth.cc

+2 −0
Original line number Diff line number Diff line
@@ -58,6 +58,7 @@ 
#include "bta/include/bta_le_audio_broadcaster_api.h"

#include "bta/include/bta_vc_api.h"

#include "btif/avrcp/avrcp_service.h"

#include "btif/include/btif_sock.h"

#include "btif/include/stack_manager.h"

#include "btif_a2dp.h"

#include "btif_activity_attribution.h"
@@ -434,6 +435,7 @@ static void dump(int fd, const char** arguments) { 
  btif_debug_av_dump(fd);

  bta_debug_av_dump(fd);

  stack_debug_avdtp_api_dump(fd);

  btif_sock_dump(fd);

  bluetooth::avrcp::AvrcpService::DebugDump(fd);

  btif_debug_config_dump(fd);

  BTA_HfClientDumpStatistics(fd);

system/btif/src/btif_sock.cc

+111 −0
Original line number Diff line number Diff line
@@ -18,10 +18,13 @@ 


#define LOG_TAG "bt_btif_sock"



#include "btif/include/btif_sock.h"



#include <base/logging.h>

#include <frameworks/proto_logging/stats/enums/bluetooth/enums.pb.h>

#include <hardware/bluetooth.h>

#include <hardware/bt_sock.h>

#include <time.h>



#include <atomic>
@@ -60,6 +63,22 @@ static void btsock_signaled(int fd, int type, int flags, uint32_t user_id); 
static std::atomic_int thread_handle{-1};

static thread_t* thread;



#define SOCK_LOGGER_SIZE_MAX 16



struct SockConnectionEvent {

  bool used;

  RawAddress addr;

  int state;

  int role;

  struct timespec timestamp;



  void dump(const int fd);

};



static std::atomic<uint8_t> logger_index;



static SockConnectionEvent connection_logger[SOCK_LOGGER_SIZE_MAX];



const btsock_interface_t* btif_sock_get_interface(void) {

  static btsock_interface_t interface = {

      sizeof(interface), btsock_listen, /* listen */
@@ -131,6 +150,88 @@ void btif_sock_cleanup(void) { 
  thread = NULL;

}



void btif_sock_connection_logger(int state, int role, const RawAddress& addr) {

  LOG_INFO("address=%s, role=%d, state=%d", addr.ToString().c_str(), state,

           role);



  uint8_t index = logger_index++ % SOCK_LOGGER_SIZE_MAX;



  connection_logger[index] = {

      .used = true,

      .addr = addr,

      .state = state,

      .role = role,

  };

  clock_gettime(CLOCK_REALTIME, &connection_logger[index].timestamp);

}



void btif_sock_dump(int fd) {

  dprintf(fd, "\nSocket Events: \n");

  dprintf(fd, "  Time        \tAddress          \tState             \tRole\n");



  const uint8_t head = logger_index.load() % SOCK_LOGGER_SIZE_MAX;



  uint8_t index = head;

  do {

    connection_logger[index].dump(fd);



    index++;

    index %= SOCK_LOGGER_SIZE_MAX;

  } while (index != head);

  dprintf(fd, "\n");

}



void SockConnectionEvent::dump(const int fd) {

  if (!used) {

    return;

  }



  char eventtime[20];

  char temptime[20];

  struct tm* tstamp = localtime(&timestamp.tv_sec);

  strftime(temptime, sizeof(temptime), "%H:%M:%S", tstamp);

  snprintf(eventtime, sizeof(eventtime), "%s.%03ld", temptime,

           timestamp.tv_nsec / 1000000);



  const char* str_state;

  switch (state) {

    case SOCKET_CONNECTION_STATE_LISTENING:

      str_state = "STATE_LISTENING";

      break;

    case SOCKET_CONNECTION_STATE_CONNECTING:

      str_state = "STATE_CONNECTING";

      break;

    case SOCKET_CONNECTION_STATE_CONNECTED:

      str_state = "STATE_CONNECTED";

      break;

    case SOCKET_CONNECTION_STATE_DISCONNECTING:

      str_state = "STATE_DISCONNECTING";

      break;

    case SOCKET_CONNECTION_STATE_DISCONNECTED:

      str_state = "STATE_DISCONNECTED";

      break;

    default:

      str_state = "STATE_UNKNOWN";

      break;

  }



  const char* str_role;

  switch (role) {

    case SOCKET_ROLE_LISTEN:

      str_role = "ROLE_LISTEN";

      break;

    case SOCKET_ROLE_CONNECTION:

      str_role = "ROLE_CONNECTION";

      break;

    default:

      str_role = "ROLE_UNKNOWN";

      break;

  }



  dprintf(fd, "  %s\t%s\t%s   \t%s\n", eventtime,

          addr.ToString().c_str(), str_state, str_role);

}



static bt_status_t btsock_listen(btsock_type_t type, const char* service_name,

                                 const Uuid* service_uuid, int channel,

                                 int* sock_fd, int flags, int app_uid) {
@@ -142,6 +243,8 @@ static bt_status_t btsock_listen(btsock_type_t type, const char* service_name, 
  bt_status_t status = BT_STATUS_FAIL;

  int original_channel = channel;



  btif_sock_connection_logger(SOCKET_CONNECTION_STATE_LISTENING,

                              SOCKET_ROLE_LISTEN, RawAddress::kEmpty);

  log_socket_connection_state(RawAddress::kEmpty, 0, type,

                              android::bluetooth::SocketConnectionstateEnum::

                                  SOCKET_CONNECTION_STATE_LISTENING,
@@ -183,6 +286,8 @@ static bt_status_t btsock_listen(btsock_type_t type, const char* service_name, 
      break;

  }

  if (status != BT_STATUS_SUCCESS) {

    btif_sock_connection_logger(SOCKET_CONNECTION_STATE_DISCONNECTED,

                                SOCKET_ROLE_LISTEN, RawAddress::kEmpty);

    log_socket_connection_state(RawAddress::kEmpty, 0, type,

                                android::bluetooth::SocketConnectionstateEnum::

                                    SOCKET_CONNECTION_STATE_DISCONNECTED,
@@ -198,9 +303,13 @@ static bt_status_t btsock_connect(const RawAddress* bd_addr, btsock_type_t type, 
  CHECK(bd_addr != NULL);

  CHECK(sock_fd != NULL);



  LOG_INFO("%s", __func__);



  *sock_fd = INVALID_FD;

  bt_status_t status = BT_STATUS_FAIL;



  btif_sock_connection_logger(SOCKET_CONNECTION_STATE_CONNECTING,

                              SOCKET_ROLE_CONNECTION, *bd_addr);

  log_socket_connection_state(*bd_addr, 0, type,

                              android::bluetooth::SocketConnectionstateEnum::

                                  SOCKET_CONNECTION_STATE_CONNECTING,
@@ -245,6 +354,8 @@ static bt_status_t btsock_connect(const RawAddress* bd_addr, btsock_type_t type, 
      break;

  }

  if (status != BT_STATUS_SUCCESS) {

    btif_sock_connection_logger(SOCKET_CONNECTION_STATE_DISCONNECTED,

                                SOCKET_ROLE_CONNECTION, *bd_addr);

    log_socket_connection_state(*bd_addr, 0, type,

                                android::bluetooth::SocketConnectionstateEnum::

                                    SOCKET_CONNECTION_STATE_DISCONNECTED,