From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from lists.gentoo.org (pigeon.gentoo.org [208.92.234.80]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by finch.gentoo.org (Postfix) with ESMTPS id 3BB4D138359 for ; Tue, 17 Nov 2020 15:33:27 +0000 (UTC) Received: from pigeon.gentoo.org (localhost [127.0.0.1]) by pigeon.gentoo.org (Postfix) with SMTP id E9161E09BB; Tue, 17 Nov 2020 15:33:21 +0000 (UTC) Received: from mail-qk1-f171.google.com (mail-qk1-f171.google.com [209.85.222.171]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by pigeon.gentoo.org (Postfix) with ESMTPS id A7C0FE0985 for ; Tue, 17 Nov 2020 15:33:21 +0000 (UTC) Received: by mail-qk1-f171.google.com with SMTP id q22so20721765qkq.6 for ; Tue, 17 Nov 2020 07:33:21 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:reply-to:subject:to:cc:mime-version :references:in-reply-to:message-id:content-disposition :content-transfer-encoding; bh=U+tm94ebQicEdljDzUvspQiuJbWl23qm3zo/Q//JHSY=; b=HqsQLQ2ELVYEkoqYbwOH3sxpebWjWgnsDY+souCH9PtRQwPKrgW6sVd/ttQtDIYC+R opD2PTOCVzfI0jLWoYTCKgC+IhKjjKb3Zhiy3Kbc5FwaJwWm6Fw735WxrXa3sGKorEVD lURzSiYBVft+5w4eU5oAj394mvWX6tL4OVWAh/ivx6/le966pNUqwDf5sXqv3pnGLOBU zynB2gdK7k7QOPw50VDqw4eonh8xv+4LU6EikFatS/M4DUVY+F4hMxiOfRFJ++ZrnjDX FcfUV024JzB/h7zNnuITiSYQ7AkIRBRKz3xrt7W+vYaVIwYoe1+Eeho//7rmuD6QsKre yBEg== X-Gm-Message-State: AOAM5312V7dPqtQwJeIJBjUlJp1LpAwaOuT3yjQAvHXLq3odJwlHOHTl lp5hLLRGwRYjFutvt9eeGI22dKX1VYZiew== X-Google-Smtp-Source: ABdhPJzManhbmP/F2vzj2BXPIqrJmpJ7q3EZ0jhsUngKp5bm2SeGa5S1kWpmjp0fp6is5Z8BRtThWA== X-Received: by 2002:a37:6892:: with SMTP id d140mr106819qkc.200.1605627200491; Tue, 17 Nov 2020 07:33:20 -0800 (PST) Received: from ffortso9 (c-76-23-130-96.hsd1.ct.comcast.net. [76.23.130.96]) by smtp.gmail.com with ESMTPSA id p72sm15046467qke.110.2020.11.17.07.33.19 for (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 17 Nov 2020 07:33:20 -0800 (PST) Date: Tue, 17 Nov 2020 10:33:18 -0500 From: Jack Subject: Re: [gentoo-user] odd issue with RTKIT syslog-ng To: gentoo-user@lists.gentoo.org Cc: Precedence: bulk List-Post: List-Help: List-Unsubscribe: List-Subscribe: List-Id: Gentoo Linux mail X-BeenThere: gentoo-user@lists.gentoo.org Reply-to: gentoo-user@lists.gentoo.org X-Auto-Response-Suppress: DR, RN, NRN, OOF, AutoReply MIME-Version: 1.0 References: <4JZI3GTM.5DK32STY.2GJR5DT7@4CJOC7Q6.CDYBV4NG.QGHV3UOT> In-Reply-To: X-Mailer: Balsa 2.6.1-108-g709771d0f Message-Id: Content-Type: text/plain; charset=ISO-8859-1; DelSp=Yes; Format=Flowed Content-Disposition: inline Content-Transfer-Encoding: quoted-printable X-Archives-Salt: 3d6c8f81-5441-4902-84f8-9fed433dae4f X-Archives-Hash: 356489627254a2d8d88e182cce40df81 On 2020.11.16 21:00, cal wrote: > On 11/16/20 4:22 PM, Jack wrote: >> On 2020.11.15 19:02, Jack wrote: >>> As usual, I've got what seems to be a really obscure problem, and I =20 >>> have not found any reference to it searching the interwebs. >>>=20 >>> The suspect package is sys-auth/rtkit-0/13-r1 (which has nothing to =20 >>> do with chkrootkit) and I'm using app-admin/syslog-ng-3.26.1-r1. >>>=20 >>> As a typical example from /var/log/messages (extract, and having =20 >>> reconfigured syslog-ng to us iso timestamps) >>>=20 >>> 2020-11-15T18:30:01-05:00 localhost CROND[7320]: (root) CMD =20 >>> (/usr/lib/sa/sa1 1 1) >>> 2020-11-15T23:34:10-05:00 localhost rtkit-daemon[6263]: Supervising =20 >>> 0 threads of 0 processes of 0 users. >>> 2020-11-15T23:36:38-05:00 localhost rtkit-daemon[6263]: Supervising =20 >>> 0 threads of 0 processes of 0 users. >>> 2020-11-15T18:40:01-05:00 localhost CROND[15943]: (root) CMD (test =20 >>> -x /usr/sbin/run-crons && /usr/sbin/run-crons) >>>=20 >>> All rtkit messages to syslog seem to be in UTC, or at least five =20 >>> hours off from my local Americas/New York timezone.=A0 rtkit uses the =20 >>> syslog() call for all logging, and there is nothing in those calls =20 >>> that even mentions timezone. >>>=20 >>> However, in digging further, I found two log entries from rtkit =20 >>> which do appear to be using local time.=A0 In looking at the rtkit =20 >>> source, those two use the LOG_INFO and LOG_NOTICE as their levels.=A0 =20 >>> All other logging in rtkit uses LOG_ERR, LOG_DEBUG, or LOG_WARNING, =20 >>> with one exception:=A0 I see one LOG_INFO message (repeated, =20 >>> scattered across the log) which does show the UTC time. >>>=20 >>> So, does anyone have an idea what is going on? >>>=20 >>> I have one theory so far, but I a bit stuck on how to test it.=A0 I'm =20 >>> not sure where in the boot process rtkit gets started, but I think =20 >>> it's automatically started when Dbus starts.=A0 As part of the =20 >>> daemon's startup routine, it drops some privileges.=A0 Is it possible =20 >>> that the applicable timezone gets changed when it drops =20 >>> privileges?=A0 As far as I can tell, the log messages with the =20 >>> correct time are all produced before it drops privs.=A0 Am I barking =20 >>> up the right tree, or am I barking mad? >>=20 >> I've done some more digging, with lots of debugging output.=A0 Up to a =20 >> point, the process acknowledges the local timezone.=A0 However, after =20 >> doing a 'chroot "/proc"' and then 'chdir "/"' it thinks it's UTC.=A0 =20 >> Still doesn't make any sense to me, though. >=20 > glibc uses /etc/localtime to for timezone conversion. Changing root =20 > to a new root directory that does not have this file (or has a =20 > different one in its place) will show a different local time =20 > conversion. >=20 > Example program: > #include > #include > #include >=20 > int main() > { > time_t now =3D time(NULL); > printf("Time outside of chroot =3D %s", ctime(&now)); > chroot("/proc"); > printf("Time inside of chroot =3D %s", ctime(&now)); > return 0; > } >=20 > Time outside of chroot =3D Mon Nov 16 17:58:19 2020 > Time inside of chroot =3D Tue Nov 17 01:58:19 2020 Thanks for the confirmation. I finally also tracked it down to the =20 same thing. In this particular case, once rtkit does the chroot, it =20 gets the same time, but without knowing the time zone, so assumes UTC. =20 When it calls syslog, syslog-ng uses that UTC timestamp as is, but =20 apparently doesn't know it is not in local time. I'm going to see if the program can capture the local time zone before =20 doing the chroot, and then applying it again afterwards.