Re: [exim-dev] Preliminary testing of a new Exim test suite

Kezdőlap
Üzenet törlése
Válasz az üzenetre
Szerző: Daniel Tiefnig
Dátum:  
Címzett: exim-dev
Tárgy: Re: [exim-dev] Preliminary testing of a new Exim test suite
Philip Hazel wrote:
> Please can you run this test with debugging turned on:
>
> ./runtest -d 2125


Sure.

> and send me the stderr output. That might show up what is different
> on our two systems.


I've attached test-stderr and test-stderr-server to this mail. This is
with 4.60-RC2 this time. (Same with RC1.)

The message comes from transports/smtp.c if a required cipher is not
found, so I wonder why others don't run into this problem. (Or is this
cipher NOT supposed to be missing?)


lg,
daniel
Exim version x.yz uid=1000 gid=1000 pid=10175 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September 6, 2005)
Support for: crypteq iconv() Perl Expand_dlfunc OpenSSL translate_ip_address Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dnsdb dsearch mysql testdb
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
uid=0 gid=1000 pid=10175
auxiliary group list: <none>
configuration file is /home/tiefnig/exim/exim-testsuite-0.00/test-config
log selectors = 00000ffc 000e1001
cwd=/home/tiefnig/exim/exim-testsuite-0.00 6 args: /home/tiefnig/exim/exim-testsuite-0.00/eximdir/exim -d -DEXIM_PATH=/home/tiefnig/exim/exim-testsuite-0.00/eximdir/exim -C /home/tiefnig/exim/exim-testsuite-0.00/test-config userx@???
admin user
changed uid/gid: privilege not needed
uid=102 gid=102 pid=10175
auxiliary group list: <none>
originator: uid=1000 gid=1000 login=tiefnig name=Daniel Tiefnig
sender address = tiefnig@???
set_process_info: 10175 accepting a local non-SMTP message from <tiefnig@???>
Sender: tiefnig@???
Recipients:
userx@???
search_tidyup called
>>Headers received:


rewrite_one_header: type=F:
From: Daniel Tiefnig <tiefnig@???>
search_tidyup called
>>Headers after rewriting and local additions:

I Message-Id: <E1EeZpI-0002e7-Gg@???>
F From: Daniel Tiefnig <tiefnig@???>
Date: Tue, 22 Nov 2005 16:12:56 +0100

Data file written for message 1EeZpI-0002e7-Gg
>>Generated Received: header line

P Received: from tiefnig by myhost.test.ex with local (Exim x.yz)
    (envelope-from <tiefnig@???>)
    id 1EeZpI-0002e7-Gg
    for userx@???; Tue, 22 Nov 2005 16:12:56 +0100
calling local_scan(); timeout=300
local_scan() returned 0 NULL
Writing spool header file
Size of headers = 310
LOG: MAIN
  <= tiefnig@??? U=tiefnig P=local S=319
search_tidyup called

>>>>>>>>>>>>>>>> Exim pid=10175 terminating with rc=0 >>>>>>>>>>>>>>>>

Exim version x.yz uid=1000 gid=1000 pid=10177 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September 6, 2005)
Support for: crypteq iconv() Perl Expand_dlfunc OpenSSL translate_ip_address Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dnsdb dsearch mysql testdb
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
uid=0 gid=1000 pid=10177
auxiliary group list: <none>
configuration file is /home/tiefnig/exim/exim-testsuite-0.00/test-config
log selectors = 00000ffc 000e1001
cwd=/home/tiefnig/exim/exim-testsuite-0.00 6 args: /home/tiefnig/exim/exim-testsuite-0.00/eximdir/exim -d -DEXIM_PATH=/home/tiefnig/exim/exim-testsuite-0.00/eximdir/exim -C /home/tiefnig/exim/exim-testsuite-0.00/test-config -qf
admin user
Single queue run
set_process_info: 10177 running the queue (single queue run)
LOG: queue_run MAIN
Start queue run: pid=10177 -qf
queue running combined directories
search_tidyup called
set_process_info: 10177 running queue: 1EeZpI-0002e7-Gg-H
set_process_info: 10177 running queue: waiting for 1EeZpI-0002e7-Gg (10178)
set_process_info: 10178 delivering 1EeZpI-0002e7-Gg (queue run pid 10177)
reading spool file 1EeZpI-0002e7-Gg-H
user=tiefnig uid=1000 gid=1000 sender=tiefnig@???
sender_local=1 ident=tiefnig
Non-recipients:
Empty Tree
---- End of tree ----
recipients_count=1
body_linecount=1 message_linecount=7
Delivery address list:
userx@???
locking /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
locked /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
EXIM_DBOPEN(/home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry)
returned from EXIM_DBOPEN
ensuring /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile is owned by exim
no retry data available
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

