Trimming and resending, original was not approved.
>>>>> 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
