Troubleshooting Password Update and Verification problems in PAM

Document ID : KB000103003
Last Modified Date : 27/06/2018
Show Technical Document Details
Introduction:
One of the major functions of PAM is to manage passwords, which includes automatically updating or verifying passwords.  This article explains the basics of how to use the Tomcat Log, catalina.out, to troubleshoot the problem.
Instructions:
First, some basic information.  One of the major functions of PAM is the management of vaulted passwords.  This includes, automatically, updating the password.  In order to perform this task on a target account that account must be in sync between PAM and the target server.  This is done by configuring the target account and password into PAM and selecting "Update both the Password Authority Server and the target system" on the Password tab.  When you save the target account with this selected PAM will log into the target server with the password that was entered for the target account.  If the login is successful the account will be marked as synchronized. 

Once synchronized it will stay synchronized as long as PAM is able to perform such a background login successfully, when the password is changed manually, by a Password View Policy, by a scheduled job, or upon expiration.  If it fails you can use the Tomcat logs to troubleshoot the reason why.  To do so, put the account back in sync, configure the Tomcat Log Level to be Info, on the Config --> Diagnostics page, and attempt to change the password again.  Next, click either the Recent Log Entries button or the Download button, for the Tomcat Log.  With the logfile downloaded it is possible to examine the file with a preferred program.  For example, Notepad++ allows for reverse searching, which is preferable since the most recent messages are at the bottom of the file.

The messages that show the problem will depend on the Target Application used.  For example, with the Unix Target Application the various prompts would be seen, as if the user were logging in manually via a dumb terminal or ssh session.  A common problem is that the prompts issued by the target server do not match what PAM is seeking.  This can happen if the wrong Unix Variant was selected on the Script Processor page, when configuring the Target Application, or if the server is configured with non-standard prompts.  The problem might also occur because of timeouts.  This can be seen by looking for the following pattern:
<long string of digits>-$?-<long string of digits>

This string causes the target server to do a status check following the last command executed on the target server, ie passwd.  Success is indicated by the following pattern:
<long string of digits>-0--<long string of digits>.

Failure would be indicated by any digit other than 0 in the string.  You might also see the string "does NOT MATCH", referring to the status check string.  When this is seen it is a good idea to check the timestamps on the messages.  By default, the Script Processor tab is configured for 5000 milliseconds(5 seconds).  Most of the time this will be sufficient, but if not the Script Timeout must be increased on the Script Processor tab.

In the case of an Active Directory account messages like those below will be seen:
Jun 21, 2018 5:36:30 PM com.cloakware.cspm.server.plugin.targetmanager.WindowsDomainServiceTargetManager updateCredentials
INFO: Updating credentials for account with username 'johnsnow'
Jun 21, 2018 5:36:30 PM com.cloakware.cspm.server.plugin.targetmanager.WindowsDomainServiceTargetManager a
INFO: Updating password of Active Directory account with username 'johnsnow'
Jun 21, 2018 5:36:30 PM com.cloakware.cspm.server.plugin.targetmanager.WindowsDomainServiceTargetManager loginToActiveDirectoryServer

Many other messages will be seen too, but most can be ignored.  Here is an example of what might be seen when the password update fails:
Jun 21, 2018 5:36:30 PM com.cloakware.cspm.server.plugin.targetmanager.WindowsDomainServiceTargetManager loginToActiveDirectoryServer
INFO: Failed authentication to Active Directory using distinguished name 'CN=John Snow,CN=Users,DC=thrones,DC=gameof' for account 'voged01rad' due to error '[LDAP: error code 49 - 80090308: LdapErr: DSID-0C09042F, comment: AcceptSecurityContext error, data 52e, v2580 ]'
javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C09042F, comment: AcceptSecurityContext error, data 52e, v2580 ]

In this case the LDAP error code is 49, which indicates that the the login failed.  The "data 523, v2580" indicates that the password is invalid.  Other error codes may be seen, depending on the problem.  For example, 525 indicates that the user was not found and 530 indicates that the user is not permitted to login at this time.

While not detailed, this gives a good idea of what to look for in the Tomcat Log.  Experiment with the various target applications being used and see what it contains.  With more experience it will become easier to identify the cause of the problem, regardless of the target application.  If assistance is needed in analyzing the Tomcat log please open a ticket.  Make sure to provide the Tomcat log, the name of the target application and target account, and the type of target application being used.