Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
sbengo opened this issue Jun 18, 2018 · 2 comments
Open

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

sbengo opened this issue Jun 18, 2018 · 2 comments

Comments

@sbengo
Copy link
Collaborator

sbengo commented 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]"
@toni-moreno
Copy link
Collaborator

I will review in next days..

@sbengo sbengo mentioned this issue Jul 2, 2018
Merged
@sbengo sbengo reopened this Oct 18, 2018
@sbengo
Copy link
Collaborator Author

sbengo commented Oct 18, 2018

After trying to fix setting the MaxPacketSize it seems to be appearing on some devices.

We can try to catch the error and make a reconnect to recreate the SFTP connection...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@toni-moreno @sbengo