hermannkuschke
commented
7 years ago So I changed my code to now specify the TwiML App Sid as a parameter and it seems that I got a different error message. Please see below:
2017-03-08 14:11:04.893485
Via: SIP/2.0/TLS 105.250.237.86:60527;received=105.250.237.86;rport=60527;branch=z9hG4bKPjpXH3tuaLwjE.P85vR0F6Ss-9j9-SU6Ij;alias
From: sip:twilio@chunderm.gll.twilio.com;tag=W-J1O1fTuk9rvxcaWBS9hi9vcg-tvO8R
To: sip:None@chunderm.gll.twilio.com;tag=2b14b56249e38f165532d4250ab0b760.535e
Call-ID: mSp.pm2IUDTzX-qJHEXIoSKyy2QCUEn5
CSeq: 7046 INVITE
Contact: <sip:54.171.127.230:10194;transport=tls>
Server: Twilio Client SBC
Content-Length: 0
--end msg--
2017-03-08 14:11:08.710398
Via: SIP/2.0/TLS 105.250.237.86:60527;rport;branch=z9hG4bKPjpXH3tuaLwjE.P85vR0F6Ss-9j9-SU6Ij;alias
Max-Forwards: 70
From: sip:twilio@chunderm.gll.twilio.com;tag=W-J1O1fTuk9rvxcaWBS9hi9vcg-tvO8R
To: sip:None@chunderm.gll.twilio.com;tag=2b14b56249e38f165532d4250ab0b760.535e
Call-ID: mSp.pm2IUDTzX-qJHEXIoSKyy2QCUEn5
CSeq: 7046 ACK
Content-Length: 0
--end msg--
2017-03-08 14:11:08.715694
CSeq: 7047 INVITE
Call-ID: mSp.pm2IUDTzX-qJHEXIoSKyy2QCUEn5
From: sip:twilio@chunderm.gll.twilio.com;tag=W-J1O1fTuk9rvxcaWBS9hi9vcg-tvO8R
To: sip:None@chunderm.gll.twilio.com
Via: SIP/2.0/TLS 105.250.237.86:60528;rport=60528;branch=z9hG4bKPj8RMJ.hkVGQ7zkjsyQZIJzairgJi23si5;alias;received=105.250.237.86
Server: Twilio
Content-Length: 0
--end msg--
2017-03-08 14:11:10.195041
CSeq: 7047 INVITE
Call-ID: mSp.pm2IUDTzX-qJHEXIoSKyy2QCUEn5
From: sip:twilio@chunderm.gll.twilio.com;tag=W-J1O1fTuk9rvxcaWBS9hi9vcg-tvO8R
To: sip:None@chunderm.gll.twilio.com;tag=39141977_6772d868_201c6762-f937-4119-b0ec-4b94b7a81e50
Via: SIP/2.0/TLS 105.250.237.86:60528;rport=60528;branch=z9hG4bKPj8RMJ.hkVGQ7zkjsyQZIJzairgJi23si5;alias;received=105.250.237.86
Server: Twilio
Contact: <sip:ec2-54-171-127-230.eu-west-1.compute.amazonaws.com:10194;transport=tls>
Content-Length: 0
--end msg--
2017-03-08 14:11:10.348734
Via: SIP/2.0/TLS 105.250.237.86:60528;rport;branch=z9hG4bKPj8RMJ.hkVGQ7zkjsyQZIJzairgJi23si5;alias
Max-Forwards: 70
From: sip:twilio@chunderm.gll.twilio.com;tag=W-J1O1fTuk9rvxcaWBS9hi9vcg-tvO8R
To: sip:None@chunderm.gll.twilio.com;tag=39141977_6772d868_201c6762-f937-4119-b0ec-4b94b7a81e50
Call-ID: mSp.pm2IUDTzX-qJHEXIoSKyy2QCUEn5
CSeq: 7047 ACK
Content-Length: 0
--end msg--
2017-03-08 14:11:10.356233
Via: SIP/2.0/TLS 105.250.237.86:60527;received=105.250.237.86;rport=60527;branch=z9hG4bKPjGAINrou0tzmqr6cRuavmzaJOpIzB2CFK;alias
From: sip:twilio@chunderm.gll.twilio.com;tag=5Wg3QV6OoxtzAMYKO2alF0Z-vMyyAjOm
To: sip:None@chunderm.gll.twilio.com;tag=2b14b56249e38f165532d4250ab0b760.9de9
Call-ID: M47VIDv0rLqfBGHRk1HJLDemLugikgEF
CSeq: 15252 INVITE
Contact: <sip:54.171.127.230:10194;transport=tls>
Server: Twilio Client SBC
Content-Length: 0
--end msg--
2017-03-08 14:11:28.764932
Via: SIP/2.0/TLS 105.250.237.86:60527;rport;branch=z9hG4bKPjGAINrou0tzmqr6cRuavmzaJOpIzB2CFK;alias
Max-Forwards: 70
From: sip:twilio@chunderm.gll.twilio.com;tag=5Wg3QV6OoxtzAMYKO2alF0Z-vMyyAjOm
To: sip:None@chunderm.gll.twilio.com;tag=2b14b56249e38f165532d4250ab0b760.9de9
Call-ID: M47VIDv0rLqfBGHRk1HJLDemLugikgEF
CSeq: 15252 ACK
Content-Length: 0
--end msg--
2017-03-08 14:11:28.772639
CSeq: 15253 INVITE
Call-ID: M47VIDv0rLqfBGHRk1HJLDemLugikgEF
From: sip:twilio@chunderm.gll.twilio.com;tag=5Wg3QV6OoxtzAMYKO2alF0Z-vMyyAjOm
To: sip:None@chunderm.gll.twilio.com
Via: SIP/2.0/TLS 105.250.237.86:60530;rport=60530;branch=z9hG4bKPjwXIJjAO1CdFnKoLwTXAFm89ZutVHA3dU;alias;received=105.250.237.86
Server: Twilio
Content-Length: 0
--end msg--
2017-03-08 14:11:30.018044
CSeq: 15253 INVITE
Call-ID: M47VIDv0rLqfBGHRk1HJLDemLugikgEF
From: sip:twilio@chunderm.gll.twilio.com;tag=5Wg3QV6OoxtzAMYKO2alF0Z-vMyyAjOm
To: sip:None@chunderm.gll.twilio.com;tag=66751661_6772d868_b65c6251-919a-4023-a287-bb03c135ade8
Via: SIP/2.0/TLS 105.250.237.86:60530;rport=60530;branch=z9hG4bKPjwXIJjAO1CdFnKoLwTXAFm89ZutVHA3dU;alias;received=105.250.237.86
Server: Twilio
Contact: <sip:ec2-54-171-127-230.eu-west-1.compute.amazonaws.com:10194;transport=tls>
Content-Length: 0
--end msg--
2017-03-08 14:11:30.166155
Via: SIP/2.0/TLS 105.250.237.86:60530;rport;branch=z9hG4bKPjwXIJjAO1CdFnKoLwTXAFm89ZutVHA3dU;alias
Max-Forwards: 70
From: sip:twilio@chunderm.gll.twilio.com;tag=5Wg3QV6OoxtzAMYKO2alF0Z-vMyyAjOm
To: sip:None@chunderm.gll.twilio.com;tag=66751661_6772d868_b65c6251-919a-4023-a287-bb03c135ade8
Call-ID: M47VIDv0rLqfBGHRk1HJLDemLugikgEF
CSeq: 15253 ACK
Content-Length: 0
--end msg--
2017-03-08 14:11:30.168792
bobiechen-twilio
Hi @bchen-twilio
First of all. Job well done with this product. I'm really excited about building a partnership. I'm just stumbling a bit with making calls at the moment and I need to get this working. I'm pasting my verbose log below. Any help is greatly appreciated.
2017-03-08 12:43:21.277963Dev[1040:539029] StartCallAction transaction request successful
2017-03-08 12:43:21.549412 Dev[1040:538862] provider:performStartCallAction:
2017-03-08 12:43:21.554492 Dev[1040:538862] DialogHelper closing dialog Optional("question")
2017-03-08 12:43:21.570669 Dev[1040:538862] DialogHelper now initializing timer
2017-03-08 12:43:21.570950 Dev[1040:538862] DialogHelper showing dialog wait
2017-03-08 12:43:23.909553 Dev[1040:538862] DialogHelper closing dialog Optional("wait")
2017-03-08 12:43:23.912991 Dev[1040:538862] DialogHelper invalidating timer
2017-03-08 12:43:23.929962 Dev[1040:539030] [VERBOSE VoiceClient] Inside configureAudioSession, preparing audio session.
2017-03-08 12:43:23.940954 Dev[1040:539030] [DEBUG TVOReachability] Reachability Flag Status: WR t------ networkStatusForFlags
2017-03-08 12:43:23.943624 Dev[1040:539030] [DEBUG TVOCommandHandler] Inside postCommand:, received command of type TVOMakeCallCommand
2017-03-08 12:43:23.964874 Dev[1040:539154] PJSIP(4): sip_endpoint.c !.Module "mod-pjsua-log" registered
2017-03-08 12:43:23.965963 Dev[1040:539154] PJSIP(4): pjsua_core.c .Nameserver 208.67.222.222 added
2017-03-08 12:43:23.966617 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-tsx-layer" registered
2017-03-08 12:43:23.966741 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-stateful-util" registered
2017-03-08 12:43:23.966868 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-ua" registered
2017-03-08 12:43:23.967801 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-100rel" registered
2017-03-08 12:43:23.967925 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-pjsua" registered
2017-03-08 12:43:23.968170 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-invite" registered
2017-03-08 12:43:24.144801 Dev[1040:539154] PJSIP(4): coreaudio_dev. .. dev_id 0: iPhone IO device (in=1, out=1) 8000Hz
2017-03-08 12:43:24.396221 Dev[1040:538862] provider:didActivateAudioSession:
2017-03-08 12:43:24.396523 Dev[1040:538862] [VERBOSE VoiceClient] Inside startAudioDevice, starting audio device.
2017-03-08 12:43:24.396791 Dev[1040:538862] PJSIP(4): pjsua_aud.c !Set sound device: capture=-1, playback=-2
2017-03-08 12:43:24.396982 Dev[1040:538862] PJSIP(1): pjsua_aud.c .Error retrieving default audio device parameters: Invalid audio device (PJMEDIA_EAUD_INVDEV) [status=420004]
2017-03-08 12:43:24.397200 Dev[1040:538862] [ERROR VoiceClient] Failed to start audio device.
2017-03-08 12:43:24.400933 Dev[1040:539154] PJSIP(4): coreaudio_dev. !..core audio initialized
2017-03-08 12:43:24.435158 Dev[1040:539154] PJSIP(4): pjlib ..select() I/O Queue created (0x109f68028)
2017-03-08 12:43:24.437339 Dev[1040:539154] PJSIP(5): conference.c ..Creating conference bridge with 40 ports
2017-03-08 12:43:24.437508 Dev[1040:539154] PJSIP(5): Master/sound ..Using delay buffer with WSOLA.
WARNING: no real random source present!
2017-03-08 12:43:24.443112 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-evsub" registered
2017-03-08 12:43:24.443363 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-presence" registered
2017-03-08 12:43:24.443861 Dev[1040:539154] PJSIP(5): evsub.c .Event pkg "presence" registered by mod-presence
2017-03-08 12:43:24.443961 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-mwi" registered
2017-03-08 12:43:24.444043 Dev[1040:539154] PJSIP(5): evsub.c .Event pkg "message-summary" registered by mod-mwi
2017-03-08 12:43:24.444120 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-refer" registered
2017-03-08 12:43:24.444199 Dev[1040:539154] PJSIP(5): evsub.c .Event pkg "refer" registered by mod-refer
2017-03-08 12:43:24.444298 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-pjsua-pres" registered
2017-03-08 12:43:24.444393 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-pjsua-im" registered
2017-03-08 12:43:24.455459 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-pjsua-options" registered
2017-03-08 12:43:24.456028 Dev[1040:539154] PJSIP(4): pjsua_core.c .1 SIP worker threads created
2017-03-08 12:43:24.456153 Dev[1040:539154] PJSIP(3): pjsua_core.c .pjsua version 2.5.1 for iOS-10.2.1/arm-iPhone7,2/iOS-SDK initialized
2017-03-08 12:43:24.456231 Dev[1040:539154] PJSIP(4): pjsua_core.c .PJSUA state changed: CREATED --> INIT
2017-03-08 12:43:24.456907 Dev[1040:539154] PJSIP(3): sip_endpoint.c Module "mod-twilio-msg-interceptor" can not be unregistered: Not found (PJ_ENOTFOUND)
2017-03-08 12:43:24.457062 Dev[1040:539154] PJSIP(4): sip_endpoint.c Module "mod-twilio-msg-interceptor" registered
2017-03-08 12:43:24.458124 Dev[1040:539154] [INFO Twilio] recreateMainTransport, Found valid IPv4 address: 105.250.237.86
2017-03-08 12:43:24.458837 Dev[1040:539154] PJSIP(4): tlstp:60344 SIP TLS listener is ready for incoming connections at 105.250.237.86:60344
2017-03-08 12:43:24.458951 Dev[1040:539154] PJSIP(4): pjsua_core.c PJSUA state changed: INIT --> STARTING
2017-03-08 12:43:24.466998 Dev[1040:539154] PJSIP(4): sip_endpoint.c .Module "mod-unsolicited-mwi" registered
2017-03-08 12:43:24.467223 Dev[1040:539154] PJSIP(4): pjsua_core.c .PJSUA state changed: STARTING --> RUNNING
2017-03-08 12:43:24.467868 Dev[1040:539154] [VERBOSE Twilio] Inside initWithConfig:, codec: speex/16000/1 -> priority: 255
2017-03-08 12:43:24.468089 Dev[1040:539154] [VERBOSE Twilio] Inside initWithConfig:, codec: speex/8000/1 -> priority: 254
2017-03-08 12:43:24.468648 Dev[1040:539154] [VERBOSE Twilio] Inside initWithConfig:, codec: speex/32000/1 -> priority: 0
2017-03-08 12:43:24.469651 Dev[1040:539154] [VERBOSE Twilio] Inside initWithConfig:, codec: PCMU/8000/1 -> priority: 128
2017-03-08 12:43:24.475992 Dev[1040:539154] [VERBOSE Twilio] Inside initWithConfig:, codec: PCMA/8000/1 -> priority: 0
2017-03-08 12:43:24.476428 Dev[1040:539154] [VERBOSE Twilio] Inside constructUri: Registration URL: sip:None@chunderm.gll.twilio.com;transport=tls
2017-03-08 12:43:24.478392 Dev[1040:539154] [INFO TVOMakeCallCommand] Call URI: sip:None@chunderm.gll.twilio.com;transport=tls
2017-03-08 12:43:24.481851 Dev[1040:539154] [DEBUG TVOConstants] X-Twilio-Client string: {"p":"ios","v":"2.0.0","mobile":{"arch":"arm64","product":"iPhone","name":"iPhone7,2","v":"10.2.1"}}, inside TVOConstants clientString
2017-03-08 12:43:24.482602 Dev[1040:539154] PJSIP(4): pjsua_acc.c Adding account: id=sip:twilio@chunderm.gll.twilio.com
2017-03-08 12:43:24.482759 Dev[1040:539154] PJSIP(4): pjsua_acc.c .Account sip:twilio@chunderm.gll.twilio.com added with id 0
2017-03-08 12:43:24.483751 Dev[1040:539154] [VERBOSE TVOCall] Inside makeCall, record permission was granted
2017-03-08 12:43:24.483855 Dev[1040:539154] PJSIP(4): pjsua_call.c Making call with acc #0 to sip:None@chunderm.gll.twilio.com;transport=tls
2017-03-08 12:43:24.483936 Dev[1040:539154] PJSIP(4): pjsua_aud.c .Set sound device: capture=-1, playback=-2
2017-03-08 12:43:24.484020 Dev[1040:539154] PJSIP(4): pjsua_aud.c ..Opening sound device (speaker + mic) PCM@16000/1/20ms
2017-03-08 12:43:24.484204 Dev[1040:539154] PJSIP(4): coreaudio_dev. ...Using VoiceProcessingIO audio unit
2017-03-08 12:43:24.812714 Dev[1040:539154] PJSIP(4): coreaudio_dev. ...core audio stream started
2017-03-08 12:43:24.825438 Dev[1040:539154] PJSIP(4): pjsua_acc.c .Warning: cannot use source TCP/TLS socket address for Contact when nameserver is configured.
2017-03-08 12:43:24.825657 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 .UAC dialog created
2017-03-08 12:43:24.825808 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 ..Session count inc to 2 by mod-pjsua
2017-03-08 12:43:24.825903 Dev[1040:539154] PJSIP(4): pjsua_media.c .Call 0: initializing media..
2017-03-08 12:43:24.826203 Dev[1040:539154] PJSIP(4): pjsua_media.c ..RTP socket reachable at 105.250.237.86:4738
2017-03-08 12:43:24.826303 Dev[1040:539154] PJSIP(4): pjsua_media.c ..RTCP socket reachable at 105.250.237.86:4739
2017-03-08 12:43:24.826640 Dev[1040:539154] PJSIP(4): pjsua_media.c ..Media index 0 selected for audio call 0
2017-03-08 12:43:24.827389 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 ..Session count dec to 2 by mod-pjsua
2017-03-08 12:43:24.828713 Dev[1040:539189] PJSIP(5): coreaudio_dev. !Recorder thread started, (372 frames)
2017-03-08 12:43:24.828804 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 !.Module mod-invite added as dialog usage, data=0x10ab11bd8
2017-03-08 12:43:24.836886 Dev[1040:539189] PJSIP(4): os_core_unix.c !Info: possibly re-registering existing thread
2017-03-08 12:43:24.836977 Dev[1040:539189] PJSIP(5): coreaudio_dev. !Player thread started, (372 frames)
2017-03-08 12:43:24.837128 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 ..Session count inc to 4 by mod-invite
2017-03-08 12:43:24.837252 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 !.Module mod-100rel added as dialog usage, data=0x10ab11efc
2017-03-08 12:43:24.837331 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 .100rel module attached
2017-03-08 12:43:24.837404 Dev[1040:539154] PJSIP(5): inv0x1069640a8 .UAC invite session created for dialog dlg0x1069640a8
2017-03-08 12:43:24.837570 Dev[1040:539154] PJSIP(5): endpoint .Request msg INVITE/cseq=2135 (tdta0x106210e00) created.
2017-03-08 12:43:24.840431 Dev[1040:539154] PJSIP(5): inv0x1069640a8 ..Sending Request msg INVITE/cseq=2135 (tdta0x106210e00)
2017-03-08 12:43:24.840638 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 ...Sending Request msg INVITE/cseq=2135 (tdta0x106210e00)
2017-03-08 12:43:24.840932 Dev[1040:539154] PJSIP(5): tsx0x10696e0a8 ....Transaction created for Request msg INVITE/cseq=2134 (tdta0x106210e00)
2017-03-08 12:43:24.841171 Dev[1040:539154] PJSIP(5): tsx0x10696e0a8 ...Sending Request msg INVITE/cseq=2134 (tdta0x106210e00) in state Null
2017-03-08 12:43:24.841432 Dev[1040:539154] PJSIP(5): sip_resolve.c ....Starting async DNS SRV query: target=_sips._tcp.chunderm.gll.twilio.com, transport=TLS, port=0
2017-03-08 12:43:24.841689 Dev[1040:539154] PJSIP(5): _sips._tcp.chu ....Starting async DNS SRV query_job: target=_sips._tcp.chunderm.gll.twilio.com:5061
2017-03-08 12:43:24.845241 Dev[1040:539154] PJSIP(5): tsx0x10696e0a8 ....State changed from Null to Calling, event=TX_MSG
2017-03-08 12:43:24.845541 Dev[1040:539154] PJSIP(5): dlg0x1069640a8 .....Transaction tsx0x10696e0a8 state changed to Calling
2017-03-08 12:43:24.846766 Dev[1040:539154] [DEBUG Twilio] Inside on_call_state(), call: 0x1702d1b80, internal state: 1
2017-03-08 12:43:24.847073 Dev[1040:539154] [VERBOSE Twilio] Inside on_call_state(), PJSIP_INV_STATE_CALLING
2017-03-08 12:43:24.847296 Dev[1040:539154] [VERBOSE TVOOutgoingCall] handlePJSIPInviteStateCalling. Error: (null)
2017-03-08 12:43:24.847507 Dev[1040:539154] [VERBOSE Twilio] on_call_tsx_state(), state: 1, status_code: 0: (null)
2017-03-08 12:43:24.987013 Dev[1040:539179] PJSIP(5): resolver.c !Received 208 bytes DNS response from 0.0.0.0:0
2017-03-08 12:43:24.987212 Dev[1040:539179] PJSIP(5): _sips._tcp.chu SRV query_job for _sips._tcp.chunderm.gll.twilio.com completed, 2 of 2 total entries selected:
2017-03-08 12:43:24.987413 Dev[1040:539179] PJSIP(5): _sips._tcp.chu 0: SRV 10 100 10194 chunderm0.ie1.twilio.com (-)
2017-03-08 12:43:24.987504 Dev[1040:539179] PJSIP(5): _sips._tcp.chu 1: SRV 10 100 10194 chunderm1.ie1.twilio.com (-)
2017-03-08 12:43:24.987588 Dev[1040:539179] PJSIP(5): _sips._tcp.chu Starting async DNS A query_job for chunderm0.ie1.twilio.com
2017-03-08 12:43:24.992165 Dev[1040:539179] PJSIP(5): _sips._tcp.chu Starting async DNS A query_job for chunderm1.ie1.twilio.com
2017-03-08 12:43:24.993484 Dev[1040:539179] PJSIP(5): resolver.c Received 82 bytes DNS response from 0.0.0.0:0
2017-03-08 12:43:24.993650 Dev[1040:539179] PJSIP(5): _sips._tcp.chu DNS A for chunderm0.ie1.twilio.com: 54.77.198.97
2017-03-08 12:43:24.994106 Dev[1040:539179] PJSIP(5): resolver.c Received 82 bytes DNS response from 0.0.0.0:0
2017-03-08 12:43:24.994529 Dev[1040:539179] PJSIP(5): _sips._tcp.chu DNS A for chunderm1.ie1.twilio.com: 54.77.198.98
2017-03-08 12:43:24.994675 Dev[1040:539179] PJSIP(5): _sips._tcp.chu Server resolution complete, 2 server entry(s) found
2017-03-08 12:43:24.995016 Dev[1040:539179] PJSIP(4): tlsc0x10697342 TLS client transport created
2017-03-08 12:43:24.995790 Dev[1040:539179] PJSIP(4): tlsc0x10697342 TLS transport 105.250.237.86:60345 is connecting to chunderm.gll.twilio.com:10194...
2017-03-08 12:43:24.999019 Dev[1040:539179] PJSIP(4): \367
2017-03-08 12:43:26.308014 Dev[1040:539179] [DEBUG Twilio] on_transport_state(): 0
2017-03-08 12:43:26.310786 Dev[1040:539179] [DEBUG Twilio] ------>Transport connected: 0x6973428, inside transportConnected:
2017-03-08 12:43:26.311397 Dev[1040:539179] PJSIP(4): tlsc0x10697342 TLS transport 105.250.237.86:60345 is connected to chunderm.gll.twilio.com:10194
2017-03-08 12:43:26.773260 Dev[1040:539179] PJSIP(5): sip_endpoint.c Processing incoming message: Response msg 302/INVITE/cseq=2134 (rdata0x106973740)
2017-03-08 12:43:26.775504 Dev[1040:539179] PJSIP(4): pjsua_core.c .RX 481 bytes Response msg 302/INVITE/cseq=2134 (rdata0x106973740) from TLS 54.77.198.97:10194:
SIP/2.0 302 Moved Temporarily
Via: SIP/2.0/TLS 105.250.237.86:60345;received=105.250.237.86;rport=60345;branch=z9hG4bKPjls0U8cHTjExLLszHBMEm8iOWw0kDnbig;alias
From: sip:twilio@chunderm.gll.twilio.com;tag=skAf-9floFfEVXZPCzw5hZCio0JhZruj
To: sip:None@chunderm.gll.twilio.com;tag=d47538de3dc305e6ad30a3af17018f93.f9f1
Call-ID: 5LtxAlocCwuefyPBKuhsu9ri.JfAqHKU
CSeq: 2134 INVITE
Contact: <sip:54.171.127.230:10194;transport=tls>
Server: Twilio Client SBC
Content-Length: 0
--end msg-- 2017-03-08 12:43:26.776593Dev[1040:539179] [VERBOSE Twilio] Inside on_rx_response(): received INVITE response, rewriting contact
2017-03-08 12:43:26.777938 Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 .Incoming Response msg 302/INVITE/cseq=2134 (rdata0x106973740) in state Calling
2017-03-08 12:43:26.778995 Dev[1040:539179] PJSIP(5): endpoint ..Request msg ACK/cseq=2134 (tdta0x10621c600) created.
2017-03-08 12:43:26.779986 Dev[1040:539179] PJSIP(4): pjsua_core.c ..TX 418 bytes Request msg ACK/cseq=2134 (tdta0x10621c600) to TLS 54.77.198.97:10194:
ACK sip:None@chunderm.gll.twilio.com;transport=tls SIP/2.0
Via: SIP/2.0/TLS 105.250.237.86:60345;rport;branch=z9hG4bKPjls0U8cHTjExLLszHBMEm8iOWw0kDnbig;alias
Max-Forwards: 70
From: sip:twilio@chunderm.gll.twilio.com;tag=skAf-9floFfEVXZPCzw5hZCio0JhZruj
To: sip:None@chunderm.gll.twilio.com;tag=d47538de3dc305e6ad30a3af17018f93.f9f1
Call-ID: 5LtxAlocCwuefyPBKuhsu9ri.JfAqHKU
CSeq: 2134 ACK
Content-Length: 0
--end msg-- 2017-03-08 12:43:26.782188Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 ..State changed from Calling to Completed, event=RX_MSG
2017-03-08 12:43:26.782510 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ...Received Response msg 302/INVITE/cseq=2134 (rdata0x106973740)
2017-03-08 12:43:26.782761 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ...Transaction tsx0x10696e0a8 state changed to Completed
2017-03-08 12:43:26.785418 Dev[1040:539179] [DEBUG Twilio] In on_call_redirected, call_id: 0, target: 0x10ab120d8, pjsip_event: 0x16e1a4638
2017-03-08 12:43:26.785912 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 .....Session count inc to 3 by mod-invite
2017-03-08 12:43:26.786480 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 .....Session count dec to 3 by mod-invite
2017-03-08 12:43:26.787121 Dev[1040:539179] PJSIP(5): inv0x1069640a8 .....Sending Request msg INVITE/cseq=2134 (tdta0x106210e00)
2017-03-08 12:43:26.787608 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ......Sending Request msg INVITE/cseq=2134 (tdta0x106210e00)
2017-03-08 12:43:26.788240 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 .......Transaction created for Request msg INVITE/cseq=2135 (tdta0x106210e00)
2017-03-08 12:43:26.788756 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 ......Sending Request msg INVITE/cseq=2135 (tdta0x106210e00) in state Null
2017-03-08 12:43:26.789286 Dev[1040:539179] PJSIP(5): sip_resolve.c .......Target '54.171.127.230:10194' type=TLS resolved to '54.171.127.230:10194' type=TLS (TLS transport)
2017-03-08 12:43:26.789916 Dev[1040:539179] PJSIP(4): tlsc0x10697ca2 .......TLS client transport created
2017-03-08 12:43:26.792388 Dev[1040:539179] PJSIP(4): tlsc0x10697ca2 .......TLS transport 105.250.237.86:60346 is connecting to 54.171.127.230:10194...
2017-03-08 12:43:26.794679 Dev[1040:539179] PJSIP(4): \367
2017-03-08 12:43:26.795255 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 .......State changed from Null to Calling, event=TX_MSG
2017-03-08 12:43:26.796130 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ........Transaction tsx0x10697b8a8 state changed to Calling
2017-03-08 12:43:26.797291 Dev[1040:539179] [VERBOSE Twilio] on_call_tsx_state(), state: 1, status_code: 0: (null)
2017-03-08 12:43:26.798268 Dev[1040:539179] [VERBOSE Twilio] on_call_tsx_state(), state: 4, status_code: 302: Moved Temporarily
2017-03-08 12:43:26.798860 Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 Timeout timer event
2017-03-08 12:43:26.799153 Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 .State changed from Completed to Terminated, event=TIMER
2017-03-08 12:43:26.799575 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ..Transaction tsx0x10696e0a8 state changed to Terminated
2017-03-08 12:43:26.800348 Dev[1040:539179] [VERBOSE Twilio] on_call_tsx_state(), state: 6, status_code: 302: Moved Temporarily
2017-03-08 12:43:26.801030 Dev[1040:539179] [DEBUG Twilio] ------>Destroying transport: 0x106973428, inside releaseTransport
2017-03-08 12:43:26.804880 Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 Timeout timer event
2017-03-08 12:43:26.805215 Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 .State changed from Terminated to Destroyed, event=TIMER
2017-03-08 12:43:26.805523 Dev[1040:539179] PJSIP(5): tdta0x10621c60 ..Destroying txdata Request msg ACK/cseq=2134 (tdta0x10621c600)
2017-03-08 12:43:26.805798 Dev[1040:539179] PJSIP(5): tsx0x10696e0a8 Transaction destroyed!
2017-03-08 12:43:29.315687 Dev[1040:539179] [DEBUG Twilio] on_transport_state(): 0
2017-03-08 12:43:29.316469 Dev[1040:539179] [DEBUG Twilio] ------>Transport connected: 0x697ca28, inside transportConnected:
2017-03-08 12:43:29.316782 Dev[1040:539179] PJSIP(4): tlsc0x10697ca2 TLS transport 105.250.237.86:60346 is connected to 54.171.127.230:10194
2017-03-08 12:43:30.032373 Dev[1040:539179] PJSIP(5): sip_endpoint.c Processing incoming message: Response msg 500/INVITE/cseq=2135 (rdata0x10697cd40)
2017-03-08 12:43:30.032713 Dev[1040:539179] PJSIP(4): pjsua_core.c .RX 531 bytes Response msg 500/INVITE/cseq=2135 (rdata0x10697cd40) from TLS 54.171.127.230:10194:
SIP/2.0 500 Server Internal Error
CSeq: 2135 INVITE
Call-ID: 5LtxAlocCwuefyPBKuhsu9ri.JfAqHKU
From: sip:twilio@chunderm.gll.twilio.com;tag=skAf-9floFfEVXZPCzw5hZCio0JhZruj
To: sip:None@chunderm.gll.twilio.com;tag=46541454_6772d868_e6f4c2df-e166-4a28-adf5-021884db6d04
Via: SIP/2.0/TLS 105.250.237.86:60346;rport=60346;branch=z9hG4bKPj.0ciAgjTJhbQ.QvOv9RmOOWnxcNI80oC;alias;received=105.250.237.86
Server: Twilio
Contact: <sip:ec2-54-171-127-230.eu-west-1.compute.amazonaws.com:10194;transport=tls>
Content-Length: 0
--end msg-- 2017-03-08 12:43:30.033437Dev[1040:539179] [VERBOSE Twilio] Inside on_rx_response(): received INVITE response, rewriting contact
2017-03-08 12:43:30.043785 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 .Incoming Response msg 500/INVITE/cseq=2135 (rdata0x10697cd40) in state Calling
2017-03-08 12:43:30.044467 Dev[1040:539179] PJSIP(5): endpoint ..Request msg ACK/cseq=2135 (tdta0x106981000) created.
2017-03-08 12:43:30.045056 Dev[1040:539179] PJSIP(4): pjsua_core.c ..TX 427 bytes Request msg ACK/cseq=2135 (tdta0x106981000) to TLS 54.171.127.230:10194:
ACK sip:54.171.127.230:10194;transport=tls SIP/2.0
Via: SIP/2.0/TLS 105.250.237.86:60346;rport;branch=z9hG4bKPj.0ciAgjTJhbQ.QvOv9RmOOWnxcNI80oC;alias
Max-Forwards: 70
From: sip:twilio@chunderm.gll.twilio.com;tag=skAf-9floFfEVXZPCzw5hZCio0JhZruj
To: sip:None@chunderm.gll.twilio.com;tag=46541454_6772d868_e6f4c2df-e166-4a28-adf5-021884db6d04
Call-ID: 5LtxAlocCwuefyPBKuhsu9ri.JfAqHKU
CSeq: 2135 ACK
Content-Length: 0
--end msg-- 2017-03-08 12:43:30.046490Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 ..State changed from Calling to Completed, event=RX_MSG
2017-03-08 12:43:30.048445 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ...Received Response msg 500/INVITE/cseq=2135 (rdata0x10697cd40)
2017-03-08 12:43:30.049118 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ...Transaction tsx0x10697b8a8 state changed to Completed
2017-03-08 12:43:30.049678 Dev[1040:539179] [VERBOSE Twilio] on_call_tsx_state(), state: 4, status_code: 500: Server Internal Error
2017-03-08 12:43:30.050344 Dev[1040:539179] [DEBUG Twilio] Inside on_call_state(), call: 0x1702d1b80, internal state: 1
2017-03-08 12:43:30.050920 Dev[1040:539179] [VERBOSE Twilio] Inside on_call_state(), PJSIP_INV_STATE_DISCONNECTED, internal state: 1, last_status: 500
2017-03-08 12:43:30.051518 Dev[1040:539179] [WARN Twilio] Inside Twilio.transportToTwilioErrorCode(): 500
2017-03-08 12:43:30.054122 Dev[1040:539179] [VERBOSE TVOOutgoingCall] handlePJSIPInviteStateDisconnected. Error: <TwilioError: 0x17464a4a0>
2017-03-08 12:43:30.062552 Dev[1040:539179] [DEBUG VoiceClient] Inside removeFromActiveOutgoingCalls:, remove outgoing call <TVOOutgoingCall: 0x1702d1b80> from active outgoing calls
2017-03-08 12:43:30.063139 Dev[1040:538862] outgoingCall:didFailWithError: Twilio Services Error
2017-03-08 12:43:30.063621 Dev[1040:538862] outgoingCall:didFailWithError: Error Domain=TwilioServicesErrorDomain Code=31000 "Twilio Services Error" UserInfo={NSLocalizedDescription=Twilio Services Error}
2017-03-08 12:43:30.065328 Dev[1040:539179] [DEBUG TVORTCMonitorThresholds] No thresholds specified. Default values will be applied.
2017-03-08 12:43:30.066843 Dev[1040:539179] [VERBOSE TVORTCMonitorThresholds] Thresholds for the RTC-monitor: {
"audio_input_level" = {
TVOEndpointAnalyticsThresholdMaxDuration = 10;
};
"audio_output_level" = {
TVOEndpointAnalyticsThresholdMaxDuration = 10;
};
jitter = {
TVOEndpointAnalyticsThresholdMax = 30;
};
mos = {
TVOEndpointAnalyticsThresholdMin = 3;
};
"packets_lost_fraction" = {
TVOEndpointAnalyticsThresholdMax = 1;
};
rtt = {
TVOEndpointAnalyticsThresholdMax = 400;
};
}
2017-03-08 12:43:30.068108 Dev[1040:539029] EndCallAction transaction request successful
2017-03-08 12:43:30.073846 Dev[1040:539179] [DEBUG Twilio] ------>Destroying transport: 0x10697ca28, inside releaseAllTransports
2017-03-08 12:43:30.074948 Dev[1040:538862] provider:performEndCallAction:
2017-03-08 12:43:30.075527 Dev[1040:538862] [VERBOSE VoiceClient] Inside stopAudioDevice, stopping audio device.
2017-03-08 12:43:30.078377 Dev[1040:539179] [DEBUG Twilio] on_transport_state(): 2
2017-03-08 12:43:30.078709 Dev[1040:539179] [DEBUG Twilio] ------>Transport disconnected: 0x10697ca28, inside transportDisconnected:
2017-03-08 12:43:30.078954 Dev[1040:539179] PJSIP(4): pjsua_media.c .....Call 0: deinitializing media..
2017-03-08 12:43:30.079061 Dev[1040:539179] PJSIP(4): pjsua_media.c ......Call 0: cleaning up provisional media, prov_med_cnt=1, med_cnt=0
2017-03-08 12:43:30.079685 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 .....Session count dec to 1 by mod-invite
2017-03-08 12:43:30.079819 Dev[1040:539179] PJSIP(5): tdta0x106210e0 ..Destroying txdata Request msg INVITE/cseq=2135 (tdta0x106210e00)
2017-03-08 12:43:30.080120 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 Timeout timer event
2017-03-08 12:43:30.080224 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 .State changed from Completed to Terminated, event=TIMER
2017-03-08 12:43:30.080317 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ..Transaction tsx0x10697b8a8 state changed to Terminated
2017-03-08 12:43:30.081550 Dev[1040:539179] PJSIP(5): dlg0x1069640a8 ...Dialog destroyed
2017-03-08 12:43:30.085417 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 Timeout timer event
2017-03-08 12:43:30.085547 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 .State changed from Terminated to Destroyed, event=TIMER
2017-03-08 12:43:30.085661 Dev[1040:539179] PJSIP(5): tdta0x10698100 ..Destroying txdata Request msg ACK/cseq=2135 (tdta0x106981000)
2017-03-08 12:43:30.088157 Dev[1040:539179] PJSIP(5): tsx0x10697b8a8 Transaction destroyed!
2017-03-08 12:43:30.088586 Dev[1040:539179] [DEBUG Twilio] on_transport_state(): 3
2017-03-08 12:43:30.096331 Dev[1040:539179] PJSIP(4): tlsc0x10697ca2 TLS transport destroyed normally
2017-03-08 12:43:32.040932 Dev[1040:538862] provider:didDeactivateAudioSession:
2017-03-08 12:43:33.080628 Dev[1040:539179] PJSIP(4): pjsua_aud.c Closing sound device after idle for 3 second(s)
2017-03-08 12:43:33.084323 Dev[1040:539179] PJSIP(4): pjsua_aud.c .Closing iPhone IO device sound playback device and iPhone IO device sound capture device
2017-03-08 12:43:33.085534 Dev[1040:539179] PJSIP(4): coreaudio_dev. .core audio stream stopped
2017-03-08 12:43:59.809407 Dev[1040:539179] [DEBUG Twilio] on_transport_state(): 3
2017-03-08 12:43:59.812502 Dev[1040:539179] PJSIP(4): tlsc0x10697342 TLS transport destroyed normally