I have inherited a problem on a system that has already been in production for for more than 3 years. At time of deployment, we provided Jasig CAS with LDAP authentication. We used Windows authentication to automatically sign-in users to the system. CAS worked fine in production for some period and after some time it stopped automatically sing-in users to the system. However problem was not critical – after failed automatic sign-in, user had to provide LDAP username and password after that he was successfully signed-in to the system.

As time went by, the problem remained unresolved. Users got used to entering username and password every time. From the developer team, who had deployed the solution, nobody remains in the company.

The management have decided that the time has come to solve this incident. I was that, who had some experience in CAS, so I get to solve this incident. 

First of all I tried to check if the site is designated as intranet and if browser is enabled to allow automatic login. This was not so easy, because the customer was a big governmental institution. There were a lot of policies, that did not allow user to change or even view Internet configurations. Most of configurations were disabled, so I had to find a system admin who had permission to do that. It seemed that everything was OK with that.

Then I started to check our code. The CAS solution was modified by our team to satisfy customer requirements.  First of all, I reviewed our custom code. Then tried to debug to get an understanding where potentially the problem could be. 

After that I asked for production environment logs. The logger was set to WARN level so I had to ask to set to DEBUG. After I got the log, I started to analyze. There were no errors or warning in the log that could indicate any problems, just info that the user is not authenticated:

2016-10-18 06:19:54 INFO [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: unknown
WHAT: supplied credentials: unknown
ACTION: AUTHENTICATION_FAILED
APPLICATION: CAS
WHEN: Tue Oct 18 06:19:54 EEST 2016
CLIENT IP ADDRESS: 111.22.201.218
SERVER IP ADDRESS: 222.11.8.77
=============================================================

 

2016-10-18 06:19:54 INFO [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: unknown
WHAT: error.authentication.credentials.bad
ACTION: TICKET_GRANTING_TICKET_NOT_CREATED
APPLICATION: CAS
WHEN: Tue Oct 18 06:19:54 EEST 2016
CLIENT IP ADDRESS: 111.22.201.218
SERVER IP ADDRESS: 222.11.8.77
=============================================================

 

So I had to go deeper and deeper to other libraries code to understand what could be wrong.

I saw that CAS receives a token something like this

2016-10-21 07:12:48 DEBUG [org.jasig.cas.support.spnego.web.flow.SpnegoCredentialsAction] - Obtained token: `ļæ½ ļæ½  +     ļæ½ļæ½ ļæ½0ļæ½ ļæ½ļæ½$0" …

And after that it says AUTHENTICATION_FAILED. That’s it.

Finally I investigated that the processing goes to processSpnego method in jcifs.spnego.Authentication class.

At first, everything seemed OK. But I noticed that first byte in the token is not that what the Snego processor expected and the exception was thrown.  The exception is then caught in the same method with this code:

       } catch (AuthenticationException ex) {
ex.printStackTrace();
            throw ex;
        } catch (Exception ex) {
ex.printStackTrace();
            throw new AuthenticationException(
                    "Error performing SPNEGO negotiation: " + ex, ex);
        }

No no no, this code is wrong! The information was printed to the system output and it was always there in the Tomcat system output log, and the exception was transformed to

WHO: unknown
WHAT: supplied credentials: unknown
ACTION: AUTHENTICATION_FAILED

 

After that it was very easy to check the system output log and to see that jcifsConfig bean configuration property loginConf pointed to a not existing login.conf file.

So please, please do not printStackTrace() in exception handling – write instead log and use logger. And of course bad code practice library developers can have too.

Comments powered by CComment