Hi all,
A discussion was started during the review of https://gerrit.osmocom.org/10116/. The main idea of this change is to fix the behaviour of 'logging level all LEVEL', but I think it was also mixed with some additional feature, which I would like to discuss here, publicly.
First of all, the change introduces a new special logging level 'unset', which allows one to reset a given category (i.e. unset its custom value):
!! Initial logging configuration: logging level all error logging level mncc debug logging level pag notice logging level meas debug
!! Resetting DMNCC: # logging level mncc unset
!! So, now DMNCC has no custom log level, it will use !! the default level (in this example it is 'error'): logging level all error logging level pag notice logging level meas debug
This feature looks fine and extremely useful for me.
But (among fixing) this change additionally changes the behaviour of a command for setting the default logging category (i.e. 'logging level all LEVEL'):
!! Initial logging configuration: logging level all error logging level mncc debug logging level pag notice logging level meas debug
!! Changing the default logging level: # logging level all debug
!! Ahhh, I've lost my custom levels :( logging level all debug
!! What I expected to get: logging level all debug logging level mncc debug logging level pag notice logging level meas debug
So, together with changing the default logging category, this command now would also reset all custom settings...
I am not sure this is exactly what one need/expect, so I would like to share the following ideas:
1) The category 'all' looks/sounds confusing when it's used in such cases like this:
# logging level all debug
because one can interpret it like:
"set all categories to debug".
despite actually (according to the implementation) this is related to the default logging policy.
Maybe, we should rename it to 'default'?
So, 'logging level all LEVEL' would *set all categories* to a given logging LEVEL, while 'logging level default LEVEL' would only affect the default logging level...
2) Introducing the new command:
# logging level unset LEVEL
which is intended to assign a given LEVEL to all categories, which have no custom logging level (i.e. have 'unset'), would make the idea of having default logging policy meaningless.
Setting logging level(s) for all possible categories (using this command), looks like writing iptables rules for all possible and impossible cases instead of using the DEFAULT policy...
3) The introduced behaviour of resetting all categories to 'unset' could be implemented in a separate function, and can be represented by a separate command:
# logging level unset-all
The name of this command clearly defines the expected behaviour. Moreover, it doesn't affect the default logging level, which can be still changed by a separate command.
As we (me and Pau) have different opinions, or we simply don't understand each other, let's make this discussion public, and let's see what others think about this...
With best regards, Vadim Yanitskiy.
Hi Vadim,
Find my answers in place with your lines.
On 24/07/18 19:10, Vadim Yanitskiy wrote:
Hi all,
A discussion was started during the review of https://gerrit.osmocom.org/10116/. The main idea of this change is to fix the behaviour of 'logging level all LEVEL', but I think it was also mixed with some additional feature, which I would like to discuss here, publicly.
First of all, the change introduces a new special logging level 'unset', which allows one to reset a given category (i.e. unset its custom value):
!! Initial logging configuration: logging level all error logging level mncc debug logging level pag notice logging level meas debug
!! Resetting DMNCC: # logging level mncc unset
!! So, now DMNCC has no custom log level, it will use !! the default level (in this example it is 'error'): logging level all error logging level pag notice logging level meas debug
This feature looks fine and extremely useful for me.
Everything's correct up to here, and I agree.
But (among fixing) this change additionally changes the behaviour of a command for setting the default logging category (i.e. 'logging level all LEVEL'):
!! Initial logging configuration: logging level all error logging level mncc debug logging level pag notice logging level meas debug
!! Changing the default logging level: # logging level all debug
As per current code with the mentioned patchset, you should use here "logging level unset debug" to accomplish what you want in this example. Then you get you expected behavior.
!! Ahhh, I've lost my custom levels :( logging level all debug
!! What I expected to get: logging level all debug logging level mncc debug logging level pag notice logging level meas debug
So, together with changing the default logging category, this command now would also reset all custom settings...
I am not sure this is exactly what one need/expect, so I would like to share the following ideas:
1) The category 'all' looks/sounds confusing when it's used in such cases like this:
# logging level all debug
because one can interpret it like:
"set all categories to debug".
despite actually (according to the implementation) this is related to the default logging policy.
Maybe, we should rename it to 'default'?
So, 'logging level all LEVEL' would *set all categories* to a given logging LEVEL, while 'logging level default LEVEL' would only affect the default logging level...
Ok so afaiu what you say is that current "unset" becomes "default". Then in "all" we loop over categories and set each with loglevel.
2) Introducing the new command:
# logging level unset LEVEL
which is intended to assign a given LEVEL to all categories, which have no custom logging level (i.e. have 'unset'), would make the idea of having default logging policy meaningless.
Currently (with patchset), "unset" actually sets the target loglevel, aka the default, so it doesn't make default meaningless because it uses it. The difference with current "all" is that it doesn't reset the categories to unset.
Setting logging level(s) for all possible categories (using this command), looks like writing iptables rules for all possible and impossible cases instead of using the DEFAULT policy...
I don't get your point here. You can do both.
3) The introduced behaviour of resetting all categories to 'unset' could be implemented in a separate function, and can be represented by a separate command:
# logging level unset-all
The name of this command clearly defines the expected behaviour. Moreover, it doesn't affect the default logging level, which can be still changed by a separate command.
As we (me and Pau) have different opinions, or we simply don't understand each other, let's make this discussion public, and let's see what others think about this...
With best regards, Vadim Yanitskiy.
So, after your comments and thinking about it, here's my proposal: 1- Take my current patchset 2- Modification: "logging level all <loglevel>" sets the loglevel foreach category, not the target loglevel (aka the default loglevel). 3- Modification: "logging level unset <loglevel>" is renamed to "logging level default <loglevel>" 4- Addition: New VTY cmd "logging level unset-all" is introduced, which sets all categories to UNSET (basically re-use the current loop we have in current patchset handling the "all").
For num.4, we could actually use "logging level all unset", which makes perfectly sense and matches with expectations.
Agree?
Hi all,
for logging changes, I would welcome a comprehensive approach and maybe add an all new set of logging commands, to not confuse with the current logging behavior; keep and deprecate the old ones for users that were fine with those. (I was the one responsible for the death of 'logging level all everything', and I've stumped at least one user who now keeps patching it back in manually; let's not repeat that.)
Maybe we can come up with more meaningful wording that more accurately indicate what is happening? But if the current command set suffices without confusion, we can also keep that, and maybe resurrect the 'logging level all everything'??
Here are the handles / use cases that come up -- I've embedded implementation choices and command names in this proposal, but it's intended as a blueprint to incorporate everyone else's bikesheds:
A) The hardcoded logging landscape on program startup without config. (Maybe this isn't all that important, including it nevertheless.) 1) a command to reset all to hardcoded defaults?
B) A "normal" logging behavior configured by the user. We need: 1) a command to set all categories at once 2) a command to tweak individual categories
C) Temporarily reducing the logging on all categories: silence the log. Even though a category is "normally" set to INFO, after this command it can be forced down to only log e.g. NOTICE. But if a category is already on ERROR, leave it down there and do not lift it up to NOTICE. 1) a command to temporarily reduce all categories. 2) a command to temporarily reduce individual categories.
D) Temporarily increasing the logging on all categories: show everything. Even though a category is "normally" set to ERROR, after this command it can be forced up to e.g. INFO. But if a category is already up at DEBUG, don't reduce it to NOTICE. 1) a command to temporarily increase all categories. 2) a command to temporarily increase individual categories. 3) we need to decide whether temporarily increasing is stronger/weaker than temporarily reducing. Depending on the implementation, it could also be "last one wins" (which IMHO would be best).
T) Maybe we also want to unconditionally set temporary levels, whether they increase or reduce.
E) Remove temporary logging to go back to the "normal" logging landscape. 1) a command to put everything back to "normal", 2) a command to put individual categories back to "normal", 3) a separate command to only remove temporary reduction, i.e lift the temporary changes only if they cause less logging than normal, 4) a separate command to only remove temporary verbosity, i.e. only lift the temporary changes if they cause more logging than normal.
F) Set a specific log context, and silence all messages (regardless of their logging category setting) unless they match the context filter: logging filter imsi 123456789123456 Though this feature has probably never been properly implemented through all code paths, it is potentially very powerful for live debugging. Especially with the new FSMs around everywhere, there is a good chance that we can fairly easily improve on the current 'logging filter foo' experience. During congress, I really yearned for this to work well. 0) In the current implementation, on each individual log message, this decides whether the context matches, and if not, the message is discarded. 1) Instead of discarding, we may want a level to reduce to. 2) Or maybe we want to leave the logging landscape unchanged, but lift the level for all logs that match the set context? 3) disable individual filters 4) disable all filters. This is currently 'logging filter all 1' but that is confusing, we could use a meaningful synonym, and separate from filters.
G) toggle all logging in the telnet vty 1) silence logging (currently 'logging filter all 0', confusing) 2) continue logging (currently 'logging filter all 1', confusing)
A bit of a meaningless image of different logging layers:
level ^ Hardcoded defaults.. | ... - ====== =.... Normal logging landscape== | == .== ... ==... -- Temporary levels-- | -- =.... ...== - = | = -- ---- -=== |________________________> categories
Same image with actual current logging overlayed:
level ^ | ... # =###== =.... | == .== ... ==... ## Resulting levels ## | ## #.... ...## # = | # ## #### #=#= |________________________> categories
- the hardcoded defaults are immutable. - the normal landscape can be freely chosen. - Some categories may have temporary tweaks. Where there are temporary tweaks, they take precedence as-is. The vty command ("make stronger" or "make weaker") decided whether to put a temporary level in place or not.
Can you guys explain the current patch proposals in terms of above features? (like, use the capital letters A-G for reference)
Feel free to change this vty transcript proposal i've tossed up as I went:
! A.1) hardcoded defaults logging hard-reset rsl,chan,msc logging hard-reset
! B) set normal categories ! B.1) all logging set notice all ! B.2) individual logging set notice rsl,chan,msc
! C) Temporarily reducing ! C.1) all logging reduce notice all ! C.2) individual logging reduce error l1p,nm,cc
! D) Temporarily increasing ! D.1) all logging increase info all ! D.2) individual logging increase debug mm,rr
! D.3) last one wins logging reduce error l1p,mm,rr logging increase debug mm,rr logging reduce notice rr ! result: l1p=error mm=debug rr=notice
! T) set temporary level unconditionally logging set-temp error all logging set-temp error mm,rr ! logging (recrease|induce) ;)
! E.3) remove temporary verbosity no logging reduce nm,cc no logging reduce all ! E.4) remove temporary silencing no logging increase nm,cc no logging increase all ! E.2) snap back to normal levels logging reset rsl,nm,rr ! E.1) ...for all categories logging reset all
! F.0) context filter logging filter imsi 123456789123456 ! F.1) choose context filter behavior logging filter-reduce error logging filter-discard ! F.2) logging filter-increase debug ! F.3) disable filter no logging filter imsi ! F.4) no logging filter
! G.1) logging [on] logging 1 ! G.2) no logging logging 0
Using a .TEXT argument, we could easily allow a space separator for category lists, as in "l1p mm cc". (nice would be to invent a VTY argument type that allows any number of the same kind, so far we have weird constructs like seen in bsc_vty.c, cfg_bts_codec0_cmd thru cfg_bts_codec4_cmd each with a different nr of same argument)
A test program should define logging categories and a context filter, issue each of above commands and then log once all across each level and category to see what logging we still see.
As a final step, we should figure out how the current logging commands match these features, and make them still do the things they always did as best as makes sense.
What do you guys think?
About bikesheds: if we can't agree, we could put out a patch contest, where everyone that cares implements a proposal, and we vote in the end. I hope we don't waste time by deadlocking in the end ;)
~N
Hi Neels,
The aim here was to fix and have a useful set of commands as close as possible to the previously existing set of commands. So my aim here is not to re-implement the whole logging system, deprecate entire command sets or add a big bunch of new ones. I want it to be as compatible as possible with older ones.
With the current patchset + few extra ideas exposed in last emails from me:
A) It's already there as it is now, no need to change. When you start a program, code harcoded categories are set with a given loglevel.
B) 1) logging level all <loglevel> 2) logging level <category> <loglevel>
C) D) T) E) I fins all this "temporary" stuff something really not there in current code, too complex and not really required. You can do whatever config setup you want with following command: logging level (all|default|<category>) (unset|<loglevel>)
F) Not sure what's the current state for this, but not directly related to the improvements I'm doing (I'm doing nothing filter related)
G) Agree that the naming is confusing, but not directly related to the improvements I'm doing (I'm doing nothing filter related)
Current proposed system is basically (and very similar to old system, just a bit better sort out imho):
* You have a logtarget loglevel. Each logtarget instance (VTY, stderr, gsmtap, etc.) has one. This is also called the "default" log level. * Each category can be either set with a loglevel or unset. * If category is set with a loglevel, this loglevel is used to resolve printing. * If category is unset, default log level (logtarget loglevel) is used. * If you add harcoded per-category values in code, then those are applied at startup, which means these categories won't use the default loglevel until unset.
On Wed, Jul 25, 2018 at 05:31:59PM +0200, Pau Espin Pedrol wrote:
A) It's already there as it is now, no need to change. When you start a program, code harcoded categories are set with a given loglevel.
But currently no way to get back to it, IIUC. Not important anyway.
C) D) T) E) I fins all this "temporary" stuff something really not there in current code, too complex and not really required.
We actually supported temporary logging increase, even though I never grokked how it was supposed to work, hence I broke it by removing the logging level all everything.
This is an attempt to bring it back in an obvious and finely tunable way. It is not really complex, is it!?
Current proposed system is basically (and very similar to old system, just a bit better sort out imho):
A problem there is that it is changing the meaning of a logging command that has been there for a decade. Because I fail to understand why exactly it isn't doing what I want and why it was implemented this way, and because I accept that other users might rely on exactly the current behavior to do what they want, I would prefer keeping it unchanged and to add new command names that make proper sense to us (to not repeat my past mistake).
You can do whatever config setup you want with following command: logging level (all|default|<category>) (unset|<loglevel>)
no, can't do whatever config setup:
- You have a logtarget loglevel. Each logtarget instance (VTY, stderr,
gsmtap, etc.) has one. This is also called the "default" log level.
- Each category can be either set with a loglevel or unset.
This does not allow for the 'logging level all everything' use case:
- I have setup a detailed logging landscape, i.e. not one default level for all categories, but a fine grained selection: some on error, some on notice, some on info, ... - Now for a minute I want to quickly see all debug logging. logging increase debug all - Later I want to go back to the detailed landscape. logging reset all
I'd like to provide a way to define a fine grained selection of logging levels as the default, more than just one level across the board. IIUC that can't be done with the current 'default' and 'unset'?
Besides it changing an old vty command and it still missing an important use case, I totally agree that your patch is a usability improvement :)
~N
On 25/07/18 18:12, Neels Hofmeyr wrote:
On Wed, Jul 25, 2018 at 05:31:59PM +0200, Pau Espin Pedrol wrote:
A) It's already there as it is now, no need to change. When you start a program, code harcoded categories are set with a given loglevel.
But currently no way to get back to it, IIUC. Not important anyway.
No, we cannot, we would probably require a new API to store them as "harcoded categories", and some VTY command to set them. If somebody thinks it's needed and really useful, patches welcome. I think it's not that useful and I want to keep the logging system as simple as possible while still providing useful ways to fine-grain loglvels.
C) D) T) E) I fins all this "temporary" stuff something really not there in current code, too complex and not really required.
We actually supported temporary logging increase, even though I never grokked how it was supposed to work, hence I broke it by removing the logging level all everything.
This is an attempt to bring it back in an obvious and finely tunable way. It is not really complex, is it!?
Same as my last above comment. My intention with this patchset was to have the logging working again trying not to touch that much, and avoid spending much time on it. If at some point we supported the feature, it's not the case anymore nowadays. If somebody wants to re-add that feature and change the logging system, patches welcome.
Current proposed system is basically (and very similar to old system, just a bit better sort out imho):
A problem there is that it is changing the meaning of a logging command that has been there for a decade. Because I fail to understand why exactly it isn't doing what I want and why it was implemented this way, and because I accept that other users might rely on exactly the current behavior to do what they want, I would prefer keeping it unchanged and to add new command names that make proper sense to us (to not repeat my past mistake).
I think current behavior (for logging level all) is imho totally broken and the patchset I'm proposing changes behavior of old commands only minimally.
- I have setup a detailed logging landscape, i.e. not one default level for all categories, but a fine grained selection: some on error, some on notice, some on info, > - Now for a minute I want to quickly see all debug logging. logging increase debug all
- Later I want to go back to the detailed landscape. logging reset all
Someone can always add these feature on top of present patchset if there's enough use for it. This feature is not there now, so I'm not removing it with presented patchset. I personally think the scenario you presented can be workarounded pretty easily in different ways, so I personally think there's no urgent need for it: 1- Open a new VTY, then call logging level all debug 2- Write down the commands you used to set the logging, then paste them after running "logging level default debug; logging level all unset" to see all logging for a while.
On Thu, Jul 26, 2018 at 11:04:25AM +0200, Pau Espin Pedrol wrote:
On 25/07/18 18:12, Neels Hofmeyr wrote:
On Wed, Jul 25, 2018 at 05:31:59PM +0200, Pau Espin Pedrol wrote:
A) It's already there as it is now, no need to change. When you start a program, code harcoded categories are set with a given loglevel.
But currently no way to get back to it, IIUC. Not important anyway.
No, we cannot, we would probably require a new API to store them as "harcoded categories"
The information is always there, the default categories log_info_cat struct are const. Remeber, each log target has its own category-level settings, so obviously the hardcoded defaults remain available. It's a simple thing.
And still not really important :)
Same as my last above comment. My intention with this patchset was to have the logging working again trying not to touch that much, and avoid spending much time on it. If at some point we supported the feature, it's not the case anymore nowadays. If somebody wants to re-add that feature and change the logging system, patches welcome.
And same as my last comment, you are changing a decade old vty command. Last time I did this it was the wrong choice.
Someone can always add these feature on top of present patchset if there's enough use for it.
Introducing a common default level actually also closes the door on fine-grained default levels. I mean the VTY UI you are introducing would have to be deprecated to introduce fine-grained defaults.
It is actually not practical to have all categories on the same level, unless it is, say, ERROR.
So the patch does what you want and is better than current 'logging level all xxx' indeed, but changes old UI and has limits. As much as I'd like to let it go ahead, I'm still -1, sorry.
1- Open a new VTY, then call logging level all debug
true. Any opinions on this one, Keith maybe?
2- Write down the commands you used to set the logging, then paste them after running "logging level default debug; logging level all unset" to see all logging for a while.
I had the same idea once, but it's not practical. Copy pasting and stuff is not something we want to require the user to do.
~N
Hi, find answers in place.
On 26/07/18 16:20, Neels Hofmeyr wrote:
No, we cannot, we would probably require a new API to store them as "harcoded categories"
The information is always there, the default categories log_info_cat struct are const. Remeber, each log target has its own category-level settings, so obviously the hardcoded defaults remain available. It's a simple thing.
Ok, no need for new API, since it's already done using a specific API (log_init). But we'd need to change the implementation to account in that function that for each category the value being copied is the "hardcoded default" instead of a regular level being set.
And same as my last comment, you are changing a decade old vty command. Last time I did this it was the wrong choice.
Ok so let's leave it broken and useless then? Deprecate it and write an entire new system? No, thanks.
Someone can always add these feature on top of present patchset if there's enough use for it.
Introducing a common default level actually also closes the door on fine-grained default levels. I mean the VTY UI you are introducing would have to be deprecated to introduce fine-grained defaults.
What do you mean with fine-grained default levels? Having a way to go back to hardcoded initial values? You can have that as long as you store the values in log_init in a new var default_loglevel for each category.
If you still want more temporary levels (increase/decrease or whatever you call it) per logtarget or even per category, you can add them later and check them before the other levels in should_log_to_target(), then change them with new VTY commands.
So the patch does what you want and is better than current 'logging level all xxx' indeed, but changes old UI and has limits. As much as I'd like to let it go ahead, I'm still -1, sorry.
It's compatible with old UI. All programs using the API continue to work fine as well as old cfg files. It adds new parameter "logging level default <loglevel>" and "logging level <category> unset", that's all. So it fixes broken logging level all and adds extra feature to make it useful.
1- Open a new VTY, then call logging level all debug
true. Any opinions on this one, Keith maybe?
You can even just re-open the session you have opened, no need to open a second one.
Before this echoing of the same arguments over and over continues between you and me, Pau, let's stop this here and let me do my homework in the logging code. I'll try to clarify what I mean, but I see I need to prove my points.
Ok so let's leave it broken and useless then? Deprecate it and write an entire new system? No, thanks.
Introducing new commands that work properly is IMO the only viable solution to fix old broken UI. IIUC your patch adds new commands?
So I'd like to clarify how the implementation affects what old commands did, and whether it permits implementing per-category defaults without problems.
What do you mean with fine-grained default levels?
Still not clear, is it? I want to set various categories to various log levels to taste, then go to say DEBUG on some/all of them, then later go back to exactly the levels selected before.
It's like your default log level, just not one across all categories, but one level per category.
Your suggestion:
level ^ | - Normal logging landscape== | ===================== Temporary levels-- | -- - | -- ---- - |________________________> categories
What I'd like to support:
level ^ | - ====== = Normal logging landscape== | == == == -- Temporary levels-- | -- = == - = | = -- ---- -=== |________________________> categories
This includes the possibility of having all of them at the same level, so it seems we are just very verbosely arguing about the implementation and UI details.
Having a way to go back to hardcoded initial values?
Please let go of the hardcoded defaults, they aren't important, I did say so a number of times now.
If you still want more temporary levels (increase/decrease or whatever you call it)
Do I read a dismissive tone here? :P
per logtarget
Everything is always inherently per logtarget!
or even per category,
exactly
you can add them later and check them before the other levels in should_log_to_target(), then change them with new VTY commands.
If you introduce one common default level for all categories, I fear that it conflicts with the use case to have separate defaults for each category. I still need to prove that.
It's compatible with old UI. All programs using the API continue to work fine as well as old cfg files. It adds new parameter "logging level default <loglevel>" and "logging level <category> unset", that's all. So it fixes broken logging level all and adds extra feature to make it useful.
Don't the code changes modify how 'logging level all foo' behaves? I have to do my homework to strengthen my argument here.
1- Open a new VTY, then call logging level all debug
true. Any opinions on this one, Keith maybe?
If monitoring e.g. BTS or PCU on a slow ARM, opening multiple log targets might impact stability.
You can even just re-open the session you have opened, no need to open a second one.
But then you lose the specific logging selection that you want to keep.
~N
Hi Pau, Neels, and all,
It seems, the reason of my misunderstanding was that confusing 'all' keyword. I have been interpretting it as 'default', but actually it is far from this meaning...
So after my proposal (from my last email): ... logging level (all|default|<category>) (unset|<loglevel>) ... Agree?
Yep, finally I am ;)
In order to have a clean commit history, I suggest the following algorithm (one high level point represents one single change):
1. Introduce 'unset' keyword first; 2. Introduce 'default' logging category ('logging level default'): 2.1. Modify the 'logging level' command (by adding 'default'); 2.2. Correct memory allocation in log_vty_command_string(); 2.3. Write *exactly 'default'* (not 'all') to the configuration; 3. Fix the behaviour of 'default' (i.e. target's) logging category: 3.1. In other words, correct the loging in should_log_to_target(); 4. Correct the behaviour of 'logging level all LEVEL'; 5. Testing coverage ;) 6. <New features> ...
And same as my last comment, you are changing a decade old vty command. Last time I did this it was the wrong choice.
Regarding to changing the behaviour of 'logging level all LEVEL' command, I think we need to make this step. Let's have a look at OsmoHLR configuration, shipped as an example:
log stderr ! ... ! Set *default* log level 'debug' for stderr logging level all debug logging level linp error
What would we get now (before merging the patch set)?
The 'debug' becomes default, but since the logging is broken, the hardcoded values will be used for all categories, excluding 'linp'. The 'all' remains confusing...
If one saves the current configuration, the result would be:
log stderr ! ... ! Set *default* log level 'debug' for stderr logging level all debug logging level linp error logging level foo <hardcoded> logging level bar <hardcoded> ! all other categories...
What would we get after this patch set?
The first command is now interpreted as it should be interpreted. So, we have no 'default' logging level (i.e. it becomes 'unset'), all categories, excluding 'linp', are set to 'debug'.
If one saves the current configuration now, the result would be similar, i.e. it will also dump all possible categories, but instead of <hardcoded> values 'debug' would be used:
log stderr ! ... ! Set *default* log level 'debug' for stderr logging level default debug logging level linp error logging level foo debug logging level bar debug ! all other categories...
How to avoid this after merging the patch set?
Update the configuration examples, replacing 'all' by 'default'. Either, doing 'logging level all unset' before saving to file.
This way one would get the original configuration untouched, i.e. without dumping all possible categories...
Then we can think about new features, and this is what do I think about some of them (described by Neels):
A.1. A command to reset all to hardcoded defaults?
I like the idea of Neels about resetting the logging levels. Additionally to the hardcoded logging settings, would be great to have a possibility to reset to the logging settings from the current configuration...
I assume the following syntax for that:
logging level (all|default|<category>) reset
C) Temporarily reducing the logging D) Temporarily increasing the logging E) Remove temporary logging to go back to the "normal" logging landscape.
Regarding to the 'temporary' staff, I think one can interpret the current ('running') modified configuration as 'temporary'. You're free to change everything, and if you like the current logging configuration - you can write it to a file. Otherwise, your idea about resetting fits here just fine, so one would be able to restore the current configuration from file at runtime.
F) ... silence all messages ... unless they match the context filter: logging filter imsi 123456789123456 ... 3) enable / disable individual filters 4) disable all filters
I think it's useful feature. I didn't even know about this :) Another interesting idea is to introduce a RegExp based filter (if not yet), like we have in the talloc context introspection command. Examples:
logging filter regexp (failed|unable|couldn't) logging filter regexp ^BTS[0-9]+
BTW: I also find 'logging filter all 1' confusing ;)
With best regards, Vadim Yanitskiy.
On 26/07/2018 16:20, Neels Hofmeyr wrote:
true. Any opinions on this one, Keith maybe?
I have now got used to using a number of pre-prepared expect scripts to open VTYs for various logging scenarios.
Rather than changing the logging in an open VTY, I would probably open another and change it there, or copy and modify the script to setup that logging config. I haven't got around to it yet, but I am planning on making this just one script that accepts params like "msc" or "mgw" as well as logging configs concepts as I can never remember the ports now with all the programs, although I have this:
sudo netstat -tapn | egrep 'LISTEN.*osmo' | awk '{print $4, $7}' | awk -F "[:/ ]" '{print $2,"- " $4}' | grep 42 | sort -n
I did not particularly have a problem with "logging level all everything" and "logging level all debug" and yes, as Neels mentioned have been patching libosmocore to revert to allowing "logging level all everything" - Despite some strange resistance to belief from some parties, this actually worked (works) as a temporary ON/OFF switch to set all categorys to debug, then revert to individual per category levels. I've explained that before, here on the list with Max, I think. The semantics off "logging level all everything" was no more difficult that anything else in GSM's world of acronyms etc. It was simply a case of learning what it does.
I think it might be nice to have a default VTY logging storable in the config as we do for stderr. Otherwise, I'm kind of OK with using expect to setup what I want.
K.
On Fri, Jul 27, 2018 at 01:42:11PM +0200, Keith wrote:
Neels mentioned have been patching libosmocore to revert to allowing "logging level all everything"
So you're saying you're no longer doing that and going with opening separate VTY telnets instead?
I think it might be nice to have a default VTY logging storable in the config as we do for stderr.
There's an interesting feature request. Maybe easier would be a vty command to adopt in the current telnet the logging config from stderr (or any other log target).
Otherwise, I'm kind of OK with using expect to setup what I want.
What's "using expect"?
~N
On Fri, Jul 27, 2018 at 04:59:46PM +0200, Neels Hofmeyr wrote:
What's "using expect"?
I guess Keith referst to the good old expect program, used by many of us for decades for automating shell like interfaces.
"apt-get install expect && man 1 expect" ?
Hi Neels,
On Wed, Jul 25, 2018 at 04:22:09PM +0200, Neels Hofmeyr wrote:
A) The hardcoded logging landscape on program startup without config. (Maybe this isn't all that important, including it nevertheless.)
- a command to reset all to hardcoded defaults?
ACK
B) A "normal" logging behavior configured by the user. We need:
- a command to set all categories at once
to set all to one level, or to set all to one set of (configurable) defaults, like a template?
- a command to tweak individual categories
ACK.
C) Temporarily reducing the logging on all categories: silence the log. Even though a category is "normally" set to INFO, after this command it can be forced down to only log e.g. NOTICE. But if a category is already on ERROR, leave it down there and do not lift it up to NOTICE.
- a command to temporarily reduce all categories.
- a command to temporarily reduce individual categories.
Not sure for what one would use that. You could switch off logging completely and re-enable it later?
D) Temporarily increasing the logging on all categories: show everything. Even though a category is "normally" set to ERROR, after this command it can be forced up to e.g. INFO. But if a category is already up at DEBUG, don't reduce it to NOTICE.
- a command to temporarily increase all categories.
- a command to temporarily increase individual categories.
- we need to decide whether temporarily increasing is stronger/weaker than temporarily reducing. Depending on the implementation, it could also be "last one wins" (which IMHO would be best).
Sounds incredibly complicated to me.
T) Maybe we also want to unconditionally set temporary levels, whether they increase or reduce.
?!?
E) Remove temporary logging to go back to the "normal" logging landscape.
- a command to put everything back to "normal",
- a command to put individual categories back to "normal",
- a separate command to only remove temporary reduction, i.e lift the temporary changes only if they cause less logging than normal,
- a separate command to only remove temporary verbosity, i.e. only lift the temporary changes if they cause more logging than normal.
WTF? Why all that complexity?
Honestly, I'm stopping at that point. Just finishing to read that one e-mail, let alone the entire thread will cost me hours.
To me, it boils down to a hypthetical luxury problem, unless there's somebody who is actually funding/contributing the amount of time required to designing, debating, implementing, reviewing and merging and overhaul of the logging sub-system.
On Wed, Jul 25, 2018 at 11:16:46AM +0200, Pau Espin Pedrol wrote:
2- Modification: "logging level all <loglevel>" sets the loglevel foreach category, not the target loglevel (aka the default loglevel). 3- Modification: "logging level unset <loglevel>" is renamed to "logging level default <loglevel>"
I find both 'logging level unset <level>' and 'logging level default <level>' confusing. Did you mean to say '<category>'?
For num.4, we could actually use "logging level all unset", which makes perfectly sense and matches with expectations.
IMHO "level unset" doesn't spark a meaningful image. Sounds like "allow any level", or next best meaning is "back to hardcoded defaults".
~N
On 25/07/18 16:33, Neels Hofmeyr wrote:
On Wed, Jul 25, 2018 at 11:16:46AM +0200, Pau Espin Pedrol wrote:
2- Modification: "logging level all <loglevel>" sets the loglevel foreach category, not the target loglevel (aka the default loglevel). 3- Modification: "logging level unset <loglevel>" is renamed to "logging level default <loglevel>"
I find both 'logging level unset <level>' and 'logging level default <level>' confusing. Did you mean to say '<category>'?
No, I meant what I wrote.
So after my proposal (from my last email):
* "logging level default <level>": Sets default log level (the loglevel for unset categories, aka the logtarget loglevel) to <level>.
* "logging level all <level>": Sets each (all) category to use log level <level>, without modifying the default log level (aka logtarget loglevel).
* "logging level (all|<category>) unset": Unsets given category log level, and as a result log messages for that category are handled by default log level (aka logtarget loglevel).
* "logging level (all|<category>) <level>": Sets given category to given log level. As a result, messages for that category are handled by this log level and not the default log level.
Regarding your last comment: unsetting doesn't mean going to initially per-category set defaults during startup of the application. It means to fallback to default log level (aka logtarget loglevel). Initial hardcoded values set per-category are basically the same as if you went through the VTY setting "log level <category> <level>" before parsing the cfg file.
No, I meant what I wrote.
So after my proposal (from my last email):
[...]
Ok, I understand now. So our main difference is that in your patch we have one single default log level, while I aim to allow separate default log levels for each category (and on each target).
Let's discuss in the other thread leaf and end this one.
~N
On 25/07/18 18:17, Neels Hofmeyr wrote:
No, I meant what I wrote.
So after my proposal (from my last email):
[...]
Ok, I understand now. So our main difference is that in your patch we have one single default log level, while I aim to allow separate default log levels for each category (and on each target).
Just to make sure: We already have a default differentiate log level on each target. Not only 1 for the whole app. It's true that we don't have one per category.
Just to make sure: We already have a default differentiate log level on each target. Not only 1 for the whole app. It's true that we don't have one per category.
Sure, everything I say and plan is on the premise of completely independent log targets, each log target has its own configuration for every single aspect (sharing only the hardcoded default category levels from the .c files).
~N
On Wed, Jul 25, 2018 at 11:16:46AM +0200, Pau Espin Pedrol wrote:
So, after your comments and thinking about it, here's my proposal: 1- Take my current patchset 2- Modification: "logging level all <loglevel>" sets the loglevel foreach category, not the target loglevel (aka the default loglevel).
I think the "target loglevel" should/could be abandoned completely.
3- Modification: "logging level unset <loglevel>" is renamed to "logging level default <loglevel>"
IMHO it should be "logging level SUBSYSTEM unset" or "logging level SUBSYSTEM default" which would then revert back to the compiled-in level for that particular subsystem?
I understand you can un-set or fall-back to the compiled-in default of a given sub-system. But how can you un-set a given *level* ?!?
On 30/07/18 20:43, Harald Welte wrote:
On Wed, Jul 25, 2018 at 11:16:46AM +0200, Pau Espin Pedrol wrote:
So, after your comments and thinking about it, here's my proposal: 1- Take my current patchset 2- Modification: "logging level all <loglevel>" sets the loglevel foreach category, not the target loglevel (aka the default loglevel).
I think the "target loglevel" should/could be abandoned completely.
I think that feature is useful and it's there already anyway, it just doesn't work correctly in current merged code base.
3- Modification: "logging level unset <loglevel>" is renamed to "logging level default <loglevel>"
IMHO it should be "logging level SUBSYSTEM unset" or "logging level SUBSYSTEM default" which would then revert back to the compiled-in level for that particular subsystem?
I understand you can un-set or fall-back to the compiled-in default of a given sub-system. But how can you un-set a given *level* ?!?
As explained in the thread, semantically it doesn't make much sense and that's why I was explaining I was modifying my patchset to remove that, and use "logging level default <loglevel>" instead, which better describes the action (setting the default log level to <loglevel>, meaning unset categories/subystems will use that log level).
These modifications are already presnet in th new version of the patchset I submited 1-2 weeks ago in gerrit.
Hi Vadim,
as I'm back from holidays, I'm catching up with mails, including this thread here.
On Wed, Jul 25, 2018 at 12:10:08AM +0700, Vadim Yanitskiy wrote:
First of all, the change introduces a new special logging level 'unset', which allows one to reset a given category (i.e. unset its custom value):
[..]
!! Resetting DMNCC: # logging level mncc unset
!! So, now DMNCC has no custom log level, it will use !! the default level (in this example it is 'error'):
but what is the "default level"? I assume as you're talking about interactive changes, you are talking about logging to a VTY. What is the default that you fall-back to? Unlike file/syslog targets, the VTY doesn't have any configurable defaults
But (among fixing) this change additionally changes the behaviour of a command for setting the default logging category (i.e. 'logging level all LEVEL'):
!! Initial logging configuration: logging level all error logging level mncc debug logging level pag notice logging level meas debug
!! Changing the default logging level: # logging level all debug
!! Ahhh, I've lost my custom levels :( logging level all debug
!! What I expected to get: logging level all debug logging level mncc debug logging level pag notice logging level meas debug
So, together with changing the default logging category, this command now would also reset all custom settings...
To be honest, I don't think I have any idea at all what "logging level all" does, I have never used it. I find it quite confusing that there are other things than setting the per-subsystem levels. Setting per-subsystem categories makes sense to me, everything else seems strange...
I am not sure this is exactly what one need/expect, so I would like to share the following ideas:
The category 'all' looks/sounds confusing when it's used in such cases like this:
# logging level all debug
because one can interpret it like:
"set all categories to debug".
despite actually (according to the implementation) this is related to the default logging policy.
Maybe, we should rename it to 'default'?
So, 'logging level all LEVEL' would *set all categories* to a given logging LEVEL,
I agree this is more intuitive from the meaning of the word "all", but I think that would be only ever used to set a global "sane" logging level like NOTICE or ERROR. You certainly don't want to set DEBUG on all categories, as otherwise you're going to be spammed and will drown in too much information.
while 'logging level default LEVEL' would only affect the default logging level...
What is the "default logging level" ? The level compiled-into the struct log_info?
The introduced behaviour of resetting all categories to 'unset' could be implemented in a separate function, and can be represented by a separate command:
# logging level unset-all
The name of this command clearly defines the expected behaviour. Moreover, it doesn't affect the default logging level, which can be still changed by a separate command.
How would you ever change the default? I thought that's the compiled-in part?
Resetting the current logging masks to those default compiled-in ones by a single command seems like a useful feature to me. My practical work-around for this is to simply close + re-open the VTY session...
Hi Harald,
as I'm back from holidays, I'm catching up with mails, including this thread here.
Nice to see you are back :)
I didn't expect this thread would grow so much. Probably, because we started to discuss the new features... But let's focus on the initial thread topic.
but what is the "default level"? What is the default that you fall-back to?
I mean the global log level of a logging target, please see:
https://git.osmocom.org/libosmocore/tree/include/osmocom/core/logging.h#n243
At the moment, it can be set with 'logging level all LEVEL', but anyway it doesn't work as expected, please see:
https://osmocom.org/issues/3409
and this change by Pau which still mixes new features with actual bugfixing (src/logging.c#479):
https://gerrit.osmocom.org/10116/
For some reason, I do associate libosmocore's logging subsystem with iptables. Please don't think I am crazy, there are really some similarities:
- Instead of filtering packets, we are filtering the logging messages;
- Logging target (e.g. stderr, or a file) is like a chain;
- The global log level of a logging target (I usually refer this as 'the default logging level') is like the default policy of a chain;
- If a logging category (e.g. 'meas' or 'l1c') has a custom logging level (e.g. 'debug'), one may interpret this as a rule in a chain. If there is no rule for a given category the default logging level can be used (like default policy).
To be honest, I don't think I have any idea at all what "logging level all" does,
Meanwhile, we do have this line in some sample configuration files, and if there is no this line, we always have the following result of calling 'show running-config' or 'write file':
logging level all everything
This is why we (at least me and Pau) would like to introduce an idea of a bit more self-explaining command:
logging level default debug
Setting per-subsystem categories makes sense to me, everything else seems strange...
Well, I think it makes sense to have some global / default logging level (e.g. 'error'), and a set of per-subsystem levels. For example, I would like to debug some particular subsystem / category (e.g. DMNCC), and silence all other:
logging level default error logging level mncc debug
Another important feature (I think) is a possibility to unset either a particular subsystem / category, or all subsystems / categories, which would fall-back to value of the default logging level for the current target.
For example, I am running a program with the following logging configuration:
logging level default notice logging level mncc debug logging level pag error logging level l1c debug logging level l1d info ...
and now I would like to debug DPAG at run-time, so I could unset all custom values from VTY, and set DPAG to 'debug':
(VTY)# logging level default error (VTY)# logging level all unset (VTY)# logging level pag debug
Result:
logging level default error logging level pag debug
Finally, let's conclude my ideas in short all in one place:
- Introduce 'unset' keyword;
- Introduce self-explaining 'logging level default ...' which is aimed to set the (default / global) log level of a given logging target (e.g. 'stderr');
- Modify the behaviour of 'logging level all ...' to affect all logging categories (e.g. 'logging level all unset' would unset all custom user-defined levels, 'logging level all error' would sett all to 'error').
P.S. Sorry for 'the default', I hope this explaination is better.
With best regards, Vadim Yanitskiy.
Hi,
I think Vadim did a pretty good explanation and I think we agree on most points here. Please correct me if I'm wrong. As far as I understand, my patchset implements the points Vadim suggested at the end of his last e-mail.
And answering gerrit's comment from Harald: "Do we really have no more pressing needs than re-desinging/defining how the log configuration works?"
I want to state again that my patchset is aiming at fixing something broken without trying to redefine or completely redesign the logging system, because indeed I didn't want to spend much time in this, only a few hours required to fix the issue and make it usable, because I'm always losing time and not trusting the logging system due to this broken behavior. I'm the first one not willing to invest lots of hours into this, just get something good enough that works fine.
With a bit of time passed, I am revisiting this.
It seems that my plan to have a per-subsystem configurable default log level as well as a per-subsystem configurable elevated/silenced log level is pretty much off the table.
So then, for me that means it opens the door to accept Pau's patch.
There was other criticism though:
You certainly don't want to set DEBUG on all categories, as otherwise you're going to be spammed and will drown in too much information.
For some programs (osmo-hlr, osmo-msc, osmo-bsc) it does actually make perfect sense to set everything to DEBUG in a lab environment. That's why the brokenness of 'logging level all debug' is so annoying. You think you've set each and every log level to debug, but for some obscure reason still some logging is missing.
Similarly, if I want to silence all logging except ERRORs, 'logging level all error' is a very useful command -- if it works the way that it sounds.
"Do we really have no more pressing needs than re-desinging/defining how the log configuration works?"
Above annoyance is recurring and hindering everything else by constant uncertainty of what is being logged and/or the need to consider each individual logging category all the time.
while 'logging level default LEVEL' would only affect the default logging level...
What is the "default logging level" ? The level compiled-into the struct log_info?
The "default" would be a single global setting for all categories. I sense a conflict between the "default" level and the struct log_info compiled-in defaults. Would the "default" level override the compiled-in defaults? Would the "default" have no effect until the vty command is issued? Or would the "default" have no effect until we call 'unset-all' to "unset" the initial levels copied from struct log_info levels?
Now that I've accepted that we will not have a per-category adjustable default level, I think we might as well just stay with the compiled-in log_info defaults, and not introduce another default level.
I want to be able to change all categories' current levels to "DEBUG" or "ERROR" with a single command, but I don't really have a need for a common default to fall back to. (Instead I would again set 'all' to that level.)
So I've swerved 180° and now think that even the proposed one common default level across all categories is more complexity than we need.
Can we fix 'logging level all foo' separately, without introducing more defaults first? We can then still consider the default,unset feature on its own.
~N
Hi Neels,
On Thu, Aug 30, 2018 at 04:05:45PM +0200, Neels Hofmeyr wrote:
With a bit of time passed, I am revisiting this.
It seems that my plan to have a per-subsystem configurable default log level as well as a per-subsystem configurable elevated/silenced log level is pretty much off the table.
So then, for me that means it opens the door to accept Pau's patch.
At this point, I am sorry to say the topic has somehow become somewhat of a "red flag" to me. So I'll hereby bestow you with the title of "Osmocom Supreme Chief Logging Officer" and you get all the freedom to decide how you'd like to change it, as you see fit.
My rough outline is: * try to handle existing config files in a useful way, without obvious breakage * make sure all documentation is updated at the very same time as the change is merged, so that user manuals / vty reference / wiki / etc. are correct.
This is without bitterness, don't get me wrong. I just don't feel like I can come to a good conclusion here, and hence I delegate it and make it your problem :P
Regards, Harald