Description Philipp Hahn 2023-08-02 18:59:07 CEST

Created attachment 11101 [details]
Parse timestamps and show time changes

Time jumps forward and backward multiple times during system setup.

Some consecutive lines from /var/log/univention/config-registry.replog:
2023-08-02 13:16:37 -> 2023-08-02 15:16:39
        2023-08-02 13:16:37: set locale/default=de_DE.UTF-8:UTF-8 old:[Previously undefined]
        2023-08-02 15:16:39: set interfaces/ens7/type=dhcp old:[Previously undefined]
2023-08-02 15:31:34 -> 2023-08-02 16:35:19
        2023-08-02 15:31:34: set nameserver1=10.207.245.210 old:10.207.0.2
        2023-08-02 16:35:19: set nameserver1=10.207.245.210 old:10.207.245.210
2023-08-02 16:41:09 <- 2023-08-02 15:41:10
        2023-08-02 16:41:09: set interfaces/ens7/broadcast=10.207.255.255 old:10.207.255.255
        2023-08-02 15:41:10: unset 'interfaces/restart/auto' old:false
2023-08-02 15:46:18 -> 2023-08-02 16:46:20
        2023-08-02 15:46:18: set umc/saml/trusted/sp/master.admember.local=master.admember.local old:[Previously undefined]
        2023-08-02 16:46:20: set timeserver=10.207.245.210 old:[Previously undefined]
2023-08-02 16:46:28 <- 2023-08-02 15:46:47
        2023-08-02 16:46:28: set samba/generate_smbpasswd=false old:[Previously undefined]
        2023-08-02 15:46:47: set samba/autostart=no old:[Previously undefined]
2023-08-02 15:48:10 -> 2023-08-02 16:48:15
        2023-08-02 15:48:10: set ucs/server/saml-idp-server/master.admember.local=master.admember.local old:master.admember.local
        2023-08-02 16:48:15: set ucs/server/saml-idp-server/master.admember.local=master.admember.local old:master.admember.local
2023-08-02 16:49:21 <- 2023-08-02 16:06:10
        2023-08-02 16:49:21: set nssldap/timelimit=30 old:30
        2023-08-02 16:06:10: unset 'system/setup/boot/pages/blacklist' old:locale welcome network

Same for /var/log/dpkg-log:
2023-08-02 13:16:36 -> 2023-08-02 15:16:39
        2023-08-02 13:16:36 status installed univention-config:all 14.0.0-18A~4.4.0.202007200731
        2023-08-02 15:16:39 startup archives unpack
2023-08-02 15:21:40 -> 2023-08-02 16:36:18
        2023-08-02 15:21:40 status installed univention-config:all 14.0.0-18A~4.4.0.202007200731
        2023-08-02 16:36:18 startup archives unpack
2023-08-02 16:40:24 <- 2023-08-02 15:41:24
        2023-08-02 16:40:24 startup packages configure
        2023-08-02 15:41:24 startup archives unpack
2023-08-02 15:41:32 -> 2023-08-02 16:46:26
        2023-08-02 15:41:32 status installed systemd:amd64 232-25+deb9u15A~4.4.9.202210182015
        2023-08-02 16:46:26 startup archives unpack
2023-08-02 16:46:28 <- 2023-08-02 15:46:30
        2023-08-02 16:46:28 status half-configured univention-config:all 14.0.0-18A~4.4.0.202007200731
        2023-08-02 15:46:30 status installed univention-config:all 14.0.0-18A~4.4.0.202007200731
2023-08-02 15:47:01 -> 2023-08-02 16:48:19
        2023-08-02 15:47:01 status installed univention-config:all 14.0.0-18A~4.4.0.202007200731
        2023-08-02 16:48:19 startup archives unpack
2023-08-02 16:49:25 <- 2023-08-02 16:11:37
        2023-08-02 16:49:25 status config-files univention-system-setup-boot:all 12.0.2-29A~4.4.0.202011172052
        2023-08-02 16:11:37 startup archives unpack

Most processes read /etc/localtime only once — most likely early during startup — so any change to it will not affect any running process;
`ucr` is invoked often enough as a new process, so it shows a changed timezone early.
`dpkg` is a long(er) running process, so only the next batch will show the changes TZ.

Many other log files use other formats which complicates merging them and sorting by timestamp.

All tools in UCS should use a consistent format when printing timestamps, e.g. `YYYY-mm-dd HH-MM-SS` followed by `Z` for timestamps in UTC or the numeric timezone offset.

date +%Y-%m-%d\ %H:%M:%S[.%N]%z
TZ=UTC date +%Y-%m-%d\ %H:%M:%S[.%N]Z