Page MenuHomePhabricator

Error for mediawiki.cirrussearch-request: '' should NOT have additional properties
Closed, ResolvedPublicBUG REPORT

Description

We're seeing a number of events causing EventGate validation errors.

From #wikimedia-search on IRC:

pfischer ebernhardson for the alert at https://alerts.wikimedia.org/?q=%40state%3Dactive&q=alertname%3DEventgateValidationErrors are we okay to dismiss the alert? i do see the schema validation error rate for stream = mediawiki.cirrussearch-request seems to be more elevated starting from that spike
10:27:43 AM 
https://grafana.wikimedia.org/d/ZB39Izmnz/eventgate?orgId=1&refresh=1m&var-service=eventgate-analytics&var-stream=mediawiki.cirrussearch-request&var-kafka_broker=$__all&var-kafka_producer_type=$__all&var-dc=000000026&from=now-7d&to=now&timezone=utc&var-site=$__all
10:27:54 AM <+ebernhardson> 
hmm
10:28:48 AM <+dr0ptp4kt> Adam Baso 
but was thinking maybe there's some other activity going on that makes this temporary (i sorta vaguely recall seeing a message somewhere, but am not sure where - my quick searches in the usual places aren't helping, except looking for stuff from earlier in the month and farther back, which isn't really what i'm thinking of, i think that was just a few days ago)
10:29:13 AM <+ebernhardson> 
dr0ptp4kt: i will have to find the actual validation errors to see whats happening
10:30:19 AM 
looks like logstash has them, '' should NOT have additional properties.  No mention of which property :P
10:30:23 AM <+dr0ptp4kt> Adam Baso 
ok ebernhardson - you got this or you want me to dig and re-dispatch to someone else? i'm working through ops week stuff and can get to it (just let me know if i should hustle as high prio)
10:30:40 AM 
oh my :)
10:31:02 AM <+ebernhardson> 
also od dthat the thing that shouldn't have additonal properties is the empty string, seems like something is supposed to be there
10:31:46 AM 
dr0ptp4kt: i can look into it, we generally expect these to work so it would be nice for them to all go through
10:31:51 AM <+dr0ptp4kt> Adam Baso 
looking for "should not have additional properties" in phab seems like an assortment of random
10:32:20 AM 
thanks ebernhardson ! i'll capture our chat here and reply on the alert email with you on the To: line for your Gmail-based task prio
10:33:08 AM <+ebernhardson> 
yea, from phab history it seems that empty string is intentional, or at least expected. odd but whatever
10:34:42 AM <+dr0ptp4kt> Adam Baso 
sigh, gmail is intermittently flapping for me
10:34:59 AM <+ebernhardson> 
somewhat tangentially...i need a nice way to do yaml -> json, because our jsonschema's are in yaml and jsonschema validators want, well, json
10:35:10 AM 
i guess i can roundtrip in python?
10:35:39 AM <+dr0ptp4kt> Adam Baso 
in order for me to conceive of yaml correctly, i mind-parse into python data structures, then mind-parse into json :P
10:35:56 AM <+ebernhardson> 
lol :)
10:36:44 AM 
hmm: Property 'context.job_type' has not been defined and the schema does not allow additional properties.
10:37:05 AM 
curious that it would only exist sometimes? will have to poke around
10:37:28 AM 
it's set to newcomerTasksCacheRefreshJob, not even clear that belongs in our event
10:42:37 AM 
ohh...it's being auto-injected via `LoggerFactory::getContext()->addScoped(...)`
10:42:48 AM 
but we can't have arbitrary code just adding properties to schema'd events
10:44:54 AM <+dr0ptp4kt> Adam Baso 
oh, in Extension:EventBus you mean?
10:45:10 AM 
via JobExecutor.php?
10:45:13 AM <+ebernhardson> 
this happens in core, via the JobRunner. So basically any event fired from a job probably has this issue
10:45:20 AM 
(or some events follow different paths? I forget)
10:47:14 AM 
maybe it's just us doing things an old way, these events have been firing through the logging system since before EventBus/EventGate existed.  Are events supposed to go through LoggerFactory still?
10:51:04 AM <+dr0ptp4kt> Adam Baso 
that i'm not sure about. ottomata you happen to know? i'll go file a ticket as i suspect someone will need to update an (as-yet-to-be-determined) piece of extension code, assuming it isn't a bot dirtying things up
10:51:44 AM <+ebernhardson> 
poking around, i suspect we might need to switch this from shipping events via LoggerFactory to using the EventBusFactory

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

I looped some additional subscribers onto this task, of course feel free to unsubscribe or mute if needed - just trying to see if we can figure out the source of this thing by someone who may have been in related code / config recently.

A few screenshots for posterity's sake:

Screenshot 2025-07-18 at 11.04.26 AM.png (3,802×1,380 px, 482 KB)

Screenshot 2025-07-18 at 11.05.40 AM.png (3,778×1,872 px, 559 KB)

{F65207273}

Change #1170586 had a related patch set uploaded (by Ebernhardson; author: Ebernhardson):

[mediawiki/extensions/CirrusSearch@master] RequestLogger: Log directly through EventBus

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

Michael moved this task from Inbox to Triaged on the Growth-Team board.

We seem to be only very incidentally related to this? Please let me know if anything is needed from Growth!

That being said, it is strange that the topic is newcomerTasksCacheRefreshJob! This class does not even have a direct dependency on any logger? Only one of its injected dependencies has a logger, and that in turn is not supposed to know about its caller 🤔

We seem to be only very incidentally related to this? Please let me know if anything is needed from Growth!

That being said, it is strange that the topic is newcomerTasksCacheRefreshJob! This class does not even have a direct dependency on any logger? Only one of its injected dependencies has a logger, and that in turn is not supposed to know about its caller 🤔

Now that I'm looking at it in logstash, there seems to actually also be an issue on our side: GrowthExperiments\NewcomerTasks\TaskSuggester\NewcomerTasksCacheRefreshJob executed for invalid userId (0). I'll create a task for it... => T400153

But this is probably separate from the issue that this task is about.

Change #1170586 merged by jenkins-bot:

[mediawiki/extensions/CirrusSearch@master] RequestLogger: Log directly through EventBus

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

Fairly certain this worked as expected. Searching logstash discover for "should NOT have additional properties" AND "cirrussearch" had ~35k messages on july 31st, and zero since.