Hello, I've noticed that pjsip (seen at least with 2.5.5 and 2.6) is not destroying SIP OPTIONS dialogs (at least over 100 or so still in memory), causing memory to continuously grow. I verified this by performing a `pjsua_dump(true);` after my process (a UAS/SIP trunk) has been running for some time. I am using pjsua2 FWIW. Here is an example dialog with the log level set to 9: 01:24:29.729 sip_endpoint.c Processing incoming message: Request msg OPTIONS/cseq=101 (rdata0x7f8160e9fb58) 01:24:29.729 pjsua_core.c .RX 372 bytes Request msg OPTIONS/cseq=101 (rdata0x7f8160e9fb58) from UDP 10.x.x.3:5070: OPTIONS sip:10.x.x.240:5070 SIP/2.0 Via: SIP/2.0/UDP 10.x.x.3:5070;branch=z9hG4bK1ca35f62036d1c From: <sip:10.x.x.3>;tag=1262409931 To: <sip:10.x.x.240> Date: Tue, 22 Aug 2017 05:24:29 GMT Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 User-Agent: Cisco-CUCM10.5 CSeq: 101 OPTIONS Contact: <sip:10.x.x.3:5070> Max-Forwards: 0 Content-Length: 0 --end msg-- 01:24:29.729 endpoint .Response msg 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) created 01:24:29.729 sip_resolve.c .Target '10.x.x.3:5070' type=UDP resolved to '10.x.x.3:5070' type=UDP (UDP transport) 01:24:29.729 pjsua_core.c .TX 655 bytes Response msg 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) to UDP 10.x.x.3:5070: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.x.x.3:5070;received=10.x.x.3;branch=z9hG4bK1ca35f62036d1c Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 From: <sip:10.x.x.3>;tag=1262409931 To: <sip:10.x.x.240>;tag=z9hG4bK1ca35f62036d1c CSeq: 101 OPTIONS Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain Supported: replaces, 100rel, timer, norefersub Allow-Events: presence, message-summary, refer Content-Length: 0 --end msg-- 01:24:29.729 tdta0x7f8160c4 .Destroying txdata Response msg 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) Is there something I may have configured incorrectly or is this a legit bug?

I should add I'm not 100% sure that the dialog memory pools are from the qualify/OPTIONS messages. They could be tied to old incoming calls too, however I already verified that my destructor is being called in my pjsua2 Call subclass for each incoming call, so any/all call dialogs *should* no longer exist... On Tue, Aug 22, 2017 at 1:49 AM, mscdexdotexe <mscdex@mscdex.net> wrote: > Hello, > > I've noticed that pjsip (seen at least with 2.5.5 and 2.6) is not > destroying SIP OPTIONS dialogs (at least over 100 or so still in memory), > causing memory to continuously grow. I verified this by performing a > `pjsua_dump(true);` after my process (a UAS/SIP trunk) has been running for > some time. I am using pjsua2 FWIW. Here is an example dialog with the log > level set to 9: > > > 01:24:29.729 sip_endpoint.c Processing incoming message: Request msg > OPTIONS/cseq=101 (rdata0x7f8160e9fb58) > 01:24:29.729 pjsua_core.c .RX 372 bytes Request msg OPTIONS/cseq=101 > (rdata0x7f8160e9fb58) from UDP 10.x.x.3:5070: > OPTIONS sip:10.x.x.240:5070 SIP/2.0 > Via: SIP/2.0/UDP 10.x.x.3:5070;branch=z9hG4bK1ca35f62036d1c > From: <sip:10.x.x.3>;tag=1262409931 > To: <sip:10.x.x.240> > Date: Tue, 22 Aug 2017 05:24:29 GMT > Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 > User-Agent: Cisco-CUCM10.5 > CSeq: 101 OPTIONS > Contact: <sip:10.x.x.3:5070> > Max-Forwards: 0 > Content-Length: 0 > > > --end msg-- > 01:24:29.729 endpoint .Response msg 200/OPTIONS/cseq=101 > (tdta0x7f8160c42e50) created > 01:24:29.729 sip_resolve.c .Target '10.x.x.3:5070' type=UDP resolved to > '10.x.x.3:5070' type=UDP (UDP transport) > 01:24:29.729 pjsua_core.c .TX 655 bytes Response msg > 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) to UDP 10.x.x.3:5070: > SIP/2.0 200 OK > Via: SIP/2.0/UDP 10.x.x.3:5070;received=10.x.x. > 3;branch=z9hG4bK1ca35f62036d1c > Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 > From: <sip:10.x.x.3>;tag=1262409931 > To: <sip:10.x.x.240>;tag=z9hG4bK1ca35f62036d1c > CSeq: 101 OPTIONS > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, > REFER, MESSAGE, OPTIONS > Accept: application/sdp, application/pidf+xml, application/xpidf+xml, > application/simple-message-summary, message/sipfrag;version=2.0, > application/im-iscomposing+xml, text/plain > Supported: replaces, 100rel, timer, norefersub > Allow-Events: presence, message-summary, refer > Content-Length: 0 > > > --end msg-- > 01:24:29.729 tdta0x7f8160c4 .Destroying txdata Response msg > 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) > > > > Is there something I may have configured incorrectly or is this a legit > bug? >

