search

dotCMS / core

Headless/Hybrid Content Management System for Enterprises
http://dotcms.com
Other
858 stars 467 forks source link

don't call createDefaultScheme() on Task00900CreateLogConsoleTable #892

Closed dotjorgeu closed 12 years ago

dotjorgeu commented 12 years ago

noticed on user comment at #788

NickPadilla commented 12 years ago

@dotjorgeu it looks like this upgrade task is also calling this same method Task00820CreateNewWorkFlowTables

dotjorgeu commented 12 years ago

sure we should call it on that task but ignore exceptions it may throw. Or maybe we should just stop throwing exceptions on that method internally. When tables are properly upgraded it will work as expected

NickPadilla commented 12 years ago

right, that is one way to handle it.

NickPadilla commented 12 years ago

maybe just write out in the log a warning that the error occurred - that way we still know it happened.

NickPadilla commented 12 years ago

yeah, that would work - just the log out that warns of the problem but hide the actual exception. As long as all the other data gets written - I'm cool wit it.

dotjorgeu commented 12 years ago

We already do that

try {
   ... do all inserts ...
   HibernateUtil.commitTransaction();
} catch (final Exception e) {
   HibernateUtil.rollbackTransaction();
   Logger.warn(this, e.getMessage(), e);
   return null;
}

@NickPadilla I need a stacktrace of the error you get

NickPadilla commented 12 years ago

@dotjorgeu so passing in the actual exception don't make the logger print the entire stack to the log? In my mind, just show this single line for this warning:

[02/08/12 01:17:55:402 MDT]  WARN business.WorkflowFactoryImpl: Invalid column name 'escalation_enable'.

When I see stacks I go looking for the problem, since it was able to get to the log I assume it is an error that isn't supposed to happen.

Here are the exceptions being thrown:

