nreco / logging

Generic file logger for .NET Core (FileLoggerProvider) with minimal dependencies
MIT License
284 stars 56 forks source link

Add different rolling name conventions #66

Closed LeviGNMBS closed 3 months ago

LeviGNMBS commented 3 months ago

Hi, first of great library, just was missing one thing i added in this PR :)

If you like it please consider updating the main library, I already tested the file creation extensively on windows, however i don't have access to linux systems at the moment. So i'd prefer if someone can test on *nix machines

This PR would potentially fix #5 but it needs to be tested if tail can handle file pointer moving.

The functions I abstracted to reuse more code could potentially be exposed outside to allow for applications to get info about the logs (getting all log files, getting their index) potentially aiding in #53

If you like it please consider testing and updating the main library, I already tested the file creation extensively on windows, however i don't have access to linux systems at the moment. So i'd prefer if someone can test on *nix machines first.

VitaliyMF commented 3 months ago

Wow - that's really cool improvements! I'll be happy to accept this PR.

I would like to ask you for small changes - just let me know if you don't have time for them, this is ok and I'll do that by myself after accepting the PR:

LeviGNMBS commented 3 months ago

Thank you πŸ˜€

I will work more on it today and apply the changes you want, I wasn't sure what brackets you used since i found both in the original source, but ill make the changes. I will write one test for each of the new modes.

Is it okay if I lengthen Asc and Desc into Ascending and Descending? I rarely shorten enums. πŸ˜‰

VitaliyMF commented 3 months ago

Is it okay if I lengthen Asc and Desc into Ascending and Descending? I rarely shorten enums.

Sure, or maybe you will find better names.

LeviGNMBS commented 3 months ago

Okay i added tests, adjusted the naming, and fixed the formatting (mostly). Since there was no actual single formatting before i think this is better, now at least this file is formatted in a single way. I also added editorconfig files so anyone who opens your project with visual studio or compatible will get the same formatting rules, you might want to tweak and apply those to your liking.

LeviGNMBS commented 3 months ago

Thanks! πŸ˜€

VitaliyMF commented 3 months ago

@LeviGNMBS It seems Github Action that should run tests compiles them but (for some reason) says that "No test is available", I guess this is not related to your PR at all.

I've executed tests in my env and test fails:

[xUnit.net 00:00:00.81]     NReco.Logging.Tests.FileProviderTests.WriteDescendingRollingFile [FAIL]
  Failed NReco.Logging.Tests.FileProviderTests.WriteDescendingRollingFile [277 ms]
  Error Message:
   Assert.Equal() Failure: Collections differ
           ↓ (pos 0)
Expected: ["test4.log", "test3.log", "test2.log", "test1.log", "test.log"]
Actual:   ["test2.log", "test3.log", "test4.log", "test.log", "test1.log"]
           ↑ (pos 0)
  Stack Trace:
     at NReco.Logging.Tests.FileProviderTests.WriteDescendingRollingFile() in FileProviderTests.cs:line 231

Failed!  - Failed:     1, Passed:    12, Skipped:     0, Total:    13, Duration:
 3 s - NReco.Logging.Tests.dll (net6.0)

Could you confirm that this test is passed in your env?..

VitaliyMF commented 3 months ago

@LeviGNMBS I fixed Github action so now it runs tests correctly and now it fails.

Could you take a look? It seems "Descending" mode works incorrectly.

LeviGNMBS commented 3 months ago

@LeviGNMBS I fixed Github action so now it runs tests correctly and now it fails.

Could you take a look? It seems "Descending" mode works incorrectly.

I will take a look at it, on my end it never fails. Maybe its something github actions related πŸ€” In the Descending test i do test more, I test the actual order of the files written, but maybe it has something to do with the github filesystem not keeping the last time written correctly? I'll see if i can rewrite the test better.

LeviGNMBS commented 3 months ago

Sorry i misunderstood the issue, i see now that the tests failing in the github actions is a part of the original test i copied, wich is weird that it would fail now in the actions. And the test failing on your end i have no idea either, maybe your pc is just much faster and we are running into race conditions? Either way im not a fan of making tests that rely on thread.sleep to function correctly. I could rewrite the tests so we don't actually test the file writing but just the naming, but that would require exposing more functions to outside the provider. But i don't know if that is something you'd want?

