-
1. Re: Performance problem with embedded EJB :/
bill.burke Dec 8, 2005 12:17 PM (in response to jacekolszak)That doesn't seem right at all. How many EJBs/EntityManagers are you deploying? I've done some profiling with a EJB jar and one EntityManager being deployed. It takes 4-5 secs on my machine (3.4 GhZ). 80% of the time is in bootstrapping the kernel. This should be a fixed time. The 20% left, most of it is initializing Hibernate.
Also, maybe you are not writing your JUnit test correctly and are bootstrapping the container with every test method? Please download Alpha 3 and check out the JUnit example for how to initalize the kernel just once for the entire class run.
Let me know....
Bill -
2. Re: Performance problem with embedded EJB :/
jacekolszak Dec 8, 2005 12:34 PM (in response to jacekolszak)Hmm.... Maybe I should say that I have 30 entities and 80 stateless beans :) I'm using one entity manager. The same problem with performance I've with my web-application (with embedded ejb3). I've Celeron 2.41 and 1 GB Ram.
Second thing is the time which takes operations on database - simple request which gets all records from db ( for example 5 records from one table) takes about 15-120ms -
3. Re: Performance problem with embedded EJB :/
slaboure Dec 8, 2005 1:03 PM (in response to jacekolszak)Can you post a log file that shows the deploy process with time information?
-
4. Re: Performance problem with embedded EJB :/
jacekolszak Dec 9, 2005 9:57 AM (in response to jacekolszak)Here is my log:
15:42:25,432 WARN XsdBinder:1097 - NOT HANDLED WILDCARD IN GLOBAL MODEL GROUP 15:42:35,525 INFO Environment:474 - Hibernate 3.1 rc1 15:42:35,540 INFO Environment:504 - hibernate.properties not found 15:42:35,540 INFO Environment:520 - using CGLIB reflection optimizer 15:42:35,540 INFO Environment:550 - using JDK 1.4 java.sql.Timestamp handling 15:42:35,853 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.adresfirmy.AdresFirmy 15:42:35,868 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.adreskontrahenta.AdresKontrahenta 15:42:35,900 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.banki.Bank 15:42:35,915 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.dokksiegowy.DokKsiegowy 15:42:35,947 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.firma.Firma 15:42:35,978 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.grupavat.GrupaVat 15:42:35,993 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kartoteka.Kartoteka 15:42:36,009 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.konffirma.KonfFirma 15:42:36,040 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontaktfirma.KontaktFirma 15:42:36,056 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontaktkontrah.KontaktKontrah 15:42:36,072 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowe.KontoBankowe 15:42:36,072 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowefirmy.KontoBankoweFirmy 15:42:36,087 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowekontrahenta.KontoBankoweKontrahenta 15:42:36,103 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowepracownika.KontoBankowePracownika 15:42:36,118 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankoweurzedu.KontoBankoweUrzedu 15:42:36,134 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontoksiegowe.KontoKsiegowe 15:42:36,150 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontrahent.Kontrahent 15:42:36,181 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.odsetki.Odsetki 15:42:36,197 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.okresewid.OkresEwid 15:42:36,212 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.panstwo.Panstwo 15:42:36,243 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.pracownik.Pracownik 15:42:36,259 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.rokewid.RokEwid 15:42:36,275 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.strukturaorg.StrukturaOrg 15:42:36,290 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.strukturawlasnosciowafirmy.StrukturaWlasnosciowaFirmy 15:42:36,322 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.typdokumentu.TypDokumentu 15:42:36,337 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.typdzial.TypDzial 15:42:36,337 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.typkonta.TypKonta 15:42:36,353 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.urzad.Urzad 15:42:36,384 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.uzytsys.UzytSys 15:42:36,400 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.vatstawka.VatStawka 15:42:36,431 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.waluta.Waluta 15:42:36,431 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.wojewodztwo.Wojewodztwo 15:42:36,509 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.users.Uprawnienie 15:42:36,525 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.users.Uzytkownik 15:42:37,837 INFO Configuration:1014 - processing extends queue 15:42:37,837 INFO Configuration:1018 - processing collection mappings 15:42:37,853 INFO CollectionBinder:459 - Mapping collection: pl.ramzes.ksiegi.firma.Firma.adresy -> AdresFirmy 15:42:37,853 INFO CollectionBinder:459 - Mapping collection: pl.ramzes.ksiegi.rokewid.RokEwid.okresyEwid -> OkresEwid 15:42:37,853 INFO Configuration:1027 - processing association property references 15:42:37,853 INFO Configuration:1049 - processing foreign key constraints 15:42:38,118 INFO Configuration:1014 - processing extends queue 15:42:38,118 INFO Configuration:1018 - processing collection mappings 15:42:38,118 INFO Configuration:1027 - processing association property references 15:42:38,134 INFO Configuration:1049 - processing foreign key constraints 15:42:38,150 INFO ConnectionProviderFactory:72 - Initializing connection provider: org.hibernate.ejb.InjectedDataSourceConnectionProvider 15:42:38,165 INFO InjectedDataSourceConnectionProvider:34 - Using provided datasource 15:42:38,712 INFO SettingsFactory:77 - RDBMS: PostgreSQL, version: 8.0.4 15:42:38,728 INFO SettingsFactory:78 - JDBC driver: PostgreSQL Native Driver, version: PostgreSQL 8.0 JDBC3 with SSL (build 311) 15:42:38,759 INFO Dialect:100 - Using dialect: org.hibernate.dialect.PostgreSQLDialect 15:42:38,774 INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions) 15:42:38,774 INFO TransactionManagerLookupFactory:38 - instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup 15:42:38,790 INFO TransactionManagerLookupFactory:42 - instantiated TransactionManagerLookup 15:42:38,790 INFO SettingsFactory:125 - Automatic flush during beforeCompletion(): disabled 15:42:38,790 INFO SettingsFactory:129 - Automatic session close at end of transaction: disabled 15:42:38,790 INFO SettingsFactory:136 - JDBC batch size: 15 15:42:38,806 INFO SettingsFactory:139 - JDBC batch updates for versioned data: disabled 15:42:38,806 INFO SettingsFactory:144 - Scrollable result sets: enabled 15:42:38,806 INFO SettingsFactory:152 - JDBC3 getGeneratedKeys(): disabled 15:42:38,806 INFO SettingsFactory:160 - Connection release mode: after_statement 15:42:38,806 INFO SettingsFactory:187 - Default batch fetch size: 1 15:42:38,806 INFO SettingsFactory:191 - Generate SQL with comments: disabled 15:42:38,806 INFO SettingsFactory:195 - Order SQL updates by primary key: disabled 15:42:38,806 INFO SettingsFactory:338 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory 15:42:38,821 INFO ASTQueryTranslatorFactory:21 - Using ASTQueryTranslatorFactory 15:42:38,821 INFO SettingsFactory:203 - Query language substitutions: {} 15:42:38,821 INFO SettingsFactory:209 - Second-level cache: enabled 15:42:38,821 INFO SettingsFactory:213 - Query cache: disabled 15:42:38,821 INFO SettingsFactory:325 - Cache provider: org.hibernate.cache.HashtableCacheProvider 15:42:38,821 INFO SettingsFactory:228 - Optimize cache for minimal puts: disabled 15:42:38,821 INFO SettingsFactory:237 - Structured second-level cache entries: disabled 15:42:38,837 INFO SettingsFactory:264 - Statistics: disabled 15:42:38,837 INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: enabled 15:42:38,837 INFO SettingsFactory:283 - Default entity-mode: POJO 15:42:39,196 INFO SessionFactoryImpl:155 - building session factory 15:42:41,352 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured 15:42:41,352 INFO Configuration:1014 - processing extends queue 15:42:41,368 INFO Configuration:1018 - processing collection mappings 15:42:41,368 INFO Configuration:1027 - processing association property references 15:42:41,368 INFO Configuration:1049 - processing foreign key constraints 15:42:41,368 INFO Configuration:1014 - processing extends queue 15:42:41,368 INFO Configuration:1018 - processing collection mappings 15:42:41,368 INFO Configuration:1027 - processing association property references 15:42:41,368 INFO Configuration:1049 - processing foreign key constraints 15:42:41,384 INFO SchemaExport:153 - Running hbm2ddl schema export 15:42:41,384 INFO SchemaExport:180 - exporting generated schema to database 15:42:49,742 INFO SchemaExport:200 - schema export complete 15:42:49,742 INFO Configuration:1014 - processing extends queue 15:42:49,742 INFO Configuration:1018 - processing collection mappings 15:42:49,742 INFO Configuration:1027 - processing association property references 15:42:49,742 INFO Configuration:1049 - processing foreign key constraints 15:42:49,742 INFO Configuration:1014 - processing extends queue 15:42:49,742 INFO Configuration:1018 - processing collection mappings 15:42:49,742 INFO Configuration:1027 - processing association property references 15:42:49,758 INFO Configuration:1049 - processing foreign key constraints 15:42:49,774 INFO NamingHelper:26 - JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces} 15:42:49,789 INFO SessionFactoryImpl:432 - Checking 47 named queries 15:42:53,742 INFO SessionFactoryImpl:831 - closing 15:42:53,742 INFO SchemaExport:153 - Running hbm2ddl schema export 15:42:53,758 INFO SchemaExport:180 - exporting generated schema to database 15:42:54,914 INFO SchemaExport:200 - schema export complete
Currently it takes about 35 s (30s+5second for initialize log4j and etc.)
Any ideas how to speed up the execution time? -
5. Re: Performance problem with embedded EJB :/
bill.burke Dec 12, 2005 10:55 AM (in response to jacekolszak)Well, it looks like it is taking ~ 11 seconds to export the schema from two EntityManagers using hbm2ddl schema export. Maybe you can precreate your schema in the database and shut this feature off in persistence.properties in ejb3.deployer/META-INF/persistence.properties?
Another 10 seconds looks like the initialization of the container. (1st 10 seconds). We are working on speeding that up, but it is low priority right now. -
6. Re: Performance problem with embedded EJB :/
maxandersen Dec 12, 2005 11:04 AM (in response to jacekolszak)also try and set hibernate.cglib.use_reflection_optimizer property to false (it should also remove a good deal of seconds spent in the creation of the building of your sessionfactory)
-
7. Re: Performance problem with embedded EJB :/
jacekolszak Dec 13, 2005 5:08 AM (in response to jacekolszak)Well, it looks like it is taking ~ 11 seconds to export the schema from two EntityManagers using hbm2ddl schema export. Maybe you can precreate your schema in the database and shut this feature off in persistence.properties in ejb3.deployer/META-INF/persistence.properties?
You mean change hbm2ddl.auto to update instead of create-drop ?
also try and set hibernate.cglib.use_reflection_optimizer property to false (it should also remove a good deal of seconds spent in the creation of the building of your sessionfactory)
Thanks, I set this.
Here is my current log (still not so fast, but it is better than before):10:52:52,472 WARN XsdBinder:1097 - NOT HANDLED WILDCARD IN GLOBAL MODEL GROUP 10:53:11,832 INFO Environment:474 - Hibernate 3.1 rc1 10:53:11,848 INFO Environment:504 - hibernate.properties not found 10:53:11,848 INFO Environment:520 - using CGLIB reflection optimizer 10:53:11,848 INFO Environment:550 - using JDK 1.4 java.sql.Timestamp handling 10:53:12,004 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.dbf.beans.Konfiguracja 10:53:12,035 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.adresfirmy.AdresFirmy 10:53:12,051 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.adreskontrahenta.AdresKontrahenta 10:53:12,051 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.banki.Bank 10:53:12,066 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.dokksiegowy.DokKsiegowy 10:53:12,082 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.firma.Firma 10:53:12,082 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.grupavat.GrupaVat 10:53:12,098 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kartoteka.Kartoteka 10:53:12,098 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.konffirma.KonfFirma 10:53:12,113 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontaktfirma.KontaktFirma 10:53:12,113 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontaktkontrah.KontaktKontrah 10:53:12,129 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowe.KontoBankowe 10:53:12,129 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowefirmy.KontoBankoweFirmy 10:53:12,129 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowekontrahenta.KontoBankoweKontrahenta 10:53:12,144 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankowepracownika.KontoBankowePracownika 10:53:12,144 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontobankoweurzedu.KontoBankoweUrzedu 10:53:12,160 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontoksiegowe.KontoKsiegowe 10:53:12,160 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.kontrahent.Kontrahent 10:53:12,176 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.odsetki.Odsetki 10:53:12,191 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.okresewid.OkresEwid 10:53:12,191 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.panstwo.Panstwo 10:53:12,207 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.pracownik.Pracownik 10:53:12,223 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.rokewid.RokEwid 10:53:12,223 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.strukturaorg.StrukturaOrg 10:53:12,223 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.strukturawlasnosciowafirmy.StrukturaWlasnosciowaFirmy 10:53:12,238 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.typdokumentu.TypDokumentu 10:53:12,254 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.typdzial.TypDzial 10:53:12,254 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.typkonta.TypKonta 10:53:12,254 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.urzad.Urzad 10:53:12,269 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.uzytsys.UzytSys 10:53:12,285 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.vatstawka.VatStawka 10:53:12,285 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.waluta.Waluta 10:53:12,285 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.ksiegi.wojewodztwo.Wojewodztwo 10:53:12,316 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.users.Uprawnienie 10:53:12,332 INFO Ejb3Configuration:314 - found EJB3 Entity bean: pl.ramzes.users.Uzytkownik 10:53:13,144 INFO Configuration:1014 - processing extends queue 10:53:13,160 INFO Configuration:1018 - processing collection mappings 10:53:13,160 INFO CollectionBinder:459 - Mapping collection: pl.ramzes.ksiegi.firma.Firma.adresy -> AdresFirmy 10:53:13,160 INFO CollectionBinder:459 - Mapping collection: pl.ramzes.ksiegi.rokewid.RokEwid.okresyEwid -> OkresEwid 10:53:13,160 INFO Configuration:1027 - processing association property references 10:53:13,160 INFO Configuration:1049 - processing foreign key constraints 10:53:13,379 INFO Configuration:1014 - processing extends queue 10:53:13,379 INFO Configuration:1018 - processing collection mappings 10:53:13,394 INFO Configuration:1027 - processing association property references 10:53:13,394 INFO Configuration:1049 - processing foreign key constraints 10:53:13,410 INFO ConnectionProviderFactory:72 - Initializing connection provider: org.hibernate.ejb.InjectedDataSourceConnectionProvider 10:53:13,410 INFO InjectedDataSourceConnectionProvider:34 - Using provided datasource 10:53:13,441 INFO SettingsFactory:77 - RDBMS: PostgreSQL, version: 8.0.4 10:53:13,441 INFO SettingsFactory:78 - JDBC driver: PostgreSQL Native Driver, version: PostgreSQL 8.0 JDBC3 with SSL (build 311) 10:53:13,457 INFO Dialect:100 - Using dialect: org.hibernate.dialect.PostgreSQLDialect 10:53:13,473 INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions) 10:53:13,488 INFO TransactionManagerLookupFactory:38 - instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup 10:53:13,488 INFO TransactionManagerLookupFactory:42 - instantiated TransactionManagerLookup 10:53:13,488 INFO SettingsFactory:125 - Automatic flush during beforeCompletion(): disabled 10:53:13,488 INFO SettingsFactory:129 - Automatic session close at end of transaction: disabled 10:53:13,504 INFO SettingsFactory:136 - JDBC batch size: 15 10:53:13,504 INFO SettingsFactory:139 - JDBC batch updates for versioned data: disabled 10:53:13,504 INFO SettingsFactory:144 - Scrollable result sets: enabled 10:53:13,504 INFO SettingsFactory:152 - JDBC3 getGeneratedKeys(): disabled 10:53:13,504 INFO SettingsFactory:160 - Connection release mode: after_statement 10:53:13,504 INFO SettingsFactory:187 - Default batch fetch size: 1 10:53:13,504 INFO SettingsFactory:191 - Generate SQL with comments: disabled 10:53:13,504 INFO SettingsFactory:195 - Order SQL updates by primary key: disabled 10:53:13,504 INFO SettingsFactory:338 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory 10:53:13,504 INFO ASTQueryTranslatorFactory:21 - Using ASTQueryTranslatorFactory 10:53:13,504 INFO SettingsFactory:203 - Query language substitutions: {} 10:53:13,504 INFO SettingsFactory:209 - Second-level cache: enabled 10:53:13,519 INFO SettingsFactory:213 - Query cache: disabled 10:53:13,519 INFO SettingsFactory:325 - Cache provider: org.hibernate.cache.HashtableCacheProvider 10:53:13,519 INFO SettingsFactory:228 - Optimize cache for minimal puts: disabled 10:53:13,519 INFO SettingsFactory:237 - Structured second-level cache entries: disabled 10:53:13,535 INFO SettingsFactory:264 - Statistics: disabled 10:53:13,535 INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: enabled 10:53:13,535 INFO SettingsFactory:283 - Default entity-mode: POJO 10:53:13,754 INFO SessionFactoryImpl:155 - building session factory 10:53:15,629 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured 10:53:15,629 INFO SchemaUpdate:114 - Running hbm2ddl schema update 10:53:15,629 INFO SchemaUpdate:126 - fetching database metadata 10:53:15,723 INFO SchemaUpdate:142 - updating schema 10:53:15,738 INFO Configuration:1014 - processing extends queue 10:53:15,738 INFO Configuration:1018 - processing collection mappings 10:53:15,738 INFO Configuration:1027 - processing association property references 10:53:15,738 INFO Configuration:1049 - processing foreign key constraints 10:53:16,645 INFO TableMetadata:40 - table found: public.adresfirmy 10:53:16,645 INFO TableMetadata:41 - columns: [panstwo_id, ulica, aktywnyad, wojewodztwo_id, edited, gmina, nrdomu, id, kodmiej, firma_id, removed, datadadresu, rodzajkontaktu, miejscowosc, nrlokalu, adreskores] 10:53:16,645 INFO TableMetadata:43 - foreign keys: [fkdac5a27ef5fa1da1, fkdac5a27e5d1dd699, fkdac5a27e265e3dac] 10:53:16,645 INFO TableMetadata:44 - indexes: [adresfirmy_pkey] 10:53:16,738 INFO TableMetadata:40 - table found: public.adreskontrahenta 10:53:16,738 INFO TableMetadata:41 - columns: [ulica, panstwo_id, wojewodztwo_id, edited, gmina, kontrahent_id, nrdomu, id, kodmiej, removed, rodzajkontaktu, miejscowosc, nrlokalu, adreskores] 10:53:16,738 INFO TableMetadata:43 - foreign keys: [fkf3f8548265e3dac, fkf3f8548dfec03d6, fkf3f8548f5fa1da1] 10:53:16,738 INFO TableMetadata:44 - indexes: [adreskontrahenta_pkey] 10:53:16,816 INFO TableMetadata:40 - table found: public.banki 10:53:16,816 INFO TableMetadata:41 - columns: [panstwo_id, removed, edited, nazwa, nr, id] 10:53:16,816 INFO TableMetadata:43 - foreign keys: [fk3cfd18d265e3dac] 10:53:16,816 INFO TableMetadata:44 - indexes: [banki_pkey, banki_nr_key, banki_nazwa_key] 10:53:16,926 INFO TableMetadata:40 - table found: public.dokksiegowy 10:53:16,926 INFO TableMetadata:41 - columns: [jestnotatka, nrwlasdok, datawlasdok, czykorekta, nrewiddok, edited, terminplatnosci, kontrahent_id, datavat, id, uzytkownik_id, rokewid_id, firma_id, removed, dataksieg, okresewid_id, datawplywu, typdokumentu_id, dataopergosp, opis, nrdokkoryg] 10:53:16,926 INFO TableMetadata:43 - foreign keys: [fk5c83518edfec03d6, fk5c83518e5d1dd699, fk5c83518eef117093, fk5c83518e33974a7, fk5c83518e67a0167b, fk5c83518e6e8ab7b1] 10:53:16,926 INFO TableMetadata:44 - indexes: [dokksiegowy_pkey] 10:53:17,066 INFO TableMetadata:40 - table found: public.firma 10:53:17,066 INFO TableMetadata:41 - columns: [knazwa, datardzial, edited, nazwarej, strukturawlasnosci_id, dzial, id, ekd, nrrej, removed, stronawww, image, nip, aktywnosc, regon, platnikvat, pesel, organrej, dnazwa] 10:53:17,066 INFO TableMetadata:43 - foreign keys: [fk40be1c3ff7229f8] 10:53:17,066 INFO TableMetadata:44 - indexes: [firma_pkey] 10:53:17,145 INFO TableMetadata:40 - table found: public.firma_kartoteka 10:53:17,145 INFO TableMetadata:41 - columns: [firmy_id, kartoteki_id] 10:53:17,145 INFO TableMetadata:43 - foreign keys: [fkec0549c28bbddcec, fkec0549c25d28bf81] 10:53:17,145 INFO TableMetadata:44 - indexes: [] 10:53:17,223 INFO TableMetadata:40 - table found: public.grupavat 10:53:17,223 INFO TableMetadata:41 - columns: [aktywna, removed, stawka_id, edited, opiss, typrej, opis, id] 10:53:17,223 INFO TableMetadata:43 - foreign keys: [fk2bf884eeafa94f15] 10:53:17,223 INFO TableMetadata:44 - indexes: [grupavat_opiss_key, grupavat_pkey] 10:53:17,301 INFO TableMetadata:40 - table found: public.kartoteka 10:53:17,301 INFO TableMetadata:41 - columns: [removed, nazwakart, edited, opis, id, predef] 10:53:17,301 INFO TableMetadata:43 - foreign keys: [] 10:53:17,301 INFO TableMetadata:44 - indexes: [kartoteka_pkey, kartoteka_nazwakart_key] 10:53:17,395 INFO TableMetadata:40 - table found: public.konffirma 10:53:17,395 INFO TableMetadata:41 - columns: [edited, datazapisu, id, removed, firma_id, rokewid_id, rozkosztrodzic, automatkk, rozkoszt, dziennikitematyczne, ewidkoszt, metvat, waluta_id] 10:53:17,395 INFO TableMetadata:43 - foreign keys: [fke7b6a107b7b1e532, fke7b6a1076e8ab7b1, fke7b6a1075d1dd699] 10:53:17,395 INFO TableMetadata:44 - indexes: [konffirma_pkey, konffirma_rokewid_id_key, konffirma_rozkoszt_key, konffirma_firma_id_key, konffirma_waluta_id_key] 10:53:17,473 INFO TableMetadata:40 - table found: public.konfiguracja 10:53:17,473 INFO TableMetadata:41 - columns: [imported, id] 10:53:17,488 INFO TableMetadata:43 - foreign keys: [] 10:53:17,488 INFO TableMetadata:44 - indexes: [konfiguracja_pkey] 10:53:17,566 INFO TableMetadata:40 - table found: public.kontaktfirma 10:53:17,566 INFO TableMetadata:41 - columns: [stanowisko, firma_id, nazwisko, removed, pracownik_id, edited, telefons, email, imie, telefonm, id] 10:53:17,566 INFO TableMetadata:43 - foreign keys: [fk3950aac35d1dd699, fk3950aac3e2b92b5a] 10:53:17,566 INFO TableMetadata:44 - indexes: [kontaktfirma_pkey] 10:53:17,645 INFO TableMetadata:40 - table found: public.kontaktkontrah 10:53:17,645 INFO TableMetadata:41 - columns: [stanowisko, nazwisko, removed, edited, telefons, email, kontrahent_id, imie, telefonm, id] 10:53:17,645 INFO TableMetadata:43 - foreign keys: [fk3a585e8fdfec03d6] 10:53:17,645 INFO TableMetadata:44 - indexes: [kontaktkontrah_pkey] 10:53:17,754 INFO TableMetadata:40 - table found: public.kontobankowe 10:53:17,754 INFO TableMetadata:41 - columns: [cyfrykont, pracownik_id, type, edited, kontrahent_id, urzad_id, id, bank_id, removed, firma_id, nazwa, nrrachunku, aktywnedata, aktywnekonto, waluta_id] 10:53:17,754 INFO TableMetadata:43 - foreign keys: [fk508a189cdfec03d6, fk508a189c5d1dd699, fk508a189ce2b92b5a, fk508a189c47378f11, fk508a189cb7b1e532, fk508a189cf81ac36] 10:53:17,754 INFO TableMetadata:44 - indexes: [kontobankowe_pkey] 10:53:17,848 INFO TableMetadata:40 - table found: public.kontoksiegowe 10:53:17,848 INFO TableMetadata:41 - columns: [nrkontaid, edited, czywalutowe, czyvat, rodzic_id, typkonta_id, wieloletnie, rodzajkonta, id, datazal, rokewid_id, removed, poziomkonta, kartoteka_id, nazwad, czydwusaldowe, nazwat, zablokowane, nazwap] 10:53:17,848 INFO TableMetadata:43 - foreign keys: [fk16f332bf9cd8d427, fk16f332bf24167e46, fk16f332bf8bba39f4, fk16f332bf6e8ab7b1] 10:53:17,848 INFO TableMetadata:44 - indexes: [kontoksiegowe_rokewid_id_key, kontoksiegowe_pkey] 10:53:17,941 INFO TableMetadata:40 - table found: public.kontrahent 10:53:17,941 INFO TableMetadata:41 - columns: [knazwa, odbiorca, dostawca, datardzial, edited, nazwarej, strukturawlasnosci_id, dzial, id, nrrej, kontrahentstaly, firma_id, removed, stronawww, nip, aktywnosc, regon, pesel, platnikvat, organrej, dnazwa] 10:53:17,941 INFO TableMetadata:43 - foreign keys: [fk3e5494fcff7229f8, fk3e5494fc5d1dd699] 10:53:17,941 INFO TableMetadata:44 - indexes: [kontrahent_pkey] 10:53:18,020 INFO TableMetadata:40 - table found: public.odsetki 10:53:18,020 INFO TableMetadata:41 - columns: [removed, dataod, edited, nrtabeli, wartodset, id] 10:53:18,020 INFO TableMetadata:43 - foreign keys: [] 10:53:18,020 INFO TableMetadata:44 - indexes: [odsetki_pkey] 10:53:18,082 INFO TableMetadata:40 - table found: public.okresewid 10:53:18,082 INFO TableMetadata:41 - columns: [rokewid_id, firma_id, removed, edited, datazammies, miesdataod, nazwa, statuszammies, miesdatado, id] 10:53:18,082 INFO TableMetadata:43 - foreign keys: [fk6d9194915d1dd699, fk6d9194916e8ab7b1] 10:53:18,098 INFO TableMetadata:44 - indexes: [okresewid_pkey] 10:53:18,160 INFO TableMetadata:40 - table found: public.panstwo 10:53:18,160 INFO TableMetadata:41 - columns: [removed, kodliczbowy, kod, edited, nazwa, czlonekue, id] 10:53:18,160 INFO TableMetadata:43 - foreign keys: [] 10:53:18,160 INFO TableMetadata:44 - indexes: [panstwo_pkey, panstwo_nazwa_key] 10:53:18,238 INFO TableMetadata:40 - table found: public.pracownik 10:53:18,238 INFO TableMetadata:41 - columns: [wielkoscud, edited, obywatelstwo, id, firma_id, nazwisko, paszport, datamodyf, nip, udzialowiec, imiematki, plec, imieojca, naziwskop, imie2, dowod, miejsceur, imie1, removed, dataod, nrpracownika, dataur, datado, narodowosc, dowodwyd, pesel] 10:53:18,238 INFO TableMetadata:43 - foreign keys: [fk5228d7e45d1dd699] 10:53:18,238 INFO TableMetadata:44 - indexes: [pracownik_pkey] 10:53:18,316 INFO TableMetadata:40 - table found: public.rokewid 10:53:18,316 INFO TableMetadata:41 - columns: [firma_id, removed, edited, nazwa, rokdo, rokod, zablokbo, id, statuszam, datazam] 10:53:18,316 INFO TableMetadata:43 - foreign keys: [fkb52de41b5d1dd699] 10:53:18,316 INFO TableMetadata:44 - indexes: [rokewid_pkey] 10:53:18,395 INFO TableMetadata:40 - table found: public.strukturaorg 10:53:18,395 INFO TableMetadata:41 - columns: [poziomdrzewa, firma_id, removed, poprzednia_id, edited, nazwa, schematobow, opisko, id] 10:53:18,395 INFO TableMetadata:43 - foreign keys: [fkb3c01a0d5d1dd699, fkb3c01a0dfa4ab124] 10:53:18,395 INFO TableMetadata:44 - indexes: [strukturaorg_pkey, strukturaorg_poprzednia_id_key] 10:53:18,457 INFO TableMetadata:40 - table found: public.strukturawlasnosciowafirmy 10:53:18,457 INFO TableMetadata:41 - columns: [removed, edited, nazwa, id] 10:53:18,457 INFO TableMetadata:43 - foreign keys: [] 10:53:18,457 INFO TableMetadata:44 - indexes: [strukturawlasnosciowafirmy_pkey] 10:53:18,520 INFO TableMetadata:40 - table found: public.typdokumentu 10:53:18,520 INFO TableMetadata:41 - columns: [domroz, removed, domnagl, edited, aktywnytd, nazwatypdok, id, opistypu, symbol] 10:53:18,520 INFO TableMetadata:43 - foreign keys: [] 10:53:18,520 INFO TableMetadata:44 - indexes: [typdokumentu_pkey, typdokumentu_opistypu_key, typdokumentu_nazwatypdok_key, typdokumentu_symbol_key] 10:53:18,598 INFO TableMetadata:40 - table found: public.typdzial 10:53:18,598 INFO TableMetadata:41 - columns: [removed, edited, nazwa, id] 10:53:18,598 INFO TableMetadata:43 - foreign keys: [] 10:53:18,598 INFO TableMetadata:44 - indexes: [typdzial_nazwa_key, typdzial_pkey] 10:53:18,660 INFO TableMetadata:40 - table found: public.typkonta 10:53:18,660 INFO TableMetadata:41 - columns: [removed, edited, nazwatypu, id] 10:53:18,660 INFO TableMetadata:43 - foreign keys: [] 10:53:18,660 INFO TableMetadata:44 - indexes: [typkonta_pkey, typkonta_nazwatypu_key] 10:53:18,723 INFO TableMetadata:40 - table found: public.uprawnienie 10:53:18,723 INFO TableMetadata:41 - columns: [nazwa, id] 10:53:18,723 INFO TableMetadata:43 - foreign keys: [] 10:53:18,723 INFO TableMetadata:44 - indexes: [uprawnienie_pkey] 10:53:18,785 INFO TableMetadata:40 - table found: public.uprawnienie_uzytkownicy 10:53:18,801 INFO TableMetadata:41 - columns: [uprawnienia_id, uzytkownicy_id] 10:53:18,801 INFO TableMetadata:43 - foreign keys: [fk1916d53296dc6a6, fk1916d53241e1b9cb] 10:53:18,801 INFO TableMetadata:44 - indexes: [] 10:53:18,863 INFO TableMetadata:40 - table found: public.urzad 10:53:18,863 INFO TableMetadata:41 - columns: [woj_id, panstwo_id, ulica, kodmiej, removed, nrlokalu, miejscowosc, edited, gmina, nrdomu, id, nazwaurzad] 10:53:18,863 INFO TableMetadata:43 - foreign keys: [fk4e37640276a05a, fk4e37640265e3dac] 10:53:18,879 INFO TableMetadata:44 - indexes: [urzad_pkey] 10:53:18,941 INFO TableMetadata:40 - table found: public.uzytsys 10:53:18,941 INFO TableMetadata:41 - columns: [datadodania, firma_id, removed, pracownik_id, login, edited, id] 10:53:18,941 INFO TableMetadata:43 - foreign keys: [fk6780060d5d1dd699, fk6780060de2b92b5a] 10:53:18,941 INFO TableMetadata:44 - indexes: [uzytsys_pracownik_id_key, uzytsys_pkey] 10:53:19,004 INFO TableMetadata:40 - table found: public.uzytkownicy 10:53:19,004 INFO TableMetadata:41 - columns: [login, haslo, id] 10:53:19,004 INFO TableMetadata:43 - foreign keys: [] 10:53:19,020 INFO TableMetadata:44 - indexes: [uzytkownicy_pkey] 10:53:19,098 INFO TableMetadata:40 - table found: public.vatstawka 10:53:19,098 INFO TableMetadata:41 - columns: [removed, dataod, edited, datado, wartosc, nazwa, aktualna, opis, id] 10:53:19,098 INFO TableMetadata:43 - foreign keys: [] 10:53:19,098 INFO TableMetadata:44 - indexes: [vatstawka_nazwa_key, vatstawka_wartosc_key, vatstawka_pkey] 10:53:19,160 INFO TableMetadata:40 - table found: public.waluta 10:53:19,160 INFO TableMetadata:41 - columns: [panstwo_id, removed, edited, przelicznik, nazwa, symbolwaluty, id] 10:53:19,160 INFO TableMetadata:43 - foreign keys: [fk99ff63a0265e3dac] 10:53:19,160 INFO TableMetadata:44 - indexes: [waluta_symbolwaluty_key, waluta_pkey] 10:53:19,238 INFO TableMetadata:40 - table found: public.wojewodztwo 10:53:19,238 INFO TableMetadata:41 - columns: [panstwo_id, removed, kod, edited, nazwa, id] 10:53:19,238 INFO TableMetadata:43 - foreign keys: [fk3fe7548b265e3dac] 10:53:19,238 INFO TableMetadata:44 - indexes: [wojewodztwo_nazwa_key, wojewodztwo_pkey] 10:53:19,238 INFO SchemaUpdate:162 - schema update complete 10:53:19,238 INFO NamingHelper:26 - JNDI InitialContext properties:{java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces} 10:53:19,254 INFO SessionFactoryImpl:432 - Checking 47 named queries
-
8. Re: Performance problem with embedded EJB :/
bill.burke Dec 13, 2005 11:12 AM (in response to jacekolszak)"jacekolszak" wrote:
You mean change hbm2ddl.auto to update instead of create-drop ?
Remote it entirely from persistence.properties and your persistence.xml file and precreate your database before running the unit test. Update still queries the database for the table metadata to try and figure out if neeeds to alter tables at all. I think this will only shave off a few seconds though.
As I said before, we will do some refactorings for the kernel initialization which should shave off a few seconds (3?). I will eventually do some more profiling, but honestly it is a low priority as we're currently working on stability and functionality first. If you want to dive into this yourself, feel free. If you provide enough patches that convince us you have working knowledge of the sourcecode, we'll grant you CVS.