Considering: userx@???
unique = userx@???
no domain retry record
no address retry record
userx@???: queued for routing
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

routing userx@???
--------> client router <--------
local_part=userx domain=test.ex
checking "condition"
calling client router
client router called for userx@???
domain = test.ex
set transport send_to_server
queued for send_to_server transport: local_part = userx
domain = test.ex
errors_to=NULL
domain_data=NULL localpart_data=NULL
routed by client router
envelope to: userx@???
transport: send_to_server
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

After routing:
  Local deliveries:
  Remote deliveries:
    userx@???
  Failed addresses:
  Deferred addresses:
search_tidyup called

>>>>>>>>>>>>>>>> Remote deliveries >>>>>>>>>>>>>>>>

--------> userx@??? <--------
search_tidyup called
changed uid/gid: remote delivery to userx@??? with transport=send_to_server
uid=102 gid=102 pid=10179
auxiliary group list: <none>
set_process_info: 10179 delivering 1EeZpI-0002e7-Gg using send_to_server
send_to_server transport entered
userx@???
using the transport's hosts: 192.168.34.107 : 127.0.0.1
getting address for 192.168.34.107
using host_fake_gethostbyname for 192.168.34.107 (IPv4)
local host found for non-MX address
fully qualified name = 192.168.34.107
gethostbyname looked up these IP addresses:
name=192.168.34.107 address=192.168.34.107
checking status of 192.168.34.107
locking /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
locked /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
EXIM_DBOPEN(/home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry)
returned from EXIM_DBOPEN
no retry data available
192.168.34.107 [192.168.34.107]:1225 status = usable
192.168.34.107 in serialize_hosts? no (option unset)
delivering 1EeZpI-0002e7-Gg to 192.168.34.107 [192.168.34.107] (userx@???)
set_process_info: 10179 delivering 1EeZpI-0002e7-Gg to 192.168.34.107 [192.168.34.107] (userx@???)
Connecting to 192.168.34.107 [192.168.34.107]:1225 ... connected
waiting for data on socket
read response data: size=68
SMTP<< 220 myhost.test.ex ESMTP Exim x.yz Tue, 22 Nov 2005 16:12:56 +0100
192.168.34.107 in hosts_avoid_esmtp? no (option unset)
SMTP>> EHLO myhost.test.ex

waiting for data on socket
read response data: size=124
  SMTP<< 250-myhost.test.ex Hello localhost.localdomain [192.168.34.107]
         250-SIZE 52428800
         250-PIPELINING
         250-STARTTLS
         250 HELP
192.168.34.107 in hosts_avoid_tls? no (option unset)

SMTP>> STARTTLS

waiting for data on socket
read response data: size=31
SMTP<< 454 TLS currently unavailable
192.168.34.107 in hosts_require_tls? yes (matched "192.168.34.107")
ok=0 send_quit=1 send_rset=1 continue_more=0 yield=1 first_address is not NULL
SMTP>> QUIT

