Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

bishtk — Tue, 29 Sep 2020 15:30:54 GMT

Hi,

Splunk Indexer got shutdown on its own and found below error messages in splunkd.log

"08-25-2017 16:13:20.777 +0200 INFO DatabaseDirectoryManager - Getting size on disk: Unable to get size on disk for bucket id=cal_a350~80~BFD443F7-AE01-4018-BE92-A82EA7410435 path="/opt/splunk/var/lib/splunk/index_name1/db/hot_v1_80" (This is usually harmless as we may be racing with a rename in BucketMover or the S2SFileReceiver thread, which should be obvious in log file; the previous WARN message about this path can safely be ignored.) caller=getCumulativeSizeForPaths
08-25-2017 16:13:22.627 +0200 WARN timeinvertedIndex - bucket=/opt/splunk/var/lib/splunk/index_name2/db/hot_v1_277 Already running 6 splunk-optimize's, max=6
08-25-2017 16:13:22.627 +0200 WARN timeinvertedIndex - bucket=/opt/splunk/var/lib/splunk/index_name2/db/hot_v1_278 Already running 6 splunk-optimize's, max=6
08-25-2017 16:13:22.627 +0200 WARN timeinvertedIndex - bucket=/opt/splunk/var/lib/splunk/index_name2/db/hot_quar_v1_276 Already running 6 splunk-optimize's, max=6
08-25-2017 16:13:26.626 +0200 WARN timeinvertedIndex - bucket=/opt/splunk/var/lib/splunk/index_name3/db/hot_v1_153 Already running 6 splunk-optimize's, max=6
08-25-2017 16:13:26.849 +0200 ERROR AdminHandler:ServerControl - forcing shutdown since it did not complete in 360 seconds"

I have searched online for the cause behind this shutdown, but didn't find anything useful.
Please let me know if you have any information on the same or if any of you have faced this issue?

Thanks,

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

hardikJsheth — Mon, 28 Aug 2017 11:26:25 GMT

Look out for any crash logs generated within $SPLUNK_HOME/val/log/splunk/ folder. If you don't find any crash logs, check crash message of your OS using command "dmesg" or equivalent as per your os.

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

s2_splunk — Mon, 28 Aug 2017 15:28:23 GMT

The message 08-25-2017 16:13:26.849 +0200 ERROR AdminHandler:ServerControl - forcing shutdown since it did not complete in 360 seconds" indicates that someone or something initiated a splunk stop command ~360 seconds before this message is being logged.
What log entries do you see around 16:07:26, i.e. 6 minutes before this message is logged?

Also, what version of Splunk are you running?

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

bishtk — Tue, 29 Sep 2020 15:31:29 GMT

@s2_splunk
Thanks
Splunk Version currently in use is Splunk 6.2.0 (build 237341)
(NOTE: We are in planning phase to migrate On-Premise to Splunk Cloud)

As per your suggestion I have checked for the log entries and found below Shutdown entries around that time:
Please let me know your views on it

