# Indexing Stats - cost of indexing custom fields

*(The indexing-stats log presented on this page is available for Jira 8.1 and later.)*

The most expensive part of indexing is creating a Lucene Document to be indexed.

Here are the logs that can help in determining which field indexers are the "most expensive" (in time) and how they affect the overall indexing time.

## Periodic Stats

These indexing stats are logged every 5mins. During the full foreground reindex they will relate only to the foreground indexing. During normal Jira operation this will be the measuring "normal" indexing tasks, caused by user actions or any other indexing action (like background indexing, de-archiving, and the like).

```
[indexing-stats] Top 10 addIndex total (noFieldIndexers: 68, sum: 10203600ms): [
{field: customfield_10000 (Approvals),
addIndex: {sum/allSum:21.1%, sum:2151531ms, avg:7.8ms, max:2750ms, count:274370}},
{field: customfield_10304 (Change reason),
addIndex: {sum/allSum:15.8%, sum:1613150ms, avg:5.9ms, max:812ms, count:274379}},
{field: issuelinks,
addIndex: {sum/allSum:9.9%, sum:1005236ms, avg:3.7ms, max:809ms, count:274374}},
...]
[indexing-stats] Top 10 addIndex snapshot (noFieldIndexers: 68, sum: 3427078ms) ...
```

**Top 10 addIndex total**- top most expensive indexing fields “forever”; “total” is “forever”, which means since this Jira started or since the start of the last re-index.**Top 10 addIndex snapshot**- top most expensive indexing fields in the last few minutes; “snapshot” means these are stats since the last snapshot (5min)**(noFieldIndexers: 68, sum: 10203600ms)**- number of field indexers and total sum of all indexers**field: customfield_10000 (Approvals):**- identifiable field name**addIndex: sum/allSum**- time spent on this field vs all fields**addIndex: sum,avg,max**- sum / avg / max time spend on this field**addIndex: count**- number of calls

## After Re-index stats

These are indexing stats presented after a full background re-index finished. They are the most accurate as during this time Jira is not doing anything else and present the cost of __ all field indexers and how they affected the overall indexing time__.

```
[indexing-stats] field indexing cost:
{order:1,
name:customfield_10000 (Approvals),
isKnown:false,
addIndex: {sum:2328373ms, avg:7.7ms, max:2750ms, count:302109},
totalIndexTime:984864ms,
addIndexSum/totalIndexTime:236.4%,
numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:2,...
...
[indexing-stats] field indexing cost: {order:68,...
```

This log shows you the cost of all field indexers (order by the cost DESC).

**order**- 1 most expensive**name:customfield_10000 (Approvals)**- field name**isKnown:false**- if true this is a system custom field (Jira Core internal)**addIndex sum / avg / max / count**- cost as in previous log message**totalIndexTime**- total re-indexing time**addIndexSum/totalIndexTime**- cost (in time) of getting this field vs total re-index time; because we have many indexing threads this can be more than 100%**numberOfIndexingThreads**- number of indexing threads (mentioned in the previous metric)

## Example

Example data from Jira Service Management 4.0 with Jira 8.1 with 300k issues.

### Periodic logs

```
[indexing-stats] Top 10 addIndex total (noFieldIndexers: 66, sum: 32140610ms): [
{field: customfield_10201 (Time to resolution), addIndex: {sum/allSum:11.2%, sum:3595247ms, avg:12.3ms, max:2555ms, count:291614}},
{field: customfield_10202 (Time to first response), addIndex: {sum/allSum:10.7%, sum:3443150ms, avg:11.8ms, max:1403ms, count:291609}},
{field: customfield_10401 (Custom2), addIndex: {sum/allSum:5.4%, sum:1736124ms, avg:6.0ms, max:1402ms, count:291606}},
{field: customfield_10404 (Custom5), addIndex: {sum/allSum:5.3%, sum:1702518ms, avg:5.8ms, max:1403ms, count:291605}},
{field: customfield_10317 (Time to approve normal change), addIndex: {sum/allSum:5.3%, sum:1688969ms, avg:5.8ms, max:969ms, count:291613}},
{field: customfield_10402 (Custom3), addIndex: {sum/allSum:5.2%, sum:1659112ms, avg:5.7ms, max:1400ms, count:291599}},
{field: customfield_10406 (Custom7), addIndex: {sum/allSum:5.2%, sum:1655281ms, avg:5.7ms, max:222ms, count:291606}},
{field: customfield_10400 (Custom1), addIndex: {sum/allSum:5.1%, sum:1652856ms, avg:5.7ms, max:1400ms, count:291612}},
{field: customfield_10316 (Time to close after resolution), addIndex: {sum/allSum:5.1%, sum:1648315ms, avg:5.7ms, max:1403ms, count:291606}},
{field: customfield_10405 (Custom6), addIndex: {sum/allSum:5.1%, sum:1633478ms, avg:5.6ms, max:218ms, count:291604}}]
[indexing-stats] Top 10 addIndex snapshot (noFieldIndexers: 66, sum: 4756291ms): [
{field: customfield_10201 (Time to resolution), addIndex: {sum/allSum:11.3%, sum:536496ms, avg:12.4ms, max:228ms, count:43370}},
{field: customfield_10202 (Time to first response), addIndex: {sum/allSum:10.8%, sum:512125ms, avg:11.8ms, max:221ms, count:43372}},
{field: customfield_10401 (Custom2), addIndex: {sum/allSum:5.4%, sum:258216ms, avg:6.0ms, max:208ms, count:43371}},
{field: customfield_10317 (Time to approve normal change), addIndex: {sum/allSum:5.3%, sum:253002ms, avg:5.8ms, max:210ms, count:43370}},
{field: customfield_10400 (Custom1), addIndex: {sum/allSum:5.2%, sum:245748ms, avg:5.7ms, max:209ms, count:43371}},
{field: customfield_10316 (Time to close after resolution), addIndex: {sum/allSum:5.1%, sum:244812ms, avg:5.6ms, max:207ms, count:43372}},
{field: customfield_10406 (Custom7), addIndex: {sum/allSum:5.1%, sum:243580ms, avg:5.6ms, max:206ms, count:43369}},
{field: customfield_10404 (Custom5), addIndex: {sum/allSum:5.1%, sum:243121ms, avg:5.6ms, max:214ms, count:43373}},
{field: customfield_10402 (Custom3), addIndex: {sum/allSum:5.1%, sum:242026ms, avg:5.6ms, max:216ms, count:43369}},
{field: customfield_10403 (Custom4), addIndex: {sum/allSum:5.1%, sum:241619ms, avg:5.6ms, max:217ms, count:43372}}]
```

