3CX conferencing module dropping calls after 15 minutes

Discussion in '3CX Phone System - General' started by ArmgaSys, Jan 17, 2012.

Thread Status:
Not open for further replies.
  1. ArmgaSys

    Joined:
    Jan 17, 2012
    Messages:
    1
    Likes Received:
    0
    We are seeing odd behavior with the conferencing module. Based on our testing, this behavior is only occurring within the conferencing module. Any suggestions are greatly appreciated!

    Issue Overview
    3CX conferencing module consistently drops external VOIP calls after 15 minutes.
    Using the same VOIP line routed directly to phones works with no issues. This issue seems to be centered around the conference module itself.

    Setup and Configuration
    - SonicWall NSA 2400 Firewall. SIP and RTP ports are forwarded and functional
    - Version V10.0.22686.2297 SP.5
    - SIP Provider Configuration
    - Support Re-invite = False
    - Supports Replace = False
    - PBX Delivers Audio = True

    Testing Completed
    Test#1
    VOIP Line routed to active conference bridge with one internal VOIP phone active (Polycom)
    Status: External call routed to conference bridge dropped after just over 15 minutes with “ACK is not received”
    Test#2
    VOIP Line routed to active conference bridge with one internal VOIP phone active (Cisco)
    Status: External call routed to conference bridge dropped after just over 15 minutes with “ACK is not received”
    Test#3
    VOIP Line routed directly to internal Cisco phone (no conference module)
    Status: Call succeeded to over 20 minutes before test considered a pass

    Logging from Test #2 (FAIL CONDITION)
    12:24:33.702 [CM503008]: Call(1): Call is terminated
    12:24:23.472 [CM503008]: Call(2): Call is terminated
    12:24:23.466 [CM503021]: Call(2): ACK is not received
    12:24:21.698 Currently active calls - 2: [1,2]
    12:23:51.388 [MS210003] C:2.1:Answer provided. Connection(transcoding mode[unsecure]):71.39.116.253:9000(9001)
    12:23:51.386 [MS210001] C:2.3:Answer received. RTP connection[unsecure]: 127.0.0.1:40316(40317)
    12:23:51.384 Remote SDP is set for legC:2.3
    12:23:51.178 [MS210002] C:2.3:Offer provided. Connection(transcoding mode): 127.0.0.1:7008(7009)
    12:23:51.177 [MS210000] C:2.1:Offer received. RTP connection: 66.62.60.229:21736(21737)
    12:23:51.176 Remote SDP is set for legC:2.1
    12:23:49.582 Currently active calls - 2: [1,2]
    12:23:19.426 Currently active calls - 2: [1,2]
    12:22:47.245 Currently active calls - 2: [1,2]
    12:22:15.062 Currently active calls - 2: [1,2]
    12:21:44.868 Currently active calls - 2: [1,2]
    12:21:12.685 Currently active calls - 2: [1,2]
    12:20:42.491 Currently active calls - 2: [1,2]
    12:20:10.308 Currently active calls - 2: [1,2]
    12:19:38.121 Currently active calls - 2: [1,2]
    12:19:05.938 Currently active calls - 2: [1,2]
    12:18:33.722 Currently active calls - 2: [1,2]
    12:18:01.361 Currently active calls - 2: [1,2]
    12:17:39.273 [CM504001]: Ext.130: new contact is registered. Contact(s): [sip:130@172.16.32.26:5060/130]
    12:17:38.589 [CM504001]: Ext.100: new contact is registered. Contact(s): [sip:100@172.16.32.23:5060/100]
    12:17:37.843 [CM504001]: Ext.120: new contact is registered. Contact(s): [sip:120@172.16.32.25:5060/120]
    12:17:28.997 Currently active calls - 2: [1,2]
    12:16:56.634 Currently active calls - 2: [1,2]
    12:16:24.273 Currently active calls - 2: [1,2]
    12:15:51.911 Currently active calls - 2: [1,2]
    12:15:19.549 Currently active calls - 2: [1,2]
    12:14:47.188 Currently active calls - 2: [1,2]
    12:14:14.826 Currently active calls - 2: [1,2]
    12:13:42.464 Currently active calls - 2: [1,2]
    12:13:10.316 Currently active calls - 2: [1,2]
    12:12:38.220 Currently active calls - 2: [1,2]
    12:12:06.123 Currently active calls - 2: [1,2]
    12:11:34.019 Currently active calls - 2: [1,2]
    12:11:01.897 Currently active calls - 2: [1,2]
    12:10:29.774 Currently active calls - 2: [1,2]
    12:09:57.651 Currently active calls - 2: [1,2]
    12:09:25.527 Currently active calls - 2: [1,2]
    12:08:59.578 [CM503007]: Call(2): Device joined: sip:701@127.0.0.1:40300;rinstance=a52782f1946d36f6
    12:08:59.574 [MS210003] C:2.3:Answer provided. Connection(transcoding mode[unsecure]):127.0.0.1:7008(7009)
    12:08:59.573 [MS210002] C:2.1:Offer provided. Connection(transcoding mode): 71.39.116.253:9000(9001)
    12:08:59.571 [MS210000] C:2.3:Offer received. RTP connection: 127.0.0.1:40316(40317)
    12:08:59.570 Remote SDP is set for legC:2.3
    12:08:59.569 [CM505001]: Ext.701: Device info: Device Identified: [Man: 3CX Ltd.;Mod: Conference place;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Conference Place] PBX contact: [sip:701@127.0.0.1:5060]
    12:08:59.569 [CM503002]: Call(2): Alerting sip:701@127.0.0.1:40300;rinstance=a52782f1946d36f6
    12:08:59.410 [CM503025]: Call(2): Calling Ext:Ext.701@[Dev:sip:701@127.0.0.1:40300;rinstance=a52782f1946d36f6]
    12:08:59.353 [CM503004]: Call(2): Route 1: Ext:Ext.701@[Dev:sip:701@127.0.0.1:40300;rinstance=a52782f1946d36f6]
    12:08:59.352 [CM503010]: Making route(s) to <sip:701@127.0.0.1:5060>
    12:08:59.351 [CM505003]: Provider:[DID For Sale] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [] PBX contact: [sip:xxx.xxx%40armgasys.com@71.39.116.253:5060]
    12:08:59.351 Refer: from=<sip:700@127.0.0.1:5060>;tag=d6182348; to="12082729833:"<sip:+12082509594@127.0.0.1:5060;nf=e>;tag=53747276; RefTo=<sip:701@127.0.0.1:5060>
    12:08:57.227 [MS211000] C:2.1: 66.62.60.229:21736 is delivering DTMF using RTP payload (RFC2833). In-Band DTMF tone detection is disabled for this call segment.
    12:08:53.405 Currently active calls - 2: [1,2]
    12:08:53.154 Session 151 of leg C:2.1 is confirmed
    12:08:52.894 [CM503007]: Call(2): Device joined: sip:700@127.0.0.1:40300;rinstance=b5858397a8b72940
    12:08:52.892 [CM503007]: Call(2): Device joined: sip:xxxxx%40armgasys.com@209.216.2.211:5060
    12:08:52.890 [MS210003] C:2.1:Answer provided. Connection(transcoding mode[unsecure]):71.39.116.253:9000(9001)
    12:08:52.888 [MS210001] C:2.2:Answer received. RTP connection[unsecure]: 127.0.0.1:40314(40315)
    12:08:52.887 Remote SDP is set for legC:2.2
    12:08:52.884 [CM505001]: Ext.700: Device info: Device Identified: [Man: 3CX Ltd.;Mod: Conference gateway;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Conference Room] PBX contact: [sip:700@127.0.0.1:5060]
    12:08:52.884 [CM503002]: Call(2): Alerting sip:700@127.0.0.1:40300;rinstance=b5858397a8b72940
    12:08:52.725 [CM503025]: Call(2): Calling Ext:Ext.700@[Dev:sip:700@127.0.0.1:40300;rinstance=b5858397a8b72940]
    12:08:52.723 [MS210002] C:2.2:Offer provided. Connection(transcoding mode): 127.0.0.1:7006(7007)
    12:08:52.694 [CM503004]: Call(2): Route 1: Ext:Ext.700@[Dev:sip:700@127.0.0.1:40300;rinstance=b5858397a8b72940]
    12:08:52.694 [CM503010]: Making route(s) to <sip:700@172.16.32.13:5060>
    12:08:52.694 [MS210000] C:2.1:Offer received. RTP connection: 66.62.60.229:21736(21737)

    Logging from test #3 (SUCCESS CONDITION)
    12:45:12.980 Currently active calls - 1: [3]
    12:44:40.861 Currently active calls - 1: [3]
    12:44:08.744 Currently active calls - 1: [3]
    12:43:58.194 [MS210003] C:3.1:Answer provided. Connection(transcoding mode[unsecure]):71.39.116.253:9002(9003)
    12:43:58.193 [MS210001] C:3.2:Answer received. RTP connection[unsecure]: 172.16.32.28:16464(16465)
    12:43:58.192 Remote SDP is set for legC:3.2
    12:43:58.145 [MS210002] C:3.2:Offer provided. Connection(transcoding mode): 172.16.32.13:7010(7011)
    12:43:58.144 [MS210000] C:3.1:Offer received. RTP connection: 66.62.60.229:17226(17227)
    12:43:58.142 Remote SDP is set for legC:3.1
    12:43:36.627 Currently active calls - 1: [3]
    12:43:04.511 Currently active calls - 1: [3]
    12:42:32.395 Currently active calls - 1: [3]
    12:42:00.278 Currently active calls - 1: [3]
    12:41:28.161 Currently active calls - 1: [3]
    12:40:58.050 Currently active calls - 1: [3]
    12:40:25.884 Currently active calls - 1: [3]
    12:39:53.706 Currently active calls - 1: [3]
    12:39:21.527 Currently active calls - 1: [3]
    12:38:49.349 Currently active calls - 1: [3]
    12:38:17.169 Currently active calls - 1: [3]
    12:37:44.989 Currently active calls - 1: [3]
    12:37:12.811 Currently active calls - 1: [3]
    12:36:40.633 Currently active calls - 1: [3]
    12:36:08.451 Currently active calls - 1: [3]
    12:35:36.196 Currently active calls - 1: [3]
    12:35:03.840 Currently active calls - 1: [3]
    12:34:31.483 Currently active calls - 1: [3]
    12:33:59.128 Currently active calls - 1: [3]
    12:33:26.773 Currently active calls - 1: [3]
    12:32:54.418 Currently active calls - 1: [3]
    12:32:22.062 Currently active calls - 1: [3]
    12:32:14.478 [CM504001]: Ext.300: new contact is registered. Contact(s): [sip:300@172.16.32.41:5060/300]
    12:31:49.706 Currently active calls - 1: [3]
    12:31:17.351 Currently active calls - 1: [3]
    12:30:45.011 Currently active calls - 1: [3]
    12:30:12.917 Currently active calls - 1: [3]
    12:29:42.824 Currently active calls - 1: [3]
    12:29:10.730 Currently active calls - 1: [3]
    12:28:59.585 Session 489 of leg C:3.1 is confirmed
    12:28:59.329 [CM503007]: Call(3): Device joined: sip:110@172.16.32.28:5060
    12:28:59.324 [CM503007]: Call(3): Device joined: sip:xxx.xxx%40armgasys.com@209.216.2.211:5060
    12:28:59.322 [MS210003] C:3.1:Answer provided. Connection(transcoding mode[unsecure]):71.39.116.253:9002(9003)
    12:28:59.320 [MS210001] C:3.2:Answer received. RTP connection[unsecure]: 172.16.32.28:16464(16465)
    12:28:59.319 Remote SDP is set for legC:3.2
    12:28:57.481 [CM505001]: Ext.110: Device info: Device Identified: [Man: Cisco;Mod: SPA Series;Rev: General] Capabilities:[reinvite, replaces, unable-no-sdp, no-recvonly] UserAgent: [Cisco/SPA525G2-7.4.9a] PBX contact: [sip:110@172.16.32.13:5060]
    12:28:57.480 [CM503002]: Call(3): Alerting sip:110@172.16.32.28:5060
    12:28:57.388 [CM503025]: Call(3): Calling Ext:Ext.110@[Dev:sip:110@172.16.32.28:5060]
    12:28:57.388 [MS210002] C:3.2:Offer provided. Connection(transcoding mode): 172.16.32.13:7010(7011)
    12:28:57.358 [CM503004]: Call(3): Route 1: Ext:Ext.110@[Dev:sip:110@172.16.32.28:5060]
    12:28:57.354 [CM503010]: Making route(s) to <sip:110@172.16.32.13:5060>
    12:28:57.354 [MS210000] C:3.1:Offer received. RTP connection: 66.62.60.229:17226(17227)
    12:28:57.353 Remote SDP is set for legC:3.1
     
Thread Status:
Not open for further replies.