LOG: MAIN
a TLS session is required for 192.168.34.107 [192.168.34.107], but an attempt to start TLS failed
set_process_info: 10179 delivering 1EeZpI-0002e7-Gg: just tried 192.168.34.107 [192.168.34.107] for userx@???: result DEFER
added retry item for T:192.168.34.107:192.168.34.107:1225: errno=-38 more_errno=0,A flags=2
address match: subject=*@192.168.34.107 pattern=*
192.168.34.107 in "*"? yes (matched "*")
*@192.168.34.107 in "*"? yes (matched "*")
getting address for 127.0.0.1
using host_fake_gethostbyname for 127.0.0.1 (IPv4)
local host found for non-MX address
fully qualified name = 127.0.0.1
gethostbyname looked up these IP addresses:
name=127.0.0.1 address=127.0.0.1
checking status of 127.0.0.1
locking /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
locked /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
EXIM_DBOPEN(/home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry)
returned from EXIM_DBOPEN
no retry data available
127.0.0.1 [127.0.0.1]:1225 status = usable
127.0.0.1 in serialize_hosts? no (option unset)
delivering 1EeZpI-0002e7-Gg to 127.0.0.1 [127.0.0.1] (userx@???)
set_process_info: 10179 delivering 1EeZpI-0002e7-Gg to 127.0.0.1 [127.0.0.1] (userx@???)
Connecting to 127.0.0.1 [127.0.0.1]:1225 ... connected
waiting for data on socket
read response data: size=68
SMTP<< 220 myhost.test.ex ESMTP Exim x.yz Tue, 22 Nov 2005 16:12:56 +0100
127.0.0.1 in hosts_avoid_esmtp? no (option unset)
SMTP>> EHLO myhost.test.ex

waiting for data on socket
read response data: size=107
  SMTP<< 250-myhost.test.ex Hello localhost [127.0.0.1]
         250-SIZE 52428800
         250-PIPELINING
         250-STARTTLS
         250 HELP
127.0.0.1 in hosts_avoid_tls? no (option unset)

SMTP>> STARTTLS

waiting for data on socket
read response data: size=18
SMTP<< 220 TLS go ahead
Initialized TLS
Calling SSL_connect
SSL info: before/connect initialization
SSL info: before/connect initialization
SSL info: SSLv2/v3 write client hello A
SSL info: SSLv3 read server hello A
SSL info: SSLv3 read server certificate A
SSL info: SSLv3 read server done A
SSL info: SSLv3 write client key exchange A
SSL info: SSLv3 write change cipher spec A
SSL info: SSLv3 write finished A
SSL info: SSLv3 flush data
SSL info: SSLv3 read finished A
SSL info: SSL negotiation finished successfully
SSL info: SSL negotiation finished successfully
SSL_connect succeeded
Cipher: TLSv1:DES-CBC3-SHA:168
SMTP>> EHLO myhost.test.ex

tls_do_write(bffbcd9f, 21)
SSL_write(SSL, bffbcd9f, 21)
outbytes=21 error=0
waiting for data on socket
Calling SSL_read(81225b8, bffbd19f, 4096)
read response data: size=93
  SMTP<< 250-myhost.test.ex Hello localhost [127.0.0.1]
         250-SIZE 52428800
         250-PIPELINING
         250 HELP
using PIPELINING
127.0.0.1 in hosts_require_auth? no (option unset)

SMTP>> MAIL FROM:<tiefnig@???> SIZE=1351
SMTP>> RCPT TO:<userx@???>
SMTP>> DATA

tls_do_write(bffbcd9f, 77)
SSL_write(SSL, bffbcd9f, 77)
outbytes=77 error=0
waiting for data on socket
Calling SSL_read(81225b8, bffbd19f, 4096)
read response data: size=8
SMTP<< 250 OK
waiting for data on socket
Calling SSL_read(81225b8, bffbd19f, 4096)
read response data: size=14
SMTP<< 250 Accepted
waiting for data on socket
Calling SSL_read(81225b8, bffbd19f, 4096)
read response data: size=56
SMTP<< 354 Enter message, ending with "." on a line by itself
SMTP>> writing message and terminating "."

