[Vratpor4] Tempo de inicialização do Tomcat

Oi pessoal,
Usando o Vraptor 4 eu notei uma diferença de tempo na inicialização muito grande em relação ao Vraptor 3. Uando Vraptor 3 o servidor iniciava em 5 segundos mais ou menos. Os projetos mais pesados iniciavam em no máximo 10 segundos. Mas usando o Vraptor 4 esse tempo passou a ser uns 20 segundos. Esse tempo de inicialização é normal ou eu estou configurando algo errado? Um detalhe que eu percebi é que eu não usava Maven e passei a usar quando migrei para o Vraptor 4. Pode ser o maven? Tem como reduzir esse tempo de inicialização de alguma forma?

O Maven pode influenciar pois ele pode estar empacotando mais bibliotecas do que necessário.

Tente montar um pacote apenas com as bibliotecas necessárias, de modo manual.

Mas o Maven é acionado toda vez que eu rodo o servidor? Teve um projeto que eu incluí apenas as dependências que eu preciso, mesmo assim ele demora pra iniciar.

[quote=gutomarzagao]Mas o Maven é acionado toda vez que eu rodo o servidor? Teve um projeto que eu incluí apenas as dependências que eu preciso, mesmo assim ele demora pra iniciar.[/quote]O maven adiciona as bibliotecas que seu projeto precisa dentro do war/ear.

Se vc rodar 15x ele vai empacotar tudo 15x.

Se você coloca que precisa do JPA ele vai adicionar tudo de JPA. Imagine que o JPA precise da dependencia “A” e por um erro de pom, “A” precisa de B e C mas C é usado apenas em teste. Isso é muito comum se voce para olhar os projetos open sources.

Pelo que me parece, não é um problema do Maven, porque quando eu dou “Maven install”, ele leva 5,338 segundos pra empacotar. Se fosse um problema do Maven, teria que demorar essa operação, não? O que mais poderia ser?

[quote=gutomarzagao]Pelo que me parece, não é um problema do Maven, porque quando eu dou “Maven install”, ele leva 5,338 segundos pra empacotar. Se fosse um problema do Maven, teria que demorar essa operação, não? O que mais poderia ser?[/quote]Pelo visto você ainda não entendeu…

Quando você usava o vraptor 3 você pegava apenas o que era necessário e empacotava na mão, certo?

Ao usar no maven, o que te garante que ao colocar a biblioteca “A” está indo apenas a “A”? O que não garante que a “A” que precisa da “B, C, D” também não está indo empacotado? É por isso que eu estou falando que o excesso de bibliotecas pode ser o problema, não quer dizer que é.

Por isso que eu disse para você fazer o teste de empacotar tudo na mão.

Eu uso o Eclipse. Então, quando eu usava o Maven 3, eu fazia apenas clicava com o botão direito no servidor e clicava em “Debug”. Não sei se o eclipse empacota o projeto sozinho ou se ele só copia as pastas.

Eu acho que ainda não estou entendendo muito bem. Vamos por partes:
1- O que significa exatamente “empacotar”? É o mesmo que gerar o “war” da aplicação?
2- Fiz o seguinte teste: exportei o “war” da aplicação, coloquei na pasta webapps do Tomcat e iniciei o servidor. Ainda assim ele demorou 20 segundos pra iniciar. Ou seja, gerar o “war” não deve estar sendo o problema. Certo?
3- Fiz uma comparação das bibliotecas de um projeto do Vraptor 4 (lento) e de um Vraptor 3 (rápido). Fiz assim: gerei o arquivo war e fui ver as bibliotecas que estavam empacotadas lá. Ou seja, nesse cenário, eu já estou considerando as bibliotecas “A”, “B”, “C” e “D” da situação que vc propôs, certo? Mesmo assim, no Vraptor 3 o meu projeto teve 51 bibliotecas que somam 20 MB e no Vraptor 4 meu projeto teve 31 bibliotecas que somam 7 MB. Ou seja, não parece ser excesso de biblioteca, certo?
4- Não sei como fazer esse teste de empacotar tudo na mão. Como posso fazer? Criando um Web Project sem usar o Maven?

[quote=gutomarzagao]Eu uso o Eclipse. Então, quando eu usava o Maven 3, eu fazia apenas clicava com o botão direito no servidor e clicava em “Debug”. Não sei se o eclipse empacota o projeto sozinho ou se ele só copia as pastas.

Eu acho que ainda não estou entendendo muito bem. Vamos por partes:
1- O que significa exatamente “empacotar”? É o mesmo que gerar o “war” da aplicação?
2- Fiz o seguinte teste: exportei o “war” da aplicação, coloquei na pasta webapps do Tomcat e iniciei o servidor. Ainda assim ele demorou 20 segundos pra iniciar. Ou seja, gerar o “war” não deve estar sendo o problema. Certo?
3- Fiz uma comparação das bibliotecas de um projeto do Vraptor 4 (lento) e de um Vraptor 3 (rápido). Fiz assim: gerei o arquivo war e fui ver as bibliotecas que estavam empacotadas lá. Ou seja, nesse cenário, eu já estou considerando as bibliotecas “A”, “B”, “C” e “D” da situação que vc propôs, certo? Mesmo assim, no Vraptor 3 o meu projeto teve 51 bibliotecas que somam 20 MB e no Vraptor 4 meu projeto teve 31 bibliotecas que somam 7 MB. Ou seja, não parece ser excesso de biblioteca, certo?
4- Não sei como fazer esse teste de empacotar tudo na mão. Como posso fazer? Criando um Web Project sem usar o Maven?[/quote]

