Source changes

[pschatzmann]

Merge update to latest source implementation

[jmsunseri]

Did this change how on_connection_state_changed works?

[pschatzmann]

No, not that I am aware of..

[jmsunseri]

oid on_connection_state_changed(esp_a2d_connection_state_t state, void *)
{
  if (state == esp_a2d_connection_state_t::ESP_A2D_CONNECTION_STATE_CONNECTED)
  {
  ...
  }
  else if (state == esp_a2d_connection_state_t::ESP_A2D_CONNECTION_STATE_DISCONNECTED)
  {
    ...
  }
}

these code branches don't seem to be getting hit anymore but my BT speaker seems to be connected to the ESP32. Maybe I'm just slowly going crazy.

[pschatzmann]

It seems that the call to process_user_state_callbacks got lost: I just committed a correction....

[jmsunseri]

if I knew cpp any better i'd add unit tests for the functions i needed.

[jmsunseri]

I'm still not seeing that code get hit on connect / disconnect

[pschatzmann]

Did you activate the logging and try to figure out what's happening ? Did you double check if your actual code contains my correction ?

[jmsunseri]

Just learned about setting the DEBUG level in the platformio file. Thanks for the nudge.

Yes process_user_state_callbacks(event, param); is now on line 667 of the BluetoothA2DPSource.cpp file.

Here are the logs from the debug session