writing data block fd=8 size=331 timeout=300
tls_do_write(81157b8, 331)
SSL_write(SSL, 81157b8, 331)
outbytes=331 error=0
waiting for data on socket
Calling SSL_read(81225b8, bffbd19f, 4096)
read response data: size=28
SMTP<< 250 OK id=1EeZpI-0002eF-Oi
journalling userx@???
ok=1 send_quit=1 send_rset=0 continue_more=0 yield=0 first_address is NULL
127.0.0.1 in hosts_nopass_tls? no (option unset)
transport_check_waiting entered
sequence=1 local_max=500 global_max=-1
locking /home/tiefnig/exim/exim-testsuite-0.00/spool/db/wait-send_to_server.lockfile
locked /home/tiefnig/exim/exim-testsuite-0.00/spool/db/wait-send_to_server.lockfile
EXIM_DBOPEN(/home/tiefnig/exim/exim-testsuite-0.00/spool/db/wait-send_to_server)
returned from EXIM_DBOPEN
opened hints database /home/tiefnig/exim/exim-testsuite-0.00/spool/db/wait-send_to_server: flags=2
dbfn_read: key=127.0.0.1
no messages waiting for 127.0.0.1
SMTP>> QUIT

tls_do_write(bffbcd9f, 6)
SSL_write(SSL, bffbcd9f, 6)
outbytes=6 error=0
tls_close(): shutting down SSL
SSL info: SSL negotiation finished successfully
set_process_info: 10179 delivering 1EeZpI-0002e7-Gg: just tried 127.0.0.1 [127.0.0.1] for userx@???: result OK
Leaving send_to_server transport
set_process_info: 10179 delivering 1EeZpI-0002e7-Gg (just run send_to_server for userx@??? in subprocess)
search_tidyup called
set_process_info: 10178 delivering 1EeZpI-0002e7-Gg: waiting for a remote delivery subprocess to finish
remote delivery process 10179 ended
set_process_info: 10178 delivering 1EeZpI-0002e7-Gg
reading pipe for subprocess 10179 (ended)
read() yielded 296
reading retry information for T:192.168.34.107:192.168.34.107:1225 from subprocess
added retry item
Z0 item read
post-process userx@??? (0)
userx@??? delivered
LOG: MAIN
=> userx@??? R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLSv1:DES-CBC3-SHA:168 CV=no DN="/C=UK/L=Cambridge/O=University of Cambridge/OU=Computing Service/CN=Philip Hazel"
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>

changed uid/gid: post-delivery tidying
uid=102 gid=102 pid=10178
auxiliary group list: <none>
set_process_info: 10178 tidying up after delivering 1EeZpI-0002e7-Gg
Processing retry items
Succeeded addresses:
userx@???
locking /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
locked /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry.lockfile
EXIM_DBOPEN(/home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry)
returned from EXIM_DBOPEN
opened hints database /home/tiefnig/exim/exim-testsuite-0.00/spool/db/retry: flags=2
address match: subject=*@192.168.34.107 pattern=*
192.168.34.107 in "*"? yes (matched "*")
*@192.168.34.107 in "*"? yes (matched "*")
retry for T:192.168.34.107:192.168.34.107:1225 (test.ex) = *
dbfn_read: key=T:192.168.34.107:192.168.34.107:1225
Writing retry data for T:192.168.34.107:192.168.34.107:1225
first failed=1132672377 last try=1132672377 next try=1132672387 expired=0
errno=-38 more_errno=0,A a TLS session is required for 192.168.34.107 [192.168.34.107], but an attempt to start TLS failed
dbfn_write: key=T:192.168.34.107:192.168.34.107:1225
Failed addresses:
Deferred addresses:
end of retry processing
LOG: MAIN
Completed
end delivery of 1EeZpI-0002e7-Gg
search_tidyup called
set_process_info: 10177 running queue: waiting for children of 10178
set_process_info: 10177 running queue
LOG: queue_run MAIN
End queue run: pid=10177 -qf
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=10177 terminating with rc=0 >>>>>>>>>>>>>>>>

