Thread Info
  • State Not Answered
  • Replies 9 replies
  • Subscribers 0 subscribers
  • Views 5883 views
  • Users 0 members are here
Options
Suggested

[9.075][BUG] Pop3 Prefetcher exception occurred

ThomasPe
Hello,

I have an big problem (reciving emails)with the pop3 SSL proxy, especially with the prefetcher. Iam not sure if this is an bug or worng configuration.

The pop3 log file: 
2013:03:25-06:34:36 Idefix pop3proxy[7843]: Prefetch for account 1: Successfully logged in on POP3 server 85.214.90.95
2013:03:25-06:35:36 Idefix pop3proxy[7843]: SslServer timeout
2013:03:25-06:35:36 Idefix pop3proxy[7843]: Prefetcher exception occurred
2013:03:25-06:35:36 Idefix pop3proxy[7843]: Failed to shutdown SSL connection 

last log entry:

2013:03:25-07:41:17 Idefix pop3proxy[16506]: SslClient 192.168.10.10 has closed the connection
2013:03:25-07:44:49 Idefix pop3proxy[16764]: Accepted client connection from 192.168.10.10 for 85.214.90.95 (Linet server_id 1)
2013:03:25-07:44:49 Idefix pop3proxy[16764]: Client: Wrong password for user ****@linet.de (account_id 1)
2013:03:25-07:44:49 Idefix pop3proxy[16764]: Failed to shutdown SSL connection
2013:03:25-07:44:49 Idefix pop3proxy[16764]: Password updated for account 1
2013:03:25-07:44:49 Idefix pop3proxy[16764]: ****@linet.de logged in (account 1)
2013:03:25-07:44:50 Idefix pop3proxy[16764]: Creating quarantine report
2013:03:25-07:44:50 Idefix pop3proxy[16764]: Warning: Can't open digest-image gradient.png: No such file or directory
2013:03:25-07:44:50 Idefix pop3proxy[16764]: Client 192.168.10.10 logged out (account=1, deleted=0)
2013:03:25-07:44:55 Idefix pop3proxy[16774]: Prefetch for account 1: Successfully logged in on POP3 server 85.214.90.95
2013:03:25-07:45:56 Idefix pop3proxy[16774]: SslServer timeout
2013:03:25-07:45:56 Idefix pop3proxy[16774]: Prefetcher exception occurred
2013:03:25-07:45:56 Idefix pop3proxy[16774]: Failed to shutdown SSL connection 

----
LiveLog Update , email address are removed

2013:03:25-09:33:44 Idefix pop3proxy[31041]: Prefetch for account 3: Successfully logged in on POP3 server 85.214.90.95
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from=""
2013:03:25-09:33:45 Idefix pop3proxy[31041]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="
2013:03:25-09:33:46 Idefix pop3proxy[31041]: id="1101" severity="info" sys="SecureMail" sub="pop3" name="email quarantined" from="
2013:03:25-09:34:46 Idefix pop3proxy[31041]: SslServer timeout
2013:03:25-09:34:46 Idefix pop3proxy[31041]: Prefetcher exception occurred
2013:03:25-09:34:46 Idefix pop3proxy[31041]: Failed to shutdown SSL connection 

2013:03:25-10:33:33 Idefix pop3proxy[7094]: Accepted client connection from 192.168.10.10 for 85.214.90.95 (Linet server_id 1)
2013:03:25-10:33:33 Idefix pop3proxy[7094]: Client: Wrong password for user lava (account_id 3)
2013:03:25-10:33:34 Idefix pop3proxy[7094]: Failed to shutdown SSL connection
2013:03:25-10:33:34 Idefix pop3proxy[7094]: Password updated for account 3
2013:03:25-10:33:34 Idefix pop3proxy[7094]: lava logged in (account 3)
2013:03:25-10:33:34 Idefix pop3proxy[7094]: Client 192.168.10.10 logged out (account=3, deleted=0) 

ok I have recived a couple of mails, but the prefetch error still exists. I have checked my mail password its correct. I dont understand the log entry 2013:03:25-10:33:33 Idefix pop3proxy[7094]: Client: Wrong password for user lava (account_id 3).

