Page MenuHomePhabricator

Argument 2 passed to GrowthExperiments\NewcomerTasks\TaskSuggester\CacheDecorator::suggest() must be of the type array, null given, called in /srv/mediawiki/php-1.36.0-wmf.16/extensions/GrowthExperiments/includes/NewcomerTasks/TaskSuggester/NewcomerTasksCacheRefreshJob.php on line 35
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error

MediaWiki version: 1.36.0-wmf.16

message
Argument 2 passed to GrowthExperiments\NewcomerTasks\TaskSuggester\CacheDecorator::suggest() must be of the type array, null given, called in /srv/mediawiki/php-1.36.0-wmf.16/extensions/GrowthExperiments/includes/NewcomerTasks/TaskSuggester/NewcomerTasksCacheRefreshJob.php on line 35

Impact

Low impact; jobs to proactively refresh the cache of newcomer tasks are failing. This means that 7 days after a visit to Special:Homepage, a page load will take several seconds instead of <1 second.

Notes

In CacheDecorator we create the job like this:

$this->jobQueueGroup->lazyPush(
	new NewcomerTasksCacheRefreshJob( [
		'userId' => $user->getId(),
		'taskTypeFilters' => $taskSetFilters->getTaskTypeFilters(),
		'topicFilters' => $taskSetFilters->getTopicFilters(),
		'limit' => SearchTaskSuggester::DEFAULT_LIMIT,
		'jobReleaseTimestamp' => (int)wfTimestamp() +
			// Process the job the day before the cache expires.
			( $this->cache::TTL_WEEK - $this->cache::TTL_DAY ),
	] )
);

TaskSetFilters is constructed with two arrays, and getTaskTypeFilters and getTopicFilters are both typed to return arrays. SearchTaskSuggester::DEFAULT_LIMIT is a constant that returns an integer value.

The erroring code in NewcomerTasksCacheRefreshJob is:

$taskSuggester->suggest(
			$user,
			$this->params['taskTypeFilters'],
			$this->params['topicFilters'],
			$this->params['limit'],
			null,
			false,
			false
		);

And from the stacktrace it looks like somehow taskTypeFilters, topicFilters, and limit are all null. I don't understand how this is possible, unless there is some mechanism that is erroring on the array / int values (but somehow not the user ID int value?).

Details

Request ID
e9977184-76b8-47c0-a534-220d09060f83
Request URL
https://jobrunner.discovery.wmnet/rpc/RunSingleJob.php
Stack Trace
exception.trace
#0 /srv/mediawiki/php-1.36.0-wmf.16/extensions/GrowthExperiments/includes/NewcomerTasks/TaskSuggester/NewcomerTasksCacheRefreshJob.php(35): GrowthExperiments\NewcomerTasks\TaskSuggester\CacheDecorator->suggest(User, NULL, NULL, NULL, NULL, boolean, boolean)
#1 /srv/mediawiki/php-1.36.0-wmf.16/extensions/EventBus/includes/JobExecutor.php(79): GrowthExperiments\NewcomerTasks\TaskSuggester\NewcomerTasksCacheRefreshJob->run()
#2 /srv/mediawiki/rpc/RunSingleJob.php(76): MediaWiki\Extension\EventBus\JobExecutor->execute(array)
#3 {main}

Event Timeline

kostajh created this task.Tue, Nov 17, 10:16 AM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptTue, Nov 17, 10:16 AM

Change 641420 had a related patch set uploaded (by Kosta Harlan; owner: Kosta Harlan):
[mediawiki/extensions/GrowthExperiments@master] CacheDecorator: Access filters and limit from within job

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

kostajh added subscribers: Pchelolo, aaron.

@aaron @Pchelolo is it possible something weird is happening with this job because it uses jobReleaseTimestamp, and somehow the array and int parameters I'm passing in are getting cast to null? Tagging Platform Engineering due to Developer/Maintainers listing you all for job queue.

kostajh updated the task description. (Show Details)Tue, Nov 17, 12:52 PM
AMooney triaged this task as Low priority.Tue, Nov 17, 2:05 PM
AMooney moved this task from Inbox to Later on the Platform Team Workboards (Clinic Duty Team) board.
Tgr added a subscriber: Tgr.Tue, Nov 17, 8:32 PM

This is happening about 1000 times an hour, which is a pretty crazy rate for a job that's supposed to run once a week for opted-in users on select wikis only.

