Capturing and Reading Novell Identity Manager Traces



By: ffreitas

July 10, 2008 10:29 pm

Reads: 790

Comments:1

Rating:0

Novell Identity Manager has a powerful tracing mechanism that can be used to track most of what is happening behind the scenes in your IDM implementation. To tap into that capability is very simple, and can be a valuable resource during development of the driver and also to troubleshoot issues in production.

Table of Contents

Introduction

Novell Identity Manager has a powerful tracing mechanism, and that can be used to track most of what is happening behind the scenes in your IDM implementation. To tap into that capability is very simple, and can be a valuable resource during development of the driver and also to troubleshoot issues in production.
This document assumes that the reader is familiar with XML and have basic knowledge about the Novell Identity Manager product. At the time of this writing the most recent version of Novell Identity Manager is version 3.5.1 .

Basic concepts

For the purpose of this document, we will consider Novell Identity Manager as 4 logical pieces, each with its own purpose:

  • IDM engine
  • Driver Configuration
  • Remote Loader
  • Driver Shim
  • The IDM engine is the piece that is installed into eDirectory (Metadirectory), and it has several functions. The most important ones for our analysis are:
    • Communicates directly with the Metadirectory, reading and writing to it
    • Detect and caches events (changes) that occur in the Metadirectory
    • Executes the logic defined on the Driver Configuration
    • Can either run the driver shim locally or communicate with the Remote Loader through the LAN
  • The Driver Configuration is an ordered group of conditions and actions that describe how the engine should treat events received from both the Metadirectory and from the connected application.
  • The Remote Loader is a piece of software that exchange XML messages with the IDM engine over the LAN, and deliver them to the driver shim. Its main purpose is to allow the driver shim to be ran in platforms other than the one where the IDM engine is installed.
  • The Driver Shim is the piece that converts what it receives from the connected application into XML to send to the IDM engine, and the XML that comes from the engine to the connected application. It is basically a translator between both systems, and can be ran locally where the IDM engine is, or remotely where the Remote Loader resides.

For the purpose of this document, a Driver will be the sum of the Driver Configuration plus the Driver Shim, no matter if the Driver Shim is running under the IDM engine or under the Remote Loader. It is possible to have multiple Drivers in the same IDM engine server.

An IDM trace will show different information depending on the level its taken, and also on where it is taken. It is possible to trace the IDM engine behavior (data caching, reading and witting to the Metadirectory, logic processing), and it is possible to trace the Driver Shim behavior (communication with the connected system).

When tracing the IDM engine we will see (depending on trace level) Status Messages, XDS (XML dialect that describes the events treated by IDM), DirXML-Script (underlying code used to describe Policy Builder’s conditions and actions), as well as engine action messages (messages that describe where in the logic the engine is, to help track things).

It is very important to understand the Identity Manager core architecture when trying to read a trace. If you are not familiar on how IDM is structured, please take the time to read the whole section “Understanding Types of Policies” at the URL:
http://www.novell.com/documentation/idm35/policy/data/policytypesoverview.html
It is specially important to have the policy flow in mind at all times while reading a trace.

It is necessary to understand how eDirectory’s schema work when designing an Identity Manager system, and that knowledge is very useful when trying to make sense of an IDM trace as well. To know more about the eDirectory schema, please go to:
http://developer.novell.com/documentation/ndslib/schm_enu/data/h4q1mn1i.html

The DTD (Document Type Definition) for DirXML-Script and XDS (NDS DTD) can be found at:
http://www.novell.com/documentation/idm35/policy_dtd/data/bookinfo.html

From the NDS DTD it is important to keep in mind two tags: <input> and <output>.

  • Input: Used to encapsulate events or commands sent as input to a driver or Identity Manager. All <nds> documents sent as a parameter to Identity Manager or driver interface method should contain exactly one <input>.
  • Output: Used to encapsulate events or commands returned to a driver or Identity Manager. All <nds> documents returned from Identity Manager or the driver interface method should contain exactly one <output>.

Setting the trace level and saving to a file

The trace level can be set through iManager or Designer. To do that in iManager you will need to install the Identity Manager plugins appropriated for your version of IDM and iManager. If you are using a Remote Loader with a driver, the Driver Shim trace will need to be configured at the Remote Loader itself.

The actual trace file can be obtained by setting the the Driver parameter so that the driver traces to a text file, by using DSTRACE or by using iMonitor. In case you have a Remote Loader, its trace file is set directly on it and contain the Driver Shim trace only. The IDM documentation explains step-by-step the procedures with some screenshots to help at the URL http://www.novell.com/documentation/idm35/admin/data/b1rc1vm.html ( Within Managing Identity Manager drivers, section 2.14 Viewing Identity Manager Processes ).

