9.3.2. ON Analytics Logs

Within the ON Analytics node, we can find a large number of logs that can help us understand or detect errors that may arise during system operation.

The main logs to take into account in the ON Analytics node are:

9.3.2.1. logstash-plain.log

This logs shows information about the Logstash service and the different problems with the data ingestion to Elasticsearch.

Path:

/var/log/logstash/logstash-plain.log

Example:

[2022-08-29T10:02:48,635][INFO ][logstash.javapipeline    ] Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>2, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>50, "pipeline.max_inflight"=>250, :thread=>"#<Thread:0x3b48f94d run>"}
[2022-08-29T10:02:50,666][INFO ][logstash.inputs.beats    ] Beats inputs: Starting input listener {:address=>"0.0.0.0:5000"}
[2022-08-29T10:02:50,681][INFO ][logstash.inputs.beats    ] Beats inputs: Starting input listener {:address=>"0.0.0.0:5001"}
[2022-08-29T10:02:51,456][INFO ][logstash.javapipeline    ] Pipeline started {"pipeline.id"=>"main"}
[2022-08-29T10:02:51,552][INFO ][org.logstash.beats.Server] Starting server on port: 5000
[2022-08-29T10:02:51,646][INFO ][logstash.inputs.tcp      ] Starting tcp input listener {:address=>"0.0.0.0:5002", :ssl_enable=>"false"}
[2022-08-29T10:02:51,703][INFO ][org.logstash.beats.Server] Starting server on port: 5001
[2022-08-29T10:02:51,804][INFO ][logstash.agent           ] Pipelines running {:count=>1, :running_pipelines=>[:main], :non_running_pipelines=>[]}
[2022-08-29T10:02:52,891][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
[2022-08-29T10:04:04,527][WARN ][logstash.outputs.elasticsearch] Could not index event to Elasticsearch. {:status=>400, :action=>["update", {:_id=>"7131054132030345254", :_index=>"opennac_ud", :_type=>"_doc", :routing=>nil, :retry_on_conflict=>3}, #<LogStash::Event:0x47623084>], :response=>{"update"=>{"_index"=>"opennac_ud", "_type"=>"_doc", "_id"=>"7131054132030345254", "status"=>400, "error"=>{"type"=>"illegal_argument_exception", "reason"=>"Limit of total fields [2000] in index [opennac_ud] has been exceeded"}}}}

9.3.2.2. elasticsearch.log

This logs shows information about the Elasticsearch service and the different problems with the data storing into indexes.

Path:

/var/log/elasticsearch/elasticsearch.log

Example:

[2022-08-29T02:00:13,160][INFO ][o.e.c.r.a.AllocationService] [12-analytics-02] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[opennac-2022.08.29][0]] ...]).
[2022-08-29T02:00:13,205][INFO ][o.e.c.m.MetaDataMappingService] [12-analytics-02] [opennac-2022.08.29/FXauSlwIQCadcPWWcyjGBw] update_mapping [_doc]
[2022-08-29T02:02:27,432][INFO ][o.e.c.m.MetaDataCreateIndexService] [12-analytics-02] [bro-2022.08.29] creating index, cause [auto(bulk api)], templates [bro, default], shards [1]/[0], mappings [_doc]
[2022-08-29T02:02:27,573][INFO ][o.e.c.r.a.AllocationService] [12-analytics-02] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[bro-2022.08.29][0]] ...]).
[2022-08-29T02:02:27,669][INFO ][o.e.c.m.MetaDataMappingService] [12-analytics-02] [bro-2022.08.29/PhGoYPrDRmy6XEAt4WCwVg] update_mapping [_doc]

9.3.2.3. kibana.log

This logs shows information about the Kibana service and the web requests that Kibana receives.

Path:

/var/log/kibana/kibana.log

Example:

{"type":"response","@timestamp":"2022-08-29T08:19:01Z","tags":["api"],"pid":770,"method":"get","statusCode":200,"req":{"url":"/api/status","method":"get","headers":{"host":"localhost:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":200,"responseTime":87,"contentLength":9},"message":"GET /api/status 200 87ms - 9.0B"}
{"type":"response","@timestamp":"2022-08-29T08:20:01Z","tags":["api"],"pid":770,"method":"get","statusCode":200,"req":{"url":"/api/status","method":"get","headers":{"host":"localhost:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":200,"responseTime":105,"contentLength":9},"message":"GET /api/status 200 105ms - 9.0B"}
{"type":"response","@timestamp":"2022-08-29T08:21:02Z","tags":["api"],"pid":770,"method":"get","statusCode":200,"req":{"url":"/api/status","method":"get","headers":{"host":"localhost:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":200,"responseTime":95,"contentLength":9},"message":"GET /api/status 200 95ms - 9.0B"}
{"type":"response","@timestamp":"2022-08-29T08:22:02Z","tags":["api"],"pid":770,"method":"get","statusCode":200,"req":{"url":"/api/status","method":"get","headers":{"host":"localhost:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":200,"responseTime":73,"contentLength":9},"message":"GET /api/status 200 73ms - 9.0B"}
{"type":"response","@timestamp":"2022-08-29T08:23:02Z","tags":["api"],"pid":770,"method":"get","statusCode":200,"req":{"url":"/api/status","method":"get","headers":{"host":"localhost:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"127.0.0.1"},"res":{"statusCode":200,"responseTime":44,"contentLength":9},"message":"GET /api/status 200 44ms - 9.0B"}

9.3.2.4. healthcheck.log

This log contains information related to the errors that might occur when healthcheck is being executed.

Path:

/var/log/opennac/healthcheck.log

Example:

TIME_SYNC [23/08/2022 03:39:05]: Service TIME_SYNC is WARNING (3 seconds)
ELASTICSEARCH [23/08/2022 05:54:30]: CRITICAL - Could not connect to server localhost
SYSTEM_LOAD [23/08/2022 05:55:14]: WARNING - load average per CPU: 2.14, 1.00, 0.47|load1=2.143;2.000;4.000;0; load5=0.998;6.000;12.000;0; load15=0.472;12.000;24.000;0;
KIBANA [29/08/2022 06:03:25]: Service KIBANA is DOWN00

9.3.2.5. cron

This log contains information related cron service executions.

Path:

/var/log/cron

Example:

Aug 29 12:26:01 ana122DC01 CROND[3005495]: (root) CMD (cd /usr/share/opennac/healthcheck; ./healthcheck.php -o redis >> /var/log/opennac/healthcheck.log 2>&1)
Aug 29 12:27:01 ana122DC01 CROND[3005620]: (root) CMD (cd /usr/share/opennac/healthcheck; ./healthcheck.php -o redis >> /var/log/opennac/healthcheck.log 2>&1)
Aug 29 12:28:01 ana122DC01 CROND[3005777]: (root) CMD (cd /usr/share/opennac/healthcheck; ./healthcheck.php -o redis >> /var/log/opennac/healthcheck.log 2>&1)

9.3.2.6. curator.log

This log contains information about the curator service, that deletes Elasticsearch indexes after defined intervals of time.

Path:

/var/log/curator/curator.log

Example:

2022-08-29 12:00:04,302 INFO      Action ID: 9, "delete_indices" completed.
2022-08-29 12:00:04,302 INFO      Preparing Action ID: 10, "delete_indices"
2022-08-29 12:00:04,303 INFO      Creating client object and testing connection
2022-08-29 12:00:04,303 INFO      Instantiating client object
2022-08-29 12:00:04,304 INFO      Testing client connectivity
2022-08-29 12:00:04,307 INFO      Successfully created Elasticsearch client object with provided settings
2022-08-29 12:00:04,310 INFO      Trying Action ID: 10, "delete_indices": Delete tm-* > 7 days.
2022-08-29 12:00:04,438 INFO      Skipping action "delete_indices" due to empty list: <class 'curator.exceptions.NoIndices'>
2022-08-29 12:00:04,438 INFO      Action ID: 10, "delete_indices" completed.
2022-08-29 12:00:04,439 INFO      Job completed.

9.3.2.7. redis.log

This log contains the information related to the redis application.

Path:

/var/log/redis/redis.log

Example:

1550:M 23 Jan 11:59:11.686 * The server is now ready to accept connections on port 6379
1550:M 23 Jan 11:59:11.943 * Slave 172.16.0.10:6379 asks for synchronization
1550:M 23 Jan 11:59:11.944 * Full resync requested by slave 172.16.0.10:6379
1550:M 23 Jan 11:59:11.944 * Delay next BGSAVE for diskless SYNC
1547:M 23 Jan 09:13:28.299 * Background RDB transfer terminated with success