PhantomTech created this task. PhantomTech added a subscriber: PhantomTech. PhantomTech added a project: pywikibot-core. Restricted Application added subscribers: Aklapper, pywikipedia-bugs.
TASK DESCRIPTION No problems running locally but when on labs using getcurrenttime() is causing issues. getcurrenttime() always seems to be returning the same time, deleting everything in apicache makes the time update once but then it goes back to repeating so it's probably a caching issue.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: PhantomTech Cc: pywikipedia-bugs, Aklapper, PhantomTech, jayvdb
PhantomTech edited the task description. PhantomTech raised the priority of this task from "High" to "Unbreak Now!". PhantomTech set Security to None.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: PhantomTech Cc: pywikipedia-bugs, Aklapper, PhantomTech, jayvdb
PhantomTech edited the task description.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: PhantomTech Cc: pywikipedia-bugs, Aklapper, PhantomTech, jayvdb
XZise added a subscriber: XZise. XZise added a project: Labs. XZise added a comment.
Maybe the version on https://phabricator.wikimedia.org/tag/labs/ is outdated? Is it possible to look in the code on labs and check if site.py does contain the same code as the current version on git? I'm not sure but I think the _is_expired method was at some point checking in the wrong direction (or something like that).
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise Cc: XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
XZise added a comment.
Okay 75e5834d1a7a19940e19708e00a4f3e5e615d199 https://github.com/wikimedia/pywikibot-core/commit/75e5834d1a7a19940e19708e00a4f3e5e615d199 did fix something along the lines, so please check that first. I'll lower the priority by the way because defining it as a bug author doesn't make sense because the bug author always wants it to get fixed.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise Cc: XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
XZise changed the title from "Time issue" to "On labs Siteinfo is caching time sensitive stuff". XZise lowered the priority of this task from "Unbreak Now!" to "Normal". XZise claimed this task.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise Cc: XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
XZise added a comment.
Do you delete the apicache and restart the script or do you delete it while the script runs? You could also (unlike other want to tell you) disable the apicache by setting `API_config_expiry = 0` in your `user-config.py`. Okay in https://phabricator.wikimedia.org/rPWBC75e5834d1a7a19940e19708e00a4f3e5e615d... the change wasn't anywhere near 1220. So I guess the line number was a guess? What is interesting that it only fails the second time. Also does https://phabricator.wikimedia.org/rPWBC75e5834d1a7a19940e19708e00a4f3e5e615d... probably not apply to this case but I was certain at some point the cache was backwards … hugh.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise Cc: XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
valhallasw added a subscriber: valhallasw. valhallasw added a comment.
With a clear apicache, the following requests are made:
1. 2015-03-28 11:33:26 threadedhttp.py, 215 in request: DEBUG ('https://en.wikipedia.org/w/api.php', 'POST', 'maxlag=5&format=json&meta=siteinfo%7Cuserinfo&action=query&siprop=namespaces%7Cnamespacealiases%7Cgeneral&uiprop=blockinfo%7Chasmsg', {'connection': 'keep-alive', 'Content-Type': 'application/x-www-form-urlencoded', 'user-agent': u'test1 (wikipedia:en; User:Valhallasw) Pywikibot/2.0b2 (g4338) httplib2/0.8 Python/2.7.6.final.0'}, 5, None) 2. 2015-03-28 11:33:26 threadedhttp.py, 215 in request: DEBUG ('https://en.wikipedia.org/w/api.php', 'POST', 'action=query&meta=userinfo&maxlag=5&uiprop=blockinfo%7Cgroups%7Chasmsg%7Crights&format=json', {'cookie': 'GeoIP=::::v4', 'connection': 'keep-alive', 'Content-Type': 'application/x-www-form-urlencoded', 'user-agent': u'test1 (wikipedia:en; User:Valhallasw) Pywikibot/2.0b2 (g4338) httplib2/0.8 Python/2.7.6.final.0'}, 5, None) 3. 2015-03-28 11:33:26 threadedhttp.py, 215 in request: DEBUG ('https://en.wikipedia.org/w/api.php', 'POST', 'action=query&meta=userinfo&maxlag=5&uiprop=blockinfo%7Cgroups%7Chasmsg%7Crights&format=json', {'cookie': 'GeoIP=::::v4', 'connection': 'keep-alive', 'Content-Type': 'application/x-www-form-urlencoded', 'user-agent': u'test1 (wikipedia:en; User:Valhallasw) Pywikibot/2.0b2 (g4338) httplib2/0.8 Python/2.7.6.final.0'}, 5, None) 4. 2015-03-28 11:33:26 threadedhttp.py, 215 in request: DEBUG ('https://en.wikipedia.org/w/api.php', 'POST', 'maxlag=5&format=json&meta=siteinfo%7Cuserinfo&action=query&siprop=general&uiprop=blockinfo%7Chasmsg', {'cookie': 'GeoIP=::::v4', 'connection': 'keep-alive', 'Content-Type': 'application/x-www-form-urlencoded', 'user-agent': u'test1 (wikipedia:en; User:Valhallasw) Pywikibot/2.0b2 (g4338) httplib2/0.8 Python/2.7.6.final.0'}, 5, None)
Only the first of those returns the server time -- I'm not sure why there's several requests for the blockinfo, though. **No further requests are made** (and I also cannot reproduce the 'first timestamp is different' issue). However, the following does appear in the log:
2015-03-28 11:33:26 api.py, 545 in _handle_warnings: WARNING API warning (query): Formatting of continuation data will be changing soon. To continue using the current formatting, use the 'rawcontinue' parameter. To begin using the new format, pass an empty string for 'continue' in the initial query. 2015-03-28 11:33:32 api.py, 545 in _handle_warnings: WARNING API warning (query): Formatting of continuation data will be changing soon. To continue using the current formatting, use the 'rawcontinue' parameter. To begin using the new format, pass an empty string for 'continue' in the initial query. 2015-03-28 11:33:39 api.py, 545 in _handle_warnings: WARNING API warning (query): Formatting of continuation data will be changing soon. To continue using the current formatting, use the 'rawcontinue' parameter. To begin using the new format, pass an empty string for 'continue' in the initial query.
which suggests the response of siteinfo is parsed every time. This suggests the issue is in the api cache. A simple confirmation if this is clearing apicache/* during the run, which results in a new date being shown.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise, valhallasw Cc: valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
valhallasw added a comment.
After puzzling with @xzise on IRC, this is what we think happens:
- Initially, the Site object has no information loaded. - site.version() calls the API with an expiry of 1 day. This loads the siteinfo from the apicache, including the site time - site.getcurrenttime() is handled by Siteinfo's internal cache, which has a bug:
12:40 < xzise> return cache_date + expire >= datetime.datetime.utcnow() 12:40 < xzise> that seems wrong to me
(this should be `cache_date + expire < datetime.datetime.utcnow()`) and thus returns the (max 1 day old) Siteinfo version.
I'm /not/ quite sure why the version request isn't handled by the Siteinfo internal cache, though.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise, valhallasw Cc: valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
valhallasw added a comment.
I'm /not/ quite sure why the version request isn't handled by the Siteinfo internal cache, though.
@xzise pointed out to me this is because the comparison is the wrong way around -- non-expired items (such as the site version) are then handled as if they /were/ expired. The same patch fixes both issues.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise, valhallasw Cc: valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
gerritbot added a subscriber: gerritbot. gerritbot added a comment.
Change 200300 had a related patch set uploaded (by XZise): [FIX] Siteinfo: Correctly compare cache time
https://gerrit.wikimedia.org/r/200300
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise, gerritbot Cc: gerritbot, valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
gerritbot added a project: Patch-For-Review.
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise, gerritbot Cc: gerritbot, valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
gerritbot added a comment.
Change 200300 merged by Merlijn van Deen: [FIX] Siteinfo: Correctly compare cache time
https://gerrit.wikimedia.org/r/200300
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise, gerritbot Cc: gerritbot, valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
XZise closed this task as "Resolved". XZise added a comment.
Sorry for blaming labs when I the comparison was the wrong way around the hole time already :/
TASK DETAIL https://phabricator.wikimedia.org/T94293
REPLY HANDLER ACTIONS Reply to comment or attach files, or !close, !claim, !unsubscribe or !assign <username>.
EMAIL PREFERENCES https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: XZise Cc: gerritbot, valhallasw, XZise, Aklapper, PhantomTech, Gryllida, jayvdb, scfc, pywikipedia-bugs
pywikipedia-bugs@lists.wikimedia.org