<p>George Joseph <strong>merged</strong> this change.</p><p><a href="https://gerrit.asterisk.org/10329">View Change</a></p><div style="white-space:pre-wrap">Approvals:
Richard Mudgett: Looks good to me, but someone else must approve
George Joseph: Looks good to me, approved; Approved for Submit
</div><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>* When a module fails to dlopen try loading it with RTLD_LAZY so we can<br> attempt to display the list of missing dependencies.<br><br>These changes are meant to reduce logger spam that is 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>Module load/start errors are delayed until the end of loader startup.<br><br>Change-Id: I046052c71331c556c09d39f47a3b92975f3e1758<br>---<br>M include/asterisk/logger.h<br>M main/loader.c<br>M main/logger.c<br>3 files changed, 258 insertions(+), 32 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/include/asterisk/logger.h b/include/asterisk/logger.h</span><br><span>index 56dd859..1d0c6bd 100644</span><br><span>--- a/include/asterisk/logger.h</span><br><span>+++ b/include/asterisk/logger.h</span><br><span>@@ -69,6 +69,9 @@</span><br><span> void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...)</span><br><span> __attribute__((format(printf, 5, 6)));</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+void ast_log_ap(int level, const char *file, int line, const char *function, const char *fmt, va_list ap)</span><br><span style="color: hsl(120, 100%, 40%);">+ __attribute__((format(printf, 5, 0)));</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /*!</span><br><span> * \brief Used for sending a log message with protection against recursion.</span><br><span> *</span><br><span>diff --git a/main/loader.c b/main/loader.c</span><br><span>index eb345b5..ff97c95 100644</span><br><span>--- a/main/loader.c</span><br><span>+++ b/main/loader.c</span><br><span>@@ -139,9 +139,39 @@</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 style="color: hsl(120, 100%, 40%);">+/*! String container for deferring output of startup errors. */</span><br><span style="color: hsl(120, 100%, 40%);">+static struct ast_vector_string startup_errors;</span><br><span style="color: hsl(120, 100%, 40%);">+static struct ast_str *startup_error_builder;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+static __attribute__((format(printf, 1, 2))) void module_load_error(const char *fmt, ...)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ char *copy = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+ va_list ap;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ va_start(ap, fmt);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (startup_error_builder) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_str_set_va(&startup_error_builder, 0, fmt, ap);</span><br><span style="color: hsl(120, 100%, 40%);">+ copy = ast_strdup(ast_str_buffer(startup_error_builder));</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!copy || AST_VECTOR_APPEND(&startup_errors, copy)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "%s", ast_str_buffer(startup_error_builder));</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(copy);</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_log_ap(LOG_ERROR, fmt, ap);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+ va_end(ap);</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /*!</span><br><span> * \brief Internal flag to indicate all modules have been initially loaded.</span><br><span> */</span><br><span>@@ -873,6 +903,22 @@</span><br><span> #endif</span><br><span> }</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+static int load_dlopen_missing(struct ast_str **list, struct ast_vector_string *deps)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ int i;</span><br><span style="color: hsl(120, 100%, 40%);">+ int c = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ for (i = 0; i < AST_VECTOR_SIZE(deps); i++) {</span><br><span style="color: hsl(120, 100%, 40%);">+ const char *dep = AST_VECTOR_GET(deps, i);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (!find_resource(dep, 0)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ STR_APPEND_TEXT(dep, list);</span><br><span style="color: hsl(120, 100%, 40%);">+ c++;</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%);">+ return c;</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> /*!</span><br><span> * \internal</span><br><span> * \brief Attempt to dlopen a module.</span><br><span>@@ -904,13 +950,60 @@</span><br><span> resource_being_loaded = mod;</span><br><span> mod->lib = dlopen(filename, flags);</span><br><span> if (resource_being_loaded) {</span><br><span style="color: hsl(120, 100%, 40%);">+ struct ast_str *list;</span><br><span style="color: hsl(120, 100%, 40%);">+ int c = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ const char *dlerror_msg = ast_strdupa(dlerror());</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> resource_being_loaded = NULL;</span><br><span> if (mod->lib) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_ERROR, "Module '%s' did not register itself during load\n", resource_in);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' did not register itself during load\n", resource_in);</span><br><span> logged_dlclose(resource_in, mod->lib);</span><br><span style="color: hsl(0, 100%, 40%);">- } else if (!suppress_logging) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Error loading module '%s': %s\n", resource_in, dlerror());</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ goto error_return;</span><br><span> }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if (suppress_logging) {</span><br><span style="color: hsl(120, 100%, 40%);">+ goto error_return;</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%);">+ resource_being_loaded = mod;</span><br><span style="color: hsl(120, 100%, 40%);">+ mod->lib = dlopen(filename, RTLD_LAZY | RTLD_LOCAL);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (resource_being_loaded) {</span><br><span style="color: hsl(120, 100%, 40%);">+ resource_being_loaded = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Error loading module '%s': %s\n", resource_in, dlerror_msg);</span><br><span style="color: hsl(120, 100%, 40%);">+ logged_dlclose(resource_in, mod->lib);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ goto error_return;</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%);">+ list = ast_str_create(64);</span><br><span style="color: hsl(120, 100%, 40%);">+ if (list) {</span><br><span style="color: hsl(120, 100%, 40%);">+ if (module_post_register(mod)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ goto loaded_error;</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%);">+ c = load_dlopen_missing(&list, &mod->requires);</span><br><span style="color: hsl(120, 100%, 40%);">+ c += load_dlopen_missing(&list, &mod->enhances);</span><br><span style="color: hsl(120, 100%, 40%);">+#ifndef OPTIONAL_API</span><br><span style="color: hsl(120, 100%, 40%);">+ c += load_dlopen_missing(&list, &mod->optional_modules);</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</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 (list && ast_str_strlen(list)) {</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Error loading module '%s', missing %s: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ resource_in, c == 1 ? "dependency" : "dependencies", ast_str_buffer(list));</span><br><span style="color: hsl(120, 100%, 40%);">+ } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Error loading module '%s': %s\n", resource_in, dlerror_msg);</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%);">+loaded_error:</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(list);</span><br><span style="color: hsl(120, 100%, 40%);">+ unload_dynamic_module(mod);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ return NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+error_return:</span><br><span> ast_free(mod);</span><br><span> </span><br><span> return NULL;</span><br><span>@@ -1416,24 +1509,24 @@</span><br><span> static unsigned int inspect_module(const struct ast_module *mod)</span><br><span> {</span><br><span> if (!mod->info->description) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Module '%s' does not provide a description.\n", mod->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' does not provide a description.\n", mod->resource);</span><br><span> return 1;</span><br><span> }</span><br><span> </span><br><span> if (!mod->info->key) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Module '%s' does not provide a license key.\n", mod->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' does not provide a license key.\n", mod->resource);</span><br><span> return 1;</span><br><span> }</span><br><span> </span><br><span> if (verify_key((unsigned char *) mod->info->key)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Module '%s' did not provide a valid license key.\n", mod->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' did not provide a valid license key.\n", mod->resource);</span><br><span> return 1;</span><br><span> }</span><br><span> </span><br><span> if (!ast_strlen_zero(mod->info->buildopt_sum) &&</span><br><span> strcmp(buildopt_sum, mod->info->buildopt_sum)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Module '%s' was not compiled with the same compile-time options as this version of Asterisk.\n", mod->resource);</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Module '%s' will not be initialized as it may cause instability.\n", mod->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' was not compiled with the same compile-time options as this version of Asterisk.\n", mod->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' will not be initialized as it may cause instability.\n", mod->resource);</span><br><span> return 1;</span><br><span> }</span><br><span> </span><br><span>@@ -1459,10 +1552,10 @@</span><br><span> </span><br><span> AST_VECTOR_INIT(&missing, 0);</span><br><span> if (module_deps_missing_recursive(mod, &missing)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_ERROR, "%s has one or more unknown dependencies.\n", mod->info->name);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("%s has one or more unknown dependencies.\n", mod->info->name);</span><br><span> }</span><br><span> for (i = 0; i < AST_VECTOR_SIZE(&missing); i++) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_ERROR, "%s loaded before dependency %s!\n", mod->info->name,</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("%s loaded before dependency %s!\n", mod->info->name,</span><br><span> AST_VECTOR_GET(&missing, i)->info->name);</span><br><span> }</span><br><span> AST_VECTOR_FREE(&missing);</span><br><span>@@ -1568,7 +1661,7 @@</span><br><span> return res;</span><br><span> </span><br><span> prestart_error:</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "Module '%s' could not be loaded.\n", resource_name);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("Module '%s' could not be loaded.\n", resource_name);</span><br><span> unload_dynamic_module(mod);</span><br><span> res = required ? AST_MODULE_LOAD_FAILURE : AST_MODULE_LOAD_DECLINE;</span><br><span> if (ast_fully_booted && !ast_shutdown_final()) {</span><br><span>@@ -1656,22 +1749,93 @@</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%);">+ module_load_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)</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%);">+ 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%);">+ module_load_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%);">+ module_load_error("%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%);">+ module_load_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%);">+ module_load_error("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%);">+ 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,31 +1844,29 @@</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 style="color: hsl(0, 100%, 40%);">- 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%);">+ module_load_error("Failed to resolve dependencies for %s\n", ast_module_name(mod));</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> if (!AST_VECTOR_SIZE(&missingdeps)) {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_WARNING, "%s load function returned an invalid result. "</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("%s load function returned an invalid result. "</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 +1878,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 +1895,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%);">+ module_load_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 +1912,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%);">+ module_load_error("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 +1942,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 +1968,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,12 +1985,13 @@</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> if (lasttry) {</span><br><span> /* This run is just to print errors. */</span><br><span style="color: hsl(0, 100%, 40%);">- ast_log(LOG_ERROR, "*** Failed to load module %s - Required\n", order->resource);</span><br><span style="color: hsl(120, 100%, 40%);">+ module_load_error("*** Failed to load module %s - Required\n", order->resource);</span><br><span> fprintf(stderr, "*** Failed to load module %s - Required\n", order->resource);</span><br><span> res = -2;</span><br><span> }</span><br><span>@@ -1821,7 +2018,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>@@ -1999,12 +2196,16 @@</span><br><span> struct load_order load_order;</span><br><span> int res = 0;</span><br><span> int modulecount = 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ int i;</span><br><span> </span><br><span> ast_verb(1, "Asterisk Dynamic Loader Starting:\n");</span><br><span> </span><br><span> AST_LIST_HEAD_INIT_NOLOCK(&load_order);</span><br><span> AST_DLLIST_LOCK(&module_list);</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_INIT(&startup_errors, 0);</span><br><span style="color: hsl(120, 100%, 40%);">+ startup_error_builder = ast_str_create(64);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> res = loader_builtin_init(&load_order);</span><br><span> if (res) {</span><br><span> goto done;</span><br><span>@@ -2023,6 +2224,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>@@ -2031,6 +2236,18 @@</span><br><span> }</span><br><span> </span><br><span> AST_DLLIST_UNLOCK(&module_list);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ for (i = 0; i < AST_VECTOR_SIZE(&startup_errors); i++) {</span><br><span style="color: hsl(120, 100%, 40%);">+ char *str = AST_VECTOR_GET(&startup_errors, i);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log(LOG_ERROR, "%s", str);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(str);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+ AST_VECTOR_FREE(&startup_errors);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_free(startup_error_builder);</span><br><span style="color: hsl(120, 100%, 40%);">+ startup_error_builder = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> return res;</span><br><span> }</span><br><span> </span><br><span>diff --git a/main/logger.c b/main/logger.c</span><br><span>index 8b4f678..57e5857 100644</span><br><span>--- a/main/logger.c</span><br><span>+++ b/main/logger.c</span><br><span>@@ -2004,18 +2004,24 @@</span><br><span> </span><br><span> void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...)</span><br><span> {</span><br><span style="color: hsl(0, 100%, 40%);">- ast_callid callid;</span><br><span> va_list ap;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ va_start(ap, fmt);</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_log_ap(level, file, line, function, fmt, ap);</span><br><span style="color: hsl(120, 100%, 40%);">+ va_end(ap);</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%);">+void ast_log_ap(int level, const char *file, int line, const char *function, const char *fmt, va_list ap)</span><br><span style="color: hsl(120, 100%, 40%);">+{</span><br><span style="color: hsl(120, 100%, 40%);">+ ast_callid callid;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> callid = ast_read_threadstorage_callid();</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- va_start(ap, fmt);</span><br><span> if (level == __LOG_VERBOSE) {</span><br><span> __ast_verbose_ap(file, line, function, 0, callid, fmt, ap);</span><br><span> } else {</span><br><span> ast_log_full(level, -1, file, line, function, callid, fmt, ap);</span><br><span> }</span><br><span style="color: hsl(0, 100%, 40%);">- va_end(ap);</span><br><span> }</span><br><span> </span><br><span> void ast_log_safe(int level, const char *file, int line, const char *function, const char *fmt, ...)</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/10329">change 10329</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/10329"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: asterisk </div>
<div style="display:none"> Gerrit-Branch: 16.0 </div>
<div style="display:none"> Gerrit-MessageType: merged </div>
<div style="display:none"> Gerrit-Change-Id: I046052c71331c556c09d39f47a3b92975f3e1758 </div>
<div style="display:none"> Gerrit-Change-Number: 10329 </div>
<div style="display:none"> Gerrit-PatchSet: 6 </div>
<div style="display:none"> Gerrit-Owner: Corey Farrell <git@cfware.com> </div>
<div style="display:none"> Gerrit-Reviewer: George Joseph <gjoseph@digium.com> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins2 (1000185) </div>
<div style="display:none"> Gerrit-Reviewer: Richard Mudgett <rmudgett@digium.com> </div>