success case ------------ [Sep 8 00:08:56] DEBUG[31225] pjsip: endpoint .Request msg CANCEL/cseq=20521 (tdta0x7ffddc036b80) created. [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: Method is CANCEL [Sep 8 00:08:56] DEBUG[31225] pjsip: inv0x7ffddc4a9 .Sending Request msg CANCEL/cseq=20521 (tdta0x7ffddc036b80) [Sep 8 00:08:56] DEBUG[31225] pjsip: dlg0x7ffddc4a9 ..Sending Request msg CANCEL/cseq=20521 (tdta0x7ffddc036b80) [Sep 8 00:08:56] DEBUG[31225] pjsip: tsx0x7ffddca6b ...Transaction created for Request msg CANCEL/cseq=20521 (tdta0x7ffddc036b80) [Sep 8 00:08:56] DEBUG[31225] pjsip: tsx0x7ffddca6b ..Sending Request msg CANCEL/cseq=20521 (tdta0x7ffddc036b80) in state Null [Sep 8 00:08:56] DEBUG[31225] pjsip: endpoint ...Request msg CANCEL/cseq=20521 (tdta0x7ffddc036b80): skipping target resolution because address is already set [Sep 8 00:08:56] DEBUG[31225] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 8 00:08:56] DEBUG[31225] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 8 00:08:56] DEBUG[31225] netsock2.c: Splitting '203.153.53.141:5060' into... [Sep 8 00:08:56] DEBUG[31225] netsock2.c: ...host '203.153.53.141' and port '5060'. [Sep 8 00:08:56] DEBUG[31225] pjsip: tsx0x7ffddca6b ...State changed from Null to Calling, event=TX_MSG [Sep 8 00:08:56] DEBUG[31225] pjsip: dlg0x7ffddc4a9 ....Transaction tsx0x7ffddca6b708 state changed to Calling [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: The state change pertains to the endpoint 'novanetpharma1(PJSIP/novanetpharma1-0000f547)' [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: The inv session still has an invite_tsx (0x7ffddc263ae8) [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: The UAC CANCEL transaction involved in this state change is 0x7ffddca6b708 [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: The current transaction state is Calling [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: The transaction state change event is TX_MSG [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: The current inv state is EARLY [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: Sending request [Sep 8 00:08:56] DEBUG[31225] res_pjsip_session.c: Method is CANCEL [Sep 8 00:08:56] DEBUG[27718] cdr.c: Finalized CDR for PJSIP/novanetpharma1-0000f547 - start 1441651086.135839 answer 0.000000 end 1441651136.913178 dispo FAILED [Sep 8 00:08:56] DEBUG[27718] cdr.c: Skipping CDR for PJSIP/novanetpharma1-0000f547 since we weren't answered [Sep 8 00:08:56] DEBUG[27716] devicestate.c: No provider found, checking channel drivers for PJSIP - novanetpharma1 [Sep 8 00:08:56] DEBUG[27716] devicestate.c: Changing state for PJSIP/novanetpharma1 - state 7 (Ring+Inuse) [Sep 8 00:08:56] DEBUG[27740] manager.c: Examining AMI event: Event: Hangup^M Privilege: call,all^M Channel: PJSIP/novanetpharma1-0000f547^M ChannelState: 0^M ChannelStateDesc: Down^M CallerIDNum: 5127176649^M CallerIDName: 5127176649^M ConnectedLineNum: 5127176649^M ConnectedLineName: 5127176649^M Language: en^M AccountCode: A090820150008050000861898^M Context: default^M Exten: s^M Priority: 1^M Failure case ------------ [Sep 8 00:09:05] DEBUG[34165] pjsip: endpoint .Request msg CANCEL/cseq=8486 (tdta0x7ffe44021e30) created. [Sep 8 00:09:05] DEBUG[29561][C-0000a7e9] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Sep 8 00:09:05] DEBUG[34165] res_pjsip_session.c: Method is CANCEL [Sep 8 00:09:05] DEBUG[27734] pjsip: sip_endpoint.c Processing incoming message: Response msg 180/INVITE/cseq=21617 (rdata0x7ffe4407ae38) [Sep 8 00:09:05] DEBUG[27734] netsock2.c: Splitting '192.168.1.137:32648' into... [Sep 8 00:09:05] DEBUG[27734] netsock2.c: ...host '192.168.1.137' and port '32648'. [Sep 8 00:09:05] DEBUG[34165] pjsip: inv0x7ffddc43a .Sending Request msg CANCEL/cseq=8486 (tdta0x7ffe44021e30) [Sep 8 00:09:05] DEBUG[27734] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 8 00:09:05] DEBUG[27734] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 8 00:09:05] DEBUG[34165] pjsip: dlg0x7ffddc43a ..Sending Request msg CANCEL/cseq=8486 (tdta0x7ffe44021e30) [Sep 8 00:09:05] DEBUG[34165] pjsip: tsx0x7ffddc453 ...Transaction created for Request msg CANCEL/cseq=8486 (tdta0x7ffe44021e30) [Sep 8 00:09:05] DEBUG[34165] pjsip: tsx0x7ffddc453 ..Sending Request msg CANCEL/cseq=8486 (tdta0x7ffe44021e30) in state Null [Sep 8 00:09:05] DEBUG[34165] pjsip: endpoint ...Request msg CANCEL/cseq=8486 (tdta0x7ffe44021e30): skipping target resolution because address is already set [Sep 8 00:09:05] DEBUG[31225] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 180/INVITE/cseq=21617 (rdata0x7ffe44055f28) [Sep 8 00:09:05] DEBUG[31225] pjsip: tsx0x7ffddc935 .Incoming Response msg 180/INVITE/cseq=21617 (rdata0x7ffe44055f28) in state Calling [Sep 8 00:09:05] DEBUG[31225] pjsip: tsx0x7ffddc935 ..State changed from Calling to Proceeding, event=RX_MSG [Sep 8 00:09:05] DEBUG[34165] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 8 00:09:05] DEBUG[31225] pjsip: dlg0x7ffddc21c ...Received Response msg 180/INVITE/cseq=21617 (rdata0x7ffe44055f28) [Sep 8 00:09:05] DEBUG[34165] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 8 00:09:05] DEBUG[34165] netsock2.c: Splitting '203.153.53.141:5060' into... [Sep 8 00:09:05] DEBUG[34165] netsock2.c: ...host '203.153.53.141' and port '5060'. [Sep 8 00:09:05] DEBUG[31225] pjsip: dlg0x7ffddc21c ....Route-set updated [Sep 8 00:09:05] DEBUG[31225] pjsip: dlg0x7ffddc21c ...Transaction tsx0x7ffddc935868 state changed to Proceeding [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: The state change pertains to the endpoint '2026(PJSIP/2026-0000f674)' [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: The inv session still has an invite_tsx (0x7ffddc935868) [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: There is no transaction involved in this state change [Sep 8 00:09:05] DEBUG[34165] pjsip: tsx0x7ffddc453 ...State changed from Null to Calling, event=TX_MSG [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: The current inv state is EARLY [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: Source of transaction state change is RX_MSG [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: Received response [Sep 8 00:09:05] DEBUG[34165] pjsip: dlg0x7ffddc43a ....Transaction tsx0x7ffddc453408 state changed to Calling [Sep 8 00:09:05] DEBUG[31225] res_pjsip_session.c: Response is 180 Ringing