On 02/08/11 02:02, Nigel Kukard wrote:
> On 08/01/11 03:13, Juan Rossi wrote:
>> Hi,
>>
>> No advances with this here.
>>
>> Will some of the developers point me to the place where the piece of
>> code that associates the modules with the policies.
>>
>> Also the piece of code that handles the priority of the policies, as
>> stated in the documentation:
>>
>> Priorities are processed in an ascending fashion, this means that 0 will
>> be processed before 1 and 10 before 20.
>>
>> What I think is happening is that a set of modules is being generated,
>> ignoring the policy priority, since there is a set of policies that
>> matches, then the module priority applies for the module set.
>>
>> It does not make much sense to me have policy priorities this way, it
>> only affects the processing of the policies only.
>>
>> I have tested using the stable version, form the site, not the debian
>> package, the same happens.
>>
>>
>> Regards.
>>
>> Juan.-
>>
>>
>>
>>
>> On 17/07/11 10:03, Juan Rossi wrote:
>>> On 07/12/2011 09:26 PM, Robert Anderson wrote:
>>>> On 07/12/11 04:31, Juan Rossi wrote:
>>>>> Sure, here we go, with a second policy, that has more priority:
>>>>>
>>>>>
>>>>> Prio:25 - Default unauthenticated, !%internal_ips,
>>>>> !%unauthenticated_src_whitelist, !%unauthenticated_dest_white
>>>>>
>>>>> Prio:26 - Default Filter unauthenticated, that do not come from internal
>>>>> ips, and are not whilisted as unauthenticated sources or destinations
>>>>>
>>>>>
>>>>> Prio:35 - Default authenticated,!%authenticated_whitelist
>>>>>
>>>>>
>>>>> I have the greylisting module enabled (greylist name: policy):
>>>>>
>>>>> Do not Greylist: Default authenticated,!%authenticated_whitelist
>>>>>
>>>>> Greylist: Default unauthenticated, !%internal_ips,
>>>>> !%unauthenticated_src_whitelist, !%unauthenticated_dest_whitelist
>>>>>
>>>>> Access module configured with (name: policy: veredict: data)
>>>>>
>>>>> spamfiltering : Default Filter unauthenticated, that do not come from
>>>>> internal ips, and are not whilisted as unauthenticated sources or
>>>>> destinations : FILTER : spamassassin:dummy
>>>>>
>>>>>
>>>>> The log is the following, the bits important I think they are on the
>>>>> scope of:
>>>>>
>>>>> [2011/07/12-02:22:24 - 31441] [CBPOLICYD] DEBUG: Got request, running
>>>>> modules...
>>>>> [2011/07/12-02:22:24 - 31441] [CBPOLICYD] DEBUG: Running module: Access
>>>>> Control Plugin
>>>>> [2011/07/12-02:22:24 - 31441] [CBPOLICYD] DEBUG: Done with modules
>>>>>
>>>>>
>>>>> Seems that policies do not get resolved one after another, the access
>>>>> module, even dough that is in second priority takes over:
>>>>>
>>>>>
>>>>> debug log:
>>>>>
>>>>>
>>>>> [2011/07/12-02:22:24 - 31441] [CORE] INFO: 2011/07/12-02:22:24 CONNECT
>>>>> TCP Peer: "127.0.0.1:44366" Local: "127.0.0.1:10031"
>>>>> [2011/07/12-02:22:24 - 31412] [CORE] INFO: Starting "1" children
>>>>> [2011/07/12-02:22:24 - 31441] [TRACKING] DEBUG: No session tracking data
>>>>> exists for request: $VAR1 = {
>>>>> 'ccert_fingerprint' => '',
>>>>> 'sasl_method' => '',
>>>>> 'sasl_sender' => '',
>>>>> 'size' => '1094',
>>>>> '_timestamp' => 1310437344,
>>>>> 'helo_name' => 'mail.rimuhosting.com',
>>>>> 'reverse_client_name' => 'mail.rimuhosting.com',
>>>>> 'queue_id' => '',
>>>>> 'encryption_cipher' => '',
>>>>> 'encryption_protocol' => '',
>>>>> 'etrn_domain' => '',
>>>>> 'ccert_subject' => '',
>>>>> 'request' => 'smtpd_access_policy',
>>>>> 'protocol_state' => 'RCPT',
>>>>> 'stress' => '',
>>>>> 'recipient' => '[email protected]',
>>>>> 'sasl_username' => '',
>>>>> 'instance' => '14f.4e1bafe0.e9450.0',
>>>>> 'protocol_name' => 'ESMTP',
>>>>> 'encryption_keysize' => '0',
>>>>> 'recipient_count' => '0',
>>>>> 'ccert_issuer' => '',
>>>>> 'sender' => '[email protected]',
>>>>> 'client_name' => 'mail.rimuhosting.com',
>>>>> 'client_address' => '206.123.102.5',
>>>>> '_protocol_transport' => 'Postfix'
>>>>> };
>>>>> [2011/07/12-02:22:24 - 31441] [TRACKING] DEBUG: Added session tracking
>>>>> information for: $VAR1 = {
>>>>> 'ccert_fingerprint' => '',
>>>>> 'sasl_method' => '',
>>>>> 'sasl_sender' => '',
>>>>> 'size' => '1094',
>>>>> '_timestamp' => 1310437344,
>>>>> 'helo_name' => 'mail.rimuhosting.com',
>>>>> 'reverse_client_name' => 'mail.rimuhosting.com',
>>>>> 'queue_id' => '',
>>>>> 'encryption_cipher' => '',
>>>>> 'encryption_protocol' => '',
>>>>> 'etrn_domain' => '',
>>>>> 'ccert_subject' => '',
>>>>> 'request' => 'smtpd_access_policy',
>>>>> 'protocol_state' => 'RCPT',
>>>>> 'stress' => '',
>>>>> 'recipient' => '[email protected]',
>>>>> 'sasl_username' => '',
>>>>> 'instance' => '14f.4e1bafe0.e9450.0',
>>>>> 'protocol_name' => 'ESMTP',
>>>>> 'encryption_keysize' => '0',
>>>>> 'recipient_count' => '0',
>>>>> 'ccert_issuer' => '',
>>>>> 'sender' => '[email protected]',
>>>>> 'client_name' => 'mail.rimuhosting.com',
>>>>> 'client_address' => '206.123.102.5',
>>>>> '_protocol_transport' => 'Postfix'
>>>>> };
>>>>> [2011/07/12-02:22:24 - 31441] [TRACKING] DEBUG: Protocol state is
>>>>> 'RCPT', resolving policy...
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: Going to resolve session
>>>>> data into policy: $VAR1 = {
>>>>> 'Recipient' => '[email protected]',
>>>>> 'SASLUsername' => '',
>>>>> 'QueueID' => '',
>>>>> 'RecipientData' => '',
>>>>> 'Instance' => '14f.4e1bafe0.e9450.0',
>>>>> 'EncryptionCipher' => '',
>>>>> 'Size' => '2',
>>>>> 'EncryptionKeySize' => '0',
>>>>> 'EncryptionProtocol' => '',
>>>>> 'Helo' => 'mail.rimuhosting.com',
>>>>> 'ClientAddress' => '206.123.102.5',
>>>>> 'ClientName' => 'mail.rimuhosting.com',
>>>>> 'Sender' => '[email protected]',
>>>>> 'SASLSender' => '',
>>>>> 'Protocol' => 'ESMTP',
>>>>> 'ClientReverseName' => 'mail.rimuhosting.com',
>>>>> 'SASLMethod' => ''
>>>>> };
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: Found policy member with
>>>>> ID '1' in policy 'Default'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: Found policy member with
>>>>> ID '6' in policy 'Default authenticated,!%authenticated_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: Found policy member with
>>>>> ID '7' in policy 'Default unauthenticated, !%internal_ips,
>>>>> !%unauthenticated_src_whitelist, !%unauthenticated_dest_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: Found policy member with
>>>>> ID '8' in policy 'Default Filter unauthenticated, that do not come from
>>>>> internal ips, and are not whilisted as unauthenticated sources or
>>>>> destinations'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:1/Name:Default]:
>>>>> Source not defined or 'any', explicit match: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:1/Name:Default]:
>>>>> Source matching result: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:1/Name:Default]:
>>>>> Destination not defined or 'any', explicit match: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:1/Name:Default]:
>>>>> Destination matching result: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:6/Name:Default
>>>>> authenticated,!%authenticated_whitelist]: Main policy sources
>>>>> '$*,!%authenticated_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:6/Name:Default
>>>>> authenticated,!%authenticated_whitelist]: - Resolved source '$*' to a
>>>>> SASL user specification, match = 0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:6/Name:Default
>>>>> authenticated,!%authenticated_whitelist]: Source matching result:
>>>>> matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Main policy sources
>>>>> '$-,!%internal_ips,!%unauthenticated_src_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: - Resolved source '$-' to a SASL user
>>>>> specification, match = 1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Group 'internal_ips' has 1 source(s)
>>>>> => 127.0.0.0/8
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]=>(group:internal_ips): - Resolved
>>>>> source '127.0.0.0/8' to a IP/CIDR specification, match = 0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]=>(group:internal_ips): Source group
>>>>> result: matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Group 'unauthenticated_src_whitelist'
>>>>> has 0 source(s) =>
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] WARNING: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: No group members for source group
>>>>> 'unauthenticated_src_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]=>(group:unauthenticated_src_whitelist):
>>>>> Source
>>>>> group result: matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Source matching result: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Main policy destinations
>>>>> '!%unauthenticated_dest_whitelist'
>>>>> [2011/07/12-02:22:24 - 339] [CORE] DEBUG: Child Preforked (339)
>>>>> [2011/07/12-02:22:24 - 339] [CBPOLICYD] DEBUG: Starting up caching engine
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Group
>>>>> 'unauthenticated_dest_whitelist' has 0 destination(s) =>
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] WARNING: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: No group members for destination
>>>>> group 'unauthenticated_dest_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]=>(group:unauthenticated_dest_whitelist):
>>>>>
>>>>> Destination group result: matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:7/Name:Default
>>>>> unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
>>>>> !%unauthenticated_dest_whitelist]: Destination matching result: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Main policy
>>>>> sources '$-,!%internal_ips,!%unauthenticated_src_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: - Resolved source
>>>>> '$-' to a SASL user specification, match = 1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Group
>>>>> 'internal_ips' has 1 source(s) => 127.0.0.0/8
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or
>>>>> destinations]=>(group:internal_ips): - Resolved source '127.0.0.0/8' to
>>>>> a IP/CIDR specification, match = 0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or
>>>>> destinations]=>(group:internal_ips): Source group result: matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Group
>>>>> 'unauthenticated_src_whitelist' has 0 source(s) =>
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] WARNING: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: No group members
>>>>> for source group 'unauthenticated_src_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or
>>>>> destinations]=>(group:unauthenticated_src_whitelist): Source group
>>>>> result: matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:8/Name:Default Filter
>>>>> unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Source matching
>>>>> result: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Main policy
>>>>> destinations '!%unauthenticated_dest_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Group
>>>>> 'unauthenticated_dest_whitelist' has 0 destination(s) =>
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] WARNING: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: No group members
>>>>> for destination group 'unauthenticated_dest_whitelist'
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: [ID:8/Name:Default
>>>>> Filter unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or
>>>>> destinations]=>(group:unauthenticated_dest_whitelist): Destination group
>>>>> result: matched=0
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] INFO: [ID:8/Name:Default Filter
>>>>> unauthenticated, that do not come from internal ips, and are not
>>>>> whilisted as unauthenticated sources or destinations]: Destination
>>>>> matching result: matched=1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: END RESULT: prio=0 =>
>>>>> policy ids: 1
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: END RESULT: prio=25 =>
>>>>> policy ids: 7
>>>>> [2011/07/12-02:22:24 - 31441] [POLICIES] DEBUG: END RESULT: prio=26 =>
>>>>> policy ids: 8
>>>>> [2011/07/12-02:22:24 - 31441] [TRACKING] DEBUG: Policy resolved into:
>>>>> $VAR1 = {
>>>>> '25' => [
>>>>> '7'
>>>>> ],
>>>>> '0' => [
>>>>> '1'
>>>>> ],
>>>>> '26' => [
>>>>> '8'
>>>>> ]
>>>>> };
>>>>> [2011/07/12-02:22:24 - 31441] [TRACKING] DEBUG: Request translated into
>>>>> session data: $VAR1 = {
>>>>> 'Recipient' => '[email protected]',
>>>>> 'SASLUsername' => '',
>>>>> 'QueueID' => '',
>>>>> 'RecipientData' => '',
>>>>> 'Instance' => '14f.4e1bafe0.e9450.0',
>>>>> 'EncryptionCipher' => '',
>>>>> 'Size' => '2',
>>>>> 'EncryptionKeySize' => '0',
>>>>> 'ParsedClientAddress' => {
>>>>> 'Broadcast_Long' => 3464193541,
>>>>> 'Network' => '206.123.102.5',
>>>>> 'IP_Long' => 3464193541,
>>>>> 'Broadcast' => '206.123.102.5',
>>>>> 'IP' => '206.123.102.5',
>>>>> 'Mask_Long' => 4294967295,
>>>>> 'Network_Long' => 3464193541
>>>>> },
>>>>> 'ProtocolTransport' => 'Postfix',
>>>>> 'EncryptionProtocol' => '',
>>>>> 'Helo' => 'mail.rimuhosting.com',
>>>>> 'ClientAddress' => '206.123.102.5',
>>>>> 'ClientName' => 'mail.rimuhosting.com',
>>>>> 'Sender' => '[email protected]',
>>>>> 'SASLSender' => '',
>>>>> 'Timestamp' => 1310437344,
>>>>> 'ProtocolState' => 'RCPT',
>>>>> 'Policy' => {
>>>>> '25' => [
>>>>> '7'
>>>>> ],
>>>>> '0' => [
>>>>> '1'
>>>>> ],
>>>>> '26' => [
>>>>> '8'
>>>>> ]
>>>>> },
>>>>> 'Protocol' => 'ESMTP',
>>>>> 'ClientReverseName' => 'mail.rimuhosting.com',
>>>>> 'SASLMethod' => ''
>>>>> };
>>>>> [2011/07/12-02:22:24 - 31441] [CBPOLICYD] DEBUG: Got request, running
>>>>> modules...
>>>>> [2011/07/12-02:22:24 - 31441] [CBPOLICYD] DEBUG: Running module: Access
>>>>> Control Plugin
>>>>> [2011/07/12-02:22:24 - 31441] [CBPOLICYD] DEBUG: Done with modules
>>>>> [2011/07/12-02:22:26 - 32158] [CORE] INFO: 2011/07/12-02:22:26 CONNECT
>>>>> TCP Peer: "127.0.0.1:44367" Local: "127.0.0.1:10031"
>>>>> [2011/07/12-02:22:26 - 32158] [TRACKING] DEBUG: Protocol state is
>>>>> 'END-OF-MESSAGE', decoding policy...
>>>>> [2011/07/12-02:22:26 - 32158] [TRACKING] DEBUG: Decoded into: $VAR1 = {
>>>>> '[email protected]' => {
>>>>> '25' => [
>>>>> '7'
>>>>> ],
>>>>> '0' => [
>>>>> '1'
>>>>> ],
>>>>> '26' => [
>>>>> '8'
>>>>> ]
>>>>> }
>>>>> };
>>>>> [2011/07/12-02:22:26 - 32158] [TRACKING] DEBUG: Request translated into
>>>>> session data: $VAR1 = {
>>>>> 'SASLUsername' => '',
>>>>> 'QueueID' => '02F94604BD',
>>>>> 'RecipientData' => '/<[email protected]>#25=7;0=1;26=8;',
>>>>> 'EncryptionCipher' => '',
>>>>> 'Instance' => '14f.4e1bafe0.e9450.0',
>>>>> 'Size' => '2',
>>>>> 'EncryptionKeySize' => '0',
>>>>> 'ParsedClientAddress' => {
>>>>> 'Broadcast_Long' => 3464193541,
>>>>> 'Network' => '206.123.102.5',
>>>>> 'IP_Long' => 3464193541,
>>>>> 'Broadcast' => '206.123.102.5',
>>>>> 'IP' => '206.123.102.5',
>>>>> 'Mask_Long' => 4294967295,
>>>>> 'Network_Long' => 3464193541
>>>>> },
>>>>> 'ProtocolTransport' => 'Postfix',
>>>>> 'EncryptionProtocol' => '',
>>>>> 'Helo' => 'mail.rimuhosting.com',
>>>>> 'ClientAddress' => '206.123.102.5',
>>>>> 'ClientName' => 'mail.rimuhosting.com',
>>>>> 'Sender' => '[email protected]',
>>>>> 'SASLSender' => '',
>>>>> 'Timestamp' => 1310437346,
>>>>> 'ProtocolState' => 'END-OF-MESSAGE',
>>>>> '_Recipient_To_Policy' => {
>>>>> '[email protected]' => {
>>>>>
>>>>> '25' => [
>>>>>
>>>>> '7'
>>>>>
>>>>> ],
>>>>>
>>>>> '0' => [
>>>>>
>>>>> '1'
>>>>>
>>>>> ],
>>>>>
>>>>> '26' => [
>>>>>
>>>>> '8'
>>>>>
>>>>> ]
>>>>> }
>>>>> },
>>>>> 'Protocol' => 'ESMTP',
>>>>> 'ClientReverseName' => 'mail.rimuhosting.com',
>>>>> 'SASLMethod' => ''
>>>>> };
>>>>> [2011/07/12-02:22:26 - 32158] [CBPOLICYD] DEBUG: Got request, running
>>>>> modules...
>>>>> [2011/07/12-02:22:26 - 32158] [CBPOLICYD] DEBUG: Running module: Access
>>>>> Control Plugin
>>>>> [2011/07/12-02:22:26 - 32158] [CBPOLICYD] DEBUG: Running module:
>>>>> HELO/EHLO Check Plugin
>>>>> [2011/07/12-02:22:26 - 32158] [CBPOLICYD] DEBUG: Running module:
>>>>> Greylisting Plugin
>>>>> [2011/07/12-02:22:26 - 32158] [CBPOLICYD] DEBUG: Running module: Quotas
>>>>> Plugin
>>>>> [2011/07/12-02:22:26 - 32158] [CBPOLICYD] DEBUG: Done with modules
>>>>> [2011/07/12-02:23:06 - 31412] [CORE] INFO: Killing "1" children
>>>>> [2011/07/12-02:23:06 - 339] [CBPOLICYD] DEBUG: Shutting down caching
>>>>> engine (339)
>>>> Could you provide us with the following:
>>>>
>>>> * results of a select * on the related policy tables
>>>> * sections configured for policyd in your postfix config
>>>> * policyd debugging config
>>> Sure,
>>>
>>> here we go:
>>>
>>> mysql> select * from policies where disabled=0 \G
>>> *************************** 1. row ***************************
>>> ID: 1
>>> Name: Default
>>> Priority: 0
>>> Description: Default System Policy
>>> Disabled: 0
>>> *************************** 2. row ***************************
>>> ID: 6
>>> Name: Default authenticated,!%authenticated_whitelist
>>> Priority: 35
>>> Description: Default policy to match authenticated, that do not belong
>>> to the authenticated_whitelist
>>> Disabled: 0
>>> *************************** 3. row ***************************
>>> ID: 7
>>> Name: Default unauthenticated, !%internal_ips,
>>> !%unauthenticated_src_whitelist, !%unauthenticated_dest_whitelist
>>> Priority: 25
>>> Description: Default policy to match unauthenticated, that do not come
>>> from internal ips, and are not whilisted as unauthenticated sources or
>>> destinations
>>> Disabled: 0
>>> *************************** 4. row ***************************
>>> ID: 8
>>> Name: Default Filter unauthenticated, that do not come from
>>> internal ips, and are not whilisted as unauthenticated sources or
>>> destinations
>>> Priority: 26
>>> Description: Default Filter unauthenticated, that do not come from
>>> internal ips, and are not whilisted as unauthenticated sources or
>>> destinations
>>> Disabled: 0
>>> 4 rows in set (0.00 sec)
>>>
>>> mysql> select * from policy_members where disabled=0 \G
>>> *************************** 1. row ***************************
>>> ID: 1
>>> PolicyID: 1
>>> Source: NULL
>>> Destination: NULL
>>> Comment: NULL
>>> Disabled: 0
>>> *************************** 2. row ***************************
>>> ID: 2
>>> PolicyID: 2
>>> Source: %internal_ips,%internal_domains
>>> Destination: !%internal_domains
>>> Comment: NULL
>>> Disabled: 0
>>> *************************** 3. row ***************************
>>> ID: 3
>>> PolicyID: 3
>>> Source: !%internal_ips,!%internal_domains
>>> Destination: %internal_domains
>>> Comment: NULL
>>> Disabled: 0
>>> *************************** 4. row ***************************
>>> ID: 4
>>> PolicyID: 4
>>> Source: %internal_ips,%internal_domains
>>> Destination: %internal_domains
>>> Comment: NULL
>>> Disabled: 0
>>> *************************** 5. row ***************************
>>> ID: 6
>>> PolicyID: 6
>>> Source: $*,!%authenticated_whitelist
>>> Destination: any
>>> Comment:
>>> Disabled: 0
>>> *************************** 6. row ***************************
>>> ID: 7
>>> PolicyID: 7
>>> Source: $-,!%internal_ips,!%unauthenticated_src_whitelist
>>> Destination: !%unauthenticated_dest_whitelist
>>> Comment:
>>> Disabled: 0
>>> *************************** 7. row ***************************
>>> ID: 8
>>> PolicyID: 8
>>> Source: $-,!%internal_ips,!%unauthenticated_src_whitelist
>>> Destination: !%unauthenticated_dest_whitelist
>>> Comment:
>>> Disabled: 0
>>> 7 rows in set (0.00 sec)
>>>
>>> mysql> select * from access_control \G
>>> *************************** 1. row ***************************
>>> ID: 2
>>> PolicyID: 8
>>> Name: spamfiltering
>>> Verdict: FILTER
>>> Data: spamassassin:dummy
>>> Comment:
>>> Disabled: 0
>>> 1 row in set (0.00 sec)
>>>
>>> mysql> select * from greylisting \G
>>> *************************** 1. row ***************************
>>> ID: 1
>>> PolicyID: 6
>>> Name: Do not Greylist
>>> UseGreylisting: 0
>>> GreylistPeriod: NULL
>>> Track: SenderIP:/32
>>> GreylistAuthValidity: NULL
>>> GreylistUnAuthValidity: NULL
>>> UseAutoWhitelist: 0
>>> AutoWhitelistPeriod: NULL
>>> AutoWhitelistCount: NULL
>>> AutoWhitelistPercentage: NULL
>>> UseAutoBlacklist: 0
>>> AutoBlacklistPeriod: NULL
>>> AutoBlacklistCount: NULL
>>> AutoBlacklistPercentage: NULL
>>> Comment:
>>> Disabled: 0
>>> *************************** 2. row ***************************
>>> ID: 2
>>> PolicyID: 7
>>> Name: Greylist
>>> UseGreylisting: 1
>>> GreylistPeriod: 240
>>> Track: SenderIP:/32
>>> GreylistAuthValidity: 604800
>>> GreylistUnAuthValidity: 8640
>>> UseAutoWhitelist: 0
>>> AutoWhitelistPeriod: NULL
>>> AutoWhitelistCount: NULL
>>> AutoWhitelistPercentage: NULL
>>> UseAutoBlacklist: 0
>>> AutoBlacklistPeriod: NULL
>>> AutoBlacklistCount: NULL
>>> AutoBlacklistPercentage: NULL
>>> Comment:
>>> Disabled: 0
>>> 2 rows in set (0.02 sec)
>>>
>>>
>>>
>>> postfix configuration:
>>>
>>> # postconf | grep 10031
>>> smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:10031
>>> smtpd_recipient_restrictions = check_policy_service
>>> inet:127.0.0.1:10031, permit_mynetworks, permit_sasl_authenticated,
>>> reject_unauth_destination
>>>
>>>
>>> cluebringer.conf log configuration
>>>
>>>
>>> log_file=/var/log/cbpolicyd.log
>>> log_mail=mail@syslog:native
>>> log_detail=modules,tracking,policies
>
> Can you add this around line 564, above "# Check Response"
> $self->log(LOG_ERR,"MODULE RAN: $module / $res");
>
> Rerun your setup and paste a full log of the issue above.
>
> Regards
> Nigel
>
Ok the code in /usr/local/sbin/cbpolicyd is like
534 # Run request in eval
535 my $res;
536 eval {
537 $res =
$module->{'request_process'}($self,$sessionData);
538 };
539 $self->log(LOG_ERR,"MODULE RAN: $module / $res");
540 # Check results
541 if ($@) {
Here is the log for another test:
# /usr/local/sbin/cbpolicyd --fg
[2011/08/02-23:08:35 - 9138] [CBPOLICYD] NOTICE: Policyd v2 /
Cluebringer - v2.0.11
[2011/08/02-23:08:35 - 9138] [CBPOLICYD] NOTICE: Initializing system
modules.
[2011/08/02-23:08:35 - 9138] [CBPOLICYD] NOTICE: System modules initialized.
[2011/08/02-23:08:35 - 9138] [CBPOLICYD] NOTICE: Module load started...
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => AccessControl: enabled
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => CheckHelo: enabled
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => CheckSPF: enabled
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => Greylisting: enabled
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => Quotas: enabled
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => Protocol(Postfix): enabled
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: => Protocol(Bizanga): enabled
[2011/08/02-23:08:35 - 9138] [CBPOLICYD] NOTICE: Module load done.
[2011/08/02-23:08:35 - 9138] [CBPOLICYD] DEBUG: Opening syslog,
destination = 'native', facility = 'mail'.
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: 2011/08/02-23:08:35 cbp
(type Net::Server::PreFork) starting! pid(9138)
[2011/08/02-23:08:35 - 9138] [CORE] NOTICE: Binding to TCP port 10031 on
host 127.0.0.1
[2011/08/02-23:08:35 - 9138] [CORE] WARNING: Group Not Defined.
Defaulting to EGID '0 0'
[2011/08/02-23:08:35 - 9138] [CORE] WARNING: User Not Defined.
Defaulting to EUID '0'
[2011/08/02-23:08:35 - 9138] [CORE] INFO: Setting up serialization via flock
[2011/08/02-23:08:35 - 9138] [CORE] INFO: Beginning prefork (4 processes)
[2011/08/02-23:08:35 - 9138] [CORE] INFO: Starting "4" children
[2011/08/02-23:08:35 - 9140] [CORE] DEBUG: Child Preforked (9140)
[2011/08/02-23:08:35 - 9140] [CBPOLICYD] DEBUG: Starting up caching engine
[2011/08/02-23:08:35 - 9139] [CORE] DEBUG: Child Preforked (9139)
[2011/08/02-23:08:35 - 9139] [CBPOLICYD] DEBUG: Starting up caching engine
[2011/08/02-23:08:35 - 9141] [CORE] DEBUG: Child Preforked (9141)
[2011/08/02-23:08:35 - 9141] [CBPOLICYD] DEBUG: Starting up caching engine
[2011/08/02-23:08:35 - 9138] [CORE] DEBUG: Parent ready for children.
[2011/08/02-23:08:35 - 9142] [CORE] DEBUG: Child Preforked (9142)
[2011/08/02-23:08:35 - 9142] [CBPOLICYD] DEBUG: Starting up caching engine
[2011/08/02-23:09:02 - 9140] [CORE] INFO: 2011/08/02-23:09:02 CONNECT
TCP Peer: "127.0.0.1:37905" Local: "127.0.0.1:10031"
[2011/08/02-23:09:02 - 9138] [CORE] INFO: Starting "1" children
[2011/08/02-23:09:02 - 9140] [TRACKING] DEBUG: No session tracking data
exists for request: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => '',
'sasl_sender' => '',
'size' => '1092',
'_timestamp' => 1312326542,
'helo_name' => 'mail.rimuhosting.com',
'reverse_client_name' => 'mail.rimuhosting.com',
'queue_id' => '',
'encryption_cipher' => '',
'encryption_protocol' => '',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'recipient' => '[email protected]',
'sasl_username' => '',
'instance' => '23bf.4e38838e.edf4b.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '0',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'mail.rimuhosting.com',
'client_address' => '206.123.102.5',
'_protocol_transport' => 'Postfix'
};
[2011/08/02-23:09:02 - 9140] [TRACKING] DEBUG: Added session tracking
information for: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => '',
'sasl_sender' => '',
'size' => '1092',
'_timestamp' => 1312326542,
'helo_name' => 'mail.rimuhosting.com',
'reverse_client_name' => 'mail.rimuhosting.com',
'queue_id' => '',
'encryption_cipher' => '',
'encryption_protocol' => '',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'recipient' => '[email protected]',
'sasl_username' => '',
'instance' => '23bf.4e38838e.edf4b.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '0',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '[email protected]',
'client_name' => 'mail.rimuhosting.com',
'client_address' => '206.123.102.5',
'_protocol_transport' => 'Postfix'
};
[2011/08/02-23:09:02 - 9155] [CORE] DEBUG: Child Preforked (9155)
[2011/08/02-23:09:02 - 9155] [CBPOLICYD] DEBUG: Starting up caching engine
[2011/08/02-23:09:03 - 9140] [TRACKING] DEBUG: Protocol state is 'RCPT',
resolving policy...
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: Going to resolve session
data into policy: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '23bf.4e38838e.edf4b.0',
'EncryptionCipher' => '',
'Size' => '1092',
'EncryptionKeySize' => '0',
'EncryptionProtocol' => '',
'Helo' => 'mail.rimuhosting.com',
'ClientAddress' => '206.123.102.5',
'ClientName' => 'mail.rimuhosting.com',
'Sender' => '[email protected]',
'SASLSender' => '',
'Protocol' => 'ESMTP',
'ClientReverseName' => 'mail.rimuhosting.com',
'SASLMethod' => ''
};
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: Found policy member with
ID '1' in policy 'Default'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: Found policy member with
ID '6' in policy 'Default authenticated,!%authenticated_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: Found policy member with
ID '7' in policy 'Default unauthenticated, !%internal_ips,
!%unauthenticated_src_whitelist, !%unauthenticated_dest_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: Found policy member with
ID '8' in policy 'Default Filter unauthenticated, that do not come from
internal ips, and are not whilisted as unauthenticated sources or
destinations'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:1/Name:Default]:
Source not defined or 'any', explicit match: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:1/Name:Default]:
Source matching result: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:1/Name:Default]:
Destination not defined or 'any', explicit match: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:1/Name:Default]:
Destination matching result: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:6/Name:Default
authenticated,!%authenticated_whitelist]: Main policy sources
'$*,!%authenticated_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:6/Name:Default
authenticated,!%authenticated_whitelist]: - Resolved source '$*' to a
SASL user specification, match = 0
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:6/Name:Default
authenticated,!%authenticated_whitelist]: Source matching result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Main policy sources
'$-,!%internal_ips,!%unauthenticated_src_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: - Resolved source '$-' to a SASL user
specification, match = 1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Group 'internal_ips' has 1 source(s)
=> 127.0.0.0/8
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]=>(group:internal_ips): - Resolved
source '127.0.0.0/8' to a IP/CIDR specification, match = 0
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]=>(group:internal_ips): Source group
result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Group 'unauthenticated_src_whitelist'
has 0 source(s) =>
[2011/08/02-23:09:03 - 9140] [POLICIES] WARNING: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: No group members for source group
'unauthenticated_src_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]=>(group:unauthenticated_src_whitelist):
Source
group result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Source matching result: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Main policy destinations
'!%unauthenticated_dest_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Group
'unauthenticated_dest_whitelist' has 0 destination(s) =>
[2011/08/02-23:09:03 - 9140] [POLICIES] WARNING: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: No group members for destination
group 'unauthenticated_dest_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]=>(group:unauthenticated_dest_whitelist):
Destination group result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:7/Name:Default
unauthenticated, !%internal_ips, !%unauthenticated_src_whitelist,
!%unauthenticated_dest_whitelist]: Destination matching result: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Main policy
sources '$-,!%internal_ips,!%unauthenticated_src_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: - Resolved source
'$-' to a SASL user specification, match = 1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Group
'internal_ips' has 1 source(s) => 127.0.0.0/8
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or
destinations]=>(group:internal_ips): - Resolved source '127.0.0.0/8' to
a IP/CIDR specification, match = 0
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or
destinations]=>(group:internal_ips): Source group result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Group
'unauthenticated_src_whitelist' has 0 source(s) =>
[2011/08/02-23:09:03 - 9140] [POLICIES] WARNING: [ID:8/Name:Default
Filter unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: No group members
for source group 'unauthenticated_src_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or
destinations]=>(group:unauthenticated_src_whitelist): Source group
result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Source matching
result: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Main policy
destinations '!%unauthenticated_dest_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Group
'unauthenticated_dest_whitelist' has 0 destination(s) =>
[2011/08/02-23:09:03 - 9140] [POLICIES] WARNING: [ID:8/Name:Default
Filter unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: No group members
for destination group 'unauthenticated_dest_whitelist'
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or
destinations]=>(group:unauthenticated_dest_whitelist): Destination group
result: matched=0
[2011/08/02-23:09:03 - 9140] [POLICIES] INFO: [ID:8/Name:Default Filter
unauthenticated, that do not come from internal ips, and are not
whilisted as unauthenticated sources or destinations]: Destination
matching result: matched=1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: END RESULT: prio=0 =>
policy ids: 1
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: END RESULT: prio=25 =>
policy ids: 7
[2011/08/02-23:09:03 - 9140] [POLICIES] DEBUG: END RESULT: prio=26 =>
policy ids: 8
[2011/08/02-23:09:03 - 9140] [TRACKING] DEBUG: Policy resolved into:
$VAR1 = {
'25' => [
'7'
],
'0' => [
'1'
],
'26' => [
'8'
]
};
[2011/08/02-23:09:03 - 9140] [TRACKING] DEBUG: Request translated into
session data: $VAR1 = {
'Recipient' => '[email protected]',
'SASLUsername' => '',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '23bf.4e38838e.edf4b.0',
'EncryptionCipher' => '',
'Size' => '1092',
'EncryptionKeySize' => '0',
'ParsedClientAddress' => {
'Broadcast_Long' => 3464193541,
'Network' => '206.123.102.5',
'IP_Long' => 3464193541,
'Broadcast' => '206.123.102.5',
'IP' => '206.123.102.5',
'Mask_Long' => 4294967295,
'Network_Long' => 3464193541
},
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => '',
'Helo' => 'mail.rimuhosting.com',
'ClientAddress' => '206.123.102.5',
'ClientName' => 'mail.rimuhosting.com',
'Sender' => '[email protected]',
'SASLSender' => '',
'Timestamp' => 1312326542,
'ProtocolState' => 'RCPT',
'Policy' => {
'25' => [
'7'
],
'0' => [
'1'
],
'26' => [
'8'
]
},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'mail.rimuhosting.com',
'SASLMethod' => ''
};
[2011/08/02-23:09:03 - 9140] [CBPOLICYD] DEBUG: Got request, running
modules...
[2011/08/02-23:09:03 - 9140] [CBPOLICYD] DEBUG: Running module: Access
Control Plugin
[2011/08/02-23:09:03 - 9140] [CORE] ERROR: MODULE RAN: HASH(0x87a9ef8) / 1
[2011/08/02-23:09:03 - 9140] [CBPOLICYD] DEBUG: Done with modules
[2011/08/02-23:09:04 - 9139] [CORE] INFO: 2011/08/02-23:09:04 CONNECT
TCP Peer: "127.0.0.1:37906" Local: "127.0.0.1:10031"
[2011/08/02-23:09:04 - 9139] [TRACKING] DEBUG: Protocol state is
'END-OF-MESSAGE', decoding policy...
[2011/08/02-23:09:04 - 9139] [TRACKING] DEBUG: Decoded into: $VAR1 = {
'[email protected]' => {
'25' => [
'7'
],
'0' => [
'1'
],
'26' => [
'8'
]
}
};
[2011/08/02-23:09:04 - 9139] [TRACKING] DEBUG: Request translated into
session data: $VAR1 = {
'SASLUsername' => '',
'QueueID' => '3A84B604BD',
'RecipientData' => '/<[email protected]>#25=7;0=1;26=8;',
'EncryptionCipher' => '',
'Instance' => '23bf.4e38838e.edf4b.0',
'Size' => '1092',
'EncryptionKeySize' => '0',
'ParsedClientAddress' => {
'Broadcast_Long' => 3464193541,
'Network' => '206.123.102.5',
'IP_Long' => 3464193541,
'Broadcast' => '206.123.102.5',
'IP' => '206.123.102.5',
'Mask_Long' => 4294967295,
'Network_Long' => 3464193541
},
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => '',
'Helo' => 'mail.rimuhosting.com',
'ClientAddress' => '206.123.102.5',
'ClientName' => 'mail.rimuhosting.com',
'Sender' => '[email protected]',
'SASLSender' => '',
'Timestamp' => 1312326544,
'ProtocolState' => 'END-OF-MESSAGE',
'_Recipient_To_Policy' => {
'[email protected]' => {
'25' => [
'7'
],
'0' => [
'1'
],
'26' => [
'8'
]
}
},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'mail.rimuhosting.com',
'SASLMethod' => ''
};
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Got request, running
modules...
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Running module: Access
Control Plugin
[2011/08/02-23:09:04 - 9139] [CORE] ERROR: MODULE RAN: HASH(0x87a9ef8) / 2
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Running module:
HELO/EHLO Check Plugin
[2011/08/02-23:09:04 - 9139] [CORE] ERROR: MODULE RAN: HASH(0x88d7648) / 2
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Running module: SPF
Check Plugin
[2011/08/02-23:09:04 - 9139] [CORE] ERROR: MODULE RAN: HASH(0x88d2598) / 2
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Running module:
Greylisting Plugin
[2011/08/02-23:09:04 - 9139] [CORE] ERROR: MODULE RAN: HASH(0x8a57ec0) / 2
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Running module: Quotas
Plugin
[2011/08/02-23:09:04 - 9139] [CORE] ERROR: MODULE RAN: HASH(0x8a73248) / 0
[2011/08/02-23:09:04 - 9139] [CBPOLICYD] DEBUG: Done with modules
^C[2011/08/02-23:09:33 - 9155] [CBPOLICYD] DEBUG: Shutting down caching
engine (9155)
[2011/08/02-23:09:33 - 9142] [CBPOLICYD] DEBUG: Shutting down caching
engine (9142)
[2011/08/02-23:09:33 - 9141] [CBPOLICYD] DEBUG: Shutting down caching
engine (9141)
[2011/08/02-23:09:33 - 9140] [CBPOLICYD] DEBUG: Shutting down caching
engine (9140)
[2011/08/02-23:09:33 - 9139] [CBPOLICYD] DEBUG: Shutting down caching
engine (9139)
[2011/08/02-23:09:33 - 9138] [CORE] NOTICE: 2011/08/02-23:09:33 Server
closing!
[2011/08/02-23:09:33 - 9138] [CORE] DEBUG: Destroying system modules.
[2011/08/02-23:09:33 - 9138] [CORE] DEBUG: System modules destroyed.
[2011/08/02-23:09:33 - 9138] [CORE] DEBUG: Closing syslog.
[2011/08/02-23:09:33 - 9138] [CORE] DEBUG: Syslog closed.
[2011/08/02-23:09:33 - 9140] [CBPOLICYD] DEBUG: Shutting down caching
engine (9140)
[2011/08/02-23:09:33 - 9139] [CBPOLICYD] DEBUG: Shutting down caching
engine (9139)
[2011/08/02-23:09:33 - 9141] [CBPOLICYD] DEBUG: Shutting down caching
engine (9141)
[2011/08/02-23:09:33 - 9142] [CBPOLICYD] DEBUG: Shutting down caching
engine (9142)
[2011/08/02-23:09:33 - 9155] [CBPOLICYD] DEBUG: Shutting down caching
engine (9155)
Regards.
Juan.-
http://launchtime.ri.mu - VPS hosting
http://ri.mu - monitoring, DNS, FTP, helpdesk software and more
_______________________________________________
Users mailing list
[email protected]
http://lists.policyd.org/mailman/listinfo/users
