Using Serilog with memstate (general discussions)

[goblinfactory]

Hi @rofr

I'm using Serilog in my project and tried to use Serilog with a memstate command and I was unable to to test it.
I wrote these 2 tests, test 1, proving that the TestCorrelator is working fine to capture Log.Information calls, and the second test, proving that my call to Log.Information from inside a memstate command is not working.

I couldn't find any tests in the memstate project for Serilog, and the code for the Serilog provider in memstate doesn't easily explain why it's not working, or how I'm supposed to do logging, and-or use Serilog with memstate.

Before I spend any serious time looking at the LibLog logging code (or experimenting with ripping part of that all out or providing some means of disabling it so that Serilog will work, and creating a PR, .. I wanted to check with you first that i wasn't doing anything obviously wrong?

here are the two tests I've written;

        [Fact]
        public void Test_that_proves_serilog_context_logging_and_testing_works_correctly()
        {
            using (TestCorrelator.CreateContext())
            {
                // this passes, proving the problem is within memstate, possibly because it's using LibLog or some strange logging provider
                // mechanism.

                var text = "can you see me?";
                Log.Information(text);

                TestCorrelator.GetLogEventsFromCurrentContext()
                    .Should().ContainSingle()
                    .Which.MessageTemplate.Text
                    .Should().Be(text);
            }
        }


        [Fact]
        public async Task Test_that_proves_Serilog_not_working_with_memstate()
        {
            using (TestCorrelator.CreateContext())
            {
                var text = "can you see me?";

                // this fails, because DummyJournalRecord calls Log.Information from within memstate, and 
                // memstate swollows it somehow?

                await _services.Database.Execute(new DummyJournalRecord() { Text = text });

                TestCorrelator.GetLogEventsFromCurrentContext()
                    .Should().ContainSingle()
                    .Which.MessageTemplate.Text
                    .Should().Be(text);
            }
        }

and here is the DummyJournalRecord that I call;

    // does not change database state, instead writes a marker record that can be used for testing to the journal file.
    public class DummyJournalRecord : Command<DomaniumDB, bool>
    {
        public string Text { get; set; }
        public override bool Execute(DomaniumDB model)
        {
            Log.Information(Text);
            return true;
        }
    }

Basically, what I want to be able to do is use Serilog as shown above in the DummyJournalRecord. It seems that memstate somehow interferes with the default Log.Logger context, and my calls disappear due to some Context problems. i.e. they don't get flushed or routed to the configured sink. (In this case, the TestCorrelator sink)

Any suggestions?

cheers,

Alan

p.s. Merry Christmas!
Oh! ...also, I wrote a new open source project last night PrettyJson : https://github.com/goblinfactory/pretty-json

[goblinfactory]

Aah, bit slow, maybe the egnog talking, but I just realised that logging inside a command is breaking the journal isolation, i.e. it's a side effect and commands should be side effect free. (outside of the model, that is)

In other words, this isn't a bug,(it's by design), all I need to do is move the logging to outside of memstate "context" and it should all be good? let me confirm that. i.e. make the call to Log before executing the command, don't do any logging inside the command.
sorry for the false alarm if this is the case.

[rofr]

The LibLog component enables memstate to integrate with whatever logging solution you choose. This means that logging statements from within the framework code hits whatever logging solution you have configured. So to use Serilog just configure it as you would normally and don't worry about LibLog.

[goblinfactory]

ah, if that's the actual behavior you want, which I doubt, then I don't think that works as you mention. Besides, it would mean that every time your app starts if you're logging inside commands, they'll write to your logs which you wont want to happen. Also Liblog is deprecated and logging with serilog is simpler and is the recommended way to decouple yourself from changes caused by different implemntations of Ilogger. Not all implementations are equal. afaik?

[goblinfactory]

In either case, if you simply use Serilog, and log before calling memstate commands everything works and memstate doesnt interfere or hook into your logging, which is much better ... imho.