Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] - IntegrityError upon startup #852

Open
peytondmurray opened this issue Jul 19, 2024 · 7 comments · May be fixed by #976
Open

[BUG] - IntegrityError upon startup #852

peytondmurray opened this issue Jul 19, 2024 · 7 comments · May be fixed by #976
Assignees
@soapy1 @peytondmurray
Labels
needs: investigation 🔎 Someone in the team needs to look into this issue before scoping type: bug 🐛 Something isn't working

Comments

@peytondmurray
Copy link
Contributor

peytondmurray commented Jul 19, 2024 •
edited
Loading

Describe the bug

Whenever I start the conda-store services with docker compose up --build, I get integrity errors:

... <more startup stuff here>

conda-store-worker-1  | [2024-07-19 00:02:40,346: WARNING/ForkPoolWorker-4] [CondaStoreWorker] building conda_prefix=/var/lib/conda-store/filesystem/7ff0f78a-1721347282-1-python-flask-env took 77.196 [s]
conda-store-worker-1  | [2024-07-19 00:02:41,850: INFO/MainProcess] Task task_build_conda_env_export[build-1-conda-env-export] received
conda-store-worker-1  | [2024-07-19 00:02:41,852: INFO/MainProcess] Task task_build_conda_pack[build-1-conda-pack] received
conda-store-worker-1  | [2024-07-19 00:02:41,853: INFO/MainProcess] Task task_build_conda_docker[build-1-docker] received
conda-store-worker-1  | [2024-07-19 00:02:41,855: INFO/MainProcess] Task task_build_constructor_installer[build-1-constructor-installer] received
conda-store-worker-1  | [2024-07-19 00:02:41,855: INFO/ForkPoolWorker-4] Task task_build_conda_environment[build-1-environment] succeeded in 78.7562527419941s: None
conda-store-worker-1  | [2024-07-19 00:02:41,867: WARNING/ForkPoolWorker-4] /opt/conda-store-server/conda_store_server/_internal/build.py:415: UserWarning: Generating Docker images is currently not supported, see https://github.com/conda-incubator/conda-store/issues/666
conda-store-worker-1  |   warnings.warn(
conda-store-worker-1  | 
conda-store-worker-1  | [2024-07-19 00:02:41,868: INFO/ForkPoolWorker-4] Task task_build_conda_docker[build-1-docker] succeeded in 0.012042938004015014s: None
conda-store-worker-1  | [2024-07-19 00:02:41,899: WARNING/ForkPoolWorker-4] /opt/conda-store-server/conda_store_server/_internal/action/generate_constructor_installer.py:48: UserWarning: Installer generation requires constructor: https://github.com/conda/constructor
conda-store-worker-1  |   warnings.warn(
conda-store-worker-1  | 
conda-store-worker-1  | [2024-07-19 00:02:41,900: WARNING/ForkPoolWorker-4] [CondaStoreWorker] creating installer for conda environment=/var/lib/conda-store/filesystem/7ff0f78a-1721347282-1-python-flask-env took 0.018 [s]
conda-store-worker-1  | [2024-07-19 00:02:41,901: INFO/ForkPoolWorker-4] Task task_build_constructor_installer[build-1-constructor-installer] succeeded in 0.03257362500880845s: None
conda-store-worker-1  | [2024-07-19 00:02:43,334: INFO/ForkPoolWorker-2] Task task_build_conda_env_export[build-1-conda-env-export] succeeded in 1.4822059069992974s: None
conda-store-worker-1  | [2024-07-19 00:02:47,599: WARNING/ForkPoolWorker-3] [CondaStoreWorker] packaging archive of conda environment=/var/lib/conda-store/filesystem/7ff0f78a-1721347282-1-python-flask-env took 5.731 [s]
conda-store-worker-1  | [2024-07-19 00:02:47,604: INFO/ForkPoolWorker-3] Task task_build_conda_pack[build-1-conda-pack] succeeded in 5.751906952005811s: None
conda-store-worker-1  | [2024-07-19 00:02:47,605: INFO/MainProcess] Task task_update_storage_metrics[build-1] received
conda-store-worker-1  | [2024-07-19 00:02:47,628: INFO/ForkPoolWorker-2] Task task_update_storage_metrics[build-1] succeeded in 0.02287509001325816s: None
conda-store-server-1  | INFO:     127.0.0.1:38788 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     127.0.0.1:58982 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-worker-1  | [2024-07-19 00:03:01,985: INFO/ForkPoolWorker-5] packages to insert : 64960 
postgres-1            | 2024-07-19 00:03:01.989 UTC [81] ERROR:  duplicate key value violates unique constraint "_conda_package_uc"
postgres-1            | 2024-07-19 00:03:01.989 UTC [81] DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
postgres-1            | 2024-07-19 00:03:01.989 UTC [81] STATEMENT:  INSERT INTO conda_package (channel_id, license, name, version, summary) VALUES (2, 'None', '_libgcc_mutex', '0.1', 'Mutex for libgcc and libgcc-ng') RETURNING conda_package.id
conda-store-worker-1  | [2024-07-19 00:03:01,991: WARNING/ForkPoolWorker-5] (psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "_conda_package_uc"
conda-store-worker-1  | DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
conda-store-worker-1  | 
conda-store-worker-1  | [SQL: INSERT INTO conda_package (channel_id, license, name, version, summary) VALUES (%(channel_id)s, %(license)s, %(name)s, %(version)s, %(summary)s) RETURNING conda_package.id]
conda-store-worker-1  | [parameters: {'channel_id': 2, 'license': 'None', 'name': '_libgcc_mutex', 'version': '0.1', 'summary': 'Mutex for libgcc and libgcc-ng'}]
conda-store-worker-1  | (Background on this error at: https://sqlalche.me/e/14/gkpj)
conda-store-worker-1  | [2024-07-19 00:03:01,996: ERROR/ForkPoolWorker-5] Task task_update_conda_channel[b07f7b56-0f96-43fb-a27b-65afaf22b1c6] raised unexpected: IntegrityError('(psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "_conda_package_uc"\nDETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.\n')
conda-store-worker-1  | Traceback (most recent call last):
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
conda-store-worker-1  |     self.dialect.do_execute(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute
conda-store-worker-1  |     cursor.execute(statement, parameters)
conda-store-worker-1  | psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "_conda_package_uc"
conda-store-worker-1  | DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
conda-store-worker-1  | 
conda-store-worker-1  | 
conda-store-worker-1  | The above exception was the direct cause of the following exception:
conda-store-worker-1  | 
conda-store-worker-1  | Traceback (most recent call last):
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/celery/app/trace.py", line 453, in trace_task
conda-store-worker-1  |     R = retval = fun(*args, **kwargs)
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/celery/app/trace.py", line 736, in __protected_call__
conda-store-worker-1  |     return self.run(*args, **kwargs)
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/worker/tasks.py", line 188, in task_update_conda_channel
conda-store-worker-1  |     channel.update_packages(db, subdirs=settings.conda_platforms)
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/orm.py", line 569, in update_packages
conda-store-worker-1  |     raise e
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/orm.py", line 564, in update_packages
conda-store-worker-1  |     db.bulk_insert_mappings(CondaPackage, packages.values())
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3810, in bulk_insert_mappings
conda-store-worker-1  |     self._bulk_save_mappings(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3912, in _bulk_save_mappings
conda-store-worker-1  |     with util.safe_reraise():
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
conda-store-worker-1  |     compat.raise_(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
conda-store-worker-1  |     raise exception
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 3901, in _bulk_save_mappings
conda-store-worker-1  |     persistence._bulk_insert(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/orm/persistence.py", line 107, in _bulk_insert
conda-store-worker-1  |     _emit_insert_statements(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/orm/persistence.py", line 1097, in _emit_insert_statements
conda-store-worker-1  |     c = connection._execute_20(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1710, in _execute_20
conda-store-worker-1  |     return meth(self, args_10style, kwargs_10style, execution_options)
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection
conda-store-worker-1  |     return connection._execute_clauseelement(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1577, in _execute_clauseelement
conda-store-worker-1  |     ret = self._execute_context(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1953, in _execute_context
conda-store-worker-1  |     self._handle_dbapi_exception(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2134, in _handle_dbapi_exception
conda-store-worker-1  |     util.raise_(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
conda-store-worker-1  |     raise exception
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
conda-store-worker-1  |     self.dialect.do_execute(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute
conda-store-worker-1  |     cursor.execute(statement, parameters)
conda-store-worker-1  | sqlalchemy.exc.IntegrityError: (psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "_conda_package_uc"
conda-store-worker-1  | DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
conda-store-worker-1  | 
conda-store-worker-1  | [SQL: INSERT INTO conda_package (channel_id, license, name, version, summary) VALUES (%(channel_id)s, %(license)s, %(name)s, %(version)s, %(summary)s) RETURNING conda_package.id]
conda-store-worker-1  | [parameters: {'channel_id': 2, 'license': 'None', 'name': '_libgcc_mutex', 'version': '0.1', 'summary': 'Mutex for libgcc and libgcc-ng'}]
conda-store-worker-1  | (Background on this error at: https://sqlalche.me/e/14/gkpj)

Even with fresh containers, this error always appears. It doesn't seem to affect anything, but getting error messages immediately upon starting up isn't helpful.

Expected behavior

No error appears.

How to Reproduce the problem?

docker compose up --build. I'm running Linux 6.6.39-1-lts x86_64.

Here's the output of pip list 
Package                       Version
----------------------------- --------
accessible-pygments           0.0.5
aiohttp                       3.9.5
aiosignal                     1.3.1
alabaster                     0.7.16
alembic                       1.13.2
amqp                          5.2.0
anyio                         4.4.0
appdirs                       1.4.4
argon2-cffi                   23.1.0
argon2-cffi-bindings          21.2.0
asttokens                     2.4.1
async-timeout                 4.0.3
attrs                         23.2.0
Babel                         2.14.0
backports.tarfile             1.0.0
bcrypt                        4.1.3
beautifulsoup4                4.12.3
billiard                      4.2.0
black                         22.3.0
boltons                       24.0.0
boto3                         1.34.143
botocore                      1.34.143
Brotli                        1.1.0
CacheControl                  0.14.0
cachy                         0.3.0
cattrs                        23.2.3
celery                        5.3.6
certifi                       2024.7.4
cffi                          1.16.0
charset-normalizer            3.3.2
click                         8.1.7
click-default-group           1.2.4
click-didyoumean              0.3.1
click-plugins                 1.1.1
click-repl                    0.3.0
clikit                        0.6.2
colorama                      0.4.6
conda                         23.5.2
conda-docker                  0.1.2
conda_lock                    2.5.7
conda-pack                    0.8.0
conda-package-handling        2.3.0
conda_package_streaming       0.10.0
constructor                   3.8.0
crashtest                     0.4.1
cryptography                  42.0.8
dataclasses                   0.8
decorator                     5.1.1
distlib                       0.3.8
dnspython                     2.6.1
docker                        6.1.3
docstring-to-markdown         0.15
docutils                      0.17.1
editables                     0.5
email_validator               2.2.0
ensureconda                   1.4.4
exceptiongroup                1.2.0
executing                     2.0.1
fancycompleter                0.9.1
fastapi                       0.111.0
fastapi-cli                   0.0.4
filelock                      3.15.4
flake8                        7.1.0
flower                        2.0.1
frozenlist                    1.4.1
gitdb                         4.0.11
GitPython                     3.1.43
greenlet                      3.0.3
h11                           0.14.0
h2                            4.1.0
hatch                         1.12.0
hatchling                     1.25.0
hpack                         4.0.0
html5lib                      1.1
httpcore                      1.0.5
httpx                         0.27.0
humanize                      4.10.0
hyperframe                    6.0.1
hyperlink                     21.0.0
idna                          3.7
imagesize                     1.4.1
importlib_metadata            8.0.0
importlib_resources           6.4.0
iniconfig                     2.0.0
ipython                       8.26.0
itsdangerous                  2.2.0
jaraco.classes                3.4.0
jaraco.context                5.3.0
jaraco.functools              4.0.0
jedi                          0.19.1
jeepney                       0.8.0
Jinja2                        3.1.4
jmespath                      1.0.1
jsonpatch                     1.33
jsonpointer                   3.0.0
keyring                       25.2.1
kombu                         5.3.7
libmambapy                    1.5.1
linkify-it-py                 2.0.3
lsprotocol                    2023.0.1
Mako                          1.3.5
mamba                         1.5.1
markdown-it-py                2.2.0
MarkupSafe                    2.1.5
matplotlib-inline             0.1.7
mccabe                        0.7.0
mdit-py-plugins               0.4.1
mdurl                         0.1.2
memray                        1.13.3
minio                         7.2.7
more-itertools                10.3.0
msgpack                       1.0.8
multidict                     6.0.5
mypy                          1.10.1
mypy-extensions               1.0.0
myst-parser                   0.18.1
orjson                        3.10.6
packaging                     24.1
paramiko                      3.4.0
parso                         0.8.4
pastel                        0.2.1
pathspec                      0.12.1
pdbpp                         0.10.3
pexpect                       4.9.0
pillow                        10.4.0
pip                           24.0
pkginfo                       1.11.1
platformdirs                  4.2.2
playwright                    1.45.0
pluggy                        1.5.0
prometheus_client             0.20.0
prompt_toolkit                3.0.47
psycopg2                      2.9.9
ptyprocess                    0.7.0
pure-eval                     0.2.2
pycodestyle                   2.12.0
pycosat                       0.6.6
pycparser                     2.22
pycryptodome                  3.20.0
pydantic                      1.10.16
pydata-sphinx-theme           0.13.3
pyee                          11.1.0
pyflakes                      3.2.0
pygls                         1.3.1
Pygments                      2.18.0
PyJWT                         2.8.0
pylev                         1.4.0
PyMySQL                       1.1.0
PyNaCl                        1.5.0
pyOpenSSL                     24.0.0
pyrepl                        0.9.0
PySocks                       1.7.1
pytest                        8.2.2
pytest-base-url               2.1.0
pytest-celery                 0.0.0a1
pytest-memray                 1.6.0
pytest-mock                   3.14.0
pytest-playwright             0.5.1
python-dateutil               2.9.0
python-docker                 0.2.0
python-lsp-jsonrpc            1.1.2
python-lsp-server             1.11.0
python-multipart              0.0.9
python-slugify                8.0.4
pytz                          2024.1
PyYAML                        6.0.1
redis                         5.0.7
requests                      2.32.3
rich                          13.7.1
ruamel.yaml                   0.17.40
ruamel.yaml.clib              0.2.8
ruff                          0.5.1
ruff-lsp                      0.0.54
s3transfer                    0.10.2
SecretStorage                 3.3.3
setuptools                    70.2.0
shellingham                   1.5.4
six                           1.16.0
smmap                         5.0.0
sniffio                       1.3.1
snowballstemmer               2.2.0
soupsieve                     2.5
Sphinx                        4.5.0
sphinx-copybutton             0.5.2
sphinx-panels                 0.6.0
sphinxcontrib-applehelp       1.0.4
sphinxcontrib-devhelp         1.0.2
sphinxcontrib-htmlhelp        2.0.1
sphinxcontrib-jsmath          1.0.1
sphinxcontrib-qthelp          1.0.3
sphinxcontrib-serializinghtml 1.1.5
SQLAlchemy                    1.4.46
stack-data                    0.6.3
starlette                     0.37.2
text-unidecode                1.3
textual                       0.73.0
tomli                         2.0.1
tomli_w                       1.0.0
tomlkit                       0.13.0
toolz                         0.12.1
tornado                       6.4.1
tqdm                          4.66.4
traitlets                     5.14.3
trove-classifiers             2024.7.2
typed-ast                     1.5.5
typer                         0.12.3
typer-slim                    0.12.3
typing_extensions             4.12.2
tzdata                        2024.1
uc-micro-py                   1.0.3
ujson                         5.10.0
urllib3                       1.26.19
userpath                      1.7.0
uvicorn                       0.30.1
vine                          5.1.0
virtualenv                    20.26.3
wcwidth                       0.2.13
webencodings                  0.5.1
websocket-client              1.8.0
wheel                         0.43.0
wmctrl                        0.5
yarl                          1.9.4
zipp                          3.19.2
zstandard                     0.22.0

Here's the output of python -VV:

Python 3.10.0 | packaged by conda-forge | (default, Nov 20 2021, 02:24:10) [GCC 9.4.0]
@peytondmurray peytondmurray added the type: bug 🐛 Something isn't working label Jul 19, 2024
@peytondmurray peytondmurray added the needs: investigation 🔎 Someone in the team needs to look into this issue before scoping label Jul 23, 2024
@trallard
Copy link
Collaborator

Going by the trace it seems this originates within

conda-store/conda-store-server/conda_store_server/_internal/worker/tasks.py

Line 103 in 24e15a1

def task_update_storage_metrics(self):

but I am unsure why duplicated entries are being added (or try to) since this seems to be at configuration time

@soapy1
Copy link
Contributor

soapy1 commented Oct 15, 2024

I was looking into this issue some but was unable to reproduce it from a clean clone of the repo and running docker compose up --build. Thinking out loud for a bit here:

Digging into the error a bit more, I notice these lines in the debug output:

conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/worker/tasks.py", line 188, in task_update_conda_channel

The task_update_conda_channel is defined here. This should be looking at the repodata for each configured channel and inserting any new packages into the postgres db.

conda-store-worker-1  | [2024-07-19 00:03:01,985: INFO/ForkPoolWorker-5] packages to insert : 64960

This line I believe comes from the package updater. It's going to try to insert a bunch of packages, which makes sense as this is the first run and the database should be empty. Though, this seems like maybe a small amount if the main channel is included in your config.

conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/orm.py", line 569, in update_packages
conda-store-worker-1  |     raise e
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/orm.py", line 564, in update_packages
conda-store-worker-1  |     db.bulk_insert_mappings(CondaPackage, packages.values())

This part is the error coming from the orm package updater. There is this little piece of logic here looks like it should be stopping any situation where duplicates get inserted into the database. Looks like this in particular is failing.

@peytondmurray in order to continue debugging this problem can you share:

  • the conda_platform setting you have (if modified from the default)
  • the list of channels you have enabled (if modified from the default)
  • the full output log for conda-store-worker-1

@peytondmurray peytondmurray self-assigned this Oct 16, 2024
@soapy1 soapy1 self-assigned this Nov 5, 2024
@soapy1 soapy1 mentioned this issue Nov 7, 2024
Merged
3 tasks
@soapy1 soapy1 moved this from New 🚦 to In Progress 🏗 in conda-store 🐍 Nov 7, 2024
@soapy1 soapy1 moved this from In Progress 🏗 to In review 👀 in conda-store 🐍 Nov 7, 2024
@soapy1
Copy link
Contributor

soapy1 commented Nov 7, 2024

This is maybe fixed by #961. Would be sweet to try it out to confirm (I'm not able to reproduce this bug specifically). You may need to reset the data in your db?

@peytondmurray
Copy link
Contributor Author

Just tried this out after a docker compose down and docker compose up --build:

conda-store-worker-1  | [2024-11-07 20:01:48,196: INFO/ForkPoolWorker-4] handling subset at index 87120 (batch size 990)
conda-store-worker-1  | [2024-11-07 20:01:48,196: INFO/ForkPoolWorker-4] retrieve the parent packages for the subset 
conda-store-worker-1  | [2024-11-07 20:01:48,687: INFO/ForkPoolWorker-4] parent packages retrieved : 990 
conda-store-worker-1  | [2024-11-07 20:01:48,688: INFO/ForkPoolWorker-4] ready to bulk save
conda-store-worker-1  | [2024-11-07 20:01:48,688: INFO/ForkPoolWorker-4] handling subset at index 88110 (batch size 990)
conda-store-worker-1  | [2024-11-07 20:01:48,688: INFO/ForkPoolWorker-4] retrieve the parent packages for the subset 
conda-store-worker-1  | [2024-11-07 20:01:48,827: INFO/ForkPoolWorker-4] parent packages retrieved : 422 
conda-store-worker-1  | [2024-11-07 20:01:48,828: INFO/ForkPoolWorker-4] ready to bulk save
conda-store-server-1  | INFO:     127.0.0.1:45488 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-worker-1  | [2024-11-07 20:01:57,066: INFO/ForkPoolWorker-4] bulk saved
conda-store-worker-1  | [2024-11-07 20:01:57,067: INFO/ForkPoolWorker-4] DONE for architecture  : noarch
conda-store-worker-1  | [2024-11-07 20:01:57,067: INFO/ForkPoolWorker-4] architecture  : linux-64 
conda-store-server-1  | INFO:     127.0.0.1:41134 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     127.0.0.1:52990 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49976 - "GET / HTTP/1.1" 307 Temporary Redirect
conda-store-server-1  | INFO:     172.19.0.1:49976 - "GET /conda-store/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49976 - "GET /conda-store/static/conda-store-ui/main.js HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49992 - "GET /conda-store/static/conda-store-ui/main.css HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49976 - "GET /conda-store/api/v1/permission/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49992 - "GET /conda-store/api/v1/namespace/?page=1&size=100 HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49976 - "GET /conda-store/api/v1/permission/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     172.19.0.1:49976 - "GET /conda-store/api/v1/environment/?page=1&size=100&search= HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     127.0.0.1:32896 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-server-1  | INFO:     127.0.0.1:50324 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-worker-1  | [2024-11-07 20:02:43,061: WARNING/ForkPoolWorker-5] [CondaStoreWorker] building conda_prefix=/var/lib/conda-store/filesystem/c3457167-1731009576-1-python-flask-env took 185.150 [s]
conda-store-worker-1  | [2024-11-07 20:02:44,662: INFO/MainProcess] Task task_build_conda_env_export[build-1-conda-env-export] received
conda-store-worker-1  | [2024-11-07 20:02:44,664: INFO/MainProcess] Task task_build_conda_pack[build-1-conda-pack] received
conda-store-worker-1  | [2024-11-07 20:02:44,666: INFO/MainProcess] Task task_build_conda_docker[build-1-docker] received
conda-store-worker-1  | [2024-11-07 20:02:44,668: INFO/ForkPoolWorker-5] Task task_build_conda_environment[build-1-environment] succeeded in 186.81190652299998s: None
conda-store-worker-1  | [2024-11-07 20:02:44,668: INFO/MainProcess] Task task_build_constructor_installer[build-1-constructor-installer] received
conda-store-server-1  | INFO:     127.0.0.1:54984 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-worker-1  | [2024-11-07 20:02:44,689: WARNING/ForkPoolWorker-5] /opt/conda-store-server/conda_store_server/_internal/worker/build.py:423: UserWarning: Generating Docker images is currently not supported, see https://github.com/conda-incubator/conda-store/issues/666
conda-store-worker-1  |   warnings.warn(
conda-store-worker-1  | 
conda-store-worker-1  | [2024-11-07 20:02:44,691: INFO/ForkPoolWorker-5] Task task_build_conda_docker[build-1-docker] succeeded in 0.02112762299998394s: None
conda-store-worker-1  | [2024-11-07 20:02:44,780: ERROR/ForkPoolWorker-5] Task task_build_constructor_installer[build-1-constructor-installer] raised unexpected: CalledProcessError(1, ['python', '-m', 'constructor', '--help'])
conda-store-worker-1  | Traceback (most recent call last):
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/celery/app/trace.py", line 453, in trace_task
conda-store-worker-1  |     R = retval = fun(*args, **kwargs)
conda-store-worker-1  |                  ^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/celery/app/trace.py", line 736, in __protected_call__
conda-store-worker-1  |     return self.run(*args, **kwargs)
conda-store-worker-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/worker/tasks.py", line 257, in task_build_constructor_installer
conda-store-worker-1  |     build_constructor_installer(db, conda_store, build)
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/worker/build.py", line 517, in build_constructor_installer
conda-store-worker-1  |     context = action.action_generate_constructor_installer(
conda-store-worker-1  |               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/action/base.py", line 38, in wrapper
conda-store-worker-1  |     action_context.result = f(action_context, *args, **kwargs)
conda-store-worker-1  |                             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/action/generate_constructor_installer.py", line 51, in action_generate_constructor_installer
conda-store-worker-1  |     logged_command(context, command)
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/action/utils.py", line 9, in logged_command
conda-store-worker-1  |     context.run_command(command, **kwargs)
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/action/base.py", line 87, in run_command
conda-store-worker-1  |     raise subprocess.CalledProcessError(p.returncode, p.args)
conda-store-worker-1  | conda_lock._vendor.poetry.utils._compat.CalledProcessError: Command '['python', '-m', 'constructor', '--help']' returned non-zero exit status 1.
conda-store-worker-1  | [2024-11-07 20:02:46,078: INFO/ForkPoolWorker-2] Task task_build_conda_env_export[build-1-conda-env-export] succeeded in 1.4153395399999908s: None
conda-store-worker-1  | [2024-11-07 20:02:54,339: WARNING/ForkPoolWorker-3] [CondaStoreWorker] packaging archive of conda environment=/var/lib/conda-store/filesystem/c3457167-1731009576-1-python-flask-env took 9.570 [s]
conda-store-worker-1  | [2024-11-07 20:02:54,343: ERROR/ForkPoolWorker-3] Chord 'b1512bde-2cbb-4abe-90ab-1afe88abc90f' raised: ChordError("Dependency build-1-constructor-installer raised CalledProcessError(1, ['python', '-m', 'constructor', '--help'])")
conda-store-worker-1  | Traceback (most recent call last):
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/celery/backends/redis.py", line 528, in on_chord_part_return
conda-store-worker-1  |     resl = [unpack(tup, decode) for tup in resl]
conda-store-worker-1  |             ^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/celery/backends/redis.py", line 434, in _unpack_chord_result
conda-store-worker-1  |     raise ChordError(f'Dependency {tid} raised {retval!r}')
conda-store-worker-1  | celery.exceptions.ChordError: Dependency build-1-constructor-installer raised CalledProcessError(1, ['python', '-m', 'constructor', '--help'])
conda-store-worker-1  | [2024-11-07 20:02:54,346: INFO/ForkPoolWorker-3] Task task_build_conda_pack[build-1-conda-pack] succeeded in 9.67913596599999s: None
conda-store-server-1  | INFO:     127.0.0.1:34046 - "GET /conda-store/api/v1/ HTTP/1.1" 200 OK
conda-store-worker-1  | [2024-11-07 20:02:58,126: INFO/ForkPoolWorker-4] packages to insert : 64966 
postgres-1            | 2024-11-07 20:02:58.131 UTC [81] ERROR:  duplicate key value violates unique constraint "_conda_package_uc"
postgres-1            | 2024-11-07 20:02:58.131 UTC [81] DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
postgres-1            | 2024-11-07 20:02:58.131 UTC [81] STATEMENT:  INSERT INTO conda_package (channel_id, license, name, version, summary) VALUES (2, 'None', '_libgcc_mutex', '0.1', 'Mutex for libgcc and libgcc-ng') RETURNING conda_package.id
conda-store-worker-1  | [2024-11-07 20:02:58,132: WARNING/ForkPoolWorker-4] (psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "_conda_package_uc"
conda-store-worker-1  | DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
conda-store-worker-1  | 
conda-store-worker-1  | [SQL: INSERT INTO conda_package (channel_id, license, name, version, summary) VALUES (%(channel_id)s, %(license)s, %(name)s, %(version)s, %(summary)s) RETURNING conda_package.id]
conda-store-worker-1  | [parameters: {'channel_id': 2, 'license': 'None', 'name': '_libgcc_mutex', 'version': '0.1', 'summary': 'Mutex for libgcc and libgcc-ng'}]
conda-store-worker-1  | (Background on this error at: https://sqlalche.me/e/14/gkpj)
conda-store-worker-1  | [2024-11-07 20:02:58,147: ERROR/ForkPoolWorker-4] Task task_update_conda_channel[e4da5a3c-e4fb-4b4d-9579-9b4d14f9aa65] raised unexpected: IntegrityError('(psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "_conda_package_uc"\nDETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.\n')
conda-store-worker-1  | Traceback (most recent call last):
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
conda-store-worker-1  |     self.dialect.do_execute(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute
conda-store-worker-1  |     cursor.execute(statement, parameters)
conda-store-worker-1  | psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "_conda_package_uc"
conda-store-worker-1  | DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
conda-store-worker-1  | 
conda-store-worker-1  | 
conda-store-worker-1  | The above exception was the direct cause of the following exception:
conda-store-worker-1  | 
conda-store-worker-1  | Traceback (most recent call last):
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/celery/app/trace.py", line 453, in trace_task
conda-store-worker-1  |     R = retval = fun(*args, **kwargs)
conda-store-worker-1  |                  ^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/celery/app/trace.py", line 736, in __protected_call__
conda-store-worker-1  |     return self.run(*args, **kwargs)
conda-store-worker-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/worker/tasks.py", line 191, in task_update_conda_channel
conda-store-worker-1  |     channel.update_packages(db, subdirs=settings.conda_platforms)
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/orm.py", line 568, in update_packages
conda-store-worker-1  |     raise e
conda-store-worker-1  |   File "/opt/conda-store-server/conda_store_server/_internal/orm.py", line 563, in update_packages
conda-store-worker-1  |     db.bulk_insert_mappings(CondaPackage, packages.values())
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/orm/session.py", line 3810, in bulk_insert_mappings
conda-store-worker-1  |     self._bulk_save_mappings(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/orm/session.py", line 3912, in _bulk_save_mappings
conda-store-worker-1  |     with util.safe_reraise():
conda-store-worker-1  |          ^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
conda-store-worker-1  |     compat.raise_(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
conda-store-worker-1  |     raise exception
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/orm/session.py", line 3901, in _bulk_save_mappings
conda-store-worker-1  |     persistence._bulk_insert(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py", line 107, in _bulk_insert
conda-store-worker-1  |     _emit_insert_statements(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py", line 1097, in _emit_insert_statements
conda-store-worker-1  |     c = connection._execute_20(
conda-store-worker-1  |         ^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1710, in _execute_20
conda-store-worker-1  |     return meth(self, args_10style, kwargs_10style, execution_options)
conda-store-worker-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/sql/elements.py", line 334, in _execute_on_connection
conda-store-worker-1  |     return connection._execute_clauseelement(
conda-store-worker-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1577, in _execute_clauseelement
conda-store-worker-1  |     ret = self._execute_context(
conda-store-worker-1  |           ^^^^^^^^^^^^^^^^^^^^^^
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1953, in _execute_context
conda-store-worker-1  |     self._handle_dbapi_exception(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 2134, in _handle_dbapi_exception
conda-store-worker-1  |     util.raise_(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
conda-store-worker-1  |     raise exception
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1910, in _execute_context
conda-store-worker-1  |     self.dialect.do_execute(
conda-store-worker-1  |   File "/opt/conda/envs/conda-store-server/lib/python3.12/site-packages/sqlalchemy/engine/default.py", line 736, in do_execute
conda-store-worker-1  |     cursor.execute(statement, parameters)
conda-store-worker-1  | sqlalchemy.exc.IntegrityError: (psycopg2.errors.UniqueViolation) duplicate key value violates unique constraint "_conda_package_uc"
conda-store-worker-1  | DETAIL:  Key (channel_id, name, version)=(2, _libgcc_mutex, 0.1) already exists.
conda-store-worker-1  | 
conda-store-worker-1  | [SQL: INSERT INTO conda_package (channel_id, license, name, version, summary) VALUES (%(channel_id)s, %(license)s, %(name)s, %(version)s, %(summary)s) RETURNING conda_package.id]
conda-store-worker-1  | [parameters: {'channel_id': 2, 'license': 'None', 'name': '_libgcc_mutex', 'version': '0.1', 'summary': 'Mutex for libgcc and libgcc-ng'}]
conda-store-worker-1  | (Background on this error at: https://sqlalche.me/e/14/gkpj)

@peytondmurray
Copy link
Contributor Author

peytondmurray commented Nov 7, 2024 •
edited
Loading

Looks like it's still trying to insert CondaPackage rows with duplicate keys 🤔

@soapy1 soapy1 moved this from In review 👀 to In Progress 🏗 in conda-store 🐍 Nov 11, 2024
@soapy1
Copy link
Contributor

soapy1 commented Nov 11, 2024 •
edited
Loading

Sweet, thanks for the additional log output. I'm now able to consistently reproduce the issue by following the steps:

  1. reset the database
  2. bring up conda-store server/worker
  3. while the task_update_conda_channel task is running (this happens when the worker is started) log into conda-store and build an environment

So, this issue arises because part of the environment build process is to execute the action_add_conda_prefix_package. This action tries to insert all the packages from the environment into the db. If these packages overlap with any of the packages inserted by task_update_conda_channel (which is common on a first run of the task) then we get the integrity error.

There are a couple options to resolve this:

  1. Don't run the task_update_conda_channel task. I don't think there needs to be an always updated set of packages in the database. Like, I think the database only needs to have entries for the packages that exist in environments.

  2. instead of bulk inserting packages in the task_update_conda_channel task, upsert instead.

I think (2) is the better option.

edit it looks like there are some endpoints for listing packages. So, removing the functionality described in option (1) will change some user facing behaviour. This is probably not the option we want to go with.

@peytondmurray
Copy link
Contributor Author

Yep, seems like option 2 is the way to go here, though we should be careful about the impact on performance of moving away from bulk_insert_mappings, I'm guessing the upsert operation is more costly here.

@soapy1 soapy1 linked a pull request Nov 11, 2024 that will close this issue
Draft
3 tasks
@soapy1 soapy1 moved this from In Progress 🏗 to TODO 📬 in conda-store 🐍 Nov 21, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@soapy1 soapy1

@peytondmurray peytondmurray

Labels
needs: investigation 🔎 Someone in the team needs to look into this issue before scoping type: bug 🐛 Something isn't working
Projects
conda-store 🐍
Status: TODO 📬
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Retry updating conda packages soapy1/conda-store
3 participants
@soapy1 @peytondmurray @trallard