The officially official Devuan Forum!

Altoid

Member

Registered: 2017-05-07

Posts: 1,581  

Log file reading issues

Hello:

I seem to have an issue with some of the log files in /var/log.

The affected files are: syslog, messages, kern.log, slim.log and sudo.log.
On a previous oportunity, slim.log was not affected.

My usual way of looking at logfiles is on the terminal with cat ot tail, but every so often I will want to look at them with a text editor such as Pluma or Leafpad.

The problem at hand is that Pluma will not open them and show a popup with an error.
With Leafpad I could open them and see them up to a point.

ie:
While I could see the whole contents of the file in terminal, Leafpad would only show me the part up to where whatever error happened.

This is the error I get in Pluma:

---

Could not open the file /var/log/slim.log.
pluma has not been able to detect the character encoding.
Please check that you are not trying to open a binary file.
Select a character encoding from the menu and try again.

---

The available encoding options are:

    Automatically Detected
    Unicode (UTF-8)
    Current Locale (ANSI_X3.4-1968)
    Western ISO-8859-15

The same problem occurs with any of the options.

With Leafpad I could open the log files and see them up to a  a certain point/line ie: the moment in time where whatever error happened.
From then on, nothing was recorded on the file and the only way to see the entire content was via the terminal.

Pluma will not open a *.txt file created via cat on the terminal either but LibreOffice Writer will open it.

groucho@devuan:~$ cat /var/log/syslog > syslog.txt

I can browse through the whole file.
The only strange thing I found when I opened it with Writer was this ...

---

Mar  4 15:42:40 devuan kernel: [  570.124482] sysrq: SysRq : Emergency Sync
Mar  4 15:42:40 devuan kernel: [  570.155699] Emergency Sync complete
Mar  4 15:42:46 devuan kernel: [  576.133524] sysrq: SysRq : Emergency Remount R/O
Mar  4 15:42:46 devuan kernel: [  576.219397] EXT4-fs (sdb1): re-mounted. Opts: (null)
#######################################################################################Mar  4 15:45:07 devuan liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="1977" x-info="http://www.rsyslog.com"] start
Mar  4 15:45:07 devuan kernel: [    0.000000] Linux version 4.9.0-8-amd64 (debian-kernel@lists.debian.org) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1) ) #1 SMP Debian 4.9.144-3.1 (2019-02-19)

---

... which on the terminal is seen in this manner:

Mar  4 15:42:40 devuan kernel: [  570.124482] sysrq: SysRq : Emergency Sync
Mar  4 15:42:40 devuan kernel: [  570.155699] Emergency Sync complete
Mar  4 15:42:46 devuan kernel: [  576.133524] sysrq: SysRq : Emergency Remount R/O
Mar  4 15:42:46 devuan kernel: [  576.219397] EXT4-fs (sdb1): re-mounted. Opts: (null)
Mar  4 15:45:07 devuan liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="1977" x-info="http://www.rsyslog.com"] start
Mar  4 15:45:07 devuan kernel: [    0.000000] Linux version 4.9.0-8-amd64 (debian-kernel@lists.debian.org) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1) ) #1 SMP Debian 4.9.144-3.1 (2019-02-19)

Seems the difference is the string of ###.
This string was the point up to which Leafpad would show the file's content, something Pluma won't do.

It would seem that the system is writing something to the log files that for some reason a text editor cannot read and (Leafpad at least) probably cannot save, which is why it stops showing anything from that point on.

Any idea as to what the system could be writing?

Thanks in advance.

A.

dxrobertson

Member

Registered: 2017-05-04

Posts: 232  

Re: Log file reading issues

This can be caused by ascii "non-text" codes being in the text log file. Often times a text terminating x00 null byte.  Leafpad is very susceptible to this. If you install a hex editor such as hexedit, you can open the log file in it and view exactly the base ascii codes and thus whats causing the problem.

Could it be that the #### stuff is at (prior to) a reboot?  Did your system halt ungracefully prior to a reboot?  This can cause non-text ascii codes to be written to the log file.

If you did not have a system abend around this time, then something else has caused problems; there should not be non-text ascii in the log files.

Last edited by dxrobertson (2019-03-07 00:12:56)

Altoid

Member

Registered: 2017-05-07

Posts: 1,581  

Re: Log file reading issues

Hello:

... caused by ascii "non-text" codes being in the text log file.
...  text terminating x00 null byte.

I see ...

Leafpad is very susceptible to this.

Pluma even more so, as it does not show me anything and then complains when I attempt to open the file.  =-)
On the other hand, Leafpad just refuses to show me the offending "non text".

I'm glad this is not a Leafpad issue as I like it better than Pluma, can't say why.

... install a hex editor such as hexedit ...
... view exactly the base ascii codes and thus whats causing the problem.

I installed GHex 3.18.3 and found that between this string:

Mar  4 15:42:46 devuan kernel: [  576.219397] EXT4-fs (sdb1): re-mounted. Opts: (null)

... and this string:

Mar  4 15:45:07 devuan liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="1977" x-info="http://www.rsyslog.com"] start

... there is a long string of .................. which for some reason the editor would not copy into the clipboard.

On the hexadecimal view pane, these .................. are represented as sets of zeroes sepatated by a space just like the rest of the hex strings.

ie: 0000 0000 0000 0000   

These strings are identified as hexadecimal 00, octal 000, binary 00000000.

...  the #### stuff is at (prior to) a reboot?

Yes.

Mar  4 15:42:40 devuan kernel: [  570.124482] sysrq: SysRq : Emergency Sync
Mar  4 15:42:40 devuan kernel: [  570.155699] Emergency Sync complete
Mar  4 15:42:46 devuan kernel: [  576.133524] sysrq: SysRq : Emergency Remount R/O
Mar  4 15:42:46 devuan kernel: [  576.219397] EXT4-fs (sdb1): re-mounted. Opts: (null)

