can't use different connections to the same datasource inside a single transaction

100 views
Skip to first unread message

Jonathan Price

unread,
Apr 25, 2016, 4:08:12 PM4/25/16
to Lucee
I'm not entirely sure why this is problematic - hoping someone can clarify what I'm doing wrong here.  When I call the login function below (with a valid username/pw combo), I'm getting the error in the title.  The error line number points to the 'var req = object.getNew('AuthenticationRequest');' line in the logAuthenticationRequest function.  FWIW, object.getNew() is just a wrapper for entityNew in this context.  I'm pretty sure I've done this type of thing in ACF10.  Any suggestions/explanations?

-------
 
component accessors="true" {

    property object;
    property datetime;

    public any function login( required string username, required string password, required string deviceId ) {
        var authenticate = authenticateUser( argumentCollection = arguments );
        var error = '';
        var status = object.getNew( name = 'ReturnStatus', np = true);

        if ( authenticate.RecordCount != 1 )
            error = 'Username and password do not match.'

        if (deviceID == '')
            error = 'Invalid device id.'

        if ( error != '' ) {
            status.error().setMessage( error );
            logAuthenticationRequest( username = arguments.username, password = arguments.password, deviceId = arguments.deviceId, status = false, message = error );
        } else {
            var user = object.get( name = 'User', id = authenticate.UserId );
            user.init();
            user.updateAuthenticationToken( deviceId = arguments.deviceId );
            user.save();
            
            status.success().setDetails( {userId: authenticate.UserId} );
        }

        return status;
    }

    public any function authenticateUser( required string username, required string password ) {
  
        local.queryService = new query(); 
        local.queryService.setName("validateUser"); 
        local.queryService.addParam( name = "username", value = arguments.username, cfsqltype = "cf_sql_varchar" ); 
        local.queryService.addParam( name = "unhashedPassword", value = arguments.password, cfsqltype = "cf_sql_varchar" ); 
        local.queryService.addParam( name = "hashedPassword", value = Hash(arguments.password, 'SHA'), cfsqltype = "cf_sql_varchar" );

        local.sql = "
            SELECT
                a.UserID,
                a.UserName,
                a.TempPassword,
                a.FirstName,
                a.LastName,
                IF( a.TempPassword = :unhashedPassword, 1, 0) AS TemporaryLogin
            FROM
                User a
            WHERE
                1 = 1
                AND (
                    a.UserName = :username
                )
                AND (
                    a.Password = :hashedPassword
                    OR a.TempPassword = :unhashedPassword
                );
        ";

        local.queryService.setSql( local.sql );
        local.result = queryService.execute( sql = local.sql );

        return local.result.getResult();
    }

    public any function logAuthenticationRequest( 
        required string username, 
        required string password, 
        required string deviceId, 
        required boolean status, 
        required string message ) 
    {
        var req = object.getNew('AuthenticationRequest');
        
        arguments.createdDate = datetime.getNow();

        if ( req.populate( context = arguments ).validate() )
            req.save();
    }
}

Jonathan Price

unread,
Apr 25, 2016, 6:02:36 PM4/25/16
to Lucee
FWIW I've verified that this same code runs in ACF10 locally.  Bummed, because we really wanted to use Lucee for a new project, but I've already hit upon this oddity.  

