Bug#816272: [Pkg-clamav-devel] Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

2016-05-06 23:56 GMT+02:00 Sebastian Andrzej Siewior <
sebast...@breakpoint.cc>:

> The question is now, what did you do to make the logrotate message go
> away? Was it the upgrade to current stable or something else?


Ok, now I've got it, sorry. The problem did occur until shortly before the
update and not at all since, with no other changes that I'm aware of. So
I'd say it was the update, yes.

Cheers,
C.

Bug#816272: [Pkg-clamav-devel] Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Sebastian Andrzej Siewior]

On 2016-05-05 14:31:31 [+0200], Christian Pernegger wrote:
> Hello!
Hi,

> So it seems to me like it has migrated to stable, and a while ago at that,
> or at least volatile / stable-updates. Or am I missing something?

No, this is correct. You reported the bug against 0.98.7+dfsg-0+deb8u1
and this version did not have the change. 

The question is now, what did you do to make the logrotate message go
away? Was it the upgrade to current stable or something else? If it was
the upgrade then yes, it is likely a duplicate of the other bug and can
be closed / merged.

> Cheers,
> C.

Sebastian

Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

Hello!

chris@buddha:~$ LANG=C apt-cache policy clamav-freshclam
clamav-freshclam:
  Installed: 0.99+dfsg-0+deb8u2
  Candidate: 0.99+dfsg-0+deb8u2
  Version table:
 *** 0.99+dfsg-0+deb8u2 0
500 http://ftp.at.debian.org/debian/ jessie/main amd64 Packages
500 http://ftp.at.debian.org/debian/ jessie-updates/main amd64
Packages
100 /var/lib/dpkg/status


changelog.Debian.gz has:
clamav (0.99+dfsg-0+deb8u1) stable; urgency=medium

  [ Andreas Cadhalpun ]
[...]
  * Prevent the logrotate scripts from aborting if reloading/restarting
fails.
Thanks to John Zaitseff. (Closes: #788652)
[...]
 -- Sebastian Andrzej Siewior   Mon, 14 Dec 2015
21:42:04 +0100

So it seems to me like it has migrated to stable, and a while ago at that,
or at least volatile / stable-updates. Or am I missing something?

Cheers,
C.



2016-05-04 21:58 GMT+02:00 Sebastian Andrzej Siewior <
sebast...@breakpoint.cc>:

> On 2016-04-05 10:43:13 [+0200], Christian Pernegger wrote:
> > Hi,
> Hi,
>
> > no error e-mail this week, yay!
> >
> > It looks like this is/was a duplicate of #788652 in the end (at least
> > the clamav-freshclam part of it). If you agree, please close & merge
> > as appropriate.
>
> indeed. This did not yet migrate into stable. What is your change that
> you made to make it go away?
> But you are right. The reload fails if it is started from cron. Not sure
> if the error message is the same :)
>
> > Thank you,
> > Christian
>
> Sebastian
>

Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Sebastian Andrzej Siewior]

On 2016-04-05 10:43:13 [+0200], Christian Pernegger wrote:
> Hi,
Hi,

> no error e-mail this week, yay!
> 
> It looks like this is/was a duplicate of #788652 in the end (at least
> the clamav-freshclam part of it). If you agree, please close & merge
> as appropriate.

indeed. This did not yet migrate into stable. What is your change that
you made to make it go away?
But you are right. The reload fails if it is started from cron. Not sure
if the error message is the same :)

> Thank you,
> Christian

Sebastian

Bug#816272: [Pkg-clamav-devel] Bug#816272: Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

Hi,

no error e-mail this week, yay!

It looks like this is/was a duplicate of #788652 in the end (at least
the clamav-freshclam part of it). If you agree, please close & merge
as appropriate.

Thank you,
Christian

Bug#816272: [Pkg-clamav-devel] Bug#816272: Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

Hi again,

sorry for the delay. TBH I was hoping againt hope that this'll just go
away. I've gotten two more error e-mails in the meantime:

21st:
/etc/cron.daily/logrotate:
error: error running non-shared postrotate script for
/var/log/clamav/freshclam.log of '/var/log/clamav/freshclam.log '
gzip: stdin: file size changed while zipping
run-parts: /etc/cron.daily/logrotate exited with return code 1

13th:
/etc/cron.daily/logrotate:
error: error running non-shared postrotate script for
/var/log/clamav/freshclam.log of '/var/log/clamav/freshclam.log '
run-parts: /etc/cron.daily/logrotate exited with return code 1

Question: Is this one error, definitely coming from clamav-freshclam, or
could it be that the gzip line comes from $otherpackage, i.e., would
multiple unrelated errors land in one e-mail?

Verbose output of a forced logrotate run is attached. Nothing about gzip,
just the postrotate script failing. I'm guessing that'd be:

if [ -d /run/systemd/system ]; then
 systemctl -q is-active clamav-freshclam && systemctl kill
--signal=SIGHUP clamav-freshclam
else
 /etc/init.d/clamav-freshclam reload-log > /dev/null
fi

Now "[ -d /run/systemd/system ]" obviously holds, "systemctl -q is-active
clamav-freshclam && echo test" prints nothing (as expected) so this should
be a no-op. $? is 3, though, maybe that's interpreted as failure?

Regards
Christian


logrotate.log
Description: Binary data

Bug#816272: [Pkg-clamav-devel] Bug#816272: Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Sebastian Andrzej Siewior]

On 2016-03-06 12:30:59 [+0100], Christian Pernegger wrote:
> > When you select `cron' in debconf then it will roll the big dice
> Tried that yesterday, result:
> 18 */12 * * *clamav [ -x /usr/bin/freshclam ] &&
> /usr/bin/freshclam --quiet >/dev/null
> 
> It now runs at 18 past noon and midnight, but I still got a
> (different) error e-mail this morning:
> /etc/cron.daily/logrotate:
> error: error running non-shared postrotate script for
> /var/log/clamav/freshclam.log of '/var/log/clamav/freshclam.log '
> run-parts: /etc/cron.daily/logrotate exited with return code 1

now there is nothing.

> Maybe that's just an artefact of the recent debconf run, we'll see in a week.
> 
> > So *I* really think just adding the extra option to lograte is the simplest
> > thing to do.
> 
> I'd love to but it is already in there as standard:

yes, indeed. I somehow though that it was not. But that makes no sense
then. It rotates the freshclam.log to freshclam.log.0 on the first week
and on the second week it performs gzip on freshclam.log.0. freshclam
should no longer have a handle on it.
Could you try to force a lograte? The -v option of lorotate might give
more information on what is going on.

> Christian

Sebastian

Bug#816272: [Pkg-clamav-devel] Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

2016-03-05 23:07 GMT+01:00 Sebastian Andrzej Siewior :
> every other? I assumed twice a day.
That's correct, of course, my mistake.

> Btw: is this the cron/ anacron package or systemd's cron stuff?
just plain cron (3.0pl1-127+deb8u1)

> When you select `cron' in debconf then it will roll the big dice
Tried that yesterday, result:
18 */12 * * *clamav [ -x /usr/bin/freshclam ] &&
/usr/bin/freshclam --quiet >/dev/null

It now runs at 18 past noon and midnight, but I still got a
(different) error e-mail this morning:
/etc/cron.daily/logrotate:
error: error running non-shared postrotate script for
/var/log/clamav/freshclam.log of '/var/log/clamav/freshclam.log '
run-parts: /etc/cron.daily/logrotate exited with return code 1

Maybe that's just an artefact of the recent debconf run, we'll see in a week.

> So *I* really think just adding the extra option to lograte is the simplest
> thing to do.

