Threaded cfschedule updates causing CFConfig.json corruption with 6.2.2.90-RC

dev support
1

One of our servers using the latest release is crashing…

My guess is that is related to the scripted update of a scheduled task, we do this


        if ( getSetting("environment") neq "DEVELOPMENT") {

            cfschedule( task = 'threaded_bla',
                hidden = false,
                requesttimeout = 530,
                url = "#cgi.http_host#ourUrl" & addSomething,
                action = 'update',
                startDate = now(),
                startTime = CreateTime(0,0,0),
                operation = 'HTTPRequest',
                interval = randrange(540,800)

The server reports that it’s missing the Ortus orm extension, if I check /opt/lucee/tomcat/lucee-server/context/.CFConfig.json
it looks like the whole extension section is removed

   {
      "scheme": "ram",
      "class": "lucee.commons.io.res.type.cache.CacheResourceProvider",
      "arguments": "case-sensitive:true;lock-timeout:1000;"
    }
  ],
  "salt": "xxx",
  "scheduledTasks": [
    {
      "name": "threaded_bla",
      "startDate": "{d '2025-08-02'}",
      "startTime": "{t '00:00:00'}",
2

what was the previous version?

3

completely reinstalled it (already third time)… will backup now .CFConfig.json

4

yeah but version were you using before and not getting this error?

any clues in the logs?

(split the thread for clarity)

5

I guess it is not related to ORM extension… there is something wrong with rewriting the scheduled task, because all scheduled tasks are gone, except one, and the whole extension section is removed

6

One of the errors which was logged is:

lucee.runtime.interpreter.InterpreterException:Syntax Error at line [326] / column [4] / position [8644] in the JSON \n325:   ]\n326: }  }\n        ^\n327:   ]
7 
"lucee.runtime.exp.NativeException: lucee.runtime.interpreter.InterpreterException:Syntax Error at line [326] / column [4] / position [8644] in the JSON ",
            "325:   ]",
            "326: }  }",
            "        ^",
            "327:   ]",
            "\tat lucee.commons.lang.ExceptionUtil.toIOException(ExceptionUtil.java:249)",
            "\tat lucee.runtime.schedule.SchedulerImpl.addScheduleTask(SchedulerImpl.java:242)",
            "\tat lucee.runtime.tag.Schedule.doUpdate(Schedule.java:490)",
            "\tat lucee.runtime.tag.Schedule.doStartTag(Schedule.java:441)",
            "\tat modules_app.akibase.modules.akibase_queue360.handlers.threaded_cfc$cf$7g.udfCall(XXXXThreaded.cfc:49)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:214)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:732)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:604)",
            "\tat lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:2129)",
            "\tat lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:896)",
            "\tat lucee.runtime.functions.dynamicEvaluation.Invoke.call(Invoke.java:54)",
            "\tat system.web.controller_cfc$cf.udfCall4(/coldbox/system/web/Controller.cfc:1257)",
            "\tat system.web.controller_cfc$cf.udfCall(/coldbox/system/web/Controller.cfc)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:214)",
            "\tat lucee.runtime.type.scope.UndefinedImpl.callWithNamedValues(UndefinedImpl.java:829)",
            "\tat lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:858)",
            "\tat lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:2113)",
            "\tat system.web.controller_cfc$cf.udfCall3(/coldbox/system/web/Controller.cfc:1006)",
            "\tat system.web.controller_cfc$cf.udfCall(/coldbox/system/web/Controller.cfc)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:214)",
            "\tat lucee.runtime.type.scope.UndefinedImpl.callWithNamedValues(UndefinedImpl.java:829)",
            "\tat lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:858)",
            "\tat lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:2113)",
            "\tat system.web.controller_cfc$cf.udfCall3(/coldbox/system/web/Controller.cfc:713)",
            "\tat system.web.controller_cfc$cf.udfCall(/coldbox/system/web/Controller.cfc)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:214)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:732)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:604)",
            "\tat lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:2129)",
            "\tat lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:858)",
            "\tat lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:2113)",
            "\tat coldbox.system.bootstrap_cfc$cf.udfCall1(/coldbox/system/Bootstrap.cfc:290)",
            "\tat coldbox.system.bootstrap_cfc$cf.udfCall(/coldbox/system/Bootstrap.cfc)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.call(UDFImpl.java:224)",
            "\tat lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:811)",
            "\tat lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:773)",
            "\tat lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:2081)",
            "\tat coldbox.system.bootstrap_cfc$cf.udfCall1(/coldbox/system/Bootstrap.cfc:506)",
            "\tat coldbox.system.bootstrap_cfc$cf.udfCall(/coldbox/system/Bootstrap.cfc)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.call(UDFImpl.java:224)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:731)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:604)",
            "\tat lucee.runtime.ComponentImpl.call(ComponentImpl.java:2110)",
            "\tat lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:773)",
            "\tat lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:2081)",
            "\tat application_cfc$cf$9v.udfCall(/Application.cfc:189)",
            "\tat lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)",
            "\tat lucee.runtime.type.UDFImpl._call(UDFImpl.java:357)",
            "\tat lucee.runtime.type.UDFImpl.call(UDFImpl.java:224)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:731)",
            "\tat lucee.runtime.ComponentImpl._call(ComponentImpl.java:604)",
            "\tat lucee.runtime.ComponentImpl.call(ComponentImpl.java:2110)",
            "\tat lucee.runtime.listener.ModernAppListener.call(ModernAppListener.java:477)",
            "\tat lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:129)",
            "\tat lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:41)",
            "\tat lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2816)",
            "\tat lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2803)",
            "\tat lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2774)",
            "\tat lucee.runtime.engine.Request.exe(Request.java:45)",
            "\tat lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1113)",
            "\tat lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1070)",
            "\tat lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)",
            "\tat lucee.loader.servlet.jakarta.CFMLServlet.service(CFMLServlet.java:52)",
            "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:710)",
            "\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:130)",
            "\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)",
            "\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:109)",
            "\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)",
            "\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:79)",
            "\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483)",
            "\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:116)",
            "\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)",
            "\tat org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:666)",
            "\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)",
            "\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)",
            "\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:396)",
            "\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)",
            "\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:903)",
            "\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1773)",
            "\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)",
            "\tat org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)",
            "\tat org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)",
            "\tat org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:59)",
            "\tat java.base/java.lang.Thread.run(Unknown Source)",
            "Caused by: java.io.IOException: lucee.runtime.interpreter.InterpreterException:Syntax Error at line [326] / column [4] / position [8644] in the JSON ",
            "325:   ]",
            "326: }  }",
            "        ^",
            "327:   ]",
            "\t... 96 more",
            "Caused by: lucee.runtime.interpreter.InterpreterException: Syntax Error at line [326] / column [4] / position [8644] in the JSON ",
            "325:   ]",
            "326: }  }",
            "        ^",
            "327:   ]",
            "\tat lucee.runtime.interpreter.CFMLExpressionInterpreter.createSyntaxException(CFMLExpressionInterpreter.java:287)",
            "\tat lucee.runtime.interpreter.CFMLExpressionInterpreter.interpret(CFMLExpressionInterpreter.java:234)",
            "\tat lucee.runtime.interpreter.CFMLExpressionInterpreter.interpret(CFMLExpressionInterpreter.java:194)",
            "\tat lucee.runtime.config.ConfigFactory._loadDocument(ConfigFactory.java:1074)",
            "\tat lucee.runtime.config.ConfigFactory.loadDocument(ConfigFactory.java:211)",
            "\tat lucee.runtime.config.ConfigAdmin.<init>(ConfigAdmin.java:279)",
            "\tat lucee.runtime.config.ConfigAdmin.updateScheduledTask(ConfigAdmin.java:624)",
            "\tat lucee.runtime.schedule.SchedulerImpl.addScheduleTask(SchedulerImpl.java:239)",
            "\t... 94 more"
