I guess either @Daimona or @Huji will know better but maybe the db-patches that need to be applied for such table to be created ain't part of update.php. See https://phabricator.wikimedia.org/diffusion/EABF/browse/master/db_patches/. Thanks.

@PlavorSeol This is weird, because the abuse_filter_action table has always been included in the main schema, i.e. it's not been added with a db_patch. SQLite schema has it as well, so it should be installed during update.php. The only thing I can think of at the moment is: the update.php output ends with MCR stuff, and not with a success message. Are you sure that the script has been fully executed?

EDIT: Yeah, running update.php on my wiki shows that the last line you reported (MCR) isn't the last. After it there are still ~10 updates from core and then it starts with extensions' ones, where AF tables are created as well. Could you please confirm?

@Daimona MCR line is really the last - commond input shows again after that (please show updated description)

This shouldn't happen. MCR isn't even the last row for core updates. The only thing I can say for sure is, this isn't due to AbuseFilter, but more likely to MCR or something else in the update script, as long as you're sure that your wiki is properly configured.

Sounds like a fatal error in populateContentTables.php leaves the DB in an inconsistent state. Are there any errors in the logfile?

@PlavorSeol Please provide more details. What exact version of MediaWiki are you running? Do you have a custom setting for $wgMultiContentRevisionSchemaMigrationStage? What happens if you run update.php again? Can you manually verify that the abuse_filter_action table exists? Were you able to use AbuseFilter before this?

In T204475#4594797, @Tgr wrote:

Sounds like a fatal error in populateContentTables.php leaves the DB in an inconsistent state.

I see no evidence for that.

What I see is that somewhere after where DatabaseUpdater::populateContentTables() prints its message the script exits without any further output. The further output should come from PopulateContentTables, either printing a message to stderr before exiting (which would also exit update.php), printing "Populating revision..." before it touches the database, or printing a message about $wgMultiContentRevisionSchemaMigrationStage lacking SCHEMA_COMPAT_WRITE_NEW before returning to DatabaseUpdater.

Are there any errors in the logfile?

That's a good question. Probably whatever useful output would normally be printed to the console is somehow instead going to a log file somewhere. Or being thrown away. Without getting that output there's not too much we can do here.

1. I'm currently running MediaWiki 1.32.0-wmf.22 (previously 1.32.0-wmf.20, I just upgraded to that)
2. There is no $wgMultiContentRevisionSchemaMigrationStage in LocalSettings.php
3. Nothing different happens when I run update.php again. AbuseFilter still doesn't work.
4. I newly installed MediaWiki few days ago, AbuseFilter doesn't work from then.
5. I currently have no debug log file.

I will check more information as soon as I can.

In T204475#4599417, @PlavorSeol wrote:

1. I'm currently running MediaWiki 1.32.0-wmf.22 (previously 1.32.0-wmf.20, I just upgraded to that)

Was wmf.20 the version you originally innstalled? Did the error already occur with that version?

1. I newly installed MediaWiki few days ago, AbuseFilter doesn't work from then.

So, you installed mediawiki, then you added the AbuseFilter extension, tried to run update.php to make that work, but update.php failed? Is that the sequence of events? It's important to know which updates you did in between, which extensions you added when, and at which point you ran update.php. If we can reproduce the exact sequence, maybe we can reproduce the error.

What I did:

1. I did "fresh install" of MediaWiki 1.32.0-wmf.20 few days ago.
2. After I finished installing MediaWiki, I installed some extension (including AbuseFilter) and ran update.php.
3. Database error occured on 'Special:RecentChanges' page because update.php doesn't update AbuseFilter-related tables.
4. So I opened this issue and removed wfLoadExtension("AbuseFilter");
5. I upgraded my MediaWiki to 1.32.0-wmf.22 few hours ago.
6. I added wfLoadExtension("AbuseFilter"); again and ran update.php (to see if this issue is fixed)
7. But AbuseFilter still not working
8. So I removed wfLoadExtension("AbuseFilter"); again

This has nothing to do with AbuseFilter, I'm afraid. MCR quits update.php without reporting errors, so the needed tables aren't created and of course AbuseFilter doesn't work. Given that we don't have any output from the script, the only thing I can suggest to try is to insert some echos all through populateContentTables to approximately see in which point it stops.

@PlavorSeol if you run update.php without AbuseFilter being enabled, does it finish, or does it also hang?

Also, in step 2 of your list, you said you ran update.php. Did it complete?

