canonical / charmcraft

Collaborate, build and publish charmed operators for Kubernetes, Linux and Windows.
Apache License 2.0
66 stars 69 forks source link

`charmcraft` installs newer version in LXC container & doesn't respect pinned snap revision #1202

Closed carlcsaposs-canonical closed 1 year ago

carlcsaposs-canonical commented 1 year ago

Bug Description

Because of #1179, our team is currently using charmcraft 2.3.0 by installing the snap with --revision=1349

However, inside the LXC container charmcraft is installed as 2.3.1 and we're running into the same issue as #1179

Expected behavior

charmcraft has the same version in the LXC container as charmcraft on the host machine

To Reproduce

Unable to reproduce so far

Examples: https://github.com/canonical/mysql-operator/actions/runs/5745497262/job/15573643405 https://github.com/canonical/mysql-operator/actions/runs/5751410879/job/15590220679

Environment

Ubuntu 22.04 LTS

charmcraft.yaml

# Copyright 2022 Canonical Ltd.
# See LICENSE file for licensing details.

type: charm
bases:
  # Whenever "bases" is changed:
  # - Update tests/integration/conftest.py::pytest_configure()
  # - Update .github/workflow/ci.yaml integration-test matrix
  - build-on:
      - name: "ubuntu"
        channel: "22.04"
    run-on:
      - name: "ubuntu"
        channel: "22.04"
parts:
  charm:
    override-pull: |
      craftctl default
      if [[ ! -f requirements.txt ]]
      then
          echo 'ERROR: Use "tox run -e build" instead of calling "charmcraft pack" directly' >&2
          exit 1
      fi
    build-packages:
      - libffi-dev
      - libssl-dev
      - pkg-config
      - rustc
      - cargo

Relevant log output

