Showing posts with label Application.cfc. Show all posts
Showing posts with label Application.cfc. Show all posts

Sunday 9 May 2021

Setting up a MariaDB JDBC datasource in ColdFusion 2021 in Application.cfc

G'day:

This is how I needed to set my datasource in Application.cfc to get ColdFusion 2021 to connect to MariaDB. I'm writing this because I could not - for the life of me - find this information in any one place in the docs. Nor could I find it anywhere else via Google. I have pieced this together from various sources (including Lucee docs, which were more helpful than the Adobe ColdFusion documentation), and want to put it in one place for my own future reference, or should anyone else need to know how to set up a MariaDB datasouce in ColdFusion using their JDBC driver. The params should also work for any other JDBC datasource.

Apologies for that fairly SEO-heavy opening paragraph.

OK, so it's this:

component {

    this.datasources["test"] = {
        host = "localhost",
        port = 3306,
        driver = "mariadb",
        class = "org.mariadb.jdbc.Driver",
        url = "jdbc:mariadb://localhost:3306/database_name?user=user_name&password=user_password",
        database = "database_name",
        username = "user_name",
        password = "user_password", 
        custom = {
            useUnicode = true,
            characterEncoding = "UTF-8"
        }
    }
    this.datasource = "test"
}

After checking up on what Sean says in the comment below, I was able to pare this back to:

this.datasources["test"] = {
    class = "org.mariadb.jdbc.Driver",
    url = "jdbc:mariadb://localhost:3306/cfmlindocker?useUnicode=true&characterEncoding=UTF-8",
    username = "cfmlindocker",
    password = server.system.environment.MYSQL_PASSWORD
}

It failed if I did not have the username and password keys; but I did not need them in the URL. And I can pass the custom stuff in the URL, rather than specifying them separately.

Cheers for encouraging me to investigate further, Sean!

I got the MariaDB jar file from Download and Install MariaDB Connector/J. I also found the class name for the URL in there. That jar should be dropped into [coldfusion directory]/]WEB-INF/lib

The driver value seems to just be a label.

Note that on Lucee they seem to use connectionString rather than url. I dunno if url also works, and CBA checking right now.

ColdFusion might give an unhelpful error if it does't like the datasource settings. Instead of saying "I don't like those datasource settings", or "they don't work", it says "Datasource test could not be found". It was easy to find, pal: it's right there in the Application.cfc file. I just had a param wrong. I especially saw this when I had connectionString rather then url.

I would normally store the password in the environment, not hard-code into a source-controlled file, eg: server.system.environment.TEST_DSN_PASSWORD (both ColdFusion and Lucee put any environment variables in server.system.environment. Or you could use an environment-specific non-source controlled config file or something. Just don't put it directly in Application.cfc

Here's some more SEO for you: so that was the Application.cfc configuration settings for ColdFusion 2021 to connect to a MariaDB database using their JDBC connection.

Righto.

--
Adam

Saturday 6 July 2013

CFML: REST requests don't seem to correctly use Application.cfc either

G'day:
The emphasis in the title is an allusion to web socket requests also not respecting them.

God knows what this article will read like. I headed to the pub to catch the last quarter of the Aussie v Lions match, and I've been sitting here since. I'm over in Portumna visiting my son, and other than my 4h appointment doing that, I've kinda got nothing better to do here, so I'm still in the pub (which has wireless), amusing myself and drinking Guinness. Am just finishing my third pint. And will order a fourth. It's 3pm ;-)


Anyway, someone posted a question on Stack Overflow about how erroring REST requests don't fire onError() calls. This is a known issue: 3506757. But it was enough for me to furrow my brow and decide to have a look into it.

Now I'm no REST expert (neither in the context of ColdFusion, nor in general), so it always takes me a bit to get a REST CFC / function working, but I've come up with this test environment:

// Application.cfc
component {

    this.name    = "testappCfcIssue09";

    public void function onApplicationStart(){
        restInitApplication(expandPath("../api"), "api");
    }

    public void function onError(){
        writeLog(file=this.name, text="#GetFunctionCalledName()# called");
        writeDump(var=local, label=this.name);
        abort;
    }

}

This is a fairly vanilla Application.cfc. The onApplicationStart() stuff is just to work around some lazy programming on the part of Adobe, in that when one changes a REST-aware CFC, it will error until one restarts the REST engine. The onError() is just there in case REST calls call this onError() instead of the one in the directory the REST CFCs are in (I came into this not knowing how this stuff was handled at all, so just making sure).

<!--- testException.cfm --->
<cfhttp method="get" url="http://#CGI.http_host#/rest/api/Messaging/forceError" result="response">
</cfhttp>
<cfdump var="#response#" label="HTTP Response">

[I have decided against Guinness for the fourth: it's cider. It's a cracking hot day here today in Portumna, so not really Guinness weather]

This calls my REST method, and dumps the response. Now, over in the API dir, I have this lot:

//Messaging.cfc
component rest=true {

    remote string function gday(required string name restargsource="query") httpmethod="get"  {
        return "G'day #name#";
    }

    remote string function forceError() httpmethod="get" restpath="forceError"  {
        throw(type="ForcedException", message="Exception forced", detail="Because you asked me to");
    }
} 

The first method is just me testing that stuff was actually working properly with a vanilla method. The second method is one that forces an error, specifically so I can see what happens when an exception occurs.

And I have this Application.cfc in this directory as well, to log everything which goes on during REST requests:

// Application.cfc
component {

    this.name                = "restRequestLogging02";
    this.sessionManagement    = true;

    public void function onApplicationStart(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
    }

    public void function onApplicationEnd(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
    }

    public void function onSessionStart(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
    }

    public void function onSessionEnd(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
    }

    public void function onRequestStart(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
    }

    public void function onRequestEnd(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
    }

    public void function onRequest(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
        include arguments[1];
    }

    public any function onCfcRequest(required string cfc, required string method, required struct args){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
        var o = createObject(arguments.cfc);
        var metadata = getMetadata(o[method]); 
        
        if (structKeyExists(metadata, "access") && metadata.access == "remote"){
            return invoke(o, method, args);
        }else{
            throw(type="InvalidMethodException", message="Invalid method called", detail="The method #method# does not exists or is inaccessible remotely");
        }
    }

    public void function onError(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
        writeDump(local);
        abort;
    }

    public void function onMissingTemplate(){
        writeLog(file=this.name, text="#getFunctionCalledName()# called");
        writeeDump(local);
        abort;
    }

}

The only non-obvious method in this is the onCfcRequest() one. The code here is reflective of the unexpected "security issue" onCfcRequest() could effect in an application that I blogged about a while ago. Any onCfcRequest() method should do this lot as a minimum. That consideration aside, basically every event handler call is logged. That's the crux of things.

Wednesday 29 May 2013

CFML: Application.cfc look-ups and virtual directories (Appendix)

G'day:
Yesterday I did a bit of an investigation in to how ColdFusion looks for an Application.cfc / .cfm when it runs a request. This article is a continuation of that, and it won't make any sense if you don't read yesterday's article first.


In yesterday's article I had this directory structure set up:

C:\
  apps\
    adobe\
      ColdFusion\
        10\
          cfusion\
            wwwroot\
              docroot\
                test.cfm
                some_dir\
                  linked_subdir\
                    test.cfm
                  local_subdir\
                    test.cfm
  temp\
    linked_subdir\
      test.cfm

And I covered the look-ups for Application.cfc from both local directories, and junctioned / linked directories.

Following my Twitter feed this evening, and Laura Springer (who I don't know, other than from following on Twitter: I hope you don't mind me using you as an inspiration, Laura) made an observation about Application.cfc file behaviour when called from a virtual directory.

And it occurred to me that this is:
  1. something I didn't cover in my previous article;
  2. another thing I didn't know the behaviour of.
I won't carry on as much as I did last night, but I set up this modification to the above directory structure:


C:\
  apps\
    adobe\
      ColdFusion\
        10\
          cfusion\
            wwwroot\
              docroot\
                test.cfm
                some_dir\
                  linked_subdir\
                    test.cfm
                  local_subdir\
                    test.cfm
                  virtual_subdir\
                    test.cfm
  temp\
    linked_subdir\
      test.cfm
    virtual_subdir\
      test.cfm

Where C:\temp\virtual_subdir is a physical directory mapped into the site via a virtual directory /some_dir/virtual_subdir/.

I'll not do all the colour-coding and stuff from last night, but when browsing to /some_dir/virtual_subdir/test.cfm, ColdFusion looks for Application.cfc / .cfm files in the directories as listed below:

Default

C:\temp\virtual_subdir\Application.cfc
C:\temp\Application.cfc
C:\Application.cfc


Until Webroot

C:\temp\virtual_subdir\Application.cfc
C:\temp\Application.cfc
C:\Application.cfc


In Webroot

C:\temp\virtual_subdir\Application.cfc
C:\apps\adobe\ColdFusion\10\cfusion\wwwroot\docroot\Application.cfc


So as you can see here: for the first two options it looks up in the physical directory structure, but in the latter example it looks in the immediate physical directory, and then looks in the web site's web root (and no further).

Another curious thing... you know how yesterday I said that the "web root" for the purposes of this look-up meant "the ColdFusion root", not the web server / site's web root? I tested that assertion three times last night, and was 100% confident I was correct in saying that (I checked because it seemed to be contradicting what I was reading elsewhere on the 'net, so presumed initially I was wrong). However this evening having seen what seemed like anomalous behaviour with that last path on the "in webroot" look-up, I tested again. And for the life of me I cannot replicate last night's behaviour this evening: this evening "web root" means "the web site's web root" not "ColdFusion's application root". There's a chance I screwed up last night, but I really don't think I did. Well: 80% sure I didn't. However I could have got something wrong. I'm gonna put a caveat on last night's article until I test more thoroughly, and make myself sure of what's what.

