Skip to content

[Bug] Collector doesn't recreate the reader after empty file rotation #25

Open
Open
[Bug] Collector doesn't recreate the reader after empty file rotation#25

Description

@sbengo
sbengo
opened on Jun 18, 2018

Hi,

It seems that on some devices, when the NMON file is rotated and it remains empty, the agent couldn't start a new reader and it will cause that no point would be read even the new file is detected, with the following message:
level=warning msg="Trying to read data without open reader"

Example:

The collector detects the NMON file change but it gives an error of EOF:

time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]Init gather cycle for device NMONSERVER"
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Import Nmon data on remote device (NMONSERVER) "
time="2018-06-17 00:01:17" level=info msg="Detected Nmon File change OLD [/logs/system/nmon/NMONSERVER_180616_0000.nmon] NEW [/logs/system/nmon/NMONSERVER_180617_0000.nmon]"
time="2018-06-17 00:01:17" level=info msg="UpdateContent: Got new 0 lines from NmonFile "
time="2018-06-17 00:01:17" level=error msg="Error on Remote Reader :failed to send packet header: EOF"

The agent tries to flush last data retrieved (in this case, the nmon file stopped to update content on 08:38:25:

time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: File  /logs/system/nmon/NMONSERVER_180617_0000.nmon has been reopened after change detected "
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Process pending Buffer before load data again "
time="2018-06-17 00:01:17" level=info msg="ProcessChunk: Decoding Chunk for Timestamp 2018-06-16 08:38:25 +0200 Europe/Paris with 46 Elements "
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Reset remaining  (47) lines in buffer"

After flush, the agent tries to parse the new file. The open reader it is not created, so it throws an error:

time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: File  /logs/system/nmon/NMONSERVER_180617_0000.nmon should be rescanned for new sections/columns "
time="2018-06-17 00:01:17" level=error msg="[*nmon.Server] [NMONSERVER]ImportData: Error on Section Initializations after reopen file :Trying to read data without open reader "
time="2018-06-17 00:01:17" level=error msg="[*nmon.Server] [NMONSERVER]Error in  import Nmon Data from Device <UUID_DEVICE>: ERROR: Trying to read data without open reader"
time="2018-06-17 00:01:17" level=info msg="STATS Device :  polling took [0.000000 seconds] "
time="2018-06-17 00:01:17" level=info msg="STATS Device: last scan send took [0.000000 seconds]"
time="2018-06-17 00:01:17" level=info msg="STATS INFLUX: influx send took [0.000000 seconds]"

As the reader is not created, on every poll, the agent will throw the same error:

time="2018-06-17 00:02:17" level=info msg="[*nmon.Server] [NMONSERVER]Init gather cycle for device NMONSERVER"
time="2018-06-17 00:02:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Import Nmon data on remote device (NMONSERVER) "
time="2018-06-17 00:02:17" level=warning msg="Trying to read data without open reader"
time="2018-06-17 00:02:17" level=info msg="UpdateContent: Got new 0 lines from NmonFile "
time="2018-06-17 00:02:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: this import has generated 0 Datapoints"
time="2018-06-17 00:02:17" level=info msg="STATS Device :  polling took [0.000134 seconds] "
time="2018-06-17 00:02:17" level=info msg="STATS Device: last scan send took [0.000000 seconds]"
time="2018-06-17 00:02:17" level=info msg="STATS INFLUX: influx send took [0.000001 seconds]"

Full log:

time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]Init gather cycle for device NMONSERVER"
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Import Nmon data on remote device (NMONSERVER) "
time="2018-06-17 00:01:17" level=info msg="Detected Nmon File change OLD [/logs/system/nmon/NMONSERVER_180616_0000.nmon] NEW [/logs/system/nmon/NMONSERVER_180617_0000.nmon]"
time="2018-06-17 00:01:17" level=info msg="UpdateContent: Got new 0 lines from NmonFile "
time="2018-06-17 00:01:17" level=error msg="Error on Remote Reader :failed to send packet header: EOF"
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: File  /logs/system/nmon/NMONSERVER_180617_0000.nmon has been reopened after change detected "
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Process pending Buffer before load data again "
time="2018-06-17 00:01:17" level=info msg="ProcessChunk: Decoding Chunk for Timestamp 2018-06-16 08:38:25 +0200 Europe/Paris with 46 Elements "
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Reset remaining  (47) lines in buffer"
time="2018-06-17 00:01:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: File  /logs/system/nmon/NMONSERVER_180617_0000.nmon should be rescanned for new sections/columns "
time="2018-06-17 00:01:17" level=error msg="[*nmon.Server] [NMONSERVER]ImportData: Error on Section Initializations after reopen file :Trying to read data without open reader "
time="2018-06-17 00:01:17" level=error msg="[*nmon.Server] [NMONSERVER]Error in  import Nmon Data from Device <UUID_DEVICE>: ERROR: Trying to read data without open reader"
time="2018-06-17 00:01:17" level=info msg="STATS Device :  polling took [0.000000 seconds] "
time="2018-06-17 00:01:17" level=info msg="STATS Device: last scan send took [0.000000 seconds]"
time="2018-06-17 00:01:17" level=info msg="STATS INFLUX: influx send took [0.000000 seconds]"
time="2018-06-17 00:02:17" level=info msg="[*nmon.Server] [NMONSERVER]Init gather cycle for device NMONSERVER"
time="2018-06-17 00:02:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: Import Nmon data on remote device (NMONSERVER) "
time="2018-06-17 00:02:17" level=warning msg="Trying to read data without open reader"
time="2018-06-17 00:02:17" level=info msg="UpdateContent: Got new 0 lines from NmonFile "
time="2018-06-17 00:02:17" level=info msg="[*nmon.Server] [NMONSERVER]ImportData: this import has generated 0 Datapoints"
time="2018-06-17 00:02:17" level=info msg="STATS Device :  polling took [0.000134 seconds] "
time="2018-06-17 00:02:17" level=info msg="STATS Device: last scan send took [0.000000 seconds]"
time="2018-06-17 00:02:17" level=info msg="STATS INFLUX: influx send took [0.000001 seconds]"

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions