Logging: add user-adjustable log levels ("err", "warn", "info")

The log_printf() function now takes an enum log_level parameter,
and prints the message to the console if the supplied level is
lower than or equal than the configured kernel log level (which can
be set via the "log_level" manifest option). The default log level
is "err".
The msg_{err,warn,info} macros have been repurposed so that in
kernel code they expand to log_printf() function calls; calls to
these macros have been modified so that the format string starts
with a sensible prefix; the trailing newline is added by
log_printf(), thus it has been removed from the macro invocations.
Some rprintf() and thread_log() calls have been converted to use
the msg_{print,err,warn,info} macros.

Author: francescolavra

klib/aws.c

@@ -42,12 +42,12 @@ closure_function(5, 1, boolean, aws_metadata_in,
             heap h = bound(h);
             value_handler vh = closure(h, aws_metadata_recv, handler, &bound(done));
             if (vh == INVALID_ADDRESS) {
-                msg_err("failed to allocate value handler\n");
+                msg_err("%s: failed to allocate value handler", func_ss);
                 goto error;
             }
             bound(parser) = allocate_http_parser(h, vh);
             if (bound(parser) == INVALID_ADDRESS) {
-                msg_err("failed to allocate HTTP parser\n");
+                msg_err("%s: failed to allocate HTTP parser", func_ss);
                 deallocate_closure(vh);
                 goto error;
             }
@@ -61,7 +61,7 @@ closure_function(5, 1, boolean, aws_metadata_in,
                 return false;
             }
         } else {
-            msg_err("failed to parse HTTP response: %v\n", s);
+            msg_err("%s: failed to parse HTTP response: %v", func_ss, s);
             timm_dealloc(s);
         }
     } else {  /* connection closed */
@@ -84,19 +84,19 @@ closure_function(3, 1, input_buffer_handler, aws_metadata_ch,
     heap h = bound(h);
     buffer_handler handler = bound(handler);
     if (!out) {
-        msg_err("failed to connect to server\n");
+        msg_err("%s: failed to connect to server", func_ss);
         goto error;
     }
     tuple req = allocate_tuple();
     if (req == INVALID_ADDRESS) {
-        msg_err("failed to allocate request\n");
+        msg_err("%s: failed to allocate request", func_ss);
         goto error;
     }
     set(req, sym(url), alloca_wrap_sstring(bound(uri)));
     status s = http_request(h, out, HTTP_REQUEST_METHOD_GET, req, 0);
     deallocate_value(req);
     if (!is_ok(s)) {
-        msg_err("failed to send HTTP request: %v\n", s);
+        msg_err("%s: failed to send HTTP request: %v", func_ss, s);
         timm_dealloc(s);
         goto error;
     }
@@ -127,10 +127,10 @@ void aws_metadata_get(heap h, sstring uri, buffer_handler handler)
         status s = direct_connect(h, &md_server, 80, ch);
         if (is_ok(s))
             return;
-        msg_err("failed to connect to server: %v\n", s);
+        msg_err("%s: failed to connect to server: %v", func_ss, s);
         timm_dealloc(s);
     } else {
-        msg_err("failed to allocate closure\n");
+        msg_err("%s: failed to allocate closure", func_ss);
     }
     apply(handler, 0);
 }
@@ -157,7 +157,7 @@ static boolean aws_cred_parse_item(buffer data, sstring name, buffer value)
     data->start = 0;    /* rewind buffer start, so that it can be re-used to parse other items */
     return true;
   error:
-    msg_err("parsing of %s failed (%b)\n", name, data);
+    msg_err("%s: parsing of %s failed (%b)", func_ss, name, data);
     return false;
 }
 
