We have some legacy app bootstrap foo that runs on the first

Question

We have some legacy app bootstrap foo that runs on the first `onRequestStart ` the app gets Sometimes it races ahead of Coldbox bootstrapping and so Wirebox and Coldbox are there but they re not done loading modules What s the easiest way to say hey Coldbox are you totally done loading everything or should we just set some app scope variable in `afterAspectsLoaded ` or someplace like that

bdw429s · Answer

< sknowlton> If ColdBox is bootstrapping in the `onApplicationStart ` it should be impossible for any `onRequest ` calls to happen until the application is up

bdw429s · Answer

It seems more likely that this is a re init sort of scenario where ColdBox is doing a tear down rebuild itself in onRequestStart

sknowlton · Answer

That used to be the case but 50 or 60 snapshots of Lucee ago we noticed it wasn t the case and we started seeing our legacy app stuff which used to wait for Coldbox to just plow ahead Haven t nailed down exactly where the train ran off the tracks

sknowlton · Answer

I don t think it s doing a teardown rebuild

bdw429s · Answer

very interesting What version of Lucee are you on

bdw429s · Answer

I know there was at least one fix in 5 3 9 that relates to the app initialization so anything is possible

sknowlton · Answer

5 3 9 133 but we started seeing this stuff in the 5 3 9 80 rc or slightly before then

bdw429s · Answer

Some console logs with timestamps from inside the app start and the on request may be useful to prove if they re going out of order

bdw429s · Answer

Also the full stack trace when it errors may help as well

sknowlton · Answer

