Page MenuHomePhabricator

mediawiki_job_generatecaptcha maintenance job fails to run
Closed, ResolvedPublic

Description

The last two runs of mediawiki_job_generatecaptcha have failed in production with the following error:

Mar  4 09:41:00 mwmaint2002 mediawiki_job_generatecaptcha[41908]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223

Feb 26th run was able to be re-started manually during the day, and finished without errors. The last one (Mar 4th) was restarted twice without being able to do a complete run. It actually failed earlier in the script loop on the second attempt.

Event Timeline

Clement_Goubert triaged this task as Unbreak Now! priority.Mar 4 2024, 10:01 AM
Clement_Goubert added subscribers: Reedy, bvibber.

I think this is technically a dupe of T230245: Make SwiftFileBackend::doStoreInternal defer the opening of file handles to stay in the concurrency limit.

But FormatJson fails like this (not exactly the same) happen in other contexts too, T307816: Installing MediaWiki: Error: Class "FormatJson" not found along with various other closed bugs

And if it is... We could just shrink the batch sizes again, the last one fixed it for ~4.5 years ;).

Having said that, there is a patch for T230245 at https://gerrit.wikimedia.org/r/c/mediawiki/core/+/606017 which has been there since June 2020. It rebases cleanly onto master, but hasn't really been properly reviewed since the last changes/improvements (ie some earlier -1s).

It seems reasonable on the face...

On T307816: Installing MediaWiki: Error: Class "FormatJson" not found, Tim says: "Maybe something in this file triggers an opcache bug." I don't really have a better idea...

Do we know if this error correlates to deployments?

Do we know if this error correlates to deployments?

It doesn't.

T230245#6229708, T230245#6229871

As I just wrote on T307816, it's not an opcache bug. The file handle limit is exceeded, then it tries to report an error without closing any of the file handles, so error reporting also fails.

As I just wrote on T307816, it's not an opcache bug. The file handle limit is exceeded, then it tries to report an error without closing any of the file handles, so error reporting also fails.

OK, so T307816 may actually be an opcache bug, considering it goes away if you touch the file. But this is not an opcache bug. Just to put it fully beyond doubt, I reproduced it locally, by setting the FD limit to 100 and then trying to generate 100 files. I just had to patch it to load the Psr\Log\LogLevel class before uploading the batch. Then any kind of error with this script leads to FormatJson.php being the first file subsequently opened, and you get the exact error message reported in the task description.

I assume we're just waiting for the wmf.22 train deployment to reach enwiki before we close the task as resolved.

thcipriani subscribed.

I assume we're just waiting for the wmf.22 train deployment to reach enwiki before we close the task as resolved.

wmf.23 is rolling out this week, can anyone confirm this is now resolved?

https://gerrit.wikimedia.org/r/c/mediawiki/core/+/606017 was in wmf/1.42.0-wmf.22, and the script only runs once a week on a Monday:

profile::mediawiki::periodic_job { 'generatecaptcha':
    command  => '/usr/local/bin/captchaloop',
    interval => 'Mon 01:00',
}

So in theory, this weeks run will have been with the patch in .22...

Last weeks worked fine though too?

