Commit Graph

26 Commits

Author SHA1 Message Date
Neels Hofmeyr f2644aee55 logging.h: define ansi color constants
It's hard to figure out what color logging categories have with those ANSI
color code strings. Instead, define these OSMO_LOGCOLOR_* constants.

Naming: commonly, the logging.h header has the "LOG" prefix in the name, but it
seems saner to include the OSMO_ prefix: it seems too likely that some
libosmocore user somewhere already has defined "LOGCOLOR_RED" somewhere.

Change-Id: I03b6b1f73ae7ee61d37ff921e071a3d0881d3e9a
2019-11-23 07:58:47 +00:00
Pau Espin d12f698dbb logging: Introduce mutex API to manage log_target in multi-thread envs
log_enable_multithread() enables use of locks inside the
implementation. Lock use is disabled by default, this way only
multi-thread processes need to enable it and suffer related
complexity/performance penalties.

Locks are required around osmo_log_target_list and items inside it,
since targets can be used, modified and deleted by different threads
concurrently (for instance, user writing "logging disable" in VTY while
another thread is willing to write into that target).

Multithread apps and libraries aiming at being used in multithread apps
should update their code to use the locks introduced here when
containing code iterating over osmo_log_target_list explictly or
implicitly by obtaining a log_target (eg. osmo_log_vty2tgt()).

Related: OS#4088
Change-Id: Id7711893b34263baacac6caf4d489467053131bb
2019-10-09 14:19:52 +02:00
Neels Hofmeyr d0b3b9edac add vty logp command to echo on all log targets
When reading SUT logs resulting from TTCN3 runs, it can be hard to figure out
which log section corresponds to which test code. Add a 'logp' command on VIEW
and ENABLE nodes that simply echos an arbitrary message on log output, useful
to set markers / explanations from the TTCN3 code, which then appear in all log
outputs and can make it trivial to figure out which log section is interesting.

	logging_vty_test# logp lglobal notice This is the log message
	DLGLOBAL NOTICE This is the log message

From TTCN3, could be used like this, e.g. in BSC_Tests.ttcn:

	private function f_logp(charstring log_msg) runs on MSC_ConnHdlr
	{
		// log on TTCN3 log output
	        log(log_msg);
		// log in stderr log
	        f_vty_transceive(BSCVTY, "logp lglobal notice " & log_msg);
	}

	...

	f_logp("f_probe_for_handover(" & log_label & "): Ending the test: Handover Failure stops the procedure.");

Change-Id: Ife5dc8999174c74e0d133729284fe526d6eaf8d9
2019-08-13 15:35:02 +02:00
Pau Espin f65278f807 tests: logging: Remove undefined param passed to logging_vty_add_cmds
Since March 15th 2017, libosmocore API logging_vty_add_cmds() had its
parameter removed (c65c5b4ea0). However,
definition in C file doesn't contain "(void)", which means number of
parameters is undefined and thus compiler doesn't complain. Let's remove
parameters from all callers before enforcing "(void)" on it.

Related: OS#4138
Change-Id: Iaea795521361a8e5b3b45eaeb35e6eda69163af3
2019-08-05 14:10:45 +02:00
Max 450f5ac910 Enable remote SIM protocol log level
It's defined in logging.h for quite some time but is not actually
enabled alongside with other internal logging categories.

Change-Id: I0e7a2add6293a072752900608c8ba34cc3850f31
2019-02-14 19:19:57 +01:00
Neels Hofmeyr ea6f519ff8 vty logging: fix crash when missing 'logging enable'
We must explicitly check the return value of osmo_log_vty2tgt(), or may run
into a segfault. I wasn't aware of this and introduced numerous such cases in
I36f17c131cc70ce5a1aef62fd9693097de230cd4.

Reproduce: on the VTY, do not issue 'logging enable', invoke 'logging level
force-all LEVEL' first.

Show in logging_vty_test.vty that this situation is now again amended by
telling the user that logging was not enabled.

Related: OS#3611
Change-Id: Id11702d1801d6654ca5e5a51b597a0d802e2e8dd
2018-10-01 15:58:20 +02:00
Harald Welte 0d67f483e2 logging_vty: Ensure writing well-formed config files
We want to have well-formed config files that print exactly one space
per VTY/config node level, and not two.

Change-Id: Ia75c7067284ea225cffe13ca71bad05a7747ae66
2018-09-25 20:25:30 +02:00
Neels Hofmeyr 28fc078f9c logging vty: add 'logging level set-all <level>'
Add new command to once-off set each and every category to the given log level,
as discussed at length on the openbsc@ mailing list.

Show that it works in logging_vty_test.vty.

Change-Id: I4c3e4f786476cb813fdc0a7c64f30ee04758309d
2018-09-16 23:09:56 +02:00
Neels Hofmeyr 9540c24058 logging vty: deprecate 'all', introduce 'force-all'
Add 'logging level force-all <level>' and 'no logging level force-all' as new
names for 'logging level all <level>' and 'logging level all everything'.

