openssh bugs - Feb 2024 - [Bug 3662] New: Make logging of chrooted sftp sessions possible internally routed to local file, without /dev/log device

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

            Bug ID: 3662
           Summary: Make logging of chrooted sftp sessions possible
                    internally routed to local file, without /dev/log
                    device
           Product: Portable OpenSSH
           Version: 9.6p1
          Hardware: amd64
                OS: Linux
            Status: NEW
          Severity: enhancement
          Priority: P5
         Component: sftp-server
          Assignee: unassigned-bugs at mindrot.org
          Reporter: daku8938 at gmx.de

Problem:

Abstract:
If you have two or more sftp-servers and the sftp user's home directory
is on one nfs share (exported by a third party NFS server), you have to
make a local bind mount over each chrooted user's /dev/log file to be
able to log the sftp sessions on all sftp servers.
If you have now 1000 or more users and therefore 1000 or more local
bind units, the system becomes slow because it does not scale.
(see e.g. https://github.com/systemd/systemd/issues/31137)

So it would be great if the sftp session log of a user session could be
routed internally directly e.g. to a local file "/var/log/sftp/%u.log"

Here the problem and the current ugly and non-scaling inperformant
workaround. You can see it also here:
https://unix.stackexchange.com/questions/666641/howto-log-multiple-sftpd-servers-activity-which-users-chrooted-home-is-on-shar

I have an Ubuntu server with sftpd running where /var/data/chroot/ is
an NFS mount from a remote central NFS server, and each sftpd user's
chroot home is /var/data/chroot/<username>/ and every user has a log
device /var/data/chroot/<username>/dev/log which I read in successfully
with syslog-ng:

source s_chroot_<username>    {
unix-stream("/var/data/chroot/<username>/dev/log" optional(yes)
); };
destination d_sftp_<username> {
file("/var/log/sftp/<username>.log");
};

Now I have a second sftpd server in parallel, with the same user
database and also mounts /var/data/chroot/ via NFS, and has the same
syslog-ng config, so every user can login on the one server or on the
other. This is for high availability. This works so far.

What is not working now is the sftpd logging: The sftp user's log is
only available on one sftp server exclusively, and that is the one
where syslog-ng was started least, because as I understand it takes the
exclusive unix socket file lock for each user's /dev/log.

So, if a user logs in on the first server, where syslog-ng was started
least, the user's sftp activity is logged on the first server. But if
the user logs in on the second server, it's sftp activity is not
logged, neither on the second nor on the first server.

If the syslog-ng is then restarted on the second server, the sftp
user's activity is exclusively logged only on the second server and
only for logins on the second server.

My ugly workaround for this is the following:

Create a local directory under which user subdirectories are created:
sudo mkdir /var/data/dev For very username <username> and the user's
primary group <groupname> do the following:

sudo mkdir             /var/data/dev/<username>
sudo chmod 550         /var/data/dev/<username>       # This
restrictive permission is a requirement I think
sudo chgrp <groupname> /var/data/dev/<username>       # so the user
can
read the directory
So the new directory is exactly the same as the existing
/var/data/chroot/<username>/dev directory (which is on the nfs mount
/var/data/chroot/).

Then do mount --bind /var/data/dev/<username>
/var/data/chroot/<username>/dev so /var/data/chroot/<username>/dev
is
now effectively local on the sftp server, not anymore on nfs mount.

Then change the syslog-ng config

from

source s_chroot_<username> {
unix-stream("/var/data/chroot/<username>/dev/log" optional(yes)
); };

to

source s_chroot_<username> {
unix-stream("/var/data/dev/<username>/log"
optional(yes) ); };

(this is not strictly needed, but I think it's nice having syslog-ng
definitely now only reading from local file, guaranteed not from nfs
mount anymore)

Whether the user logs in on the one sftp server or the other, syslog-ng
can now log the sftp session on the affected sftp server.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |djm at mindrot.org

--- Comment #1 from Damien Miller <djm at mindrot.org> ---
Does "Subsystem sftp internal-sftp" not do what you want?

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #2 from Miranda <daku8938 at gmx.de> ---
(In reply to Damien Miller from comment #1)
> Does "Subsystem sftp internal-sftp" not do what you want?
We use "Subsystem sftp internal-sftp". So that does not solve the
described problem of the exclusive lock of the <NFS mounted chroot
home>/dev/log socket.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #3 from Damien Miller <djm at mindrot.org> ---
you shouldn't need a /dev/log socket with internal-sftp, it logs via
the privileged monitor sshd process that runs without chroot

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #4 from Miranda <daku8938 at gmx.de> ---
(In reply to Damien Miller from comment #3)
> you shouldn't need a /dev/log socket with internal-sftp, it logs via
> the privileged monitor sshd process that runs without chroot
"Logging with the built-in sftp-subsystem inside a chroot jail, defined
by ChrootDirectory, needs a ./dev/log node to exist inside the jail."
(source:
https://en.wikibooks.org/wiki/OpenSSH/Logging_and_Troubleshooting#Logging_Chrooted_SFTP)

(we have set "ChrootDirectory %h" and every users has it's own
home
dir)

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #5 from Damien Miller <djm at mindrot.org> ---
Have you actually tried using internal-sftp without /dev/log?

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #6 from Miranda <daku8938 at gmx.de> ---
(In reply to Damien Miller from comment #3)
> you shouldn't need a /dev/log socket with internal-sftp, it logs via
> the privileged monitor sshd process that runs without chroot
Right, it seems like if sftp-server does not find the /dev/log in the
user's chroot jail (that is /var/data/chroot/<username>/dev/log
absolute path in my case), the sftp server (monitor) writes to global
/dev/log device (so absolute path ist /dev/log).

With that, yes, there would not be any NFS concurrent lock problem
anymore. We would have alle the log messages of all users together in
one local system's /dev/log device and could read it with syslog-ng via
the sftp-specific log facility set with e.g. "ForceCommand
internal-sftp -f LOCAL5".

But for each of our 1400 sftp customers we need to have a reliable
dedicated sftp log, for our support to be able to look for one specific
customer's sftp activity, therefore we would need to parse the global
log to filter each user's log lines and write those to a user specific
log file. The problem is, I think it is not trivial to make this
parsing reliable and robust, since we need to parse the process id
(sftp session), check which username that session belongs to and write
that log lines to the username specific log file. Of course, process
IDs are reused for different sessions, we have overlapping sessions of
the same user in the same time etc. A challenge would also be e.g. if
the user never logs out, and the log file rotates daily, so after one
day, the parser could not find any "session opened for local user xxx"
log lines anymore. And we need the user's log to be 100% reliable for
high service and support quality.

For that reason, I really would like to stay with each user having a
specific dedicated log device at the first point, because that is
simple, scaling and fast (real time result, no parser process in
between needed) and 100% guaranteed reliable and robust.

My suggestion for a solution:
-----------------------------
Give the /usr/lib/sftp-server program a new parameter

-L <custom log device name that is searched for underneath /dev>

For example one could set

"ForceCommand internal-sftp -L log1"

and then the sftp-server would look for a /dev/log1 in the user's
chroot jail and if it exists, write the user's log to that device.

In my case on the second sftp sftp server I would set
"ForceCommand internal-sftp -L log2"

Then of course the syslog-ng on the first sftp server would need to
listen to /dev/log1 and on the second server syslog-ng would need to
listen on /dev/log2 of every user). So, with that, this issue would be
solved.

Maybe, if sftp-server would not find the configured custom log file
(e.g. /dev/log1) in a user's chroot jail, it could try to log to
system's /dev/log file (so, absolute path /dev/log), so that would be
the old behavior. No strong opinion in that, though.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

Miranda <daku8938 at gmx.de> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|Make logging of chrooted    |Enhance sftp-server with a
                   |sftp sessions possible      |parameter to customize the
                   |internally routed to local  |name of the log device
                   |file, without /dev/log      |(currently fix /dev/log)
                   |device                      |

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #7 from Damien Miller <djm at mindrot.org> ---
unfortunately libc provides no way for a program to select a different
log socket without rewriting the entirety of the syslog() function: 

https://linux.die.net/man/3/openlog

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

Miranda <daku8938 at gmx.de> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|Enhance sftp-server with a  |Provide chrooted sftp users
                   |parameter to customize the  |dedicated session log
                   |name of the log device      |without /dev/log unix
                   |(currently fix /dev/log)    |socket in users chroot jail
                   |                            |(that does not work when
                   |                            |chroot jail is shared
                   |                            |between multiple sftp
                   |                            |servers e.g. via NFS)

--- Comment #8 from Miranda <daku8938 at gmx.de> ---
@Damien Very sad that the fix /dev/log name is burried so deep in the
code.

An alternative minimal-invasive solution would be to to allow to follow
symlink if /dev/log in user's chroot jail is a symlink to a local file.

Give the /usr/lib/sftp-server program a new parameter

-L <0=do not allow to follow /dev/log if it's a symlink out of jail
(default) | 1=follow if /dev/log is a symlink out of jail>

(so, this would be the same concept as now with the bind mount, only to
be a symlink, so the performance and scaling problem would be solved)

In my case that would be the symlink:

/var/data/chroot/<username>/dev/log -> /var/data/dev/<username>


Best way I could imagine would be to provide /usr/lib/sftp-server
program a new parameter

-L <user log file wit %u being username macro>

e.g. so one could set

"ForceCommand internal-sftp -L /var/log/sftp/%u.log"

I can understand that it is not easy for you to change something here,
but please also understand that we need a solution. It seems like we
are a really rare user that operates OpenSSH SFTP as a HA cluster
having the user's chroot shared via NFS, and therefore the user logging
with exclusive lock on /dev/log in chroot does not work. Otherwise this
isse must have been reportet already long time ago.

Any solution welcome, if we could only have one. Thanks

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

Miranda <daku8938 at gmx.de> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Priority|P5                          |P3
           Severity|enhancement                 |normal

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #9 from Damien Miller <djm at mindrot.org> ---
Whether /dev/log can be a symlink is also up to the libc
implementation. Nothing in OpenSSH limits the use of a symlink for
/dev/log, but similarly we can't control whether the system will accept
a symlink without rewriting syslog(3)

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #10 from Miranda <daku8938 at gmx.de> ---
(In reply to Damien Miller from comment #9)
> Whether /dev/log can be a symlink is also up to the libc
> implementation. Nothing in OpenSSH limits the use of a symlink for
> /dev/log, but similarly we can't control whether the system will
> accept a symlink without rewriting syslog(3)
On modern Linux hosts with systemd (e.g. Ubuntu Server 18.04 and later)
the system's /dev/log (the real absolute OS filesystem path) is a
symlink to systemd's journal:
/dev/log -> /run/systemd/journal/dev-log

so at least that symlink is accepted. Not sure what that means for what
you write about libc. But I tested with a symlink of chroot jail's
/dev/log to a destiantion out of the chroot jail, but I could not get
any log messages with syslog-ng from the symlink's destination. Would
be great if that could be made work. Of course the sftp client would
need to be forbidden to create that symlink itself, as otherwise that
would be a possibility to access files out of chroot jail.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

--- Comment #11 from Miranda <daku8938 at gmx.de> ---
(In reply to Damien Miller from comment #3)
> you shouldn't need a /dev/log socket with internal-sftp, it logs via
> the privileged monitor sshd process that runs without chroot
It would be a solution for the chroot log device problem, to use the
log from the privileged monitor sshd process that you mention here, but
only if each sftp user's session log line has a unique identifiable log
line prefix.

My suggestion for a solution:
Change the current log prefix

" internal-sftp[<PID>]: "

to

" internal-sftp[<PID>][<username>]: "

E.g. change
" internal-sftp[12345]: "
to
" internal-sftp[12345][myusername]: "

E.g. here an example of a session with file upload:

Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: session opened
for local user myuser from [10.7.2.100]
Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: open
"/file.txt"
flags WRITE,CREATE,TRUNCATE mode 0644
Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: close
"/file.txt" bytes read 0 written 44
Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: session closed
for local user myuser from [10.7.2.100]

With that it would be possible to reliably filter out the session log
lines for each sftp user.

Please check and comment if this could be a solution for you.

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

jason.nader at protonmail.com changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |jason.nader at protonmail.com

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3662

Geert van de Kamp <ghvdkamp at gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |ghvdkamp at gmail.com

--- Comment #12 from Geert van de Kamp <ghvdkamp at gmail.com> ---
(In reply to Miranda from comment #11)
> (In reply to Damien Miller from comment #3)
> > you shouldn't need a /dev/log socket with internal-sftp, it logs
via
> > the privileged monitor sshd process that runs without chroot
> 
> It would be a solution for the chroot log device problem, to use the
> log from the privileged monitor sshd process that you mention here,
> but only if each sftp user's session log line has a unique
> identifiable log line prefix.
> 
> My suggestion for a solution:
> Change the current log prefix
> 
> " internal-sftp[<PID>]: "
> 
> to
> 
> " internal-sftp[<PID>][<username>]: "
> 
> E.g. change
> " internal-sftp[12345]: "
> to
> " internal-sftp[12345][myusername]: "
> 
> E.g. here an example of a session with file upload:
> 
> Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: session
> opened for local user myuser from [10.7.2.100]
> Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: open
> "/file.txt" flags WRITE,CREATE,TRUNCATE mode 0644
> Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: close
> "/file.txt" bytes read 0 written 44
> Feb 13 14:37:30 10.1.2.3 internal-sftp[16066][myuser]: session
> closed for local user myuser from [10.7.2.100]
> 
> With that it would be possible to reliably filter out the session
> log lines for each sftp user.
> 
> Please check and comment if this could be a solution for you.
I experience this exact issue and after Googling a bit, I bumped into
this thread. For me, the workaround that Miranda has implemented,
should be workable. I have to deal with about 20 accounts, so very much
doable.

I was just wondering, is it possible to let the internal-sftp add a
syslog tag?

Something like:

ForceCommand internal-sftp -l INFO -t "my-tag"

The tag could then be picked up by syslog-ng or rsyslog (in my case)

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.