Shiro+Grails, controllers having slow init time first time accessed

classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

Shiro+Grails, controllers having slow init time first time accessed

matero
Hi,

We're using shiro to secure a Grails application, and it works fantastically
:)
But we have noted that grails controllers (and only the controllers) are
consuming too much time to init the  first time they are accessed.
After fine tunning loggers and debugging we've find out that part of the
problem *seems* to be related to some kind of shiro configuration. This is
what logs are stating:

2018-04-03 10:10:13.247 DEBUG --- [     http-nio-8080-exec-4]
o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of
singleton bean
'org.springframework.transaction.config.internalTransactionAdvisor'
2018-04-03 10:10:13.247 DEBUG --- [     http-nio-8080-exec-4]
o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of
singleton bean 'shiroAttributeSourceAdvisor'
2018-04-03 10:10:15.478 DEBUG --- [     http-nio-8080-exec-4]
.p.b.ServiceInitLoggingBeanPostProcessor : Initialized
***.platform.security.UserController in 4507 ms

as you can see, between accessing the shiroAttributeSourceAdvisor and statig
that the bean is fully initiallized, there's more than 2 seconds.
Depending on the controller, this lapse goes from 2s to almost 5s.
I'm thinking that there's a missconfiguration on our shiro side.

I've looked at our realm and the AuthorizationAttributeSourceAdvisor but all
seems to be working ok.

Can someone tell me if this is the expected behavior or what should I check
to look for some missconfig or a hint to improve this times, it would be
awesome.

Regards,
Juanjo





--
Sent from: http://shiro-user.582556.n2.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Shiro+Grails, controllers having slow init time first time accessed

matero
I forgotten to state, this is the env environment,

$ grails -v
| Grails Version: 3.3.3
| Groovy Version: 2.4.14
| JVM Version: 1.8.0_152

The pc where I'm having this logs has an Intel Core i7-8700K Coffee Lake
6-Core 3.7 GHz (4.7 GHz Turbo) + GIGABYTE Z370XP SLI + 32GB DDR4 2400Mhz

Regards,
Juanjo



--
Sent from: http://shiro-user.582556.n2.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Shiro+Grails, controllers having slow init time first time accessed

Brian Demers
In reply to this post by matero
My guess is that is something specific to the Grails plugin.  It doesn't sound like it should be expected though.

Is it just the first request after starting your app or the first request per user?

On Tue, Apr 3, 2018 at 9:21 AM, matero <[hidden email]> wrote:
Hi,

We're using shiro to secure a Grails application, and it works fantastically
:)
But we have noted that grails controllers (and only the controllers) are
consuming too much time to init the  first time they are accessed.
After fine tunning loggers and debugging we've find out that part of the
problem *seems* to be related to some kind of shiro configuration. This is
what logs are stating:

2018-04-03 10:10:13.247 DEBUG --- [     http-nio-8080-exec-4]
o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of
singleton bean
'org.springframework.transaction.config.internalTransactionAdvisor'
2018-04-03 10:10:13.247 DEBUG --- [     http-nio-8080-exec-4]
o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of
singleton bean 'shiroAttributeSourceAdvisor'
2018-04-03 10:10:15.478 DEBUG --- [     http-nio-8080-exec-4]
.p.b.ServiceInitLoggingBeanPostProcessor : Initialized
***.platform.security.UserController in 4507 ms

as you can see, between accessing the shiroAttributeSourceAdvisor and statig
that the bean is fully initiallized, there's more than 2 seconds.
Depending on the controller, this lapse goes from 2s to almost 5s.
I'm thinking that there's a missconfiguration on our shiro side.

I've looked at our realm and the AuthorizationAttributeSourceAdvisor but all
seems to be working ok.

Can someone tell me if this is the expected behavior or what should I check
to look for some missconfig or a hint to improve this times, it would be
awesome.

Regards,
Juanjo





--
Sent from: http://shiro-user.582556.n2.nabble.com/

Reply | Threaded
Open this post in threaded view
|

Re: Shiro+Grails, controllers having slow init time first time accessed

matero
Brian Demers wrote
> ...
> Is it just the first request after starting your app or the first request
> per user?
> ...

Its only the first time accessed & initiallized.
As they are all singleton controllers, it's only one time.



--
Sent from: http://shiro-user.582556.n2.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Shiro+Grails, controllers having slow init time first time accessed

Brian Demers
I'm not a grails guy, but is there an eager setting to not make them lazy load?

On Tue, Apr 3, 2018 at 10:34 AM, matero <[hidden email]> wrote:
Brian Demers wrote
> ...
> Is it just the first request after starting your app or the first request
> per user?
> ...

Its only the first time accessed & initiallized.
As they are all singleton controllers, it's only one time.

Reply | Threaded
Open this post in threaded view
|

Re: Shiro+Grails, controllers having slow init time first time accessed

matero
Brian Demers wrote
> I'm not a grails guy, but is there an eager setting to not make them lazy
> load?

Yep, but setting it for all controllers makes the app startup times too big
-> makes development process painfull and integration/functional testing
times skyrocket

But, the strange thing is that if the controller has lazyInit = false, the
time consumed by the shiro related advisor is less (almost 1 second in the
case of the UserController)




--
Sent from: http://shiro-user.582556.n2.nabble.com/