[asterisk-bugs] [JIRA] (ASTERISK-26490) res_pjsip: Channel driver sometimes sends 481 Call/Transaction Does Not Exist

[Rusty Newton (JIRA)]

    [ https://issues.asterisk.org/jira/browse/ASTERISK-26490?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=233349#comment-233349 ] 

Rusty Newton edited comment on ASTERISK-26490 at 11/2/16 3:21 PM:
------------------------------------------------------------------

Well, I see what is happening, but I'm not sure why it is happening.

Some further information would help.

We'd like to get another log file that includes the pjproject debug. This will show us when the INVITE transaction was destroyed so we can see if the transaction was actually destroyed before the CANCEL was received and possibly see whether it was destroyed for a proper reason. There may be something killing the transaction before it should be killed. Maybe the system is just overloaded and can't handle the transaction somehow.

*If you are not using bundled PJPROJECT* then you can simply provide an Asterisk log with the following log channel types: (warning,notice,error,verbose,debug) and be sure to turn verbose and debug up to level 5.

Be sure to include the output of "pjsip set logger on" in that same log.

*If you are using bundled PJPROJECT* then you'll need to make a source code modification in addition to getting a log with the channels and levels as described above.

In your Asterisk source make sure to re-run configure, then open up and edit: third-party/pjproject/source/pjlib/include/pj/config_site.h

Set the PJ_LOG_MAX_LEVEL define to 5 instead of 3

{noformat}
#define PJ_LOG_MAX_LEVEL 3
{noformat}
Change that to
{noformat}
#define PJ_LOG_MAX_LEVEL 5
{noformat}

Then, make and make install of course.

Now grab the debug described and make sure it includes messages that look like these:

{noformat}
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=311 (rdata0x7f7e54005c88)
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	      endpoint .Response msg 401/INVITE/cseq=311 (tdta0x7f7e0c001c90) created
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	tdta0x7f7e0c00 .Destroying txdata Response msg 401/INVITE/cseq=311 (tdta0x7f7e0c001c90)
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	tsx0x7f7e0c00f ..Transaction created for Request msg INVITE/cseq=311 (rdata0x7f7e54005c88)
{noformat}

That is, DEBUG messages that begin with "pjproject:"

The log needs to include everything from the very beginning of the call in question so that we can hopefully see where the transaction are created and where they are destroyed.

We should be able to use the INVITE's cseq number to find its tdta* numbers then use those to follow the transactions.


was (Author: rnewton):
Well, I see what is happening, but I'm not sure why it is happening.

Some further information would help.

We'd like to get another log file that includes the pjproject debug. This will show us when the INVITE transaction was destroyed so we can see if the transaction was actually destroyed before the CANCEL was received and possibly see whether it was destroyed for a proper reason. There may be something killing the transaction before it should be killed. Maybe the system is just overloaded and can't handle the transaction somehow.

*If you are not using bundled PJPROJECT* then you can simply provide an Asterisk log with the following log channel types: (warning,notice,error,verbose,debug) and be sure to turn verbose and debug up to level 5.

Be sure to include the output of "pjsip set logger on" in that same log.

*If you are using bundled PJPROJECT* then you'll need to make a source code modification in addition to getting a log with the channels and levels as described above.

In your Asterisk source make sure to re-run configure, then open up and edit: third-party/pjproject/source/pjlib/include/pj/config_site.h

Set the PJ_LOG_MAX_LEVEL define to 5 instead of 3

{noformat}
#define PJ_LOG_MAX_LEVEL 3
{noformat}
Change that to
{noformat}
#define PJ_LOG_MAX_LEVEL 5
{noformat}

Then, make and make install of course.

Now grab the debug described and make sure it has these messages included:

{noformat}
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=311 (rdata0x7f7e54005c88)
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	      endpoint .Response msg 401/INVITE/cseq=311 (tdta0x7f7e0c001c90) created
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	tdta0x7f7e0c00 .Destroying txdata Response msg 401/INVITE/cseq=311 (tdta0x7f7e0c001c90)
[Nov  2 13:14:08] DEBUG[8893] pjproject: 	tsx0x7f7e0c00f ..Transaction created for Request msg INVITE/cseq=311 (rdata0x7f7e54005c88)
{noformat}

That is, DEBUG messages that begin with "pjproject:"

The log needs to include everything from the very beginning of the call in question so that we can hopefully see where the transaction are created and where they are destroyed.

We should be able to use the INVITE's cseq number to find its tdta* numbers then use those to follow the transactions.

> res_pjsip: Channel driver sometimes sends 481 Call/Transaction Does Not Exist
> -----------------------------------------------------------------------------
>
>                 Key: ASTERISK-26490
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-26490
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: pjproject/pjsip, Resources/res_pjsip
>    Affects Versions: 13.11.2
>         Environment: Linux 4.4.19-1-pve #1 SMP x86_64 x86_64 x86_64 GNU/Linux
>            Reporter: Juris Breicis
>            Assignee: Juris Breicis
>         Attachments: 2_mss_smex_capture.log.pcap, asterisk_log.txt, extensions.conf, extensions.conf, MSS_SIP_TRACE_ISSUES.txt, pjsip.conf
>
>
> In this particular setup asterisk 13.11.2 [10.40.6.100] is connected to NSN MSS through SIP trunk [212.210.2.2:5060]. The calls are received and routed back through the same trunk. Randomly the PJSIP will reply 481 Call/Transaction Does Not Exist to the trunk's CANCEL request of ongoing call in Ringing state. And sometimes (for no apparent reason) it just processes CANCEL request as expected.
> I have attached console dump with: 
> core set debug 10 
> core set verbose 10
> pjsip set logging on
> and corresponding sections of pjsip.conf and extensions.conf
> Please note although it looks like internal network 10.X.X.X is communicating through nat with public one 212.X.X.X - the routers are configured so, that this communication happens without NAT directly machine to machine. 



--
This message was sent by Atlassian JIRA
(v6.2#6252)