reedy@mwmaint2002:/var/log/mediawiki/mediawiki_job_generatecaptcha$ tail -n 200 syslog.log 
Mar  4 09:53:23 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Whole captchas generation process took 47.8 seconds
Mar  4 09:53:23 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 900.
Mar  4 09:53:24 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 900 new captchas.. Done.
Mar  4 09:53:24 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 900 captchas in 0.8 seconds
Mar  4 09:53:33 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage... Done.
Mar  4 09:53:33 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copied 900 captchas to storage in 9.3 seconds
Mar  4 09:53:33 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Removing temporary files... Done.
Mar  4 09:53:33 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Whole captchas generation process took 10.2 seconds
Mar  4 09:53:33 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:34 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 900 new captchas.. Failed.
Mar  4 09:53:34 mwmaint2002 mediawiki_job_generatecaptcha[39123]: An error occurred when running captcha.py.
Mar  4 09:53:35 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:36 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 1800 new captchas.. Done.
Mar  4 09:53:36 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 1800 captchas in 1.4 seconds
Mar  4 09:53:36 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:53:37 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:39 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 2700 new captchas.. Done.
Mar  4 09:53:39 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 2700 captchas in 2.1 seconds
Mar  4 09:53:39 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:53:40 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:42 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 3600 new captchas.. Done.
Mar  4 09:53:42 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 3600 captchas in 2.6 seconds
Mar  4 09:53:43 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:53:43 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:46 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 4500 new captchas.. Failed.
Mar  4 09:53:46 mwmaint2002 mediawiki_job_generatecaptcha[39123]: An error occurred when running captcha.py.
Mar  4 09:53:47 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:50 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 5400 new captchas.. Done.
Mar  4 09:53:50 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 5400 captchas in 3.7 seconds
Mar  4 09:53:51 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:53:51 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:53:56 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 6300 new captchas.. Done.
Mar  4 09:53:56 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 6300 captchas in 4.5 seconds
Mar  4 09:53:57 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:53:57 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:54:02 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 7200 new captchas.. Done.
Mar  4 09:54:02 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 7200 captchas in 5.0 seconds
Mar  4 09:54:03 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:54:03 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Current number of captchas is 1800.
Mar  4 09:54:09 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generating 8100 new captchas.. Done.
Mar  4 09:54:09 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Generated 8100 captchas in 5.7 seconds
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Copying the new captchas to storage...Fatal error: require(): Failed opening required '/srv/mediawiki/php-1.42.0-wmf.20/includes/json/FormatJson.php' (include_path='/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/console_getopt:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/mail_mime:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_smtp:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_socket:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/net_url2:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear-core-minimal/src:/srv/mediawiki/php-1.42.0-wmf.20/vendor/pear/pear_exception:/srv/mediawiki/php-1.42.0-wmf.20:/usr/local/lib/php:/usr/share/php') in /srv/mediawiki/php-1.42.0-wmf.20/includes/AutoLoader.php on line 223
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]: Traceback (most recent call last):
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]:   File "/usr/local/bin/mw-cli-wrapper", line 61, in <module>
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]:     subprocess.run(cmd, check=True, shell=True)
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]:   File "/usr/lib/python3.7/subprocess.py", line 487, in run
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]:     output=stdout, stderr=stderr)
Mar  4 09:54:10 mwmaint2002 mediawiki_job_generatecaptcha[39123]: subprocess.CalledProcessError: Command '/usr/local/bin/captchaloop' returned non-zero exit status 255.
Mar 11 01:00:01 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:00:01 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.7 seconds
Mar 11 01:00:01 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Getting a list of old captchas to delete... Done.
Mar 11 01:00:16 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:00:16 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 15.2 seconds
Mar 11 01:00:16 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Deleting 1800 old captchas...
Mar 11 01:00:40 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Done.
Mar 11 01:00:40 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Deleted 1800 old captchas in 23.6 seconds
Mar 11 01:00:40 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:00:40 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 39.6 seconds
Mar 11 01:00:40 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 900.
Mar 11 01:00:41 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:00:41 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:01:00 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:01:00 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 18.8 seconds
Mar 11 01:01:00 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:01:00 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 19.8 seconds
Mar 11 01:01:00 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 1800.
Mar 11 01:01:01 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:01:01 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:01:17 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:01:17 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 15.4 seconds
Mar 11 01:01:17 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:01:17 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 16.4 seconds
Mar 11 01:01:17 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 2700.
Mar 11 01:01:18 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:01:18 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:01:36 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:01:36 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 18.3 seconds
Mar 11 01:01:36 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:01:36 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 19.3 seconds
Mar 11 01:01:36 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 3600.
Mar 11 01:01:37 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:01:37 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:01:55 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:01:55 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 18.0 seconds
Mar 11 01:01:55 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:01:55 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 19.0 seconds
Mar 11 01:01:56 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 4500.
Mar 11 01:01:57 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:01:57 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:02:14 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:02:14 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 17.3 seconds
Mar 11 01:02:14 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:02:14 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 18.4 seconds
Mar 11 01:02:14 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 5400.
Mar 11 01:02:15 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:02:15 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:02:43 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:02:43 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 27.5 seconds
Mar 11 01:02:43 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:02:43 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 28.5 seconds
Mar 11 01:02:43 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 6300.
Mar 11 01:02:44 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:02:44 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:03:03 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:03:03 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 18.7 seconds
Mar 11 01:03:03 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:03:03 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 19.8 seconds
Mar 11 01:03:03 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 7200.
Mar 11 01:03:04 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:03:04 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:03:19 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:03:19 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 15.1 seconds
Mar 11 01:03:19 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:03:19 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 16.2 seconds
Mar 11 01:03:20 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 8100.
Mar 11 01:03:20 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:03:20 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:03:48 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:03:48 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 27.4 seconds
Mar 11 01:03:48 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:03:48 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 28.5 seconds
Mar 11 01:03:48 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Current number of captchas is 9000.
Mar 11 01:03:49 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generating 900 new captchas.. Done.
Mar 11 01:03:49 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Generated 900 captchas in 0.8 seconds
Mar 11 01:04:11 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copying the new captchas to storage... Done.
Mar 11 01:04:11 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Copied 900 captchas to storage in 21.6 seconds
Mar 11 01:04:11 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Removing temporary files... Done.
Mar 11 01:04:11 mwmaint2002 mediawiki_job_generatecaptcha[15705]: Whole captchas generation process took 22.7 seconds
Mar 18 01:00:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 900 new captchas.. Done.
Mar 18 01:00:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 900 captchas in 0.8 seconds
Mar 18 01:00:02 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Getting a list of old captchas to delete... Done.
Mar 18 01:00:11 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:00:11 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 900 captchas to storage in 9.2 seconds
Mar 18 01:00:11 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Deleting 9900 old captchas...
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Errored.
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An unknown error occurred in storage backend "global-swift-codfw".
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 144.5 seconds
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 902.
Mar 18 01:02:26 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 898 new captchas.. Done.
Mar 18 01:02:26 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 898 captchas in 0.8 seconds
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage...Errored.
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An unknown error occurred in storage backend "global-swift-codfw".
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 16.0 seconds
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 1797.
Mar 18 01:02:42 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Failed.
Mar 18 01:02:42 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An error occurred when running captcha.py.
Mar 18 01:02:43 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 1797.
Mar 18 01:02:44 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 1803 new captchas.. Done.
Mar 18 01:02:44 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 1803 captchas in 1.5 seconds
Mar 18 01:03:10 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:03:10 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 1800 captchas to storage in 25.4 seconds
Mar 18 01:03:10 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:03:10 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 27.1 seconds
Mar 18 01:03:10 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 3597.
Mar 18 01:03:11 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Done.
Mar 18 01:03:11 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 903 captchas in 0.9 seconds
Mar 18 01:03:27 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:03:27 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 900 captchas to storage in 15.8 seconds
Mar 18 01:03:27 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:03:27 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 16.9 seconds
Mar 18 01:03:27 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 4497.
Mar 18 01:03:28 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Done.
Mar 18 01:03:28 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 903 captchas in 0.8 seconds
Mar 18 01:03:45 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:03:45 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 900 captchas to storage in 16.7 seconds
Mar 18 01:03:45 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:03:45 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 17.7 seconds
Mar 18 01:03:45 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 5397.
Mar 18 01:03:46 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Done.
Mar 18 01:03:46 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 903 captchas in 0.8 seconds
Mar 18 01:04:00 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:04:00 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 900 captchas to storage in 13.7 seconds
Mar 18 01:04:00 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:04:00 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 14.7 seconds
Mar 18 01:04:00 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 6297.
Mar 18 01:04:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Failed.
Mar 18 01:04:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An error occurred when running captcha.py.
Mar 18 01:04:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 6297.
Mar 18 01:04:03 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 1803 new captchas.. Done.
Mar 18 01:04:03 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 1803 captchas in 1.4 seconds
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage...Errored.
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An unknown error occurred in storage backend "global-swift-codfw".
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 34.5 seconds
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 8095.
Mar 18 01:04:37 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 905 new captchas.. Done.
Mar 18 01:04:37 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 905 captchas in 0.8 seconds
Mar 18 01:04:56 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:04:56 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 904 captchas to storage in 19.3 seconds
Mar 18 01:04:56 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:04:56 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 20.5 seconds
Mar 18 01:04:57 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Current number of captchas is 8999.
Mar 18 01:04:58 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 901 new captchas.. Done.
Mar 18 01:04:58 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 901 captchas in 0.8 seconds
Mar 18 01:05:24 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage... Done.
Mar 18 01:05:24 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copied 900 captchas to storage in 25.8 seconds
Mar 18 01:05:24 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Removing temporary files... Done.
Mar 18 01:05:24 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Whole captchas generation process took 27.0 seconds
reedy@mwmaint2002:/var/log/mediawiki/mediawiki_job_generatecaptcha$