... system halt ungracefully prior to a reboot?

Apparently so, I thought it would not happen because the script includes a previous disk sync and unmount/remount as RO.
Evidently I'm mistaken and yet another sync maybe needed after the u.

Some background to this:
At present I'm attempting to solve a shutdown issue I have with my Ultra 24 WS.

The issue is basically this:

---
On shutdown, the rig will do one of two things:

1. shut down properly
2. freeze during the shutdown at this point ...

e1000e: EEE Tx LPI Timer
Preparing to enter sleep state S5
Reboot: Power Down

... with the fans blowing at full speed.
---

This shutdown problem ocurrs in a totally unpredictable manner, I have not been able to reproduce it or been able to link it to anything in particular.

Unfortunately, unloading the e1000e driver module before shutdown (a well known issue) or inserting a variety of reboot= stanzas in the kernel command line have not worked, even when using reboot=force.

Eventually, it would happen again.

To try to see what was going on, I decided to try shutting down the rig using a script that would (hopefully) isolate each of the stages of the shut down process and give me some feedback, much like I did in my old MS-DOS days by running config.sys and autoexec.bat in steps to weed out start-up issues:

#!/bin/sh
# Shutdown system without the use of shutdownhelper 
#
PATH=/sbin:/bin:/usr/sbin:/usr/bin:
for i in s u o; do echo $i | sudo tee /proc/sysrq-trigger; sleep 2; done  # halt

I think that what we are seeing is the same shutdown problem which does not manifest itself in the same manner as when a normal shutdown command is issued.
This because of the o in the script directly powers off the system. ie: does not give it a chance to freeze and start blowing fans.

... then something else has caused problems; there should not be non-text ascii in the log files.

I'll try adding a second sync and see what happens.

In the meanwhile, do you know a better way to see what is going on during the shutdown process?

The unmount/mount RO and the sync in the script I cobbled up seem to go ahead without any issues.
It would seem that it's just the shutdown part that is acting up.

Thanks in advance,

A.

dxrobertson

Member

Registered: 2017-05-04

Posts: 232  

Re: Log file reading issues

On the hexadecimal view pane, these .................. are represented as sets of zeroes sepatated by a space just like the rest of the hex strings.

ie: 0000 0000 0000 0000   

These strings are identified as hexadecimal 00, octal 000, binary 00000000.

OK, thats exactly why the text editors are having trouble reading the log file.  x00 is whats called the string terminating character, it defines the end of a string of text.  Leafpad is doing its job; it encounters the x00 and stops displaying text.  Pluma appears to be too anal; seems to be scanning the file for invalid text before displaying anything. 

Another good text editor as well as very useful all around tool is mc.  It will display ALL of the text, including non-text, and its internal editor allows you to modify the non-text characters.  Very useful.

The x00 being in the log file was definitely caused by the ungraceful shutdown, this often happens.

Sorry, I cant help much with the actual hardware problem nor with more shutdown info.  A long shot, since it seems to be ethernet, did you try disabling wake on lan?

Altoid

Member

Registered: 2017-05-07

Posts: 1,581  

Re: Log file reading issues

Hello:

... exactly why the text editors are having trouble reading the log file.

I see ...

...  x00 is whats called the string terminating character, it defines the end of a string of text.

Sort of like the CR that's important to have in sudoers.d filers, else visudo.c will complain?

... it encounters the x00 and stops displaying text.

Seems a better (more reasonable) behaviour than Pluma. 

Another good text editor as well as very useful all around tool is mc.

Midnight Commander?
Memories of the trusty NC under DOS come to mind. =-)

Thanks for the heads-up, I'll give it a try - didn't know it was available for Linux .

There's quite a bit of text editors for Linux out there but I find that, if you're not a programmer (my case), they (as well as hex editors) tend to be a bit too much.

... x00 being in the log file was definitely caused by the ungraceful shutdown ...

Indeed ...

To try, I added a second s to the script to test.

#!/bin/sh
# Shutdown system without the use of shutdownhelper 
#
PATH=/sbin:/bin:/usr/sbin:/usr/bin:
for i in s u s o; do echo $i | sudo tee /proc/sysrq-trigger; sleep 2; done  # halt

The first time I tried it, I got the freeze+fans act for the first time using this script.
Obviously, right before/coincidentally with the shutdown ie: o:

s
u
sudo: unable to open log file: /var/log/sudo.log: read only file system
s
sudo: unable to open log file: /var/log/sudo.log: read only file system

... and the fan at full blast.

Sorry, I cant help much ...

It's all right, you have been very helpful.  =-)

... since it seems to be ethernet, did you try disabling wake on lan?

I used to think it was all ethernet (the problematic on board e1000e) related.
But no.

Once I managed to get WoL disabled, the reboot after shutdown was solved (it was part one of a two part shutdown problem).

WoL is disabled, gave me a hard time to get that done as there's no BIOS option for the in the Ultra 24 and the DOS utility Intel says you MUST use to disable WoL does not disable it permanently as ethtool can enable it again from within Linux, so I added a script to /etc/networks/interfaces to try to keep it disabled.

  post-up /sbin/ethtool -s eth0 wol d
  post-down /sbin/ethtool -s eth0 wol d

So why the MUST use the DOS utility if it does not disable WoL in the BIOS or the controller EEPROM? Go figure ...
In any case, Intel tech support for the e1000e was absolutely useless.

The thing is that with WoL and EEE=0 disabled the problem is still there.   8-/

Thank you very much for your help.

Best,

A.