[arch-general] Hardlock after postfix/smtp entry in log - leaves 4 lost inodes each time - ideas?
David C. Rankin
drankinatty at suddenlinkmail.com
Tue Mar 19 17:49:32 EDT 2013
On 03/18/2013 05:39 PM, Martti Kühne wrote:
> What about df/tmpfs overflows etc, to cover the obvious sources of error...?
> Do you have that email 81963E9720 somewhere in lost+found or could
> otherwise make sure it survives the crash? I would be surprised if
> that email is making things crash, but who knows.
>
> One of the things that caught my eye was the 450 error for which a
> quick google turned me to [1]... As this is something my boss also was
> fighting with this week, I thought I'd read it quickly - it doesn't
> look that hard if you compute English, which the people I work with
> don't...
>
> For examining this stuff mor thoroughly, we'd need your postfix
> config, said main.cf file would be most likely to be revealing.
I experienced another lockup today. The result was the same. System lock, then
on poweroff-reboot you are dropped to the recovery console to fsck the /
partition and then 4 orphaned inodes are found/delete and then the server is
back up and running. This server runs under *extremely LIGHT load*, so the only
heavy loading it would ever experience would be from some sort of attack. The
log from today seems to indicate that smtp, then named led to the crash. I'm not
sure whether it is smtpd causing the crash and the named log entries just
happened as the system was hanging --or-- if named is somehow involved in
causing it? Here is the log snippet:
Mar 19 15:00:48 phoenix postfix/anvil[13900]: statistics: max connection rate
1/60s for (smtp:66.96.185.12) at Mar 19 14:57:28
Mar 19 15:00:48 phoenix postfix/anvil[13900]: statistics: max connection count 1
for (smtp:66.96.185.12) at Mar 19 14:57:28
Mar 19 15:00:48 phoenix postfix/anvil[13900]: statistics: max cache size 1 at
Mar 19 14:57:28
Mar 19 15:02:55 phoenix postfix/scache[13932]: statistics: start interval Mar 19
14:59:35
Mar 19 15:02:55 phoenix postfix/scache[13932]: statistics: domain lookup hits=0
miss=2 success=0%
Mar 19 15:02:55 phoenix postfix/scache[13932]: statistics: address lookup hits=0
miss=2 success=0%
Mar 19 15:02:55 phoenix postfix/scache[13932]: statistics: max simultaneous
domains=1 addresses=1 connection=2
Mar 19 15:05:48 phoenix postfix/smtpd[13998]: connect from
bosmailout04.eigbox.net[66.96.189.4]
Mar 19 15:05:48 phoenix postfix/smtpd[13998]: D6ED6E92B1:
client=bosmailout04.eigbox.net[66.96.189.4]
Mar 19 15:05:48 phoenix postfix/cleanup[14002]: D6ED6E92B1:
message-id=<00e001ce24dc$8cf42a60$a6dc7f20$@scherer at schererinvestments.com>
Mar 19 15:05:49 phoenix named[413]: error (network unreachable) resolving
'clickme2.click2site.com/AAAA/IN': 2001:503:231d::2:30#53
Mar 19 15:05:49 phoenix named[413]: error (network unreachable) resolving
'clickme.click2site.com/AAAA/IN': 2001:503:231d::2:30#53
Mar 19 15:05:49 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme.click2site.com/AAAA/IN': 38.113.1.30#53
Mar 19 15:05:49 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme2.click2site.com/AAAA/IN': 38.113.1.30#53
Mar 19 15:05:49 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme2.click2site.com/AAAA/IN': 38.113.1.31#53
Mar 19 15:05:50 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme.click2site.com/AAAA/IN': 38.113.1.31#53
Mar 19 15:05:50 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme.click2site.com/AAAA/IN': 38.113.1.30#53
Mar 19 15:05:50 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme2.click2site.com/AAAA/IN': 38.113.1.30#53
Mar 19 15:05:51 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme2.click2site.com/AAAA/IN': 38.113.1.31#53
Mar 19 15:05:51 phoenix named[413]: error (unexpected RCODE SERVFAIL) resolving
'clickme.click2site.com/AAAA/IN': 38.113.1.31#53
Mar 19 15:24:04 phoenix kernel: [ 0.000000] Initializing cgroup subsys cpuset
Mar 19 15:24:04 phoenix kernel: [ 0.000000] Initializing cgroup subsys cpu
I did still have the mail in question:
[16:42 phoenix:/var/spool] # l postfix/deferred/8/81963E9720
-rwx------ 1 postfix postfix 8174 Mar 19 2013 postfix/deferred/8/81963E9720
The message itself is just some bulk mail wanting you to "Play for millions at
Ruby Palace Casino". It is was actually addressed to my son (no doubt the e-mail
address was scammed from one of the gaming servers he frequents) If you are
interest in the actual content of the message, I have saved a copy and can send
it to you off-list.
I don't think there is an overflow issue, there is plenty of available space:
16:09 phoenix:~> df -h
Filesystem Size Used Avail Use% Mounted on
rootfs 23G 14G 8.4G 62% /
dev 1009M 0 1009M 0% /dev
run 1011M 280K 1010M 1% /run
/dev/mapper/nvidia_haheegdbp6 23G 14G 8.4G 62% /
shm 1011M 0 1011M 0% /dev/shm
/dev/mapper/nvidia_haheegdbp5 120M 36M 79M 31% /boot
/dev/mapper/nvidia_haheegdbp8 205G 36G 159G 19% /home
I can make the whole main.cf available if needed, but a postconf -n is
included below:
16:05 phoenix:~> postconf -n
alias_database = $alias_maps
alias_maps = hash:/etc/postfix/aliases
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/lib/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd
$daemon_directory/$process_name $process_id & sleep 5
html_directory = no
inet_interfaces = all
mail_owner = postfix
mail_spool_directory = /var/spool/mail
mailbox_command = /usr/bin/procmail -a "$EXTENSION"
mailbox_size_limit = 0
mailq_path = /usr/bin/mailq
manpage_directory = /usr/share/man
message_size_limit = 33554432
mydestination = $myhostname, localhost.$mydomain, $mydomain, www.$mydomain,
rankinfirm.com, rankinlawfirm.com, drrankin.com, www.drrankin.com
myhostname = phoenix.rlfpllc.com
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases
queue_directory = /var/spool/postfix
readme_directory = no
relay_domains = $mydestination, 3111skyline.com
sample_directory = /etc/postfix/sample
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
smtpd_client_restrictions = permit_sasl_authenticated
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, reject_invalid_hostname,
reject_non_fqdn_hostname
smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated,
check_client_access hash:/etc/postfix/client_access, reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain = $mydomain
smtpd_sasl_path = private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_tls_security_options = noanonymous
smtpd_sasl_type = dovecot
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/ssl/certs/dovecot.pem
smtpd_tls_key_file = /etc/ssl/private/dovecot.pem
unknown_local_recipient_reject_code = 550
Let me know if you have any additional thoughts. I am really curious to track
this issue down and find out what is doing this. I'm happy to test on this end.
--
David C. Rankin, J.D.,P.E.
More information about the arch-general
mailing list