Bug 542538

Summary: logrotate seems to hang every few days.
Product: [Fedora] Fedora Reporter: Steven W. Orr <steveo>
Component: logrotateAssignee: Daniel Novotny <dnovotny>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 10CC: dnovotny, tsmetana
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 3.7.7-2.fc10 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-12-02 04:47:27 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Steven W. Orr 2009-11-30 03:52:43 UTC
Description of problem:
Logrotate hangs on occasion, usually every few days.


Version-Release number of selected component (if applicable):

logrotate-3.7.7-1.fc10.i386
gawk-3.1.6-2.fc10.i386
crontabs-1.10-26.fc10.noarch

From ps auxfw
root      3400  0.0  0.0   3408   944 ?        Ss   Oct16   0:08 crond
root      2012  0.0  0.0   4196  1572 ?        S    04:02   0:00  \_ CROND
root      2013  0.0  0.0   2732  1000 ?        Ss   04:02   0:00  |   \_ /bin/bash /usr/bin/run-parts /etc/cron.daily
root      3792  0.0  0.0      0     0 ?        T    04:50   0:00  |   |   \_ awk -v progname /etc/cron.daily/logrotate progname {?????   print progname ":\n"?????   progname="";????       }????       { print; }
smmsp     3756  0.0  0.0   9404  2836 ?        S    04:50   0:00  |   \_ /usr/sbin/sendmail -FCronDaemon -i -odi -oem -oi -t


How reproducible:
It hangs every few days.

Steps to Reproduce:
1. Just wait for it.
2.
3.
  
Actual results:


Expected results:
Should not hang.

Additional info:
[root@saturn log]# ps aux | grep awk
root      3792  0.0  0.0   2392   732 ?        S    04:50   0:00 awk -v progname /etc/cron.daily/logrotate progname {?????   print progname ":\n"?????   progname="";????       }????       { print; }
root     26434  0.0  0.0   4188   664 pts/5    S+   21:52   0:00 grep awk
[root@saturn log]# cd
[root@saturn ~]#  gdb awk 3792
GNU gdb Fedora (6.8-32.fc10)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu"...
(no debugging symbols found)
Attaching to program: /bin/awk, process 3792
Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /lib/libc.so.6...
(no debugging symbols found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2

(no debugging symbols found)
0x001b0424 in __kernel_vsyscall ()
Missing separate debuginfos, use: debuginfo-install gawk-3.1.6-2.fc10.i386
(gdb) bt
#0  0x001b0424 in __kernel_vsyscall ()
#1  0x00cb1a93 in __read_nocancel () from /lib/libc.so.6
#2  0x0806c21a in ?? ()
#3  0x0806c55a in ?? ()
#4  0x0806d24c in do_input ()
#5  0x0807222f in main ()


Also, please accept my apologies for confusing this hang with a problem reported in 542056. The hang is not part of that bug. It is part of this one.

A couple of observations:

1. In run-parts, there is a for loop

for i in $(LC_ALL=C; echo $1/*[^~,]) ; do

I don't believe this does what is intended (unless I'm missing something). If LC_ALL is a preexisting environment variable then it will be over-ridden, which is what I believe is intended. If it is not previously set then all that happens is that a local variable is being set which has no effect on how the glob expands. If I'm right then a correct way would be (something like)

for i in $(LC_ALL=C echo $1/*[^~,]) ; do

I'm pretty sure this is not part of the problem, but I just wanted to mention it.

2. According to the process tree printout above, we see awk as the child of run-parts but we do not see logrotate in the output at all. Does this mean we have a process cleanup problem?

I did not supply my logrotate.conf files but I'm happy to do so if needed.

3. I see that run-parts calls basename twice but run-parts *is* a bash script. Is not reasonable to use ${i##*/} to replace basename?

The same would then apply to use of [ instead of using [[. Note that [[ provides logical short-circuiting and [ does not.

[[Suggested mod?]]
#!/bin/bash
# run-parts - concept taken from Debian

# keep going when something fails
set +e

if (( $# < 1 )); then
    echo "Usage: run-parts <dir>" 1>&2
    exit 1
fi

if [[ ! -d $1 ]]; then
    echo "Not a directory: $1" 1>&2
    exit 1
fi

# Ignore *~ and *, scripts
for i in $(LC_ALL=C echo $1/*[^~,]) ; do
    # Don't run *.{rpmsave,rpmorig,rpmnew,swp,cfsaved} scripts
     [[ -d $i ||
        "${i%.cfsaved}" != "${i}" ||
        "${i%.rpmsave}" != "${i}" ||
        "${i%.rpmorig}" != "${i}" ||
        "${i%.rpmnew}" != "${i}"  ||
        "${i%.swp}" != "${i}"     ||
        "${i%,v}" != "${i}" ]] && continue

    if [[ -x $i ]]; then
      logger -p cron.notice -t "run-parts($1)[$$]" "starting ${i##*/}"
      $i 2>&1 | awk -v "progname=$i" \
              'progname {
                   print progname ":\n"
                   progname="";
               }
               { print; }'
      logger -i -p cron.notice -t "run-parts($1)" "finished ${i##*/}"
    fi
done

exit 0

Comment 1 Daniel Novotny 2009-11-30 12:56:49 UTC
see Bug 517321 - this was fixed in rawhide
maybe it's a good idea to fix this also in older releases,
I can do this

Comment 2 Fedora Update System 2009-12-01 10:26:29 UTC
logrotate-3.7.8-3.fc11 has been submitted as an update for Fedora 11.
http://admin.fedoraproject.org/updates/logrotate-3.7.8-3.fc11

Comment 3 Fedora Update System 2009-12-01 10:27:34 UTC
logrotate-3.7.7-2.fc10 has been submitted as an update for Fedora 10.
http://admin.fedoraproject.org/updates/logrotate-3.7.7-2.fc10

Comment 4 Fedora Update System 2009-12-02 04:29:11 UTC
logrotate-3.7.8-3.fc11 has been pushed to the Fedora 11 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 5 Fedora Update System 2009-12-02 04:47:23 UTC
logrotate-3.7.7-2.fc10 has been pushed to the Fedora 10 stable repository.  If problems still persist, please make note of it in this bug report.