Page MenuHomePhabricator

Git tag/version fetching times out
Closed, ResolvedPublic3 Estimated Story PointsBUG REPORT

Description

We get quite a few errors like this:

Uncaught PHP Exception Twig\Error\RuntimeError: "An exception has been thrown during the rendering of a template ("The process "'git' 'describe' '--tags' '--always'" exceeded the timeout of 60 seconds.")." at /data/project/svgtranslate/app/templates/base.html.twig line 47

It's running this command in order to display the current version number in the footer. This isn't very useful information for most users, and it doesn't seem worth slowing down (and sometimes failing all toghether) the display of the homepage. There are a few options:

  • Move the version number to an 'About' page, and link that from the footer. Perhaps that could include other useful information for debugging.
  • Cache the version number, for maybe 10 minutes. That would reduce the number of times the command has to be run. During times of quick development it could be slightly annoying to sometimes have the displayed version number be out of sync with the actual version number, but for most cases it probably wouldn't bother anyone.

Details:

{
    "class": "Twig\\Error\\RuntimeError",
    "message": "An exception has been thrown during the rendering of a template (\"The process \"'git' 'describe' '--tags' '--always'\" exceeded the timeout of 60 seconds.\").",
    "code": 0,
    "file": "/data/project/svgtranslate/app/templates/base.html.twig:47",
    "trace": [
        "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:367",
        "/data/project/svgtranslate/app/var/cache/prod/twig/96/965c923fbabe9e479fe2f653956053771bc1b20cff296566a1a17fe2aa249490.php:45",
        "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:394",
        "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:367",
        "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:379",
        "/data/project/svgtranslate/app/vendor/twig/twig/src/TemplateWrapper.php:40",
        "/data/project/svgtranslate/app/vendor/twig/twig/src/Environment.php:280",
        "/data/project/svgtranslate/app/vendor/symfony/framework-bundle/Controller/AbstractController.php:258",
        "/data/project/svgtranslate/app/vendor/symfony/framework-bundle/Controller/AbstractController.php:266",
        "/data/project/svgtranslate/app/src/Controller/SearchController.php:66",
        "/data/project/svgtranslate/app/vendor/symfony/http-kernel/HttpKernel.php:163",
        "/data/project/svgtranslate/app/vendor/symfony/http-kernel/HttpKernel.php:75",
        "/data/project/svgtranslate/app/vendor/symfony/http-kernel/Kernel.php:202",
        "/data/project/svgtranslate/app/public/index.php:47"
    ],
    "previous": {
        "class": "Symfony\\Component\\Process\\Exception\\ProcessTimedOutException",
        "message": "The process \"'git' 'describe' '--tags' '--always'\" exceeded the timeout of 60 seconds.",
        "code": 0,
        "file": "/data/project/svgtranslate/app/vendor/symfony/process/Process.php:1204",
        "trace": [
            "/data/project/svgtranslate/app/vendor/symfony/process/Process.php:430",
            "/data/project/svgtranslate/app/vendor/symfony/process/Process.php:254",
            "/data/project/svgtranslate/app/vendor/wikimedia/toolforge-bundle/Twig/Extension.php:215",
            "/data/project/svgtranslate/app/var/cache/prod/twig/4f/4ff8caeb8adae869c3bd9663c8fb9dabdaf458cc21eb41e492e4da730e722707.php:151",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:394",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:367",
            "/data/project/svgtranslate/app/var/cache/prod/twig/96/965c923fbabe9e479fe2f653956053771bc1b20cff296566a1a17fe2aa249490.php:45",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:394",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:367",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/Template.php:379",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/TemplateWrapper.php:40",
            "/data/project/svgtranslate/app/vendor/twig/twig/src/Environment.php:280",
            "/data/project/svgtranslate/app/vendor/symfony/framework-bundle/Controller/AbstractController.php:258",
            "/data/project/svgtranslate/app/vendor/symfony/framework-bundle/Controller/AbstractController.php:266",
            "/data/project/svgtranslate/app/src/Controller/SearchController.php:66",
            "/data/project/svgtranslate/app/vendor/symfony/http-kernel/HttpKernel.php:163",
            "/data/project/svgtranslate/app/vendor/symfony/http-kernel/HttpKernel.php:75",
            "/data/project/svgtranslate/app/vendor/symfony/http-kernel/Kernel.php:202",
            "/data/project/svgtranslate/app/public/index.php:47"
        ]
    }
}

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald Transcript
Samwilson changed the subtype of this task from "Task" to "Bug Report".Apr 11 2023, 9:35 AM
Samwilson updated the task description. (Show Details)
Samwilson set the point value for this task to 3.Apr 12 2023, 11:10 AM
Samwilson moved this task from New & TBD Tickets to Up Next on the Community-Tech board.

Just general advice from a "eureka" moment I had at the recent hackathon... we should probably avoid any file system operations on Toolforge. The actual issue boils down to the fragility of NFS. So use APCu instead of file caching where possible, etc.

That said,

Cache the version number, for maybe 10 minutes. That would reduce the number of times the command has to be run. During times of quick development it could be slightly annoying to sometimes have the displayed version number be out of sync with the actual version number, but for most cases it probably wouldn't bother anyone.

