I've been fighting with getting this thing working, and I've got to be
missing something here. I have removed (manually) the filter from the
DC, and reinstalled it. That put the registry keys back, with the same
permissions that they had before I removed them. The filter DLLs are
installed in system32. As far as I can tell, I've followed the
installation instructions, but they're not working.

The driver is running on the same DC. There is one other DC, but I'm not
yet ready to tackle that. It does have the filter installed, but that
doesn't seem to be important, at least not right now.

Here's the level 10 trace of a user (a02dag8) changing his password. It
looks like the driver is notified that something happened, then goes off
to the registry to find the password. I *think* the driver is ok.


[04/27/07 10:35:30.078]:ADDriver-Win2K PT:ADDriver: Publisher Poll
[04/27/07 10:35:30.078]:ADDriver-Win2K PT:ADDriver: get object changes -
0x0000
[04/27/07 10:35:30.078]:ADDriver-Win2K PT:ADDriver: process object
change entry
[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: Processing change
from AD: isDeleted: NULL, whenCreated NULL, name NULL

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: Publisher MODIFY

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: Publisher Modify-
effectiveClassQuery
dn=CN=a02dag8,OU=InfoSvc,OU=InfoTech,OU=GenAdmin,O U=DK,DC=win2k,DC=niu,DC=edu
className=user
[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: displayName

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver:
facsimileTelephoneNumber

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: givenName

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: initials

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: l

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: mail

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: memberOf

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: postOfficeBox

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: postalCode

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: sn

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: st

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: streetAddress

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: telephoneNumber

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: title

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync::getUserData()

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync::getUserData().... checking that RPC Server is listening

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync::getUserData().... checking that RPC Server is listening

[04/27/07 10:35:30.093]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::GetPwdInfoByUser()

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::GetPwdInfoByUser() Looking for specific Username[a02dag8]

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - open the cache. Key =
SOFTWARE\Novell\PassSync\Data\WIN2K.NIU.EDU

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - acquire the mutex.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - mutex acquired.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - get number of registry keys.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - dwSubKeys[0] dwPrefMaxEntries[1]
*lpdwResumeHandle[0] lpszUserName[a02dag8].

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - release the mutex.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - mutex released.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfoByUser() - close the cache.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::GetPwdInfoByUser() returned 0x00000000

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync::getUserData() returned 0x00000000

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::FreeSyncData()

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::FreeSyncData() returned.

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync:ataEnum()

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync:ataEnum().... checking that RPC Server is listening

[04/27/07 10:35:30.109]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync:ataEnum().... checking that RPC Server is listening

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::GetPwdInfo()

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::GetPwdInfo() Looking for specific Username[(null)]

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
PassSyncCache::GetPwdInfo() Logging Error to eventlog

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - open the cache. Key =
SOFTWARE\Novell\PassSync\Data\WIN2K.NIU.EDU

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - acquire the mutex.

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - mutex acquired.

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - get number of registry keys.

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - dwSubKeys[0] dwPrefMaxEntries[-2] *lpdwResumeHandle[0]
lpszUserName[(null)].

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - Query only returned 0.

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - release the mutex.

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD 3324]
GetPwdInfo() - mutex released.

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:ADDriver: [PWD]
PasswordSync:ataEnum() returned 0x00000000

[04/27/07 10:35:30.125]:ADDriver-Win2K PT:Receiving DOM document from
application.
[04/27/07 10:35:30.125]:ADDriver-Win2K PT:
<nds dtdversion="2.2">
<source>
<product version="3.5.0.20070315 ">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<init-params>
<publisher-state>

<cookie>TVNEUwMAAADCOL2v4YjHAQAAAAAAAAAA0AAAADmuQg AAAAAAAAAAAAAAAAA5rkIAAAAAAJDs0kkiKG5GuK+AKCpiZTYB AAAAAAAAAAgAAAAAAAAAjdH6IzDM+UmWIbeLZvQhrUReBgAAAA AAkOzSSSIobka4r4AoKmJlNj2uQgAAAAAAbnpbdpDfGk2HEhXH sBcBuWDRAgAAAAAAHVP1qKyn3EWu666vUHfUTs3fEgAAAAAAbu mathCn40WyeUpdHeEn9gQSAwAAAAAAoRsFxn+u00yHi6Xix3z2 y9XqGgAAAAAAdP+Ky1uqoUGPcV1bnsur27cmBwAAAAAAV+J17B GHq0m+HfGhWM10g4n2HAAAAAAA</cookie>
</publisher-state>
</init-params>
</input>
</nds>
[04/27/07 10:35:30.140]:ADDriver-Win2K PT:Applying input transformation
policies.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT:Applying policy: %+C%14C'Email
notifications for failed password subscriptions'%-C.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: Applying to init-params #1.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: Evaluating selection
criteria for rule 'Send e-mail on a failure when subscribing to
passwords'.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: (if-global-variable
'notify-user-on-password-dist-failure' equal "true") = FALSE.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: Rule rejected.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: Evaluating selection
criteria for rule 'Send e-mail on failure to reset connected system
password using the Identity Manager data store password'.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: (if-global-variable
'notify-user-on-password-dist-failure' equal "true") = FALSE.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT: Rule rejected.
[04/27/07 10:35:30.140]:ADDriver-Win2K PT:Policy returned:
[04/27/07 10:35:30.140]:ADDriver-Win2K PT:
<nds dtdversion="2.2">
<source>
<product version="3.5.0.20070315 ">DirXML</product>
<contact>Novell, Inc.</contact>
</source>
<input>
<init-params>
<publisher-state>