Exim version x.yz uid=1000 gid=1000 pid=10173 D=fbb95cfd
Berkeley DB: Sleepycat Software: Berkeley DB 4.3.29: (September  6, 2005)
Support for: crypteq iconv() Perl Expand_dlfunc OpenSSL translate_ip_address Content_Scanning Old_Demime
Lookups: lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmnz dnsdb dsearch mysql testdb
Authenticators: cram_md5 cyrus_sasl plaintext spa
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
changed uid/gid: forcing real = effective
  uid=0 gid=1000 pid=10173
  auxiliary group list: <none>
configuration file is /home/tiefnig/exim/exim-testsuite-0.00/test-config
log selectors = 00000ffc 000e1001
cwd=/home/tiefnig/exim/exim-testsuite-0.00 9 args: /home/tiefnig/exim/exim-testsuite-0.00/eximdir/exim -d -DEXIM_PATH=/home/tiefnig/exim/exim-testsuite-0.00/eximdir/exim -C /home/tiefnig/exim/exim-testsuite-0.00/test-config -DSERVER=server -bdf -oX 1225
admin user
originator: uid=1000 gid=1000 login=tiefnig name=Daniel Tiefnig
10173 daemon_smtp_port overridden by -oX:
10173   <: 1225
10173 listening on all interfaces (IPv4) port 1225
10173 pid written to /home/tiefnig/exim/exim-testsuite-0.00/spool/exim-daemon.pid
10173 changed uid/gid: running as a daemon
10173   uid=102 gid=102 pid=10173
10173   auxiliary group list: 102
10173 LOG: MAIN
10173   exim x.yz daemon started: pid=10173, no queue runs, listening for SMTP on port 1225 (IPv4)
10173 set_process_info: 10173 daemon: no queue runs, listening for SMTP on port 1225 (IPv4)
10173 daemon running with uid=102 gid=102 euid=102 egid=102
10173 Listening...
10173 Connection request from 192.168.34.107 port 33181
10173 search_tidyup called
10180 sender_fullhost = [192.168.34.107]
10180 sender_rcvhost = [192.168.34.107]
10180 Process 10180 is handling incoming connection from [192.168.34.107]
10180 checking for IP options
10180 no IP options found
10180 host in host_lookup? no (option unset)
10180 set_process_info: 10180 handling incoming connection from [192.168.34.107]
10180 host in host_reject_connection? no (option unset)
10180 host in sender_unqualified_hosts? no (option unset)
10180 host in recipient_unqualified_hosts? no (option unset)
10180 host in helo_verify_hosts? no (option unset)
10180 host in helo_try_verify_hosts? no (option unset)
10180 host in helo_accept_junk_hosts? no (option unset)
10180 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 22 Nov 2005 16:12:56 +0100
10180 Process 10180 is ready for new message
10180 smtp_setup_msg entered
10173 1 SMTP accept process running
10173 Listening...
10180 SMTP<< EHLO myhost.test.ex
10180 myhost.test.ex in helo_lookup_domains? yes (matched "@")
10180 looking up host name for 192.168.34.107
10180 DNS lookup of 107.34.168.192.in-addr.arpa (PTR) using fakens
10180 DNS lookup of 107.34.168.192.in-addr.arpa (PTR) succeeded
10180 IP address lookup yielded localhost.localdomain
10180 using host_fake_gethostbyname for localhost.localdomain (IPv4)
10180 DNS lookup of localhost.localdomain (A) using fakens
10180 DNS lookup of localhost.localdomain (A) succeeded
10180 gethostbyname looked up these IP addresses:
10180   name=localhost.localdomain address=192.168.34.107
10180 checking addresses for localhost.localdomain
10180   192.168.34.107 OK
10180 sender_fullhost = localhost.localdomain (myhost.test.ex) [192.168.34.107]
10180 sender_rcvhost = localhost.localdomain ([192.168.34.107] helo=myhost.test.ex)
10180 set_process_info: 10180 handling incoming connection from localhost.localdomain (myhost.test.ex) [192.168.34.107]
10180 host in pipelining_advertise_hosts? yes (matched "*")
10180 host in tls_advertise_hosts? yes (matched "*")
10180 SMTP>> 250-myhost.test.ex Hello localhost.localdomain [192.168.34.107]
10180 250-SIZE 52428800
10180 250-PIPELINING
10180 250-STARTTLS
10180 250 HELP
10180 SMTP<< STARTTLS
10180 tls_certificate file /home/tiefnig/exim/exim-testsuite-0.00/aux-fixed/cert1
10180 tls_privatekey file /home/tiefnig/exim/exim-testsuite-0.00/aux-fixed/cert1
10180 Initialized TLS
10180 required ciphers: IDEA-CBC-MD5
10180 LOG: MAIN
10180   TLS error on connection from localhost.localdomain (myhost.test.ex) [192.168.34.107] (SSL_CTX_set_cipher_list): error:144020B9:SSL routines:SSL_CTX_set_cipher_list:no cipher match
10180 SMTP>> 454 TLS currently unavailable
10173 Connection request from 127.0.0.1 port 33182
10173 search_tidyup called
10173 2 SMTP accept processes running
10173 Listening...
10183 sender_fullhost = [127.0.0.1]
10183 sender_rcvhost = [127.0.0.1]
10183 Process 10183 is handling incoming connection from [127.0.0.1]
10183 checking for IP options
10183 no IP options found
10183 host in host_lookup? no (option unset)
10183 set_process_info: 10183 handling incoming connection from [127.0.0.1]
10183 host in host_reject_connection? no (option unset)
10183 host in sender_unqualified_hosts? no (option unset)
10183 host in recipient_unqualified_hosts? no (option unset)
10183 host in helo_verify_hosts? no (option unset)
10183 host in helo_try_verify_hosts? no (option unset)
10183 host in helo_accept_junk_hosts? no (option unset)
10183 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 22 Nov 2005 16:12:56 +0100
10183 Process 10183 is ready for new message
10183 smtp_setup_msg entered
10180 SMTP<< QUIT
10180 SMTP>> 221 myhost.test.ex closing connection
10180 LOG: smtp_connection MAIN
10180   SMTP connection from localhost.localdomain (myhost.test.ex) [192.168.34.107] closed by QUIT
10180 search_tidyup called
10173 child 10180 ended: status=0x0
10173 1 SMTP accept process now running
10173 Listening...
10183 SMTP<< EHLO myhost.test.ex
10183 myhost.test.ex in helo_lookup_domains? yes (matched "@")
10183 looking up host name for 127.0.0.1
10183 DNS lookup of 1.0.0.127.in-addr.arpa (PTR) using fakens
10183 DNS lookup of 1.0.0.127.in-addr.arpa (PTR) succeeded
10183 IP address lookup yielded localhost
10183 using host_fake_gethostbyname for localhost (IPv4)
10183 gethostbyname looked up these IP addresses:
10183   name=localhost address=127.0.0.1
10183 checking addresses for localhost
10183   127.0.0.1 OK
10183 sender_fullhost = localhost (myhost.test.ex) [127.0.0.1]
10183 sender_rcvhost = localhost ([127.0.0.1] helo=myhost.test.ex)
10183 set_process_info: 10183 handling incoming connection from localhost (myhost.test.ex) [127.0.0.1]
10183 host in pipelining_advertise_hosts? yes (matched "*")
10183 host in tls_advertise_hosts? yes (matched "*")
10183 SMTP>> 250-myhost.test.ex Hello localhost [127.0.0.1]
10183 250-SIZE 52428800
10183 250-PIPELINING
10183 250-STARTTLS
10183 250 HELP
10183 SMTP<< STARTTLS
10183 tls_certificate file /home/tiefnig/exim/exim-testsuite-0.00/aux-fixed/cert1
10183 tls_privatekey file /home/tiefnig/exim/exim-testsuite-0.00/aux-fixed/cert1
10183 Initialized TLS
10183 required ciphers: !RSA-AES-256:DES-CBC3-SHA
10183 host in tls_verify_hosts? no (option unset)
10183 host in tls_try_verify_hosts? no (option unset)
10183 SMTP>> 220 TLS go ahead
10183 Calling SSL_accept
10183 SSL info: before/accept initialization
10183 SSL info: before/accept initialization
10183 SSL info: SSLv3 read client hello A
10183 SSL info: SSLv3 write server hello A
10183 SSL info: SSLv3 write certificate A
10183 SSL info: SSLv3 write server done A
10183 SSL info: SSLv3 flush data
10183 SSL info: SSLv3 read client key exchange A
10183 SSL info: SSLv3 read finished A
10183 SSL info: SSLv3 write change cipher spec A
10183 SSL info: SSLv3 write finished A
10183 SSL info: SSLv3 flush data
10183 SSL info: SSL negotiation finished successfully
10183 SSL info: SSL negotiation finished successfully
10183 SSL_accept was successful
10183 Cipher: TLSv1:DES-CBC3-SHA:168
10183 Shared ciphers: DHE-RSA-AES256-SHA:DHE-DSS-AES256-SHA:AES256-SHA:EDH-RSA-DES-CBC3-SHA:EDH-DSS-DES-CBC3-SHA:DES-CBC3-SHA:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA:AES128-SHA:DHE-DSS-RC4-SHA:RC4-SHA:RC4-MD5:EXP1024-DHE-DSS-DES-CBC-SHA:EXP1024-DES-CBC-SHA:EXP1024-RC2-CBC-MD5:EDH-RSA-DES-CBC-SHA:EDH-DSS-DES-CBC-SHA:DES-CBC-SHA:EXP1024-DHE-DSS-RC4-SHA:EXP1024-RC4-SHA:EXP1024-RC4-MD5:EXP-EDH-RSA-DES-CBC-SHA:EXP-EDH-DSS-DES-CBC-SHA:EXP-DES-CBC-SHA:EXP-RC2-CBC-MD5:EXP-RC4-MD5
10183 sender_fullhost = localhost [127.0.0.1]
10183 sender_rcvhost = localhost ([127.0.0.1])
10183 set_process_info: 10183 handling incoming TLS connection from localhost [127.0.0.1]
10183 TLS active
10183 Calling SSL_read(8120cb8, 8130ff0, 4096)
10183 SMTP<< EHLO myhost.test.ex
10183 sender_fullhost = localhost (myhost.test.ex) [127.0.0.1]
10183 sender_rcvhost = localhost ([127.0.0.1] helo=myhost.test.ex)
10183 set_process_info: 10183 handling TLS incoming connection from localhost (myhost.test.ex) [127.0.0.1]
10183 host in pipelining_advertise_hosts? yes (matched "*")
10183 tls_do_write(81129d0, 93)
10183 SSL_write(SSL, 81129d0, 93)
10183 outbytes=93 error=0
10183 SMTP>> 250-myhost.test.ex Hello localhost [127.0.0.1]
10183 250-SIZE 52428800
10183 250-PIPELINING
10183 250 HELP
10183 Calling SSL_read(8120cb8, 8130ff0, 4096)
10183 SMTP<< MAIL FROM:<tiefnig@???> SIZE=1351
10183 spool directory space = 12154004K inodes = 3719051 check_space = 0K inodes = 0 msg_size = 6351
10183 SMTP>> 250 OK
10183 tls_do_write(810b010, 8)
10183 SSL_write(SSL, 810b010, 8)
10183 outbytes=8 error=0
10183 SMTP<< RCPT TO:<userx@???>
10183 processing "accept"
10183 accept: condition test succeeded
10183 SMTP>> 250 Accepted
10183 tls_do_write(810b010, 14)
10183 SSL_write(SSL, 810b010, 14)
10183 outbytes=14 error=0
10183 SMTP<< DATA
10183 SMTP>> 354 Enter message, ending with "." on a line by itself
10183 tls_do_write(810b010, 56)
10183 SSL_write(SSL, 810b010, 56)
10183 outbytes=56 error=0
10183 search_tidyup called
10183 Calling SSL_read(8120cb8, 8130ff0, 4096)
10183 host in ignore_fromline_hosts? no (option unset)
10183 >>Headers received:
10183 Received: from tiefnig by myhost.test.ex with local (Exim x.yz)
10183     (envelope-from <tiefnig@???>)
10183     id 1EeZpI-0002e7-Gg
10183     for userx@???; Tue, 22 Nov 2005 16:12:56 +0100
10183 Message-Id: <E1EeZpI-0002e7-Gg@???>
10183 From: Daniel Tiefnig <tiefnig@???>
10183 Date: Tue, 22 Nov 2005 16:12:56 +0100
10183 
10183 rewrite_one_header: type=F:
10183   From: Daniel Tiefnig <tiefnig@???>
10183 search_tidyup called
10183 >>Headers after rewriting and local additions:
10183 P Received: from tiefnig by myhost.test.ex with local (Exim x.yz)
10183     (envelope-from <tiefnig@???>)
10183     id 1EeZpI-0002e7-Gg
10183     for userx@???; Tue, 22 Nov 2005 16:12:56 +0100
10183 I Message-Id: <E1EeZpI-0002e7-Gg@???>
10183 F From: Daniel Tiefnig <tiefnig@???>
10183   Date: Tue, 22 Nov 2005 16:12:56 +0100
10183 
10183 Data file written for message 1EeZpI-0002eF-Oi
10183 >>Generated Received: header line
10183 P Received: from localhost ([127.0.0.1] helo=myhost.test.ex)
10183     by myhost.test.ex with esmtps (TLSv1:DES-CBC3-SHA:168)
10183     (Exim x.yz)
10183     (envelope-from <tiefnig@???>)
10183     id 1EeZpI-0002eF-Oi
10183     for userx@???; Tue, 22 Nov 2005 16:12:56 +0100
10183 calling local_scan(); timeout=300
10183 local_scan() returned 0 NULL
10183 Writing spool header file
10183 Size of headers = 553
10183 LOG: MAIN
10183   <= tiefnig@??? H=localhost (myhost.test.ex) [127.0.0.1] P=esmtps X=TLSv1:DES-CBC3-SHA:168 CV=no S=562 id=E1EeZpI-0002e7-Gg@???
10183 SMTP>> 250 OK id=1EeZpI-0002eF-Oi
10183 tls_do_write(810b010, 28)
10183 SSL_write(SSL, 810b010, 28)
10183 outbytes=28 error=0
10183 search_tidyup called
10183 Sender: tiefnig@???
10183 Recipients:
10183   userx@???
10183 Process 10183 is ready for new message
10183 smtp_setup_msg entered
10183 Calling SSL_read(8120cb8, 8130ff0, 4096)
10183 SMTP<< QUIT
10183 SMTP>> 221 myhost.test.ex closing connection
10183 tls_do_write(810b010, 39)
10183 SSL_write(SSL, 810b010, 39)
10183 outbytes=39 error=0
10183 tls_close(): shutting down SSL
10183 LOG: smtp_connection MAIN
10183   SMTP connection from localhost (myhost.test.ex) [127.0.0.1] closed by QUIT
10183 search_tidyup called
10173 child 10183 ended: status=0x0
10173 0 SMTP accept processes now running
10173 Listening...