[Users] VSDM´s logrotate makes Hosts fill up var eventually

[Gianluca Cecchi]

On Thu, Jan 9, 2014 at 5:33 PM, Dan Kenigsberg wrote:

>
> The question of how much logging we should keep is a tough one. I, as a
> developer, would like to have as much as possible. For long-running busy
> systems, it has happened to me that the core bug was spotted in
> vdsm.log.67 or so.
>
> However, I understand that verbosity has its price. To understand
> whether we are stable enough to change the defaults, I need volunteers:
> people who are willing to change their log level to INFO or WARNING, and
> see if they miss useful information from their logs.
>
> When you make you log level higher, you can lower the number of kept
> log files, as they would not be filled as quick.
>
> Would you, users@, help me with hard data?
>
> Dan.

I can't tell about missing information because at the moment I didn't
had big problmes since in my case I put logging to INFO where there
was DEBUG on 17 December for both vdsm and supervdsm.
This is a very calm infra composed by two nodes f19 oVirt 3.3.2 stable
repo and GlusterFS datcenter.
Only 3 VMS running about everytime

Rotation has not yet overwritten old log files
Under /var/log/vdsm now
# du -sh .
137M .
# ll supervdsm.log*|wc -l
106
# ll vdsm.log*|wc -l
113

For vdsm logs:
before I had 5 daily generated files for an overall of about 100Mb
uncompressed, now one file per day of about 14Mb uncompressed
A newer log
-rw-r--r--. 1 vdsm kvm    429380 Jan  7 12:00 vdsm.log.1.xz

A before change log sequence
-rw-r--r--. 1 vdsm kvm   660280 Dec  8 22:01 vdsm.log.36.xz
-rw-r--r--. 1 vdsm kvm   659672 Dec  8 17:01 vdsm.log.37.xz
-rw-r--r--. 1 vdsm kvm   662584 Dec  8 12:01 vdsm.log.38.xz
-rw-r--r--. 1 vdsm kvm   655232 Dec  8 07:01 vdsm.log.39.xz
-rw-r--r--. 1 vdsm kvm   657832 Dec  8 02:00 vdsm.log.40.xz

For supervdsm logs no rotation yet after change, because size is set
to 15M in logrotate conf files:
Before change I had one file a day (uncompressed daily size was about 17-20Mb)
# ls -lt super*
-rw-r--r--. 1 root root 12620463 Jan  7 12:57 supervdsm.log
-rw-r--r--. 1 root root   342736 Dec 16 16:01 supervdsm.log.1.xz
-rw-r--r--. 1 root root   328952 Dec 15 14:00 supervdsm.log.2.xz
-rw-r--r--. 1 root root   343360 Dec 14 13:01 supervdsm.log.3.xz
-rw-r--r--. 1 root root   339244 Dec 13 11:00 supervdsm.log.4.xz
-rw-r--r--. 1 root root   349012 Dec 12 09:00 supervdsm.log.5.xz

I got a problem with SPM on 7 anuary and I correctly found in vdsm.log
Thread-7000::INFO::2014-01-07
15:42:52,632::logUtils::44::dispatcher::(wrapper) Run and protect:
disconnectStorageServer(domType=7, sp
UUID='eb679feb-4da2-4fd0-a185-abbe459ffa70', conList=[{'port': '',
'connection': 'f18ovn01.mydomain:gvdata', 'iqn': '', 'portal'
: '', 'user': '', 'vfs_type': 'glusterfs', 'password': '******', 'id':
'9d01b8fa-853e-4720-990b-f86bdb7cfcbb'}], options=None)
Thread-7001::INFO::2014-01-07
15:42:54,776::logUtils::44::dispatcher::(wrapper) Run and protect:
getAllTasksStatuses(spUUID=None, opti
ons=None)
Thread-7001::ERROR::2014-01-07
15:42:54,777::task::850::TaskManager.Task::(_setError)
Task=`2e948a29-fdaa-4049-ada4-421c6407b037`::Une
xpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 857, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 2109, in getAllTasksStatuses
    raise se.SpmStatusError()
SpmStatusError: Not SPM: ()
Thread-7001::INFO::2014-01-07
15:42:54,777::task::1151::TaskManager.Task::(prepare)
Task=`2e948a29-fdaa-4049-ada4-421c6407b037`::abort
ing: Task is aborted: 'Not SPM' - code 654
Thread-7001::ERROR::2014-01-07
15:42:54,778::dispatcher::67::Storage.Dispatcher.Protect::(run)
{'status': {'message': 'Not SPM: ()', '
code': 654}}

So I think it is good for me, otherwise I would have great
difficulties identifying problems inside the big files produced

Gianluca