Also, I hadn't included the code calling the login function in the original post.  It's within a Taffy resource and looks like this.  Not much going on.

    public function post(required string username, required string password, required string deviceId ) {
        transaction {
            try {
                var status = variables.authSvc.login(username = arguments.username, password = arguments.password, deviceId = arguments.deviceId );
                transaction action="commit";
            }
            catch( any e ) {
                transaction action="rollback";
                rethrow;
            }
        }

        if ( status.isError() )
            return noData().withStatus(401, status.getMessage() );
        else
            return noData().withStatus(200, status.getMessage() );

Jon Clausen

unread,
Apr 25, 2016, 6:32:31 PM4/25/16
to lu...@googlegroups.com
Jonathan,

What, specifically, is the error message that’s being thrown?  Without that, I’d have no idea what to tell you.

Lucee does maintain separate connection pools for ORM/Hibernate and CF queries, which may have something to do with what you’re seeing.

Jon
--
Love Lucee? Become a supporter and be part of the Lucee project today! - http://lucee.org/supporters/become-a-supporter.html
---
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/c4ae96aa-bc63-404a-a951-e9fd4fffba1b%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Puritan Paul

unread,
Apr 25, 2016, 6:34:10 PM4/25/16
to lu...@googlegroups.com
Here’s the stack trace I’m getting:

{
   "ERROR": "can't use different connections to the same datasource inside a single transaction",
   "DETAIL": "",
   "TAGCONTEXT": "/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/model/services/object.cfc [Line 8]",
   "STACKTRACE": [
      {
         "Raw_Trace": "model.services.object_cfc$cf.udfCall(/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/model/services/object.cfc:8)",
         "codePrintPlain": "6: \n7: public struct function get( required numeric id, required string name ) {\n8: local.obj = entityLoad('#arguments.name#', #arguments.id#, true);\n9: \n10: if (!isDefined('local.obj') )\n",
         "column": 0,
         "line": 8,
         "template": "/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/model/services/object.cfc",
         "id": "??",
         "type": "cfml",
         "codePrintHTML": "6: <br>\n7: public struct function get( required numeric id, required string name ) {<br>\n<b>8: local.obj = entityLoad('#arguments.name#', #arguments.id#, true);</b><br>\n9: <br>\n10: if (!isDefined('local.obj') )<br>\n"
      
},
      {
         "Raw_Trace": "model.services.authentication_cfc$cf.udfCall(/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/model/services/authentication.cfc:21)",
         "codePrintPlain": "19: logAuthenticationRequest( username = arguments.username, password = arguments.password, deviceId = arguments.deviceId, status = false, message = error );\n20: } else {\n21: var user = object.get( name = 'User', id = authenticate.UserId );\n22: // writeDump(user);\n23: user.init();\n",
         "column": 0,
         "line": 21,
         "template": "/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/model/services/authentication.cfc",
         "id": "??",
         "type": "cfml",
         "codePrintHTML": "19: logAuthenticationRequest( username = arguments.username, password = arguments.password, deviceId = arguments.deviceId, status = false, message = error );<br>\n20: } else {<br>\n<b>21: var user = object.get( name = 'User', id = authenticate.UserId );</b><br>\n22: // writeDump(user);<br>\n23: user.init();<br>\n"
      
},
      {
         "Raw_Trace": "authentication_cfc$cf.udfCall(/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/api/rest/resources/authentication.cfc:8)",
         "codePrintPlain": "6: transaction {\n7: try {\n8: var status = variables.authSvc.login(username = arguments.username, password = arguments.password, deviceId = arguments.deviceId );\n9: transaction action=\"commit\";\n10: }\n",
         "column": 0,
         "line": 8,
         "template": "/Users/jonathanprice/Websites/Lucee/lucee-4.5.2.018-express/webapps/ROOT/EM2/api/rest/resources/authentication.cfc",
         "id": "??",
         "type": "cfml",
         "codePrintHTML": "6: transaction {<br>\n7: try {<br>\n<b>8: var status = variables.authSvc.login(username = arguments.username, password = arguments.password, deviceId = arguments.deviceId );</b><br>\n9: transaction action=&quot;commit&quot;;<br>\n10: }<br>\n"
      
},
      {
         "Raw_Trace": "core.api_cfc$cf.udfCall1(/Users/jonathanprice/Websites/Taffy/atuttle-Taffy-75b0912/core/api.cfc:338)",
         "codePrintPlain": "336: \t\t\t\t\t\tmethod=\"#_taffyRequest.method#\"\n337: \t\t\t\t\t\targumentcollection=\"#_taffyRequest.requestArguments#\"\n338: \t\t\t\t\t\treturnvariable=\"_taffyRequest.result\"\n339: \t\t\t\t\t/>\n340: \t\t\t\t\t<cfset m.afterResource = getTickCount() />\n",
         "column": 0,
         "line": 338,
         "template": "/Users/jonathanprice/Websites/Taffy/atuttle-Taffy-75b0912/core/api.cfc",
         "id": "??",
         "type": "cfml",
         "codePrintHTML": "336: \t\t\t\t\t\tmethod=&quot;#_taffyRequest.method#&quot;<br>\n337: \t\t\t\t\t\targumentcollection=&quot;#_taffyRequest.requestArguments#&quot;<br>\n<b>338: \t\t\t\t\t\treturnvariable=&quot;_taffyRequest.result&quot;</b><br>\n339: \t\t\t\t\t/&gt;<br>\n340: \t\t\t\t\t&lt;cfset m.afterResource = getTickCount() /&gt;<br>\n"
      
}
   ]
}

You received this message because you are subscribed to a topic in the Google Groups "Lucee" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/lucee/OOtXwK3pMpc/unsubscribe.
To unsubscribe from this group and all its topics, send an email to lucee+un...@googlegroups.com.

To post to this group, send email to lu...@googlegroups.com.

Jon Clausen

unread,
Apr 25, 2016, 8:18:58 PM4/25/16
to lu...@googlegroups.com
OK. I see now.   This error probably needs to be thrown, since the logistics of managing transactions through multiple connections is the responsibility of the driver and isn’t guaranteed - not to mention row locking issues which may arise.  Just because it works in ACF doesn’t mean it, necessarily, should work. :)