Ok, I'm starting to think these may in fact actually be dialogs from previous incoming calls. When the dialog sets are dumped there is a huge list (e.g. 3000+) of: [in] [est] <--uri too long--> entries shown. The "uri too long" agrees with the typical incoming calls I receive. I'm guessing the former two columns mean 'incoming' and 'established.' I still don't understand how that's possible since pjsip is acknowledging BYEs (with an ACK) sent by the remote party, so everything should be cleaned up. Again, I'm using pjsua2 here so as far as I know I shouldn't have to be doing anything explicit here aside from making sure my Call subclass is being destructed. In the pjsip log output, I do see lines like this when the call first comes in: 18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-invite 18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-pjsua but when the same call disconnects, I only see this 'session count decrement' message when the BYE is received: 18:40:29.945 dlg0x7fdfac0e7 ......Session count dec to 4 by mod-invite Should I be seeing a similar log line when mod-pjsua decreases the reference counter as well? Any pointers about where I should begin to debug this issue? On Tue, Aug 22, 2017 at 2:16 AM, mscdexdotexe <mscdex@mscdex.net> wrote: > I should add I'm not 100% sure that the dialog memory pools are from the > qualify/OPTIONS messages. They could be tied to old incoming calls too, > however I already verified that my destructor is being called in my pjsua2 > Call subclass for each incoming call, so any/all call dialogs *should* no > longer exist... > > On Tue, Aug 22, 2017 at 1:49 AM, mscdexdotexe <mscdex@mscdex.net> wrote: > >> Hello, >> >> I've noticed that pjsip (seen at least with 2.5.5 and 2.6) is not >> destroying SIP OPTIONS dialogs (at least over 100 or so still in memory), >> causing memory to continuously grow. I verified this by performing a >> `pjsua_dump(true);` after my process (a UAS/SIP trunk) has been running for >> some time. I am using pjsua2 FWIW. Here is an example dialog with the log >> level set to 9: >> >> >> 01:24:29.729 sip_endpoint.c Processing incoming message: Request msg >> OPTIONS/cseq=101 (rdata0x7f8160e9fb58) >> 01:24:29.729 pjsua_core.c .RX 372 bytes Request msg OPTIONS/cseq=101 >> (rdata0x7f8160e9fb58) from UDP 10.x.x.3:5070: >> OPTIONS sip:10.x.x.240:5070 SIP/2.0 >> Via: SIP/2.0/UDP 10.x.x.3:5070;branch=z9hG4bK1ca35f62036d1c >> From: <sip:10.x.x.3>;tag=1262409931 >> To: <sip:10.x.x.240> >> Date: Tue, 22 Aug 2017 05:24:29 GMT >> Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 >> User-Agent: Cisco-CUCM10.5 >> CSeq: 101 OPTIONS >> Contact: <sip:10.x.x.3:5070> >> Max-Forwards: 0 >> Content-Length: 0 >> >> >> --end msg-- >> 01:24:29.729 endpoint .Response msg 200/OPTIONS/cseq=101 >> (tdta0x7f8160c42e50) created >> 01:24:29.729 sip_resolve.c .Target '10.x.x.3:5070' type=UDP resolved to >> '10.x.x.3:5070' type=UDP (UDP transport) >> 01:24:29.729 pjsua_core.c .TX 655 bytes Response msg >> 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) to UDP 10.x.x.3:5070: >> SIP/2.0 200 OK >> Via: SIP/2.0/UDP 10.x.x.3:5070;received=10.x.x. >> 3;branch=z9hG4bK1ca35f62036d1c >> Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 >> From: <sip:10.x.x.3>;tag=1262409931 >> To: <sip:10.x.x.240>;tag=z9hG4bK1ca35f62036d1c >> CSeq: 101 OPTIONS >> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, >> REFER, MESSAGE, OPTIONS >> Accept: application/sdp, application/pidf+xml, application/xpidf+xml, >> application/simple-message-summary, message/sipfrag;version=2.0, >> application/im-iscomposing+xml, text/plain >> Supported: replaces, 100rel, timer, norefersub >> Allow-Events: presence, message-summary, refer >> Content-Length: 0 >> >> >> --end msg-- >> 01:24:29.729 tdta0x7f8160c4 .Destroying txdata Response msg >> 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) >> >> >> >> Is there something I may have configured incorrectly or is this a legit >> bug? >> > >

