-
1. Re: deploy() takes an awefully LONG time
kukeltje Dec 9, 2009 6:32 AM (in response to ajaygautam)Uhhmmmm I assume you have WAY more logging.... if so please post here. If not, it is very, very hard for us to help.
-
2. Re: deploy() takes an awefully LONG time
ajaygautam Dec 10, 2009 9:39 AM (in response to ajaygautam)Sure. Here you go... The complete log leading upto this. The time lag occurs between 9:33:57 to 9:35:43. This is when the deploy() runs.
PS: Could this be a timeout thing? Does deploy() go out to the internet, and try to retrieve a DTD file or something like that? We are behind a proxy, so that could be a problem.
Any help / pointers will be appreciated.
Thanks
Ajay2009-12-10 09:33:52,191 INFO WorkflowEngineTest - Creating workflow engine 2009-12-10 09:33:52,691 DEBUG Log4jLog - eagerly initializing org.jbpm.pvm.internal.id.DatabaseIdComposer Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Environment <clinit> INFO: Hibernate 3.3.1.GA Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Environment <clinit> INFO: hibernate.properties not found Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Environment buildBytecodeProvider INFO: Bytecode provider name : javassist Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Environment <clinit> INFO: using JDK 1.4 java.sql.Timestamp handling Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Configuration configure INFO: configuring from resource: jbpm.hibernate.cfg.xml Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Configuration getConfigurationInputStream INFO: Configuration resource: jbpm.hibernate.cfg.xml Dec 10, 2009 9:33:52 AM org.hibernate.cfg.Configuration addResource INFO: Reading mappings from resource : jbpm.repository.hbm.xml Dec 10, 2009 9:33:52 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.repository.DeploymentImpl -> JBPM4_DEPLOYMENT Dec 10, 2009 9:33:52 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.repository.DeploymentProperty -> JBPM4_DEPLOYPROP Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.id.PropertyImpl -> JBPM4_PROPERTY Dec 10, 2009 9:33:53 AM org.hibernate.cfg.Configuration addResource INFO: Reading mappings from resource : jbpm.execution.hbm.xml Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.model.ExecutionImpl -> JBPM4_EXECUTION Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.type.Variable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.BlobVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.DateVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.DoubleVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.HibernateLongVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.HibernateStringVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.LongVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.NullVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.StringVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.type.variable.TextVariable -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.lob.Lob -> JBPM4_LOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.job.JobImpl -> JBPM4_JOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.job.MessageImpl -> JBPM4_JOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.model.op.ExecuteActivityMessage -> JBPM4_JOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.model.op.ExecuteEventListenerMessage -> JBPM4_JOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.job.CommandMessage -> JBPM4_JOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.job.TimerImpl -> JBPM4_JOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.Configuration addResource INFO: Reading mappings from resource : jbpm.history.hbm.xml Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.history.model.HistoryProcessInstanceImpl -> JBPM4_HIST_PROCINST Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.history.model.HistoryActivityInstanceImpl -> JBPM4_HIST_ACTINST Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryAutomaticInstanceImpl -> JBPM4_HIST_ACTINST Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryDecisionInstanceImpl -> JBPM4_HIST_ACTINST Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryTaskInstanceImpl -> JBPM4_HIST_ACTINST Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.history.model.HistoryTaskImpl -> JBPM4_HIST_TASK Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.history.model.HistoryVariableImpl -> JBPM4_HIST_VAR Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.history.model.HistoryDetailImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryCommentImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryProcessInstanceMigrationImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryPriorityUpdateImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryTaskAssignmentImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryTaskDuedateUpdateImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindSubclass INFO: Mapping subclass: org.jbpm.pvm.internal.history.model.HistoryVariableUpdateImpl -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.Configuration addResource INFO: Reading mappings from resource : jbpm.task.hbm.xml Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.task.TaskImpl -> JBPM4_TASK Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.task.ParticipationImpl -> JBPM4_PARTICIPATION Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.task.SwimlaneImpl -> JBPM4_SWIMLANE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.Configuration addResource INFO: Reading mappings from resource : jbpm.identity.hbm.xml Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.identity.impl.UserImpl -> JBPM4_ID_USER Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.identity.impl.MembershipImpl -> JBPM4_ID_MEMBERSHIP Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindRootPersistentClassCommonValues INFO: Mapping class: org.jbpm.pvm.internal.identity.impl.GroupImpl -> JBPM4_ID_GROUP Dec 10, 2009 9:33:53 AM org.hibernate.cfg.Configuration doConfigure INFO: Configured SessionFactory: null Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.repository.DeploymentImpl.resources -> JBPM4_LOB Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.repository.DeploymentImpl.objectProperties -> JBPM4_DEPLOYPROP Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.model.ExecutionImpl.variables -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.model.ExecutionImpl.systemVariables -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.model.ExecutionImpl.executions -> JBPM4_EXECUTION Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.model.ExecutionImpl.swimlanes -> JBPM4_SWIMLANE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryProcessInstanceImpl.historyActivityInstances -> JBPM4_HIST_ACTINST Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryProcessInstanceImpl.historyVariables -> JBPM4_HIST_VAR Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryProcessInstanceImpl.details -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryActivityInstanceImpl.details -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryTaskImpl.details -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryTaskImpl.historyVariables -> JBPM4_HIST_VAR Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryTaskImpl.subTasks -> JBPM4_HIST_TASK Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryVariableImpl.details -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.history.model.HistoryCommentImpl.replies -> JBPM4_HIST_DETAIL Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.task.TaskImpl.participations -> JBPM4_PARTICIPATION Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.task.TaskImpl.variables -> JBPM4_VARIABLE Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.task.TaskImpl.subTasks -> JBPM4_TASK Dec 10, 2009 9:33:53 AM org.hibernate.cfg.HbmBinder bindCollectionSecondPass INFO: Mapping collection: org.jbpm.pvm.internal.task.SwimlaneImpl.participations -> JBPM4_PARTICIPATION Dec 10, 2009 9:33:53 AM org.hibernate.connection.DriverManagerConnectionProvider configure INFO: Using Hibernate built-in connection pool (not for production use!) Dec 10, 2009 9:33:53 AM org.hibernate.connection.DriverManagerConnectionProvider configure INFO: Hibernate connection pool size: 20 Dec 10, 2009 9:33:53 AM org.hibernate.connection.DriverManagerConnectionProvider configure INFO: autocommit mode: false Dec 10, 2009 9:33:53 AM org.hibernate.connection.DriverManagerConnectionProvider configure INFO: using driver: oracle.jdbc.driver.OracleDriver at URL: jdbc:oracle:thin:@(DESCRIPTION =(ADDRESS = (PROTOCOL = TCP)(HOST = LON3230XUS.fm.rbsgrp.net)(PORT = 1621))(ADDRESS = (PROTOCOL = TCP)(HOST = LON3231XUS.fm.rbsgrp.net)(PORT = 1621)) (LOAD_BALANCE = yes)(CONNECT_DATA = (SERVER = DEDICATED)(SERVICE_NAME = RSLONU))) Dec 10, 2009 9:33:53 AM org.hibernate.connection.DriverManagerConnectionProvider configure INFO: connection properties: {user=rates_services_dev_2_owner, password=****} Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: RDBMS: Oracle, version: Oracle Database 10g Enterprise Edition Release 10.2.0.2.0 - 64bit Production With the Partitioning, Real Application Clusters and Data Mining options Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: JDBC driver: Oracle JDBC driver, version: 10.2.0.1.0 Dec 10, 2009 9:33:54 AM org.hibernate.dialect.Dialect <init> INFO: Using dialect: org.hibernate.dialect.Oracle10gDialect Dec 10, 2009 9:33:54 AM org.hibernate.transaction.TransactionFactoryFactory buildTransactionFactory INFO: Using default transaction strategy (direct JDBC transactions) Dec 10, 2009 9:33:54 AM org.hibernate.transaction.TransactionManagerLookupFactory getTransactionManagerLookup INFO: No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended) Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Automatic flush during beforeCompletion(): disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Automatic session close at end of transaction: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: JDBC batch size: 15 Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: JDBC batch updates for versioned data: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Scrollable result sets: enabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: JDBC3 getGeneratedKeys(): disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Connection release mode: auto Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Default batch fetch size: 1 Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Generate SQL with comments: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Order SQL updates by primary key: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Order SQL inserts for batching: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory createQueryTranslatorFactory INFO: Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory Dec 10, 2009 9:33:54 AM org.hibernate.hql.ast.ASTQueryTranslatorFactory <init> INFO: Using ASTQueryTranslatorFactory Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Query language substitutions: {} Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: JPA-QL strict compliance: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Second-level cache: enabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Query cache: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory createRegionFactory INFO: Cache region factory : org.hibernate.cache.impl.NoCachingRegionFactory Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Optimize cache for minimal puts: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Structured second-level cache entries: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Statistics: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Deleted entity synthetic identifier rollback: disabled Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Default entity-mode: pojo Dec 10, 2009 9:33:54 AM org.hibernate.cfg.SettingsFactory buildSettings INFO: Named query checking : enabled Dec 10, 2009 9:33:54 AM org.hibernate.impl.SessionFactoryImpl <init> INFO: building session factory Dec 10, 2009 9:33:55 AM org.hibernate.impl.SessionFactoryObjectFactory addInstance INFO: Not binding factory to JNDI, no JNDI name configured 2009-12-10 09:33:55,769 DEBUG Log4jLog - ----- beginning hibernate tx 31633330 -------------------------------------------------------- 2009-12-10 09:33:56,457 INFO Log4jLog - jBPM version info: library[4.2], schema[null] 2009-12-10 09:33:56,457 DEBUG Log4jLog - ----- committing hibernate tx 21719810 ------------------------------------------------------- 2009-12-10 09:33:56,550 DEBUG WorkflowEngineImpl - adding definition file [pretrade.jpdl.xml] 2009-12-10 09:33:56,566 DEBUG Log4jLog - ----- beginning hibernate tx 27253707 -------------------------------------------------------- 2009-12-10 09:33:56,613 DEBUG Log4jLog - last id -2 was consumed. acquiring new block... 2009-12-10 09:33:56,613 DEBUG Log4jLog - ----- beginning hibernate tx 19762893 -------------------------------------------------------- 2009-12-10 09:33:57,832 DEBUG Log4jLog - ----- committing hibernate tx 25894799 ------------------------------------------------------- 2009-12-10 09:33:57,910 DEBUG Log4jLog - acquired new id block [1340001-1350000] 2009-12-10 09:35:43,908 DEBUG Log4jLog - ----- committing hibernate tx 1279942 ------------------------------------------------------- 2009-12-10 09:35:43,986 INFO WorkflowEngineTest - Creating workflow engine 2009-12-10 09:35:44,002 DEBUG WorkflowEngineTest - ======== testWFStart START ======== ... ... ... tests run fine here ... ... ...
-
3. Re: deploy() takes an awefully LONG time
kukeltje Dec 10, 2009 1:17 PM (in response to ajaygautam)jBPM afaik has the xsd's in a local resolver so should not need to go to the internet. But it could be that (since the xsd changed in 4.2) this was overlooked.
Regarding the logging.... Well, I (ofcourse ;-)) meant logging of what happens DURING the deploy. So if it turns out not to be a internet access thing, turn on logging of lots of other libraries. And before you say 'which?' I'd go for 'all' OR maybe run JBoss in debugging mode and put a breakpoint on the deploy and go from there. -
4. Re: deploy() takes an awefully LONG time
ajaygautam Dec 10, 2009 1:24 PM (in response to ajaygautam)"kukeltje" wrote:
jBPM afaik has the xsd's in a local resolver so should not need to go to the internet. But it could be that (since the xsd changed in 4.2) this was overlooked.
Regarding the logging.... Well, I (ofcourse ;-)) meant logging of what happens DURING the deploy. So if it turns out not to be a internet access thing, turn on logging of lots of other libraries. And before you say 'which?' I'd go for 'all' OR maybe run JBoss in debugging mode and put a breakpoint on the deploy and go from there.
I guess, if I had *that* log, I wouldn't be posting ;) -
5. Re: deploy() takes an awefully LONG time
kukeltje Dec 10, 2009 1:53 PM (in response to ajaygautam)Is there any reason you cannot configure log4j (or jdk logging) to log in more detail? Works fine here (and I'm serious, not joking or trying to make fun of you or anything)
Now (besides the internet access) It's like saying: "Hey, look at that car driving by, it is going slow. Can you tell me what is wrong with it?" :-) -
6. Re: deploy() takes an awefully LONG time
ajaygautam Dec 10, 2009 1:56 PM (in response to ajaygautam)This statement takes all the time:
ProcessDeployer.java line 134, method checkKey(). List<ProcessDefinition> existingProcesses = repositorySession.createProcessDefinitionQuery() .processDefinitionName(processDefinitionName) .list();
Then the code goes on to perform a "find":for (ProcessDefinition existingProcess: existingProcesses) { if (!processDefinitionKey.equals(existingProcess.getKey())) { deployment.addProblem("invalid key '"+processDefinitionKey+"' in process "+processDefinition.getName()+". Existing process has name '"+processDefinitionName+"' and key '"+processDefinitionKey+"'"); } }
uuumm.... shouldn't the query actually be performed at the database level !?!?
On top of that, here is the code that performs the actual query:public Object execute(Session session) { List<Map<String, Object>> propertyMaps = (List<Map<String, Object>>) super.execute(session); List<ProcessDefinition> processDefinitions = new ArrayList<ProcessDefinition>(); for (Map<String, Object> properties: propertyMaps) { String deploymentId = properties.get("deploymentDbid").toString(); String objectName = (String)properties.get("objectName"); RepositorySession repositorySession = EnvironmentImpl.getFromCurrent(RepositorySession.class); ProcessDefinitionImpl processDefinition = (ProcessDefinitionImpl) repositorySession.getObject(deploymentId, objectName); processDefinitions.add(processDefinition); } return processDefinitions; }
So, instead of loading everything from the database in one go, its loading data one row at a time! - FROM THE DATABASE !! HOLY PENGUIN!
Whats going on?
The symptom is magnified, by the fact that the process is running in US, and the database is in UK!
Or am I using it wrong?
Ajay -
7. Re: deploy() takes an awefully LONG time
ajaygautam Dec 10, 2009 2:49 PM (in response to ajaygautam)Changing the database location from cross continent to local fixes the time issue.
I think I should file this as a bug. Database developers should be frugal with resources.
What do you think?
Ajay -
8. Re: deploy() takes an awefully LONG time
saraswati.santanu Dec 11, 2009 1:23 AM (in response to ajaygautam)Ajay,
I did not get the first part of your questionshouldn't the query actually be performed at the database level !?!?
The query will be performed at the db only.
Do you mean a db procedure kind of thing? That will have other significant disadvantages. So that query there looks fine.
About the second part, where the query seems to be fired in a loop - I think the goal should be to fire less number of queries. Though it appears that the queries are fired in a loop, but making query in that way actually will result in less number of queries (in fact no query to db most of the time). If you try to aggregate values and fire query then cache hit will not be possible most of the time. -
9. Re: deploy() takes an awefully LONG time
kukeltje Dec 11, 2009 10:03 AM (in response to ajaygautam)I do not get it either. jBPM retrieves all processdefinitions with the same name (how many can that be, just several I think) and loops over that.
I again urge you to log additional things, you might e.g. have a problem with a reverse dns lookup why things take long...
So I would not file a bug for this since it most likely will be marked invalid. -
10. Re: deploy() takes an awefully LONG time
ajaygautam Dec 11, 2009 10:08 AM (in response to ajaygautam)"saraswati.santanu" wrote:
Ajay,
I did not get the first part of your questionshouldn't the query actually be performed at the database level !?!?
The query will be performed at the db only.
Do you mean a db procedure kind of thing? That will have other significant disadvantages. So that query there looks fine.
Well... what I meant was that instead of querying for everything, loading everything, then performing a find in java code, shouldn't jBPM be creating a query criteria with the call that goes to the database? I mean, whats the point of loading everything in memory, and searching through it... databases are designed for tasks like these..."saraswati.santanu" wrote:
About the second part, where the query seems to be fired in a loop - I think the goal should be to fire less number of queries. Though it appears that the queries are fired in a loop, but making query in that way actually will result in less number of queries (in fact no query to db most of the time). If you try to aggregate values and fire query then cache hit will not be possible most of the time.
I think is some misunderstanding here. I will code at the code again, and comment.
Thanks
Ajay -
11. Re: deploy() takes an awefully LONG time
ajaygautam Dec 11, 2009 10:10 AM (in response to ajaygautam)"kukeltje" wrote:
I do not get it either. jBPM retrieves all processdefinitions with the same name (how many can that be, just several I think) and loops over that.
I again urge you to log additional things, you might e.g. have a problem with a reverse dns lookup why things take long...
So I would not file a bug for this since it most likely will be marked invalid.
I can't seem to get my head around jbpm's logging. Do you have a log file I could use - that would generate the additional logs?
Here is what my log file looks like (DEBUG level, with NO class level filters):log4j.rootLogger=DEBUG, A1 log4j.appender.A1=org.apache.log4j.ConsoleAppender log4j.appender.A1.layout=org.apache.log4j.PatternLayout log4j.appender.A1.layout.ConversionPattern=%d %-5p %C{1} %3x - %m%n
-
12. Re: deploy() takes an awefully LONG time
kukeltje Dec 11, 2009 10:20 AM (in response to ajaygautam)"ajaygautam" wrote:
"saraswati.santanu" wrote:
Ajay,
I did not get the first part of your questionshouldn't the query actually be performed at the database level !?!?
The query will be performed at the db only.
Do you mean a db procedure kind of thing? That will have other significant disadvantages. So that query there looks fine.
Well... what I meant was that instead of querying for everything, loading everything, then performing a find in java code, shouldn't jBPM be creating a query criteria with the call that goes to the database? I mean, whats the point of loading everything in memory, and searching through it... databases are designed for tasks like these...
It doesn'tList<ProcessDefinition> existingProcesses = repositorySession.createProcessDefinitionQuery() .processDefinitionName(processDefinitionName) .list();
only retrieves those processdefinitions with the same name.In most production environments that will only be a few....