LogViewPlus Support

Not updating on every file change and sometimes missing entries when starting session

https://www.logviewplus.com/forum/Topic717.aspx

By InelLVP - 18 Aug 2020

Hello,

We are testing live monitoring of log files and noticed, that LogViewPlus only updates on every second or third file change, so it is effectively behind on showing the current log state (tested with other solutions at the same time and those showed the changes as they happened).
The second issue we noticed is that sometimes entries would go missing when starting session (they would not appear in original view, nor in session view that is supposed to show new changes) and refresh while having session started also yields strange results in many cases.
This was tested with both the latest release and beta versions.
By LogViewPlus Support - 18 Aug 2020

Hi Inel,

Thanks for the feedback.

LogViewPlus monitors files by polling them.  A small delay of a fraction of a second is expected.  If you are experiencing delays beyond this it might be a problem with your parser.  In this case, LogViewPlus might be expecting more data in order to complete parsing of the log entry.  Log entries can only be displayed once they have been completely parsed.  

It sounds like you have a significant delay and parsing might be the issue.  I am happy to help with this if you can give me a few sample log entries and the parser configuration you are using.  This might best be done in a separate thread.

Sessions work by taking the last known log entry timestamp and using that as a starting point for a date range filter.  Note that the last known starting point may be several hours ago - or even in a different timezone.  Once the start date is chosen, the filter is simply "show everything after this date".  This is a very simple filter.

Does the session show the correct log entries once started (start date only)?  Does the session show the correct log entries once it is completed (start + end date)?  What happens in both scenarios on a log file refresh?

LogViewPlus does not have the ability to selectively remove or skip a log entry.  So the behavior where it "would not appear in original view" is very strange.  To debug this, I will need more information so I can try to recreate the problem on my side.

Hope that helps,

Toby
By InelLVP - 19 Aug 2020

Hello Toby,

The issue isnt a delay in displaying entries, but the entries not displaying at all no matter how long you wait until more entries are added in files.

In this case a really simple configuration is used - a pattern parser with the following arguments:
%d{yyyy-MM-dd %H:mm:ss.fff}    [%p]    <%t>    %m%n

An example to reproduce this:
Start with a text file containing some entries.
2020-08-19 07:41:10.068    [INF]    <1>    Starting service...
2020-08-19 07:41:10.074    [INF]    <1>    Service started.
Open file in LogViewPlus.
Add a line (without newline / line break):
2020-08-19 07:41:10.068    [INF]    <1>    Test message 1.
*This line probably already wont show, no matter if you wait.
Add another line.
2020-08-19 07:42:00.000    [INF]    <1>    Test message 2.
Both message 1 and message 2 will now show.

It seems it has to do with newline (%n) not being present, since it works otherwise if a newline is added after each entry, but this is not always the case in all log files. And why does it load the second entry with the first one then when no newline is present at the second entry also baffles me.

The issue with session is not consistently reproducible. The session start and end dates are correct though as long as you do not reload the file (if you reaload it, nothing goes into session view anymore and the date starts at jan 1. 00:00:00).
By LogViewPlus Support - 19 Aug 2020

Thanks for the update. 

I will try and reproduce the issue now.  Can you please confirm that the area between the fields represents spaces and not tabs?

Note that if your parser configuration specifies there are 4 spaces between fields, it will always expect 4 spaces.  You can work with spaces with format modifiers.

Alternatively, you could include the spaces in the resulting values by using a simplified pattern like: 
%d{yyyy-MM-dd %H:mm:ss.fff} [%p] <%t> %m%n
By InelLVP - 19 Aug 2020

All three spacings are actually tabs, it seems they got converted to spaces when copying.
By LogViewPlus Support - 19 Aug 2020

Thanks for the update.  I have replaced the 4 spaces to use three tabs.  When I do this, I can parse the file with:
%d{yyyy-MM-dd %H:mm:ss.fff}\t\t\t[%p]\t\t\t<%t>\t\t\t%m%n



Is this what you expected?  

Tabs are similar to spaces in that, if three tabs are expected, three tabs will always need to be found.  Maybe the problem is that the number of tabs can fluctuate?

