URL:
<http://savannah.cern.ch/bugs/?88357>
Summary: xrootd per-day log file naming - trouble with DST
change?
Project: XROOTD
Submitted by: iven
Submitted on: 2011-11-01 10:28
Severity: 2 - Minor
Priority: 5 - Normal
Status: None
Privacy: Public
Assigned to: None
Originator Email:
Open/Closed: Open
Discussion Lock: Any
Fixed by commit(s):
_______________________________________________________
Details:
We've seen some odd behaviour with respect to the xrootd log file naming on
the night when DST got switched off (we have a cron job that ought to
compress the resulting file, runs at 00:30, and predictably caused lots of
mails about existing files.. and required manual cleanup).
On an example machine:
-rw-r--r-- 1 stage st 229532 Oct 29 23:59
/var/log/xroot/server/xrdlog.server.20111029.gz
-rw-r--r-- 1 stage st 256592 Oct 30 22:59
/var/log/xroot/server/xrdlog.server.20111030.gz
-rw-r--r-- 1 stage st 2416944 Oct 31 22:59
/var/log/xroot/server/xrdlog.server.20111030
-rw-r--r-- 1 stage st 782648 Nov 1 08:56
/var/log/xroot/server/xrdlog.server
So somehow our log rotation managed to get a copy of xrdlog.server.20111030
and compress it, only for it to appear again under the same name, with the
same timestamp?
The two log files are actually different and nicely line up:
[root@lxfsrb57a02 logrotate.d]# zcat
/var/log/xroot/server/xrdlog.server.20111030.gz| tail
111030 22:59:01 27243 alicesgm.20409:28@lxbst2711 ofs_close: use=1
[log in to unmask]
111030 22:59:01 27243 alicesgm.20409:28@lxbst2711 ofs_close: use=0 fn=dummy
111030 22:59:01 27243 XrootdXeq: alicesgm.20409:28@lxbst2711 disc 0:00:00
111030 22:59:10 27243 alisgm56.31450:23@lxbsu0741 ofs_close: use=1
[log in to unmask]
111030 22:59:10 27243 alisgm56.31450:23@lxbsu0741 ofs_close: use=0 fn=dummy
111030 22:59:49 27243 XrootdXeq:
alicesgm.16262:[log in to unmask] disc 0:41:25
111030 22:59:51 001 XrdInet: Accepted connection from
[log in to unmask]
111030 22:59:51 27243 XrootdXeq:
alicesgm.11918:[log in to unmask] login as alicesgm
111030 22:59:52 27243 alicesgm.11918:[log in to unmask]
ofs_open: castorlfn=/00/28480/7dee278a-0342-11e1-8be1-67c0b04f203d
111030 22:59:52 27243 alicesgm.11918:[log in to unmask]
ofs_open: 4200-40664 [log in to unmask]
[root@lxfsrb57a02 logrotate.d]# head
/var/log/xroot/server/xrdlog.server.20111030
111030 23:00:00 27243 Copr. 2010 Stanford University, xrd version v3.0.4
111030 23:00:00 27243 xrootd [log in to unmask]:1095 running.
111030 23:00:38 001 XrdInet: Accepted connection from
[log in to unmask]
111030 23:00:38 27243 XrootdXeq:
alicesgm.19506:[log in to unmask] login as alicesgm
111030 23:00:38 27243 alicesgm.19506:[log in to unmask]
XrootdProtocol: endsess 27241:24.404093
but the second file got started an hour early - usually xrootd closes/reopens
these file at midnight. The DST switchover happened at 02:00, i.e. way after
the supposed logfile switch (and compression).
I don't get how we could end up with such a situation, unless xroot actually
renamed the file by itself after the cronjob came along (i.e > 00:30) and
also changed the access time.. in which case it seems to have some trouble
coping with such DST changes.
xrootd-server-3.0.4-0
_______________________________________________________
Reply to this item at:
<http://savannah.cern.ch/bugs/?88357>
_______________________________________________
Message sent via/by LCG Savannah
http://savannah.cern.ch/
