The same CAPTCHA image is always used across platforms and refresh
Closed, ResolvedPublic

Description

Always seeing the same "berylenrol" captcha on acct creation even if you try to refresh it.

Noticed it late last night, but assumed it was a caching issue on the app... but I see the same captcha on desktop and mobile web too. Confirmed on Android as well.

Mhurd created this task.Mar 3 2017, 10:10 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptMar 3 2017, 10:10 PM
Tgr triaged this task as "Unbreak Now!" priority.Mar 3 2017, 10:11 PM
Restricted Application added subscribers: Jay8g, TerraCodes. · View Herald TranscriptMar 3 2017, 10:11 PM
Tgr edited the task description. (Show Details)Mar 3 2017, 10:14 PM
Tgr edited the task description. (Show Details)
Tgr added subscribers: Reedy, Tgr.

@Reedy something gone horribly wrong with captcha regeneration?

Tgr added a comment.Mar 4 2017, 12:30 AM

The sole captcha is located in the 9/9/9 hash subdirectory (could be a coincidence, especially with the digits supposedly being hexadecimal, but it's suspoicious). The only posibly related recent change was 7de460c289041e6fd729d0209c08077ab95f1b27, which seems sound.

Tgr added a comment.Mar 4 2017, 3:32 AM

Confirmed that there is only one captcha file in swift:

tgr@terbium:~$ mwscript eval.php --wiki=metawiki
> $backend = FileBackendGroup::singleton()->get( $wgCaptchaFileBackend );

> $baseDir = FileBackendGroup::singleton()->get( $wgCaptchaFileBackend )->getRootStoragePath() . '/captcha-render';

> $fl = $backend->getFileList( [ 'dir' => $baseDir ] )

> var_dump(iterator_to_array($fl))
array(1) {
  [0]=>
  string(41) "9/9/9/image_67350e1b_9996cc25d9b58fc9.png"
}

The captcha generation script does not update/clear the cache used in FancyCaptcha::pickImage*, which it probably should, but that shouldn't be able to cause anything remotely similar.

TTO changed the title from "Seeing same "berylenrol" CAPTCHA image across platforms and refresh" to "The same CAPTCHA image is always used across platforms and refresh".EditedMar 4 2017, 3:54 AM
TTO added a subscriber: TTO.

There is still only one captcha, but it has changed to gottaedify.

Better fix it quick, otherwise we'll be cutting off an income stream to those people who solve captchas for a living ;)

Mentioned in SAL (#wikimedia-operations) [2017-03-04T16:35:22Z] <Reedy> Manually generating some more captchas T159581

Reedy added a comment.Mar 4 2017, 4:42 PM

@Reedy something gone horribly wrong with captcha regeneration?

I don't think it's the generation (I'd steadily been manually generating captchas, we had about 100k at one point), I'm guessing something went wrong with the delete operation

Confirmed that there is only one captcha file in swift:

 tgr@terbium:~$ mwscript eval.php --wiki=metawiki
> $backend = FileBackendGroup::singleton()->get( $wgCaptchaFileBackend );
 
> $baseDir = FileBackendGroup::singleton()->get( $wgCaptchaFileBackend )->getRootStoragePath() . '/captcha-render';
 
> $fl = $backend->getFileList( [ 'dir' => $baseDir ] )
 
> var_dump(iterator_to_array($fl))
 array(1) {
   [0]=>
   string(41) "9/9/9/image_67350e1b_9996cc25d9b58fc9.png"
 }

FWIW, I created a script to do this for ease

reedy@terbium:~$ /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/CountFancyCaptchas.php mediawikiwiki
Current number of captchas is 1000.

Mentioned in SAL (#wikimedia-operations) [2017-03-04T16:43:25Z] <Reedy> Manually generating even more captchas (going upto 10k total) in screen as reedy on terbium T159581

Reedy lowered the priority of this task from "Unbreak Now!" to "Normal".Mar 4 2017, 4:43 PM
Reedy closed this task as "Resolved".EditedMar 4 2017, 4:52 PM
Reedy claimed this task.

Closing task as new captchas have been generated, and more are being generated in a screen session. Initial problem is fixed, parent task created for investigating the whole issue (and fixing it), along with a few other minor issues to followup/fix

JJMC89 added a subscriber: JJMC89.EditedMar 5 2017, 5:23 PM

@Reedy This issue has been reported since this task was resolved.

Not that I really mind, but over the past couple of days the captcha for IP editors does not update properly. Tonight it is "glibhaber"-- every time.

Tgr reopened this task as "Open".Mar 5 2017, 8:48 PM

Once again there is a single captcha and it has a hash starting with 999. Spooky.

Reedy added a comment.Mar 5 2017, 10:20 PM

From tee

Current number of captchas is 1001.
Generating 8999 new captchas.. Done.

Generated 8999 captchas in 1444.1 seconds
Copying the new captchas to storage...Errored.
Array
Array
Array
<snip>
Array
ArrayRemoving temporary files... Done.

Whole captchas generation process took 3096.5 seconds

Looking at the end of the screen

Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: md5_file(/tmp/mw-fancycaptcha-1488648093-5d769b/a/5/9/image_dbdbf524_a591694b8177d718.png): failed to open stream: Too many open files in /srv/mediawiki/php-1.29.0-wmf.14/includes/libs/filebackend/SwiftFileBackend.php on line 331
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220
Warning: socket_sendto(): Host lookup failed [-9999]: Unknown error -9999 in /srv/mediawiki/php-1.29.0-wmf.14/includes/debug/logger/monolog/LegacyHandler.php on line 220

Mentioned in SAL (#wikimedia-operations) [2017-03-05T22:23:41Z] <Reedy> Generating some more captchas again T159581

Reedy added a comment.Mar 5 2017, 10:34 PM

So, 1000 works fine. 10,000 doesn't. Something in the MW swift layer really doesn't like this batch operations refactoring. No idea why at this stage, whether it shouldn't be used for such large batches, or if there's some other MW/Swift bug. Of course, these can be split into batches of 1k, and done that way

However, when I ran this 10k, it wasn't being run with the --delete, so why any were deleted from swift at all is a mystery, even when the copy to storage failed....

Plus the errors why terbium (at least) doesn't seem to be able to send the logfiles where they need to go, which results in various other spam of errors

I'm wondering if the below is responsible for the array outputs above

$this->output( implode( "\n", $ret->getErrors() ) );

Still confused why we only end up with one.

Tgr added a comment.Mar 6 2017, 5:50 AM

Down to a single captcha again with 999 in the hash (9/9/9/image_7e7fe1a7_999a0e0a55004a1b.png). Could some forgotten cronjob be going wild?

Hmm, must be a manually created one, at least I haven't found any cronjob in puppet, except the one, which runs monthly and creates the CAPTCHAs.

TTO raised the priority of this task from "Normal" to "High".Mar 7 2017, 8:38 AM

This probably ought to be UBN!. With only one captcha at any given time, the system loses what little value it has.

(As an aside, today's coveypoem captcha was trivially solved by most of the free online OCR sites I tried. It really calls into question the value of the whole thing. Keeps non-Latin-alphabet-literate people out and lets smart spambots in.)

Reedy added a comment.Mar 7 2017, 12:54 PM

This is still weird. I can understand why it broke once after the first of March, as it was the first time the cronjob ran against a wiki that had ConfirmEdit. As for why it keeps breaking (other than when I ran the script, and left it in a screen.. See various filed tasks), is weird. Especially for the last one, where it had finished.

Hmm, must be a manually created one, at least I haven't found any cronjob in puppet, except the one, which runs monthly and creates the CAPTCHAs.

I'm fairly sure (but I haven't checked) there aren't any manually created ones. Before I started running the scripts this year, the captchas were a few years old. And had been a constant number all along

I just tried to create some more, upto 1,000, and it bailed out leaving 262...

Reedy added a comment.Mar 7 2017, 1:04 PM
reedy@terbium:~$ /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/GenerateFancyCaptchas.php mediawikiwiki --wordlist=/etc/fancycaptcha/words --font=/usr/share/fonts/truetype/freefont/FreeMonoBoldOblique.ttf --blacklist=/etc/fancycaptcha/badwords --fill=1000 --oldcaptcha
Current number of captchas is 262.
Generating 738 new captchas.. Done.

Generated 738 captchas in 120.1 seconds
Copying the new captchas to storage... Done.

Copied 1692 captchas to storage in 18.4 seconds
Removing temporary files... Done.

Whole captchas generation process took 138.7 seconds
reedy@terbium:~$ /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/CountFancyCaptchas.php mediawikiwiki
Current number of captchas is 1000.
reedy@terbium:~$

Going to leave it at that, pending fixes of some of the error handling/output etc

Change 341261 merged by jenkins-bot:
[mediawiki/extensions/ConfirmEdit] Fix error output

https://gerrit.wikimedia.org/r/341261

Hmm, strange. The bad thing is, that we probably don't have an easy way to find out why and who runs a script to delete the captchas. What we could do, for a first indication, is to add a logging level to the delete and regeneration scripts of ConfirmEdit, which logs the start and end time to logstash. With that information, we could at least find out, if the deletion is made by one of these scripts and especially when. Unfortunately, this is the only thing I currently can think of :/

Reedy added a comment.Mar 8 2017, 6:00 PM
reedy@terbium:~$ /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/CountFancyCaptchas.php mediawikiwiki
Current number of captchas is 1.

There's definitely something odd going on

0 1 */1 * * /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/GenerateFancyCaptchas.php enwiki --wordlist=/etc/fancycaptcha/words --font=/usr/share/fonts/truetype/freefont/FreeMonoBoldOblique.ttf --blacklist=/etc/fancycaptcha/badwords --fill=10000 --oldcaptcha --delete >/dev/null 2>&1

I think there's some problem with the cron here...

"At 01:00 on every day-of-month."

The cron is running every day, but it shouldn't be!

Let's fix that in the first instance

Change 341823 had a related patch set (by Reedy) published:
Actually run generatecaptcha cronjob on 1st day of every month

https://gerrit.wikimedia.org/r/341823

Reedy added a comment.Mar 8 2017, 6:08 PM

I'm guessing this has been running for a while, every day... Just when the script worked, all was fine. When enwiki was changed to using the new version of the script... I guess on the 2nd March, all hell started breaking loose

Change 341823 merged by Dzahn:
[operations/puppet] mediawiki::maintenance: Actually run generatecaptcha cronjob on 1st day of every month

https://gerrit.wikimedia.org/r/341823

Reedy added a comment.Mar 8 2017, 6:15 PM

Much fun is to be had...

reedy@terbium:~$ /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/GenerateFancyCaptchas.php mediawikiwiki --wordlist=/etc/fancycaptcha/words --font=/usr/share/fonts/truetype/freefont/FreeMonoBoldOblique.ttf --blacklist=/etc/fancycaptcha/badwords --fill=1000 --oldcaptcha
Current number of captchas is 1.
Generating 999 new captchas.. Done.

Generated 999 captchas in 159.7 seconds
Copying the new captchas to storage...Errored.
Warning: implode(): Invalid arguments passed in /srv/mediawiki/php-1.29.0-wmf.15/extensions/ConfirmEdit/maintenance/GenerateFancyCaptchas.php on line 197
Removing temporary files... Done.

Whole captchas generation process took 564.4 seconds
reedy@terbium:~$ /usr/local/bin/mwscript extensions/ConfirmEdit/maintenance/CountFancyCaptchas.php mediawikiwiki
Current number of captchas is 242.
reedy@terbium:~$

Change 341827 merged by jenkins-bot:
[mediawiki/extensions/ConfirmEdit] Fix error output

https://gerrit.wikimedia.org/r/341827

Reedy closed this task as "Resolved".Mar 9 2017, 2:33 PM

Ok, I'm gonna close this task again. The problem (wrong cronjob) causing the jobs to be deleted has been fixed; and we didn't go back to 1 overnight

Other tasks can/will be used for further debugging, testing etc