Summary:	ASTERISK-21168: asterisk logger stops logging VERBOSE and NOTICE messages after some time.
Reporter:	Nikola Ciprich (nikola.ciprich)	Labels:
Date Opened:	2013-02-26 04:26:39.000-0600	Date Closed:	2013-05-10 16:41:46
Priority:	Major	Regression?	No
Status:	Closed/Complete	Components:	Resources/General
Versions:	1.8.20.1	Frequency of Occurrence	Occasional
Related Issues:
Environment:	RHEL5	Attachments:	( 0) asterisk.conf ( 1) logger.conf
Description:	We're usually using notice,warning,error,debug,verbose logging on our asterisk boxes. (either to file, or using syslog). however, it's happening, that after some time asterisk starts logging only WARNING/ERROR messages. We usually find out when we need to investigate some problem, that logs are incomplete... What is strange is, that when asterisk console is connected (using asterisk -rvvvvvvv), logging immetiately starts working, on the other side, forcing logger reload using "asterisk -rx "logger reload") doesn't help.. We've observed this behaviour on wide variety of versions from 1.4.x to 1.8.x.
Comments:	By: Rusty Newton (rnewton) 2013-02-27 17:52:49.439-0600 If we can't reproduce this issue, there is nothing we can do. You'll need to help us by looking into what happens around the time the logger stops logging. Please attach your logger.conf and asterisk.conf files. (More Actions > Attach files) You could also add the message type DEBUG, and after the issue occurs provide us the full log so we look at whats going on right before the issue occurs. In general, we'll need more specific information about what is happening on the system, what is happening in Asterisk and need any relevant configuration files. By: Nikola Ciprich (nikola.ciprich) 2013-03-02 11:00:03.594-0600 logger.conf and asterisk.conf as requested by Rusty Newton By: Nikola Ciprich (nikola.ciprich) 2013-03-02 11:26:19.360-0600 There doesn't seem to by anything logged during/prior to time logging stops.. I'll try to enable core debugging on some of the less loaded boxes to see whether I'm able to catch anything interesting.. By: Nikola Ciprich (nikola.ciprich) 2013-03-09 08:56:37.386-0600 just to let You know, I've enabled core debugging (lvl 10) on three asterisk boxes on which I've experienced the problem (one is 1.4.41, one 1.8.17, one 1.8.20.1). I'll report as soon as problem occurs.. By: Rusty Newton (rnewton) 2013-03-25 13:13:11.983-0500 Okay - we'll leave this open for a few weeks to see what you find. We'll only care about the debug from the support versions of course.. That would be 1.8.X or 11 right now. By: Rusty Newton (rnewton) 2013-04-09 15:36:42.707-0500 I don't see anything obvious from the config files. We haven't had any additional reports of this issue. Have you been able to gather any additional information that would allow us to reproduce it? By: Nikola Ciprich (nikola.ciprich) 2013-04-10 01:17:44.300-0500 Hi Rusty, it's pretty anoying, but no.. on all boxes on which I've enabled debugging, logging works.. on another ones on which I didn't, logging stops.. so it can be somehow related.. however I don't know how to proceed now.. I'm considering I'll just have debugging enabled on all boxes and filter debug messages in syslog :-( By: Rusty Newton (rnewton) 2013-04-10 13:54:36.101-0500 {quote} "on all boxes on which I've enabled debugging, logging works.. on another ones on which I didn't, logging stops.. so it can be somehow related." {quote} Can you explain more what you mean here? By "enabled debugging" do you mean just enabling DEBUG messages in logger.conf for a file or syslog? Can you attach a separate logger.conf for both a machine that you have "enabled debugging" for and one for which you didn't. By: Nikola Ciprich (nikola.ciprich) 2013-04-10 14:55:39.664-0500 "core set debug 10" (I think) config file is the same as one attached.. By: Rusty Newton (rnewton) 2013-04-10 16:54:20.507-0500 so to confirm - DEBUG messages are enabled on both the systems that seem to fail and the ones that appear fine, but on the ones that fail at some point you have changed the level of DEBUG by using the CLI command? Can you tell us the following about the systems that exhibit the behavior and the ones that don't: * Has Asterisk been started with any number of -v or -d flags? * Is asterisk.conf identical to the one you posted here? (that is with no verbose= or debug= options set?) By: Nikola Ciprich (nikola.ciprich) 2013-04-11 07:46:53.910-0500 so to confirm - DEBUG messages are enabled on both the systems that seem to fail and the ones that appear fine, but on the ones that fail at some point you have changed the level of DEBUG by using the CLI command? - actually it's the opposite. Yes, I have debug messages logging enabled on both failing and nonfailing systems. On (failing) systems when I've enabled debugging using core set debug 10 as I was requested, problem vanished.. Can you tell us the following about the systems that exhibit the behavior and the ones that don't: Has Asterisk been started with any number of -v or -d flags? - no -v's, no -d's Is asterisk.conf identical to the one you posted here? (that is with no verbose= or debug= options set?) - yes, no verbose, no debug mention in asterisk.conf By: Rusty Newton (rnewton) 2013-04-17 17:46:15.813-0500 Okay, and to clarify the behavior further The problem appears to occur on machines (Ast version 1.4.x - 1.8.x) where debug messages are enabled in logger.conf (possibly along with other message types) and you have *not* changed the debug level with a CLI command. When the problem occurs, the logs consist of only WARNING and ERROR messages, but no other types - where you would have expected additionally DEBUG messages at least to be written as well? If that is the case.. then there are plenty of other users who should be seeing the same issue. I've had systems run in that situation for long periods and haven't observed the problem as well. You may want to post ALL of your Asterisk configs (sanitized) to this issue. That way even if we have to close it for now (we can't reproduce it) then they'll be there for comparison in case another user reports this at some point. By: Walter Doekes (wdoekes) 2013-04-22 08:12:58.216-0500 Isn't this intended? If there is no debug=N and no verbose=N, then no logging of those messages occur. First when rasterisk is started with -vvv, then the verbose log level goes up and logging starts. That's why I have: {noformat} debug=0 verbose=20 {noformat} In my asterisk.conf. Looks to me like a configuration problem.. By: Nikola Ciprich (nikola.ciprich) 2013-04-22 08:17:37.968-0500 Hello Rusty, Walter. I'm not sure... the problem is, that it IS logging properly, but after some period of time it just stops without any apparent reason... I'll try adding verbose=20 though and report if it makes any difference. By: Rusty Newton (rnewton) 2013-05-10 16:41:46.970-0500 So far we can't reproduce this and haven't seen it elsewhere. If you can find a way to reproduce or narrow it down then we can look into it..