Resurrect the functionality of 'logging level all everything' -- even if it is
still deprecated because the name is confusing, it is now just an alias for
'no logging level force-all'.

Show in logging_vty_test.vty that we can now again lift the global logging
clamp, both with the new commands as well as with the deprecated ones.
Also show that 'force-all' is written back properly, if set.

Change-Id: I36f17c131cc70ce5a1aef62fd9693097de230cd4
2018-09-13 15:46:55 +00:00
Neels Hofmeyr 7e0686c6b4 logging vty: deprecate the 'everything' keyword
The 'logging level all everything' has not had an effect for some time now. The
plan is to bring back its old functionality, but to keep it deprecated and
rather define a less confusing name.

* Deprecate 'everything'.
* Do not write 'everything' during 'write file' or 'show running-config', which
  we curiously still do until now.

BTW, the reason why we need to compose a complete list of categories for the
deprecated 'everything' command is explained in detail in the commit log for
I3b083f27e3d751ccec258880ae7676e9af959a63

Change-Id: Ib75fedb0572570a61bb34ee729a2af86cf5f16da
2018-09-13 15:46:55 +00:00
Neels Hofmeyr 3a9ff11e57 logging vty: add VTY transcript test
I am setting out to refactor various details about logging. To show the effect,
I am first adding this new test to illustrate the exact effects on the various
osmo programs.

Add logging_vty_test.c as a standalone program that simply defines a few
logging categories and opens a telnet vty to play with.

Add logging_vty_test.vty, as an osmo_verify_transcript_vty.py test script.

Add --enable-external-tests to configure.ac, to enable running
logging_vty_test.vty during 'make check'.

Also allow running 'make vty-test' without the need to first configure with
--enable-external-tests (a flexibility I've missed many times over in the other
osmo source trees).

Add a Makefile.am stub for external CTRL tests, basically a copy-paste from
osmo-msc.git. I doubt that libosmocore will get python driven CTRL interface
testing any time soon, but if so we will know to not run it concurrently.

Change-Id: I948e832a33131f8eab98651d6010ceb0ccbc9a9c
2018-09-12 03:06:37 +02:00
Holger Hans Peter Freyther 53aa0f51b8 license: Fix the license to GPL
This was always intended to be GPL and not AGPL. "kat" did the
development as part of an internship paid by me and we agreed
to shared copyright.

Change-Id: Ied2041ba20c5737bd967dfaa3017edf72a95b31c
2017-12-09 13:03:29 +00:00
Neels Hofmeyr 886d6fdec6 fix logging: log_set_category_filter() for internal DL* logging cats
In log_set_category_filter(), passing a negative index lead to memory
corruption. Particularly dangerous since the internal logging categories have
negative values.

Fix: apply map_subsys() to interpret negative values as internal logging
categories.

As a side effect, out-of-bounds logging categories will be mapped to DLGLOBAL
instead of being dropped.

Fix the expectations in logging_test to match the fixed bug.

While at it also guard against a NULL logging target.

Change-Id: Ib0725b22bc39498c6b3970a61eb3339cf56d19f1
2016-12-12 16:56:54 +01:00
Neels Hofmeyr a4842afc83 show bug in logging: log_set_category_filter on DL* categories
Add a check to logging_test.c to show a bug: passing an internal DL* category
constant to log_set_category_filter() results in a negative array index and
undefined behavior. A sanitize build should catch this.

The bug is confirmed by the fact that logging_test.err stays the same
(hopefully) although a logging output should appear from this patch. The test
could as well segfault or anything else, it's a bit of a gamble.

This bug will be fixed along with the expectation in a subsequent patch.

Change-Id: Ie2da77c642a84cafc0f528985930697ec167183b
2016-12-12 16:56:54 +01:00
Neels Hofmeyr 748022694c fix logging: out-of-bounds check should end with user categories
To check category bounds, rather use num_cat_user, to redirect all semantically
unknown categories to DLGLOBAL.

Adjust logging_test expectations accordingly: "(d)" is now also shown.

Note: subsys is and needs to be signed, while num_cat* are unsigned. Thus for a
negative subsys, 'subsys >= num_cat_user' practically always yields true. Pay
close attention to signedness and check upper bound only for positive values.

Change-Id: I4a952b759f30d90fbfb81fedcfc56a8092ea18c1
2016-12-12 16:56:50 +01:00
Neels Hofmeyr d1a145e5e7 show bug in logging: out-of-bounds check should end with user categories
In the background osmo_log_info array, the user's logging categories are
enhanced by the library internal ones. So far logging category range checking
only checked for the larger array bounds, although passing a logging category
>= num_cat_user is already semantically unknown and should redirect to
DLGLOBAL.

