Dear Toby,

when analyzing complex log files or problems I sometimes would like to be able to make very special evaluations like the following.

For example I have a list of 50 log files and I want to see the first 10 and last 10 log entries of every log file.

Or another example is, that our log files contain a list of hardware components in our device including serial numbers. And for a list of 50 consecutive log files I would like to see if and where hardware changes between log files have occurred.

Both cases I think could be realized by a custom filter on a merged log file list. However the current ILogFilter interface only allows to see a single log file entry. For the above cases I would have to also check other, neighboring, log file entries (to find the position of the log entries in the log files or the find the hardware components list of the preceding log file).

Do you think such an extension would be feasible?

Kind Regards
Andreas

Hi Andreas,

This is a difficult one for me to debug without the underlying data.  I have looked at the code and can't see any reason why the 'additional' 1.7M log entries would have any impact.  That is the aspect of the problem I would like to focus on as your performance issue only happens with the 'additional' records.

If you are filtering off of a parent filter with 8000 log entries, then I would expect the Show method to be called 8000 times.  I would also expect logEntry.FindPrevious(LookupSource.ParentFilter) never returns more then 8000 entries.  Can you please confirm this assumption is correct by adding logging or trace statements?

I would also expect the first call into logEntry.FindPrevious takes time, but subsequent requests (for the same source LogEntry) should be very quick.  It may be worth adding a timer to see how long that first call takes.  This is the timer I frequently use:

        private static System.Diagnostics.Stopwatch _stopWatch = null;
        private static void StartTimer()
        {
            _stopWatch = System.Diagnostics.Stopwatch.StartNew();
        }

        private static string StopTimer()
        {
            _stopWatch.Stop();
            return _stopWatch.Elapsed.ToString();
        }

Thanks,

Toby

Hi Toby,

first one correction from my side. The filtered view only has 880 entries, not 8000.

Doing some suggested analysis I found out, that FindPrevious(LookupSource.ParentFilter) unexpectedly returns more than 880 entries. In fact it returns the previous entries from the whole log. If I use LookupSource.CurrentFilter it looks better (works as expected).

Here is what I have in my "Files and Views" List:

LogFile1
LogFile2
LogFile....
LogFile35
Merged View of all above Log Files <- 1.7 Mio entries
    Standard Logger Filter <- 880 entries
        My Custom Filter  <- My code

Can you explain the LookupSource for this example please?

Thanks,
Andreas

I know what the problems is.  Unfortunately, I have once again missed something and will need to make an API change. 

I tested this from an Analyzer and not a Filter.  With an Analyzer, look-ups like 'Current' and 'Parent' make sense because they are triggered by user action from a Filter.  However, with a Filter those relationships only make sense relative to a particular filter.  Relative to your custom filter in this case.

Unfortunately, the API that you are working with takes "Current Filter" to mean the one that the user user currently looking at.  In a tail file situation, lots of filters are triggered but only one currently has the user focus.  Only one can be 'Current'.  

When you are executing your code, the "Current Filter" is actually the parent of the filter you are currently creating.  The parent filter is the one above that.

Really, you want the 'Current Filter' to be 'this' filter.  ...and that is information that is not currently supported in the API.

So, I will need to make a change (again - sorry :-) to the API.  The new API will look like:

public IEnumerable<LogEntry> FindNext(LookupSource source, ILogFilter currentFilter)

...which you can then call with:

logEntry.FindNext(LookupSource.ParentFilter, this)

If you wanted to search relative the the users current focus, you can pass in NULL instead.  The current focus will become the default behavior.

I hope that makes sense.  Apologies for not spotting this issue sooner.  I should be able to turn this around in the next few days.

Thanks,

Toby

Thanks for the explanation. Now I understand.

Another thing that came to my mind while testing the new API. It would be nice for a custom filter to provide it's own configuration dialog instead of the default "Edit Custom Filter" dialog. Do you think that is easy to implement?

Thanks,
Andreas

One step ahead of you on that one.  :-)
https://www.logviewplus.com/forum/150/Configuration-of-Custom-Reader

Should be out in the next release along with the change discussed above.

Hi Toby,

I implemented another filter now, that works on larger logs (not already filtered ones). And here I observe some performance problems that seem to originate from the IEnumerators MoveNext method. From first tests it takes about 0.5ms to execute. Even if I only get the next neighbor  for each entry (without doing any other analysis) of a 10.000 line log file, it takes about 5s. For logs with much more entries this takes to long. 

