Logger cannot log long json lines properly

[angrygami]

I have following version of asterisk (running inside docker alpine based container):

Asterisk 18.1.1 built by buildozer @ build-3-13-x86_64 
on a x86_64 running Linux on 2020-12-26 04:47:38 UTC

When I configure logger to use json formatter like this:

...
messages => [json]notice,warning,error
...

and enable verbose logging for pjsip like this:

$ rasterisk -x 'pjsip set logger on'

After making some calls I noticed that log lines that are longer than 1024 symbols are cut off making json invalid and loosing information.
Is there any way around this?

[jcolp]

The logger appears to have a fixed buffer size for things, so there is no way around it except for changing how that works in the logger. You could file an issue[1] but there’s no timeframe on when it would get looked into.

[1] https://issues.asterisk.org/jira

[angrygami]

Thank you for your response.
I see why this limit exists for logger, but I also see that it totally can properly log full sip dialog when not using json. I.e. logger is fine - json serialization is broken or… well, maybe not “broken” but sub-optimal. Anyway, if only json serializer can produce json with line breaks (giving logger a chance to flush buffer in the middle of big json message)… I understand that you can’t just print line feed character in the middle of json string value (this makes invalid json and this is why currently json is riddled with \r\n), therefore such messages have to be converted into json array of strings - e.g.:

{...
"log":[
"<--- Received SIP request (1421 bytes) from UDP:10.5.5.1:44170 --->",
"INVITE sip:testuser@test.asterisk.com",
...
]}

Is this a good idea?

[jcolp]

I’d rather identify the specific limits in the logger that are causing it, instead of trying to work around it in such a fashion… I think ultimately you have to make code changes somewhere.

[jcolp]

This is the JSON logger implementation itself[1]. It dumps the JSON as a string and sticks it into a buffer for writing[2]. The buffer there is defined using BUFSIZ[3].

[1] asterisk/logger.c at master · asterisk/asterisk · GitHub
[2] asterisk/logger.c at master · asterisk/asterisk · GitHub
[3] asterisk/logger.c at master · asterisk/asterisk · GitHub

[angrygami]

Yes, now I see why my idea won’t work. Though just cranking up buffer size to a higher value will only delay inevitable - when message is again bigger than that.

I also saw that there is probably a typo there - second line missing comma in the end:

	json = ast_json_pack("{s: s, s: s, "
		"s: {s: i, s: s} "
		"s: {s: {s: s, s: s, s: i}, "
		"s: s, s: s} }",

[jcolp]

Quite possible. I haven’t dealt with this code so don’t know anything further of it.

[angrygami]

Though is is still not clear to me how logger manages to print entire sip message when no formatter is specified.
It seems that in this case it will use default formatter, here

This formatter will use snprintf for constructing output message into buffer, here
Therefore it is also limited by same buffer size as json formatter. How this is possible?

[jcolp]

I’ve seen it not output the entire SIP message. In JSON there’s additional data, so it may cause it to exceed the limit.

[angrygami]

Ah… yes, that makes sense.