I'd love to but it is already in there as standard:
/var/log/clamav/freshclam.log {
 rotate 12
 weekly
 compress
 delaycompress
 missingok
 create 640  clamav adm
 postrotate
 if [ -d /run/systemd/system ]; then
 systemctl -q is-active clamav-freshclam && systemctl kill
--signal=SIGHUP clamav-freshclam
 else
 /etc/init.d/clamav-freshclam reload-log > /dev/null
 fi
 endscript
 }

Christian

Bug#816272: [Pkg-clamav-devel] Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Sebastian Andrzej Siewior]

On 2016-03-05 20:44:33 [+0100], Christian Pernegger wrote:
> Thank you for getting back to me on this.
> 
> Yes, cron.weekly seems to run at 6:47 and the freshclam update every
> other hour at :46 ...

every other? I assumed twice a day. Probably got the numbers wrong.
Btw: is this the cron/ anacron package or systemd's cron stuff?

> I'll try the delaycompress option. Do you know if there's anything I
> can do to fix the root cause, i.e. the two cron jobs running so close
> together? It's a server that runs 24/7, there's plenty of time for
> them to get out of each other's hair.

I don't know if this is the cron daemon optimizing things or if it is really
by chance that cron.weekly runs at :47 while debconf decided :46 is a good
one.

When you select `cron' in debconf then it will roll the big dice and come up
with a number between 0 and 59 for the minute value. hour is just 24/x
depending on the interval you select. It seems you had bad luck and those
two came close together.
So either you edit it manually (/etc/cron.d/freshclam or so) or try again your
luck with debconf. Assuming the minute value gets set to :15 and then out of 
the sudden cron.weekly runs at 6:15 then it might be optimizing on cron's
side (but then this is the first report).
So there is this. I don't know how easy it would be to get both sides using
`flock' so they don't try writting to the same file at the same time. And we
have multiple scenarios like daemon mode, cron mode and so on.
So *I* really think just adding the extra option to lograte is the simplest
thing to do.

> 
> Christian

Sebastian

Bug#816272: [Pkg-clamav-devel] Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

2016-03-04 22:10 GMT+01:00 Sebastian Andrzej Siewior :
> I copied your debconf and it seems to work here. Can you check your logs
> if the freshclam log runs at the same time as your logrorate script?
> I have no idea why but it seems to be the case. Adding `delaycompress'
> to the cron script should fix it.

Thank you for getting back to me on this.

Yes, cron.weekly seems to run at 6:47 and the freshclam update every
other hour at :46 ...

I'll try the delaycompress option. Do you know if there's anything I
can do to fix the root cause, i.e. the two cron jobs running so close
together? It's a server that runs 24/7, there's plenty of time for
them to get out of each other's hair.

Christian

Bug#816272: [Pkg-clamav-devel] Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Sebastian Andrzej Siewior]

On 2016-02-29 12:02:51 [+0100], Christian Pernegger wrote:
> > From: Cron Daemon 
> > To: r...@buddha.southpark.chp
> > Subject: Cron  test -x /usr/sbin/anacron || ( cd / && 
> > run-parts --report /etc/cron.daily )
> >
> > /etc/cron.daily/logrotate:
> > error: error running non-shared postrotate script for 
> > /var/log/clamav/freshclam.log of '/var/log/clamav/freshclam.log '
> > gzip: stdin: file size changed while zipping
> > run-parts: /etc/cron.daily/logrotate exited with return code 1
> 
> No configuration of clamav or freshclam has been done (yet), apart
> from the debconf settings at the bottom of this mail.

I copied your debconf and it seems to work here. Can you check your logs
if the freshclam log runs at the same time as your logrorate script?
I have no idea why but it seems to be the case. Adding `delaycompress'
to the cron script should fix it.

> Regards,
> Christian Pernegger

Sebastian

Bug#816272: clamav-freshclam: logrotate errors out with "gzip: stdin: file size changed while zipping"

[Christian Pernegger]

Package: clamav-freshclam
Version: 0.98.7+dfsg-0+deb8u1
Severity: normal

