Getting a log from ADAMSync

Over the course of the next few posts we’re going to start modifying all sorts of things in the configuration. Depending upon the particulars of your environment this might or might not pan out. :) As such, we should probably take a quick look at the logging available before we break anything too badly.

When you run ADAMSync there’s a switch to give you enhanced logging:
  /log [log file]                       -- Log messages, use "-" option to log to screen

I’m typically a fan of using a filename rather than – as the logs tend to get quite large.

From our run yesterday, here’s some of the output of the log (snipped for brevity):

Adamsync.exe v1.0 (5.2.3790.2021) Establishing connection to target server localhost:50000. Saving Configuration File on DC=SyncTargetDC Saved configuration file. ADAMSync is querying for a writeable replica of erictest.local. Establishing connection to source server efleis-df2.erictest.local:389. Using file .\damF.tmp as a store for deferred dn-references. Populating the schema cache Populating the well known objects cache Starting synchronization run from dc=erictest,dc=local. Starting DirSync Search with object mode security.

<snip>

Processing Entry: Page 1, Frame 1, Entry 4, Count 1, USN 0 Processing source entry <guid=51b2fc571aa27c4e9a488e7b79d1d5e1> Processing in-scope entry 51b2fc571aa27c4e9a488e7b79d1d5e1. Adding target object CN=Users,dc=SyncTargetDC. Adding attributes: sourceobjectguid, objectClass, description, instanceType, showInAdvancedViewOnly, lastagedchange,  Previous entry took 0 seconds (31, 31) to process

<snip>

Beginning processing of deferred dn references. Processing deferred modifications for 53d9609b8ee6014c947f57d3fc850aab:ipsecISAKMPReference. + Synchronizing dn-ref to 39b749b601b1f547a2a76a97e5beb0f2.

<snip>

Finished processing of deferred dn references.
Finished (successful) synchronization run.
Number of entries processed via dirSync: 169
Number of entries processed via ldap: 3
Processing took 7 seconds (0, 1082877952).
Number of object additions: 168
Number of object modifications: 4
Number of object deletions: 0
Number of object renames: 3
Number of references processed / dropped: 58, 7
Maximum number of attributes seen on a single object: 18
Maximum number of values retrieved via range syntax: 0
Beginning aging run. Aging requested every 0 runs. We last aged 1 runs ago. Saving Configuration File on DC=SyncTargetDC Saved configuration file.

Alright, so time to slice it up some. This post would go on forever if I sliced it up too much, so I’ll point out some of the highlights.

Of course, we start off with just a bit of overview of what we’re about to do. Version of the tool, host we’re talking to, etc. Nothing out of the ordinary. :)

Next up, object sync. We will have an entry for objects synchronized. Note the GUID that is listed. While this might not look like the sort of GUID you’re used to, it is actually the GUID of the object in the source NC. There are two potentially confusing things about what I just said, so I’d like to call them both out so we’re all on the same page, else things will only get worse from here :):
1) It is the GUID despite looking like it is wrong. Note the form:
51b2fc571aa27c4e9a488e7b79d1d5e1
The GUID of that object when all prettied up is:
57fcb251-a21a-4e7c-9a48-8e7b79d1d5e1
Here’s the magic to the conversion. Let’s look at just the first section:
57fcb251 vs. 51b2fc57
See the pattern yet? Let’s color it in:
57fcb251 vs. 51b2fc57
Yes, there’s some ordering going on. I won’t get in to why here, but that’s how we pretty up GUIDs before we display them. With that example I’m sure you can walk through the rest of it and figure out where it comes from.
2) It is the GUID of the object in the source NC. One of the confusing things about synchronization is that we’re doing logical recreation of some data state in the target environment based upon what we see in the source environment. As a result, some properties aren’t the same. One such property is the GUID. The “copy” of the object in the target will have a different GUID, because all we’re really doing in ADAMSync is telling ADAM to create an object with the following logical properties (name, description, etc.)…namely those properties we care about (you get to pick the list)...and letting the stuff going on at the directory layer do it’s thing. So much like we didn’t tell AD the GUID of the object in the source, we don’t tell ADAM what the GUID should be in the target.
The result of this subtle yet important distinction is that when thinking about tasks ADAMSync is doing it is exceptionally important to consider if the task is relative to the source or the target. Things get awfully confusing awfully fast if you don’t.

We then get in to deferred dn references. ADAMSync processes things like link value attributes later such that all objects are already created when it is time to create the links. We can revisit this later in more detail if people are interested in the subtleties of what and how and why.

And finally, closing statistics with a little note that we succeeded.
Errors will be painstakingly obvious. We’ll probably start seeing some as we start modifying our config file in some crazy ways over the next few posts. I’ll try and include the common errors so you get a sense of what I think is likely that you’ll hit as well as my general methodology in approaching these sorts of errors.

Update: Fixed some formatting issues I didn't notice before.