Conference Bridge - 3rd user gets kicked out

Hi everyone,
I am quite new to Asterisk yet I have created a simple solution which used to handle my SIP traffic. Problem I started facing recently is that my conference bridge is dropping 3rd user trying to connect to the bridge.

OS Version: CentOS 7.2
Asterisk version: 13.10.0.-rc1 && 13.7.2
PJSIP version: 2.4 && 2.5.1

My scenario is bit complicated so let me start from the beginning.
I am not using Asterisk in office environment. I am using it as a VoIP mixer in my app. So all traffic is being routed from my SIP Gateway to the conference bridge and then back to same SIP gateway and to the users phone (the app).
I have 2 servers which handle similar traffic but one is stable and other test, that later one is my troublemaker.

All traffic that confB receives is internal. The Virtual Machine has no public IP and firewall is disabled, also I am not authenticating users.Max users in confB is 20. I assume that users who know conference bridge numbers have access to that one conference bridge (numbers are complex and setup only when user creates a group).
My configs are all based on sample asterisk configs with exception of dial plan.
It is as follows:

  • I have removed all lines regarding netsock2.c as they seemed irrelevant.
    [conference-context]
    exten => 00000001,1,Progress()
    exten => 00000001,n,Wait(1)
    exten => 00000001,n,Answer()
    exten => 00000001,n,Confbridge(00000001,default_bridge,default_user)
    exten => 00000001,n,Hangup()

So scenario is this. We have User A , B and C. All of them know that they want to call conference bridge (00000001)
The enter as in order A, B, C.
User C is always kicked off when trying to come in after B. Also awkwardly he could enter other confB (00000002) and there is no issue with that.

