spool file not present on disk

For quite a long time (as long as I've used qpsmtpd), I've been getting chmod errors in my logs from the clamdscan plugin. The errors look like this:

(data_post) virus::clamdscan: chmod: /usr/home/qpsmtpd/tmp/1338343891:23427:0: No such file or directory

I've also received a few virus emails, that I expected clamav to have caught. I'm 99% certain the reason they snuck through is because under some circumstances, the clamdscan plugin isn't working. Today I did some research.

To make it easier to test, I abstracted the portions of the clamdscan plugin code that extract the filename and test it.  The subroutine looks like this:

sub get_filename {
    my $self = shift;

    my $filename = $self->qp->transaction->body_filename;

    if ( ! $filename ) {
        $self->log( LOGWARN, "Cannot process due to lack of filename" );
        return;
    }

    if ( ! -f $filename ) {
        $self->log( LOGERROR, "skip, $filename not on disk?" );
        return;
    }

    $self->log( LOGINFO, "pass, found $filename on disk." );
    return $filename;
};

Then I waited for a ham to get delivered, and I posted the full logs here: http://www.tnpi.net/internet/mail/qpsmtpd.html
The most relevant portions are:
92028 354 go ahead
92028 spooling message to disk
92028 (data_post) bogus_bounce: pass, not a bounce
92028 (data_post) basicheaders: pass
92028 (data_post) domainkeys: pass, good
92028 (data_post) spamassassin: pass, Ham, -0.2 < 100
92028 (data_post) dspam: pass, agree, Innocent, 0.99 c
92028 (data_post) virus::clamdscan: skip, /usr/home/qpsmtpd/tmp/1338351693:92028:0 not on disk?
92038 (queue) queue::qmail_2dqueue: (for 92028 ) Queuing qp 92038 to /var/qmail/bin/qmail-queue

In tracking this down, I read through Transaction.pm, where I found this pod:

=head2 body_filename ( )

Returns the temporary filename used to store the message contents; useful for
virus scanners so that an additional copy doesn't need to be made.

Calling C<body_filename()> also forces spooling to disk. A message is not 
spooled to disk if it's size is smaller than 
I<$self-E<gt>config("size_threshold")>, default threshold is 0, the sample
config file sets this to 10000.

and this code:

sub body_filename {
  my $self = shift;
  $self->body_spool() unless $self->{_filename};
  $self->{_body_file}->flush(); # so contents won't be cached
  return $self->{_filename};
}

And it sure looks like that code is working as advertised. But why is the file disappearing from the spool directory before the clamdscan plugin can get at it?  Or is it ever written there at all?   So I copied and pasted that same get_filename() into the dspam plugin, and added a call to it. Here's the results:

2768 354 go ahead
2768 spooling message to disk
2768 (data_post) bogus_bounce: pass, not a bounce
2768 (data_post) basicheaders: pass
2768 (data_post) domainkeys: skip: unsigned
2768 (data_post) spamassassin: pass, Ham, 1.0 < 100
2768 (data_post) dspam: pass, found /usr/home/qpsmtpd/tmp/1338352889:2768:0 on disk.
2768 (data_post) dspam: pass, agree, Innocent, 0.99 c
2768 (data_post) virus::clamdscan: skip, /usr/home/qpsmtpd/tmp/1338352889:2768:0 not on disk?
2779 (queue) queue::qmail_2dqueue: (for 2768 ) Queuing qp 2779 to /var/qmail/bin/qmail-queue
2768 250 Queued! 1338352891 qp 2779 <[email protected]>
2768 dispatching QUIT
2768 221 mail.theartfarm.com closing connection. Have a wonderful day.
2768 click, disconnecting

Huh?  The file is there when dspam runs but it's gone when the clamdscan plugin runs.

Ideas?

Matt

PS: I am not running async. Yet.

`````````````````````````````````````````````````````````````````````````
  Matt Simerson                   http://matt.simerson.net/
  Systems Engineer            http://www.tnpi.net/

  Mail::Toaster  - http://mail-toaster.org/
  NicTool          - http://www.nictool.com/
`````````````````````````````````````````````````````````````````````````