Problem/Motivation

Postponed on #3579174: [meta] Diagnose issues related to TUF-enabled projects.

We'd like to have the community start to test TUF via Composer directly (i.e. not via Automatic Updates). We'd also like to gather some real-world data about how much TUF metadata is being downloaded, and how is scales with the number of Drupal packages installed.

Steps to reproduce

First off, thank you for helping to test the new TUF-secured infrastructure on drupal.org. By doing so, you are helping to ensure the stability of these new systems, and providing valuable feedback that will guide future plans for improvements.

Before you start, you'll need a Drupal project where you can run Composer at the command-line. Ideally, you can test this on one or more existing projects, because we're looking for feedback on real-world scenarios. If not, see the Drupal installation documentation for how to get set up.

The first step is to add the PHP-TUF Composer Integration Plugin, and authorize Composer to run it. From the root of your project, run the following:

composer config allow-plugins.php-tuf/composer-integration true
composer require php-tuf/composer-integration:dev-main --dev

To provide the root of trust for TUF verifications, download the initial root metadata for these two repos:

mkdir tuf
curl -o tuf/packages.drupal.org.json https://packages.drupal.org/8/metadata/1.root.json
curl -o tuf/packagist-signed.drupalcode.org.json https://packagist-signed.drupalcode.org/metadata/1.root.json

Next, you will need to configure Composer to enable TUF protection for the Drupal package repository:

composer tuf:protect https://packages.drupal.org/8

Then, add the signed repository for Drupal core (and related projects) and enable TUF protection for it too:

composer config repositories.drupal-core composer https://packagist-signed.drupalcode.org
composer tuf:protect https://packagist-signed.drupalcode.org

Finally, update Composer dependencies:

composer -vv update

You should see the following in the output:

[TUF] Packages from https://packages.drupal.org/8 are verified by TUF. This may impact performance.
[TUF] Packages from https://packagist-signed.drupalcode.org are verified by TUF. This may impact performance.
Authenticity of packages from https://asset-packagist.org are not verified by TUF.
Authenticity of packages from https://repo.packagist.org are not verified by TUF.

If you see any errors, please immediately file a bug report on the "drupal.org infrastructure" project, using the "Packaging" component.

Remaining tasks

We're trying to gather some performance metrics as well. If you'd like to help with this, please follow the steps below, and report the results.

First, we'd like to know how many Drupal packages (modules, themes, etc.) your project is using:

$ composer show | grep drupal/ | wc -l
  15

Second, we'd like to know how much TUF metadata was downloaded to cover those packages.

$ du -sh vendor/composer/tuf
2.9M	vendor/composer/tuf

To report the results, add a comment below. This can be as simple as:

Packages: 15
TUF metadata: 2.9M

Thank you again for helping to test the new TUF-secured infrastructure on drupal.org.

Comments

ergonlogic created an issue. See original summary.

ergonlogic’s picture

Issue summary: View changes
ergonlogic’s picture

Issue summary: View changes
ergonlogic’s picture

Tested on a small personal project. Results:

  • Packages: 15
  • TUF metadata: 2.9M
ergonlogic’s picture

StatusFileSize
new928 bytes
new258 bytes

Tested on a second small side-project:

Packages: 19
TUF metadata: 2.8M

I'm planning to test on a bunch of different projects. To make this more efficient, I put together a couple simple scripts that just run the steps outlined in the issue summary.

ergonlogic’s picture

Report from a medium-sized application:

Packages: 53
TUF metadata: 3.6M

fjgarlin’s picture

When running this composer tuf:protect https://packagist-signed.drupalcode.org I got the following:

Authenticity of packages from https://packagist-signed.drupalcode.org are not verified by TUF.

[red] There are no commands defined in the "tuf" namespace. [/red]

