No Messages In or Out after rebooting Graylog Server

rrmike · November 16, 2021, 9:17pm

Description of your problem

After rebooting the Graylog server no message are coming in or out.

Description of steps you’ve taken to attempt to solve the issue

I thought it might be a problem with iptables, but they are persistent after the reboot.

```
# Generated by iptables-save v1.6.1 on Wed Sep 22 09:29:43 2021
*nat
:PREROUTING ACCEPT [360:45924]
:INPUT ACCEPT [3:182]
:OUTPUT ACCEPT [57:3591]
:POSTROUTING ACCEPT [57:3591]
-A PREROUTING -p tcp -m tcp --dport 514 -j REDIRECT --to-ports 1514
-A PREROUTING -p udp -m udp --dport 514 -j REDIRECT --to-ports 1514
COMMIT
# Completed on Wed Sep 22 09:29:43 2021
# Generated by iptables-save v1.6.1 on Wed Sep 22 09:29:43 2021
*filter
:INPUT ACCEPT [6207039:4313946592]
:FORWARD ACCEPT [0:0]
:OUTPUT ACCEPT [2529722:1022112025]
COMMIT
# Completed on Wed Sep 22 09:29:43 2021
```

I’ve looked through the forums and nothing seems to be similar to what I’m experiencing.

I’m running Ubuntu 18.04 on Hyper-v. I’ll created a checkpoint prior to rebooting and if I roll back to that checkpoint Graylog works.

Environmental information

Operating system information

Hyper-V Server 2019
Ubuntu 18.04

Package versions

Graylog 4.2.0+5adccc3 on graylog (Private Build 1.8.0_292 on Linux 4.15.0-159-generic)
MongoDB v4.0.27
Elasticsearch 7.10.2

tmacgbay · November 16, 2021, 9:24pm

Was it working before? What lead you to believe it was iptables? What changed after your hyper-v checkpoint other than a reboot? Was it an upgrade of Graylog or the OS or both? What are you seeing in your Graylog logs? You can watch them with:

tail -f /var/log/graylog-server/server.log

rrmike · November 16, 2021, 9:57pm

Was it working before?
Yes
What lead you to believe it was iptables?
I struggled with iptables when I installed Graylog. I also rebooted the server once before and got it working. I remember playing around with iptables, but I don’t think that is was what made it work in the end.
What changed after your hyper-v checkpoint other than a reboot?
Nothing changed.
Was it an upgrade of Graylog or the OS or both?
No upgrade to Graylog or the OS
Graylog logs
The log file from the point of the reboot is to large to post here. This is what the forum will allow.


2021-11-16T16:38:29.545-05:00 WARN  [ClusterEventPeriodical] Error while reading cluster events from MongoDB, retrying.
com.mongodb.MongoQueryException: Query failed with error code 11600 and error message 'interrupted at shutdown' on server localhost:27017
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:735) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.OperationHelper.withReadConnectionSource(OperationHelper.java:463) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:89) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:196) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:177) ~[graylog.jar:?]
        at com.mongodb.DBCursor.initializeCursor(DBCursor.java:989) ~[graylog.jar:?]
        at com.mongodb.DBCursor.hasNext(DBCursor.java:172) ~[graylog.jar:?]
        at org.mongojack.DBCursor.hasNext(DBCursor.java:330) ~[graylog.jar:?]
        at org.graylog2.events.ClusterEventPeriodical.doRun(ClusterEventPeriodical.java:152) [graylog.jar:?]
        at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:77) [graylog.jar:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_292]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_292]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_292]
2021-11-16T16:38:29.545-05:00 ERROR [NodePingThread] Uncaught exception in periodical
com.mongodb.MongoQueryException: Query failed with error code 11600 and error message 'interrupted at shutdown' on server localhost:27017
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:735) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.OperationHelper.withReadConnectionSource(OperationHelper.java:463) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:89) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:196) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:177) ~[graylog.jar:?]
        at com.mongodb.DBCursor.initializeCursor(DBCursor.java:989) ~[graylog.jar:?]
        at com.mongodb.DBCursor.hasNext(DBCursor.java:172) ~[graylog.jar:?]
        at com.mongodb.DBCursor.one(DBCursor.java:790) ~[graylog.jar:?]
        at com.mongodb.DBCollection.findOne(DBCollection.java:867) ~[graylog.jar:?]
        at com.mongodb.DBCollection.findOne(DBCollection.java:827) ~[graylog.jar:?]
        at com.mongodb.DBCollection.findOne(DBCollection.java:770) ~[graylog.jar:?]
        at org.graylog2.database.PersistedServiceImpl.findOne(PersistedServiceImpl.java:128) ~[graylog.jar:?]
        at org.graylog2.cluster.NodeServiceImpl.byNodeId(NodeServiceImpl.java:73) ~[graylog.jar:?]
        at org.graylog2.cluster.NodeServiceImpl.byNodeId(NodeServiceImpl.java:84) ~[graylog.jar:?]
        at org.graylog2.periodical.NodePingThread.doRun(NodePingThread.java:62) ~[graylog.jar:?]
        at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:77) [graylog.jar:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_292]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_292]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_292]
