search

twilio / twilio-voice-ios

Programmable Voice SDK by Twilio
https://www.twilio.com/voice
38 stars 14 forks source link

Call does not disconnect #61

Closed MrHertal closed 4 years ago

MrHertal commented 4 years ago

Description

I am unable to properly disconnect an incoming call after answering it. When I call the method disconnect, the delegate method callDidDisconnect is triggered without error.

But when I check the call in the Twilio console, it still has the Answered status and is only completed once the remote hangup.

Steps to Reproduce

  1. Accept an incoming call
  2. Disconnect call in the endCall delegate as in the quickstart project: https://github.com/twilio/voice-quickstart-ios/blob/d7136e6360f9f9b7b86f8452a96bb263c5c43438/SwiftVoiceQuickstart/ViewController.swift#L620
  3. callDidDisconnect is triggered without error but call has Answered status in the Twilio console

Reproduces How Often

Call is not disconnected on every incoming calls, but it works well on outgoing calls.

Logs

Here are the logs from Mac console when I disconnect the call.

par défaut  12:02:07.974345+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> resuming, timeouts(60.0, 604800.0) QOS(0x15) Voucher (null)
par défaut  12:02:07.975600+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [6305CC23-CAFB-4FD7-BA7E-D043CBAE0DBC] (reporting strategy default)> on Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> was not selected for reporting
par défaut  12:02:07.978025+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:07.978809+0200    TwilioVoiceExample  Connection 11: enabling TLS
par défaut  12:02:07.979324+0200    TwilioVoiceExample  Connection 11: starting, TC(0x0)
par défaut  12:02:07.979531+0200    TwilioVoiceExample  [C11 800E5644-2577-4022-9212-4B7314CB4C22 firebaselogging-pa.googleapis.com:443 tcp, url hash: 83d44504, tls, context: com.apple.CFNetwork.NSURLSession.{F350D5AA-1CCC-483E-BC4E-CF1CE3672AF7}{(null)}{Y}{2}, proc: ABB1DE84-50E9-3EE4-9E24-EEA2C385F750] start
par défaut  12:02:07.979739+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 initial path ((null))] event: path:start @0.000s
par défaut  12:02:07.980230+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 waiting path (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: path:satisfied @0.000s, uuid: 816C608B-D57F-47AE-B476-A0ED05B93435
par défaut  12:02:07.980612+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: resolver:start_dns @0.001s
par défaut  12:02:07.980822+0200    TwilioVoiceExample  nw_connection_report_state_with_handler_on_nw_queue [C11] reporting state preparing
par défaut  12:02:07.981262+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> setting up Connection 11
par défaut  12:02:07.982330+0200    mDNSResponder   [R5884] getaddrinfo start -- flags: 0xC000D000, ifindex: 0, protocols: 0, hostname: <mask.hash: '3yOGX762fma+wFANZuW5Jw=='>, options: {}, client pid: 612 (TwilioVoiceExam)
par défaut  12:02:07.985395+0200    mDNSResponder   [R5884] getaddrinfo stop -- hostname: <mask.hash: '3yOGX762fma+wFANZuW5Jw=='>, client pid: 612 (TwilioVoiceExam)
par défaut  12:02:07.985976+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: resolver:receive_dns @0.007s
par défaut  12:02:07.986711+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 initial path ((null))] event: path:start @0.007s
par défaut  12:02:07.988138+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 waiting path (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: path:satisfied @0.008s, uuid: 660AEEED-E9D8-44F1-A0C4-FD3FAD543054
par défaut  12:02:07.988495+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 in_progress channel-flow (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: flow:start_nexus @0.008s
par défaut  12:02:07.991170+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 in_progress channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] event: flow:receive_nexus @0.011s
par défaut  12:02:07.993279+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 in_progress channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] event: flow:start_connect @0.013s
par défaut  12:02:07.993876+0200    TwilioVoiceExample  tcp_output [C11.1:3] flags=[S] seq=3613470434, ack=0, win=65535 state=SYN_SENT rcv_nxt=0, snd_una=3613470434
par défaut  12:02:07.996134+0200    symptomsd   SymptomAnalytics ServiceImpl: FAE perform query for powerlogHelperd (pid 613) on LiveUsage predicate hasProcess.procName == $targetname sort (null) actions {
    "hasProcess.procName" = copyRelationship;
    nameChain = "com.XXX.TwilioVoiceExample";
    refreshUsage = refreshUsage;
    "hasProcess.firstTimeStamp" = copyRelationship;
    "hasProcess.bundleName" = copyRelationship;
    "<null>" = "<null>";
}
par défaut  12:02:07.998794+0200    TwilioVoiceExample  tcp_input [C11.1:3] flags=[S.] seq=3685954482, ack=3613470435, win=65535 state=SYN_SENT rcv_nxt=0, snd_una=3613470434
par défaut  12:02:07.998975+0200    TwilioVoiceExample  nw_flow_connected [C11.1 2a00:1450:4007:812::200a.443 in_progress channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] Transport protocol connected
par défaut  12:02:07.999258+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 in_progress channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] event: flow:finish_transport @0.019s
par défaut  12:02:07.999377+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 in_progress resolver (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: flow:finish_transport @0.019s
par défaut  12:02:08.001949+0200    TwilioVoiceExample  boringssl_session_apply_protocol_options_for_transport_block_invoke(1689) [C11.1:2][0x106b40db0] TLS configured [min_version(0x0301) max_version(0x0304) name(firebaselogging-pa.googleapis.com) tickets(false) false_start(false) enforce_ev(false) enforce_ats(false)]
par défaut  12:02:08.002283+0200    TwilioVoiceExample  boringssl_context_info_handler(1821) [C11.1:2][0x106b40db0] Client handshake started
par défaut  12:02:08.002576+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS client enter_early_data
par défaut  12:02:08.004343+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS client read_server_hello
par défaut  12:02:08.008615+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807795422/56974929, WiFi delta_in/delta_out: 120/823, Cell in/out: 62873/3158532, Cell delta_in/delta_out: 0/0, RNF: 0, subscriber tag: 0
par défaut  12:02:08.010202+0200    symptomsd   entry: Thu Oct  8 14:49:31 2020          com.XXX.TwilioVoiceExample (bundle)     807795422     56974929        62873      3158532   0   1
par défaut  12:02:08.017829+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_hello_retry_request
par défaut  12:02:08.018232+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_server_hello
par défaut  12:02:08.018462+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_encrypted_extensions
par défaut  12:02:08.019495+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_certificate_request
par défaut  12:02:08.019635+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_server_certificate
par défaut  12:02:08.019706+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_server_certificate_verify
par défaut  12:02:08.020153+0200    TwilioVoiceExample  boringssl_context_evaluate_trust_async(1510) [C11.1:2][0x106b40db0] Performing external trust evaluation
par défaut  12:02:08.020236+0200    TwilioVoiceExample  boringssl_context_evaluate_trust_async_external(1495) [C11.1:2][0x106b40db0] Asyncing for external verify block
par défaut  12:02:08.020476+0200    TwilioVoiceExample  Connection 11: asked to evaluate TLS Trust
par défaut  12:02:08.020596+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> auth completion disp=1 cred=0x0
par défaut  12:02:08.027020+0200    TwilioVoiceExample  Connection 11: TLS Trust result 0
par défaut  12:02:08.027220+0200    TwilioVoiceExample  boringssl_context_evaluate_trust_async_external_block_invoke_3(1451) [C11.1:2][0x106b40db0] Returning from external verify block with result: true
par défaut  12:02:08.027360+0200    TwilioVoiceExample  boringssl_context_certificate_verify_callback(1609) [C11.1:2][0x106b40db0] Certificate verification result: OK
par défaut  12:02:08.027669+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client read_server_finished
par défaut  12:02:08.027899+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client send_end_of_early_data
par défaut  12:02:08.028022+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client send_client_certificate
par défaut  12:02:08.028186+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client complete_second_flight
par défaut  12:02:08.028415+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS 1.3 client done
par défaut  12:02:08.028692+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS client finish_client_handshake
par défaut  12:02:08.028819+0200    TwilioVoiceExample  boringssl_context_info_handler(1836) [C11.1:2][0x106b40db0] Client handshake state: TLS client done
par défaut  12:02:08.028913+0200    TwilioVoiceExample  boringssl_context_info_handler(1826) [C11.1:2][0x106b40db0] Client handshake done
par défaut  12:02:08.029409+0200    TwilioVoiceExample  nw_protocol_boringssl_signal_connected(728) [C11.1:2][0x106b40db0] TLS connected [version(0x0304) ciphersuite(TLS_AES_128_GCM_SHA256) group(0x001d) signature_alg(0x0403) alpn(h2) resumed(0) offered_ticket(0) false_started(0) ocsp_received(0) sct_received(0) connect_time(30ms) flight_time(18ms) rtt(9ms) write_stalls(0) read_stalls(6)]
par défaut  12:02:08.029707+0200    TwilioVoiceExample  nw_flow_connected [C11.1 2a00:1450:4007:812::200a.443 in_progress channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] Output protocol connected
par défaut  12:02:08.030277+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 ready channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] event: flow:finish_connect @0.050s
par défaut  12:02:08.030489+0200    TwilioVoiceExample  nw_connection_report_state_with_handler_on_nw_queue [C11] reporting state ready
par défaut  12:02:08.030632+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 ready resolver (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: flow:finish_connect @0.050s
par défaut  12:02:08.030761+0200    TwilioVoiceExample  [C11.1 2a00:1450:4007:812::200a.443 ready channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns)] event: flow:changed_viability @0.050s
par défaut  12:02:08.030848+0200    TwilioVoiceExample  [C11 firebaselogging-pa.googleapis.com:443 ready resolver (satisfied (Path is satisfied), interface: en0, ipv4, ipv6, dns)] event: flow:changed_viability @0.050s
par défaut  12:02:08.030946+0200    TwilioVoiceExample  Connection 11: connected successfully
par défaut  12:02:08.031053+0200    TwilioVoiceExample  Connection 11: TLS handshake complete
par défaut  12:02:08.031136+0200    TwilioVoiceExample  Connection 11: ready C(N) E(N)
par défaut  12:02:08.031682+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> now using Connection 11
par défaut  12:02:08.032001+0200    TwilioVoiceExample  Connection 11: received viability advisory(Y)
par défaut  12:02:08.032078+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> sent request, body S 358
par défaut  12:02:08.047624+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> received response, status 200 content K
par défaut  12:02:08.048041+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> done using Connection 11
par défaut  12:02:08.048679+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> response ended
par défaut  12:02:08.048857+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> summary for task success {transaction_duration_ms=72, response_status=200, connection=11, protocol="h2", domain_lookup_duration_ms=6, connect_duration_ms=37, secure_connection_duration_ms=30, request_start_ms=53, request_duration_ms=0, response_start_ms=71, response_duration_ms=0, request_bytes=548, response_bytes=606, cache_hit=1}
par défaut  12:02:08.049221+0200    TwilioVoiceExample  Task <0C8E112A-237D-4CDE-99C7-EE4A714864C2>.<1> finished successfully
par défaut  12:02:08.049947+0200    runningboardd   Invalidating assertion 32-612-2506 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [application<com.XXX.TwilioVoiceExample>:612]
par défaut  12:02:08.050906+0200    runningboardd   Acquiring assertion targeting [application<com.XXX.TwilioVoiceExample>:612] from originator [application<com.XXX.TwilioVoiceExample>:612] with description <RBSAssertionDescriptor| "com.apple.CFNetwork.StorageDB" ID:32-612-2507 target:612 attributes:[
    <RBSDomainAttribute| domain:"com.apple.common" name:"FinishTaskUninterruptable" sourceEnvironment:"(null)">,
    <RBSAcquisitionCompletionAttribute| policy:AfterApplication>
    ]>