Hello,

since I've installed clamav-freshclam I get a weekly error message by
e-mail:

> From: Cron Daemon 
> To: r...@buddha.southpark.chp
> Subject: Cron  test -x /usr/sbin/anacron || ( cd / && run-parts 
> --report /etc/cron.daily )
>
> /etc/cron.daily/logrotate:
> error: error running non-shared postrotate script for 
> /var/log/clamav/freshclam.log of '/var/log/clamav/freshclam.log '
> gzip: stdin: file size changed while zipping
> run-parts: /etc/cron.daily/logrotate exited with return code 1

No configuration of clamav or freshclam has been done (yet), apart
from the debconf settings at the bottom of this mail.

Regards,
Christian Pernegger


-- Package-specific info:
--- configuration ---
# Automatically created by the clamav-freshclam postinst
# Comments will get lost when you reconfigure the clamav-freshclam package

DatabaseOwner clamav
UpdateLogFile /var/log/clamav/freshclam.log
LogVerbose false
LogSyslog false
LogFacility LOG_LOCAL6
LogFileMaxSize 0
LogRotate true
LogTime true
Foreground false
Debug false
MaxAttempts 5
DatabaseDirectory /var/lib/clamav
DNSDatabaseInfo current.cvd.clamav.net
AllowSupplementaryGroups false
ConnectTimeout 30
ReceiveTimeout 30
TestDatabases yes
ScriptedUpdates yes
CompressLocalDatabase no
SafeBrowsing false
Bytecode true
DatabaseMirror db.at.clamav.net
DatabaseMirror database.clamav.net

--- data dir ---
total 179504
-rw-r--r-- 1 clamav clamav 75879 Feb 10 18:20 bytecode.cvd
drwxr-xr-x 2 clamav clamav  4096 Feb 22 12:52 
clamav-4d66ff37073e2760f1f527f86d9f6696.tmp
-rw-r--r-- 1 clamav clamav 119002112 Feb 28 12:46 daily.cld
-rw-r--r-- 1 clamav clamav  64720632 Feb 10 18:20 main.cvd
-rw--- 1 clamav clamav   104 Feb 29 00:46 mirrors.dat

-- System Information:
Debian Release: 8.3
  APT prefers stable
  APT policy: (990, 'stable'), (500, 'stable-updates')
Architecture: amd64 (x86_64)

Kernel: Linux 3.16.0-4-amd64 (SMP w/4 CPU cores)
Locale: LANG=de_AT.UTF-8, LC_CTYPE=de_AT.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages clamav-freshclam depends on:
ii  clamav-base0.98.7+dfsg-0+deb8u1
ii  debconf [debconf-2.0]  1.5.56
ii  dpkg   1.17.26
ii  init-system-helpers1.22
ii  libc6  2.19-18+deb8u3
ii  libclamav6 0.98.7+dfsg-0+deb8u1
ii  libssl1.0.01.0.1k-3+deb8u2
ii  logrotate  3.8.7-1+b1
ii  lsb-base   4.1+Debian13+nmu1
ii  procps 2:3.3.9-9
ii  ucf3.0030
ii  zlib1g 1:1.2.8.dfsg-2+b1

clamav-freshclam recommends no packages.

Versions of packages clamav-freshclam suggests:
pn  apparmor 
pn  clamav-docs  

-- debconf information:
* clamav-freshclam/PrivateMirror:
* clamav-freshclam/LogRotate: true
* clamav-freshclam/Bytecode: true
* clamav-freshclam/NotifyClamd: false
* clamav-freshclam/SafeBrowsing: false
* clamav-freshclam/http_proxy:
  clamav-freshclam/internet_interface:
* clamav-freshclam/local_mirror: db.at.clamav.net (Austria)
  clamav-freshclam/proxy_user:
* clamav-freshclam/update_interval: 2
* clamav-freshclam/autoupdate_freshclam: cron