On 2014/11/25, 10:20 AM, Nigel Kukard via Users wrote:
Remove the first one, modify the second one to...
src=any,!%whitelist_quotas dest=any
Best to go back to enabling full debugging in policyd and seeing what
the policy resolution looks like by injecting the request manually.
-N
Hi Nigel
Change made as instructed.
Below is a full debug of a message sent from the address to be excluded.
I have noticed that since changing the src, nothing appears in maillog
on policyd server.
also, how would one inject a request manually?
Thanks
Tom
_*debug:*_
/[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: Process Backgrounded
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] NOTICE: Policyd v2 /
Cluebringer - v2.1.x-201310261831
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] NOTICE: Initializing system
modules.
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] NOTICE: System modules
initialized.
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] NOTICE: Module load started...
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => AccessControl: enabled
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => Accounting: enabled
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => Amavis: disabled
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => CheckHelo: enabled
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => Quotas: enabled
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => Protocol(Postfix): enabled
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: => Protocol(Bizanga): enabled
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] NOTICE: Module load done.
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] NOTICE: Session tracking is
ENABLED.
[2014/11/25-11:02:33 - 14222] [CBPOLICYD] DEBUG: Opening syslog,
destination = 'native', facility = 'mail'.
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: 2014/11/25-11:02:33 cbp
(type Net::Server::PreFork) starting! pid(14222)
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: Resolved [*]:10031 to
[::]:10031, IPv6
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: Not including resolved host
[0.0.0.0] IPv4 because it will be handled by [::] IPv6
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: Binding to TCP port 10031
on host :: with IPv6
[2014/11/25-11:02:33 - 14222] [CORE] NOTICE: Setting gid to "0 0"
[2014/11/25-11:02:33 - 14222] [CORE] INFO: Setting up serialization via
flock
[2014/11/25-11:02:33 - 14222] [CORE] INFO: Beginning prefork (8 processes)
[2014/11/25-11:02:33 - 14222] [CORE] INFO: Starting "8" children
[2014/11/25-11:02:33 - 14224] [CORE] DEBUG: Child Preforked (14224)
[2014/11/25-11:02:33 - 14224] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14225] [CORE] DEBUG: Child Preforked (14225)
[2014/11/25-11:02:33 - 14225] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14226] [CORE] DEBUG: Child Preforked (14226)
[2014/11/25-11:02:33 - 14226] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14222] [CORE] DEBUG: Parent ready for children.
[2014/11/25-11:02:33 - 14227] [CORE] DEBUG: Child Preforked (14227)
[2014/11/25-11:02:33 - 14227] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14229] [CORE] DEBUG: Child Preforked (14229)
[2014/11/25-11:02:33 - 14230] [CORE] DEBUG: Child Preforked (14230)
[2014/11/25-11:02:33 - 14229] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14230] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14228] [CORE] DEBUG: Child Preforked (14228)
[2014/11/25-11:02:33 - 14228] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:33 - 14231] [CORE] DEBUG: Child Preforked (14231)
[2014/11/25-11:02:33 - 14231] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:59 - 14222] [CORE] INFO: Starting "1" children
[2014/11/25-11:02:59 - 14224] [CORE] INFO: 2014/11/25-11:02:59 CONNECT
TCP Peer: "[::ffff:10.113.154.84]:38308" Local:
"[::ffff:10.115.244.114]:10031"
[2014/11/25-11:02:59 - 14224] [PROTOCOLS/Postfix] DEBUG: Possible
Postfix protocol
[2014/11/25-11:02:59 - 14224] [PROTOCOLS/Postfix] INFO: Identified
Postfix protocol
[2014/11/25-11:02:59 - 14234] [CORE] DEBUG: Child Preforked (14234)
[2014/11/25-11:02:59 - 14234] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: No session tracking data
exists for request: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => '',
'sasl_sender' => '',
'size' => 402,
'_timestamp' => 1416906179,
'helo_name' => 'bbdjn.domain.local',
'reverse_client_name' => 'unknown',
'queue_id' => '',
'encryption_cipher' => '',
'encryption_protocol' => '',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'_peer_address' => '::ffff:10.113.154.84',
'recipient' => '[email protected]',
'sasl_username' => '',
'instance' => '4208.547445c3.1400a.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '0',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'unknown',
'client_address' => '10.113.131.23',
'_protocol_transport' => 'Postfix'
};
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Added session tracking
information for: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => '',
'sasl_sender' => '',
'size' => 402,
'_timestamp' => 1416906179,
'helo_name' => '///bbdjn.domain.local'/,
'reverse_client_name' => 'unknown',
'queue_id' => '',
'encryption_cipher' => '',
'encryption_protocol' => '',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'_peer_address' => '::ffff:10.113.154.84',
'recipient' => '[email protected]',
'sasl_username' => '',
'instance' => '4208.547445c3.1400a.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '0',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'unknown',
'client_address' => '10.113.131.23',
'_protocol_transport' => 'Postfix'
};
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Protocol state is
'RCPT', resolving policy...
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: Going to resolve session
data into policy: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '4208.547445c3.1400a.0',
'EncryptionCipher' => '',
'Size' => '1',
'EncryptionKeySize' => '0',
'EncryptionProtocol' => '',
'Helo' => '///bbdjn.domain.local'/,
'ClientAddress' => '10.113.131.23',
'ClientName' => 'unknown',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '10.113.131.23',
'ip' => '10.113.131.23',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'Protocol' => 'ESMTP',
'ClientReverseName' => 'unknown',
'SASLMethod' => ''
};
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: Found policy member with
ID '20' in policy 'Default'
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: Found policy member with
ID '34' in policy 'Test'
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: [ID:20/Name:Default]:
Source not defined or 'any', explicit match: matched=1
[2014/11/25-11:02:59 - 14224] [POLICIES] INFO: [ID:20/Name:Default]:
Source matching result: matched=1
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: [ID:20/Name:Default]:
Destination not defined or 'any', explicit match: matched=1
[2014/11/25-11:02:59 - 14224] [POLICIES] INFO: [ID:20/Name:Default]:
Destination matching result: matched=1
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: [ID:34/Name:Test]: Main
policy sources 'any,!%whitelist_quotas'
[2014/11/25-11:02:59 - 14224] [POLICIES] WARNING: [ID:34/Name:Test]: -
Source 'any' is not a valid specification
[2014/11/25-11:02:59 - 14224] [POLICIES] INFO: [ID:34/Name:Test]: Source
matching result: matched=0
[2014/11/25-11:02:59 - 14224] [POLICIES] DEBUG: END RESULT: prio=0 =>
policy ids: 1
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Policy resolved into:
$VAR1 = {
'0' => [
'1'
]
};
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Request translated into
session data: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '4208.547445c3.1400a.0',
'EncryptionCipher' => '',
'Size' => '1',
'EncryptionKeySize' => '0',
'UnixTimestamp' => 1416906179,
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => '',
'Helo' => '///bbdjn.domain.local'/,
'ClientAddress' => '10.113.131.23',
'ClientName' => 'unknown',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '10.113.131.23',
'ip' => '10.113.131.23',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'ProtocolState' => 'RCPT',
'Policy' => {
'0' => [
'1'
]
},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'unknown',
'SASLMethod' => ''
};
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] INFO: Got request #1
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module: Access
Control Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'Access Control
Plugin' returned CBP_CONTINUE
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module:
HELO/EHLO Check Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'HELO/EHLO Check
Plugin' returned CBP_CONTINUE
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module: Quotas
Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'Quotas Plugin'
returned CBP_CONTINUE
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module:
Accounting Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'Accounting
Plugin' returned CBP_CONTINUE
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Done with modules
[2014/11/25-11:02:59 - 14224] [PROTOCOLS/Postfix] DEBUG: Possible
Postfix protocol
[2014/11/25-11:02:59 - 14224] [PROTOCOLS/Postfix] INFO: Identified
Postfix protocol
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Protocol state is
'END-OF-MESSAGE', decoding policy...
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Decoded into: $VAR1 = {
'[email protected]' => {
'0' => [
'1'
]
}
};
[2014/11/25-11:02:59 - 14224] [TRACKING] DEBUG: Request translated into
session data: $VAR1 = {
'SASLUsername' => '',
'QueueID' => 'D27C18023411',
'RecipientData' => '/<[email protected]>#0=1;',
'EncryptionCipher' => '',
'Instance' => '4208.547445c3.1400a.0',
'Size' => '1',
'EncryptionKeySize' => '0',
'UnixTimestamp' => 1416906179,
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => '',
'Helo' => '///bbdjn.domain.local'/',
'ClientAddress' => '10.113.131.23',
'ClientName' => 'unknown',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '10.113.131.23',
'ip' => '10.113.131.23',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'ProtocolState' => 'END-OF-MESSAGE',
'_Recipient_To_Policy' => {
'[email protected]' => {
'0' => [
'1'
]
}
},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'unknown',
'SASLMethod' => ''
};
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] INFO: Got request #2 (pipelined)
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module: Access
Control Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'Access Control
Plugin' returned CBP_SKIP
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module:
HELO/EHLO Check Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'HELO/EHLO Check
Plugin' returned CBP_SKIP
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module: Quotas
Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'Quotas Plugin'
returned CBP_CONTINUE
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Running module:
Accounting Plugin
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Module 'Accounting
Plugin' returned CBP_CONTINUE
[2014/11/25-11:02:59 - 14224] [CBPOLICYD] DEBUG: Done with modules
[2014/11/25-11:03:02 - 14222] [CORE] INFO: Starting "1" children
[2014/11/25-11:03:02 - 14226] [CORE] INFO: 2014/11/25-11:03:02 CONNECT
TCP Peer: "[::ffff:10.113.154.84]:38319" Local:
"[::ffff:10.115.244.114]:10031"
[2014/11/25-11:03:02 - 14226] [PROTOCOLS/Postfix] DEBUG: Possible
Postfix protocol
[2014/11/25-11:03:02 - 14226] [PROTOCOLS/Postfix] INFO: Identified
Postfix protocol
[2014/11/25-11:03:02 - 14235] [CORE] DEBUG: Child Preforked (14235)
[2014/11/25-11:03:02 - 14235] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/11/25-11:03:02 - 14226] [TRACKING] DEBUG: No session tracking data
exists for request: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => '',
'sasl_sender' => '',
'size' => 855,
'_timestamp' => 1416906182,
'helo_name' => 'localhost',
'reverse_client_name' => 'localhost',
'queue_id' => '1C23A80232C0',
'encryption_cipher' => '',
'encryption_protocol' => '',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'END-OF-MESSAGE',
'stress' => '',
'_peer_address' => '::ffff:10.113.154.84',
'recipient' => '[email protected]',
'sasl_username' => '',
'instance' => '40ff.547445c6.1a74c.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '0',
'recipient_count' => '1',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'localhost',
'client_address' => '127.0.0.1',
'_protocol_transport' => 'Postfix'
};
[2014/11/25-11:03:02 - 14226] [TRACKING] DEBUG: Protocol state is
'END-OF-MESSAGE', decoding policy...
[2014/11/25-11:03:02 - 14226] [TRACKING] DEBUG: Decoded into: $VAR1 = undef;
[2014/11/25-11:03:02 - 14226] [TRACKING] DEBUG: Request translated into
session data: $VAR1 = {
'SASLUsername' => '',
'QueueID' => '1C23A80232C0',
'RecipientData' => '',
'Instance' => '40ff.547445c6.1a74c.0',
'EncryptionCipher' => '',
'Size' => '1',
'EncryptionKeySize' => '0',
'UnixTimestamp' => 1416906182,
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => '',
'Helo' => 'localhost',
'ClientAddress' => '127.0.0.1',
'ClientName' => 'localhost',
'Sender' => '[email protected]',
'SASLSender' => '',
'_ClientAddress' => bless( {
'raw_ip' => '127.0.0.1',
'ip' => '127.0.0.1',
'ip_version' => 4,
'cidr' => 32
}, 'awitpt::netip' ),
'ProtocolState' => 'END-OF-MESSAGE',
'Protocol' => 'ESMTP',
'ClientReverseName' => 'localhost',
'SASLMethod' => ''
};
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] INFO: Got request #1
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Running module: Access
Control Plugin
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Module 'Access Control
Plugin' returned CBP_SKIP
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Running module:
HELO/EHLO Check Plugin
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Module 'HELO/EHLO Check
Plugin' returned CBP_SKIP
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Running module: Quotas
Plugin
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Module 'Quotas Plugin'
returned CBP_SKIP
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Running module:
Accounting Plugin
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Module 'Accounting
Plugin' returned CBP_SKIP
[2014/11/25-11:03:02 - 14226] [CBPOLICYD] DEBUG: Done with modules
/
_______________________________________________
Users mailing list
[email protected]
http://lists.policyd.org/mailman/listinfo/users_lists.policyd.org