1 -> Sim

2 -> Não é esse o problema porque o war já está gerado

4 -> Sim

O problema pode estar no fato do seu AS processar as bibliotecas, mas isso não é certeza. Pode se também que o Vraptor 4 leve mais tempo para processar o deploy, você poderia fazer alguns testes em relação a isso, mas vai dar um certo trabalho :slight_smile:

Eu criei um projeto comum (sem Maven) e adicionei todas as dependências geradas no projeto com Maven. O resultado foi o mesmo: 30 segundos de inicialização. O que mais pode ser? Tem algum outro teste que eu poderia fazer (mesmo que dê trabalho)? Esperar 30 segundos pra cada alteração que eu fizer no código de back-end é inviável :frowning:

30 segundos para esperar o servidor subir com a aplicação no ar é inviável para você? Fiquei curioso para saber o motivo.

Lembrando que se você alterar um código com o servidor em modo debug não precisará fazer deploy da aplicação novamente (claro, se alterar o algoritmo de um método e não uma estrutura de uma classe).

Ah, pode ser que seja questão de costume, mas eu acho 30 segundos muito tempo pra esperar em cada alteração… E pelo que eu conheço de outras linguagens/frameworks não demora tanto assim. Tem muitos por aí que são aparentemente instantâneos.

Tentou deixar o log de debug do VRaptor (e do hibernate e alguma outra lib) habilitado pra ver o que pode estar parando…

não acho que esse problema esteja acontecendo em geral, pode ser alguma coisa que está sendo inicializada junto com o servidor agora e era lazy antes.

Tem basicamente 2 pontos que fica lento:

  • INFORMAÇÕES: Starting Servlet Engine: Apache Tomcat/8.0.14 - demora uns 8 segundos (acho que esse tempo é normal)
  • INFO: HV000001: Hibernate Validator 5.1.1.Final - demora uns 22 segundos (esse tempo que eu to achando alto)

1- O que pode estar causando lentidão no Hibernate Validator? O Vraptor mudou alguma coisa do 3.5 pro 4.0 nesse sentido?

2- Eu também estou tendo problemas com o log. Primeiro eu notei que as rotas que apareceriam na inicialização do Tomcat não aparecem mais. É pra ser assim mesmo? E agora eu habilitei o log de DEBUG do Vraptor e do Hibernate no log4j.xml, mas não imprimiu nada de DEBUG, só de INFO… Tem que configurar mais alguma coisa pra poder habilitar?

Sobre a segunda dúvida, já consegui resolver. Estava faltando a dependência do log4j no pom.xml. Agora eu consegui rodar no modo debug e vi que logo no inicio tem um ponto que não aparece logs por 16 segundos:

01:29:25,143 DEBUG [logging ] Logging Provider: org.jboss.logging.Log4jLoggerProvider 01:29:25,210 INFO [Version ] WELD-000900: 2.1.2 (Final) 01:29:26,459 INFO [Bootstrap ] WELD-000101: Transactional services not available. Injection of @Inject UserTransaction not available. Transactional observers will be invoked synchronously. 01:29:26,635 DEBUG [Bootstrap ] WELD-000124: Using 2 threads for bootstrap 01:29:27,339 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|ApplicationContext 01:29:27,382 DEBUG [Reflection ] WELD-000601: interface javax.inject.Singleton is missing @Target. Weld will use this annotation, however this may make the application unportable. 01:29:27,382 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|SingletonContext 01:29:27,395 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|BoundSessionContext 01:29:27,401 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|BoundConversationContext 01:29:27,408 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|BoundRequestContext 01:29:27,409 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|RequestContext 01:29:27,411 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|DependentContext 01:29:27,413 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|HttpSessionContext 01:29:27,418 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|HttpSessionDestructionContext 01:29:27,418 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|HttpConversationContext 01:29:27,418 DEBUG [Bootstrap ] WELD-000106: Bean: WELD|AbstractSyntheticBean|deployment|HttpRequestContext 01:29:27,616 DEBUG [Bootstrap ] WELD-000106: Bean: Built-in Bean [javax.enterprise.inject.spi.BeanManager] with qualifiers [@Default] 01:29:27,619 DEBUG [Bootstrap ] WELD-000106: Bean: Built-in Bean [org.jboss.weld.manager.BeanManagerImpl] with qualifiers [@Default] 01:29:27,714 INFO [Version ] HV000001: Hibernate Validator 5.1.1.Final 01:29:27,761 DEBUG [DefaultTraversableResolver] Found javax.persistence.Persistence on classpath containing 'getPersistenceUtil'. Assuming JPA 2 environment. Trying to instantiate JPA aware TraversableResolver 01:29:27,766 DEBUG [DefaultTraversableResolver] Instantiated JPA aware TraversableResolver of type org.hibernate.validator.internal.engine.resolver.JPATraversableResolver. 01:29:27,810 DEBUG [ValidationXmlParser ] Trying to load META-INF/validation.xml for XML based Validator configuration. 01:29:27,839 DEBUG [ValidationXmlParser ] No META-INF/validation.xml found. Using annotation based configuration only. 01:29:28,584 DEBUG [Bootstrap ] WELD-000106: Bean: Extension [class org.hibernate.validator.internal.cdi.ValidationExtension] with qualifiers [@Default]; jar:file:/C:/Users/Guto/workspace/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/fleec/WEB-INF/lib/hibernate-validator-cdi-5.1.1.Final.jar!/META-INF/services/javax.enterprise.inject.spi.Extension@1[org.hibernate.validator.internal.cdi.ValidationExtension@51e43d0e] 01:29:28,661 DEBUG [Bootstrap ] WELD-000106: Bean: Built-in Bean [javax.enterprise.inject.spi.BeanManager] with qualifiers [@Default] 01:29:28,662 DEBUG [Bootstrap ] WELD-000106: Bean: Built-in Bean [org.jboss.weld.manager.BeanManagerImpl] with qualifiers [@Default] 01:29:44,459 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={message={javax.validation.constraints.NotNull.message}, groups=[Ljava.lang.Class;@6681b8df, payload=[Ljava.lang.Class;@5e6fcce1}, constraintType=GENERIC}. 01:29:44,460 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={groups=[Ljava.lang.Class;@5031410a, min=1, message={javax.validation.constraints.Size.message}, max=2147483647, payload=[Ljava.lang.Class;@2ff788ac}, constraintType=GENERIC}. 01:29:44,505 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={message={javax.validation.constraints.NotNull.message}, groups=[Ljava.lang.Class;@31589efb, payload=[Ljava.lang.Class;@69b0ab61}, constraintType=GENERIC}. 01:29:44,506 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={groups=[Ljava.lang.Class;@26e20958, min=1, message={javax.validation.constraints.Size.message}, max=2147483647, payload=[Ljava.lang.Class;@29d823fc}, constraintType=GENERIC}. 01:29:44,510 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Pattern, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={flags=[Ljavax.validation.constraints.Pattern$Flag;@6eb4ff55, groups=[Ljava.lang.Class;@248714f6, regexp=.*, message={javax.validation.constraints.Pattern.message}, payload=[Ljava.lang.Class;@38ff3812}, constraintType=GENERIC}. 01:29:44,513 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={message={javax.validation.constraints.NotNull.message}, groups=[Ljava.lang.Class;@7525df56, payload=[Ljava.lang.Class;@12721317}, constraintType=GENERIC}. 01:29:44,513 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={groups=[Ljava.lang.Class;@4fa9867, min=1, message={javax.validation.constraints.Size.message}, max=2147483647, payload=[Ljava.lang.Class;@6abcd679}, constraintType=GENERIC}. 01:29:46,792 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={message={javax.validation.constraints.NotNull.message}, groups=[Ljava.lang.Class;@c322190, payload=[Ljava.lang.Class;@49af1467}, constraintType=GENERIC}. 01:29:46,796 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={groups=[Ljava.lang.Class;@1089cd71, min=1, message={javax.validation.constraints.Size.message}, max=2147483647, payload=[Ljava.lang.Class;@46e3eff4}, constraintType=GENERIC}. 01:29:46,797 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Pattern, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={flags=[Ljavax.validation.constraints.Pattern$Flag;@6eb4ff55, groups=[Ljava.lang.Class;@11c654cb, regexp=.*, message={javax.validation.constraints.Pattern.message}, payload=[Ljava.lang.Class;@1e8dc2f5}, constraintType=GENERIC}. 01:29:49,224 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={message={javax.validation.constraints.NotNull.message}, groups=[Ljava.lang.Class;@2732a570, payload=[Ljava.lang.Class;@19f28651}, constraintType=GENERIC}. 01:29:49,225 DEBUG [ConstraintDescriptorImpl] Adding composing constraint: ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size, payloads=[], hasComposingConstraints=true, isReportAsSingleInvalidConstraint=false, elementType=FIELD, definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default], attributes={groups=[Ljava.lang.Class;@6c285246, min=1, message={javax.validation.constraints.Size.message}, max=2147483647, payload=[Ljava.lang.Class;@f93e003}, constraintType=GENERIC}.

Percebe que o tempo vai de 01:29:28,661 para 01:29:44,459. É normal isso?

Parece ser na hora que ele scaneia todas as classes do seu sistema procurando por anotações do cdi e coisas do tipo…

seu projeto tem muitas classes? muitos jars?

Tenho só 10 classes, mas tenho 62 jars (não sei se é muito). São praticamente só os jars que vem com o Vraptor.