Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Virendra Negi]

Thanks, Lennart.

On Mon, May 22, 2023 at 4:28 PM Lennart Poettering 
wrote:

> On Mo, 22.05.23 15:58, Virendra Negi (virendra.n...@sugarboxnetworks.com)
> wrote:
>
> > I'm not sure how Systemd was handling this, but my assumption is that
> > systemd redirects STDOUT , STDERR to  /*dev/log *and then systemd would
> > pick that up and write to the respective file based. Given I found no
> help
> > with rsyslog to deal with the large size log message (which are few in
> > number) I looked at the journald conf.
>
> "Standard{Output|Error}=syslog" is legacy. It's identical to
> "Standard{Output|Error}=journal", and that's the default anyway. Hence
> these two lines are entirely unnecessary, you can drop them without
> change in behaviour
>
> The journal daemon picks up the logs from stdout/stderr of various
> services, from syslog, form the native journal protocol and writes it
> to the journal files.
>
> I have no idea about rsyslog and your distro, but secondary logging
> services have two way to get ahold of the log data once journald
> picked it up: they can listen on some AF_UNIX that systemd forwards
> all mentioned log data. This is mostly a compat feature since it only
> covers log data "as it happens", and that means not early boot/late
> shutdown stuff. It also doesn't do structured loggic. The other way is
> to simply read the data from journal files as the are updated, using
> the files as a "live" transport, with the nice functionality that
> secondary logging services can easily catch up with what happened
> while they weren't running. And you get full structured data. I know
> that RHEL configures rsyslog that way, but I think rsyslog upstream
> used to be hostile to such an approach, so no idea, if that ever was
> merged upstream.
>
> > As mentioned you can use the _LINE_BREAK= field to reassemble the
> > > lines. But seriously, if you are logging megabytes of data in single
> > > log messages you are doing things wrong. Rivisit what you are doing
> > > there, you are trying to hammer a square log message into a round log
> > > transport. Bad idea.
> >
> > @Lennart How? JFI, this is what the split message of a large log message
> > looks like.
>
> Well, I think rsyslog has no idea about the journal's structured
> logging, because it lives in its own world. It won't see the
> _LINE_BREAK= structured logging. Hence you cannot reasonably
> reassamble I guess, the info is simply lost once rsyslog takes over.
>
> Lennart
>
> --
> Lennart Poettering, Berlin
>

-- 

   
  





-- 
**Disclaimer*: This e-mail and any documents, files, or previous e-mail 
messages appended or attached to it may contain confidential and/or 
privileged information. If you are not the intended recipient (or have 
received this email in error) please notify the sender immediately and 
delete this e-mail. Any unauthorized copying, disclosure or distribution of 
the material in this email is strictly prohibited & unlawful. The recipient 
acknowledges that Margo Networks Private Limited (SugarBox) may be unable 
to exercise control or ensure or guarantee the integrity of the text of the 
email message and the text is not warranted as to completeness and 
accuracy. Before opening and accessing the attachment, if any, please check 
and scan for virus*

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Lennart Poettering]

On Mo, 22.05.23 15:58, Virendra Negi (virendra.n...@sugarboxnetworks.com) wrote:

> I'm not sure how Systemd was handling this, but my assumption is that
> systemd redirects STDOUT , STDERR to  /*dev/log *and then systemd would
> pick that up and write to the respective file based. Given I found no help
> with rsyslog to deal with the large size log message (which are few in
> number) I looked at the journald conf.

"Standard{Output|Error}=syslog" is legacy. It's identical to
"Standard{Output|Error}=journal", and that's the default anyway. Hence
these two lines are entirely unnecessary, you can drop them without
change in behaviour

The journal daemon picks up the logs from stdout/stderr of various
services, from syslog, form the native journal protocol and writes it
to the journal files.

I have no idea about rsyslog and your distro, but secondary logging
services have two way to get ahold of the log data once journald
picked it up: they can listen on some AF_UNIX that systemd forwards
all mentioned log data. This is mostly a compat feature since it only
covers log data "as it happens", and that means not early boot/late
shutdown stuff. It also doesn't do structured loggic. The other way is
to simply read the data from journal files as the are updated, using
the files as a "live" transport, with the nice functionality that
secondary logging services can easily catch up with what happened
while they weren't running. And you get full structured data. I know
that RHEL configures rsyslog that way, but I think rsyslog upstream
used to be hostile to such an approach, so no idea, if that ever was
merged upstream.

> As mentioned you can use the _LINE_BREAK= field to reassemble the
> > lines. But seriously, if you are logging megabytes of data in single
> > log messages you are doing things wrong. Rivisit what you are doing
> > there, you are trying to hammer a square log message into a round log
> > transport. Bad idea.
>
> @Lennart How? JFI, this is what the split message of a large log message
> looks like.

Well, I think rsyslog has no idea about the journal's structured
logging, because it lives in its own world. It won't see the
_LINE_BREAK= structured logging. Hence you cannot reasonably
reassamble I guess, the info is simply lost once rsyslog takes over.

Lennart

--
Lennart Poettering, Berlin

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Virendra Negi]

@Lennart  Earlier our unit file had the following definition



*StandardOutput=syslogStandardError=syslogSyslogIdentifier=sbagent*


I'm not sure how Systemd was handling this, but my assumption is that
systemd redirects STDOUT , STDERR to  /*dev/log *and then systemd would
pick that up and write to the respective file based. Given I found no help
with rsyslog to deal with the large size log message (which are few in
number) I looked at the journald conf.

I removed the above explicit definition i.e. *StandardOutput etc ..*  from
the unit file.

And now currently,  our logs are written on STDOUT and STDERR and systemd
writes it to journal which `rsyslog` observer redirects them to a specific
file(that is what my understanding)



As mentioned you can use the _LINE_BREAK= field to reassemble the
> lines. But seriously, if you are logging megabytes of data in single
> log messages you are doing things wrong. Rivisit what you are doing
> there, you are trying to hammer a square log message into a round log
> transport. Bad idea.



@Lennart How? JFI, this is what the split message of a large log message
looks like.

May 22 05:22:38 088c16 echo-command[31926]:. Start ...

...
> 2109876543210987654321098765432109876543210987654321098765432109876543210987654321098765432109876543210987654321098765432109876543210987654
> May 22 05:22:38 088c16 echo-command[31926]:
> 32109876543210987654321098765432109876543210987654321098765432109876543210987654321098765...
> .. End
>



*Start ... End* suppose to be a single line but because it reach the upper
limit of 48K it was broken. Now how can I assemble them?


Thanks

On Mon, May 22, 2023 at 2:01 PM Lennart Poettering 
wrote:

> On Mo, 22.05.23 09:31, Virendra Negi (virendra.n...@sugarboxnetworks.com)
> wrote:
>
> > Ok, I think I get a sense of who is doing what which results in the Large
> > Message getting Split as per my understanding it's *LINE_MAX* value in
> the
> > `journalctl` conf that causes the Large message to get split.
> >
> > The default value is 48K and compared to the size of the split message
> and
> > it comes approx to 48K. Now that explains that I'm thinking *is there** a
> > way to prepend any "IDENTIFIER"  for the message that was split* from the
> > original message? so that we can reassemble/merge them at the central L
> > *ogstash* server.
> >
> > I'm looking at the correct section of code,
> >
> https://github.com/systemd/systemd/blob/main/src/journal/journald-stream.c#L498
> > I
> > don't think there exists anything like it. Still want to check if there
> is
> > anything possible?
>
> As mentioned you can use the _LINE_BREAK= field to reassemble the
> lines. But seriously, if you are logging megabytes of data in single
> log messages you are doing things wrong. Rivisit what you are doing
> there, you are trying to hammer a square log message into a round log
> transport. Bad idea.
>
> Lennart
>
> --
> Lennart Poettering, Berlin
>

-- 

   
  





-- 
**Disclaimer*: This e-mail and any documents, files, or previous e-mail 
messages appended or attached to it may contain confidential and/or 
privileged information. If you are not the intended recipient (or have 
received this email in error) please notify the sender immediately and 
delete this e-mail. Any unauthorized copying, disclosure or distribution of 
the material in this email is strictly prohibited & unlawful. The recipient 
acknowledges that Margo Networks Private Limited (SugarBox) may be unable 
to exercise control or ensure or guarantee the integrity of the text of the 
email message and the text is not warranted as to completeness and 
accuracy. Before opening and accessing the attachment, if any, please check 
and scan for virus*

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Lennart Poettering]

On Mo, 22.05.23 09:31, Virendra Negi (virendra.n...@sugarboxnetworks.com) wrote:

> Ok, I think I get a sense of who is doing what which results in the Large
> Message getting Split as per my understanding it's *LINE_MAX* value in the
> `journalctl` conf that causes the Large message to get split.
>
> The default value is 48K and compared to the size of the split message and
> it comes approx to 48K. Now that explains that I'm thinking *is there** a
> way to prepend any "IDENTIFIER"  for the message that was split* from the
> original message? so that we can reassemble/merge them at the central L
> *ogstash* server.
>
> I'm looking at the correct section of code,
> https://github.com/systemd/systemd/blob/main/src/journal/journald-stream.c#L498
> I
> don't think there exists anything like it. Still want to check if there is
> anything possible?

As mentioned you can use the _LINE_BREAK= field to reassemble the
lines. But seriously, if you are logging megabytes of data in single
log messages you are doing things wrong. Rivisit what you are doing
there, you are trying to hammer a square log message into a round log
transport. Bad idea.

Lennart

--
Lennart Poettering, Berlin

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Lennart Poettering]

On So, 21.05.23 15:32, Virendra Negi (virendra.n...@sugarboxnetworks.com) wrote:

> It's been over a week I have been chasing this
> https://github.com/rsyslog/rsyslog/issues/5137
>
> I was unsure how to ensure that the systemd (since I was getting nowhere
> with rsyslog)  split the message instead of the application program doing
> this.

How did you send the original message? via stdout/stderr? via syslog?
via journald's native protocol?

The syslog protocol is not really suitable for passing around massive
amounts of data. First of all, it is mostly commonly used
datagram-based transports, which means 64K (in case of AF_UNIX) or
~1.5K (in case of AF_INET/AF_INET6 on ethernet without fragmentation)
size limits.

systemd-journald does not split up messages it receives via the syslog
protocol, since clients send their messages via SOCK_DGRAM/AF_UNIX a
64K limit applies however. YOu have to subtract a bunch of bytes of
those, since the timestamp/identifier/pid will take away some of the
datagram however.

If you use the native journal protocol systemd-journald is actually
happy to take arbitrary sized data, since besides datagrams it also
accepts payload in memfds, which can be more or less unlimited in
size.

If the message comes via stdout/stderr systemd will break up lines for
four different reasons:

1. A newline byte was seen
2. A NUL byte was seen
3. The sending PID changed (i.e. two programs log interleaved to the
   same stdout/stderr stream)
4. EOF was seen on the stream
5. The maximum line limit was hit (as configured via journald.conf's
   LineMax=, which defaults to 48K)

Which of the 5 it is you can see from _LINE_BREAK= (which is
suppressed in case of regular newline, however).

Generally, I'd suggest that apps remain conservative with the log
message sizes they generate, for compat with classic syslogs. Sending
megabytes of data in a single log message is a pretty poor idea I am sure.

> StandardOutput=syslog
> StandardError=syslog
> SyslogIdentifier=sbagent
>
> And set the MaxMessageSize to 64K and what I saw was the 1.5MB long message
> that was truncating earlier went through this time without truncation and a
> split happened the way I wanted it to be.

So apparently your are logging via stdout/stderr. In that case
LineMax= as mentioned above will help you. Still though: bad idea to
send a 1.5 MB line that way.

Lennart

--
Lennart Poettering, Berlin

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Virendra Negi]

Ok, I think I get a sense of who is doing what which results in the Large
Message getting Split as per my understanding it's *LINE_MAX* value in the
`journalctl` conf that causes the Large message to get split.

The default value is 48K and compared to the size of the split message and
it comes approx to 48K. Now that explains that I'm thinking *is there** a
way to prepend any "IDENTIFIER"  for the message that was split* from the
original message? so that we can reassemble/merge them at the central L
*ogstash* server.

I'm looking at the correct section of code,
https://github.com/systemd/systemd/blob/main/src/journal/journald-stream.c#L498
I
don't think there exists anything like it. Still want to check if there is
anything possible?

Thanks






On Mon, May 22, 2023 at 4:44 AM Virendra Negi <
virendra.n...@sugarboxnetworks.com> wrote:

> > Syslog was never really intended for large size messages. It is not
> Windows event log.
> > If you are sending large complex things then using dbus to communicate
> directly
> > is a better option.
>
>
> Now I'm bit prepexled uptil now I was under the impression that the large
> message is getting split as a result of systemd, I still believe that is
> the case but apparently the rsyslog team had told me that they dont support
> splitting.
>
> I just want to know how?
>
> On Sunday, May 21, 2023, Michael Biebl  wrote:
>
>> Am So., 21. Mai 2023 um 18:26 Uhr schrieb Stephen Hemminger
>> :
>> > Syslog was never really intended for large size messages. It is not
>> Windows event log.
>> > If you are sending large complex things then using dbus to communicate
>> directly
>> > is a better option.
>>
>> dbus is not a suitable protocol for large amounts of data  and high
>> frequency of events.
>>
>

-- 

   
  





-- 
**Disclaimer*: This e-mail and any documents, files, or previous e-mail 
messages appended or attached to it may contain confidential and/or 
privileged information. If you are not the intended recipient (or have 
received this email in error) please notify the sender immediately and 
delete this e-mail. Any unauthorized copying, disclosure or distribution of 
the material in this email is strictly prohibited & unlawful. The recipient 
acknowledges that Margo Networks Private Limited (SugarBox) may be unable 
to exercise control or ensure or guarantee the integrity of the text of the 
email message and the text is not warranted as to completeness and 
accuracy. Before opening and accessing the attachment, if any, please check 
and scan for virus*

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Virendra Negi]

> Syslog was never really intended for large size messages. It is not
Windows event log.
> If you are sending large complex things then using dbus to communicate
directly
> is a better option.


Now I'm bit prepexled uptil now I was under the impression that the large
message is getting split as a result of systemd, I still believe that is
the case but apparently the rsyslog team had told me that they dont support
splitting.

I just want to know how?

On Sunday, May 21, 2023, Michael Biebl  wrote:

> Am So., 21. Mai 2023 um 18:26 Uhr schrieb Stephen Hemminger
> :
> > Syslog was never really intended for large size messages. It is not
> Windows event log.
> > If you are sending large complex things then using dbus to communicate
> directly
> > is a better option.
>
> dbus is not a suitable protocol for large amounts of data  and high
> frequency of events.
>

-- 

   
  





-- 
**Disclaimer*: This e-mail and any documents, files, or previous e-mail 
messages appended or attached to it may contain confidential and/or 
privileged information. If you are not the intended recipient (or have 
received this email in error) please notify the sender immediately and 
delete this e-mail. Any unauthorized copying, disclosure or distribution of 
the material in this email is strictly prohibited & unlawful. The recipient 
acknowledges that Margo Networks Private Limited (SugarBox) may be unable 
to exercise control or ensure or guarantee the integrity of the text of the 
email message and the text is not warranted as to completeness and 
accuracy. Before opening and accessing the attachment, if any, please check 
and scan for virus*

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Michael Biebl]

Am So., 21. Mai 2023 um 18:26 Uhr schrieb Stephen Hemminger
:
> Syslog was never really intended for large size messages. It is not Windows 
> event log.
> If you are sending large complex things then using dbus to communicate 
> directly
> is a better option.

dbus is not a suitable protocol for large amounts of data  and high
frequency of events.

Re: [systemd-devel] Splitting large message written to stdout, explanation?

[Stephen Hemminger]

On Sun, 21 May 2023 15:32:14 +0530
Virendra Negi  wrote:

> It's been over a week I have been chasing this
> https://github.com/rsyslog/rsyslog/issues/5137
> 
> I was unsure how to ensure that the systemd (since I was getting nowhere
> with rsyslog)  split the message instead of the application program doing
> this.
> 
> Apparently, today I just removed the following section from the `
> *target.service*` file
> 
> StandardOutput=syslog
> StandardError=syslog
> SyslogIdentifier=sbagent
> 
> And set the MaxMessageSize to 64K and what I saw was the 1.5MB long message
> that was truncating earlier went through this time without truncation and a
> split happened the way I wanted it to be.
> 
> I'm unsure what caused it hence for the sake of understanding it. I'm
> writing this. Can someone put some light on it as to why this happened now
> and not earlier.
> 
> Thanks


Syslog was never really intended for large size messages. It is not Windows 
event log.
If you are sending large complex things then using dbus to communicate directly
is a better option.

[systemd-devel] Splitting large message written to stdout, explanation?

[Virendra Negi]

It's been over a week I have been chasing this
https://github.com/rsyslog/rsyslog/issues/5137

I was unsure how to ensure that the systemd (since I was getting nowhere
with rsyslog)  split the message instead of the application program doing
this.

Apparently, today I just removed the following section from the `
*target.service*` file

StandardOutput=syslog
StandardError=syslog
SyslogIdentifier=sbagent

And set the MaxMessageSize to 64K and what I saw was the 1.5MB long message
that was truncating earlier went through this time without truncation and a
split happened the way I wanted it to be.

I'm unsure what caused it hence for the sake of understanding it. I'm
writing this. Can someone put some light on it as to why this happened now
and not earlier.

Thanks

-- 

   
  





-- 
**Disclaimer*: This e-mail and any documents, files, or previous e-mail 
messages appended or attached to it may contain confidential and/or 
privileged information. If you are not the intended recipient (or have 
received this email in error) please notify the sender immediately and 
delete this e-mail. Any unauthorized copying, disclosure or distribution of 
the material in this email is strictly prohibited & unlawful. The recipient 
acknowledges that Margo Networks Private Limited (SugarBox) may be unable 
to exercise control or ensure or guarantee the integrity of the text of the 
email message and the text is not warranted as to completeness and 
accuracy. Before opening and accessing the attachment, if any, please check 
and scan for virus*