unless there is some mechanism that is erroring on the array / int values (but somehow not the user ID int value?).

I suppose the user ID could also be null, we'd still end up in an (anonymous) User object in that call.

is it possible something weird is happening with this job because it uses jobReleaseTimestamp, and somehow the array and int parameters I'm passing in are getting cast to null?

Not that I know of or have seen this before, but it's not entirely impossible that empty array, being falsy, would get somehow replaced with null over the course of json serialization/deserialization rounds... The attached patch should fix this problem..

This is happening about 1000 times an hour,

The job gets executed about 0.05 times/s on average, = 180 times an our. Plus it's retried 2 times = 540 executions. Given that estimate of 0.05 I derived to by looking at a very spiky graph, 1000 an hour is not entirely impossible.

is it possible something weird is happening with this job because it uses jobReleaseTimestamp, and somehow the array and int parameters I'm passing in are getting cast to null?

Not that I know of or have seen this before, but it's not entirely impossible that empty array, being falsy, would get somehow replaced with null over the course of json serialization/deserialization rounds... The attached patch should fix this problem..

This is happening about 1000 times an hour,

The job gets executed about 0.05 times/s on average, = 180 times an our. Plus it's retried 2 times = 540 executions. Given that estimate of 0.05 I derived to by looking at a very spiky graph, 1000 an hour is not entirely impossible.

Is it possible to inspect the params stored for one of these jobs, so that we could for example verify that userId is set to a value we expect?

@kostajh here's 10 latest ones:

ssh stat1007.eqiad.wmnet
kafkacat -b kafka-main1001.eqiad.wmnet -t "eqiad.mediawiki.job.newcomerTasksCacheRefreshJob" -p 0 -o -10 -c 10