Iam unsing Thunderbird as mailclient with following configuration
Email Clients sind alle Mozilla Thunderbird 17.0.4
email server: pop.linet.de
Port:995
connection security: SSL/TLS
authentication[:P]asswort/normal

Pop3 proxy UTM 9.075:
Global: 

allowed networks:Internal (Network) 

advancend:
POP3 servers and prefetch settings:
pop server is -> pop.linet.de
TLS Certificate:Webadmin certificat for Idefix
use prefetch mode -> activated
Prefetch interval -> 900s

Furthermore I have created two user accounts in the user portal. 

Any help would be appreciated. 

thanks Thomas
  • 0
    Hi Thomas,

    Please provide more information for the pop3 logs by increasing the log level. In order to do this, follow the steps below:

    -> vim /var/chroot-pop3/etc/pop3proxy.conf and change loglevel to 5
    -> vim /var/chroot-pop3/etc/pop3proxy.conf-default and change loglevel to 5
    -> restart pop3: /var/mdw/scripts/pop3 restart

    Please post the logs with the results. Not sure right now why you are getting the "Client: Wrong password for user lava" and almoust instantly you get "password updated".

    Did u ever try UTM version 9.0 with the same setup and same pop3 server?
    Regards,
    Bianca
  • 0 in reply to Tinkerbell
    Hello Bianca, thanks for your quick reply.

    ok after changing loglevels to 5 and restart the pop3 proxy here is the livelog for a short period


    Live Log: POP3 proxy 
    Filter: 
    Autoscroll
    2013:03:26-19:45:23 Idefix pop3proxy[4327]: Cleanup 31680 exited normally
    2013:03:26-19:47:58 Idefix pop3proxy[4327]: Master terminated
    2013:03:26-19:49:12 Idefix pop3proxy[4327]: Master started
    2013:03:26-19:49:12 Idefix pop3proxy[4327]: Forked cleanup 4330
    2013:03:26-19:49:12 Idefix pop3proxy[4330]: Cleanup terminates normally
    2013:03:26-19:49:12 Idefix pop3proxy[4327]: Cleanup 4330 exited normally
    2013:03:26-19:51:29 Idefix pop3proxy[4327]: Reloading configuration
    2013:03:26-19:51:29 Idefix pop3proxy[4327]: Forked cleanup 5956
    2013:03:26-19:51:29 Idefix pop3proxy[5956]: Cleanup terminates normally
    2013:03:26-19:51:29 Idefix pop3proxy[4327]: Cleanup 5956 exited normally
    2013:03:26-19:51:45 Idefix pop3proxy[4327]: Forked SSL client 6000
    2013:03:26-19:51:45 Idefix pop3proxy[6000]: Spawning a new SSL client handler for accepted connection from 192.168.10.10
    2013:03:26-19:51:45 Idefix pop3proxy[6000]: Accepted client connection from 192.168.10.10 for 85.214.90.95 (pop.linet.de Servers server_id 3)
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: SSL references REF_CaHosWebadCertiFor REF_PopSerPopliServe
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load default SSL certificate /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.cert
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load default SSL key /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.key
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Fatal: Failed to load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Failed to load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Client: Account lava not present in database
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Server said +OK Hello there. 
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Failed to shutdown SSL connection
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Connection and authentication at remote server succeeded
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Account 8 added
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: lava logged in (account 8)
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Quarantine report for account 8 is due
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Quarantine report for account 8 would be empty, skipping...
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Client 192.168.10.10 logged out (account=8, deleted=0)
    2013:03:26-19:51:46 Idefix pop3proxy[4327]: Client 6000 exited normally
    2013:03:26-19:51:59 Idefix pop3proxy[4327]: 1 accounts to fetch, 0 prefetcher are running, starting 1 new ones
    2013:03:26-19:51:59 Idefix pop3proxy[4327]: Forked prefetcher 6016
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch: Acquired lock for account 8
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch for account=8, ref=REF_PopSerPopliServe ip=85.214.90.95
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch for account 8: Successfully connected to POP3 server 85.214.90.95
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch for account 8: Successfully logged in on POP3 server 85.214.90.95
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch: Retrieved message (uid UID5919-1310384787) from server
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Skip expression scanning: Disabled in configuration
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Skip scanning: Internal notification message
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: skips: av 1 spam 1 extension 1 expression 1
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Scan result: OK
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Will save message on proxy (0/6016-1-1364323919)
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="do-not-reply@fw-notify.net" to="*****@linet.de" subject="[Idefix][WARN-007] Failed console login" size="1481" srcip="0.0.0.0" dstip="85.214.90.95" uid="UID5919-1310384787" ident="0/6016-1-1364323919"
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: RemoteMail::scan() returns with 0
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch: Retrieved message (uid UID5920-1310384787) from server
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Skip expression scanning: Disabled in configuration
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Skip scanning: Internal notification message
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: skips: av 1 spam 1 extension 1 expression 1
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Scan result: OK
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Will save message on proxy (0/6016-2-1364323919)
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="do-not-reply@fw-notify.net" to="*******@linet.de" subject="[Idefix][INFO-000] System was restarted" size="1432" srcip="0.0.0.0" dstip="85.214.90.95" uid="UID5920-1310384787" ident="0/6016-2-1364323919"
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: RemoteMail::scan() returns with 0
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch for account 8 finished (fetched=2, deleted=0, not_on_server=0)
    2013:03:26-19:51:59 Idefix pop3proxy[6016]: Prefetch: Released lock for account 8
    2013:03:26-19:52:11 Idefix pop3proxy[4327]: Forked SSL client 6034
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Spawning a new SSL client handler for accepted connection from 192.168.10.10
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Accepted client connection from 192.168.10.10 for 85.214.90.95 (pop.linet.de Servers server_id 3)
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: SSL references REF_CaHosWebadCertiFor REF_PopSerPopliServe
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Load default SSL certificate /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.cert
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Load default SSL key /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.key
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Fatal: Failed to load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:52:11 Idefix pop3proxy[6034]: Failed to load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Client: Authentication succeeded (user lava, account_id 8)
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Not connected to remote server because local authentication succeeded and prefetch mode is enabled
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: lava logged in (account 8)
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Client wants message #1
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Unpinned message #96
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Client wants message #2
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Unpinned message #97
    2013:03:26-19:52:12 Idefix pop3proxy[6034]: Client 192.168.10.10 logged out (account=8, deleted=0)
    2013:03:26-19:52:12 Idefix pop3proxy[4327]: Client 6034 exited normally
    2013:03:26-19:52:30 Idefix pop3proxy[6016]: Prefetcher 6016 terminates normally
    2013:03:26-19:52:30 Idefix pop3proxy[4327]: Prefetcher 6016 exited normally
    2013:03:26-19:53:28 Idefix pop3proxy[4327]: Forked SSL client 6130
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Spawning a new SSL client handler for accepted connection from 192.168.10.10
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Accepted client connection from 192.168.10.10 for 85.214.90.95 (pop.linet.de Servers server_id 3)
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: SSL references REF_CaHosWebadCertiFor REF_PopSerPopliServe
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Load default SSL certificate /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.cert
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Load default SSL key /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.key
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Fatal: Failed to load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Failed to load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Client: Authentication succeeded (user lava, account_id 8)
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: Not connected to remote server because local authentication succeeded and prefetch mode is enabled
    2013:03:26-19:53:28 Idefix pop3proxy[6130]: lava logged in (account 8)
    2013:03:26-19:53:29 Idefix pop3proxy[6130]: Client 192.168.10.10 logged out (account=8, deleted=0)
    2013:03:26-19:53:29 Idefix pop3proxy[4327]: Client 6130 exited normally
    2013:03:26-19:59:52 Idefix pop3proxy[4327]: Forked SSL client 6740
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Spawning a new SSL client handler for accepted connection from 192.168.10.11
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Accepted client connection from 192.168.10.11 for 85.214.90.95 (pop.linet.de Servers server_id 3)
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: SSL references REF_CaHosWebadCertiFor REF_PopSerPopliServe
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Load default SSL certificate /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.cert
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Load default SSL key /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.key
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Fatal: Failed to load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:59:52 Idefix pop3proxy[6740]: Failed to load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:59:54 Idefix pop3proxy[6740]: Client: Account falkenhorst not present in database
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Server said +OK Hello there. 
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Failed to shutdown SSL connection
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Connection and authentication at remote server succeeded
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Account 9 added
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: falkenhorst logged in (account 9)
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Quarantine report for account 9 is due
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Quarantine report for account 9 would be empty, skipping...
    2013:03:26-19:59:55 Idefix pop3proxy[6740]: Client 192.168.10.11 logged out (account=9, deleted=0)
    2013:03:26-19:59:55 Idefix pop3proxy[4327]: Client 6740 exited normally
    2013:03:26-19:59:59 Idefix pop3proxy[4327]: 1 accounts to fetch, 0 prefetcher are running, starting 1 new ones
    2013:03:26-19:59:59 Idefix pop3proxy[4327]: Forked prefetcher 6750
    2013:03:26-19:59:59 Idefix pop3proxy[6750]: Prefetch: Acquired lock for account 9
    2013:03:26-19:59:59 Idefix pop3proxy[6750]: Prefetch for account=9, ref=REF_PopSerPopliServe ip=85.214.90.95
    2013:03:26-19:59:59 Idefix pop3proxy[6750]: Prefetch for account 9: Successfully connected to POP3 server 85.214.90.95
    2013:03:26-19:59:59 Idefix pop3proxy[6750]: Prefetch for account 9: Successfully logged in on POP3 server 85.214.90.95
    2013:03:26-19:59:59 Idefix pop3proxy[6750]: Prefetch: Retrieved message (uid UID8281-1310385098) from server
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: Skip expression scanning: Disabled in configuration
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: skips: av 0 spam 0 extension 0 expression 1
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: Scan result: OK
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: Will save message on proxy (0/6750-1-1364324399)
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: Scanned for spam, CTCH-RefID: str=0001.0A0C0207.5151F030.00B4:SCGMA553950,ss=1,re=-4.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=1024
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="ebay@ebay.de" to="***********@linet.de" subject="Leider waren Sie nicht Höchstbietender " size="64541" srcip="0.0.0.0" dstip="85.214.90.95" uid="UID8281-1310385098" ident="0/6750-1-1364324399"
    2013:03:26-20:00:00 Idefix pop3proxy[6750]: RemoteMail::scan() returns with 0
    2013:03:26-20:01:00 Idefix pop3proxy[6750]: SslServer timeout
    2013:03:26-20:01:00 Idefix pop3proxy[6750]: Prefetcher exception occurred
    2013:03:26-20:01:00 Idefix pop3proxy[6750]: Failed to shutdown SSL connection
    2013:03:26-20:01:00 Idefix pop3proxy[6750]: Prefetch: Released lock for account 9
    2013:03:26-20:01:30 Idefix pop3proxy[4327]: Prefetcher 6750 exited normally
    2013:03:26-20:07:00 Idefix pop3proxy[4327]: 1 accounts to fetch, 0 prefetcher are running, starting 1 new ones
    2013:03:26-20:07:00 Idefix pop3proxy[4327]: Forked prefetcher 8030
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Prefetch: Acquired lock for account 8
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Prefetch for account=8, ref=REF_PopSerPopliServe ip=85.214.90.95
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Prefetch for account 8: Successfully connected to POP3 server 85.214.90.95
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Prefetch for account 8: Successfully logged in on POP3 server 85.214.90.95
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Prefetch: Retrieved message (uid UID5921-1310384787) from server
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Skip expression scanning: Disabled in configuration
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: skips: av 0 spam 0 extension 0 expression 1
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Scan result: OK
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Will save message on proxy (0/8030-1-1364324820)
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: Scanned for spam, CTCH-RefID: str=0001.0A0C0205.5151F1D4.00B3,ss=1,re=0.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=0
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: id="1100" severity="info" sys="SecureMail" sub="pop3" name="email passed" from="*****" to="Thomas " subject="Re: test" size="1439" srcip="87.143.235.57" dstip="85.214.90.95" uid="UID5921-1310384787" ident="0/8030-1-1364324820"
    2013:03:26-20:07:00 Idefix pop3proxy[8030]: RemoteMail::scan() returns with 0
    2013:03:26-20:08:00 Idefix pop3proxy[8030]: SslServer timeout
    2013:03:26-20:08:00 Idefix pop3proxy[8030]: Prefetcher exception occurred
    2013:03:26-20:08:00 Idefix pop3proxy[8030]: Failed to shutdown SSL connection
    2013:03:26-20:08:00 Idefix pop3proxy[8030]: Prefetch: Released lock for account 8
    2013:03:26-20:08:28 Idefix pop3proxy[4327]: Forked SSL client 8145
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Spawning a new SSL client handler for accepted connection from 192.168.10.10
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Accepted client connection from 192.168.10.10 for 85.214.90.95 (pop.linet.de Servers server_id 3)
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: SSL references REF_CaHosWebadCertiFor REF_PopSerPopliServe
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Load default SSL certificate /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.cert
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Load default SSL key /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.key
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Fatal: Failed to load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Failed to load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Client: Authentication succeeded (user lava, account_id 8)
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: Not connected to remote server because local authentication succeeded and prefetch mode is enabled
    2013:03:26-20:08:28 Idefix pop3proxy[8145]: lava logged in (account 8)
    2013:03:26-20:08:29 Idefix pop3proxy[8145]: Client wants message #3
    2013:03:26-20:08:29 Idefix pop3proxy[8145]: Unpinned message #99
    2013:03:26-20:08:29 Idefix pop3proxy[8145]: Client 192.168.10.10 logged out (account=8, deleted=0)
    2013:03:26-20:08:29 Idefix pop3proxy[4327]: Client 8145 exited normally
    2013:03:26-20:08:30 Idefix pop3proxy[4327]: Prefetcher 8030 exited normally


    it seems that there is a problem during loading the ssl key an certificate

    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load default SSL certificate /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.cert
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load default SSL key /etc/pop3proxy.conf.includes/DREF_CaHosWebadCertiFor.key
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Fatal: Failed to load SSL certificate /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.cert
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key
    2013:03:26-19:51:46 Idefix pop3proxy[6000]: Failed to load SSL key /etc/pop3proxy.conf.includes/REF_PopSerPopliServe.key

    but I am not sure whats the reason?


    I have played a bit around with the pop3 ssl proxy. If I turn off the prefetcher function , remove the pop3 prefetcher server and disable the prefetch time and do some relogging I am able to recive mails. [:S]

    I hope this information would help you.

    greetings Thomas
  • 0
    Thanks for reporting. We are now tracking this as Mantis ID #25070
  • 0 in reply to Astaro Beta Bot
    Hi Thomas,

    Opened a bug for your issue. Apparently the problem is the SSL timeout.
    Do you have IPS enabled? Or Application Control? I'm asking you this because there were some "faults" in Pop3 with them enabled/in use.
    If the Pop3 prefetching error occurs again, and if you are using the features could you maybe provide the logs? ips.log / afc.log

    Thank you. Best regards,
    Bianca
  • 0
    Hi Bianca,

    Yes I have IPS enabled and Application controll disabled. 

    I have installed the 9.091 beta from scratch new. After that I have configured all settings in my utm new, to see if the pop3 prefetcher works. The result was that for one day all works fine, prefetching especially .

    At the next day the prefetcher wont work. You can see this in the log files.
    I hope the log files will to solve this issue. 

    I will attche the ips.logs for you and the pop3.log.

    greetings Thomas
    Ips-pop3logs.zip
  • 0
    The Mantis ID #25070 is now being worked on. We are planning to release a fix for this issue in Version 9.109.
  • 0
    We are planning to release a fix for this issue in Version 9.102.
Unfiltered HTML