Message-Id: <200501092057.j09Kvq5l031401@delorie.com>
Mailing-List: contact cygwin-help AT cygwin DOT com; run by ezmlm
List-Subscribe: <mailto:cygwin-subscribe AT cygwin DOT com>
List-Archive: <http://sourceware.org/ml/cygwin/>
List-Post: <mailto:cygwin AT cygwin DOT com>
List-Help: <mailto:cygwin-help AT cygwin DOT com>, <http://sourceware.org/ml/#faqs>
Sender: cygwin-owner AT cygwin DOT com
Mail-Followup-To: cygwin AT cygwin DOT com
Delivered-To: mailing list cygwin AT cygwin DOT com
From: "David Christensen" <dpchrist AT holgerdanske DOT com>
To: "'Cygwin List'" <cygwin AT cygwin DOT com>
Subject: FW: Is Cygwin cron supposed to send e-mail reports?
Date: Sun, 9 Jan 2005 12:57:53 -0800
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
X-IsSubscribed: yes

>> 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/