Discussion:
Bug#672361: bootlogd: escape sequences should be filtered out
(too old to reply)
Vincent Lefevre
2012-05-10 11:30:02 UTC
Permalink
Package: bootlogd
Version: 2.88dsf-22.1
Severity: wishlist

/var/log/boot contains escape sequences, which make it difficult to
read, e.g.

Thu May 3 14:35:20 2012: [....] Setting parameters of disc: (none)^[[?25l^[[?1c^[7^[[1G[^[[32m ok ^[[39;49m^[8^[[?25h^[[?0c.

They should be filtered out (or interpreted to make "ok"/"warn"/...
appear at the right place).

-- System Information:
Debian Release: wheezy/sid
APT prefers unstable
APT policy: (500, 'unstable'), (500, 'testing'), (500, 'stable'), (1, 'experimental')
Architecture: amd64 (x86_64)

Kernel: Linux 3.2.0-2-amd64 (SMP w/8 CPU cores)
Locale: LANG=POSIX, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages bootlogd depends on:
ii libc6 2.13-32
ii lsb-base 4.1+Debian3

bootlogd recommends no packages.

bootlogd suggests no packages.

-- no debconf information
--
To UNSUBSCRIBE, email to debian-bugs-dist-***@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact ***@lists.debian.org
Jesse Smith
2019-08-08 22:40:01 UTC
Permalink
control: tags -1 +upstream
[2019-08-07 05:13] Adam Borowski
[...]
a /var/log/boot.log file is
generated where nothing is filtered out, so that the file is readable
with "cat" or "less" (and text is colored).
I don't think files in /var/log/ should be anything but plain text -- at
least unless colorized-logs becomes essential :ß and/or less defaults to
-R. But until a solution is implemented, I agree that leaving binaryish
control codes intact is better than corrupting them.
Jesse, there seems to be demand on turning-off escape sequence filtering
in bootlogd. Can you please make it configurable?
It is pretty easy to make an option for printing the escape sequences to
the log file. This will allow tools like "less" to print the boot log
with its colour codes.

I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines. This is partly because escape characters include
positional instructions like '\r' for carriage-return.

In other words, if we make the boot log completely unfiltered, lines in
"less" will display properly, but using "cat", "head" or "tail" will
result in mangled lines that look like this:

Thu Aug 8 19:06:30 2019:
[ ok ug 8 19:06:30 2019: [... starting ]


I'm not sure we want to do that. Perhaps the ideal would be a small
degree of filtering to remove the positional control characters (like
'\r') while leaving the rest in to allow for colour to be displayed?

- Jesse
Vincent Lefevre
2019-08-09 07:50:01 UTC
Permalink
Post by Jesse Smith
I'm not sure we want to do that. Perhaps the ideal would be a small
degree of filtering to remove the positional control characters (like
'\r') while leaving the rest in to allow for colour to be displayed?
I think so. Filter \r out, which is proved to be wrong (a date
is added at the beginning of the line). Concerning the escape
sequences, either leave them as they are (just like for
/var/log/boot.log under systemd) or remove them entirely with
ansi2txt from the colorized-logs package.
--
Vincent Lefèvre <***@vinc17.net> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)
Dmitry Bogatov
2019-08-11 17:50:01 UTC
Permalink
part 2 text/plain 1753
control: tags -1 +upstream
[2019-08-07 05:13] Adam Borowski
[...]
a /var/log/boot.log file is
generated where nothing is filtered out, so that the file is readable
with "cat" or "less" (and text is colored).
I don't think files in /var/log/ should be anything but plain text -- at
least unless colorized-logs becomes essential :ß and/or less defaults to
-R. But until a solution is implemented, I agree that leaving binaryish
control codes intact is better than corrupting them.
Jesse, there seems to be demand on turning-off escape sequence filtering
in bootlogd. Can you please make it configurable?
It is pretty easy to make an option for printing the escape sequences to
the log file. This will allow tools like "less" to print the boot log
with its colour codes.
I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines. This is partly because escape characters include
positional instructions like '\r' for carriage-return.
In other words, if we make the boot log completely unfiltered, lines in
"less" will display properly, but using "cat", "head" or "tail" will
[ ok ug 8 19:06:30 2019: [... starting ]
I'm not sure we want to do that. Perhaps the ideal would be a small
degree of filtering to remove the positional control characters (like
'\r') while leaving the rest in to allow for colour to be displayed?
- Jesse
Dmitry Bogatov
2019-08-11 17:50:01 UTC
Permalink
part 2 text/plain 1753
control: tags -1 +upstream
[2019-08-07 05:13] Adam Borowski
[...]
a /var/log/boot.log file is
generated where nothing is filtered out, so that the file is readable
with "cat" or "less" (and text is colored).
I don't think files in /var/log/ should be anything but plain text -- at
least unless colorized-logs becomes essential :ß and/or less defaults to
-R. But until a solution is implemented, I agree that leaving binaryish
control codes intact is better than corrupting them.
Jesse, there seems to be demand on turning-off escape sequence filtering
in bootlogd. Can you please make it configurable?
It is pretty easy to make an option for printing the escape sequences to
the log file. This will allow tools like "less" to print the boot log
with its colour codes.
I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines. This is partly because escape characters include
positional instructions like '\r' for carriage-return.
In other words, if we make the boot log completely unfiltered, lines in
"less" will display properly, but using "cat", "head" or "tail" will
[ ok ug 8 19:06:30 2019: [... starting ]
I'm not sure we want to do that. Perhaps the ideal would be a small
degree of filtering to remove the positional control characters (like
'\r') while leaving the rest in to allow for colour to be displayed?
- Jesse
Dmitry Bogatov
2019-08-11 17:50:01 UTC
Permalink
Post by Jesse Smith
control: tags -1 +upstream
[2019-08-07 05:13] Adam Borowski
[...]
a /var/log/boot.log file is
generated where nothing is filtered out, so that the file is readable
with "cat" or "less" (and text is colored).
I don't think files in /var/log/ should be anything but plain text -- at
least unless colorized-logs becomes essential :þ and/or less defaults to
-R. But until a solution is implemented, I agree that leaving binaryish
control codes intact is better than corrupting them.
Jesse, there seems to be demand on turning-off escape sequence filtering
in bootlogd. Can you please make it configurable?
It is pretty easy to make an option for printing the escape sequences to
the log file. This will allow tools like "less" to print the boot log
with its colour codes.
I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines.
No. When you output raw escape sequences on terminal, they will be
interpreted by terminal, so `head', `tail' and `grep' output will be
readable and colored. Pager `less' with -R option also interpret escape
symbols.

Obliviously, editors like `vi' or `emacs' do not interpret sequences,
so logs in editor will not look pretty.

All above does not apply to dumb terminals, but who uses them?
Post by Jesse Smith
This is partly because escape characters include
positional instructions like '\r' for carriage-return.
In other words, if we make the boot log completely unfiltered, lines in
"less" will display properly, but using "cat", "head" or "tail" will
[ ok ug 8 19:06:30 2019: [... starting ]
Looks like your terminal interpret '\r' incorrectly. What does following
command print on your terminal?

$ bash -c "printf 'foo\rbar'"
Post by Jesse Smith
I'm not sure we want to do that. Perhaps the ideal would be a small
degree of filtering to remove the positional control characters (like
'\r') while leaving the rest in to allow for colour to be displayed?
Please, don't. Issue with '\r' can be resolved by removal of '\r' in
`bin:lsb-base'.

With filtering as implemented now `/var/boot/log' looks bad both in editor
and terminal. Example:

Fri Feb 22 18:42:36 2019: [....] Not activating swap on logical volume. ...??7[warn8?? (warning).
Fri Feb 20 18:42:36 2019: [....] Starting early crypto disks...sda3_crypt (running)...??7[ ok 8??done.
--
Note, that I send and fetch email in batch, once in a few days.
Please, mention in body of your reply when you add or remove recepients.
Jesse Smith
2019-08-11 21:10:01 UTC
Permalink
Post by Dmitry Bogatov
Please, don't. Issue with '\r' can be resolved by removal of '\r' in
`bin:lsb-base'.
Okay, I'll do an option for completely unfiltered and other tools and be
adjusted to match.
Post by Dmitry Bogatov
With filtering as implemented now `/var/boot/log' looks bad both in editor
Fri Feb 22 18:42:36 2019: [....] Not activating swap on logical volume. ...??7[warn8?? (warning).
Fri Feb 20 18:42:36 2019: [....] Starting early crypto disks...sda3_crypt (running)...??7[ ok 8??done.
For situations like this where you already have a log with escape
characters in it, you can fix the output by using the readbootlog
program, which is part of the sysvinit suite. It cleans out most of the
control characters so the log looks like a normal, plain-text file.
Vincent Lefevre
2019-08-12 07:30:01 UTC
Permalink
Post by Jesse Smith
For situations like this where you already have a log with escape
characters in it, you can fix the output by using the readbootlog
program, which is part of the sysvinit suite. It cleans out most of the
control characters so the log looks like a normal, plain-text file.
It does not seem to be in Debian (not installed by default, not found
by "apt-file search readbootlog").
--
Vincent Lefèvre <***@vinc17.net> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)
Jesse Smith
2019-08-12 14:20:02 UTC
Permalink
Post by Vincent Lefevre
Post by Jesse Smith
For situations like this where you already have a log with escape
characters in it, you can fix the output by using the readbootlog
program, which is part of the sysvinit suite. It cleans out most of the
control characters so the log looks like a normal, plain-text file.
It does not seem to be in Debian (not installed by default, not found
by "apt-file search readbootlog").
Which version of sysvinit do you have installed? You'd need a version
from around 2.90 or newer.
Post by Vincent Lefevre
Post by Jesse Smith
There might be problems with some implementations of these utilities
due to binary data, but AFAIK, coreutils implementation is fine with
escape sequences.
They are not. As I mentioned above, I tested this.
Post by Vincent Lefevre
Post by Jesse Smith
If this is correct with "less", then there should be no issues with a
decent implementation of "cat", "head" and "tail".
Sadly, that is not the case.
Vincent Lefevre
2019-08-12 15:10:03 UTC
Permalink
Post by Jesse Smith
Post by Vincent Lefevre
Post by Jesse Smith
For situations like this where you already have a log with escape
characters in it, you can fix the output by using the readbootlog
program, which is part of the sysvinit suite. It cleans out most of the
control characters so the log looks like a normal, plain-text file.
It does not seem to be in Debian (not installed by default, not found
by "apt-file search readbootlog").
Which version of sysvinit do you have installed? You'd need a version
from around 2.90 or newer.
sysvinit-core 2.95-4
Post by Jesse Smith
Post by Vincent Lefevre
Post by Jesse Smith
There might be problems with some implementations of these utilities
due to binary data, but AFAIK, coreutils implementation is fine with
escape sequences.
They are not. As I mentioned above, I tested this.
This is a problem with your machine. I also tested (with the coreutils
versions) and I don't have any problem on mine.
--
Vincent Lefèvre <***@vinc17.net> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)
Dmitry Bogatov
2019-08-12 19:40:02 UTC
Permalink
control: tags -1 +fixed-upstream
Post by Jesse Smith
Post by Dmitry Bogatov
Please, don't. Issue with '\r' can be resolved by removal of '\r' in
`bin:lsb-base'.
Okay, I'll do an option for completely unfiltered and other tools and be
adjusted to match.
Thank you very much.
Post by Jesse Smith
Post by Dmitry Bogatov
With filtering as implemented now `/var/boot/log' looks bad both in editor
Fri Feb 22 18:42:36 2019: [....] Not activating swap on logical volume. ...??7[warn8?? (warning).
Fri Feb 20 18:42:36 2019: [....] Starting early crypto disks...sda3_crypt (running)...??7[ ok 8??done.
For situations like this where you already have a log with escape
characters in it, you can fix the output by using the readbootlog
program, which is part of the sysvinit suite. It cleans out most of the
control characters so the log looks like a normal, plain-text file.
Fragment above does not contain escape sequences. Those question marks
are literal (0x3f) ASCII question marks.

I do now know what and when converted ASCII escape symbols into question
marks.
--
Note, that I send and fetch email in batch, once in a few days.
Please, mention in body of your reply when you add or remove recepients.
Dmitry Bogatov
2019-08-11 17:50:02 UTC
Permalink
part 2 text/plain 1753
control: tags -1 +upstream
[2019-08-07 05:13] Adam Borowski
[...]
a /var/log/boot.log file is
generated where nothing is filtered out, so that the file is readable
with "cat" or "less" (and text is colored).
I don't think files in /var/log/ should be anything but plain text -- at
least unless colorized-logs becomes essential :ß and/or less defaults to
-R. But until a solution is implemented, I agree that leaving binaryish
control codes intact is better than corrupting them.
Jesse, there seems to be demand on turning-off escape sequence filtering
in bootlogd. Can you please make it configurable?
It is pretty easy to make an option for printing the escape sequences to
the log file. This will allow tools like "less" to print the boot log
with its colour codes.
I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines. This is partly because escape characters include
positional instructions like '\r' for carriage-return.
In other words, if we make the boot log completely unfiltered, lines in
"less" will display properly, but using "cat", "head" or "tail" will
[ ok ug 8 19:06:30 2019: [... starting ]
I'm not sure we want to do that. Perhaps the ideal would be a small
degree of filtering to remove the positional control characters (like
'\r') while leaving the rest in to allow for colour to be displayed?
- Jesse
Jesse Smith
2019-08-11 21:20:01 UTC
Permalink
Post by Dmitry Bogatov
Post by Jesse Smith
I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines.
No. When you output raw escape sequences on terminal, they will be
interpreted by terminal, so `head', `tail' and `grep' output will be
readable and colored. Pager `less' with -R option also interpret escape
symbols.

I wasn't speaking theoretically. I tried it and the "head", "cat" and
"tail" commands mangle the lines of the log file when escape sequences
are not escaped. Output from "less" is clean though and looks correct.
Post by Dmitry Bogatov
Looks like your terminal interpret '\r' incorrectly.
What makes you think that? The lines look exactly as I would expect them
to look.
Post by Dmitry Bogatov
What does following command print on your terminal?
  $ bash -c "printf 'foo\rbar'"
It prints "bar", just as it should.
Vincent Lefevre
2019-08-12 07:40:01 UTC
Permalink
Post by Jesse Smith
I wasn't speaking theoretically. I tried it and the "head", "cat" and
"tail" commands mangle the lines of the log file when escape sequences
are not escaped.
There might be problems with some implementations of these utilities
due to binary data, but AFAIK, coreutils implementation is fine with
escape sequences.
Post by Jesse Smith
Output from "less" is clean though and looks correct.
If this is correct with "less", then there should be no issues with a
decent implementation of "cat", "head" and "tail".
--
Vincent Lefèvre <***@vinc17.net> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)
Dmitry Bogatov
2019-08-12 19:40:02 UTC
Permalink
Post by Dmitry Bogatov
Post by Dmitry Bogatov
Post by Jesse Smith
I'd like to point out though that with such an option enabled, it is
going to result in some weird output. If all escape sequences are
printed to the file, tools like "less" can handle it, but other (more
raw) text manipulation tools such as "head" and "tail" will end up
mangling the lines.
No. When you output raw escape sequences on terminal, they will be
interpreted by terminal, so `head', `tail' and `grep' output will be
readable and colored. Pager `less' with -R option also interpret escape
symbols.
I wasn't speaking theoretically.
No offence intended. Sorry if I sounded harsh.
Post by Dmitry Bogatov
I tried it and the "head", "cat" and "tail" commands mangle the lines
of the log file when escape sequences are not escaped. Output from
"less" is clean though and looks correct.
Interesting. Can you please send text that shows this behaviour?
Post by Dmitry Bogatov
Post by Dmitry Bogatov
Looks like your terminal interpret '\r' incorrectly.
What makes you think that? The lines look exactly as I would expect them
to look.
I encountered terminal emulator that do so. Can't recall the name right
now, unfortunately.
--
Note, that I send and fetch email in batch, once in a few days.
Please, mention in body of your reply when you add or remove recepients.
Jesse Smith
2019-08-12 20:50:02 UTC
Permalink
Post by Dmitry Bogatov
Post by Dmitry Bogatov
Post by Dmitry Bogatov
No. When you output raw escape sequences on terminal, they will be
interpreted by terminal, so `head', `tail' and `grep' output will be
readable and colored. Pager `less' with -R option also interpret escape
symbols.
I wasn't speaking theoretically.
No offence intended. Sorry if I sounded harsh.
No offence taken. I can understand why you'd expect the output to look
normal.
Post by Dmitry Bogatov
Post by Dmitry Bogatov
I tried it and the "head", "cat" and "tail" commands mangle the lines
of the log file when escape sequences are not escaped. Output from
"less" is clean though and looks correct.
Interesting. Can you please send text that shows this behaviour?
Certainly. Attached is a file with the last 20 lines of the
/var/boot/log file on a test machine. When I view the log with "less"
the output looks normal. When I run the file through "head" "tail" or
"cat" the "[ ok" part of the message line appears at the beginning of
the text. This happens in both the text console and in a virtual
terminal window.

This output was achieved by turning off escape character filtering in
bootlogd. The contents of the file are just written out raw, as the data
comes into bootlogd.

- Jesse
Vincent Lefevre
2019-08-13 06:40:01 UTC
Permalink
Post by Jesse Smith
Post by Dmitry Bogatov
Post by Dmitry Bogatov
I tried it and the "head", "cat" and "tail" commands mangle the lines
of the log file when escape sequences are not escaped. Output from
"less" is clean though and looks correct.
Interesting. Can you please send text that shows this behaviour?
Certainly. Attached is a file with the last 20 lines of the
/var/boot/log file on a test machine. When I view the log with "less"
the output looks normal.
With "less", it is *not* correct.
Post by Jesse Smith
When I run the file through "head" "tail" or "cat" the "[ ok" part
of the message line appears at the beginning of the text.
just because text has been corrupted by bootlogd. That was *not* text
that was sent the console as documented in the bootlogd(8) man page.

FYI, with /var/log/boot.log under systemd, there is no such an issue.
--
Vincent Lefèvre <***@vinc17.net> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)
Thorsten Glaser
2019-08-13 14:40:02 UTC
Permalink
Post by Vincent Lefevre
Post by Jesse Smith
When I run the file through "head" "tail" or "cat" the "[ ok" part
of the message line appears at the beginning of the text.
=20
just because text has been corrupted by bootlogd. That was *not* text
that was sent the console as documented in the bootlogd(8) man page.
If you write FANCYTTY=3D0 to /etc/lsb-base-logging.sh things look as
expected. Otherwise, the control sequences *are* text written to the
console (just not directly by you, but by LSB stuff on your behalf).

I=E2=80=99m against introducing any kind of filtering here (what if the
problematic output is in those sequences, or the developer of the
LSB logging stuff wants to debug their stuff?), and would advice
that, instead, when bootlogd is enabled, it (automatically) sets
FANCYTTY=3D0 (maybe overridable, for the logging developer), or that
users are adviced, e.g. in a README, to set it.

bye,
//mirabilos
--=20
tarent solutions GmbH
Rochusstra=C3=9Fe 2-4, D-53123 Bonn =E2=80=A2 http://www.tarent.de/
Tel: +49 228 54881-393 =E2=80=A2 Fax: +49 228 54881-235
HRB 5168 (AG Bonn) =E2=80=A2 USt-ID (VAT): DE122264941
Gesch=C3=A4ftsf=C3=BChrer: Dr. Stefan Barth, Kai Ebenrett, Boris Esser, Ale=
xander Steeg

**********

Mit der tarent Academy bieten wir auch Trainings und Schulungen in den
Bereichen Softwareentwicklung, Agiles Arbeiten und Zukunftstechnologien an.

Besuchen Sie uns auf www.tarent.de/academy. Wir freuen uns auf Ihren Kontak=
t.

**********
Dmitry Bogatov
2019-08-13 17:10:02 UTC
Permalink
Post by Jesse Smith
Post by Dmitry Bogatov
Post by Dmitry Bogatov
I tried it and the "head", "cat" and "tail" commands mangle the lines
of the log file when escape sequences are not escaped. Output from
"less" is clean though and looks correct.
Interesting. Can you please send text that shows this behaviour?
Certainly. Attached is a file with the last 20 lines of the
/var/boot/log file on a test machine. When I view the log with "less"
the output looks normal. When I run the file through "head" "tail" or
"cat" the "[ ok" part of the message line appears at the beginning of
the text. This happens in both the text console and in a virtual
terminal window.
Ah, everything is clear now. Log file contains following escape
sequence:

<ESC> [ 1 G

It moves cursor to first column of terminal, so text after displaces
text (timestamp) at beginning of line.

On other hand, `less -R' do not interpret cursor movement sequences
(quote from less(1)):

For the purpose of keeping track of screen appearance, ANSI
color escape sequences are assumed to not move the cursor.

If you use `less -r', output will be same as with `head', but I expect
`less' get confused on scrolling.

Cursor movement control sequences are okay for presentation, but are
very fragile to be stored and manipulated in any way.

I already filed bug to src:lsb to avoid control sequences more complex
than coloring.
--
Note, that I send and fetch email in batch, once in a few days.
Please, mention in body of your reply when you add or remove recepients.
Jesse Smith
2019-08-13 19:00:01 UTC
Permalink
Post by Dmitry Bogatov
Post by Jesse Smith
Certainly. Attached is a file with the last 20 lines of the
/var/boot/log file on a test machine. When I view the log with "less"
the output looks normal. When I run the file through "head" "tail" or
"cat" the "[ ok" part of the message line appears at the beginning of
the text. This happens in both the text console and in a virtual
terminal window.
Ah, everything is clear now. Log file contains following escape
<ESC> [ 1 G
It moves cursor to first column of terminal, so text after displaces
text (timestamp) at beginning of line.
I came to a similar conclusion. I found I could edit the character
sequences in vim and pick which ones to keep or erase. As you pointed
out, editing or filtering some sequences makes for fragile formatting.
We could remove just those sequences in bootlogd, but I think the better
solution is (as you wrote) to fix the formatting in the program sending
us the log messages.

Loading...