1{
2 "$schema": "/mediawiki/job/1.0.0",
3 "meta": {
4 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
5 "request_id": "1a5ac064-233c-4d40-b579-9fa00979ecbb",
6 "id": "8445860f-2446-47a1-812b-6db2d46e6c5c",
7 "dt": "2020-11-17T20:50:58Z",
8 "domain": "ru.wikipedia.org",
9 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
10 },
11 "database": "ruwiki",
12 "type": "newcomerTasksCacheRefreshJob",
13 "delay_until": "2020-11-23T20:50:57Z",
14 "sha1": "a500a6d432aee4525ff3185452cdf953521a8d1f",
15 "params": {
16 "userId": 2875991,
17 "taskTypeFilters": [
18 "copyedit",
19 "links"
20 ],
21 "topicFilters": [],
22 "limit": 250,
23 "jobReleaseTimestamp": 1606164657,
24 "requestId": "1a5ac064-233c-4d40-b579-9fa00979ecbb"
25 },
26 "mediawiki_signature": "65136641fd84e7b6ee21cf3162afe8eb26fdab7c"
27}
28{
29 "$schema": "/mediawiki/job/1.0.0",
30 "meta": {
31 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
32 "request_id": "b9dc7564-4722-4a5d-838b-4fdc36232955",
33 "id": "521ab0f2-7bad-4544-9a8e-3fe55d11d144",
34 "dt": "2020-11-17T20:50:59Z",
35 "domain": "fr.wikipedia.org",
36 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
37 },
38 "database": "frwiki",
39 "type": "newcomerTasksCacheRefreshJob",
40 "delay_until": "2020-11-23T20:50:59Z",
41 "sha1": "f34a29d59504ebbd9ec8e9d9f7ba5f1343b69509",
42 "params": {
43 "userId": 3961567,
44 "taskTypeFilters": [
45 "copyedit",
46 "links",
47 "references",
48 "update"
49 ],
50 "topicFilters": [],
51 "limit": 250,
52 "jobReleaseTimestamp": 1606164659,
53 "requestId": "b9dc7564-4722-4a5d-838b-4fdc36232955"
54 },
55 "mediawiki_signature": "97ea087b14f164679e90fa434ceea01cf15ab844"
56}
57{
58 "$schema": "/mediawiki/job/1.0.0",
59 "meta": {
60 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
61 "request_id": "8cecee25-e4d0-419e-9b15-73fc29101221",
62 "id": "f786285b-06f6-45a5-ae6d-52c828c649b4",
63 "dt": "2020-11-17T20:51:01Z",
64 "domain": "fr.wikipedia.org",
65 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
66 },
67 "database": "frwiki",
68 "type": "newcomerTasksCacheRefreshJob",
69 "delay_until": "2020-11-23T20:51:01Z",
70 "sha1": "9cd66b47953a6532d57438fbd7c25ab692b43cf0",
71 "params": {
72 "userId": 3961567,
73 "taskTypeFilters": [
74 "copyedit",
75 "links",
76 "references",
77 "update",
78 "expand"
79 ],
80 "topicFilters": [],
81 "limit": 250,
82 "jobReleaseTimestamp": 1606164661,
83 "requestId": "8cecee25-e4d0-419e-9b15-73fc29101221"
84 },
85 "mediawiki_signature": "49cd274d4077ef73833c5680c51936929e1baee5"
86}
87{
88 "$schema": "/mediawiki/job/1.0.0",
89 "meta": {
90 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
91 "request_id": "21697334-92b0-44be-b5df-ae27e469c140",
92 "id": "383e0198-a4d9-4412-8516-23bb26288f7d",
93 "dt": "2020-11-17T20:51:39Z",
94 "domain": "fr.wikipedia.org",
95 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
96 },
97 "database": "frwiki",
98 "type": "newcomerTasksCacheRefreshJob",
99 "delay_until": "2020-11-23T20:51:37Z",
100 "sha1": "cc25a7c5ce971b179b956bf2052ad01c67037eea",
101 "params": {
102 "userId": 3961571,
103 "taskTypeFilters": [
104 "copyedit",
105 "links"
106 ],
107 "topicFilters": [],
108 "limit": 250,
109 "jobReleaseTimestamp": 1606164697,
110 "requestId": "21697334-92b0-44be-b5df-ae27e469c140"
111 },
112 "mediawiki_signature": "39b870c70d5833a17581b8aaacfb531d01b1f367"
113}
114{
115 "$schema": "/mediawiki/job/1.0.0",
116 "meta": {
117 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
118 "request_id": "ae068da3-6991-41f8-af51-c5ec86756c73",
119 "id": "8c951df6-43e3-4c92-a4e0-ac8df14b8e19",
120 "dt": "2020-11-17T20:51:39Z",
121 "domain": "fr.wikipedia.org",
122 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
123 },
124 "database": "frwiki",
125 "type": "newcomerTasksCacheRefreshJob",
126 "delay_until": "2020-11-23T20:51:37Z",
127 "sha1": "763b34006a9226dd35b2de1f4ea12a93ca321a03",
128 "params": {
129 "userId": 3961572,
130 "taskTypeFilters": [
131 "copyedit",
132 "links"
133 ],
134 "topicFilters": [],
135 "limit": 250,
136 "jobReleaseTimestamp": 1606164697,
137 "requestId": "ae068da3-6991-41f8-af51-c5ec86756c73"
138 },
139 "mediawiki_signature": "cccd23cb555b321b561ae44660f35156e2e3042e"
140}
141{
142 "$schema": "/mediawiki/job/1.0.0",
143 "meta": {
144 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
145 "request_id": "d700ff2b-dc7b-4d0e-9dce-9ded9239d4bb",
146 "id": "ad80a49e-5d12-4767-96fb-bb68abf38be9",
147 "dt": "2020-11-17T20:52:49Z",
148 "domain": "fa.wikipedia.org",
149 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
150 },
151 "database": "fawiki",
152 "type": "newcomerTasksCacheRefreshJob",
153 "delay_until": "2020-11-23T20:52:42Z",
154 "sha1": "e4ff0407b386be6347a3eca3bae4afb568ad400f",
155 "params": {
156 "userId": 979651,
157 "taskTypeFilters": [
158 "copyedit",
159 "links"
160 ],
161 "topicFilters": [],
162 "limit": 250,
163 "jobReleaseTimestamp": 1606164762,
164 "requestId": "d700ff2b-dc7b-4d0e-9dce-9ded9239d4bb"
165 },
166 "mediawiki_signature": "ce0fe3cf6d36245144c1db1717428f82af2f8141"
167}
168{
169 "$schema": "/mediawiki/job/1.0.0",
170 "meta": {
171 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
172 "request_id": "c0868e27-de01-4d0d-a2e4-196abca7d65c",
173 "id": "ad949cc1-1f83-4da4-9380-2a38668237e8",
174 "dt": "2020-11-17T20:53:09Z",
175 "domain": "tr.wikipedia.org",
176 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
177 },
178 "database": "trwiki",
179 "type": "newcomerTasksCacheRefreshJob",
180 "delay_until": "2020-11-23T20:53:07Z",
181 "sha1": "2614d3e5fae5882c019795e488689b93387bb1ad",
182 "params": {
183 "userId": 1242191,
184 "taskTypeFilters": [
185 "copyedit",
186 "links"
187 ],
188 "topicFilters": [],
189 "limit": 250,
190 "jobReleaseTimestamp": 1606164787,
191 "requestId": "c0868e27-de01-4d0d-a2e4-196abca7d65c"
192 },
193 "mediawiki_signature": "bde19e4c54f94a535c5100d848cb329e549b28d0"
194}
195{
196 "$schema": "/mediawiki/job/1.0.0",
197 "meta": {
198 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
199 "request_id": "06225c86-db64-4f1e-afa3-e82a9c4f3ae5",
200 "id": "3abde321-bfd2-4f5c-8ff9-2c593598843f",
201 "dt": "2020-11-17T20:53:11Z",
202 "domain": "ru.wikipedia.org",
203 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
204 },
205 "database": "ruwiki",
206 "type": "newcomerTasksCacheRefreshJob",
207 "delay_until": "2020-11-23T20:53:11Z",
208 "sha1": "6112c6175fdb04eece53e6222b8900d0837b9382",
209 "params": {
210 "userId": 2873927,
211 "taskTypeFilters": [
212 "links"
213 ],
214 "topicFilters": [
215 "music",
216 "entertainment",
217 "tv-and-film",
218 "food-and-drink",
219 "computers-and-internet",
220 "medicine-and-health"
221 ],
222 "limit": 250,
223 "jobReleaseTimestamp": 1606164791,
224 "requestId": "06225c86-db64-4f1e-afa3-e82a9c4f3ae5"
225 },
226 "mediawiki_signature": "8128cfd01cb4d84da41f94d1bd25b37803f10871"
227}
228{
229 "$schema": "/mediawiki/job/1.0.0",
230 "meta": {
231 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
232 "request_id": "6474dea8-2314-4221-a20d-bdaaef935cf5",
233 "id": "dc724f58-6e8e-48e0-a6a0-f2f616224634",
234 "dt": "2020-11-17T20:53:45Z",
235 "domain": "fa.wikipedia.org",
236 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
237 },
238 "database": "fawiki",
239 "type": "newcomerTasksCacheRefreshJob",
240 "delay_until": "2020-11-23T20:53:42Z",
241 "sha1": "5e60a3c416dcd3dace0b1650a8695d3007b92512",
242 "params": {
243 "userId": 979652,
244 "taskTypeFilters": [
245 "copyedit",
246 "links"
247 ],
248 "topicFilters": [],
249 "limit": 250,
250 "jobReleaseTimestamp": 1606164822,
251 "requestId": "6474dea8-2314-4221-a20d-bdaaef935cf5"
252 },
253 "mediawiki_signature": "4990dcd2677da3c47ff5733f11d00befc76e049b"
254}
255{
256 "$schema": "/mediawiki/job/1.0.0",
257 "meta": {
258 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
259 "request_id": "e5b547f8-d593-4ea0-893a-4fe76255629b",
260 "id": "2d261e41-cf47-4680-8a5e-d63445d235f2",
261 "dt": "2020-11-17T20:54:01Z",
262 "domain": "sv.wikipedia.org",
263 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
264 },
265 "database": "svwiki",
266 "type": "newcomerTasksCacheRefreshJob",
267 "delay_until": "2020-11-23T20:53:57Z",
268 "sha1": "271352ee6cef456d290e5d8e7427c42277071a8f",
269 "params": {
270 "userId": 753874,
271 "taskTypeFilters": [
272 "copyedit",
273 "links"
274 ],
275 "topicFilters": [],
276 "limit": 250,
277 "jobReleaseTimestamp": 1606164837,
278 "requestId": "e5b547f8-d593-4ea0-893a-4fe76255629b"
279 },
280 "mediawiki_signature": "86068515ed7107a137441807af883eaa5eaa0d4c"
281}