par défaut  12:02:08.051270+0200    runningboardd   Assertion 32-612-2507 (target:[application<com.XXX.TwilioVoiceExample>:612]) will be created as inactive as start-time-defining assertions exist
par défaut  12:02:08.052571+0200    runningboardd   Finished acquiring assertion 32-612-2507 (target:[application<com.XXX.TwilioVoiceExample>:612])
par défaut  12:02:08.680244+0200    TwilioVoiceExample  tcp_input [C1:2] flags=[F.] seq=4015111311, ack=3463867618, win=2055 state=ESTABLISHED rcv_nxt=4015111311, snd_una=3463867618
par défaut  12:02:08.680646+0200    TwilioVoiceExample  nw_protocol_tcp_log_summary [C1:2] 
    [3FFA3F9C-CBB2-4152-858B-E82AB9039E7C 192.168.1.40:55096<->192.168.1.16:8081]
    Init: 1, Conn_Time: 84.278ms, SYNs: 1, WR_T: 0/0, RD_T: 0/0, TFO: 0/0/0, ECN: 0/0/0, TS: 1
    rtt_cache: kernel, rtt_upd: 2, rtt: 16.500ms, rtt_var: 21.625ms rtt_nc: 74.125ms, rtt_var_nc: 51.250ms
    ACKs-compressed: 0, ACKs delayed: 0 delayed ACKs sent: 0
par défaut  12:02:08.681658+0200    TwilioVoiceExample  Connection 1: read-side closed
par défaut  12:02:08.682766+0200    TwilioVoiceExample  tcp_output [C1:2] flags=[F.] seq=3463867618, ack=4015111312, win=4112 state=LAST_ACK rcv_nxt=4015111312, snd_una=3463867618
par défaut  12:02:08.684366+0200    TwilioVoiceExample  Connection 1: is being canceled
par défaut  12:02:08.684809+0200    TwilioVoiceExample  [C1 F5C9AC4B-7B77-41E1-B355-1B7DEEEAD234 192.168.1.16:8081 tcp, url hash: c608e01a] cancel
par défaut  12:02:08.685200+0200    TwilioVoiceExample  [C1 F5C9AC4B-7B77-41E1-B355-1B7DEEEAD234 192.168.1.16:8081 tcp, url hash: c608e01a] cancelled
    [C1 57439DA7-41C7-4134-AED0-63D24B0A9001 192.168.1.40:55096<->192.168.1.16:8081]
    Connected Path: satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns
    Duration: 30.129s, TCP @0.020s took 0.084s
    bytes in/out: 175/205, packets in/out: 4/6, rtt: 0.016s, retransmitted bytes: 0, out-of-order bytes: 0
