Logging in LTSP startup

[Rainer Stumbaum]

Hi,
during the upgrade of our complex LTSP environment I was constantly adding debugging echos in some file in the code:
- During /sbin/init-ltsp run
- During /usr/share/ltsp/screen_session run

Normally every service creates some logging into a file - some exhaustive like Xorg - some just that they started.

I am sure that most of new user errors/problems could be solved if there was an exhaustive log file like Xorgs log file - even more helpful with markers of the message (like Xorg.logs:
---
[ 16.374] Markers: (--) probed, (**) from config file, (==) default setting,
        (++) from command line, (!!) notice, (II) informational,
        (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
---

It would also be helpful for error analysis - users would have only to upload one file when having problems to ask others for help.

Please implement a /var/log/ltsp.log that is filled from all scripts related to ltsp.

Thanks
Rainer

[Rainer Stumbaum (stumbaumr)]

Hi,

here the first patch:

(debian7-i386-clnt)root@controlnode02:~# diff /sbin/init-ltsp /root/init-ltsp
1a2
> echo "LTSP: $0: Starting..." > /dev/kmsg
28a30
> echo "LTSP: $0: Sourcing $script" > /dev/kmsg
29a32
> echo "LTSP: $0: Sourcing $script finished" > /dev/kmsg
31c34
<
---
> echo "LTSP: $0: Sourcing scripts finished" > /dev/kmsg
38a42
> echo "LTSP: $0: Starting /sbin/init" > /dev/kmsg
(debian7-i386-clnt)root@controlnode02:~#

With this change we found out that we have to create an empty tftproot/lts.conf - since the boot was delayed for 10 seconds since the file did not exist...

Using grep LTSP /var/log/syslog we could see the runtime of each single script.

[Rainer Stumbaum (stumbaumr)]

Hi,

here the second patch:

(debian7-i386-clnt)root@controlnode02:~# diff /usr/share/ltsp/init-ltsp.d/50-swap /root/50-swap
5a6
> echo "LTSP: $0: Found local swap partition $part" > /dev/kmsg
57a59
> echo "LTSP: $0: Adding swap device $swap" > /dev/kmsg
(debian7-i386-clnt)root@controlnode02:~#

With this change we found out that we have to use "MODULES=most" in /etc/initramfs-tools/initramfs.conf to USE_LOCAL_SWAP - since with "MODULES=netboot" the harddisk driver is not available yet...

Looking through /var/log/syslog we were able to see that the driver for the disk was loaded later...

[Rainer Stumbaum (stumbaumr)]

Hi,

here the third patch:

(debian7-i386-clnt)root@controlnode02:~# diff /root/screen_session.orig /root/screen_session
75a76
> logger -i -p syslog.info -t LTSP "$0: Sourcing $script"
77a79
> logger -i -p syslog.info -t LTSP "$0: Running $script_path $args"
79a82
> logger -i -p syslog.info -t LTSP "$0: Sourcing $script"
(debian7-i386-clnt)root@controlnode02:~#

(debian7-i386-clnt)root@controlnode02:~# diff /root/XS90-assembleXorgConf.orig XS90-assembleXorgConf
8a9
> logger -i -p syslog.info -t LTSP "$0: Running ${CONFIGURE_X_COMMAND}"
11a13
> logger -i -p syslog.info -t LTSP "$0: Writing ${XCONF} ( using $screen_hacks $monitor_hacks $device_hacks $module_hacks $display_hacks)"
(debian7-i386-clnt)root@controlnode02:~#

With this change we found out that the XORG generated is named "/var/run/ltsp-xorg.conf" - completely obvious...

[Rainer Stumbaum (stumbaumr)]

Hi,

here the fourth patch:

(debian7-i386-clnt)root@controlnode02:~# diff kiosk.orig kiosk
54c54,55
< su - ${KIOSKUSER} -c "XINITRC_DAEMON=${XINITRC_DAEMON} KIOSK_WM=${KIOSK_WM} xinit $xinitrc /usr/share/ltsp/kioskSession ${KIOSK_EXE} ${KIOSK_OPTIONS} -- ${DISPLAY} vt${TTY} ${X_ARGS} -br" >/dev/null
---
> logger -i -p syslog.info -t LTSP "$0: Running su - ${KIOSKUSER} -c \"XINITRC_DAEMON=${XINITRC_DAEMON} KIOSK_WM=${KIOSK_WM} xinit $xinitrc /usr/share/ltsp/kioskSession ${KIOSK_EXE} ${KIOSK_OPTIONS} -- ${DISPLAY} vt${TTY} ${X_ARGS} -br\""
> su - ${KIOSKUSER} -c "XINITRC_DAEMON=${XINITRC_DAEMON} KIOSK_WM=${KIOSK_WM} xinit $xinitrc /usr/share/ltsp/kioskSession ${KIOSK_EXE} ${KIOSK_OPTIONS} -- ${DISPLAY} vt${TTY} ${X_ARGS} -br" 2>&1 | logger -i -p syslog.info -t LTSP
(debian7-i386-clnt)root@controlnode02:~#

With this change we got the following syslog output:
...
Apr 30 14:32:49 stat1 LTSP[853]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS00-halt-reboot
Apr 30 14:32:49 stat1 LTSP[854]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS00-setvars
Apr 30 14:32:49 stat1 LTSP[856]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS00-xorg-conf-functions
Apr 30 14:32:49 stat1 LTSP[857]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS10-xramperc
Apr 30 14:32:49 stat1 LTSP[858]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS20-intel-virtual-hack
Apr 30 14:32:49 stat1 LTSP[862]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS20-xserver-geode-gx2-hack
Apr 30 14:32:49 stat1 LTSP[866]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS20-xserver-ppc-r128-hack
Apr 30 14:32:49 stat1 LTSP[868]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS80-monitor-options
Apr 30 14:32:49 stat1 LTSP[872]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS80-sync-ranges
Apr 30 14:32:49 stat1 LTSP[873]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS80-x-modes
Apr 30 14:32:49 stat1 LTSP[874]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS85-virtual
Apr 30 14:32:49 stat1 LTSP[875]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS85-xmodule
Apr 30 14:32:49 stat1 LTSP[879]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS85-xserver
Apr 30 14:32:49 stat1 LTSP[880]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS85-xserver-device-options
Apr 30 14:32:49 stat1 LTSP[884]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS85-xvideoram
Apr 30 14:32:49 stat1 LTSP[885]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS90-assembleXorgConf
Apr 30 14:32:49 stat1 LTSP[886]: /usr/share/ltsp/screen_session: Writing /var/run/ltsp-xorg.conf ( using x_virtual)
Apr 30 14:32:49 stat1 LTSP[914]: /usr/share/ltsp/screen_session: Sourcing /usr/share/ltsp/screen-session.d/XS90-set-x-conf
Apr 30 14:32:49 stat1 LTSP[915]: /usr/share/ltsp/screen_session: So...

[Rainer Stumbaum (stumbaumr)]

Hi,

and with the fifth patch we got X_BLANKING = 0 to work again.

Attached the two patches...

[Vagrant Cascadian (vagrantc)]

On 2014-04-29 08:43:18 -0500, Rainer Stumbaum wrote:
> during the upgrade of our complex LTSP environment I was constantly
> adding debugging echos in some file in the code:
> - During /sbin/init-ltsp run
> - During /usr/share/ltsp/screen_session run
...
> Please implement a /var/log/ltsp.log that is filled from all scripts
> related to ltsp.

Thanks for your patches, apologies for the slow response...

So your patches mostly write to /dev/kmsg or log to syslog using
"logger"; do they work if there is no syslogging daemon running? Would
your rather they log to /var/log/ltsp.log than use syslogging
facilities?

I definitely see the value in more logging, although some cases (both
the start and the end of a particular phase) might be a bit
excessive. It would also be ideal if the logging could be
enabled/disabled by a commandline flag or something.

Could you refactor your patches against current ltsp, and submit as a
bzr branch for merging?

  https://code.launchpad.net/~ltsp-upstream/ltsp/ltsp-trunk

live well,
  vagrant

[Rainer Stumbaum (stumbaumr)]

Hi Vagrant,

just created a branch for this.

If there is no syslogging daemon then logger just exits with an error. If administrators do not use a syslog facility then they also do not care about logging so this should be fine then.

I removed the excessive parts in a second commit.

The whole point of logging is that the information is always available. If a user complains about a slow startup of a system I want to see the log - if I ask them to reboot for me to check they say we have to wait for the weekend. And then it probably just works...

What is the next step to incorporate these changes from my branch?

Thanks
Rainer

[Alkis Georgopoulos (alkisg)]

Closing old LTSP bugs as they're no longer relevant after LTSP has been rewritten from scratch.