I've now tried forcefully terminating the dialogs several different ways but that always ends up in assertions killing my process. I've also tried 2.6-svn as of this evening and still each call's dialog is still held in memory after the call ends. Each call's dialog is still there even after the related transactions are destroyed 32 seconds after the 200 OK is sent in response to the received BYE message. I really have no clue what else to try or where to look at this point and it is very frustrating. On a related note, does anyone offer paid pjsip support? On Wed, Aug 23, 2017 at 8:23 PM, mscdexdotexe <mscdex@mscdex.net> wrote: > Ok, I'm starting to think these may in fact actually be dialogs from > previous incoming calls. When the dialog sets are dumped there is a huge > list (e.g. 3000+) of: > > [in] [est] <--uri too long--> > > entries shown. The "uri too long" agrees with the typical incoming calls I > receive. I'm guessing the former two columns mean 'incoming' and > 'established.' I still don't understand how that's possible since pjsip is > acknowledging BYEs (with an ACK) sent by the remote party, so everything > should be cleaned up. Again, I'm using pjsua2 here so as far as I know I > shouldn't have to be doing anything explicit here aside from making sure my > Call subclass is being destructed. > > In the pjsip log output, I do see lines like this when the call first > comes in: > > 18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-invite > 18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-pjsua > > but when the same call disconnects, I only see this 'session count > decrement' message when the BYE is received: > > 18:40:29.945 dlg0x7fdfac0e7 ......Session count dec to 4 by mod-invite > > Should I be seeing a similar log line when mod-pjsua decreases the > reference counter as well? > > Any pointers about where I should begin to debug this issue? > > On Tue, Aug 22, 2017 at 2:16 AM, mscdexdotexe <mscdex@mscdex.net> wrote: > >> I should add I'm not 100% sure that the dialog memory pools are from the >> qualify/OPTIONS messages. They could be tied to old incoming calls too, >> however I already verified that my destructor is being called in my pjsua2 >> Call subclass for each incoming call, so any/all call dialogs *should* no >> longer exist... >> >> On Tue, Aug 22, 2017 at 1:49 AM, mscdexdotexe <mscdex@mscdex.net> wrote: >> >>> Hello, >>> >>> I've noticed that pjsip (seen at least with 2.5.5 and 2.6) is not >>> destroying SIP OPTIONS dialogs (at least over 100 or so still in memory), >>> causing memory to continuously grow. I verified this by performing a >>> `pjsua_dump(true);` after my process (a UAS/SIP trunk) has been running for >>> some time. I am using pjsua2 FWIW. Here is an example dialog with the log >>> level set to 9: >>> >>> >>> 01:24:29.729 sip_endpoint.c Processing incoming message: Request msg >>> OPTIONS/cseq=101 (rdata0x7f8160e9fb58) >>> 01:24:29.729 pjsua_core.c .RX 372 bytes Request msg OPTIONS/cseq=101 >>> (rdata0x7f8160e9fb58) from UDP 10.x.x.3:5070: >>> OPTIONS sip:10.x.x.240:5070 SIP/2.0 >>> Via: SIP/2.0/UDP 10.x.x.3:5070;branch=z9hG4bK1ca35f62036d1c >>> From: <sip:10.x.x.3>;tag=1262409931 >>> To: <sip:10.x.x.240> >>> Date: Tue, 22 Aug 2017 05:24:29 GMT >>> Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 >>> User-Agent: Cisco-CUCM10.5 >>> CSeq: 101 OPTIONS >>> Contact: <sip:10.x.x.3:5070> >>> Max-Forwards: 0 >>> Content-Length: 0 >>> >>> >>> --end msg-- >>> 01:24:29.729 endpoint .Response msg 200/OPTIONS/cseq=101 >>> (tdta0x7f8160c42e50) created >>> 01:24:29.729 sip_resolve.c .Target '10.x.x.3:5070' type=UDP resolved >>> to '10.x.x.3:5070' type=UDP (UDP transport) >>> 01:24:29.729 pjsua_core.c .TX 655 bytes Response msg >>> 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) to UDP 10.x.x.3:5070: >>> SIP/2.0 200 OK >>> Via: SIP/2.0/UDP 10.x.x.3:5070;received=10.x.x. >>> 3;branch=z9hG4bK1ca35f62036d1c >>> Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 >>> From: <sip:10.x.x.3>;tag=1262409931 >>> To: <sip:10.x.x.240>;tag=z9hG4bK1ca35f62036d1c >>> CSeq: 101 OPTIONS >>> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, >>> REFER, MESSAGE, OPTIONS >>> Accept: application/sdp, application/pidf+xml, application/xpidf+xml, >>> application/simple-message-summary, message/sipfrag;version=2.0, >>> application/im-iscomposing+xml, text/plain >>> Supported: replaces, 100rel, timer, norefersub >>> Allow-Events: presence, message-summary, refer >>> Content-Length: 0 >>> >>> >>> --end msg-- >>> 01:24:29.729 tdta0x7f8160c4 .Destroying txdata Response msg >>> 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) >>> >>> >>> >>> Is there something I may have configured incorrectly or is this a legit >>> bug? >>> >> >> >