@@ -190,13 +190,13 @@ closure_function(2, 1, status, aws_iam_role_get,
     aws_cred_handler handler = bound(handler);
     closure_finish();
     if (!data || (buffer_length(data) == 0)) {
-        msg_err("no IAM role associated to instance\n");
+        msg_err("%s: no role associated to instance", func_ss);
         goto error;
     }
     buffer uri = wrap_string_cstring(AWS_CRED_URI);
     push_u8(uri, '/');
     if (!push_buffer(uri, data)) {
-        msg_err("failed to build URI\n");
+        msg_err("%s: failed to build URI", func_ss);
         deallocate_buffer(uri);
         goto error;
     }
@@ -205,7 +205,7 @@ closure_function(2, 1, status, aws_iam_role_get,
         aws_metadata_get(h, buffer_to_sstring(uri), cred_parser);
         return STATUS_OK;
     } else {
-        msg_err("failed to allocate closure\n");
+        msg_err("%s: failed to allocate closure", func_ss);
         deallocate_buffer(uri);
     }
   error:
@@ -219,7 +219,7 @@ void aws_cred_get(heap h, aws_cred_handler handler)
     if (role_handler != INVALID_ADDRESS) {
         aws_metadata_get(h, ss(AWS_CRED_URI), role_handler);
     } else {
-        msg_err("failed to allocate closure\n");
+        msg_err("%s: failed to allocate closure", func_ss);
         apply(handler, 0);
     }
 }

klib/azure.c