Im thinking if we expose the file name functions in the provider, and allow to switch file there without having written to them, and retrieve the current file, we can just test if the order is correct without ever having written a file and relying on the logging framework to flush? plus that might also help #53 ?

VitaliyMF commented 3 months ago

@LeviGNMBS

I tried to run tests in a single-thread mode (with "-p:ParallelizeTestCollections=false") and anyway test fails:

[xUnit.net 00:00:00.82]     NReco.Logging.Tests.FileProviderTests.WriteDescendingRollingFile [FAIL]
  Failed NReco.Logging.Tests.FileProviderTests.WriteDescendingRollingFile [270 ms]
  Error Message:
   Assert.Equal() Failure: Collections differ
           ↓ (pos 0)
Expected: ["test4.log", "test3.log", "test2.log", "test1.log", "test.log"]
Actual:   ["test.log", "test1.log", "test2.log", "test3.log", "test4.log"]
           ↑ (pos 0)

It looks like "Descending" works ok now, but simply "expected" result is wrong:

//check last time written in order
Assert.Equal(new[] { "test4.log", "test3.log", "test2.log", "test1.log", "test.log" }, new DirectoryInfo(tmpFileDir).GetFiles("test*.log").OrderBy(f => f.LastWriteTimeUtc).Select(f => f.Name).ToArray());

I guess correct "extected" result should be "test.log", "test1.log", "test2.log", "test3.log", "test4.log" (order by LastWriteTime - so newest files are first files).

Could you confirm that this is simply a bug in the test?

LeviGNMBS commented 3 months ago

Could you confirm that this is simply a bug in the test?

No :)

I guess correct "extected" result should be "test.log", "test1.log", "test2.log", "test3.log", "test4.log" (order by LastWriteTime - so newest files are first files).

This is incorrect, since the files are ordered Ascending in time .GetFiles("test*.log").OrderBy(f => f.LastWriteTimeUtc) This means that the last written file is last in the list, not first since later time > older time. This however is affected by the computer/os caching and not directly writing the files, which affects these times, as i said these are race conditions we have no control over and a better test would not write to disk at all since that is an unknown factor. Ill see if i can write a test without writing to disk.

VitaliyMF commented 3 months ago

@LeviGNMBS I see. The root of the problem is this code in the WriteDescendingRollingFile:

                for (int i = 0; i < 1000; i++) {
                    logger.LogInformation("TEST 0123456789");
                }

Adding Thread.Sleep helps to get green test. I'll try to modify this test to make it more stable.

LeviGNMBS commented 3 months ago

@VitaliyMF

I have a better test that does not involve times:

                for (int i = 0; i < 10; i++) {
                    logger.LogInformation("TEST " + i);
                    Thread.Sleep(20); // give some time for log writer to handle the queue
                }
                factory.Dispose();

                // check how many files are created, Descending will always write to test.log
                Assert.Equal(5, Directory.GetFiles(tmpFileDir, "test*.log").Length);

                //check order of files
                Assert.Contains("TEST 9", System.IO.File.ReadAllText(Path.Combine(tmpFileDir, "test.log")));
                Assert.Contains("TEST 8", System.IO.File.ReadAllText(Path.Combine(tmpFileDir, "test1.log")));
                Assert.Contains("TEST 7", System.IO.File.ReadAllText(Path.Combine(tmpFileDir, "test2.log")));
                Assert.Contains("TEST 6", System.IO.File.ReadAllText(Path.Combine(tmpFileDir, "test3.log")));
                Assert.Contains("TEST 5", System.IO.File.ReadAllText(Path.Combine(tmpFileDir, "test4.log")));
VitaliyMF commented 3 months ago

At least for now adding Thread.Sleep makes all tests green. You may propose a new PR with better organized tests if you have some time for that.

Thank you for your contribution! Your enhancement is already shipped in 1.2.1.

LeviGNMBS commented 3 months ago

You are welcome and thank you for the library! I might try to work on the tests/the functions some more if i find the time :)