I am still encountering this dialog leak with pjsip 2.7.1. I have now narrowed it down to a very simple pjsua C program that is more or less a copy of the pjsua sample program. I have attached the config_site.h we're using for pjsip, the source to the C program, and output from the program. At the end of the output, you will see where I send a USR2 signal to the process to trigger the internal state dump, which shows the dialogs still in memory, even after the related transactions time out and are terminated (on a possibly related note, I'm not sure why the timers/transactions are still alive immediately after pjsip sends the response acknowledging the BYE message). I believe there is a dialog ref counter decrement missing somewhere. For example, if I edit pjsip/src/pjsua-lib/pjsua_call.c and insert a `pjsip_dlg_dec_session(...)` inside the `inv->state == PJSIP_INV_STATE_DISCONNECTED` conditional after the `on_call_state` callback is executed, then the dialog is properly destroyed (albeit once the transaction timer expires/fires). However at least this particular change will cause a crash randomly due to an assertion about the ioqueue free list, otherwise it seems to work. On Sat, Aug 26, 2017 at 12:07 AM, mscdexdotexe <mscdex@mscdex.net> wrote: > I've now tried forcefully terminating the dialogs several different ways > but that always ends up in assertions killing my process. > > I've also tried 2.6-svn as of this evening and still each call's dialog is > still held in memory after the call ends. Each call's dialog is still there > even after the related transactions are destroyed 32 seconds after the 200 > OK is sent in response to the received BYE message. > > I really have no clue what else to try or where to look at this point and > it is very frustrating. > > On a related note, does anyone offer paid pjsip support? > > On Wed, Aug 23, 2017 at 8:23 PM, mscdexdotexe <mscdex@mscdex.net> wrote: > >> Ok, I'm starting to think these may in fact actually be dialogs from >> previous incoming calls. When the dialog sets are dumped there is a huge >> list (e.g. 3000+) of: >> >> [in] [est] <--uri too long--> >> >> entries shown. The "uri too long" agrees with the typical incoming calls >> I receive. I'm guessing the former two columns mean 'incoming' and >> 'established.' I still don't understand how that's possible since pjsip is >> acknowledging BYEs (with an ACK) sent by the remote party, so everything >> should be cleaned up. Again, I'm using pjsua2 here so as far as I know I >> shouldn't have to be doing anything explicit here aside from making sure my >> Call subclass is being destructed. >> >> In the pjsip log output, I do see lines like this when the call first >> comes in: >> >> 18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-invite >> 18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-pjsua >> >> but when the same call disconnects, I only see this 'session count >> decrement' message when the BYE is received: >> >> 18:40:29.945 dlg0x7fdfac0e7 ......Session count dec to 4 by mod-invite >> >> Should I be seeing a similar log line when mod-pjsua decreases the >> reference counter as well? >> >> Any pointers about where I should begin to debug this issue? >> >> On Tue, Aug 22, 2017 at 2:16 AM, mscdexdotexe <mscdex@mscdex.net> wrote: >> >>> I should add I'm not 100% sure that the dialog memory pools are from the >>> qualify/OPTIONS messages. They could be tied to old incoming calls too, >>> however I already verified that my destructor is being called in my pjsua2 >>> Call subclass for each incoming call, so any/all call dialogs *should* no >>> longer exist... >>> >>> On Tue, Aug 22, 2017 at 1:49 AM, mscdexdotexe <mscdex@mscdex.net> wrote: >>> >>>> Hello, >>>> >>>> I've noticed that pjsip (seen at least with 2.5.5 and 2.6) is not >>>> destroying SIP OPTIONS dialogs (at least over 100 or so still in memory), >>>> causing memory to continuously grow. I verified this by performing a >>>> `pjsua_dump(true);` after my process (a UAS/SIP trunk) has been running for >>>> some time. I am using pjsua2 FWIW. Here is an example dialog with the log >>>> level set to 9: >>>> >>>> >>>> 01:24:29.729 sip_endpoint.c Processing incoming message: Request msg >>>> OPTIONS/cseq=101 (rdata0x7f8160e9fb58) >>>> 01:24:29.729 pjsua_core.c .RX 372 bytes Request msg OPTIONS/cseq=101 >>>> (rdata0x7f8160e9fb58) from UDP 10.x.x.3:5070: >>>> OPTIONS sip:10.x.x.240:5070 SIP/2.0 >>>> Via: SIP/2.0/UDP 10.x.x.3:5070;branch=z9hG4bK1ca35f62036d1c >>>> From: <sip:10.x.x.3>;tag=1262409931 >>>> To: <sip:10.x.x.240> >>>> Date: Tue, 22 Aug 2017 05:24:29 GMT >>>> Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 >>>> User-Agent: Cisco-CUCM10.5 >>>> CSeq: 101 OPTIONS >>>> Contact: <sip:10.x.x.3:5070> >>>> Max-Forwards: 0 >>>> Content-Length: 0 >>>> >>>> >>>> --end msg-- >>>> 01:24:29.729 endpoint .Response msg 200/OPTIONS/cseq=101 >>>> (tdta0x7f8160c42e50) created >>>> 01:24:29.729 sip_resolve.c .Target '10.x.x.3:5070' type=UDP resolved >>>> to '10.x.x.3:5070' type=UDP (UDP transport) >>>> 01:24:29.729 pjsua_core.c .TX 655 bytes Response msg >>>> 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) to UDP 10.x.x.3:5070: >>>> SIP/2.0 200 OK >>>> Via: SIP/2.0/UDP 10.x.x.3:5070;received=10.x.x. >>>> 3;branch=z9hG4bK1ca35f62036d1c >>>> Call-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 >>>> From: <sip:10.x.x.3>;tag=1262409931 >>>> To: <sip:10.x.x.240>;tag=z9hG4bK1ca35f62036d1c >>>> CSeq: 101 OPTIONS >>>> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, >>>> NOTIFY, REFER, MESSAGE, OPTIONS >>>> Accept: application/sdp, application/pidf+xml, application/xpidf+xml, >>>> application/simple-message-summary, message/sipfrag;version=2.0, >>>> application/im-iscomposing+xml, text/plain >>>> Supported: replaces, 100rel, timer, norefersub >>>> Allow-Events: presence, message-summary, refer >>>> Content-Length: 0 >>>> >>>> >>>> --end msg-- >>>> 01:24:29.729 tdta0x7f8160c4 .Destroying txdata Response msg >>>> 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) >>>> >>>> >>>> >>>> Is there something I may have configured incorrectly or is this a legit >>>> bug? >>>> >>> >>> >> >