In either case, why don’t you just thread the code in your logging and then you won’t have to worry about the transaction used in the primary thread? 

Jon

Puritan Paul

unread,
Apr 25, 2016, 9:22:29 PM4/25/16
to lu...@googlegroups.com
On Apr 25, 2016, at 5:18 PM, Jon Clausen <jon_c...@silowebworks.com> wrote:

OK. I see now.   This error probably needs to be thrown, since the logistics of managing transactions through multiple connections is the responsibility of the driver and isn’t guaranteed - not to mention row locking issues which may arise.  Just because it works in ACF doesn’t mean it, necessarily, should work. :)

Yep, I figured that might be the case.  Wouldn’t surprise me at all if I were approaching incorrectly.  Just hoping to figure out what I’m doing incorrectly, if that’s the case.

In either case, why don’t you just thread the code in your logging and then you won’t have to worry about the transaction used in the primary thread? 

Mostly because I’m not sure what that means :)  Do you mean put a transaction inside the logging function itself as opposed to wrap the entire thing in a transaction?

Jon Clausen

unread,
Apr 26, 2016, 7:41:14 AM4/26/16
to lu...@googlegroups.com

Hi Paul,

I meant start a separate thread for your logging using cfthread. Something like:

 public any function logAuthenticationRequest(  
    required string username,  
    required string password,  
    required string deviceId,  
    required boolean status,  
    required string message  
)  
{
     
    var threadName = "logAuthenticationRequest_" & createUUID();
         
    thread name="#threadName#" action="run"
        object=object
        arguments=arguments
    {
        var req = object.getNew('AuthenticationRequest');
     
        arguments.createdDate = datetime.getNow();

        if ( req.populate( context = arguments ).validate() )
            req.save();
     
    }
     
    return cfthread[ threadName ];
     
}

Debugging thread errors is a bit more involved, but logging is an example of when they can come in really handy.

Puritan Paul

unread,
Apr 26, 2016, 1:03:57 PM4/26/16
to lu...@googlegroups.com
I’ve got *zero* threading experience, so it’s time to do some reading.  Thanks for the suggestions.

-- 
Love Lucee? Become a supporter and be part of the Lucee project today! - http://lucee.org/supporters/become-a-supporter.html
--- 
You received this message because you are subscribed to a topic in the Google Groups "Lucee" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/lucee/OOtXwK3pMpc/unsubscribe.
To unsubscribe from this group and all its topics, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.

Puritan Paul

unread,
Apr 26, 2016, 3:23:28 PM4/26/16
to lu...@googlegroups.com
Okay, so this is turning into a broader issue that I’m unclear about how to handle.  I often use a query to validate some condition, like the existence of a record (as opposed to entityload).  I usually use ORM objects to persist to the DB.  So, it’s pretty common for a service function to call both - which seems to be a problem in Lucee?  Or maybe it should be a problem in ACF and isn’t - regardless, it’s a fairly customary practice in some apps I’ve worked on.

Is this really that unusual?  If not, how are people handling it?  Starting separate threads feels like overkill, especially having to handle them asynchronously.

Or do people really not do both?

Jon Clausen

unread,
Apr 26, 2016, 5:31:31 PM4/26/16
to lu...@googlegroups.com
Depends on if you are within a transaction when you perform that validation.  The issue, from what I can see, is that you are running into is that you are within an open transaction block when you attempt to run those additional validation queries.  

It’s really a processing flow issue and the solution is to perform your validation first before you enter the transactional state or to use ORM methods in your validation so that the ORM session state is consistent, along with the connection.   

Ideally, you’ve ensured the record you are about to persist meets all of your validation requirements before you open that transaction up.

Jon
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.

To post to this group, send email to lu...@googlegroups.com.

Puritan Paul

unread,
Apr 26, 2016, 6:36:15 PM4/26/16
to lu...@googlegroups.com
Right, this makes sense.  Sounds like I’ve just gotten away with some laziness up to now.

