espressif / esp-adf

Espressif Audio Development Framework
Other
1.55k stars 688 forks source link

BT-HFP client functions only work once or twice (pipeline_a2dp_sink_and_hfp example) (AUD-3705) #786

Open BigJk opened 2 years ago

BigJk commented 2 years ago

Enviroment

Problem

I want to use the hfp client functions like esp_hf_client_answer_call, esp_hf_client_dial. Unfortunately they stop working after 1 or 2 uses. I mapped the Buttons on the Board to the functions so I can easily try it out. This happens both in the pipeline_a2dp_sink_and_hfp example and in a own program that ONLY uses HFP. Both show different logs but same core problem.

Expected Behaviour

Actual Behaviour

Steps to reproduce

Button Code

  if ((int) msg.data == get_input_play_id()) {
      ESP_LOGI(TAG, "[ * ] ANSWER Call");

      esp_err_t err = esp_hf_client_answer_call();
      if (err != ESP_OK) {
          ESP_LOGW(TAG, "[ * ] ANSWER Failed");
      }
  } else if ((int) msg.data == get_input_set_id()) {
      ESP_LOGI(TAG, "[ * ] REJECT Call");

      esp_err_t err = esp_hf_client_reject_call();
      if (err != ESP_OK) {
          ESP_LOGW(TAG, "[ * ] REJECT Failed");
      }
  } else if ((int) msg.data == get_input_volup_id()) {
      ESP_LOGI(TAG, "[ * ] VOL 16");

      esp_err_t err = esp_hf_client_volume_update(ESP_HF_VOLUME_CONTROL_TARGET_SPK, 16);
      if (err != ESP_OK) {
          ESP_LOGW(TAG, "[ * ] VOL 16");
      }

  } else if ((int) msg.data == get_input_voldown_id()) {
      ESP_LOGI(TAG, "[ * ] VOL 0");

      esp_err_t err = esp_hf_client_volume_update(ESP_HF_VOLUME_CONTROL_TARGET_SPK, 0);
      if (err != ESP_OK) {
          ESP_LOGW(TAG, "[ * ] VOL 0 Failed");
      }
  } else if ((int) msg.data == get_input_mode_id()) {
      ESP_LOGI(TAG, "[ * ] CALL");

      esp_err_t err = esp_hf_client_dial("XXXXXX"); // removed number
      if (err != ESP_OK) {
          ESP_LOGW(TAG, "[ * ] CALL Failed");
      }
  }

Debug Logs: pipeline_a2dp_sink_and_hfp

I (2949) BLUETOOTH_EXAMPLE: [ 7 ] Listen for all pipeline events
W (18819) BT_APPL: new conn_srvc id:27, app_id:1
E (18819) BT_HF: APP HFP event: CONNECTION_STATE_EVT
E (18819) BT_HF: --connection state connected, peer feats 0x0, chld_feats 0x0
E (19069) BT_HF: APP HFP event: CALL_IND_EVT
E (19069) BT_HF: --Call indicator NO call in progress
E (19069) BT_HF: APP HFP event: CALL_SETUP_IND_EVT
E (19079) BT_HF: --Call setup indicator NONE
E (19079) BT_HF: APP HFP event: NETWORK_STATE_EVT
E (19089) BT_HF: --NETWORK STATE available
E (19089) BT_HF: APP HFP event: SIGNAL_STRENGTH_IND_EVT
E (19109) BT_HF: -- signal strength: 5
E (19109) BT_HF: APP HFP event: ROAMING_STATUS_IND_EVT
E (19109) BT_HF: --ROAMING: inactive
E (19109) BT_HF: APP HFP event: BATTERY_LEVEL_IND_EVT
E (19119) BT_HF: --battery level 1
E (19119) BT_HF: APP HFP event: CALL_HELD_IND_EVT
E (19129) BT_HF: --Call held indicator NONE held
E (19139) BT_HF: APP HFP event: CONNECTION_STATE_EVT
E (19139) BT_HF: --connection state slc_connected, peer feats 0x36f, chld_feats 0x2b
E (19149) BT_HF: APP HFP event: INBAND_RING_TONE_EVT
E (19159) BT_HF: --inband ring state Provided
I (37099) BLUETOOTH_EXAMPLE: [ * ] CALL
E (44629) BT_HF: APP HFP event: AT_RESPONSE
E (44629) BT_HF: --AT response event, code 0, cme 0
E (44689) BT_BTM: btm_sco_connected, handle 180
E (44699) BT_HF: APP HFP event: AUDIO_STATE_EVT
E (44699) BT_HF: --audio state connected_msbc
E (44699) BT_HF: bt_app_hf_client_audio_open
I (44709) BLUETOOTH_EXAMPLE: [ * ] Receive music info from Bluetooth, sample_rates=16000, bits=16, ch=1
I (44709) RSP_FILTER: reset sample rate of source data : 16000, reset channel of source data : 1
I (44759) AUDIO_ELEMENT: [i2s_w] AEL_MSG_CMD_PAUSE
I (44769) RSP_FILTER: sample rate of source data : 16000, channel of source data : 1, sample rate of destination data : 48000, channel of destination data : 2
I (44799) I2S: APLL expected frequency is 24576000 Hz, real frequency is 24575996 Hz
E (48939) BT_HCI: host_recv_pkt_cb couldn't aquire memory for inbound data buffer.