Here s a piece of one from the container start ```OR runwar context lucee runtime exp ExpressionException key cbController doesn t exist at lucee runtime type util StructSupport invalidKey StructSupport java 67 at lucee runtime type StructImpl get StructImpl java 139 at coldbox system bootstrap cfc$cf udfCall1 coldbox system Bootstrap cfc 557 at coldbox system bootstrap cfc$cf udfCall coldbox system Bootstrap cfc at lucee runtime type UDFImpl implementation UDFImpl java 112 at lucee runtime type UDFImpl call UDFImpl java 350 at lucee runtime type UDFImpl call UDFImpl java 223 at lucee runtime ComponentImpl call ComponentImpl java 697 at lucee runtime ComponentImpl call ComponentImpl java 585 at lucee runtime ComponentImpl call ComponentImpl java 1932 at lucee runtime util VariableUtilImpl callFunctionWithoutNamedValues VariableUtilImpl java 787 at lucee runtime PageContextImpl getFunction PageContextImpl java 1762 at application cfc$cf udfCall Application cfc 412 at lucee runtime type UDFImpl implementation UDFImpl java 112 at lucee runtime type UDFImpl call UDFImpl java 350 at lucee runtime type UDFImpl call UDFImpl java 223 at lucee runtime ComponentImpl call ComponentImpl java 697 at lucee runtime ComponentImpl call ComponentImpl java 585 at lucee runtime ComponentImpl call ComponentImpl java 1932 at lucee runtime listener ModernAppListener call ModernAppListener java 444 at lucee runtime listener ModernAppListener onSessionStart ModernAppListener java 345 at lucee runtime PageContextImpl initApplicationContext PageContextImpl java 3182 at lucee runtime listener ModernAppListener onRequest ModernAppListener java 122 at lucee runtime listener ModernAppListener onRequest ModernAppListener java 107 at lucee runtime PageContextImpl execute PageContextImpl java 2475 at lucee runtime PageContextImpl execute PageContextImpl java 2465 at lucee runtime PageContextImpl executeCFML PageContextImpl java 2436 at lucee runtime engine Request exe Request java 45 at lucee runtime engine CFMLEngineImpl service CFMLEngineImpl java 1194 at lucee runtime engine CFMLEngineImpl serviceCFML CFMLEngineImpl java 1140 at lucee loader engine CFMLEngineWrapper serviceCFML CFMLEngineWrapper java 97 at lucee loader servlet CFMLServlet service CFMLServlet java 51 at javax servlet http HttpServlet service HttpServlet java 590 at io undertow servlet handlers ServletHandler handleRequest ServletHandler java 74 at io undertow servlet handlers FilterHandler$FilterChainImpl doFilter FilterHandler java 129 at org cfmlprojects regexpathinfofilter RegexPathInfoFilter doFilter RegexPathInfoFilter java 47 at io undertow servlet core ManagedFilter doFilter ManagedFilter java 61 at io undertow servlet handlers FilterHandler$FilterChainImpl doFilter FilterHandler java 131 at io undertow servlet handlers FilterHandler handleRequest FilterHandler java 84 at io undertow servlet handlers security ServletSecurityRoleHandler handleRequest ServletSecurityRoleHandler java 62 at io undertow servlet handlers ServletChain$1 handleRequest ServletChain java 68 at io undertow servlet handlers ServletDispatchingHandler handleRequest ServletDispatchingHandler java 36 at io undertow servlet handlers RedirectDirHandler handleRequest RedirectDirHandler java 68 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow servlet handlers ServletInitialHandler dispatchRequest ServletInitialHandler java 257 at io undertow servlet handlers ServletInitialHandler dispatchToPath ServletInitialHandler java 182 at io undertow servlet spec RequestDispatcherImpl forwardImpl RequestDispatcherImpl java 225 at io undertow servlet spec RequestDispatcherImpl forwardImplSetup RequestDispatcherImpl java 147 at io undertow servlet spec RequestDispatcherImpl forward RequestDispatcherImpl java 110 at org cfmlprojects regexpathinfofilter RegexPathInfoFilter doFilter RegexPathInfoFilter java 45 at io undertow servlet core ManagedFilter doFilter ManagedFilter java 61 at io undertow servlet handlers FilterHandler$FilterChainImpl doFilter FilterHandler java 131 at io undertow servlet handlers FilterHandler handleRequest FilterHandler java 84 at io undertow servlet handlers security ServletSecurityRoleHandler handleRequest ServletSecurityRoleHandler java 62 at io undertow servlet handlers ServletChain$1 handleRequest ServletChain java 68 at io undertow servlet handlers ServletDispatchingHandler handleRequest ServletDispatchingHandler java 36 at io undertow servlet handlers RedirectDirHandler handleRequest RedirectDirHandler java 68 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow servlet handlers ServletInitialHandler dispatchRequest ServletInitialHandler java 257 at io undertow servlet handlers ServletInitialHandler dispatchToPath ServletInitialHandler java 182 at io undertow servlet spec RequestDispatcherImpl forwardImpl RequestDispatcherImpl java 225 at io undertow servlet spec RequestDispatcherImpl forwardImplSetup RequestDispatcherImpl java 147 at io undertow servlet spec RequestDispatcherImpl forward RequestDispatcherImpl java 110 at org tuckey web filters urlrewrite NormalRewrittenUrl doRewrite NormalRewrittenUrl java 215 at org tuckey web filters urlrewrite RuleChain handleRewrite RuleChain java 171 at org tuckey web filters urlrewrite RuleChain doRules RuleChain java 145 at org tuckey web filters urlrewrite UrlRewriter processRequest UrlRewriter java 92 at org tuckey web filters urlrewrite UrlRewriteFilter doFilter UrlRewriteFilter java 405 at io undertow servlet core ManagedFilter doFilter ManagedFilter java 61 at io undertow servlet handlers FilterHandler$FilterChainImpl doFilter FilterHandler java 131 at io undertow servlet handlers FilterHandler handleRequest FilterHandler java 84 at io undertow servlet handlers security ServletSecurityRoleHandler handleRequest ServletSecurityRoleHandler java 62 at io undertow servlet handlers ServletChain$1 handleRequest ServletChain java 68 at io undertow servlet handlers ServletDispatchingHandler handleRequest ServletDispatchingHandler java 36 at io undertow servlet handlers RedirectDirHandler handleRequest RedirectDirHandler java 68 at io undertow servlet handlers security SSLInformationAssociationHandler handleRequest SSLInformationAssociationHandler java 117 at io undertow servlet handlers security ServletAuthenticationCallHandler handleRequest ServletAuthenticationCallHandler java 57 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow security handlers AbstractConfidentialityHandler handleRequest AbstractConfidentialityHandler java 46 at io undertow servlet handlers security ServletConfidentialityConstraintHandler handleRequest ServletConfidentialityConstraintHandler java 64 at io undertow security handlers AuthenticationMechanismsHandler handleRequest AuthenticationMechanismsHandler java 60 at io undertow servlet handlers security CachedAuthenticatedSessionHandler handleRequest CachedAuthenticatedSessionHandler java 77 at io undertow security handlers AbstractSecurityContextAssociationHandler handleRequest AbstractSecurityContextAssociationHandler java 43 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow servlet handlers SendErrorPageHandler handleRequest SendErrorPageHandler java 52 at io undertow server handlers PredicateHandler handleRequest PredicateHandler java 43 at io undertow servlet handlers ServletInitialHandler handleFirstRequest ServletInitialHandler java 275 at io undertow servlet handlers ServletInitialHandler access$100 ServletInitialHandler java 79 at io undertow servlet handlers ServletInitialHandler$2 call ServletInitialHandler java 134 at io undertow servlet handlers ServletInitialHandler$2 call ServletInitialHandler java 131 at io undertow servlet core Serv```

