Closed GoogleCodeExporter closed 9 years ago
Below is my log file for your reference:
02-05 03:10:13.759 D/ConnectivityService( 745): ConnectivityChange for WIFI:
CONNECTED/CONNECTED
02-05 03:10:14.450 D/DynamicReceiver( 9982): Internal receive
android.net.conn.CONNECTIVITY_CHANGE
02-05 03:10:14.480 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:14.490 D/DynamicReceiver( 9982): onConnectivityChanged(): null ->
WIFI
02-05 03:10:14.490 D/SIP SRV ( 9982): Stop sip stack
02-05 03:10:14.490 D/PjService( 9982): >> SIP STOP <<
02-05 03:10:14.500 D/PjService( 9982): Detroying...
02-05 03:10:14.510 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:14.510 D/libpjsip( 9982): 03:10:14.518 pjsua_core.c !Shutting
down, flags=0...
02-05 03:10:14.510 D/libpjsip( 9982): 03:10:14.518 pjsua_core.c PJSUA state
changed: RUNNING --> CLOSING
02-05 03:10:14.510 D/libpjsip( 9982): 03:10:14.524 pjsua_call.c .Hangup all
calls..
02-05 03:10:14.510 D/libpjsip( 9982): 03:10:14.524 pjsua_pres.c .Shutting
down presence..
02-05 03:10:14.510 D/libpjsip( 9982): 03:10:14.526 pjsua_media.c .Shutting
down media..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_media.c ..Call 0:
deinitializing media..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_media.c ..Call 1:
deinitializing media..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_media.c ..Call 2:
deinitializing media..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_media.c ..Call 3:
deinitializing media..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ..Destroying
video subsystem..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ...Window 0:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ...Window 1:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ...Window 2:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ...Window 3:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ...Window 4:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.814 pjsua_vid.c ...Window 5:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window 6:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window 7:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window 8:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window 9:
destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window
10: destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window
11: destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window
12: destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window
13: destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window
14: destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 pjsua_vid.c ...Window
15: destroying..
02-05 03:10:14.801 D/libpjsip( 9982): 03:10:14.815 opensl_dev.c ..OpenSL
sound library shutting down..
02-05 03:10:15.571 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:15.581 D/Device State( 9982): Try to start service if not already
started
02-05 03:10:15.641 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:15.641 D/SIP SRV ( 9982): Direct sip start
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 pjsua_core.c
.Destroying...
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_transactio .Stopping
transaction layer module
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_transactio .Stopped
transaction layer module
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-unsolicited-mwi" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-pjsua-options" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-pjsua-im" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-pjsua-pres" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-pjsua" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-stateful-util" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-refer" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.823 sip_endpoint.c .Module
"mod-mwi" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-presence" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-evsub" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-invite" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-100rel" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-ua" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_transactio .Transaction
layer module destroyed
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-tsx-layer" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-reg-tracker" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-earlylock" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-opus-sdp-rewriter" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-msg-print" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.824 sip_endpoint.c .Module
"mod-pjsua-log" unregistered
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.825 tcplis:34396 .SIP TCP
listener destroyed
02-05 03:10:15.812 D/libpjsip( 9982): 03:10:15.825 tlslis:45075 .SIP TLS
listener destroyed
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.827 sip_endpoint.c .Endpoint
0x40f53c3c destroyed
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.827 stunresolve .Pool is not
released by application, releasing now
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.827 glck0x5bf48d40 .Pool is not
released by application, releasing now
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.827 stunresolve .Pool is not
released by application, releasing now
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.827 stunresolve .Pool is not
released by application, releasing now
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.828 pjsua_core.c .PJSUA state
changed: CLOSING --> NULL
02-05 03:10:15.822 D/libpjsip( 9982): 03:10:15.828 pjsua_core.c .PJSUA
destroyed...
02-05 03:10:15.822 I/MediaManager( 9982): Remove media manager....
02-05 03:10:15.822 D/BT8 ( 9982): Unregister BT media receiver
02-05 03:10:15.832 D/SIP SRV ( 9982): Accounts status.onChange( false)
02-05 03:10:15.832 D/SIP SRV ( 9982): Update registration state
02-05 03:10:15.832 D/SIP SRV ( 9982): Stop and unregister device receiver
02-05 03:10:15.842 D/SIP SRV ( 9982): Unregister telephony receiver
02-05 03:10:15.852 D/dalvikvm( 9982): WAIT_FOR_CONCURRENT_GC blocked 0ms
02-05 03:10:15.912 D/dalvikvm( 9982): GC_EXPLICIT freed 645K, 47% free
10484K/19523K, paused 7ms+12ms, total 63ms
02-05 03:10:16.012 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:16.012 D/SIP SRV ( 9982): Start was asked and we should actually
start now
02-05 03:10:16.012 D/SIP SRV ( 9982): Ask pjservice to start itself
02-05 03:10:16.022 D/PjService( 9982): Starting sip stack
02-05 03:10:16.973 I/PjService( 9982): Created 0
02-05 03:10:16.973 D/PjService( 9982): create ua receiver
02-05 03:10:16.973 D/SIP UA Receiver( 9982): Create async worker !!!
02-05 03:10:17.013 D/BT8 ( 9982): Register BT media receiver
02-05 03:10:17.013 D/BT8 ( 9982): >>> BT SCO state changed !!!
02-05 03:10:17.013 D/BT8 ( 9982): BT SCO state changed : 0 target is false
02-05 03:10:17.073 D/PjService( 9982): Attach is done to callback
02-05 03:10:17.183 D/PjService( 9982): Use OpenSL-ES implementation
02-05 03:10:17.253 D/PjService( 9982): add server
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.398 sip_endpoint.c .Module
"mod-pjsua-log" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.398 sip_endpoint.c .Module
"mod-tsx-layer" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.398 sip_endpoint.c .Module
"mod-stateful-util" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.399 sip_endpoint.c .Module
"mod-ua" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.399 sip_endpoint.c .Module
"mod-100rel" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.399 sip_endpoint.c .Module
"mod-pjsua" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.399 sip_endpoint.c .Module
"mod-invite" registered
02-05 03:10:17.393 D/libpjsip( 9982): 03:10:17.399 pjsua_core.c .Trying STUN
server (1 of 1)..
02-05 03:10:18.485 D/libpjsip( 9982): 03:10:18.493 pjsua_core.c .Error
starting STUN socket for : gethostbyname() has returned error (PJ_ERESOLVE)
02-05 03:10:18.485 E/libpjsip( 9982): 03:10:18.493 pjsua_core.c .STUN
resolution failed: gethostbyname() has returned error (PJ_ERESOLVE)
02-05 03:10:18.485 W/libpjsip( 9982): 03:10:18.493 pjsua_core.c .Ignoring
STUN resolution failure (by setting)
02-05 03:10:18.495 D/libpjsip( 9982): 03:10:18.501 pjlib ..select()
I/O Queue created (0x5c124e64)
02-05 03:10:18.495 D/libpjsip( 9982): 03:10:18.501 webrtc_codec.c ..List of
supported codec.
02-05 03:10:18.495 D/libpjsip( 9982): 03:10:18.502 webrtc_codec.c ..0 ISAC 103
16000 480 32000
02-05 03:10:18.495 D/libpjsip( 9982): 03:10:18.502 webrtc_codec.c ..5 ILBC 102
8000 240 13300
02-05 03:10:18.495 D/libpjsip( 9982): 03:10:18.502 silk.c ..SILK codec
version 1.0.9 initialized
02-05 03:10:18.495 D/libpjsip( 9982): 03:10:18.502 sip_endpoint.c ..Module
"mod-opus-sdp-rewriter" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.508 pjsua_vid.c
..Initializing video subsystem..
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.508 sip_endpoint.c .Module
"mod-evsub" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.508 sip_endpoint.c .Module
"mod-presence" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.509 sip_endpoint.c .Module
"mod-mwi" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.509 sip_endpoint.c .Module
"mod-refer" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.509 sip_endpoint.c .Module
"mod-pjsua-pres" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.509 sip_endpoint.c .Module
"mod-pjsua-im" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.509 sip_endpoint.c .Module
"mod-pjsua-options" registered
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.510 pjsua_core.c .1 SIP
worker threads created
02-05 03:10:18.505 I/libpjsip( 9982): 03:10:18.510 pjsua_core.c .pjsua
version 2.1-svn for initialized
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.510 pjsua_core.c .PJSUA state
changed: CREATED --> INIT
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.510 opensl_dev.c OpenSL sound
library initialized
02-05 03:10:18.505 D/libpjsip( 9982): 03:10:18.510 pjsua_jni_addo Loaded audio
dev
02-05 03:10:19.476 D/libpjsip( 9982): 03:10:19.480 pjsua_core.c SIP UDP
socket reachable at 192.168.1.3:38128
02-05 03:10:19.476 D/libpjsip( 9982): 03:10:19.480 udp0x5c02b678 SIP UDP
transport started, published address is 192.168.1.3:38128
02-05 03:10:19.476 D/libpjsip( 9982): 03:10:19.480 pjsua_acc.c Adding
account: id=<sip:192.168.1.3:38128>
02-05 03:10:19.476 D/libpjsip( 9982): 03:10:19.480 pjsua_acc.c .Account
<sip:192.168.1.3:38128> added with id 0
02-05 03:10:19.546 D/dalvikvm( 9982): WAIT_FOR_CONCURRENT_GC blocked 0ms
02-05 03:10:19.586 D/dalvikvm( 9982): GC_EXPLICIT freed 349K, 47% free
10453K/19523K, paused 3ms+4ms, total 38ms
02-05 03:10:20.437 D/libpjsip( 9982): 03:10:20.446 tcplis:54420 SIP TCP
listener ready for incoming connections at 192.168.1.3:54420
02-05 03:10:20.437 D/libpjsip( 9982): 03:10:20.446 pjsua_acc.c Adding
account: id=<sip:192.168.1.3:54420;transport=TCP>
02-05 03:10:20.437 D/libpjsip( 9982): 03:10:20.446 pjsua_acc.c .Account
<sip:192.168.1.3:54420;transport=TCP> added with id 1
02-05 03:10:21.428 D/libpjsip( 9982): 03:10:21.446 tlslis:57426 SIP TLS
listener is ready for incoming connections at 192.168.1.3:57426
02-05 03:10:21.428 D/libpjsip( 9982): 03:10:21.446 pjsua_acc.c Adding
account: id=<sip:192.168.1.3:57426;transport=TLS>
02-05 03:10:21.428 D/libpjsip( 9982): 03:10:21.446 pjsua_acc.c .Account
<sip:192.168.1.3:57426;transport=TLS> added with id 2
02-05 03:10:21.438 D/libpjsip( 9982): 03:10:21.452 sip_endpoint.c Module
"mod-earlylock" registered
02-05 03:10:21.438 D/libpjsip( 9982): 03:10:21.452 sip_endpoint.c Module
"mod-reg-tracker" registered
02-05 03:10:21.438 D/RegHandlerModule( 9982): Reg handler module added with
status 0
02-05 03:10:21.438 D/libpjsip( 9982): 03:10:21.452 pjsua_core.c PJSUA state
changed: INIT --> STARTING
02-05 03:10:21.438 E/libpjsip( 9982): 03:10:21.452 pjsua_media.c ..NAT type
detection failed: Invalid STUN server or server not configured
(PJNATH_ESTUNINSERVER)
02-05 03:10:21.448 D/libpjsip( 9982): 03:10:21.457 sip_endpoint.c .Module
"mod-unsolicited-mwi" registered
02-05 03:10:21.448 D/libpjsip( 9982): 03:10:21.458 pjsua_core.c .PJSUA state
changed: STARTING --> RUNNING
02-05 03:10:21.898 D/PjService( 9982): Audio codecs : PCMU/8000/1 (60) -
PCMA/8000/1 (50) - ISAC/16000/1 (1) - SILK/24000/1 (220) - opus/16000/1 (1) -
02-05 03:10:21.898 D/PjService( 9982): Video codecs :
02-05 03:10:21.938 D/DynamicReceiver( 9982): Start monitoring of route file ? 0
02-05 03:10:21.938 D/SIP SRV ( 9982): Listen for phone state
02-05 03:10:21.958 D/SIP SRV ( 9982): Add all accounts
02-05 03:10:21.958 D/SIP SRV ( 9982): We are adding all accounts right now....
02-05 03:10:22.008 D/PjSipAccount( 9982): Create proxy 0
02-05 03:10:22.058 D/libpjsip( 9982): 03:10:22.071 pjsua_acc.c Adding
account: id=<sip:xxxx@sipsorcery.com>
02-05 03:10:22.058 D/libpjsip( 9982): 03:10:22.071 pjsua_acc.c .Account
<sip:xxxx@sipsorcery.com> added with id 3
02-05 03:10:22.058 D/libpjsip( 9982): 03:10:22.072 pjsua_acc.c Acc 3:
setting registration..
02-05 03:10:23.109 D/libpjsip( 9982): 03:10:23.124 tcpc0x5c045f4c ..TCP client
transport created
02-05 03:10:23.109 D/libpjsip( 9982): 03:10:23.124 tcpc0x5c045f4c ..TCP
transport 192.168.1.3:58241 is connecting to 67.222.131.147:2060...
02-05 03:10:23.109 D/libpjsip( 9982): 03:10:23.124 pjsua_core.c ..TX 537
bytes Request msg REGISTER/cseq=32679 (tdta0x5c0446a8) to TCP
67.222.131.147:2060:
02-05 03:10:23.109 D/libpjsip( 9982): REGISTER
sip:sipsorcery.com:2060;transport=tcp;lr SIP/2.0
02-05 03:10:23.109 D/libpjsip( 9982): v: SIP/2.0/TCP
192.168.1.3:58241;rport;branch=z9hG4bKPjXZW8dsaSUk84drjZCJsG2sKETIAcv2oU;alias
02-05 03:10:23.109 D/libpjsip( 9982): Max-Forwards: 70
02-05 03:10:23.109 D/libpjsip( 9982): f:
<sip:xxxx@sipsorcery.com>;tag=O1K6AquYjHh8JF.cTazHrIk-JbBhoQGk
02-05 03:10:23.109 D/libpjsip( 9982): t: <sip:xxxx@sipsorcery.com>
02-05 03:10:23.109 D/libpjsip( 9982): i: pWeXxRBdypUZSR6zLWVOxO.x3X2O9rK2
02-05 03:10:23.109 D/libpjsip( 9982): CSeq: 32679 REGISTER
02-05 03:10:23.109 D/libpjsip( 9982): User-Agent: CSipSimple.G729
02-05 03:10:23.109 D/libpjsip( 9982): m:
<sip:xxxx@192.168.1.3:54420;transport=TCP>;+sip.ice
02-05 03:10:23.109 D/libpjsip( 9982): Expires: 900
02-05 03:10:23.109 D/libpjsip( 9982): Allow: PRACK, INVITE, ACK, BYE, CANCEL,
UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
02-05 03:10:23.109 D/libpjsip( 9982): l: 0
02-05 03:10:23.109 D/libpjsip( 9982):
02-05 03:10:23.109 D/libpjsip( 9982): --end msg--
02-05 03:10:23.119 D/libpjsip( 9982): 03:10:23.128 pjsua_acc.c .Acc 3:
Registration sent
02-05 03:10:23.119 D/DBProvider( 9982): Added status_text= status_code=-1
display_name=SIPSorcery expires=0 account_id=4 added_status=0 priority=0
active=true wizard=EXPERT reg_uri=sip:sipsorcery.com:2060 pjsua_id=3
02-05 03:10:23.119 D/libpjsip( 9982): 03:10:23.135 pjsua_acc.c Acc 3:
setting online status to 1..
02-05 03:10:23.129 D/SIP SRV ( 9982): Accounts status.onChange( false)
02-05 03:10:23.129 D/SIP SRV ( 9982): Update registration state
02-05 03:10:23.190 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:23.190 D/SIP SRV ( 9982): Start was asked and we should actually
start now
02-05 03:10:23.190 D/SIP SRV ( 9982): Ask pjservice to start itself
02-05 03:10:23.190 D/dalvikvm( 9982): WAIT_FOR_CONCURRENT_GC blocked 0ms
02-05 03:10:23.190 D/libpjsip( 9982): 03:10:23.204 tcpc0x5c045f4c !TCP
transport 192.168.1.3:58241 is connected to 67.222.131.147:2060
02-05 03:10:23.230 D/dalvikvm( 9982): GC_EXPLICIT freed 414K, 47% free
10478K/19523K, paused 3ms+6ms, total 45ms
02-05 03:10:23.250 D/DynamicReceiver( 9982): Internal receive
android.net.conn.CONNECTIVITY_CHANGE
02-05 03:10:23.260 D/libpjsip( 9982): 03:10:23.273 pjsua_core.c .RX 502
bytes Response msg 401/REGISTER/cseq=32679 (rdata0x5c0460fc) from TCP
67.222.131.147:2060:
02-05 03:10:23.260 D/libpjsip( 9982): SIP/2.0 401 Unauthorised
02-05 03:10:23.260 D/libpjsip( 9982): Via: SIP/2.0/TCP
192.168.1.3:58241;rport=58241;branch=z9hG4bKPjXZW8dsaSUk84drjZCJsG2sKETIAcv2oU;a
lias;received=67.173.9.164
02-05 03:10:23.260 D/libpjsip( 9982): To: <sip:xxxx@sipsorcery.com>
02-05 03:10:23.260 D/libpjsip( 9982): From:
<sip:xxxx@sipsorcery.com>;tag=O1K6AquYjHh8JF.cTazHrIk-JbBhoQGk
02-05 03:10:23.260 D/libpjsip( 9982): Call-ID: pWeXxRBdypUZSR6zLWVOxO.x3X2O9rK2
02-05 03:10:23.260 D/libpjsip( 9982): CSeq: 32679 REGISTER
02-05 03:10:23.260 D/libpjsip( 9982): WWW-Authenticate: Digest
realm="sipsorcery.com",nonce="16432337902066415797"
02-05 03:10:23.260 D/libpjsip( 9982): Content-Length: 0
02-05 03:10:23.260 D/libpjsip( 9982): Allow: ACK, BYE, CANCEL, INFO, INVITE,
NOTIFY, OPTIONS, REFER, REGISTER, SUBSCRIBE
02-05 03:10:23.260 D/libpjsip( 9982):
02-05 03:10:23.260 D/libpjsip( 9982): --end msg--
02-05 03:10:23.260 D/libpjsip( 9982): 03:10:23.274 mobile_reg_han
.mod_reg_tracker_on_rx_response
02-05 03:10:23.260 D/libpjsip( 9982): 03:10:23.274 mobile_reg_han
.mod_reg_tracker_on_rx_response done
02-05 03:10:23.270 D/PjService( 9982): Found pjsua 3 searching 3
02-05 03:10:23.270 D/RegHandlerReceiver( 9982): We restore
<sip:xxxx@67.173.9.164:60671;transport=TCP>;+sip.ice
02-05 03:10:23.270 D/libpjsip( 9982): 03:10:23.283 mobile_reg_han ....Hook a
RX request
02-05 03:10:23.270 D/libpjsip( 9982): 03:10:23.283 pjsua_core.c ....TX 792
bytes Request msg REGISTER/cseq=32680 (tdta0x5c0446a8) to TCP
67.222.131.147:2060:
02-05 03:10:23.270 D/libpjsip( 9982): REGISTER
sip:sipsorcery.com:2060;transport=tcp;lr SIP/2.0
02-05 03:10:23.270 D/libpjsip( 9982): v: SIP/2.0/TCP
192.168.1.3:58241;rport;branch=z9hG4bKPjyUfdWsmEPgoAg1fmBW-2.Piks3OqgjQf;alias
02-05 03:10:23.270 D/libpjsip( 9982): Max-Forwards: 70
02-05 03:10:23.270 D/libpjsip( 9982): f:
<sip:xxxx@sipsorcery.com>;tag=O1K6AquYjHh8JF.cTazHrIk-JbBhoQGk
02-05 03:10:23.270 D/libpjsip( 9982): t: <sip:xxxx@sipsorcery.com>
02-05 03:10:23.270 D/libpjsip( 9982): i: pWeXxRBdypUZSR6zLWVOxO.x3X2O9rK2
02-05 03:10:23.270 D/libpjsip( 9982): CSeq: 32680 REGISTER
02-05 03:10:23.270 D/libpjsip( 9982): User-Agent: CSipSimple.G729
02-05 03:10:23.270 D/libpjsip( 9982): m:
<sip:xxxx@192.168.1.3:54420;transport=TCP>;+sip.ice
02-05 03:10:23.270 D/libpjsip( 9982): Expires: 900
02-05 03:10:23.270 D/libpjsip( 9982): Allow: PRACK, INVITE, ACK, BYE, CANCEL,
UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
02-05 03:10:23.270 D/libpjsip( 9982): Authorization: Digest username="xxxx",
realm="sipsorcery.com", nonce="16432337902066415797",
uri="sip:sipsorcery.com:2060;transport=tcp;lr",
response="5de29825d85d4755b534bac36a945403"
02-05 03:10:23.270 D/libpjsip( 9982): m:
<sip:xxxx@67.173.9.164:60671;transport=TCP>;expires=0;+sip.ice
02-05 03:10:23.280 D/libpjsip( 9982): l: 0
02-05 03:10:23.280 D/libpjsip( 9982):
02-05 03:10:23.280 D/libpjsip( 9982): --end msg--
02-05 03:10:23.290 D/Prefs ( 9982): We are valid for WIFI
02-05 03:10:23.290 D/DynamicReceiver( 9982): onConnectivityChanged(): null ->
WIFI
02-05 03:10:23.460 D/libpjsip( 9982): 03:10:23.469 pjsua_core.c .RX 476
bytes Response msg 200/REGISTER/cseq=32680 (rdata0x5c0460fc) from TCP
67.222.131.147:2060:
02-05 03:10:23.460 D/libpjsip( 9982): SIP/2.0 200 Ok
02-05 03:10:23.460 D/libpjsip( 9982): Via: SIP/2.0/TCP
192.168.1.3:58241;rport=58241;branch=z9hG4bKPjyUfdWsmEPgoAg1fmBW-2.Piks3OqgjQf;a
lias;received=67.173.9.164
02-05 03:10:23.460 D/libpjsip( 9982): To:
<sip:xxxx@sipsorcery.com>;tag=SGTRMDEVXE
02-05 03:10:23.460 D/libpjsip( 9982): From:
<sip:xxxx@sipsorcery.com>;tag=O1K6AquYjHh8JF.cTazHrIk-JbBhoQGk
02-05 03:10:23.460 D/libpjsip( 9982): Call-ID: pWeXxRBdypUZSR6zLWVOxO.x3X2O9rK2
02-05 03:10:23.460 D/libpjsip( 9982): CSeq: 32680 REGISTER
02-05 03:10:23.460 D/libpjsip( 9982): Contact:
<sip:xxxx@192.168.1.3:54420;transport=TCP>;expires=900
02-05 03:10:23.460 D/libpjsip( 9982): Date: Wed, 05 Feb 2014 09:10:24 GMT
02-05 03:10:23.460 D/libpjsip( 9982): Content-Length: 0
02-05 03:10:23.460 D/libpjsip( 9982): Server: www.sipsorcery.com
02-05 03:10:23.460 D/libpjsip( 9982):
02-05 03:10:23.460 D/libpjsip( 9982): --end msg--
02-05 03:10:23.460 D/libpjsip( 9982): 03:10:23.469 mobile_reg_han
.mod_reg_tracker_on_rx_response
02-05 03:10:23.460 D/libpjsip( 9982): 03:10:23.469 mobile_reg_han
.mod_reg_tracker_on_rx_response 2
02-05 03:10:23.460 D/libpjsip( 9982): 03:10:23.469 mobile_reg_han .Hook a
REGISTER RX response !!!
02-05 03:10:23.460 D/libpjsip( 9982): 03:10:23.469 mobile_reg_han . Hook
should save contact : <sip:xxxx@192.168.1.3:54420;transport=TCP>;+sip.ice > 900
02-05 03:10:23.660 D/PjService( 9982): Found pjsua 3 searching 3
02-05 03:10:23.680 D/libpjsip( 9982): 03:10:23.691 mobile_reg_han
.mod_reg_tracker_on_rx_response done
02-05 03:10:23.690 D/libpjsip( 9982): 03:10:23.701 pjsua_acc.c ....SIP
outbound status for acc 3 is not active
02-05 03:10:23.690 I/libpjsip( 9982): 03:10:23.701 pjsua_acc.c ....IP
address change detected for account 3 (192.168.1.3:54420 -->
67.173.9.164:58241). Updating registration (using method 2)
02-05 03:10:23.690 D/libpjsip( 9982): 03:10:23.701 pjsua_acc.c ....Acc 3:
setting registration..
02-05 03:10:24.571 D/PjService( 9982): Found pjsua 3 searching 3
02-05 03:10:24.571 D/RegHandlerReceiver( 9982): We restore
<sip:xxxx@192.168.1.3:54420;transport=TCP>;+sip.ice
02-05 03:10:24.571 D/libpjsip( 9982): 03:10:24.581 mobile_reg_han ......The
register already has old contact in it, ignore
02-05 03:10:24.571 D/libpjsip( 9982): 03:10:24.581 pjsua_core.c ......TX 792
bytes Request msg REGISTER/cseq=32681 (tdta0x5c0493e8) to TCP
67.222.131.147:2060:
02-05 03:10:24.571 D/libpjsip( 9982): REGISTER
sip:sipsorcery.com:2060;transport=tcp;lr SIP/2.0
02-05 03:10:24.571 D/libpjsip( 9982): v: SIP/2.0/TCP
192.168.1.3:58241;rport;branch=z9hG4bKPjyMlCfbKeLIogKi514PsXOdqLex6CxE3X;alias
02-05 03:10:24.571 D/libpjsip( 9982): Max-Forwards: 70
02-05 03:10:24.571 D/libpjsip( 9982): f:
<sip:xxxx@sipsorcery.com>;tag=wBJN6ReoTlSLeTX1KI0tMJoFI5202guZ
02-05 03:10:24.571 D/libpjsip( 9982): t: <sip:xxxx@sipsorcery.com>
02-05 03:10:24.571 D/libpjsip( 9982): i: pWeXxRBdypUZSR6zLWVOxO.x3X2O9rK2
02-05 03:10:24.571 D/libpjsip( 9982): CSeq: 32681 REGISTER
02-05 03:10:24.571 D/libpjsip( 9982): Authorization: Digest username="xxxx",
realm="sipsorcery.com", nonce="16432337902066415797",
uri="sip:sipsorcery.com:2060;transport=tcp;lr",
response="5de29825d85d4755b534bac36a945403"
02-05 03:10:24.571 D/libpjsip( 9982): User-Agent: CSipSimple.G729
02-05 03:10:24.571 D/libpjsip( 9982): m:
<sip:xxxx@67.173.9.164:58241;transport=TCP>;+sip.ice
02-05 03:10:24.571 D/libpjsip( 9982): m:
<sip:xxxx@192.168.1.3:54420;transport=TCP>;expires=0;+sip.ice
02-05 03:10:24.571 D/libpjsip( 9982): Expires: 900
02-05 03:10:24.571 D/libpjsip( 9982): Allow: PRACK, INVITE, ACK, BYE, CANCEL,
UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
02-05 03:10:24.571 D/libpjsip( 9982): l: 0
02-05 03:10:24.571 D/libpjsip( 9982):
02-05 03:10:24.571 D/libpjsip( 9982): --end msg--
02-05 03:10:24.581 D/libpjsip( 9982): 03:10:24.587 pjsua_acc.c .....Acc 3:
Registration sent
02-05 03:10:24.661 D/libpjsip( 9982): 03:10:24.672 pjsua_core.c .RX 477
bytes Response msg 200/REGISTER/cseq=32681 (rdata0x5c0460fc) from TCP
67.222.131.147:2060:
02-05 03:10:24.661 D/libpjsip( 9982): SIP/2.0 200 Ok
02-05 03:10:24.661 D/libpjsip( 9982): Via: SIP/2.0/TCP
192.168.1.3:58241;rport=58241;branch=z9hG4bKPjyMlCfbKeLIogKi514PsXOdqLex6CxE3X;a
lias;received=67.173.9.164
02-05 03:10:24.661 D/libpjsip( 9982): To:
<sip:xxxx@sipsorcery.com>;tag=MOACJKMSBG
02-05 03:10:24.661 D/libpjsip( 9982): From:
<sip:xxxx@sipsorcery.com>;tag=wBJN6ReoTlSLeTX1KI0tMJoFI5202guZ
02-05 03:10:24.661 D/libpjsip( 9982): Call-ID: pWeXxRBdypUZSR6zLWVOxO.x3X2O9rK2
02-05 03:10:24.661 D/libpjsip( 9982): CSeq: 32681 REGISTER
02-05 03:10:24.661 D/libpjsip( 9982): Contact:
<sip:xxxx@67.173.9.164:58241;transport=TCP>;expires=900
02-05 03:10:24.661 D/libpjsip( 9982): Date: Wed, 05 Feb 2014 09:10:25 GMT
02-05 03:10:24.661 D/libpjsip( 9982): Content-Length: 0
02-05 03:10:24.661 D/libpjsip( 9982): Server: www.sipsorcery.com
02-05 03:10:24.661 D/libpjsip( 9982):
02-05 03:10:24.661 D/libpjsip( 9982): --end msg--
02-05 03:10:24.661 D/libpjsip( 9982): 03:10:24.675 mobile_reg_han
.mod_reg_tracker_on_rx_response
02-05 03:10:24.661 D/libpjsip( 9982): 03:10:24.676 mobile_reg_han
.mod_reg_tracker_on_rx_response 2
02-05 03:10:24.661 D/libpjsip( 9982): 03:10:24.676 mobile_reg_han .Hook a
REGISTER RX response !!!
02-05 03:10:24.661 D/libpjsip( 9982): 03:10:24.676 mobile_reg_han . Hook
should save contact : <sip:xxxx@67.173.9.164:58241;transport=TCP>;+sip.ice > 900
02-05 03:10:24.671 D/PjService( 9982): Found pjsua 3 searching 3
02-05 03:10:24.701 D/libpjsip( 9982): 03:10:24.712 mobile_reg_han
.mod_reg_tracker_on_rx_response done
02-05 03:10:24.711 D/libpjsip( 9982): 03:10:24.726 pjsua_acc.c ....SIP
outbound status for acc 3 is not active
02-05 03:10:24.711 I/libpjsip( 9982): 03:10:24.726 pjsua_acc.c
....<sip:xxxx@sipsorcery.com>: registration success, status=200 (Ok), will
re-register in 900 seconds
02-05 03:10:24.711 D/SIP UA Receiver( 9982): < LOCK CPU
02-05 03:10:24.721 D/PjService( 9982): Found pjsua 3 searching 3
02-05 03:10:24.731 D/PjService( 9982): Update profile from service for 3 aka in
db 4
02-05 03:10:24.731 D/SIP UA Receiver( 9982): > UNLOCK CPU 0
02-05 03:10:24.731 D/DBProvider( 9982): Updated status_text=OK status_code=200
display_name=SIPSorcery expires=894 account_id=4 added_status=0 priority=0
active=true wizard=EXPERT reg_uri=sip:sipsorcery.com:2060 pjsua_id=3
02-05 03:10:24.741 D/PjService( 9982): Profile state UP : status_text=OK
status_code=200 expires=894
02-05 03:10:24.771 D/SIP SRV ( 9982): Accounts status.onChange( false)
02-05 03:10:24.771 D/SIP SRV ( 9982): Update registration state
Original comment by phtr...@gmail.com
on 5 Feb 2014 at 10:40
It's a software design choice. In order to clear all state of the sip stack
it's choosen to stop and restart totally the stack. It's the shorter way to do
and is not so bad compared to alternative that are bug prone
(http://trac.pjsip.org/repos/wiki/IPAddressChange). Also in android it's
advised to wait a little so that the network layer is fully ready again for
transport.
BTW, I think that this is the delay you observe, the sip stack restart does not
take so many time that it should be noticeable.
If you have a close look to logs, you'll see that it restarts in 7 seconds
(10:17 to 10:24) and that half of this time is spent trying to bind local
sockets and resolving network :
17 -> 18 : spent to request stun server... that is unresolvable ! (what is your
stun config? maybe there is a problem here, or maybe the network layer is not
yet fully ready)
18 -> 19 : spent to bind udp socket
19 -> 20 : spent to bind tcp socket
20 -> 21 : spetn to bind tls socket => do you need it, maybe you can disable
this option and save 1 second?
after that time is spend in network communication (and the app receive at 10:23
a final confirmation of the fact the network layer is fully ready) (
02-05 03:10:23.290 D/DynamicReceiver( 9982): onConnectivityChanged(): null ->
WIFI)
So, compared to a solution where you have registration changed and all
interface rebound as listening socket... there is no performance difference at
all ! If we compare between a precise solution that would only rebind listening
sockets on new interfaces + send a re-register and a solution that restarts the
entire stack : the long time spent is time spent to re-bind sockets and to
re-register. It's not time spent allocating pjsip stack and modules and
launching them (maybe the only small thing that takes time from your logs is
the codec allocation, but it's very few time compared to the rest).
Another point : during the time of the restart you are actually not connected
to the server, and IMHO it's good to remove the csipsimple icon from
notification bar during this time.
Original comment by r3gis...@gmail.com
on 5 Feb 2014 at 3:50
>>the long time spent is time spent to re-bind sockets and to re-register.
Actually, we don't need to bind udp/tcp/tls before making network connection if
RFC5626 is used. The only necessary spending in this case is from 10:22.058 to
10:23.460, if I disable the stun server totally.
At least we can schedule the stack-destruction task right after the NetworkOff
event, without changing the current design structure too much, right?
Original comment by phtr...@gmail.com
on 5 Feb 2014 at 5:28
we don't need to bind udp/tcp/tls before making network connection if RFC5626 is used.
Yep you are right. I didn't thought about this case. Indeed if rfc5626 is
supported by server with TCP or TLS there's something that could maybe done. It
would not be very simple implementation however because when android tell app a
network type is lost it does not tells a new one will come soon. And in case
none come I would like to keep the current behavior (stack and service stopped
and consuming no more CPU)
So, I change the issue state to accepted enhancement. It does not go in my
personal task list however because I personnaly don't see big benefit to that +
is at risk that some changes has to be made in pjsip layer + have few free time
for csipsimple those days and free time will be spent on more critical problems
;). But if anyone contribute a robust solution for this, it will be welcome :)
>> At least we can schedule the stack-destruction task right after the
NetworkOff event
Mmmh, should be the case. what do you consider to be the "network off" event in
terms of android SDK? Normally as soon as network changes (lost or change)
(except if a hidden hacky option of CSipSimple is used or if there is an
ongoing call) the sip service is stopped (restarted) immediately if I don't
mistake (but I could have forgot things on this part : it's a stable one that I
didn't changed for a while)
Original comment by r3gis...@gmail.com
on 5 Feb 2014 at 11:01
Original comment by r3gis...@gmail.com
on 22 Jun 2015 at 11:31
Original issue reported on code.google.com by
phtr...@gmail.com
on 5 Feb 2014 at 10:38