log_graph_sync.json

adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "atexit", "lineno": 51, "funcname": "_shutdown", "created": 1595279407.2818103, "asctime": "2020-07-20 21:10:07,281", "msecs": 281.8102836608887, "relative_created": 169235.69345474243, "process": 1, "message": "atexit: got shutdown signal"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "atexit", "lineno": 55, "funcname": "_shutdown", "created": 1595279407.2824044, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.40442276000977, "relative_created": 169236.28759384155, "process": 1, "message": "atexit: shutting down client"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "transport", "lineno": 335, "funcname": "flush", "created": 1595279407.2826114, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.6113700866699, "relative_created": 169236.4945411682, "process": 1, "message": "Flushing HTTP transport"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 105, "funcname": "flush", "created": 1595279407.282713, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.7129364013672, "relative_created": 169236.5961074829, "process": 1, "message": "background worker got flush request"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 109, "funcname": "flush", "created": 1595279407.2827928, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.7928066253662, "relative_created": 169236.6759777069, "process": 1, "message": "background worker flushed"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "transport", "lineno": 341, "funcname": "kill", "created": 1595279407.2828486, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.848596572876, "relative_created": 169236.73176765442, "process": 1, "message": "Killing HTTP transport"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 92, "funcname": "kill", "created": 1595279407.2828994, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.8993797302246, "relative_created": 169236.78255081177, "process": 1, "message": "background worker got kill request"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "transport", "lineno": 341, "funcname": "kill", "created": 1595279407.282953, "asctime": "2020-07-20 21:10:07,282", "msecs": 282.95302391052246, "relative_created": 169236.83619499207, "process": 1, "message": "Killing HTTP transport"}
adviser-4e4520b7-3285270457: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 92, "funcname": "kill", "created": 1595279407.2830012, "asctime": "2020-07-20 21:10:07,283", "msecs": 283.001184463501, "relative_created": 169236.88435554504, "process": 1, "message": "background worker got kill request"}
adviser-4e4520b7-3798677719: {"name": "thoth.storages.graph.models_base", "levelname": "WARNING", "module": "models_base", "lineno": 60, "funcname": "get_or_create", "created": 1595279450.0640476, "asctime": "2020-07-20 21:10:50,064", "msecs": 64.04757499694824, "relative_created": 13995.768785476685, "process": 1, "message": "Integrity error on creating a new record; this can be due to concurrent writes to database, recovering (attributes: {'package_name': 'voluptuous', 'package_version': '0.11.7', 'python_package_index_id': 1, 'os_name': 'rhel', 'os_version': '8', 'python_version': '3.6', 'entity_id': 87, 'python_package_metadata_id': 84462}): (psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint \"python_package_version_package_name_package_version_python__key\"\nDETAIL:  Key (package_name, package_version, python_package_index_id, os_name, os_version, python_version)=(voluptuous, 0.11.7, 1, rhel, 8, 3.6) already exists.\n\n[SQL: INSERT INTO python_package_version (package_name, package_version, os_name, os_version, python_version, entity_id, python_package_index_id, python_package_metadata_id, is_missing) VALUES (%(package_name)s, %(package_version)s, %(os_name)s, %(os_version)s, %(python_version)s, %(entity_id)s, %(python_package_index_id)s, %(python_package_metadata_id)s, %(is_missing)s) RETURNING python_package_version.id]\n[parameters: {'package_name': 'voluptuous', 'package_version': '0.11.7', 'os_name': 'rhel', 'os_version': '8', 'python_version': '3.6', 'entity_id': 87, 'python_package_index_id': 1, 'python_package_metadata_id': 84462, 'is_missing': False}]\n(Background on this error at: http://sqlalche.me/e/gkpj)"}
adviser-4e4520b7-3798677719: Traceback (most recent call last):
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
adviser-4e4520b7-3798677719:     cursor, statement, parameters, context
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
adviser-4e4520b7-3798677719:     cursor.execute(statement, parameters)
adviser-4e4520b7-3798677719: psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "python_package_version_package_name_package_version_python__key"
adviser-4e4520b7-3798677719: DETAIL:  Key (package_name, package_version, python_package_index_id, os_name, os_version, python_version)=(voluptuous, 0.11.7, 1, rhel, 8, 3.6) already exists.
adviser-4e4520b7-3798677719: The above exception was the direct cause of the following exception:
adviser-4e4520b7-3798677719: Traceback (most recent call last):
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/graph/models_base.py", line 52, in get_or_create
adviser-4e4520b7-3798677719:     session.commit()
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 1036, in commit
adviser-4e4520b7-3798677719:     self.transaction.commit()
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 503, in commit
adviser-4e4520b7-3798677719:     self._prepare_impl()
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 482, in _prepare_impl
adviser-4e4520b7-3798677719:     self.session.flush()
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2496, in flush
adviser-4e4520b7-3798677719:     self._flush(objects)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2637, in _flush
adviser-4e4520b7-3798677719:     transaction.rollback(_capture_exception=True)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 69, in __exit__
adviser-4e4520b7-3798677719:     exc_value, with_traceback=exc_tb,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/util/compat.py", line 178, in raise_
adviser-4e4520b7-3798677719:     raise exception
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2597, in _flush
adviser-4e4520b7-3798677719:     flush_context.execute()
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 422, in execute
adviser-4e4520b7-3798677719:     rec.execute(self)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 589, in execute
adviser-4e4520b7-3798677719:     uow,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 245, in save_obj
adviser-4e4520b7-3798677719:     insert,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1136, in _emit_insert_statements
adviser-4e4520b7-3798677719:     statement, params
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 984, in execute
adviser-4e4520b7-3798677719:     return meth(self, multiparams, params)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/sql/elements.py", line 293, in _execute_on_connection
adviser-4e4520b7-3798677719:     return connection._execute_clauseelement(self, multiparams, params)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1103, in _execute_clauseelement
adviser-4e4520b7-3798677719:     distilled_params,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1288, in _execute_context
adviser-4e4520b7-3798677719:     e, statement, parameters, cursor, context
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1482, in _handle_dbapi_exception
adviser-4e4520b7-3798677719:     sqlalchemy_exception, with_traceback=exc_info[2], from_=e
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "transport", "lineno": 212, "funcname": "_send_event", "created": 1595279450.5706875, "asctime": "2020-07-20 21:10:50,570", "msecs": 570.6875324249268, "relative_created": 14502.408742904663, "process": 1, "message": "Sending event, type:null level:error event_id:e01cb7c481af4bf3b7dbd44cd54301de project:1298083 host:sentry.io"}
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/util/compat.py", line 178, in raise_
adviser-4e4520b7-3798677719:     raise exception
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
adviser-4e4520b7-3798677719:     cursor, statement, parameters, context
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/engine/default.py", line 590, in do_execute
adviser-4e4520b7-3798677719:     cursor.execute(statement, parameters)
adviser-4e4520b7-3798677719: sqlalchemy.exc.IntegrityError: (psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "python_package_version_package_name_package_version_python__key"
adviser-4e4520b7-3798677719: DETAIL:  Key (package_name, package_version, python_package_index_id, os_name, os_version, python_version)=(voluptuous, 0.11.7, 1, rhel, 8, 3.6) already exists.
adviser-4e4520b7-3798677719: [SQL: INSERT INTO python_package_version (package_name, package_version, os_name, os_version, python_version, entity_id, python_package_index_id, python_package_metadata_id, is_missing) VALUES (%(package_name)s, %(package_version)s, %(os_name)s, %(os_version)s, %(python_version)s, %(entity_id)s, %(python_package_index_id)s, %(python_package_metadata_id)s, %(is_missing)s) RETURNING python_package_version.id]
adviser-4e4520b7-3798677719: [parameters: {'package_name': 'voluptuous', 'package_version': '0.11.7', 'os_name': 'rhel', 'os_version': '8', 'python_version': '3.6', 'entity_id': 87, 'python_package_index_id': 1, 'python_package_metadata_id': 84462, 'is_missing': False}]
adviser-4e4520b7-3798677719: (Background on this error at: http://sqlalche.me/e/gkpj)
adviser-4e4520b7-3798677719: During handling of the above exception, another exception occurred:
adviser-4e4520b7-3798677719: Traceback (most recent call last):
adviser-4e4520b7-3798677719:   File "app.py", line 239, in <module>
adviser-4e4520b7-3798677719:     cli()
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/click/core.py", line 829, in __call__
adviser-4e4520b7-3798677719:     return self.main(*args, **kwargs)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/click/core.py", line 782, in main
adviser-4e4520b7-3798677719:     rv = self.invoke(ctx)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/click/core.py", line 1066, in invoke
adviser-4e4520b7-3798677719:     return ctx.invoke(self.callback, **ctx.params)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/click/core.py", line 610, in invoke
adviser-4e4520b7-3798677719:     return callback(*args, **kwargs)
adviser-4e4520b7-3798677719:   File "app.py", line 219, in cli
adviser-4e4520b7-3798677719:     is_local=local_file,
adviser-4e4520b7-3798677719:   File "app.py", line 119, in _do_sync
adviser-4e4520b7-3798677719:     is_local=is_local,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/sync.py", line 617, in sync_documents
adviser-4e4520b7-3798677719:     to_sync_document_id, force=force, graceful=graceful, graph=graph, is_local=is_local
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/sync.py", line 85, in sync_adviser_documents
adviser-4e4520b7-3798677719:     graph.sync_adviser_result(document)
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/graph/postgres.py", line 4940, in sync_adviser_result
adviser-4e4520b7-3798677719:     overall_score=overall_score,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/graph/postgres.py", line 3727, in _create_python_software_stack
adviser-4e4520b7-3798677719:     session, requirements_lock, software_environment=software_environment, sync_only_entity=is_external
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/graph/postgres.py", line 3553, in _create_python_packages_pipfile
adviser-4e4520b7-3798677719:     sync_only_entity=sync_only_entity,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/graph/postgres.py", line 3691, in _create_python_package_version
adviser-4e4520b7-3798677719:     python_package_metadata_id=python_package_metadata_id,
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/thoth/storages/graph/models_base.py", line 62, in get_or_create
adviser-4e4520b7-3798677719:     return session.query(cls).filter_by(**kwargs).one(), True
adviser-4e4520b7-3798677719:   File "/opt/app-root/lib/python3.6/site-packages/sqlalchemy/orm/query.py", line 3370, in one
adviser-4e4520b7-3798677719:     raise orm_exc.NoResultFound("No row was found for one()")
adviser-4e4520b7-3798677719: sqlalchemy.orm.exc.NoResultFound: No row was found for one()
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "atexit", "lineno": 51, "funcname": "_shutdown", "created": 1595279450.5794013, "asctime": "2020-07-20 21:10:50,579", "msecs": 579.4012546539307, "relative_created": 14511.122465133667, "process": 1, "message": "atexit: got shutdown signal"}
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "atexit", "lineno": 55, "funcname": "_shutdown", "created": 1595279450.5796754, "asctime": "2020-07-20 21:10:50,579", "msecs": 579.6754360198975, "relative_created": 14511.396646499634, "process": 1, "message": "atexit: shutting down client"}
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "transport", "lineno": 320, "funcname": "flush", "created": 1595279450.5797806, "asctime": "2020-07-20 21:10:50,579", "msecs": 579.7805786132812, "relative_created": 14511.501789093018, "process": 1, "message": "Flushing HTTP transport"}
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 105, "funcname": "flush", "created": 1595279450.57985, "asctime": "2020-07-20 21:10:50,579", "msecs": 579.8499584197998, "relative_created": 14511.571168899536, "process": 1, "message": "background worker got flush request"}
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 116, "funcname": "_wait_flush", "created": 1595279450.680274, "asctime": "2020-07-20 21:10:50,680", "msecs": 680.2740097045898, "relative_created": 14611.995220184326, "process": 1, "message": "0 event(s) pending on flush"}
adviser-4e4520b7-3798677719: Sentry is attempting to send 0 pending error messages
adviser-4e4520b7-3798677719: Waiting up to 2 seconds
adviser-4e4520b7-3798677719: Press Ctrl-C to quit
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 109, "funcname": "flush", "created": 1595279450.857898, "asctime": "2020-07-20 21:10:50,857", "msecs": 857.8979969024658, "relative_created": 14789.619207382202, "process": 1, "message": "background worker flushed"}
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "transport", "lineno": 326, "funcname": "kill", "created": 1595279450.8582726, "asctime": "2020-07-20 21:10:50,858", "msecs": 858.2725524902344, "relative_created": 14789.99376296997, "process": 1, "message": "Killing HTTP transport"}
adviser-4e4520b7-3798677719: {"name": "sentry_sdk.errors", "levelname": "DEBUG", "module": "worker", "lineno": 92, "funcname": "kill", "created": 1595279450.8583684, "asctime": "2020-07-20 21:10:50,858", "msecs": 858.3683967590332, "relative_created": 14790.08960723877, "process": 1, "message": "background worker got kill request"}