So when 3rd user arrives he is distinguished as 3rd party, he receives ACK from SIPGateway. In the meantime it seems that Asterisk waits for response from SIPGateway and then instantly sends BYE. If you want I can attach SIP Debug as well for now Asterisk is attached below. Hopefully you could point me in the right direction.
Asterisk Debug
[:39] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7f8a6c005cc8)
[:39] DEBUG[2897] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against
[:39] DEBUG[2897] res_pjsip_endpoint_identifier_user.c: Could not identify endpoint by username ‘User C’
[:39] DEBUG[2897] res_pjsip_endpoint_identifier_anonymous.c: Retrieved anonymous endpoint ‘anonymous’
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 …Transaction created for Request msg INVITE/cseq=1 (rdata0x7f8a6c005cc8)
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 .Incoming Request msg INVITE/cseq=1 (rdata0x7f8a6c005cc8) in state Null
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Null to Trying, event=RX_MSG
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Trying
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 .UAS dialog created
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 .Module mod-invite added as dialog usage, data=0x7f8a94019548
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Session count inc to 2 by mod-invite
[:39] DEBUG[2897] pjsip: inv0x7f8a94002 .UAS invite session created for dialog dlg0x7f8a94002a08
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 .Module Session Module added as dialog usage, data=(nil)
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Session count inc to 2 by Session Module
[:39] DEBUG[2897] res_pjsip_session.c: Negotiating incoming SDP media stream ‘audio’ using audio SDP handler
[:39] DEBUG[2897] rtp_engine.c: Using engine ‘asterisk’ for RTP instance ‘0x7f8a94029478’
[:39] DEBUG[2897] res_rtp_asterisk.c: Allocated port 10812 for RTP instance ‘0x7f8a94029478’
[:39] DEBUG[2897] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:10812 (10812) for RTP instance ‘0x7f8a94029478’
[:39] DEBUG[2897] pjsip: icess0x7f8a940 ICE session created, comp_cnt=2, role is Unknown agent
[:39] DEBUG[2897] pjsip: icess0x7f8a940 Candidate 0 added: comp_id=1, type=host, foundation=Ha29042f, addr=ConferenceBridge:10812, base=ConferenceBridge:10812, prio=0x7effffff (2130706431)
[:39] DEBUG[2897] rtp_engine.c: RTP instance ‘0x7f8a94029478’ is setup and ready to go
[:39] DEBUG[2897] res_rtp_asterisk.c: Setup RTCP on RTP instance ‘0x7f8a94029478’
[:39] DEBUG[2897] pjsip: icess0x7f8a940 Candidate 1 added: comp_id=2, type=host, foundation=Ha29042f, addr=ConferenceBridge:10813, base=ConferenceBridge:10813, prio=0x7efffffe (2130706430)
[:39] DEBUG[2897] pjsip: icess0x7f8a940 Destroying ICE session 0x7f8a9403c1e8
[:39] DEBUG[2897] pjsip: stuse0x7f8a940 STUN session 0x7f8a9401d7f8 destroy request, ref_cnt=4
[:39] DEBUG[2897] pjsip: stuse0x7f8a940 STUN session 0x7f8a9403aec8 destroy request, ref_cnt=3
[:39] DEBUG[2897] pjsip: ice_session.c ICE session 0x7f8a9403c1e8 destroyed
[:39] DEBUG[2897] pjsip: stun_session.c STUN session 0x7f8a9401d7f8 destroyed
[:39] DEBUG[2897] pjsip: stun_session.c STUN session 0x7f8a9403aec8 destroyed
[:39] DEBUG[2897] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f8a939623d0
[:39] DEBUG[2897] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f8a939623d0
[:39] DEBUG[2897] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f8a939623d0
[:39] DEBUG[2897] rtp_engine.c: Copying payload 0 (0x7f8a94012d30) from 0x7f8a939623d0 to 0x7f8a94029640
[:39] DEBUG[2897] rtp_engine.c: Copying payload 8 (0x7f8a94012490) from 0x7f8a939623d0 to 0x7f8a94029640
[:39] DEBUG[2897] rtp_engine.c: Copying payload 101 (0x7f8a9403aa00) from 0x7f8a939623d0 to 0x7f8a94029640
[:39] DEBUG[2897] res_pjsip_session.c: Media stream ‘audio’ handled by audio
[:39] DEBUG[2897] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled
[:39] DEBUG[2897] pjsip: endpoint .Response msg 100/INVITE/cseq=1 (tdta0x7f8a94008c80) created
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 .Initial answer Response msg 100/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[:39] DEBUG[2897] pjsip: inv0x7f8a94002 .Sending Response msg 100/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Sending Response msg 100/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 …Sending Response msg 100/INVITE/cseq=1 (tdta0x7f8a94008c80) in state Trying
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Trying to Proceeding, event=TX_MSG
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Proceeding
[:39] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[:39] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:39] DEBUG[2897] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8a94003848)
[:39] DEBUG[2897] res_pjsip_session.c: There is no transaction involved in this state change
[:39] DEBUG[2897] res_pjsip_session.c: The current inv state is INCOMING
[:39] DEBUG[2897] res_pjsip_session.c: Source of transaction state change is TX_MSG
[:39] DEBUG[2897] res_pjsip_session.c: Sending response
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[:39] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:39] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:39] DEBUG[2897] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8a94003848)
[:39] DEBUG[2897] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f8a94003848
[:39] DEBUG[2897] res_pjsip_session.c: The current transaction state is Proceeding
[:39] DEBUG[2897] res_pjsip_session.c: The transaction state change event is TX_MSG
[:39] DEBUG[2897] res_pjsip_session.c: The current inv state is INCOMING
[:39] DEBUG[2897] res_pjsip_session.c: Sending response
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 100 Trying
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 Module NAT added as dialog usage, data=(nil)
[:39] DEBUG[2897] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/anonymous-00000003
[:39] DEBUG[2915][C-00000003] pbx.c: Launching ‘Progress’
[:39] VERBOSE[2915][C-00000003] pbx.c: Executing [00000001@conference-context:1] Progress(“PJSIP/anonymous-00000003”, “”) in new stack
[:39] DEBUG[2915][C-00000003] pbx.c: Launching ‘Wait’
[:39] VERBOSE[2915][C-00000003] pbx.c: Executing [00000001@conference-context:2] Wait(“PJSIP/anonymous-00000003”, “1”) in new stack
[:39] DEBUG[2897] pjsip: inv0x7f8a94002 .SDP negotiation done, status=0
[:39] DEBUG[2897] res_pjsip_session.c: Applying negotiated SDP media stream ‘audio’ using audio SDP handler
[:39] DEBUG[2897] netsock2.c: Splitting ‘SIPGateway’ into…
[:39] DEBUG[2897] netsock2.c: …host ‘SIPGateway’ and port ‘’.
[:39] DEBUG[2897] res_rtp_asterisk.c: Setting RTCP address on RTP instance ‘0x7f8a94029478’
[:39] DEBUG[2897] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f8a93961d90
[:39] DEBUG[2897] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f8a93961d90
[:39] DEBUG[2897] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f8a93961d90
[:39] DEBUG[2897] rtp_engine.c: Copying payload 0 (0x7f8a940077b0) from 0x7f8a93961d90 to 0x7f8a94029640
[:39] DEBUG[2897] rtp_engine.c: Copying payload 8 (0x7f8a940218f0) from 0x7f8a93961d90 to 0x7f8a94029640
[:39] DEBUG[2897] rtp_engine.c: Copying payload 101 (0x7f8a94020260) from 0x7f8a93961d90 to 0x7f8a94029640
[:39] DEBUG[2897] res_pjsip_session.c: Applied negotiated SDP media stream ‘audio’ using audio SDP handler
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 183 Session Progress
[:39] DEBUG[2897] pjsip: inv0x7f8a94002 .Sending Response msg 183/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Sending Response msg 183/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 …Sending Response msg 183/INVITE/cseq=1 (tdta0x7f8a94008c80) in state Proceeding
[:39] DEBUG[2897] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to ConferenceBridge:5060
[:39] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Proceeding to Proceeding, event=TX_MSG
[:39] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Proceeding
[:39] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[:39] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous(PJSIP/anonymous-00000003)’
[:39] DEBUG[2897] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8a94003848)
[:39] DEBUG[2897] res_pjsip_session.c: There is no transaction involved in this state change
[:39] DEBUG[2897] res_pjsip_session.c: The current inv state is EARLY
[:39] DEBUG[2897] res_pjsip_session.c: Source of transaction state change is TX_MSG
[:39] DEBUG[2897] res_pjsip_session.c: Sending response
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 183 Session Progress
[:39] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:39] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous(PJSIP/anonymous-00000003)’
[:39] DEBUG[2897] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8a94003848)
[:39] DEBUG[2897] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f8a94003848
[:39] DEBUG[2897] res_pjsip_session.c: The current transaction state is Proceeding
[:39] DEBUG[2897] res_pjsip_session.c: The transaction state change event is TX_MSG
[:39] DEBUG[2897] res_pjsip_session.c: The current inv state is EARLY
[:39] DEBUG[2897] res_pjsip_session.c: Sending response
[:39] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 183 Session Progress
[:40] DEBUG[2915][C-00000003] pbx.c: Launching ‘Answer’
[:40] VERBOSE[2915][C-00000003] pbx.c: Executing [00000001@conference-context:3] Answer(“PJSIP/anonymous-00000003”, “”) in new stack
[:40] DEBUG[2821] devicestate.c: No provider found, checking channel drivers for PJSIP - anonymous
[:40] DEBUG[2821] devicestate.c: Changing state for PJSIP/anonymous - state 2 (In use)
[:40] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[:40] DEBUG[2897] pjsip: inv0x7f8a94002 .Sending Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:40] DEBUG[2897] pjsip: dlg0x7f8a94002 …Sending Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:40] DEBUG[2897] pjsip: tsx0x7f8a94003 …Sending Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80) in state Proceeding
[:40] DEBUG[2897] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to ConferenceBridge:5060
[:40] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Proceeding to Completed, event=TX_MSG
[:40] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Completed
[:40] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[:40] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous(PJSIP/anonymous-00000003)’
[:40] DEBUG[2897] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8a94003848)
[:40] DEBUG[2897] res_pjsip_session.c: There is no transaction involved in this state change
[:40] DEBUG[2897] res_pjsip_session.c: The current inv state is CONNECTING
[:40] DEBUG[2897] res_pjsip_session.c: Source of transaction state change is TX_MSG
[:40] DEBUG[2897] res_pjsip_session.c: Sending response
[:40] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[:40] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:40] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous(PJSIP/anonymous-00000003)’
[:40] DEBUG[2897] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8a94003848)
[:40] DEBUG[2897] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f8a94003848
[:40] DEBUG[2897] res_pjsip_session.c: The current transaction state is Completed
[:40] DEBUG[2897] res_pjsip_session.c: The transaction state change event is TX_MSG
[:40] DEBUG[2897] res_pjsip_session.c: The current inv state is CONNECTING
[:40] DEBUG[2897] res_pjsip_session.c: Sending response
[:40] DEBUG[2897] res_pjsip_session.c: Method is INVITE, Response is 200 OK
[:40] DEBUG[2867] acl.c: Not an IPv4 nor IPv6 address, cannot get port.
[:40] DEBUG[2867] netsock2.c: Splitting ‘LinuxVM’ into…
[:40] DEBUG[2867] netsock2.c: …host ‘LinuxVM’ and port ‘’.
[:40] DEBUG[2867] acl.c: Not an IPv4 nor IPv6 address, cannot get port.
[:40] DEBUG[2867] acl.c: Attached to given IP address
[:40] DEBUG[2883] netsock2.c: Splitting ‘ConferenceBridge:0’ into…
[:40] DEBUG[2883] netsock2.c: …host ‘ConferenceBridge’ and port ‘0’.
[:40] DEBUG[2883] netsock2.c: Splitting ‘SIPGateway:3697’ into…
[:40] DEBUG[2883] netsock2.c: …host ‘SIPGateway’ and port ‘3697’.
[:41] DEBUG[2840] pjsip: tsx0x7f8a94003 Retransmit timer event
[:41] DEBUG[2840] pjsip: tsx0x7f8a94003 .Retransmiting Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80), count=0, restart?=1
[:41] DEBUG[2840] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to ConferenceBridge:5060
[:41] DEBUG[2915][C-00000003] channel.c: Didn’t receive a media frame from PJSIP/anonymous-00000003 within 500 ms of answering. Continuing anyway
[:41] DEBUG[2915][C-00000003] pbx.c: Launching ‘ConfBridge’
[:41] VERBOSE[2915][C-00000003] pbx.c: Executing [00000001@conference-context:4] ConfBridge(“PJSIP/anonymous-00000003”, “00000001,default_bridge,default_user”) in new stack
[:41] DEBUG[2915][C-00000003] app_confbridge.c: Trying to find conference bridge ‘00000001’
[:41] DEBUG[2915][C-00000003] app_confbridge.c: User PJSIP/anonymous-00000003 is unmuted: user:0 system:0.
[:41] WARNING[2915][C-00000003] file.c: File yes does not exist in any format
[:41] WARNING[2915][C-00000003] file.c: Unable to open yes (format (ulaw)): No such file or directory
[:41] DEBUG[2915][C-00000003] pbx.c: Spawn extension (conference-context,00000001,4) exited non-zero on ‘PJSIP/anonymous-00000003’
[:41] VERBOSE[2915][C-00000003] pbx.c: Spawn extension (conference-context, 00000001, 4) exited non-zero on ‘PJSIP/anonymous-00000003’
[:41] DEBUG[2915][C-00000003] channel.c: Soft-Hanging (0x10) up channel ‘PJSIP/anonymous-00000003’
[:41] DEBUG[2915][C-00000003] channel.c: Hanging up channel ‘PJSIP/anonymous-00000003’
[:41] DEBUG[2915][C-00000003] chan_pjsip.c: AST hangup cause 0 (no match found in PJSIP)
[:41] DEBUG[2897] pjsip: endpoint .Request msg BYE/cseq=13978 (tdta0x7f8a5c004fd0) created.
[:41] DEBUG[2897] res_pjsip_session.c: Method is BYE
[:41] DEBUG[2897] pjsip: inv0x7f8a94002 .Sending Request msg BYE/cseq=13978 (tdta0x7f8a5c004fd0)
[:41] DEBUG[2897] pjsip: inv0x7f8a94002 .Delaying BYE request until ACK is received
[:41] DEBUG[2821] devicestate.c: No provider found, checking channel drivers for PJSIP - anonymous
[:41] DEBUG[2821] devicestate.c: Changing state for PJSIP/anonymous - state 2 (In use)
[:41] DEBUG[2827] cdr.c: Finalized CDR for PJSIP/anonymous-00000003 - start 1467033939.886153 answer 1467033940.890376 end 1467033941.392322 dispo ANSWERED
[:42] DEBUG[2840] pjsip: tsx0x7f8a94003 Retransmit timer event
[:42] DEBUG[2840] pjsip: tsx0x7f8a94003 .Retransmiting Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80), count=1, restart?=1
[:42] DEBUG[2840] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to ConferenceBridge:5060
[:42] DEBUG[2867] acl.c: Not an IPv4 nor IPv6 address, cannot get port.
[:42] DEBUG[2867] acl.c: Not an IPv4 nor IPv6 address, cannot get port.
[:42] DEBUG[2867] acl.c: Attached to given IP address
[:44] DEBUG[2840] pjsip: tsx0x7f8a94003 Retransmit timer event
[:44] DEBUG[2840] pjsip: tsx0x7f8a94003 .Retransmiting Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80), count=2, restart?=1
[:44] DEBUG[2840] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to ConferenceBridge:5060
[:45] DEBUG[2867] acl.c: Not an IPv4 nor IPv6 address, cannot get port.
[:45] DEBUG[2867] acl.c: Not an IPv4 nor IPv6 address, cannot get port.
[:45] DEBUG[2867] acl.c: Attached to given IP address
[:46] DEBUG[2840] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=1 (rdata0x7f8a6c003d78)
[:46] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 .Received Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …Request to terminate transaction
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Completed to Terminated, event=USER
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Terminated
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f8a94003848
[:46] DEBUG[2897] res_pjsip_session.c: The current transaction state is Terminated
[:46] DEBUG[2897] res_pjsip_session.c: The transaction state change event is USER
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is CONNECTING
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: There is no transaction involved in this state change
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is CONFIRMED
[:46] DEBUG[2897] res_pjsip_session.c: Received request
[:46] DEBUG[2897] res_pjsip_session.c: Method is ACK
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Sending pending BYE
[:46] DEBUG[2897] pjsip: inv0x7f8a94002 …Sending Request msg BYE/cseq=13978 (tdta0x7f8a5c004fd0)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Sending Request msg BYE/cseq=13978 (tdta0x7f8a5c004fd0)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94030 …Transaction created for Request msg BYE/cseq=13977 (tdta0x7f8a5c004fd0)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94030 …Sending Request msg BYE/cseq=13977 (tdta0x7f8a5c004fd0) in state Null
[:46] DEBUG[2897] pjsip: sip_resolve.c …Target ‘SIPGateway:5060’ type=Unspecified resolved to ‘SIPGateway:5060’ type=UDP (UDP transport)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94030 …State changed from Null to Calling, event=TX_MSG
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94030698 state changed to Calling
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f8a94030698
[:46] DEBUG[2897] res_pjsip_session.c: The current transaction state is Calling
[:46] DEBUG[2897] res_pjsip_session.c: The transaction state change event is TX_MSG
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is CONFIRMED
[:46] DEBUG[2897] res_pjsip_session.c: Sending request
[:46] DEBUG[2897] res_pjsip_session.c: Method is BYE
[:46] DEBUG[2840] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=1 (rdata0x7f8a6c003d78)
[:46] DEBUG[2840] pjsip: tsx0x7f8a94003 Timeout timer event
[:46] DEBUG[2840] pjsip: tsx0x7f8a94003 .State changed from Terminated to Destroyed, event=TIMER
[:46] DEBUG[2840] pjsip: tdta0x7f8a9400 …Destroying txdata Response msg 200/INVITE/cseq=1 (tdta0x7f8a94008c80)
[:46] DEBUG[2840] pjsip: tsx0x7f8a94003 Transaction destroyed!
[:46] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 .Received Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2840] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=1 (rdata0x7f8a6c003d78)
[:46] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 .Received Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2840] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=1 (rdata0x7f8a6c003d78)
[:46] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 .Received Request msg ACK/cseq=1 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2840] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/BYE/cseq=13977 (rdata0x7f8a6c003d78)
[:46] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/BYE/cseq=13977 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94030 .Incoming Response msg 200/BYE/cseq=13977 (rdata0x7f8a6c005cc8) in state Calling
[:46] DEBUG[2897] pjsip: tsx0x7f8a94030 …State changed from Calling to Completed, event=RX_MSG
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Received Response msg 200/BYE/cseq=13977 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94030698 state changed to Completed
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: There is no transaction involved in this state change
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is DISCONNCTD
[:46] DEBUG[2897] res_pjsip_session.c: Source of transaction state change is RX_MSG
[:46] DEBUG[2897] res_pjsip_session.c: Received response
[:46] DEBUG[2897] res_pjsip_session.c: Response is 200 Ok
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Session count dec to 2 by mod-invite
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f8a94030698
[:46] DEBUG[2897] res_pjsip_session.c: The current transaction state is Completed
[:46] DEBUG[2897] res_pjsip_session.c: The transaction state change event is RX_MSG
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is DISCONNCTD
[:46] DEBUG[2897] res_pjsip_session.c: Received response
[:46] DEBUG[2897] res_pjsip_session.c: Response is 200 Ok
[:46] DEBUG[2897] res_pjsip_session.c: BYE received final response code 200
[:46] DEBUG[2840] pjsip: sip_endpoint.c Processing incoming message: Request msg BYE/cseq=2 (rdata0x7f8a6c003d78)
[:46] DEBUG[2897] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg BYE/cseq=2 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 .Received Request msg BYE/cseq=2 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …Transaction created for Request msg BYE/cseq=2 (rdata0x7f8a6c005cc8)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …Incoming Request msg BYE/cseq=2 (rdata0x7f8a6c005cc8) in state Null
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Null to Trying, event=RX_MSG
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Trying
[:46] DEBUG[2897] pjsip: endpoint …Response msg 200/BYE/cseq=2 (tdta0x7f8a94008c80) created
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Sending Response msg 200/BYE/cseq=2 (tdta0x7f8a94008c80)
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …Sending Response msg 200/BYE/cseq=2 (tdta0x7f8a94008c80) in state Trying
[:46] DEBUG[2897] pjsip: tsx0x7f8a94003 …State changed from Trying to Completed, event=TX_MSG
[:46] DEBUG[2897] pjsip: dlg0x7f8a94002 …Transaction tsx0x7f8a94003848 state changed to Completed
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f8a94003848
[:46] DEBUG[2897] res_pjsip_session.c: The current transaction state is Completed
[:46] DEBUG[2897] res_pjsip_session.c: The transaction state change event is TX_MSG
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is DISCONNCTD
[:46] DEBUG[2897] res_pjsip_session.c: Sending response
[:46] DEBUG[2897] res_pjsip_session.c: Method is BYE, Response is 200 OK
[:46] DEBUG[2897] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[:46] DEBUG[2897] res_pjsip_session.c: The state change pertains to the endpoint ‘anonymous()’
[:46] DEBUG[2897] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[:46] DEBUG[2897] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f8a94003848
[:46] DEBUG[2897] res_pjsip_session.c: The current transaction state is Completed
[:46] DEBUG[2897] res_pjsip_session.c: The transaction state change event is RX_MSG
[:46] DEBUG[2897] res_pjsip_session.c: The current inv state is DISCONNCTD
Thanks a lot for any pointers.

