Skip to content

Wrong timing in rsync daemon log #729

@mruprich

Description

@mruprich

When running rsync against a remote daemon, if the daemon is using chroot, time in the log file will be off. I used the following config for the daemon:

lock file          = /var/run/rsyncd-mirrors.lock
read only          = true
max connections    = 16
log file           = /var/log/rsyncd/rpms.log
transfer logging   = yes
timeout            = 900
ignore nonreadable = yes
dont compress      = *.gz *.tgz *.zip *.z *.Z *.rpm *.deb *.bz2
refuse options     = checksum
uid                = test
gid                = test
use chroot         = yes
hosts allow        = 10.45.224.124

[test]
      comment      = Just a testing repo
      path         = /home/test/rpms

I've put some files in /home/test/rpms. Then I run rsync from an allowed host:

$ rsync -av test@10.X.X.X::test rpms/
receiving incremental file list
./
...
...
sent 1,000 bytes  received 43,040,520 bytes  1,179,219.73 bytes/sec
total size is 43,025,373  speedup is 1.00

When I look at the log file at the daemon's side:

2025/01/31 08:16:34 [2235] rsyncd version 3.4.1 starting, listening on port 873
2025/01/31 08:16:50 [2239] name lookup failed for 10.X.X.X: Name or service not known
2025/01/31 08:16:50 [2239] connect from UNKNOWN (10.X.X.X)
2025/01/31 08:16:51 [2239] rsync allowed access on module test from UNKNOWN (10.X.X.X)
2025/01/31 13:16:51 [2239] rsync on test/ from UNKNOWN (10.X.X.X)
2025/01/31 13:16:52 [2239] building file list
2025/01/31 13:16:52 [2239] send UNKNOWN [10.X.X.X] test () finch-2.14.10-2.fc35.x86_64.rpm 143985
2025/01/31 13:16:54 [2239] send UNKNOWN [10.X.X.X] test () finch-debuginfo-2.14.10-2.fc35.x86_64.rpm 348677
...

The 08:16 is the actual correct time, the 13:16 is the time on the host. I've seen this before and it is an ancient bug actually (almost 20 years) - https://bugzilla.samba.org/show_bug.cgi?id=2607. I will open a PR with a fix. The key is to use glibc functions for getting the time that end with _r - for instance localtime_r() instead of localtime(). The reason is that localtime_r() does not call tzset function which fails after chroot.

All the credit for discovering the bug and for the fix goes to @remicollet

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions