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@xxxxxxxxxx> 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@xxxxxxxxxx> 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-invite18:39:50.544 dlg0x7fdfac11f ...Session count inc to 3 by mod-pjsuabut 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-inviteShould 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@xxxxxxxxxx> 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@xxxxxxxxxx> 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.0Via: SIP/2.0/UDP 10.x.x.3:5070;branch=z9hG4bK1ca35f62036d1c From: <sip:10.x.x.3>;tag=1262409931To: <sip:10.x.x.240>Date: Tue, 22 Aug 2017 05:24:29 GMTCall-ID: 2a68ea00-99b1c00d-c5b0c-3a0030a@10.x.x.3 User-Agent: Cisco-CUCM10.5CSeq: 101 OPTIONSContact: <sip:10.x.x.3:5070>Max-Forwards: 0Content-Length: 0--end msg--01:24:29.729 endpoint .Response msg 200/OPTIONS/cseq=101 (tdta0x7f8160c42e50) created01: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 OKVia: 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=1262409931To: <sip:10.x.x.240>;tag=z9hG4bK1ca35f62036d1c CSeq: 101 OPTIONSAllow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONSAccept: 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, norefersubAllow-Events: presence, message-summary, referContent-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?
19:53:58.351 critsec !Mutex created
19:53:58.353 critsec !Mutex: thread thr0x7f781495a700 is waiting
19:53:58.353 critsec Mutex acquired by thread thr0x7f781495a700
19:53:58.353 critsec Mutex released by thread thr0x7f781495a700
19:53:58.353 critsec Mutex: thread thr0x7f781495a700 is waiting
19:53:58.353 critsec Mutex acquired by thread thr0x7f781495a700
19:53:58.353 critsec Mutex released by thread thr0x7f781495a700
19:53:58.353 os_core_unix.c pjlib 2.7.1 for POSIX initialized
19:53:58.354 cachingpool .pool created, size=512
19:53:58.354 cachingpool .Mutex created
19:53:58.354 cachingpool .Mutex: thread thr0x7f781495a700 is waiting
19:53:58.354 cachingpool .Mutex acquired by thread thr0x7f781495a700
19:53:58.354 pjsua .pool created, size=1024
19:53:58.354 cachingpool .Mutex released by thread thr0x7f781495a700
19:53:58.354 pjsua .Mutex created
19:53:58.354 sip_endpoint.c .Creating endpoint instance...
19:53:58.354 cachingpool .Mutex: thread thr0x7f781495a700 is waiting
19:53:58.354 cachingpool .Mutex acquired by thread thr0x7f781495a700
19:53:58.354 pept0x2428f60 .pool created, size=4096
19:53:58.354 cachingpool .Mutex released by thread thr0x7f781495a700
19:53:58.354 critsec .Mutex: thread thr0x7f781495a700 is waiting
19:53:58.355 critsec .Mutex acquired by thread thr0x7f781495a700
19:53:58.355 critsec .Mutex: thread thr0x7f781495a700 is waiting
19:53:58.355 critsec .Mutex acquired by thread thr0x7f781495a700
19:53:58.355 critsec .Mutex released by thread thr0x7f781495a700
19:53:58.355 critsec .Mutex: thread thr0x7f781495a700 is waiting
19:53:58.355 critsec .Mutex acquired by thread thr0x7f781495a700
19:53:58.355 critsec .Mutex released by thread thr0x7f781495a700
19:53:58.355 critsec .Mutex released by thread thr0x7f781495a700
19:53:58.355 ept0x24292a8 .Mutex created
19:53:58.355 pept0x2428f60 .20971504 bytes requested, resizing pool by 20972000 bytes (used=992, cap=4096)
19:53:58.355 pept0x2428f60 .create_block(sz=20972000), cur.cap=4096, cur.used=992
19:53:58.355 pept0x2428f60 . block created, buffer=0x7f780dabe038-0x7f780eebe1f0
19:53:58.355 pept0x2428f60 .10485752 bytes requested, resizing pool by 10488000 bytes (used=20972536, cap=20976096)
19:53:58.355 pept0x2428f60 .create_block(sz=10488000), cur.cap=20976096, cur.used=20972536
19:53:58.355 pept0x2428f60 . block created, buffer=0x7f780d0bd038-0x7f780dabd8d0
19:53:58.376 edpt0x7f780dabd058 .Mutex created
19:53:58.376 mtx0x7f780dabd4b8 .Mutex created
19:53:58.376 mtx0x7f780dabd678 .Mutex created
19:53:58.376 mtx0x7f780dabd838 .Mutex created
19:53:58.376 mtx0x7f780eebe178 .Mutex created
19:53:58.376 mtx0x2429490 .Mutex created
19:53:58.376 mtx0x2429628 .Mutex created
19:53:58.376 mtx0x24297e8 .Mutex created
19:53:58.376 mtx0x24299a8 .Mutex created
19:53:58.376 mtx0x2429b68 .Mutex created
19:53:58.376 mtx0x2429d28 .Mutex created
19:53:58.376 mtx0x2429ee8 .Mutex created
19:53:58.376 pept0x2428f60 .336 bytes requested, resizing pool by 4000 bytes (used=31464040, cap=31464096)
19:53:58.376 pept0x2428f60 .create_block(sz=4000), cur.cap=31464096, cur.used=31464040
19:53:58.376 pept0x2428f60 . block created, buffer=0x2429f98-0x242af10
19:53:58.376 mtx0x242a110 .Mutex created
19:53:58.376 mtx0x242a2d0 .Mutex created
19:53:58.376 mtx0x242a490 .Mutex created
19:53:58.376 mtx0x242a650 .Mutex created
19:53:58.377 mtx0x242a810 .Mutex created
19:53:58.377 mtx0x242a9d0 .Mutex created
19:53:58.377 mtx0x242ab90 .Mutex created
19:53:58.377 mtx0x242ad50 .Mutex created
19:53:58.377 pept0x2428f60 .72 bytes requested, resizing pool by 4000 bytes (used=31468040, cap=31468096)
19:53:58.377 pept0x2428f60 .create_block(sz=4000), cur.cap=31468096, cur.used=31468040
19:53:58.377 pept0x2428f60 . block created, buffer=0x242af48-0x242bec0
19:53:58.381 mtx0x242af48 .Mutex created
19:53:58.381 mtx0x242b108 .Mutex created
19:53:58.381 mtx0x242b2c8 .Mutex created
19:53:58.381 mtx0x242b488 .Mutex created
19:53:58.381 mtx0x242b648 .Mutex created
19:53:58.381 mtx0x242b808 .Mutex created
19:53:58.381 mtx0x242b9c8 .Mutex created
19:53:58.381 mtx0x242bb88 .Mutex created
19:53:58.381 mtx0x242bd48 .Mutex created
19:53:58.382 pept0x2428f60 .336 bytes requested, resizing pool by 4000 bytes (used=31471736, cap=31472096)
19:53:58.382 pept0x2428f60 .create_block(sz=4000), cur.cap=31472096, cur.used=31471736
19:53:58.382 pept0x2428f60 . block created, buffer=0x242bef8-0x242ce70
19:53:58.382 mtx0x242c070 .Mutex created
19:53:58.382 mtx0x242c230 .Mutex created
19:53:58.382 mtx0x242c3f0 .Mutex created
19:53:58.382 mtx0x242c5b0 .Mutex created
19:53:58.382 mtx0x242c770 .Mutex created
19:53:58.382 mtx0x242c930 .Mutex created
19:53:58.382 mtx0x242caf0 .Mutex created
19:53:58.382 mtx0x242ccb0 .Mutex created
19:53:58.382 mtx0x242bd90 .Mutex created
19:53:58.382 pept0x2428f60 .336 bytes requested, resizing pool by 4000 bytes (used=31475808, cap=31476096)
19:53:58.382 pept0x2428f60 .create_block(sz=4000), cur.cap=31476096, cur.used=31475808
19:53:58.382 pept0x2428f60 . block created, buffer=0x242cea8-0x242de20
19:53:58.382 mtx0x242d020 .Mutex created
19:53:58.382 mtx0x242d1e0 .Mutex created
19:53:58.382 mtx0x242d3a0 .Mutex created
19:53:58.382 mtx0x242d560 .Mutex created
19:53:58.382 mtx0x242d720 .Mutex created
19:53:58.382 mtx0x242d8e0 .Mutex created
19:53:58.383 mtx0x242daa0 .Mutex created
19:53:58.383 mtx0x242dc60 .Mutex created
19:53:58.383 mtx0x242bdd8 .Mutex created
19:53:58.383 pept0x2428f60 .336 bytes requested, resizing pool by 4000 bytes (used=31479880, cap=31480096)
19:53:58.383 pept0x2428f60 .create_block(sz=4000), cur.cap=31480096, cur.used=31479880
19:53:58.383 pept0x2428f60 . block created, buffer=0x242de58-0x242edd0
19:53:58.383 mtx0x242dfd0 .Mutex created
19:53:58.383 mtx0x242e190 .Mutex created
19:53:58.383 mtx0x242e350 .Mutex created
19:53:58.383 mtx0x242e510 .Mutex created
19:53:58.383 mtx0x242e6d0 .Mutex created
19:53:58.383 mtx0x242e890 .Mutex created
19:53:58.383 mtx0x242ea50 .Mutex created
19:53:58.383 mtx0x242ec10 .Mutex created
19:53:58.383 mtx0x242be20 .Mutex created
19:53:58.383 pept0x2428f60 .336 bytes requested, resizing pool by 4000 bytes (used=31483952, cap=31484096)
19:53:58.383 pept0x2428f60 .create_block(sz=4000), cur.cap=31484096, cur.used=31483952
19:53:58.383 pept0x2428f60 . block created, buffer=0x242ee08-0x242fd80
19:53:58.383 mtx0x242ef80 .Mutex created
19:53:58.383 mtx0x242f140 .Mutex created
19:53:58.383 mtx0x242f300 .Mutex created
19:53:58.383 mtx0x242f4c0 .Mutex created
19:53:58.384 mtx0x242f680 .Mutex created
19:53:58.384 mtx0x242f840 .Mutex created
19:53:58.384 mtx0x242fa00 .Mutex created
19:53:58.384 mtx0x242fbc0 .Mutex created
19:53:58.384 mtx0x242be68 .Mutex created
19:53:58.384 pept0x2428f60 .336 bytes requested, resizing pool by 4000 bytes (used=31488024, cap=31488096)
19:53:58.384 pept0x2428f60 .create_block(sz=4000), cur.cap=31488096, cur.used=31488024
19:53:58.384 pept0x2428f60 . block created, buffer=0x242fdb8-0x2430d30
19:53:58.384 mtx0x242ff30 .Mutex created
19:53:58.384 ioq0x242ffa0 .Mutex created
19:53:58.384 pjlib .epoll I/O Queue created (0x7f780dabd0a0)
19:53:58.384 sip_endpoint.c .Module "mod-msg-print" registered
19:53:58.384 hashtbl .hash table 0x24305c8 created from pool pept0x2428f60
19:53:58.384 tmgr0x2430710 .Mutex created
19:53:58.384 sip_transport.c .Transport manager created.
19:53:58.384 pjsua_timer .Mutex created
19:53:58.384 pjsua_core.c .PJSUA state changed: NULL --> CREATED
19:53:58.384 sip_endpoint.c .Module "mod-pjsua-log" registered
19:53:58.386 sip_endpoint.c .Module "mod-tsx-layer" registered
19:53:58.387 sip_endpoint.c .Module "mod-stateful-util" registered
19:53:58.389 sip_endpoint.c .Module "mod-ua" registered
19:53:58.393 sip_endpoint.c .Module "mod-100rel" registered
19:53:58.393 sip_endpoint.c .Module "mod-pjsua" registered
19:53:58.397 sip_endpoint.c .Module "mod-invite" registered
19:53:58.404 alsa_dev.c ..ALSA driver found 0 devices
19:53:58.404 alsa_dev.c ..ALSA initialized
19:53:58.404 pjlib ..epoll I/O Queue created (0x2447128)
19:53:58.404 conference.c ..Creating conference bridge with 12288 ports
19:53:58.404 Master/sound ..Using delay buffer with WSOLA.
19:53:58.411 sip_endpoint.c .Module "mod-evsub" registered
19:53:58.411 sip_endpoint.c .Module "mod-presence" registered
19:53:58.411 evsub.c .Event pkg "presence" registered by mod-presence
19:53:58.411 sip_endpoint.c .Module "mod-mwi" registered
19:53:58.412 evsub.c .Event pkg "message-summary" registered by mod-mwi
19:53:58.412 sip_endpoint.c .Module "mod-refer" registered
19:53:58.412 evsub.c .Event pkg "refer" registered by mod-refer
19:53:58.412 sip_endpoint.c .Module "mod-pjsua-pres" registered
19:53:58.412 sip_endpoint.c .Module "mod-pjsua-im" registered
19:53:58.412 sip_endpoint.c .Module "mod-pjsua-options" registered
19:53:58.412 pjsua_core.c .1 SIP worker threads created
19:53:58.412 pjsua_core.c .pjsua version 2.7.1 for Linux-4.4.0.112/x86_64/glibc-2.23 initialized
19:53:58.412 pjsua_core.c .PJSUA state changed: CREATED --> INIT
19:53:58.412 pjsua_core.c SIP UDP socket reachable at 192.168.100.190:5070
19:53:58.412 udp0x2444ea0 SIP UDP transport started, published address is 192.168.100.190:5070
19:53:58.412 pjsua_core.c PJSUA state changed: INIT --> STARTING
19:53:58.413 sip_endpoint.c .Module "mod-unsolicited-mwi" registered
19:53:58.413 pjsua_core.c .PJSUA state changed: STARTING --> RUNNING
19:53:58.413 pjsua_acc.c Adding account: id=sip:7777@192.168.100.189
19:53:58.413 pjsua_acc.c .Account sip:7777@192.168.100.189 added with id 0
19:54:47.826 sip_endpoint.c !Processing incoming message: Request msg INVITE/cseq=101 (rdata0x247e498)
19:54:47.826 pjsua_core.c .RX 1169 bytes Request msg INVITE/cseq=101 (rdata0x247e498) from UDP 192.168.100.189:50600:
INVITE sip:7777@192.168.100.190:5070 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:50600;branch=z9hG4bKe7c40602ffe
From: "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37236~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579540
To: <sip:7777@192.168.100.190>
Date: Wed, 21 Feb 2018 00:54:47 GMT
Call-ID: cec7eb00-a8c1c357-d1d-bd64a8c0@192.168.100.189
Supported: timer,resource-priority,replaces
Min-SE: 1800
User-Agent: Cisco-CUCM8.6
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence
Supported: X-cisco-srtp-fallback
Supported: Geolocation
Cisco-Guid: 3469208320-0000065536-0000000089-3177490624
Session-Expires: 1800
Diversion: <sip:7777@192.168.100.189>;reason=recording;privacy=off;screen=yes
P-Preferred-Identity: "7961 Phone" <sip:2802@192.168.100.189>
Remote-Party-ID: "7961 Phone" <sip:2802@192.168.100.189>;party=calling;screen=no;privacy=off
Contact: <sip:2802@192.168.100.189:50600>;isFocus
Max-Forwards: 70
Content-Length: 0
--end msg--
19:54:47.826 pjsua_call.c .Incoming Request msg INVITE/cseq=101 (rdata0x247e498)
19:54:47.827 tsx0x7f7804004b28 ...Transaction created for Request msg INVITE/cseq=101 (rdata0x247e498)
19:54:47.827 tsx0x7f7804004b28 ..Incoming Request msg INVITE/cseq=101 (rdata0x247e498) in state Null
19:54:47.827 tsx0x7f7804004b28 ...State changed from Null to Trying, event=RX_MSG
19:54:47.827 dlg0x7f78040038c8 ....Transaction tsx0x7f7804004b28 state changed to Trying
19:54:47.827 dlg0x7f78040038c8 ..UAS dialog created
19:54:47.827 dlg0x7f78040038c8 ..Module mod-invite added as dialog usage, data=0x7f7804005ef8
19:54:47.827 dlg0x7f78040038c8 ...Session count inc to 3 by mod-invite
19:54:47.827 inv0x7f78040038c8 ..UAS invite session created for dialog dlg0x7f78040038c8
19:54:47.827 dlg0x7f78040038c8 ...Session count inc to 3 by mod-pjsua
19:54:47.827 endpoint ...Response msg 100/INVITE/cseq=101 (tdta0x7f78040063a8) created
19:54:47.827 dlg0x7f78040038c8 ...Initial answer Response msg 100/INVITE/cseq=101 (tdta0x7f78040063a8)
19:54:47.827 inv0x7f78040038c8 ...Sending Response msg 100/INVITE/cseq=101 (tdta0x7f78040063a8)
19:54:47.827 dlg0x7f78040038c8 ....Sending Response msg 100/INVITE/cseq=101 (tdta0x7f78040063a8)
19:54:47.827 tsx0x7f7804004b28 ....Sending Response msg 100/INVITE/cseq=101 (tdta0x7f78040063a8) in state Trying
19:54:47.827 sip_resolve.c .....Target '192.168.100.189:50600' type=UDP resolved to '192.168.100.189:50600' type=UDP (UDP transport)
19:54:47.827 pjsua_core.c .....TX 474 bytes Response msg 100/INVITE/cseq=101 (tdta0x7f78040063a8) to UDP 192.168.100.189:50600:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.100.189:50600;received=192.168.100.189;branch=z9hG4bKe7c40602ffe
Call-ID: cec7eb00-a8c1c357-d1d-bd64a8c0@192.168.100.189
From: "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37236~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579540
To: <sip:7777@192.168.100.190>
CSeq: 101 INVITE
Content-Length: 0
--end msg--
19:54:47.827 tsx0x7f7804004b28 .....State changed from Trying to Proceeding, event=TX_MSG
19:54:47.827 dlg0x7f78040038c8 ......Transaction tsx0x7f7804004b28 state changed to Proceeding
19:54:47.827 APP ..Incoming call from "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>!!
19:54:47.827 pjsua_call.c ..Answering call 0: code=200
19:54:47.827 pjsua_media.c ...Call 0: initializing media..
19:54:47.827 pjsua_media.c ....RTP socket reachable at 192.168.100.190:4000
19:54:47.827 pjsua_media.c ....RTCP socket reachable at 192.168.100.190:4001
19:54:47.827 srtp0x7f780400c290 ....SRTP keying SDES created
19:54:47.827 pjsua_media.c ....Media index 0 selected for audio call 0
19:54:47.827 pjsua_media.c ....Call 0: media transport initialization complete: Success
19:54:47.827 inv0x7f78040038c8 ....Sending Response msg 200/INVITE/cseq=101 (tdta0x7f78040063a8)
19:54:47.827 dlg0x7f78040038c8 .....Sending Response msg 200/INVITE/cseq=101 (tdta0x7f78040063a8)
19:54:47.827 tsx0x7f7804004b28 .....Sending Response msg 200/INVITE/cseq=101 (tdta0x7f78040063a8) in state Proceeding
19:54:47.827 pjsua_core.c ......TX 1323 bytes Response msg 200/INVITE/cseq=101 (tdta0x7f78040063a8) to UDP 192.168.100.189:50600:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.100.189:50600;received=192.168.100.189;branch=z9hG4bKe7c40602ffe
Call-ID: cec7eb00-a8c1c357-d1d-bd64a8c0@192.168.100.189
From: "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37236~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579540
To: <sip:7777@192.168.100.190>;tag=.NLzUagSiNQyOEsfdfqpaHfefZTwAxcg
CSeq: 101 INVITE
Contact: <sip:7777@192.168.100.190:5070>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800;refresher=uac
Require: timer
Content-Type: application/sdp
Content-Length: 541
v=0
o=- 3728163287 3728163287 IN IP4 192.168.100.190
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 98 97 99 104 3 0 8 9 120 96
c=IN IP4 192.168.100.190
b=TIAS:96000
a=rtcp:4001 IN IP4 192.168.100.190
a=sendrecv
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:99 speex/32000
a=rtpmap:104 iLBC/8000
a=fmtp:104 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
--end msg--
19:54:47.827 tsx0x7f7804004b28 ......State changed from Proceeding to Completed, event=TX_MSG
19:54:47.827 dlg0x7f78040038c8 .......Transaction tsx0x7f7804004b28 state changed to Completed
19:54:47.827 APP .........Call 0 state=CONNECTING
19:54:47.827 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=101 (rdata0x7f78040008e8)
19:54:47.827 pjsua_core.c .RX 1168 bytes Request msg INVITE/cseq=101 (rdata0x7f78040008e8) from UDP 192.168.100.189:50600:
INVITE sip:7777@192.168.100.190:5070 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:50600;branch=z9hG4bKe7d652da46d
From: "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37237~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579543
To: <sip:7777@192.168.100.190>
Date: Wed, 21 Feb 2018 00:54:47 GMT
Call-ID: cec7eb00-a8c1c357-d1e-bd64a8c0@192.168.100.189
Supported: timer,resource-priority,replaces
Min-SE: 1800
User-Agent: Cisco-CUCM8.6
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence
Supported: X-cisco-srtp-fallback
Supported: Geolocation
Cisco-Guid: 3469208320-0000065536-0000000090-3177490624
Session-Expires: 1800
Diversion: <sip:7777@192.168.100.189>;reason=recording;privacy=off;screen=yes
P-Preferred-Identity: "7961 Phone" <sip:2802@192.168.100.189>
Remote-Party-ID: "7961 Phone" <sip:2802@192.168.100.189>;party=calling;screen=no;privacy=off
Contact: <sip:2802@192.168.100.189:50600>;isFocus
Max-Forwards: 70
Content-Length: 0
--end msg--
19:54:47.827 pjsua_call.c .Incoming Request msg INVITE/cseq=101 (rdata0x7f78040008e8)
19:54:47.828 tsx0x7f78040142d8 ...Transaction created for Request msg INVITE/cseq=101 (rdata0x7f78040008e8)
19:54:47.828 tsx0x7f78040142d8 ..Incoming Request msg INVITE/cseq=101 (rdata0x7f78040008e8) in state Null
19:54:47.828 tsx0x7f78040142d8 ...State changed from Null to Trying, event=RX_MSG
19:54:47.828 dlg0x7f7804013078 ....Transaction tsx0x7f78040142d8 state changed to Trying
19:54:47.828 dlg0x7f7804013078 ..UAS dialog created
19:54:47.828 dlg0x7f7804013078 ..Module mod-invite added as dialog usage, data=0x7f78040156a8
19:54:47.828 dlg0x7f7804013078 ...Session count inc to 3 by mod-invite
19:54:47.828 inv0x7f7804013078 ..UAS invite session created for dialog dlg0x7f7804013078
19:54:47.828 dlg0x7f7804013078 ...Session count inc to 3 by mod-pjsua
19:54:47.828 endpoint ...Response msg 100/INVITE/cseq=101 (tdta0x7f7804015b58) created
19:54:47.828 dlg0x7f7804013078 ...Initial answer Response msg 100/INVITE/cseq=101 (tdta0x7f7804015b58)
19:54:47.828 inv0x7f7804013078 ...Sending Response msg 100/INVITE/cseq=101 (tdta0x7f7804015b58)
19:54:47.828 dlg0x7f7804013078 ....Sending Response msg 100/INVITE/cseq=101 (tdta0x7f7804015b58)
19:54:47.828 tsx0x7f78040142d8 ....Sending Response msg 100/INVITE/cseq=101 (tdta0x7f7804015b58) in state Trying
19:54:47.828 sip_resolve.c .....Target '192.168.100.189:50600' type=UDP resolved to '192.168.100.189:50600' type=UDP (UDP transport)
19:54:47.828 pjsua_core.c .....TX 473 bytes Response msg 100/INVITE/cseq=101 (tdta0x7f7804015b58) to UDP 192.168.100.189:50600:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.100.189:50600;received=192.168.100.189;branch=z9hG4bKe7d652da46d
Call-ID: cec7eb00-a8c1c357-d1e-bd64a8c0@192.168.100.189
From: "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37237~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579543
To: <sip:7777@192.168.100.190>
CSeq: 101 INVITE
Content-Length: 0
--end msg--
19:54:47.828 tsx0x7f78040142d8 .....State changed from Trying to Proceeding, event=TX_MSG
19:54:47.828 dlg0x7f7804013078 ......Transaction tsx0x7f78040142d8 state changed to Proceeding
19:54:47.828 APP ..Incoming call from "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>!!
19:54:47.828 pjsua_call.c ..Answering call 1: code=200
19:54:47.828 pjsua_media.c ...Call 1: initializing media..
19:54:47.828 pjsua_media.c ....RTP socket reachable at 192.168.100.190:4002
19:54:47.828 pjsua_media.c ....RTCP socket reachable at 192.168.100.190:4003
19:54:47.828 srtp0x7f780401b830 ....SRTP keying SDES created
19:54:47.828 pjsua_media.c ....Media index 0 selected for audio call 1
19:54:47.828 pjsua_media.c ....Call 1: media transport initialization complete: Success
19:54:47.828 inv0x7f7804013078 ....Sending Response msg 200/INVITE/cseq=101 (tdta0x7f7804015b58)
19:54:47.828 dlg0x7f7804013078 .....Sending Response msg 200/INVITE/cseq=101 (tdta0x7f7804015b58)
19:54:47.828 tsx0x7f78040142d8 .....Sending Response msg 200/INVITE/cseq=101 (tdta0x7f7804015b58) in state Proceeding
19:54:47.828 pjsua_core.c ......TX 1322 bytes Response msg 200/INVITE/cseq=101 (tdta0x7f7804015b58) to UDP 192.168.100.189:50600:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.100.189:50600;received=192.168.100.189;branch=z9hG4bKe7d652da46d
Call-ID: cec7eb00-a8c1c357-d1e-bd64a8c0@192.168.100.189
From: "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37237~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579543
To: <sip:7777@192.168.100.190>;tag=QDtMvvPNUx4RLeGdauL7hjaClxxbZZWW
CSeq: 101 INVITE
Contact: <sip:7777@192.168.100.190:5070>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800;refresher=uac
Require: timer
Content-Type: application/sdp
Content-Length: 541
v=0
o=- 3728163287 3728163287 IN IP4 192.168.100.190
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 98 97 99 104 3 0 8 9 120 96
c=IN IP4 192.168.100.190
b=TIAS:96000
a=rtcp:4003 IN IP4 192.168.100.190
a=sendrecv
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:99 speex/32000
a=rtpmap:104 iLBC/8000
a=fmtp:104 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
--end msg--
19:54:47.828 tsx0x7f78040142d8 ......State changed from Proceeding to Completed, event=TX_MSG
19:54:47.828 dlg0x7f7804013078 .......Transaction tsx0x7f78040142d8 state changed to Completed
19:54:47.828 APP .........Call 1 state=CONNECTING
19:54:47.832 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=101 (rdata0x7f78040110a8)
19:54:47.832 pjsua_core.c .RX 867 bytes Request msg ACK/cseq=101 (rdata0x7f78040110a8) from UDP 192.168.100.189:50600:
ACK sip:7777@192.168.100.190:5070 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:50600;branch=z9hG4bKe7e20c60288
From: "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37236~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579540
To: <sip:7777@192.168.100.190>;tag=.NLzUagSiNQyOEsfdfqpaHfefZTwAxcg
Date: Wed, 21 Feb 2018 00:54:47 GMT
Call-ID: cec7eb00-a8c1c357-d1d-bd64a8c0@192.168.100.189
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence
Content-Type: application/sdp
Content-Length: 250
v=0
o=CiscoSystemsCCM-SIP 37236 1 IN IP4 192.168.100.189
s=SIP Call
c=IN IP4 192.168.100.182
b=AS:64
t=0 0
m=audio 4000 RTP/AVP 9 96
b=TIAS:64000
a=rtpmap:9 G722/8000
a=ptime:20
a=sendonly
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
--end msg--
19:54:47.833 dlg0x7f78040038c8 .Received Request msg ACK/cseq=101 (rdata0x7f78040110a8)
19:54:47.833 inv0x7f78040038c8 ..Got SDP answer in Request msg ACK/cseq=101 (rdata0x7f78040110a8)
19:54:47.833 inv0x7f78040038c8 ..SDP negotiation done, status=0
19:54:47.833 pjsua_call.c ...Call 0: remote NAT type is 0 (Unknown)
19:54:47.833 pjsua_media.c ...Call 0: updating media..
19:54:47.833 pjsua_media.c .....Media stream call00:0 is destroyed
19:54:47.833 pjsua_aud.c ....Audio channel update..
19:54:47.833 strm0x7f7804001d48 .....VAD temporarily disabled
19:54:47.834 rtp.c .....pjmedia_rtp_session_init: ses=0x7f7804022124, default_pt=9, ssrc=0x1e2e04c7
19:54:47.834 rtp.c .....pjmedia_rtp_session_init: ses=0x7f78040227a4, default_pt=9, ssrc=0x1e2e04c7
19:54:47.834 stream.c .....Stream strm0x7f7804001d48 created
19:54:47.834 strm0x7f7804001d48 .....Encoder stream paused
19:54:47.834 strm0x7f7804001d48 .....Decoder stream started
19:54:47.834 pjsua_media.c ....Audio updated, stream #0: G722 (recvonly)
19:54:47.834 tsx0x7f7804004b28 ..Request to terminate transaction
19:54:47.834 tsx0x7f7804004b28 ...State changed from Completed to Terminated, event=USER
19:54:47.834 dlg0x7f78040038c8 ....Transaction tsx0x7f7804004b28 state changed to Terminated
19:54:47.834 APP ...Call 0 state=CONFIRMED
19:54:47.834 sip_endpoint.c Processing incoming message: Request msg ACK/cseq=101 (rdata0x7f78040110a8)
19:54:47.834 pjsua_core.c .RX 866 bytes Request msg ACK/cseq=101 (rdata0x7f78040110a8) from UDP 192.168.100.189:50600:
ACK sip:7777@192.168.100.190:5070 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:50600;branch=z9hG4bKe7f711452a4
From: "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37237~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579543
To: <sip:7777@192.168.100.190>;tag=QDtMvvPNUx4RLeGdauL7hjaClxxbZZWW
Date: Wed, 21 Feb 2018 00:54:47 GMT
Call-ID: cec7eb00-a8c1c357-d1e-bd64a8c0@192.168.100.189
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence
Content-Type: application/sdp
Content-Length: 250
v=0
o=CiscoSystemsCCM-SIP 37237 1 IN IP4 192.168.100.189
s=SIP Call
c=IN IP4 192.168.100.182
b=AS:64
t=0 0
m=audio 4000 RTP/AVP 9 96
b=TIAS:64000
a=rtpmap:9 G722/8000
a=ptime:20
a=sendonly
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
--end msg--
19:54:47.835 dlg0x7f7804013078 .Received Request msg ACK/cseq=101 (rdata0x7f78040110a8)
19:54:47.835 inv0x7f7804013078 ..Got SDP answer in Request msg ACK/cseq=101 (rdata0x7f78040110a8)
19:54:47.835 inv0x7f7804013078 ..SDP negotiation done, status=0
19:54:47.835 pjsua_call.c ...Call 1: remote NAT type is 0 (Unknown)
19:54:47.835 pjsua_media.c ...Call 1: updating media..
19:54:47.835 pjsua_media.c .....Media stream call01:0 is destroyed
19:54:47.835 pjsua_aud.c ....Audio channel update..
19:54:47.835 strm0x7f7804030ce8 .....VAD temporarily disabled
19:54:47.835 rtp.c .....pjmedia_rtp_session_init: ses=0x7f7804034344, default_pt=9, ssrc=0x6982c644
19:54:47.835 rtp.c .....pjmedia_rtp_session_init: ses=0x7f78040349c4, default_pt=9, ssrc=0x6982c644
19:54:47.835 stream.c .....Stream strm0x7f7804030ce8 created
19:54:47.835 strm0x7f7804030ce8 .....Encoder stream paused
19:54:47.835 strm0x7f7804030ce8 .....Decoder stream started
19:54:47.835 pjsua_media.c ....Audio updated, stream #0: G722 (recvonly)
19:54:47.836 tsx0x7f78040142d8 ..Request to terminate transaction
19:54:47.836 tsx0x7f78040142d8 ...State changed from Completed to Terminated, event=USER
19:54:47.836 dlg0x7f7804013078 ....Transaction tsx0x7f78040142d8 state changed to Terminated
19:54:47.836 APP ...Call 1 state=CONFIRMED
19:54:47.836 tsx0x7f7804004b28 Timeout timer event
19:54:47.836 tsx0x7f7804004b28 .State changed from Terminated to Destroyed, event=TIMER
19:54:47.836 tdta0x7f78040063a8 ..Destroying txdata Response msg 200/INVITE/cseq=101 (tdta0x7f78040063a8)
19:54:47.836 tsx0x7f7804004b28 Transaction destroyed!
19:54:47.836 tsx0x7f78040142d8 Timeout timer event
19:54:47.836 tsx0x7f78040142d8 .State changed from Terminated to Destroyed, event=TIMER
19:54:47.836 tdta0x7f7804015b58 ..Destroying txdata Response msg 200/INVITE/cseq=101 (tdta0x7f7804015b58)
19:54:47.836 tsx0x7f78040142d8 Transaction destroyed!
19:54:47.961 strm0x7f7804001d48 !RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
19:54:47.981 stream.c G722 codec used, remote samples per frame detected = 80
19:54:48.014 strm0x7f7804030ce8 RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
19:54:48.034 stream.c G722 codec used, remote samples per frame detected = 80
19:54:48.141 udp0x7f7804009470 Remote RTP address switched to 192.168.100.182:20262
19:54:48.141 udp0x7f7804009470 Remote RTCP address switched to predicted address 192.168.100.182:20263
19:54:48.194 udp0x7f7804018a10 Remote RTP address switched to 192.168.100.182:20268
19:54:48.195 udp0x7f7804018a10 Remote RTCP address switched to predicted address 192.168.100.182:20269
19:54:59.566 sip_endpoint.c !Processing incoming message: Request msg BYE/cseq=102 (rdata0x7f78040110a8)
19:54:59.566 pjsua_core.c .RX 650 bytes Request msg BYE/cseq=102 (rdata0x7f78040110a8) from UDP 192.168.100.189:50600:
BYE sip:7777@192.168.100.190:5070 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:50600;branch=z9hG4bKe802785babd
From: "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37236~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579540
To: <sip:7777@192.168.100.190>;tag=.NLzUagSiNQyOEsfdfqpaHfefZTwAxcg
Date: Wed, 21 Feb 2018 00:54:47 GMT
Call-ID: cec7eb00-a8c1c357-d1d-bd64a8c0@192.168.100.189
User-Agent: Cisco-CUCM8.6
Max-Forwards: 70
P-Preferred-Identity: "7961 Phone" <sip:2802@192.168.100.189>
CSeq: 102 BYE
Content-Length: 0
--end msg--
19:54:59.566 dlg0x7f78040038c8 .Received Request msg BYE/cseq=102 (rdata0x7f78040110a8)
19:54:59.566 tsx0x7f78040142d8 ...Transaction created for Request msg BYE/cseq=102 (rdata0x7f78040110a8)
19:54:59.566 tsx0x7f78040142d8 ..Incoming Request msg BYE/cseq=102 (rdata0x7f78040110a8) in state Null
19:54:59.566 tsx0x7f78040142d8 ...State changed from Null to Trying, event=RX_MSG
19:54:59.566 dlg0x7f78040038c8 ....Transaction tsx0x7f78040142d8 state changed to Trying
19:54:59.566 endpoint .....Response msg 200/BYE/cseq=102 (tdta0x7f7804015b58) created
19:54:59.566 dlg0x7f78040038c8 ......Sending Response msg 200/BYE/cseq=102 (tdta0x7f7804015b58)
19:54:59.566 tsx0x7f78040142d8 ......Sending Response msg 200/BYE/cseq=102 (tdta0x7f7804015b58) in state Trying
19:54:59.566 sip_resolve.c .......Target '192.168.100.189:50600' type=UDP resolved to '192.168.100.189:50600' type=UDP (UDP transport)
19:54:59.566 pjsua_core.c .......TX 504 bytes Response msg 200/BYE/cseq=102 (tdta0x7f7804015b58) to UDP 192.168.100.189:50600:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.100.189:50600;received=192.168.100.189;branch=z9hG4bKe802785babd
Call-ID: cec7eb00-a8c1c357-d1d-bd64a8c0@192.168.100.189
From: "7961 Phone" <sip:2802@192.168.100.189;x-nearend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37236~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579540
To: <sip:7777@192.168.100.190>;tag=.NLzUagSiNQyOEsfdfqpaHfefZTwAxcg
CSeq: 102 BYE
Content-Length: 0
--end msg--
19:54:59.566 tsx0x7f78040142d8 .......State changed from Trying to Completed, event=TX_MSG
19:54:59.566 dlg0x7f78040038c8 ........Transaction tsx0x7f78040142d8 state changed to Completed
19:54:59.566 APP ......Call 0 state=DISCONNCTD
19:54:59.566 pjsua_media.c ......Call 0: deinitializing media..
19:54:59.566 strm0x7f7804001d48 ........JB summary:
size=50/eff=50 prefetch=0 level=0
delay (min/max/avg/dev)=0/0/0/0 ms
burst (min/max/avg/dev)=0/0/0/0 frames
lost=0 discard=1110 empty=0
19:54:59.566 pjsua_media.c ........Media stream call00:0 is destroyed
19:54:59.566 dlg0x7f78040038c8 ......Session count dec to 4 by mod-invite
19:54:59.566 sip_endpoint.c Processing incoming message: Request msg BYE/cseq=102 (rdata0x7f7804020e28)
19:54:59.566 pjsua_core.c .RX 649 bytes Request msg BYE/cseq=102 (rdata0x7f7804020e28) from UDP 192.168.100.189:50600:
BYE sip:7777@192.168.100.190:5070 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:50600;branch=z9hG4bKe816ae504e0
From: "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37237~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579543
To: <sip:7777@192.168.100.190>;tag=QDtMvvPNUx4RLeGdauL7hjaClxxbZZWW
Date: Wed, 21 Feb 2018 00:54:47 GMT
Call-ID: cec7eb00-a8c1c357-d1e-bd64a8c0@192.168.100.189
User-Agent: Cisco-CUCM8.6
Max-Forwards: 70
P-Preferred-Identity: "7961 Phone" <sip:2802@192.168.100.189>
CSeq: 102 BYE
Content-Length: 0
--end msg--
19:54:59.566 dlg0x7f7804013078 .Received Request msg BYE/cseq=102 (rdata0x7f7804020e28)
19:54:59.566 tsx0x7f7804004b28 ...Transaction created for Request msg BYE/cseq=102 (rdata0x7f7804020e28)
19:54:59.566 tsx0x7f7804004b28 ..Incoming Request msg BYE/cseq=102 (rdata0x7f7804020e28) in state Null
19:54:59.566 tsx0x7f7804004b28 ...State changed from Null to Trying, event=RX_MSG
19:54:59.567 dlg0x7f7804013078 ....Transaction tsx0x7f7804004b28 state changed to Trying
19:54:59.567 endpoint .....Response msg 200/BYE/cseq=102 (tdta0x7f7804000968) created
19:54:59.567 dlg0x7f7804013078 ......Sending Response msg 200/BYE/cseq=102 (tdta0x7f7804000968)
19:54:59.567 tsx0x7f7804004b28 ......Sending Response msg 200/BYE/cseq=102 (tdta0x7f7804000968) in state Trying
19:54:59.567 sip_resolve.c .......Target '192.168.100.189:50600' type=UDP resolved to '192.168.100.189:50600' type=UDP (UDP transport)
19:54:59.567 pjsua_core.c .......TX 503 bytes Response msg 200/BYE/cseq=102 (tdta0x7f7804000968) to UDP 192.168.100.189:50600:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.100.189:50600;received=192.168.100.189;branch=z9hG4bKe816ae504e0
Call-ID: cec7eb00-a8c1c357-d1e-bd64a8c0@192.168.100.189
From: "7961 Phone" <sip:2802@192.168.100.189;x-farend;x-refci=18579534;x-nearenddevice=PHONE1;x-farendrefci=18579535;x-farenddevice=PHONE2;x-farendaddr=2800>;tag=37237~71c7513b-05dd-4b86-9860-7502a52eb9e2-18579543
To: <sip:7777@192.168.100.190>;tag=QDtMvvPNUx4RLeGdauL7hjaClxxbZZWW
CSeq: 102 BYE
Content-Length: 0
--end msg--
19:54:59.567 tsx0x7f7804004b28 .......State changed from Trying to Completed, event=TX_MSG
19:54:59.567 dlg0x7f7804013078 ........Transaction tsx0x7f7804004b28 state changed to Completed
19:54:59.567 APP ......Call 1 state=DISCONNCTD
19:54:59.567 pjsua_media.c ......Call 1: deinitializing media..
19:54:59.567 strm0x7f7804030ce8 ........JB summary:
size=50/eff=50 prefetch=0 level=0
delay (min/max/avg/dev)=0/0/0/0 ms
burst (min/max/avg/dev)=0/0/0/0 frames
lost=0 discard=1104 empty=0
19:54:59.567 pjsua_media.c ........Media stream call01:0 is destroyed
19:54:59.567 dlg0x7f7804013078 ......Session count dec to 4 by mod-invite
19:55:31.566 tsx0x7f78040142d8 Timeout timer event
19:55:31.566 tsx0x7f78040142d8 .State changed from Completed to Terminated, event=TIMER
19:55:31.566 dlg0x7f78040038c8 ..Transaction tsx0x7f78040142d8 state changed to Terminated
19:55:31.566 tsx0x7f7804004b28 Timeout timer event
19:55:31.567 tsx0x7f7804004b28 .State changed from Completed to Terminated, event=TIMER
19:55:31.567 dlg0x7f7804013078 ..Transaction tsx0x7f7804004b28 state changed to Terminated
19:55:31.567 tsx0x7f78040142d8 Timeout timer event
19:55:31.567 tsx0x7f78040142d8 .State changed from Terminated to Destroyed, event=TIMER
19:55:31.567 tdta0x7f7804015b58 ..Destroying txdata Response msg 200/BYE/cseq=102 (tdta0x7f7804015b58)
19:55:31.567 tsx0x7f78040142d8 Transaction destroyed!
19:55:31.567 tsx0x7f7804004b28 Timeout timer event
19:55:31.567 tsx0x7f7804004b28 .State changed from Terminated to Destroyed, event=TIMER
19:55:31.567 tdta0x7f7804000968 ..Destroying txdata Response msg 200/BYE/cseq=102 (tdta0x7f7804000968)
19:55:31.567 tsx0x7f7804004b28 Transaction destroyed!
19:55:36.079 pjsua_core.c !Start dumping application states:
PJLIB (c)2008-2016 Teluu Inc.
Dumping configurations:
PJ_VERSION : 2.7.1
PJ_M_NAME : x86_64
PJ_HAS_PENTIUM : 0
PJ_OS_NAME : x86_64-unknown-linux-gnu
PJ_CC_NAME/VER_(1,2,3) : gcc-5.4.0
PJ_IS_(BIG/LITTLE)_ENDIAN : little-endian
PJ_HAS_INT64 : 1
PJ_HAS_FLOATING_POINT : 1
PJ_DEBUG : 0
PJ_FUNCTIONS_ARE_INLINED : 0
PJ_LOG_MAX_LEVEL : 9
PJ_LOG_MAX_SIZE : 4000
PJ_LOG_USE_STACK_BUFFER : 1
PJ_POOL_DEBUG : 0
PJ_HAS_POOL_ALT_API : 0
PJ_HAS_TCP : 1
PJ_MAX_HOSTNAME : 128
ioqueue type : epoll
PJ_IOQUEUE_MAX_HANDLES : 64
PJ_IOQUEUE_HAS_SAFE_UNREG : 1
PJ_HAS_THREADS : 1
PJ_LOG_USE_STACK_BUFFER : 1
PJ_HAS_SEMAPHORE : 1
PJ_HAS_EVENT_OBJ : 1
PJ_ENABLE_EXTRA_CHECK : 0
PJ_HAS_EXCEPTION_NAMES : 1
PJ_MAX_EXCEPTION_ID : 16
PJ_EXCEPTION_USE_WIN32_SEH: 0
PJ_TIMESTAMP_USE_RDTSC: : 0
PJ_OS_HAS_CHECK_STACK : 0
PJ_HAS_HIGH_RES_TIMER : 1
PJ_HAS_IPV6 : 0
pjsip_endpt_dump()
Dumping endpoint 0x2429008:
Dumping caching pool:
Capacity=0, max_capacity=0, used_cnt=21
Dumping all active pools:
pjsua: 161720 of 164024 (98%) used
pept0x2428f60: 31492784 of 31496096 (99%) used
tsxlayer: 8388920 of 8389632 (99%) used
ua0x2430f50: 8389048 of 8389632 (99%) used
alsa_aud_base: 13376 of 13568 (98%) used
alsa_aud: 168 of 256 (65%) used
med-ept: 35800 of 37376 (95%) used
codec-mgr: 240 of 256 (93%) used
speex: 240 of 4096 (5%) used
gsm: 240 of 4096 (5%) used
g711: 240 of 4096 (5%) used
g722: 7672 of 8024 (95%) used
l16: 240 of 4096 (5%) used
opus-factory: 168 of 1024 (16%) used
evsub: 3000 of 4608 (65%) used
udp0x2444ea0: 1176 of 1536 (76%) used
glck0x247d040: 584 of 1024 (57%) used
rtd0x247d460: 5064 of 12096 (41%) used
acc0x24803c0: 648 of 768 (84%) used
dlg0x7f7804003820: 67600 of 68608 (98%) used
dlg0x7f7804012fd0: 67592 of 68608 (98%) used
Total 48636520 of 48673520 (99 %) used!
Endpoint pool capacity=31496096, used_size=31492784
Dumping listeners:
Dumping transports:
udp0x2444ea0 udp 0.0.0.0:5070 [published as 192.168.100.190:5070] (refcnt=1)
Timer heap has 1 entries
Dumping PJMEDIA capabilities:
Total number of installed codecs: 11
Audio codec # 0: pt=98 (speex @16KHz/1, 27.8Kbps, 20ms vad cng plc penh)
Audio codec # 1: pt=97 (speex @8KHz/1, 15.0Kbps, 20ms vad cng plc penh)
Audio codec # 2: pt=99 (speex @32KHz/1, 29.6Kbps, 20ms vad cng plc penh)
Audio codec # 3: pt=104 (iLBC @8KHz/1, 13.3Kbps, 30ms vad plc penh)
Audio codec # 4: pt=3 (GSM @8KHz/1, 13.2Kbps, 20ms vad plc)
Audio codec # 5: pt=0 (PCMU @8KHz/1, 64.0Kbps, 20ms vad plc)
Audio codec # 6: pt=8 (PCMA @8KHz/1, 64.0Kbps, 20ms vad plc)
Audio codec # 7: pt=9 (G722 @16KHz/1, 64.0Kbps, 20ms vad plc)
Audio codec # 8: pt=120 (opus @48KHz/2, 0bps, 20ms plc)
Audio codec # 9: pt=10 (L16 @44KHz/2, 1.41Mbps, 10ms vad plc disabled)
Audio codec #10: pt=11 (L16 @44KHz/1, 705.6Kbps, 10ms vad plc disabled)
Dumping media transports:
Dumping transaction table:
Total 0 transactions
- none -
Number of dialog sets: 2
Dumping dialog sets:
[in] [est] <--uri too long-->
[in] [est] <--uri too long-->
Dumping pjsua server subscriptions:
sip:7777@192.168.100.189
- none -
Dumping pjsua client subscriptions:
- no buddy list -
19:55:36.090 pjsua_core.c Dump complete
#define PJ_SCANNER_USE_BITWISE 0 #undef PJ_OS_HAS_CHECK_STACK #define PJ_OS_HAS_CHECK_STACK 0 #define PJ_LOG_MAX_LEVEL 9 #define PJ_ENABLE_EXTRA_CHECK 0 #define PJSIP_MAX_TSX_COUNT ((640*1024)-1) #define PJSIP_MAX_DIALOG_COUNT ((640*1024)-1) #define PJSIP_UDP_SO_SNDBUF_SIZE (24*1024*1024) #define PJSIP_UDP_SO_RCVBUF_SIZE (24*1024*1024) #define PJ_DEBUG 0 #define PJSIP_SAFE_MODULE 0 #define PJ_HAS_STRICMP_ALNUM 0 #define PJ_HASH_USE_OWN_TOLOWER 1 #define PJSIP_UNESCAPE_IN_PLACE 1 #define PJSUA_MAX_CALLS 4096 #define PJMEDIA_HAS_SPEEX_AEC 0 #define PJSUA_MAX_PLAYERS 4096 #define PJSUA_MAX_RECORDERS 4096 #define PJSUA_MAX_CONF_PORTS (PJSUA_MAX_CALLS+2*PJSUA_MAX_PLAYERS)
// gcc repro.c -o repro -g -L/usr/local/lib -lpjsua -lpjsip-ua -lpjsip-simple -lpjsip -lpjmedia-codec -lpjmedia -lpjmedia-videodev -lpjmedia-audiodev -lpjmedia -lpjnath -lpjlib-util -lsrtp -lresample -lgsmcodec -lilbccodec -lportaudio -lpj -lm -lrt -lpthread -lcrypto -lssl
#include <signal.h>
#include <pjsua-lib/pjsua.h>
#define THIS_FILE "APP"
static void on_incoming_call(pjsua_acc_id acc_id, pjsua_call_id call_id,
pjsip_rx_data *rdata) {
pjsua_call_info ci;
PJ_UNUSED_ARG(acc_id);
PJ_UNUSED_ARG(rdata);
pjsua_call_get_info(call_id, &ci);
PJ_LOG(3,(THIS_FILE, "Incoming call from %.*s!!",
(int)ci.remote_info.slen,
ci.remote_info.ptr));
/* Automatically answer incoming calls with 200/OK */
pjsua_call_answer(call_id, 200, NULL, NULL);
}
static void on_call_state(pjsua_call_id call_id, pjsip_event *e) {
pjsua_call_info ci;
PJ_UNUSED_ARG(e);
pjsua_call_get_info(call_id, &ci);
PJ_LOG(3,(THIS_FILE, "Call %d state=%.*s", call_id,
(int)ci.state_text.slen,
ci.state_text.ptr));
}
static void error_exit(const char *title, pj_status_t status) {
pjsua_perror(THIS_FILE, title, status);
pjsua_destroy();
exit(1);
}
void sighandler(int signum, siginfo_t* info, void* ptr) {
pjsua_dump(PJ_TRUE);
}
int main(int argc, char *argv[]) {
pjsua_acc_id acc_id;
pj_status_t status;
/* Create pjsua first! */
status = pjsua_create();
if (status != PJ_SUCCESS)
error_exit("Error in pjsua_create()", status);
/* Init pjsua */
{
pjsua_config cfg;
pjsua_logging_config log_cfg;
pjsua_config_default(&cfg);
cfg.cb.on_incoming_call = &on_incoming_call;
cfg.cb.on_call_state = &on_call_state;
pjsua_logging_config_default(&log_cfg);
log_cfg.console_level = 5;
status = pjsua_init(&cfg, &log_cfg, NULL);
if (status != PJ_SUCCESS)
error_exit("Error in pjsua_init()", status);
}
/* Add UDP transport. */
{
pjsua_transport_config cfg;
pjsua_transport_config_default(&cfg);
cfg.port = 5070;
status = pjsua_transport_create(PJSIP_TRANSPORT_UDP, &cfg, NULL);
if (status != PJ_SUCCESS)
error_exit("Error creating transport", status);
}
/* Initialization is done, now start pjsua */
status = pjsua_start();
if (status != PJ_SUCCESS)
error_exit("Error starting pjsua", status);
/* Register to SIP server by creating SIP account. */
{
pjsua_acc_config cfg;
pjsua_acc_config_default(&cfg);
cfg.id = pj_str("sip:7777@192.168.100.189");
status = pjsua_acc_add(&cfg, PJ_TRUE, &acc_id);
if (status != PJ_SUCCESS)
error_exit("Error adding account", status);
}
struct sigaction act;
act.sa_sigaction = sighandler;
act.sa_flags = SA_SIGINFO;
sigaction(SIGUSR2, &act, NULL);
while (1)
pj_thread_sleep(100);
return 0;
}
_______________________________________________ Visit our blog: http://blog.pjsip.org pjsip mailing list pjsip@xxxxxxxxxxxxxxx http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
