Job inspector output for one of the slow searches (note that it only took 14 sec. but that's only for the last 15 minutes)
This search has completed and has returned 23 results by scanning 309 events in 13.604 seconds.
The following messages were returned by the search subsystem:
DEBUG: base lispy: [ AND index::sitescope sourcetype::sitescope_daily_log ]
DEBUG: search context: user="admin", app="glg", bs-pathname="/opt/splunk/etc"
(SID: 1395958659.213)
Execution costs
Duration (seconds) Component Invocations Input count Output count
0.002 command.fields 4 38 38
0.001 command.presort 1 23 23
0.001 command.rename 1 23 23
13.403 command.search 4 - 38
0.005 command.search.index 4 - -
0.004 command.search.filter 3 - -
0.003 command.search.fieldalias 3 309 309
0.002 command.search.calcfields 3 309 309
0 command.search.index.usec_1_8 50 - -
0 command.search.index.usec_8_64 2 - -
13.382 command.search.kv 3 - -
0.013 command.search.rawdata 3 - -
0.006 command.search.typer 4 38 38
0.004 command.search.tags 4 38 38
0.003 command.search.lookups 3 309 309
0 command.search.summary 4 - -
0.001 command.sort 1 23 23
0.004 command.stats.execute_input 5 - -
0.001 command.stats.execute_output 1 - -
0.001 command.table 1 23 46
0.002 dispatch.check_disk_usage 2 - -
0.056 dispatch.createProviderQueue 1 - -
0.12 dispatch.evaluate 1 - -
0.119 dispatch.evaluate.search 1 - -
0.001 dispatch.evaluate.rename 1 - -
0.001 dispatch.evaluate.sort 1 - -
0.001 dispatch.evaluate.stats 1 - -
0.001 dispatch.evaluate.table 1 - -
13.405 dispatch.fetch 5 - -
0.001 dispatch.preview 1 - -
0.001 dispatch.preview.command.presort 1 23 23
0.001 dispatch.preview.command.rename 1 23 23
0.001 dispatch.preview.command.sort 1 23 23
0.001 dispatch.preview.command.table 1 23 46
0.001 dispatch.preview.stats.execute_output 1 - -
0.001 dispatch.preview.write_results_to_disk 1 - -
13.403 dispatch.stream.local 4 - -
0.016 dispatch.timeline 5 - -
0.013 dispatch.writeStatus 7 - -
0.062 startup.handoff 1 - -
Search job properties
canSummarize 1
createTime 2014-03-27T16:17:39.000-06:00
cursorTime 2014-03-27T16:02:00.000-06:00
custom {'dispatch.earliest_time': '-15m', 'display.general.type': 'events', 'search': 'index=sitescope sourcetype=sitescope_daily_log sis_monitor_host=* | stats count by sis_monitor_host sis_monitor_status | table sis_monitor_host sis_monitor_status count | sort sis_monitor_status,-count | rename sis_monitor_host as MonitoredHost, sis_monitor_status as "Status", count as "Count"', 'dispatch.latest_time': 'now'}
defaultSaveTTL 604800
defaultTTL 600
delegate None
diskUsage 237568
dispatchState DONE
doneProgress 1.0
dropCount 0
eai:acl {'sharing': 'global', 'app': 'glg', 'modifiable': '1', 'perms': {'read': ['admin'], 'write': ['admin']}, 'owner': 'admin', 'can_write': '1', 'ttl': '600'}
earliestTime 2014-03-27T16:02:39.000-06:00
eventAvailableCount 38
eventCount 38
eventFieldCount 30
eventIsStreaming True
eventIsTruncated False
eventSearch search index=sitescope sourcetype=sitescope_daily_log sis_monitor_host=*
eventSorting desc
indexEarliestTime 1395957779
indexLatestTime 1395958558
isBatchModeSearch False
isDone True
isFailed False
isFinalized False
isGoodSummarizationCandidate 1
isPaused False
isPreviewEnabled True
isRealTimeSearch False
isRemoteTimeline False
isSaved False
isSavedSearch False
isZombie False
keywords index::sitescope sis_monitor_host::* sourcetype::sitescope_daily_log
label None
latestTime 2014-03-27T16:17:39.000-06:00
meanPreviewPeriod 13.604000
messages {'debug': ['base lispy: [ AND index::sitescope sourcetype::sitescope_daily_log ]', 'search context: user="admin", app="glg", bs-pathname="/opt/splunk/etc"']}
modifiedTime 2014-03-27T16:18:35.742-06:00
normalizedSearch litsearch index=sitescope sourcetype=sitescope_daily_log sis_monitor_host=* | fields keepcolorder=t "" "bkt" "_cd" "_si" "host" "index" "linecount" "prestats_reserved" "psrsvd_" "sis_monitor_host" "sis_monitor_status" "source" "sourcetype" "splunk_server"
numPreviews 1
performance {'dispatch.evaluate.search': {'duration_secs': '0.119000', 'invocations': '1'}, 'command.search.index.usec_1_8': {'invocations': '50'}, 'command.search.typer': {'input_count': '38', 'invocations': '4', 'output_count': '38', 'duration_secs': '0.006000'}, 'command.search.fieldalias': {'input_count': '309', 'invocations': '3', 'output_count': '309', 'duration_secs': '0.003000'}, 'command.search.index': {'duration_secs': '0.005000', 'invocations': '4'}, 'dispatch.evaluate.sort': {'duration_secs': '0.001000', 'invocations': '1'}, 'dispatch.preview.command.sort': {'input_count': '23', 'invocations': '1', 'output_count': '23', 'duration_secs': '0.001000'}, 'command.search.filter': {'duration_secs': '0.004000', 'invocations': '3'}, 'command.search.index.usec_8_64': {'invocations': '2'}, 'dispatch.preview.command.table': {'input_count': '23', 'invocations': '1', 'output_count': '46', 'duration_secs': '0.001000'}, 'dispatch.createProviderQueue': {'duration_secs': '0.056000', 'invocations': '1'}, 'command.rename': {'input_count': '23', 'invocations': '1', 'output_count': '23', 'duration_secs': '0.001000'}, 'command.search.lookups': {'input_count': '309', 'invocations': '3', 'output_count': '309', 'duration_secs': '0.003000'}, 'dispatch.evaluate.rename': {'duration_secs': '0.001000', 'invocations': '1'}, 'command.search.calcfields': {'input_count': '309', 'invocations': '3', 'output_count': '309', 'duration_secs': '0.002000'}, 'command.fields': {'input_count': '38', 'invocations': '4', 'output_count': '38', 'duration_secs': '0.002000'}, 'dispatch.evaluate': {'duration_secs': '0.120000', 'invocations': '1'}, 'command.sort': {'input_count': '23', 'invocations': '1', 'output_count': '23', 'duration_secs': '0.001000'}, 'startup.handoff': {'duration_secs': '0.062000', 'invocations': '1'}, 'command.stats.execute_output': {'duration_secs': '0.001000', 'invocations': '1'}, 'dispatch.preview.command.rename': {'input_count': '23', 'invocations': '1', 'output_count': '23', 'duration_secs': '0.001000'}, 'dispatch.evaluate.stats': {'duration_secs': '0.001000', 'invocations': '1'}, 'command.table': {'input_count': '23', 'invocations': '1', 'output_count': '46', 'duration_secs': '0.001000'}, 'dispatch.check_disk_usage': {'duration_secs': '0.002000', 'invocations': '2'}, 'dispatch.evaluate.table': {'duration_secs': '0.001000', 'invocations': '1'}, 'dispatch.writeStatus': {'duration_secs': '0.013000', 'invocations': '7'}, 'command.search.kv': {'duration_secs': '13.382000', 'invocations': '3'}, 'dispatch.preview.stats.execute_output': {'duration_secs': '0.001000', 'invocations': '1'}, 'command.presort': {'input_count': '23', 'invocations': '1', 'output_count': '23', 'duration_secs': '0.001000'}, 'command.search.tags': {'input_count': '38', 'invocations': '4', 'output_count': '38', 'duration_secs': '0.004000'}, 'dispatch.stream.local': {'duration_secs': '13.403000', 'invocations': '4'}, 'dispatch.preview.write_results_to_disk': {'duration_secs': '0.001000', 'invocations': '1'}, 'command.search.summary': {'invocations': '4'}, 'dispatch.fetch': {'duration_secs': '13.405000', 'invocations': '5'}, 'command.search.rawdata': {'duration_secs': '0.013000', 'invocations': '3'}, 'dispatch.preview': {'duration_secs': '0.001000', 'invocations': '1'}, 'command.stats.execute_input': {'duration_secs': '0.004000', 'invocations': '5'}, 'dispatch.preview.command.presort': {'input_count': '23', 'invocations': '1', 'output_count': '23', 'duration_secs': '0.001000'}, 'command.search': {'input_count': '0', 'invocations': '4', 'output_count': '38', 'duration_secs': '13.403000'}, 'dispatch.timeline': {'duration_secs': '0.016000', 'invocations': '5'}}
pid 8822
priority 5
reduceSearch sistats count by sis_monitor_host sis_monitor_status
remoteSearch litsearch index=sitescope sourcetype=sitescope_daily_log sis_monitor_host= | fields keepcolorder=t "" "bkt" "_cd" "_si" "host" "index" "linecount" "prestats_reserved" "psrsvd_" "sis_monitor_host" "sis_monitor_status" "source" "sourcetype" "splunk_server"
reportSearch stats count by sis_monitor_host sis_monitor_status | table sis_monitor_host sis_monitor_status count | sort sis_monitor_status,-count | rename sis_monitor_host as MonitoredHost, sis_monitor_status as "Status", count as "Count"
request {'auto_cancel': '30', 'adhoc_search_level': 'verbose', 'custom.dispatch.earliest_time': '-15m', 'status_buckets': '300', 'rf': '', 'custom.dispatch.latest_time': 'now', 'indexedRealtime': None, 'search': 'search index=sitescope sourcetype=sitescope_daily_log sis_monitor_host=* | stats count by sis_monitor_host sis_monitor_status | table sis_monitor_host sis_monitor_status count | sort sis_monitor_status,-count | rename sis_monitor_host as MonitoredHost, sis_monitor_status as "Status", count as "Count"', 'earliest_time': '-15m', 'custom.search': 'index=sitescope sourcetype=sitescope_daily_log sis_monitor_host=* | stats count by sis_monitor_host sis_monitor_status | table sis_monitor_host sis_monitor_status count | sort sis_monitor_status,-count | rename sis_monitor_host as MonitoredHost, sis_monitor_status as "Status", count as "Count"', 'ui_dispatch_app': 'glg', 'preview': '1', 'latest_time': 'now'}
resultCount 23
resultIsStreaming False
resultPreviewCount 23
runDuration 13.604
runtime {'auto_cancel': '30', 'auto_pause': '0'}
scanCount 309
search search index=sitescope sourcetype=sitescope_daily_log sis_monitor_host=* | stats count by sis_monitor_host sis_monitor_status | table sis_monitor_host sis_monitor_status count | sort sis_monitor_status,-count | rename sis_monitor_host as MonitoredHost, sis_monitor_status as "Status", count as "Count"
searchEarliestTime 1395957759.000000000
searchLatestTime 1395958659.000000000
searchProviders ['slc-srv-splunk.glg.local']
sid 1395958659.213
statusBuckets 300
ttl 600
Additional info timeline field summary search.log
... View more