Usual IDM trace levels range from 0 through 5, with the JDBC driver having levels 6 and 7, and the scripting, mainframe, midrange and Linux&Unix drivers going all the way up to trace level 10. Most engine-side troubleshooting (driver start-up & driver logic issues) can be done at level 3. Driver Shim troubleshooting might require a higher level (higher numeric value for the trace level) depending on what you are trying to troubleshoot. The table below shows the amount of information provided by trace levels 0 through 4 on the IDM engine. Please keep in mind that type and amount of information provided for the Driver Shim varies per driver type.

Engine Trace Level Information Provided
0 Status messages only
1 Current location in the driver logic and Status messages
2 Events (XML format), Current location in the driver logic and Status messages
3 Driver logic execution details (showing the DirXML-Script as well), Events (XML format), Current location in the driver logic and Status messages
4 Cache-related information about the event coming from the Metadirectory, Driver logic execution details (showing the DirXML-Script as well), Events (XML format), Current location in the driver logic and Status messages

For the rest of this document it will be assumed that the trace was taken by configuring a trace file within the driver parameters. This method has the following advantages over DSTRACE and iMonitor:

  • It traces a single driver and nothing else (DSTRACE and iMonitor will get all drivers that are running mixed in the trace, making it harder to track anything)
  • It is possible to set a trace size limit to the file
  • The timestamp precision is milliseconds (very helpful when tracking performance issues)
  • The actual trace file is indented for easier reading

Parts of the Engine trace

On an IDM engine trace level 3 and above, there will be four basic types of messages. Traces taken from the Driver Shim will have additional types of messages, but since those will be driver-specific they won’t be mentioned on this document. The four types of engine trace messages are:

Status Messages

Status Description
success Operation or event was successful
warning Operation or event was partially successful
error Operation or event failed
fatal A fatal error occurred. The driver should be shut down
retry Application server was unavailable. Send this event or operation later

Here are some sample Status messages with a break-down of their structure:

Success status message:

[12/05/07 07:12:03.609]: SampleDriver ST:
DirXML Log Event -------------------
Driver: \LAB-TREE\idmorg\Driverset\SampleDriver
Channel: Subscriber
Object: \LAB-TREE\idmorg\users\sampleuser
Status: Success

  • First line breakdown:
    [12/05/07 07:12:03.609]: SampleDriver ST:
    Timestamp                       Driver’s name Channel
                                                                 (ST = Subscriber, PT = Publisher)
  • Second line: “DirXML Log Event ——————-” is standard and can be used to search for Status messages in an IDM trace
  • Third line list’s the driver’s object location in the tree, using slash format for the dn
  • Fourth line describe in which channel the event happened, and its values can be either Publisher or Subscriber
  • Fifth line gives the object in the Metadirectory affected by the event, using slash format for the dn
  • Sixth line has the final status of the event (look at the table above for Status values)

Warning status message:

[12/05/07 07:12:45.231]: SampleDriver ST:
DirXML Log Event -------------------
Driver: \LAB-TREE\idmorg\Driverset\SampleDriver
Status: Warning
Message: Code(-8001) Unable to retrieve application schema.

  • First line breakdown:
    [12/05/07 07:12:45.231]: SampleDriver ST:
    Timestamp                       Driver’s name Channel
                                                                 (ST = Subscriber, PT = Publisher)
  • Second line: “DirXML Log Event ——————-” is standard and can be
    used to search for Status messages in an IDM trace
  • Third line list’s the driver’s object location in the tree, using slash format for the dn
  • Fourth line has the final status of the event (look at the table above for Status values)
  • Fifth line has a message describing the error, quite often with an error code and/or
    Java stack below it.

Error status message:

[12/05/07 07:13:01.790]: SampleDriver ST:
DirXML Log Event -------------------
Driver: \LAB-TREE\idmorg\Driverset\SampleDriver
Channel: Subscriber
Status: Error
Message: Code(-9075) Shutting down because DirXML engine evaluation
period has expired

  • First line breakdown:
    [12/05/07 07:13:01.790]: SampleDriver ST:
    Timestamp                       Driver’s name Channel
                                                                 (ST = Subscriber, PT = Publisher)
  • Second line: “DirXML Log Event ——————-” is standard and can be
    used to search for Status messages in an IDM trace
  • Third line list’s the driver’s object location in the tree, using slash format for the dn
  • Fourth line describe in which channel the event happened, and its values can be
    either Publisher or Subscriber
  • Fifth line has the final status of the event (look at the table above for Status values)
  • Sixth line has a message describing the error, quite often with an error code and/or
    Java stack below it.

Fatal status message:

[12/05/07 07:14:23.987]: SampleDriver PT:
DirXML Log Event -------------------
Driver: \LAB-TREE\idmorg\Driverset\SampleDriver
Channel: Publisher
Status: Fatal
Message: <message>unable to authenticate to Active Directory</message>
<ldap-err ldap-rc="86" ldap-rc-name="LDAP_AUTH_UNKNOWN">
<client-err ldap-rc="14"/>
</ldap-err>

  • First line breakdown:
    [12/05/07 07:14:23.987]: SampleDriver ST:
    Timestamp                       Driver’s name Channel
                                                                 (ST = Subscriber, PT = Publisher)
  • Second line: “DirXML Log Event ——————-” is standard and can be
    used to search for Status messages in an IDM trace
  • Third line list’s the driver’s object location in the tree, using slash format for the dn
  • Fourth line describe in which channel the event happened, and its values can be
    either Publisher or Subscriber
  • Fifth line has the final status of the event (look at the table above for Status values)
  • Sixth line has a message describing the error, quite often with an error code and/or
    Java stack below it. In this case its an XML document with more data on the
    problem that happened

Retry status message:

[12/05/07 07:15:57.875]: SampleDriver ST:
DirXML Log Event -------------------
Driver: \LAB-TREE\idmorg\Driverset\SampleDriver
Channel: Subscriber
Status: Retry
Message: Code(-9006) The driver returned a "retry" status indicating
that the operation should be retried later. Detail from driver: No connection
to remote loader

  • First line breakdown:
    [12/05/07 07:15:57.875]: SampleDriver ST:
    Timestamp                       Driver’s name Channel
                                                                 (ST = Subscriber, PT = Publisher)
  • Second line: “DirXML Log Event ——————-” is standard and can be
    used to search for Status messages in an IDM trace
  • Third line list’s the driver’s object location in the tree, using slash format for the dn
  • Fourth line describe in which channel the event happened, and its values can be
    either Publisher or Subscriber
  • Fifth line has the final status of the event (look at the table above for Status values)
  • Sixth line has a message describing the error, quite often with an error code and/or
    Java stack below it.

Messages that describe the location in the driver’s logic

Those are single lines that point where the engine is while executing the driver’s logic or
interacting with the Metadirectory vault. Its basic format is:

[12/05/07 07:12:03.790]: SampleDriver ST: Start transaction.:
Timestamp                       Driver’s name Channel Message

The table below is a list with some of those messages and their meanings:

Message What it means
Start transaction. An event that occurred on the Metadirectory was read from the cache to be processed by the Subscriber channel
No event transformation policies. The driver’s logic don’t have any event transformation policies to be processed
Applying event transformation policies. The logic contained in the driver’s event transformation policies will be executed after this message
No object matching policies. The driver’s logic don’t have any object matching policies to be processed
Applying object matching policies. The logic contained in the driver’s object matching policies will be executed after this message
No object creation policies. The driver’s logic don’t have any object creation policies to be processed
Applying object creation policies. The logic contained in the driver’s object creation policies will be executed after this message
No object placement policies. The driver’s logic don’t have any object
placement policies to be processed
Applying object placement policies. The logic contained in the driver’s object placement policies will be executed after this message
No schema mapping policies to output. The driver’s logic don’t have any schemamapping policies to be processed when sending information to the connected system
Applying schema mapping policies to output. The logic contained in the driver’s schema mapping policies will be executed after this message
No schema mapping policies to input. The driver’s logic don’t have any schema mapping policies to be processed when receiving information from the connected system
Applying schema mapping policies to input. The logic contained in the driver’s schema mapping policies will be executed after this message
No command transformation policies. The driver’s logic don’t have any command transformation policies to be processed
Applying command transformation policies. The logic contained in the driver’s command transformation policies will be executed after this message
No output transformation policies. The driver’s logic don’t have any output transformation policies to be processed
Applying output transformation policies. The logic contained in the driver’s output transformation policies will be executed after this message
No input transformation policies. The driver’s logic don’t have any input transformation policies to be processed
Applying input transformation policies. The logic contained in the driver’s input transformation policies will be executed after this message
Pumping XDS to eDirectory. An event or query (XML) will be executed on
the Metadirectory, and a return XML document will be provided with either a status or a query result
Stripping operation data from input
document
The XML fragment whose root is the tag <operation-data> will be excluded from the XML document send to the Driver Shim
Restoring operation data to output document The XML fragment whose root is the tag <operation-data>, saved before the XML was sent to the Driver Shim, will be reinserted on the response XML document returned from the Driver Shim
End transaction. The event initiated on the previous Start transaction. is finished, and any status messages related to it will happen before this Message
Receiving DOM document from application. An event that occurred on the connected application was received to be processed on the Publisher channel
Applying XSLT policy. The StyleSheet (XSLT code) located at this
point on the driver was executed on the event’s XML document
Filtering out notification-only attributes. Attributes flagged as “Notify” in the Driver’s filter for the channel being processed will be removed
Fixing up association references. Attributes whose syntax is “dn” or “path” on the Metadirectory will have their values (object references) converted to the name of associated object on the connected system
Resolving association references. Attributes whose syntax is “dn” or “path” on the Metadirectory will have their values (object references) converted from the associated object on the connected system back to the equivalent Metadirectory object
Applying publisher filter. The attributes/classes flagged as “Synchronize” on the Publisher channel filter will be allowed to pass, the attributes/classes flagged as “Ignore” on the Publisher channel filter will be stripped from the current event. Any attributes/classes not listed in the filter will be stripped as well.