2021-11-16T16:38:29.545-05:00 INFO  [cluster] Cluster description not yet available. Waiting for 30000 ms before timing out
2021-11-16T16:38:29.546-05:00 INFO  [cluster] Cluster description not yet available. Waiting for 30000 ms before timing out
2021-11-16T16:38:29.544-05:00 ERROR [AWSInstanceNameLookupProcessor] Could not refresh AWS instance lookup table.
java.util.concurrent.ExecutionException: com.mongodb.MongoQueryException: Query failed with error code 11600 and error message 'interrupted at shutdown' on server localhost:27017
        at com.github.rholder.retry.Retryer$ExceptionAttempt.<init>(Retryer.java:254) ~[graylog.jar:?]
        at com.github.rholder.retry.Retryer.call(Retryer.java:163) ~[graylog.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor.waitForMigrationCompletion(AWSInstanceNameLookupProcessor.java:136) ~[graylog-plugin-aws-4.2.0.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor.access$000(AWSInstanceNameLookupProcessor.java:42) ~[graylog-plugin-aws-4.2.0.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor$1.run(AWSInstanceNameLookupProcessor.java:82) [graylog-plugin-aws-4.2.0.jar:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_292]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_292]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_292]
Caused by: com.mongodb.MongoQueryException: Query failed with error code 11600 and error message 'interrupted at shutdown' on server localhost:27017
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:735) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.OperationHelper.withReadConnectionSource(OperationHelper.java:463) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:89) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:196) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:177) ~[graylog.jar:?]
        at com.mongodb.DBCursor.initializeCursor(DBCursor.java:989) ~[graylog.jar:?]
        at com.mongodb.DBCursor.hasNext(DBCursor.java:172) ~[graylog.jar:?]
        at org.mongojack.DBCursor.hasNext(DBCursor.java:330) ~[graylog.jar:?]
        at org.mongojack.JacksonDBCollection.findOne(JacksonDBCollection.java:1408) ~[graylog.jar:?]
        at org.mongojack.JacksonDBCollection.findOne(JacksonDBCollection.java:1369) ~[graylog.jar:?]
        at org.mongojack.JacksonDBCollection.findOne(JacksonDBCollection.java:1343) ~[graylog.jar:?]
        at org.graylog2.cluster.ClusterConfigServiceImpl.get(ClusterConfigServiceImpl.java:102) ~[graylog.jar:?]
        at org.graylog2.cluster.ClusterConfigServiceImpl.get(ClusterConfigServiceImpl.java:119) ~[graylog.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor.lambda$waitForMigrationCompletion$1(AWSInstanceNameLookupProcessor.java:136) ~[graylog-plugin-aws-4.2.0.jar:?]
        at com.github.rholder.retry.AttemptTimeLimiters$NoAttemptTimeLimit.call(AttemptTimeLimiters.java:78) ~[graylog.jar:?]
        at com.github.rholder.retry.Retryer.call(Retryer.java:160) ~[graylog.jar:?]
        ... 10 more
2021-11-16T16:38:29.546-05:00 ERROR [AWSInstanceNameLookupProcessor] Could not refresh AWS instance lookup table.
java.util.concurrent.ExecutionException: com.mongodb.MongoQueryException: Query failed with error code 11600 and error message 'interrupted at shutdown' on server localhost:27017
        at com.github.rholder.retry.Retryer$ExceptionAttempt.<init>(Retryer.java:254) ~[graylog.jar:?]
        at com.github.rholder.retry.Retryer.call(Retryer.java:163) ~[graylog.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor.waitForMigrationCompletion(AWSInstanceNameLookupProcessor.java:136) ~[graylog-plugin-aws-4.2.0.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor.access$000(AWSInstanceNameLookupProcessor.java:42) ~[graylog-plugin-aws-4.2.0.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor$1.run(AWSInstanceNameLookupProcessor.java:82) [graylog-plugin-aws-4.2.0.jar:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_292]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_292]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_292]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_292]
Caused by: com.mongodb.MongoQueryException: Query failed with error code 11600 and error message 'interrupted at shutdown' on server localhost:27017
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:735) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation$1.call(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.OperationHelper.withReadConnectionSource(OperationHelper.java:463) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:725) ~[graylog.jar:?]
        at com.mongodb.operation.FindOperation.execute(FindOperation.java:89) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:196) ~[graylog.jar:?]
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:177) ~[graylog.jar:?]
        at com.mongodb.DBCursor.initializeCursor(DBCursor.java:989) ~[graylog.jar:?]
        at com.mongodb.DBCursor.hasNext(DBCursor.java:172) ~[graylog.jar:?]
        at org.mongojack.DBCursor.hasNext(DBCursor.java:330) ~[graylog.jar:?]
        at org.mongojack.JacksonDBCollection.findOne(JacksonDBCollection.java:1408) ~[graylog.jar:?]
        at org.mongojack.JacksonDBCollection.findOne(JacksonDBCollection.java:1369) ~[graylog.jar:?]
        at org.mongojack.JacksonDBCollection.findOne(JacksonDBCollection.java:1343) ~[graylog.jar:?]
        at org.graylog2.cluster.ClusterConfigServiceImpl.get(ClusterConfigServiceImpl.java:102) ~[graylog.jar:?]
        at org.graylog2.cluster.ClusterConfigServiceImpl.get(ClusterConfigServiceImpl.java:119) ~[graylog.jar:?]
        at org.graylog.aws.processors.instancelookup.AWSInstanceNameLookupProcessor.lambda$waitForMigrationCompletion$1(AWSInstanceNameLookupProcessor.java:136) ~[graylog-plugin-aws-4.2.0.jar:?]
        at com.github.rholder.retry.AttemptTimeLimiters$NoAttemptTimeLimit.call(AttemptTimeLimiters.java:78) ~[graylog.jar:?]
        at com.github.rholder.retry.Retryer.call(Retryer.java:160) ~[graylog.jar:?]
        ... 10 more
