Attachment 949388 Details for Bug 1082805 – rhqctl_upgrade_312_330er05

rhqctl_upgrade_312_330er05

rhqctl_upgrade_312_330er5.log (text/plain), 18.33 KB, created by Armine Hovsepyan on 2014-10-22 13:09:04 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Armine Hovsepyan

Created: 2014-10-22 13:09:04 UTC

Size: 18.33 KB

patch

obsolete

>[hudson@jon312 ~]$ ./jon-server-3.3.0.ER05/bin/rhqctl upgrade --from-server-dir /home/hudson/jon-server-3.1.2.GA/
>09:05:06,226 INFO  [org.jboss.modules] JBoss Modules version 1.3.3.Final-redhat-1
>09:05:06,438 INFO  [org.rhq.server.control.command.Upgrade] Stopping any running RHQ components...
>Trying to stop the RHQ Server...
>RHQ Server (pid=3237) is stopping...
>RHQ Server has stopped.
>09:05:12,597 INFO  [org.rhq.server.control.command.Upgrade] The old installation components have been stopped
>09:05:12,600 INFO  [org.rhq.server.control.command.Upgrade] Preparing to install RHQ storage node.
>Starting RHQ Storage Installer ...
>09:05:13,193 INFO  [org.jboss.modules] JBoss Modules version 1.3.3.Final-redhat-1
>09:05:13,321 INFO  [org.rhq.storage.installer.StorageInstaller] Running RHQ Storage Node installer...
>09:05:13,345 INFO  [org.rhq.storage.installer.StorageInstaller] Checking perms for ../../../rhq-data/saved_caches
>09:05:13,365 INFO  [org.rhq.storage.installer.StorageInstaller] Checking perms for ../../../rhq-data/commit_log
>09:05:13,366 INFO  [org.rhq.storage.installer.StorageInstaller] Checking perms for ../../../rhq-data/data
>09:05:13,377 INFO  [org.rhq.cassandra.Deployer] Unzipping storage node to /home/hudson/jon-server-3.3.0.ER05/rhq-storage
>09:05:13,721 INFO  [org.rhq.cassandra.Deployer] Applying configuration changes to /home/hudson/jon-server-3.3.0.ER05/rhq-storage/conf/cassandra.yaml
>09:05:13,842 INFO  [org.rhq.cassandra.Deployer] Applying configuration changes to /home/hudson/jon-server-3.3.0.ER05/rhq-storage/conf/log4j-server.properties
>09:05:13,845 INFO  [org.rhq.cassandra.Deployer] Applying configuration changes to /home/hudson/jon-server-3.3.0.ER05/rhq-storage/conf/cassandra-jvm.properties
>09:05:13,860 INFO  [org.rhq.cassandra.Deployer] Updating file permissions in /home/hudson/jon-server-3.3.0.ER05/rhq-storage/bin
>09:05:13,865 INFO  [org.rhq.storage.installer.StorageInstaller] Updating rhq-server.properties...
>09:05:13,909 INFO  [org.rhq.storage.installer.StorageInstaller] Starting RHQ Storage Node
>09:05:25,894 INFO  [org.rhq.storage.installer.StorageInstaller] RHQ Storage Node is up and running and ready to service client requests
>09:05:25,900 INFO  [org.rhq.storage.installer.StorageInstaller] Installation of the storage node has completed successfully.
>09:05:25,918 INFO  [org.rhq.server.control.command.Upgrade] The storage node installer has finished with an exit value of 0
>09:05:26,247 INFO  [org.rhq.server.control.command.Upgrade] Looks like the new server already has an Oracle driver: /home/hudson/jon-server-3.3.0.ER05/modules/org/rhq/oracle/main/ojdbc6-12.1.0.1.0.jar
>09:05:26,317 INFO  [org.rhq.server.control.command.Upgrade] The RHQ Server must be started to complete its installation. Starting the RHQ server in preparation of running the server installer...
>09:05:26,347 INFO  [org.rhq.server.control.command.Upgrade] Waiting for the RHQ Server to start in preparation of running the server installer...
>Trying to start the RHQ Server...
>RHQ Server                     (pid 4291   ) is starting
>09:05:33,067 INFO  [org.jboss.modules] JBoss Modules version 1.3.3.Final-redhat-1
>09:05:33,255 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] The server is preconfigured and ready for auto-install.
>09:05:33,343 INFO  [org.xnio] XNIO Version 3.0.10.GA-redhat-1
>09:05:33,413 INFO  [org.xnio.nio] XNIO NIO Implementation Version 3.0.10.GA-redhat-1
>09:05:33,441 INFO  [org.jboss.remoting] JBoss Remoting version (unknown)
>09:05:34,229 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] Installing into app server version [7.4.0.Final-redhat-19]
>09:05:34,474 INFO  [org.rhq.enterprise.server.installer.ServerInstallUtil] Database is supported: postgresql8.4(postgresql:8.4)
>09:05:34,507 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] This [[name=jon312.bc.jonqe.lab.eng.bos.redhat.com, address=10.16.23.149, port=7080, secureport=7443]] will be considered a reinstallation of an existing server [[name=jon312.bc.jonqe.lab.eng.bos.redhat.com, address=10.16.23.149, port=7080, secureport=7443]]
>09:05:34,508 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] The app server where the installation will go is found at: /home/hudson/jon-server-3.3.0.ER05
>09:05:34,509 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] It looks like everything is OK and you can start the installation.
>09:05:34,515 INFO  [org.rhq.server.control.command.Upgrade] The RHQ Server is ready to be upgraded by the server installer.
>09:05:34,517 INFO  [org.rhq.server.control.command.Upgrade] Upgrading RHQ Server
>09:05:34,518 INFO  [org.rhq.server.control.command.Upgrade] The RHQ Server installer is running
>09:05:34,685 INFO  [org.xnio] XNIO Version 3.0.10.GA-redhat-1
>09:05:34,700 INFO  [org.xnio.nio] XNIO NIO Implementation Version 3.0.10.GA-redhat-1
>09:05:34,750 INFO  [org.jboss.remoting] JBoss Remoting version (unknown)
>09:05:35,499 INFO  [org.jboss.modules] JBoss Modules version 1.3.3.Final-redhat-1
>09:05:35,642 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] The server is preconfigured and ready for auto-install.
>09:05:35,724 INFO  [org.xnio] XNIO Version 3.0.10.GA-redhat-1
>09:05:35,734 INFO  [org.xnio.nio] XNIO NIO Implementation Version 3.0.10.GA-redhat-1
>09:05:35,757 INFO  [org.jboss.remoting] JBoss Remoting version (unknown)
>09:05:36,298 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] Installing into app server version [7.4.0.Final-redhat-19]
>09:05:36,512 INFO  [org.rhq.enterprise.server.installer.ServerInstallUtil] Database is supported: postgresql8.4(postgresql:8.4)
>09:05:36,541 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] Database setup log file directory: /home/hudson/jon-server-3.3.0.ER05/logs
>09:05:36,583 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] Database schema exists - it will now be updated.
>09:05:40,446 INFO  [org.rhq.cassandra.schema.VersionManager] Preparing to check storage schema compatibility.
>09:05:40,837 INFO  [org.rhq.cassandra.schema.VersionManager] Completed storage schema compatibility check.
>09:05:40,837 INFO  [org.rhq.enterprise.server.installer.InstallerServiceImpl] Install RHQ schema along with updates to storage nodes.
>09:05:40,839 INFO  [org.rhq.cassandra.schema.VersionManager] Preparing to install storage schema
>09:05:40,839 INFO  [org.rhq.cassandra.schema.AbstractManager] Shutting down existing cluster connections
>09:05:40,869 INFO  [org.rhq.cassandra.schema.AbstractManager] Shutting down existing cluster connections
>09:05:41,825 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/create/0001.xml
>09:05:43,941 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/create/0001.xml
>09:05:43,942 INFO  [org.rhq.cassandra.schema.AbstractManager] Shutting down existing cluster connections
>09:05:44,523 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/create/0002.xml
>09:05:44,662 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/create/0002.xml
>09:05:44,715 INFO  [org.rhq.cassandra.schema.VersionManager] Installed storage schema version is 0
>09:05:44,716 INFO  [org.rhq.cassandra.schema.VersionManager] Required storage schema version is 7
>09:05:44,716 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema requires udpates. Updating from version 0 to version 7.
>09:05:44,716 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0001.xml
>09:05:47,887 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0001.xml
>09:05:47,891 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0001.xml applied.
>09:05:47,891 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0002.xml
>09:05:50,925 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0002.xml
>09:05:50,928 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0002.xml applied.
>09:05:50,929 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0003.xml
>09:05:50,931 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0003.xml
>09:05:50,933 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0003.xml applied.
>09:05:50,934 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0004.xml
>09:05:51,901 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0004.xml
>09:05:51,904 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0004.xml applied.
>09:05:51,904 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0005.xml
>09:05:51,963 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Migrating aggregate metrics for 2345 schedule ids
>09:05:51,964 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Migrating one_hour data for 2345 schedules
>09:05:51,966 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] There are 2345 remaining schedules for the one_hour data migration
>09:05:56,082 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Finished migrating one_hour data
>09:05:56,082 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Migrating six_hour data for 2345 schedules
>09:05:56,083 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] There are 2345 remaining schedules for the six_hour data migration
>09:05:58,811 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Finished migrating six_hour data
>09:05:58,812 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Migrating twenty_four_hour data for 2345 schedules
>09:05:58,812 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] There are 2345 remaining schedules for the twenty_four_hour data migration
>09:06:01,069 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Finished migrating twenty_four_hour data
>09:06:01,070 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Finished aggregate metrics migration in 9 seconds
>09:06:01,074 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Dropping table one_hour_metrics
>09:06:02,594 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Dropping table six_hour_metrics
>09:06:04,105 INFO  [org.rhq.cassandra.schema.MigrateAggregateMetrics] Dropping table twenty_four_hour_metrics
>09:06:05,242 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0005.xml
>09:06:05,244 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0005.xml applied.
>09:06:05,244 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0006.xml
>09:06:05,754 INFO  [org.rhq.server.control.command.Upgrade] Still waiting for server to start...
>09:06:05,917 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0006.xml
>09:06:05,920 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0006.xml applied.
>09:06:05,920 INFO  [org.rhq.cassandra.schema.AbstractManager] Applying update file: schema/update/0007.xml
>09:06:06,032 INFO  [org.rhq.cassandra.schema.ReplaceIndex] Preparing to replace metrics_index
>09:06:06,039 INFO  [org.rhq.cassandra.schema.ReplaceRHQ411Index] Updating raw index
>09:06:06,135 INFO  [org.rhq.cassandra.schema.ReplaceRHQ411Index] Updating one_hour index
>09:06:06,157 INFO  [org.rhq.cassandra.schema.ReplaceRHQ411Index] Updating six_hour index
>09:06:06,163 INFO  [org.rhq.cassandra.schema.ReplaceRHQ411Index] Dropping table metrics_index
>09:06:07,274 INFO  [org.rhq.cassandra.schema.AbstractManager] Applied update file: schema/update/0007.xml
>09:06:07,289 INFO  [org.rhq.cassandra.schema.VersionManager] Storage schema update schema/update/0007.xml applied.
>09:06:07,304 INFO  [org.rhq.cassandra.schema.TopologyManager] Applying topology updates...
>09:06:07,305 INFO  [org.rhq.cassandra.schema.TopologyManager] Starting to execute UpdateReplicationFactor task.
>09:06:07,307 INFO  [org.rhq.cassandra.schema.TopologyManager] No need to update replication factor. Replication factor already 1
>09:06:07,307 INFO  [org.rhq.cassandra.schema.TopologyManager] Successfully executed UpdateReplicationFactor task.
>09:06:07,307 INFO  [org.rhq.cassandra.schema.TopologyManager] Starting to execute UpdateGCGrace task.
>09:06:11,438 INFO  [org.rhq.cassandra.schema.TopologyManager] Updated gc_grace_seconds to 0
>09:06:11,438 INFO  [org.rhq.cassandra.schema.TopologyManager] Successfully executed UpdateGCGrace task.
>09:06:11,494 INFO  [org.rhq.enterprise.server.installer.ServerInstallUtil] Admin user password is already set, property [rhq.autoinstall.server.admin.password] will be ignored.
>09:06:11,506 INFO  [org.rhq.enterprise.server.installer.ServerInstallUtil] Persisting to database new storage nodes for values specified in server configuration property [rhq.storage.nodes]
>09:06:11,513 ERROR [org.rhq.enterprise.server.installer.ServerInstallUtil] Failed to persist to database the storage nodes specified by server configuration property [rhq.storage.nodes]. Transaction will be rolled back.: org.postgresql.util.PSQLException: ERROR: column "version" of relation "rhq_storage_node" does not exist
>  Position: 105
>	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2157) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1886) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:363) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.rhq.enterprise.server.installer.ServerInstallUtil.persistStorageNodesIfNecessary(ServerInstallUtil.java:1111) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.InstallerServiceImpl.prepareDatabase(InstallerServiceImpl.java:650) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.InstallerServiceImpl.install(InstallerServiceImpl.java:409) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.Installer.doInstall(Installer.java:134) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.Installer.main(Installer.java:59) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_45]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_45]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_45]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_45]
>	at org.jboss.modules.Module.run(Module.java:312) [jboss-modules.jar:1.3.3.Final-redhat-1]
>	at org.jboss.modules.Main.main(Main.java:460) [jboss-modules.jar:1.3.3.Final-redhat-1]
>
>09:06:11,518 ERROR [org.rhq.enterprise.server.installer.Installer] The installer will now exit due to previous errors: org.postgresql.util.PSQLException: ERROR: column "version" of relation "rhq_storage_node" does not exist
>  Position: 105
>	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2157) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1886) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:363) [postgresql-9.2-1002.jdbc4.jar:]
>	at org.rhq.enterprise.server.installer.ServerInstallUtil.persistStorageNodesIfNecessary(ServerInstallUtil.java:1111) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.InstallerServiceImpl.prepareDatabase(InstallerServiceImpl.java:650) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.InstallerServiceImpl.install(InstallerServiceImpl.java:409) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.Installer.doInstall(Installer.java:134) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at org.rhq.enterprise.server.installer.Installer.main(Installer.java:59) [rhq-installer-util-4.12.0.JON330ER05.jar:4.12.0.JON330ER05]
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_45]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_45]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_45]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_45]
>	at org.jboss.modules.Module.run(Module.java:312) [jboss-modules.jar:1.3.3.Final-redhat-1]
>	at org.jboss.modules.Main.main(Main.java:460) [jboss-modules.jar:1.3.3.Final-redhat-1]
>
>Trying to stop the RHQ Server...
>RHQ Server (pid=4291) is stopping...
>RHQ Server has stopped.
>RHQ Server                     (no pid file) is âdown
>Stopping RHQ storage node...
>RHQ storage node (pid=4071) is stopping...
>RHQ storage node has stopped
>09:06:24,048 ERROR [org.rhq.server.control.RHQControl] Installer failed with code 2, shut down server
>09:06:24,048 WARN  [org.rhq.server.control.command.Upgrade] UNDO: Removing server-installed marker file and management user and reverting to original standalone-full.xml
>09:06:24,049 WARN  [org.rhq.server.control.command.Upgrade] UNDO: Stopping component: --server
>RHQ Server                     (no pid file) is âdown
>09:06:24,103 WARN  [org.rhq.server.control.command.Upgrade] UNDO: Stopping component: --storage
>09:06:24,104 WARN  [org.rhq.server.control.command.Upgrade] UNDO: Removing storage node data and install directories
>09:06:24,179 WARN  [org.rhq.server.control.command.Upgrade] UNDO: Reverting server properties file
>[hudson@jon312 ~]$ 
>

Actions: View

Attachments on bug 1082805: 949388 | 949820 | 951552 | 951905