Project

General

Profile

Actions

Bug #2577

closed

Ensure meaningful default loglevels.

Added by dexter over 6 years ago. Updated almost 4 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
10/17/2017
Due date:
% Done:

100%

Spec Reference:

Description

There are some loglevels configured to LOGL_DEBUG by default in osmo-sgsn. Find meaningful defaults and also check the other products.

(We should also add a test that checks if some application registers odd log levels by default.)

Actions #1

Updated by laforge almost 5 years ago

  • Assignee set to lynxis
Actions #2

Updated by laforge about 4 years ago

  • Assignee changed from lynxis to dexter
Actions #3

Updated by dexter about 4 years ago

  • Status changed from New to In Progress
  • % Done changed from 0 to 50

To ensure proper default loglevel I think it makes sense to print a message as a reminder. Maybe later when we fixed the problem in every osmocom project, then we can migrate to an OSMO_ASSERT()

https://gerrit.osmocom.org/c/libosmocore/+/16832 logging.c: Add valuestrings for loglevels
https://gerrit.osmocom.org/c/libosmocore/+/16833 application.c: check default loglevels on startup

Actions #4

Updated by pespin about 4 years ago

I think it makes much more sense to test this as a unit test for apps where we really want to avoid DEBUG being default. I (or someone else) may be writing an app which uses DEBUG by default for whatever reason, and we must not reject that.

Actions #5

Updated by laforge about 4 years ago

I would think it's sufficient to go through all applications (it's not that many, after all) and ensure that the current code doesn't have any compiled-in default log level below NOTICE or INFO. In the future we should pay attention during code review to prevent new such bugs from being introduced. I would expect they date back to our pre-gerrit development days.

This way thre's no need for enforcement in libosmocore, which may create problems as pau indicates.

Actions #6

Updated by dexter about 4 years ago

  • % Done changed from 50 to 90

I have now checked the applications. LOGL_NOTICE seems to be the standard everywhere. I have found some odd loglevels in osmocom-bb and osmo-bsc which i have corrected. There is also some old stuff bs_11_config and openBSC which I did not touch.

Actions #7

Updated by fixeria about 4 years ago

Looking at the commits related to this ticket, I noticed that we're basically changing all logging categories to use LOGL_NOTICE. In the end I see an array of struct log_info_cat where every entry has the same line: '.loglevel = LOGL_NOTICE'. This looks odd and cumbersome, so I've got an idea.

LOGL_DEBUG has the lowest value, and it starts from 1:

/*! different log levels */
#define LOGL_DEBUG      1       /*!< debugging information */
#define LOGL_INFO       3       /*!< general information */
#define LOGL_NOTICE     5       /*!< abnormal/unexpected condition */
#define LOGL_ERROR      7       /*!< error condition, requires user action */
#define LOGL_FATAL      8       /*!< fatal, program aborted */

this means that we can omit those repeating lines, and leave it up to log_init() to initialize the default logging level:

diff --git a/src/logging.c b/src/logging.c
index 4d6224d5..60719d50 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -1056,6 +1056,8 @@ int log_init(const struct log_info *inf, void *ctx)
                for (i = 0; i < inf->num_cat; i++) {
                        memcpy((struct log_info_cat *) &osmo_log_info->cat[i],
                               &inf->cat[i], sizeof(struct log_info_cat));
+                       if (!inf->cat[i].loglevel)
+                               !inf->cat[i].loglevel = LOGL_NOTICE;
                }
        }
Actions #8

Updated by dexter about 4 years ago

I like the idea, lets integrate that.

Actions #9

Updated by dexter almost 4 years ago

I have integrated what fixeria suggested, when no loglevel is set it will automatically switch to notice.

https://gerrit.osmocom.org/c/libosmocore/+/17604

I also had a look at the default loglevels in the various osmocom projects. The following projects have loglevels other than LOGL_NOTICE set as default loglevel. Many of them are minor cases, LOGL_INFO vs. LOGL_NOTICE but in some even LOGL_DEBUG is the default, see also:

openbsc https://gerrit.osmocom.org/c/openbsc/+/17605
osmo-bts https://gerrit.osmocom.org/c/osmo-bts/+/17606
osmo-ggsn https://gerrit.osmocom.org/c/osmo-ggsn/+/17607
osmo-iuh https://gerrit.osmocom.org/c/osmo-iuh/+/17608
osmo-pcu https://gerrit.osmocom.org/c/osmo-pcu/+/17609
osmo-trx https://gerrit.osmocom.org/c/osmo-trx/+/17610