2021-11-16T16:39:15.420-05:00 INFO  [ImmutableFeatureFlagsCollector] Following feature flags are used: {}
2021-11-16T16:39:19.913-05:00 INFO  [CmdLineTool] Loaded plugin: AWS plugins 4.2.0 [org.graylog.aws.AWSPlugin]
2021-11-16T16:39:19.915-05:00 INFO  [CmdLineTool] Loaded plugin: Integrations 4.1.5 [org.graylog.integrations.IntegrationsPlugin]
2021-11-16T16:39:19.916-05:00 INFO  [CmdLineTool] Loaded plugin: Collector 4.2.0 [org.graylog.plugins.collector.CollectorPlugin]
2021-11-16T16:39:19.917-05:00 INFO  [CmdLineTool] Loaded plugin: Threat Intelligence Plugin 4.2.0 [org.graylog.plugins.threatintel.ThreatIntelPlugin]
2021-11-16T16:39:19.918-05:00 INFO  [CmdLineTool] Loaded plugin: Elasticsearch 6 Support 4.2.0+5adccc3 [org.graylog.storage.elasticsearch6.Elasticsearch6Plugin]
2021-11-16T16:39:19.918-05:00 INFO  [CmdLineTool] Loaded plugin: Elasticsearch 7 Support 4.2.0+5adccc3 [org.graylog.storage.elasticsearch7.Elasticsearch7Plugin]
2021-11-16T16:39:20.948-05:00 INFO  [CmdLineTool] Running with JVM arguments: -Xms1g -Xmx1g -XX:NewRatio=1 -XX:+ResizeTLAB -XX:-OmitStackTraceInFastThrow -Djdk.tls.acknowledgeCloseNotify=true -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+CMSConcurrentMTEnabled -XX:+CMSClassUnloadingEnabled -Dlog4j.configurationFile=file:///etc/graylog/server/log4j2.xml -Djava.library.path=/usr/share/graylog-server/lib/sigar -Dgraylog2.installation_source=deb
2021-11-16T16:39:22.159-05:00 INFO  [Version] HV000001: Hibernate Validator null
2021-11-16T16:39:35.939-05:00 INFO  [InputBufferImpl] Message journal is enabled.
2021-11-16T16:39:36.023-05:00 INFO  [NodeId] Node ID: 0646dbed-0a28-49e5-bf71-00e9e67fcfd9
2021-11-16T16:39:37.057-05:00 INFO  [LogManager] Loading logs.
2021-11-16T16:39:37.150-05:00 WARN  [Log] Found a corrupted index file, /var/lib/graylog-server/journal/messagejournal-0/00000000000252596337.index, deleting and rebuilding index...
2021-11-16T16:39:38.285-05:00 INFO  [LogManager] Logs loading complete.
2021-11-16T16:39:38.290-05:00 INFO  [LocalKafkaJournal] Initialized Kafka based journal at /var/lib/graylog-server/journal
2021-11-16T16:39:38.776-05:00 INFO  [cluster] Cluster created with settings {hosts=[localhost:27017], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=5000}
2021-11-16T16:39:39.011-05:00 INFO  [cluster] Cluster description not yet available. Waiting for 30000 ms before timing out
2021-11-16T16:39:39.129-05:00 INFO  [connection] Opened connection [connectionId{localValue:1, serverValue:1}] to localhost:27017
2021-11-16T16:39:39.142-05:00 INFO  [cluster] Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 27]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=5049514}
2021-11-16T16:39:39.208-05:00 INFO  [connection] Opened connection [connectionId{localValue:2, serverValue:2}] to localhost:27017
2021-11-16T16:39:40.358-05:00 INFO  [InputBufferImpl] Initialized InputBufferImpl with ring size <65536> and wait strategy <BlockingWaitStrategy>, running 2 parallel message handlers.
2021-11-16T16:39:41.996-05:00 ERROR [VersionProbe] Unable to retrieve version from Elasticsearch node: Failed to connect to /127.0.0.1:9200. - Connection refused (Connection refused).
2021-11-16T16:39:47.000-05:00 ERROR [VersionProbe] Unable to retrieve version from Elasticsearch node: Failed to connect to /127.0.0.1:9200. - Connection refused (Connection refused).
2021-11-16T16:39:52.604-05:00 INFO  [ElasticsearchVersionProvider] Elasticsearch cluster is running v7.10.2
2021-11-16T16:39:55.570-05:00 INFO  [ProcessBuffer] Initialized ProcessBuffer with ring size <65536> and wait strategy <BlockingWaitStrategy>.
2021-11-16T16:39:55.812-05:00 INFO  [connection] Opened connection [connectionId{localValue:3, serverValue:3}] to localhost:27017
2021-11-16T16:39:57.244-05:00 INFO  [OutputBuffer] Initialized OutputBuffer with ring size <65536> and wait strategy <BlockingWaitStrategy>.
2021-11-16T16:40:00.977-05:00 INFO  [ServerBootstrap] Graylog server 4.2.0+5adccc3 starting up
2021-11-16T16:40:00.978-05:00 INFO  [ServerBootstrap] JRE: Private Build 1.8.0_292 on Linux 4.15.0-162-generic
2021-11-16T16:40:00.979-05:00 INFO  [ServerBootstrap] Deployment: deb
2021-11-16T16:40:00.986-05:00 INFO  [ServerBootstrap] OS: Ubuntu 18.04.6 LTS (bionic)
2021-11-16T16:40:00.986-05:00 INFO  [ServerBootstrap] Arch: amd64
2021-11-16T16:40:01.125-05:00 INFO  [PeriodicalsService] Starting 29 periodicals ...
2021-11-16T16:40:01.139-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.ThroughputCalculator] periodical in [0s], polling every [1s].
2021-11-16T16:40:01.158-05:00 INFO  [Periodicals] Starting [org.graylog.plugins.pipelineprocessor.periodical.LegacyDefaultStreamMigration] periodical, running forever.
2021-11-16T16:40:01.167-05:00 INFO  [PeriodicalsService] Not starting [org.graylog2.periodical.AlertScannerThread] periodical. Not configured to run on this node.
2021-11-16T16:40:01.167-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.BatchedElasticSearchOutputFlushThread] periodical in [0s], polling every [1s].
2021-11-16T16:40:01.188-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.ClusterHealthCheckThread] periodical in [120s], polling every [20s].
2021-11-16T16:40:01.207-05:00 INFO  [PeriodicalsService] Not starting [org.graylog2.periodical.ContentPackLoaderPeriodical] periodical. Not configured to run on this node.
2021-11-16T16:40:01.219-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.GarbageCollectionWarningThread] periodical, running forever.
2021-11-16T16:40:01.269-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.IndexerClusterCheckerThread] periodical in [0s], polling every [30s].
2021-11-16T16:40:01.278-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.IndexRetentionThread] periodical in [0s], polling every [300s].
2021-11-16T16:40:01.279-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.IndexRotationThread] periodical in [0s], polling every [10s].
2021-11-16T16:40:01.286-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.NodePingThread] periodical in [0s], polling every [1s].
2021-11-16T16:40:01.303-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.VersionCheckThread] periodical in [300s], polling every [1800s].
2021-11-16T16:40:01.304-05:00 INFO  [LegacyDefaultStreamMigration] Legacy default stream has no connections, no migration needed.
2021-11-16T16:40:01.305-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.ThrottleStateUpdaterThread] periodical in [1s], polling every [1s].
2021-11-16T16:40:01.306-05:00 INFO  [Periodicals] Starting [org.graylog2.events.ClusterEventPeriodical] periodical in [0s], polling every [1s].
2021-11-16T16:40:01.306-05:00 INFO  [Periodicals] Starting [org.graylog2.events.ClusterEventCleanupPeriodical] periodical in [0s], polling every [86400s].
2021-11-16T16:40:01.306-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.ClusterIdGeneratorPeriodical] periodical, running forever.
2021-11-16T16:40:01.315-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.IndexRangesMigrationPeriodical] periodical, running forever.
2021-11-16T16:40:01.336-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.IndexRangesCleanupPeriodical] periodical in [15s], polling every [3600s].
2021-11-16T16:40:01.415-05:00 INFO  [connection] Opened connection [connectionId{localValue:4, serverValue:4}] to localhost:27017
2021-11-16T16:40:01.417-05:00 INFO  [connection] Opened connection [connectionId{localValue:8, serverValue:5}] to localhost:27017
2021-11-16T16:40:01.448-05:00 INFO  [connection] Opened connection [connectionId{localValue:7, serverValue:8}] to localhost:27017
2021-11-16T16:40:01.452-05:00 INFO  [connection] Opened connection [connectionId{localValue:5, serverValue:7}] to localhost:27017
2021-11-16T16:40:01.475-05:00 INFO  [connection] Opened connection [connectionId{localValue:6, serverValue:6}] to localhost:27017
2021-11-16T16:40:01.509-05:00 INFO  [PeriodicalsService] Not starting [org.graylog2.periodical.UserPermissionMigrationPeriodical] periodical. Not configured to run on this node.
2021-11-16T16:40:01.509-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.ConfigurationManagementPeriodical] periodical, running forever.
2021-11-16T16:40:01.510-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.TrafficCounterCalculator] periodical in [0s], polling every [1s].
2021-11-16T16:40:01.510-05:00 INFO  [Periodicals] Starting [org.graylog2.indexer.fieldtypes.IndexFieldTypePollerPeriodical] periodical in [0s], polling every [3600s].
2021-11-16T16:40:01.483-05:00 INFO  [connection] Opened connection [connectionId{localValue:9, serverValue:9}] to localhost:27017
2021-11-16T16:40:01.515-05:00 INFO  [Periodicals] Starting [org.graylog.scheduler.periodicals.ScheduleTriggerCleanUp] periodical in [120s], polling every [86400s].
2021-11-16T16:40:01.516-05:00 INFO  [Periodicals] Starting [org.graylog2.periodical.ESVersionCheckPeriodical] periodical in [0s], polling every [30s].
2021-11-16T16:40:01.517-05:00 INFO  [Periodicals] Starting [org.graylog.plugins.sidecar.periodical.PurgeExpiredSidecarsThread] periodical in [0s], polling every [600s].
2021-11-16T16:40:01.517-05:00 INFO  [Periodicals] Starting [org.graylog.plugins.sidecar.periodical.PurgeExpiredConfigurationUploads] periodical in [0s], polling every [600s].
2021-11-16T16:40:01.543-05:00 INFO  [Periodicals] Starting [org.graylog.plugins.views.search.db.SearchesCleanUpJob] periodical in [3600s], polling every [28800s].
2021-11-16T16:40:01.546-05:00 INFO  [Periodicals] Starting [org.graylog.events.periodicals.EventNotificationStatusCleanUp] periodical in [120s], polling every [86400s].
2021-11-16T16:40:01.546-05:00 INFO  [Periodicals] Starting [org.graylog.plugins.collector.periodical.PurgeExpiredCollectorsThread] periodical in [0s], polling every [3600s].
2021-11-16T16:40:01.667-05:00 INFO  [LookupTableService] Data Adapter geoip/614e28029f8bf82a3736d378 [@3cbb6a91] STARTING
2021-11-16T16:40:01.735-05:00 INFO  [LookupTableService] Data Adapter geoip/614e28029f8bf82a3736d378 [@3cbb6a91] RUNNING
2021-11-16T16:40:01.736-05:00 INFO  [LookupDataAdapterRefreshService] Adding job for <geoip/614e28029f8bf82a3736d378/@3cbb6a91> [interval=60000ms]
2021-11-16T16:40:02.295-05:00 INFO  [LookupTableService] Cache geoip/614e28469f8bf82a3736d3c2 [@725b0b0a] STARTING
2021-11-16T16:40:02.316-05:00 INFO  [LookupTableService] Cache geoip/614e28469f8bf82a3736d3c2 [@725b0b0a] RUNNING
2021-11-16T16:40:02.403-05:00 INFO  [LookupTableService] Starting lookup table geoip/614e288a9f8bf82a3736d40e [@2375d4d0] using cache geoip/614e28469f8bf82a3736d3c2 [@725b0b0a], data adapter geoip/614e28029f8bf82a3736d378 [@3cbb6a91]
2021-11-16T16:40:03.322-05:00 INFO  [IndexRetentionThread] Elasticsearch cluster not available, skipping index retention checks.
2021-11-16T16:40:10.214-05:00 INFO  [NetworkListener] Started listener bound to [172.16.2.15:9000]
2021-11-16T16:40:10.217-05:00 INFO  [HttpServer] [HttpServer] Started.
2021-11-16T16:40:10.217-05:00 INFO  [JerseyService] Started REST API at <172.16.2.15:9000>
2021-11-16T16:40:10.219-05:00 INFO  [ServerBootstrap] Services started, startup times in ms: {ConfigurationEtagService [RUNNING]=174, OutputSetupService [RUNNING]=179, BufferSynchronizerService [RUNNING]=179, PrometheusExporter [RUNNING]=180, JobSchedulerService [RUNNING]=189, EtagService [RUNNING]=207, InputSetupService [RUNNING]=264, LocalKafkaMessageQueueWriter [RUNNING]=266, LocalKafkaMessageQueueReader [RUNNING]=266, FailureHandlingService [RUNNING]=266, GracefulShutdownService [RUNNING]=267, UserSessionTerminationService [RUNNING]=271, UrlWhitelistService [RUNNING]=292, LocalKafkaJournal [RUNNING]=296, MongoDBProcessingStatusRecorderService [RUNNING]=322, PeriodicalsService [RUNNING]=439, StreamCacheService [RUNNING]=440, LookupTableService [RUNNING]=1204, JerseyService [RUNNING]=9109}
2021-11-16T16:40:10.225-05:00 INFO  [ServiceManagerListener] Services are healthy
2021-11-16T16:40:10.233-05:00 INFO  [InputSetupService] Triggering launching persisted inputs, node transitioned from Uninitialized [LB:DEAD] to Running [LB:ALIVE]
2021-11-16T16:40:10.369-05:00 INFO  [ServerBootstrap] Graylog server up and running.
2021-11-16T16:40:10.369-05:00 INFO  [InputStateListener] Input [Syslog UDP/614b32dd9f8bf82a37339ca9] is now STARTING
2021-11-16T16:40:10.376-05:00 INFO  [InputStateListener] Input [Raw/Plaintext UDP/614b86e49f8bf82a3733f849] is now STARTING
2021-11-16T16:40:11.119-05:00 WARN  [Bootstrap] Unknown channel option 'io.netty.channel.unix.UnixChannelOption#SO_REUSEPORT' for channel '[id: 0xdebf0307]'
2021-11-16T16:40:11.151-05:00 WARN  [Bootstrap] Unknown channel option 'io.netty.channel.unix.UnixChannelOption#SO_REUSEPORT' for channel '[id: 0xfeed0eba]'
2021-11-16T16:40:11.270-05:00 INFO  [InputStateListener] Input [Syslog UDP/614b32dd9f8bf82a37339ca9] is now RUNNING
2021-11-16T16:40:11.271-05:00 WARN  [UdpTransport] receiveBufferSize (SO_RCVBUF) for input SyslogUDPInput{title=Local graylog, type=org.graylog2.inputs.syslog.udp.SyslogUDPInput, nodeId=0646dbed-0a28-49e5-bf71-00e9e67fcfd9} (channel [id: 0xdebf0307, L:/0:0:0:0:0:0:0:0:1514]) should be >= 262144 but is 212992.
2021-11-16T16:40:11.268-05:00 WARN  [UdpTransport] Failed to start channel for input RawUDPInput{title=FortiGate, type=org.graylog2.inputs.raw.udp.RawUDPInput, nodeId=0646dbed-0a28-49e5-bf71-00e9e67fcfd9}
java.net.BindException: Address already in use
        at sun.nio.ch.Net.bind0(Native Method) ~[?:1.8.0_292]
        at sun.nio.ch.Net.bind(Net.java:461) ~[?:1.8.0_292]
        at sun.nio.ch.DatagramChannelImpl.bind(DatagramChannelImpl.java:698) ~[?:1.8.0_292]
        at io.netty.util.internal.SocketUtils$6.run(SocketUtils.java:133) ~[graylog.jar:?]
        at io.netty.util.internal.SocketUtils$6.run(SocketUtils.java:130) ~[graylog.jar:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_292]
        at io.netty.util.internal.SocketUtils.bind(SocketUtils.java:130) ~[graylog.jar:?]
        at io.netty.channel.socket.nio.NioDatagramChannel.doBind0(NioDatagramChannel.java:200) ~[graylog.jar:?]
        at io.netty.channel.socket.nio.NioDatagramChannel.doBind(NioDatagramChannel.java:195) ~[graylog.jar:?]
        at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:550) [graylog.jar:?]
        at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334) [graylog.jar:?]
        at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506) [graylog.jar:?]
        at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:491) [graylog.jar:?]
        at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973) [graylog.jar:?]
        at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:248) [graylog.jar:?]
        at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356) [graylog.jar:?]
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [graylog.jar:?]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [graylog.jar:?]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [graylog.jar:?]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [graylog.jar:?]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [graylog.jar:?]
        at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:180) [graylog.jar:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_292]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_292]
        at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_292]
