Mailinglist Archive: opensuse (1352 mails)

< Previous Next >
Re: [opensuse] Re: Black display on media server
On 2018-06-19 07:50, L A Walsh wrote:
Carlos E. R. wrote:
So those are probably milliseconds since X started. It is impossible to
correlate "1337508.841" to the date/time stamp in other logs. In that
case it means 1337, less than one hour since start X, so not relevant at
all then.
---
times in kernel are usually given in seconds, like
[xxxx.yyyy]

I can't see why 'X' would be different.

Seconds counting from where? The epoch? Boot?

The 3 first lines of the log are:

[ 432.065]
X.Org X Server 1.18.3
Release Date: 2016-04-04

So, does the log start 432 seconds after the epoch? Impossible.
Seconds since start of X? Also impossible.
432 seconds, ie, 7.2 minutes after boot? Doubtful. X starts automatically.
Boots stops to ask for the disk password, assume two minutes top to enter the
password, and half a minute more to type the login password. Still, 4 more
minutes to account for...

So it has to be milliseconds since the start of X. When did it start?
The log continues:

[ 432.065] X Protocol Version 11, Revision 0
[ 432.065] Build Operating System: openSUSE SUSE LINUX
[ 432.065] Current Operating System: Linux Isengard 4.4.132-53-default #1
SMP Wed May 23 06:57:07 UTC 2018 (036cd2f) x86_64
[ 432.065] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-4.4.132-53-default
root=UUID=0d457df1-b43d-4587-aa5a-6c919bcbedb8 ro showopts
resume=/dev/disk/by-label/Swap splash=verbose
[ 432.065] Build Date: 14 March 2018 10:01:54PM
[ 432.065]
[ 432.066] Current version of pixman: 0.34.0
[ 432.066] Before reporting problems, check http://wiki.x.org
to make sure that you have the latest version.
[ 432.066] Markers: (--) probed, (**) from config file, (==) default setting,
(++) from command line, (!!) notice, (II) informational,
(WW) warning, (EE) error, (NI) not implemented, (??) unknown.
[ 432.066] (==) Log file: "/var/log/Xorg.0.log", Time: Sat Jun 2 12:54:19
2018


Well, this may be it. 432.066 is Sat Jun 2 12:54:19 2018

Ok, the line of interest are:

[1337273.371] (II) AIGLX: Suspending AIGLX clients for VT switch
[1337508.841] (II) AIGLX: Resuming AIGLX clients after VT switch
[1337508.841] (II) intel(0): switch to mode 1920x1080@60.0 on HDMI3 using pipe
2, position (0, 0), rotation normal, reflection none

Let's do some math using LO calc.

How do I add seconds to a day date? I think it is =A3/(1000*60*60*24) where A5
is the cell containing the timestamp.

The formulas are then (csv format):

432,066;"=A1/1000/60";02/06/2018 12:54;"=C1"
;;;
1337273,371;"=A3/(1000*60*60*24)";"=C$1+B3-B$1";
1337508,841;"=A4/(1000*60*60*24)";"=C$1+B4-B$1";
1337508,841;"=A5/(1000*60*60*24)";"=C$1+B5-B$1";

(the second column are days)

And the results are:

432,066 0,0072011 02/06/2018 12:54 43253,5377199074

1337273,371 0,015477701053241 02/06/2018 13:06
1337508,841 0,015480426400463 02/06/2018 13:06
1337508,841 0,015480426400463 02/06/2018 13:06 (day/month/year)

So those timestamps corresponds to the third column and are of no interest for
whatever happened to my display, not in the day of interest.



Now, if the timestamps were really seconds since *boot*, the results are
different and plausible:

432,066 0,005000763888889 02/06/18 12:54

1337273,371 15,4777010532407 18/06/18 00:14
1337508,841 15,480426400463 18/06/18 00:18
1337508,841 15,480426400463 18/06/18 00:18

These are the messages log entries corresponding to those times:


<10.6> 2018-06-18T00:05:03.661874+02:00 Isengard CRON 14995 - -
pam_unix(crond:session): session closed for user root
<10.6> 2018-06-18T00:10:01.673904+02:00 Isengard cron 15116 - -
pam_unix(crond:session): session opened for user root by (uid=0)
<3.6> 2018-06-18T00:10:01.720686+02:00 Isengard systemd 1 - - Started Session
7486 of user root.
<10.6> 2018-06-18T00:10:03.957215+02:00 Isengard CRON 15116 - -
pam_unix(crond:session): session closed for user root
<10.6> 2018-06-18T00:15:01.970598+02:00 Isengard cron 15253 - -
pam_unix(crond:session): session opened for user root by (uid=0)
<10.6> 2018-06-18T00:15:01.975040+02:00 Isengard cron 15251 - -
pam_unix(crond:session): session opened for user root by (uid=0)
<10.6> 2018-06-18T00:15:01.975715+02:00 Isengard cron 15252 - -
pam_unix(crond:session): session opened for user root by (uid=0)
<3.6> 2018-06-18T00:15:02.036825+02:00 Isengard systemd 1 - - Started Session
7489 of user root.
<3.6> 2018-06-18T00:15:02.042528+02:00 Isengard systemd 1 - - Started Session
7488 of user root.
<3.6> 2018-06-18T00:15:02.052475+02:00 Isengard systemd 1 - - Started Session
7487 of user root.
<10.6> 2018-06-18T00:15:02.185681+02:00 Isengard CRON 15251 - -
pam_unix(crond:session): session closed for user root
<1.5> 2018-06-18T00:15:02.383306+02:00 Isengard Sistema - - - Logging the
current external IP= 83....
<10.6> 2018-06-18T00:15:02.388517+02:00 Isengard CRON 15252 - -
pam_unix(crond:session): session closed for user root
<10.6> 2018-06-18T00:15:04.313946+02:00 Isengard CRON 15253 - -
pam_unix(crond:session): session closed for user root
<3.6> 2018-06-18T00:18:45.295279+02:00 Isengard systemd 1 - - Received
SIGWINCH.
<3.3> 2018-06-18T00:18:45.300274+02:00 Isengard systemd 1 - - Failed to
enqueue kbrequest.target job: Unit kbrequest.target failed to load: No such
file or directory.
<10.6> 2018-06-18T00:20:01.325297+02:00 Isengard cron 15451 - -
pam_unix(crond:session): session opened for user root by (uid=0)
<3.6> 2018-06-18T00:20:01.348723+02:00 Isengard systemd 1 - - Started Session
7490 of user root.
<10.6> 2018-06-18T00:20:03.620759+02:00 Isengard CRON 15451 - -
pam_unix(crond:session): session closed for user root
<3.6> 2018-06-18T00:24:13.747671+02:00 Isengard smartd 1185 - - Device:
/dev/sda [SAT], SMART Usage Attribute: 189 Airflow_Temperature_Cel changed from
52 to 56
<3.6> 2018-06-18T00:24:13.749185+02:00 Isengard smartd 1185 - - Device:
/dev/sda [SAT], SMART Usage Attribute: 194 Temperature_Celsius changed from 52
to 56


The only doubt there is the signal "Received SIGWINCH". It is not listed in
"man signal.h"

It appears here:
cer@Telcontar:~> grep SIGWINCH /usr/src/linux-4.4.136-56/include/linux/signal.h
* | SIGWINCH | ignore |
rt_sigmask(SIGWINCH) | rt_sigmask(SIGURG) )
cer@Telcontar:~>

No explanation.

Wikipedia has one:

SIGWINCH
The SIGWINCH signal is sent to a process when its controlling terminal
changes its size (a window change).


Oh, well. But systemd getting that? It doesn't have a terminal. Go figure.

Googling "systemd 1 - - Received SIGWINCH" says it is related to apache.


So, nothing related to current problem, I think.


What about "Isengard systemd 1 - - Failed to enqueue kbrequest.target job:
Unit kbrequest.target failed to load: No such file or directory."?

Isengard:~ # locate kbrequest.target
Isengard:~ #

There are some hits on google for "Failed to enqueue kbrequest.target job" but
nothing that leaps to my eye.
And anyway, it is the sole such entry in the messages file since January.


--
Cheers / Saludos,

Carlos E. R.
(from 42.3 x86_64 "Malachite" at Telcontar)

< Previous Next >
Follow Ups