Re: [gentoo-user] odd issue with RTKIT syslog-ng

[cal <cal@mail.meme.technology>]

On 11/17/20 7:33 AM, Jack wrote:
> 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 
>>>> have not found any reference to it searching the interwebs.
>>>>
>>>> The suspect package is sys-auth/rtkit-0/13-r1 (which has nothing to 
>>>> do with chkrootkit) and I'm using app-admin/syslog-ng-3.26.1-r1.
>>>>
>>>> As a typical example from /var/log/messages (extract, and having 
>>>> reconfigured syslog-ng to us iso timestamps)
>>>>
>>>> 2020-11-15T18:30:01-05:00 localhost CROND[7320]: (root) CMD 
>>>> (/usr/lib/sa/sa1 1 1)
>>>> 2020-11-15T23:34:10-05:00 localhost rtkit-daemon[6263]: Supervising 
>>>> 0 threads of 0 processes of 0 users.
>>>> 2020-11-15T23:36:38-05:00 localhost rtkit-daemon[6263]: Supervising 
>>>> 0 threads of 0 processes of 0 users.
>>>> 2020-11-15T18:40:01-05:00 localhost CROND[15943]: (root) CMD (test 
>>>> -x /usr/sbin/run-crons && /usr/sbin/run-crons)
>>>>
>>>> All rtkit messages to syslog seem to be in UTC, or at least five 
>>>> hours off from my local Americas/New York timezone.  rtkit uses the 
>>>> syslog() call for all logging, and there is nothing in those calls 
>>>> that even mentions timezone.
>>>>
>>>> However, in digging further, I found two log entries from rtkit 
>>>> which do appear to be using local time.  In looking at the rtkit 
>>>> source, those two use the LOG_INFO and LOG_NOTICE as their levels.  
>>>> All other logging in rtkit uses LOG_ERR, LOG_DEBUG, or LOG_WARNING, 
>>>> with one exception:  I see one LOG_INFO message (repeated, scattered 
>>>> across the log) which does show the UTC time.
>>>>
>>>> So, does anyone have an idea what is going on?
>>>>
>>>> I have one theory so far, but I a bit stuck on how to test it.  I'm 
>>>> not sure where in the boot process rtkit gets started, but I think 
>>>> it's automatically started when Dbus starts.  As part of the 
>>>> daemon's startup routine, it drops some privileges.  Is it possible 
>>>> that the applicable timezone gets changed when it drops privileges?  
>>>> As far as I can tell, the log messages with the correct time are all 
>>>> produced before it drops privs.  Am I barking up the right tree, or 
>>>> am I barking mad?
>>>
>>> I've done some more digging, with lots of debugging output.  Up to a 
>>> point, the process acknowledges the local timezone.  However, after 
>>> doing a 'chroot "/proc"' and then 'chdir "/"' it thinks it's UTC.  
>>> Still doesn't make any sense to me, though.
>>
>> glibc uses /etc/localtime to for timezone conversion.  Changing root 
>> to a new root directory that does not have this file (or has a 
>> different one in its place) will show a different local time conversion.
>>
>> Example program:
>> #include <stdio.h>
>> #include <time.h>
>> #include <unistd.h>
>>
>> int main()
>> {
>>     time_t now = time(NULL);
>>     printf("Time outside of chroot = %s", ctime(&now));
>>     chroot("/proc");
>>     printf("Time inside of chroot = %s", ctime(&now));
>>     return 0;
>> }
>>
>> Time outside of chroot = Mon Nov 16 17:58:19 2020
>> Time inside of chroot = Tue Nov 17 01:58:19 2020
> Thanks for the confirmation.  I finally also tracked it down to the same 
> thing.  In this particular case, once rtkit does the chroot, it gets the 
> same time, but without knowing the time zone, so assumes UTC.  When it 
> calls syslog, syslog-ng uses that UTC timestamp as is, but 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 
> doing the chroot, and then applying it again afterwards.

You may be able to get somewhere by setting the TZ environment variable 
to your desired timezone.

https://www.gnu.org/software/libc/manual/html_node/TZ-Variable.html

Cal