Monitoring and Analysis
As request/result re-writing is an on-the-fly process within the LDAP proxy server and thus only either the client will see the rewritten results or the target server will see the rewritten request it is hard to actually see whether the rules are applied correctly as intended.
In order to provide better insight some extensions to the existing monitoring capabilities have been made.
Analyzing Errors in Rewriting Rule Definitions
As everything regarding rewriting is controlled by the rules contained within the DLP server configuration file, it is pretty easy to make incorrect definitions either by making syntax errors or by making logical mistakes between relations.
Let’s assume we made a rewriting rule definition like this one:
{
"object" : "ProxyRule",
"ruleType" : "ReqRewrite",
"name" : "REQREWRITE1",
"condition" : "(&(opr.req.typ=search)(search.req.baseObject=o=my-company))",
"actions" : [ "search.req.baseObject.replace(NULL,o=pqr)" ]
}
The definition looks fine at first glance, but still the DLP server refuses to start.
Finding Syntax Errors
One of the most common errors is one or more syntax errors in a condition or an action definition.
With the definition from the previous section, the server will not start. Why not?
ProxyConf-Error: Illegal condition-string '(&(opr.req.typ=search)(search.req.baseObject=o=my-company))' found in ProxyRule object 'REQREWRITE1'! FATAL: Cannot read PROXY configuration (ldap_proxy.json)! LDAP Server exit (ExitCode: 19 Reason: FATAL: Cannot process PROXY configuration! Server stopped.)
Chances are that you can’t see the problem immediately, so what can we do to find it?
The best way to localize the problem is to activate DLP server tracing by setting:
"Tracing" : 3
in the Defaults object definition in the DLP server configuration file and then restarting the DLP server.
Restarting the server causes a trace file to be generated at install_path*/ldap/log/proxytrace*PID*.txt*, where PID is the process ID of the newly started server.
When we look at the end of the file, we find the following data:
pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3786) ConditionListToLdapFilter((opr.req.typ=search)(search.req.baseObject=o=my-company)) pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3932) ConditionToLdapFilter((opr.req.typ=search)) pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3639) SimpleConditionToLdapFilter(opr.req.typ=search) pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3533) IsLegalConditionToken(opr.req.typ=search) pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3622) ILLEGAL TOKEN or VALUE found in 'opr.req.typ=search'! pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3709) [JSON] Illegal Token found in condition string: 'opr.req.typ' pid:8788,tid:10704, 10:42:46.401 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3763) [JSON] Syntax error in Condition-Filter
From this output, we can see that the error is caused by the incorrect token name opr.req.typ in the condition definition. The correct token name is opr.req.type. We can easily correct this error in the corresponding proxyRule object in the configuration file.
ProxyConf-Error: Illegal CMD-String in Action 'search.req.baseObject.replace(NULL,o=pqr)'! FATAL: Cannot read PROXY configuration (ldap_proxy.json)! LDAP Server exit (ExitCode: 19 Reason: FATAL: Cannot process PROXY configuration! Server stopped.)
As we can see, the error has changed. Now it reports an error in the action string.
Looking again at the trace file, we find the following data:
pid:8400,tid:10292, 13:10:59.032 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3018) PrepareCmdParamsStr(search.req.baseObject.replace(NULL,o=pqr)) pid:8400,tid:10292, 13:10:59.032 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:3055) Bad parameters found in 'search.req.baseObject.replace(NULL,o=pqr)' -> P1 & P2 must contain old-value and new-value! pid:8400,tid:10292, 13:10:59.032 (..\..\dirxldapv3\mainthread\mn_proxy.cpp:4214) PrepareAction():Illegal action specification: 'search.req.baseObject.replace(NULL,o=pqr)'
This gives the error reason. The problem is that the parameter list (NULL,o=pqr) is not a legal parameter list for the replace action on the component search.req.baseObject.
The first parameter must be the old string to be replaced by the string in the second parameter.
The definition contains NULL as the first parameter, which is not allowed for a replace operation. Let’s correct this mistake in the proxyRule object in the configuration file:
{
"object" : "ProxyRule",
"ruleType" : "ReqRewrite",
"name" : "REQREWRITE1",
"condition" : "(&(opr.req.type=search)(search.req.baseObject=o=my-company))",
"actions" : [ "search.req.baseObject.replace(o=my-company,o=pqr)" ]
}
After doing so, our server starts up.
| Don’t forget to disable tracing after fixing, otherwise performance will decrease dramatically. |
Detecting Logical Errors
These types of errors are much harder to detect as the server will not necessarily report an error at all. Suppose we have the following rule definition:
{
"object" : "ProxyRule",
"ruleType" : "ReqRewrite",
"name" : "REQREWRITE1",
"condition" : "(&(opr.req.type=modify)(search.req.baseObject=o=my-company))",
"actions" : [ "search.req.baseObject.replace(o=my-company,o=pqr)" ]
}
This definition has no syntax errors so the server can start.
The problem here is that the condition will never match any request because there is no modify operation for a search baseObject.We wanted to address a search, but we mistyped a modify instead.The server will not detect such incorrect use/mixing of incompatible tokens.It only checks whether the syntax is OK and whether all mandatory components are described.The DLP server will not detect logical errors.
In our example, the rule will never become active but the DLP server administrator may never discover the problem.Therefore, we strongly recommend running a quick check on any new rule you create by performing an operation that should match the rule and then checking whether or not everything is applied as expected.
DLP Server Logging
The LDAP server binary is the same whether it is running as a DLP server or a plain LDAP server.Consequently, the same logging environment applies to both modes.
To view details about DLP server processing, add the following components to the dirxlog.cfg file:
ldap_op.1.4.5
Because logging can have a significant performance impact, it is recommended to enable this only for diagnostic purposes, not for normal operation.
Logging Example
This example shows sample output of the logging generated when a client performs an LDAP bind operation against the DLP server:
--------------------------------------------------------------------------------
LDAP Listener 0x000024fc LDAP 9.2.104 dir Di 28.03.2017 16:14:21
--------------------------------------------------------------------------------
-- 0x45046755 DEBUG1 ldap_op mn_ldap_listener 429 14:21:997
1 New LDAP connection (Con1) accepted from client IP: "127.0.0.1":63210
The DLP server recognizes traffic on the LDAP port by the listener thread – listener creates a new connection object (Con0) and hands processing over to the pool thread.
--------------------------------------------------------------------------------
PoolThread#1 0x00002b60 LDAP 9.2.104 dir Di 28.03.2017 16:14:21
--------------------------------------------------------------------------------
-- 0x4504674e DEBUG1 ldap_op op_ldap_operatio 535 14:21:997
0 New operation: "LDAP_Con1_Op0" "BindReq" V3
The pool thread creates a new operation object on Con0 and receives data from client: it detects a bind request.
-- 0x45046766 DEBUG5 ldap_op mn_proxy.cpp 2842 14:21:997 1 lookup_user_rule(user:"cn=richter,ou=sales,o=my-company")="FOUND"
The DLP server extracts the user DN from the bind operation and performs a lookup against the operation-forwarding rules for this user.
-- 0x4504676a DEBUG5 ldap_op mn_proxy.cpp 3014 14:21:997 1 "get_relevant_servers(cn=richter,ou=sales,o=my-company)=USER_RULE URule: USERRULE3 (type:2) (match:cn=richter,ou=sales,o=my-company) ORule: none"
The DLP server’s lookup has found a forwarding rule (USERRULE3) for the user and prepares the possible target servers.
-- 0x4504676a DEBUG5 ldap_op mn_proxy.cpp 3017 14:21:998
1 "Found 2 Relevant Servers from Rule"
-- 0x4504676a DEBUG5 ldap_op mn_proxy.cpp 3044 14:21:998
1 "ServerName: LDAP1
Address:127.0.0.1:1636
Protocol:LDAPS - TLSv1.2
Trusted-CA-File:C:/Program Files/DirX/Directory/conf/testCA.pem
Cipher:HIGH"
-- 0x4504676a DEBUG5 ldap_op mn_proxy.cpp 3044 14:21:998
1 "ServerName: LDAP3
Address:127.0.0.1:3333
Protocol:LDAP"
The identified user rule defines two target servers (LDAP1, LDAP3) with corresponding server parameters. LDAP1 is the primary server.
-- 0x4504675c DEBUG1 ldap_op mn_proxy.cpp 742 14:22:005
2 ldap_connect(sd:836)=PROXY_OK(0)
OpName:"LDAP_Con1_Op0",
Server:"127.0.0.1":1636 ("LDAP1") sec:"ssl"
The DLP server prepares to establish a LDAP connection via SSL/TLS to LDAP1.
-- 0x4504676d DEBUG4 ldap_op mn_proxy.cpp 3403 14:22:005 1 GetTargetServerConnection(): Using Connection to Server '"LDAP1"'
The DLP establishes a connection to the server.
-- 0x45046762 DEBUG4 ldap_op mn_proxy.cpp 1611 14:22:005
2 SendLdapDataToServer("LDAP1",sd:836)=PROXY_OK(0)
Data: (len:277)
0000 30 82 01 11 02 01 01 60 26 02 01 03 04 19 63 6E 0‚.....`&.....cn
0010 3D 72 69 63 68 74 65 72 2C 6F 75 3D 73 61 6C 65 =richter,ou=sale
0020 73 2C 6F 3D 70 71 72 80 06 61 62 63 31 32 33 A0 s,o=my-company..abc123
0030 81 E3 30 75 04 1A 31 2E 33 2E 36 2E 31 2E 34 2E .ã0u..1.3.6.1.4.
0040 31 2E 32 31 30 30 38 2E 31 30 38 2E 36 33 2E 31 1.21008.108.63.1
0050 04 57 30 55 04 0C 31 30 2E 39 33 2E 32 35 2E 31 .W0U..10.93.25.1
0060 36 32 04 0D 64 69 72 78 63 70 20 5B 37 32 36 30 62..dirxcp [7260
0070 5D 04 1C 31 2E 33 2E 36 2E 31 2E 34 2E 31 2E 32 ]..1.3.6.1.4.1.2
0080 31 30 30 38 2E 31 30 38 2E 36 33 2E 31 2E 33 04 1008.108.63.1.3.
0090 18 63 6E 3D 61 62 65 6C 65 39 2C 6F 75 3D 73 61 .cn=abele9,ou=sa
00A0 6C 65 73 2C 6F 3D 70 71 72 30 6A 04 18 31 2E 33 les,o=my-company0j..1.3
00B0 2E 31 32 2E 32 2E 31 31 30 37 2E 31 2E 33 2E 32 .12.2.1107.1.3.2
00C0 2E 31 32 2E 38 04 4E 30 4C 04 24 36 36 65 63 38 .12.8.N0L.$66ec8
00D0 62 35 31 2D 32 35 31 31 2D 34 38 32 32 2D 38 32 b51-2511-4822-82
00E0 62 33 2D 32 33 32 63 30 31 66 61 66 35 34 35 04 b3-232c01faf545.
00F0 24 64 66 37 35 64 32 31 35 2D 36 30 36 64 2D 34 $df75d215-606d-4
0100 33 62 30 2D 39 37 61 64 2D 39 35 61 37 31 31 61 3b0-97ad-95a711a
0110 62 63 63 37 30 bcc70...........
The DLP server sends the client bind request to the target server (implicitly the OpUUID was appended to the request – this is visible at the end of the hex-dump).
-- 0x45046763 DEBUG4 ldap_op mn_proxy.cpp 1801 14:22:021
3 RecvLdapDataFromServer("LDAP1",sd:836)=PROXY_OK(0)
Data: (len:52)
0000 30 32 02 01 01 61 2D 0A 01 00 04 00 04 26 42 69 02...a-......&Bi
0010 6E 64 20 73 75 63 63 65 65 64 65 64 2E 20 28 43 nd succeeded. (C
0020 6F 6E 74 61 63 74 2D 44 53 41 3A 2F 43 4E 3D 44 ontact-DSA:/CN=D
0030 53 41 33 29 SA3)............
The DLP server receives the bind result PDU from the LDAP server.
-- 0x45046765 DEBUG5 ldap_op mn_proxy.cpp 1438 14:22:021
4 DecodeLdapPdu(pduType:1, data:0x0000000004C24F50, data_len:52)=PROXY_OK(0)
Decoded:
STRUCT LDAP_Message_V3 {
bit_mask = 0 ;
messageID = 0x1 ;
protoOp = UNION ProtoOp {
choice = 0x2 ;
u.bindResp_V3 = STRUCT LDAP_BindResp_V3 {
bit_mask = 0 ;
resultCode = LDAP_SUCCESS(0) ;
matchedDN = <ABSENT> ;
errorMessage = 38 char value(s)
0000 42 69 6E 64 20 73 75 63 63 65 65 64 Bind succeed
000C 65 64 2E 20 28 43 6F 6E 74 61 63 74 ed. (Contact
0018 2D 44 53 41 3A 2F 43 4E 3D 44 53 41 -DSA:/CN=DSA
0024 33 29 3)..........
referral_V3 = <ABSENT> ;
serverSaslCreds_V3 = <ABSENT> ;
}
}
controls_V3 = <ABSENT> ;
}
The DLP server decodes the received bind result PDU for two reasons: a) to get the LDAP result code and b) to check whether the received data is really a correct bind response PDU. In this example, PDU and bind were OK.
-- 0x45046764 DEBUG4 ldap_op mn_proxy.cpp 1491 14:22:021
3 SendLdapDataToClient(sd:1216)=PROXY_OK(0)
Data: (len:52)
0000 30 32 02 01 01 61 2D 0A 01 00 04 00 04 26 42 69 02...a-......&Bi
0010 6E 64 20 73 75 63 63 65 65 64 65 64 2E 20 28 43 nd succeeded. (C
0020 6F 6E 74 61 63 74 2D 44 53 41 3A 2F 43 4E 3D 44 ontact-DSA:/CN=D
0030 53 41 33 29
The DLP server sends the received result back to the client.
SA3)............
-- 0x4504675b DEBUG1 ldap_op mn_proxy.cpp 1259 14:22:021
1 ldap_bind(user:"cn=richter,ou=sales,o=my-company")=PROXY_OK(0)
OpName:"LDAP_Con1_Op0",
Server:"127.0.0.1":1636 ("LDAP1") sec:"ssl" sd:836
The final log indicates that the forwarded bind was OK.
DLP Server Audit
The DLP server uses the same audit mechanism as the plain LDAP server.The only major difference is the record layout.The same common tool dirxauddecode can be used to evaluate DSA audit, LDAP server audit and DLP server audit.Note that the dirxaudstatistics tool does not recognize proxy-mode records and thus cannot be used to evaluate DLP server audit files
DLP Server Audit Record Layout
The layout of DLP server audit records is quite different from the LDAP server records due to the different tasks of customizing or forwarding a request rather than processing it.Nevertheless, the evaluation of a DLP server audit file is still the same.For example, consider the following command:
dirxauddecode –i audit.log –a audit.log.txt –v –v
The command produces an ASCII file with an initial header that looks very similar to the LDAP audit header.The only difference is that the Content Type field is PROXY instead of LDAP:
################# DIR.X AUDIT TRAIL (c) Eviden ################################
Cmd-Line: -i audit.log -a audit.log.txt -v -v
=================================================================================
Audit File # :1
Input File :audit.log
Output File :audit.log.txt
Audit Version :9.2
Server UUID :0235b963-f69d-403f-8918-2425fef3ae34
Audit Start Time (local) :Thu Apr 20 10:13:39 2017
Audit Start Time (GMT) :Thu Apr 20 08:13:39 2017
Content Type :PROXY
OpSelection :all
OpErrors :yes
Audit Level :max
Audit Encryption :none
Overflow Action: :move
Max Records per File :5000
Value Limit :128
Server-PID :7680
DB Master-Entries :118503
DB Copy-Entries :0
Filter Records with IP :---
Ignore Records with IP :---
Included LDAP Ops :All
Included DSA Ops :All
OS Name :Microsoft Windows 7 64-bit- Service Pack 1 (build 7601)
Total Phys Memory :16266 MB
Avail Phys Memory :11851 MB
Allocated CTX Size :56 MB
HWM CTX Size :88 MB
CTX ULimit :6000 MB
MemPagesize :4096
CPUs :4
Max Open Files soft :unlimited
Max Open Files hard :unlimited
Audit Disk Space Total :807641084 kB
Audit Disk Space Free :465029860 kB
PID :7680
Host Name :XXXXXXXX
Host IP :1.1.1.1
Server Version :DirX Directory V8.6 9.2.104 2017:03:25 20:10 64-Bit
Server Type :Frontend Proxy Server
Server Mode :Read/Write
Contact-DSA :Name=/CN=DSA1, enabled=yes, fails=0, PSAP=TS=DSA1,NA='TCP/IP_IDM!internet=1.2.3.4+port=4711',DNS='(HOST=XXXXXXX,SSLPORT=21201,PLAINPORT=21200,MODE=ssl)'
SSL Encryption :SSLv3.0 TLSv1.0 TLSv1.1 TLSv1.2
Server Start Time :Thu Apr 20 10:13:38 2017
Configuration Name :ldapConfiguration
ClCfg File :C:\Program Files\DirX\Directory\ldap\conf\dirxldap.cfg
Ldap Port :389
SSL Port :636
RPC Port :6999
Max Conn :777
Client Idle Time :300
TCP/IP Response Mode :24
Socket Mode :async
Thread Pool Size :32
DN Escape Mode :backslash
Allowed IPs :all
Denied IPs :12.23.34.45
Denied IPs :11.22.33.44
Denied IPs :100.101.102.103
DB-Index-Info:
Attr: uid : initial final present
Attr: userid : initial final present
Attr: objectClass : initial
Attr: ocl : initial
Attr: cn : initial final
Attr: commonName : initial final
Attr: sn : initial final
Attr: surname : initial final
Attr: c : initial final
Attr: countryName : initial final
Attr: o : initial final
Attr: organizationName : initial final
Attr: collectiveOrganizationName : initial final
Attr: ou : initial final
Attr: organizationalUnitName : initial final
Attr: collectiveOrganizationalUnitName : initial final
Attr: description : initial final
Attr: dsc : initial final
Attr: remarks : initial final contains
=================================================================================
DB-Index-Usage:
Attribute access counter high score at Thu Apr 20 10:12:45 2017 :
Attribute name : Index access counter
: INITIAL FINAL CONTAINS PRESENT
uid : 2719993 0 - 0
cn : 1175911 0 - -
objectClass : 95 - - -
description : 4 14 - -
o : 4 0 - -
sn : 0 3 - -
ou : 2 0 - -
=================================================================================
| that any information about the DSA or the database is derived from the local DSA and not from the target servers. For example, the information: |
DB Master-Entries :118503
describes the local DSA DB and provides no information about the target server’s database.
The single operation records follow the header. These records have a different layout from plain LDAP records since the server is running as a DLP server, not as a plain LDAP server.
Bind, Search, Add Example
To illustrate the meaning of an audit record, let’s assume a user has performed three operations: a bind, a search and an add request with the following DLP server proxy rules defined for these three operations:
{
// redirect user ‘richter’ to LDAP1
"object" : "ProxyRule",
"ruleType" : "UserRouting",
"name" : "USERROUTING1",
"condition" : "(user=cn=richter,ou=sales,o=pqr)",
"actions" : [ "forwardto(LDAP1)" ],
"loadbalance" : 1,
"failover" : 1
},
{
// redirect ADDs to LDAP2
"object" : "ProxyRule",
"ruleType" : "OprRouting",
"name" : "OPRROUTING2",
"condition" : "opr.req.type=add",
"actions" : [ "singleforwardto(LDAP2)" ],
"failover" : 0,
"keepconn" : 1
},
{
// change o=my-company to o=pqr for search bases
"object" : "ProxyRule",
"ruleType" : "ReqRewrite",
"name" : "ReqRewrite1",
"condition" : "opr.req.type=search",
"actions" : [ "search.req.baseObject.replace(o=my-company,o=pqr,NULL)" ]
}
{
// remove sn=Digger from any search result
// add description=blabla to all result entries
"object" : "ProxyRule",
"ruleType" : "ResRewrite",
"name" : "Test 04",
"condition" : "opr.req.type=search",
"actions" : [ "search.res.attributes.del(sn,Digger,NULL)",
“search.res.attributes.add(description,blabla,NULL)" ]
}
Now let’s look at the audit output. Note that in the example shown here, fields that have the same meaning as for LDAP audits are not described.
The DLP Server Bind Record
Let’s start with the DLP server bind record:
----------------- OPERATION 000001 ---------------- Create Time :Wed Jul 25 14:46:33.036496 2018 Start Time :Wed Jul 25 14:46:33.036571 2018 SrvSend EndTime:Wed Jul 25 14:46:33.062344 2018 SrvRecv EndTime:Wed Jul 25 14:46:33.072868 2018 ClSend EndTime :Wed Jul 25 14:46:33.074132 2018 End Time :Wed Jul 25 14:46:33.075126 2018 OpUUID :35d6c5ad-89fa-44e3-84d3-845f70b97f51 Concurrency :1 OpStackSize :1 OpFlow In/Out :0/0 Contact-Server :127.0.0.1:1636 (LDAP1) SrvRelRule :USERROUTING1 SrvSecurity :ssl SrvSslProtocol :TLSv1.2 SrvSslCipher :ECDHE-RSA-AES256-GCM-SHA384 #ContactedSrv :1 SrvSocket :1232 SvrErrno :0 SvrConnectDur :0.014270 sec SvrSendDur :0.000299 sec (1 calls) SvrRecvDur :0.010132 sec (2 calls) SvrBytesSent :279 SvrBytesRecv :29 Duration :0.038555 sec User :cn=richter,ou=sales,o=pqr ClIP+Port+Sd :[127.0.0.1]+55631+668 Op-Name :LDAP_Con0_Op0 Operation :BIND Version :3 MessageID :1 ClSecurity :plain ClRecvDur :0.005230 sec (3 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ClSendDur :0.000021 sec (1 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ReqRewriteDur :0.000584 sec ResRewriteDur :0.000000 sec ClBytes Rcvd :169 ClBytes Sent :29 LdapResultCode :0 (success) ProxyResultCode:0
As shown in the lines above, all records start with some absolute timestamps that give the time at which the operation was processed.
The line:
Create Time :Wed Jul 25 14:46:33.036496 2018
shows the time at which the request was recognized by the DLP server via TCP to come in from the LDAP client.
The line:
Start Time :Wed Jul 25 14:46:33.036571 2018
shows the time at which the DLP server started processing the request by reading the LDAP PDU, decoding it, etc. Usually this time is close to the CreateTime which shows that the server was not too busy and processing started immediately. If this time is significantly later (by seconds) it indicates that no pool thread was available to process the request and the request had to wait for a pool thread to become available. This kind of message may indicate a heavy load situation, especially if the concurrency (number of parallel processed operations) is high.
The line:
SrvSend EndTime:Wed Jul 25 14:46:33.062344 2018
shows the time at which the request was completely forwarded to the target LDAP server (when the local processing (deciding which target server to use, decoding the message, performing request rewrite actions) has completed.
The line:
SrvRecv EndTime:Wed Jul 25 14:46:33.072868 2018
shows the time the answer from the server was completely received (for search results, this includes the receipt of all resulting entries).
The line:
ClSend EndTime :Wed Jul 25 14:46:33.074132 2018
shows the time at which the result (after applying all result rewriting rules) was completely sent out to the client.
The line:
End Time :Wed Jul 25 14:46:33.075126 2018
shows the time at which the operation ended within the DLP server (after cleanup, audit write and other operations.).
This line:
Contact-Server :127.0.0.1:1636 (LDAP1)
shows the target LDAP server to which the request was finally forwarded, with IP, port and logical server name taken from the DLP server configuration file.
The line:
SrvRelRule :USERROUTING1
shows which rule defined the target server. In our example, it was USERROUTING1 for user richter. Note that only user-routing rules or the LB fallback servers have any effect on this property.
These lines:
SrvSecurity :ssl SrvSslProtocol :TLSv1.2 SrvSslCipher :ECDHE-RSA-AES256-GCM-SHA384
show that the target server (LDAP1) was contacted via SSL/TLS.
These lines:
SrvSocket :1232 SvrErrno :0 SvrConnectDur :0.014270 sec SvrSendDur :0.000299 sec (1 calls) SvrRecvDur :0.010132 sec (2 calls) SvrBytesSent :279 SvrBytesRecv :29
provide details about the socket number used to transfer data to the target server, how long it took to establish a TCP connection (if it was necessary to create a new connection to the target), how long it took and how many send() calls were necessary to send out the request and for the result to be received along with the amount of data sent out and received from the target LDAP server.
This line:
Duration :0.038555 sec
shows the time the DLP server took to process the request (including the time spent at the target server).
These lines:
ClSecurity :plain ClRecvDur :0.005230 sec (3 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ClSendDur :0.000021 sec (1 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ClBytes Rcvd :169 ClBytes Sent :29
provide information about the client activity: how it accessed the server (via a plain connection, not SSL/TLS) how long it took to read the request from the client, how long it took to send the result back to the client and the amount of data received in the request/response.
These lines:
ReqRewriteDur :0.000584 sec ResRewriteDur :0.000000 sec
show how long it took to rewrite the request or the result. Please note that even if NO rule matches and NO rewrite takes place, the DLP server needs time to evaluate these conditions.
These lines:
LdapResultCode :0 (success) ProxyResultCode:0
show that we have two result codes: the result code as received from the LDAP server and the result code about the DLP server processing. It can be that the request was successfully processed by the LDAP server but could not be sent back to the client (for example, due to network problems).
The Search Record
The subsequent search received from the client by the DLP server looks like this:
----------------- OPERATION 000002 ---------------- Create Time :Wed Jul 25 14:46:35.501099 2018 Start Time :Wed Jul 25 14:46:35.501191 2018 SrvSend EndTime:Wed Jul 25 14:46:35.510630 2018 SrvRecv EndTime:Wed Jul 25 14:46:35.761931 2018 ClSend EndTime :Wed Jul 25 14:46:35.764063 2018 End Time :Wed Jul 25 14:46:35.764587 2018 OpUUID :a14f41da-e11a-43c1-a8e8-6afde8d3472f Concurrency :1 OpStackSize :1 OpFlow In/Out :0/0 Contact-Server :127.0.0.1:1636 (LDAP1) SrvSecurity :ssl SrvSslProtocol :TLSv1.2 SrvSslCipher :ECDHE-RSA-AES256-GCM-SHA384 SrvSocket :1232 SvrErrno :0 SvrConnectDur :0.000000 sec SvrSendDur :0.000362 sec (1 calls) SvrRecvDur :0.068365 sec (60 calls) SvrBytesSent :284 SvrBytesRecv :1301 Duration :0.263396 sec User :cn=richter,ou=sales,o=pqr ClIP+Port+Sd :[127.0.0.1]+55631+668 Op-Name :LDAP_Con0_Op1 Operation :SEARCH Version :3 MessageID :0 ClSecurity :plain ClRecvDur :0.000405 sec (3 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ClSendDur :0.000340 sec (30 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ReqRewriteDur :0.004085 sec ResRewriteDur :0.115512 sec NumResEntries :29 ClBytes Rcvd :181 ClBytes Sent :2043 LdapResultCode :0 (success) ProxyResultCode:0 ProxyRuleExec :ReqRewrite1 (CallCount: 1, ItemsModified: 1) ProxyRuleExec :Test 04 (CallCount: 29, ItemsModified: 29)
Most fields are identical to the bind record audit output. We can see that the search went to the same target (LDAP1) on the same socket as the bind operation.
The last lines of the output show the list of rules that were applied to this operation (ProxyRuleExec). Each line refers to a separate rule and indicates how many times the condition was evaluated (CallCount) and how many changes/actions were executed (ItemsModified). We see that one item in the request was modified. From the corresponding rule (ReqRewrite1), we know that the incoming baseObject was modified. The returned results were modified by rule Test 04. We know that 29 entries were returned (NumResEntries=29) and all of them were modified (ItemsModified=29).
You may notice that the following two values differ:
ClBytes Rcvd :181 // bytes received from client SvrBytesSent :284 // bytes forwarded to backend LDAP
Shouldn’t they be the same? In principle yes, but the DLP server adds a control to the request that allows shifting the DLP server-generated UUID to the LDAP server, which uses this UUID in its corresponding audit log record and even passes it to the DSA, which also includes it into its audit. This operation makes it easier to locate the corresponding record in DLP server/LDAP/DSA audits. As it is appended to the incoming request, the size of the forwarded request will grow a little.
The Add Record
The subsequent add operation received from the client by the DLP server looks like this:
----------------- OPERATION 000003 ---------------- Create Time :Wed Jul 25 14:47:30.304363 2018 Start Time :Wed Jul 25 14:47:30.304413 2018 SrvSend EndTime:Wed Jul 25 14:47:30.340626 2018 SrvRecv EndTime:Wed Jul 25 14:47:30.343205 2018 ClSend EndTime :Wed Jul 25 14:47:30.344562 2018 End Time :Wed Jul 25 14:47:30.345118 2018 OpUUID :36fadde3-274c-4e23-a96c-508395b515d2 Concurrency :1 OpStackSize :1 OpFlow In/Out :0/0 Contact-Server :127.0.0.1:2636 (LDAP2) SrvSecurity :ssl SrvSslProtocol :TLSv1.2 SrvSslCipher :ECDHE-RSA-AES256-GCM-SHA384 #ContactedSrv :1 SrvSocket :836 SvrErrno :0 SvrConnectDur :0.017388 sec SvrSendDur :0.000840 sec (2 calls) SvrRecvDur :0.010794 sec (4 calls) SvrBytesSent :570 SvrBytesRecv :78 Duration :0.040705 sec User :cn=richter,ou=sales,o=pqr ClIP+Port+Sd :[127.0.0.1]+55631+668 Op-Name :LDAP_Con0_Op2 Operation :ADD Version :3 MessageID :0 ClSecurity :plain ClRecvDur :0.000162 sec (3 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ClSendDur :0.000033 sec (1 calls, 0 WouldBlocks, WouldblockTime:0.000000 sec) ReqRewriteDur :0.000616 sec ResRewriteDur :0.000000 sec ClBytes Rcvd :181 ClBytes Sent :49 LdapResultCode :32 (noSuchObject) ProxyResultCode:0 ProxyRuleExec :OPRROUTING2 (CallCount: 1, ItemsModified: 0)
At the end of the output, we see that OPRROUTING2 was applied. From the proxy rule definition given at the start of this example, we know that this is an operation-routing rule and should redirect the operation to LDAP2, which is confirmed by the line:
Contact-Server :127.0.0.1:2636 (LDAP2)
We can also see that the LDAP operation failed with a “noSuchObject” error, but the processing was fine from the DLP server’s point of view:
LdapResultCode :32 (noSuchObject) ProxyResultCode:0
LDAP Extended Operations for DLP Servers
DirX provides the following LDAP operations to observe and control a DLP server:
-
ldap_proxy_status - Shows the current status of the server
-
ldap_proxy_update - Triggers a runtime update of the DLP server configuration file
-
ldap_proxy_server_disable - Disables an LDAP target server
-
ldap_proxy_server_enable - Re-enables a disabled LDAP target server
All of these extended operations can be invoked by the dirxextop tool.See the DirX Directory Administration Reference for a description of dirxextop.
The DLP server status display and update trigger can also be invoked in the DirX Directory Manager with the Monitoring view:
Disabling and enabling a target server can only be performed via dirxextop.
ldap_proxy_server_disable
Parameters
server_name
The name of the target server to be disabled, as specified in the DLP server configuration file.
Description
The ldap_disable_config_dsa LDAP extended operation allows DirX Directory administrators to permanently disable a target LDAP server for a DLP server; for example, before taking it off-line for maintenance.
Use the mandatory server_name parameter in the -P option to dirxextop to specify the name of the LDAP server to be disabled.
The OID of this extended operation is 1.3.12.2.1107.1.3.2.11.62.
When you use this operation to disable a server, you must explicitly re-enable it with the ldap_proxy_server_enable LDAP extended operation before the DLP server can select it again.
Example
The following example shows how to apply the ldap_proxy_server_disable LDAP extended operation with the dirxextop command. In the example, the target LDAP server LDAP2 is disabled:
dirxextop -h localhost -p 389 -D cn=admin,o=my-company -w dirx -t ldap_proxy_server_disable -P LDAP2
Use the ldap_proxy_status extended operation to view the result:
-----------------------------------------------------------------------------
---------------------------[ Servers ]---------------------------------------
-----------------------------------------------------------------------------
NumLdapServers : 5 (SelCount:2)
Server : Name=LDAP5, Status:AVAILABLE
Addr=10.93.25.72:3333, Sec=plain,
ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP4, Status:AVAILABLE
Addr=127.0.0.1:3333, Sec=plain,
ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP3, Status:AVAILABLE
Addr=127.0.0.1:3333, Sec=plain,
ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP2, Status:DISABLED since Tue Apr 18 16:00:11.115654
Addr=127.0.0.1:2636, Sec=TLSv1.2,
ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP1, Status:AVAILABLE
Addr=127.0.0.1:1636, Sec=TLSv1.2,
ConnOK=2, ConnFail=0, OpOK=3, OpFail=0
The server section of the output shows that the server LDAP2 has the status DISABLED.
ldap_proxy_server_enable
Parameters
server_name
The name of the target LDAP server to be enabled, as specified in the DLP server configuration file.
Description
The ldap_proxy_server_enable LDAP extended operation allows DirX Directory administrators to enable an LDAP server that was previously disabled with the ldap_proxy_server_disable LDAP extended operation.
Use the mandatory server_name parameter in the -P option to dirxextop to specify the name of the LDAP server to be enabled.
What is the OID for this operation is 1.3.12.2.1107.1.3.2.11.63.
ldap_proxy_status
Description
On success, this operation returns the current state of the DLP server in readable format. The output consists of a header section, a server section and a rule section.
The header section provides general information about the DLP server, including:
-
The selected LDAP configuration subentry name for the DLP server. By default, the proxy-name is ldapConfiguration, which is the name of the server’s default LDAP configuration subentry if not set otherwise. (See the section in the DirX Directory Administration Guide that describes how to add multiple LDAP servers for details.)
-
The proxy mode in which the DLP server is currently running. A value of 1 indicates that SSL/TLS is not in use on any target server. A value of 2 indicates that at least one target server has been contacted via SSL/TLS.
-
The currently active Proxy-ID number. At DLP server startup, this field is set to 1 and is incremented with every ldap_proxy_update call. You can use this field to determine how many online updates of the DLP server configuration have occurred to date.
-
Whether or not failover is enabled. When enabled, the DLP server uses the next configured LDAP server when a failure is detected. We recommend enabling this feature in the operation-forwarding rule object definition(s) (with the failover key) and/or in the Defaults object definition (with the LdapProxy.lb_failover key. See the “Configuration” chapter for details.
-
Whether or not the primary LDAP server function is shifted among the available load-balancing LDAP servers (LB-servers). When disabled, all traffic for users without any forwarding rule will go to the first LB-server. We recommend enabling the feature in the Defaults object definition (with the LdapProxy.lb_balance key). See the “Configuration” chapter for details. Note that load balancing is not performed for users that match a configured user, subuser or wildcard user rule.
-
How long (in seconds) the DLP server will wait for a TCP connect to be confirmed before dropping the server and switching to the next server (if possible).
-
How long (in seconds) the DLP server will wait to select a failed target server for new client connections.
-
The character encoding of the DLP server configuration file.
-
Whether (1) or not (0) notification of request/result rewriting is included in the LDAP response error message.
-
The string used to indicate an empty parameter in protocol-specific rewriting actions.
-
The level of tracing information sent to stderr.
-
How many active subscribers (client connections) (and thus implicitly which target servers) were selected against the settings of this DLP server configuration. Every new bind operation always uses the most recent DLP server configuration and increments the subscription counter for this DLP server configuration. Every unbind operation will decrement the subscription counter (DLP server configuration objects with a subscription count of 0 are scheduled to be removed at next automatic cleanup).
-
The last subscribed user to this DLP server configuration.
The “Processed LDAP Requests” section displays how many operations of which type have been processed to date and the number of result entries returned by searches.
The server section:
-
Lists all available target servers by their name, IP, port and whether they will be contacted via SSL/TLS or plain connections.
-
Displays the current status of each server. Possible states are:
-
AVAILABLE (the server can be selected)
-
OFFLINE (the server cannot be selected for some period of time)
-
DISABLED (the server will not be selected until it has been re-enabled).
-
Shows how many successful/failed connects and operations have been seen for each server. Note that for the DLP server, an operation fails if an I/O error occurs, but not because an LDAP operation returns an error code != 0. The LDAP result code never affects DLP server operation.
The user- and operation-routing rules section shows the rules of these types that have been defined in the DLP server configuration file. For each rule, the output displays:
-
The rule condition that must be met
-
How many times the rule has been selected to date
-
The servers that are involved if the rule is selected
-
Whether failover, load-balancing (user-routing only), and keep connection (operation-routing only) are in force
The request- and result-rewriting rules section shows the rules of these types that have been defined in the DLP server configuration file. For each rule, the output displays:
-
The rule conditions that must be met and the actions to be performed.
-
How many times the rule matched a request or a result to date. Note that a result matching can occur for each returned entry of a search rules. Consequently, if a search result contains n result entries, the selection count can increase by n.
-
How many attributes and/or values the rule actions have actually changed to date. Note that if m actions are applied to n result entries of a single search request, the counter is increased by n*m.
The OID for this extended operation is 1.3.12.2.1107.1.3.2.11.61.
Example
The following example shows how to apply the ldap_proxy_status LDAP extended operation on the local LDAP server (which is running with the complete database and the default ports on the local machine) with the dirxextop command:
dirxextop -D cn=admin,o=my-company -w dirx -t ldap_proxy_status
The LDAP extended operation returns output like the following:
=============================================================================
+++ LDAP-Proxy-Configuration Status at:Thu Oct 11 10:12:34.576991
+++ Proxy-Name: ldapConfiguration
+++ Proxy-Mode: 2 (support for SSL/TLS target servers)
+++ Number of existing Proxy-Config Objects: 1
-----------------------------------------------------------------------------
Active Proxy-ID : 1
CreateTime : Thu Oct 11 10:10:58.144897
LB-Failover : yes
LB-Balance : yes
ConnectTimeout : 5 sec
OfflineRetryTime : 30 sec
JSON CodeSet : UTF8
NotifyRewrite : yes
NullParamStr : NULL
Tracing : 0
# Active Subscribers : 2
LastSubscriber : Conn:LDAP_Con1, User:cn=richter,ou=sales,o=pqr, Time:Thu Oct 11 10:12:10.301399
-----------------------------------------------------------------------------
--------------------[ Processed LDAP Requests ]------------------------------
-----------------------------------------------------------------------------
Total Requests : 16
Binds : 2
Searches : 13 (17 ResultEntries)
Adds : 0
Modifys : 0
Deletes : 0
ModDNs : 0
Compares : 0
Unbinds : 0
ExtOPs : 1
---------------------------------------------------------------------------------------------------------[ Servers ]--------------------------------------
-----------------------------------------------------------------------------
NumLdapServers : 5 (SelCount:1)
Server : Name=LDAP5, Status:AVAILABLE
Addr=10.93.25.72:3333, Sec=plain, ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP4, Status:AVAILABLE
Addr=127.0.0.1:3333, Sec=plain, ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP3, Status:AVAILABLE
Addr=127.0.0.1:3333, Sec=plain, ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP2, Status:AVAILABLE
Addr=127.0.0.1:2636, Sec=TLSv1.2, ConnOK=0, ConnFail=0, OpOK=0, OpFail=0
Server : Name=LDAP1, Status:AVAILABLE
Addr=127.0.0.1:1636, Sec=TLSv1.2, ConnOK=1, ConnFail=0, OpOK=1, OpFail=0
-----------------------------------------------------------------------------
NumLBServers : 3 (SelCount:0)
LBServers : LDAP1->LDAP2->LDAP3
-----------------------------------------------------------------------------
--------------------------[ UserRoutingRules ]-------------------------------
-----------------------------------------------------------------------------
NumUserRules : 2 (TotSelCount:2)
Rule-Name : USERROUTING1
Condition : (|(user=cn=richter,ou=sales,o=pqr)(wcuser=cn=IADM.*)(subuser=ou=sales,o=pqr))
Selection-Count : 1
Failover : yes
Load-balance : 0
#Target-Servers : 2
Target-Servers : LDAP2->LDAP1
-----------------------------------------------------------------------------
Rule-Name : USERROUTING2
Condition : (|(user=cn=admin,o=pqr)(wcuser=^cn=ad.*)(subuser=ou=sdevelopment,o=pqr))
Selection-Count : 1
Failover : yes
Load-balance : 0
#Target-Servers : 2
Target-Servers : LDAP3->LDAP1
-----------------------------------------------------------------------------
---------------------------[ OprRoutingRules ]-------------------------------
-----------------------------------------------------------------------------
NumOprRules : 2 (TotSelCount:5)
Rule-Name : OPRROUTING1
Condition : (&(opr.req.type=search)(search.req.control=simplePagedResult))
Selection-Count : 5
Failover : no
KeepConn : yes
#Target-Servers : 2
Target-Servers : LDAP2->LDAP1
-----------------------------------------------------------------------------
Rule-Name : OPRROUTING2
Condition : (&(opr.req.type=search)(search.req.baseObject=o=pqr))
Selection-Count : 0
Failover : yes
KeepConn : yes
#Target-Servers : 2
Target-Servers : LDAP1->LDAP3
-----------------------------------------------------------------------------
---------------------[ RequestRewriteRules ]---------------------------------
-----------------------------------------------------------------------------
NumReqRewriteRules : 5
Rule-Name : REQREWRITE0
Condition : (opr.req.type=search)
Selection-Count : 13
Change-Count : 0
Action : SEARCH.res.entry.hide(o=my-company,NULL,NULL)
-----------------------------------------------------------------------------
Rule-Name : REQREWRITE1
Condition : (&(opr.req.type=search)(user=anonymous))
Selection-Count : 0
Change-Count : 0
Action : search.req.filter.replace(mycn,cn,NULL)
Action : search.req.filter.replace(*,abele,richter)
Action : search.req.filter.replace(mycn,abc,NULL)
-----------------------------------------------------------------------------
Rule-Name : REQREWRITE2
Condition : (opr.req.type=modify)
Selection-Count : 0
Change-Count : 0
Action : modify.req.object.replace(my-company,pqr,NULL)
Action : modify.req.changes_add.replace(abc,23,45)
-----------------------------------------------------------------------------
Rule-Name : REQREWRITE4
Condition : (opr.req.type=modDN)
Selection-Count : 0
Change-Count : 0
Action : modDN.req.newrdn.replace(myxx,cn,NULL)
Action : modDN.req.newsup.replace(xxx,sales2,NULL)
-----------------------------------------------------------------------------
Rule-Name : REQREWRITE5
Condition : (&(opr.req.type=compare)(compare.req.attr=road))
Selection-Count : 0
Change-Count : 0
Action : compare.req.attr.replace(road,street,NULL)
-----------------------------------------------------------------------------
---------------------[ ResultRewriteRules ]----------------------------------
-----------------------------------------------------------------------------
NumResRewriteRules : 1
Rule-Name : RESREWRITE0
Condition : (opr.req.type=search)
Selection-Count : 18
Change-Count : 1
Action : search.res.entry.hide(Abele72,NULL,NULL)
Action : search.res.attributes.replace(street,road,NULL)
Action : search.res.attributes.replace(road,Schönweg,Schoenweg)
Action : search.res.attributes.replace(road,Schoenweg,Hausweg)
Action : search.res.attributes.replace(description,jensen,#4DC3BC6C6C6572)
Action : search.res.attributes.replace(description,Der\,Hund,Der Wolf)
-----------------------------------------------------------------------------
-----------------------------------------------------------------------------
+++LDAP-Proxy Status finished at:Thu Oct 11 10:12:34.577093
=============================================================================
ldap_proxy_update
Purpose
Activates changes made to the DLP server configuration file for a DLP server without having to re-start the server.
Description
This operation is used to update the settings from the DLP server configuration file while the DLP server is running. Use this extended operation when you’ve added new rules or servers to the configuration file and want to update the DLP server without interrupting the service.
If an update is performed, chances are that there are existing connections that were established against the previous DLP server configuration settings. To maintain a clean relationship between existing users and the DLP server settings, the old settings are preserved as long as there are users that were bound when these old settings were active. As a result, multiple DLP server configurations can coexist and multiple users can be subscribed to these different configurations. To which configuration a user is subscribed depends solely on the time of its connection to the DLP server. When the DLP server configuration is updated via an ldap_proxy_update call, a new configuration instance is created to which all subsequent users will subscribe. Users that were subscribed before the update remain attached to the old configuration and will thus follow the old rules and settings until they unbind from the DLP server. When the last user unbinds from a configuration, the entire configuration is deleted
The OID for ldap_proxy_update is 1.3.12.2.1107.1.3.2.11.60.
Example
The following example shows how to apply the ldap_proxy_update LDAP extended operation on the local LDAP server (which is running with the complete database and using the default ports on the local machine) with the dirxextop command:
dirxextop -D cn=admin,o=my-company -w dirx -t ldap_proxy_update
The LDAP extended operation returns output like the following:
=============================================================================
+++LDAP-Proxy-Configuration Update Started at:Thu Oct 11 13:54:05.016999
+++Proxy-Name:ldapconfiguration
Proxy-Update suceeded. Old Proxy-Mode: 1, New Proxy-Mode: 1
Number of existing Proxy-Configuration Objects: 2
Proxy-Object-ID: 9, Subscribers: 0 (active)
CreateTime : Thu Oct 11 13:54:05.016999
NumAllServers : 4
NumLBServers : 2 (sel-count:0)
NumUserRoutingRules : 1 (sel-count:0)
NumOprRoutingRules : 2 (sel-count:0)
NumRewriteRules : 3 (2 Req, 1 Res)
Proxy-Object-ID: 8, Subscribers: 1
CreateTime : Thu Oct 11 09:24:32.085999
LastSubscriber : LDAP_Con33 (Thu Oct 11 13:50:19.832999)
NumAllServers : 4
NumLBServers : 2 (sel-count:2)
NumUserRoutingRules : 1 (sel-count:0)
NumOprRoutingRules : 2 (sel-count:0)
NumRewriteRules : 3 (2 Req, 1 Res)
-----------------------------------------------------------------------------
+++LDAP-Proxy Update finished at:Thu Oct 11 13:54:05.296999
=============================================================================
This example shows that the DLP server configuration was updated for the eighth time since server startup (Proxy-Object-ID: 9) It also shows that one user is still subscribed to the previous configuration settings (Proxy-Object-ID: 8) while 0 users are subscribed to the new settings.
The reason for these values is that the update was performed via dirxextop, which performs a bind and then the extended operation; as a result, at the time of the configuration update, the user of the dirxextop tool was subscribed to the settings established by the Proxy-Object-ID: 8. Instance. The update created Proxy-Object-ID: 9 but no new bind operation has since been initiated.
For each DLP server configuration instance, the number of servers and rules are listed along with their total selection count per rule group.
If the update fails, the existing configuration remains active.