Hi,
I still have problems with the Amavis-Integration and try to find the problem.
One question regarding the installation instruction on
http://wiki.policyd.org/installing:
The instruction states that I need to add a line to the amavisd.conf
('include_config_files('/path/to/amavisd-policyd.pm');').
As I use Ubuntu 12.04 I added this line into "/etc/amavis/conf.d/50-user".
Is that right? Im not shure about it.
kindly Nigel checked my cluebringer.conf which seems to look fine and looks
loike this:
---------------------------/etc/postfix/main.cf-------------------------------------
smtpd_recipient_restrictions = check_policy_service inet:127.0.0.1:10031,
reject_unauth_pipelining, permit_mynetworks, permit_sasl_authenticated,
reject_non_fqdn_recipient, reject_unknown_recipient_domain,
reject_unauth_destination, check_policy_service inet:127.0.0.1:10023, permit
smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:10031
------------------------------------------------------------------------------------
so everything ok here.
But it seems like the plugin is not running. Could someone take a look at my
debugging log and give me some hint pls.
--------------/var/log/cbpolicyd/cbpolicyd.log---on
log_level=4----------------------
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: Process Backgrounded
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] NOTICE: Policyd v2 / Cluebringer -
v2.1.x-201310261831
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] NOTICE: Initializing system modules.
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] NOTICE: System modules initialized.
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] NOTICE: Module load started...
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => AccessControl: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => Accounting: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => Amavis: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => CheckHelo: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => CheckSPF: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => Greylisting: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => Quotas: enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => Protocol(Postfix): enabled
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: => Protocol(Bizanga): enabled
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] NOTICE: Module load done.
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] NOTICE: Session tracking is ENABLED.
[2013/11/10-16:41:44 - 10881] [CBPOLICYD] DEBUG: Opening syslog, destination =
'native', facility = 'ARRAY(0x3136980)'.
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: 2013/11/10-16:41:44 cbp (type
Net::Server::PreFork) starting! pid(10881)
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: Resolved [*]:10031 to [::]:10031,
IPv6
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: Not including resolved host
[0.0.0.0] IPv4 because it will be handled by [::] IPv6
[2013/11/10-16:41:44 - 10881] [CORE] NOTICE: Binding to TCP port 10031 on host
:: with IPv6
[2013/11/10-16:41:44 - 10881] [CORE] INFO: Setting up serialization via flock
[2013/11/10-16:41:44 - 10881] [CORE] INFO: Beginning prefork (4 processes)
[2013/11/10-16:41:44 - 10881] [CORE] INFO: Starting "4" children
[2013/11/10-16:41:44 - 10881] [CORE] DEBUG: Parent ready for children.
[2013/11/10-16:41:44 - 10885] [CORE] DEBUG: Child Preforked (10885)
[2013/11/10-16:41:44 - 10885] [CBPOLICYD] DEBUG: Starting up caching engine
[2013/11/10-16:41:44 - 10886] [CORE] DEBUG: Child Preforked (10886)
[2013/11/10-16:41:44 - 10886] [CBPOLICYD] DEBUG: Starting up caching engine
[2013/11/10-16:41:44 - 10884] [CORE] DEBUG: Child Preforked (10884)
[2013/11/10-16:41:44 - 10884] [CBPOLICYD] DEBUG: Starting up caching engine
[2013/11/10-16:41:44 - 10887] [CORE] DEBUG: Child Preforked (10887)
[2013/11/10-16:41:44 - 10887] [CBPOLICYD] DEBUG: Starting up caching engine
[2013/11/10-16:42:47 - 10881] [CORE] INFO: Starting "1" children
[2013/11/10-16:42:47 - 10887] [CORE] INFO: 2013/11/10-16:42:47 CONNECT TCP
Peer: "[::ffff:127.0.0.1]:33656" Local: "[::ffff:127.0.0.1]:10031"
[2013/11/10-16:42:47 - 10906] [CORE] DEBUG: Child Preforked (10906)
[2013/11/10-16:42:47 - 10906] [CBPOLICYD] DEBUG: Starting up caching engine
[2013/11/10-16:42:47 - 10887] [PROTOCOLS/Postfix] DEBUG: Possible Postfix
protocol
[2013/11/10-16:42:47 - 10887] [PROTOCOLS/Postfix] INFO: Identified Postfix
protocol
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: No session tracking data exists
for request: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => 'PLAIN',
'sasl_sender' => '',
'size' => 0,
'_timestamp' => 1384098167,
'helo_name' => 'www.anydomain.de',
'reverse_client_name' => 'server1.anydomain.de',
'queue_id' => '',
'encryption_cipher' => 'ECDHE-RSA-AES256-SHA',
'encryption_protocol' => 'TLSv1.1',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'_peer_address' => '::ffff:127.0.0.1',
'sasl_username' => '[email protected]',
'recipient' => '[email protected]',
'ccert_pubkey_fingerprint' => '',
'instance' => '2a94.527fa977.5557b.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '256',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'server1.anydomain.de',
'client_address' => '***.***.***.***',
'_protocol_transport' => 'Postfix'
};
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Added session tracking
information for: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => 'PLAIN',
'sasl_sender' => '',
'size' => 0,
'_timestamp' => 1384098167,
'helo_name' => 'www.anydomain.de',
'reverse_client_name' => 'server1.anydomain.de',
'queue_id' => '',
'encryption_cipher' => 'ECDHE-RSA-AES256-SHA',
'encryption_protocol' => 'TLSv1.1',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'_peer_address' => '::ffff:127.0.0.1',
'sasl_username' => '[email protected]',
'recipient' => '[email protected]',
'ccert_pubkey_fingerprint' => '',
'instance' => '2a94.527fa977.5557b.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '256',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'server1.anydomain.de',
'client_address' => '***.***.***.***',
'_protocol_transport' => 'Postfix'
};
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Protocol state is 'RCPT',
resolving policy...
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: Going to resolve session data
into policy: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '[email protected]',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '2a94.527fa977.5557b.0',
'EncryptionCipher' => 'ECDHE-RSA-AES256-SHA',
'Size' => '0',
'EncryptionKeySize' => '256',
'EncryptionProtocol' => 'TLSv1.1',
'Helo' => 'www.anydomain.de',
'ClientAddress' => '***.***.***.***',
'ClientName' => 'server1.anydomain.de',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '***.***.***.***',
'ip' => '***.***.***.***',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'Protocol' => 'ESMTP',
'ClientReverseName' => 'server1.anydomain.de',
'SASLMethod' => 'PLAIN'
};
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: Found policy member with ID '6'
in policy 'Default Outbound'
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default Outbound]:
Main policy sources '%SASL_users'
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default Outbound]:
Group 'SASL_users' has 2 source(s) =>
[email protected],[email protected]
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default
Outbound]=>(group:SASL_users): - Resolved source '[email protected]'
to a email address specification, match = 1
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default
Outbound]=>(group:SASL_users): Source group result: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] INFO: [ID:6/Name:Default Outbound]:
Source matching result: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default Outbound]:
Destination not defined or 'any', explicit match: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] INFO: [ID:6/Name:Default Outbound]:
Destination matching result: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: END RESULT: prio=10 => policy
ids: 2
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Policy resolved into: $VAR1 = {
'10' => [
'2'
]
};
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Request translated into session
data: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '[email protected]',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '2a94.527fa977.5557b.0',
'EncryptionCipher' => 'ECDHE-RSA-AES256-SHA',
'Size' => '0',
'EncryptionKeySize' => '256',
'UnixTimestamp' => 1384098167,
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => 'TLSv1.1',
'Helo' => 'www.anydomain.de',
'ClientAddress' => '***.***.***.***',
'ClientName' => 'server1.anydomain.de',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '***.***.***.***',
'ip' => '***.***.***.***',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'ProtocolState' => 'RCPT',
'Policy' => {
'10' => [
'2'
]
},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'server1.anydomain.de',
'SASLMethod' => 'PLAIN'
};
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] INFO: Got request #1
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Access Control
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Access Control Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: HELO/EHLO
Check Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'HELO/EHLO Check
Plugin' returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: SPF Check
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'SPF Check Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Greylisting
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Greylisting Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Quotas Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Quotas Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Accounting
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Accounting Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Done with modules
[2013/11/10-16:42:47 - 10887] [PROTOCOLS/Postfix] DEBUG: Possible Postfix
protocol
[2013/11/10-16:42:47 - 10887] [PROTOCOLS/Postfix] INFO: Identified Postfix
protocol
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Protocol state is 'RCPT',
resolving policy...
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: Going to resolve session data
into policy: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '[email protected]',
'QueueID' => '',
'RecipientData' => '/<[email protected]>#10=2;',
'EncryptionCipher' => 'ECDHE-RSA-AES256-SHA',
'Instance' => '2a94.527fa977.5557b.0',
'Size' => '0',
'EncryptionKeySize' => '256',
'UnixTimestamp' => '1384098167',
'EncryptionProtocol' => 'TLSv1.1',
'Helo' => 'www.anydomain.de',
'ClientAddress' => '***.***.***.***',
'ClientName' => 'server1.anydomain.de',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '***.***.***.***',
'ip' => '***.***.***.***',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'Protocol' => 'ESMTP',
'ClientReverseName' => 'server1.anydomain.de',
'SASLMethod' => 'PLAIN'
};
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: Found policy member with ID '6'
in policy 'Default Outbound'
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default Outbound]:
Main policy sources '%SASL_users'
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default Outbound]:
Group 'SASL_users' has 2 source(s) =>
[email protected],[email protected]
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default
Outbound]=>(group:SASL_users): - Resolved source '[email protected]'
to a email address specification, match = 1
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default
Outbound]=>(group:SASL_users): Source group result: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] INFO: [ID:6/Name:Default Outbound]:
Source matching result: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: [ID:6/Name:Default Outbound]:
Destination not defined or 'any', explicit match: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] INFO: [ID:6/Name:Default Outbound]:
Destination matching result: matched=1
[2013/11/10-16:42:47 - 10887] [POLICIES] DEBUG: END RESULT: prio=10 => policy
ids: 2
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Policy resolved into: $VAR1 = {
'10' => [
'2'
]
};
[2013/11/10-16:42:47 - 10887] [TRACKING] DEBUG: Request translated into session
data: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '[email protected]',
'QueueID' => '',
'RecipientData' => '/<[email protected]>#10=2;',
'EncryptionCipher' => 'ECDHE-RSA-AES256-SHA',
'Instance' => '2a94.527fa977.5557b.0',
'Size' => '0',
'EncryptionKeySize' => '256',
'UnixTimestamp' => 1384098167,
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => 'TLSv1.1',
'Helo' => 'www.anydomain.de',
'ClientAddress' => '***.***.***.***',
'ClientName' => 'server1.anydomain.de',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '***.***.***.***',
'ip' => '***.***.***.***',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'ProtocolState' => 'RCPT',
'Policy' => {
'10' => [
'2'
]
},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'server1.anydomain.de',
'SASLMethod' => 'PLAIN'
};
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] INFO: Got request #2 (pipelined)
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Access Control
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Access Control Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: HELO/EHLO
Check Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'HELO/EHLO Check
Plugin' returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: SPF Check
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'SPF Check Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Greylisting
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Greylisting Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Quotas Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Quotas Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Running module: Accounting
Plugin
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Module 'Accounting Plugin'
returned CBP_CONTINUE
[2013/11/10-16:42:47 - 10887] [CBPOLICYD] DEBUG: Done with modules
> Gesendet: Freitag, 08. November 2013 um 23:38 Uhr
> Von: "Nigel Kukard" <[email protected]>
> An: [email protected]
> Betreff: Re: [policyd-users] Optional Amavisd Support - BCC rule not working?
>
> On 11/08/2013 07:48 PM, Steffen Wegner wrote:
> > Hi Nigel,
> > thank you for comming back so fast always.
> > You wrote
> >> Please enable full debugging.
> > i already did that, by changing the log_level in "/etc/cluebringer.conf" to
> > log_level=4.
> > Is there something else that I need to change?
>
> A few lines above or below, there is another option which describes what
> to log. Enable everything.
>
>
> >
> > smtpd_recipient_restrictions = check_policy_service inet:127.0.0.1:10031,
> > reject_unauth_pipelining, permit_mynetworks, permit_sasl_authenticated,
> > reject_non_fqdn_recipient, reject_unknown_recipient_domain,
> > reject_unauth_destination, check_policy_service inet:127.0.0.1:10023, permit
> >
> > # nach policyd-Anleitung:
> > smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:10031
>
> Those look fine
>
>
> -N
>
>
> _______________________________________________
> 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