bdw429s · Answer

Is it possible there are two requests hitting the server at the same time or can you reproduce it in a vacuum with only a single hit

sknowlton · Answer

It s possible between the healthcheck and us but this is a local dev container

sknowlton · Answer

I don t see how it s possible for Bootstrap cfc to be on line 557 and not have cbController

bdw429s · Answer

What s on line ```at application cfc$cf udfCall Application cfc 412 ```

bdw429s · Answer

The stack almost makes it look like it s an onsessionstart

sknowlton · Answer

It is ``` public void function onSessionStart if structKeyExists application cbBootstrap onApplicationStart application cbBootStrap onSessionStart ```

sknowlton · Answer

it s not triggering the if 412 is just the onSessionStart

bdw429s · Answer

Ahh so that error isn t coming from onrequest

sknowlton · Answer

we have others that are coming from onRequest

sknowlton · Answer

They all go away after a couple seconds

bdw429s · Answer

So the question is whether or not Lucee makes the onrequeststart method wait fo rthe app to be initialized

sknowlton · Answer

Maybe something is triggering the session prior to the bootstrap being finished and it is doing a teardown rebuild from that if

sknowlton · Answer

and I should just replace that if onApplicationStart with a while to have it wait for cbBootstrap to finish

bdw429s · Answer

You d have to be careful with a while if there is a legit issue with the app coming up you ll have threads that hang forever

bdw429s · Answer

I wonder if we can create a simple test case that proves stuff goes out of order

sknowlton · Answer

I guess the question is what should onSessionStart do if cbBootstrap doesn t exist just return

sknowlton · Answer

say sorry pal no session for you

sknowlton · Answer

I guess we don t have anything really happening in our onSessionStart

sknowlton · Answer

so just whatever Coldbox does with it

bdw429s · Answer

It could just not make the call but of course that means if you have important logic in your COldBox on sessions start handler you could get an incomplete session

bdw429s · Answer

If ColdBox doesn t actually have an on session start handler then it s just boilerplate

bdw429s · Answer

On a related note I would probably consider it a bug that ColdBox s session start end handlers don t have the fail fast logic in them

bdw429s · Answer

In other words they should check and ensure the framework isn t in mid reinit just like onRequest does

bdw429s · Answer

Just on the off chance coldbox is somehow mid reinit even though you ve said it shouldn t be

sknowlton · Answer

got no errors when I took out that maybe re bootstrap Coldbox in onSessionStart call but not sure we were getting errors 100 of the time previously Will keep an eye on it this is one of those moles that only pops up every so often so it hasn t had much attention on it before now

sknowlton · Answer

I think we were causing it to reinit when any session tried to start before the original init was totally done

bdw429s · Answer

That would make sense

bdw429s · Answer

even though I don t THINK a session should be allowed to start until the app is up

bdw429s · Answer

I m doing a quick test to see if I can get them to fire out of order

wil-shiftinsert · Answer

I have seen that behaviour before i e a session start before the application is started

wil-shiftinsert · Answer