--- Terminal on /dev/ttyUSB1 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
[     5][D][BluetoothA2DPSource.cpp:126] BluetoothA2`␆5��ɍ��): [BT_API] BluetoothA2DPSource, 
[    10][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
starting I2S-ADC...
bluetooth device name Gameboy-94C
[   526][I][BluetoothA2DPCommon.h:150] set_volume(): [BT_AV] set_volume: 255
[   527][D][BluetoothA2DPSource.cpp:167] start(): [BT_API] start, 
[   530][D][BluetoothA2DPSource.cpp:186] start_raw(): [BT_API] start_raw, 
[   537][D][BluetoothA2DPCommon.cpp:152] get_last_connection(): [BT_AV] get_last_connection
[   546][D][BluetoothA2DPCommon.cpp:175] get_last_connection(): [BT_AV] => f4:4e:fc:b4:35:d5
[   553][I][BluetoothA2DPSource.cpp:251] reset_last_connection(): [BT_API] reset_last_connection, 
[   562][D][BluetoothA2DPSource.cpp:253] reset_last_connection(): [BT_API] last connection f4:4e:fc:b4:35:d5, 
[   572][I][BluetoothA2DPCommon.cpp:67] disconnect(): [BT_AV] disconect a2d: f4:4e:fc:b4:35:d5
[  3111][D][BluetoothA2DPSource.cpp:338] bt_app_task_start_up(): [BT_AV] bt_app_task_start_up
[  3112][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0x0, param len 0
[  3119][D][BluetoothA2DPSource.cpp:319] bt_app_task_handler(): [BT_API] bt_app_task_handler, signal: 0x1, event: 0x0
[  3129][D][BluetoothA2DPSource.cpp:565] bt_av_hdl_stack_evt(): [BT_AV] bt_av_hdl_stack_evt event: 0
[  3139][I][BluetoothA2DPCommon.cpp:289] set_scan_mode_connectable(): [BT_AV] set_scan_mode_connectable false
[  3148][I][BluetoothA2DPSource.cpp:601] bt_av_hdl_stack_evt(): [BT_AV] Starting device discovery...
[  3155][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0x4, param len 16
[  3167][D][BluetoothA2DPSource.cpp:319] bt_app_task_handler(): [BT_API] bt_app_task_handler, signal: 0x1, event: 0x4
[  3167][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 10
[  3178][I][BluetoothA2DPSource.cpp:666] bt_app_av_sm_hdlr(): [BT_AV] bt_app_av_sm_hdlr state APP_AV_STATE_DISCOVERING, evt 0x4
[  3186][I][BluetoothA2DPSource.cpp:557] bt_app_gap_callback(): [BT_AV] event: 10
[  3197][D][BluetoothA2DPSource.cpp:633] process_user_state_callbacks(): [BT_AV] process_user_state_callbacks
[  3205][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 10
[  3223][I][BluetoothA2DPSource.cpp:557] bt_app_gap_callback(): [BT_AV] event: 10
[  3231][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 10
[  3239][I][BluetoothA2DPSource.cpp:557] bt_app_gap_callback(): [BT_AV] event: 10
[  3246][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 10
[  3255][I][BluetoothA2DPSource.cpp:557] bt_app_gap_callback(): [BT_AV] event: 10
[  3267][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 1
[  3271][I][BluetoothA2DPSource.cpp:487] bt_app_gap_callback(): [BT_AV] Discovery started.
[  9098][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 0
[  9099][I][BluetoothA2DPSource.cpp:401] filter_inquiry_scan_result(): [BT_AV] Scanned device: f4:4e:fc:b4:35:d5
[  9106][I][BluetoothA2DPSource.cpp:407] filter_inquiry_scan_result(): [BT_AV] --Class of Device: 0x240404
[  9115][I][BluetoothA2DPSource.cpp:411] filter_inquiry_scan_result(): [BT_AV] --RSSI: -30
[  9123][I][BluetoothA2DPSource.cpp:431] filter_inquiry_scan_result(): [BT_AV] --Compatiblity: Compatible
[  9133][I][BluetoothA2DPSource.cpp:433] filter_inquiry_scan_result(): [BT_AV] --Name: Tribit StormBox Micro 2
available ssid: Tribit StormBox Micro 2 strength: -30
[  9153][I][BluetoothA2DPSource.cpp:454] filter_inquiry_scan_result(): [BT_AV] --Result: Target device found
[  9157][D][BluetoothA2DPCommon.cpp:180] set_last_connection(): [BT_AV] set_last_connection: f4:4e:fc:b4:35:d5
[  9166][D][BluetoothA2DPCommon.cpp:184] set_last_connection(): [BT_AV] no change!
[  9174][I][BluetoothA2DPSource.cpp:458] filter_inquiry_scan_result(): [BT_AV] Cancel device discovery ...
[  9183][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 0
[  9192][I][BluetoothA2DPSource.cpp:401] filter_inquiry_scan_result(): [BT_AV] Scanned device: f4:4e:fc:b4:35:d5
[  9201][I][BluetoothA2DPSource.cpp:407] filter_inquiry_scan_result(): [BT_AV] --Class of Device: 0x240404
[  9211][I][BluetoothA2DPSource.cpp:411] filter_inquiry_scan_result(): [BT_AV] --RSSI: -30
[  9219][I][BluetoothA2DPSource.cpp:431] filter_inquiry_scan_result(): [BT_AV] --Compatiblity: Compatible
[  9228][I][BluetoothA2DPSource.cpp:433] filter_inquiry_scan_result(): [BT_AV] --Name: Tribit StormBox Micro 2
available ssid: Tribit StormBox Micro 2 strength: -30
[  9248][I][BluetoothA2DPSource.cpp:454] filter_inquiry_scan_result(): [BT_AV] --Result: Target device found
[  9252][D][BluetoothA2DPCommon.cpp:180] set_last_connection(): [BT_AV] set_last_connection: f4:4e:fc:b4:35:d5
[  9262][D][BluetoothA2DPCommon.cpp:184] set_last_connection(): [BT_AV] no change!
[  9269][I][BluetoothA2DPSource.cpp:458] filter_inquiry_scan_result(): [BT_AV] Cancel device discovery ...
[  9282][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 1
[  9287][I][BluetoothA2DPSource.cpp:478] bt_app_gap_callback(): [BT_AV] Device discovery stopped.
[  9296][I][BluetoothA2DPSource.cpp:479] bt_app_gap_callback(): [BT_AV] a2dp connecting to peer: Tribit StormBox Micro 2
[  9306][I][BluetoothA2DPSource.h:257] esp_a2d_connect(): [BT_AV] a2dp connecting to: f4:4e:fc:b4:35:d5
[  9316][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 1
[  9324][I][BluetoothA2DPSource.cpp:483] bt_app_gap_callback(): [BT_AV] Device discovery failed, continue to discover...
[  9346][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0x0, param len 16
[  9347][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 1
[  9355][I][BluetoothA2DPSource.cpp:487] bt_app_gap_callback(): [BT_AV] Discovery started.
[  9573][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 16
[  9574][I][BluetoothA2DPSource.cpp:548] bt_app_gap_callback(): [BT_AV] ESP_BT_GAP_ACL_CONN_CMPL_STAT_EVT
[ 10018][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0x0, param len 16
[ 10259][D][BluetoothA2DPSource.cpp:900] bt_app_rc_ct_cb(): [RCCT] bt_app_rc_ct_cb evt 0
[ 10260][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0x0, param len 12
[ 10267][D][BluetoothA2DPSource.cpp:900] bt_app_rc_ct_cb(): [RCCT] bt_app_rc_ct_cb evt 5
[ 10274][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0x5, param len 12
[ 13157][D][BluetoothA2DPSource.cpp:269] bt_app_work_dispatch(): [BT_API] bt_app_work_dispatch event 0xff00, param len 0
[ 17248][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 13
[ 17249][I][BluetoothA2DPSource.cpp:553] bt_app_gap_callback(): [BT_AV] ESP_BT_GAP_MODE_CHG_EVT mode:0
[ 22157][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 1
[ 22157][I][BluetoothA2DPSource.cpp:483] bt_app_gap_callback(): [BT_AV] Device discovery failed, continue to discover...
[ 22169][D][BluetoothA2DPSource.cpp:468] bt_app_gap_callback(): [BT_AV] bt_app_gap_callback evt 1
[ 22174][I][BluetoothA2DPSource.cpp:487] bt_app_gap_callback(): [BT_AV] Discovery started.

I added a simple line to my app which should have logged out the connection state change but apparently did not do so.

void on_connection_state_changed(esp_a2d_connection_state_t state, void *)
{
  Serial.print("connection state changed ");
  Serial.println(a2dp_source.to_str(state));
  ...
 }

void setup () {
 ...
 a2dp_source.set_on_connection_state_changed(on_connection_state_changed);
 ...

[pschatzmann]

I think you are wrong in your analyses: it is actually called: you just ignore it by having no final else case. Maybe you better use some switch with a default case. Look at the log and you will find a line with bt_app_av_sm_hdlr!

You don't get any ESP_A2D_CONNECTION_STATE_CONNECTED in your log because it is not connecting...

[jmsunseri]

There is no if else statement wrapping this log call. The full function is as follows

void on_connection_state_changed(esp_a2d_connection_state_t state, void *)
{
  Serial.print("connection state changed ");
  Serial.println(a2dp_source.to_str(state));
  if (state == esp_a2d_connection_state_t::ESP_A2D_CONNECTION_STATE_CONNECTED)
  {
    shutdown_ms = 0;
   //  muting internal gameboy speaker
    muteSpeaker();
  }
  else if (state == esp_a2d_connection_state_t::ESP_A2D_CONNECTION_STATE_DISCONNECTED)
  {
    shutdown_ms = millis() + 1000 * 60 * minutes;
   //  turning on internal gameboy speaker
    turnOnSpeaker();
  }
}

The BT device is indeed connected. If i rub my fingers across pin 34 a sound does come out of the speakers.

[pschatzmann]

The log that you sent me ends with [ 22174][I][BluetoothA2DPSource.cpp:487] bt_app_gap_callback(): [BT_AV] Discovery started. So it is still discovering and has not connected.

So I let you analyse your full log yourself.

Try to find out why you don't get process_user_state_callbacks() called right after it. My guess would be that you are still executing the old code...

[jmsunseri]

are you certain that bt_app_av_sm_hdlr is still being called on connection / disconnection? I see the following line multiple times in my log files

[  3175][I][BluetoothA2DPSource.cpp:774] bt_app_av_sm_hdlr(): [BT_AV] bt_app_av_sm_hdlr state APP_AV_STATE_DISCOVERING, evt 0x4

but I don't see any corresponding logs for other states.

[pschatzmann]

No, if I remember right this functionality has been tested on the sink only. So the logic might need to be extended to support the source properly

[jmsunseri]

I thought I had a working code prototype based on this stuff last week. It was a bit noisy in that I would get multiple connection events for a single connect etc but it seemed to work. Let me see if I can see what happened or fix it.

[pschatzmann]

So you maybe try with the last released version and file an issue. But first did you find out process_user_state_callbacks is not called. I would not trust the orignal reported state in the log too much...

[jmsunseri]

I think I see something wrong. I added the following lines to Source.cpp

  void BluetoothA2DPSource::process_user_state_callbacks(uint16_t event,
                                                       void *param)
{
  ESP_LOGD(BT_AV_TAG, "JUSTIN JUSTIN JUSTIN event %d, enum %d", event, ESP_A2D_CONNECTION_STATE_EVT);
  ESP_LOGD(BT_AV_TAG, "%s", __func__);

And I got the following log output

[  3186][I][BluetoothA2DPSource.cpp:780] bt_app_av_sm_hdlr(): [BT_AV] bt_app_av_sm_hdlr state APP_AV_STATE_DISCOVERING, evt 0x4
[  3195][I][BluetoothA2DPSource.cpp:651] bt_app_gap_callback(): [BT_AV] event: 10
[  3206][D][BluetoothA2DPSource.cpp:737] process_user_state_callbacks(): [BT_AV] JUSTIN JUSTIN JUSTIN event 4, enum 0

The event doesn't match up with the switch case is expecting. I couldn't find where ESP_A2D_CONNECTION_STATE_EVT was defined. is this a problem with with my development environment?

[pschatzmann]

I don't understand you: Why are us pasting these log lines and the most important ones you just leave away? I just made a test and confirm that it works like a charm!

09:54:21.755 -> [  6582][I][BluetoothA2DPSource.cpp:658] bt_app_av_sm_hdlr(): [BT_AV] bt_app_av_sm_hdlr state APP_AV_STATE_CONNECTING, evt 0x0
09:54:21.755 -> [  6593][D][BluetoothA2DPSource.cpp:625] process_user_state_callbacks(): [BT_AV] process_user_state_callbacks
09:54:21.787 -> [  6602][D][BluetoothA2DPSource.cpp:634] process_user_state_callbacks(): [BT_AV] process_user_state_callbacks ESP_A2D_CONNECTION_STATE_EVT: Connecting
09:54:21.787 -> Connecting

I have added a new example for this case

Please note that the state reported by bt_app_av_sm_hdlr is the source processing state that is used to determine the valid state changes and not the target state and this is not identical with the esp_a2d_connection_state_t!

[jmsunseri]

Thank you for taking all this time to educate me. I really do appreciate it. I think the solution was to add a delay(1000) in my loop method. After adding that in the event handler fired exactly as expected.