"08-25-2017 16:07:05.562 +0200 INFO DatabaseDirectoryManager - Getting size on disk: Unable to get size on disk for bucket id=index_name1~325~BFD443F7-AE01-4018-BE92-A82EA7410435 path="/mnt/splunklv2/splunk/var/lib/splunk/index_name1/colddb/db_1474373027_1474143531_325" (This is usually harmless as we may be racing with a rename in BucketMover or the S2SFileReceiver thread, which should be obvious in log file; the previous WARN message about this path can safely be ignored.) caller=getBucketManifestValues
08-25-2017 16:07:06.277 +0200 INFO DC:DeploymentClient - channel=tenantService/handshake Will retry sending handshake message to DS; err=not_connected
08-25-2017 16:07:18.278 +0200 INFO DC:DeploymentClient - channel=tenantService/handshake Will retry sending handshake message to DS; err=not_connected
08-25-2017 16:07:21.496 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_debug.sh" /bin/sh: /opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_debug.sh: No such file or directory
08-25-2017 16:07:21.580 +0200 WARN DateParserVerbose - Failed to parse timestamp. Defaulting to timestamp of previous event (Sat Jul 23 00:00:00 2011). Context: source::ps_all_sos|host::INDEXER_HOSTNAME|ps|0
08-25-2017 16:07:21.583 +0200 WARN DateParserVerbose - Failed to parse timestamp. Defaulting to timestamp of previous event (Sat Nov 2 00:00:00 2013). Context: source::ps_all_sos|host::INDEXER_HOSTNAME|ps|0
08-25-2017 16:07:21.585 +0200 WARN DateParserVerbose - Failed to parse timestamp. Defaulting to timestamp of previous event (Tue Oct 30 00:00:00 2012). Context: source::ps_all_sos|host::INDEXER_HOSTNAME|ps|0
08-25-2017 16:07:21.594 +0200 WARN DateParserVerbose - Failed to parse timestamp. Defaulting to timestamp of previous event (Sun Aug 27 00:00:00 2017). Context: source::ps_all_sos|host::INDEXER_HOSTNAME|ps|0
08-25-2017 16:07:21.698 +0200 INFO PipelineComponent - Performing early shutdown tasks
08-25-2017 16:07:21.698 +0200 INFO IndexProcessor - handleSignal : Disabling streaming searches.
08-25-2017 16:07:21.698 +0200 INFO IndexProcessor - request state change from=RUN to=SHUTDOWN_SIGNALED
08-25-2017 16:07:22.699 +0200 INFO IndexProcessor - active realtime streams have hit 0 during shutdown
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0001_2013_06_14-061325.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0487_2017_01_06-083424.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0488_2017_01_06-134917.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0489_2017_01_10-074445.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0491_2017_01_11-083152.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0492_2017_01_13-081712.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0493_2017_01_31-124809.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0494_2017_02_02-083130.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0495_2017_02_03-052048.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0496_2017_02_03-151920.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0497_2017_02_06-054822.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0498_2017_02_06-115012.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0499_2017_02_06-133826.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0500_2017_02_07-091032.cubadcn': Operation not permitted
08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0501_2017_02_07-122750.cubadcn': Operation not permitted 08-25-2017 16:07:26.735 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/ADCN/A350_0001_F0502_2017_02_08-093158.cubadcn': Operation not permitted
.
.
.
.
.
.
08-25-2017 16:07:26.769 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of /mnt/slv01/import/APP_NAME1/NCD/A350_0071_F0087_2017_06_19_122116.ncd.gz': Operation not permitted 08-25-2017 16:07:26.769 +0200 ERROR ExecProcessor - message from "/opt/splunk/etc/apps/APP_NAME1/bin/APP_NAME1_preprocessing_manual.sh" chmod: changing permissions of/mnt/slv01/import/APP_NAME1/NCD/A350_0071_F0087_2017_06_19_133053.ncd.gz': Operation not permitted
08-25-2017 16:07:26.848 +0200 INFO loader - Shutdown HTTPDispatchThread
08-25-2017 16:07:26.849 +0200 INFO ShutdownHandler - Shutting down splunkd
08-25-2017 16:07:26.849 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_Begin"
08-25-2017 16:07:26.849 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_KVStore"
08-25-2017 16:07:26.849 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_Thruput"
08-25-2017 16:07:26.849 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_TcpInput1"
08-25-2017 16:07:26.849 +0200 INFO TcpInputProc - Running shutdown level 1. Closing listening ports.
08-25-2017 16:07:26.849 +0200 INFO TcpInputProc - Shutting down listening ports
08-25-2017 16:07:26.849 +0200 INFO TcpInputProc - Stopping IPv4 port 9997
08-25-2017 16:07:26.849 +0200 INFO TcpInputProc - Setting up input quiesce timeout for : 90 secs
08-25-2017 16:07:27.653 +0200 INFO TcpInputProc - Waiting for connection from src=SEARCHHEAD_IP:44338 to close before shutting down TcpInputProcessor.
08-25-2017 16:07:28.529 +0200 ERROR ArchiveContext - inflate failure: invalid token
08-25-2017 16:07:30.146 +0200 WARN IniFile - /opt/splunk/etc/apps/learned/local/props.conf, line 1: Cannot parse into key-value pair: rue
08-25-2017 16:07:30.278 +0200 INFO DC:DeploymentClient - channel=tenantService/handshake Will retry sending handshake message to DS; err=not_connected
.
.
.
.
08-25-2017 16:07:42.469 +0200 INFO ArchiveProcessor - handling file=/mnt/filer003/splunk_input/a350/qtr/IMO_Logs.20170721103232.A7-ALK.zip
08-25-2017 16:07:42.588 +0200 INFO ArchiveProcessor - new tailer already processed path=/mnt/filer003/splunk_input/a350/qtr/IMO_Logs.20170721103232.A7-ALK.zip
08-25-2017 16:07:42.639 +0200 INFO ArchiveProcessor - handling file=/mnt/filer003/splunk_input/a350/qtr/IMO_Logs.20170724050753.A7-ALK.zip
08-25-2017 16:07:42.668 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_TcpOutput"
08-25-2017 16:07:42.668 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_UdpInput"
08-25-2017 16:07:42.669 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_FifoInput"
08-25-2017 16:07:42.669 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_WinEventLogInput"
08-25-2017 16:07:42.669 +0200 INFO ShutdownHandler - shutting down level "ShutdownLevel_Scheduler"
08-25-2017 16:07:42.758 +0200 INFO ArchiveProcessor - new tailer already processed path=/mnt/filer003/splunk_input/a350/qtr/IMO_Logs.20170724050753.A7-ALK.zip"

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

bishtk — Fri, 01 Sep 2017 04:45:53 GMT

Hi @ssievert_splunk
Please let me know your findings, if you were able to go through the log entries I have pasted. Thanks

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

s2_splunk — Fri, 01 Sep 2017 21:25:10 GMT

The line

08-25-2017 16:07:21.698 +0200 INFO PipelineComponent - Performing early shutdown tasks

indicates that something or somebody issued a splunk stop command at that time.

topic Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log in Getting Data In

Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log

Re: Splunk indexer got shutdown with "AdminHandler:ServerControl" error message in splunkd.log