<p>Corey Farrell has uploaded this change for <strong>review</strong>.</p><p><a href="https://gerrit.asterisk.org/10315">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;">loader: Improve error handling.<br><br>* Display list of unavailable dependencies when they cause another<br>  module to fail loading.<br>* When a module declines to load find all modules which depend on it so<br>  they can be declined and listed together.<br>* Prevent retry of declined modules during startup.<br><br>These changes are meant to reduce logger spam that were caused when a<br>module has many dependencies and declines to load.  This also fixes some<br>error paths which failed to recognize required modules.<br><br>Change-Id: I046052c71331c556c09d39f47a3b92975f3e1758<br>---<br>M main/loader.c<br>1 file changed, 133 insertions(+), 15 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;">git pull ssh://gerrit.asterisk.org:29418/asterisk refs/changes/15/10315/1</pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/main/loader.c b/main/loader.c</span><br><span>index eb345b5..b3f1671 100644</span><br><span>--- a/main/loader.c</span><br><span>+++ b/main/loader.c</span><br><span>@@ -139,6 +139,13 @@</span><br><span> </span><br><span> AST_VECTOR(module_vector, struct ast_module *);</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+/*! Used with AST_VECTOR_CALLBACK_VOID to create a</span><br><span style="color: hsl(120, 100%, 40%);">+ * comma separated list of module names for error messages. */</span><br><span style="color: hsl(120, 100%, 40%);">+#define STR_APPEND_TEXT(txt, str) \</span><br><span style="color: hsl(120, 100%, 40%);">+   ast_str_append(&str, 0, "%s%s", \</span><br><span style="color: hsl(120, 100%, 40%);">+               ast_str_strlen(str) > 0 ? ", " : "", \</span><br><span style="color: hsl(120, 100%, 40%);">+         txt)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /* Built-in module registrations need special handling at startup */</span><br><span> static unsigned int loader_ready;</span><br><span> </span><br><span>@@ -1656,22 +1663,96 @@</span><br><span>    if (lres == AST_MODULE_LOAD_SUCCESS) {</span><br><span>               (*count)++;</span><br><span>  } else if (lres == AST_MODULE_LOAD_FAILURE) {</span><br><span style="color: hsl(0, 100%, 40%);">-           ast_log(LOG_ERROR, "*** Failed to load module %s\n", mod->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+             ast_log(LOG_ERROR, "*** Failed to load %smodule %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                      mod->flags.required ? "required " : "",</span><br><span style="color: hsl(120, 100%, 40%);">+                        mod->resource);</span><br><span>   }</span><br><span> </span><br><span>        return lres;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+static int resource_list_recursive_decline(struct module_vector *resources, struct ast_module *mod,</span><br><span style="color: hsl(120, 100%, 40%);">+    struct ast_str **printmissing_ptr)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ struct module_vector missingdeps;</span><br><span style="color: hsl(120, 100%, 40%);">+     struct ast_vector_const_string localdeps;</span><br><span style="color: hsl(120, 100%, 40%);">+     struct ast_str *printmissing = *printmissing_ptr;</span><br><span style="color: hsl(120, 100%, 40%);">+     int i = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+    int res = -1;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+       mod->flags.declined = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+   if (mod->flags.required) {</span><br><span style="color: hsl(120, 100%, 40%);">+         ast_log(LOG_ERROR, "Required module %s declined to load.\n", ast_module_name(mod));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+               return -2;</span><br><span style="color: hsl(120, 100%, 40%);">+    }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   ast_log(LOG_WARNING, "%s declined to load.\n", ast_module_name(mod));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+     if (!printmissing) {</span><br><span style="color: hsl(120, 100%, 40%);">+          printmissing = ast_str_create(64);</span><br><span style="color: hsl(120, 100%, 40%);">+            if (!printmissing) {</span><br><span style="color: hsl(120, 100%, 40%);">+                  return -1;</span><br><span style="color: hsl(120, 100%, 40%);">+            }</span><br><span style="color: hsl(120, 100%, 40%);">+     } else {</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_str_reset(printmissing);</span><br><span style="color: hsl(120, 100%, 40%);">+  }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   AST_VECTOR_INIT(&missingdeps, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_INIT(&localdeps, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Decline everything that depends on 'mod' from resources so we can</span><br><span style="color: hsl(120, 100%, 40%);">+   * print a concise list. */</span><br><span style="color: hsl(120, 100%, 40%);">+   while (res != -2 && i < AST_VECTOR_SIZE(resources)) {</span><br><span style="color: hsl(120, 100%, 40%);">+              struct ast_module *dep = AST_VECTOR_GET(resources, i);</span><br><span style="color: hsl(120, 100%, 40%);">+                i++;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+                AST_VECTOR_RESET(&missingdeps, AST_VECTOR_ELEM_CLEANUP_NOOP);</span><br><span style="color: hsl(120, 100%, 40%);">+             if (dep->flags.declined || module_deps_missing_recursive(dep, &missingdeps)) {</span><br><span style="color: hsl(120, 100%, 40%);">+                 continue;</span><br><span style="color: hsl(120, 100%, 40%);">+             }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+           if (AST_VECTOR_GET_CMP(&missingdeps, mod, AST_VECTOR_ELEM_DEFAULT_CMP)) {</span><br><span style="color: hsl(120, 100%, 40%);">+                 dep->flags.declined = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+                   if (dep->flags.required) {</span><br><span style="color: hsl(120, 100%, 40%);">+                         ast_log(LOG_ERROR, "Cannot load required module %s that depends on %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                                   ast_module_name(dep), ast_module_name(mod));</span><br><span style="color: hsl(120, 100%, 40%);">+                          res = -2;</span><br><span style="color: hsl(120, 100%, 40%);">+                     } else {</span><br><span style="color: hsl(120, 100%, 40%);">+                              AST_VECTOR_APPEND(&localdeps, ast_module_name(dep));</span><br><span style="color: hsl(120, 100%, 40%);">+                      }</span><br><span style="color: hsl(120, 100%, 40%);">+             }</span><br><span style="color: hsl(120, 100%, 40%);">+     }</span><br><span style="color: hsl(120, 100%, 40%);">+     AST_VECTOR_FREE(&missingdeps);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+  if (res != -2 && AST_VECTOR_SIZE(&localdeps)) {</span><br><span style="color: hsl(120, 100%, 40%);">+           AST_VECTOR_CALLBACK_VOID(&localdeps, STR_APPEND_TEXT, printmissing);</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_log(LOG_WARNING, "Declined modules which depend on %s: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                   ast_module_name(mod), ast_str_buffer(printmissing));</span><br><span style="color: hsl(120, 100%, 40%);">+  }</span><br><span style="color: hsl(120, 100%, 40%);">+     AST_VECTOR_FREE(&localdeps);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+    *printmissing_ptr = printmissing;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+   return res;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> static int start_resource_list(struct module_vector *resources, int *mod_count)</span><br><span> {</span><br><span>     struct module_vector missingdeps;</span><br><span>    int res = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+  struct ast_str *printmissing = NULL;</span><br><span> </span><br><span>     AST_VECTOR_INIT(&missingdeps, 0);</span><br><span style="color: hsl(0, 100%, 40%);">-   while (AST_VECTOR_SIZE(resources)) {</span><br><span style="color: hsl(120, 100%, 40%);">+  while (res != -2 && AST_VECTOR_SIZE(resources)) {</span><br><span>            struct ast_module *mod = AST_VECTOR_REMOVE(resources, 0, 1);</span><br><span>                 enum ast_module_load_result lres;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+         if (mod->flags.declined) {</span><br><span style="color: hsl(120, 100%, 40%);">+                 ast_debug(1, "%s is already declined, skipping\n", ast_module_name(mod));</span><br><span style="color: hsl(120, 100%, 40%);">+                   continue;</span><br><span style="color: hsl(120, 100%, 40%);">+             }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> retry_load:</span><br><span>           lres = start_resource_attempt(mod, mod_count);</span><br><span>               if (lres == AST_MODULE_LOAD_SUCCESS) {</span><br><span>@@ -1680,21 +1761,19 @@</span><br><span>             }</span><br><span> </span><br><span>                if (lres == AST_MODULE_LOAD_FAILURE) {</span><br><span style="color: hsl(0, 100%, 40%);">-                  ast_log(LOG_ERROR, "Failed to load %s.\n", ast_module_name(mod));</span><br><span>                  res = -2;</span><br><span>                    break;</span><br><span>               }</span><br><span> </span><br><span>                if (lres == AST_MODULE_LOAD_DECLINE) {</span><br><span style="color: hsl(120, 100%, 40%);">+                        res = resource_list_recursive_decline(resources, mod, &printmissing);</span><br><span>                    continue;</span><br><span>            }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-           res = module_deps_missing_recursive(mod, &missingdeps);</span><br><span style="color: hsl(0, 100%, 40%);">-             if (res) {</span><br><span style="color: hsl(120, 100%, 40%);">+            if (module_deps_missing_recursive(mod, &missingdeps)) {</span><br><span>                  AST_VECTOR_RESET(&missingdeps, AST_VECTOR_ELEM_CLEANUP_NOOP);</span><br><span>                    ast_log(LOG_ERROR, "Failed to resolve dependencies for %s\n", ast_module_name(mod));</span><br><span style="color: hsl(0, 100%, 40%);">-                  mod->flags.declined = 1;</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span style="color: hsl(120, 100%, 40%);">+                   res = resource_list_recursive_decline(resources, mod, &printmissing);</span><br><span>                    continue;</span><br><span>            }</span><br><span> </span><br><span>@@ -1703,8 +1782,8 @@</span><br><span>                                "This is a bug in the module.\n", ast_module_name(mod));</span><br><span>                   /* Dependencies were met but the module failed to start and the result</span><br><span>                        * code was not AST_MODULE_LOAD_FAILURE or AST_MODULE_LOAD_DECLINE. */</span><br><span style="color: hsl(0, 100%, 40%);">-                  res = -1;</span><br><span style="color: hsl(0, 100%, 40%);">-                       break;</span><br><span style="color: hsl(120, 100%, 40%);">+                        res = resource_list_recursive_decline(resources, mod, &printmissing);</span><br><span style="color: hsl(120, 100%, 40%);">+                     continue;</span><br><span>            }</span><br><span> </span><br><span>                ast_debug(1, "%s has %d dependencies\n",</span><br><span>@@ -1716,8 +1795,16 @@</span><br><span>                  while (i < AST_VECTOR_SIZE(&missingdeps)) {</span><br><span>                           struct ast_module *dep = AST_VECTOR_GET(&missingdeps, i);</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+                             if (dep->flags.declined) {</span><br><span style="color: hsl(120, 100%, 40%);">+                                 ast_debug(1, "%s tried to start %s but it's already declined\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                                                ast_module_name(mod), ast_module_name(dep));</span><br><span style="color: hsl(120, 100%, 40%);">+                                  i++;</span><br><span style="color: hsl(120, 100%, 40%);">+                                  continue;</span><br><span style="color: hsl(120, 100%, 40%);">+                             }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>                          ast_debug(1, "%s trying to start %s\n", ast_module_name(mod), ast_module_name(dep));</span><br><span style="color: hsl(0, 100%, 40%);">-                          if (!start_resource_attempt(dep, mod_count)) {</span><br><span style="color: hsl(120, 100%, 40%);">+                                lres = start_resource_attempt(dep, mod_count);</span><br><span style="color: hsl(120, 100%, 40%);">+                                if (lres == AST_MODULE_LOAD_SUCCESS) {</span><br><span>                                       ast_debug(1, "%s started %s\n", ast_module_name(mod), ast_module_name(dep));</span><br><span>                                       AST_VECTOR_REMOVE(&missingdeps, i, 1);</span><br><span>                                   AST_VECTOR_REMOVE_CMP_ORDERED(resources, dep,</span><br><span>@@ -1725,6 +1812,13 @@</span><br><span>                                       didwork++;</span><br><span>                                   continue;</span><br><span>                            }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+                           if (lres == AST_MODULE_LOAD_FAILURE) {</span><br><span style="color: hsl(120, 100%, 40%);">+                                        ast_log(LOG_ERROR, "Failed to load %s.\n", ast_module_name(dep));</span><br><span style="color: hsl(120, 100%, 40%);">+                                   res = -2;</span><br><span style="color: hsl(120, 100%, 40%);">+                                     goto exitpoint;</span><br><span style="color: hsl(120, 100%, 40%);">+                               }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>                          ast_debug(1, "%s failed to start %s\n", ast_module_name(mod), ast_module_name(dep));</span><br><span>                               i++;</span><br><span>                         }</span><br><span>@@ -1735,9 +1829,26 @@</span><br><span>           }</span><br><span> </span><br><span>                if (AST_VECTOR_SIZE(&missingdeps)) {</span><br><span style="color: hsl(0, 100%, 40%);">-                        ast_log(LOG_WARNING, "Failed to load %s due to unfilled dependencies.\n",</span><br><span style="color: hsl(0, 100%, 40%);">-                             ast_module_name(mod));</span><br><span style="color: hsl(0, 100%, 40%);">-                  mod->flags.declined = 1;</span><br><span style="color: hsl(120, 100%, 40%);">+                   if (!printmissing) {</span><br><span style="color: hsl(120, 100%, 40%);">+                          printmissing = ast_str_create(64);</span><br><span style="color: hsl(120, 100%, 40%);">+                    } else {</span><br><span style="color: hsl(120, 100%, 40%);">+                              ast_str_reset(printmissing);</span><br><span style="color: hsl(120, 100%, 40%);">+                  }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+                   if (printmissing) {</span><br><span style="color: hsl(120, 100%, 40%);">+                           struct ast_vector_const_string localdeps;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+                           AST_VECTOR_INIT(&localdeps, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+                           module_deps_reference(mod, &localdeps);</span><br><span style="color: hsl(120, 100%, 40%);">+                           AST_VECTOR_CALLBACK_VOID(&localdeps, STR_APPEND_TEXT, printmissing);</span><br><span style="color: hsl(120, 100%, 40%);">+                              AST_VECTOR_FREE(&localdeps);</span><br><span style="color: hsl(120, 100%, 40%);">+                      }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+                   ast_log(LOG_WARNING, "Failed to load %s due to dependencies: %s.\n",</span><br><span style="color: hsl(120, 100%, 40%);">+                                ast_module_name(mod),</span><br><span style="color: hsl(120, 100%, 40%);">+                         printmissing ? ast_str_buffer(printmissing) : "allocation failure creating list");</span><br><span style="color: hsl(120, 100%, 40%);">+                  res = resource_list_recursive_decline(resources, mod, &printmissing);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span>                  AST_VECTOR_RESET(&missingdeps, AST_VECTOR_ELEM_CLEANUP_NOOP);</span><br><span> </span><br><span>                        continue;</span><br><span>@@ -1748,6 +1859,8 @@</span><br><span>            goto retry_load;</span><br><span>     }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+exitpoint:</span><br><span style="color: hsl(120, 100%, 40%);">+     ast_free(printmissing);</span><br><span>      AST_VECTOR_FREE(&missingdeps);</span><br><span> </span><br><span>       return res;</span><br><span>@@ -1772,7 +1885,7 @@</span><br><span>          return -1;</span><br><span>   }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   while (!res) {</span><br><span style="color: hsl(120, 100%, 40%);">+        while (res != -2) {</span><br><span>          didwork = 0;</span><br><span> </span><br><span>             AST_LIST_TRAVERSE_SAFE_BEGIN(load_order, order, entry) {</span><br><span>@@ -1789,6 +1902,7 @@</span><br><span>                              * module that is missing dependencies. */</span><br><span>                           break;</span><br><span>                       case AST_MODULE_LOAD_DECLINE:</span><br><span style="color: hsl(120, 100%, 40%);">+                         res = -1;</span><br><span>                            break;</span><br><span>                       case AST_MODULE_LOAD_FAILURE:</span><br><span>                                /* LOAD_FAILURE only happens for required modules */</span><br><span>@@ -1821,7 +1935,7 @@</span><br><span>                 attempt++;</span><br><span>   }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-   if (!res) {</span><br><span style="color: hsl(120, 100%, 40%);">+   if (res != -2) {</span><br><span>             res = start_resource_list(&module_priorities, &count);</span><br><span>       }</span><br><span> </span><br><span>@@ -2023,6 +2137,10 @@</span><br><span>               ast_log(LOG_NOTICE, "%u modules will be loaded.\n", load_count);</span><br><span> </span><br><span>       res = load_resource_list(&load_order, &modulecount);</span><br><span style="color: hsl(120, 100%, 40%);">+  if (res == -1) {</span><br><span style="color: hsl(120, 100%, 40%);">+              ast_log(LOG_WARNING, "Some non-required modules failed to load.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+                res = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+      }</span><br><span> </span><br><span> done:</span><br><span>       while ((order = AST_LIST_REMOVE_HEAD(&load_order, entry))) {</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/10315">change 10315</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/10315"/><meta itemprop="name" content="View Change"/></div></div>

<div style="display:none"> Gerrit-Project: asterisk </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-MessageType: newchange </div>
<div style="display:none"> Gerrit-Change-Id: I046052c71331c556c09d39f47a3b92975f3e1758 </div>
<div style="display:none"> Gerrit-Change-Number: 10315 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: Corey Farrell <git@cfware.com> </div>