par défaut  12:02:08.687386+0200    TwilioVoiceExample  nw_flow_disconnected [C1 192.168.1.16:8081 cancelled channel-flow ((null))] Output protocol disconnected
par défaut  12:02:08.687982+0200    TwilioVoiceExample  nw_connection_report_state_with_handler_on_nw_queue [C1] reporting state cancelled
par défaut  12:02:08.690033+0200    TwilioVoiceExample  tcp_close [C1:2] TCP Packets:
     snd    0.000s seq 3463867412:3463867413 ack 0          win 65535 len 0    [S]
     rcv    0.084s seq 4015111135:4015111136 ack 3463867413 win 65535 len 0    [S.]
     snd    0.000s seq 3463867413:3463867413 ack 4015111136 win 4117  len 0    [.]
     snd    0.004s seq 3463867413:3463867618 ack 4015111136 win 4117  len 205  [P.]
     rcv    0.001s seq 4015111136:4015111136 ack 3463867413 win 2058  len 0    [.]
     rcv    0.004s seq 4015111136:4015111311 ack 3463867618 win 2055  len 175  [P.]
     snd    0.000s seq 3463867618:3463867618 ack 4015111311 win 4112  len 0    [.]
     rcv   29.872s seq 4015111311:4015111312 ack 3463867618 win 2055  len 0    [F.]
     snd    0.000s seq 3463867618:3463867618 ack 4015111312 win 4112  len 0    [.]
     snd    0.001s seq 3463867618:3463867619 ack 4015111312 win 4112  len 0    [F.]
     rcv    0.005s seq 4015111312:4015111312 ack 3463867619 win 2055  len 0    [.]
    Last packet 0ms ago.
par défaut  12:02:08.696676+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807795606/56975085, WiFi delta_in/delta_out: 184/156, Cell in/out: 62873/3158532, Cell delta_in/delta_out: 0/0, RNF: 0, subscriber tag: 0
par défaut  12:02:09.002233+0200    symptomsd   SymptomAnalytics ServiceImpl: FAE perform query for powerlogHelperd (pid 613) on LiveUsage predicate hasProcess.procName == $targetname sort (null) actions {
    "hasProcess.procName" = copyRelationship;
    nameChain = "com.XXX.TwilioVoiceExample";
    refreshUsage = refreshUsage;
    "hasProcess.firstTimeStamp" = copyRelationship;
    "hasProcess.bundleName" = copyRelationship;
    "<null>" = "<null>";
}
par défaut  12:02:09.018472+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807801414/56977111, WiFi delta_in/delta_out: 5808/2026, Cell in/out: 62873/3158532, Cell delta_in/delta_out: 0/0, RNF: 0, subscriber tag: 0
par défaut  12:02:09.034539+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807801414/56977111, WiFi delta_in/delta_out: 0/0, Cell in/out: 62873/3159524, Cell delta_in/delta_out: 0/992, RNF: 0, subscriber tag: 0
par défaut  12:02:09.037096+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807801414/56977111, WiFi delta_in/delta_out: 0/0, Cell in/out: 62873/3160392, Cell delta_in/delta_out: 0/868, RNF: 0, subscriber tag: 0
par défaut  12:02:09.039576+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807801414/56977111, WiFi delta_in/delta_out: 0/0, Cell in/out: 62873/3161384, Cell delta_in/delta_out: 0/992, RNF: 0, subscriber tag: 0
par défaut  12:02:09.042347+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807801414/56977111, WiFi delta_in/delta_out: 0/0, Cell in/out: 62873/3162376, Cell delta_in/delta_out: 0/992, RNF: 0, subscriber tag: 0
par défaut  12:02:09.046273+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807815420/56985229, WiFi delta_in/delta_out: 14006/8118, Cell in/out: 62873/3162376, Cell delta_in/delta_out: 0/0, RNF: 0, subscriber tag: 0
par défaut  12:02:09.059497+0200    runningboardd   Invalidating assertion 32-612-2507 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [application<com.XXX.TwilioVoiceExample>:612]
par défaut  12:02:09.060019+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807815606/56985466, WiFi delta_in/delta_out: 186/237, Cell in/out: 62873/3162376, Cell delta_in/delta_out: 0/0, RNF: 0, subscriber tag: 0
par défaut  12:02:09.081358+0200    symptomsd   entry: Thu Oct  8 14:49:31 2020          com.XXX.TwilioVoiceExample (bundle)     807815606     56985466        62873      3162376   0   1
par défaut  12:02:09.201937+0200    SpringBoard change foreground process from KeyboardArbiter:<FBApplicationProcess: 0x109bdbb10; application<com.XXX.TwilioVoiceExample>:612(v6A4)>
par défaut  12:02:09.202269+0200    SpringBoard didSelectKeyboardFocusProcess:<FBApplicationProcess: 0x109bdbb10; application<com.XXX.TwilioVoiceExample>:612(v6A4)> token:com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default
par défaut  12:02:09.202650+0200    SpringBoard updateKeyboardFocusDeferringRules: app focus pid:612 token:com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default
par défaut  12:02:09.204164+0200    backboardd  new deferring rules for pid:62: [
    <environment: system> -> <pid: 62; token: 0xB68EDF0A> reason: "1-deferDiscrete: systemGestures",
    <environment: keyboardFocus; display: builtin> -> <pid: 62; token: 0xB68EDF0A> reason: "3-deferDiscrete: Key Window event focus deferral",
    <environment: keyboardFocus; display: builtin> -> <pid: 62; token: 0x405E3825> reason: "390-deferDiscrete: Key Window event focus deferral",
    <environment: keyboardFocus; display: builtin> -> <pid: 612; token: com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default> reason: "399-deferDiscrete: SpringBoardToApp",
    <environment: keyboardFocus; display: builtin; token: 0x405E3825> -> <pid: 612; token: com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default> reason: "400-deferDiscrete: SpringBoardToAppCompatibility"
]
par défaut  12:02:09.205373+0200    runningboardd   Acquiring assertion targeting [application<com.XXX.TwilioVoiceExample>:612] from originator [daemon<com.apple.SpringBoard>:62] with description <RBSAssertionDescriptor| "com.apple.UIKit.KeyboardManagement.message" ID:32-62-2509 target:612 attributes:[
    <RBSLegacyAttribute| requestedReason:FinishTask reason:FinishTask flags:( AllowIdleSleep PreventTaskSuspend PreventTaskThrottleDown PreventThrottleDownUI )>,
    <RBSAcquisitionCompletionAttribute| policy:AfterValidation>
    ]>