...also, does the wiki have content? Was the main page created properly? Perhaps we are seeing T203982: update.php fails for wikis with zero revisions.

In T204475#4600808, @Daimona wrote:

This has nothing to do with AbuseFilter, I'm afraid.

That part is true.

MCR quits update.php without reporting errors,

I don't know where the errors are going in @PlavorSeol's setup, but there's no code path where "MCR" quits update.php without generating an error message of some sort.

Given that we don't have any output from the script, the only thing I can suggest to try is to insert some echos all through populateContentTables to approximately see in which point it stops.

I'd probably start with DatabaseUpdater::populateContentTables(). We know it's outputting the "Migrating revision data" line, and it seems reasonable it's not reaching the line that would output "done" or "errors were encountered". There are two calls in between, is it exiting during the first one or the second? Then follow things down the call stack.

In T204475#4600922, @daniel wrote:

...also, does the wiki have content? Was the main page created properly? Perhaps we are seeing T203982: update.php fails for wikis with zero revisions.

That's not the script being run here.

@daniel update.php terminates after MCR migration again even I disabled AbuseFilter:

C:\NGINX\web\PlavorEXITBeta\plavorexitbeta>"C:\PHP\php.exe" "maintenance\update.php"
MediaWiki 1.32.0-wmf.22 Updater

Your composer.lock file is up to date with current dependencies!
Going to run database updates for database
Using SQLite file: 'C:/NGINX/data/PlavorEXITBeta/database.sqlite'
Depending on the size of your database this may take a while!
Abort with control-c in the next five seconds (skip this countdown with --quick) ... 0
Turning off Content Handler DB fields for this part of upgrade.
...have ss_active_users field in site_stats table.
...ss_active_users user count set...
...have ipb_allow_usertalk field in ipblocks table.
...have initial indexes
...change_tag table already exists.
...tag_summary table already exists.
...valid_tag table already exists.
...user_properties table already exists.
...log_search table already exists.
...have log_user_text field in logging table.
...l10n_cache table already exists.
...index tag_summary_rc_id already set on tag_summary table.
...have rd_interwiki field in redirect table.
...fulltext search table appears to be in order.
...iwlinks table already exists.
...index iwl_prefix_title_from already set on iwlinks table.
...have ul_value field in updatelog table.
...have iw_api field in interwiki table.
...iwl_prefix key doesn't exist.
...have cl_collation field in categorylinks table.
...module_deps table already exists.
...ar_page_revid key doesn't exist.
...skipping index ar_revid because index ar_revid_uniq already set on archive table.
...index user_email already set on user table.
...uploadstash table already exists.
...user_former_groups table already exists.
...batch conversion of user_options: nothing to migrate. done.
...user table does not contain user_options field.
...have rev_sha1 field in revision table.
...have ar_sha1 field in archive table.
...index page_redirect_namespace_len already set on page table.
...have us_chunk_inx field in uploadstash table.
...have job_timestamp field in job table.
...index page_user_timestamp already set on revision table.
...have ipb_parent_block_id field in ipblocks table.
...index ipb_parent_block_id already set on ipblocks table.
...category table does not contain cat_hidden field.
...have rev_content_format field in revision table.
...have rev_content_model field in revision table.
...have ar_content_format field in archive table.
...have ar_content_model field in archive table.
...have page_content_model field in page table.
Content Handler DB fields should be usable now.
...site_stats table does not contain ss_admins field.
...recentchanges table does not contain rc_moved_to_title field.
...sites table already exists.
...have fa_sha1 field in filearchive table.
...have job_token field in job table.
...have job_attempts field in job table.
...have us_props field in uploadstash table.
...ug_group in table user_groups already modified by patch patch-ug_group-length-increase-255.sql.
...ufg_group in table user_former_groups already modified by patch patch-ufg_group-length-increase-255.sql.
...index pp_propname_page already set on page_props table.
...index img_media_mime already set on image table.
...index iwl_prefix_from_title already set on iwlinks table.
...have ar_id field in archive table.
...have el_id field in externallinks table.
...have rc_source field in recentchanges table.
...index log_user_text_type_time already set on logging table.
...index log_user_text_time already set on logging table.
...have page_links_updated field in page table.
...have user_password_expires field in user table.
...have pp_sortkey field in page_props table.
...recentchanges table does not contain rc_cur_time field.
...index wl_user_notificationtimestamp already set on watchlist table.
...have page_lang field in page table.
...have pl_from_namespace field in pagelinks table.
...have tl_from_namespace field in templatelinks table.
...have il_from_namespace field in imagelinks table.
...hitcounter doesn't exist.
...site_stats table does not contain ss_total_views field.
...page table does not contain page_counter field.
...fa_deleted_reason in table filearchive already modified by patch patch-editsummary-length.sql.
...msg_resource_links doesn't exist.
...msg_resource doesn't exist.
...bot_passwords table already exists.
...have wl_id field in watchlist table.
...cl_collation key doesn't exist.
...index cl_collation_ext already set on categorylinks table.
...collations up-to-date.
...index rc_name_type_patrolled_timestamp already set on recentchanges table.
...have ct_id field in change_tag table.
...have ts_id field in tag_summary table.
...have el_index_60 field in externallinks table.
...have ug_expiry field in user_groups table.
...index img_user_timestamp already set on image table.
...img_media_type in table image already modified by patch patch-add-3d.sql.
...ip_changes table already exists.
...skipping: index cl_from doesn't exist.
...skipping: index tl_from doesn't exist.
...skipping: index pl_from doesn't exist.
...skipping: index old_id doesn't exist.
...skipping: index il_from doesn't exist.
...skipping: index iwl_from doesn't exist.
...skipping: index ll_from doesn't exist.
...skipping: index ls_field_val doesn't exist.
...skipping: index md_module_skin doesn't exist.
...skipping: index keyname doesn't exist.
...skipping: index qci_type doesn't exist.
...skipping: index ss_row_id doesn't exist.
...skipping: index ufg_user_group doesn't exist.
...skipping: index user_properties_user_property doesn't exist.
...comment table already exists.
...have img_description_id field in image table.
...skipping: index lc_lang_key doesn't exist.
...content table already exists.
...content_models table already exists.
...slots table already exists.
...have slot_origin field in slots table.
...slot_roles table already exists.
...actor table already exists.
...rev_text_id in table revision already modified by patch patch-rev_text_id-default.sql.
...table site_stats already modified by patch patch-site_stats-modify.sql.
...index rc_namespace_title_timestamp already set on recentchanges table.
...change_tag_def table already exists.
...el_index_60 in table externallinks already modified by patch patch-externallinks-el_index_60-drop-default.sql.
Running maintenance/deduplicateArchiveRevId.php...
...Update 'DeduplicateArchiveRevId' already logged as completed.
done.
...have ct_tag_id field in change_tag table.
...index ar_revid_uniq already set on archive table.
Migrating revision data to the MCR 'slot' and 'content' tables, printing progress markers.
For large databases, you may want to hit Ctrl-C and do this manually with
maintenance/populateContentTables.php.