@kostajh here's 10 latest ones:

ssh stat1007.eqiad.wmnet
kafkacat -b kafka-main1001.eqiad.wmnet -t "eqiad.mediawiki.job.newcomerTasksCacheRefreshJob" -p 0 -o -10 -c 10

1{
2 "$schema": "/mediawiki/job/1.0.0",
3 "meta": {
4 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
5 "request_id": "1a5ac064-233c-4d40-b579-9fa00979ecbb",
6 "id": "8445860f-2446-47a1-812b-6db2d46e6c5c",
7 "dt": "2020-11-17T20:50:58Z",
8 "domain": "ru.wikipedia.org",
9 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
10 },
11 "database": "ruwiki",
12 "type": "newcomerTasksCacheRefreshJob",
13 "delay_until": "2020-11-23T20:50:57Z",
14 "sha1": "a500a6d432aee4525ff3185452cdf953521a8d1f",
15 "params": {
16 "userId": 2875991,
17 "taskTypeFilters": [
18 "copyedit",
19 "links"
20 ],
21 "topicFilters": [],
22 "limit": 250,
23 "jobReleaseTimestamp": 1606164657,
24 "requestId": "1a5ac064-233c-4d40-b579-9fa00979ecbb"
25 },
26 "mediawiki_signature": "65136641fd84e7b6ee21cf3162afe8eb26fdab7c"
27}
28{
29 "$schema": "/mediawiki/job/1.0.0",
30 "meta": {
31 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
32 "request_id": "b9dc7564-4722-4a5d-838b-4fdc36232955",
33 "id": "521ab0f2-7bad-4544-9a8e-3fe55d11d144",
34 "dt": "2020-11-17T20:50:59Z",
35 "domain": "fr.wikipedia.org",
36 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
37 },
38 "database": "frwiki",
39 "type": "newcomerTasksCacheRefreshJob",
40 "delay_until": "2020-11-23T20:50:59Z",
41 "sha1": "f34a29d59504ebbd9ec8e9d9f7ba5f1343b69509",
42 "params": {
43 "userId": 3961567,
44 "taskTypeFilters": [
45 "copyedit",
46 "links",
47 "references",
48 "update"
49 ],
50 "topicFilters": [],
51 "limit": 250,
52 "jobReleaseTimestamp": 1606164659,
53 "requestId": "b9dc7564-4722-4a5d-838b-4fdc36232955"
54 },
55 "mediawiki_signature": "97ea087b14f164679e90fa434ceea01cf15ab844"
56}
57{
58 "$schema": "/mediawiki/job/1.0.0",
59 "meta": {
60 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
61 "request_id": "8cecee25-e4d0-419e-9b15-73fc29101221",
62 "id": "f786285b-06f6-45a5-ae6d-52c828c649b4",
63 "dt": "2020-11-17T20:51:01Z",
64 "domain": "fr.wikipedia.org",
65 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
66 },
67 "database": "frwiki",
68 "type": "newcomerTasksCacheRefreshJob",
69 "delay_until": "2020-11-23T20:51:01Z",
70 "sha1": "9cd66b47953a6532d57438fbd7c25ab692b43cf0",
71 "params": {
72 "userId": 3961567,
73 "taskTypeFilters": [
74 "copyedit",
75 "links",
76 "references",
77 "update",
78 "expand"
79 ],
80 "topicFilters": [],
81 "limit": 250,
82 "jobReleaseTimestamp": 1606164661,
83 "requestId": "8cecee25-e4d0-419e-9b15-73fc29101221"
84 },
85 "mediawiki_signature": "49cd274d4077ef73833c5680c51936929e1baee5"
86}
87{
88 "$schema": "/mediawiki/job/1.0.0",
89 "meta": {
90 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
91 "request_id": "21697334-92b0-44be-b5df-ae27e469c140",
92 "id": "383e0198-a4d9-4412-8516-23bb26288f7d",
93 "dt": "2020-11-17T20:51:39Z",
94 "domain": "fr.wikipedia.org",
95 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
96 },
97 "database": "frwiki",
98 "type": "newcomerTasksCacheRefreshJob",
99 "delay_until": "2020-11-23T20:51:37Z",
100 "sha1": "cc25a7c5ce971b179b956bf2052ad01c67037eea",
101 "params": {
102 "userId": 3961571,
103 "taskTypeFilters": [
104 "copyedit",
105 "links"
106 ],
107 "topicFilters": [],
108 "limit": 250,
109 "jobReleaseTimestamp": 1606164697,
110 "requestId": "21697334-92b0-44be-b5df-ae27e469c140"
111 },
112 "mediawiki_signature": "39b870c70d5833a17581b8aaacfb531d01b1f367"
113}
114{
115 "$schema": "/mediawiki/job/1.0.0",
116 "meta": {
117 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
118 "request_id": "ae068da3-6991-41f8-af51-c5ec86756c73",
119 "id": "8c951df6-43e3-4c92-a4e0-ac8df14b8e19",
120 "dt": "2020-11-17T20:51:39Z",
121 "domain": "fr.wikipedia.org",
122 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
123 },
124 "database": "frwiki",
125 "type": "newcomerTasksCacheRefreshJob",
126 "delay_until": "2020-11-23T20:51:37Z",
127 "sha1": "763b34006a9226dd35b2de1f4ea12a93ca321a03",
128 "params": {
129 "userId": 3961572,
130 "taskTypeFilters": [
131 "copyedit",
132 "links"
133 ],
134 "topicFilters": [],
135 "limit": 250,
136 "jobReleaseTimestamp": 1606164697,
137 "requestId": "ae068da3-6991-41f8-af51-c5ec86756c73"
138 },
139 "mediawiki_signature": "cccd23cb555b321b561ae44660f35156e2e3042e"
140}
141{
142 "$schema": "/mediawiki/job/1.0.0",
143 "meta": {
144 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
145 "request_id": "d700ff2b-dc7b-4d0e-9dce-9ded9239d4bb",
146 "id": "ad80a49e-5d12-4767-96fb-bb68abf38be9",
147 "dt": "2020-11-17T20:52:49Z",
148 "domain": "fa.wikipedia.org",
149 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
150 },
151 "database": "fawiki",
152 "type": "newcomerTasksCacheRefreshJob",
153 "delay_until": "2020-11-23T20:52:42Z",
154 "sha1": "e4ff0407b386be6347a3eca3bae4afb568ad400f",
155 "params": {
156 "userId": 979651,
157 "taskTypeFilters": [
158 "copyedit",
159 "links"
160 ],
161 "topicFilters": [],
162 "limit": 250,
163 "jobReleaseTimestamp": 1606164762,
164 "requestId": "d700ff2b-dc7b-4d0e-9dce-9ded9239d4bb"
165 },
166 "mediawiki_signature": "ce0fe3cf6d36245144c1db1717428f82af2f8141"
167}
168{
169 "$schema": "/mediawiki/job/1.0.0",
170 "meta": {
171 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
172 "request_id": "c0868e27-de01-4d0d-a2e4-196abca7d65c",
173 "id": "ad949cc1-1f83-4da4-9380-2a38668237e8",
174 "dt": "2020-11-17T20:53:09Z",
175 "domain": "tr.wikipedia.org",
176 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
177 },
178 "database": "trwiki",
179 "type": "newcomerTasksCacheRefreshJob",
180 "delay_until": "2020-11-23T20:53:07Z",
181 "sha1": "2614d3e5fae5882c019795e488689b93387bb1ad",
182 "params": {
183 "userId": 1242191,
184 "taskTypeFilters": [
185 "copyedit",
186 "links"
187 ],
188 "topicFilters": [],
189 "limit": 250,
190 "jobReleaseTimestamp": 1606164787,
191 "requestId": "c0868e27-de01-4d0d-a2e4-196abca7d65c"
192 },
193 "mediawiki_signature": "bde19e4c54f94a535c5100d848cb329e549b28d0"
194}
195{
196 "$schema": "/mediawiki/job/1.0.0",
197 "meta": {
198 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
199 "request_id": "06225c86-db64-4f1e-afa3-e82a9c4f3ae5",
200 "id": "3abde321-bfd2-4f5c-8ff9-2c593598843f",
201 "dt": "2020-11-17T20:53:11Z",
202 "domain": "ru.wikipedia.org",
203 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
204 },
205 "database": "ruwiki",
206 "type": "newcomerTasksCacheRefreshJob",
207 "delay_until": "2020-11-23T20:53:11Z",
208 "sha1": "6112c6175fdb04eece53e6222b8900d0837b9382",
209 "params": {
210 "userId": 2873927,
211 "taskTypeFilters": [
212 "links"
213 ],
214 "topicFilters": [
215 "music",
216 "entertainment",
217 "tv-and-film",
218 "food-and-drink",
219 "computers-and-internet",
220 "medicine-and-health"
221 ],
222 "limit": 250,
223 "jobReleaseTimestamp": 1606164791,
224 "requestId": "06225c86-db64-4f1e-afa3-e82a9c4f3ae5"
225 },
226 "mediawiki_signature": "8128cfd01cb4d84da41f94d1bd25b37803f10871"
227}
228{
229 "$schema": "/mediawiki/job/1.0.0",
230 "meta": {
231 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
232 "request_id": "6474dea8-2314-4221-a20d-bdaaef935cf5",
233 "id": "dc724f58-6e8e-48e0-a6a0-f2f616224634",
234 "dt": "2020-11-17T20:53:45Z",
235 "domain": "fa.wikipedia.org",
236 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
237 },
238 "database": "fawiki",
239 "type": "newcomerTasksCacheRefreshJob",
240 "delay_until": "2020-11-23T20:53:42Z",
241 "sha1": "5e60a3c416dcd3dace0b1650a8695d3007b92512",
242 "params": {
243 "userId": 979652,
244 "taskTypeFilters": [
245 "copyedit",
246 "links"
247 ],
248 "topicFilters": [],
249 "limit": 250,
250 "jobReleaseTimestamp": 1606164822,
251 "requestId": "6474dea8-2314-4221-a20d-bdaaef935cf5"
252 },
253 "mediawiki_signature": "4990dcd2677da3c47ff5733f11d00befc76e049b"
254}
255{
256 "$schema": "/mediawiki/job/1.0.0",
257 "meta": {
258 "uri": "https://placeholder.invalid/wiki/Special:Badtitle",
259 "request_id": "e5b547f8-d593-4ea0-893a-4fe76255629b",
260 "id": "2d261e41-cf47-4680-8a5e-d63445d235f2",
261 "dt": "2020-11-17T20:54:01Z",
262 "domain": "sv.wikipedia.org",
263 "stream": "mediawiki.job.newcomerTasksCacheRefreshJob"
264 },
265 "database": "svwiki",
266 "type": "newcomerTasksCacheRefreshJob",
267 "delay_until": "2020-11-23T20:53:57Z",
268 "sha1": "271352ee6cef456d290e5d8e7427c42277071a8f",
269 "params": {
270 "userId": 753874,
271 "taskTypeFilters": [
272 "copyedit",
273 "links"
274 ],
275 "topicFilters": [],
276 "limit": 250,
277 "jobReleaseTimestamp": 1606164837,
278 "requestId": "e5b547f8-d593-4ea0-893a-4fe76255629b"
279 },
280 "mediawiki_signature": "86068515ed7107a137441807af883eaa5eaa0d4c"
281}