par défaut  12:02:09.205509+0200    runningboardd   Assertion 32-62-2509 (target:[application<com.XXX.TwilioVoiceExample>:612]) will be created as inactive as start-time-defining assertions exist
par défaut  12:02:09.207408+0200    runningboardd   Finished acquiring assertion 32-62-2509 (target:[application<com.XXX.TwilioVoiceExample>:612])
par défaut  12:02:09.207547+0200    runningboardd   Invalidating assertion 32-62-2509 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [daemon<com.apple.SpringBoard>:62]
par défaut  12:02:09.245738+0200    TwilioVoiceExample  Received configuration update from daemon (initial)
par défaut  12:02:09.249231+0200    TwilioVoiceExample  [RNCallKeep][endCall] uuidString = E731957F-8148-481C-A34D-0B388F9394FC
par défaut  12:02:09.249649+0200    TwilioVoiceExample  [RNCallKeep][requestTransaction] transaction = <CXTransaction 0x282236680 UUID=AC7583A3-928E-4A12-BFB9-0B602FBE3E08 isComplete=0 actions=(
    "<CXEndCallAction 0x2831bf740 UUID=9D6D19AF-EBBB-48E5-BA19-6CF652BB630B state=0 commitDate=(null) callUUID=E731957F-8148-481C-A34D-0B388F9394FC dateEnded=(null)>"
)>
par défaut  12:02:09.249887+0200    TwilioVoiceExample  transaction: <CXTransaction 0x282236680 UUID=AC7583A3-928E-4A12-BFB9-0B602FBE3E08 isComplete=0 actions=(
    "<CXEndCallAction 0x2831bf740 UUID=9D6D19AF-EBBB-48E5-BA19-6CF652BB630B state=0 commitDate=(null) callUUID=E731957F-8148-481C-A34D-0B388F9394FC dateEnded=(null)>"
)>
par défaut  12:02:09.254096+0200    TwilioVoiceExample  Received reply from transaction request with error: (null)
par défaut  12:02:09.254215+0200    TwilioVoiceExample  [RNCallKeep][requestTransaction] Requested transaction successfully
par défaut  12:02:09.254460+0200    TwilioVoiceExample  Received request to commit transaction <CXTransaction 0x28223bce0 UUID=005B1195-CDD0-4E9A-AB1D-6D05659A1B30 isComplete=0 actions=(
    "<CXEndCallAction 0x2831ba8c0 UUID=9D6D19AF-EBBB-48E5-BA19-6CF652BB630B state=0 commitDate=2020-10-14 10:02:09 +0000 callUUID=E731957F-8148-481C-A34D-0B388F9394FC dateEnded=(null)>"
)>
par défaut  12:02:09.254754+0200    TwilioVoiceExample  Delegate did not execute transaction. Performing actions individually
par défaut  12:02:09.254986+0200    TwilioVoiceExample  Asking delegate to perform action <CXEndCallAction 0x2831ba8c0 UUID=9D6D19AF-EBBB-48E5-BA19-6CF652BB630B state=0 commitDate=2020-10-14 10:02:09 +0000 callUUID=E731957F-8148-481C-A34D-0B388F9394FC dateEnded=(null)>
par défaut  12:02:09.255253+0200    TwilioVoiceExample  [RNCallKeep][CXProviderDelegate][provider:performEndCallAction]
par défaut  12:02:09.255830+0200    TwilioVoiceExample  Provider <CXXPCProvider: 0x280710410> was notified that action <CXEndCallAction 0x2831767c0 UUID=9D6D19AF-EBBB-48E5-BA19-6CF652BB630B state=1 commitDate=2020-10-14 10:02:09 +0000 callUUID=E731957F-8148-481C-A34D-0B388F9394FC dateEnded=2020-10-14 10:02:09 +0000> completed
par défaut  12:02:09.256509+0200    TwilioVoiceExample  Removing transaction from list of pending transactions because it is now complete: <CXTransaction 0x282236680 UUID=005B1195-CDD0-4E9A-AB1D-6D05659A1B30 isComplete=1 actions=(
    "<CXEndCallAction 0x283163200 UUID=9D6D19AF-EBBB-48E5-BA19-6CF652BB630B state=1 commitDate=2020-10-14 10:02:09 +0000 callUUID=E731957F-8148-481C-A34D-0B388F9394FC dateEnded=2020-10-14 10:02:09 +0000>"
)>
par défaut  12:02:09.257244+0200    TwilioVoiceExample  [TwilioVoice] Rejecting call invite
par défaut  12:02:09.257880+0200    TwilioVoiceExample  [TwilioVoice] No call invite matches the call sid
par défaut  12:02:09.258028+0200    TwilioVoiceExample  [TwilioVoice] Disconnecting call
par défaut  12:02:09.261065+0200    runningboardd   Acquiring assertion targeting [application<com.XXX.TwilioVoiceExample>:612] from originator [application<com.XXX.TwilioVoiceExample>:612] with description <RBSAssertionDescriptor| "Shared Background Assertion 4 for com.XXX.TwilioVoiceExample" ID:32-612-2510 target:612 attributes:[
    <RBSLegacyAttribute| requestedReason:FinishTask reason:FinishTask flags:( PreventTaskSuspend )>,
    <RBSAcquisitionCompletionAttribute| policy:AfterValidation>
    ]>