2023-08-03 13:36:43.270 Starting charmcraft version 2.3.0
2023-08-03 13:36:43.275 System details: OSPlatform(system='ubuntu', release='22.04', machine='x86_64'); Environment: None
2023-08-03 13:36:43.275 Packing the charm.
2023-08-03 13:36:43.276 Reading '/home/runner/work/mysql-operator/mysql-operator/metadata.yaml'
2023-08-03 13:36:43.282 Validating metadata format
2023-08-03 13:36:43.507 Executing on host: lxc --project default profile show local:default
2023-08-03 13:36:43.569 Building for 'bases[0]' as host matches 'build-on[0]'.
2023-08-03 13:36:43.569 Building for 'bases[0][0]'.
2023-08-03 13:36:43.569 Launching environment to pack for base name='ubuntu' channel='22.04' architectures=['amd64'] (may take a while the first time but it's reusable)
2023-08-03 13:36:43.570 Using hostname 'charmcraft-mysql-344327-0-0-amd64'
2023-08-03 13:36:43.570 Executing on host: lxc remote list --format=yaml
2023-08-03 13:36:43.633 Executing on host: lxc remote add craft-com.ubuntu.cloud-buildd https://cloud-images.ubuntu.com/buildd/releases --protocol=simplestreams
2023-08-03 13:36:43.693 Remote 'craft-com.ubuntu.cloud-buildd' was successfully added.
2023-08-03 13:36:43.693 Executing on host: lxc project list local: --format=yaml
2023-08-03 13:36:43.758 Set LXD instance name to 'charmcraft-mysql-344327-0-0-amd64'
2023-08-03 13:36:43.758 Checking for instance 'charmcraft-mysql-344327-0-0-amd64' in project 'charmcraft' in remote 'local'
2023-08-03 13:36:43.758 Executing on host: lxc --project charmcraft list local: --format=yaml
2023-08-03 13:36:43.846 Executing on host: lxc --project charmcraft config get local:charmcraft-mysql-344327-0-0-amd64 raw.idmap
2023-08-03 13:36:43.908 Executing on host: lxc --project charmcraft list local: --format=yaml
2023-08-03 13:36:43.997 Instance exists and is not running. Starting instance.
2023-08-03 13:36:43.998 Executing on host: lxc --project charmcraft start local:charmcraft-mysql-344327-0-0-amd64
2023-08-03 13:36:44.570 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 test -f /etc/craft-instance.conf
2023-08-03 13:36:44.715 Executing on host: lxc --project charmcraft file pull local:charmcraft-mysql-344327-0-0-amd64/etc/craft-instance.conf /home/runner/tmpiw1l9ivn.tmp-craft/tmp6hu1pikw
2023-08-03 13:36:44.844 Instance has already been setup.
2023-08-03 13:36:44.844 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 cat /etc/os-release
2023-08-03 13:36:44.979 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 test -f /etc/craft-instance.conf
2023-08-03 13:36:45.109 Executing on host: lxc --project charmcraft file pull local:charmcraft-mysql-344327-0-0-amd64/etc/craft-instance.conf /home/runner/tmp0vsjqep3.tmp-craft/tmpw5fwr1ro
2023-08-03 13:36:45.206 Instance is compatible with compatibility tag 'charmcraft-buildd-base-v1.0'
2023-08-03 13:36:45.207 Waiting for environment to be ready...
2023-08-03 13:36:45.207 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:45.331 systemctl is-system-running status: starting
2023-08-03 13:36:45.582 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:45.730 systemctl is-system-running status: starting
2023-08-03 13:36:45.981 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:46.131 systemctl is-system-running status: starting
2023-08-03 13:36:46.382 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:46.519 systemctl is-system-running status: starting
2023-08-03 13:36:46.770 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:46.877 systemctl is-system-running status: starting
2023-08-03 13:36:47.128 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:47.257 systemctl is-system-running status: starting
2023-08-03 13:36:47.508 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:47.604 systemctl is-system-running status: starting
2023-08-03 13:36:47.855 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:47.969 systemctl is-system-running status: starting
2023-08-03 13:36:48.220 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:48.327 systemctl is-system-running status: starting
2023-08-03 13:36:48.578 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 systemctl is-system-running
2023-08-03 13:36:48.675 Waiting for networking to be ready...
2023-08-03 13:36:48.675 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 getent hosts snapcraft.io
2023-08-03 13:36:48.822 Holding refreshes for snaps.
2023-08-03 13:36:48.822 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 snap set system refresh.hold=2023-08-04T13:36:48.822068Z
2023-08-03 13:36:49.970 Waiting for pending snap refreshes to complete.
2023-08-03 13:36:49.970 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 snap watch '--last=auto-refresh?'
2023-08-03 13:36:56.355 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 snap unset system proxy.http
2023-08-03 13:36:56.508 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 snap unset system proxy.https
2023-08-03 13:36:56.740 Installing snap 'charmcraft' with channel=None and classic=True
2023-08-03 13:36:56.740 Installing snap 'charmcraft' from host (classic=True)
2023-08-03 13:36:56.749 Executing in container: lxc --project charmcraft exec local:charmcraft-mysql-344327-0-0-amd64 -- env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin CHARMCRAFT_MANAGED_MODE=1 test -f /etc/craft-instance.conf
2023-08-03 13:36:56.840 Executing on host: lxc --project charmcraft file pull local:charmcraft-mysql-344327-0-0-amd64/etc/craft-instance.conf /home/runner/tmpmvtcomhd.tmp-craft/tmpwclzfdqo
2023-08-03 13:36:56.912 Revisions found: host='1349', target='1349'
2023-08-03 13:36:56.912 Skipping snap injection: target is already up-to-date with revision on host
2023-08-03 13:36:56.912 Mounting directory inside the instance
2023-08-03 13:36:56.912 Executing on host: lxc --project charmcraft config device show local:charmcraft-mysql-344327-0-0-amd64
2023-08-03 13:36:56.979 Executing on host: lxc --project charmcraft config device add local:charmcraft-mysql-344327-0-0-amd64 disk-/root/project disk source=/home/runner/work/mysql-operator/mysql-operator path=/root/project
2023-08-03 13:36:57.074 Packing the charm
2023-08-03 13:36:57.074 Running ['charmcraft', 'pack', '--bases-index', '0', '--verbosity=brief']
2023-08-03 13:36:57.074 Emitter: Pausing control of the terminal
2023-08-03 13:37:09.792 Emitter: Resuming control of the terminal
2023-08-03 13:37:09.969 Logs captured from managed instance:
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.511 Starting charmcraft version 2.3.1
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.517 System details: OSPlatform(system='ubuntu', release='22.04', machine='x86_64'); Environment: CHARMCRAFT_MANAGED_MODE='1'
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.517 Packing the charm.
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.517 Reading '/root/project/metadata.yaml'
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.523 Validating metadata format
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.532 Building for 'bases[0]' as host matches 'build-on[0]'.
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.532 Building for 'bases[0][0]'.
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.532 Building charm in '/root'
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.657 Parts definition: {'charm': {'source': '/root/project', 'charm-entrypoint': 'src/charm.py', 'charm-binary-python-packages': [], 'charm-python-packages': [], 'charm-requirements': ['requirements.txt'], 'override-pull': 'craftctl default\nif [[ ! -f requirements.txt ]]\nthen\n    echo \'ERROR: Use "tox run -e build" instead of calling "charmcraft pack" directly\' >&2\n    exit 1\nfi\n', 'build-packages': ['libffi-dev', 'libssl-dev', 'pkg-config', 'rustc', 'cargo'], 'plugin': 'charm', 'prime': ['src', 'venv', 'metadata.yaml', 'dispatch', 'hooks', 'config.yaml', 'actions.yaml', 'lib', 'LICENSE', 'icon.svg', 'README.md']}}
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.657 is_snap: True, SNAP_NAME set to charmcraft
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.658 Setting target machine to x86_64
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.658 load state file: /root/parts/charm/state/pull
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.666 load state file: /root/parts/charm/state/build
2023-08-03 13:37:09.969 :: 2023-08-03 13:36:59.688 load state file: /root/parts/charm/state/stage
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.353 load state file: /root/parts/charm/state/prime
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.970 Executing parts lifecycle in '/root/project'
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.971 process charm:Step.PULL
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.971 check if Part('charm'):Step.PULL is dirty
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.971 check if Part('charm'):Step.PULL is outdated
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.971 ignore patterns: ['*.charm']
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.972 updated files: {'icon.svg', 'CONTRIBUTING.md', 'actions.yaml', 'metadata.yaml', 'charmcraft.yaml', 'requirements-last-build.txt', 'config.yaml', 'poetry.lock', 'LICENSE', 'requirements.txt', 'tox.ini', '.gitignore', '.jujuignore', 'README.md', 'pyproject.toml'}
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.972 updated directories: {'.github', 'docs', '.tox', '.git', 'src', 'lib', 'tests'}
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.972 charm:Step.PULL is outdated
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.972 update step charm:Step.PULL
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.972 add action charm:Step.PULL(ActionType.UPDATE)
2023-08-03 13:37:09.969 :: 2023-08-03 13:37:00.972 process charm:Step.BUILD
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.972 check if Part('charm'):Step.BUILD is dirty
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.987 check if Part('charm'):Step.BUILD is outdated
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.987 charm:Step.BUILD is outdated
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.987 update step charm:Step.BUILD
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.987 add action charm:Step.BUILD(ActionType.UPDATE)
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.987 process charm:Step.STAGE
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.987 check if Part('charm'):Step.STAGE is dirty
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.988 check if Part('charm'):Step.STAGE is outdated
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.988 charm:Step.STAGE is outdated
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.988 rerun step charm:Step.STAGE
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.988 add action charm:Step.STAGE(ActionType.RERUN)
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.989 process charm:Step.PRIME
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.989 add action charm:Step.PRIME(ActionType.RUN)
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.989 Parts actions: [Action(part_name='charm', step=Step.PULL, action_type=ActionType.UPDATE, reason='source changed', project_vars=None, properties=ActionProperties(changed_files=['.gitignore', '.jujuignore', 'CONTRIBUTING.md', 'LICENSE', 'README.md', 'actions.yaml', 'charmcraft.yaml', 'config.yaml', 'icon.svg', 'metadata.yaml', 'poetry.lock', 'pyproject.toml', 'requirements-last-build.txt', 'requirements.txt', 'tox.ini'], changed_dirs=['.git', '.github', '.tox', 'docs', 'lib', 'src', 'tests'])), Action(part_name='charm', step=Step.BUILD, action_type=ActionType.UPDATE, reason="'PULL' step changed", project_vars=None, properties=ActionProperties(changed_files=['.gitignore', '.jujuignore', 'CONTRIBUTING.md', 'LICENSE', 'README.md', 'actions.yaml', 'charmcraft.yaml', 'config.yaml', 'icon.svg', 'metadata.yaml', 'poetry.lock', 'pyproject.toml', 'requirements-last-build.txt', 'requirements.txt', 'tox.ini'], changed_dirs=['.git', '.github', '.tox', 'docs', 'lib', 'src', 'tests'])), Action(part_name='charm', step=Step.STAGE, action_type=ActionType.RERUN, reason="'BUILD' step changed", project_vars=None, properties=ActionProperties(changed_files=None, changed_dirs=None)), Action(part_name='charm', step=Step.PRIME, action_type=ActionType.RUN, reason=None, project_vars=None, properties=ActionProperties(changed_files=None, changed_dirs=None))]
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.989 ignore patterns: ['*.charm']
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.989 part build packages: ['libffi-dev', 'libssl-dev', 'pkg-config', 'rustc', 'cargo']
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.990 plugin build packages: {'python3-pip', 'python3-dev', 'python3-wheel', 'python3-setuptools', 'python3-venv'}
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:00.990 Requested build-packages: ['cargo', 'libffi-dev', 'libssl-dev', 'pkg-config', 'python3-dev', 'python3-pip', 'python3-setuptools', 'python3-venv', 'python3-wheel', 'rustc']
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.558 Marking libssl-dev (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.558 package: libssl-dev
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.567 Marking python3-pip (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.567 package: python3-pip
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.573 Marking pkg-config (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.573 package: pkg-config
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.578 Marking python3-dev (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.579 package: python3-dev
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.584 Marking python3-wheel (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.584 package: python3-wheel
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.589 Marking rustc (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.589 package: rustc
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.595 Marking python3-setuptools (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.595 package: python3-setuptools
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.600 Marking python3-venv (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.600 package: python3-venv
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.606 Marking cargo (and its dependencies) to be fetched
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.606 package: cargo
2023-08-03 13:37:09.970 :: 2023-08-03 13:37:01.611 Marking libffi-dev (and its dependencies) to be fetched
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.611 package: libffi-dev
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.639 Requested build-packages already installed: ['cargo', 'libffi-dev', 'libssl-dev', 'pkg-config', 'python3-dev', 'python3-pip', 'python3-setuptools', 'python3-venv', 'python3-wheel', 'rustc']
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.915 verify plugin environment for part 'charm'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.916 Running step PULL for part 'charm'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.916 Execute action
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.917 execute action charm:Action(part_name='charm', step=Step.PULL, action_type=ActionType.UPDATE, reason='source changed', project_vars=None, properties=ActionProperties(changed_files=['.gitignore', '.jujuignore', 'CONTRIBUTING.md', 'LICENSE', 'README.md', 'actions.yaml', 'charmcraft.yaml', 'config.yaml', 'icon.svg', 'metadata.yaml', 'poetry.lock', 'pyproject.toml', 'requirements-last-build.txt', 'requirements.txt', 'tox.ini'], changed_dirs=['.git', '.github', '.tox', 'docs', 'lib', 'src', 'tests']))
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:01.923 :: + craftctl default
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.577 :: + [[ ! -f requirements.txt ]]
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.695 load state file: /root/parts/charm/state/pull
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.710 Running step BUILD for part 'charm'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.710 Execute action
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.711 execute action charm:Action(part_name='charm', step=Step.BUILD, action_type=ActionType.UPDATE, reason="'PULL' step changed", project_vars=None, properties=ActionProperties(changed_files=['.gitignore', '.jujuignore', 'CONTRIBUTING.md', 'LICENSE', 'README.md', 'actions.yaml', 'charmcraft.yaml', 'config.yaml', 'icon.svg', 'metadata.yaml', 'poetry.lock', 'pyproject.toml', 'requirements-last-build.txt', 'requirements.txt', 'tox.ini'], changed_dirs=['.git', '.github', '.tox', 'docs', 'lib', 'src', 'tests']))
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.711 ignore patterns: []
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.712 updated files: {'icon.svg', 'CONTRIBUTING.md', 'actions.yaml', 'metadata.yaml', 'charmcraft.yaml', 'requirements-last-build.txt', 'config.yaml', 'poetry.lock', 'LICENSE', 'requirements.txt', 'tox.ini', '.gitignore', '.jujuignore', 'README.md', 'pyproject.toml'}
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:03.712 updated directories: {'.github', 'docs', '.tox', '.git', 'src', 'lib', 'tests'}
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:04.182 remove directory /root/parts/charm/install
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:04.262 load state file: /root/parts/charm/state/pull
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:04.272 Executing PosixPath('/root/parts/charm/run/build.sh')
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:04.277 :: + env -i LANG=C.UTF-8 LC_ALL=C.UTF-8 PATH=/snap/charmcraft/1429/libexec/charmcraft:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin SNAP=/snap/charmcraft/1429 SNAP_ARCH=amd64 SNAP_NAME=charmcraft SNAP_VERSION=2.3.1 /snap/charmcraft/1429/bin/python3 -u -I /snap/charmcraft/1429/lib/charmcraft/charm_builder.py --builddir /root/parts/charm/build --installdir /root/parts/charm/install --entrypoint /root/parts/charm/build/src/charm.py -r requirements.txt
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.257 :: Starting charm builder
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.257 :: Translated .jujuignore 2 '.git' => '.*/\\.git\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.257 :: Translated .jujuignore 3 '.svn' => '.*/\\.svn\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.257 :: Translated .jujuignore 4 '.hg' => '.*/\\.hg\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.257 :: Translated .jujuignore 5 '.bzr' => '.*/\\.bzr\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 6 '.tox' => '.*/\\.tox\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 8 '/build/' => '/build\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 9 '/revision' => '/revision\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 10 '/venv' => '/venv\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 12 '.jujuignore' => '.*/\\.jujuignore\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 1 '/venv\n' => '/venv\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 2 '*.py[cod]\n' => '.*/[^/]*\\.py[cod]\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 3 '*.charm\n' => '.*/[^/]*\\.charm\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 4 '.tox/\n' => '.*/\\.tox\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.258 :: Translated .jujuignore 1 '/staging-venv' => '/staging\\-venv\\Z'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.367 :: Collected charmlib dependencies: {'cosl', 'pydantic<2', 'ops>=2.0.0'}
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.367 :: Building charm in '/root/parts/charm/install'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.367 :: Linking in generic paths
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.368 :: Ignoring directory because of rules: '.git'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.368 :: Ignoring directory because of rules: 'staging-venv'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.368 :: Ignoring directory because of rules: '.tox'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.368 :: Ignoring file because of rules: '.jujuignore'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Creating the dispatch mechanism
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Creating the 'upgrade-charm' hook script pointing to dispatch
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Creating the 'install' hook script pointing to dispatch
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Creating the 'start' hook script pointing to dispatch
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Handling dependencies
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Current dependencies hash: 'bbf27888b17954e8b8a2d50d2a33e1e7a6b027d6'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Previous dependencies hash: 'a7906a96ab8f9d22f321dfba91795f2be8a85ebb'
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Installing dependencies
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:05.375 :: Running external command ['python3', '-m', 'venv', '/root/parts/charm/build/staging-venv']
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:07.241 :: Running external command ['/root/parts/charm/build/staging-venv/bin/pip3', '--version']
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:07.561 ::    :: pip 22.0.2 from /root/parts/charm/build/staging-venv/lib/python3.10/site-packages/pip (python 3.10)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:07.604 :: Running external command ['/root/parts/charm/build/staging-venv/bin/pip3', 'install', '--upgrade', '--no-binary', ':all:', '--requirement=requirements.txt', 'cosl', 'pydantic<2', 'ops>=2.0.0']
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:08.083 ::    :: Requirement already satisfied: cosl in ./staging-venv/lib/python3.10/site-packages (0.0.5)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:08.225 ::    :: Requirement already satisfied: pydantic<2 in ./staging-venv/lib/python3.10/site-packages (1.10.12)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:08.344 ::    :: Requirement already satisfied: ops>=2.0.0 in ./staging-venv/lib/python3.10/site-packages (2.5.0)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:08.367 ::    :: Requirement already satisfied: attrs==23.1.0 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 1)) (23.1.0)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:08.387 ::    :: Requirement already satisfied: boto3==1.28.15 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 4)) (1.28.15)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:08.739 ::    :: Requirement already satisfied: botocore==1.31.15 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 7)) (1.31.15)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.134 ::    :: Requirement already satisfied: cffi==1.15.1 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 10)) (1.15.1)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.269 ::    :: Requirement already satisfied: cryptography==41.0.2 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 78)) (41.0.2)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.435 ::    :: Requirement already satisfied: jmespath==1.0.1 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 102)) (1.0.1)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.453 ::    :: Requirement already satisfied: jsonschema-specifications==2023.7.1 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 105)) (2023.7.1)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.471 ::    :: Requirement already satisfied: jsonschema==4.18.4 in ./staging-venv/lib/python3.10/site-packages (from -r requirements.txt (line 108)) (4.18.4)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.509 ::    :: Collecting ops>=2.0.0
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.509 ::    :: ERROR: In --require-hashes mode, all requirements must have their versions pinned with ==. These do not:
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.509 ::    ::     ops>=2.0.0 from https://files.pythonhosted.org/packages/9e/44/26e661d17a483af287dcac85da4a8614fa10921474607b7af6c4ea04183e/ops-2.4.1.tar.gz#sha256=b5762bea03049ec150c6266833925d0bb36237b26b006ca878e74e24d162f981
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.640 :: Traceback (most recent call last):
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.640 ::   File "/snap/charmcraft/1429/lib/charmcraft/charm_builder.py", line 432, in <module>
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::     main()
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::   File "/snap/charmcraft/1429/lib/charmcraft/charm_builder.py", line 427, in main
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::     builder.build_charm()
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::   File "/snap/charmcraft/1429/lib/charmcraft/charm_builder.py", line 102, in build_charm
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::     self.handle_dependencies()
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::   File "/snap/charmcraft/1429/lib/charmcraft/charm_builder.py", line 314, in handle_dependencies
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::     self._install_dependencies(staging_venv_dir)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.641 ::   File "/snap/charmcraft/1429/lib/charmcraft/instrum.py", line 152, in _f
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.642 ::     return func(*args, **kwargs)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.642 ::   File "/snap/charmcraft/1429/lib/charmcraft/charm_builder.py", line 274, in _install_dependencies
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.642 ::     _process_run(cmd)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.642 ::   File "/snap/charmcraft/1429/lib/charmcraft/charm_builder.py", line 368, in _process_run
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.642 ::     raise RuntimeError(f"Subprocess command {cmd} execution failed with retcode {retcode}")
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.642 :: RuntimeError: Subprocess command ['/root/parts/charm/build/staging-venv/bin/pip3', 'install', '--upgrade', '--no-binary', ':all:', '--requirement=requirements.txt', 'cosl', 'pydantic<2', 'ops>=2.0.0'] execution failed with retcode 1
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.710 Parts processing error: Failed to run the build script for part 'charm'.
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715 Traceback (most recent call last):
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/step_handler.py", line 146, in _builtin_build
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     _create_and_run_script(
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/step_handler.py", line 409, in _create_and_run_script
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     subprocess.run(
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/usr/lib/python3.8/subprocess.py", line 516, in run
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     raise CalledProcessError(retcode, process.args,
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715 subprocess.CalledProcessError: Command '[PosixPath('/root/parts/charm/run/build.sh')]' returned non-zero exit status 1.
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715 The above exception was the direct cause of the following exception:
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715 Traceback (most recent call last):
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/charmcraft/parts.py", line 468, in run
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     aex.execute([act], stdout=stream, stderr=stream)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/executor.py", line 304, in execute
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     self._executor.execute(actions, stdout=stdout, stderr=stderr)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/executor.py", line 128, in execute
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     self._run_action(act, stdout=stdout, stderr=stderr)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/executor.py", line 193, in _run_action
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     handler.run_action(action, stdout=stdout, stderr=stderr)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/part_handler.py", line 137, in run_action
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     self._update_action(
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/part_handler.py", line 546, in _update_action
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     handler(step_info, stdout=stdout, stderr=stderr)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/part_handler.py", line 642, in _update_build
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     self._run_build(step_info, stdout=stdout, stderr=stderr, update=True)
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/part_handler.py", line 309, in _run_build
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     self._run_step(
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/part_handler.py", line 493, in _run_step
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     return step_handler.run_builtin()
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/step_handler.py", line 106, in run_builtin
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     return handler()
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715   File "/snap/charmcraft/1429/lib/craft_parts/executor/step_handler.py", line 155, in _builtin_build
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715     raise errors.PluginBuildError(part_name=self._part.name) from process_error
2023-08-03 13:37:09.977 :: 2023-08-03 13:37:09.715 craft_parts.errors.PluginBuildError: Failed to run the build script for part 'charm'.
2023-08-03 13:37:11.233 Failed to build charm for bases index '0'.
2023-08-03 13:37:11.237 Traceback (most recent call last):
2023-08-03 13:37:11.237   File "/snap/charmcraft/1349/lib/charmcraft/commands/build.py", line 388, in pack_charm_in_instance
2023-08-03 13:37:11.237     instance.execute_run(cmd, check=True, cwd=instance_output_dir)
2023-08-03 13:37:11.237   File "/snap/charmcraft/1349/lib/craft_providers/lxd/lxd_instance.py", line 289, in execute_run
2023-08-03 13:37:11.237     return self.lxc.exec(
2023-08-03 13:37:11.237   File "/snap/charmcraft/1349/lib/craft_providers/lxd/lxc.py", line 371, in exec
2023-08-03 13:37:11.237     return runner(final_cmd, **kwargs)  # pylint: disable=subprocess-run-check
2023-08-03 13:37:11.237   File "/snap/charmcraft/1349/usr/lib/python3.8/subprocess.py", line 516, in run
2023-08-03 13:37:11.237     raise CalledProcessError(retcode, process.args,
2023-08-03 13:37:11.237 subprocess.CalledProcessError: Command '['lxc', '--project', 'charmcraft', 'exec', 'local:charmcraft-mysql-344327-0-0-amd64', '--cwd', '/root/project', '--', 'env', 'PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin', 'CHARMCRAFT_MANAGED_MODE=1', 'charmcraft', 'pack', '--bases-index', '0', '--verbosity=brief']' returned non-zero exit status 1.
2023-08-03 13:37:11.237 Full execution log: '/home/runner/.local/state/charmcraft/log/charmcraft-20230803-133643.269717.log'
carlcsaposs-canonical commented 1 year ago

From some testing, it appears that charmcraft gets the target revision from /etc/craft-instance.conf in the LXC container—even if a different revision of charmcraft is installed

2023-08-03 13:36:56.912 Revisions found: host='1349', target='1349'
2023-08-03 13:36:56.912 Skipping snap injection: target is already up-to-date with revision on host
mr-cal commented 1 year ago

Thanks for the report.

Craft-providers assumes the snap is not refreshed or being installed by another entity. This assumption contributes to this problem and could be improved.

Craft-providers is already disabling automatic snap refreshes here, but with the old syntax (snap set system refresh.hold=<24 hours>). I'm not sure why it's failing in your workflow, there haven't been any changes this year. Perhaps it has always been failing and it has not been noticed.

Your workaround uses the new syntax (snap refresh --hold=forever charmcraft). We've been waiting to use the new syntax since it was put into snapd's beta (https://github.com/canonical/craft-providers/issues/184). It may be time we switch.

carlcsaposs-canonical commented 1 year ago

Yes it's likely it hasn't been noticed—normally we use the latest version of charmcraft but because of #1179 we've been pinning to 2.3.0 because we cannot build our charm with the latest version

mr-cal commented 1 year ago

As part of this enhancement, we will be adding a regression test to charmcraft where we create a charm and assert the automatic refreshes are held.