I believe the issue is that you are missing a sound file which is causing the channel to get hung up:

[:41] WARNING[2915][C-00000003] file.c: File yes does not exist in any format
[:41] WARNING[2915][C-00000003] file.c: Unable to open yes (format (ulaw)): No such file or directory

Thanks for quick reply. This sound file error has been there for other users connecting as well. I will investigate it.

Is [:41] DEBUG[2915][C-00000003] pbx.c: Spawn extension (conference-context,00000001,4) exited non-zero on ‘PJSIP/anonymous-00000003’ something I should worry about?? It seems that this is the moment when error occurs. As BYE is initiated. I might be wrong in this case…

I have rebuild Asterisk with the latest version and latest PJSIP. The config files were used from the sample ones and error still occurs. I will try to grab fresh logs and post it here as soon as I can.

It means that the channel was hung up and is no longer executing dialplan.

I have gotten rid of that missing sound file issue. Yet the problem still persist. I would kindly appreciate some other pointers. I will try to get some fresh logs.

As for time being I noticed that issue is happening only with certain SIP Clients. I tried enabling SIP verbose debug but somehow doesn’t see the difference in logging… Any thoughts on that?

By verbose log do you mean “pjsip set logger on”?

Spot on, I actually did “sip set debug on” now I see that it was reference to the previous version. Thanks again! I am going to review the logs and maybe I will be able to make sense of them packets.

