datalust / serilog-sinks-seq

A Serilog sink that writes events to the Seq structured log server
https://datalust.co/seq
Apache License 2.0
225 stars 50 forks source link

Invalid Json format writes to file #140

Closed dm-23 closed 3 years ago

dm-23 commented 4 years ago

I've got the template string: "{Timestamp:yyyy-MM-dd HH:mm:ss,fff} [{ThreadId}] {Level:u} {LoggerName} - {Message:lj}{NewLine}{Exception}"

And when invoke logger.Debug with string: "[{\"$type\":\"SystemModels.Новый_ответ, 11111111-ba34-43ca-9864-9141987b4a72_145\",\"Набор1\":{\"$type\":\"SystemModels.Набор1_6245b237, 11111111-ba34-43ca-9864-9141987b4a72_145\",\"ОписаниеНабора\":\"Набор первый\",\"Ответы\":[{\"$type\":\"SystemModels.Ответ, 11111111-ba34-43ca-9864-9141987b4a72_145\",\"Результат\":\"Ок\",\"Время\":\"2020-09-03T11:45:30.9135838+03:00\"}]}},{\"$type\":\"SystemModels.Новый_ответ, 11111111-ba34-43ca-9864-9141987b4a72_145\",\"Набор1\":{\"$type\":\"SystemModels.Набор1_6245b237, 11111111-ba34-43ca-9864-9141987b4a72_145\",\"ОписаниеНабора\":\"Набор второй\",\"Ответы\":[{\"$type\":\"SystemModels.Ответ, 11111111-ba34-43ca-9864-9141987b4a72_145\",\"Результат\":\"Ок\",\"Время\":\"2020-09-03T11:45:30.9135998+03:00\"}]}}]"

we have got the invalid json in our log file:

[{"$type":"SystemModels.Новый_ответ, 11111111-ba34-43ca-9864-9141987b4a72_145","Набор1":{"$type":"SystemModels.Набор1_6245b237, 11111111-ba34-43ca-9864-9141987b4a72_145","ОписаниеНабора":"Набор первый","Ответы":[{"$type":"SystemModels.Ответ, 11111111-ba34-43ca-9864-9141987b4a72_145","Результат":"Ок","Время":"2020-09-03T11:45:30.9135838+03:00"}]},{"$type":"SystemModels.Новый_ответ, 11111111-ba34-43ca-9864-9141987b4a72_145","Набор1":{"$type":"SystemModels.Набор1_6245b237, 11111111-ba34-43ca-9864-9141987b4a72_145","ОписаниеНабора":"Набор второй","Ответы":[{"$type":"SystemModels.Ответ, 11111111-ba34-43ca-9864-9141987b4a72_145","Результат":"Ок","Время":"2020-09-03T11:45:30.9135998+03:00"}]}]

You can see there is not closing } for first array items. I pointed it as bold.

dm-23 commented 4 years ago

There is error on picture. There_is_error

dm-23 commented 4 years ago

Sorry, I'm forgot to write version: Serilog 2.9.0

dm-23 commented 4 years ago

I caught It. In a Logger.cs:

// Catch a common pitfall when a single non-object array is cast to object[]
            if (propertyValues != null &&
                propertyValues.GetType() != typeof(object[]))
                propertyValues = new object[] { propertyValues };

            _messageTemplateProcessor.Process(messageTemplate, propertyValues, out var parsedTemplate, out var boundProperties);

In my case the propertyValues is null. Next Process - MessageTemplateProcessor.cs:

public void Process(string messageTemplate, object[] messageTemplateParameters, out MessageTemplate parsedTemplate, out EventProperty[] properties)
        {
            parsedTemplate = _parser.Parse(messageTemplate);
            properties = _propertyBinder.ConstructProperties(parsedTemplate, messageTemplateParameters);
        }

parsedTemplate = _parser.Parse(messageTemplate); Parsing allways and when messageTemplateParameters is null, Why ? Next...

public MessageTemplate Parse(string messageTemplate)
        {
            if (messageTemplate == null) throw new ArgumentNullException(nameof(messageTemplate));

            return new MessageTemplate(messageTemplate, Tokenize(messageTemplate));
        }

Tokenize(messageTemplate) => Next

static IEnumerable<MessageTemplateToken> Tokenize(string messageTemplate)
        {
            if (messageTemplate.Length == 0)
            {
                yield return new TextToken("", 0);
                yield break;
            }

            var nextIndex = 0;
            while (true)
            {
                var beforeText = nextIndex;
                var tt = ParseTextToken(nextIndex, messageTemplate, out nextIndex);
....

And a little more

static TextToken ParseTextToken(int startAt, string messageTemplate, out int next)
        {
            var first = startAt;

            var accum = new StringBuilder();
            do
            {
                var nc = messageTemplate[startAt];
                if (nc == '{')
                {
                    if (startAt + 1 < messageTemplate.Length &&
                        messageTemplate[startAt + 1] == '{')
                    {
                        accum.Append(nc);
                        startAt++;
                    }
                    else
                    {
                        break;
                    }
                }
                else
                {
                    accum.Append(nc);
                    if (nc == '}')
                    {
                        if (startAt + 1 < messageTemplate.Length &&
                            messageTemplate[startAt + 1] == '}')
                        {
                            startAt++;

There is a search the symbols {{ or }} and after, you will create a token for message template and we have get error in our string. Why you parce string for tokens if you have not any parameters ? Now made this: I'm replacing in the string {{ and }} to { { and } }, with space. But I want to know how to exclude this ? Create custom ITextFormatter or else ?

nblumhardt commented 3 years ago

Thanks for your message. This repository is for the Seq sink, to which this issue is unrelated.

I think there are two considerations: 1, the parameterless log method overloads (Information(string) for example) still assume the string is a message template, as you've observed. Using a template with one substitution will be closer to what you want:

Log.Information("{SomeJson}", someJson);

But 2, also, if you want to output parseable JSON, a JSON formatter of some kind (JsonFormatter or CompactJsonFormatter) is usually the way to go.

Hope this helps; if you need further info, this is probably a good question for Stack Overflow. Cheers!