8

ahhh, sounds like something is corrupting the CFConfig.json, got more details???

i.e. the stacktrace

9

line 49 is exactly this:

  cfschedule( task = 'threaded_bla',
                hidden = false,
                requesttimeout = 530,
                url = "#cgi.http_host#ourUrl" & addSomething,
                action = 'update',
                startDate = now(),
                startTime = CreateTime(0,0,0),
                operation = 'HTTPRequest',
                interval = randrange(540,800)
10

ok, can you log out the values being passed out to the update schedule task?

BTW are you concurrently updating scheduled task in a thread?

11

BTW are you concurrently updating scheduled task in a thread?

I guess it could happen, after reviewing the code I think we update the schduled tasks too often, but it was never an issue with 5.4

12

there is not much passed just two url sting parameters

13

with 6 the scheduled tasks are all stored in cfconfig.json, you could try doing a lock around the individual call to update the tasks.

my theory is the overlapping updates are potentially causing a race condition and corrupting the file?

I know this problem about schedule updates, I think a bulk update mechanism would be good and of course some better locking internally in Lucee !

This is a 5.4 to 6.2 upgrade?

14

This is a 5.4 to 6.2 upgrade?

Fresh install but ran on 5.x for several years

15

Ok, so this is a 5.4 code base being now run on 6.2?

16

Ok, so this is a 5.4 code base being now run on 6.2?

Yes, decent Coldbox 7.3 app which 50+ Coldbox (own) modules

17

the only changes between that and the RC are enabling reflection and the dynclasses cleanup, which shouldn’t be causing a problem.

Pretty sure it’s the threaded cfscheduled updates causing the problem

18

Just added lock around it, let’s see if the error disappears

2 Likes
19

bug filed for 6.2.3

https://luceeserver.atlassian.net/browse/LDEV-5747

@gunnar.lieb which jira account is your current one? there are three! I’ll make you the reporter

20

It should be gunnar.lieb@a…