2021-11-16T16:40:11.292-05:00 ERROR [InputLauncher] The [org.graylog2.inputs.raw.udp.RawUDPInput] input with ID <614b86e49f8bf82a3733f849> misfired. Reason: Address already in use.
org.graylog2.plugin.inputs.MisfireException: org.graylog2.plugin.inputs.MisfireException: java.net.BindException: Address already in use
        at org.graylog2.plugin.inputs.MessageInput.launch(MessageInput.java:158) ~[graylog.jar:?]
        at org.graylog2.shared.inputs.InputLauncher$1.run(InputLauncher.java:84) [graylog.jar:?]
        at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:180) [graylog.jar:?]

2021-11-16T16:40:19.106-05:00 WARN  [LookupTableService] Lookup table <geoip-lookup> does not exist

gsmith · November 17, 2021, 12:17am

Hello,

Just chiming in. I looked over your log file real quick.

I believe error 11600 means that the client is trying to do an operation on a server that is shutting down. So, if you provide the driver with a connection URI the driver should reconnect as soon as it’s available. You may want to look here.

This may have to do with your reboot, You normally receive this error when Graylog starts first and elasticsearch has not fully started OR your elasticsearch service failed to start.

Seams like you have a issue on a input.

Best suggestion I could tell ya is execute what @tmacgbay suggested first. Make sure Elasticsearch is started before the other services (MongoDb, Graylog). If there is no problems then start MongoDb and check for errors/warnings. Then start Graylog service and either tail the log files while its starting up or check status of the service/s to see if there are any issues.