Ok now I remember If you create some object in application cfc and access the application scope in the constructor of this object it will fire onsessionstart or onrequeststart before the application has been started We had this scenario with the cborm event handler <https luceeserver atlassian net browse LDEV 3883>

bdw429s · Answer

ooh that s an interesting combination

wil-shiftinsert · Answer

There s also a cborm or coldbox bug for that Not sure if we should blame coldbox or cborm or lucee

wil-shiftinsert · Answer

sknowlton · Answer

Can anybody articulate a use case for why inside of Application cfc you reference the application scope that should trigger a session or request It seems counter intuitive

wil-shiftinsert · Answer

Sam I totally agree But this is exactly what the ORMEventhandler does since coldbox 6 5 I am just reading how Luis fixed this bug

wil-shiftinsert · Answer

I spent several days finding out why cborm was broken It was only some stupid test project to compare quick and cborm but I couldn t understand And the cborm event handler has to be defined before coldbox starts

sknowlton · Answer

yeah because of how Hibernate loads before everything reason 553 I don t miss Hibernate

bdw429s · Answer

< sknowlton> Is hibernate active on the app in question where you re seeing this

sknowlton · Answer

Yes

sknowlton · Answer

Not super active anymore but not dead yet

wil-shiftinsert · Answer

There are plenty of reasons to hate hibernate I could say the same for all bugs and performance problems I had in some other modules

wil-shiftinsert · Answer

If you have some active ORM event handler it could cause some nasty side effects Or just break without a decent error message

sknowlton · Answer

That s not what s breaking though and we don t have any custom event handlers

wil-shiftinsert · Answer

Well than that s not causing out of order session and applicationstart Just mentioning it is possible because we wasted a lot of time on it And I think it is a Lucee bug I think it shouldn t be allowed and need some proper exceptions

bdw429s · Answer

Man I can t seem to get a repro for this I created this `Application cfc` ```component this name= brad this sessionManagement=true function onApplicationStart systemoutput onApplicationStart getTickCount 1 new myClass sleep 5000 systemoutput onApplicationStart DONE getTickCount 1 function onRequestStart systemoutput onRequestStart getTickCount 1 function onSessionStart systemoutput onSessionStart getTickCount 1 ``` And then `myClass cfc` is just ```component function init application foo = bar systemoutput application foo 1 ``` and there is an empty `index cfm` When I fire two requests starting the app at the same time I get this ``` INFO onApplicationStart 1652290966351 INFO bar INFO onApplicationStart DONE 1652290971369 INFO onSessionStart 1652290971389 INFO onSessionStart 1652290971390 INFO onRequestStart 1652290971396 INFO onRequestStart 1652290971397``` which would appear everything is waiting for `onApplicationStart ` to finish before proceeding

bdw429s · Answer

There must be another piece to the puzzle

sknowlton · Answer

it s cause you named the application `brad` it s just doing everything too quickly

sknowlton · Answer

name it `sknowlton` and it ll laze around firing random requests and promoting entropy

bdw429s · Answer

Looks like Pothys repro case did include ORM event handlers <https github com lucee Lucee pull 1605 files diff baeb0543fbfff4e06de8e05211b34a6cc4e3965efc3143dd12dbcd13dd2953df>

wil-shiftinsert · Answer

You are creating the myClass inside of the onApplicationStart If you create this class directly in Application cfc it will probably fire in the wrong order

wil-shiftinsert · Answer

I saw Luis fixed the coldbox side for the orm stuff So don t try that on new box versions slightly smiling face

bdw429s · Answer

Moving ```new myClass ``` to the Application cfc pseudoconstructor didn t do it I even had it touch the session scope too which is rather interesting since it means it was setting session variables before onSessionStart actually ran thinking face

wil-shiftinsert · Answer

Maybe it is specific to certain Lucee versions Interesting that you can set session variables

sknowlton · Answer

Reviving this thread with a new symptom of a similar same issue just brought up a container locally and on the first request got a `The target ExplicitCall requested a missing dependency with a Name of and DSL of StackSportsService stackSports ` with the stack trace pointing to `afterAspectsLoad ` in one of our interceptors The relevant `stackSports` module wasn t loaded yet but it was firing `afterAspectsLoad ` Am I using the wrong interception point here or is that not supposed to happen