<cookie>TVNEUwMAAADCOL2v4YjHAQAAAAAAAAAA0AAAADmuQg AAAAAAAAAAAAAAAAA5rkIAAAAAAJDs0kkiKG5GuK+AKCpiZTYB AAAAAAAAAAgAAAAAAAAAjdH6IzDM+UmWIbeLZvQhrUReBgAAAA AAkOzSSSIobka4r4AoKmJlNj2uQgAAAAAAbnpbdpDfGk2HEhXH sBcBuWDRAgAAAAAAHVP1qKyn3EWu666vUHfUTs3fEgAAAAAAbu mathCn40WyeUpdHeEn9gQSAwAAAAAAoRsFxn+u00yHi6Xix3z2 y9XqGgAAAAAAdP+Ky1uqoUGPcV1bnsur27cmBwAAAAAAV+J17B GHq0m+HfGhWM10g4n2HAAAAAAA</cookie>
</publisher-state>
</init-params>
</input>
</nds>
[04/27/07 10:35:30.156]:ADDriver-Win2K PT:Applying schema mapping
policies to input.


I'm looking at the registry, and there isn't anything under the key that
the driver is reading. SOFTWARE\Novell\PassSync\Data\WIN2K.NIU.EDU is,
indeed, empty. I do see a02dag8 referenced under
SOFTWARE\Novell\PwFilter\Data\WIN2K.NIU.EDU however.

If I'm understanding how the filter works, it is supposed to grab the
password cleartext from the change, and stuff it in to the registry
("cache") for later processing by the driver. It's not entirely clear,
but it looks like the initial phase of this is to put it under the
PwFilter key on whatever DC processed the password change. Then
something else is supposed to take it from PwFilter key on the DC and
put it under the PassSync key on the DC where the driver is running,
where the driver can then pick it up and use it.

I assume that the driver, if it found something under PassSync, would
use it to build a useful input document for the publisher channel. I
obviously am not getting a useful input document, which seems to be
because there's nothing in the registry to read.

What am I missing here? How does one troubleshoot the password filter to
see what it's doing, or what it's not doing and why not?


---------------------------------------------------------------------------
David Gersic dgersic_@_niu.edu

I'm tired of receiving rubbish in my mailbox, so the E-mail address is
munged to foil the junkmail bots. Humans will figure it out on their own.