search

grealish / pwm

Automatically exported from code.google.com/p/pwm
0 stars 0 forks source link

Macro's in the Password Guide text breaks PWM #363

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
1. Within a working PWM configuration add in User Interface -> Password Guide 
text a custom text with macro's.
2. Save the changed configuration

What is the expected output? What do you see instead?
After the restart of PWM I would expect no changes in the behaviour of the 
frontend, except for an extra Password Guide text link on the change password 
page. Instead I get a non functional PWM frontend (see attached screenshot 1)

What version of PWM are you using?
Daily build (pwmVersion="1.7.0" pwmBuild="1216" pwmBuildType="RC1" 
createTime="2013-04-04 06:24:31 +0000")

The actual config change in my PwmConfiguration.xml:

diff PwmConfiguration.xml PwmConfiguration.xml-backup-1.xml
2c2
< <PwmConfiguration pwmVersion="1.7.0" pwmBuild="1216" pwmBuildType="RC1" 
createTime="2013-04-04 06:24:31 +0000" modifyTime="2013-04-11 10:43:39 +0000" 
xmlVersion="2">

---
> <PwmConfiguration pwmVersion="1.7.0" pwmBuild="1216" pwmBuildType="RC1" 
createTime="2013-04-04 06:24:31 +0000" modifyTime="2013-04-11 09:54:03 +0000" 
xmlVersion="2">
20,21c20,21
<     <property key="configEpoch">84</property>
<     <property 
key="settingsChecksum">95984E997209EC061254EB0DA42A3A0F</property>

---
>     <property key="configEpoch">83</property>
>     <property 
key="settingsChecksum">2371483A4B76EF417174C4EC37E6DD20</property>
80,85c80
<       <value><![CDATA[<p>Your passwords will also not be able to contain 
three or more consecutive letters from the following data:</p>
< <ul>
<   <li>@LDAP:fullName@</li>
<   <li>@LDAP:sn@</li>
<   <li>@LDAP:ULCNuser@</li>
< </ul>]]></value>

---
>       <default />

Requesting the PWM login frontend  gives the following log in catalina.out:

