How do I tell when a LexoRank job started?

[dmitri]

We observed some resource intensive queries on our database related to _LEXORANK tables along with high cpu %. How can we tell if and when a LexoRank job started to correlate this?

[crf]

None of the options I see are outright amazing, but here's what I can come up with:

If you only care about the most recent run, you should be able to obtain this from the rundetails table of the database, the SchedulerHistoryService, or the Scheduler Details admin page.

For more long-running histories, there is an INFO level log from com.atlassian.greenhopper.service.lexorank.balance.LexoRankBalancer when it completes:

log.info("Balancing of field with id [%d] completed with %d errors", fieldId, errors.getErrors().size());

so you can look for that.  If you also want to know more than this, then you could try enabling DEBUG level logging for that same class, but this probably reports way too much detail to be of any practical use on a production system, as it logs activity for each individual issue that it visits.  LexoRankBalancingService in that same package also looks to be a bit too noisy at DEBUG, but that is another one you could consider.

If you are willing to write your own P2 plugin, you could listen for the series of analytics events that are published by these classes, such as LexoRankBalanceStartAnalyticsEvent, and log them yourself.

[dmitri]

thanks. unfortunately i think we're logging at WARN for that topic. what should i be looking for in the rundetails table? i see

select * from rundetails where JOB_ID like '%lexo%'
ID	JOB_ID	START_TIME	RUN_DURATION	RUN_OUTCOME	INFO_MESSAGE
14741425	CompatibilityPluginScheduler.JobId.LEXO_RANK_SCHEDULER_JOB	2016-10-04 16:08:36.850	2	S	
14740925	JiraPluginScheduler:LEXO_RANK_STATS_COLLECTOR_JOB	2016-10-04 16:09:17.787	1	S

are these relevant?

[crf]

Yes.  The CompatibilityPluginScheduler.JobId.LEXO_RANK_SCHEDULER_JOB should be the one that you want.  I don't normally work on JIRA Software, but if I'm following the code correctly, the job is just a trigger and the actual balancing runs in a separate thread, so the rundetails entry would be telling you when the balance started, but if you wanted to know when it was finished, the duration it reports there is not helpful.

[Steven F Behnke]

It is available via REST API and via a management screen: 

https://confluence.atlassian.com/jirakb/lexorank-management-779159218.html

[dmitri]

I believe that only shows if it's currently running. I was wondering if it's possible to see the history of when it started/stopped (e.g. is there a log message?)

[Steven F Behnke]

Sorry, that I do not know. It doesn't show up in the Audit Log at all. I am unsure of what prints in the application log.