serilog / serilog-sinks-email

A Serilog sink that writes events to SMTP email
Apache License 2.0
75 stars 68 forks source link

Design Question: Flush First Message #47

Closed merbla closed 6 years ago

merbla commented 6 years ago

From @ericvb - https://github.com/serilog/serilog-sinks-periodicbatching/issues/19

Hi, When trying to use an other serilog sink, namely serilog-sinks-email, I stumbled on a problem. Whatever I do, I receive always one email with the first log message and then a second mail with the rest of the same error message types.

The email sink code is based on this sink and I see that 'by design' the first message is always directly sent. I understand the need when in a "F5" scenario, but with an email scenario I don't want this. Can this behaviour be overrided?

I find it strange that I don't find any other issues from other people with this same problem. Am I using the email sink not correctly? (maybe this question is more for the github rep serilog-sinks-email :-) )

nblumhardt commented 6 years ago

I think the best outcome in the long run might be to separate the email sink from PeriodicBatching - the design goals of the two are slightly different - in the email case, the batches themselves are presented to a user somewhere down the line, while PeriodicBatching is all about getting events efficiently over a high-latency network connection. Not sure how much code duplication would occur, though.

(I'm not a fan of making any concessions to the needs of the email sink in PeriodicBatching.)

Thoughts?

ericvb commented 6 years ago

I can understand your concern to not make any concessions to PeriodicBatching for the need of another program.

But if you wrap the methode SetTimer(TimeSpan interval) into another protected virtual method, an inheriting class can override the default behaviour if needed

        public void Emit(LogEvent logEvent)
        {
            if (logEvent == null) throw new ArgumentNullException(nameof(logEvent));

            if (_unloading)
                return;

            if (!_started)
            {
                lock (_stateLock)
                {
                    if (_unloading) return;
                    if (!_started)
                    {
                        // Special handling to try to get the first event across as quickly
                        // as possible to show we're alive!
                        _queue.TryEnqueue(logEvent);
                        _started = true;
                        SetFirstRunTimerSetting();
                        return;
                    }
                }
            }

            _queue.TryEnqueue(logEvent);
        }
        protected virtual void SetFirstRunTimerSetting()
        {
            SetTimer(TimeSpan.Zero);
        }

That should work, or am I missing something fundamental? What do you think?

ericvb commented 6 years ago

Does my idea have a chance to get into the root branch? I would prefer to stick with the root code, then to create my own fork.

nblumhardt commented 6 years ago

@ericvb no, sorry; PeriodicBatching needs to stay as-is for now. We don't want to introduce more dependencies on its current implementation quirks, as there's quite a bit of future change that needs to happen there.

Doing something directly in the email sink itself would be fine though, if there's a workaround or change we can make here.

ericvb commented 6 years ago

I don't see directly, without code duplication, a workaround only in the email sink.

When reworking the PeriodicBatching class, please consider an override possibility for this 'by design' F5 scenario hack ;-). A boolean should be enough.

I don't want to fork a mainstream project, so I will 'live' with it for the moment. Later on, we will work with a splunk implementation. So the email sink is only a temporary solution, we must have only a sign that something goes wrong. Thanks for your time.

nblumhardt commented 6 years ago

Thanks for the follow-up @ericvb 👍

cmeeren commented 6 years ago

Just want to say that I would really like this implemented. I'm using the email sink for critical production systems where the customer gets a daily batch of warnings, and I would really like for them not to be bugged by the individual first warning every day.

nblumhardt commented 6 years ago

@cmeeren thanks for the feedback; just regarding @ericvb 's comment:

I don't see directly, without code duplication, a workaround only in the email sink.

I think in this case, some minor code duplication here would be acceptable. A PR that brings in some of the relevant PeriodicBatchingSink code and addresses the issue would be a strong candidate. Cheers!

cmeeren commented 6 years ago

For the time being, said critical systems are consuming all my time and energy. I'll see what I can do about it in the long run though, unless someone else beats me to it.

ericvb commented 4 years ago

@nblumhardt This issue is already closed for about 2 years, but I remarked now that the serilog-sinks-periodicbatching code was adapted with a configuration option to not emit directly the first log message? You changed of opinion?

public void Emit(LogEvent logEvent)
{
    if (logEvent == null) throw new ArgumentNullException(nameof(logEvent));

    if (_unloading)
        return;

    if (!_started)
    {
        lock (_stateLock)
        {
            if (_unloading) return;
            if (!_started)
            {
                _queue.TryEnqueue(logEvent);
                _started = true;

                if (_eagerlyEmitFirstEvent)
                {
                    // Special handling to try to get the first event across as quickly
                    // as possible to show we're alive!
                    SetTimer(TimeSpan.Zero);
                }
                else
                {
                    SetTimer(_status.NextInterval);
                }

                return;
            }
        }
    }

    _queue.TryEnqueue(logEvent);
}

This can be used in the email sink to avoid the first mail. Will try that.

Meanwhile we implemented the Splunk sink. But with Splunk we don't have realtime alerts (it is possible, but it puts heavy load on the system, so our sys admin does not like it) and our client wants directly an email when a task is going wrong. So the temporary solution of two years ago is still working today :-)

nblumhardt commented 4 years ago

Hi @ericvb - thanks for looping back!

You changed of opinion?

I have been known to change opinions occasionally! :-) Hehe.... But no, in this case, my reply two years ago was:

PeriodicBatching needs to stay as-is for now. We don't want to introduce more dependencies on its current implementation quirks, as there's quite a bit of future change that needs to happen there.

Happily, I had some time to make those future changes and reorganize PeriodicBatchingSink around a better API, and this requirement fit in nicely.

It'd be great if you have a chance to update the email sink to utilize the new option 👍 Let me know if you need any help. Thanks!

ericvb commented 4 years ago

Hi @nblumhardt I was analysing the email sink and saw that @bcallaghan-et did a pull request to change the email sink implementation away from the concrete periodicbatching sink class by implementing directly the IBatchedLogEventSink interface and the ILogEventSink interface.

By this way the emailsink is not depending anymore of the specific periodicbatching sink implementation. Correct, but implemented like this, there will be an email per logged event, if I read his code correctly. I don't want that!

I liked to receive one email with the configured number of log events as batch. I use the mail sink in a taskscheduler console app way, so that when the task is finished, it sends me the mail with the logged events (or if > batch limit, several mails) The only thing I didn't like was the first mail due to the old implementation of the periodicbatching sink ;-)

Before continuing, I want to know what are your thoughts about it?

If we want the mail batch implementation

Before continuing, I want to know your opinion, because a PR has more chance if it follows the mainstream idea :-)

bcallaghan-et commented 4 years ago

@ericvb My intention was not to send an email with every log event, though my solution does allow you to do that. I wanted to separate the email logic from the batching logic, so that consumers could choose how the events were batched. I chose to implement ILogEventSink so it would be compatible with "wrapper sinks" that use the standard LogSinkConfiguration.Wrap method. It's then the responsibility of the wrapper to check if the underlying sink supports batching. If you have any other concerns with my solution, please comment on my pull request.

ericvb commented 4 years ago

I link also here to pull request #78 for extra information and follow-up