Page MenuHomePhabricator
Paste P35364

Debugging notes for T238025
ActivePublic

Authored by Chlod on Oct 5 2022, 4:04 PM.
Tags
None
Referenced Files
F35548343: Debugging notes for T238025
Oct 5 2022, 4:04 PM
Subscribers
== BEGINNING DEBUG FOR T238025
Issue: PageTriage is not properly creating AfD pages
The common thing between all of the examples in T238025:
- log already exists
- 1st nom
ATTEMPTING REPLICATION:
- $wgMetaNamespace set to "Wikipedia"
- "Wikipedia:Articles for deletion/Log/2022 October 5" created
- Always going to be first nom
- mwdev.chlod.local
- `?...&debug=true`
- All tests avoid saving to the log page, because no log page wikitext was set (because `Template:afd3` doesn't exist).
---
CASE 1:
Title: Random
Log: Exists
Page is tagged, various logs updated, Articles for Deletion page is created
- TAGGING FAILED BUT DID NOT CAUSE DESTRUCTIVE ISSUE
REPLICATION FAIL
---
CASE 2:
Title: Random2
Log: Exists
Page is tagged, various logs updated, Articles for Deletion page is created
REPLICATION FAIL
---
CASE 3:
Title: Random3
Log: Exists
console.log has been added in multiple places to assess when promises get created, functions get called, etc.
LOG OUTPUT:
```
REPLICATE START load.php:2692:17
logPage: start load.php:2893:11
Object { abort: abort(statusText), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
undefined load.php:1991:10
$.when.apply load.php:2717:15
XHRGEThttps://mwdev.chlod.local/api.php?action=query&format=json&prop=revisions&titles=Wikipedia:Articles for deletion/Log/2022 October 5&rvprop=content
[HTTP/1.1 200 OK 563ms]
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 3104ms]
logPage: addToLog load.php:2913:16
addToLog: load.php:2939:11
Object { abort: abort(), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 926ms]
addToLog: success load.php:2963:14
addToLog: discussionPage load.php:2966:15
discussionPage: start load.php:2986:11
discussionPage: posting load.php:3004:11
Object { abort: abort(), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add() }
```
Page is tagged, various logs updated, Articles for Deletion page is created
REPLICATION FAIL, but vital data gathered
RESULTS:
From the output above, it seems that PageTriage assumes that the entire process is done as long as logPage has been run,
which doesn't sound right.
ADD: It seems `actionQueue` actually handles this. Will investigate further.
---
CASE 4:
Title: Random4
Log: Exists
Added more test and debug points
LOG OUTPUT:
```
REPLICATE START load.php:2692:17
logPage: start load.php:2901:11
Object { abort: abort(statusText), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
undefined load.php:1991:10
actionQueue.mark load.php:2707:15
Object { reviewed: true, reviewer: "Chlod" }
load.php:1991:10
actionQueue.delete load.php:2713:14
Object { tags: {…} }
load.php:1991:10
$.when.apply load.php:2719:15
tagPage: start load.php:2765:11
Object { abort: abort(), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
undefined load.php:1991:10
XHRGEThttps://mwdev.chlod.local/api.php?action=query&format=json&prop=revisions&titles=Wikipedia:Articles for deletion/Log/2022 October 5&rvprop=content
[HTTP/1.1 200 OK 595ms]
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 3174ms]
logPage: addToLog load.php:2921:16
addToLog: start load.php:2947:11
Object { abort: abort(), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 960ms]
addToLog: success load.php:2971:14
addToLog: discussionPage load.php:2974:15
discussionPage: start load.php:2994:11
discussionPage: posting load.php:3012:11
Object { abort: abort(), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 2066ms]
tagPage: notifyUser load.php:2830:14
notifyUser: start load.php:2850:11
XHRGEThttps://mwdev.chlod.local/api.php?action=query&format=json&formatversion=2&prop=info&titles=User_talk:127.0.0.1
[HTTP/1.1 200 OK 542ms]
Object { state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 1735ms]
Navigated to https://mwdev.chlod.local/index.php?title=Random4&debug=true
notifyUser: runAndRefresh load.php:2886:13
RELOADING NOW!
```
RESULTS:
Page is tagged, various logs updated, Articles for Deletion page is created
I'm leaning that my previous assessment in case 3 was true. To prove this, I'll add a forced delay to addToLog to prevent
it from calling discussionPage for another 10 seconds. Will NOT throttle on Firefox DevTools. My reasoning for this is that
the debugger is probably halting the sequence responsible for making the posting, but I so far can't prove this without
definitively halting the process with a delay and seeing what happens. Will also add more debug points to the queue, since I'm
not exactly sure how that one works.
---
CASE 5:
Title: Random5
Log: Exists
```
REPLICATE START load.php:2698:17
logPage: start load.php:2907:11
Object { abort: abort(statusText), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
undefined load.php:1991:10
actionQueue.mark load.php:2713:15
Object { reviewed: true, reviewer: "Chlod" }
load.php:1991:10
actionQueue.delete load.php:2719:14
Object { tags: {…} }
load.php:1991:10
$.when.apply load.php:2725:15
tagPage: start load.php:2771:11
Object { abort: abort(), state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
undefined load.php:1991:10
XHRGEThttps://mwdev.chlod.local/api.php?action=query&format=json&prop=revisions&titles=Wikipedia:Articles for deletion/Log/2022 October 5&rvprop=content
[HTTP/1.1 200 OK 545ms]
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 3228ms]
logPage: addToLog load.php:2927:16
addToLog: start load.php:2953:11
Object { state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
tagPage: notifyUser load.php:2836:14
notifyUser: start load.php:2856:11
XHRGEThttps://mwdev.chlod.local/api.php?action=query&format=json&formatversion=2&prop=info&titles=User_talk:127.0.0.1
[HTTP/1.1 200 OK 414ms]
Object { state: state(), always: always(), catch: catch(fn), pipe: pipe(), then: then(onFulfilled, onRejected, onProgress), promise: promise(obj), progress: add(), done: add(), fail: add()
}
load.php:1991:10
XHRPOSThttps://mwdev.chlod.local/api.php
[HTTP/1.1 200 OK 1637ms]
notifyUser: runAndRefresh load.php:2892:13
runAndRefresh: start ext.pageTriage.actionQueue.js:194:12
Object { action: {…}, data: {…} }
load.php:1991:10
iterableActionNames
Array [ "mark", "delete" ]
ext.pageTriage.actionQueue.js:115:12
runAllInAction: promises
Array []
ext.pageTriage.actionQueue.js:137:12
RELOADING NOW!
```
RESULTS: REPLICATION!!!
- submit: Marked reviewed (log)
- tagPage: AfD template added on page
- pagetriage-curation (log)
- pagetriage-deletion (log)
- notifyUser: User notified
- RELOAD CALLED
The proposed solution for this, and the solution that I've been eyeing since the start, is returning the deferreds
in a chain. `.then` would actually be the better function for this, since it intentionally creates promise chains.
This means reversing the `.fail` to go at the start.
Redoing, to ensure this isn't a fluke.
---
CASE 6:
Title: Random6
Log: Exists
RESULTS: REPLICATION!!!
Will `git reset --hard HEAD` to reset changes, and then perform the above changes. Will also do the delay thing
later on to replicate.
ADD: I just did `git reset --hard HEAD`. I probably should have stashed instead. Oh well.
ADD: I'll attempt to replicate this one last time with JUST the delay to see if I introduced any possible cause.
---
CASE 7:
Title: Random7
Log: Exists
Specific diff:
```
diff --git a/modules/ext.pageTriage.views.toolbar/delete.js b/modules/ext.pageTriage.views.toolbar/delete.js
index 094ac2e..ac7cc60 100644
--- a/modules/ext.pageTriage.views.toolbar/delete.js
+++ b/modules/ext.pageTriage.views.toolbar/delete.js
@@ -899,7 +899,11 @@ module.exports = ToolView.extend( {
var that = this,
title = specialDeletionTagging[ tagObj.tag ].getLogPageTitle( tagObj.prefix );
- new mw.Api().get( {
+ (function() {
+ var defer = $.Deferred();
+ setTimeout(function() { defer.resolve(); }, 5000);
+ return defer;
+ })().then( function () { return new mw.Api().get( {
action: 'query',
prop: 'revisions',
titles: title,
@@ -924,7 +928,7 @@ module.exports = ToolView.extend( {
.fail( function () {
// If log page is missing, skip ahead to making the AFD/MFD page
that.discussionPage( tagObj );
- } );
+ } ) } );
},
/**
```
No logging data this round. Will base on RecentChanges log.
RESULTS: REPLICATION FAIL
ADD: I just noticed that I fucked up the placement and ended up delaying logPage instead. Changing this to
delay addToLog. Also bumping the time by 10 seconds.
---
CASE 8:
Title: Random8
Log: Exists
Specific diff:
```
diff --git a/modules/ext.pageTriage.views.toolbar/delete.js b/modules/ext.pageTriage.views.toolbar/delete.js
index 094ac2e..36f37c3 100644
--- a/modules/ext.pageTriage.views.toolbar/delete.js
+++ b/modules/ext.pageTriage.views.toolbar/delete.js
@@ -899,7 +899,7 @@ module.exports = ToolView.extend( {
var that = this,
title = specialDeletionTagging[ tagObj.tag ].getLogPageTitle( tagObj.prefix );
- new mw.Api().get( {
+ return new mw.Api().get( {
action: 'query',
prop: 'revisions',
titles: title,
@@ -954,7 +954,11 @@ module.exports = ToolView.extend( {
return;
}
- new mw.Api().postWithToken( 'csrf', request )
+ (function() {
+ var defer = $.Deferred();
+ setTimeout(function() { defer.resolve(); }, 10000);
+ return defer;
+ })().then( function () { return new mw.Api().postWithToken( 'csrf', request )
.done( function ( data ) {
if ( data.edit && data.edit.result === 'Success' ) {
// If AFD or MFD, make page. Else we're done for now.
@@ -967,7 +971,7 @@ module.exports = ToolView.extend( {
} )
.fail( function () {
that.handleError( mw.msg( 'pagetriage-del-log-page-adding-error' ) );
- } );
+ } ) } );
},
/**
```
RESULTS: REPLICATION!!!
Will now perform changes in CASE 5 comments. I'm not going to change tagPage and related functions, since they
execute on time despite not having proper `.then`s due to [[callback hell]]. Following the virtue of fixing the
bug exclusively, I won't touch that part.
Assuming that this quote from StackOverflow is true:
```js
promise.then( doneCallback, failCallback )
// was equivalent to
promise.done( doneCallback ).fail( failCallback )
```
I'll try returning the promises returned by the subsequent functions in all `.done` callbacks. Hopefully this
will attach that promise to the promise chain, and subsequently force it to finish first. I'll also add two log
points to check if things ran correctly: one when `discussionPage` finishes, and another when `tagPage` begins.
Testing this without the delay first, and then reintroducing the delay.
==================
PATCH TESTS
---
PATCH 1:
logPage and addToLog now return this promises, their `.done` callbacks now return the promise of the
inner function called.
RESULTS (CONTROL): Success.
Title: Random9
Log: Exists
NOTE: Control test to see if the flow works perfectly. Not attempting to replicate bug yet.
- pagetriage-curation
- tagged (tagPage)
- pagetriage-curation
- pagetriage-deletion
- AfD page created
- User notified
RESULTS (REPLICATION): Failed due to replication attempt failure.
Title: Random10
Log: Exists
I forgot to return the promise that creates the delay, thus it's never awaited for. Fixing this real quick.
RESULTS (REPLICAITON): FAILED.
Title: Random11
Log: Exists
Still not awaited for. I'm feeling that the quote from earlier is false. I'll try a different route.
---
PATCH 2:
logPage and addToLog now return this promises, their `.done` and `.fail` callbacks
have been modified to use `.then` instead (which createse a new promise for chaining,
compared to using the original Deferred) and return the promise of the inner function called.
I have an inklink feeling this still won't work, and that's if we have promises that resolve
promises. We'll see, though.
RESULTS (CONTROL): Success.
Title: Random12, Random13
Log: Exists
NOTE: Control test to see if the flow works perfectly. Not attempting to replicate bug yet.
- pagetriage-curation
- tagged (tagPage)
- pagetriage-curation
- pagetriage-deletion
- AfD page created
- User notified
RESULTS (REPLICATION): SUCCESS!
Title: Random14
Log: Exists
Timeout was set to 10 seconds. Browser properly waited for completion until proceeding. Thank God.
Uploading this patch to Gerrit now. QED October 5, 2022 11:47 PM (UTC+8)!