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.
| Comment | File | Size | Author |
|---|---|---|---|
| #26 | composer.json_.txt | 4.14 KB | jimconte |
| #26 | composer.log_.txt | 30.13 KB | jimconte |
| #5 | report-tuf.sh_.txt | 258 bytes | ergonlogic |
| #5 | test-tuf.sh_.txt | 928 bytes | ergonlogic |
Comments
Comment #2
ergonlogicComment #3
ergonlogicComment #4
ergonlogicTested on a small personal project. Results:
Comment #5
ergonlogicTested 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.
Comment #6
ergonlogicReport from a medium-sized application:
Packages: 53
TUF metadata: 3.6M
Comment #7
fjgarlin commentedWhen running this
composer tuf:protect https://packagist-signed.drupalcode.orgI got the following:I edited the
composer.jsonfile manually to have:And then I could continue.
Report:
- Packages: 32
- TUF metadata: 3.0M
Comment #8
fjgarlin commentedI 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.
Comment #9
ergonlogicFYI, you may occasionally see an error like:
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.
Comment #10
vensiresI 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.
Comment #11
papagrandeI also had problems with installation and now get out of memory errors when running
composer upin 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 46FWIW, here is my data on one client's installation after several attempts:
Packages: 118
TUF metadata: 5.3M
Comment #12
nickdickinsonwildeHit an immediate hard failure - opened PR https://github.com/php-tuf/composer-integration/pull/126
With applying that, get:
(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.
Comment #13
catchI haven't done the steps yet but #10 suggests this needs work one way or the other.
Comment #14
drummhttps://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.
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.
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
-vvvmight help point to which URL might be the issue.This looks like it is resolved now:
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.
Comment #15
drummOpened 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.
Comment #16
skyejohnson commentedI 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 updateReport from my medium D11 site:
- Packages: 31
- TUF metadata: 3.9M
Comment #17
kyriazo commentedSame here as the previous tests, some memory issues, plus the order of commands.
My results:
- Packages: 89
- TUF metadata: 6.6M
Comment #18
drummPutting my edits to address #7 back in the issue summary.
Comment #19
drummskyejohnson & kyriazo - what was your PHP memory limit that you hit when you started, and how much did you raise it to succeed?
Comment #20
skyejohnson commented@drumm I just set it to -1 tbh
Comment #21
cmlaraUsing 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:
Without the tuff plugin:
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)
Comment #22
drummI misread the conversion here:
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.
Comment #23
fubarhouse commentedNeil 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:
I also ran into this one.... once - in a series of tests, however this seems inconsistent as I only got it once.
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:
Comment #24
jimconte commentedI 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.
Comment #25
drummCan 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.
Comment #26
jimconte commentedPiped output to log:
COMPOSER_MEMORY_LIMIT=-1 /usr/bin/php83 /usr/local/bin/composer28 -vvv update --no-ansi &> ../temp/composer.logI am prototyping with a very basic install.
Comment #27
catchI just tried this using the steps in the issue summary, and immediately got this error during composer update:
Then I manually remove
drupal/core-project-messagefrom composer.json, and tried composer update again, got this: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.
Comment #28
catchWith 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.
Comment #29
catchMR up at https://github.com/php-tuf/php-tuf/pull/386 which appears to be a 50% improvement for both CPU and memory.
Comment #30
drummThis is a server-side issue. https://packagist-signed.drupalcode.org/metadata/bin_094-097.json says
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-devand 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.Comment #31
catchSecond 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.
Comment #32
drummThis 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-devisn’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...Comment #33
nicxvan commentedOk 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->preFileDownloadSteps taken:
ddev composer config allow-plugins.php-tuf/composer-integration trueNo output
ddev composer require php-tuf/composer-integration:dev-main --devAbridged output:
And
Next I ran the mkdir and curl commands, nothing remarkable
Comment #34
trackleft2Packages: 114
When I ran
composer -vv updateI sawAnd was able to get past it by running
COMPOSER_MEMORY_LIMIT=-1 composer -vv updateInstead, but then I see the following.
So I upgraded composer.
brew upgrade composerAnd 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/tufComment #35
drummThere 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.
Comment #36
catchhttps://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.
Comment #37
pcambraI've tested this with a somehow large project I'm working on and after around 10 minutes or less I got:
Comment #38
cmlaraThis 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.
Comment #39
cmlaraTesting against Drupal CMS fails.
Comment #40
catchI 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/tufthen it works for me (although the initial composer update is taking forever and still running):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?
Comment #41
drummWe 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.
Comment #42
catchOpened https://github.com/php-tuf/php-tuf/issues/396
Comment #43
rajab natshahShould we have both in the same root
composer.jsonfileOr only one
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 dateAnd I see this
https://packagist-signed.drupalcode.org/metadata/3.root.jsontoo.Comment #44
drummhttps://packagist-signed.drupalcode.org/metadata/3.root.jsonis by design, that will only exist when the root metadata is refreshed for a 3rd time.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.
Comment #45
drummBoth https://packagist-signed.drupalcode.org and https://packages.drupal.org/8 should be in composer.json with
"tuf": truehttps://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.
Comment #46
rajab natshahGot 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
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!!
Comment #47
cmlaraGiven 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?
Comment #48
drummWe 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.
Comment #49
neil_w commentedPackages: 120
TUF metadata: 9.1M
Comment #50
fjgarlin commentedI 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?
Comment #51
catch@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).
Comment #52
quietone commentedIn 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
Comment #53
catchYes 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.
Comment #54
star-szrThis 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.
Comment #55
catchComment #56
star-szr