AIX

AIX

Connect with fellow AIX users and experts to gain knowledge, share insights, and solve problems.


#Power
#Power
 View Only
Expand all | Collapse all

OpenSSH 9.9: oslevel invocation causes login delays

  • 1.  OpenSSH 9.9: oslevel invocation causes login delays

    Posted Thu October 30, 2025 01:50 PM

    Hello,

    on a busy SSH/SFTP server we encounter constantly login delays and ran now openssh in debug mode to find the reason. As the README says, openssh 9.9 comes compiled with auditing and EFS capabilities, but there is no possibility (shown) to turn these functions off, like the OS counterparts. So the first impression of the debug messages are lots of auditing events, even when auditing is shutdown. But the most shocking discovery, and probably the reason for the login delays, was that on every connection, before the kex exchange init,  in the very beginging of a ssh handshake, the openssh daemon runs the command oslevelWe first thought, this is ran by some auditing script/config, but no, oslevel is hard coded  in the sshd binary:

    strings /usr/sbin/sshd* | grep oslevel
    getoslevel                                                  
    oslevel : %s
    /usr/bin/oslevel
    getoslevel
    oslevel : %s
    /usr/bin/oslevel
    

    The second last line is also what appears in the log:

    Oct 30 17:45:53 sftp local6:debug sshd-session[57214588]: debug1: oslevel : 7.2.0.0\n\n

    And this is an example showing a delay of more than 10 seconds (3. and 4. line) for the oslevel command, before the ssh authentication goes further:

    Oct 30 14:09:11 sftp local6:debug sshd-session[34865828]: debug1: Remote protocol version 2.0, remote software version OpenSSH_9.9
    Oct 30 14:09:11 sftp local6:debug sshd-session[34865828]: debug1: compat_banner: match: OpenSSH_9.9 pat OpenSSH* compat 0x04000000
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: oslevel : 7.2.0.0\n\n
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: using libzNX from /opt/freeware/ssh/libzNX_s.a(libz.so.1) \n
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: init_libz_ptrs success
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: init_func_ptrs passed
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: value of krb5 is : 1
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: value of gssapi is : 1
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: permanently_set_uid: 202/201 [preauth]
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: SSH2_MSG_KEXINIT sent [preauth]
    Oct 30 14:09:25 sftp local6:debug sshd-session[34865828]: debug1: SSH2_MSG_KEXINIT received [preauth]
    

    We have about 400 to 600 connections per minute! So 400 to 600 times oslevel gets executed even before any user authentication takes place! 

    Since we have old debug logs with openssh 8, we see no oslevel there, but downgrading seems imposible for AIX, simply because there are no more old openssh packages officially available. 

    My first attempt for a workaround will be to replace the oslevel with something like:

    #!/bin/ksh -f
    if [[ -n "$1" ]] ; then
        exec /usr/bin/oslevel.orig "$@"
    else
        print 7.2.0.0
    fi

    Any ideas, besides compiling own sshd or switch to another OS?

    Best regards,

    P. Tanovski



    ------------------------------
    P T
    ------------------------------


  • 2.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Fri October 31, 2025 04:50 AM

    P T,

    Your post is very timely as I was beginning to consider moving up from 9.7.3013.1000 to 9.9.x.x HOWEVER I might take a rain check on that!!  Out of interest, did your analysis find anything @ 9.7, I'm presuming that, like v8, it was fine?

    Many thanks, Steve



    ------------------------------
    Steve Munday
    AIX, IBMi, HMC, CMC, PowerVM, PowerVS, Ansible automation engineering
    ------------------------------



  • 3.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Fri October 31, 2025 11:43 AM

    Can you please set 'enablehwcompression no' in /usr/sbin/sshd_config and restart ssh daemon (stopsrc -s sshd and startsrc -s sshd). This should solve your issue.



    ------------------------------
    Sandeep Umesh
    ------------------------------



  • 4.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Sat November 01, 2025 06:27 AM

    Hello,

    thanks, "EnableHWCompression no" stops the execution of oslevel. Our solution was though to overlay oslevel as shown in my first post. 

    Best regards,

    P. Tanovski



    ------------------------------
    P T
    ------------------------------



  • 5.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Mon November 03, 2025 11:02 AM

    I find it "interesting" (in the most annoying way possible), that oslevel caches the information needed for "oslevel -r", but not for "oslevel -s".

    On a random LPAR:
    After removing the cache: 5.86 seconds

    oslevel -r: 0.19 seconds
    oslevel -s: 1.80 seconds

    After the cache is rebuilt, none of the files is touched, but an oslevel invocation does touch the directory.



    ------------------------------
    José Pina Coelho
    IT Specialist at Kyndryl
    ------------------------------



  • 6.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Mon November 03, 2025 11:26 AM

    oslevel doc

    My testing:

    $time oslevel -r
    7300-03

    real    0m0.15s
    user    0m0.01s
    sys     0m0.01s

    $time oslevel -s
    7300-03-01-2520

    real    0m0.62s
    user    0m0.09s
    sys     0m0.07s

    $time oslevel -fs
    7300-03-01-2520

    real    0m2.65s
    user    0m0.33s
    sys     0m0.29s


    $time oslevel -fr
    7300-03

    real    0m2.07s
    user    0m0.25s
    sys     0m0.24s



    ------------------------------
    Alexander Pettitt
    ------------------------------



  • 7.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Mon November 03, 2025 04:36 PM

    Here is an another way of testing:

    • on the sftp server run an endless loop: 
      while  find /tmp/.oslevel.datafiles/ -name '*.lock'  -ls ; do : ; done
    • on another LPAR try parallel ssh logins: 
      for i in {1..30} ; do time ssh sftp oslevel  & done ;  2>&1  | grep real | tail

    What I see with out of the box AIX openssh: 

    1. Lots of locking on the server like (yes, even simple oslevel locks)
      4164    1 -rw-------  1 root      system           8 Nov  3 22:28 /tmp/.oslevel.datafiles/.oslevel.lock
    2. the times:
      real    0m2.85s
      real    0m3.64s
      real    0m3.70s
      real    0m3.73s
      real    0m3.81s
      real    0m3.84s
      real    0m3.85s
      real    0m4.68s
      real    0m4.79s
      real    0m4.85s
      

    With 60 parallel connections the delay increases to ca. 10 seconds.



    ------------------------------
    P T
    ------------------------------



  • 8.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Tue November 04, 2025 04:07 AM
    Edited by José Pina Coelho Tue November 04, 2025 04:23 AM

    Ok, this has turned the "bad" dial all the way to 11...

    On 7.3.3.1, just the main process "oslevel -r" forks 15 times, "oslevel -s" forks 23 times, then each process produces some output to be consumed by the original process...

    One of those forks does an execve("/usr/bin/oslevel",...), so it seems to me that the oslevel code is exec'ing itself to get information it shouldn't need to exec itself for...

    If like me you think sanity if overrated, you might feel tempted to "truss -af oslevel -r"...

    302 kfork()
    167 execve

    100 getuidx

    100 getgidx

    ...


    Now multiply the effect by thousands of connections from an Ansible Tower or similar...

    Just the noise of trusted execution logging and AIX syscall audit is enough justification for oslevel to be made SETUID and cache it's (complete) results.

    Edit: Of course it's a shell script... one that's in dire need of optimization (many calls to awk could be merged, uniq right after sort, grep|grep|awk) 



  • 9.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Tue November 04, 2025 07:34 AM

    If I had to propose sshd improvements, that would be:

    1.  Make EFS and Audit support optional through config switches. There is another bug we noticed on the current version: PrintLastLog switch has been (silently) removed! The last login information is always fetched/printed, on ssh and sftp connections! I suppose, it is audit related. 
    2. Let the parent sshd process determine the OS version once and pass it (trough environment) to the sessions.
    3. There are other ways to get the AIX version, for example the tunsave script uses whatkernel from rsct and then parses bos.<kernel type> package info.
    4. Run the HW/OS checking after the user authentification
    5. Make sftp logging works also when chrooted. Currently the logging breaks when sftp chroot.  At least this is documented:

              On some systems, sftp-server must be able to access /dev/log
              for logging to work, and use of sftp-server in a chroot
              configuration therefore requires that syslogd(8) establish a
              logging socket inside the chroot directory.

    Best regards,

    P. Tanovski



    ------------------------------
    P T
    ------------------------------



  • 10.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Tue November 04, 2025 08:28 AM
    On Tue, Nov 04, 2025 at 12:33:51PM +0000, P T via IBM TechXchange Community wrote:
    > Make sftp logging works also when chrooted. Currently the logging breaks when sftp chroot. At least this is documented:
    >
    > On some systems, sftp-server must be able to access /dev/log
    > for logging to work, and use of sftp-server in a chroot
    > configuration therefore requires that syslogd(8) establish a
    > logging socket inside the chroot directory.

    You can make SFTPD log transfers in a chroot. You have to create a log
    device in your chroot, and enable it with syslogd.

    In /etc/ssh/sshd_config, replace:

    Subsystem sftp /usr/sbin/sftp-server

    with:

    Subsystem sftp internal-sftp -f AUTH -l VERBOSE -u 002

    You need to update the match command for specific users, or consider
    running an SFTP only sshd on another port (my preference).

    Add these to /etc/ssh/sshd_config and customize the match:

    Match User !root
    ChrootDirectory /sftproot/
    ForceCommand internal-sftp -f AUTH -l VERBOSE -u 002

    Create your sftproot:

    mkdir -p /sftproot/dev
    chown root:system /sftproot/dev
    chmod 755 /sftproot/dev
    chown root:system /sftproot
    chmod 755 /sftproot
    mknod /sftproot/dev/null c 2 2
    chmod 666 /sftproot/dev/null

    Update syslog to open a log device:

    chssys -s syslogd -a "-r -R -n -A /sftproot/dev/log"
    stopsrc -s syslogd
    startsrc -s syslogd

    The /sftproot/dev/log device is created by syslogd when it starts.

    Now all sftp commands, including up and download should be logged to
    syslog.

    Thanks.


    ------------------------------------------------------------------
    Russell Adams Russell.Adams@AdamsSystems.nl
    Principal Consultant Adams Systems Consultancy
    https://adamssystems.nl/




  • 11.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Wed November 05, 2025 04:28 AM

    Thank you! My naive approach of symlinking /dev/log failed of course, obviously syslogd needs to know the exact location.

    Best regards,

    P. Tanovski



    ------------------------------
    P T
    ------------------------------



  • 12.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Wed November 05, 2025 10:39 AM

    Hi All

    While on the subject of oslevel command slowness, there is a known ksh performance issue when there are a lot of files (10's of thousands) in /tmp.

    This led to: IJ54441: KSH MAYBE SLOW ON EXIT DUE TO CONTENTION ON /TMP

    It is not a common problem, but one worth ruling out 



    ------------------------------
    Chris Wickremasinghe
    IBM
    ------------------------------



  • 13.  RE: OpenSSH 9.9: oslevel invocation causes login delays

    Posted Wed November 05, 2025 01:35 PM
    I have developed an habit since 1991:  I don't clean /tmp... instead I uncomment skulker in the root's crontab to solve the problem permanently. ;-)

    Unless stated otherwise above:
    KNDRL SERVICES PORTUGAL, S.A.
    Sociedade Anónima com o Capital Social de € 11.000.000
    Registada na Conservatória do Registo Comercial de Lisboa, sob o número único fiscal e de matrícula  516360558
    Edifício "Office Oriente" - Rua do Mar da China, Nº 3, Parque das Nações, 1990-138 LISBOA