There's a handful of vague (and different) errors in there from this weeks:

reedy@mwmaint2002:/var/log/mediawiki/mediawiki_job_generatecaptcha$ tail -n 75 syslog.log | grep -i -B 1 error
Mar 18 01:00:11 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Deleting 9900 old captchas...
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Errored.
Mar 18 01:02:25 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An unknown error occurred in storage backend "global-swift-codfw".
--
Mar 18 01:02:26 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 898 captchas in 0.8 seconds
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage...Errored.
Mar 18 01:02:41 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An unknown error occurred in storage backend "global-swift-codfw".
--
Mar 18 01:02:42 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Failed.
Mar 18 01:02:42 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An error occurred when running captcha.py.
--
Mar 18 01:04:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generating 903 new captchas.. Failed.
Mar 18 01:04:01 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An error occurred when running captcha.py.
--
Mar 18 01:04:03 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Generated 1803 captchas in 1.4 seconds
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: Copying the new captchas to storage...Errored.
Mar 18 01:04:36 mwmaint2002 mediawiki_job_generatecaptcha[31793]: An unknown error occurred in storage backend "global-swift-codfw".

T360653 should improve the error output related to running captcha.py

For the An unknown error occurred in storage backend "global-swift-codfw", that's going to be digging around in Swift logs, and/or changing something in the swift code inside MediaWiki