Composer [tuf:protect https://packagist-signed.drupalcode.org] failed, composer command failed: exit status 1. stderr=

I edited the composer.json file manually to have:

        "drupal-core": {
            "type": "composer",
            "url": "https://packagist-signed.drupalcode.org",
            "tuf": true
        },

And then I could continue.

Report:
- Packages: 32
- TUF metadata: 3.0M

fjgarlin’s picture

I re-did the whole thing from scratch on the above project and I did not get that small error, so all the steps worked directly.

ergonlogic’s picture

FYI, you may occasionally see an error like:

The 'bin_c50-c53' contents does not match hash 'sha256' specified in the 'snapshot' metadata.

Sometimes this is transitory, and will fix itself in a matter of seconds. Re-running `composer update` will likely succeed. If not, but the 'bin_c50-c53' part changes, wait a minute or two and try again. This is a symptom of temporary inconsistency during metadata updates on the server-side. This is being addressed upstream in rugged/rugged#208: Ensure metadata consistency.

On the other hand, this kind of error can also persist longer. If re-running `composer update` show no change in the 'bin_c50-c53' part of the error message, this likely indicates that the TUF server has "stalled" during a metadata update. This will generally require intervention by a TUF server administrator. This is being addressed upstream in rugged/rugged#204: Add a monitor task to clean up stuck targets.

We expect this to stabilize as we address the upstream issues. However, if you do encounter such an error, it is worthwhile to report it here, in this ticket.

vensires’s picture

I did the process and it didn't work initially. As @fjgarlin said in #8, only after I did the process from start a second time it did work. Maybe we should have first executed the code to download the initial root metadata for the repos and only then try to add the signed repository for Drupal core and enable TUF protection for it? I mean, it doesn't seem like an issue of the Packaging component but more like an incorrect order of the commands as described in the issue summary here.

Packages: 77
TUF metadata: 4.5M
papagrande’s picture

I also had problems with installation and now get out of memory errors when running composer up in both ddev and on my MacOS host.
PHP Fatal error: Allowed memory size of 1610612736 bytes exhausted (tried to allocate 20480 bytes) in /var/www/html/vendor/php-tuf/php-tuf/src/CanonicalJsonTrait.php on line 46

FWIW, here is my data on one client's installation after several attempts:
Packages: 118
TUF metadata: 5.3M

nickdickinsonwilde’s picture

Hit an immediate hard failure - opened PR https://github.com/php-tuf/composer-integration/pull/126
With applying that, get:

https://packagist-signed.drupalcode.org could not be fully loaded (Maximum allowed download size reached. Downloaded 1165080 of allowed 1165080 bytes), package information was loaded from the local cache and may be out of date

(this continues after many runs)

Packages: 81
TUF metadata: 5.4mb

Failing with "The 'bin_d9c-d9f' contents does not match hash 'sha256' specified in the 'snapshot' metadata." - for a while.

catch’s picture

Status: Active » Needs work

I haven't done the steps yet but #10 suggests this needs work one way or the other.

drumm’s picture

On the other hand, this kind of error can also persist longer. If re-running `composer update` show no change in the 'bin_c50-c53' part of the error message, this likely indicates that the TUF server has "stalled" during a metadata update. This will generally require intervention by a TUF server administrator. This is being addressed upstream in rugged/rugged#204: Add a monitor task to clean up stuck targets.

https://gitlab.com/drupal-infrastructure/package-signing/rugged-metrics now alerts us when targets are stuck, but it does require manual intervention to resolve. Once https://gitlab.com/rugged/rugged/-/issues/204 is deployed, this will be more automatic.

Most of the issues we have seen are actually directories stuck in the building phase, before Rugged is involved. There is also some chance of disruption on Tuesdays during the regular AWS maintenance window for the managed queue.

PHP Fatal error: Allowed memory size of 1610612736 bytes exhausted (tried to allocate 20480 bytes) in /var/www/html/vendor/php-tuf/php-tuf/src/CanonicalJsonTrait.php on line 46

1.6MB is not a lot, especially when Drupal will require 64MB. Regardless, the php-tuf client will need to be better at detecting constrained memory situations, and keeping memory usage low. We do want to be judicious with memory use, since the hope is to expand TUF signing to the wider PHP ecosystem.

https://packagist-signed.drupalcode.org could not be fully loaded (Maximum allowed download size reached. Downloaded 1165080 of allowed 1165080 bytes), package information was loaded from the local cache and may be out of date

I think the Composer plugin client will need some error handling improved. This suggests something is amiss server-side, good chance cached at the CDN, but I don’t know what it might be. Running with -vvv might help point to which URL might be the issue.

Failing with "The 'bin_d9c-d9f' contents does not match hash 'sha256' specified in the 'snapshot' metadata." - for a while.

This looks like it is resolved now:

$ curl --silent https://packagist-signed.drupalcode.org/metadata/snapshot.json | grep -A2 bin_d9c-d9f
   "bin_d9c-d9f.json": {
    "hashes": {
     "sha256": "bf9500067989a47152416e9dde6b7c059286657d080f2fd526949e462d5c0172",
$ curl --silent https://packagist-signed.drupalcode.org/metadata/bin_d9c-d9f.json | sha256sum
bf9500067989a47152416e9dde6b7c059286657d080f2fd526949e462d5c0172  -

Right now we are permanently caching at the CDN and purging when changes happen. I’ve seen caching be enough of an issue that I think I will put a 5 or 10 minute lifetime on the cache at the CDN. So issues like this should self-heal after a few minutes.

drumm’s picture

Issue summary: View changes
Status: Needs work » Needs review

Opened a few issues to track what I mentioned in my last comment:

I moved “To provide the root of trust for TUF verifications, download the initial root metadata for these two repos:” up in the issue summary, which should make the setup steps run more smoothly. While there are things to improve, we do need more real-world testing to see if the improvements have been effective, so setting back to needs review.

skyejohnson’s picture

Issue summary: View changes
Status: Needs review » Active

I also got the same result as #7 and @fjgarlin's notes fixed it.
I had to increase my php memory limit to run composer -vv update

Report from my medium D11 site:

- Packages: 31
- TUF metadata: 3.9M

kyriazo’s picture

Same here as the previous tests, some memory issues, plus the order of commands.
My results:

- Packages: 89
- TUF metadata: 6.6M

drumm’s picture

Issue summary: View changes

Putting my edits to address #7 back in the issue summary.

drumm’s picture

skyejohnson & kyriazo - what was your PHP memory limit that you hit when you started, and how much did you raise it to succeed?

skyejohnson’s picture

@drumm I just set it to -1 tbh

cmlara’s picture

Using the time utility (make sure its the binary one not the bash built-in) would also probably be useful to log memory usage.

I put this into a contrib module lab (in no way representative of an actual deployment, just 10 packages of drupal/core using 3.0 mb in the tuf folder to develop a single contrib module)

With the tuf plugin:

$ /usr/bin//time composer -vv update
22.15user 3.12system 0:50.02elapsed 50%CPU (0avgtext+0avgdata 975440maxresident)k
88inputs+297600outputs (0major+270631minor)pagefaults 0swaps

Without the tuff plugin:

$ /usr/bin//time composer -vv update
10.19user 3.09system 0:20.90elapsed 63%CPU (0avgtext+0avgdata 280376maxresident)k
0inputs+285856outputs (0major+90243minor)pagefaults 0swaps

Max resident memory consumption increase, 695mb (3.4x higher total consumption)..
(Jut to be clear #14 mentions 1.6Mb, the OOM report is actually 1.6Gb)

COMPOSER_MEMORY_LIMIT=960m - succeed with tuff (succeeds by less than 64mb)
COMPOSER_MEMORY_LIMIT=256m - succeed without tuf (by less than 10mb)

drumm’s picture

I misread the conversion here:

PHP Fatal error: Allowed memory size of 1610612736 bytes exhausted (tried to allocate 20480 bytes) in /var/www/html/vendor/php-tuf/php-tuf/src/CanonicalJsonTrait.php on line 46

1.6MB is not a lot, especially when Drupal will require 64MB. Regardless, the php-tuf client will need to be better at detecting constrained memory situations, and keeping memory usage low. We do want to be judicious with memory use, since the hope is to expand TUF signing to the wider PHP ecosystem.

This is actually 1.6GB, which is already quite a high memory limit. Along with #21, it does look like the client seems to have a memory usage problem. So https://github.com/php-tuf/composer-integration/issues/127 is looking like the biggest blocker to getting this closer to core.

fubarhouse’s picture

Neil brought this to my attention, so I've been taking a quick look at this as part of DrupalCon contribution day in Singapore.

I've used a fresh clone of drupal_cms for testing with a fresh install and initialization of DDEV, on Apple silicon.

As specified in the description, here are the following desired metrics:

fubarhouse@drupal-cms-dev-web:/var/www/html$ composer show | grep drupal/ | wc -l
Authenticity of packages from https://repo.packagist.org are not verified by TUF.
104
fubarhouse@drupal-cms-dev-web:/var/www/html$ du -sh vendor/composer/tuf
7.7M	vendor/composer/tuf

I also ran into this one.... once - in a series of tests, however this seems inconsistent as I only got it once.

In TrustedAuthorityTrait.php line 50:

  [Tuf\Exception\MetadataException]
  The 'bin_c50-c53' contents does not match hash 'sha256' specified in the 'snapshot' metadata.

I have posted a couple of graphs in Drupal Slack if anybody is interested - they show the memory usage at ~800MB without the running process and at its peak it was using 7.1GB, however it did not run out of memory or show an error. A link to these graphs is below:

jimconte’s picture

We expect this to stabilize as we address the upstream issues. However, if you do encounter such an error, it is worthwhile to report it here, in this ticket.

I set up composer as described, and I'm running composer update -vvv manually.
I've been getting the same "Maximum allowed download size reached. Downloaded 1024 of allowed 1024 bytes" on these two for the past hour:
https://packages.drupal.org/8/metadata/bin_628-62b.json
https://packages.drupal.org/8/metadata/bin_04c-04f.json

On repeated runs, when one succeeds, the other fails.

drumm’s picture

Can you include a bit more context, ideally the full console output? What I was understanding in https://github.com/php-tuf/composer-integration/issues/128 was that the specific files weren’t mentioned in the error message. HTTP requests happen in parallel, so I don’t think the line above the error message is necessarily the cause, which would also explain why it appears to be switching.

jimconte’s picture

StatusFileSize
new30.13 KB
new4.14 KB

Piped output to log:
COMPOSER_MEMORY_LIMIT=-1 /usr/bin/php83 /usr/local/bin/composer28 -vvv update --no-ansi &> ../temp/composer.log

I am prototyping with a very basic install.

catch’s picture

Category: Task » Bug report
Priority: Normal » Critical

I just tried this using the steps in the issue summary, and immediately got this error during composer update:

  - Downloading drupal/core-project-message (11.x-dev 656efa0)
    Failed to download drupal/core-project-message from dist: Maximum allowed download size reached. Content-length header indicates 10666 bytes. Allowed 10658 bytes
    Now trying to download from source


.... [ binary output ] ....


In CurlDownloader.php line 374:
                                                              
  [TypeError]                                                 
  rewind(): supplied resource is not a valid stream resource  
                                                             

Then I manually remove drupal/core-project-message from composer.json, and tried composer update again, got this:

 1/7 [====>-----------------------]  14%    Failed to download drupal/core from dist: Maximum allowed download size reached. Content-length header indicates 26347482 bytes. Allowed 25427652 bytes
    Now trying to download from source

Are the steps in the issue summary outdated, or this is a regression somewhere?

edit: reading more I see this is the same issue as people have reported above.

catch’s picture

With a completely fresh install via composer create-project I was able to get the composer update to run. Maybe it's because I was on 11.x-dev?

Once I was able to run composer update, I did some profiling with xhprof, and opened https://github.com/php-tuf/php-tuf/issues/385 with initial findings.

catch’s picture

MR up at https://github.com/php-tuf/php-tuf/pull/386 which appears to be a 50% improvement for both CPU and memory.

drumm’s picture

  - Downloading drupal/core-project-message (11.x-dev 656efa0)
    Failed to download drupal/core-project-message from dist: Maximum allowed download size reached. Content-length header indicates 10666 bytes. Allowed 10658 bytes

This is a server-side issue. https://packagist-signed.drupalcode.org/metadata/bin_094-097.json says

   "drupal/core-project-message/11.9999999.9999999.9999999-dev": {
    "hashes": {
     "sha256": "78163df67a5207b9b0ba0ede7ff2652396f5c66ee9d6ce5f137db24d4242bd6e"
    },
    "length": 10657
   },

But https://packagist-signed.drupalcode.org/dist/drupal/core-project-message... is a different file. It was last updated Feb 3, which is around when I was shoring things up, so it's hard to say if it was a systematic issue or debris from something that was fixed. I'll look at getting that re-signed.

TUF is signing a target named drupal/core-project-message/11.9999999.9999999.9999999-dev and presumably it has a previous version of that file. For packagist-signed, dev zipballs do change location with every commit, the commit hash is in the filename. I wonder if there’s some way to use this for better error messaging or working around issues.

catch’s picture

Second MR:
https://github.com/php-tuf/php-tuf/pull/387

If I combine the two of these, memory usage in xhprof is more or less equivalent to vanilla composer.

drumm’s picture

  - Downloading drupal/core-project-message (11.x-dev 656efa0)
    Failed to download drupal/core-project-message from dist: Maximum allowed download size reached. Content-length header indicates 10666 bytes. Allowed 10658 bytes

This is now fixed. I had put in logic that only signed each zip file once. The dev version zip archives have the Git commit ID in their name and change when a new commit is added. However, the target name drupal/core-project-message/11.9999999.9999999.9999999-dev isn’t changing and what is actually checked. The fix was https://gitlab.com/drupal-infrastructure/package-signing/packagist-signe... and https://gitlab.com/drupal-infrastructure/package-signing/packagist-signe...

nicxvan’s picture

Ok I went through this with a mature Drupal project on 10.4.6

Highlights:
ddev composer show | grep drupal/ | wc -l
Authenticity of packages from https://asset-packagist.org are not verified by TUF.
Authenticity of packages from https://repo.packagist.org are not verified by TUF.
68

du -sh vendor/composer/tuf
6.5M vendor/composer/tuf

High level impression, it took forever, it was almost 30 minutes I think for the update step and there was so much output it went past scrollback.
> pre-file-download: Tuf\ComposerIntegration\Plugin->preFileDownload

Steps taken:
ddev composer config allow-plugins.php-tuf/composer-integration true
No output
ddev composer require php-tuf/composer-integration:dev-main --dev
Abridged output:

./composer.json has been updated
Running composer update php-tuf/composer-integration
Gathering patches for root package.
Loading composer repositories with package information
Updating dependencies
Lock file operations: 4 installs, 0 updates, 0 removals
  - Locking paragonie/random_compat (v9.99.100)
  - Locking paragonie/sodium_compat (v1.21.1)
  - Locking php-tuf/composer-integration (dev-main 05a6d3e)
  - Locking php-tuf/php-tuf (0.1.6)
Writing lock file

And

Authenticity of packages from https://packages.drupal.org/8 are not verified by TUF.
Authenticity of packages from https://asset-packagist.org are not verified by TUF.
Authenticity of packages from https://repo.packagist.org are not verified by TUF.

Next I ran the mkdir and curl commands, nothing remarkable

ddev composer tuf:protect https://packages.drupal.org/8
Authenticity of packages from https://packages.drupal.org/8 are not verified by TUF.
Authenticity of packages from https://asset-packagist.org are not verified by TUF.
Authenticity of packages from https://repo.packagist.org are not verified by TUF.
https://packages.drupal.org/8 is now protected by TUF.
ddev composer config repositories.drupal-core composer https://packagist-signed.drupalcode.org
Authenticity of packages from https://asset-packagist.org are not verified by TUF.
Authenticity of packages from https://repo.packagist.org are not verified by TUF.
ddev composer tuf:protect https://packagist-signed.drupalcode.org
Authenticity of packages from https://packagist-signed.drupalcode.org are not verified by TUF.
Authenticity of packages from https://asset-packagist.org are not verified by TUF.
Authenticity of packages from https://repo.packagist.org are not verified by TUF.
https://packagist-signed.drupalcode.org is now protected by TUF.
trackleft2’s picture

Packages: 114

When I ran composer -vv update I saw

PHP Fatal error:  Allowed memory size of 1610612736 bytes exhausted (tried to allocate 4096 bytes) in /vendor/php-tuf/php-tuf/src/CanonicalJsonTrait.php on line 46

Check https://getcomposer.org/doc/articles/troubleshooting.md#memory-limit-errors for more info on how to handle out of memory errors.%

And was able to get past it by running
COMPOSER_MEMORY_LIMIT=-1 composer -vv update
Instead, but then I see the following.

PHP Fatal error:  Uncaught ErrorException: include(phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/composer/../symfony/string/UnicodeString.php): Failed to open stream: phar error: Cannot open phar archive "/opt/homebrew/Cellar/composer/2.8.3/bin/composer" for reading in phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/composer/ClassLoader.php:576



Stack trace:
#0 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/composer/ClassLoader.php(576): Composer\Util\ErrorHandler::handle(2, 'include(phar://...', 'phar:///opt/hom...', 576)
#1 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/composer/ClassLoader.php(576): include()
#2 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/composer/ClassLoader.php(427): Composer\Autoload\{closure}('phar:///opt/hom...')
#3 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/symfony/console/Helper/Helper.php(65): Composer\Autoload\ClassLoader->loadClass('Symfony\\Compone...')
#4 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/symfony/console/Application.php(855): Symfony\Component\Console\Helper\Helper::width('  [ErrorExcepti...')
#5 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/symfony/console/Application.php(840): Symfony\Component\Console\Application->doRenderThrowable(Object(ErrorException), Object(Symfony\Component\Console\Output\StreamOutput))
#6 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/symfony/console/Application.php(154): Symfony\Component\Console\Application->renderThrowable(Object(ErrorException), Object(Symfony\Component\Console\Output\StreamOutput))
#7 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/symfony/console/Application.php(177): Symfony\Component\Console\Application->Symfony\Component\Console\{closure}(Object(ErrorException))
#8 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/src/Composer/Console/Application.php(136): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#9 phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/bin/composer(98): Composer\Console\Application->run()
#10 /opt/homebrew/Cellar/composer/2.8.3/bin/composer(29): require('phar:///opt/hom...')
#11 {main}
  thrown in phar:///opt/homebrew/Cellar/composer/2.8.3/bin/composer/vendor/composer/ClassLoader.php on line 576

So I upgraded composer.

brew upgrade composer

And I got the same error.

I was able to run composer update if I revert the changes to composer.json and composer.lock.

I started over with the updated version of composer (2.8.9) and the whole process went waaaaay faster and actually completed.

4.6M vendor/composer/tuf

drumm’s picture

There have been significant memory usage improvements which need review linked from https://github.com/php-tuf/composer-integration/issues/127. Those could help the runtime as well.

catch’s picture

https://github.com/php-tuf/php-tuf/pull/395 just landed which was the last major memory improvement I found.

For me with just Drupal core, the combination of the three recent MRs brought memory usage down from about 320mb to 60mb. It would be great if people could test this again with some larger projects to see how it does when there are more packages to deal with.

pcambra’s picture

I've tested this with a somehow large project I'm working on and after around 10 minutes or less I got:

Packages: 146
TUF metadata: 9.9M

cmlara’s picture

This appears to needs an IS update to have those running the composer steps gather memory (and time if it really took 10 minutes) usage to be included in reports.

cmlara’s picture

Testing against Drupal CMS fails.

mkdir -p /tmp/dcms
cd /tmp/dcms
/usr/bin/time composer create-project drupal/cms
cd cms
/usr/bin/time composer -vv update
composer config allow-plugins.php-tuf/composer-integration true
composer require php-tuf/composer-integration:dev-main --dev
mkdir tuf
curl -o tuf/packages.drupal.org.json https://packages.drupal.org/8/metadata/1.root.json
curl -o tuf/packagist-signed.drupalcode.org.json https://packagist-signed.drupalcode.org/metadata/1.root.json
composer tuf:protect https://packages.drupal.org/8
composer config repositories.drupal-core composer https://packagist-signed.drupalcode.org
composer tuf:protect https://packagist-signed.drupalcode.org
composer -vv update
> pre-file-download: Tuf\ComposerIntegration\Plugin->preFileDownload

In RootVerifier.php line 36:
                                                                          
  [Tuf\Exception\Attack\RollbackAttackException]                          
  Remote 'root' metadata version "$1" does not the expected version "$2"  
                                                                          

Exception trace:
  at /tmp/dcms/cms/vendor/php-tuf/php-tuf/src/Metadata/Verifier/RootVerifier.php:36
 Tuf\Metadata\Verifier\RootVerifier->checkRollbackAttack() at /tmp/dcms/cms/vendor/php-tuf/php-tuf/src/Metadata/Verifier/RootVerifier.php:25
 Tuf\Metadata\Verifier\RootVerifier->verify() at /tmp/dcms/cms/vendor/php-tuf/php-tuf/src/Metadata/Verifier/UniversalVerifier.php:59
 Tuf\Metadata\Verifier\UniversalVerifier->verify() at /tmp/dcms/cms/vendor/php-tuf/php-tuf/src/Client/Updater.php:231
 Tuf\Client\Updater->updateRoot() at /tmp/dcms/cms/vendor/php-tuf/php-tuf/src/Client/Updater.php:152
 Tuf\Client\Updater->refresh() at /tmp/dcms/cms/vendor/php-tuf/composer-integration/src/ComposerCompatibleUpdater.php:51
 Tuf\ComposerIntegration\ComposerCompatibleUpdater->getLength() at /tmp/dcms/cms/vendor/php-tuf/composer-integration/src/TufValidatedComposerRepository.php:220
 Tuf\ComposerIntegration\TufValidatedComposerRepository->prepareComposerMetadata() at /tmp/dcms/cms/vendor/php-tuf/composer-integration/src/Plugin.php:55
 Tuf\ComposerIntegration\Plugin->preFileDownload() at /var/www/html/vendor/composer/composer/src/Composer/EventDispatcher/EventDispatcher.php:220
 Composer\EventDispatcher\EventDispatcher->doDispatch() at /var/www/html/vendor/composer/composer/src/Composer/EventDispatcher/EventDispatcher.php:115
 Composer\EventDispatcher\EventDispatcher->dispatch() at /var/www/html/vendor/composer/composer/src/Composer/Repository/ComposerRepository.php:1653
 Composer\Repository\ComposerRepository->asyncFetchFile() at /var/www/html/vendor/composer/composer/src/Composer/Repository/ComposerRepository.php:1111
 Composer\Repository\ComposerRepository->startCachedAsyncDownload() at /var/www/html/vendor/composer/composer/src/Composer/Repository/ComposerRepository.php:1039
 Composer\Repository\ComposerRepository->loadAsyncPackages() at /var/www/html/vendor/composer/composer/src/Composer/Repository/ComposerRepository.php:540
 Composer\Repository\ComposerRepository->loadPackages() at /var/www/html/vendor/composer/composer/src/Composer/DependencyResolver/PoolBuilder.php:429
 Composer\DependencyResolver\PoolBuilder->loadPackagesMarkedForLoading() at /var/www/html/vendor/composer/composer/src/Composer/DependencyResolver/PoolBuilder.php:279
 Composer\DependencyResolver\PoolBuilder->buildPool() at /var/www/html/vendor/composer/composer/src/Composer/Repository/RepositorySet.php:332
 Composer\Repository\RepositorySet->createPool() at /var/www/html/vendor/composer/composer/src/Composer/Installer.php:501
 Composer\Installer->doUpdate() at /var/www/html/vendor/composer/composer/src/Composer/Installer.php:298
 Composer\Installer->run() at /var/www/html/vendor/composer/composer/src/Composer/Command/UpdateCommand.php:281
 Composer\Command\UpdateCommand->execute() at /var/www/html/vendor/symfony/console/Command/Command.php:279
 Symfony\Component\Console\Command\Command->run() at /var/www/html/vendor/symfony/console/Application.php:1076
 Symfony\Component\Console\Application->doRunCommand() at /var/www/html/vendor/symfony/console/Application.php:342
 Symfony\Component\Console\Application->doRun() at /var/www/html/vendor/composer/composer/src/Composer/Console/Application.php:396
 Composer\Console\Application->doRun() at /var/www/html/vendor/symfony/console/Application.php:193
 Symfony\Component\Console\Application->run() at /var/www/html/vendor/composer/composer/src/Composer/Console/Application.php:136
 Composer\Console\Application->run() at /var/www/html/vendor/composer/composer/bin/composer:99
 include() at /var/www/html/vendor/bin/composer:119
catch’s picture

I tried the same steps as #39 and got the same result.

The error message made me wonder if there's a version 2 of the metadata, and there is https://packagist-signed.drupalcode.org/metadata/2.root.json

If I replace the following from the issue summary, after rm -rf vendor/composer/tuf then it works for me (although the initial composer update is taking forever and still running):

curl -o tuf/packagist-signed.drupalcode.org.json https://packagist-signed.drupalcode.org/metadata/2.root.json
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  2987  100  2987    0     0   1411      0  0:00:02  0:00:02 --:--:--  1411
catch@*:~/www/cms$ curl -o tuf/packages.drupal.org.json https://packages.drupal.org/8/metadata/2.root.json
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  2987  100  2987    0     0   2190      0  0:00:01  0:00:01 --:--:--  2191

But this begs the question - if the new version is as a result of a key rotation or something, then how would a php-tuf enabled site be able to use new versions of the metadata?

drumm’s picture

We did recently refresh the root metadata ahead of the expiration later this month for both:

I would expect the client to fetch and use this automatically. If we refreshed and rotated keys in the root metadata as a result of a compromise, I would think the client should automatically start using the new metadata, which has a chain of trust back to 1.root.json. This should be checked against the TUF spec.

This will need some debugging to figure out where the root cause is.

catch’s picture

rajab natshah’s picture

Should we have both in the same root composer.json file

    "drupal-core": {
      "type": "composer",
      "url": "https://packagist-signed.drupalcode.org",
      "tuf": true
    },
    "drupal": {
      "type": "composer",
      "url": "https://packages.drupal.org/8",
      "tuf": true
    },

Or only one

    "drupal-core": {
      "type": "composer",
      "url": "https://packagist-signed.drupalcode.org",
      "tuf": true
    },

I keep hitting https://packages.drupal.org/8 could not be fully loaded (Maximum allowed download size reached. Content-length header indicates 7240 bytes. Allowed 1024 bytes), package information was loaded from the local cache and may be out of date

And I see this https://packagist-signed.drupalcode.org/metadata/3.root.json too.

drumm’s picture

https://packagist-signed.drupalcode.org/metadata/3.root.json is by design, that will only exist when the root metadata is refreshed for a 3rd time.

I keep hitting https://packages.drupal.org/8 could not be fully loaded (Maximum allowed download size reached. Content-length header indicates 7240 bytes. Allowed 1024 bytes), package information was loaded from the local cache and may be out of date

Until https://github.com/php-tuf/composer-integration/issues/128 is resolved, I have basically no capability to help with issues like this. I need to know which HTTP request is causing the problem.

drumm’s picture

Both https://packagist-signed.drupalcode.org and https://packages.drupal.org/8 should be in composer.json with "tuf": true

https://packages.drupal.org/8 only includes contrib modules and themes from Drupal.org. The rest of Drupal, including core, is distributed via Packagist.org, which does not have code signing. packagist-signed.drupalcode.org mirrors packagist.org, so core and the TUF library are signed.

rajab natshah’s picture

Got it
Thanks, Neil, for the tips and notes.
Doing one day round of testing with TUF, Auto-update for a real case. ( figuring out the robot workflow for auto updating a live site - with a cloned copy in a staged host.
Interesting finding and steps

Thinking of crating two DDEV commands ( or bash ) like

ddev init-autoupdate
ddev disable-autoupdate

As I think a cloned local or staged copy could work with DDEV or Docker directly
1- Clone
2- Init Autoupdate
3- Auto update
4- Automated Unit/Functional testing process ( Get a pass flag )
5- Disable autoupdate
6- Git commit
7- Deploy

Thank you so much for working on TUF and the Package Manager for Drupal!!

cmlara’s picture

Until https://github.com/php-tuf/composer-integration/issues/128 is resolved, I have basically no capability to help with issues like this.

Given we had issues in #30 is there any background process running to routinely verify the integrity of the repository (and alert when integrity is breached) that could identify these issues prior to a report from a user and without need to resolve the issue in TUF?

drumm’s picture

We are monitoring for known causes of integrity issues, such as queues not being processed promptly. Verifying the entire repository would probably take multiple days and have little practical benefit for spotting issues which I suspect are only present for a few minutes at a time.

neil_w’s picture

Packages: 120
TUF metadata: 9.1M

fjgarlin’s picture

I had the sale problem reported in #39. The steps in #40 fixed things.

So, is this something that should happen automatically and isn't? Is there an issue here or upstream to deal with that or do we just need to update the steps in the issue description?

catch’s picture

@fjgarlin I opened https://github.com/php-tuf/php-tuf/issues/396 for this issue. I think it must be something that should happen automatically but isn't, because metadata is going to get refreshed on Drupal.org every year or so and we can't expect people to manually refresh it themselves.

However, I'm not familiar with this part of the php-tuf code base enough to know whether it's trying to manually handle the refresh and hitting a bug, or if it's an oversight and just wasn't implemented (because there wasn't refreshed data to test against with while it was being developed, feels like it would be easy to overlook because it's something that only happens over time in real repositories).

quietone’s picture

Issue summary: View changes

In a meeting in autoupdates-package-manager today, catch explained that this is postponed on https://github.com/php-tuf/php-tuf/issues/396

I added that to the Remaining tasks

catch’s picture

Title: Manually test TUF-enabled Composer projects » [PP-upstream] Manually test TUF-enabled Composer projects
Status: Active » Postponed

Yes that issue results in php-tuf incorrectly thinking that d.o has been hacked (because the keys don't match) and refusing to do any composer operations at all. If you start fresh with the updated keys then it works, but that's very manual.

Once it's fixed in php-tuf, it should be feasible to do wider testing on it again. Moving to postponed to make it clear this issue is paused, but the testing done here did flush that one out, and it's good to have identified it before we enabled php-tuf in core or Drupal CMS instead of afterwards when potentially thousands of sites would have had broken composer installs.

star-szr’s picture

Title: [PP-upstream] Manually test TUF-enabled Composer projects » [PP-1] Manually test TUF-enabled Composer projects

This is no longer postponed on upstream with that issue (https://github.com/php-tuf/php-tuf/issues/396) resolved, but should be postponed on #3579174: [meta] Diagnose issues related to TUF-enabled projects since some packages are not working well. Currently unclear how many packages are affected.

The behaviour seems to be similar to previous reports in #12, #43, and many comments in between, and we should resolve this before we continue with more testing.

catch’s picture

Issue summary: View changes
star-szr’s picture

Issue summary: View changes