Hi, Urban, you were right about roundcube, it was in fact connecting using the local mail function. Thanks a lot for bringing that to my attention. I changed the roundcue config so that it is NOW connecting via SMTPS. I can see that in the /var/log/mail.log now.:
____________/var/log/mail.log______________________ Nov 4 10:18:45 server1 postfix/smtps/smtpd[2990]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled Nov 4 10:18:45 server1 postfix/smtps/smtpd[2990]: connect from anydomain.de[xx.xx.xx.xx] Nov 4 10:18:45 server1 postfix/smtps/smtpd[2990]: Anonymous TLS connection established from anydomain.de[xx.xx.xx.xx]: TLSv1.1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits) Nov 4 10:18:45 server1 postfix/smtps/smtpd[2990]: EF8FC34006F: client=anydomain.de[xx.xx.xx.xx], sasl_method=PLAIN, [email protected] Nov 4 10:18:46 server1 postfix/cleanup[2998]: EF8FC34006F: message-id=<[email protected]> Nov 4 10:18:46 server1 postfix/qmgr[1907]: EF8FC34006F: from=<[email protected]>, size=358, nrcpt=1 (queue active) ________________________________________________ If I now send an Outbound mail via Roundcube to an external domain, I can see that in table 'policyd.quotas_tracking' there is a new dataset appearing. That is a progress compared to my starting point. The problem is, that the value 'Counter' is always 'NULL'. I would expect that field to be '1.0000'. Each time I resend the Outbound mail the Counter again is set to 'NULL'. Again, everything is fine with Inbound mails. on 'cbpolicyd.log' I get the following log entries during sending an outbound mail which contains some strange errors: [2013/11/04-10:32:29 - 2938] [CORE] INFO: 2013/11/04-10:32:29 CONNECT TCP Peer: "[::ffff:127.0.0.1]:53869" Local: "[::ffff:127.0.0.1]:10031" [2013/11/04-10:32:29 - 1926] [CORE] INFO: Starting "1" children [2013/11/04-10:32:29 - 3063] [CORE] DEBUG: Child Preforked (3063) [2013/11/04-10:32:29 - 3063] [CBPOLICYD] DEBUG: Starting up caching engine [2013/11/04-10:32:29 - 2938] [CBPOLICYD] INFO: Got request #1 Use of uninitialized value in multiplication (*) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 181, <$read> line 4. Use of uninitialized value in subtraction (-) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 186, <$read> line 4. Use of uninitialized value in multiplication (*) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 181, <$read> line 4. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 262, <$read> line 4. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 318, <$read> line 4. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 262, <$read> line 4. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 262, <$read> line 4. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 318, <$read> line 4. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 318, <$read> line 4. [2013/11/04-10:32:29 - 2938] [CBPOLICYD] INFO: Got request #2 (pipelined) [2013/11/04-10:32:31 - 1965] [CORE] INFO: 2013/11/04-10:32:31 CONNECT TCP Peer: "[::ffff:127.0.0.1]:53883" Local: "[::ffff:127.0.0.1]:10031" [2013/11/04-10:32:31 - 1926] [CORE] INFO: Starting "1" children [2013/11/04-10:32:31 - 3087] [CORE] DEBUG: Child Preforked (3087) [2013/11/04-10:32:31 - 3087] [CBPOLICYD] DEBUG: Starting up caching engine [2013/11/04-10:32:31 - 1965] [CBPOLICYD] INFO: Got request #1 Use of uninitialized value in multiplication (*) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 181. Use of uninitialized value in subtraction (-) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 186. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 262. Use of uninitialized value in addition (+) at /usr/local/lib/cbpolicyd-2.1/cbp/modules/Quotas.pm line 318. [2013/11/04-10:32:31 - 1965] [CBPOLICYD] INFO: Got request #2 (pipelined) may that be the cause of the constant 'NULL' entry in 'policyd.quotas_tracking.Counter'? Could someone please give me a hint on that? @Urban: I tried your suggestion to change "smtpd_client_restrictions=" in my "master.cf" from: ____________master.cf____________________________ -o smtpd_client_restrictions=permit_sasl_authenticated,reject_unauth_destination,reject to -o smtpd_client_restrictions=check_policy_service inet:127.0.0.1:10031, permit_sasl_authenticated,reject_unauth_destination,reject ________________________________________________ without much luck. I got the following error message in /var/log/mail.log: ____________/var/log/mail.log______________________ Nov 3 21:47:05 server1 postfix/smtps/smtpd[9055]: fatal: unexpected command-line argument: inet:127.0.0.1:10031, ________________________________________________ @Christoph: Thanks for the great explanation. I appreciate that. regards Steffen > Gesendet: Sonntag, 03. November 2013 um 19:13 Uhr > Von: "Urban Loesch" <[email protected]> > An: [email protected] > Betreff: Re: [policyd-users] Outgoing quota problem - only Inbound is working > > Hi Steffen, > > you can put "check_policy_service,inet:127.0.0.1:10031" in your "smtps" > section in "master.cf" after "smtpd_client_restrictions=" and then > restart postfix. This should activate policyd for smtps on port 465 too. > Check your logs after restart to be sure all is running correctly. > > Are you sure roundcoube connects via smtps to postfix and smtps? > The first row of the logs below say something else. "uid=33" tells me > that the mail was submitted by the webservers user id. On Debian user id > 33 is the user on which apache is running (www-data). > > Am 03.11.2013 17:41, schrieb Steffen Wegner: > > Nov 3 17:08:17 server1 postfix/pickup[3329]: 76EB034006F: uid=33 > > from=<[email protected]> > > Nov 3 17:08:17 server1 postfix/cleanup[6730]: 76EB034006F: > > message-id=<[email protected]> > > Nov 3 17:08:17 server1 postfix/qmgr[1843]: 76EB034006F: > > from=<[email protected]>, size=522, nrcpt=1 (queue active) > > Nov 3 17:08:17 server1 postfix/smtp[6736]: 76EB034006F: > > to=<[email protected]>, relay=mx-ha03.web.de[213.165.67.104]:25, > > delay=0.44, delays=0.03/0.01/0.2/0.21, dsn=2.0.0, status=sent (250 > > Requested mail action okay, completed: id=0M71LJ-1VpQMm3FJN-00wknM) > > Nov 3 17:08:17 server1 postfix/qmgr[1843]: 76EB034006F: removed > > > If I read your logs correctly it seems that roundcube does not connect > via smtps, but it uses the local php mail function. > See here for a explanation of local submissions: > http://www.postfix.org/OVERVIEW.html > > I have no experience with roundcube but you should check your roundcube > config to see if it uses the local sendmail command or really the smtps > port 465. > > Reagards > Urban > > > > > > > > > > > _______________________________________________ > Users mailing list > [email protected] > http://lists.policyd.org/mailman/listinfo/users_lists.policyd.org > _______________________________________________ Users mailing list [email protected] http://lists.policyd.org/mailman/listinfo/users_lists.policyd.org
