[asterisk-bugs] [JIRA] (ASTERISK-28960) system gets into state where bridges collapse within a few seconds
Robert Sutton (JIRA)
noreply at issues.asterisk.org
Wed Jun 24 19:49:25 CDT 2020
[ https://issues.asterisk.org/jira/browse/ASTERISK-28960?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=251232#comment-251232 ]
Robert Sutton commented on ASTERISK-28960:
------------------------------------------
I have a pcap from yesterdays event.
here is data extracted from it around a single call.
The call recording from the point the bridge was initiated only contains the agent's voice
{noformat}
cat call-agent.txt
|Time | agentip |
| | | 192.168.160.59 |
|7043.977842| 100 Trying| |SIP Status 100 Trying
| |(64091) ------------------> (5060) |
|7044.164403| 180 Ringing |SIP Status 180 Ringing
| |(64091) ------------------> (5060) |
|7045.293780| 200 OK SDP (g711U te |SIP Status 200 OK
| |(64091) ------------------> (5060) |
|7045.294888| ACK | |SIP ACK From: "E CPAP DIRECT GOLD COAST RECEPTION" <sip:3333333333 at 192.168.160.59> To:<sip:112 at agentip> CSeq:25407
| |(64091) <------------------ (5060) |
|7045.294888| ACK | |SIP ACK From: "E CPAP DIRECT GOLD COAST RECEPTION" <sip:3333333333 at 192.168.160.59> To:<sip:112 at agentip> CSeq:25407
| |(64091) <------------------ (5060) |
|7056.095022| BYE | |SIP Request BYE CSeq:25408
| |(64091) ------------------> (5060) |
|7056.095022| BYE | |SIP Request BYE CSeq:25408
| |(64091) ------------------> (5060) |
|7056.095412| 200 OK | |SIP Status 200 OK
| |(64091) <------------------ (5060) |
|7056.095412| 200 OK | |SIP Status 200 OK
| |(64091) <------------------ (5060) |
cat call-caller.txt
|Time | 103.47.234.6 |
| | | 192.168.160.59 |
|6943.106587| INVITE SDP (g711A g7 |SIP INVITE From: <sip:22222222222 at providerip> To:<sip:11111111111 at externalip:5060;line=fsadhxs> Call-ID:CLA_XRQCIWh2blh6VFVeWQtQW3dcRgN2fGouAy9UBgdYA0oONRdaBGh3d2pFf09dR1kFUEV3 CSeq:21926098
| |(5060) ------------------> (5060) |
|6943.106587| INVITE SDP (g711A g7 |SIP INVITE From: <sip:22222222222 at providerip> To:<sip:11111111111 at externalip:5060;line=fsadhxs> Call-ID:CLA_XRQCIWh2blh6VFVeWQtQW3dcRgN2fGouAy9UBgdYA0oONRdaBGh3d2pFf09dR1kFUEV3 CSeq:21926098
| |(5060) ------------------> (5060) |
|6943.108645| 100 Trying| |SIP Status 100 Trying
| |(5060) <------------------ (5060) |
|6943.108645| 100 Trying| |SIP Status 100 Trying
| |(5060) <------------------ (5060) |
|6943.113836| 183 Session Progress |SIP Status 183 Session Progress
| |(5060) <------------------ (5060) |
|6943.113836| 183 Session Progress |SIP Status 183 Session Progress
| |(5060) <------------------ (5060) |
|6943.113964| 200 OK SDP (g711U g7 |SIP Status 200 OK
| |(5060) <------------------ (5060) |
|6943.113964| 200 OK SDP (g711U g7 |SIP Status 200 OK
| |(5060) <------------------ (5060) |
|6943.140271| ACK | |SIP Request INVITE ACK 200 CSeq:21926098
| |(5060) ------------------> (5060) |
|6943.140271| ACK | |SIP Request INVITE ACK 200 CSeq:21926098
| |(5060) ------------------> (5060) |
|7056.096775| BYE | |SIP Request BYE CSeq:26142
| |(5060) <------------------ (5060) |
|7056.096775| BYE | |SIP Request BYE CSeq:26142
| |(5060) <------------------ (5060) |
|7056.116854| 200 OK | |SIP Status 200 OK
| |(5060) ------------------> (5060) |
|7056.116854| 200 OK | |SIP Status 200 OK
| |(5060) ------------------> (5060) |
egrep -i '3333333333|1592959781|00000EF7|6f508be4eab4|00000f25' asterisk-logs.txt
Jun 24 10:49:41 -- AGI Script Executing Application: (mixmonitor) Options: (/var/spool/asterisk/monitor/1592959775.5179-anonymous-03//127.0.0.1:8080/rest/recordingMigration/migrate?guid=1592959781143-20668&apiKey=xxxxxxxxxxxxxxx')
Jun 24 10:49:41 -- Executing [11111111111 at routesv2-inbound:1] Set("PJSIP/trunk-00000ef7", "AGIEXITONHANGUP=yes") in new stack
Jun 24 10:49:41 -- Executing [11111111111 at routesv2-inbound:2] Set("PJSIP/trunk-00000ef7", "recovery-did=11111111111") in new stack
Jun 24 10:49:41 -- Executing [11111111111 at routesv2-inbound:3] AGI("PJSIP/trunk-00000ef7", "agi://127.0.0.1/route?targ=11111111111&ctx=
Jun 24 10:49:47 -- AGI Script Executing Application: (mixmonitor) Options: (/var/spool/asterisk/monitor/1592959781.5182-3333333333-0://127.0.0.1:8080/rest/recordingMigration/migrate?guid=1592959787095-23261&apiKey=xxxxxxxxxxxxxxx')
Jun 24 10:49:47 == Begin MixMonitor Recording PJSIP/trunk-00000ef7
Jun 24 10:49:47 -- Started music on hold, class 'queue', on channel 'PJSIP/trunk-00000ef7'
Jun 24 10:49:58 == Executing [curl 'http://127.0.0.1:8080/rest/recordingMigration/migrate?guid=1592959781143-20668&apiKey=8d26f182-978
Jun 24 10:51:22 -- PJSIP/112-00000f25 is ringing
Jun 24 10:51:22 -- PJSIP/112-00000f25 is ringing
Jun 24 10:51:23 -- PJSIP/112-00000f25 answered
Jun 24 10:51:23 -- Executing [activity-agi at noojee-activity:1] Set("PJSIP/112-00000f25", "AGIEXITONHANGUP=yes") in new stack
Jun 24 10:51:23 -- Executing [activity-agi at noojee-activity:2] AGI("PJSIP/112-00000f25", "agi://127.0.0.1/activityAgi") in new stack
Jun 24 10:51:23 == Begin MixMonitor Recording PJSIP/trunk-00000ef7
Jun 24 10:51:23 -- AGI Script Executing Application: (bridge) Options: (PJSIP/trunk-00000ef7,x)
Jun 24 10:51:23 -- Stopped music on hold on PJSIP/trunk-00000ef7
Jun 24 10:51:23 -- Channel PJSIP/trunk-00000ef7 joined 'simple_bridge' basic-bridge <a96a4bc4-e774-414a-8688-6f508be4eab4>
Jun 24 10:51:23 == Spawn extension (routesv2-inbound, 11111111111, 3) exited non-zero on 'Surrogate/PJSIP/trunk-00000ef7'
Jun 24 10:51:23 -- Channel PJSIP/112-00000f25 joined 'simple_bridge' basic-bridge <a96a4bc4-e774-414a-8688-6f508be4eab4>
Jun 24 10:51:23 == Begin MixMonitor Recording PJSIP/trunk-00000ef7
Jun 24 10:51:24 OK == End MixMonitor Recording PJSIP/trunk-00000ef7
Jun 24 10:51:24 OK == End MixMonitor Recording PJSIP/trunk-00000ef7
Jun 24 10:51:34 -- Channel PJSIP/112-00000f25 left 'simple_bridge' basic-bridge <a96a4bc4-e774-414a-8688-6f508be4eab4>
Jun 24 10:51:34 -- Channel PJSIP/trunk-00000ef7 left 'simple_bridge' basic-bridge <a96a4bc4-e774-414a-8688-6f508be4eab4>
Jun 24 10:51:34 == Spawn extension (noojee-activity, activity-agi, 2) exited non-zero on 'PJSIP/112-00000f25'
Jun 24 10:51:34 [Jun 24 10:51:34] NOTICE[418]: manager.c:4491 action_hangup: Request to hangup non-existent channel: PJSIP/112-00000F25
{noformat}
> system gets into state where bridges collapse within a few seconds
> ------------------------------------------------------------------
>
> Key: ASTERISK-28960
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-28960
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Bridges/bridge_simple
> Affects Versions: 16.10.0
> Environment: ubunut 18.04, docker asterisk 16.10
> Reporter: Robert Sutton
> Assignee: Robert Sutton
>
> system gets into state where bridges collapse within a few seconds
> calls kept flowing into the system, but bridges would collapse without error within a few seconds of starting.
> Seems to be happening about once a week.
> This particular system has only ever run 16.10
> I have a core dump from the running system and full logs including a period with debug set to 4
> below is a typical call flow while the system was in this state.
> {noformat}
> Jun 24 10:53:29 -- Executing [555555555 at routesv2-inbound:1] Set("PJSIP/trunk-00000fa4", "AGIEXITONHANGUP=yes") in new stack
> Jun 24 10:53:29 -- Executing [555555555 at routesv2-inbound:2] Set("PJSIP/trunk-00000fa4", "recovery-did=555555555") in new stack
> Jun 24 10:53:29 -- Executing [555555555 at routesv2-inbound:3] AGI("PJSIP/trunk-00000fa4", "agi://127.0.0.1/route?targ=555555555&ctx=Pre-Inbound") in new stack
> Jun 24 10:53:34 -- AGI Script Executing Application: (mixmonitor) Options: (/var/spool/asterisk/monitor/1592960009.5408-4444444444-3333333333-I-1.wav,,curl 'http://127.0.0.1:8080/rest/recordingMigration/migrate?guid=1592960014936-35584&apiKey=xxxxxxxxxxxx')
> Jun 24 10:53:34 == Begin MixMonitor Recording PJSIP/trunk-00000fa4
> Jun 24 10:53:34 -- Started music on hold, class 'queue17', on channel 'PJSIP/trunk-00000fa4'
> Jun 24 10:53:35 -- PJSIP/417-00000faa is ringing
> Jun 24 10:53:35 -- PJSIP/417-00000faa is ringing
> Jun 24 10:53:40 -- PJSIP/417-00000faa answered
> Jun 24 10:53:40 -- Executing [activity-agi at activity:1] Set("PJSIP/417-00000faa", "AGIEXITONHANGUP=yes") in new stack
> Jun 24 10:53:40 -- Executing [activity-agi at activity:2] AGI("PJSIP/417-00000faa", "agi://127.0.0.1/activityAgi") in new stack
> Jun 24 10:53:40 == Begin MixMonitor Recording PJSIP/trunk-00000fa4
> Jun 24 10:53:40 -- AGI Script Executing Application: (bridge) Options: (PJSIP/trunk-00000fa4,x)
> Jun 24 10:53:40 -- Stopped music on hold on PJSIP/trunk-00000fa4
> Jun 24 10:53:40 == Spawn extension (routesv2-inbound, 555555555, 3) exited non-zero on 'Surrogate/PJSIP/trunk-00000fa4'
> Jun 24 10:53:40 -- Channel PJSIP/trunk-00000fa4 joined 'simple_bridge' basic-bridge <67256011-e289-430d-bc1c-08b96c97811e>
> Jun 24 10:53:40 -- Channel PJSIP/417-00000faa joined 'simple_bridge' basic-bridge <67256011-e289-430d-bc1c-08b96c97811e>
> Jun 24 10:53:40 == Begin MixMonitor Recording PJSIP/trunk-00000fa4
> Jun 24 10:53:40 OK == End MixMonitor Recording PJSIP/trunk-00000fa4
> Jun 24 10:53:40 OK == End MixMonitor Recording PJSIP/trunk-00000fa4
> Jun 24 10:53:41 -- Channel PJSIP/trunk-00000fa4 left 'simple_bridge' basic-bridge <67256011-e289-430d-bc1c-08b96c97811e>
> Jun 24 10:53:41 -- Channel PJSIP/417-00000faa left 'simple_bridge' basic-bridge <67256011-e289-430d-bc1c-08b96c97811e>
> Jun 24 10:53:41 -- Manager 'njcontact' from 127.0.0.1, hanging up channel: PJSIP/417-00000faa
> Jun 24 10:53:41 == Spawn extension (activity, activity-agi, 2) exited non-zero on 'PJSIP/417-00000faa'
> Jun 24 10:53:42 OK == End MixMonitor Recording PJSIP/trunk-00000fa4
> {noformat}
> for future reference:
> {noformat}
> the issue started somewhere between 10:38 and 10:46
> debug set to level 4 at 10:56:08
> core dump triggered at 10:55:32
> system restart at 10:57:30 approx
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list