<p>George Joseph <strong>submitted</strong> this change.</p><p><a href="https://gerrit.asterisk.org/c/testsuite/+/19151">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span></span><br></pre><div style="white-space:pre-wrap">Approvals:
Friendly Automation: Verified
George Joseph: Looks good to me, approved; Approved for Submit
</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">testsuite: avoid hang on waitfullybooted<br><br>change to call waitfullybooted as blocking with<br>a fixed number of tries (3). The delay is set<br>to one second per asterisk instance.<br><br>ASTERISK-30208<br><br>Change-Id: I444f714834081e73f584bd08e21b3ec4c047ae8e<br>---<br>M lib/python/asterisk/asterisk.py<br>M lib/python/asterisk/test_case.py<br>2 files changed, 77 insertions(+), 31 deletions(-)<br><br></pre>
<pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/lib/python/asterisk/asterisk.py b/lib/python/asterisk/asterisk.py</span><br><span>index 6ca964e..66c1124 100644</span><br><span>--- a/lib/python/asterisk/asterisk.py</span><br><span>+++ b/lib/python/asterisk/asterisk.py</span><br><span>@@ -10,6 +10,7 @@</span><br><span> the GNU General Public License Version 2.</span><br><span> """</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+import subprocess</span><br><span> import sys</span><br><span> import os</span><br><span> import time</span><br><span>@@ -337,7 +338,7 @@</span><br><span> default_etc_directory = "/etc/asterisk"</span><br><span> </span><br><span> def __init__(self, base=None, ast_conf_options=None, host="127.0.0.1",</span><br><span style="color: hsl(0, 100%, 40%);">- remote_config=None, test_config=None):</span><br><span style="color: hsl(120, 100%, 40%);">+ remote_config=None, test_config=None, bootdelay=1):</span><br><span> """Construct an Asterisk instance.</span><br><span> </span><br><span> Keyword Arguments:</span><br><span>@@ -368,6 +369,8 @@</span><br><span> self.remote_config = remote_config</span><br><span> self.memcheck_delay_stop = 0</span><br><span> self.instance_id = 0</span><br><span style="color: hsl(120, 100%, 40%);">+ self.wfbdelay = bootdelay</span><br><span style="color: hsl(120, 100%, 40%);">+ self.wfbfailures = 0</span><br><span> if test_config is not None and 'memcheck-delay-stop' in test_config:</span><br><span> self.memcheck_delay_stop = test_config['memcheck-delay-stop'] or 0</span><br><span> </span><br><span>@@ -464,47 +467,30 @@</span><br><span> self.process = reactor.spawnProcess(self.protocol,</span><br><span> cmd[0],</span><br><span> cmd, env=os.environ)</span><br><span style="color: hsl(0, 100%, 40%);">- # This was a one second delay, now two. This is to allow</span><br><span style="color: hsl(120, 100%, 40%);">+ # This was a one second delay, now is passed in. This is to allow</span><br><span> # asterisk sufficient time to actually start and create the ctl</span><br><span> # file. If we try to send the fully booted command before this</span><br><span> # happens we wait and try again, but this results in an unhandled</span><br><span> # error in twisted after the command succeeds.</span><br><span style="color: hsl(0, 100%, 40%);">- reactor.callLater(2, __execute_wait_fully_booted)</span><br><span style="color: hsl(120, 100%, 40%);">+ reactor.callLater(self.wfbdelay, __execute_wait_fully_booted)</span><br><span> </span><br><span> def __execute_wait_fully_booted():</span><br><span> """Send the CLI command waitfullybooted"""</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- cli_deferred = self.cli_exec("core waitfullybooted")</span><br><span style="color: hsl(0, 100%, 40%);">- cli_deferred.addCallbacks(__wait_fully_booted_callback,</span><br><span style="color: hsl(0, 100%, 40%);">- __wait_fully_booted_error)</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(0, 100%, 40%);">- def __wait_fully_booted_callback(cli_command):</span><br><span style="color: hsl(0, 100%, 40%);">- """Callback for CLI command waitfullybooted"""</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(0, 100%, 40%);">- if "Asterisk has fully booted" in cli_command.output:</span><br><span style="color: hsl(120, 100%, 40%);">+ # try to send the command three times, then assume asterisk won't start and error out</span><br><span style="color: hsl(120, 100%, 40%);">+ CLIRetVal = self.cli_exec_blocking("core waitfullybooted", "Asterisk has fully booted")</span><br><span style="color: hsl(120, 100%, 40%);">+ if CLIRetVal == 0:</span><br><span> msg = "Successfully started Asterisk %s" % self.host</span><br><span> self._start_deferred.callback(msg)</span><br><span style="color: hsl(120, 100%, 40%);">+ elif self.wfbfailures < 2:</span><br><span style="color: hsl(120, 100%, 40%);">+ self.wfbfailures +=1</span><br><span style="color: hsl(120, 100%, 40%);">+ msg = "Asterisk core waitfullybooted for %s failed, retrying" % self.host</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGGER.warning(msg)</span><br><span style="color: hsl(120, 100%, 40%);">+ reactor.callLater(self.wfbdelay, __execute_wait_fully_booted)</span><br><span> else:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGGER.debug("Asterisk core waitfullybooted failed " +</span><br><span style="color: hsl(0, 100%, 40%);">- "with output '%s', attempting again..." %</span><br><span style="color: hsl(0, 100%, 40%);">- cli_command.output)</span><br><span style="color: hsl(0, 100%, 40%);">- reactor.callLater(1, __execute_wait_fully_booted)</span><br><span style="color: hsl(0, 100%, 40%);">- return cli_command</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(0, 100%, 40%);">- def __wait_fully_booted_error(cli_command):</span><br><span style="color: hsl(0, 100%, 40%);">- """Errback for CLI command waitfullybooted"""</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(0, 100%, 40%);">- timeout = 90 if self.valgrind_enabled else 45</span><br><span style="color: hsl(0, 100%, 40%);">- if time.time() - self.__start_asterisk_time > timeout:</span><br><span style="color: hsl(0, 100%, 40%);">- msg = "Asterisk core waitfullybooted for %s failed" % self.host</span><br><span style="color: hsl(120, 100%, 40%);">+ msg = "Asterisk core waitfullybooted for %s failed too many times, exiting" % self.host</span><br><span> LOGGER.error(msg)</span><br><span> self._start_deferred.errback(Exception(msg))</span><br><span style="color: hsl(0, 100%, 40%);">- else:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGGER.debug("Asterisk core waitfullybooted failed " +</span><br><span style="color: hsl(0, 100%, 40%);">- "with output '%s', attempting again..." %</span><br><span style="color: hsl(0, 100%, 40%);">- cli_command.value.err.decode('utf-8'))</span><br><span style="color: hsl(0, 100%, 40%);">- reactor.callLater(1, __execute_wait_fully_booted)</span><br><span style="color: hsl(0, 100%, 40%);">- return cli_command</span><br><span> </span><br><span> self.install_configs(os.getcwd() + "/configs", deps)</span><br><span> self._setup_configs()</span><br><span>@@ -947,6 +933,47 @@</span><br><span> cli_protocol = AsteriskRemoteCliCommand(self.remote_config, cmd)</span><br><span> return cli_protocol.execute()</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ def cli_exec_blocking(self, cli_cmd, responsekey=""):</span><br><span style="color: hsl(120, 100%, 40%);">+ """Execute a CLI command on this instance of Asterisk.</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ Keyword Arguments:</span><br><span style="color: hsl(120, 100%, 40%);">+ cli_cmd The command to execute.</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ Returns:</span><br><span style="color: hsl(120, 100%, 40%);">+ A integer indicating success/failure, looking for the</span><br><span style="color: hsl(120, 100%, 40%);">+ response key in stdout</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ Example Usage:</span><br><span style="color: hsl(120, 100%, 40%);">+ asterisk.cli_exec_immediate("core set verbose 10")</span><br><span style="color: hsl(120, 100%, 40%);">+ """</span><br><span style="color: hsl(120, 100%, 40%);">+ CLIRetVal = 0</span><br><span style="color: hsl(120, 100%, 40%);">+ # If this is going to a remote system, make sure we enclose</span><br><span style="color: hsl(120, 100%, 40%);">+ # the command in quotes</span><br><span style="color: hsl(120, 100%, 40%);">+ if self.remote_config:</span><br><span style="color: hsl(120, 100%, 40%);">+ cli_cmd = '"{0}"'.format(cli_cmd)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ cmd = [self.ast_binary,</span><br><span style="color: hsl(120, 100%, 40%);">+ "-C", "%s" % os.path.join(self.astetcdir, "asterisk.conf"),</span><br><span style="color: hsl(120, 100%, 40%);">+ "-rx", "%s" % cli_cmd</span><br><span style="color: hsl(120, 100%, 40%);">+ ]</span><br><span style="color: hsl(120, 100%, 40%);">+ cmd = " ".join(cmd)</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGGER.debug("Executing \"%s\"", cmd)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if not self.remote_config:</span><br><span style="color: hsl(120, 100%, 40%);">+ completed = subprocess.run([self.ast_binary,</span><br><span style="color: hsl(120, 100%, 40%);">+ "-C", "%s" % os.path.join(self.astetcdir, "asterisk.conf"),</span><br><span style="color: hsl(120, 100%, 40%);">+ "-rx", "%s" % cli_cmd],</span><br><span style="color: hsl(120, 100%, 40%);">+ capture_output=True, encoding='utf-8')</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if responsekey not in completed.stdout:</span><br><span style="color: hsl(120, 100%, 40%);">+ CLIRetVal = 2</span><br><span style="color: hsl(120, 100%, 40%);">+ else:</span><br><span style="color: hsl(120, 100%, 40%);">+ CLIRetVal = completed.returncode</span><br><span style="color: hsl(120, 100%, 40%);">+ else:</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGGER.debug("remote not quite supported")</span><br><span style="color: hsl(120, 100%, 40%);">+ CLIRetVal = 1</span><br><span style="color: hsl(120, 100%, 40%);">+ return CLIRetVal</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> def _make_directory_structure(self):</span><br><span> """ Mirror system directory structure """</span><br><span> </span><br><span>diff --git a/lib/python/asterisk/test_case.py b/lib/python/asterisk/test_case.py</span><br><span>index 56bf37c..67ef93d 100644</span><br><span>--- a/lib/python/asterisk/test_case.py</span><br><span>+++ b/lib/python/asterisk/test_case.py</span><br><span>@@ -267,6 +267,8 @@</span><br><span> configuration can be overwritten by individual tests,</span><br><span> however.</span><br><span> """</span><br><span style="color: hsl(120, 100%, 40%);">+ # delay first cli call for waitfullybooted by 1 second per asterisk instance</span><br><span style="color: hsl(120, 100%, 40%);">+ wfbootdelay = count</span><br><span> for i, ast_config in enumerate(self.get_asterisk_hosts(count)):</span><br><span> local_num = ast_config.get('num')</span><br><span> host = ast_config.get('host')</span><br><span>@@ -279,12 +281,14 @@</span><br><span> LOGGER.info("Creating Asterisk instance %d" % local_num)</span><br><span> ast_instance = Asterisk(base=self.testlogdir, host=host,</span><br><span> ast_conf_options=self.ast_conf_options,</span><br><span style="color: hsl(0, 100%, 40%);">- test_config=test_config)</span><br><span style="color: hsl(120, 100%, 40%);">+ test_config=test_config,</span><br><span style="color: hsl(120, 100%, 40%);">+ bootdelay=wfbootdelay)</span><br><span> else:</span><br><span> LOGGER.info("Managing Asterisk instance at %s" % host)</span><br><span> ast_instance = Asterisk(base=self.testlogdir, host=host,</span><br><span> remote_config=ast_config,</span><br><span style="color: hsl(0, 100%, 40%);">- test_config=test_config)</span><br><span style="color: hsl(120, 100%, 40%);">+ test_config=test_config,</span><br><span style="color: hsl(120, 100%, 40%);">+ bootdelay=wfbootdelay)</span><br><span> self.ast.append(ast_instance)</span><br><span> self.condition_controller.register_asterisk_instance(self.ast[i])</span><br><span> </span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/c/testsuite/+/19151">change 19151</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.asterisk.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.asterisk.org/c/testsuite/+/19151"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: testsuite </div>
<div style="display:none"> Gerrit-Branch: 16 </div>
<div style="display:none"> Gerrit-Change-Id: I444f714834081e73f584bd08e21b3ec4c047ae8e </div>
<div style="display:none"> Gerrit-Change-Number: 19151 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: Michael Bradeen <mbradeen@sangoma.com> </div>
<div style="display:none"> Gerrit-Reviewer: Friendly Automation </div>
<div style="display:none"> Gerrit-Reviewer: George Joseph <gjoseph@digium.com> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>