Make sure that the service are enabled. So, after a reboot these service will start back up.

 sudo systemctl enable graylog-server
 sudo systemctl enable mongod
 sudo systemctl enable elasticsearch

Hope that helps

tmacgbay · November 18, 2021, 6:39pm

Hard to figure out what we are missing!! Here is something… your elaticsearch.yml in a previous post says your data is hanging off /mnt (non-default but fine) but when you posted logs from /var/log/elasticsearch they have todays timestamp. Link or misconfiguration or I am missing something?

and

gsmith · November 19, 2021, 11:10pm

Nice, seams like were getting closer

I have a couple of question to add to @tmacgbay suggestions.
This picture below (which I marked with a red box) shows my concerns that your plugin is not the right version.

You can either perform an upgrade to the plugin or navigate to the plugin directory and remove it.
Directory location.

/usr/share/graylog-server/plugin

Command for install plugin.

sudo apt-get install graylog-integrations-plugins

https://docs.graylog.org/docs/setup-intergrations

Have you checked permissions on Elasticsearch data directory?

ls -al /var/lib/elasticsearch

I believe in your case you have moved the data directory.

ls -al /mnt/sdb/data

Are you actually rebooting the server or restarting GL service?
If you rebooted the servers I’m concerned about the mount point /mnt in your fstab file.

