[zypp-devel] Cleaning up YaST log files
Hi, There are several bugreports in bugzilla that YaST logs are still increasing and they're very often impossible to attach them into a bugreport because of 5MB limit. I wrote a simple script that goes through the file given as a parameter and prints the output in this format: Example ------- Log line: 2007-08-27 10:32:48 <0> 10.10.103.73(3944) [parser::susetags] RepoParser.cc(parse):424 ReferenceCounted(@0xb4656f70<=1) Output: $VAR1 = { 'parser::susetags' => { 'RepoParser.cc' => { '0' => { 'count' => 1, 'size' => 72, } ... } ... } ... } The script is not ideal but could provide some hints where to look and which logs to remove or minimize. Without any offense, the biggest 'sinner' ;) is libzypp. I've used y2log-1 from bug #304815 as an example. The format is: Source File | Log Level | Count | Total Size in Bytes QueueItemRequire.cc 1 1956 285.556 0 450 88.196 ContextPool.cc 0 6145 844.020 Exception.cc 5 7807 1.531.198 Resolver.cc 1 6630 886.471 0 12858 1.664.251 MediaCurl.cc 0 5900 968.752 ResolverUpgrade.cc 1 15506 2.675.810 ExternalProgram.cc 0 7479 1.145.172 The log file has 15.601.918 bytes in total... Entries mentioned above are just an example and I know that common libzypp developer can find more information that I did in the output. Both the script and the exemplary output have been attached. Please, remove as much logs (mostly debugging entries) as you can. Thanks Lukas -- Lukas Ocilka, YaST Developer (xn--luk-gla45d) ----------------------------------------------------------------- SUSE LINUX, s. r. o., Lihovarska 1060/12, Praha 9, Czech Republic
Lukas Ocilka wrote:
Hi,
There are several bugreports in bugzilla that YaST logs are still increasing and they're very often impossible to attach them into a bugreport because of 5MB limit.
We've also found this kind of entries: Measure -> Measure.cc -> 5 Count: 103 Size: 12878 Although it is only 12 kB in that log, Duncan told me that nobody has really ever used these logs for anything so it seems that they only make libzypp a bit slower and logs bigger. Please, remove then or do not turn them on by default. In my opinion, they could be very useful but only when we focus on such task so some nice variable: ZYPP_MEASURE=1 could be better than complete removing. That's on you... Thanks & Bye Lukas
Lukas Ocilka wrote:
Lukas Ocilka wrote:
Hi,
There are several bugreports in bugzilla that YaST logs are still increasing and they're very often impossible to attach them into a bugreport because of 5MB limit.
We've also found this kind of entries: Measure -> Measure.cc -> 5 Count: 103 Size: 12878
Maybe I should have told you more about the reason why minimized logging is worth investing your time. Installation of SUSE/openSUSE Linux needs quite a lot of memory because it uses virtual system (in memory) also for logging. Very often no swap is activated until the disk is formatted and installation really starts. YaST logs are not rotated during the installation and compression on-the-fly also seems to be very uneasy. So, all logs are stored in the uncompressed textual form. During upgrade, when there are several repositories available, the log sometimes take take tenths or even hundreds of megabytes. I'd like to point out some issues how logging could be optimized. Quite easy seems to be remove duplicated data stored into the log. See this example: --- example --- Source.cc(ScanProductsWithCallBacks):75 Scanning products in ftp://10.10.0.100/install/SLP/openSUSE-10.3-Build936-DVD/i386/DVD1 ... MediaAccess.cc(open):109 Trying scheme 'ftp' MediaCurl.cc(MediaCurl):177 MediaCurl::MediaCurl(ftp://10.10.0.100/install/SLP/openSUSE-10.3-Build936-DVD/i386/DVD1,) MediaAccess.cc(open):141 Opened: ftp(ftp://10.10.0.100/install/SLP/openSUSE-10.3-Build936-DVD/i386/DVD1 not attached; localRoot "") MediaManager.cc(open):426 Opened new media access using id 1 to ftp://10.10.0.100/install/SLP/openSUSE-10.3-Build936-DVD/i386/DVD1 --- example --- What's wrong there? The very same URL is logged four-times even if it would be enough to log it only once or twice. We don't use several threads so it's easy to track the URL in log-lines above. And even if we used several threads, there is always a PID written into the log. Please, try to remove such issues from the libzypp code. Thanks Lukas
Lukas Ocilka wrote:
I've used y2log-1 from bug #304815 as an example. The format is: Source File | Log Level | Count | Total Size in Bytes
QueueItemRequire.cc 1 1956 285.556 0 450 88.196 ContextPool.cc 0 6145 844.020 Exception.cc 5 7807 1.531.198 Resolver.cc 1 6630 886.471 0 12858 1.664.251 MediaCurl.cc 0 5900 968.752 ResolverUpgrade.cc 1 15506 2.675.810 ExternalProgram.cc 0 7479 1.145.172
There are logged messages with level 0, they should be logged only when debug logging is enabled. I should fix the redirection in pkg-bindings to check the level. That would considerably decrease the amount of logged messages without any change in zypp... If you are removing a log message consider using the debug level (level 0) if the message might be useful in some situation later. It's usually easy to ask the reporter to enable debug and reproduce the problem again if you need more information for debugging. -- Best Regards Ladislav Slezák Yast Developer ------------------------------------------------------------------------ SUSE LINUX, s.r.o. e-mail: lslezak@suse.cz Lihovarská 1060/12 tel: +420 284 028 960 190 00 Prague 9 fax: +420 284 028 951 Czech Republic http://www.suse.cz/ -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
On Thursday 30 August 2007 17:08, Ladislav Slezak wrote:
If you are removing a log message consider using the debug level (level 0) if the message might be useful in some situation later. It's usually easy to ask the reporter to enable debug and reproduce the problem again if you need more information for debugging.
Just in case this got lost in too much information:
You can ask bug reporters to turn on debug logging at specific points. With
the Qt UI, Shift-F7 opens a pop-up dialog where you can turn debug logging on
or off.
For example, you can ask a bug reporter to start an installation normally, and
when, say, the proposal dialog is shown, to hit Shift-F7, turn on debug
logging and then go to the package selection.
You might also want to ask him to turn debug logging off again (Shift-F7
again), for example when he is back at the proposal.
Anticipating that remark: Yes, it's documented in the Bug Reporting FAQ.
http://en.opensuse.org/Bugs/YaST#The_y2logs_don.27t_seem_to_show_my_problem....
CU
--
Stefan Hundhammer
Ladislav Slezak napsal(a):
Source File | Log Level | Count | Total Size in Bytes
QueueItemRequire.cc 1 1956 285.556 0 450 88.196 ContextPool.cc 0 6145 844.020 Exception.cc 5 7807 1.531.198 Resolver.cc 1 6630 886.471 0 12858 1.664.251 MediaCurl.cc 0 5900 968.752 ResolverUpgrade.cc 1 15506 2.675.810 ExternalProgram.cc 0 7479 1.145.172
There are logged messages with level 0, they should be logged only when debug logging is enabled. I should fix the redirection in pkg-bindings to check the level. That would considerably decrease the amount of logged messages without any change in zypp...
Fixed in yast2-pkg-bindings-2.15.47. You still need some debug messages for debugging then increase the level. -- Best Regards Ladislav Slezák Yast Developer ------------------------------------------------------------------------ SUSE LINUX, s.r.o. e-mail: lslezak@suse.cz Lihovarská 1060/12 tel: +420 284 028 960 190 00 Prague 9 fax: +420 284 028 951 Czech Republic http://www.suse.cz/ -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Ladislav Slezak schrieb:
If you are removing a log message consider using the debug level (level 0) if the message might be useful in some situation later. It's usually easy to ask the reporter to enable debug and reproduce the problem again if you need more information for debugging.
Do you really think that a beta tester will be able/willing to reproduce an update error again if he has finished an update ? Just a thought..... -- ******************************************************************************* Stefan Schubert SUSE LINUX GmbH - Maxfeldstrasse 5 - D-90409 Nuernberg, Germany e-mail: schubi@suse.de ------------------------------------------------------------------------------- SUSE LINUX Products GmbH, GF: Markus Rex, HRB 16746 (AG Nürnberg) -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Stefan Schubert wrote:
Ladislav Slezak schrieb:
If you are removing a log message consider using the debug level (level 0) if the message might be useful in some situation later. It's usually easy to ask the reporter to enable debug and reproduce the problem again if you need more information for debugging.
Do you really think that a beta tester will be able/willing to reproduce an update error again if he has finished an update ?
Just a thought.....
I also always thought that those <0> debug logs from zypp were intentional there :) We have had them in the YaST log since the zypp was born, don't we? L.
Lukas Ocilka napsal(a):
Stefan Schubert wrote:
Ladislav Slezak schrieb:
If you are removing a log message consider using the debug level (level 0) if the message might be useful in some situation later. It's usually easy to ask the reporter to enable debug and reproduce the problem again if you need more information for debugging.
Do you really think that a beta tester will be able/willing to reproduce an update error again if he has finished an update ?
Just a thought.....
I also always thought that those <0> debug logs from zypp were intentional there :) We have had them in the YaST log since the zypp was born, don't we?
Yes, because nobody has complained of this behavior. So the question is how should we proceed? There are three possibilities: 1) I can revert the change in pkg-bindings, some unnecessary log messages from libzypp should be removed. 2) Leave the change in pkg-bindings and increase log level of really needed debug messages in libzypp. 3) Revert pkg-bindings back and leave libzypp as is (i.e. revert to the previous state) and solve it after 10.3. In the log run we should use 2), libzypp logging should be compatible with yast logging. But we are close to the release, which solution should we choose for 10.3? What do you think? Ladislav -- Best Regards Ladislav Slezák Yast Developer ------------------------------------------------------------------------ SUSE LINUX, s.r.o. e-mail: lslezak@suse.cz Lihovarská 1060/12 tel: +420 284 028 960 190 00 Prague 9 fax: +420 284 028 951 Czech Republic http://www.suse.cz/ -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Ladislav Slezak wrote:
There are three possibilities:
1) I can revert the change in pkg-bindings, some unnecessary log messages from libzypp should be removed.
2) Leave the change in pkg-bindings and increase log level of really needed debug messages in libzypp.
3) Revert pkg-bindings back and leave libzypp as is (i.e. revert to the previous state) and solve it after 10.3.
In the log run we should use 2), libzypp logging should be compatible with yast logging. But we are close to the release, which solution should we choose for 10.3?
What do you think?
Definitely not the option "3" (i.e., leave it as it was). We urgently need to remove a lot of zypp logs from YaST log. It's vitally important YaST is not killed during the installation/update because of "out of memory". Thanks L.
Lukas Ocilka schrieb:
Ladislav Slezak wrote:
There are three possibilities:
1) I can revert the change in pkg-bindings, some unnecessary log messages from libzypp should be removed.
2) Leave the change in pkg-bindings and increase log level of really needed debug messages in libzypp.
3) Revert pkg-bindings back and leave libzypp as is (i.e. revert to the previous state) and solve it after 10.3.
In the log run we should use 2), libzypp logging should be compatible with yast logging. But we are close to the release, which solution should we choose for 10.3?
What do you think?
Definitely not the option "3" (i.e., leave it as it was). We urgently need to remove a lot of zypp logs from YaST log. It's vitally important YaST is not killed during the installation/update because of "out of memory".
Thanks L.
Ok, I will have a look. By the way. In the initial mail there has been blamed the the logfiles has increased over 5 MByte. You have mentiont that this could result to a memory overflow. Does that means that we have only about 5 MByte free memory available in the instsys ? -- ******************************************************************************* Stefan Schubert SUSE LINUX GmbH - Maxfeldstrasse 5 - D-90409 Nuernberg, Germany e-mail: schubi@suse.de ------------------------------------------------------------------------------- SUSE LINUX Products GmbH, GF: Markus Rex, HRB 16746 (AG Nürnberg) -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
By the way. In the initial mail there has been blamed the the logfiles has increased over 5 MByte. You have mentiont that this could result to a memory overflow. Does that means that we have only about 5 MByte free memory available in the instsys ?
No, Schubi, you got it wrong. 5MB is a bugzilla limit for the attachement size. If the logs are larger, bugzilla simply rejects it and users usually post their logs on some public www server I'm a yast2-maintainer of this month and I have to say that some of the y2log attachements are well over 200MB :) Esp. when one reports solver, or libzypp in general issues B. -- \\\\\ Katarina Machalkova \\\\\\\__o YaST developer __\\\\\\\'/_ & hedgehog painter
Katarina Machalkova schrieb:
By the way. In the initial mail there has been blamed the the logfiles has increased over 5 MByte. You have mentiont that this could result to a memory overflow. Does that means that we have only about 5 MByte free memory available in the instsys ?
No, Schubi, you got it wrong. 5MB is a bugzilla limit for the attachement size. If the logs are larger, bugzilla simply rejects it and users usually post their logs on some public www server
I'm a yast2-maintainer of this month and I have to say that some of the y2log attachements are well over 200MB :) Esp. when one reports solver, or libzypp in general issues
B.
OK, you have convinced me. I have all interesting "<0>" logging moved to milestones. ( It was only one) and the others to loglevel "ZYPP_FULLLOG=1". So the normal YaST log should be smaller. Some words to the 200 MB: This is a generated testcase. It includes the complete environment which makes it very easy to reproduce an error. Additional there is a logfile of one solver-run with the option "ZYPP_FULLLOG=1". This testcase is really large but I need this information and it will be generated on demand only. This problem is, that the testcase will be stored under /var/log/YaST/solvertestcase and noone deletes it. So, I assume that there are a lot of bugreports which contain an old testcase which nobody needs and which floods bugzilla ( if it fits:-)) The question is who deletes the testcases after they are not needed anymore ? Greetings Stefan -- ******************************************************************************* Stefan Schubert SUSE LINUX GmbH - Maxfeldstrasse 5 - D-90409 Nuernberg, Germany e-mail: schubi@suse.de ------------------------------------------------------------------------------- SUSE LINUX Products GmbH, GF: Markus Rex, HRB 16746 (AG Nürnberg) -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Stefan Schubert napsal(a): [...]
OK, you have convinced me. I have all interesting "<0>" logging moved to milestones. ( It was only one) and the others to loglevel "ZYPP_FULLLOG=1". So the normal YaST log should be smaller.
OK, thank you. [...]
The question is who deletes the testcases after they are not needed anymore ?
I think that save_y2logs could remove them once they are gzipped. (It optionally can ask the user to confirm the removal.) -- Best Regards Ladislav Slezák Yast Developer ------------------------------------------------------------------------ SUSE LINUX, s.r.o. e-mail: lslezak@suse.cz Lihovarská 1060/12 tel: +420 284 028 960 190 00 Prague 9 fax: +420 284 028 951 Czech Republic http://www.suse.cz/ -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Ladislav Slezak schrieb:
I think that save_y2logs could remove them once they are gzipped. (It optionally can ask the user to confirm the removal.)
Who takes care about it ? Greetings Stefan -- ******************************************************************************* Stefan Schubert SUSE LINUX GmbH - Maxfeldstrasse 5 - D-90409 Nuernberg, Germany e-mail: schubi@suse.de ------------------------------------------------------------------------------- SUSE LINUX Products GmbH, GF: Markus Rex, HRB 16746 (AG Nürnberg) -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Stefan Schubert napsal(a):
Ladislav Slezak schrieb:
I think that save_y2logs could remove them once they are gzipped. (It optionally can ask the user to confirm the removal.)
Who takes care about it ?
AFAIK Stefan Hundhammer is the original developer. -- Best Regards Ladislav Slezák Yast Developer ------------------------------------------------------------------------ SUSE LINUX, s.r.o. e-mail: lslezak@suse.cz Lihovarská 1060/12 tel: +420 284 028 960 190 00 Prague 9 fax: +420 284 028 951 Czech Republic http://www.suse.cz/ -- To unsubscribe, e-mail: zypp-devel+unsubscribe@opensuse.org For additional commands, e-mail: zypp-devel+help@opensuse.org
Stefan Schubert wrote:
Ok, I will have a look.
By the way. In the initial mail there has been blamed the the logfiles has increased over 5 MByte. You have mentiont that this could result to a memory overflow. Does that means that we have only about 5 MByte free memory available in the instsys ?
The initial mail was based on a common installation log. It hasn't been told anything about "how much it increased", there were only examples of some parts of zypp that fill the log with the total size occupied by them. Of course, there are several other ones that filled it with 400kB, 240kB, etc, but then I would how to mention all parts with more than *n* kB :) Of course, not every installation/upgrade ends up with oom-killer in action, it just sometimes happens, mainly when solver has several solutions and tries to find the best one. Several conflicts can product so big log, that the memory is just not enough. It can't be said: we have only 5 or 50 or 500 MB of free memory. RAM in every computer is (almost) always variable. Bye Lukas
On Friday 31 August 2007 09:16, Ladislav Slezak wrote:
I also always thought that those <0> debug logs from zypp were intentional there :) We have had them in the YaST log since the zypp was born, don't we?
Yes, because nobody has complained of this behavior.
Huh?
Those complaints are as old as libzypp.
https://bugzilla.novell.com/show_bug.cgi?id=163186
This one is marked as "fixed", albeit only at one point logging was reduced.
Frankly, I find it hard to make any use whatsoever of y2logs where any libzypp
action was performed (and there are few that have none), because libzypp
logging typically dominates 95% or more of the y2logs.
While I understand that package management is a very complex matter and
problems can only be tracked down with comprehensive logs, let's _please_
reduce this to a reasonable amount.
Many things are logged 5 times or more, on each function call level. More
often than not, there is little or no information added at each level. Why
not reduce that to one single log line? (And come to think of it, how did it
ever come this far - it's obvious when you start the program for the first
time that most logging is duplicated, triplicated or worse?).
No, all this is not new. And it's not true that nobody complained.
U
--
Stefan Hundhammer
participants (5)
-
Katarina Machalkova -
Ladislav Slezak -
Lukas Ocilka -
Stefan Hundhammer -
Stefan Schubert