<html>
<body>
<div style="font-family: Verdana, Arial, Helvetica, Sans-Serif;">
<table bgcolor="#f9f3c9" width="100%" cellpadding="8" style="border: 1px #c9c399 solid;">
<tr>
<td>
This is an automatically generated e-mail. To reply, visit:
<a href="https://reviewboard.asterisk.org/r/4221/">https://reviewboard.asterisk.org/r/4221/</a>
</td>
</tr>
</table>
<br />
<table bgcolor="#fefadf" width="100%" cellspacing="0" cellpadding="8" style="background-image: url('https://reviewboard.asterisk.org/static/rb/images/review_request_box_top_bg.ab6f3b1072c9.png'); background-position: left top; background-repeat: repeat-x; border: 1px black solid;">
<tr>
<td>
<div>Review request for Asterisk Developers.</div>
<div>By Matt Jordan.</div>
<div style="margin-top: 1.5em;">
<b style="color: #575012; font-size: 10pt;">Repository: </b>
Asterisk
</div>
<h1 style="color: #575012; font-size: 10pt; margin-top: 1.5em;">Description </h1>
<table width="100%" bgcolor="#ffffff" cellspacing="0" cellpadding="10" style="border: 1px solid #b8b5a0">
<tr>
<td>
<pre style="margin: 0; padding: 0; white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">A rather stable test - apps/control_playback/control_reverse - had a sporadic failure on a build agent. This test uses the AppTest test object, which relies heavily on AMI events to drive an internal state machine that changes what action the test should take. During one phase of the test, the test expects the following:
* Receive a Newexten event, indicating which channel went into the 'application under test' - in this case, ControlPlayback. Remember that channel.
* Look for a TestEvent indicating a playback of tt-monkeys. When we see that, send a ControlPlayback AMI action to reverse the playback.
The error occurred here in the logs:
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Event: TestEvent'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Privilege: test,all'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Type: StateChange'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'State: PLAYBACK'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'AppFile: file.c'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'AppFunction: ast_streamfile'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'AppLine: 1108'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Message: tt-monkeys'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Channel: Local/test_remote@default-00000002;2'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: ''
[Dec 03 04:20:40] DEBUG[15942]: AMI:221 dispatchIncoming: Dispatch Incoming
[Dec 03 04:20:40] DEBUG[15942]: AMI:248 dispatchIncoming: Incoming Message: {'appfile': 'file.c', 'appline': '1108', 'appfunction': 'ast_streamfile', 'state': 'PLAYBACK', 'privilege': 'test,all', 'message': 'tt-monkeys', 'type': 'StateChange', 'event': 'TestEvent', 'channel': 'Local/test_remote@default-00000002;2'}
[Dec 03 04:20:40] DEBUG[15942]: ami:144 __event_callback: Condition Message: tt-monkeys matches Message: tt-monkeys in event
[Dec 03 04:20:40] DEBUG[15942]: ami:144 __event_callback: Condition State: PLAYBACK matches State: PLAYBACK in event
[Dec 03 04:20:40] DEBUG[15942]: ami:144 __event_callback: Condition Event: TestEvent matches Event: TestEvent in event
[Dec 03 04:20:40] DEBUG[15942]: apptest:617 execute_next_action: Executing action 0 on (Controller: ; Application )
[Dec 03 04:20:40] DEBUG[15942]: apptest:820 __call__: Sending message: {'action': 'ControlPlayback', 'control': 'Reverse', 'Channel': ''}
[Dec 03 04:20:40] DEBUG[15942]: AMI:343 sendMessage: MSG OUT: {'action': 'ControlPlayback', 'control': 'Reverse', 'actionid': 'asterisk-testsuite-32-centos.digium.internal-161149804-9', 'channel': ''}
Egads. We got the TestEvent first! Note that the 'channel' field in the AMI action sent to Asterisk is empty. No bueno.
[Dec 03 04:20:40] DEBUG[15942]: ami:136 __event_callback: Condition Control not in event, returning
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Event: Newexten'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Privilege: call,all'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Channel: Local/test_remote@default-00000002;2'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'ChannelState: 6'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'ChannelStateDesc: Up'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'CallerIDNum: <unknown>'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'CallerIDName: <unknown>'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'ConnectedLineNum: <unknown>'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'ConnectedLineName: <unknown>'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'AccountCode: '
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Context: default'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Exten: test_remote'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Priority: 3'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Uniqueid: 1417602039.26'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Extension: test_remote'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'Application: ControlPlayback'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: 'AppData: tt-monkeys'
[Dec 03 04:20:40] DEBUG[15942]: AMI:160 lineReceived: Line In: ''
Whoops. And now we get the Newexten event.
Those are out of order - and as a result, the test fails.
The reason is due to the Test Suite topic not being forwarded to the AMI topic. The code in manager, prior to this patch, had a dedicated handler for Test Suite messages that was independent of the topics forwarded to the AMI topic. Properly forwarding the Test Suite topic to the AMI topic ensures that the messages are synchronized properly.
This patch does that, and moves the message handling to the Stasis definition of the Test Suite message in test.c as well.</pre>
</td>
</tr>
</table>
<h1 style="color: #575012; font-size: 10pt; margin-top: 1.5em;">Testing </h1>
<table width="100%" bgcolor="#ffffff" cellspacing="0" cellpadding="10" style="border: 1px solid #b8b5a0">
<tr>
<td>
<pre style="margin: 0; padding: 0; white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">Re-ran the control playback reverse test locally, it passes (although it did before).
Really, this is a pretty rare failure. It may explain a few rare sporadic failures we see in 12+.</pre>
</td>
</tr>
</table>
<h1 style="color: #575012; font-size: 10pt; margin-top: 1.5em;">Diffs</b> </h1>
<ul style="margin-left: 3em; padding-left: 0;">
<li>/branches/12/main/test.c <span style="color: grey">(428862)</span></li>
<li>/branches/12/main/manager.c <span style="color: grey">(428862)</span></li>
</ul>
<p><a href="https://reviewboard.asterisk.org/r/4221/diff/" style="margin-left: 3em;">View Diff</a></p>
</td>
</tr>
</table>
</div>
</body>
</html>