Messages about the driver’s logic execution details

These messages point which operation is being evaluated against the driver’s logic, as well as
give the police and rule name, as well as the results of evaluating the rule’s conditions and
actions. Its basic format is:

[12/05/07 07:54:02.250]: SampleDriver PT: Applying to add #1.
Timestamp                       Driver’s name Channel Message

The table below is a list with some of those messages and their meanings:

Message What it means
Applying policy: %+C%14CMy policy name here%-C. The IDM engine will execute the logic contained in the policy named
“My policy name here” The name of the policy will always be within the delimiters %+C%14C and %-C , and will match the name of a policy in the driver’s logic
Applying to operation #1. The policy logic will be applied to the operation listed. In this message you will not see the text operation, instead you will see one of the strings below:
  • add
  • add-association
  • check-object-password
  • check-password
  • delete
  • get-named-password
  • init-params
  • instance
  • modify
  • modify-association
  • modify-password
  • move
  • password
  • query
  • query-schema
  • remove-association
  • rename
  • schema-def
  • status
  • sync

The number after the # sign is the position of that
event within the <input> or <output> document,
number 1 being the first position.

Evaluating selection criteria for rule ‘My rule name comes here’. The conditions coded in the rule named “My rule name comes here” will be evaluated. The name of the rule will always be within single quotes, and will match the name of a rule in your driver’s logic
(if-operation equal “add”) = TRUE. This line shows the engine evaluating the DirXML-Script code contained between the parentheses, and the other side of the equal side is the result of evaluating that code, and can be TRUE or FALSE.
This code is the result of the logic entered in the driver through Policy Builder (iManager) or Designer’s User Interface. In this message used as an example, the policy builder equivalent for the DirXML-Script can be found here: http://www.novell.com/documentation/idm35/policy_imanager/data/bxj6vfi.html
Rule rejected. The rule’s conditions weren’t completely met, so
that rule’s actions won’t be executed.
Rule selected. The rule’s conditions were met, so that rule’s
actions will be executed.
Applying rule ‘My rule name comes here’. The actions coded in the rule named “My rule name comes here” will be executed. The name of the rule will always be within single quotes, and will match the name of a rule in your driver’s logic
Action: do-strip-opattr(“nspmDistributionPass word”). The action corresponding to the DirXML-Script right after the colon sign will be executed. To understand the details of that action please refer to the DirXML-Script DTD link provided in the Basic Concepts section of this document

Here is an excerpt of an actual IDM engine level 3 trace to serve as an example (emphasis
added to clarify explanation):

[12/05/07 07:54:02.250]: SampleDriver PT: Applying policy: %+C%14CPassword(Pub)-Default Password
Policy%-C.
[12/05/07 07:54:02.265]: SampleDriver PT: Applying to add #1.
[12/05/07 07:54:02.265]: SampleDriver PT: Evaluating selection criteria for rule 'On User
add, provide default password of @Dirxml1 if no password exists'.
[12/05/07 07:54:02.265]: SampleDriver PT: (if-operation equal "add") = TRUE.
[12/05/07 07:54:02.265]: SampleDriver PT: (if-class-name equal "User") = TRUE.
[12/05/07 07:54:02.265]: SampleDriver PT: (if-password not-available) = FALSE.
[12/05/07 07:54:02.265]: SampleDriver PT: Rule rejected.
[12/05/07 07:54:02.265]: SampleDriver PT: Policy returned:

The first line of the trace excerpt above tell us that the engine will process a policy called
Password(Pub)-Default Password Policy
The second line inform us that the operation being executed is an object add
The third line show that the rule being processed is called On User add, provide default
password of @Dirxml1 if no password exists

Fourth, Fifth and Sixth lines are DirXML-Script conditions being evaluated. First two evaluate
to true, third one to false
Seventh line shows that not all necessary conditions were met, so the rule won’t be processed
(Rule rejected.)

Here is another IDM engine level 3 trace excerpt (emphasis added to clarify explanation):

