Effectively Reading a DirXML Trace File
Articles and Tips: article
Net Solutions Support
Novell, Inc.
iforst@novell.com
Hicham Mourad
Net Solutions Support
Novell, Inc.
hmourad@novell.com
Garth Williamson
Net Solutions Support
Novell, Inc.
gwilliamson@novell.com
01 Oct 2002
One of the useful tools in troubleshooting DirXML implementations is the trace file. This AppNote walks you through an actual DirXML trace file to show what a normal trace looks like. By understanding this, you will be better able to identify issues that don't seem to be normal when you encounter them in your own DirXML trace files.
|
Topics |
DSTRACE, iMonitor, Java trace file, NXSL Processor |
|
Products |
DirXML 1.x |
|
Audience |
developers |
|
Level |
intermediate |
|
Prerequisite Skills |
familiarity with architecture and use of DirXML |
|
Operating System |
n/a |
|
Tools |
DSTRACE, iMonitor, Java Trace File, NXSL Processor |
|
Sample Code |
no |
Introduction
In a previous AppNote (see "An Methodology for Troubleshooting DirXML" in the September 2002 issue of Novell AppNotes, available online at http://support.novell.com/techcenter/articles/dnd20020904.html), we introduced a recommended methodology for troubleshooting DirXML issues. As part of that discussion, we explained how to capture DirXML trace files to assist you in determining where the problem may lie.
This AppNote walks you through an actual DirXML trace file and explains what is occurring. Hopefully, by going through this trace file, you will see what a normal trace looks like and thus be better able to identify issues that don't seem to be normal when you encounter them in your own DirXML trace files.
Trace File Key Concept Review
Before we start looking at the sample trace file, let's review some of the key concepts you need to understand.
Understand each section of the trace file before proceeding to the next. You will learn with experience what each line means, but until then you must review the trace thoroughly. Going through a DirXML trace file is an excellent way to learn how the DirXML engine works and in what order the engine performs it responsibilities.
Never assume that what is in the trace file is okay just because the error occurs later on in the trace file. Errors often occur because some set of criteria is not being met earlier in the chain of order. Be sure to investigate every error and understand it.
Have a list of the driver exports at hand. This is an absolute must--having the driver exports means that you have all information about the filters, rules, and stylesheets of both the subscriber and publisher channels. As you review the trace file, the best practice is to follow along and go through the filters, rules, and stylesheets as they are being executed.
A good reference to have on hand is the DirXML Engine and Architecture diagram (see Figure 1). Having such a diagram can simplify the complexities of a trace by helping you see what is going to happen next in the order of DirXML engine execution. It also clarifies filter, rule, and stylesheet execution for both subscriber and publisher channels.
Figure 1: DirXML engine and architecture diagram.
Another good reference to keep handy is the DirXML Rule Execution Order diagram in Figure 2.
Figure 2: DirXML rule execution order.
Reading a Sample Trace File
This example scenario involves an eDirectory-to-eDirectory driver. It is a simple creation of a user in TREE-ONE being synchronized to TREE-TWO. The trace contains no errors, but serves as an example of normal DirXML behavior. In this section we will go through the trace file and explain its contents.
In this particular example, the DirXML event goes out through the subscriber channel on TREE-ONE and in the publisher channel on TREE-TWO, as shown in Figure 3.
Figure 3: Diagram of the eDirectory-to-eDirectory driver setup.
The Trace from TREE-ONE
In our example scenario, a user is initially created in eDirectory on TREE-ONE. Since we are looking at the trace file from a TREE-ONE perspective, keep in mind that we are currently on the subscriber channel of TREE-ONE.
The messages below represent DirXML detecting the changes to the eDirectory database for which a DirXML event must be generated. Once these changes to eDirectory are complete, DirXML will trigger an event to send down the Subscriber channel.
[01/07/02 12:13:17.912]: TRACE: Commit transaction requested [01/07/02 12:21:36.196]: TRACE: Start transaction [01/07/02 12:21:36.196]: TRACE: submitEvent requested [01/07/02 12:21:36.196]: TRACE: event for attr: null [01/07/02 12:21:36.196]: TRACE: created a DOM node for event [01/07/02 12:21:36.196]: TRACE: submitEvent requested [01/07/02 12:21:36.196]: TRACE: event for attr: ACL [01/07/02 12:21:36.196]: TRACE: created a DOM node for event [01/07/02 12:21:36.416]: TRACE: Processing events for transaction [01/07/02 12:21:36.416]: TRACE: Converting \TREE-ONE\novell\Users\James Dean from Unknown to real base class
A user named James Dean is now created in the eDirectory database. DirXML will detect this and issue an event for the Add operation, as represented in the following XML document. (We are still on the subscriber channel of TREE-ONE.)
<nds dtdversion="1.1" ndsversion="8.5">
<source>
<product version="1.1">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<add class-name="User" src-dn="\TREE-ONE\novell\Users\James
Dean" src-entry-id="33151">
<add-attr attr-name="Surname" timestamp="1010424096#15">
<value timestamp="1010424096#15"
type="string">Dean</value>
</add-attr>
<add-attr attr-name="Given Name"
timestamp="1010424096#17">
<value timestamp="1010424096#17"
type="string">Jimmy</value>
</add-attr>
<add-attr attr-name="CN" timestamp="1010424096#28">
<value timestamp="1010424096#28" type="string">James
Dean</value>
</add-attr>
</add>
</input>
</nds>
Next, DirXML sends the Add XML document down the subscriber channel, processing each rule and stylesheet (if any exist) in the order in which the DirXML engine executes them (refer to the diagram in Figure 1). You can also see that the DirXML engine attempts to execute the Event Transformation stylesheet, but it is skipped since there isn't one in place. (We are still on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.416]: TRACE: No event transformation rule, skipping [01/07/02 12:21:36.416]: TRACE: Subscriber processing add for \TREE-ONE\novell\Users\James Dean
The Association Processor checks to see whether the event has changed. In this example, it hasn't. (We are still on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.416]: TRACE: Re-reading associations in case they changed since this event was queued
In the above line, the DirXML engine performs a double-check to see that the object is not associated.
Note: There is a situation when a Modify event on a User object can occur and the User object does not have an association. If this occurs, the DirXML engine will take this Modify event and change it to an Add event. This type of Add event is known as a Synthesized Add Event.
The DirXML engine executes the Matching rule, the Create rule, and the Placement rule, in that order. You can see this happening in the few lines below. However, none of these rules exists on the subscriber channel; hence you see the messages indicating that these rules are being skipped. (We are still on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.416]: TRACE: No matching rule, skipping [01/07/02 12:21:36.416]: TRACE: No create rule, skipping [01/07/02 12:21:36.416]: TRACE: No placement rule, skipping [01/07/02 12:21:36.470]: TRACE: Submitting add to subscriber shim
The DirXML engine has completed the channel specific transformation (rules and stylesheets). Now DirXML applies the Schema and Output Transformation rules. Notice the "No mapping rule skipping". This is normal when using the eDirectory- to-eDirectory driver, as the schemas will generally be identical--with the exception of any custom extensions made to either tree. (We are still on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.470]: TRACE: Applying output transformations [01/07/02 12:21:36.470]: TRACE: Fixing up associations references [01/07/02 12:21:36.470]: TRACE: No mapping rule, skipping [01/07/02 12:21:36.470]: TRACE: No output stylesheet, skipping [01/07/02 12:21:36.470]: TRACE: Submitting document to subscriber shim
Once all transformations are complete on the Add event on this subscriber channel, DirXML sends the transformed document to the Driver Shim to be sent to the remote database. Below you can see the subscriber channel sending the Add event as an XML document to the DirXML Driver Shim. (We are still on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.470]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: Reusing connection. [01/07/02 12:21:36.470]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: Sending... [01/07/02 12:21:36.470]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: XML Document: [01/07/02 12:21:36.470]: TRACE:
The following XML document shows what the DirXML Driver Shim sends to the destination tree. (We are still on the subscriber channel of TREE-ONE.)
<nds dtdversion="1.1" ndsversion="8.5">
<source>
<product version="1.1">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<add class-name="User" event-id="0"
src-dn="\TREE-ONE\novell\Users\James Dean"
src-entry-id="33151">
<add-attr attr-name="Surname" timestamp="1010424096#15">
<value timestamp="1010424096#15"
type="string">Dean</value>
</add-attr>
<add-attr attr-name="Given Name" timestamp="1010424096#17">
<value timestamp="1010424096#17"
type="string">Jimmy</value>
</add-attr>
<add-attr attr-name="CN" timestamp="1010424096#28">
<value timestamp="1010424096#28" type="string">James
Dean</value>
</add-attr>
</add>
</input>
</nds>
This is the Add Event XML document after all the transformations completed, and as it will appear to the remote eDirectory database in TREE-TWO.
At this time the DirXML driver shim has sent the document and is waiting for a response.
[01/07/02 12:21:36.470]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: Document sent. [01/07/02 12:21:36.470]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: Waiting for receive...
Since we are discussing the eDirectory-to-eDirectory driver, we can now switch over the trace file that has been captured from TREE-TWO. Depending on the filters, rules, and stylesheets used, there may be some transformations done on the Add XML document in that tree.
The Trace from TREE-TWO
You see below the publisher channel on TREE-TWO stating that is has just received a XML document. The document is then displayed.
[01/07/02 12:15:11.981]: TRACE: Commit transaction requested
[01/07/02 12:20:37.920]: TRACE: NdsToNds Publisher - NDSToNDS -
Flat: Receiving...
[01/07/02 12:20:37.930]: TRACE: NdsToNds Publisher - NDSToNDS -
Flat: Received.
[01/07/02 12:20:37.930]: TRACE: NdsToNds Publisher - NDSToNDS -
Flat: XML Document:
[01/07/02 12:20:37.950]: TRACE:
<nds dtdversion="1.1" ndsversion="8.5">
<source>
<product version="1.1">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<add class-name="User" event-id="0"
src-dn="\TREE-ONE\novell\Users\James Dean"
src-entry-id="33151">
<add-attr attr-name="Surname" timestamp="1010424096#15">
<value timestamp="1010424096#15" type="string">Dean</value>
</add-attr>
<add-attr attr-name="Given Name" timestamp="1010424096#17">
<value timestamp="1010424096#17" type="string">Jimmy</value>
</add-attr>
<add-attr attr-name="CN" timestamp="1010424096#28">
<value timestamp="1010424096#28" type="string">James
Dean</value>
</add-attr>
</add>
</input>
</nds>
The DirXML engine starts applying the Input Transformation and Schema Mapping rules, which are not present, and therefore states that they are being skipped. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:37.960]: TRACE: Applying input transformations [01/07/02 12:20:37.970]: TRACE: No input stylesheet, skipping [01/07/02 12:20:37.970]: TRACE: No mapping rule, skipping [01/07/02 12:20:37.970]: TRACE: Resolving association references [01/07/02 12:20:37.980]: TRACE: No event transformation rule, skipping
The DirXML engine checks to see if this object is already associated. It then applies the publisher filter and proceeds with the Add event on the publisher channel. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:37.990]: TRACE: No associated objects [01/07/02 12:20:37.990]: TRACE: Applying publisher filter [01/07/02 12:20:37.990]: TRACE: Publisher processing add for \TREE-ONE\novell\Users\James Dean
The DirXML engine tries to apply the Matching rule. It then queries eDirectory based on the match criteria in the Matching rule. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:37.990]: TRACE: Applying matching rule [01/07/02 12:20:38.00]: TRACE: Pumping XDS to NDS [01/07/02 12:20:38.10]: TRACE: Performing operation, op: query for: novell\Users [01/07/02 12:20:38.10]: TRACE:
No results are returned. Due to the lack of a response to the query, DirXML assumes that no match was found and proceeds with the Create rule. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:38.10]: TRACE: No match found
The Create rule is checked. Notice there is a hit in the Create rule on rule number 1. This means that the criteria in rule number 1 in the Create rule is met. This rule is selected and the Add is not vetoed but is allowed to continue through. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:38.10]: TRACE: Applying create rule [01/07/02 12:20:38.10]: TRACE: Trying create rule 1 [01/07/02 12:20:38.10]: TRACE: Rule selected
The DirXML engine applies the next rule in order, which is the Placement rule. From applying this rule, the DirXML engine will select the Destination Container in which the User object is to be created. Notice that placement rule number 1 is selected from the placement rule. Then the User object is created in that container. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:38.10]: TRACE: Applying placement rule [01/07/02 12:20:38.10]: TRACE: Trying placement rule 1 [01/07/02 12:20:38.10]: TRACE: Rule selected [01/07/02 12:20:38.10]: TRACE: Placing object at: novell\Users\James Dean [01/07/02 12:20:38.10]: TRACE: Pumping XDS to NDS [01/07/02 12:20:38.10]: TRACE: Performing operation, op: add for: novell\Users\James Dean [01/07/02 12:20:38.20]: TRACE: Adding entry: novell\Users\James Dean [01/07/02 12:20:38.20]: TRACE: Creating RDN: James Dean in context: novell\Users
Notice the user James Dean being created in the Novell\Users container. Since the user was created without errors, DirXML logs a "success" status message on the publisher channel, as indicated in the lines below. (We are still on the publisher channel of TREE-TWO.)
DirXML Log Event -------------------
Driver = \TREE-TWO\novell\servers\driver-set\NDSToNDS - Flat
Channel = publisher
Object = \TREE-ONE\novell\Users\James Dean (novell\Users\James Dean)
Status = success
In addition to sending a success document to TREE-ONE (source tree), DirXML adds the <add-association> element so that TREE-ONE updates its Association value. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:38.281]: TRACE: Applying output transformations [01/07/02 12:20:38.281]: TRACE: Fixing up associations references
Since the Success document is being transmitted back to TREE-ONE, it must go through the Output Transformation and Schema Mapping rule. This is done on the same channel on which the original Add event document was received--in this case, the publisher channel on TREE-TWO. You will then see the document that is being sent. (We are still on the publisher channel of TREE-TWO.)
[01/07/02 12:20:38.281]: TRACE: No mapping rule, skipping
[01/07/02 12:20:38.281]: TRACE: No output stylesheet, skipping
[01/07/02 12:20:38.281]: TRACE: NdsToNds Publisher - NDSToNDS - Flat: Sending...
[01/07/02 12:20:38.281]: TRACE: NdsToNds Publisher - NDSToNDS - Flat: XML Document:
<nds dtdversion="1.1" ndsversion="8.5">
<source>
<product version="1.1">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<output>
<status event-id="0" level="success"></status>
<add-association dest-dn="\TREE-ONE\novell\Users\James Dean"
dest-entry-id="33151">
{0090A600-9303-d611-A4CF-00C04F803492}
</add-association>
</output>
</nds>
[01/07/02 12:20:38.321]: TRACE: NdsToNds Publisher - NDSToNDS - Flat: Document sent.
[01/07/02 12:20:38.321]: TRACE: NdsToNds Publisher - NDSToNDS - Flat: Reusing connection
[01/07/02 12:20:38.321]: TRACE: NdsToNds Publisher - NDSToNDS - Flat: Waiting for receive...
To summarize what has happened thus far, the user creation event came across from TREE-ONE, the user was then created in TREE-TWO, associated, and a success message was back along with the association value to TREE-ONE.
From the publishers channel's perspective on TREE-TWO, this event is now complete.
Back to the Subscriber Channel on TREE-ONE
The subscriber channel in TREE-ONE receives the success message and the <add-association> document from TREE-TWO. It then shows the document that is being received.
[01/07/02 12:21:36.910]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: Receiving...
[01/07/02 12:21:36.910]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: Received.
[01/07/02 12:21:36.910]: TRACE: NdsToNds Subscriber - NDSToNDS - Flat: XML Document:
[01/07/02 12:21:36.910]: TRACE: SubscriptionShim.execute() returned:
[01/07/02 12:21:36.910]: TRACE:
<nds dtdversion="1.1" ndsversion="8.5">
<source>
<product version="1.1">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<output>
<status event-id="0" level="success"/>
<add-association dest-dn="\TREE-ONE\novell\Users\James Dean"
dest-entry-id="33151">
{0090A600-9303-d611-A4CF-00C04F803492}
</add-association>
</output>
</nds>
Since this is an incoming document, it must be processed by the Input Transformation and Schema Mapping rule, which occurs in the lines below. (We are on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.910]: TRACE: Applying input transformations [01/07/02 12:21:36.910]: TRACE: No input stylesheet, skipping [01/07/02 12:21:36.910]: TRACE: No mapping rule, skipping [01/07/02 12:21:36.910]: TRACE: Resolving association references
DirXML receives the success document, processes the <add-association>, and updates the association in TREE-ONE, which is the source tree. (We are still on the subscriber channel of TREE-ONE.)
[01/07/02 12:21:36.910]: TRACE: Handling returned document
[01/07/02 12:21:36.910]: TRACE: Handling operation, op: status for:
DirXML Log Event -------------------
Driver = \TREE-ONE\novell\servers\driver-set\NDSToNDS - Flat
Channel = subscriber
Object = \TREE-ONE\novell\Users\James Dean
Status = success
[01/07/02 12:21:36.910]: TRACE: Handling operation, op: add-association for:
\TREE-ONE\novell\Users\James Dean
The DirXML engine acknowledges the success document being received from the TREE-TWO and updates the User object's association value with what came through in the XML document. This event is now complete from the subscriber channel's perspective on TREE-ONE as well.
Conclusion
This AppNote has reviewed the key concepts you need to know when looking at a DirXML trace file and walked you through what is happening in an actual trace. This information should help you effectively read your own DirXML trace files in a troubleshooting situation.
* Originally published in Novell AppNotes
Disclaimer
The origin of this information may be internal or external to Novell. While Novell makes all reasonable efforts to verify this information, Novell does not make explicit or implied claims to its validity.