Hi All,

i was kicked out of the conference and not sure about the reason please find the log and help

[2016-07-11 18:35:18] VERBOSE[48084][C-00001c43] file.c: – <Bridge/0x7ff3400039b8-input> Playing ‘/var/spool/asterisk/confbridge/confbridge-name-155121-1468241790.16318.slin’ (language ‘’)
[2016-07-11 18:35:19] VERBOSE[45566][C-00001c37] file.c: – <Bridge/0x7ff3400039b8-input> Playing ‘conf-hasleft.gsm’ (language ‘’)
[2016-07-11 18:35:19] VERBOSE[2830][C-00001c48] netsock2.c: == Using SIP RTP TOS bits 184
[2016-07-11 18:35:19] VERBOSE[2830][C-00001c48] netsock2.c: == Using SIP RTP CoS mark 5
[2016-07-11 18:35:21] VERBOSE[48084][C-00001c43] file.c: – <Bridge/0x7ff3400039b8-input> Playing ‘conf-hasleft.gsm’ (language ‘’)
[2016-07-11 18:35:22] VERBOSE[45566][C-00001c37] file.c: – <Bridge/0x7ff3400039b8-input> Playing ‘confbridge-leave.gsm’ (language ‘’)
[2016-07-11 18:35:23] VERBOSE[48084][C-00001c43] file.c: – <Bridge/0x7ff3400039b8-input> Playing ‘confbridge-leave.gsm’ (language ‘’)
[2016-07-11 18:35:23] VERBOSE[45566][C-00001c37] file.c: – <IAX2/5521-9687> Playing ‘conf-kicked.ulaw’ (language ‘en’)
[2016-07-11 18:35:23] VERBOSE[44918][C-00001c2e] app_mixmonitor.c: == MixMonitor close filestream (mixed)
[2016-07-11 18:35:23] VERBOSE[44918][C-00001c2e] app_mixmonitor.c: == End MixMonitor Recording ConfBridgeRecorder/conf-155121-uid-1261635393
[2016-07-11 18:35:23] VERBOSE[48084][C-00001c43] file.c: – <SIP/132-0000201e> Playing ‘conf-kicked.ulaw’ (language ‘en’)
[2016-07-11 18:35:25] VERBOSE[49109][C-00001c48] app_dial.c: – IAX2/pot-dsl-9668 stopped sounds
[2016-07-11 18:35:25] VERBOSE[49109][C-00001c48] app_dial.c: – IAX2/pot-dsl-9668 answered SIP/160-00002023

By this point in the log file, your channel has already been kicked out.

And, in fact, the log shows several channels leaving - one indicated by call ID C-00001c43 and another by C-00001c37.

A full picture of what is occurring at this point in time would probably indicate what is happening, since having channels be ejected from a ConfBridge can occur for a variety of reasons.