diff --git a/rally/cli/commands/task.py b/rally/cli/commands/task.py index 2cae2c48dc..69315f23e0 100644 --- a/rally/cli/commands/task.py +++ b/rally/cli/commands/task.py @@ -138,7 +138,7 @@ class TaskCommands(object): if task_instance: task_instance.set_failed(err.__class__.__name__, str(err), - json.dumps(traceback.format_stack())) + json.dumps(traceback.format_exc())) raise api.Task.validate(deployment, input_task, task_instance) print(_("Task config is valid :)")) @@ -325,11 +325,11 @@ class TaskCommands(object): print("-" * 80) verification = yaml.safe_load(task["verification_log"]) if logging.is_debug(): - print(yaml.safe_load(verification[2])) + print(yaml.safe_load(verification["trace"])) else: - print(verification[0]) - print(verification[1]) - print(_("\nFor more details run:\nrally -vd task detailed %s") + print(verification["etype"]) + print(verification["msg"]) + print(_("\nFor more details run:\nrally -d task detailed %s") % task["uuid"]) return 0 elif task["status"] not in [consts.TaskStatus.FINISHED, diff --git a/rally/common/db/sqlalchemy/migrations/script.py.mako b/rally/common/db/sqlalchemy/migrations/script.py.mako index 43c09401bc..f3f0d2edd3 100644 --- a/rally/common/db/sqlalchemy/migrations/script.py.mako +++ b/rally/common/db/sqlalchemy/migrations/script.py.mako @@ -1,3 +1,17 @@ +# All Rights Reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + """${message} Revision ID: ${up_revision} @@ -16,9 +30,12 @@ from alembic import op import sqlalchemy as sa ${imports if imports else ""} +${"from rally import exceptions" if not downgrades else ""} + + def upgrade(): ${upgrades if upgrades else "pass"} def downgrade(): - ${downgrades if downgrades else "pass"} + ${downgrades if downgrades else "raise exceptions.DowngradeNotSupported()"} diff --git a/rally/common/db/sqlalchemy/migrations/versions/08e1515a576c_fix_invalid_verification_logs.py b/rally/common/db/sqlalchemy/migrations/versions/08e1515a576c_fix_invalid_verification_logs.py new file mode 100644 index 0000000000..f9eb973e2f --- /dev/null +++ b/rally/common/db/sqlalchemy/migrations/versions/08e1515a576c_fix_invalid_verification_logs.py @@ -0,0 +1,112 @@ +# All Rights Reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + +"""fix invalid verification logs + +Revision ID: 08e1515a576c +Revises: 54e844ebfbc3 +Create Date: 2016-09-12 15:47:11.279610 + +""" + +# revision identifiers, used by Alembic. +revision = "08e1515a576c" +down_revision = "54e844ebfbc3" +branch_labels = None +depends_on = None + + +import json +import uuid + +from alembic import op +import sqlalchemy as sa + +from rally import consts +from rally import exceptions + + +def UUID(): + return str(uuid.uuid4()) + + +task_helper = sa.Table( + "tasks", + sa.MetaData(), + sa.Column("id", sa.Integer, primary_key=True, autoincrement=True), + sa.Column("uuid", sa.String(36), default=UUID, nullable=False), + sa.Column("status", sa.Enum(*list(consts.TaskStatus), + name="enum_tasks_status"), + default=consts.TaskStatus.INIT, nullable=False), + sa.Column("verification_log", sa.Text, default=""), + sa.Column("tag", sa.String(64), default=""), + sa.Column("deployment_uuid", sa.String(36), nullable=False) +) + + +def _make_trace(etype, emsg, raw_trace=None): + trace = "Traceback (most recent call last):\n" + if raw_trace is None: + trace += "\n\t\t...n/a..\n\n" + else: + trace += "".join(json.loads(raw_trace)) + + trace += "%s: %s" % (etype, emsg) + return trace + + +def upgrade(): + connection = op.get_bind() + for task in connection.execute(task_helper.select()): + verification_log = task.verification_log + + if not verification_log: + continue + + new_value = None + + verification_log = json.loads(verification_log) + if isinstance(verification_log, list): + new_value = {"etype": verification_log[0], + "msg": verification_log[1], + "trace": verification_log[2]} + if new_value["trace"].startswith("["): + # NOTE(andreykurilin): For several cases traceback was + # transmitted as list instead of string. + new_value["trace"] = _make_trace(*verification_log) + else: + if verification_log.startswith("No such file"): + new_value = {"etype": IOError.__name__, + "msg": verification_log} + new_value["trace"] = _make_trace(new_value["etype"], + new_value["msg"]) + elif verification_log.startswith("Task config is invalid"): + new_value = {"etype": exceptions.InvalidTaskException.__name__, + "msg": verification_log} + new_value["trace"] = _make_trace(new_value["etype"], + new_value["msg"]) + elif verification_log.startswith("Failed to load task"): + new_value = {"etype": "FailedToLoadTask", + "msg": verification_log} + new_value["trace"] = _make_trace(new_value["etype"], + new_value["msg"]) + + if new_value: + connection.execute(task_helper.update().where( + task_helper.c.id == task.id).values( + verification_log=json.dumps(new_value))) + + +def downgrade(): + raise exceptions.DowngradeNotSupported() diff --git a/rally/common/objects/task.py b/rally/common/objects/task.py index a44175a50a..85f0207582 100644 --- a/rally/common/objects/task.py +++ b/rally/common/objects/task.py @@ -350,10 +350,8 @@ class Task(object): def set_failed(self, etype, msg, etraceback): self._update({"status": consts.TaskStatus.FAILED, - "verification_log": json.dumps([etype, - msg, - etraceback - ])}) + "verification_log": json.dumps( + {"etype": etype, "msg": msg, "trace": etraceback})}) def get_results(self): return db.task_result_get_all_by_uuid(self.task["uuid"]) diff --git a/tests/unit/cli/commands/test_task.py b/tests/unit/cli/commands/test_task.py index e5227abb08..8868312f34 100644 --- a/tests/unit/cli/commands/test_task.py +++ b/tests/unit/cli/commands/test_task.py @@ -324,8 +324,9 @@ class TaskCommandsTestCase(test.TestCase): "uuid": test_uuid, "status": consts.TaskStatus.FAILED, "results": [], - "verification_log": json.dumps(["error_type", "error_message", - "error_traceback"]) + "verification_log": json.dumps({"etype": "error_type", + "msg": "error_message", + "trace": "error_traceback"}) } mock_task.get_detailed = mock.MagicMock(return_value=value) @@ -334,14 +335,14 @@ class TaskCommandsTestCase(test.TestCase): verification = yaml.safe_load(value["verification_log"]) if debug: expected_calls = [mock.call("Task test_task_id: failed"), - mock.call("%s" % verification[2])] + mock.call("%s" % verification["trace"])] mock_stdout.write.assert_has_calls(expected_calls, any_order=True) else: expected_calls = [mock.call("Task test_task_id: failed"), - mock.call("%s" % verification[0]), - mock.call("%s" % verification[1]), + mock.call("%s" % verification["etype"]), + mock.call("%s" % verification["msg"]), mock.call("\nFor more details run:\nrally " - "-vd task detailed %s" % test_uuid)] + "-d task detailed %s" % test_uuid)] mock_stdout.write.assert_has_calls(expected_calls, any_order=True) @mock.patch("rally.cli.commands.task.api.Task") diff --git a/tests/unit/common/db/test_migrations.py b/tests/unit/common/db/test_migrations.py index c4b54f6735..082ba768e8 100644 --- a/tests/unit/common/db/test_migrations.py +++ b/tests/unit/common/db/test_migrations.py @@ -383,3 +383,76 @@ class MigrationWalkTestCase(rtest.DBTestCase, deployment_table.delete().where( deployment_table.c.uuid == deployment.uuid) ) + + def _pre_upgrade_08e1515a576c(self, engine): + self._08e1515a576c_logs = [ + {"pre": "No such file name", + "post": {"etype": IOError.__name__, "msg": "No such file name"}}, + {"pre": "Task config is invalid: bla", + "post": {"etype": "InvalidTaskException", + "msg": "Task config is invalid: bla"}}, + {"pre": "Failed to load task foo", + "post": {"etype": "FailedToLoadTask", + "msg": "Failed to load task foo"}}, + {"pre": ["SomeCls", "msg", json.dumps( + ["File some1.py, line ...\n", + "File some2.py, line ...\n"])], + "post": {"etype": "SomeCls", + "msg": "msg", + "trace": "Traceback (most recent call last):\n" + "File some1.py, line ...\n" + "File some2.py, line ...\nSomeCls: msg"}}, + ] + + deployment_table = db_utils.get_table(engine, "deployments") + task_table = db_utils.get_table(engine, "tasks") + + self._08e1515a576c_deployment_uuid = "08e1515a576c-uuuu-uuuu-iiii-dddd" + with engine.connect() as conn: + conn.execute( + deployment_table.insert(), + [{"uuid": self._08e1515a576c_deployment_uuid, + "name": self._08e1515a576c_deployment_uuid, + "config": six.b("{}"), + "enum_deployments_status": + consts.DeployStatus.DEPLOY_FINISHED, + "credentials": six.b(json.dumps([])), + "users": six.b(json.dumps([])) + }]) + for i in range(0, len(self._08e1515a576c_logs)): + log = json.dumps(self._08e1515a576c_logs[i]["pre"]) + conn.execute( + task_table.insert(), + [{"uuid": i, + "verification_log": log, + "status": consts.TaskStatus.FAILED, + "enum_tasks_status": consts.TaskStatus.FAILED, + "deployment_uuid": self._08e1515a576c_deployment_uuid + }]) + + def _check_08e1515a576c(self, engine, data): + self.assertEqual("08e1515a576c", + api.get_backend().schema_revision(engine=engine)) + + tasks = self._08e1515a576c_logs + + deployment_table = db_utils.get_table(engine, "deployments") + task_table = db_utils.get_table(engine, "tasks") + + with engine.connect() as conn: + tasks_found = conn.execute(task_table.select()).fetchall() + for task in tasks_found: + actual_log = json.loads(task.verification_log) + self.assertIsInstance(actual_log, dict) + expected = tasks[int(task.uuid)]["post"] + for key in expected: + self.assertEqual(expected[key], actual_log[key]) + + conn.execute( + task_table.delete().where(task_table.c.uuid == task.uuid)) + + deployment_uuid = self._08e1515a576c_deployment_uuid + conn.execute( + deployment_table.delete().where( + deployment_table.c.uuid == deployment_uuid) + ) diff --git a/tests/unit/common/objects/test_task.py b/tests/unit/common/objects/test_task.py index fff8266ef1..884b5a6703 100644 --- a/tests/unit/common/objects/test_task.py +++ b/tests/unit/common/objects/test_task.py @@ -249,8 +249,9 @@ class TaskTestCase(test.TestCase): mock_task_update.assert_called_once_with( self.task["uuid"], {"status": consts.TaskStatus.FAILED, - "verification_log": "[\"foo_type\", \"foo_error_message\", " - "\"foo_trace\"]"}, + "verification_log": json.dumps({"etype": "foo_type", + "msg": "foo_error_message", + "trace": "foo_trace"})}, ) @ddt.data(