[12/05/07 08:29:22.625]: Active Directory ST: Applying policy: %+C%14C'Transform NMAS attribute
to password elements'%-C.
[12/05/07 08:29:22.625]: Active Directory ST: Applying to modify #1.
[12/05/07 08:29:22.625]: Active Directory ST: Evaluating selection criteria for rule
'Convert adds of the nspmDistributionPassword attribute to password elements'.
[12/05/07 08:29:22.625]: Active Directory ST: (if-operation equal "add") = FALSE.
[12/05/07 08:29:22.625]: Active Directory ST: Rule rejected.
[12/05/07 08:29:22.625]: Active Directory ST: Evaluating selection criteria for rule 'Block
modifies for failed password publish operations if reset password is false'.
[12/05/07 08:29:22.640]: Active Directory ST: (if-global-variable 'reset-externalpassword-
on-failure' equal "false") = FALSE.
[12/05/07 08:29:22.640]: Active Directory ST: Rule rejected.
[12/05/07 08:29:22.640]: Active Directory ST: Evaluating selection criteria for rule
'Convert modifies of a nspmDistributionPassword attribute to a modify password operation'.
[12/05/07 08:29:22.640]: Active Directory ST: (if-operation equal "modify") = TRUE.
[12/05/07 08:29:22.640]: Active Directory ST: (if-op-attr 'nspmDistributionPassword'
available) = TRUE.
[12/05/07 08:29:22.640]: Active Directory ST: Rule selected.
[12/05/07 08:29:22.640]: Active Directory ST: Applying rule 'Convert modifies of a
nspmDistributionPassword attribute to a modify password operation'.
[12/05/07 08:29:22.640]: Active Directory ST: Action: do-set-dest-password(tokenxpath("
modify-attr[@attr-name='nspmDistributionPassword']//add-value//value")).
[12/05/07 08:29:22.656]: Active Directory ST: arg-string(token-xpath("modify-attr[@attrname='
nspmDistributionPassword']//add-value//value"))
[12/05/07 08:29:22.656]: Active Directory ST: token-xpath("modify-attr[@attrname='
nspmDistributionPassword']//add-value//value")
[12/05/07 08:29:22.656]: Active Directory ST: Token Value: "-- suppressed --".
[12/05/07 08:29:22.656]: Active Directory ST: Arg Value: "-- suppressed --".
[12/05/07 08:29:22.656]: Active Directory ST: Action: do-strip-opattr("
nspmDistributionPassword").
[12/05/07 08:29:22.656]: Active Directory ST: Action: do-set-xml-attr("eventid","../
modify-password","pwd-subscribe").
[12/05/07 08:29:22.656]: Active Directory ST: arg-string("pwd-subscribe")
[12/05/07 08:29:22.656]: Active Directory ST: token-text("pwd-subscribe")
[12/05/07 08:29:22.671]: Active Directory ST: Arg Value: "pwd-subscribe".

The first line of the trace excerpt above tell us that the engine will process a policy called
Transform NMAS attribute to password elements
The second line inform us that the operation being executed is an object modify
The third line show that the rule being processed is called Convert adds of the
nspmDistributionPassword attribute to password elements

Fourth line is a DirXML-Script condition being evaluated for the rule. It evaluated to FALSE
Fifth line shows that not all necessary conditions for the rule were met, so the rule won’t be
processed (Rule rejected.)
Sixth line show that the rule being processed now is Block modifies for failed password publish
operations if reset password is false

Seventh line is a DirXML-Script condition being evaluated for the rule. It evaluated to FALSE
Eighth line shows that not all necessary conditions for the rule were met, so the rule won’t be
processed (Rule rejected.)
Ninth line show that the rule being processed now is Convert modifies of a
nspmDistributionPassword attribute to a modify password operation.

Lines 10 and 11 are DirXML-Script conditions being evaluated for the rule. Both evaluated to
TRUE
Line 12 shows that all necessary conditions for the rule were met, so the rule will be processed
(Rule selected.)
Line 13 enter into the Actions part of the rule Convert modifies of a nspmDistributionPassword
attribute to a modify password operation.
Lines 14 all the way through the end are the Actions being executed by the IDM engine based
on the driver’s logic, and they are in DirXML-Script format.

Events (XML – NDS DTD)

This is the part of the trace that shows what type of operation and data is flowing from one
system to the other, and allows us to trace changes made by the driver’s logic in both data and
operations. It is pure XML, and conforms with the NDS DTD mentioned in the Basic Concepts
section of this document.

There are several sample events that can be used to better understand how each type of event is
structured. Those example come with Identity Manager Designer. The current version of
Identity Manager Designer (version 2.1.1 at the time of this writing) can be downloaded from:
http://www.novell.com/coolsolutions/dirxml/designer/ and you can see the location for the
sample Event XML files within Designer’s docs:

http://www.novell.com/documentation/idm35/policy_designer/data/xpathbuilder.html

The events themselves are actually XDS documents (XDS is an XML vocabulary defined by
the NDS DTD)

The root of a XDS document is the <nds> tag. It can have the following tags as its immediate
children:

  • <source>

    The source or creator of the document
  • <input>

    Input events or commands
  • <output>

Result of events or commands

Here is a sample XDS document for an event’s result:

<nds dtdversion="3.0" ndsversion="8.x">
<source>
<product version="3.0.10.20060630 ">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<output>
<status event-id="0" level="success"></status>
</output>
</nds>

In this document, we have the <source> tag and the <output> tag as children of <nds>. The <source> tag and its children show us that the product version is 3.0.10.20060630 (note that the last piece is a timestamp, June 30th, 2006), and that the Contact for that product is Novell, Inc.

The <output> tag has only one child, a <status> tag. Looking at the “level” attribute of that tag, we know that the event sent was successful, and this XML will generate a Success Status
Message when it reaches the proper location on the driver.

Here is a sample XDS document for an event coming from the connected application:

<nds dtdversion="2.2">
<source>
<product version="3.0.10.20060630 ">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<add class-name="user" event-id="sampleADdriver##116a048eaca##0" srcdn="
CN=labuser01,OU=idm,DC=labdomain2,DC=com">
<association>84381d55999337498f37f3561face219</association>
<add-attr attr-name="displayName">
<value naming="false" type="string">labuser01</value>
</add-attr>
<add-attr attr-name="givenName">
<value naming="false" type="string">lab</value>
</add-attr>
<add-attr attr-name="sAMAccountName">
<value naming="false" type="string">labuser01lab</value>
</add-attr>
<add-attr attr-name="sn">
<value naming="false" type="string">user</value>
</add-attr>
</add>
</input>
</nds>

In this document, we have the <source> tag and the <input> tag as children of <nds>. Since we already discussed the <source> tag, this time let’s focus on the <input> tag.

This <input> tag has a single add object operation below it, characterized by <add> tag. Looking at the XML attributes of the add tag we can see that the object being added is of the “user” class (look at the value for the CML attribute class-name), and that 4 attributes are being added (an attribute add is characterized by the <add-attr> tag children of an <add> tag). Looking from the top, the first attribute being added is called “displayName”, the second is “givenName”, the third is “sAMAccountName”, and the fourth is “sn”.

Each <add-attr> tag contains one or more <value> tags, and the text within the <value> and </value> is the attribute data. So for the first attribute, its value is “labuser01”, for the second attribute its value is “lab”, for the third attribute the value is “labuser01lab” and the fourth attribute’s value is “user”. If at this point you are curious about the other pieces in those XML documents, they are fully described in the NDS DTD for each of the tags.

Both the <input> and <output> tags can contain multiple events within them, and those event are processed top-down linearly by the driver. Each operation has its own tag. Look at the table below for a view of operations, its tags and if they will be contained by <input> or <output>.

Look up each tag definition on NDS DTD for details on each operation and its structure.

Child of Tag Operation’s description
<input> <add> Add an object
<modify> Modify an object’s attributes
<delete> Delete an object
<rename> Rename an object
<move> Move an object
<query> Query command
<query-ex> Query command that can fragment the reply in several
pieces
<query-schema> Query Schema command
<check-password> Checks password against an eDirectory driver object
<modify-password> Modify an object’s password
<check-object-password> Check password against an eDirectory driver object
<sync> Force the migration or resynchronization of an object
<get-named-password> Retrieves a named password for a driver
<output> <instance> Current state of an instance of an object (query result)
<schema-def> Schema definition
<password> The password used to authenticate against the connected
application
<query-token> Opaque handle for query-ex commands (query-ex result)
<input> and <output> <add-association> Add a DirXML-Association to an object
<modify-association> Modifies the DirXML-Association on an object
<remove-association> Removes the DirXML-Association from an object
<init-params> Initialization parameters for a DriverShim,
SubscriptionShim or PublicationShim
<status> Status of the processing of a command or event

Lastly, a quick summary of the trace pieces as seem in a text editor:

Driver Startup trace parts

During the driver initialization it is possible to capture in the trace a lot of useful information,
such as GCV information, initialization parameters, filter information, among other things.

The initialization start with the string Reading named passwords list. , so that string can be used
as a starting point. Next it will progress reading information from the Driver Object, and later
reading the objects that store the actual policies / rules / stylesheets. Whenever the driver
initialization is reading one of those pieces, there will be messages like Reading XML attribute
vnd.nds.stream: , followed by the full DN of the object and attribute being read.

After those lines, when relevant, the information read will also be presented in the trace. Here is
an sample excerpt from an eDirectory driver startup:

[01/02/08 10:26:15.451]:eDirectory Driver :Reading named passwords list.
[01/02/08 10:26:15.469]:eDirectory Driver :Named passwords:
[01/02/08 10:26:15.570]:eDirectory Driver :Reading XML attribute
vnd.nds.stream://OESNW_TREE/idm/services/driverset/eDirectory+Driver#DirXML-EngineControlValues.
[01/02/08 10:26:16.113]:eDirectory Driver :Reading XML attribute
vnd.nds.stream://OESNW_TREE/idm/services/driverset#DirXML-ConfigValues.
[01/02/08 10:26:16.126]:eDirectory Driver :Reading XML attribute
vnd.nds.stream://OESNW_TREE/idm/services/driverset/eDirectory+Driver#DirXML-ConfigValues.
[01/02/08 10:26:16.180]:eDirectory Driver :Global Configuration Values:
[01/02/08 10:26:16.182]:eDirectory Driver : Name: enable-password-subscribe Value: true
[01/02/08 10:26:16.184]:eDirectory Driver : Name: enable-password-publish Value: true
[01/02/08 10:26:16.185]:eDirectory Driver : Name: publish-password-to-nds Value: true
[01/02/08 10:26:16.186]:eDirectory Driver : Name: publish-password-to-dp Value: false
[01/02/08 10:26:16.188]:eDirectory Driver : Name: enforce-password-policy Value: true
[01/02/08 10:26:16.190]:eDirectory Driver : Name: reset-external-password-on-failure Value:
true
[01/02/08 10:26:16.205]:eDirectory Driver : Name: notify-user-on-password-dist-failure Value:
true
[01/02/08 10:26:16.206]:eDirectory Driver : Name: ConnectedSystemName Value: eDirectory Driver
[01/02/08 10:26:16.208]:eDirectory Driver : Name: dirxml.auto.treename Value: OESNW_TREE
[01/02/08 10:26:16.209]:eDirectory Driver : Name: dirxml.auto.driverdn
Value: \OESNW_TREE\idm\services\driverset\eDirectory Driver
[01/02/08 10:26:16.223]:eDirectory Driver : Name: dirxml.auto.driverguid Value: {044F4400-
B953-11dc-968B-000C290066AE}

Going through it line by line, here is the meaning of them:

  1. Driver starting, as its first step it tries to read the named passwords list
  2. Header shown before listing the names on the named password list (in this case, blank since this driver didn’t have any named passwords configured)
  3. The engine is reading the value from the attribute “DirXML-EngineControlValues” , that resides in the eDirectory object called “eDirectory Driver”, under the container “driverset.services.idm”, at the tree named “OESNW_TREE”
  4. The engine is reading the value from the attribute “DirXML-ConfigValues” , that resides in the eDirectory object called “driverset”, under the container “services.idm”, at the tree named “OESNW_TREE”
  5. The engine is reading the value from the attribute “DirXML-ConfigValues” , that resides in the eDirectory object called “eDirectory Driver”, under the container “driverset.services.idm”, at the tree named “OESNW_TREE”
  6. Header shown before listing the Global Configuration Values
  7. This and all the remaining lines are just showing the GCV’s names and values, shown as they will be used in the policy’s logic.

The driver initialization will continue, and as it reads the values for certain attributes it will
show its contents in the trace as well.
Example of driver initialization parameters:

[01/02/08 10:26:18.759]:eDirectory Driver ST:Reading XML attribute
vnd.nds.stream://OESNW_TREE/idm/services/driverset/eDirectory+Driver#DirXML-ShimConfigInfo.
[01/02/08 10:26:18.813]:eDirectory Driver ST:
<nds dtdversion="3.5" ndsversion="8.x">
<source>
<product version="3.5.10.20070918 ">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<init-params src-dn="\OESNW_TREE\idm\services\driverset\eDirectory Driver">
<authentication-info>
<server>10.0.110.3:8196</server>
<user>eDirectory Driver(NW65SP7_kmo)</user>
</authentication-info>
</init-params>
</input>
</nds>

Example of a driver filter:

[01/02/08 10:26:21.702]:eDirectory Driver ST:Reading XML attribute
vnd.nds.stream://OESNW_TREE/idm/services/driverset/eDirectory+Driver#DirXML-DriverFilter.
[01/02/08 10:26:22.422]:eDirectory Driver ST:Loaded filter.
[01/02/08 10:26:22.475]:eDirectory Driver ST:
<filter>
<filter-class class-name="Group" publisher="sync" subscriber="sync">
<filter-attr attr-name="CN" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Description" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="GUID" subscriber="sync"/>
</filter-class>
<filter-class class-name="Organizational Unit" publisher="sync" subscriber="sync">
<filter-attr attr-name="Description" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="GUID" subscriber="sync"/>
<filter-attr attr-name="OU" publisher="sync" subscriber="sync"/>
</filter-class>
<filter-class class-name="User" publisher="sync" subscriber="sync">
<filter-attr attr-name="CN" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="co" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="company" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Description" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Equivalent To Me" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Facsimile Telephone Number" publisher="sync"
subscriber="sync"/>
<filter-attr attr-name="Full Name" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Generational Qualifier" publisher="sync"
subscriber="sync"/>
<filter-attr attr-name="Given Name" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Group Membership" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="GUID" subscriber="sync"/>
<filter-attr attr-name="L" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="manager" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="OU" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Security Equals" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="See Also" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="spouse" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Surname" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Telephone Number" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="Title" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="UID" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="uniqueID" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="workforceID" publisher="sync" subscriber="sync"/>
<filter-attr attr-name="nspmDistributionPassword" merge-authority="none"
publisher="ignore" publisher-optimize-modify="false" subscriber="notify"/>
</filter-class>
</filter>

If the driver is using remote loader, we will also see some remote loader connection messages in
the trace.

The driver initialization proceeds reading information from the needed objects until it finishes
initializing them all, then proceeds to query the shim for the __driver_identification_class__ .

Sample query below:

[01/02/08 10:26:26.156]:eDirectory Driver ST:Submitting identification query to subscriber shim:
[01/02/08 10:26:26.196]:eDirectory Driver ST:
<nds dtdversion="3.5" ndsversion="8.x">
<source>
<product version="3.5.10.20070918 ">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<query event-id="query-driver-ident" scope="entry">
<search-class class-name="__driver_identification_class__"/>
<read-attr/>
</query>
</input>
</nds>

The shim replies the query with information about its type, version, activation level and capabilities. Sample response:

[01/02/08 10:26:26.199]:eDirectory Driver ST:SubscriptionShim.execute() returned:
[01/02/08 10:26:26.216]:eDirectory Driver ST:
<nds dtdversion="3.5">
<source>
<product instance="eDirectory Driver" version="3.5.10.20070918 ">DirXML Driver for
eDirectory</product>
<contact>Novell, Inc.</contact>
</source>
<output>
<instance class-name="__driver_identification_class__">
<attr attr-name="driver-id">
<value type="string">EDIR</value>
</attr>
<attr attr-name="driver-version">
<value type="string">3.5.10.20070918 </value>
</attr>
<attr attr-name="min-activation-version">
<value type="int">4</value>
</attr>
<attr attr-name="query-ex-supported">
<value type="state">true</value>
</attr>
</instance>
</output>
</nds>

Some other queries and message exchanges will happen, like a query from the shim to the driver for its GUID and Public Key attributes, among others. The driver initialization itself is over when we see a message like this:

[01/02/08 10:26:26.467]:eDirectory Driver ST:Transitioned from state '%+C%14CStarting%-C' to state '%+C%14CRunning%-C'.

Any point after that message we will see the events starting to come through in the trace. A lot of the driver initialization problems can be fixed by getting a level 4 engine trace and following it step by step until we get an error message with more details.

Queries and Direct commands from Policy

Another point worth mentioning is that queries and direct commands from policy don’t follow the regular flow like an event. If a query or a direct command from policy are issued to eDirectory from any rule, they will go straight into eDirectory without passing any other stages, and the results will come back directly to the rule that issued them.

If a query or a direct command from policy are issued to the connected application from any rule, they will need to be converted to the application format before being sent to the driver shim, and converted back into eDirectory format before going back to the rule. Due to that, those types of query / direct command from policy will pass through the association reference processor, Schema Mapping policy set and Output Transformation policy set before being sent to the connected application. The response from the application will pass through the Input Transformation Policy set, Schema Mapping policy set and association reference processor before going back to the issuing rule.

The only exception to this is when the query/direct command from policy is issued from the Input Transformation policy set itself, since it assumes that the data is already in the application format. In that case, the query/direct command from policy will go straight to the shim, and the results come back directly to the issuing rule.

VN:F [1.9.22_1171]
Rating: 0.0/5 (0 votes cast)

Tags:
Categories: Uncategorized

Disclaimer: As with everything else at NetIQ Cool Solutions, this content is definitely not supported by NetIQ, so Customer Support will not be able to help you if it has any adverse effect on your environment.  It just worked for at least one person, and perhaps it will be useful for you too.  Be sure to test in a non-production environment.

1 Comment

  1. By:bguay

    Excellent article.
    Tracing to a file instead of using DSTrace has many advantages as the author mentioned. Additional advantages include:
    - less performance impact on the server;
    - ability to write trace files on a remote shared drive, thus ability to limit access to the IDM server;
    - easier support (customer can send trace files by e-mail in case of problems);
    - easier troubleshooting by comparing a reference “healthy” trace with a problematic one;
    - easy capturing of events and outputs for simulation in Designer.

    It is even more so when using an enhanced text editor such as UltraEdit. Here are functionalities I find useful:

    - “view as XML”: the editor will add color to XML tags and several XML elements, making traces easier to read;
    - revert to saved: a simple click or keyboard shortcut will reload the file, thus updating the file;
    - Detect changes: the editor will detect updates to the file and ask if it should be reloaded;
    - open shared: open the file even if it is already opened by the IDM engine, which Notepad won’t do;
    - advanced search functions;
    - ability to open several trace files in multiple tabs instead of several windows;
    - line numbering (“the problem is at line 7623″).

Comment