@@ -53,7 +53,7 @@ closure_function(1, 1, void, azure_instance_md_parsed,
 closure_func_basic(parse_error, void, azure_instance_md_err,
                    string data)
 {
-    msg_err("failed to parse JSON: %b\n", data);
+    msg_err("%s: failed to parse JSON: %b", func_ss, data);
 }
 
 closure_func_basic(value_handler, void, azure_instance_md_vh,
@@ -62,7 +62,7 @@ closure_func_basic(value_handler, void, azure_instance_md_vh,
     az_instance_md_req req_data = struct_from_closure(az_instance_md_req, vh);
     deallocate_value(req_data->req);
     if (!v) {
-        msg_err("failed to retrieve instance metadata\n");
+        msg_err("%s: failed to retrieve metadata", func_ss);
         goto done;
     }
     value start_line = get(v, sym(start_line));
@@ -74,7 +74,7 @@ closure_func_basic(value_handler, void, azure_instance_md_vh,
     else
         content = 0;
     if (!content) {
-        msg_err("unexpected metadata server response %v\n", v);
+        msg_err("%s: unexpected server response %v", func_ss, v);
         goto done;
     }
     tuple md = 0;
@@ -106,12 +106,12 @@ void azure_instance_md_get(az_instance_md_handler complete)
     req_params.method = HTTP_REQUEST_METHOD_GET;
     az_instance_md_req req_data = allocate(azure.h, sizeof(*req_data));
     if (req_data == INVALID_ADDRESS) {
-        msg_err("out of memory\n");
+        msg_err("%s: out of memory", func_ss);
         goto error;
     }
     tuple req = allocate_tuple();
     if (req == INVALID_ADDRESS) {
-        msg_err("out of memory\n");
+        msg_err("%s: out of memory", func_ss);
         deallocate(azure.h, req_data, sizeof(*req_data));
         goto error;
     }

klib/azure_diagnostics.c

@@ -75,7 +75,7 @@ static boolean azure_metric_get_interval(tuple metrics, sstring name, const u64
     u64 interval;
     if (get_u64(metrics, sym_sstring(name), &interval)) {
         if (interval < min_value) {
-            rprintf("Azure diagnostics: invalid metrics %s (minimum allowed value %ld seconds)\n",
+            msg_err("Azure diagnostics: invalid metrics %s (minimum allowed value %ld seconds)",
                     name, min_value);
             return false;
         }
@@ -158,11 +158,11 @@ static void azdiag_resolve_cb(sstring name, const ip_addr_t *addr, void *cb_arg)
     if (addr) {
         azdiag_debug("connecting to server (%F)", ch);
         if (tls_connect((ip_addr_t *)addr, 443, ch) < 0) {
-            msg_err("failed to connect to server %s\n", name);
+            msg_err("%s: failed to connect to server %s", func_ss, name);
             apply(ch, 0);
         }
     } else {
-        msg_err("failed to resolve server name %s\n", name);
+        msg_err("%s: failed to resolve server name %s", func_ss, name);
         apply(ch, 0);
     }
 }
@@ -193,7 +193,7 @@ static boolean azure_metrics_table_post(az_diag diag, sstring resource, buffer c
     status s = http_request(diag->h, diag->metrics.out, HTTP_REQUEST_METHOD_POST, req, body);
     boolean success = is_ok(s);
     if (!success) {
-        msg_err("%v\n", s);
+        msg_err("%s error %v", func_ss, s);
         timm_dealloc(s);
     }
     deallocate_value(req);
@@ -253,7 +253,7 @@ closure_func_basic(status_handler, void, azdiag_setup_complete,
          * instance startup (a few seconds might elapse before the network interface acquires a DHCP
          * address). */
         if (setup->retry_backoff > seconds(2))
-            msg_err("%v\n", s);
+            msg_err("%s error %v", func_ss, s);
         else
             azdiag_debug("setup error %v, retrying", s);
 
@@ -268,7 +268,7 @@ closure_func_basic(status_handler, void, azdiag_setup_complete,
                            false, 0, setup_retry);
             return;
         } else {
-            msg_err("out of memory\n");
+            msg_err("%s: out of memory", func_ss);
         }
     }
     deallocate(h, setup, sizeof(*setup));
@@ -357,12 +357,12 @@ static boolean azure_metrics_post(az_diag diag)
 {
     timestamp ts = diag->metrics.ts;
     if ((ts >= diag->metrics.table_switch) && !azure_metrics_table_switch(diag)) {
-        msg_err("failed to create table\n");
+        msg_err("%s: failed to create table", func_ss);
         return false;
     }
     buffer b = allocate_buffer(diag->h, 1024);
     if (b == INVALID_ADDRESS) {
-        msg_err("out of memory\n");
+        msg_err("%s: out of memory", func_ss);
         return false;
     }
     u64 secs = sec_from_timestamp(ts);
@@ -419,7 +419,7 @@ closure_func_basic(input_buffer_handler, boolean, azure_metrics_in_handler,
             if (!diag->metrics.out)
                 return true;
         } else {
-            msg_err("failed to parse response: %v\n", s);
+            msg_err("%s: failed to parse response: %v", func_ss, s);
             timm_dealloc(s);
             apply(diag->metrics.out, 0);
             return true;
@@ -449,13 +449,13 @@ closure_func_basic(value_handler, void, azure_metrics_value_handler,
         }
         if (i == _countof(expected_codes)) {
             if (status_code == 403)
-                rprintf("Azure: invalid storage account SAS token\n");
+                msg_err("Azure: invalid storage account SAS token");
             else
                 status_code = 0;
         }
     }
     if (!status_code)
-        msg_err("unexpected response %v\n", v);
+        msg_err("%s: unexpected response %v", func_ss, v);
     apply(diag->metrics.out, 0);
     diag->metrics.out = 0;  /* signal to input buffer handler that connection is closed */
 }
@@ -474,8 +474,8 @@ int azure_diag_init(tuple cfg)
     tuple metrics = get_tuple(cfg, sym_this("metrics"));
     if (metrics) {
         if (!diag->storage_account || !diag->storage_account_sas) {
-            rprintf("Azure diagnostics: missing storage account or SAS token, "
-                    "required for metrics\n");
+            msg_err("Azure diagnostics: missing storage account or SAS token, "
+                    "required for metrics");
             return KLIB_INIT_FAILED;
         }
         if (!azure_metric_get_interval(metrics, ss("sample_interval"), 15, 15,
@@ -524,7 +524,7 @@ int azure_diag_init(tuple cfg)
         extension->name = ss("Microsoft.Azure.Diagnostics.LinuxDiagnostic");
         extension->version = ss("3.0.142");
         if (!azure_register_ext(extension)) {
-            rprintf("Azure diagnostics: failed to register extension\n");
+            msg_err("Azure diagnostics: failed to register extension");
             return KLIB_INIT_FAILED;
         }
         azdiag_setup_s setup = allocate(h, sizeof(*setup));

klib/cloud_azure.c

@@ -75,7 +75,7 @@ closure_func_basic(timer_handler, void, az_report_th,
     if (is_ok(s)) {
         az->goalstate_pending = true;
     } else {
-        msg_err("%v\n", s);
+        msg_err("%s error %v", func_ss, s);
         timm_dealloc(s);
     }
 }
@@ -85,7 +85,7 @@ static void az_report_status(azure az)
     heap h = az->h;
     buffer blob = allocate_buffer(h, KB);
     if (blob == INVALID_ADDRESS) {
-        msg_err("out of memory\n");
+        msg_err("%s: out of memory", func_ss);
         return;
     }
     status s;
@@ -169,7 +169,7 @@ static void az_report_status(azure az)
     s = net_http_req(req_params);
   done:
     if (!is_ok(s)) {
-        msg_err("%v\n", s);
+        msg_err("%s error %v", func_ss, s);
         timm_dealloc(s);
         deallocate_buffer(blob);
     }
@@ -184,7 +184,7 @@ closure_func_basic(value_handler, void, az_get_ext_vh,
     deallocate_value(req_data->req);
     deallocate(az->h, req_data, sizeof(*req_data));
     if (!v) {
-        msg_err("failed to get response\n");
+        msg_err("%s: failed to get response", func_ss);
         return;
     }
     buffer content = get(v, sym(content));
@@ -277,10 +277,10 @@ closure_func_basic(value_handler, void, az_get_ext_vh,
         return;
     }
   parse_error:
-    msg_err("failed to parse response\n");
+    msg_err("%s: failed to parse response", func_ss);
     return;
   alloc_error:
-    msg_err("out of memory\n");
+    msg_err("%s: out of memory", func_ss);
 }
 
 static void az_get_ext_config(azure az)
@@ -330,7 +330,7 @@ static void az_get_ext_config(azure az)
     if (req_data != INVALID_ADDRESS)
         deallocate(h, req_data, sizeof(*req_data));
     if (!is_ok(s)) {
-        msg_err("%v\n", s);
+        msg_err("%s error %v", func_ss, s);
         timm_dealloc(s);
     }
 }
@@ -340,7 +340,7 @@ closure_func_basic(value_handler, void, az_status_upload_vh,
 {
     azure az = struct_from_closure(azure, status_upload.vh);
     if (!v) {
-        msg_err("failed to get response\n");
+        msg_err("%s: failed to get response", func_ss);
         return;
     }
     value start_line = get(v, sym(start_line));
@@ -355,12 +355,12 @@ closure_func_basic(value_handler, void, az_status_upload_vh,
         if (is_ok(s)) {
             az->status_upload.last_update = kern_now(CLOCK_ID_REALTIME);
         } else {
-            msg_err("failed to upload blob page: %v\n", s);
+            msg_err("%s: failed to upload blob page: %v", func_ss, s);
             timm_dealloc(s);
             deallocate_buffer(req_params->body);
         }
     } else {
-        msg_err("unexpected response %v\n", v);
+        msg_err("%s: unexpected response %v", func_ss, v);
     }
 }
 
@@ -370,7 +370,7 @@ closure_func_basic(value_handler, void, az_goalstate_vh,
     azure az = struct_from_closure(azure, goalstate_vh);
     az->goalstate_pending = false;
     if (!v) {
-        msg_err("failed to get response\n");
+        msg_err("%s: failed to get response", func_ss);
         return;
     }
     buffer content = get(v, sym(content));
@@ -415,7 +415,7 @@ closure_func_basic(value_handler, void, az_goalstate_vh,
         return;
     }
   exit:
-    msg_err("failed to parse response %v\n", v);
+    msg_err("%s: failed to parse response %v", func_ss, v);
 }
 
 closure_func_basic(value_handler, void, az_ready_vh,