Hello,
I'm trying to install the 4.05 version of qpopper on my Solaris 9 box. I
configured it with
./configure -enable-debugging -with-openssl
My config file looaks like:
set tls-support = stls
set tls-server-cert-file = /etc/mail/certs/cert.pem
I'm starting from Inetd with:
pop3 stream tcp nowait root /usr/local/sbin/popper
qpopper -d -s -f /etc/mail/pop/qpopper.config
All compiled well, and I went through the creation of a certificate with a
test CA. When I connect without SLL everything works beautifully. When I
connect with SSL from Outlook 2003 I see the entries under <<LOG1>> below in
my log file.
When I connect from Eudora I see the, slightly different, log under <<LOG2>>
I have checked the search engines and I have seen references to the "ERR POP
EOF or I/O" problem between Outlook XP/2003 and qpopper. Some postings even
went so far as to offer a patch for qpopper (which I tried but did not
work),
Interestingly the problem seems to manifest itself differently with Outlook
then Eudora or maybe I'm actually looking at two problems.
Any and all help would be greatly appreciated,
Thank you,
Willem
<<LOG1>>
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...read line 1
(22): set tls-support = stls [pop_config.c:1370]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] Set tls-support
to STLS (2) [pop_config.c:1234]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...read line 2
(51): set tls-server-cert-file = /etc/mail/certs/cert.pem
[pop_config.c:1370]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] Set
tls-server-cert-file to "/etc/mail/certs/cert.pem" [pop_config.c:1250]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] Finished
processing config file '/etc/mail/pop/qpopper.config'; rslt=1
[pop_config.c:1518]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] (v4.0.5)
Servicing request from "host" at 11.22.33.44 [pop_init.c:1186]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] before TLS;
tls_support==2 [popper.c:181]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...Initializing
OpenSSL library (version OpenSSL 0.9.7c 30 Sep 2003) [pop_tls_openssl.c:230]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...have
/dev/urandom; skipping PRNG seeding [pop_tls_openssl.c:288]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...setting
method to SSLv23_server_method [pop_tls_openssl.c:312]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...allocating
OpenSSL context [pop_tls_openssl.c:342]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...setting
certificate file /etc/mail/certs/cert.pem [pop_tls_openssl.c:363]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...private key
file not set; assuming private key is in cert (/etc/mail/certs/cert.pem)
[pop_tls_openssl.c:380]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...setting
private key file /etc/mail/certs/cert.pem [pop_tls_openssl.c:384]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...verifying
private key against certificate [pop_tls_openssl.c:397]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug]
...(tls_cipher_list not specified) [pop_tls_openssl.c:424]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...allocating
OpenSSL connection [pop_tls_openssl.c:435]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...setting
input (0) and output (0) file descriptors [pop_tls_openssl.c:446]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] ...successfully
completed OpenSSL initialization [pop_tls_openssl.c:465]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] TLS Init
[popper.c:202]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] (v4.0.5) Intro
[popper.c:247]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] +OK Qpopper
(version 4.0.5) at ns1 starting. [popper.c:260]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] Qpopper ready
for input from (null) at 11.22.33.44 [11.22.33.44] [popper.c:294]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.notice] (null) at
11.22.33.44 (11.22.33.44): -ERR POP EOF or I/O Error [popper.c:820]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] +OK Pop server
at ns1 signing off. [popper.c:360]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug]
pTLS->m_pPOP->tls_started == false [pop_tls_openssl.c:823]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] freeing
m_OpenSSLconn [pop_tls_openssl.c:827]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] freeing
m_OpenSSLctx [pop_tls_openssl.c:833]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug]
openssl_shutdown returning 0 [pop_tls_openssl.c:838]
Jan 12 15:33:37 ns1 qpopper[12590]: [ID 702911 local1.debug] (v4.0.5) Ending
request from "" at (11.22.33.44) 11.22.33.44 [popper.c:378]
<<LOG2>>
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Debugging
turned on (-d) [pop_init.c:723]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Will generate
stats records (-s) [pop_init.c:858]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] tls-support=1
(-l) [pop_init.c:796]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Processing
config file '/etc/mail/pop/qpopper.config'; CallTime=1 [pop_config.c:1334]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...read line 1
(22): set tls-support = stls [pop_config.c:1370]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Set tls-support
to STLS (2) [pop_config.c:1234]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...read line 2
(51): set tls-server-cert-file = /etc/mail/certs/cert.pem
[pop_config.c:1370]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Set
tls-server-cert-file to "/etc/mail/certs/cert.pem" [pop_config.c:1250]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Finished
processing config file '/etc/mail/pop/qpopper.config'; rslt=1
[pop_config.c:1518]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] (v4.0.5)
Servicing request from "host" at 11.22.33.44 [pop_init.c:1186]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] before TLS;
tls_support==2 [popper.c:181]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...Initializing
OpenSSL library (version OpenSSL 0.9.7c 30 Sep 2003) [pop_tls_openssl.c:230]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...have
/dev/urandom; skipping PRNG seeding [pop_tls_openssl.c:288]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...setting
method to SSLv23_server_method [pop_tls_openssl.c:312]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...allocating
OpenSSL context [pop_tls_openssl.c:342]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...setting
certificate file /etc/mail/certs/cert.pem [pop_tls_openssl.c:363]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...private key
file not set; assuming private key is in cert (/etc/mail/certs/cert.pem)
[pop_tls_openssl.c:380]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...setting
private key file /etc/mail/certs/cert.pem [pop_tls_openssl.c:384]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...verifying
private key against certificate [pop_tls_openssl.c:397]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug]
...(tls_cipher_list not specified) [pop_tls_openssl.c:424]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...allocating
OpenSSL connection [pop_tls_openssl.c:435]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...setting
input (0) and output (0) file descriptors [pop_tls_openssl.c:446]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] ...successfully
completed OpenSSL initialization [pop_tls_openssl.c:465]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] TLS Init
[popper.c:202]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] (v4.0.5) Intro
[popper.c:247]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] +OK Qpopper
(version 4.0.5) at ns1 starting. [popper.c:260]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Qpopper ready
for input from (null) at 11.22.33.44 [11.22.33.44] [popper.c:294]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Received (4):
"CAPA" [pop_get_command.c:105]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] capa returned
1; CurrentState now auth1 [popper.c:338]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Qpopper ready
for input from (null) at 11.22.33.44 [11.22.33.44] [popper.c:294]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] Received (4):
"QUIT" [pop_get_command.c:105]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] quit returned
1; CurrentState now halt [popper.c:338]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] +OK Pop server
at ns1 signing off. [popper.c:360]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug]
pTLS->m_pPOP->tls_started == false [pop_tls_openssl.c:823]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] freeing
m_OpenSSLconn [pop_tls_openssl.c:827]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] freeing
m_OpenSSLctx [pop_tls_openssl.c:833]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug]
openssl_shutdown returning 0 [pop_tls_openssl.c:838]
Jan 12 15:28:23 ns1 qpopper[12588]: [ID 702911 local1.debug] (v4.0.5) Ending
request from "" at (11.22.33.44) 11.22.33.44 [popper.c:378]