Do you think the performance could be improved a bit?

Thanks,
Andreas

I will take a look and see what we can do for the next release.  I think just reversing the order of the search (to start with the more recent entries) should have a big impact.

Thanks,

Toby

Ok. Thanks. Btw, here is the code of this second filter. The intention is to show the n first and n last log entries of every source file of a merged log view. So I check if the MoveNext method can be called at least n times to check if we are in the middle or at the end of the log file. (Maybe there is a simpler way, but basically it works, however slow.)

public bool Show(LogEntry logEntry)
    {
    bool bShow = false;
    bool bPrev = false;
    IEnumerable<LogEntry> previous = logEntry.FindPrevious(LookupSource.SourceLogFile);
    IEnumerator<LogEntry> prevEnum = previous.GetEnumerator();
    for (int i = 0; i < m_iNumLogEntries; i++)
    {
      bPrev = prevEnum.MoveNext();
    }
    if (!bPrev)
    {
      bShow = true;
    }
    else
    {
      bool bNext = false;
      IEnumerable<LogEntry> next = logEntry.FindNext(LookupSource.SourceLogFile);
      IEnumerator<LogEntry> nextEnum = next.GetEnumerator();
      for (int i = 0; i < m_iNumLogEntries; i++)
      {
        bNext = nextEnum.MoveNext();
      }
      if (!bNext)
      {
        bShow = true;
      }
    }
    return bShow;
    }

Hi Andreas,

In the latest BETA release of LogViewPlus (v2.3.8), I have modified the initial lookup to use a binary search based on the log entry date.  This will significantly improve performance assuming your log entries are date sorted.  This is usually the case, but is not required.  A table scan will be used as a fall back.

Thanks for the code snippet.  I have used this as a starting point for a new ILogFilter implementation called TopBottomFilter which is now available in our updated sample code.  Please see:
http://www.logviewplus.com/dist/LogViewPlus_Samples.zip
https://www.logviewplus.com/docs/running_the_samples.html

The updated sample code also shows how to implement custom configuration.   This is as discussed on this thread:
https://www.logviewplus.com/forum/150/Configuration-of-Custom-Reader

Hopefully, this new implementation will resolve the issues you were having but please do let me know if you have any further questions or issues.

Thanks,

Toby

Hi Toby,

I just had a look at the current version and adapted my filters. Everything seems to be working as expected so far. Performance is also improved, now taking about 15s for my 1.7Mio entries merged log example, which I think is sufficient. Thanks for your support.

At the new CustomConfiguration interfaces I also had a quick look, but didn't implement one yet. I was however a little bit surprised to find that they are opened by a new "Configure" button in the "Create Custom Filter" dialog. I somehow expected that the custom configuration dialogs would replace the default dialog when present. So for changing settings I have to click twice to enter the configuration dialog. Probably will get used to it.

Two other things I noticed:
a) The copy instruction in the sample projects should include "quotation marks" to also work for cases with space in the folder names.
b) When using my TopBottom Filter I noticed something that I didn't observe before. Our log files are limited in size, so we have the case that some log entries will be written to the end of the previous log file and the next ones to the beginning of the next log file. I then merge all relevant log files to see one big log file with all data. With the current Release I noticed, that when the log files that at the end and the beginning have the same time-stamp, the order of the log files is not preserved. I don't know if this is to be expected, but did not observe before, or if this is maybe a bug of the new version. For my use case it is a little bit unexpected.

Thanks
Andreas

Hi Andreas,

Glad to hear that things are working a little bit more smoothly now.

Thanks for pointing out the issue with spaces in file name paths.  I have updated the sample projects to use quotes as suggested.

I agree that the CustomConfiguration process is a little bit clunky for the end user.  However, completely replacing the existing configuration screens would greatly increase the complexity of the configuration implementation.  Also, a lot of this implementation would end up being the same for most users (name pattern validation, etc...).  For now, I wanted to focus on API simplicity.

> log files that at the end and the beginning have the same time-stamp, the order of the log files is not preserved

When log files are merged, the log entries are sorted by timestamp.  In the case where two log entries have the same timestamp, LogViewPlus has no way of knowing what the order should be.  While I understand that some data is lost - I think this is the correct behavior.  I am happy to explore this issue further, but it may be best to do so on a separate thread.

Thanks again,

Toby