I removed the outer transaction call and pushed it into the service function like so:

    public any function login( required string username, required string password, required string deviceId ) {
        var authenticate = authenticateUser( argumentCollection = arguments );
        var error = '';
        var status = object.getNew( name = 'ReturnStatus', np = true);

        if ( authenticate.RecordCount != 1 )
            error = 'Username and password do not match.';

        if (deviceID == '')
            error = 'Invalid device id.';

        if ( error != '' ) {
            status.error().setMessage( error );
        } else {

            transaction {
                try {
                    var user = object.get( name = 'User', id = authenticate.UserId );
                    user
                        .updateAuthenticationToken( deviceId = arguments.deviceId )
                        .save();

                    status.success().setDetails( {token: user.getAuthenticationTokenByDevice( deviceId = arguments.deviceId )} );
                    transaction action="commit";            
                }
                catch( any e ) {
                    transaction action="rollback";
                    rethrow;
                }
            }
            
        }

        logAuthenticationRequest( 
            username = arguments.username, 
            password = arguments.password, 
            deviceId = arguments.deviceId, 
            status = status.isValid(), 
            message = error );

        return status;
    }


And now I’m getting some kind of StackOverflow error.  But maybe it’s a Taffy issue?  I can’t really tell.  Thanks a lot for all your help.


An unhandled exception occurred: java.lang.StackOverflowError --
ERROR WHEN LOGGING EXCEPTION 
Catch

    additional Struct

    Detail 
        string 
    ErrNumber 
        number 0 
    ErrorCode 
        string 0 
    Extended_Info 
        string 
    ExtendedInfo 
        string 
    Message 
        string Element at position [1] doesn't exist in array 
    StackTrace 
        string Element at position [1] doesn't exist in array
	at lucee.runtime.type.ArrayImpl.invalidPosition(ArrayImpl.java:194):194
	at lucee.runtime.type.ArrayImpl.getE(ArrayImpl.java:171):171
	at lucee.runtime.type.ArrayImpl.get(ArrayImpl.java:124):124
	at lucee.runtime.type.util.ArraySupport.get(ArraySupport.java:314):314
	at lucee.runtime.util.VariableUtilImpl.get(VariableUtilImpl.java:255):255
	at lucee.runtime.util.VariableUtilImpl.getCollection(VariableUtilImpl.java:249):249
	at lucee.runtime.PageContextImpl.getCollection(PageContextImpl.java:1416):1416
	at core.api_cfc$cf.udfCall1(/Users/jonathanprice/Websites/Taffy/atuttle-Taffy-75b0912/core/api.cfc:163):163
	at core.api_cfc$cf.udfCall(/Users/jonathanprice/Websites/Taffy/atuttle-Taffy-75b0912/core/api.cfc):-1
	at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111):111
	at lucee.runtime.type.UDFImpl._call(UDFImpl.java:328):328
	at lucee.runtime.type.UDFImpl.call(UDFImpl.java:229):229
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:642):642
	at lucee.runtime.ComponentImpl._call(ComponentImpl.java:524):524
	at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1761):1761
	at lucee.runtime.listener.ModernAppListener.call(ModernAppListener.java:405):405
	at lucee.runtime.listener.ModernAppListener.onError(ModernAppListener.java:392):392
	at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2273):2273
	at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2225):2225
	at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:456):456
	at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:47):47
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:725):725
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291):291
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206):206
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52):52
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239):239
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206):206
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219):219
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106):106
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501):501
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142):142
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79):79
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610):610
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88):88
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:537):537
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1085):1085
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:658):658
	at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222):222
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1556):1556
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1513):1513
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142):1142
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617):617
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61):61
	at java.lang.Thread.run(Thread.java:745):745
 
    TagContext Array

        1 Struct

            codePrintHTML 
                string 161: 				</cfif>
162: <cfif structKeyExists(root,"tagContext")>
163: <cfset data.tagContext = root.tagContext[1].template & " [Line #root.tagContext[1].line#]" />
164: </cfif>
165: <!--- MAKE IT LOOK GOOD! --->
codePrintPlain string 161: 162: 163: 164: 165: column number 0 id string ?? line number 163 Raw_Trace string core.api_cfc$cf.udfCall1(/Users/jonathanprice/Websites/Taffy/atuttle-Taffy-75b0912/core/api.cfc:163) template string /Users/jonathanprice/Websites/Taffy/atuttle-Taffy-75b0912/core/api.cfc type string cfml type string expression

Jon Clausen

unread,
Apr 26, 2016, 8:35:38 PM4/26/16
to lu...@googlegroups.com

Jon Clausen

unread,
Apr 26, 2016, 8:36:42 PM4/26/16
to lu...@googlegroups.com
It looks like it’s something related to Taffy, for sure. Without posting a sample of that, it’d be hard to debug.
Reply all
Reply to author
Forward
0 new messages