Then I inspected the default configs. It is important to notice that the default configs (at least one of them) is also used in the packages and installed as default config to /etc. I think it is important not only to have sane loglevels here but also have a "harmonic" configuration. This means that the IP-Addresses in the configs should match up. Its indeed possible to use only loopback addresses when every network component including bts+pcu runs on the same host. Here is what I think should be improved:

osmo-ggsn:
https://gerrit.osmocom.org/c/osmo-ggsn/+/17601 (Default IP)
https://gerrit.osmocom.org/c/osmo-ggsn/+/17584 (Problematic loglevels)
https://gerrit.osmocom.org/c/osmo-ggsn/+/17576 (Random IPs for DNS)

osmo-hlr:
https://gerrit.osmocom.org/c/osmo-hlr/+/17600 (Problematic loglevels)

osmo-mgw:
https://gerrit.osmocom.org/c/osmo-mgw/+/17599 (Binds to random IP)

osmo-msc:
https://gerrit.osmocom.org/c/osmo-msc/+/17598 (Random MGW IP address)

osmo-trx:
https://gerrit.osmocom.org/c/osmo-trx/+/17594 (Problematic loglevels

(The patches suggest to stick strictly to LOGL_NOTICE which might be debatable)

Actions #10

Updated by dexter almost 4 years ago

Actions #11

Updated by dexter almost 4 years ago

I have rebased and fixed the review issues for the patches that are still in review:

https://gerrit.osmocom.org/c/libosmocore/+/17604 logging: use LOGL_NOTICE when not loglevel is set
https://gerrit.osmocom.org/c/libosmo-sccp/+/17597 doc: make sure all log categories are set to level notice
https://gerrit.osmocom.org/c/osmo-ggsn/+/17607 debug: use LOGL_NOTICE instead of LOGL_DEBUG
https://gerrit.osmocom.org/c/osmo-hlr/+/17600 doc: do not use loglevel info for log category ss
https://gerrit.osmocom.org/c/osmo-pcu/+/17609 gprs_debug: Use only LOGL_NOTICE as default loglevel
https://gerrit.osmocom.org/c/osmo-trx/+/17594 doc: switch log levels to notice

Actions #12

Updated by dexter almost 4 years ago

I have gone through the patches again, fixed and rebased everything. This is what still remains:

https://gerrit.osmocom.org/c/libosmocore/+/17604 logging: use LOGL_NOTICE when not loglevel is set
https://gerrit.osmocom.org/c/osmo-hlr/+/17600 doc: do not use loglevel info for log category ss
https://gerrit.osmocom.org/c/osmo-pcu/+/17609 gprs_debug: Use only LOGL_NOTICE as default loglevel
https://gerrit.osmocom.org/c/osmo-trx/+/17594 doc: switch log levels to notice

Actions #13

Updated by laforge almost 4 years ago

  • Status changed from In Progress to Stalled
Actions #14

Updated by dexter almost 4 years ago

I have checked through the current state of the review. All changes are now merged except for one:

https://gerrit.osmocom.org/c/osmo-trx/+/17594 doc: switch log levels to notice

The problem here is that some users need to identify when the sending of clock indications begins, however this would require to set the loglevel of DTRXCLK to info, which we are trying to eleminate. I think a good compromise would be to log only once that when the sending of clock indications begins on loglevel NOTICE. Then one can easily identify that the code runs fine until the point where clock indications are sent:

https://gerrit.osmocom.org/c/osmo-trx/+/18395 Transceiver: Log when sending of CLK indications begins

However this still lacks the possibility to see when there is no CLOCK indication for an extended amount of time, this would require to implement some kind of watchdog but I think that would be overkill. If there is something to debug in that area, one should choose a lower loglevel anyway.

Actions #15

Updated by dexter almost 4 years ago

  • Status changed from Stalled to In Progress
  • % Done changed from 90 to 100

Patch 17594 got merged, this means we are now through with this ticket. The patch 18395 for osmo-trx, which I proposed as a compromise is still in review. I will keep this ticket open as a reminder until that patch is merged.

Actions #16

Updated by dexter almost 4 years ago

  • Status changed from In Progress to Resolved

18395 is now merged, so we can set this to resolved

Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)