C:\NGINX\web\PlavorEXITBeta\plavorexitbeta>

@daniel There is no abuse_filter_action table in database.

I found this on debug log file (temporarily enabled debug logging and ran update.php):

IP: 127.0.0.1
Start command line script maintenance\update.php
[caches] cluster: WinCacheBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: WinCacheBagOStuff, session: WinCacheBagOStuff
[caches] LocalisationCache: using store LCStoreNull
[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.
[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {
    "IPAddress": "127.0.0.1",
    "UserAgent": false,
    "ChronologyProtection": false,
    "ChronologyPositionIndex": 0,
    "ChronologyClientId": null
}
[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

That debug info isn't really helpful...

Can you try to run maintenance/populateContentTables.php directly?

@daniel populateContentTables.php ends with no outputs.

Can't reproduce.

I installed wmf/1.32.0-wmf.20 from scratch, added AbuseFilter, and ran update.php. I completes as expected. Did the same with wmf.22. Works fine for me.

I'm using PHP 7.1.17 and MySQL 5.7.22.

@PlavorSeol the only thing I can suggest is that you try again installing from scratch, and see if the problem occurs again. If it does, there is a workaround you could try:

1. set $wgMultiContentRevisionSchemaMigrationStage = SCHEMA_COMPAT_OLD. Do not make edits while in this mode!
2. run update.php
3. remove the $wgMultiContentRevisionSchemaMigrationStage settingg again.

This may allow you to install AbuseFilter. But it won't help us to understand the problem.

I have a hunch: I see that @PlavorSeol runs MW on Windows. Maybe it's a problem with windows and Shell? I'm sure that Shell has problems with windows (see T199989 and T183759, although in this case the script seems to complete), maybe this is related? All I can suggest is, as I wrote in T204475#4600808, to add some echos and see where the execution is halted.

If it's caused by a fatal error (which is usually what causes PHP scripts to just exit without printing anything), there should be some info in the PHP error log. Or you can try running it like php -d display_errors=1 populateContentTables.php.

@Tgr Still no output...

Also update.php shows nothing different even I add -d display_errors=1 parameter:

Oh no... Nothing different shows even I set error_reporting=E_ALL, display_errors=On, $wgShowExceptionDetails=true; ,$wgShowDBErrorBacktrace=true; and $wgShowSQLErrors=true;.

@PlavorSeol Could you please add something like

echo "\nfoo\n";

at this line, run update.php, and see if "foo" is printed in the console? If so, then the error is inside populateContentTables. Otherwise, the failure is from runChild.

Oh I see you already tried to run the script alone with the same result. Then, could you please add it here and run populateContentTables?

Huh? Why it doesn't print anything?

@Daimona
String inserted in line 74 was printed, but string inserted in line 86 wasn't.

Same when running update.php

In T204475#4606656, @PlavorSeol wrote:

String inserted in line 74 was printed, but string inserted in line 86 wasn't.

Now we're getting somewhere. What if you insert a one at line 84?

If the on on line 84 is printed, then try adding more between lines 67-68 and 68-69. If the one on line 84 isn't printed, try adding one between lines 81-82.

In T204475#4606697, @Anomie wrote:

If the one on line 84 isn't printed, try adding one between lines 81-82.

Or, better, between lines 77-78.

@PlavorSeol Now we surely know that the problem is directly inside populateContentTables, so you can run it instead of update.php for debugging. The next thing to try is what Anomie suggested, then we'll probably get some sort of answer.

@Anomie

@PlavorSeol I lost row count. What comes directly after the print at line 68? $this->mainRoleId? And is there an echo after it?

@Daimona It just ends after printing at line 68, and yes, there is an echo in line 69 (which contains $this->mainRoleId):

@PlavorSeol Alright, so the problem happens in that call. I'm not expert with that code, but a simple test could be to replace line 69 with

$this->mainRoleId = MediaWikiServices::getInstance()->getSlotRoleStore();die("Success");

Please note that you need to halt execution anyway using "die" to avoid running the rest of the script.
BTW, I expect this to correctly print "success", and the problem to be inside acquireId.

@Daimona It prints "Success":

@PlavorSeol Nice. Now, you should restore the original line 69 and try the same here. I guess a good start would be to insert an echo at the beginning of every if/elseif/else and see what happens. I'm not familiar with this code, but looking at blame I guess @daniel is.

@Daimona

@PlavorSeol I didn't explain well. I meant to do the same for that function, but not at line 152. Instead, I'd add echoes at lines: 155, 158, 160, 176 and 181.

@Daimona Which should I add, echo or die?

@PlavorSeol For the moment, echo is fine.

@Daimona Only string in line 155 was printed.

I also tried to do "fresh install" another wiki with newly downloaded MediaWiki 1.32.0-wmf.22, but same thing happens.

And I also completely uninstalled and reinstalled PHP 7.2.10, but issue wasn't resolved.

@PlavorSeol Alright. If testing was done correctly, acquireId doesn't return, and thus the problem is inside getTableFromCachesOrReplica. Could be some cache issue... What are your caching options? For the moment, you may try adding prints here at lines 324, 328, and 338, and I think you'll only get 324 and 328.

@Daimona Exactly what you thought

I just changed my caching method from WinCache to APCu, and update.php updates tables related to AbuseFilter successfully.
I think update.php doesn't work correctly when using PHP WinCache extension, and it needs to be fixed because IIS users must use WinCache for caching (but I'm using NGINX).

@PlavorSeol Glad to see that the problem is resolved. I probably cannot help you any further, but at least now we know where the problem originates :-)

The understanding so far here is that MCR-related code in the Revision backend (specifically NameTableStore), is using WANObjectCache for something. And that this code works fine when using APC or Memcached as the wikis "Main" cache backend, but that it fails when using WinCache.

The running theory appears to be that the code is not relying on accidental behaviour from APC/Memc, but using only the contract as provided by WANCache, but that something in our WinCache implementation of BagOStuff (or something in Microsoft's WinCache itself) is violating that contract and thus causing the MCR-related upgrade script to act as if the wiki is empty.

The expectation seems to be that we'll find this bug in WinCacheBagOStuff and fix it, or if it resides in WinCache itself to workaround it in our abstraction layer (if possible).