par défaut  12:02:09.261218+0200    runningboardd   Assertion 32-612-2510 (target:[application<com.XXX.TwilioVoiceExample>:612]) will be created as inactive as start-time-defining assertions exist
par défaut  12:02:09.262681+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> resuming, timeouts(10.0, 604800.0) QOS(0x21) Voucher (null)
par défaut  12:02:09.263694+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [BF5770B4-E35C-405B-AB38-C95B9294D0A5] (reporting strategy default)> on Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> was not selected for reporting
par défaut  12:02:09.265054+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:09.265692+0200    runningboardd   Finished acquiring assertion 32-612-2510 (target:[application<com.XXX.TwilioVoiceExample>:612])
par défaut  12:02:09.266390+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> now using Connection 10
par défaut  12:02:09.267947+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> sent request, body S 1163
par défaut  12:02:09.273523+0200    runningboardd   Invalidating assertion 32-154-2491 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [daemon<com.apple.telephonyutilities.callservicesd>:154]
par défaut  12:02:09.278620+0200    TwilioVoiceExample  call: <CXCall: 0x2824138a0>
par défaut  12:02:09.279985+0200    TwilioVoiceExample  AURemoteIO.cpp:1621:Stop: Stopping AURemoteIO(0x10704aa40)
par défaut  12:02:09.280812+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> resuming, timeouts(10.0, 604800.0) QOS(0x21) Voucher (null)
par défaut  12:02:09.282998+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [13C555DA-38FD-4612-A744-B81B38DE40F9] (reporting strategy default)> on Task <7BE92308-E985-44F2-851D-63326B376568>.<33> was not selected for reporting
par défaut  12:02:09.283075+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> resuming, timeouts(10.0, 604800.0) QOS(0x21) Voucher (null)
par défaut  12:02:09.283150+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:09.283675+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> now using Connection 10
par défaut  12:02:09.283935+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [52724BC3-2E36-47FF-899A-AABA92F44689] (reporting strategy default)> on Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> was not selected for reporting
par défaut  12:02:09.284408+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> resuming, timeouts(10.0, 604800.0) QOS(0x21) Voucher (null)
par défaut  12:02:09.284733+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:09.285092+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> now using Connection 10
par défaut  12:02:09.285697+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [2A41D45E-DA7A-4C7A-BBE8-ACB9B514B02C] (reporting strategy default)> on Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> was not selected for reporting
par défaut  12:02:09.286417+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> sent request, body S 1163
par défaut  12:02:09.286736+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:09.286860+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> now using Connection 10
par défaut  12:02:09.287189+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> sent request, body S 1162
par défaut  12:02:09.287262+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> sent request, body S 1157
par défaut  12:02:09.287561+0200    mediaserverd    MEDeviceStreamClient.cpp:429:RemoveRunningClient: AQME Device.AQDefaultDevice: client stopping: <RemoteIOClient@0x1023ad000(@0x1023ad238); output voice; sid:0x22a4e, TwilioVoiceExamp(612), 'prim'>; running count now 0
par défaut  12:02:09.288482+0200    mediaserverd    MEDeviceStreamClient.cpp:429:RemoveRunningClient: AQME Device.AQDefaultDevice: client stopping: <RemoteIOClient@0x1023ad000(@0x1023ad070); input voice; sid:0x22a4e, TwilioVoiceExamp(612), 'prim'>; running count now 0
par défaut  12:02:09.288744+0200    mediaserverd    AudioSessionServerImp.cpp:4727:AudioSessionSetClientPlayState_Inner: { "action":"set_play_state", "session":{"ID":"0x22a4e","PID":612,"name":"TwilioVoiceExamp"}, "details":"entry" }
par défaut  12:02:09.289073+0200    mediaserverd    -CMSUtilities- CMSUtility_GetCurrentConsolidatedPlayingState: client 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'': SomeMXSessionIsPlaying = STOPPED, AudioToolboxIsPlaying = STOPPED, HapticEngineIsPlaying = STOPPED
par défaut  12:02:09.289187+0200    mediaserverd    -CMSessionMgr- cmsSetIsPlaying: 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'' with [PlayAndRecord_WithBluetooth/VoiceChat] [NonMixable] [System Audio] stopping playing. Ringer switch state: Device is not silenced, Session is unmuted.
par défaut  12:02:09.289268+0200    mediaserverd         CAReportingClient.mm:497   message {
    MXSessionVolume = "0.875";
    MXSessionVolumeCategory = "Audio/Video";
    MXSessionVolumeOperationProcess = "com.XXX.TwilioVoiceExample";
    MXSessionVolumeOperationTime = 10170;
    MXSessionVolumePlayingState = 0;
}: (
    146028888097
)
par défaut  12:02:09.289343+0200    mediaserverd    -CMSessionMgr- cmsSetIsPlaying: Starting deactivate timer for client 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim''
par défaut  12:02:09.290849+0200    runningboardd   Invalidating assertion 32-34-2503 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [daemon<com.apple.mediaserverd>:34]
par défaut  12:02:09.292000+0200    mediaserverd    -CMSUtilities- CMSUtility_GetCurrentConsolidatedPlayingState: client 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'': SomeMXSessionIsPlaying = STOPPED, AudioToolboxIsPlaying = STOPPED, HapticEngineIsPlaying = STOPPED
par défaut  12:02:09.292536+0200    mDNSResponder   [R5885] DNSServiceQueryRecord(15000, 0, <mask.hash: 'ilGkNgWmLjRatRsrLuXxzg=='>, Addr) START PID[612](TwilioVoiceExam)
par défaut  12:02:09.294006+0200    mDNSResponder   [R5886] DNSServiceQueryRecord(15000, 0, <mask.hash: 'ilGkNgWmLjRatRsrLuXxzg=='>, AAAA) START PID[612](TwilioVoiceExam)
par défaut  12:02:09.294423+0200    mediaserverd    -CMSUtilities- CMSUtility_SetIsRecording: Client sid:0x22a4e, TwilioVoiceExamp(612), 'prim' has stopped recording
par défaut  12:02:09.296201+0200    mDNSResponder   [R5885] DNSServiceQueryRecord(15000, 0, <mask.hash: 'Oq802g5hcA0vauykIfO1SA=='>, Addr) STOP PID[612](TwilioVoiceExam)
par défaut  12:02:09.296397+0200    mDNSResponder   [R5886] DNSServiceQueryRecord(15000, 0, <mask.hash: 'Oq802g5hcA0vauykIfO1SA=='>, AAAA) STOP PID[612](TwilioVoiceExam)
par défaut  12:02:09.296986+0200    mediaserverd    AudioSessionServerImp.cpp:4955:AudioSessionSetClientPlayState_Inner: { "action":"set_play_state", "session":{"ID":"0x22a4e","PID":612,"name":"TwilioVoiceExamp"}, "details":{"IOs":[0,0,0,0,0],"IsRecording":false,"IsRecordingMuted":false,"active":true,"modes":"Input/Output","player":"0x1023ad000","state":"Stopped","type":"Remote IO"} }
par défaut  12:02:09.297096+0200    mediaserverd    AudioSessionServerImp.cpp:1307:operator(): { "action":"setMicrophoneMonitorState", "session":{"ID":"0x22a4e","PID":612,"name":"TwilioVoiceExamp"}, "details":{"microphone_state":false} }
par défaut  12:02:09.297719+0200    SpringBoard application<com.XXX.TwilioVoiceExample> now recording audio: NO
par défaut  12:02:09.297817+0200    SpringBoard Sensor activity changed:
Active: {(
)}
Recent: <SBSensorActivityAttribution: 0x282b96940; TwilioVoice Example; sensor: microphone>
par défaut  12:02:09.298703+0200    runningboardd   Invalidating assertion 32-62-2504 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [daemon<com.apple.SpringBoard>:62]
par défaut  12:02:09.299187+0200    TwilioVoiceExample  AURemoteIO.cpp:1621:Stop: Stopping AURemoteIO(0x10704aa40)
par défaut  12:02:09.320811+0200    TwilioVoiceExample  AURemoteIO.cpp:1621:Stop: Stopping AURemoteIO(0x10704aa40)
par défaut  12:02:09.336081+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> resuming, timeouts(10.0, 604800.0) QOS(0x21) Voucher (null)
par défaut  12:02:09.340261+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [F0E2B5AE-8FCD-4066-9E38-A05CE69B3CDB] (reporting strategy default)> on Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> was not selected for reporting
par défaut  12:02:09.354422+0200    runningboardd   Calculated state for application<com.XXX.TwilioVoiceExample>: running-active (role: UserInteractiveNonFocal)
par défaut  12:02:09.373296+0200    powerd  Process runningboardd.32 Released SystemIsActive "application<com.XXX.TwilioVoiceExample>;32-154-2491:CSDVoIPProcessAssertion-com.XXX.TwilioVoiceExample(VoIP);32-34-2503:MediaExperience.612."com.XXX.TwilioVoiceExample"."PlayAndRecord_WithBluetooth".isPlayingProcessAssertion(MediaPlayback)" age:00:00:14  id:51539648047 [System: PrevIdle SysAct]
par défaut  12:02:09.373516+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:09.373755+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> now using Connection 10
par défaut  12:02:09.385401+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> sent request, body S 1167
par défaut  12:02:09.392452+0200    SpringBoard SBMainWorkspaceApplicationSceneLayoutElementViewController-sceneID:com.XXX.TwilioVoiceExample-default will begin transition to visible YES
par défaut  12:02:09.402441+0200    heard   -[HUNearbyController callStatusDidChange:]:206 Call status changed - NSConcreteNotification 0x128b05910 {name = TUCallCenterCallStatusChangedNotification; object = <TUProxyCall 0x128c04210 p=XXX.com.XXX.TwilioVoiceExample svc=Unknown hdl=<TUHandle 0x128c05850 type=PhoneNumber, value=quick_start, normalizedValue=(null), isoCountryCode=(null)> isoCC=(null) stat=Disconnected tStat=0 dR=0 fR=0 supportsR=1 uPI=E731957F-8148-481C-A34D-0B388F9394FC grp=(null) lSIUUID=(null) lSIAccountUUID=(null) hosted=1 endpt=1 callerNFN= srcID=(null) aC=AVAudioSessionCategoryPlayAndRecord aM=AVAudioSessionModeVoiceChat iUB=0 vm=0 connStat=11 cID=(null) nMICS=0 sR=0 iSA=0 iSV=0 wHM=0 hSI=0 vST=0 iapST=0 oapST=0 vCA=<TUVideoCallAttributes 0x128c05bb0 remoteCameraOrientation=0 localVideoContextSlotIdentifier=0 remoteVideoContextSlotIdentifier=0> model=<TUCallModel 0x128b07460 hold=1 grp=1 ungrp=1 DTMF=1 uMPS=1 aC=1 sTV=0> em=0 sos=0 sSR=0 sSUI=0 mX=0 iUM=0 iDM=0 tty=0 ttyWV=0 convo=0 rUM=0 ver=0 pri=0 oUI=0 jCon<…>
par défaut  12:02:09.403639+0200    heard   -[HUNearbyController callStatusDidChange:]_block_invoke:224 Phone call [pending = 0, active = 0, avc = 0, endpoint = 0] - [connected = 0, should = 0] - NSConcreteNotification 0x128b05910 {name = TUCallCenterCallStatusChangedNotification; object = <TUProxyCall 0x128c04210 p=XXX.com.XXX.TwilioVoiceExample svc=Unknown hdl=<TUHandle 0x128c05850 type=PhoneNumber, value=quick_start, normalizedValue=(null), isoCountryCode=(null)> isoCC=(null) stat=Disconnected tStat=0 dR=0 fR=0 supportsR=1 uPI=E731957F-8148-481C-A34D-0B388F9394FC grp=(null) lSIUUID=(null) lSIAccountUUID=(null) hosted=1 endpt=1 callerNFN= srcID=(null) aC=AVAudioSessionCategoryPlayAndRecord aM=AVAudioSessionModeVoiceChat iUB=0 vm=0 connStat=11 cID=(null) nMICS=0 sR=0 iSA=0 iSV=0 wHM=0 hSI=0 vST=0 iapST=0 oapST=0 vCA=<TUVideoCallAttributes 0x128c05bb0 remoteCameraOrientation=0 localVideoContextSlotIdentifier=0 remoteVideoContextSlotIdentifier=0> model=<TUCallModel 0x128b07460 hold=1 grp=1 ungrp=1 DTMF=1 uMPS=1 aC=1 sTV=0> em=0 sos<…>
par défaut  12:02:09.407915+0200    heard   -[HUNearbyController callStatusDidChange:]_block_invoke:224 Phone call [pending = 0, active = 0, avc = 0, endpoint = 0] - [connected = 0, should = 0] - NSConcreteNotification 0x128b05910 {name = TUCallCenterCallStatusChangedNotification; object = <TUProxyCall 0x128c04210 p=XXX.com.XXX.TwilioVoiceExample svc=Unknown hdl=<TUHandle 0x128c05850 type=PhoneNumber, value=quick_start, normalizedValue=(null), isoCountryCode=(null)> isoCC=(null) stat=Disconnected tStat=0 dR=0 fR=0 supportsR=1 uPI=E731957F-8148-481C-A34D-0B388F9394FC grp=(null) lSIUUID=(null) lSIAccountUUID=(null) hosted=1 endpt=1 callerNFN= srcID=(null) aC=AVAudioSessionCategoryPlayAndRecord aM=AVAudioSessionModeVoiceChat iUB=0 vm=0 connStat=11 cID=(null) nMICS=0 sR=0 iSA=0 iSV=0 wHM=0 hSI=0 vST=0 iapST=0 oapST=0 vCA=<TUVideoCallAttributes 0x128c05bb0 remoteCameraOrientation=0 localVideoContextSlotIdentifier=0 remoteVideoContextSlotIdentifier=0> model=<TUCallModel 0x128b07460 hold=1 grp=1 ungrp=1 DTMF=1 uMPS=1 aC=1 sTV=0> em=0 sos<…>
par défaut  12:02:09.414469+0200    mediaserverd    AudioSessionServerImp.cpp:3068:Sub_AudioSessionSetActiveWithFlags: { "action":"deactivate", "session":{"ID":"0x22a4e","PID":612,"name":"TwilioVoiceExamp"}, "details":"entry" }
par défaut  12:02:09.418293+0200    mediaserverd    AudioToolboxServers.mm:576:AudioToolboxServerHandleInterruptionWithID: ================= -> AudioToolboxServerHandleInterruption Stop Now process 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'', fade time 0.50s, level 0.00 =================
par défaut  12:02:09.418713+0200    mediaserverd    AudioToolboxServers.mm:606:AudioToolboxServerHandleInterruptionWithID: ================= <- AudioToolboxServerHandleInterruption Stop Now process 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'' =================
par défaut  12:02:09.418916+0200    mediaserverd    -CMSUtilities- CMSUtility_GetCurrentConsolidatedPlayingState: client 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'': SomeMXSessionIsPlaying = STOPPED, AudioToolboxIsPlaying = STOPPED, HapticEngineIsPlaying = STOPPED
par défaut  12:02:09.423882+0200    mediaserverd    -CMSessionMgr- _CMSessionEndInterruption: client 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'' [0x100bd5710]: status = resumable.endInterruption
par défaut  12:02:09.423937+0200    mediaserverd    -CMSessionMgr- cmsSetIsActive: 'sid:0x22a4e, TwilioVoiceExamp(612), 'prim'' with [PlayAndRecord_WithBluetooth/VoiceChat] [NonMixable] [System Audio] siriEndpointID: (null) going inactive NowPlayingApp:NO
par défaut  12:02:09.429646+0200    SpringBoard SBMainWorkspaceApplicationSceneLayoutElementViewController-sceneID:com.XXX.TwilioVoiceExample-default did end transition to visible YES
par défaut  12:02:09.429716+0200    SpringBoard SBMainWorkspaceApplicationSceneLayoutElementViewController-sceneID:com.XXX.TwilioVoiceExample-default shouldDisplayLayoutElementBecomeActive=YES because isEffectivelyForeground=YES isSuspendedUnderLock=NO sceneIfExists=<FBScene: 0x2838718c0; sceneID: sceneID:com.XXX.TwilioVoiceExample-default; valid: YES>
par défaut  12:02:09.429785+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> received response, status 200 content U
par défaut  12:02:09.429882+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> done using Connection 10
par défaut  12:02:09.430116+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> response ended
par défaut  12:02:09.430244+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> summary for task success {transaction_duration_ms=90, response_status=200, connection=10, reused=1, request_start_ms=1, request_duration_ms=1, response_start_ms=90, response_duration_ms=0, request_bytes=1214, response_bytes=384, cache_hit=0}
par défaut  12:02:09.431634+0200    SpringBoard sceneHandle=<SBDeviceApplicationSceneHandle: 0x1211cb9d0; sceneID: sceneID:com.XXX.TwilioVoiceExample-default; scenePointer: 0x2838718c0; scene: <FBScene: 0x2838718c0; sceneID: sceneID:com.XXX.TwilioVoiceExample-default; valid: YES> {
    specification = UIApplicationSceneSpecification;
    settings = <UIApplicationSceneSettings: 0x28205d200> {
        displayConfiguration = "<FBSDisplayConfiguration: 0x283654000; Main; mode: "375x812@3x 60Hz p3 SDR">";
        frame = {{0, 0}, {375, 812}};
        level = 1.0;
        interfaceOrientation = portrait (1);
        foreground = YES;
        interruptionPolicy = default;
        isOccluded = BSSettingFlagNotSet;
        otherSettings = <BSSettings: 0x280ee0a40> {
            statusBarStyleOverridesToSuppress = inCall;
            deactivationReasons = ;
            deviceOrientationEventsEnabled = YES;
            canShowAlerts = YES;
            userInterfaceStyle = dark;
            peripheryInsets = UIEdgeInsets: {32, 0, 0, 0};
            deviceOrie
par défaut  12:02:09.432018+0200    TwilioVoiceExample  Task <E4443F4C-F9D5-4B87-9BA4-0AA83F7C13F5>.<32> finished successfully
par défaut  12:02:09.440143+0200    SpringBoard Front display did change: <SBApplication: 0x2834222f0; com.XXX.TwilioVoiceExample>
par défaut  12:02:09.448528+0200    SpringBoard Updating configuration of monitor <RBSProcessMonitorConfiguration| id:M62-6 qos:25 predicates:[<RBSProcessPredicate <RBSCompoundPredicate [<RBSCompoundPredicate [<RBSProcessBKSLegacyPredicate>, <RBSProcessEUIDPredicate 501>]>, <RBSProcessBundleIdentifierPredicate "com.apple.springboard">]>>, <RBSProcessPredicate <RBSCompoundPredicate [<RBSCompoundPredicate [<RBSProcessBKSLegacyPredicate>, <RBSProcessEUIDPredicate 501>]>, <RBSProcessBundleIdentifierPredicate "com.XXX.TwilioVoiceExample">]>>] descriptor:<RBSProcessStateDescriptor| values:9 namespaces:[com.apple.frontboard.visibility]> events:0x0>
par défaut  12:02:09.451777+0200    SpringBoard updateKeyboardFocusDeferringRules: app focus pid:612 token:com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default
par défaut  12:02:09.452874+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> received response, status 200 content U
par défaut  12:02:09.453057+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> received response, status 200 content U
par défaut  12:02:09.453196+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> received response, status 200 content U
par défaut  12:02:09.453382+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> done using Connection 10
par défaut  12:02:09.453944+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> done using Connection 10
par défaut  12:02:09.465188+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> done using Connection 10
par défaut  12:02:09.468832+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> response ended
par défaut  12:02:09.469264+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> summary for task success {transaction_duration_ms=91, response_status=200, connection=10, reused=1, request_start_ms=0, request_duration_ms=0, response_start_ms=89, response_duration_ms=1, request_bytes=1214, response_bytes=383, cache_hit=0}
par défaut  12:02:09.469882+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> response ended
par défaut  12:02:09.470279+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> summary for task success {transaction_duration_ms=90, response_status=200, connection=10, reused=1, request_start_ms=0, request_duration_ms=0, response_start_ms=88, response_duration_ms=2, request_bytes=1213, response_bytes=383, cache_hit=0}
par défaut  12:02:09.471229+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> response ended
par défaut  12:02:09.472099+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> summary for task success {transaction_duration_ms=90, response_status=200, connection=10, reused=1, request_start_ms=0, request_duration_ms=0, response_start_ms=88, response_duration_ms=2, request_bytes=1208, response_bytes=384, cache_hit=0}
par défaut  12:02:09.472892+0200    TwilioVoiceExample  Task <7BE92308-E985-44F2-851D-63326B376568>.<33> finished successfully
par défaut  12:02:09.474176+0200    TwilioVoiceExample  Task <20F13199-39BD-4EEA-9042-2DC2717FCECA>.<34> finished successfully
par défaut  12:02:09.475066+0200    TwilioVoiceExample  Task <53DCD133-C4B2-4223-802A-A5517008D4C8>.<35> finished successfully
par défaut  12:02:09.484534+0200    backboardd  new deferring rules for pid:62: [
    <environment: system> -> <pid: 62; token: 0xB68EDF0A> reason: "1-deferDiscrete: systemGestures",
    <environment: keyboardFocus; display: builtin> -> <pid: 62; token: 0xB68EDF0A> reason: "3-deferDiscrete: Key Window event focus deferral",
    <environment: keyboardFocus; display: builtin> -> <pid: 62; token: 0x405E3825> reason: "390-deferDiscrete: Key Window event focus deferral",
    <environment: keyboardFocus; display: builtin> -> <pid: 612; token: com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default> reason: "401-deferDiscrete: SpringBoardToApp",
    <environment: keyboardFocus; display: builtin; token: 0x405E3825> -> <pid: 612; token: com.apple.frontboard.systemappservices::sceneID%3Acom.XXX.TwilioVoiceExample-default> reason: "402-deferDiscrete: SpringBoardToAppCompatibility"
]
par défaut  12:02:09.513102+0200    runningboardd   Acquiring assertion targeting [application<com.XXX.TwilioVoiceExample>:612] from originator [application<com.XXX.TwilioVoiceExample>:612] with description <RBSAssertionDescriptor| "com.apple.CFNetwork.StorageDB" ID:32-612-2513 target:612 attributes:[
    <RBSDomainAttribute| domain:"com.apple.common" name:"FinishTaskUninterruptable" sourceEnvironment:"(null)">,
    <RBSAcquisitionCompletionAttribute| policy:AfterApplication>
    ]>
par défaut  12:02:09.514528+0200    runningboardd   Assertion 32-612-2513 (target:[application<com.XXX.TwilioVoiceExample>:612]) will be created as inactive as start-time-defining assertions exist
par défaut  12:02:09.540822+0200    runningboardd   Finished acquiring assertion 32-612-2513 (target:[application<com.XXX.TwilioVoiceExample>:612])
par défaut  12:02:09.542695+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> received response, status 200 content U
par défaut  12:02:09.542800+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> done using Connection 10
par défaut  12:02:09.543200+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> response ended
par défaut  12:02:09.543286+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> summary for task success {transaction_duration_ms=105, response_status=200, connection=10, reused=1, request_start_ms=1, request_duration_ms=15, response_start_ms=105, response_duration_ms=0, request_bytes=1218, response_bytes=384, cache_hit=0}
par défaut  12:02:09.543646+0200    TwilioVoiceExample  Task <DBAFFA28-4F83-473A-97BA-3D2A551BD2E4>.<36> finished successfully
par défaut  12:02:09.544753+0200    TwilioVoiceExample  [TwilioVoice] Call disconnected
par défaut  12:02:09.545660+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> resuming, timeouts(10.0, 604800.0) QOS(0x21) Voucher (null)
par défaut  12:02:09.546452+0200    TwilioVoiceExample  [Telemetry]: Activity <nw_activity 12:2 [69E2A3D0-A785-481F-B3B6-D420F2132E82] (reporting strategy default)> on Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> was not selected for reporting
par défaut  12:02:09.547139+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> {strength 0, tls 4, ct 0, sub 0, sig 1, ciphers 0, bundle 0, builtin 0}
par défaut  12:02:09.547240+0200    runningboardd   Invalidating assertion 32-612-2510 (target:[application<com.XXX.TwilioVoiceExample>:612]) from originator [application<com.XXX.TwilioVoiceExample>:612]
par défaut  12:02:09.547339+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> now using Connection 10
par défaut  12:02:09.548404+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> sent request, body S 1611
par défaut  12:02:09.597038+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807827098/56995878, WiFi delta_in/delta_out: 11492/10412, Cell in/out: 62873/3162376, Cell delta_in/delta_out: 0/0, RNF: 0, subscriber tag: 0
par défaut  12:02:09.602713+0200    symptomsd   Data Usage for com.XXX.TwilioVoiceExample - WiFi in/out: 807827098/56995878, WiFi delta_in/delta_out: 0/0, Cell in/out: 62929/3162432, Cell delta_in/delta_out: 56/56, RNF: 0, subscriber tag: 0
par défaut  12:02:09.619674+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> received response, status 200 content U
par défaut  12:02:09.619816+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> done using Connection 10
par défaut  12:02:09.620102+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> response ended
par défaut  12:02:09.620300+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> summary for task success {transaction_duration_ms=88, response_status=200, connection=10, reused=1, request_start_ms=0, request_duration_ms=0, response_start_ms=88, response_duration_ms=0, request_bytes=1662, response_bytes=381, cache_hit=0}
par défaut  12:02:09.620682+0200    TwilioVoiceExample  Task <EB99110A-9401-4400-B093-56F3A85C1D39>.<37> finished successfully
par défaut  12:02:09.621160+0200    TwilioVoiceExample  Connection 10: is being canceled
par défaut  12:02:09.622049+0200    TwilioVoiceExample  [C10 72205760-2771-4FE4-98BC-089B5B52953E eventgw.twilio.com:443 tcp, url hash: 004d3bd8, tls] cancel
par défaut  12:02:09.622216+0200    TwilioVoiceExample  [C10 72205760-2771-4FE4-98BC-089B5B52953E eventgw.twilio.com:443 tcp, url hash: 004d3bd8, tls] cancelled
    [C10.1 1A7C77B7-AB56-40FD-BE7A-3FE64FF77A56 192.168.1.40:55103<->35.173.0.91:443]
    Connected Path: satisfied (Path is satisfied), viable, interface: en0, ipv4, ipv6, dns
    Duration: 15.016s, DNS @0.002s took 0.009s, TCP @0.022s took 0.086s, TLS 1.2 took 0.191s
    bytes in/out: 22152/55257, packets in/out: 56/122, rtt: 0.084s, retransmitted bytes: 0, out-of-order bytes: 0
par défaut  12:02:09.623292+0200    TwilioVoiceExample  nw_protocol_tcp_log_summary [C10.1:3] 
    [DFC57B7C-0EA2-476E-8427-61969065B24C 192.168.1.40:55103<->35.173.0.91:443]
    Init: 1, Conn_Time: 85.863ms, SYNs: 1, WR_T: 0/0, RD_T: 0/0, TFO: 0/0/0, ECN: 0/0/0, TS: 1
    rtt_cache: process, rtt_upd: 48, rtt: 84.281ms, rtt_var: 3.812ms rtt_nc: 84.281ms, rtt_var_nc: 3.812ms
    ACKs-compressed: 0, ACKs delayed: 0 delayed ACKs sent: 0
par défaut  12:02:09.623423+0200    TwilioVoiceExample  nw_flow_disconnected [C10.1 35.173.0.91:443 cancelled channel-flow ((null))] Output protocol disconnected
par défaut  12:02:09.623797+0200    TwilioVoiceExample  nw_connection_report_state_with_handler_on_nw_queue [C10] reporting state cancelled
par défaut  12:02:09.623924+0200    TwilioVoiceExample  Connection 10: destroyed
par défaut  12:02:09.624042+0200    TwilioVoiceExample  tcp_output [C10.1:3] flags=[F.] seq=3968096317, ack=2648212935, win=4096 state=FIN_WAIT_1 rcv_nxt=2648212935, snd_una=3968096240

Versions

Using Swift.

Voice iOS SDK

6.0.0 via CocoaPods

Xcode

12

iOS Version

14

iOS Device

iPhone X

MrHertal commented 4 years ago

Here are some call sids:

CA5330ed040bc9199e50dbaaf017a1aa2b

CA9c7ae4311afe0a8ceb6c2f3ca37a1d9c

bobiechen-twilio commented 4 years ago

Hi @MrHertal

Thanks for reaching out. From the records of the Calls you provided, the last status of the Calls are completed. Can you confirm that it's showing the same status in your developer console?

MrHertal commented 4 years ago

I do confirm

bobiechen-twilio commented 4 years ago

Thanks @MrHertal.

MrHertal commented 4 years ago

I think there is a misunderstanding, the issue is still here.

My problem is that I receive an incoming call, I answer this call, I call disconnect()method on this call, callDidDisconnect is triggered, but when I check the console, call has status Answered.

After some time call has status Completed (only when remote hangup).

Maybe I got it wrong but, disconnect() is supposed to end the call on both sides right?

bobiechen-twilio commented 4 years ago

Hi @MrHertal thanks for the update. Yes, the disconnect() method will end the connection between the local client and Twilio, as well as the remote client if it's a client-to-client or client-to-number call ( might have different result). It might take some time for the status to reflect, but in basic use cases like this, the disconnect method should end the call for both call parties.

MrHertal commented 4 years ago

OK thanks for the explanation, it confirms I do have an issue with the disconnect() method

As you can see, both sids are client-to-client calls. Both calls lasted about 44 seconds (which corresponds to the TwiML execution time).

But the TO client client:leo called disconnect() method about 10 seconds after answering the calls.

Each time the TO client calls disconnect() method, call is still marked as Answered. After TwiML execution ends, FROM client client:quick_start hangs up.

My issue is that client:leo calling disconnect() method should end call on both sides and call should not continue to execute TwiML

bobiechen-twilio commented 4 years ago

Thanks again for the update @MrHertal.

I checked again the Call SIDs and I think I know what's going on - in your Call API there is an URL (which is required) which generates a TwiML response with a couple of verbs, in addition to the call to client:leo. The call on leo's side should end once .disconnect() is called, but the first call originated from the Call API won't finish until all the verbs are done. This could be the result why the status update seemed to be delayed.

MrHertal commented 4 years ago

Ok i got it now 🙂 no issue

thanks for your help!