The account creation team is seeing an increased volume of requests reporting captcha errors "Incorrect or missing CAPTCHA's" recently.

The account creation team is seeing an increased volume of requests reporting captcha errors "Incorrect or missing CAPTCHA's" recently.

You’re going to have to give more information/examples than that for anyone to be able to help…

The account creation team is seeing an increased volume of requests reporting captcha errors "Incorrect or missing CAPTCHA's" recently.

You’re going to have to give more information/examples than that for anyone to be able to help…

Since your entry in to the SAL at 18:00: reedy@deploy1002: Synchronized php-1.42.0-wmf.23/extensions/ConfirmEdit/maintenance/GenerateFancyCaptchas.php: T360653 (duration: 16m 00s)

We at ACC have had 18 requests, at least 13 of those with a comment identifying the captcha on [[Special:CreateAccount]] as not working correctly.

When I tested, indeed, I get 'Incorrect or missing CAPTCHA.' even though the entry is absolutely correct

I don’t know if you’re just using my deploy as a line in the sand, or you’re blaming it…

If it’s the latter, that patch is completely irrelevant. It is run once a week, via cron on a Monday. Today is Thursday, and won’t be run for a few days.

The account creation team is seeing an increased volume of requests reporting captcha errors "Incorrect or missing CAPTCHA's" recently.

Moved to T360717: HTMLForm hidden fields gone -- CAPTCHA failure rate at 100%

Dumping this over here too, as it's probably more relevant (and potentially some of the errors in the log)

I get this sometimes:

An error occurred when running captcha.py:
multiprocessing.pool.RemoteTraceback: 
"""
Traceback (most recent call last):
  File "/usr/lib/python3.7/multiprocessing/pool.py", line 121, in worker
    result = (True, func(*args, **kwds))
  File "/usr/lib/python3.7/multiprocessing/pool.py", line 44, in mapstar
    return list(map(*args))
  File "/srv/mediawiki/php-1.42.0-wmf.23/extensions/ConfirmEdit/captcha.py", line 275, in run_in_thread
    subdir = gen_subdir(opts.output, md5hash, opts.dirs)
  File "/srv/mediawiki/php-1.42.0-wmf.23/extensions/ConfirmEdit/captcha.py", line 168, in gen_subdir
    os.mkdir(fulldir)
FileExistsError: [Errno 17] File exists: '/tmp/mw-fancycaptcha-1711055439-de0840/3/1'
"""

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/srv/mediawiki/php-1.42.0-wmf.23/extensions/ConfirmEdit/captcha.py", line 426, in <module>
    p.map(run_in_thread, data)
  File "/usr/lib/python3.7/multiprocessing/pool.py", line 268, in map
    return self._map_async(func, iterable, mapstar, chunksize).get()
  File "/usr/lib/python3.7/multiprocessing/pool.py", line 657, in get
    raise self._value
FileExistsError: [Errno 17] File exists: '/tmp/mw-fancycaptcha-1711055439-de0840/3/1'
tstarling claimed this task.

The logs show that there have been no more instances of "Failed opening required '...FormatJson.php'. Other ConfirmEdit-related issues can be discussed elsewhere.