W (55159) AUDIO_EVT: There is no space in external queue
W (56319) AUDIO_EVT: There is no space in external queue
W (56419) AUDIO_EVT: There is no space in external queue
W (841879) AUDIO_EVT: There is no space in external queue
W (841979) AUDIO_EVT: There is no space in external queue
W (851699) AUDIO_EVT: There is no space in external queue
W (851819) AUDIO_EVT: There is no space in external queue

AUDIO_EVT: There is no space in external queue will be printed on button presses.

Debug Logs: Own only hfp version

I (19731) HFP_STREAM_C: --Inband ring state Provided
D (19741) BT_BTC: btc_transfer_context msg 0 10 1 0x0

D (19741) BT_BTC: btc_thread_handler msg 0 10 1 0x0

D (26651) BT_BTC: btc_transfer_context msg 0 8 0 0x3ffbd008

D (26651) BT_BTC: btc_thread_handler msg 0 8 0 0x3ffdfff0

D (26651) BT_BTC: btc_alarm_handler act 0

D (26661) BT_BTC: btc_transfer_context msg 1 7 31 0x3ffdb4f0

D (26661) BT_BTC: btc_thread_handler msg 1 7 31 0x3ffe37f4

D (26661) BT_BTC: btc_dm_upstreams_cback  ev: 31

D (26671) BT_BTC: BTA_DM_PM_MODE_CHG_EVT mode:2
I (32831) HFP_EXAMPLE: [ * ] CALL
D (32831) BT_BTC: btc_transfer_context msg 0 17 9 0x3ffca818

D (32831) BT_BTC: btc_thread_handler msg 0 17 9 0x3ffe3dc0

D (33461) BT_BTC: btc_transfer_context msg 1 7 31 0x3ffdb4f0

D (33461) BT_BTC: btc_thread_handler msg 1 7 31 0x3ffe37f4

D (33461) BT_BTC: btc_dm_upstreams_cback  ev: 31

D (33471) BT_BTC: BTA_DM_PM_MODE_CHG_EVT mode:0
D (33801) BT_BTC: btc_transfer_context msg 1 17 15 0x3ffdb520

D (33801) BT_BTC: btc_thread_handler msg 1 17 15 0x3ffdfff0

I (33801) HFP_STREAM_C: APP HFP event: AT_RESPONSE
I (33811) HFP_STREAM_C: --AT response event, code 0, cme 0
E (33921) BT_BTM: btm_sco_connected, handle 180
D (33921) BT_BTC: btc_transfer_context msg 1 17 5 0x0

D (33921) BT_BTC: btc_thread_handler msg 1 17 5 0x0

I (33921) HFP_STREAM_C: APP HFP event: AUDIO_STATE_EVT
I (33931) HFP_STREAM_C: --Audio state connected
I (33941) HFP_EXAMPLE: bt_app_hf_client_audio_open type = 0
I (37141) HFP_EXAMPLE: [ * ] REJECT Call
D (37141) BT_BTC: btc_transfer_context msg 0 17 14 0x0

I (43021) HFP_EXAMPLE: [ * ] REJECT Call
D (43021) BT_BTC: btc_transfer_context msg 0 17 14 0x0

I (44341) HFP_EXAMPLE: [ * ] REJECT Call
D (44341) BT_BTC: btc_transfer_context msg 0 17 14 0x0

I (45981) HFP_EXAMPLE: [ * ] REJECT Call
D (45981) BT_BTC: btc_transfer_context msg 0 17 14 0x0

D (48761) BT_BTC: btc_transfer_context msg 1 17 7 0x0

D (48771) BT_BTC: btc_transfer_context msg 1 17 10 0x3ffdb500

I (55461) HFP_EXAMPLE: [ * ] CALL
D (55461) BT_BTC: btc_transfer_context msg 0 17 9 0x3ffca818

D (56131) BT_BTC: btc_transfer_context msg 1 7 31 0x3ffdb4f0

I (57741) HFP_EXAMPLE: [ * ] CALL
D (57741) BT_BTC: btc_transfer_context msg 0 17 9 0x3ffca818

The first first ([ * ] CALL) works. The mobile device starts the call, but after that no call to esp_hf_client_* has any effect anymore. As you can see after the first call the btc_transfer_context keeps passing the messages, but never starts handling them (btc_thread_handler) again. This will lead to memory allocations per button press that never get free'ed again as the messages never get handled and no HFP function is ever executed again.

What might be the reason that the btc_ layer stops handling messages?

BigJk commented 2 years ago

After further testing I can confirm that the problem only appears on the "ESP32-LyraTD-MSC_A V2.2". The "ESP32-LyraT-Mini_v1.2" is working as expected.

HengYongChao commented 2 years ago

Hi @BigJk

Thanks for your report, I will check and try to reproduce the issue.