02/08/12 01:17:55:320 MDT]  INFO db.DotConnect: Executing delete from workflow_history
[02/08/12 01:17:55:342 MDT]  INFO db.DotConnect: Executing delete from workflow_comment
[02/08/12 01:17:55:345 MDT]  INFO db.DotConnect: Executing delete from workflowtask_files
[02/08/12 01:17:55:346 MDT]  INFO db.DotConnect: Executing delete from workflow_task
[02/08/12 01:17:55:357 MDT]  INFO db.DotConnect: Executing alter table workflow_task add constraint FK_workflow_task_asset foreign key (webasset) references identifier(id)
[02/08/12 01:17:55:361 MDT]  INFO db.DotConnect: Executing drop index workflow_task.idx_workflow_3
[02/08/12 01:17:55:362 MDT]  INFO db.DotConnect: Executing drop index workflow_task.idx_workflow_1
[02/08/12 01:17:55:364 MDT]  INFO db.DotConnect: Executing ALTER TABLE workflow_task ALTER COLUMN status varchar(36)
[02/08/12 01:17:55:367 MDT]  INFO db.DotConnect: Executing ALTER TABLE workflow_task ALTER COLUMN assigned_to varchar(36)
[02/08/12 01:17:55:369 MDT]  INFO db.DotConnect: Executing create index idx_workflow_1 on workflow_task (assigned_to)
[02/08/12 01:17:55:371 MDT]  INFO db.DotConnect: Executing create index idx_workflow_3 on workflow_task (status)
[02/08/12 01:17:55:373 MDT]  INFO db.DotConnect: Executing alter table workflow_task add constraint FK_workflow_assign foreign key (assigned_to) references cms_role(id)
[02/08/12 01:17:55:382 MDT]  INFO db.DotConnect: Executing alter table workflow_task add constraint FK_workflow_step foreign key (status) references workflow_step(id)
[02/08/12 01:17:55:385 MDT]  INFO db.DotConnect: Executing alter table workflow_scheme add constraint FK_wf_scheme_action foreign key (entry_action_id) references workflow_action(id)
[02/08/12 01:17:55:387 MDT]  INFO db.DotConnect: Executing ALTER TABLE workflow_history add  workflow_action_id varchar(36)
[02/08/12 01:17:55:389 MDT]  INFO db.DotConnect: Executing create index wf_histroy_action_idx on workflow_history(workflow_action_id)
[02/08/12 01:17:55:390 MDT]  INFO db.DotConnect: Executing ALTER TABLE workflow_history add  workflow_step_id varchar(36)
[02/08/12 01:17:55:392 MDT]  INFO db.DotConnect: Executing create index wf_histroy_step_idx on workflow_history(workflow_step_id)
[02/08/12 01:17:55:394 MDT]  INFO business.WorkflowFactoryImpl: Creating Default Workflow Schema
[02/08/12 01:17:55:402 MDT]  WARN business.WorkflowFactoryImpl: Invalid column name 'escalation_enable'.
com.dotmarketing.exception.DotDataException: Invalid column name 'escalation_enable'.
    at com.dotmarketing.common.db.DotConnect.loadResult(DotConnect.java:232)
    at com.dotmarketing.portlets.workflows.business.WorkflowFactoryImpl.saveStep(WorkflowFactoryImpl.java:1010)
    at com.dotmarketing.portlets.workflows.business.WorkflowFactoryImpl.createDefaultScheme(WorkflowFactoryImpl.java:242)
    at com.dotmarketing.portlets.workflows.business.WorkflowAPIImpl.createDefaultScheme(WorkflowAPIImpl.java:890)
    at com.dotmarketing.startup.runonce.Task00820CreateNewWorkFlowTables.executeUpgrade(Task00820CreateNewWorkFlowTables.java:400)
    at com.dotmarketing.startup.StartupTasksExecutor.executeUpgrades(StartupTasksExecutor.java:260)
    at com.liferay.portal.servlet.MainServlet.init(MainServlet.java:117)
    at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1173)
    at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993)
    at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4187)
    at org.apache.catalina.core.StandardContext.start(StandardContext.java:4496)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:546)
    at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
    at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:563)
    at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498)
    at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
    at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321)
    at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
    at org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
    at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443)
    at org.apache.catalina.core.StandardService.start(StandardService.java:519)
    at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Invalid column name 'escalation_enable'.
    at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:213)
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1493)
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:388)
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:338)
    at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:5569)
    at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1629)
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:179)
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:154)
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.execute(SQLServerPreparedStatement.java:320)
    at org.apache.tomcat.dbcp.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
    at com.dotmarketing.common.db.DotConnect.executeQuery(DotConnect.java:545)
    at com.dotmarketing.common.db.DotConnect.executeQuery(DotConnect.java:467)
    at com.dotmarketing.common.db.DotConnect.loadResult(DotConnect.java:230)
    ... 32 more
