search

lucagrulla / node-tail

The zero dependency Node.js module for tailing a file
https://www.lucagrulla.com/node-tail/
MIT License
467 stars 76 forks source link

node-tail prints out entire file, doesn't keep track of last know position in file #90

Closed BestInSlot closed 4 years ago

BestInSlot commented 5 years ago

Problem: I have a file being constantly written to, I'm using node-tail to watch this file and I'm piping the data through a socket to the front end. Unfortunately instead of receiving the latest appended information I'm receiving everything.

a very basic example (I'm not using a socket here, just console to log out the results):

const Tail = require("node-tail").Tail;
const tail = new Tail(file);

tail.on("line", data => console.log(data));
lucagrulla commented 5 years ago

Which OS?

When you say everything, you mean multiple line events, with each events reporting the whole content?

BestInSlot commented 5 years ago

Lubuntu 18.04.

Happens when one line event is fired, but that line event will dump the entirety of the file. Instead of getting the appended data, I'm getting the old and new data dumped.

mostfurious commented 5 years ago

When will this be resolved ? Does anyone know any other alternatives to use ? I tried "nodejs-tail", returs only ONE line and then does nothing, "tail-file" seems to have issues to even start, and this returns the WHOLE file conetent and not the single line.

lucagrulla commented 4 years ago

hi @mostfurious,

Are you experiencing the same problem? Which OS are you using?

mostfurious commented 4 years ago

Windows 10 build 1607 and Debian 9. What i noticed is if you start with empty file and add one line or few it works fine As in if you add one line it returns one line and if you add two lines it calls twice returning two lines.. But if you are warking with a file that already has some data in it lets say 50 lines, if you add a new one it would call 51 times, add another one it will call 52 times and so on

lucagrulla commented 4 years ago

Same behaviour on Windows and Debian?

mostfurious commented 4 years ago

I was working on Windows with empty files so i didnt notice any problems, i moved the code to Debian to filter logs and noticed that something was off, downloaded logs from Debian to Windows to check whats going on and then figured out that this is what was happening. That if the file has data in it, this plugin returns ALL file content not the last latest data.

lucagrulla commented 4 years ago

I cannot reproduce the scenario on MacOS X. I could expect odd behaviours on Windows (some low level nodeJS functions are platform dependant), but I would expect consistent behaviour between MacOSX and Debian.

What the frequency of new lines addes to the file?

mostfurious commented 4 years ago

Windows 10, v1607 Node version: v8.12.0

test.js content:

Tail = require('tail').Tail; tail = new Tail("log.log"); tail.on("line", function(data) { console.log(data); });

log.log content before starting test.js:

127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747

After the start i have log.log open and manualy copy/paste the last line "127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747" and then press ctrl+s to save file.

Console output:

PS D:\Desktop\node> node .\test.js

127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747

log.log content:

127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747

Debian 9 Node version: v12.13.0 Same script, same log, same procedure Putty output:

root@vps46:/node/node# node test.js 127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747127.2.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.0.0.3 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747 127.3.0.1 - - [03/Nov/2019:09:16:40 +0200] "GET /wp-admins/js/customize-controls.minx.js?ver=7.2.5 HTTP/1.1" 200 28747

Sorry for the long post

lucagrulla commented 4 years ago

How have you appened your new line both on Windows and Debian)?

I tried and again I cannot reproduce the problem on MacOSX: 

Tail = require('tail').Tail;
tail = new Tail("blah.txt",{logger: console}  );
tail.on("line", (data) =>{
  console.log(data);
});
echo "a1" >>blah.txt

Do you mind the same try the same approach to append on Debian?

By looking to the log it's also hard to really understand if it's repeating or is something else. Is there a way for you to add a unique identifier to your log line so we can be 100% sure it's starting from the beginning every time? Right now they look all the same (minus IP rotating); It might be enough to introduce milliseconds in the timestamp to achieve the goal.

mostfurious commented 4 years ago

Sorry for confusion, On bot Windows and Debian i just open notepad press enter to make a new line then ctrl+v to paste the line and then ctrl+s to save file

Code:

Tail = require('tail').Tail; tail = new Tail("log.log");

tail.on("line", function(data) { console.log(${Date.now()} -- ${data}); });

log.log before:

New Line 1 New Line 2 New Line 3

I paste one and the same line at the time which is "New Line 3" and then save the file.

Windows output:

PS D:\Desktop\node> node .\test.js 1573292987096 -- 1573292989766 -- New Line 3New Line 1 1573292989766 -- New Line 2 1573292989766 -- New Line 3 1573292989766 -- New Line 3 1573292995928 -- New Line 3New Line 1 1573292995928 -- New Line 2 1573292995928 -- New Line 3 1573292995928 -- New Line 3 1573292995928 -- New Line 3

How log.log looks after this:

New Line 1 New Line 2 New Line 3 New Line 3 New Line 3 New Line 3

Same steps on Debian 9 putty output:

root@vps46:/node/node# node test.js 1573293602856 -- New Line 1 1573293602861 -- New Line 2 1573293602861 -- New Line 3 1573293609362 -- New Line 3New Line 1 1573293609362 -- New Line 2 1573293609362 -- New Line 3 1573293609363 -- New Line 3 1573293616859 -- New Line 3New Line 1 1573293616860 -- New Line 2 1573293616860 -- New Line 3 1573293616861 -- New Line 3 1573293616862 -- New Line 3

Hope this clarifies things a bit

lucagrulla commented 4 years ago

I've seen notepad+Windows messing around in the past with operating system level file events in Node , so the test might be incorrect.

Rather then using Notepad can you please try:

echo newline >> log.log

to append a new line directly from your command line (both on Windows and Debian) and let me know?

mostfurious commented 4 years ago

I guess the issue can be closed.... By using the command above in both Windows and Debian 9 i no longer get the whole file content but only last recent data. I tried with live logs that are generated by openlitespeed web server and it seems to work fine now ?? Even tho it was giving me issues before. For future reference i was adding lines to log.log with Notepad++ and then with Visual Studio code which gave me same results... I guess none of text editors can be used while working with this... Sorry for wasting your time and thank you..

lucagrulla commented 4 years ago

glad to hear it's solved!

I won't close this because I have not had the time (yet) to verify what happens with Lubuntu.

ghita commented 4 years ago

Have same behaviour as described in this bug description. On Windows 10.

lucagrulla commented 4 years ago

hi @ghita Can you give more details? Are you using an editor to add lines?

ghita commented 4 years ago

Sorry for late reply. Yes, was using notepad++ to edit. If I don't use that things work though.

lucagrulla commented 4 years ago

Great to hear @ghita.

GravityMsc commented 3 years ago

@lucagrulla any plan to solve this problem? When I add a new line and save the file by using vscode, it still print all lines of the file.

VibingCreator commented 3 years ago

I had the same issue on Windows. Used notepad for changing the content of a file instead of vscode, and that fixed the problem.

Clockworkx commented 3 years ago

I can second @VibingCreator @lucagrulla please leave a note for people using the addon that using an external editor can cause this kind of behavior! Perhaps you know a fix for it, but using notepad works fine (or writing to the file programmatically)

Best regards