[Jul 9 19:00:58] Asterisk SVN-trunk-r393816 built by root @ rnewton-office-lab on a i686 running Linux on 2013-07-08 18:47:30 UTC [Jul 9 19:00:58] DEBUG[22828] config.c: Parsing /etc/asterisk/logger.conf [Jul 9 19:00:58] VERBOSE[22828] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Jul 9 19:00:58] VERBOSE[22828] logger.c: Asterisk Queue Logger restarted [Jul 9 19:01:04] DEBUG[22802] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 9 19:01:04] DEBUG[22793] threadpool.c: Destroying worker thread 1 [Jul 9 19:01:09] DEBUG[22796] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 9 19:01:09] DEBUG[22793] threadpool.c: Destroying worker thread 0 [Jul 9 19:01:15] VERBOSE[22808] res_sip_logger.c: <--- Received SIP request (892 bytes) from UDP:10.24.18.16:5060 ---> INVITE sip:92345678888@10.24.17.228 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjBEKJELkPjF.axotmz5-WgOFZ5JfFjWmA Max-Forwards: 70 From: "RustyONE" ;tag=o2oVXFvmeLM-3tErKt4yar2A5WDKf4sa To: Contact: "RustyONE" Call-ID: QnkiSCT9rUKl7K7Qczssw.oRbiAhMqYy CSeq: 21384 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: Digium D40 1_3_2_0_54993 Content-Type: application/sdp Content-Length: 240 v=0 o=- 68785769 68785769 IN IP4 10.24.18.16 s=digphn c=IN IP4 10.24.18.16 t=0 0 a=X-nat:0 m=audio 4056 RTP/AVP 0 96 a=rtcp:4057 IN IP4 10.24.18.16 a=rtpmap:0 PCMU/8000 a=sendrecv a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.18.16' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.18.16' and port ''. [Jul 9 19:01:15] DEBUG[22813] res_sip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.17.228' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.17.228' and port ''. [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.18.16' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.18.16' and port ''. [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] VERBOSE[22813] res_sip_logger.c: <--- Transmitting SIP response (530 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.24.18.16:5060;rport;received=10.24.18.16;branch=z9hG4bKPjBEKJELkPjF.axotmz5-WgOFZ5JfFjWmA Call-ID: QnkiSCT9rUKl7K7Qczssw.oRbiAhMqYy From: "RustyONE" ;tag=o2oVXFvmeLM-3tErKt4yar2A5WDKf4sa To: ;tag=z9hG4bKPjBEKJELkPjF.axotmz5-WgOFZ5JfFjWmA CSeq: 21384 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1373414475/7cebedc642bd6fa4ecea5c1ffa8254a8",opaque="20eefd4f75b6f8cf",algorithm=md5,qop="auth" Content-Length: 0 [Jul 9 19:01:15] VERBOSE[22808] res_sip_logger.c: <--- Received SIP request (393 bytes) from UDP:10.24.18.16:5060 ---> ACK sip:92345678888@10.24.17.228 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjBEKJELkPjF.axotmz5-WgOFZ5JfFjWmA Max-Forwards: 70 From: "RustyONE" ;tag=o2oVXFvmeLM-3tErKt4yar2A5WDKf4sa To: ;tag=z9hG4bKPjBEKJELkPjF.axotmz5-WgOFZ5JfFjWmA Call-ID: QnkiSCT9rUKl7K7Qczssw.oRbiAhMqYy CSeq: 21384 ACK Content-Length: 0 [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.18.16' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.18.16' and port ''. [Jul 9 19:01:15] DEBUG[22813] res_sip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Jul 9 19:01:15] VERBOSE[22808] res_sip_logger.c: <--- Received SIP request (1191 bytes) from UDP:10.24.18.16:5060 ---> INVITE sip:92345678888@10.24.17.228 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjGSTo37kYCJXGmjvT9.tInmOLqSJ3vnCV Max-Forwards: 70 From: "RustyONE" ;tag=o2oVXFvmeLM-3tErKt4yar2A5WDKf4sa To: Contact: "RustyONE" Call-ID: QnkiSCT9rUKl7K7Qczssw.oRbiAhMqYy CSeq: 21385 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: Digium D40 1_3_2_0_54993 Authorization: Digest username="6001", realm="asterisk", nonce="1373414475/7cebedc642bd6fa4ecea5c1ffa8254a8", uri="sip:92345678888@10.24.17.228", response="c5566dffd0453627ca7c637f0e6a4716", algorithm=md5, cnonce="BC7lCUx0nu6oiFnHWG0y5ccO0GActrvj", opaque="20eefd4f75b6f8cf", qop=auth, nc=00000001 Content-Type: application/sdp Content-Length: 240 v=0 o=- 68785769 68785769 IN IP4 10.24.18.16 s=digphn c=IN IP4 10.24.18.16 t=0 0 a=X-nat:0 m=audio 4056 RTP/AVP 0 96 a=rtcp:4057 IN IP4 10.24.18.16 a=rtpmap:0 PCMU/8000 a=sendrecv a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.18.16' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.18.16' and port ''. [Jul 9 19:01:15] DEBUG[22813] res_sip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Jul 9 19:01:15] DEBUG[22813] res_sip_authenticator_digest.c: Calculated nonce 1373414475/7cebedc642bd6fa4ecea5c1ffa8254a8. Actual nonce is 1373414475/7cebedc642bd6fa4ecea5c1ffa8254a8 [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.17.228' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.17.228' and port ''. [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.18.16' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.18.16' and port ''. [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.18.16' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.18.16' and port ''. [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb6e1fa94' [Jul 9 19:01:15] DEBUG[22813] res_rtp_asterisk.c: Allocated port 16340 for RTP instance '0xb6e1fa94' [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.17.228' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.17.228' and port ''. [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: RTP instance '0xb6e1fa94' is setup and ready to go [Jul 9 19:01:15] DEBUG[22813] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb6e1fa94' [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.17.228' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.17.228' and port ''. [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: Setting payload 0 based on m type on 0xb6031618 [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: Setting payload 96 based on m type on 0xb6031618 [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: Copying payload 0 from 0xb6031618 to 0xb6e1fbbc [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: Copying payload 96 from 0xb6031618 to 0xb6e1fbbc [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Method is INVITE, Response is 100 Trying [Jul 9 19:01:15] VERBOSE[22813] res_sip_logger.c: <--- Transmitting SIP response (331 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.24.18.16:5060;rport;received=10.24.18.16;branch=z9hG4bKPjGSTo37kYCJXGmjvT9.tInmOLqSJ3vnCV Call-ID: QnkiSCT9rUKl7K7Qczssw.oRbiAhMqYy From: "RustyONE" ;tag=o2oVXFvmeLM-3tErKt4yar2A5WDKf4sa To: CSeq: 21385 INVITE Content-Length: 0 [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The state change pertains to the session with 6001 [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The inv session still has an invite_tsx (0xb6e112ec) [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: There is no transaction involved in this state change [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The current inv state is INCOMING [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Source of transaction state change is TX_MSG [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Sending response [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Method is INVITE, Response is 100 Trying [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The state change pertains to the session with 6001 [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The inv session still has an invite_tsx (0xb6e112ec) [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The transaction involved in this state change is 0xb6e112ec [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The current transaction state is Proceeding [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The transaction state change event is TX_MSG [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The current inv state is INCOMING [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Method is INVITE [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22793] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 19:01:15] DEBUG[22813] chan_gulp.c: Started PBX on new GULP channel Gulp/6001-00000000 [Jul 9 19:01:15] DEBUG[22840][C-00000000] pbx.c: Result of 'EXTEN' is '92345678888' [Jul 9 19:01:15] DEBUG[22840][C-00000000] pbx.c: Launching 'Dial' [Jul 9 19:01:15] VERBOSE[22840][C-00000000] pbx.c: -- Executing [92345678888@internal:1] Dial("Gulp/6001-00000000", "GULP/rustytel/sip:2345678888@10.24.18.124:5060") in new stack [Jul 9 19:01:15] DEBUG[22840][C-00000000] channel.c: Not copying variable DIALEDTIME. [Jul 9 19:01:15] DEBUG[22840][C-00000000] channel.c: Not copying variable ANSWEREDTIME. [Jul 9 19:01:15] DEBUG[22840][C-00000000] channel.c: Not copying variable DIALEDPEERNAME. [Jul 9 19:01:15] DEBUG[22840][C-00000000] channel.c: Not copying variable DIALEDPEERNUMBER. [Jul 9 19:01:15] DEBUG[22840][C-00000000] channel.c: Not copying variable DIALSTATUS. [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb6e460b4' [Jul 9 19:01:15] DEBUG[22813] res_rtp_asterisk.c: Allocated port 24064 for RTP instance '0xb6e460b4' [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.17.228' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.17.228' and port ''. [Jul 9 19:01:15] DEBUG[22813] rtp_engine.c: RTP instance '0xb6e460b4' is setup and ready to go [Jul 9 19:01:15] DEBUG[22813] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb6e460b4' [Jul 9 19:01:15] DEBUG[22813] netsock2.c: Splitting '10.24.17.228' into... [Jul 9 19:01:15] DEBUG[22813] netsock2.c: ...host '10.24.17.228' and port ''. [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Method is INVITE [Jul 9 19:01:15] VERBOSE[22813] res_sip_logger.c: <--- Transmitting SIP request (924 bytes) to UDP:10.24.18.124:5060 ---> INVITE sip:2345678888@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.17.228:5060;rport;branch=z9hG4bKPj5f1c917e-3583-4321-bb64-db0d87bf7ce1 Max-Forwards: 70 From: "Rusty Newton" ;tag=f1635e4b-456b-4df8-b5dd-63e7a9104173 To: sip:2345678888@10.24.18.124 Contact: Call-ID: 84447519-2880-49cf-bf31-e8e6571453ea CSeq: 2639 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 Content-Type: application/sdp Content-Length: 255 v=0 o=Asterisk 109924523 109924523 IN IP4 rnewton-office-lab s=Asterisk c=IN IP4 10.24.17.228 t=0 0 m=audio 24064 RTP/AVP 0 101 c=IN IP4 10.24.17.228 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 9 19:01:15] VERBOSE[22808] res_sip_logger.c: <--- Received SIP response (602 bytes) from UDP:10.24.18.124:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.24.17.228:5060;branch=z9hG4bKPj5f1c917e-3583-4321-bb64-db0d87bf7ce1;received=10.24.17.228;rport=5060 From: "Rusty Newton" ;tag=f1635e4b-456b-4df8-b5dd-63e7a9104173 To: sip:2345678888@10.24.18.124;tag=as221ff066 Call-ID: 84447519-2880-49cf-bf31-e8e6571453ea CSeq: 2639 INVITE Server: Asterisk PBX SVN-branch-1.8-r391778 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7570a22e" Content-Length: 0 [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The state change pertains to the session with rustytel [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The inv session still has an invite_tsx (0xb6e44dbc) [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: There is no transaction involved in this state change [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The current inv state is CALLING [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Source of transaction state change is TX_MSG [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Sending request [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Method is INVITE [Jul 9 19:01:15] VERBOSE[22840][C-00000000] app_dial.c: -- Called GULP/rustytel/sip:2345678888@10.24.18.124:5060 [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The state change pertains to the session with rustytel [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The inv session still has an invite_tsx (0xb6e44dbc) [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The transaction involved in this state change is 0xb6e44dbc [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The current transaction state is Calling [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The transaction state change event is TX_MSG [Jul 9 19:01:15] DEBUG[22813] res_sip_session.c: The current inv state is CALLING [Jul 9 19:01:15] VERBOSE[22814] res_sip_logger.c: <--- Transmitting SIP request (379 bytes) to UDP:10.24.18.124:5060 ---> ACK sip:2345678888@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.17.228:5060;rport;branch=z9hG4bKPj5f1c917e-3583-4321-bb64-db0d87bf7ce1 Max-Forwards: 70 From: "Rusty Newton" ;tag=f1635e4b-456b-4df8-b5dd-63e7a9104173 To: sip:2345678888@10.24.18.124;tag=as221ff066 Call-ID: 84447519-2880-49cf-bf31-e8e6571453ea CSeq: 2639 ACK Content-Length: 0 [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: Method is INVITE [Jul 9 19:01:15] VERBOSE[22814] res_sip_logger.c: <--- Transmitting SIP request (1099 bytes) to UDP:10.24.18.124:5060 ---> INVITE sip:2345678888@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.17.228:5060;rport;branch=z9hG4bKPjdc277148-adbf-4363-a5fd-fe26a7b405fc Max-Forwards: 70 From: "Rusty Newton" ;tag=f1635e4b-456b-4df8-b5dd-63e7a9104173 To: sip:2345678888@10.24.18.124 Contact: Call-ID: 84447519-2880-49cf-bf31-e8e6571453ea CSeq: 2640 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 Authorization: Digest username="blah", realm="asterisk", nonce="7570a22e", uri="sip:2345678888@10.24.18.124:5060", response="0f3690c6d30b950248c6d7d5299a5f55", algorithm=MD5 Content-Type: application/sdp Content-Length: 255 v=0 o=Asterisk 109924523 109924523 IN IP4 rnewton-office-lab s=Asterisk c=IN IP4 10.24.17.228 t=0 0 m=audio 24064 RTP/AVP 0 101 c=IN IP4 10.24.17.228 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The state change pertains to the session with rustytel [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The inv session still has an invite_tsx (0xb6c29ec4) [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The transaction involved in this state change is 0xb6c29ec4 [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The current transaction state is Calling [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The transaction state change event is TX_MSG [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The current inv state is CALLING [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The state change pertains to the session with rustytel [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The inv session still has an invite_tsx (0xb6c29ec4) [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The transaction involved in this state change is 0xb6e44dbc [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The current transaction state is Completed [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The transaction state change event is RX_MSG [Jul 9 19:01:15] VERBOSE[22808] res_sip_logger.c: <--- Received SIP response (587 bytes) from UDP:10.24.18.124:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.24.17.228:5060;branch=z9hG4bKPjdc277148-adbf-4363-a5fd-fe26a7b405fc;received=10.24.17.228;rport=5060 From: "Rusty Newton" ;tag=f1635e4b-456b-4df8-b5dd-63e7a9104173 To: sip:2345678888@10.24.18.124 Call-ID: 84447519-2880-49cf-bf31-e8e6571453ea CSeq: 2640 INVITE Server: Asterisk PBX SVN-branch-1.8-r391778 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 [Jul 9 19:01:15] DEBUG[22814] res_sip_session.c: The current inv state is CALLING