Also, LogViewPlus should never 'skip' a line.  If a parser is configured incorrectly, I would expect the data to be included as part of the previous log entry.  It can still be found with a text search.  This might be the problem you are describing with "Both message 1 and message 2 will now show."
By InelLVP - 19 Aug 2020

The messages show up as separate entries. Screenshots below to clear up any misunderstanding.
Starting state:

Added message 2 and saved (message 2 missing in LVP):

Added message 3 and saved (message 2 and message 3 now show up at the same time in LVP):

Selected entries in code so you can see the tabs are there as they should be for parsing.
By LogViewPlus Support - 19 Aug 2020

Thanks for the update.  

I am able to recreate the behavior described by not including a newline after a log message.  In other words:
<LogLine>\n  - Works as expected.
\n<LogLine>  - Recreates the issue described.

I will need to investigate this and get back to you.  This looks like a bug and something that will need to be fixed in the next release.

This issue is specific to the most recent log entry.  You have reported a number of different issues in this thread and I am wondering if they all stem from this problem.  Have the other issues been resolved?  Do the other issues appear related to this cause?

Thanks for reporting this issue!

Toby
By InelLVP - 19 Aug 2020

Hello Toby, some other issues do seem to stem from this, some probably not.
The only one i can reproduce at the moment is what i would consider unexpected behaviour:
Open a file, start a session, then reload the file (on either session or file view context menu). The session then states "All new log entries", so you would expect new entries to show up there, however they go under the underlying view from that point on.
There is also something else we noticed - elapsed times are calculated as an absolute value and only when they are added instead of being a calculated value or refreshing upon sorting. So if you have entries that have timestamps out of order in respect to line order (which can happen in certain cases), they should show the relevant difference to the prior entry (so negative values should be possible) and if the entries are reordered (usually you would want them ordered by timestamps), the elapsed values should be recalculated. Examples of what i mean by this in below screenshots.

By LogViewPlus Support - 19 Aug 2020

I am able to recreate the "All new log entries" issue.  I will get this fixed for the next release as well.  Thanks for bringing this it my attention.

Elapsed times are calculated as the absolute time between a given log entry and the previous log entry in the view.  Sorting does not change the elapsed time.

I can see where a negative elapsed time value might be helpful.  I will look into this for the next release.

Thanks again,

Toby
By InelLVP - 20 Aug 2020

We just tried sorting your DX grids by multiple columns, which is also useful in certain cases, but does not seem not work (you can shift-click on additional columns and the sorting indicator appears as usual, but no further sorting occurs). Is this expected if you are perhaps implementing CustomColumnSort, or could this be made to work?
By LogViewPlus Support - 20 Aug 2020

Hi Inel,

When I test, this feature seems to be working correctly:




This might have something to do with the data types of the columns you are sorting.  If you can give me more detail, I can try to recreate on my end.

Also, in future it would be best to create new threads for new issues.  This helps to keep the conversation focused and makes it a bit easier to track what has / hasn't been fixed.

Thanks,

Toby

By InelLVP - 20 Aug 2020

Hello Toby,

It seems the issue appears when sorting starts with date / time.

Of course, we will create separate threads for any further reports.
By LogViewPlus Support - 20 Aug 2020

Thanks Inel - I am able to recreate the issue now.  Let me take a look and see if we can get this fixed for the next release.

Thanks for bringing this problem to my attention!

Toby
By LogViewPlus Support - 29 Sep 2020

Hi Inel,

I just wanted to let you know that we have now released LogViewPlus v2.4.42 into BETA available here:
https://www.logviewplus.com/download.html

This release includes fixes for a number of the issues discussed in this thread:
 - Refreshing a log file with a running session now displays all log entries.
 - Negative elapsed times will now be displayed correctly.  Note that sorting does not impact elapsed times.
 - Adding lines in the format "\n<Message>" is now handled correctly.  This was the core problem discussed in the thread.

After further investigation the "sorting by date" issue is not a bug.  The issue here is that the date and time columns are related.  When you sort by date, you are really sorting by date and time.  This leads to the second sort column seeming appear out of order, but what is really happening is that there are very few entries for a given timestamp. 

Thanks for bringing these issues to my attention. Please let me know if you have any further questions or issues.

Toby