After re-index logs

```
ReindexAll took: 2203668 ms in foreground
[indexing-stats] field indexing cost: {order:1, name:customfield_10202 (Time to first response), isKnown:false, addIndex: {sum:3554163ms, avg:11.8ms, max:1468ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:161.3%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:2, name:customfield_10201 (Time to resolution), isKnown:false, addIndex: {sum:3500704ms, avg:11.6ms, max:1458ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:158.9%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:3, name:customfield_10000 (Approvals), isKnown:false, addIndex: {sum:2410210ms, avg:8.0ms, max:1456ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:109.4%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:4, name:customfield_10404 (Custom5), isKnown:false, addIndex: {sum:1745079ms, avg:5.8ms, max:1456ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:79.2%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:5, name:customfield_10317 (Time to approve normal change), isKnown:false, addIndex: {sum:1740746ms, avg:5.8ms, max:1456ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:79.0%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:6, name:customfield_10401 (Custom2), isKnown:false, addIndex: {sum:1709668ms, avg:5.7ms, max:218ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:77.6%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:7, name:customfield_10400 (Custom1), isKnown:false, addIndex: {sum:1705397ms, avg:5.6ms, max:1460ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:77.4%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:8, name:customfield_10402 (Custom3), isKnown:false, addIndex: {sum:1704191ms, avg:5.6ms, max:215ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:77.3%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:9, name:customfield_10406 (Custom7), isKnown:false, addIndex: {sum:1703002ms, avg:5.6ms, max:1458ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:77.3%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:10, name:customfield_10316 (Time to close after resolution), isKnown:false, addIndex: {sum:1694045ms, avg:5.6ms, max:214ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:76.9%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:11, name:customfield_10407 (Custom8), isKnown:false, addIndex: {sum:1689112ms, avg:5.6ms, max:1456ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:76.7%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:12, name:customfield_10405 (Custom6), isKnown:false, addIndex: {sum:1684330ms, avg:5.6ms, max:1457ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:76.4%, numberOfIndexingThreads:20}
[indexing-stats] field indexing cost: {order:13, name:customfield_10403 (Custom4), isKnown:false, addIndex: {sum:1682427ms, avg:5.6ms, max:257ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:76.3%, numberOfIndexingThreads:20}
...
[indexing-stats] field indexing cost: {order:68, name:workratio, isKnown:false, addIndex: {sum:140ms, avg:0.0ms, max:2ms, count:302109}, totalIndexTime:2203668ms, addIndexSum/totalIndexTime:0.0%, numberOfIndexingThreads:20}
Reindex took: 2203668ms. Indexer: DefaultIndexManager: paths: [/home/ubuntu/jirahome/caches/indexesV1/comments, /home/ubuntu/jirahome/caches/indexesV1/issues, /home/ubuntu/jirahome/caches/indexesV1/changes, /home/ubuntu/jirahome/caches/indexesV1/worklogs, /home/ubuntu/jirahome/caches/indexesV1/plugins/servicedeskcannedresponses]
```

In this case the full re-index took: 2203668 ms in foreground, which is **37min.**

Let’s look at the most expensive indexing field:

```
[indexing-stats] field indexing cost: {order:1, name:customfield_10202 (Time to first response), isKnown:false,
addIndex: {sum:3554163ms, avg:11.8ms, max:1468ms, count:302109},
totalIndexTime:2203668ms, addIndexSum/totalIndexTime:161.3%, numberOfIndexingThreads:20}
```

Getting data for `name: customfield_10202`

`(Time to first response)`

took 3554163ms, which is **59min**. Remember that to increase the performance of loading the data we have multiple indexing threads: `numberOfIndexingThreads:20`

.

The second one on the list is `customfield_10201`

`(Time to resolution)`

that took 3500704ms, which is **58min.**

```
[indexing-stats] field indexing cost: {order:2, name:customfield_10201 (Time to resolution), isKnown:false,
addIndex: {sum:3500704ms, avg:11.6ms, max:1458ms, count:302109},
totalIndexTime:2203668ms, addIndexSum/totalIndexTime:158.9%, numberOfIndexingThreads:20}
```

The 3rd on the list is `customfield_10000 (Approvals)`

with 2410210ms, which is **40min**.

So getting data for those 3 custom fields took 161% + 158% + 109% = 428% of indexing time, so more than 4 out of 20 indexing threads would be used just to load data for those 3 fields.