Why not longer, say a full week? It's standard practice to clear the cache on deploy, and it's in the deploy script. Locally, sure, it might be a little misleading. Maybe we could check the environment and conditionally cache?

With such a brief cache expiry, I'm guessing we will still get emails about whatever tool being down since UptimeRobot runs at 5 minute cycles. Inevitably it will hit the NFS issue at some point.

The actual issue boils down to the fragility of NFS.

Though that doesn't explain why WS Export has the git commands timing out (T335553#9014538), as VPS does not use NFS. That is mysterious to me, as other VPS tools like XTools and Wikimedia OCR that do the same git operations do not seem to time out.

Regardless, I do believe the issue with NFS still stands. I was chatting with Cloud Services at the Hackathon and they confirmed that is the likely culprit as to why file system-related things often fail on Toolforge.

Good point about avoiding file operations on NFS. We're using the filesystem cache adapter for WS Export, and the files are stored on the volume mounted at /ws-export. So I also don't know why WS Export is failing there. But SVG Translate is probably failing at least sometimes due to NSF slowness. I've noticed sometimes that doing git status in the svgtranslate directory can take a long time (although never minutes, I don't think).

It's probably a good idea to move to a faster caching system, on Toolforge and VPS, regardless. The cache directories are not currently large:

  • SVG Translate: /data/project/svgtranslate/app/var/cache/prod/pools/ 1.8M
  • WS Export: /ws-export/var/cache/prod/pools/ 880K

So perhaps moving to Redis would be good?

Anyway, I've started a pull request for updating SVG Translate to use the new version of the bundle, with Git caching, but it's failing on unrelated stuff that I can't currently replicate on my local! So that's annoying. I'll get that fixed, and the caching deployed, and then think about further work to improve things.

It's standard practice to clear the cache on deploy, and it's in the deploy script.

Actually, it's only the application cache that's cleared when we run composer install, the cache pools are not touched unless you run ./bin/console cache:pool:clear <pools>....

I converted another Symfony tool recently to use Redis and it was pretty easy and now works much faster.

Actually, it's only the application cache that's cleared when we run composer install, the cache pools are not touched unless you run ./bin/console cache:pool:clear <pools>....

I've worked with Symfony for however many years now and never knew this... thanks! Ref: https://symfony.com/doc/current/cache.html#clearing-the-cache

I converted another Symfony tool recently to use Redis and it was pretty easy and now works much faster.

Sounds good to me!

The patches have been failing due to a peculiar issue with PHP changing how it handled XML prefixes. For example, the following code produces different output only for 8.1.21–8.1.24 and 8.2.8–8.2.11:

<?php
$dom = new DOMDocument();
$dom->loadXML('<?xml version="1.0" encoding="UTF-8"?><svg xmlns:svg="http://www.w3.org/2000/svg" xmlns="http://www.w3.org/2000/svg"><text><svg:tspan>T</svg:tspan></text></svg>');
$text = $dom->getElementsByTagName('text')[0];
$switch = $dom->createElementNS('http://www.w3.org/2000/svg', 'switch');
$text->parentNode->insertBefore($switch, $text);
$switch->appendChild($text);
echo $dom->saveXML($dom->getElementsByTagName('switch')[0]);

Output for 8.0.1 - 8.0.30, 8.1.0 - 8.1.20, 8.1.25 - 8.1.27, 8.2.0 - 8.2.7, 8.2.12 - 8.2.16, 8.3.0 - 8.3.3

<svg:switch><svg:text><svg:tspan>T</svg:tspan></svg:text></svg:switch>

Output for 8.1.21 - 8.1.24, 8.2.8 - 8.2.11

<switch><text><tspan>T</tspan></text></switch>

See it working here: https://3v4l.org/YMY6j

So I'm updating the tests to make the prefix optional, for greatest flexibility for developers working on it (and because as far as actually rendering the SVG goes either form seems to work fine). There are various other open tasks about how we handle XML prefixes in SVG Translate, so perhaps this will need revisiting at some point, but for now I just want to get things working again.

We can also update the Toolforge webservice to PHP 8.2 which will help avoid some other issues we've got with the current tests.

I've made a minimal PR that gets things running again: https://github.com/wikimedia/svgtranslate/pull/725 (ready for review)

The PHP 8.2 upgrade I think can wait; I've created T357844 for that.

I've tagged and released version 1.2.4… and something seems to be broken! The preview doesn't work now. I'm investigating.

The preview does not work in some situations, but it seems a bit flaky: it's some combination of being logged in and having selected (or not) an interface language. e.g. https://svgtranslate.toolforge.org/File:Test.svg?uselang=en-gb works, but if I then log in it doesn't. But sometimes it does! There's something weird going on with how we're passing or storing the target language in I think, because even with en-ca selected as a target language it's still sending requests to https://svgtranslate.toolforge.org/api/translate/Test.svg/en with the translations.

Anyway, this is not related to the current bug, so I've created a separate one to track it: T358305: Image preview is not updating when translations are changed

The issue of git describe timing out seems to be resolved.