Menu
▾
▴
[AMaViS-user] Amavisd is dead
|
From: Gordon T. <go...@en...> - 2005-12-01 18:51:40
|
Solaris 9 Amavisd-New 2.3.3 Postfix 2.2.5 SpamAssassin 3.0.2 ClamAV 0.87.1 Can someone help me figure this out? I return from holiday on Monday and my Amavisd is dead. I've been trying to sort this out all week by downloading the latest Perl modules and upgrading to the latest Amavisd-New but its always the same. Below are the relevant sections from my Postfix and Amavisd-New logs (log level 5). Thanks to any and all who may be of assistance. Cheers, Gordon Thagard ------------------------------------------------------ cut here ------------------------------------------------------ # tn localhost 10024 Trying 127.0.0.1... Connected to localhost. Escape character is '^]'. 220 [127.0.0.1] ESMTP amavisd-new service ready quit 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel Connection to localhost closed by foreign host. # tn localhost 10025 Trying 127.0.0.1... Connected to localhost. Escape character is '^]'. 220 horus.eng.fsu.edu ESMTP FAMU-FSU College of Engineering quit 221 Bye Connection to localhost closed by foreign host. POSTFIX LOGS Dec 1 12:42:44 horus postfix/smtp[19180]: [ID 197553 mail.info] 0320620C63: to=<ma...@en...>, relay=127.0.0.1[127.0.0.1], delay=1, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once) Dec 1 12:42:44 horus postfix/smtp[19180]: [ID 197553 mail.info] 0320620C63: to=<dea...@ya...>, relay=127.0.0.1[127.0.0.1], delay=1, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once) AMAVISD LOGS Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17892]: starting. /usr/local/sbin/amavisd at horus.eng.fsu.edu amavisd-new-2.3.3 (20050822) Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17892]: user=amavis, EUID: 11369 (11369); group=amavis, EGID: 184 184 (184 184) Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17892]: Perl version 5.006001 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17892]: INFO: no optional modules: DBD::mysql Sys::Hostname::Long Mail::SPF::Query Net::CIDR::Lite Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Net::Server: Process Backgrounded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Net::Server: 2005/12/01-12:38:00 Amavis (type Net::Server::PreForkSimple) starting! pid(17916) Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Net::Server: Binding to UNIX socket file /var/amavis/amavisd.sock using SOCK_STREAM Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Net::Server: Group Not Defined. Defaulting to EGID '184 184' Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Net::Server: User Not Defined. Defaulting to EUID '11369' Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Amavis::Conf 2.043 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Archive::Tar 1.26 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Archive::Zip 1.16 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module BerkeleyDB 0.27 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Compress::Zlib 1.41 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Convert::TNEF 0.17 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Convert::UUlib 1.051 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module DBI 1.47 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module DB_File 1.811 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module MIME::Entity 5.417 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module MIME::Parser 5.417 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module MIME::Tools 5.417 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Mail::Header 1.66 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Mail::Internet 1.66 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Mail::SpamAssassin 3.000002 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Net::Cmd 2.26 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Net::DNS 0.48 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Net::SMTP 2.29 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Net::Server 0.89 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Razor2::Client::Version 2.67 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Time::HiRes 1.66 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Module Unix::Syslog 0.100 Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Amavis::DB code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Amavis::Cache code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: SQL base code NOT loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: SQL::Log code NOT loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: SQL::Quarantine NOT loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Lookup::SQL code NOT loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Lookup::LDAP code NOT loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: AM.PDP prot code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: SMTP-in prot code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: ANTI-VIRUS code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: ANTI-SPAM code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Unpackers code loaded Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Found $file at /usr/bin/file Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: No $dspam, not using it Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Internal decoder for .mail Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Internal decoder for .asc Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Internal decoder for .uue Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: Internal decoder for .hqx [root@horus amavis]# tail -f amavis.log Dec 1 12:38:00 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: SpamControl: initializing Mail::SpamAssassin Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17916]: SpamControl: done Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: TIMING [total 28 ms] - bdb-open: 28 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: TIMING [total 20 ms] - bdb-open: 20 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: TIMING [total 20 ms] - bdb-open: 20 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: TIMING [total 20 ms] - bdb-open: 20 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: TIMING [total 25 ms] - bdb-open: 25 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: TIMING [total 18 ms] - bdb-open: 18 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: TIMING [total 19 ms] - bdb-open: 18 (100%)100, rundown: 0 (0%)100 Dec 1 12:38:02 horus.eng.fsu.edu /usr/local/sbin/amavisd[17932]: TIMING [total 18 ms] - bdb-open: 18 (100%)100, rundown: 0 (0%)100 Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: loaded base policy bank Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: process_request: suggested_protocol="" on TCP Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 4: was busy, 16.6 ms, total idle 0.000 s, busy 0.017 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.6 ms, total idle 0.001 s, busy 0.017 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250-[127.0.0.1] Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250-PIPELINING Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250-SIZE Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250-8BITMIME Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 3.0 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< XFORWARD NAME=dhcp31069.eng.fsu.edu ADDR=146.201.31.69\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< XFORWARD PROTO=ESMTP HELO=eng.fsu.edu\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.0 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< MAIL FROM:<ur...@en...> SIZE=630907\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) check_mail_begin_task: task_count=1 Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T123901-17924Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T123901-17924/email.txt Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) lookup (debug_sender) => undef, "ur...@en..." does not match Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.1.0 Sender ur...@en... OK Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 53.1 ms, total idle 0.001 s, busy 0.075 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.075 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< RCPT TO:<cut...@en...>\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.1.5 Recipient cut...@en... OK Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.6 ms, total idle 0.002 s, busy 0.077 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.077 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< RCPT TO:<ow...@en...>\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.1.5 Recipient ow...@en... OK Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.002 s, busy 0.078 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.078 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< RCPT TO:<car...@fa...>\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.1.5 Recipient car...@fa... OK Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.2 ms, total idle 0.002 s, busy 0.079 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.079 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< RCPT TO:<han...@fa...>\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.1.5 Recipient han...@fa... OK Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.002 s, busy 0.080 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.003 s, busy 0.080 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< RCPT TO:<lin...@fa...>\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 250 2.1.5 Recipient lin...@fa... OK Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.003 s, busy 0.081 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.003 s, busy 0.081 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< DATA\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T123901-17924: <ur...@en...> -> <cut...@en...>,<ow...@en...>,<car...@fa...>,<han...@fa...>,<lin...@fa...> Received: SIZE=630907 from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17924-01; Thu, 1 Dec 2005 12:39:01 -0500 (EST) Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) ESMTP< .\r\n Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) setting body type: 7BIT (0,0) Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) body hash: 6a73c65e8b9c8f25fd8c61f57c7ff9c5 Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[17924]: (17924-01) Original mail size: 630907; quota set to: 314572800 bytes Dec 1 12:39:01 horus.eng.fsu.edu /usr/local/sbin/amavisd[18196]: TIMING [total 17 ms] - bdb-open: 17 (100%)100, rundown: 0 (0%)100 Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: loaded base policy bank Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: process_request: suggested_protocol="" on TCP Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 4: was busy, 16.8 ms, total idle 0.000 s, busy 0.017 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 5: was idle, 0.6 ms, total idle 0.001 s, busy 0.017 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250-[127.0.0.1] Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250-PIPELINING Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250-SIZE Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250-8BITMIME Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 6: was busy, 2.8 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 5: was idle, 0.4 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP< XFORWARD NAME=mussa1.eng.fsu.edu ADDR=146.201.24.78\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 6: was busy, 1.4 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP< XFORWARD PROTO=ESMTP HELO=mussa1.eng.fsu.edu\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP< MAIL FROM:<mu...@en...> SIZE=2135\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) check_mail_begin_task: task_count=1 Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T123916-17925Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T123916-17925/email.txt Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) lookup (debug_sender) => undef, "mu...@en..." does not match Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250 2.1.0 Sender mu...@en... OK Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 6: was busy, 94.9 ms, total idle 0.001 s, busy 0.117 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.117 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP< RCPT TO:<ny...@ad...>\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 250 2.1.5 Recipient ny...@ad... OK Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 6: was busy, 1.6 ms, total idle 0.002 s, busy 0.119 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.119 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP< DATA\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T123916-17925: <mu...@en...> -> <ny...@ad...> Received: SIZE=2135 from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17925-01 for <ny...@ad...>; Thu, 1 Dec 2005 12:39:16 -0500 (EST) Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) ESMTP< .\r\n Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) setting body type: 7BIT (0,0) Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) body hash: e6754faa0e46ae6e8230a393849a8354 Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[17925]: (17925-01) Original mail size: 2135; quota set to: 1067500 bytes Dec 1 12:39:16 horus.eng.fsu.edu /usr/local/sbin/amavisd[18232]: TIMING [total 18 ms] - bdb-open: 18 (100%)100, rundown: 0 (0%)100 Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: loaded base policy bank Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: process_request: suggested_protocol="" on TCP Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 4: was busy, 16.2 ms, total idle 0.000 s, busy 0.016 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 5: was idle, 0.5 ms, total idle 0.001 s, busy 0.016 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250-[127.0.0.1] Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250-PIPELINING Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250-SIZE Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250-8BITMIME Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 6: was busy, 2.8 ms, total idle 0.001 s, busy 0.019 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.019 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP< XFORWARD NAME=localhost ADDR=127.0.0.1\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 6: was busy, 1.2 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP< XFORWARD PROTO=ESMTP HELO=webmail.eng.fsu.edu\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 6: was busy, 1.0 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP< MAIL FROM:<jc...@en...> SIZE=4290 BODY=8BITMIME\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) check_mail_begin_task: task_count=1 Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T123925-17927Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T123925-17927/email.txt Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) lookup (debug_sender) => undef, "jc...@en..." does not match Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250 2.1.0 Sender jc...@en... OK Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 6: was busy, 41.6 ms, total idle 0.001 s, busy 0.063 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 5: was idle, 0.4 ms, total idle 0.002 s, busy 0.063 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP< RCPT TO:<ith...@ho...>\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 250 2.1.5 Recipient ith...@ho... OK Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 6: was busy, 1.6 ms, total idle 0.002 s, busy 0.064 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.064 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP< DATA\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T123925-17927: <jc...@en...> -> <ith...@ho...> Received: SIZE=4290 BODY=8BITMIME from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17927-01 for <ith...@ho...>; Thu, 1 Dec 2005 12:39:25 -0500 (EST) Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) ESMTP< .\r\n Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) body hash: eb7d4d16e3001301f7cfda510897131e Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[17927]: (17927-01) Original mail size: 4290; quota set to: 2145000 bytes Dec 1 12:39:25 horus.eng.fsu.edu /usr/local/sbin/amavisd[18256]: TIMING [total 16 ms] - bdb-open: 16 (100%)100, rundown: 0 (0%)100 Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: loaded base policy bank Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: process_request: suggested_protocol="" on TCP Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 4: was busy, 34.3 ms, total idle 0.000 s, busy 0.034 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 5: was idle, 0.5 ms, total idle 0.001 s, busy 0.034 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250-[127.0.0.1] Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250-PIPELINING Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250-SIZE Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250-8BITMIME Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 6: was busy, 2.7 ms, total idle 0.001 s, busy 0.037 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.037 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP< XFORWARD NAME=mussa1.eng.fsu.edu ADDR=146.201.24.78\r\n Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 6: was busy, 1.2 ms, total idle 0.001 s, busy 0.038 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.038 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP< XFORWARD PROTO=ESMTP HELO=mussa1.eng.fsu.edu\r\n Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.001 s, busy 0.039 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.039 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP< MAIL FROM:<mu...@en...> SIZE=8019\r\n Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) check_mail_begin_task: task_count=1 Dec 1 12:42:36 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T124236-17928Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T124236-17928/email.txt Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) lookup (debug_sender) => undef, "mu...@en..." does not match Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250 2.1.0 Sender mu...@en... OK Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 6: was busy, 50.2 ms, total idle 0.001 s, busy 0.090 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.090 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP< RCPT TO:<CAS...@pb...>\r\n Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 250 2.1.5 Recipient CAS...@pb... OK Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 6: was busy, 1.9 ms, total idle 0.002 s, busy 0.092 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.092 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP< DATA\r\n Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T124236-17928: <mu...@en...> -> <CAS...@pb...> Received: SIZE=8019 from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17928-01 for <CAS...@pb...>; Thu, 1 Dec 2005 12:42:36 -0500 (EST) Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) ESMTP< .\r\n Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) setting body type: 7BIT (0,0) Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) body hash: 444fb32cfe04037191a872ba6861ff72 Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17928]: (17928-01) Original mail size: 8019; quota set to: 4009500 bytes Dec 1 12:42:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[19182]: TIMING [total 46 ms] - bdb-open: 46 (100%)100, rundown: 0 (0%)100 Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: loaded base policy bank Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: process_request: suggested_protocol="" on TCP Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 4: was busy, 17.2 ms, total idle 0.000 s, busy 0.017 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.7 ms, total idle 0.001 s, busy 0.017 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250-[127.0.0.1] Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250-PIPELINING Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250-SIZE Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250-8BITMIME Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 6: was busy, 3.0 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< XFORWARD NAME=localhost ADDR=127.0.0.1\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< XFORWARD PROTO=ESMTP HELO=webmail.eng.fsu.edu\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.001 s, busy 0.023 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.023 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< MAIL FROM:<ma...@en...> SIZE=75846 BODY=8BITMIME\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) check_mail_begin_task: task_count=1 Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T124244-17929Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T124244-17929/email.txt Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) lookup (debug_sender) => undef, "ma...@en..." does not match Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250 2.1.0 Sender ma...@en... OK Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 6: was busy, 46.5 ms, total idle 0.001 s, busy 0.069 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.069 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< RCPT TO:<ma...@en...>\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250 2.1.5 Recipient ma...@en... OK Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 6: was busy, 1.6 ms, total idle 0.002 s, busy 0.071 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.071 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< RCPT TO:<dea...@ya...>\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 250 2.1.5 Recipient dea...@ya... OK Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 6: was busy, 1.1 ms, total idle 0.002 s, busy 0.072 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.072 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< DATA\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T124244-17929: <ma...@en...> -> <ma...@en...>,<dea...@ya...> Received: SIZE=75846 BODY=8BITMIME from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17929-01; Thu, 1 Dec 2005 12:42:44 -0500 (EST) Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[17929]: (17929-01) ESMTP< .\r\n Dec 1 12:42:44 horus.eng.fsu.edu /usr/local/sbin/amavisd[19301]: TIMING [total 18 ms] - bdb-open: 18 (100%)100, rundown: 0 (0%)100 Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: loaded base policy bank Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: process_request: suggested_protocol="" on TCP Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 4: was busy, 16.6 ms, total idle 0.000 s, busy 0.017 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 5: was idle, 0.6 ms, total idle 0.001 s, busy 0.017 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250-[127.0.0.1] Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250-PIPELINING Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250-SIZE Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250-8BITMIME Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 6: was busy, 2.9 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP< XFORWARD NAME=dingo.eng.fsu.edu ADDR=146.201.26.201\r\n Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP< XFORWARD PROTO=ESMTP HELO=dingo.eng.fsu.edu\r\n Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 6: was busy, 1.2 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP< MAIL FROM:<rc...@en...> SIZE=1184\r\n Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) check_mail_begin_task: task_count=1 Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T124337-17930Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T124337-17930/email.txt Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) lookup (debug_sender) => undef, "rc...@en..." does not match Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250 2.1.0 Sender rc...@en... OK Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 6: was busy, 46.8 ms, total idle 0.001 s, busy 0.069 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.069 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP< RCPT TO:<va...@en...>\r\n Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 250 2.1.5 Recipient va...@en... OK Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 6: was busy, 1.5 ms, total idle 0.002 s, busy 0.070 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.070 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP< DATA\r\n Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T124337-17930: <rc...@en...> -> <va...@en...> Received: SIZE=1184 from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17930-01 for <va...@en...>; Thu, 1 Dec 2005 12:43:37 -0500 (EST) Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:43:37 horus.eng.fsu.edu /usr/local/sbin/amavisd[17930]: (17930-01) ESMTP< .\r\n Dec 1 12:43:38 horus.eng.fsu.edu /usr/local/sbin/amavisd[19457]: TIMING [total 19 ms] - bdb-open: 19 (100%)100, rundown: 0 (0%)100 Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: loaded base policy bank Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1 Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: prolong_timer after new request - timer reset: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: process_request: suggested_protocol="" on TCP Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 4: was busy, 16.8 ms, total idle 0.000 s, busy 0.017 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 5: was idle, 0.6 ms, total idle 0.001 s, busy 0.017 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) SMTP< EHLO horus.eng.fsu.edu\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250-[127.0.0.1] Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250-PIPELINING Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250-SIZE Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250-8BITMIME Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250-ENHANCEDSTATUSCODES Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 6: was busy, 2.9 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.020 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP< XFORWARD NAME=yoda.eng.fsu.edu ADDR=146.201.29.245\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.021 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP< XFORWARD PROTO=ESMTP HELO=[146.201.29.245]\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250 2.5.0 Ok XFORWARD Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.022 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP< MAIL FROM:<ko...@en...> SIZE=16192 BODY=8BITMIME\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) check_mail_begin_task: task_count=1 Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prepare_tempdir: creating directory /var/amavis/tmp/amavis-20051201T124342-17931Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prepare_tempdir: creating file /var/amavis/tmp/amavis-20051201T124342-17931/email.txt Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) lookup (debug_sender) => undef, "ko...@en..." does not match Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250 2.1.0 Sender ko...@en... OK Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 6: was busy, 36.3 ms, total idle 0.001 s, busy 0.059 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.002 s, busy 0.059 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP< RCPT TO:<nu...@ur...>\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 250 2.1.5 Recipient nu...@ur... OK Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 6: was busy, 1.6 ms, total idle 0.002 s, busy 0.060 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.002 s, busy 0.060 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after reading SMTP command: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP< DATA\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) prolong_timer after DATA received - timer reset: remaining time = 300 s Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP::10024 /var/amavis/tmp/amavis-20051201T124342-17931: <ko...@en...> -> <nu...@ur...> Received: SIZE=16192 BODY=8BITMIME from horus.eng.fsu.edu ([127.0.0.1]) by localhost (horus.eng.fsu.edu [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 17931-01 for <nu...@ur...>; Thu, 1 Dec 2005 12:43:42 -0500 (EST) Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP> 354 End data with <CR><LF>.<CR><LF> Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) ESMTP< .\r\n Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[17931]: (17931-01) Actual message size 16180 B, declared 16192 B Dec 1 12:43:42 horus.eng.fsu.edu /usr/local/sbin/amavisd[19569]: TIMING [total 17 ms] - bdb-open: 17 (100%)100, rundown: 0 (0%)100 |