Uploaded image for project: 'OFBiz'
  1. OFBiz
  2. OFBIZ-6721

org.ofbiz.common.login.LoginServices.userLogin causes stack track when username or password is incorrect

    Details

    • Type: Improvement
    • Status: Closed
    • Priority: Trivial
    • Resolution: Done
    • Affects Version/s: Release Branch 11.04, Release Branch 12.04, Release Branch 13.07, Release Branch 14.12, Trunk
    • Fix Version/s: 14.12.01, 12.04.06, 13.07.03, 16.11.01
    • Component/s: commonext
    • Labels:
    • Flags:
      Patch

      Description

      org.ofbiz.common.login.LoginServices.userLogin is returning ERROR when a username or password is incorrect. It should return FAILURE instead of error. The error causes stack track to be printed to the log. The stack trace makes watching the log for actual errors difficult. This is especially hard when running and analyzing the log after a full test run, of in my case, a custom set of test cases.

      Stack trace:

      [java] 2015-11-12 16:35:00,412 |ajp-bio-8009-exec-7 |LoginWorker |I| Setting default delegator
      [java] 2015-11-12 16:35:00,413 |ajp-bio-8009-exec-7 |LoginServices |I| [LoginServices.userLogin] : Password Incorrect
      [java] 2015-11-12 16:35:00,420 |ajp-bio-8009-exec-7 |ServiceDispatcher |E| Error in Service [userLogin]: Password incorrect.
      [java] 2015-11-12 16:35:00,420 |ajp-bio-8009-exec-7 |TransactionUtil |E| [TransactionUtil.rollback]
      [java] java.lang.Exception: Stack Trace
      [java] at org.ofbiz.entity.transaction.TransactionUtil.rollback(TransactionUtil.java:322) [ofbiz-entity.jar:?]
      [java] at org.ofbiz.entity.transaction.TransactionUtil.rollback(TransactionUtil.java:299) [ofbiz-entity.jar:?]
      [java] at org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:534) [ofbiz-service.jar:?]
      [java] at org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:227) [ofbiz-service.jar:?]
      [java] at org.ofbiz.service.GenericDispatcherFactory$GenericDispatcher.runSync(GenericDispatcherFactory.java:88) [ofbiz-service.jar:?]
      [java] at org.ofbiz.webapp.control.LoginWorker.login(LoginWorker.java:488) [ofbiz-webapp.jar:?]
      [java] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_60]
      [java] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_60]
      [java] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_60]
      [java] at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_60]
      [java] at org.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:92) [ofbiz-webapp.jar:?]
      [java] at org.ofbiz.webapp.event.JavaEventHandler.invoke(JavaEventHandler.java:78) [ofbiz-webapp.jar:?]
      [java] at org.ofbiz.webapp.control.RequestHandler.runEvent(RequestHandler.java:759) [ofbiz-webapp.jar:?]
      [java] at org.ofbiz.webapp.control.RequestHandler.doRequest(RequestHandler.java:476) [ofbiz-webapp.jar:?]
      [java] at org.ofbiz.webapp.control.ControlServlet.doGet(ControlServlet.java:213) [ofbiz-webapp.jar:?]
      [java] at org.ofbiz.webapp.control.ControlServlet.doPost(ControlServlet.java:88) [ofbiz-webapp.jar:?]
      [java] at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [servlet-api-3.0.jar:?]
      [java] at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) [servlet-api-3.0.jar:?]
      [java] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.ofbiz.webapp.control.ContextFilter.doFilter(ContextFilter.java:323) [ofbiz-webapp.jar:?]
      [java] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423) [tomcat-7.0.64-catalina.jar:7.0.64]
      [java] at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:190) [tomcat-7.0.64-tomcat-coyote.jar:7.0.64]
      [java] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) [tomcat-7.0.64-tomcat-coyote.jar:7.0.64]
      [java] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-7.0.64-tomcat-coyote.jar:7.0.64]
      [java] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_60]
      [java] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_60]
      [java] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-7.0.64-tomcat-coyote.jar:7.0.64]
      [java] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_60]
      [java] 2015-11-12 16:35:00,420 |ajp-bio-8009-exec-7 |TransactionUtil |I| Transaction rolled back
      [java] 2015-11-12 16:35:00,421 |ajp-bio-8009-exec-7 |ServiceDispatcher |T| Sync service [webtools/userLogin] finished in [9] milliseconds
      [java] 2015-11-12 16:35:00,421 |ajp-bio-8009-exec-7 |RequestHandler |I| Ran Event java:org.ofbiz.webapp.control.LoginWorker#login from [request], result is [error]
      [java] 2015-11-12 16:35:00,421 |ajp-bio-8009-exec-7 |RequestHandler |E| Request login caused an error with the following message: following error occurred during login: Password incorrect.

      1. OFBIZ-6721.patch
        0.6 kB
        Forrest Rae

        Activity

        Hide
        fbr@14x.net Forrest Rae added a comment -

        One line patch.

        Show
        fbr@14x.net Forrest Rae added a comment - One line patch.
        Hide
        jacques.le.roux Jacques Le Roux added a comment -

        Yes indeed, I see no reasons why we should rollback here

        Show
        jacques.le.roux Jacques Le Roux added a comment - Yes indeed, I see no reasons why we should rollback here
        Hide
        jacques.le.roux Jacques Le Roux added a comment -

        Sorry Forrest but I don't consider this a bug

        Show
        jacques.le.roux Jacques Le Roux added a comment - Sorry Forrest but I don't consider this a bug
        Hide
        jacques.le.roux Jacques Le Roux added a comment -

        Done in trunk at revision: 1714244

        Show
        jacques.le.roux Jacques Le Roux added a comment - Done in trunk at revision: 1714244
        Hide
        fbr@14x.net Forrest Rae added a comment - - edited

        I believe it is a bug. You have to consider how this is being used by people extending the framework. The difference between ERROR and FAILURE when it comes to authentication, especially when you need to rely on ignore-failure="false" ignore-error="false", is a blocker for me. I have a SECA on userLogin service, and I need to know if there was an ERROR, or there was a FAILURE. This prevents my ability to augment the authentication process.

        In my use case, I need to make sure OOTB authentication passes, and then I need to check the status of a series of relationships, and then I save some data to some custom entities. Here is my SECA:

        <eca service="userLogin" event="return" run-on-error="false" run-on-failure="false">
        <action service="userLoginRelationshipCheck" mode="sync" ignore-failure="false" ignore-error="false"/>
        </eca>

        I considered building an external org.ofbiz.common.authentication.api.Authenticator, but the main issue is the external auth runs first, before the password check. This creates an opportunity to brute force usernames based on time inference, if the code has to do several operations before ever checking if the authentication details are correct, not to mention invalid data to custom entities. A SECA is more advantageous here.

        Perhaps the bug title and original description probably should have contained this info, but I'm trying not to disclose too much information.

        Show
        fbr@14x.net Forrest Rae added a comment - - edited I believe it is a bug. You have to consider how this is being used by people extending the framework. The difference between ERROR and FAILURE when it comes to authentication, especially when you need to rely on ignore-failure="false" ignore-error="false", is a blocker for me. I have a SECA on userLogin service, and I need to know if there was an ERROR, or there was a FAILURE. This prevents my ability to augment the authentication process. In my use case, I need to make sure OOTB authentication passes, and then I need to check the status of a series of relationships, and then I save some data to some custom entities. Here is my SECA: <eca service="userLogin" event="return" run-on-error="false" run-on-failure="false"> <action service="userLoginRelationshipCheck" mode="sync" ignore-failure="false" ignore-error="false"/> </eca> I considered building an external org.ofbiz.common.authentication.api.Authenticator, but the main issue is the external auth runs first, before the password check. This creates an opportunity to brute force usernames based on time inference, if the code has to do several operations before ever checking if the authentication details are correct, not to mention invalid data to custom entities. A SECA is more advantageous here. Perhaps the bug title and original description probably should have contained this info, but I'm trying not to disclose too much information.
        Hide
        jacques.le.roux Jacques Le Roux added a comment -

        OK, though you have a specific case, you convinced me at large to backport. Even if I still consider this a trivial improvement.

        Backported in
        R14.12 r1714301
        R13.07 r1714302
        R12.04 r1714303

        Show
        jacques.le.roux Jacques Le Roux added a comment - OK, though you have a specific case, you convinced me at large to backport. Even if I still consider this a trivial improvement. Backported in R14.12 r1714301 R13.07 r1714302 R12.04 r1714303
        Hide
        fbr@14x.net Forrest Rae added a comment -

        Thanks Jacques, I'll take some time in the next month or so to improve the password checking code a bit in trunk, and put in support for PBKDF2 with rolling password hash upgrades for posix style password storage.

        Show
        fbr@14x.net Forrest Rae added a comment - Thanks Jacques, I'll take some time in the next month or so to improve the password checking code a bit in trunk, and put in support for PBKDF2 with rolling password hash upgrades for posix style password storage.
        Hide
        jacques.le.roux Jacques Le Roux added a comment -

        That would be appreciated I think!

        Show
        jacques.le.roux Jacques Le Roux added a comment - That would be appreciated I think!

          People

          • Assignee:
            jacques.le.roux Jacques Le Roux
            Reporter:
            fbr@14x.net Forrest Rae
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development