2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: /pwm/ (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/ (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication (/pwm/private/), but is not authenticated; 
redirecting to LoginServlet [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/progressBarEmpty.png (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/progressBarAnim.gif (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/a11y/indeterminate_progress.gif (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication 
(/pwm/private/undefined/dojo/dijit/themes/nihilo/images/progressBarEmpty.png), 
but is not authenticated; redirecting to LoginServlet [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication 
(/pwm/private/undefined/dojo/dijit/themes/nihilo/images/progressBarAnim.gif), 
but is not authenticated; redirecting to LoginServlet [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication 
(/pwm/private/undefined/dojo/dijit/themes/a11y/indeterminate_progress.gif), but 
is not authenticated; redirecting to LoginServlet [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/titleBar.png (no params) 
 [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/spriteRoundedIconsSmall.p
ng (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication 
(/pwm/private/undefined/dojo/dijit/themes/nihilo/images/spriteRoundedIconsSmall.
png), but is not authenticated; redirecting to LoginServlet 
[127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication 
(/pwm/private/undefined/dojo/dijit/themes/nihilo/images/titleBar.png), but is 
not authenticated; redirecting to LoginServlet [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:06:57, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]

After login I get a HTTP 404 error and catalina.out gives:

2013-04-11 13:08:25, TRACE, pwm.SessionFilter, {y} POST request for: 
/pwm/private/undefined  [127.0.0.1/localhost]
  time='1365678505742'
  pwmFormID='undefined'
  processAction='idleUpdate'
2013-04-11 13:08:25, TRACE, pwm.AuthenticationFilter, {y} user requested 
resource requiring authentication (/pwm/private/undefined), but is not 
authenticated; redirecting to LoginServlet [127.0.0.1/localhost]
2013-04-11 13:08:25, TRACE, pwm.SessionFilter, {y} GET request for: 
/pwm/private/Login (no params)  [127.0.0.1/localhost]
2013-04-11 13:08:25, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.SessionFilter, {y} POST request for: 
/pwm/private/Login  [127.0.0.1/localhost]
  username='veldhuisens'
  pwmFormID='xZFfZgCFD4t4EQUdnuZfwKYzgIwbblSc13df8c5f488wufa5u'
  password=***removed***
  processAction='login'
2013-04-11 13:08:28, TRACE, pwm.AuthenticationFilter, {y} permitting 
unauthenticated request of login page [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserSearchEngine, {y} username does not 
appear to be a DN (does not start with configured ldap naming attribute 'cn') 
[127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.UserSearchEngine, {y} beginning user 
search process [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.UserSearchEngine, {y} performing ldap 
search for user, base=ou=users,o=meta filter=SearchHelper: filter: 
(&(objectClass=ULCNperson)(ULCNuser=veldhuisens)), scope: SUBTREE, attributes: 
[] [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserSearchEngine, {y} found 1 results in 
context: ou=users,o=meta [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.UserSearchEngine, {y} completed user 
search process in 6ms, resultSize=1 [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.UserSearchEngine, {y} found userDN: 
cn=x,ou=users,o=meta [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserAuthenticator, {y} beginning 
testCredentials process [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserAuthenticator, {y} attempting 
authentication using ldap BIND [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.SessionManager, {y} attempting to open new ldap 
connection for cn=x,ou=users,o=meta [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, util.Helper, creating new chai provider using 
config of ChaiConfiguration: locked=false settings: 
{chai.bind.URLs=ldaps://iowa-dev.srvtest.leidenuniv.nl:636,, 
chai.bind.dn=cn=x,ou=users,o=meta, chai.bind.password=**stripped**, 
chai.cache.enable=false, chai.cache.maximumSize=128, 
chai.cache.maximumAge=1000, chai.statistics.enable=true, 
chai.watchdog.enable=true, chai.watchdog.operationTimeout=60000, 
chai.watchdog.idleTimeout=24000, chai.watchdog.disableIfPwExpired=true, 
chai.connection.watchdog.frequency=60000, chai.connection.promiscuousSSL=false, 
chai.wireDebug.enable=false, chai.failover.enable=true, 
chai.failover.failBackTime=90000, chai.failover.connectRetries=4, 
chai.ldap.dereferenceAliases=never, chai.ldap.ldapTimeout=5000, 
chai.ldap.followReferrals=false, 
chai.provider.implementation=com.novell.ldapchai.provider.JNDIProviderImpl, 
chai.edirectory.enableNMAS=true, 
chai.provider.extendedOperation.failureCache=true, 
chai.provider.readonly=false, chai.vendor.default=, 
chai.provider.jndi.enablePool=true, chai.crsetting.caseInsensitive=true, 
chai.crsetting.allowDuplicateResponses=false, 
chai.crsetting.defaultFormatType=SHA1_SALT, 
chai.cr.chai.attributeName=pwmResponseSet, chai.cr.chai.recordId=0002, 
chai.cr.chai.saltCount=100000}
2013-04-11 13:08:28, TRACE, provider.JNDIProviderImpl, bind successful as 
cn=x,ou=users,o=meta (108ms)
2013-04-11 13:08:28, TRACE, provider.ChaiProviderFactory, adding 
WatchdogWrapper to provider instance
2013-04-11 13:08:28, TRACE, provider.WatchdogWrapper, checking for user 
password expiration to adjust watchdog timeout
2013-04-11 13:08:28, TRACE, provider.ChaiProviderFactory, adding 
StatisticsWrapper to provider instance
2013-04-11 13:08:28, INFO , operations.UserAuthenticator, {y} successful 
plaintext authentication for cn=x,ou=users,o=meta (129ms) [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, entry.EdirEntries, using active universal password 
policy for user cn=x,ou=users,o=meta at cn=unipwd-nvl-employee,cn=Password 
Policies,cn=Security
2013-04-11 13:08:28, DEBUG, operations.PasswordUtility, {y} discovered assigned 
password policy for cn=x,ou=users,o=meta PwmPasswordPolicy: 
{MinimumLowerCase=1, MinimumSpecial=0, MaximumUpperCase=0, MaximumNumeric=0, 
MinimumLifetime=0, MinimumUnique=0, DisallowedAttributes=[CN, Full Name, 
Surname, ULCNuser], UniqueRequired=TRUE, AllowNumeric=TRUE, CaseSensitive=TRUE, 
ChangeMessage=, ExpirationInterval=15724800, MaximumLowerCase=0, 
AllowSpecial=FALSE, MaximumLength=13, AllowFirstCharNumeric=TRUE, 
MinimumLength=8, MaximumSequentialRepeat=0, MinimumNumeric=1, 
AllowLastCharSpecial=TRUE, PolicyEnabled=true, MaximumSpecial=0, 
MinimumUpperCase=1, AllowFirstCharSpecial=TRUE, DisallowedValues=[], 
AllowLastCharNumeric=TRUE} [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.PasswordUtility, {y} 
readPasswordPolicyForUser completed in 10ms [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, edir.NmasCrFactory, challengeSetDN is null, return 
null for readNmasAssignedChallengeSetPolicy()
2013-04-11 13:08:28, TRACE, entry.EdirEntries, using active universal password 
policy for user cn=x,ou=users,o=meta at cn=unipwd-nvl-employee,cn=Password 
Policies,cn=Security
2013-04-11 13:08:28, TRACE, edir.NmasCrFactory, challengeSetDN is null, return 
null for readNmasAssignedChallengeSetPolicy()
2013-04-11 13:08:28, DEBUG, operations.CrUtility, {y} no nmas c/r policy found 
for user cn=x,ou=users,o=meta [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.CrUtility, {y} using pwm c/r policy for 
user cn=x,ou=users,o=meta: ChallengeSet identifier: pwm-defined v1.7.0 b1216 
(RC1), minRandom: 2, locale: en, (Challenge: "What is the name of the main 
character in your favorite book?", required: false, adminDefined: true, 
minLength: 4, maxLength: 200) (Challenge: "What is the name of your favorite 
teacher?", required: false, adminDefined: true, minLength: 4, maxLength: 200) 
(Challenge: "What is the name of your favorite pet?", required: false, 
adminDefined: true, minLength: 4, maxLength: 200) (Challenge: "What was the 
name of your childhood best friend?", required: false, adminDefined: true, 
minLength: 4, maxLength: 200) (Challenge: "What was your favorite show as a 
child?", required: false, adminDefined: true, minLength: 4, maxLength: 200) 
(Challenge: "Who is your favorite author?", required: false, adminDefined: 
true, minLength: 4, maxLength: 200) (Challenge: "What is your favorite food?", 
required: false, adminDefined: true, minLength: 4, maxLength: 200) (Challenge: 
"What is your partner's nickname?", required: false, adminDefined: true, 
minLength: 4, maxLength: 200) (Challenge: "What is your favorite team?", 
required: false, adminDefined: true, minLength: 4, maxLength: 200) (Challenge: 
"What street did you grow up on?", required: false, adminDefined: true, 
minLength: 4, maxLength: 200) (Challenge: "What city / town were you born in?", 
required: false, adminDefined: true, minLength: 4, maxLength: 200) (Challenge: 
"What is your favorite vehicle?", required: false, adminDefined: true, 
minLength: 4, maxLength: 200) (Challenge: "If you could meet someone from 
history, who would it be?", required: false, adminDefined: true, minLength: 4, 
maxLength: 200) (Challenge: "What is your least favorite film of all time?", 
required: false, adminDefined: true, minLength: 4, maxLength: 200) (Challenge: 
"Who was your least favorite teacher?", required: false, adminDefined: true, 
minLength: 4, maxLength: 200) (Challenge: "What food do you dislike the most?", 
required: false, adminDefined: true, minLength: 4, maxLength: 200)  
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.CrUtility, {y} readUserChallengeSet 
completed in 17ms [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, util.Helper, read VENDORGUID value for user 
cn=x,ou=users,o=meta: 6e0331e7b3576045dc876e0331e7b357
2013-04-11 13:08:28, TRACE, operations.UserStatusHelper, {y,veldhuisens} 
beginning password status check process for cn=x,ou=users,o=meta 
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserStatusHelper, {y,veldhuisens} 
password for cn=x,ou=users,o=meta does not appear to be expired 
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserStatusHelper, 
ldapPasswordExpirationTime (cn=x,ou=users,o=meta): Thu Oct 10 12:12:32 CEST 
2013 (1381399952889 ms)
2013-04-11 13:08:28, DEBUG, operations.UserStatusHelper, {y,veldhuisens} 
completed user password status check for cn=x,ou=users,o=meta PasswordStatus 
{expired=false, pre-expired=false, warn=false, violatesPolicy=false} (10ms) 
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.CrUtility, {y,veldhuisens} beginning 
check to determine if responses need to be configured for user 
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.CrUtility, {y,veldhuisens} beginning 
read of user response sequence [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.CrUtility, {y,veldhuisens} will attempt 
to read the following storage methods: LDAP [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.CrUtility, {y,veldhuisens} attempting 
read of responses via storage method: LDAP [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.CrUtility, {y,veldhuisens} returning 
responses read via method LDAP [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, operations.CrUtility, {y,veldhuisens} 
checkIfResponseConfigNeeded: cn=x,ou=users,o=meta has good responses 
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.Permission, {y,veldhuisens} begin check for 
permission for cn=x,ou=users,o=meta for PROFILE_UPDATE using queryMatch: 
(objectClass=ULCNperson) [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.Permission, {y,veldhuisens} checking ldap to 
see if cn=x,ou=users,o=meta matches '(objectClass=ULCNperson)' 
[127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, pwm.Permission, {y,veldhuisens} user 
cn=x,ou=users,o=meta is a match for '(objectClass=ULCNperson)', granting 
privilege for PROFILE_UPDATE [127.0.0.1/localhost]
2013-04-11 13:08:28, INFO , servlet.CommandServlet, {y,veldhuisens} 
checkProfiles: cn=x,ou=users,o=meta does not match 'checkProfiles query match', 
update profile not required by user [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserStatusHelper, {y,veldhuisens} read 
last user password change timestamp (via chai) as: Thu Apr 11 12:12:32 CEST 
2013 [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, operations.UserStatusHelper, {y,veldhuisens} 
populateUserInfoBean for cn=x,ou=users,o=meta completed in 93ms 
[127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/private/undefined  [127.0.0.1/localhost]
  time='1365678505742'
  pwmFormID='undefined'
  processAction='idleUpdate'
2013-04-11 13:08:28, TRACE, pwm.Permission, {y,veldhuisens} begin check for 
permission for cn=x,ou=users,o=meta for CHANGE_PASSWORD using queryMatch: 
(objectClass=ULCNperson) [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.Permission, {y,veldhuisens} checking ldap to 
see if cn=x,ou=users,o=meta matches '(objectClass=ULCNperson)' 
[127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, pwm.Permission, {y,veldhuisens} user 
cn=x,ou=users,o=meta is a match for '(objectClass=ULCNperson)', granting 
privilege for CHANGE_PASSWORD [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.Permission, {y,veldhuisens} begin check for 
permission for cn=x,ou=users,o=meta for SETUP_RESPONSE using queryMatch: 
(objectClass=*) [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, pwm.Permission, {y,veldhuisens} permission check is 
guaranteed to be true, skipping ldap query [127.0.0.1/localhost]
2013-04-11 13:08:28, DEBUG, pwm.Permission, {y,veldhuisens} user 
cn=x,ou=users,o=meta is a match for '(objectClass=*)', granting privilege for 
SETUP_RESPONSE [127.0.0.1/localhost]
2013-04-11 13:08:28, TRACE, util.PwmMacroMachine, replaced Macro @User:ID@ with 
value: veldhuisens
2013-04-11 13:08:29, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/public/jsClientValues.jsp  [127.0.0.1/localhost]
  nonce='723EFD1717961BB185DC7BEF3DC59DE8'
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, could not replace value for 
'@LDAP:fullName@', user does not have value for 'fullName'
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro @LDAP:sn@ with 
value: Veldhuisen
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro 
@LDAP:ULCNuser@ with value: veldhuisens
2013-04-11 13:08:29, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/progressBarAnim.gif (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:08:29, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/progressBarEmpty.png (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:08:29, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/a11y/indeterminate_progress.gif (no 
params)  [127.0.0.1/localhost]
2013-04-11 13:08:29, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/titleBar.png (no params) 
 [127.0.0.1/localhost]
2013-04-11 13:08:29, TRACE, pwm.SessionFilter, {y,veldhuisens} GET request for: 
/pwm/private/undefined/dojo/dijit/themes/nihilo/images/spriteRoundedIconsSmall.p
ng (no params)  [127.0.0.1/localhost]
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro @User:ID@ with 
value: veldhuisens
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro @User:ID@ with 
value: veldhuisens
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro @User:ID@ with 
value: veldhuisens
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro @User:ID@ with 
value: veldhuisens
2013-04-11 13:08:29, TRACE, util.PwmMacroMachine, replaced Macro @User:ID@ with 
value: veldhuisens

After restoring my PwmConfiguration without the Password Guide text with 
macro's, everything works normal again.

Original issue reported on code.google.com by sebastia...@gmail.com on 11 Apr 2013 at 11:29

Attachments:

GoogleCodeExporter commented 9 years ago 
Fixed in revision 548.

Original comment by jrivard on 25 Apr 2013 at 8:06

GoogleCodeExporter commented 9 years ago 
Retested this with today build. The Password Guide seems to be working now with 
some macro's actually being replaced by the correct values. However some weird 
behavior is seen with the macro @LDAP:fullName@

PWM is actually performing an LDAP search on "Full Name" (which is not valid 
according to the relevant LDAP RFC) and not on "fullName". This leads to no 
value for the macro @LDAP:fullName@, because attributes with spaces are not 
valid. In my config I have not specified "Full Name" as an LDAP attribute, so 
this must be a bug in PWM.

Upon login, the LDAP query is done, so I made a LDAP wire trace + ndstrace 
debug of this.

Relevant part of Catalina.out

2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#13 
readStringAttributes(cn=12345678,ou=users,o=meta,[mail, sn, manager, 
AuxTestmail, AuxTestmail3, Full Name, VENDORGUID, AuxTestsmsNumber, givenName, 
loginExpirationTime, pwmEventLog, cn, AuxTestuser, Surname, AuxTestdateOfBirth, 
CN, pwmResponseSet, passwordExpirationTime])
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#13 result: 
{sn=Veldhuisen, AuxTestmail=testuser@example.com, 
AuxTestmail3=testuser@gmail.com, AuxTestsmsNumber=+31612345678} (21ms)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#31 
getDirectoryVendor()
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#31 result: 
NOVELL_EDIRECTORY (0ms)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#32 
readMultiByteAttribute(cn=12345678,ou=users,o=meta,guid)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#32 result: 
[[B@5025d840 (19ms)
2013-04-26 08:16:08, TRACE, util.Helper, read VENDORGUID value for user 
cn=12345678,ou=users,o=meta: 6e0331e7b3576045dc876e0331e7b357
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#14 
readStringAttribute(cn=12345678,ou=users,o=meta,passwordExpirationTime)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#14 result: 
20131023145236Z (2ms)
2013-04-26 08:16:08, TRACE, operations.UserStatusHelper, {3,testuser} beginning 
password status check process for cn=12345678,ou=users,o=meta [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#15 
readStringAttributes(cn=12345678,ou=users,o=meta,[passwordExpirationTime, 
loginGraceRemaining, loginGraceLimit])
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#15 result: 
{passwordExpirationTime=20131023145236Z, loginGraceRemaining=6, 
loginGraceLimit=6} (3ms)
2013-04-26 08:16:08, TRACE, operations.UserStatusHelper, {3,testuser} password 
for cn=12345678,ou=users,o=meta does not appear to be expired [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#16 
readStringAttribute(cn=12345678,ou=users,o=meta,passwordExpirationTime)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#16 result: 
20131023145236Z (4ms)
2013-04-26 08:16:08, TRACE, operations.UserStatusHelper, 
ldapPasswordExpirationTime (cn=12345678,ou=users,o=meta): Wed Oct 23 16:52:36 
CEST 2013 (1382539956171 ms)
2013-04-26 08:16:08, DEBUG, operations.UserStatusHelper, {3,testuser} completed 
user password status check for cn=12345678,ou=users,o=meta PasswordStatus 
{expired=false, pre-expired=false, warn=false, violatesPolicy=false} (13ms) 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, operations.CrUtility, {3,testuser} beginning check 
to determine if responses need to be configured for user [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#33 
search(cn=12345678,ou=users,o=meta,(objectClass=AuxTestperson),[],SUBTREE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#33 result: 
{cn=12345678,ou=users,o=meta={}} (5ms)
2013-04-26 08:16:08, TRACE, operations.CrUtility, {3,testuser} beginning read 
of user response sequence [123.456.789.123]
2013-04-26 08:16:08, DEBUG, operations.CrUtility, {3,testuser} will attempt to 
read the following storage methods: LDAP [123.456.789.123]
2013-04-26 08:16:08, TRACE, operations.CrUtility, {3,testuser} attempting read 
of responses via storage method: LDAP [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#17 
readMultiStringAttribute(cn=12345678,ou=users,o=meta,pwmResponseSet)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#17 result: 
[0002#.#.#<?xml version="1.0" encoding="UTF-8"?><ResponseSet 
minRandomRequired="2" locale="nl" version="2" chaiVersion="0.6.3 devbuild" 
caseInsensitive="true" challengeSetID="pwm-defined v1.7.0 b1216 (RC1)" 
time="2013-04-18 10:07:17 +0000"><response adminDefined="true" required="false" 
minLength="4" maxLength="200"><challenge>What is the name of the main character 
in your favorite book?</challenge><answer 
salt="uGRojw6rq9jGqUXjmEd61xXGdKi6WFdV" format="SHA1_SALT" 
hashcount="100000">BBDTNbpOxk21GNBRTqgxwzQR9O8=</answer></response><response 
adminDefined="true" required="false" minLength="4" 
maxLength="200"><challenge>What city / town were you born 
in?</challenge><answer salt="OPWHhUjpKpPq48l10Djc0TL3G41yNDDH" 
format="SHA1_SALT" 
hashcount="100000">3AWgIR6Ehy1IAACy5Vm25YZN+FM=</answer></response><response 
adminDefined="true" required="false" minLength="4" 
maxLength="200"><challenge>What is your favorite vehicle?</challenge><answer 
salt="ZayfzBkIJJYOofXQ0QdgRWNbeLyySQ1Q" format="SHA1_SALT" 
hashcount="100000">77IV/Oql8SYmo/BQLnvQezkz2Gg=</answer></response><response 
adminDefined="true" required="false" minLength="4" 
maxLength="200"><challenge>What food do you dislike the 
most?</challenge><answer salt="2bqV8nzBKGxqO2PfZYVOaFWN0ciGh6To" 
format="SHA1_SALT" 
hashcount="100000">NZl6+Otg8VKXwpHkrEG6kwedDtk=</answer></response></ResponseSet
>] (5ms)
2013-04-26 08:16:08, DEBUG, operations.CrUtility, {3,testuser} returning 
responses read via method LDAP [123.456.789.123]
2013-04-26 08:16:08, DEBUG, operations.CrUtility, {3,testuser} 
checkIfResponseConfigNeeded: cn=12345678,ou=users,o=meta has good responses 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#34 
getDirectoryVendor()
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#34 result: 
NOVELL_EDIRECTORY (0ms)
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} begin check for 
permission for cn=12345678,ou=users,o=meta for PROFILE_UPDATE using queryMatch: 
(objectClass=AuxTestperson) [123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} checking ldap to see 
if cn=12345678,ou=users,o=meta matches '(objectClass=AuxTestperson)' 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#35 
search(cn=12345678,ou=users,o=meta,(objectClass=AuxTestperson),[],BASE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#35 result: 
{cn=12345678,ou=users,o=meta={}} (3ms)
2013-04-26 08:16:08, DEBUG, pwm.Permission, {3,testuser} user 
cn=12345678,ou=users,o=meta is a match for '(objectClass=AuxTestperson)', 
granting privilege for PROFILE_UPDATE [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#36 
search(cn=12345678,ou=users,o=meta,(&(objectClass=AuxTestperson)(!(&(AuxTestsmsN
umber=*)(AuxTestmail3=*)))),[],SUBTREE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#36 result: {} 
(3ms)
2013-04-26 08:16:08, INFO , servlet.CommandServlet, {3,testuser} checkProfiles: 
cn=12345678,ou=users,o=meta does not match 'checkProfiles query match', update 
profile not required by user [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#18 
readStringAttribute(cn=12345678,ou=users,o=meta,pwdChangedTime)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#18 result: 
20130424145236Z (3ms)
2013-04-26 08:16:08, TRACE, operations.UserStatusHelper, {3,testuser} read last 
user password change timestamp (via chai) as: Wed Apr 24 16:52:36 CEST 2013 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, operations.UserStatusHelper, {3,testuser} 
populateUserInfoBean for cn=12345678,ou=users,o=meta completed in 161ms 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.SessionFilter, {3,testuser} GET request for: 
/pwm/private/ (no params)  [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#37 
getDirectoryVendor()
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#37 result: 
NOVELL_EDIRECTORY (1ms)
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} begin check for 
permission for cn=12345678,ou=users,o=meta for CHANGE_PASSWORD using 
queryMatch: (objectClass=AuxTestperson) [123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} checking ldap to see 
if cn=12345678,ou=users,o=meta matches '(objectClass=AuxTestperson)' 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#38 
search(cn=12345678,ou=users,o=meta,(objectClass=AuxTestperson),[],BASE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#38 result: 
{cn=12345678,ou=users,o=meta={}} (5ms)
2013-04-26 08:16:08, DEBUG, pwm.Permission, {3,testuser} user 
cn=12345678,ou=users,o=meta is a match for '(objectClass=AuxTestperson)', 
granting privilege for CHANGE_PASSWORD [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#39 
getDirectoryVendor()
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#39 result: 
NOVELL_EDIRECTORY (0ms)
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} begin check for 
permission for cn=12345678,ou=users,o=meta for SETUP_RESPONSE using queryMatch: 
(objectClass=AuxTestperson) [123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} checking ldap to see 
if cn=12345678,ou=users,o=meta matches '(objectClass=AuxTestperson)' 
[123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#40 
search(cn=12345678,ou=users,o=meta,(objectClass=AuxTestperson),[],BASE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#40 result: 
{cn=12345678,ou=users,o=meta={}} (3ms)
2013-04-26 08:16:08, DEBUG, pwm.Permission, {3,testuser} user 
cn=12345678,ou=users,o=meta is a match for '(objectClass=AuxTestperson)', 
granting privilege for SETUP_RESPONSE [123.456.789.123]
2013-04-26 08:16:08, TRACE, util.MacroMachine, replaced Macro @User:ID@ with 
value: testuser
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#41 
getDirectoryVendor()
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#41 result: 
NOVELL_EDIRECTORY (0ms)
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} begin check for 
permission for cn=12345678,ou=users,o=meta for HELPDESK using queryMatch: 
(groupMembership=cn=pwm_helpdesk,ou=groups,o=meta) [123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} checking ldap to see 
if cn=12345678,ou=users,o=meta matches 
'(groupMembership=cn=pwm_helpdesk,ou=groups,o=meta)' [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#42 
search(cn=12345678,ou=users,o=meta,(groupMembership=cn=pwm_helpdesk,ou=groups,o=
meta),[],BASE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#42 result: 
{cn=12345678,ou=users,o=meta={}} (5ms)
2013-04-26 08:16:08, DEBUG, pwm.Permission, {3,testuser} user 
cn=12345678,ou=users,o=meta is a match for 
'(groupMembership=cn=pwm_helpdesk,ou=groups,o=meta)', granting privilege for 
HELPDESK [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#43 
getDirectoryVendor()
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#43 result: 
NOVELL_EDIRECTORY (0ms)
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} begin check for 
permission for cn=12345678,ou=users,o=meta for PWMADMIN using queryMatch: 
(groupMembership=cn=pwm_admin,ou=groups,o=meta) [123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.Permission, {3,testuser} checking ldap to see 
if cn=12345678,ou=users,o=meta matches 
'(groupMembership=cn=pwm_admin,ou=groups,o=meta)' [123.456.789.123]
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, begin op#44 
search(cn=12345678,ou=users,o=meta,(groupMembership=cn=pwm_admin,ou=groups,o=met
a),[],BASE)
2013-04-26 08:16:08, TRACE, provider.WireTraceWrapper, finish op#44 result: 
{cn=12345678,ou=users,o=meta={}} (4ms)
2013-04-26 08:16:08, DEBUG, pwm.Permission, {3,testuser} user 
cn=12345678,ou=users,o=meta is a match for 
'(groupMembership=cn=pwm_admin,ou=groups,o=meta)', granting privilege for 
PWMADMIN [123.456.789.123]
2013-04-26 08:16:08, TRACE, pwm.SessionFilter, {3,testuser} GET request for: 
/pwm/public/jsClientValues.jsp  [123.456.789.123]
  nonce='8868BB475E4D8B5771393B8D3C770407'
2013-04-26 08:16:08, TRACE, util.MacroMachine, could not replace value for 
'@LDAP:fullName@', user does not have value for 'fullName'
2013-04-26 08:16:08, TRACE, util.MacroMachine, replaced Macro @LDAP:sn@ with 
value: Veldhuisen
2013-04-26 08:16:08, TRACE, util.MacroMachine, replaced Macro 
@LDAP:AuxTestuser@ with value: testuser

Relevant part of ndstrace:

[2013/04/26  8:16:08.116] (123.456.789.321:45230)(0x000c:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "mail"
    attribute: "sn"
    attribute: "manager"
    attribute: "AuxTestmail"
    attribute: "AuxTestmail3"
    attribute: "Full Name"
    attribute: "VENDORGUID"
    attribute: "AuxTestsmsNumber"
    attribute: "givenName"
    attribute: "loginExpirationTime"
    attribute: "pwmEventLog"
    attribute: "cn"
    attribute: "AuxTestuser"
    attribute: "Surname"
    attribute: "AuxTestdateOfBirth"
    attribute: "CN"
    attribute: "pwmResponseSet"
    attribute: "passwordExpirationTime"
[2013/04/26  8:16:08.116] (123.456.789.321:45230)(0x000c:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.117] (123.456.789.321:45230)(0x000c:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870380
[2013/04/26  8:16:08.117] (123.456.789.321:45230)(0x000c:0x63) Sending 
operation result 0:"":"" to connection 0x10870380
[2013/04/26  8:16:08.140] (123.456.789.321:45216)(0x0017:0x63) DoSearch on 
connection 0x10870700
[2013/04/26  8:16:08.140] (123.456.789.321:45216)(0x0017:0x63) Search request:
    base: ""
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    no attributes
[2013/04/26  8:16:08.140] (123.456.789.321:45216)(0x0017:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.141] (123.456.789.321:45216)(0x0017:0x63) Empty attribute 
list implies all user attributes
[2013/04/26  8:16:08.141] (123.456.789.321:45216)(0x0017:0x63) Server 
configured to also include operational attributes
[2013/04/26  8:16:08.142] (123.456.789.321:45216)(0x0017:0x63) Sending search 
result entry "" to connection 0x10870700
[2013/04/26  8:16:08.142] (123.456.789.321:45216)(0x0017:0x63) Sending 
operation result 0:"":"" to connection 0x10870700
[2013/04/26  8:16:08.156] (123.456.789.321:45216)(0x0018:0x63) DoSearch on 
connection 0x10870700
[2013/04/26  8:16:08.156] (123.456.789.321:45216)(0x0018:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "guid"
[2013/04/26  8:16:08.156] (123.456.789.321:45216)(0x0018:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.156] (123.456.789.321:45216)(0x0018:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870700
[2013/04/26  8:16:08.157] (123.456.789.321:45216)(0x0018:0x63) Sending 
operation result 0:"":"" to connection 0x10870700
[2013/04/26  8:16:08.160] (123.456.789.321:45230)(0x000d:0x63) DoSearch on 
connection 0x10870380
[2013/04/26  8:16:08.160] (123.456.789.321:45230)(0x000d:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "passwordExpirationTime"
[2013/04/26  8:16:08.160] (123.456.789.321:45230)(0x000d:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.160] (123.456.789.321:45230)(0x000d:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870380
[2013/04/26  8:16:08.160] (123.456.789.321:45230)(0x000d:0x63) Sending 
operation result 0:"":"" to connection 0x10870380
[2013/04/26  8:16:08.164] (123.456.789.321:45230)(0x000e:0x63) DoSearch on 
connection 0x10870380
[2013/04/26  8:16:08.165] (123.456.789.321:45230)(0x000e:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "passwordExpirationTime"
    attribute: "loginGraceRemaining"
    attribute: "loginGraceLimit"
[2013/04/26  8:16:08.165] (123.456.789.321:45230)(0x000e:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.166] (123.456.789.321:45230)(0x000e:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870380
[2013/04/26  8:16:08.166] (123.456.789.321:45230)(0x000e:0x63) Sending 
operation result 0:"":"" to connection 0x10870380
[2013/04/26  8:16:08.169] (123.456.789.321:45230)(0x000f:0x63) DoSearch on 
connection 0x10870380
[2013/04/26  8:16:08.170] (123.456.789.321:45230)(0x000f:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "passwordExpirationTime"
[2013/04/26  8:16:08.170] (123.456.789.321:45230)(0x000f:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.170] (123.456.789.321:45230)(0x000f:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870380
[2013/04/26  8:16:08.170] (123.456.789.321:45230)(0x000f:0x63) Sending 
operation result 0:"":"" to connection 0x10870380
[2013/04/26  8:16:08.177] (123.456.789.321:45216)(0x0019:0x63) DoSearch on 
connection 0x10870700
[2013/04/26  8:16:08.177] (123.456.789.321:45216)(0x0019:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:2  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=AuxTestperson)"
    attribute: "1.1"
[2013/04/26  8:16:08.177] (123.456.789.321:45216)(0x0019:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.178] (123.456.789.321:45216)(0x0019:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870700
[2013/04/26  8:16:08.179] (123.456.789.321:45216)(0x0019:0x63) Sending 
operation result 0:"":"" to connection 0x10870700
[2013/04/26  8:16:08.185] (123.456.789.321:45230)(0x0010:0x63) DoSearch on 
connection 0x10870380
[2013/04/26  8:16:08.185] (123.456.789.321:45230)(0x0010:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "pwmResponseSet"
[2013/04/26  8:16:08.185] (123.456.789.321:45230)(0x0010:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.186] (123.456.789.321:45230)(0x0010:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870380
[2013/04/26  8:16:08.186] (123.456.789.321:45230)(0x0010:0x63) Sending 
operation result 0:"":"" to connection 0x10870380
[2013/04/26  8:16:08.204] (123.456.789.321:45216)(0x001a:0x6e) DoCompare on 
connection 0x10870700
[2013/04/26  8:16:08.204] (123.456.789.321:45216)(0x001a:0x6e) compare: dn 
(cn=12345678,ou=users,o=meta) attr (objectClass) value (AuxTestperson)
[2013/04/26  8:16:08.204] (123.456.789.321:45216)(0x001a:0x6e) Sending 
operation result 6:"":"" to connection 0x10870700
[2013/04/26  8:16:08.208] (123.456.789.321:45216)(0x001b:0x63) DoSearch on 
connection 0x10870700
[2013/04/26  8:16:08.208] (123.456.789.321:45216)(0x001b:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:2  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(&(objectClass=AuxTestperson)(!(&(AuxTestsmsNumber=*)(AuxTestmail3=*))))"
    attribute: "1.1"
[2013/04/26  8:16:08.208] (123.456.789.321:45216)(0x001b:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.209] (123.456.789.321:45216)(0x001b:0x63) Sending 
operation result 0:"":"" to connection 0x10870700
[2013/04/26  8:16:08.211] (123.456.789.321:45230)(0x0011:0x63) DoSearch on 
connection 0x10870380
[2013/04/26  8:16:08.211] (123.456.789.321:45230)(0x0011:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(objectClass=*)"
    attribute: "pwdChangedTime"
[2013/04/26  8:16:08.211] (123.456.789.321:45230)(0x0011:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.212] (123.456.789.321:45230)(0x0011:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870380
[2013/04/26  8:16:08.212] (123.456.789.321:45230)(0x0011:0x63) Sending 
operation result 0:"":"" to connection 0x10870380
[2013/04/26  8:16:08.244] (123.456.789.321:45216)(0x001c:0x6e) DoCompare on 
connection 0x10870700
[2013/04/26  8:16:08.245] (123.456.789.321:45216)(0x001c:0x6e) compare: dn 
(cn=12345678,ou=users,o=meta) attr (objectClass) value (AuxTestperson)
[2013/04/26  8:16:08.245] (123.456.789.321:45216)(0x001c:0x6e) Sending 
operation result 6:"":"" to connection 0x10870700
[2013/04/26  8:16:08.252] (123.456.789.321:45216)(0x001d:0x6e) DoCompare on 
connection 0x10870700
[2013/04/26  8:16:08.252] (123.456.789.321:45216)(0x001d:0x6e) compare: dn 
(cn=12345678,ou=users,o=meta) attr (objectClass) value (AuxTestperson)
[2013/04/26  8:16:08.252] (123.456.789.321:45216)(0x001d:0x6e) Sending 
operation result 6:"":"" to connection 0x10870700
[2013/04/26  8:16:08.276] (123.456.789.321:45216)(0x001e:0x63) DoSearch on 
connection 0x10870700
[2013/04/26  8:16:08.276] (123.456.789.321:45216)(0x001e:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(groupMembership=cn=pwm_helpdesk,ou=groups,o=meta)"
    attribute: "1.1"
[2013/04/26  8:16:08.276] (123.456.789.321:45216)(0x001e:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.278] (123.456.789.321:45216)(0x001e:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870700
[2013/04/26  8:16:08.278] (123.456.789.321:45216)(0x001e:0x63) Sending 
operation result 0:"":"" to connection 0x10870700
[2013/04/26  8:16:08.285] (123.456.789.321:45216)(0x001f:0x63) DoSearch on 
connection 0x10870700
[2013/04/26  8:16:08.285] (123.456.789.321:45216)(0x001f:0x63) Search request:
    base: "cn=12345678,ou=users,o=meta"
    scope:0  dereference:0  sizelimit:0  timelimit:0  attrsonly:0
    filter: "(groupMembership=cn=pwm_admin,ou=groups,o=meta)"
    attribute: "1.1"
[2013/04/26  8:16:08.285] (123.456.789.321:45216)(0x001f:0x63) nds_back_search: 
Search Control OID 2.16.840.1.113730.3.4.2
[2013/04/26  8:16:08.286] (123.456.789.321:45216)(0x001f:0x63) Sending search 
result entry "cn=12345678,ou=Users,o=Meta" to connection 0x10870700
[2013/04/26  8:16:08.286] (123.456.789.321:45216)(0x001f:0x63) Sending 
operation result 0:"":"" to connection 0x10870700

Original comment by sebastia...@gmail.com on 26 Apr 2013 at 6:36

GoogleCodeExporter commented 9 years ago 
Comment #2 is reporting same issue as issue 370.

Original comment by jrivard on 26 Apr 2013 at 6:39

GoogleCodeExporter commented 9 years ago 
Are you sure about that? Because @LDAP:sn@ and @LDAP:ULCNuser@ are being 
replaced with the current build.

Original comment by sebastia...@gmail.com on 26 Apr 2013 at 6:42

GoogleCodeExporter commented 9 years ago 
Quite sure.  I'll explain more in issue 370.

Original comment by jrivard on 26 Apr 2013 at 6:44