Thanks. That looks like what I'd expect...

Tgr added a comment.Tue, Nov 17, 10:48 PM

Not that I know of or have seen this before, but it's not entirely impossible that empty array, being falsy, would get somehow replaced with null over the course of json serialization/deserialization rounds...

taskTypeFilters is never empty (topicFilters might be). It is also not something only affecting arrays as limit (a non-zero integer) is also affected.

The job gets executed about 0.05 times/s on average, = 180 times an our. Plus it's retried 2 times = 540 executions. Given that estimate of 0.05 I derived to by looking at a very spiky graph, 1000 an hour is not entirely impossible.

I was just eyeballing Logstash, might have been off. But it seems like the entirely wrong magnitude for a job that should run once per week per opted-in new user on a subset of wikis. We have a little less than 10K weekly homepage visits, so the number of job executions per week should be below that (times three for error handling), I think? Of course, that might be an unrelated issue and might be caused by some logic error in GrowthExperiments code. Or I might be just misunderstanding the job's behavior.

But it seems like the entirely wrong magnitude for a job that should run once per week per opted-in new user on a subset of wikis.

Once per week? The job is configured to execute 1 week after it was triggered, but there's nothing about triggering it once per week as I understand. It is coalesced if all the params are the same, at a ~0.05/s rate: https://grafana.wikimedia.org/d/LSeAShkGz/jobqueue?viewPanel=14&orgId=1

Tgr added a comment.Tue, Nov 17, 11:51 PM

It gets scheduled on cache misses, and the cache expires in a week. It also gets stale if the user changes filter settings, but it seems implausible that that would happen a few thousand times a week.

Change 641586 had a related patch set uploaded (by Gergő Tisza; owner: Gergő Tisza):
[mediawiki/extensions/GrowthExperiments@master] Fix NewcomerTasksCacheRefreshJob

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

Tgr added a comment.Wed, Nov 18, 6:57 AM

@Pchelolo I apologize for the false alarm; the error was in the extension code after all. The Job contract that we broke is IMO rather obscure, I added two patches that hopefully clarify it.

Tgr added a comment.Wed, Nov 18, 7:02 AM

Change 641586 had a related patch set uploaded (by Gergő Tisza; owner: Gergő Tisza):
[mediawiki/extensions/GrowthExperiments@master] Fix NewcomerTasksCacheRefreshJob

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

I found testing the job tricky; in the end, these steps worked:

  • comment out the jobReleaseTimestamp parameter in CacheDecorator (I don't think there's a way to force a delayed job to run)
  • disable the normal job runner mechanism (on Vagrant that's sudo service jobchron stop && sudo service jobrunner stop)
  • enable CacheDecorator since it's not default for a development setup; e.g.
//return;

use GrowthExperiments\GrowthExperimentsServices;
use GrowthExperiments\NewcomerTasks\TaskSuggester\CacheDecorator;
use GrowthExperiments\NewcomerTasks\TaskSuggester\DecoratingTaskSuggesterFactory;
use GrowthExperiments\NewcomerTasks\TaskSuggester\TaskSuggesterFactory;
use MediaWiki\Logger\LoggerFactory;
use MediaWiki\MediaWikiServices;

$wgHooks['MediaWikiServices'][] = function ( MediaWikiServices $services ) {
    $services->addServiceManipulator( 'GrowthExperimentsTaskSuggesterFactory', function (
        TaskSuggesterFactory $taskSuggesterFactory, MediaWikiServices $services
    ) {
        $decoratedFactory = new DecoratingTaskSuggesterFactory(
            $taskSuggesterFactory,
            $services->getObjectFactory(),
            [ [
                  'class' => CacheDecorator::class,
                  'args' => [
                      JobQueueGroup::singleton(),
                      GrowthExperimentsServices::wrap( $services )->getTemplateFilter(),
                      $services->getMainWANObjectCache()
                  ],
              ] ]
        );
        $decoratedFactory->setLogger( LoggerFactory::getInstance( 'GrowthExperiments' ) );
        return $decoratedFactory;
    } );
};
  • load the homepage so a job gets scheduled
  • run the job with mwscript runJobs.php --type newcomerTasksCacheRefreshJob and test (XDEBUG_CONFIG etc. works here)

Change 641586 merged by jenkins-bot:
[mediawiki/extensions/GrowthExperiments@master] Fix NewcomerTasksCacheRefreshJob

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

Change 641501 had a related patch set uploaded (by Hashar; owner: Gergő Tisza):
[mediawiki/extensions/GrowthExperiments@wmf/1.36.0-wmf.18] Fix NewcomerTasksCacheRefreshJob

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

Change 641501 merged by jenkins-bot:
[mediawiki/extensions/GrowthExperiments@wmf/1.36.0-wmf.18] Fix NewcomerTasksCacheRefreshJob

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

Mentioned in SAL (#wikimedia-operations) [2020-11-18T12:25:31Z] <urbanecm@deploy1001> Synchronized php-1.36.0-wmf.18/extensions/GrowthExperiments/includes/NewcomerTasks/TaskSuggester/NewcomerTasksCacheRefreshJob.php: 45d71a37f381e81e5382c8e10ac4063c9665beb8: Fix NewcomerTasksCacheRefreshJob (T268008) (duration: 01m 05s)

Change 641503 had a related patch set uploaded (by Urbanecm; owner: Gergő Tisza):
[mediawiki/extensions/GrowthExperiments@wmf/1.36.0-wmf.16] Fix NewcomerTasksCacheRefreshJob

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

Change 641503 merged by jenkins-bot:
[mediawiki/extensions/GrowthExperiments@wmf/1.36.0-wmf.16] Fix NewcomerTasksCacheRefreshJob

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

Mentioned in SAL (#wikimedia-operations) [2020-11-18T12:40:08Z] <urbanecm@deploy1001> Synchronized php-1.36.0-wmf.16/extensions/GrowthExperiments/includes/NewcomerTasks/TaskSuggester/NewcomerTasksCacheRefreshJob.php: 5488f56c7458fa8fb9be5f41f131e00b26a84cc0: Fix NewcomerTasksCacheRefreshJob (T268008) (duration: 01m 05s)

Urbanecm closed this task as Resolved.Wed, Nov 18, 12:46 PM
Urbanecm assigned this task to Tgr.
Urbanecm added a subscriber: Urbanecm.