Add a check to logging_test.c to show that this isn't happening. Instead of
DLGLOBAL, a logging category that happens to be at that index is queried.

The bug is confirmed by logging_test.err only showing "(e)" and not "(d)":
"(e)" is shown because the first category after the user ones happens to be
DLGLOBAL. "(d)" is omitted since it hits a category that's not on debug level.

This bug will be fixed along with the expectation in a subsequent patch.

Change-Id: I397278714018ee9a0ae5101515f31ddddf79c2ec
2016-12-12 16:09:14 +01:00
Neels Hofmeyr ca13574ba4 fix logging: also catch first out-of-bounds logging cat
In map_subsys(), fix the '>' condition to '>=' for array bounds checking.

Also make the bounds checking more strict: after both invocations of
subsys_lib2index(), re-check validity of the array index. If the final index is
still wrong, which should never happen, exit by assertion.

Change-Id: I7ca1a1d47724e40350f1c4dfebe90bad01c965f9
2016-12-12 15:48:08 +01:00
Neels Hofmeyr a280b82f8e show bug in logging: erratic redirection to DLGLOBAL for first invalid category
Add a check to logging_test.c to show a bug: when a logging category value that
is the first out-of-bounds value is passed to the logging system, the internal
map_subsys() fails to redirect to DLGLOBAL due to a flawed conditional. This
results in a too large array index and undefined behavior. A sanitize build
should catch this.

The bug is confirmed by the fact that logging_test.err stays the same
(hopefully) although a logging output should appear from this patch. The test
could as well segfault or anything else, it's a bit of a gamble.

This bug will be fixed along with the expectation in a subsequent patch.

Change-Id: I12bf38b6c1f85e2d7bf5a15f942dfe0beed41eba
2016-12-12 15:47:51 +01:00
Neels Hofmeyr 42240de04c fix logging: redirection to DLGLOBAL for invalid categories
For out-of-bounds logging categories, redirect to the proper DLGLOBAL array
index instead of returning -1.

Adjust test expectation which shows that the bugs tested for are fixed.

Note: there are separate bounds checking problems, left for another patch.

Change-Id: I6ea9a59e005a22e0305454291714fdb9531c346b
2016-12-12 15:47:37 +01:00
Neels Hofmeyr 85b42c4618 show bug in logging: erratic redirection to DLGLOBAL for invalid categories
Add a check to logging_test.c to show a bug: when a logging category value that
is out-of-bounds is passed to the logging system, the internal map_subsys()
function should remap that to DLGLOBAL. But in fact DLGLOBAL is -1 and the
function fails to map this to a proper positive array index, directly returning
-1 instead. This results in a negative array index and undefined behavior. A
sanitize build should catch this.

The bug is confirmed by the fact that logging_test.err stays the same
(hopefully) although a logging output should appear from this patch. The test
could as well segfault or anything else, it's a bit of a gamble.

This bug will be fixed along with the expectation in a subsequent patch.

Note: osmo_log_info->num_cat + 0 is also out-of-bounds, but there is a separate
bug there, so leaving this for another patch.

Change-Id: I161b6550fa204a872bad1abefee1a6155393fafd
2016-12-12 15:47:32 +01:00
Neels Hofmeyr 9adf32fb60 logging test: cosmetic: print target and don't print color
Prepares for upcoming modifications of the logging test to show and fix bugs in
the logging system.

Change-Id: I9461b987adf85d87469a6af55de5f1aa478f6ebb
2016-12-12 14:24:39 +01:00
Holger Hans Peter Freyther 79599acd66 logging: Move the filter check up as well
There doesn't seem to be a reason not to check the filter. Update
and extend the test. Currently the filter function will be called
once for the log check and once for the output of it.
2016-02-29 14:30:14 +01:00
Jacob Erlbeck 64e0eb56fd log/test: Extend test case for log_check_level
This commit adds OSMO_ASSERTs for mandatory conditions related to
log_check_level, and fprintfs for optional conditions, since it is
always safe for log_check_level to return != 0.

Sponsored-by: On-Waves ehf
2016-02-29 14:30:14 +01:00
Holger Hans Peter Freyther b7d0f4686b logging: Copy the filter_fn and fix the IMSI filter in OpenBSC
The filter_fn has not been copied into the new structure breaking
the imsi and other filters in OpenBSC. Looking at the code we should
also introduce a callback for the reset of the context so we could
use subscr_get/subscr_put on the subscriber structure.
2013-12-29 19:38:01 +01:00
Holger Hans Peter Freyther 779d2f42a4 logging: Modify the testcase to excercise Nico's fix 2012-09-27 16:31:29 +02:00
Holger Hans Peter Freyther 4b54cab476 logging: Move the logging test from OpenBSC into libosmocore
Add a testcase for the logging facility. The test is coming from
the OpenBSC code.
2012-09-27 16:29:54 +02:00