EDIT: I re-read this post again and remembered a incident similar to this one. This is referring to your mount points. As you stated, you reconfigured your data/log directory when you had your server running. I have done the same thing before maybe I can shed some light on your fstab file configuration. Here is an example of what I would have done in your situation. Maybe it can help.

Stop graylog service using command: sudo systemctl stop graylog.service
Stop elasticsearch.service using command: sudo systemctl stop elasticsearch.service
Make a backup of your data !!! For example, simple copy to another destination with enough space using command: cp -av /var/lib/elasticsearch /media/backupdisk.
Check name for mounted volume.
- sudo fdisk -l

Create elasticsearch directory in /mnt
- sudo mkdir /mnt/elasticsearch
Mount /dev/sdb1 to /mnt/elasticsearch
- mount /dev/sdb1 /mnt/elasticsearch
Create new sub-directories for elastic data/logs using these commands:
- sudo mkdir -p /mnt/elasticsearch/es_data
- sudo mkdir -p /mnt/elasticsearch/es_log
Now make sure the mounts are good after reboot by adding it to fstab file
- /dev/sdb1 /mnt/elasticsearch ext4 defaults 0 0

Setup permissions for these directories using commands:
- sudo chown -R elasticsearch:elasticsearch /mnt/elasticsearch/es_data
- sudo chown -R elasticsearch:elasticsearch /mnt/elasticsearch/es_log
Move elasticsaerch db and logs to new directory.
- sudo mv -v /var/lib/elasticsearch/ /mnt/elasticsearch/es_data*
- sudo mv -v /var/log/elasticsearch/ /mnt/elasticsearch/es_log*
Start elasticsearch. service using command:
- sudo systemctl start elasticsearch.service
Wait few moments to elasticsearch and then start graylog using:
- sudo systemctl start graylog.service