[02/08/12 01:17:55:403 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 820
[02/08/12 01:17:55:404 MDT]  INFO startup.StartupTasksExecutor: Running: Task00825UpdateLoadRecordsToIndex
[02/08/12 01:17:55:405 MDT]  INFO db.DotConnect: Executing SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[02/08/12 01:17:55:405 MDT]  INFO db.DotConnect: Finished Executing SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[02/08/12 01:17:55:405 MDT]  INFO db.DotConnect: Executing ALTER TABLE dist_reindex_journal ALTER COLUMN serverid VARCHAR(64) NULL
[02/08/12 01:17:55:423 MDT]  INFO db.DotConnect: Finished Executing ALTER TABLE dist_reindex_journal ALTER COLUMN serverid VARCHAR(64) NULL
[02/08/12 01:17:55:423 MDT]  INFO db.DotConnect: Executing DROP FUNCTION load_records_to_index
[02/08/12 01:17:55:424 MDT]  INFO db.DotConnect: Finished Executing DROP FUNCTION load_records_to_index
[02/08/12 01:17:55:424 MDT]  INFO db.DotConnect: Executing CREATE PROCEDURE load_records_to_index(@server_id VARCHAR, @records_to_fetch INT)
AS 
BEGIN
WITH cte AS (
  SELECT TOP(@records_to_fetch) *
  FROM dist_reindex_journal WITH (ROWLOCK, READPAST, UPDLOCK)
  WHERE serverid IS NULL 
  ORDER BY priority ASC)
UPDATE cte
  SET serverid=@server_id
OUTPUT
  INSERTED.*
END
[02/08/12 01:17:55:478 MDT]  INFO db.DotConnect: Finished Executing CREATE PROCEDURE load_records_to_index(@server_id VARCHAR, @records_to_fetch INT)
AS 
BEGIN
WITH cte AS (
  SELECT TOP(@records_to_fetch) *
  FROM dist_reindex_journal WITH (ROWLOCK, READPAST, UPDLOCK)
  WHERE serverid IS NULL 
  ORDER BY priority ASC)
UPDATE cte
  SET serverid=@server_id
OUTPUT
  INSERTED.*
END
[02/08/12 01:17:55:481 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 825
[02/08/12 01:17:55:483 MDT]  INFO startup.StartupTasksExecutor: Running: Task00835CreateIndiciesTables
[02/08/12 01:17:55:484 MDT]  INFO db.DotConnect: Executing SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[02/08/12 01:17:55:484 MDT]  INFO db.DotConnect: Finished Executing SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[02/08/12 01:17:55:484 MDT]  INFO db.DotConnect: Executing create table indicies (
  index_name varchar(30) primary key,
  index_type varchar(16) not null unique
)
[02/08/12 01:17:55:485 MDT]  INFO db.DotConnect: Finished Executing create table indicies (
  index_name varchar(30) primary key,
  index_type varchar(16) not null unique
)
[02/08/12 01:17:55:488 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 835
[02/08/12 01:17:55:491 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 840
[02/08/12 01:17:55:491 MDT]  INFO startup.StartupTasksExecutor: Running: Task00845ChangeLockedOnToTimeStamp
[02/08/12 01:17:55:491 MDT]  INFO db.DotConnect: Executing alter table contentlet_version_info alter column locked_on datetime  
[02/08/12 01:17:55:494 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 845
[02/08/12 01:17:55:495 MDT]  INFO startup.StartupTasksExecutor: Running: Task00850DropOldFilesConstraintInWorkflow
[02/08/12 01:17:55:495 MDT]  INFO db.DotConnect: Executing alter table workflowtask_files drop constraint FK_task_file_inode 
[02/08/12 01:17:55:502 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 850
[02/08/12 01:17:55:503 MDT]  INFO startup.StartupTasksExecutor: Running: Task00855FixRenameFolder
[02/08/12 01:17:55:504 MDT]  INFO db.DotConnect: Executing SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[02/08/12 01:17:55:504 MDT]  INFO db.DotConnect: Finished Executing SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[02/08/12 01:17:55:506 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 855
[02/08/12 01:17:55:507 MDT]  INFO startup.StartupTasksExecutor: Running: Task00860ExtendServerIdsMSSQL
[02/08/12 01:17:55:507 MDT]  INFO db.DotConnect: Executing ALTER PROCEDURE load_records_to_index(@server_id VARCHAR(100), @records_to_fetch INT)
AS
BEGIN
WITH cte AS (
  SELECT TOP(@records_to_fetch) *
  FROM dist_reindex_journal WITH (ROWLOCK, READPAST, UPDLOCK)
  WHERE serverid IS NULL
  ORDER BY priority ASC)
UPDATE cte
  SET serverid=@server_id
OUTPUT
  INSERTED.*
END;
[02/08/12 01:17:55:509 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 860
[02/08/12 01:17:55:510 MDT]  INFO startup.StartupTasksExecutor: Running: Task00865AddTimestampToVersionTables
[02/08/12 01:17:55:510 MDT]  INFO db.DotConnect: Executing alter table container_version_info add version_ts datetime default getdate() not null
[02/08/12 01:17:55:527 MDT]  INFO db.DotConnect: Executing alter table contentlet_version_info add version_ts datetime default getdate() not null
[02/08/12 01:17:55:579 MDT]  INFO db.DotConnect: Executing alter table fileasset_version_info add version_ts datetime default getdate() not null
[02/08/12 01:17:55:652 MDT]  INFO db.DotConnect: Executing alter table htmlpage_version_info add version_ts datetime default getdate() not null
[02/08/12 01:17:55:717 MDT]  INFO db.DotConnect: Executing alter table link_version_info add version_ts datetime default getdate() not null
[02/08/12 01:17:55:720 MDT]  INFO db.DotConnect: Executing alter table template_version_info add version_ts datetime default getdate() not null
[02/08/12 01:17:55:724 MDT]  INFO startup.StartupTasksExecutor: Database upgraded to version: 865
[02/08/12 01:17:55:725 MDT]  INFO startup.StartupTasksExecutor: Running: Task00900CreateLogConsoleTable
[02/08/12 01:17:55:726 MDT]  INFO db.DotConnect: Executing create table log_mapper(
log_name varchar(30) primary key,
description varchar(50) not null,
enabled numeric(1,0) not null)
[02/08/12 01:17:55:727 MDT]  INFO db.DotConnect: Executing insert into log_mapper (ENABLED,LOG_NAME,DESCRIPTION) values ('1','dotcms-userActivity.log','Log Users action on pages, structures, documents.')
[02/08/12 01:17:55:729 MDT]  INFO db.DotConnect: Executing insert into log_mapper (ENABLED,LOG_NAME,DESCRIPTION) values ('1','dotcms-security.log','Log users login activity into dotCMS.')
[02/08/12 01:17:55:730 MDT]  INFO db.DotConnect: Executing insert into log_mapper (ENABLED,LOG_NAME,DESCRIPTION) values ('1','dotcms-adminaudit.log','Log Admin activity on dotCMS.')
[02/08/12 01:17:55:730 MDT]  INFO business.WorkflowFactoryImpl: Creating Default Workflow Schema
[02/08/12 01:17:55:733 MDT]  WARN business.WorkflowFactoryImpl: Invalid column name 'escalation_enable'.
com.dotmarketing.exception.DotDataException: Invalid column name 'escalation_enable'.
    at com.dotmarketing.common.db.DotConnect.loadResult(DotConnect.java:232)
    at com.dotmarketing.portlets.workflows.business.WorkflowFactoryImpl.saveStep(WorkflowFactoryImpl.java:1010)
    at com.dotmarketing.portlets.workflows.business.WorkflowFactoryImpl.createDefaultScheme(WorkflowFactoryImpl.java:242)
    at com.dotmarketing.portlets.workflows.business.WorkflowAPIImpl.createDefaultScheme(WorkflowAPIImpl.java:890)
    at com.dotmarketing.startup.runonce.Task00900CreateLogConsoleTable.executeUpgrade(Task00900CreateLogConsoleTable.java:36)
    at com.dotmarketing.startup.StartupTasksExecutor.executeUpgrades(StartupTasksExecutor.java:260)
    at com.liferay.portal.servlet.MainServlet.init(MainServlet.java:117)
    at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1173)
    at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993)
    at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4187)
    at org.apache.catalina.core.StandardContext.start(StandardContext.java:4496)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:546)
    at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:637)
    at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:563)
    at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:498)
    at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277)
    at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321)
    at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
    at org.apache.catalina.core.StandardHost.start(StandardHost.java:785)
    at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
    at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443)
    at org.apache.catalina.core.StandardService.start(StandardService.java:519)
    at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:581)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Invalid column name 'escalation_enable'.
    at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:213)
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1493)
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:388)
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:338)
    at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:5569)
    at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1629)
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:179)
    at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:154)
    at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.execute(SQLServerPreparedStatement.java:320)
    at org.apache.tomcat.dbcp.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
    at com.dotmarketing.common.db.DotConnect.executeQuery(DotConnect.java:545)
    at com.dotmarketing.common.db.DotConnect.executeQuery(DotConnect.java:467)
    at com.dotmarketing.common.db.DotConnect.loadResult(DotConnect.java:230)
    ... 32 more
dotjorgeu commented 12 years ago

right, the stacktrace is just a warn and it isn't stopping the upgrade proccess. It's just noise you can ignore. Closing this one. Nothing to fix