Mail Archives: cygwin/2005/01/09/15:57:55
>> Is Cygwin cron supposed to send e-mail reports?
Pierre A. Humblet wrote:
> Yes.
Thanks for the response. :-)
> According to your logs below, you seem to have two problems:
> 1) queue runner fork problems, probably due to a rebase issue.
> (I am not an expert, not having been a victim)
I dunno either, but gave it a try anyway:
dpchrist AT p42800e:~$ rebaseall
ReBaseImage (/usr/bin/cygcrypt-0.dll) failed with last error = 6
dpchrist AT p42800e:~$ rebaseall
ReBaseImage (/usr/bin/cygcrypt-0.dll) failed with last error = 6
> 2) a mail delivery issue:
>> 2005-01-09 09:18:21 IA282L-00030G-88 <= dpchrist AT p42800e U=dp
christ P=local S=716
>> 2005-01-09 09:18:21 IA282L-00030G-88 cloud.he.net [65.19.145.
2]: Software caused connection abort
>> 2005-01-09 09:18:21 IA282L-00030G-88 == dpchrist AT holgerdanske
.com R=dnslookup T=remote_smtp defer (113): Software caused connection a
bort
> This shows that a mail was generated locally (from cron, I assume).
The log messages were generated by "email -s test dpchrist AT holgerdanske DOT com".
> The delivery failed, apparently because of an issue at the remote
> end, but perhaps with a local root cause (rebase?).
> (I grep'ed "Software caused" in the exim source and didn't find it.)
Google gave me some hits, but I don't know what I'm looking for...
> You could try to find details by running
> "exim -d dpchrist AT holgerdanske DOT com" from the command line (type CR +
> a few words + CR when exim seems to wait for input).
dpchrist AT p42800e:~$ exim -d dpchrist AT holgerdanske DOT com
Exim version 4.43 uid=1003 gid=513 pid=1976 D=fbb95cfd
Probably GDBM (native mode)
Support for: iconv() PAM OpenSSL
Lookups: lsearch wildlsearch nwildlsearch iplsearch dbm dbmnz dnsdb dsearch ldap
ldapdn ldapm passwd
Authenticators: cram_md5 plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply pipe smtp
changed uid/gid: forcing real = effective
uid=1003 gid=513 pid=1976
auxiliary group list: 0 513 544 545 1005
configuration file is /etc/exim.conf
log selectors = 00000ffc 00010400
trusted user
admin user
changed uid/gid: privilege not needed
uid=1003 gid=513 pid=1976
auxiliary group list: 0 513 544 545 1005
user name "U-P42800E\dpchrist" extracted from gecos field "U-P42800E\dpchrist,S-
[editorial delete]"
originator: uid=1003 gid=513 login=dpchrist name="U-P42800E\dpchrist"
sender address = dpchrist AT p42800e
set_process_info: 1976 accepting a local non-SMTP message from <dpchrist AT p42800
e>
Sender: dpchrist AT p42800e
Recipients:
dpchrist AT holgerdanske DOT com
search_tidyup called
test of Cygwin exim invoked as exim -d dpchrist AT holgerdanske DOT com
.
>>Headers received:
rewrite_one_header: type=F:
From: "U-P42800E\dpchrist" <dpchrist AT p42800e>
search_tidyup called
>>Headers after rewriting and local additions:
I Message-Id: <EIA2GCI-0001IW-L9 AT p42800e>
F From: "U-P42800E\dpchrist" <dpchrist AT p42800e>
Date: Sun, 09 Jan 2005 12:17:56 -0800
Data file written for message IA2GCI-0001IW-L9
>>Generated Received: header line
P Received: from dpchrist by p42800e with local (Exim 4.43)
id IA2GCI-0001IW-L9
for dpchrist AT holgerdanske DOT com; Sun, 09 Jan 2005 12:17:56 -0800
calling local_scan(); timeout=300
local_scan() returned 0 NULL
Writing spool header file
Size of headers = 267
LOG: MAIN
<= dpchrist AT p42800e U=dpchrist P=local S=335
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=1976 terminating with rc=0 >>>>>>>>>>>>>>>>
set_process_info: 2516 delivering IA2GCI-0001IW-L9
reading spool file IA2GCI-0001IW-L9-H
user=dpchrist uid=1003 gid=513 sender=dpchrist AT p42800e
sender_local=1 ident=dpchrist
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1 message_linecount=6
Delivery address list:
dpchrist AT holgerdanske DOT com
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
opened hints database /var/spool/exim/db/retry: flags=0
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Considering: dpchrist AT holgerdanske DOT com
unique = dpchrist AT holgerdanske DOT com
dbfn_read: key=R:holgerdanske.com
dbfn_read: key=R:dpchrist AT holgerdanske DOT com
no domain retry record
no address retry record
dpchrist AT holgerdanske DOT com: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
routing dpchrist AT holgerdanske DOT com
--------> dnslookup router <--------
local_part=dpchrist domain=holgerdanske.com
checking domains
holgerdanske.com in "@"? no (end of list)
holgerdanske.com in "! +local_domains"? yes (end of list)
calling dnslookup router
dnslookup router called for dpchrist AT holgerdanske DOT com
domain = holgerdanske.com
DNS lookup of holgerdanske.com (MX) succeeded
65.19.145.2 in "0.0.0.0 : 127.0.0.0/8"? no (end of list)
fully qualified name = holgerdanske.com
host_find_bydns yield = HOST_FOUND (2); returned hosts:
cloud.he.net 65.19.145.2 MX=1
set transport remote_smtp
queued for remote_smtp transport: local_part = dpchrist
domain = holgerdanske.com
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by dnslookup router
envelope to: dpchrist AT holgerdanske DOT com
transport: remote_smtp
host cloud.he.net [65.19.145.2] MX=1
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
After routing:
Local deliveries:
Remote deliveries:
dpchrist AT holgerdanske DOT com
Failed addresses:
Deferred addresses:
search_tidyup called
>>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>
--------> dpchrist AT holgerdanske DOT com <--------
search_tidyup called
set_process_info: 2516 delivering IA2GCI-0001IW-L9: waiting for a remote delive
ry subprocess to finish
selecting on subprocess pipes
changed uid/gid: remote delivery to dpchrist AT holgerdanske DOT com with transport=rem
ote_smtp
uid=1003 gid=513 pid=3376
auxiliary group list: 0 513 544 545 1005
set_process_info: 3376 delivering IA2GCI-0001IW-L9 using remote_smtp
remote_smtp transport entered
dpchrist AT holgerdanske DOT com
holgerdanske.com in queue_smtp_domains? no (option unset)
checking status of cloud.he.net
locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
opened hints database /var/spool/exim/db/retry: flags=0
dbfn_read: key=T:cloud.he.net:65.19.145.2
dbfn_read: key=T:cloud.he.net:65.19.145.2:IA2GCI-0001IW-L9
no message retry record
cloud.he.net [65.19.145.2] status = usable
65.19.145.2 in serialize_hosts? no (option unset)
delivering IA2GCI-0001IW-L9 to cloud.he.net [65.19.145.2] (dpchrist AT holgerdanske
.com)
set_process_info: 3376 delivering IA2GCI-0001IW-L9 to cloud.he.net [65.19.145.2
] (dpchrist AT holgerdanske DOT com)
Connecting to cloud.he.net [65.19.145.2]:25 ... failed
LOG: MAIN
cloud.he.net [65.19.145.2]: Software caused connection abort
set_process_info: 3376 delivering IA2GCI-0001IW-L9: just tried cloud.he.net [65
.19.145.2] for dpchrist AT holgerdanske DOT com: result DEFER
added retry item for T:cloud.he.net:65.19.145.2: errno=113 more_errno=0,M flags=
2
all IP addresses skipped or deferred at least one address
locking /var/spool/exim/db/wait-remote_smtp.lockfile
locked /var/spool/exim/db/wait-remote_smtp.lockfile
opened hints database /var/spool/exim/db/wait-remote_smtp: flags=2
dbfn_read: key=cloud.he.net
dbfn_write: key=cloud.he.net
Leaving remote_smtp transport
set_process_info: 3376 delivering IA2GCI-0001IW-L9 (just run remote_smtp for dp
christ AT holgerdanske DOT com in subprocess)
search_tidyup called
reading pipe for subprocess 3376 (not ended)
read() yielded 76
reading retry information for T:cloud.he.net:65.19.145.2 from subprocess
added retry item
Z0 item read
remote delivery process 3376 ended
set_process_info: 2516 delivering IA2GCI-0001IW-L9
post-process dpchrist AT holgerdanske DOT com (1)
LOG: MAIN
== dpchrist AT holgerdanske DOT com R=dnslookup T=remote_smtp defer (113): Software c
aused connection abort
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
changed uid/gid: post-delivery tidying
uid=1003 gid=513 pid=2516
auxiliary group list: 0 513 544 545 1005
set_process_info: 2516 tidying up after delivering IA2GCI-0001IW-L9
Processing retry items
Succeeded addresses:
Failed addresses:
Deferred addresses:
dpchrist AT holgerdanske DOT com
dpchrist AT p42800e:~$ locking /var/spool/exim/db/retry.lockfile
locked /var/spool/exim/db/retry.lockfile
opened hints database /var/spool/exim/db/retry: flags=2
address match: subject=*@cloud.he.net pattern=*
cloud.he.net in "*"? yes (matched "*")
*@cloud.he.net in "*"? yes (matched "*")
retry for T:cloud.he.net:65.19.145.2 (holgerdanske.com) = *
dbfn_read: key=T:cloud.he.net:65.19.145.2
Writing retry data for T:cloud.he.net:65.19.145.2
first failed=1105291101 last try=1105301876 next try=1105305476 expired=0
errno=113 more_errno=0,M Software caused connection abort
dbfn_write: key=T:cloud.he.net:65.19.145.2
end of retry processing
time on queue = 50s
warning counts: required 0 done 0
delivery deferred: update_spool=1 header_rewritten=0
Writing spool header file
Size of headers = 267
end delivery of IA2GCI-0001IW-L9
search_tidyup called
search_tidyup called
dpchrist AT p42800e:~$ tail /var/log/exim/
cygrunsrv_err.log cygrunsrv_out.log exim_main.log exim_panic.log
dpchrist AT p42800e:~$ tail /var/log/exim/exim_main.log
2005-01-09 10:45:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 11:00:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 11:15:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 11:30:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 11:45:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 12:00:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 12:15:41 daemon: fork of queue-runner process failed: Resource tempor
arily unavailable
2005-01-09 12:17:56 IA2GCI-0001IW-L9 <= dpchrist AT p42800e U=dpchrist P=local S=33
5
2005-01-09 12:17:56 IA2GCI-0001IW-L9 cloud.he.net [65.19.145.2]: Software caused
connection abort
2005-01-09 12:17:56 IA2GCI-0001IW-L9 == dpchrist AT holgerdanske DOT com R=dnslookup T=
remote_smtp defer (113): Software caused connection abort
dpchrist AT p42800e:~$
The key line appears to be:
Connecting to cloud.he.net [65.19.145.2]:25 ... failed
LOG: MAIN
cloud.he.net [65.19.145.2]: Software caused connection abort
Test it with Windows telnet:
C:\Documents and Settings\dpchrist>telnet cloud.he.net 25
Connecting To cloud.he.net...Could not open connection to the host,
on port 25:
Connect failed
So, Cygwin exim and Windows telnet both can't connect to cloud.he.net on port
25, yet Outlook sends mail via that host... (?)
Check Windows Firewall -- oops! I disabled the exception for SMTP... Turning
it back on and retrying -- nope. Restarting and retrying -- nope. Set Windows
Firewall to "Don't allow exceptions", unplug Cygwin host from LAN, plug directly
into ADSL modem, run ipconfig /release and ipconfig /renew, and try telnet again
-- telnet still can't see cloud.he.net on port 25. ping can see it. I don't
get it...
Test it on the Debian box for comparison:
dpchrist AT p166d302:~$ telnet cloud.he.net 25
Trying 65.19.145.2...
Connected to cloud.he.net.
Escape character is '^]'.
220 cloud.he.net ESMTP Ready
help
250-recvmail 2004-10-21 15:19:28
250-Valid commands are:
250- HELO EHLO NOOP HELP RSET
250- MAIL RCPT DATA QUIT
250 OK
quit
221 goodbye.
Connection closed by foreign host.
> ssmtp is less likely to suffer rebase issue. Use ssmtp-config.
I don't seem to have it:
dpchrist AT p42800e:~$ updatedb
dpchrist AT p42800e:~$ locate smtp-config
dpchrist AT p42800e:~$ smtp
smtpapi.dll smtpcons.mfl smtpctrs.dll smtpctrs.ini
smtpcons.dll smtpcons.mof smtpctrs.h
Any suggestions?
TIA,
David
--
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple
Problem reports: http://cygwin.com/problems.html
Documentation: http://cygwin.com/docs.html
FAQ: http://cygwin.com/faq/
- Raw text -