If you noticed my second drive partition is named /dev/sdb1 my drive is named /dev/sdb.
using this command may help.

root # lsblk
The lsblk command lists all the block devices of your system along with their logical partitions.

I’m not 100% sure what you did before but maybe this would could give you some insight of what I did.

@tmacgbay

rrmike · November 23, 2021, 2:41pm

Here is the output of lsblk.

root@graylog:/home/ldog# lsblk
NAME                      MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
loop0                       7:0    0  68.3M  1 loop /snap/powershell/189
loop2                       7:2    0  55.5M  1 loop /snap/core18/2246
loop3                       7:3    0  42.2M  1 loop /snap/snapd/13831
loop4                       7:4    0  32.5M  1 loop /snap/snapd/13640
loop5                       7:5    0  55.5M  1 loop /snap/core18/2253
loop6                       7:6    0  66.5M  1 loop /snap/powershell/185
sda                         8:0    0   127G  0 disk
├─sda1                      8:1    0   512M  0 part /boot/efi
├─sda2                      8:2    0     1G  0 part /boot
└─sda3                      8:3    0 125.5G  0 part
  └─ubuntu--vg-ubuntu--lv 253:0    0 125.5G  0 lvm  /
sdb                         8:16   0   700G  0 disk /mnt/sdb

Next things to do:

Clone VM.
Upgrade plugins.
Work through instructions that @gsmith provided.

gsmith · December 1, 2021, 11:31pm

Hello,

Good question, its hard for me to tell you but from what you stated I would go with where the data is actually being saved.

[root@graylog graylog_user]#  cat /etc/elasticsearch/elasticsearch.yml | egrep -v "^\s*(#|$)"
cluster.name: graylog
path.data: /var/lib/elasticsearch  <----- **DATA**
path.logs: /var/log/elasticsearch <---- **LOGS**
network.host: 8.8.8.8
http.port: 9200
action.auto_create_index: false
discovery.type: single-node
path.repo: ["/mnt/sdb1/my_repo"]
[root@graylog graylog_user]#

Note:
You need to modify the path.data setting in the elasticsearch.yml file to the new folder you want the data to.

Here is what you need to do:

You may want to shut down your services , like graylog and elasticsearch first.

In elasticsearch.yml modify path.data to:

path.data: /foo/bar

You’ll end up with your data being stored in /foo/bar/elasticsearch instead of /var/lib/elasticsearch.
Make sure that the elasticsearch process can access your new folder.

Once you configure Elasticsearch make sure you start elasticsearch service first, wait until its completely running then start Graylog.

Hope that helps

EDIT @rrmike I have a question for ya, I was wondering why you didn’t create a portion on you drive sdb ? Or did you format the whole drive?

rrmike · January 4, 2022, 7:48pm

That was it.

Thanks @tmacgbay and @gsmith for all your help, I really appropriate it. I definitely learned some stuff along the way.

gsmith · January 4, 2022, 11:11pm

Glad you fixed your issue BTW I seen this in the forum.

danmassa7 · January 5, 2022, 1:17pm

@gsmith found my post on the iptables subject. Thanks!

To summarize:

When you make an iptables change it will not persist across reboots. To save the config I use:
sudo /sbin/iptables-save
When you make a change to iptables it also doesn’t effect existing flows. If your Fortinet box is sending udp packets to 514 it will just stick there and the redirect to 1514 will never happen. Once you realize that’s what’s happening you can reboot the box and that will clear the iptables state. But I found a much easier way.

# If conntrack is not already installed...
sudo yum update
sudo yum install conntrack
# List all existing connections...
sudo conntrack -L
# Flush all connections in the state table...
sudo conntrack -F

The conntrack utility does the flush. After the flush you’ll see the redirect from 514 to 1514 starts immediately (along with any other changes you’ve made to iptables).

Sometimes I wish Linux people were better at documenting how things work! It took me about six months from finding the connection tracking problem to finding a solution. (Don’t worry, it’s not my full time job. It wasn’t six months of full-time effort!)

Hope that helps.

Topic		Replies	Views
Some messages not showing Graylog Central (peer support)	3	183	September 6, 2022
Graylog port change not held at reboot Graylog Central (peer support)	3	649	September 1, 2021
Graylog not found any syslog Graylog Central (peer support) basic-configuration , elastic	7	574	May 12, 2022
Messages getting to server but not to Graylog Graylog Central (peer support)	5	2008	April 9, 2019
Graylog stopps processing messages. Only coming in but no out Graylog Central (peer support)	6	10438	November 12, 2018