That's all I have to say on that. I had better go put a warning on y/day's article to the effect that I might be talking ballocks. Well: more so than usual, I mean ;-)

--
Adam

Tuesday 28 May 2013

CFML: Application.cfc look-ups and linked directories

G'day:
This is a pretty non-descript topic / article, sorry. Someone raised a question on the Adobe ColdFusion forums about the possibility of CF10 not getting along well with Application.cfc look-ups from within a symlinked directory. I doubted this would be an issue, but I wasn't 100% sure so I thought I'd check it out.

Links / junctions
Before I start, just in case you're unsure about symlinks, here's what Wikipedia has to say about them. These are pretty prevalent on *nix systems, but they're under-utilised on Windows. Mostly because people are unaware they exist. Windows has actually been able to effect pretty much the same thing as a symbolic link since Windows 2000. Well: the Windows GUI shell couldn't, but the underlying NTFS file system has supported junction points since Windows 2000 came out. And a junction point amounts to the same thing.

Junction points are bloody handy. I have quite a number of CFML app servers running on this machine: CF5, CFMX7, CF8, CF9 (multiple instances), CF10 (multiple instances... Railo Express, some manner of OpenBD install (gathering dust)... and they all have their own discrete webroots for platform-specific stuff (eg: C:\webroots\cf5, C:\webroots\railo-express, etc). However I have a repository of all my common code @ C:\webroots\shared. Into each of my version-specific webroots I junction-in a reference to shared, so I have C:\webroot\cf10\shared etc. As far as CF10 is concerned, C:\webroot\cf10\shared is a discrete directory. And as far as Railo is concerned, C:\webroots\railo-express\shared is a discrete directory. But it's all the same place. Cool. I dunno how to create these things on *nix (something to do with ln comment), but , but on Windows it's just this:

C:\webroots\cf10> mklink /d shared c:\webroots\shared

Where obviously "shared" is what the junction ends up being called, and c:\webroots\shared is where it points to.

I've never had any problems with these on ColdFusion or Railo, and have been using them for a decade.

Anyway, that was a digression. Another side issue that came up from the original question is how does CF look for which Application.cfc (or .cfm in the case of the original question) to execute, for a given request. I'd forgotten that there were multiple "modes" for doing this settable in CFAdmin, and had never really paid much attention to them, so decided to roll both these concepts / questions into one investigation.

Firstly, lets look at the options on offer in CFAdmin:

As various people have blogged, docs on this setting are a bit thin on the ground, so I can reproduce it in its entirety without blowing out my word count:

Select the order in which ColdFusion searches for Application.cfm or Application.cfc if it is not found in the current project folder. You can set ColdFusion to search as follows:

  • default search order: ColdFusion looks for an Application.cfc/Application.cfm file from the current folder until the system root directory. On Windows, this could be C:\ and on UNIX, /opt.
  • till web root: ColdFusion looks for an Application.cfc/Application.cfm file from the current folder till web root.
  • in web root: ColdFusion looks for an Application.cfc/Application.cfm file in the current folder or web root.
And that's all there is to it. I think perhaps the guidance is wrong for *nix... surely / is the root, not /opt? I suppose it depends on permissions, but the same could be said for the /opt dir as well. And "till"? Sigh. But anyway. There's also another significant terminology error in there, but I'll get to that.

To demonstrate each of these, I have set up the following directory structure on my box:

C:\
  apps\
    adobe\
      ColdFusion\
        10\
          cfusion\
            wwwroot\
              docroot\
                test.cfm
                some_dir\
                  linked_subdir\
                    test.cfm
                  local_subdir\
                    test.cfm
  temp\
    linked_subdir\
      test.cfm

There are several significant elements to this:
  • The root
  • The ColdFusion instance directory
  • The ColdFusion app root - CF serves files from within here
  • The web root - the web server serves files from within here
  • A junction
  • The directory that is junctioned
  • Test files
In the table below, I highlight where ColdFusion will look for an Application.cfc or Application.cfm (it'll be one or the other, in that order of precedence, btw), given the specified file being requested.

Saturday 20 April 2013

It's easy to create a security hole in your application with onCfcRequest()

G'day:
Man... PHP continues to take a back seat with me, as interesting ColdFusion stuff keeps cropping up. Well: my definition of "interesting", anyhow.

Today on Stackoverflow I was reminded of a potential "gotcha" that onCfcRequest() brings to the table. One that has bitten me on the bum in the past, has done so with the person on S/O too, and has probably bitten other people too. And the "gotcha" creates quite a gaping security hole in the application if one doesn't deal with it.


I've not seen much coverage of this, so I'll detail it here.

First some background.

When Application.cfc was implemented back in CFMX7 (?), one of the methods added was a request interceptor, onRequest(). Instead of the requested file being run, onRequest() was run instead. This gives one's application a chance to do [something] regarding the requested template before, after and/or instead of running the template. An example would be this:

// Application.cfc
component {

    public void function onRequest(required string requestedFile){
        writelog(file="requests",text=arguments.requestedFile);
        if (arguments.requestedFile does not contain "restricted"){
            include arguments.requestedFile;
            writelog(file="requests", text="#arguments.requestedFile# Completed OK");
        }else{
            writelog(file="requests", text="#arguments.requestedFile# Blocked", type="warning");
            throw(type="InvalidFileException");
        }
    }
    
}

<!---publicFile.cfm --->
This is the public file

<!--- restrictedFile.cfm --->
Should not be able to access this!

If I browse to each of publicFile.cfm and restrictedFile.cfm, I get the expected results on the screen, and this in the log:

/shared/git/blogExamples/onRequest/publicFile.cfm
/shared/git/blogExamples/onRequest/publicFile.cfm Completed OK
/shared/git/blogExamples/onRequest/restrictedFile.cfm
/shared/git/blogExamples/onRequest/restrictedFile.cfm Blocked

So that's quite cool.

However note how the requested file is included. This approach won't be suitable for remote method requests, so for those, there is a method onCfcRequest(). This works the same way, but invokes the CFC & method, passing in the specified arguments:

public any function onCfcRequest(required string cfc, required string method, required struct args){
    return invoke(cfc, method, args);
}

(Obviously the same logic as per the onRequest() method could be used here too, but I've omitted it for the sake af clarity).

OK, great. What's the problem?

Well consider this CFC:

component {

    remote string function remoteMethod(){
        return "From remoteMethod()";
    }

    public string function publicMethod(){
        return "From publicMethod()";
    }

    package string function packageMethod(){
        return "From packageMethod()";
    }

    private string function privateMethod(){
        return "From rivateMethod()";
    }

}

Which methods are intended to be called here? Just the remote one. But here's the thing... a method call is only "remote" if it's being called from outwith the application. And when using onCfcRequest(), where is the method actually being called from? From this statement:

return invoke(cfc, method, args);

Which is inside the application. It's not registered as a remote call, because it's not being called remotely! This means that as well as all remote methods, one can also actually access all public methods too (package and private ones are still secure). This is something people don't necessarily realise, so one might inadvertently expose a helluva lot more of one's API than is the intent. YIKES.

So what's the mitigation here? Well one needs to do something similar to the logic we employed in onRequest() to block restricted files, but the problem is tricky to work around than that. One needs to do this:

public any function onCfcRequest(required string cfc, required string method, required struct args){
    var o = createObject(arguments.cfc);
    var metadata = getMetadata(o[method]); 
    
    if (structKeyExists(metadata, "access") && metadata.access == "remote"){
        return invoke(o, method, args);
    }else{
        throw(type="InvalidMethodException", message="Invalid method called", detail="The method #method# does not exists or is inaccessible remotely");
    }
}

Basically one needs to look at the object's metadata and check to see if the method being called is remote. If so: all good; if not: block it.

So make sure you do this in your onCfcRequest(). Otherwise you could be leaving yourself a bit open.

--
Adam

Thursday 11 April 2013

onApplicationEnd() usage survey results

G'day:
I've had a reasonable number of results on my survey asking whether or not you use onApplicationEnd(), and if so: how so. It's telling a predictable story: the answer is "no, not really".

I've had 42 responses, and 38 of them are "no".


Four were "yes", with the following comments:

Current application uses onApplicationEnd to write to a log file that the application has shut down.

for some projects I work on we have to do audit records almost everything. So that's one of the things that's triggered on Applicationend. Other stuff I've used it for was for general cleanup of data.

I've used this to clear a shopping cart for a reservation app. I'm not convinced it was the best solution. I also used it for a large streaming app with thousands of users to save the last channel they were listening to when their app timed out. So at their next login it remembered. It does delete the structures & I had a lot of issues with blowing up memory with session variables.

Record page views for cart tracking / checkout progress.
I think the logging situations make sense, although perhaps it would be more robust to put it in onApplicationStart(), because an application will always start, but it might not end: for example if the box itself crashes, or the JVM gets tangled-up (sorry about the technical jargon there). So there's a chance of missing some metrics doing it at the end. I understand, though, in an auditing situation "what makes best sense" is not necessarily one of the requirements. And also there's merit to be had in a "belt 'n' braces" approach.

I'm not sure about the shopping cart ones. Aren't shopping carts generally session-centric, not app centric? Also an application can time out without a session timing out. If the application times out and restarts, it will re-acquire any sessions that were still around when it timed out. Obviously it'd be unusual in the normal sequence of events for the application to time out before its sessions, but it's possible if say one calls applicationStop().

Still: I will not base any sort of judgement from a quick comment in a survey, obviously I know stuff-all about the environments / codebases in question.

There were a coupla good comments on the survey article too:

Abram Adams said:
I've never used onApplicationEnd (and indicated so in the survey), but that got me thinking of what I could use it for. Perhaps as a mechanism to keep an application alive and fresh? One of our larger projects uses a custom framework that does some data/object caching, etc... The first request (if app has expired) can take around 5-10 seconds to complete while subsequent requests take <1-2 seconds. Perhaps I could hook into the onAppEnd and re-init the framework so that it doesn't become stagnant, but is always ready...

I've prototyped the idea in my dev environment and it does seems to work nicely, though there may be hidden gotchas that I'm not aware of. Any thoughts to that approach?

And Jose Galdamez said:
I've rarely had a need for OnApplicationEnd. The server should be handling garbage collection of application-scoped variables, so one shouldn't have to write that sort of logic. When I see OnApplicationEnd in lessons I usually see examples where applications log information such as the date/time when it ended. Personally, I can't think of anything useful to log when the application ends. If you really want to keep track of the application lifecycle you could always log that within OnApplicationStart and leave it at that. I'm curious to see what people say in your survey!

Both good observations.

I think with the application timeout thing - I've had similar thoughts in the past - the easiest way to mitigate it is to have a really long application timeout. This removes the issue. Bear in mind that by the time onApplicationEnd() runs, the application has already timed out, so I think if one is after continuity, then making sure it never times out, rather than re-init-ing it if it does time out is a better approach.

Also if an application must be up, then there should be some sort of "are you up?" check going on to alert [someone] if the answer is "no". And the act of asking the question will reset the time out timer anyhow.

Unfortunately there were no responses with some really excellent thing we can all take away thinking "hey, that's cool". But I think we all probably suspected that would be the case anyhow.

Thanks for filling out the survey, to all those that did.

Righto.

--
Adam

Tuesday 9 April 2013

CFML: Quick survey: do you actually use onApplicationEnd()?

G'day:
I'm in rapid fire mode today.

When talking about all this onApplicationEnd() stuff recently, Bruce asked a good question: what does one use it for? I mean in real life? Well: I don't.

Do you? If you do, and fancy sharing, pls fill out this survey. It's one question: just a bit of typing.

Update:
The survey is closed. The results are here.

NB: as Sean has just pointed out... my wording was slightly vague before, but I'm also keen on you answering even if you don't use onApplicationEnd(). There's a "no" option in there too. It'll be good to see the split of do/don't use it.

I'll report back with what people say when when the frequency of submissions flattens out.

Cheers.

--
Adam

CFML: Preventing onApplicationStart from kicking off whilst onApplicationEnd is still running

G'day:
This is a follow-up from yesterday's article discussing that onApplicationStart() will run quite happily whilst onApplicationEnd() is still working. The person on Stackoverflow - rhinds -  was trying to use locking to force the processes to queue-up, but was having issues. I volunteered to look into it further. And I have.


Here's a rough facsimile of what I was expecting the person was trying to do:

// Application.cfc
component {

    this.name = "lockApplicationScope4";
    this.applicationTimeout        = createTimespan(0,0,2,0);
    variables.sleepDuration        = 3000;
    sleep(variables.sleepDuration);


    function onApplicationStart(){
        logIt("Begin onApplicationStart()");
        logIt("Before lock onApplicationStart()");
        lock scope="application" type="exclusive" timeout=variables.sleepDuration/100 {
            logIt("Top of lock onApplicationStart()");
            sleep(variables.sleepDuration);
            logIt("Mid onApplicationStart()");
            sleep(variables.sleepDuration);
            logIt("Bottom of lock onApplicationStart()");
        }
        logIt("After lock onApplicationStart()");
        logIt("End onApplicationStart()");
    }

    function onRequestStart(){
        logIt("Begin onRequestStart()");
    }

    function onRequest(){
        include arguments[1];
    }

    function onRequestEnd(){
        sleep(variables.sleepDuration);
        logIt("End onRequestEnd()");
    }

    function onApplicationEnd(){
        logIt("Begin onApplicationEnd()");
        logIt("Before lock onApplicationEnd()");

        lock scope="application" type="exclusive" timeout=variables.sleepDuration/100 {
            logIt("Top of lock onApplicationEnd()");
            sleep(variables.sleepDuration * 3); // need some time to react
            logIt("Mid onApplicationEnd()");
            sleep(variables.sleepDuration * 3); // need some time to react
            logIt("Bottom of lock onApplicationEnd()");
        }
        logIt("End onApplicationEnd()");
    }
    
    function logIt(required String message){
        writeLog(file=this.name, text="#message# from @ #listLast(CGI.script_name, '/\')#");
    }

}

A lot of that is just telemetry-gathering so I can watch what's happening as it happens. The key bits are highlighted: I'm putting an exclusive application-scope lock on the code in onApplicationStart() and onApplicationEnd() so that the two won't run simultaneously.

My test code was much the same as yesterday:

<!--- normalRequest.cfm --->
<cfset logIt("Start requested template")>
<cfoutput>#now()#</cfoutput>

<!--- shutdownRequest.cfm --->
<cfset logIt("Start requested template")>
<cfoutput>#now()#</cfoutput>
<cfset applicationStop()>
<cfset logIt("End requested template")>

The test is run as follows:
  • hit normalRequest.cfm to "warm" the application. I let this run to conclusion.
  • Hit shutdownRequest.cfm, and after a few seconds whilst it's still running...
  • hit normalRequest.cfm again.
What happens here is that normalRequest.cfm will start the application up; then the call to shutdownRequest.cfm will call applicationStop() to commence application shutdown, but whilst that's happening, a concurrent call to normalRequest.cfm comes in and commences application startup again. Yesterday we saw that onApplicationStart() will start running whilst onApplicationEnd() is still running, which could cause "unexpected results". We're trying to mitigate this.

Here's the log from a test run:

Begin onApplicationStart() from @ normalRequest.cfm
Before lock onApplicationStart() from @ normalRequest.cfm
Top of lock onApplicationStart() from @ normalRequest.cfm
Mid onApplicationStart() from @ normalRequest.cfm
Bottom of lock onApplicationStart() from @ normalRequest.cfm
After lock onApplicationStart() from @ normalRequest.cfm
End onApplicationStart() from @ normalRequest.cfm
Begin onRequestStart() from @ normalRequest.cfm
Start requested template from @ normalRequest.cfm
End onRequestEnd() from @ normalRequest.cfm

Begin onRequestStart() from @ shutdownRequest.cfm
Start requested template from @ shutdownRequest.cfm
Begin onApplicationEnd() from @ shutdownRequest.cfm
Before lock onApplicationEnd() from @ shutdownRequest.cfm

End requested template from @ shutdownRequest.cfm
Begin onApplicationStart() from @ normalRequest.cfm
Before lock onApplicationStart() from @ normalRequest.cfm
Top of lock onApplicationStart() from @ normalRequest.cfm

End onRequestEnd() from @ shutdownRequest.cfm
Mid onApplicationStart() from @ normalRequest.cfm
Bottom of lock onApplicationStart() from @ normalRequest.cfm
After lock onApplicationStart() from @ normalRequest.cfm
End onApplicationStart() from @ normalRequest.cfm
Begin onRequestStart() from @ normalRequest.cfm
Start requested template from @ normalRequest.cfm
End onRequestEnd() from @ normalRequest.cfm


Something's up here. onApplicationEnd() is never getting into the lock. It looked to me like it was erroring but there was nothing in the log.

So I hastily changed onApplicationEnd() to do my own logging:

function onApplicationEnd(){
    logIt("Begin onApplicationEnd()");
    logIt("Before lock onApplicationEnd()");
    try {
        lock scope="application" type="exclusive" timeout=variables.sleepDuration/100 {
            logIt("Top of lock onApplicationEnd()");
            sleep(variables.sleepDuration * 3); // need some time to react
            logIt("Mid onApplicationEnd()");
            sleep(variables.sleepDuration * 3); // need some time to react
            logIt("Bottom of lock onApplicationEnd()");
        }
    }
    catch (any e){
        logIt("Exception in onApplicationEnd(): #e.message# #e.detail#");
    }
    logIt("End onApplicationEnd()");
}

And repeating the experiment, we see this (just the relevant bit):

Begin onApplicationEnd() from @ shutdownRequest.cfm
Before lock onApplicationEnd() from @ shutdownRequest.cfm
Exception in onApplicationEnd(): Cannot lock application scope. Cannot use cflock to lock the application or session shared scopes without these scopes  using the cfapplication tag. To use the session  scope, you must enable session management. Application and/or Session variables  must also be enabled in the ColdFusion Administrator. from @ shutdownRequest.cfm
End onApplicationEnd() from @ shutdownRequest.cfm

So that explains that, and it kinda makes sense. Bear in mind that this is running in onApplicationEnd(), so the application scope is gone by the time this code runs.

So to do what rhinds wanted to effect, instead of using a scope lock, we can use a named lock quite safely here. IE:

function onApplicationStart(){
    logIt("Begin onApplicationStart()");
    logIt("Before lock onApplicationStart()");
    lock name="applicationEventHandlers" type="exclusive" timeout=variables.sleepDuration/100 {
        logIt("Top of lock onApplicationStart()");
        sleep(variables.sleepDuration);
        logIt("Mid onApplicationStart()");
        sleep(variables.sleepDuration);
        logIt("Bottom of lock onApplicationStart()");
    }
    logIt("After lock onApplicationStart()");
    logIt("End onApplicationStart()");
}

// ...

function onApplicationEnd(){
    logIt("Begin onApplicationEnd()");
    logIt("Before lock onApplicationEnd()");
    try {
        lock name="applicationEventHandlers" type="exclusive" timeout=variables.sleepDuration/100 {
            logIt("Top of lock onApplicationEnd()");
            sleep(variables.sleepDuration * 3); // need some time to react
            logIt("Mid onApplicationEnd()");
            sleep(variables.sleepDuration * 3); // need some time to react
            logIt("Bottom of lock onApplicationEnd()");
        }
    }
    catch (any e){
        logIt("Exception in onApplicationEnd(): #e.message# #e.detail#");
    }
    logIt("End onApplicationEnd()");
}

And now, running this, we get what we want:

Begin onRequestStart() from @ shutdownRequest.cfm
Start requested template from @ shutdownRequest.cfm
Begin onApplicationEnd() from @ shutdownRequest.cfm
Before lock onApplicationEnd() from @ shutdownRequest.cfm
Top of lock onApplicationEnd() from @ shutdownRequest.cfm
Begin onApplicationStart() from @ normalRequest.cfm
Before lock onApplicationStart() from @ normalRequest.cfm

Mid onApplicationEnd() from @ shutdownRequest.cfm
Bottom of lock onApplicationEnd() from @ shutdownRequest.cfm

End onApplicationEnd() from @ shutdownRequest.cfm
Top of lock onApplicationStart() from @ normalRequest.cfm

End requested template from @ shutdownRequest.cfm
End onRequestEnd() from @ shutdownRequest.cfm
Mid onApplicationStart() from @ normalRequest.cfm
Bottom of lock onApplicationStart() from @ normalRequest.cfm

After lock onApplicationStart() from @ normalRequest.cfm
End onApplicationStart() from @ normalRequest.cfm
Begin onRequestStart() from @ normalRequest.cfm
Start requested template from @ normalRequest.cfm
End onRequestEnd() from @ normalRequest.cfm

This was hard to colour-code sensibly but the green is the shutdown request, and the orange the following "restart" request. Within that, we can see the red text shows all the internals of onApplicationEnd() being run before the blue text that is onApplicationStart(). it all runs in series, so that's the result we want. Sorted.

So the work-around for this issue with onApplicationStart() and onApplicationEnd() running concurrently is to use a named lock.


Oh. And why did the error that we got when trying to lock the application scope in onApplicationEnd() not show up in the error log? because of this: 3041747. I even knew about that. It'd slipped my mind though. It'd be nice if Adobe - who apparently "didn't have time" to fix it - cracked on and found the time to sort that out.

--
Adam

Monday 8 April 2013

CFML: onApplicationStart will run whilst onApplicationEnd is still underway

G'day:
This is another article which comes on the back of research stemming from not knowing the answer to a Stackoverflow question. In this case the questioner had noticed that onApplicationStart() seems to re-run (so the application is restarting) whilst onApplicationEnd() from a previous application shutdown is still underway.


I figured this would be unfortunately if this was true, so decided to find out.

I knocked out this code:

// Application.cfc
component {

    this.name = "shutdownSequenceTest12";
    logIt("Begin Pseudoconstructor");
    this.applicationTimeout        = createTimespan(0,0,2,0);
    variables.sleepDuration        = 3000;
    sleep(variables.sleepDuration);
    logIt("End Pseudoconstructor");


    function onApplicationStart(){
        logIt("Begin onApplicationStart()");
        sleep(variables.sleepDuration);
        logIt("Mid onApplicationStart()");
        sleep(variables.sleepDuration);
        logIt("End onApplicationStart()");
    }

    function onRequestStart(){
        logIt("Begin onRequestStart()");
    }

    function onRequest(){
        include arguments[1];
    }

    function onRequestEnd(){
        sleep(variables.sleepDuration);
        logIt("End onRequestEnd()");
    }

    function onApplicationEnd(){
        logIt("Begin onApplicationEnd()");
        sleep(variables.sleepDuration * 3); // need some time to react
        logIt("Mid onApplicationEnd()");
        sleep(variables.sleepDuration * 3); // need some time to react
        logIt("End onApplicationEnd()");
    }
    
    function logIt(required String message){
        writeLog(file=this.name, text="#message# from @ #listLast(CGI.script_name, '/\')#");
    }

}

This basically emulates an app that takes some time to execute its various stages, so I can interleave requests and see how they run.

I then created two CFM templates:

<!--- normalRequest.cfm --->
<cfset logIt("Start requested template")>
<cfoutput>#now()#</cfoutput>

<!--- shutdownRequest.cfm --->
<cfset logIt("Start requested template")>
<cfoutput>#now()#</cfoutput>
<cfset applicationStop()>
<cfset logIt("End requested template")>

I use the former to "warm" the application, then use the latter to shut it down. Whilst the shutdown is in progress, I re-run the normalRequest.cfm, to see what happens.

Here's the resultant log file:

Begin Pseudoconstructor from @ normalRequest.cfm
End Pseudoconstructor from @ normalRequest.cfm
Begin onApplicationStart() from @ normalRequest.cfm
Mid onApplicationStart() from @ normalRequest.cfm
End onApplicationStart() from @ normalRequest.cfm
Begin onRequestStart() from @ normalRequest.cfm
Start requested template from @ normalRequest.cfm
End onRequestEnd() from @ normalRequest.cfm

Begin Pseudoconstructor from @ shutdownRequest.cfm
End Pseudoconstructor from @ shutdownRequest.cfm
Begin onRequestStart() from @ shutdownRequest.cfm
Start requested template from @ shutdownRequest.cfm
Begin onApplicationEnd() from @ shutdownRequest.cfm

Begin Pseudoconstructor from @ normalRequest.cfm
End Pseudoconstructor from @ normalRequest.cfm
Begin onApplicationStart() from @ normalRequest.cfm
Mid onApplicationStart() from @ normalRequest.cfm

Mid onApplicationEnd() from @ shutdownRequest.cfm
End onApplicationStart() from @ normalRequest.cfm
Begin onRequestStart() from @ normalRequest.cfm
Start requested template from @ normalRequest.cfm
End onRequestEnd() from @ normalRequest.cfm

End onApplicationEnd() from @ shutdownRequest.cfm
End requested template from @ shutdownRequest.cfm
End onRequestEnd() from @ shutdownRequest.cfm



Here the initial warming request is greyed out.

The next request is me requesting a shutdown, and whilst that's still running, I perform another normal request, which commences the application starting again. However the application is still in the process of being shut down from last time. Note that the stop/start event handler processing are intertwined there: the re-start actually finishes before the shutdown of the previous application is complete.

I think this is something to be aware of, and it makes a kind of sense.

Bear in mind that onApplicationStart() and onApplication() end are event handlers, not the events themselves. They do not represent the application starting or the application stopping, they are simply something that ColdFusion will fire off for us when it handles the start/stop process.

So if we were being dogmatic about things, then this is correct behaviour. However in reality, I think it's legitimate for a running onApplicationStop() process should block the next onApplicationStart() process, just like one won't get two almost concurrent requests both trying to run onApplicationStart() each: only the first one runs it, and the second one waits until the first one is done before proceeding (and by then the application is started, so that second request doesn't even try to run onApplicationStart() itself). I think there's a good case for onApplicationStop() to be synchronised with onApplicationStart().

I have not run this on Railo yet, but I will after I walk down to the park to get some coffee.

Thoughts?

Update: I've written a follow-up to this article, which shows how to resolve this issue.

--
Adam

Saturday 3 November 2012

CFML: Application.cfc-set mappings don't work in onApplicationEnd

G'day:
Well this was not what I was intending to be looking at this evening, but I made the mistake of  looking at StackOverflow and didn't understand what I was reading about mappings and onSessionEnd and ColdFusion 8, so looked into it.


I don't really care about quirks of CF8: the boat's pretty much sailed on any problems anyone finds with that.  However I wanted to make sure it wasn't still happening in CF9 or CF10.

The original problem is that ColdFusion mappings that are set in Application.cfc don't seem to exist by the time onSessionEnd() runs (this is on ColdFusion 8).  Here's some test code and the results:

<cfcomponent output="true">
    
    <cfset this.name = "testMappings">
    <cfset this.sessionManagement = true>
    <cfset this.applicationTimeout    = createTimespan(0,0,0,20)>
    <cfset this.sessionTimeout        = createTimespan(0,0,0,10)>
    
    <cfset this.mappings = structNew()>
    <cfset this.mappings["/test"] = "C:\temp">
    
    <cfset testExpandPath("Pseudoconstructor")>
    
    <cffunction name="onApplicationStart" returnType="boolean" output="true">
        <cfset testExpandPath("onApplicationStart")>
        <cfreturn true>
    </cffunction>

    <cffunction name="onApplicationEnd" returnType="void" output="true">
        <cfargument name="applicationScope" required="true">
        <cfset testExpandPath("onApplicationEnd")>
    </cffunction>
    
    <cffunction name="onRequestStart" returnType="boolean" output="true">
        <cfargument name="thePage" type="string" required="true">
        <cfset testExpandPath("onRequestStart")>
        <cfreturn true>
    </cffunction>

    <cffunction name="onRequest" returnType="void">
        <cfargument name="thePage" type="string" required="true">
        <cfset testExpandPath("onRequest")>
        <cfinclude template="#arguments.thePage#">
    </cffunction>

    <cffunction name="onRequestEnd" returnType="void" output="true">
        <cfargument name="thePage" type="string" required="true">
        <cfset testExpandPath("onRequestEnd")>
    </cffunction>

    <cffunction name="onSessionStart" returnType="void" output="true">
        <cfset testExpandPath("onSessionStart")>
    </cffunction>

    <cffunction name="onSessionEnd" returnType="void" output="true">
        <cfargument name="sessionScope" type="struct" required="true">
        <cfargument name="appScope" type="struct" required="false">
        <cfset testExpandPath("onSessionEnd")>
    </cffunction>


    <cffunction name="testExpandPath" returntype="void" access="public" output="true">
        <cfargument name="message" required="true" type="string">

        <cfset var path  = expandPath("/test")>
        <cfset var fullMessage = "#message#: #path#">
        <cfoutput>#fullMessage#<br /></cfoutput>
        <cflog file="testMappings" text="#fullMessage#">
    </cffunction>

</cfcomponent>

Pseudoconstructor: C:\apps\adobe\ColdFusion\8\instances\CF801\cfusion.ear\cfusion.war\test
onApplicationStart: C:\temp
onSessionStart: C:\temp
onRequestStart: C:\temp
onRequest: C:\temp
test.cfm: C:\temp
onRequestEnd: C:\temp
onSessionEnd: C:\apps\adobe\ColdFusion\8\instances\CF801\cfusion.ear\cfusion.war\test
onApplicationEnd: C:\apps\adobe\ColdFusion\8\instances\CF801\cfusion.ear\cfusion.war\test

Firstly, it's completely legit that the mapping doesn't work in the pseudoconstructor.  See my article on how the settings set in the this scope work if you're not sure why.

However to me it's a bug that they aren't still around in onSessionEnd() and onApplicationEnd().  Someone at Adobe clearly thinks so too, as the behaviour has been modified (partially) in CF9:

Pseudoconstructor: C:\webroots\CF902\test
onApplicationStart: C:\temp
onSessionStart: C:\temp
onRequestStart: C:\temp
onRequest: C:\temp
test.cfm: C:\temp
onRequestEnd: C:\temp
onSessionEnd: C:\temp
onApplicationEnd: C:\webroots\CF902\test

onSessionEnd() has been fixed, but not onApplicationEnd().  You'd think that if someone took the time to fix one of these, they might check the other one too eh?  Apparently not.

It's the same behaviour in ColdFusion 10.  But Railo (4.0.013) works fine: the mapping is still available in onApplicationEnd().

I've raised a bug for this: 3358817.

The work around - such as it is - for this is to set the mappings in CFAdmin: then they work fine.  Not much of a work around, but it might help some people.

Righto.

--
Adam

Thursday 11 October 2012

CFML: Clarification (in my mind) as to how this.[various settings] work in Application.cfc

G'day:
This might be another one of those "Adam states the obvious" articles. Sorry, but I freely admit two things:
  1. not to know everything already;
  2. to be a bit slow on the uptake sometimes.
So if you fall into those categories too, then maybe this will be worthwhile to read. Apologies to the rest of you.


One of the good things about helping out out on various ColdFusion forums is that the problems people have are not necessarily based on things I find myself doing on a regular basis, so encourages me to consider different approaches to things, and to think outside my own personal box. And this means I broaden my exposure to various facets of ColdFusion that I might not normally be exposed to. I would say I've learned more about CF by helping people solve their challenges than I have from my day-to-day work or any amount of reading blogs or articles detailing other people's investigations. That's not to say you should immediately stop reading... hey... aah... come back!

Ahem. Anyway.

Yesterday a person with the rather interesting name of Aegis Kleais was having a challenge with application-specific custom tag paths. The full thread is here, but it's long and drawn out, so I'll summarise it all below to save you... um... clicking on a link and reading the original.

Oh, before I start, I'd like to personally acknowledge Jason Dean's help and persistence on the forums. Jason's one of the more-clued-up ColdFusion community members out there, so it's an excellent asset to Adobe's forums that he mans-the-pumps there (as it were). I also like Jason's style because - and he might disagree with me here - he can be almost as grumpy as I tend to be, and doesn't shy away from having and expressing a strong opinion when he has one.  Cheers Jason.

Right, what was Aegis asking about?

Aegis (I'm gonna steer clear of personal pronouns unless I get the wrong gender...) was investigating the usage of per-application custom tag paths.  Just some background here.  In the olden days (like up to and including CFMX7 I think) the only place one could set a custom tag path was in CFAdmin, which is a server-wide setting.  These days they're settable in Application.cfc, with the this.customTagPaths setting.  Aegis was leveraging this application-specific approach and had mapped a directory, then called a custom tag on a subsequent line of Application.cfc.  But it was erroring: it just wasn't finding the custom tag file.  If the tag was placed in the same directory as Application.cfc, it ran fine. If the tag call was placed in one of the event handlers within (eg: onApplicationStart() or onRequestStart()), it worked fine.  So it wasn't a syntax or pathing issue.  Weird.  I verified this behaviour on CF8->CF10, and Railo too.

This initially flumoxed me, and I was about to suggest it was a bug when something occurred to me, and I had a watershed moment when I suddenly worked out how Application.cfc works in regards to all those this-scoped settings we use.

I thought about any other code I might run:

component {
    this.foo = "bar";
    
    // other stuff here
    
}

That code sets a variable, this.foo.  That's all it does: sets a variable.  No other action takes place.  I might subsequently do something with that variable that makes excellent stuff happen, but that's not what's happening there.

So what's this code doing:

component {

    this.name            = "myApplicationName";
    this.customTagPaths    = "/path/to/the/custom/tags/";

    public void function onApplicationStart(){
        // stuff
    }
    
    // etc

}

We all recognise this as an Application.cfc file, but it's still just some CFML code, so what is this line of code doing:

    this.customTagPaths    = "/path/to/the/custom/tags/";

It's setting a variable.  That's all it's doing.  It does not say this:

    setCustomTagPaths("/path/to/the/custom/tags/");

If it was saying that, we could reasonably conclude that subsequent to that line of code any custom tag calls would find tags in  /path/to/the/custom/tags/.

But all it's doing is setting a variable.

So I found myself thinking, "OK, what's going on then?  How does this all work?"

It occurred to me that it seems like - under the hood - the ColdFusion server is doing this (pseudocode):

appSettingAndHandlers = new Application() // ie: instantiating Application.cfc

theApp.setName(appSettingAndHandlers.name) // because name was set as this.name, it's exposed as a public variable
theApp.setCustomTagPaths(appSettingAndHandlers.customTagPaths) // use the exposed value for customTagPaths to actually make the custom tag paths
//etc

if not theApp.started() then
    theApp.start()
    appSettingAndHandlers.onApplicationStart()
/if
// etc

So what happens is - the same as any other CFC instantiation - the "calling code" (which is within the inner workings of the ColdFusion server) instantiates Application.cfc, which causes all the pseudo-constructor code to run, and then it accesses the settings created in that code to perform various other actions / config / settings etc.  But the crux is that just like when we instantiate a CFC then use it, all the pseudo-constructor code completes before anything is done with the values. This makes sense. Doesn't it?

This actually explains a situation  had in the past wherein I was creating an application-specific mapping with this.mappings, then trying to use a path leveraging that mapping in my ormSettings.cfcLocation value.  And for the same reasons, this did not work.

Anyway, with a combination of Aegis's own investigations, and guidance from Jason any myself,the problem was sorted out.  And I now know something new.

Cool.

--
Adam

Wednesday 19 September 2012

CFML:Curious behaviour with THIS-scoped variables in onSessionEnd and onApplicationEnd

G'day
This article stems from a question that came up on StackOverflow today. In summary the bod wanted to know if they could set this.datasource conditionally on a CGI variable, and I confirmed they could, eg:
  • if the cgi.server_name equals "www.firsturl.com" => this.datasource = "firstdsn"
  • if the cgi.server_name equals "www.secondurl.com" => this.datasource = "seconddsn"
My initial response (beyond "just try it and see") was to confirm it was possible.


Someone (called "nosilleg") followed my answer up with  a warning that there could be unexpected results if onSessionEnd (etc) was to use the this.datasource value, as the CGI scope wouldn't be there, so which DSN would be used?  Good question!

To clarify... normal requests all instantiate Application.cfc, and run the pseudo-constructor code to create all the this-scoped config variables, and the CGI variables will all be there so logic predicated on them will work: that's fine.  But things like onSessionEnd() and onApplicationEnd() do not run via a request, per-se, so they won't have any CGI variables.  So what will happen?

This was - of course - my cue to slap together some test code and log stuff and run requests and all that sort of malarky, and now you have to endure reading about my findings.  Well don't say you weren't warned.

So I knocked some code together to test this:


And had a test file to request, thus:


<cfdump var="#this#">

The idea here is that I have DSN1 and DSN2 set up pointing to two different DBs, both of which have identical T_TEST tables to write data to.  Conditional on whether I request test.cfm via localhost or testing.local (both point to the same CF instance) I set this.datasource to point to one or the other (via checking CGI.SERVER_NAME).  If CGI.SERVER_NAME is neither of those, they get nowt.

What I was expecting here was for the onSessionEnd() and onApplicationEnd() to error.  I was not correct.  Well I was a bit correct.  But there is definitely fishy behaviour here.

My log file says this:

Start of logIt(). onApplicationStart [localhost] [dsn1]
End of logIt(). onApplicationStart [localhost] [dsn1]
Start of logIt(). onSessionStart [localhost] [dsn1]
End of logIt(). onSessionStart [localhost] [dsn1]
Start of logIt(). onRequestStart [localhost] [dsn1]
End of logIt(). onRequestStart [localhost] [dsn1]
Start of logIt(). onSessionStart [testing.local] [dsn2]
End of logIt(). onSessionStart [testing.local] [dsn2]
Start of logIt(). onRequestStart [testing.local] [dsn2]
End of logIt(). onRequestStart [testing.local] [dsn2]
Start of logIt(). onRequestStart [localhost] [dsn1]
End of logIt(). onRequestStart [localhost] [dsn1]
Start of logIt(). onSessionEnd [none] [dsn1]
End of logIt(). onSessionEnd [none] [dsn1]
Start of logIt(). onSessionEnd [none] [dsn1]
End of logIt(). onSessionEnd [none] [dsn1]
Start of logIt(). onApplicationEnd [none] [dsn1]
CATCH in logIt(). onApplicationEnd [none] [dsn1] [Attribute validation error for tag CFQUERY.] [The value of the attribute datasource, which is currently '', is invalid.]


I've truncated it, but the "proper" request's log entries were made by "catalina-exec-nn" when nn was a number, whereas the onSessionEnd() and onApplicationEnd() entries were made by "scheduler-n" (where n was a number).  This demonstrates the difference between a normal request running and CF doing its own thing in the background to tidy-up sessions and applications.


Note that neither onSessionEnd() or onApplicationEnd() see a CGI.server_name value.  This is no surprise. However what appears to happen is - by magic, it seems - the onSessionEnd() and onApplicationEnd() calls both receive the last value that this.datasource was set to be via a legit "request".  I verified this through more testing I'll not bore you with, but it was always the DSN of the previous request that these handlers used.  However - rather weirdly - despite onApplicationEnd() definitely seeing this.datasource, the <cfquery> tag in Query.cfc did not think it had a default datasource set.  That's an interesting disconnect, isn't it?  Especially given it seems like onSessionEnd() is in the same boat, but its query worked fine.  Oh, I should have said: data when into the DB tables exactly as one would expect, given the DSN setting (other than the error in onApplicationEnd(), I mean).

If I can be bothered (currently: no) I will refactor the Application.cfc to be tag-based so I can use <cfquery> instead, and see what happens.

Anyway, the bottom line here is that nosilleg was right to be cautious here.  However in situations wherein one doesn't need to use the DSN in the tidy-up handlers, the technique works fine.  I'll feed this back to StackOverflow.

And that's it.

--
Adam

Wednesday 15 August 2012

CFML: More on Application.cfc... when things run

G'day
This one stemmed from me trying to come up with an accurate answer to someone's question on StackOverflow.  To summarise, the question was about what order things run in, what scopes come into play when, and all that sort of thing.  Stuff I imagine most of us pretty much know, but perhaps don't completely know the boundaries of the edgecases.  Certainly I sat down at the keyboard, drew myself up in an all-knowing sort of way ready to type the model answer, before thinking... "you know what?  I don't actually know for sure".  And when I answer stuff on forums, I like to be like 99% confident I'm right.  Not for my sake, but because I don't like wasting people's time by giving inaccurate answers.  And a bit for my own sake ;-)


Anyway, I voted-down the two answers that were there when I first read the question, because I thought they were - on balance - inaccurate.  Both had elements of correctness about them, but they both had blatant inaccuracies about them too (ie: they stated things that were outright wrong).  But I figured if I was voting stuff down, I had better come back with the goods.
Speaking of StackOverflow... here's an aside.  If you are reading this and you don't already help out on StackOverflow and - more importantly - the Adobe ColdFusion forums, please consider donating some of your time to helping the ColdFusion community.  There are a lot of people asking questions out there, and not enough people to answer them.  We could use your help.
But anyway... that's not the topic of my wittering for the day.
Application.cfc.

So, yeah, it occurred to me I didn't actually 100% know when various scopes became available, and what was available where, and that sort of thing.  I also saw it as low-hanging-fruit for a blog entry, so here I am now.

I knocked together a quick Application.cfc, which logged what it was up to and when:


The logic at play in this is repetitive: at each step of the Application.cfc I test various scopes that might exist, report if they do exist, and attempt to create a variable in them.  Then as processing continues through various event handlers, I keep track of what exists and where.

The log file created is as follows (this is a bit longwinded... scroll down rather than read it all. I've highlighted the important bits):

1 in pseudoconstructor before application name is set application scope not enabled
1 in pseudoconstructor before application name is set session scope not enabled
1 in pseudoconstructor before application name is set request.pseudoconstructor initialised
1 in pseudoconstructor before application name is set this.pseudoconstructor initialised
==================================================
1 in pseudoconstructor after application name is set application scope not enabled
1 in pseudoconstructor after application name is set session scope not enabled
1 in pseudoconstructor after application name is set request.pseudoconstructor existed
1 in pseudoconstructor after application name is set this.pseudoconstructor existed
==================================================
1 in onApplicationStart application.pseudoconstructor initialised
1 in onApplicationStart session scope not enabled
1 in onApplicationStart request.pseudoconstructor existed
1 in onApplicationStart this.pseudoconstructor existed
==================================================
1 in onApplicationStart application.onApplicationStart initialised
1 in onApplicationStart session scope not enabled
1 in onApplicationStart request.onApplicationStart initialised
1 in onApplicationStart this.onApplicationStart existed
==================================================
1 in onSessionStart application.pseudoconstructor existed
1 in onSessionStart session.pseudoconstructor initialised
1 in onSessionStart request.pseudoconstructor existed
1 in onSessionStart this.pseudoconstructor existed
==================================================
1 in onSessionStart application.onApplicationStart existed
1 in onSessionStart session.onApplicationStart initialised
1 in onSessionStart request.onApplicationStart existed
1 in onSessionStart this.onApplicationStart existed
==================================================
1 in onSessionStart application.onSessionStart initialised
1 in onSessionStart session.onSessionStart initialised
1 in onSessionStart request.onSessionStart initialised
1 in onSessionStart this.onSessionStart existed
==================================================
1 in onRequestStart application.pseudoconstructor existed
1 in onRequestStart session.pseudoconstructor existed
1 in onRequestStart request.pseudoconstructor existed
1 in onRequestStart this.pseudoconstructor existed
==================================================
1 in onRequestStart application.onApplicationStart existed
1 in onRequestStart session.onApplicationStart existed
1 in onRequestStart request.onApplicationStart existed
1 in onRequestStart this.onApplicationStart existed
==================================================
1 in onRequestStart application.onSessionStart existed
1 in onRequestStart session.onSessionStart existed
1 in onRequestStart request.onSessionStart existed
1 in onRequestStart this.onSessionStart existed
==================================================
1 in onRequestStart application.onRequestStart initialised
1 in onRequestStart session.onRequestStart initialised
1 in onRequestStart request.onRequestStart initialised
1 in onRequestStart this.onRequestStart existed
==================================================
1 in onRequest application.pseudoconstructor existed
1 in onRequest session.pseudoconstructor existed
1 in onRequest request.pseudoconstructor existed
1 in onRequest this.pseudoconstructor existed
==================================================
1 in onRequest application.onApplicationStart existed
1 in onRequest session.onApplicationStart existed
1 in onRequest request.onApplicationStart existed
1 in onRequest this.onApplicationStart existed
==================================================
1 in onRequest application.onSessionStart existed
1 in onRequest session.onSessionStart existed
1 in onRequest request.onSessionStart existed
1 in onRequest this.onSessionStart existed
==================================================
1 in onRequest application.onRequestStart existed
1 in onRequest session.onRequestStart existed
1 in onRequest request.onRequestStart existed
1 in onRequest this.onRequestStart existed
==================================================
1 in onRequest application.onRequest initialised
1 in onRequest session.onRequest initialised
1 in onRequest request.onRequest initialised
1 in onRequest this.onRequest existed
==================================================
1 in onRequestEnd application.pseudoconstructor existed
1 in onRequestEnd session.pseudoconstructor existed
1 in onRequestEnd request.pseudoconstructor existed
1 in onRequestEnd this.pseudoconstructor existed
==================================================
1 in onRequestEnd application.onApplicationStart existed
1 in onRequestEnd session.onApplicationStart existed
1 in onRequestEnd request.onApplicationStart existed
1 in onRequestEnd this.onApplicationStart existed
==================================================
1 in onRequestEnd application.onSessionStart existed
1 in onRequestEnd session.onSessionStart existed
1 in onRequestEnd request.onSessionStart existed
1 in onRequestEnd this.onSessionStart existed
==================================================
1 in onRequestEnd application.onRequestStart existed
1 in onRequestEnd session.onRequestStart existed
1 in onRequestEnd request.onRequestStart existed
1 in onRequestEnd this.onRequestStart existed
==================================================
1 in onRequestEnd application.onRequest existed
1 in onRequestEnd session.onRequest existed
1 in onRequestEnd request.onRequest existed
1 in onRequestEnd this.onRequest existed
==================================================
1 in onRequestEnd application.onRequestEnd initialised
1 in onRequestEnd session.onRequestEnd initialised
1 in onRequestEnd request.onRequestEnd initialised
1 in onRequestEnd this.onRequestEnd existed
==================================================
2 in pseudoconstructor before application name is set application scope not enabled
2 in pseudoconstructor before application name is set session scope not enabled
2 in pseudoconstructor before application name is set request.pseudoconstructor initialised
2 in pseudoconstructor before application name is set this.pseudoconstructor initialised
==================================================
2 in pseudoconstructor after application name is set application scope not enabled
2 in pseudoconstructor after application name is set session scope not enabled
2 in pseudoconstructor after application name is set request.pseudoconstructor existed
2 in pseudoconstructor after application name is set this.pseudoconstructor existed
==================================================
2 in onRequestStart application.pseudoconstructor existed
2 in onRequestStart session.pseudoconstructor existed
2 in onRequestStart request.pseudoconstructor existed
2 in onRequestStart this.pseudoconstructor existed
==================================================
2 in onRequestStart application.onApplicationStart existed
2 in onRequestStart session.onApplicationStart existed
2 in onRequestStart request.onApplicationStart initialised
2 in onRequestStart this.onApplicationStart existed
==================================================
2 in onRequestStart application.onSessionStart existed
2 in onRequestStart session.onSessionStart existed
2 in onRequestStart request.onSessionStart initialised
2 in onRequestStart this.onSessionStart existed
==================================================
2 in onRequestStart application.onRequestStart existed
2 in onRequestStart session.onRequestStart existed
2 in onRequestStart request.onRequestStart initialised
2 in onRequestStart this.onRequestStart existed
==================================================
2 in onRequest application.pseudoconstructor existed
2 in onRequest session.pseudoconstructor existed
2 in onRequest request.pseudoconstructor existed
2 in onRequest this.pseudoconstructor existed
==================================================
2 in onRequest application.onApplicationStart existed
2 in onRequest session.onApplicationStart existed
2 in onRequest request.onApplicationStart existed
2 in onRequest this.onApplicationStart existed
==================================================
2 in onRequest application.onSessionStart existed
2 in onRequest session.onSessionStart existed
2 in onRequest request.onSessionStart existed
2 in onRequest this.onSessionStart existed
==================================================
2 in onRequest application.onRequestStart existed
2 in onRequest session.onRequestStart existed
2 in onRequest request.onRequestStart existed
2 in onRequest this.onRequestStart existed
==================================================
2 in onRequest application.onRequest existed
2 in onRequest session.onRequest existed
2 in onRequest request.onRequest initialised
2 in onRequest this.onRequest existed
==================================================
2 in onRequestEnd application.pseudoconstructor existed
2 in onRequestEnd session.pseudoconstructor existed
2 in onRequestEnd request.pseudoconstructor existed
2 in onRequestEnd this.pseudoconstructor existed
==================================================
2 in onRequestEnd application.onApplicationStart existed
2 in onRequestEnd session.onApplicationStart existed
2 in onRequestEnd request.onApplicationStart existed
2 in onRequestEnd this.onApplicationStart existed
==================================================
2 in onRequestEnd application.onSessionStart existed
2 in onRequestEnd session.onSessionStart existed
2 in onRequestEnd request.onSessionStart existed
2 in onRequestEnd this.onSessionStart existed
==================================================
2 in onRequestEnd application.onRequestStart existed
2 in onRequestEnd session.onRequestStart existed
2 in onRequestEnd request.onRequestStart existed
2 in onRequestEnd this.onRequestStart existed
==================================================
2 in onRequestEnd application.onRequest existed
2 in onRequestEnd session.onRequest existed
2 in onRequestEnd request.onRequest existed
2 in onRequestEnd this.onRequest existed
==================================================
2 in onRequestEnd application.onRequestEnd existed
2 in onRequestEnd session.onRequestEnd existed
2 in onRequestEnd request.onRequestEnd initialised
2 in onRequestEnd this.onRequestEnd existed


The log here follows two consecutive requests (labelled "1" and "2" in the leftmost column).

There's a whole lot of bumpf there, but the stand-out things are highlighted.

First, let's look at what happens in the pseudo-constructor (the bit of code within the component tags, but outwith any method in the CFC).

This is not surprising:

1 in pseudoconstructor before application name is set application scope not enabled
1 in pseudoconstructor before application name is set session scope not enabled

There's no chance that there'd be any sense of application before the this.name line had been encountered.  CF doesn't know which application a given request is part of before it's been told.  Equally the session scope cannot exist prior to the application being identified, because sessions are bound to applications.

This is straight forward:
1 in pseudoconstructor before application name is set request.pseudoconstructor initialised
1 in pseudoconstructor before application name is set this.pseudoconstructor initialised

Obviously we know we can set this-scoped variables here... we'd not be able to set the application settings otherwise.  Being able to set request-scope variables is slightly surprising, given that this is before onRequestStart(), esp. given what I'm drawing your attention to next:

1 in pseudoconstructor after application name is set application scope not enabled
1 in pseudoconstructor after application name is set session scope not enabled

So this is after the application has been named.  But still the application and session scopes aren't available.  I expected they might have been as there's no reason for them not to.  I guess CF waits until the onApplicationStart() and onSessionStart() event handlers start before starting those two scopes.  Given my earlier diatribe on events vs event handlers, I half expected the scopes to be there, even if the event handlers had yet to be called.  So that is definitely something I have learned about all this.

Saturday 14 July 2012

CFML: onApplicationStart is not intrinsically single-threaded (part 2)

G'day:
I'm very new to the blog carry-on, and was quite pleased to get some good feedback from my first post, and that it was sufficiently interesting for me to create a follow-up post to take a look at the question.

David McGuigan made a comment, and had this to say (extract):
[If] you call onApplicationStart programmatically, [...] say with a check in onRequestStart for a URL scope flag that triggers it from within Application.cfc itself, it still *is* single-threaded.
I gotta say my initial thought was "um... I'm pretty sure it's not single-threaded", but I wasn't completely sure, so decided to look into it.


I knocked-together some slightly different code from last time, thus:

<!--- Application.cfc --->
<cfcomponent>

    <cfset this.name                = "singleThreadedAppStart3">
    <cfset this.applicationTimeout  = createTimeSpan(0,0,0,30)>

    <cffunction name="onApplicationStart">
        <cfset application.startTick = getTickCount()>
        <cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Top of onApplicationStart() called via #CGI.script_name#">
        <cfset application.startedBy = CGI.script_name>
        <cfset sleep(10000)>
        <cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Bottom of onApplicationStart() called via #CGI.script_name#">
    </cffunction>

    <cffunction name="onRequestStart">
        <cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Top of onRequestStart() called via #CGI.script_name#">
        <cfif structKeyExists(URL,  "restart")>
            <cfset onApplicationStart()>
        </cfif>
        <cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Bottom of onRequestStart() called via #CGI.script_name#">
    </cffunction>

</cfcomponent>

I've added a coupla bits in here that stand quick clarification:
  • I'm setting a small application timeout, so between tests I get a new application starting.  I only mention this because I've been a bit of a drongo (look it up) in the past, and when I want to scrub my test application I change the name in the this.name setting (as you can see I've still actually done this three times in my code as it is, eg: "singleThreadedAppStart3").  There's no need to do that... a 30sec time out is enough for me to run the test and then whilst analysing it, the app times out of its own accord, ready for the next test.  This is not earthshattering, but I was marginally pleased with myself for this finally occurring to me to do.  I now feel I'm slightly less stupid than I was yesterday.
  • I've added to the log entries how long it's been since the app was started (well: in this case, "since onApplicationStart() was called"). This info is already in the log entries, but this just makes it a bit more clear in the extract I'm going to include below.
  • I've added in one of these "restart the app" conditions into onRequestStart(), so I can specify on the URL to restart the app.  I'll repeat that this is not something I would usually do nor do I recommend it as a practice, but it's relevant to this discussion.
Other than that, it's all the same gig as last time:  basically log what's going on when the app starts,  so I can see what order (and when) events occur.  And in the app start code I have a contrived 10sec delay to make it easier to to time my "simultaneous" requests.

The calling code for this is much the same as before:

<!--- requestOne.cfm --->
<cfdump var="#application#" label="#CGI.script_name#">

<!--- requestTwo.cfm --->
<cfdump var="#application#" label="#CGI.script_name#">

The test I run is to do this:
  1. Hit requestOne.cfm (without the restart switch set).  This is just to warm up the app.
  2. Count off my guess at 5sec (so halfway through the 10sec delay in onApplicationStart())
  3. Hit requestTwo.cfm (again, with no restart switch set).  This is just to "prove" that app restart - if not calls to onApplicationStart() - are single-threaded.
  4. Wait for them both to finish, but being mindful that my new 30sec app timeout is perhaps working against me here (I screwed it up the first time, forgetting about it, I have to admit.  Back to being as dumb as I was y/day.  Sigh ;-)
  5. Hit requestOne.cfm?restart=true
  6. Count to five again.
  7. Hit requestTwo.cfm?restart=true
So what I'm testing here is twofold:
  1. that my baseline is sensible... the actual application start-up process is single-threaded.
  2. However the actual test hypothesis is that the second two calls to onApplicationStart() actually are not single threaded.
Right.  What's in the log?

[0] Top of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10002] Bottom of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10005] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10005] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[10017] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10022] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm

[12291] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[4] Top of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[4097] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[0] Top of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[5908] Bottom of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[5909] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10001] Bottom of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[10002] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm


And what does this tell us?

I've put a break between the two sets of requests (steps 1-3, then steps 5-7).

The first block shows us that requestOne.cfm takes the mantle of starting the application up, and requestTwo.cfm patiently waits until requestOne.cfm is done, then it continues its request (and it doesn't call onApplicationStart() at all).  Good.  This is what we want.

The second block is our actual test.  What we see here is that requestOne.cfm starts, and correctly calls onApplicationStart().  However requestTwo.cfm comes in right behind it (note the "4097ms": I can't actually count off 5sec very well... ;-), and it also merrily calls onApplicationStart() too.  Bleah.  We really didn't want that to happen.

This is especially true if we look at the dumps afterwards:

/shared/CF/other/appcfc/singlethreaded/requestOne.cfm - struct
applicationnamesingleThreadedAppStart3
startedby/shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
starttick1342293921379

(wow: am quite impressed I could just copy the CFDUMP output from my browser into here and it renders perfectly.  Nice one blogger.com).

/shared/CF/other/appcfc/singlethreaded/requestTwo.cfm - struct
applicationnamesingleThreadedAppStart3
startedby/shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
starttick1342293921379

 So unfortunately as requestTwo.cfm started to execute onApplicationStart()'s code before requestOne.cfm had finished, we get the wrong value for application.startedBy.

This is a foolishly contrived example, I know, but it shows the point: onApplicationStart() in and of itself is just not single-threaded no matter how you spin it.  It's just a method in a CFC.  The single-threadedness of application start-up is because app-start-up is single-threaded, not that onApplicationStart() itself is single-threaded.

One last thing I better check... Dave, is that what you were kinda talking about?  It'd be... "funny" if I'd blathered on about all this, and you were actually meaning something else.  Heh... :-/

Righto... cheers all and enjoy your Saturday.  What's left of it, if any.

--
Adam