14 Replies Latest reply on Aug 6, 2017 5:03 AM by BKBK

    empty onSessionEnd creating NullPointerExceptions?

    bruceb19075631 Level 1

      Some background: we recently upgraded from CF 10 to CF 2016, and moved to a new server (Windows Server 2012 R2, IIS 8).  All updates are installed for all of the above (cf version 2016.0.03.300466 and jvm version: 25.72-b15).

       

      Here's the issue:  In my Application.cfc I've got a completely empty onSessionEnd.

       

      <cffunction name="onSessionEnd" returnType="void">

          <cfargument name="SessionScope" required="true" />

          <cfargument name="ApplicationScope" required="false" />

      </cffunction>

       

      I've got onError is currently set up to send me an email. 

       

      I am periodically getting this:

       

      arguments - struct

      EVENTNAME onSessionEnd
      EXCEPTION
      arguments - struct
      Cause
      arguments - struct
      Message [empty string]
      StackTrace java.lang.NullPointerException at coldfusion.runtime.NeoJspWriter.writeOutput(NeoJspWriter.java:228) at coldfusion.runtime.NeoJspWriter.flush(NeoJspWriter.java:362) at coldfusion.cfc.CFCProxy.flush(CFCProxy.java:357) at coldfusion.cfc.CFCProxy.doInvoke(CFCProxy.java:332) at coldfusion.cfc.CFCProxy.invoke(CFCProxy.java:302) at coldfusion.runtime.AppEventInvoker.onSessionEnd(AppEventInvoker.java:462) at coldfusion.runtime.SessionTracker.invokeOnSessinEnd(SessionTracker.java:291) at coldfusion.runtime.SessionTracker.cleanUp(SessionTracker.java:274) at coldfusion.runtime.SessionTracker.access$000(SessionTracker.java:43) at coldfusion.runtime.SessionTracker$SessionCleanUpAgent.run(SessionTracker.java:483) at coldfusion.scheduling.ThreadPool.run(ThreadPool.java:260) at coldfusion.scheduling.WorkerThread.run(WorkerThread.java:71)
      Suppressed
      arguments - array [empty]
      TagContext
      arguments - array [empty]
      Type java.lang.NullPointerException
      Detail An exception occurred while invoking an event handler method from Application.cfc. The method name is: onSessionEnd.
      Message Event handler exception.

       

      I'm basically at a loss as to how it's generating a nullPointerException (which, to my understanding, can sometimes be basically a variable undefined error when encountered in onSessionEnd or onApplicationEnd which aren't handled well by onError, but as there's literally nothing in it, that's not relevant).

       

      So I dug into the logs.

      Exception log:

       

      "Error","scheduler-2","12/02/16","15:13:59","","'' The specific sequence of files included or processed is: '''' "

      java.lang.NullPointerException

          at coldfusion.runtime.NeoJspWriter.writeOutput(NeoJspWriter.java:228)

          at coldfusion.runtime.NeoJspWriter.flush(NeoJspWriter.java:362)

          at coldfusion.cfc.CFCProxy.flush(CFCProxy.java:357)

          at coldfusion.cfc.CFCProxy.doInvoke(CFCProxy.java:332)

          at coldfusion.cfc.CFCProxy.invoke(CFCProxy.java:302)

          at coldfusion.runtime.AppEventInvoker.onSessionEnd(AppEventInvoker.java:462)

          at coldfusion.runtime.SessionTracker.invokeOnSessinEnd(SessionTracker.java:291)

          at coldfusion.runtime.SessionTracker.cleanUp(SessionTracker.java:274)

          at coldfusion.runtime.SessionTracker.access$000(SessionTracker.java:43)

          at coldfusion.runtime.SessionTracker$SessionCleanUpAgent.run(SessionTracker.java:483)

          at coldfusion.scheduling.ThreadPool.run(ThreadPool.java:260)

          at coldfusion.scheduling.WorkerThread.run(WorkerThread.java:71)

       

      application log:

       

      "Error","scheduler-2","12/02/16","15:13:59","","'' The specific sequence of files included or processed is: '''' "

       

      coldfusion-out log:

       

      Dec 2, 2016 15:13:59 PM Error [scheduler-2] - '' The specific sequence of files included or processed is: ''''

       

      Other notes: I am using J2EE session variables, and SESSSION management is enabled for the app.

       

      My question(s): what weird thing is this scheduler thread doing, why would it be encountering a null pointer exception in onsessionend, and how would one go about stopping it from occurring again?

        • 1. Re: empty onSessionEnd creating NullPointerExceptions?
          BKBK Adobe Community Professional & MVP

          Weird indeed. The only cause I can think of is a NULL session. Which implies no session might have been created in the first place or that an error resulted during the creation of the session.

           

          Could you show us how you enable sessions? Also, what are your JVM parameters? Does your Coldfusion installation share JVM resources with an external application, such as FusionReactor?

          • 2. Re: empty onSessionEnd creating NullPointerExceptions?
            philipp40543364 Level 1

            We are having the same problem, although we don't have an empty OnSessionEnd function. I'm curious about why you're asking about sharing resources with FusionReactor, what affects might that have?

             

            Edit: @bruceb19075631 does it happen for you every time or sporadically?

            • 3. Re: empty onSessionEnd creating NullPointerExceptions?
              Steve Sommers Level 4

              Just a guess but possibly the required="true" parameter in the cfargument tag.

              • 4. Re: empty onSessionEnd creating NullPointerExceptions?
                bruceb19075631 Level 1

                Sessions are enabled at top of Application.cfc, per usual.

                 

                <cfcomponent output="false">

                 

                <cfset this.name = "[applicationname]" />

                <cfset this.applicationTimeout = createTimeSpan(5,0,0,0) />

                <cfset this.loginStorage = "session" />

                <cfset this.scriptProtect = "all" />

                <cfset this.serverSideFormValidation = "no" />

                <cfset this.sessioncookie.httponly = "yes" />

                <cfset this.sessionManagement = "yes" />

                <cfset this.sessionTimeout = createTimeSpan(0,0,30,0) />

                <cfset this.setclientcookies = "no">
                etc. etc.

                 

                JVM arguments: -server -XX:MaxMetaspaceSize=192m -XX:+UseParallelGC -Xbatch -Dcoldfusion.home={application.home} -Duser.language=en -Dcoldfusion.rootDir={application.home} -Dcoldfusion.libPath={application.home}/lib -Dorg.apache.coyote.USE_CUSTOM_STATUS_MSG_IN_HEADER=true -Dcoldfusion.jsafe.defaultalgo=FIPS186Random -Dorg.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.JavaUtilLog -Djava.util.logging.config.file={application.home}/lib/logging.properties

                 

                CF is the only thing using JVM on the machine.

                • 5. Re: empty onSessionEnd creating NullPointerExceptions?
                  bruceb19075631 Level 1

                  The problem started with a normal, full of stuff onsessionend. 

                   

                  We slowly pared it down until it was completely empty and the problem still persisted/persists.

                   

                  Originally I believed it was happening at the end of every session, but we eventually figured out that the error doesn't happen on normal session endings.  Only when these weird scheduler things happen.

                  • 6. Re: empty onSessionEnd creating NullPointerExceptions?
                    BKBK Adobe Community Professional & MVP

                    philipp40543364 wrote:

                     

                    I'm curious about why you're asking about sharing resources with FusionReactor, what affects might that have?

                     

                    Sometimes when you instal FusionReactor the JVM settings of your Coldfusion settings change.

                    • 7. Re: empty onSessionEnd creating NullPointerExceptions?
                      BKBK Adobe Community Professional & MVP

                      philipp40543364 wrote:

                       

                      Edit: @bruceb19075631 does it happen for you every time or sporadically?

                      I also wanted to ask that. The cause of the error may be a stranded scheduled task. Do you run any custom scheduled tasks?

                      • 8. Re: empty onSessionEnd creating NullPointerExceptions?
                        BKBK Adobe Community Professional & MVP

                        Steve Sommers wrote:

                         

                        Just a guess but possibly the required="true" parameter in the cfargument tag.

                        I agree. The application could be debugged as follows

                         

                        <cffunction name="onSessionEnd" returnType="void">

                            <cfargument name="SessionScope" required="true" />

                            <cfargument name="ApplicationScope" required="true" />

                        <cftry>

                            <cflog file="#this.Name#" type="Information" text="The session #arguments.SessionScope.sessionid# has ended">

                        <cfcatch type="Any">

                            <cflog file="errorInOnSessionEnd" type="error" text="cfcatch.message=#cfcatch.message#">

                        </cfcatch>

                        </cftry>

                        </cffunction>

                        • 9. Re: empty onSessionEnd creating NullPointerExceptions?
                          bruceb19075631 Level 1

                          We do have some scheduled tasks on the server, but they're largely once a day things, with the exception of one that runs every 30 minutes, and one every 6 hours.  The times don't remotely match up, and don't remotely conform to those intervals.

                           

                          Additionally, scheduled tasks show up in the logs with a ThreadID of [DefaultQuartzScheduler_Worker-x] where x is a number, like so:

                           

                               Dec 15, 2016 16:37:00 PM Information [DefaultQuartzScheduler_Worker-4] - Task default. [NAME OF TASK] triggered.

                               Dec 15, 2016 16:37:00 PM Information [DefaultQuartzScheduler_Worker-4] - Starting HTTP request {URL='[URL OF TASK]', method='get'}

                               Dec 15, 2016 16:37:00 PM Information [DefaultQuartzScheduler_Worker-4] - HTTP request completed  {Status Code=200 ,Time taken=47 ms}

                           

                          All the normal requests are handled via ThreadID [ajp-nio-8016-exec-x] where x is a number.

                           

                               Dec 15, 2016 16:37:53 PM Error [ajp-nio-8016-exec-6] - File not found: [NONEXISTENT FILE] The specific sequence of files included or processed is: [FILEPATH]''

                               Dec 15, 2016 16:37:55 PM Information [ajp-nio-8016-exec-4] - Starting HTTP request {URL='[REMOTE URL]', method='get'}

                               Dec 15, 2016 16:37:56 PM Information [ajp-nio-8016-exec-4] - HTTP request completed  {Status Code=200 ,Time taken=516 ms}

                           

                          Whereas when the actual error occurs, you can see it's executed by the [scheduler-x] ThreadIDs (and then I'm promptly sent an email about it):

                           

                               Dec 15, 2016 16:46:15 PM Error [scheduler-2] - '' The specific sequence of files included or processed is: ''''

                               Dec 15, 2016 16:46:24 PM Information [scheduler-0] - Mail: 'New Error' From:'site_error@[SITE].com' To:'[MY EMAIL]' was successfully sent using [MAIL SERVER]

                           

                          The only thing besides sending error emails and metrics (before I disabled metrics logging so I could actually read the logs easily) that [scheduler-x] does is:

                           

                               Dec 15, 2016 15:00:05 PM Information [scheduler-0] - Run Client Storage Purge


                          Well, besides my lovely inexplicable

                           

                                Dec 15, 2016 14:56:02 PM Error [scheduler-0] - '' The specific sequence of files included or processed is: ''''

                           

                          Thoughts?

                          • 10. Re: empty onSessionEnd creating NullPointerExceptions?
                            BKBK Adobe Community Professional & MVP

                            Well described, @bruceb19075631. I am looking into it some more.

                             

                            Did you try out the suggestions of yesterday? If so, what did you get?

                            • 11. Re: empty onSessionEnd creating NullPointerExceptions?
                              Steve Sommers Level 4

                              Maybe try:

                               

                              <cffunction name="onSessionEnd" returnType="void">

                                  <cfargument name="SessionScope" required="false" />

                                  <cfargument name="ApplicationScope" required="false" />

                              <cftry>

                              <cfif structKeyExists(arguments,"SessionScope")>

                                  <cflog file="#this.Name#" type="Information" text="The session #arguments.SessionScope.sessionid# has ended" />

                              <cfelse>

                                  <cflog file="#this.Name#" type="Information" text="Unprovided session has ended" />

                              <cfelse>

                              </cfif>

                              <cfcatch type="Any">

                                  <cflog file="errorInOnSessionEnd" type="error" text="cfcatch.message=#cfcatch.message#" />

                              </cfcatch>

                              </cftry>

                              </cffunction>

                              • 12. Re: empty onSessionEnd creating NullPointerExceptions?
                                BKBK Adobe Community Professional & MVP

                                bruceb19075631 wrote:

                                 

                                Originally I believed it was happening at the end of every session, but we eventually figured out that the error doesn't happen on normal session endings. Only when these weird scheduler things happen.

                                The [scheduler-x] things are just the threads that run the onSessionEnd method. The error implies that Coldfusion encounters a null object when ending a session.

                                 

                                By design, when a session ends, Coldfusion calls the onSessionEnd method. When it does, it passes a session-scope struct and an application-scope struct. The logical explanation I can think of for the error is that at least one of the structs is non-existent, hence null. If true, then this is a bug. I would therefore suggest that you report a bug.

                                 

                                Could you show us the entire Application.cfc?

                                • 13. Re: empty onSessionEnd creating NullPointerExceptions?
                                  Terry_2011_ Level 1

                                  Hi Bruce --

                                   

                                  Did you ever work out a fix for this?

                                   

                                  We are having this identical problem.   We just went from CF9 to CF2016 and have been seeing these appear in our app.log once or twice a day:

                                   

                                  "Error","scheduler-2","08/04/17","17:51:21","","'' The specific sequence of files included or processed is: '''' "

                                  "Error","scheduler-2","08/04/17","17:51:21","","'' The specific sequence of files included or processed is: '''' "

                                  "Error","scheduler-2","08/04/17","17:51:21","","'' The specific sequence of files included or processed is: '''' "

                                   

                                  There were 38 lines of this just a few minutes ago.

                                   

                                  Each one corresponds to an exception.log error:

                                   

                                  "Error","scheduler-2","08/04/17","17:51:21","","'' The specific sequence of files included or processed is: '''' "

                                  java.lang.NullPointerException

                                          at coldfusion.runtime.NeoJspWriter.writeOutput(NeoJspWriter.java:228)

                                          at coldfusion.runtime.NeoJspWriter.flush(NeoJspWriter.java:362)

                                          at coldfusion.cfc.CFCProxy.flush(CFCProxy.java:357)

                                          at coldfusion.cfc.CFCProxy.doInvoke(CFCProxy.java:332)

                                          at coldfusion.cfc.CFCProxy.invoke(CFCProxy.java:302)

                                          at coldfusion.runtime.AppEventInvoker.onSessionEnd(AppEventInvoker.java:462)

                                          at coldfusion.runtime.SessionTracker.invokeOnSessinEnd(SessionTracker.java:292)

                                          at coldfusion.runtime.SessionTracker.cleanUp(SessionTracker.java:275)

                                          at coldfusion.runtime.SessionTracker.access$000(SessionTracker.java:43)

                                          at coldfusion.runtime.SessionTracker$SessionCleanUpAgent.run(SessionTracker.java:484)

                                          at coldfusion.scheduling.ThreadPool.run(ThreadPool.java:260)

                                          at coldfusion.scheduling.WorkerThread.run(WorkerThread.java:71)

                                   

                                  This looks like your same problem.   Did you ever find a way to stop the exceptions from occurring?

                                  • 14. Re: empty onSessionEnd creating NullPointerExceptions?
                                    BKBK Adobe Community Professional & MVP

                                    Chances are, there is a bug in ColdFusion 2016's session apparatus.

                                    I have voted for your bug report, CF-4199420.