Logging and Debugging

As an SSH server runs, it optionally produces log messages to describe what it's doing. Log messages aid the system administrator in tracking the server's behavior and detecting and diagnosing problems. For example, if a server is mysteriously rejecting connections, one of the first places to look is the server's log output.

By default, the SSH server writes log messages to syslog , the standard Unix logging service (see the sidebar, "The Syslog Logging Service"). For example, an SSH server typically announces its startup with log messages like:^[86]

    Server listening on 0.0.0.0 port 22.
    Generating 768 bit RSA key.
    RSA key generation complete.

and a connection from a client is recorded with log messages like:

    session opened for user rebecca by (uid=9005)
    Accepted publickey for rebecca from 10.1.2.3 port 1265
    ssh2 session closed for user rebecca

The SyslogFacility keyword specifies how the SSH server tags log messages:

    SyslogFacility LOCAL3

The value is one of the (case-insensitive) syslog facility codes, and the default is AUTH.

Warning

Tectia confusingly interprets AUTH to actually mean AUTHPRIV (this also applies to the default behavior), and does not recognize AUTHPRIV as a syslog facility code. On systems that do not support a separate AUTHPRIV facility, Tectia resorts to AUTH. Otherwise, Tectia provides no way to specify the AUTH facility explicitly.

For Tectia, a separate syslog facility code is used for the sftp subsystem. [5.8] This is specified by the SftpSysLogFacility keyword:

    # Tectia
    SftpSysLogFacility LOCAL7

By default, no logging is performed for sftp.

Tip

If the sftp subsystem is implemented by an external program, then the Tectia server passes the sftp syslog facility code via the environment variable SSH2_SFTP_LOG_FACILITY. Otherwise, if the internal sftp subsystem that is built into the server is used, then the value for the SftpSysLogFacility keyword is consulted directly.

SSH servers use a range of syslog priority levels, depending on the types of log messages that are sent. These priority levels aren't directly controllable, but the syslog configuration determines where and how they are recorded (or discarded).

The amount of detail provided by log messages can be specified in a variety of ways, however. OpenSSH uses the keyword LogLevel to control the verbosity level:

    # OpenSSH
    LogLevel VERBOSE

The permitted values (in order of increasing verbosity) are QUIET, FATAL, ERROR, INFO, VERBOSE, DEBUG, and DEBUG1 through DEBUG3.^[87]

The QUIET level sends nothing whatsoever to the system log (although some messages resulting from OpenSSH activity may still be recorded by other programs and libraries, such as PAM). Tectia uses a separate keyword, QuietMode, to suppress all log messages (except fatal errors), with the values yes or no (the default):

    # Tectia
    QuietMode yes

The -q command-line option also selects quiet operation:

    $ sshd -q

5.9.1 OpenSSH Logging and Debugging

For OpenSSH, the LogLevel values DEBUG1 through DEBUG3 produce voluminous information useful only for diagnostic purposes.^[88] These levels are sufficiently verbose to reveal sensitive personal information that should not normally be recorded, so avoid them for routine operation. Debugging output is usually requested on the command line:

    # OpenSSH
    $ sshd -o "LogLevel DEBUG2"

More concisely, the -d command-line option can be specified one to three times, to set the LogLevel to DEBUG1 through DEBUG3, respectively:

    # OpenSSH
    $ sshd -d -d        DEBUG2 level

The -t (test) option causes the OpenSSH server to start up, check the validity of its host keys and the server configuration file, and exit. [5.2.2] Combine it with -d to see more details about successful operation:

    # OpenSSH
    $ sshd -d -t
    debug1: sshd version OpenSSH_3.9p1
    debug1: read PEM private key done: type RSA
    debug1: private host key: #0 type 1 RSA
    debug1: read PEM private key done: type DSA
    debug1: private host key: #1 type 2 DSA

For OpenSSH, the -d command-line option also causes the server to run in "debug mode," which alters its behavior to support debugging. The LogLevel keyword does not enable debug mode—it only sets the verbosity level.

In debug mode, the OpenSSH server runs in the foreground, without forking, instead of running detached as a daemon. Normally, the server forks again after it accepts each connection from a client, and continues further work for the session in a separate child process, while the parent process resumes listening for more connection requests. In debug mode, however, the OpenSSH server handles only a single connection, again without forking, and then exits. This is usually convenient for debugging, when forking and multiple processes are unwelcome complications; it's often easier to determine what's happening if all actions are performed by a single process.

OpenSSH doesn't bother to record its process ID in the PidFile [5.3.1.3] when it runs in debug mode, since no forking occurs, and it's easy to determine the process ID if the server needs to be signaled.

OpenSSH can also be prevented from running as a daemon by using the -D command-line option:

    # OpenSSH
    $ sshd -D

The -D option does not change the LogLevel or enable any of the other side effects of debug mode. The OpenSSH server still forks to handle multiple client connections, even when -D is specified.

The -D option is handy in special circumstances when some other process needs to monitor the OpenSSH server, and would incorrectly conclude that sshd had exited if it forked and ran in the background. For example, the Cygwin program cygrunsrv uses sshd -D to launch OpenSSH as a Windows service. [14.1]

In debug mode, the OpenSSH server prints log messages to the standard error, instead of sending them to syslog. For example, we can use the -p option to test the server without disturbing normal operation on the standard port: [5.3.3.1]

    # OpenSSH
    $ sshd -d -p 2222
    debug1: sshd version OpenSSH_3.5p1
    debug1: private host key: #0 type 0 RSA1
    debug1: read PEM private key done: type RSA
    debug1: private host key: #1 type 1 RSA
    debug1: read PEM private key done: type DSA
    debug1: private host key: #2 type 2 DSA
    debug1: rexec_argv[0]='/usr/sbin/sshd'
    debug1: rexec_argv[1]='-d'
    debug1: rexec_argv[2]='-p'
    debug1: rexec_argv[3]='2222'
    debug1: Bind to port 2222 on 0.0.0.0.
    Server listening on 0.0.0.0 port 2222.
    Generating 768 bit RSA key.
    RSA key generation complete.
    ... The server waits for an incoming connection request, and then ...
    debug1: Server will not fork when running in debugging mode.
    debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7
    ... Further debug output is sent to syslog: see below ...

Log messages that would have been sent to syslog are printed directly. Extra debug messages are printed with the debug1 prefix (or debug2 or debug3 if more verbose debugging log levels are used). Lots of sample output from sshd -d can be found in Chapter 3.

The -e option causes the OpenSSH server to independently redirect syslog output to the standard error, without all of the other side effects of debug mode. For example:

    # OpenSSH
    $ sshd -D -e -p 2222
    Server listening on 0.0.0.0 port 2222.
    Accepted publickey for rebecca from 10.1.2.3 port 32788 ssh2
    ...

When debugging OpenSSH, it's usually a good idea to disable server restarts with the undocumented -r option, again to confine all activity to a single process for simplicity, and to prevent debug output from being diverted from stderr to syslog after the restart. [5.3.3.3] In the previous example for sshd -d, debug output lines that mention rexec refer to server restarts, and debug output sent to stderr abruptly ends after the rexec start line. If we repeat the example with the -r option, we see much more debugging information sent to stderr, without any of the rexec clutter:

    # OpenSSH
    $ sshd -d -r -p 2222
    debug1: sshd version OpenSSH_3.9p1
    debug1: private host key: #0 type 0 RSA1
    debug1: read PEM private key done: type RSA
    debug1: private host key: #1 type 1 RSA
    debug1: read PEM private key done: type DSA
    debug1: private host key: #2 type 2 DSA
    debug1: Bind to port 2222 on 0.0.0.0.
    Server listening on 0.0.0.0 port 2222.
    Generating 768 bit RSA key.
    RSA key generation complete.
    ... The server waits for an incoming connection request, and then ...
    debug1: Server will not fork when running in debugging mode.
    Connection from 10.1.2.3 port 32777
    debug1: Client protocol version 2.0; client software version OpenSSH_3.9p1
    debug1: match: OpenSSH_3.9p1 pat OpenSSH*
    debug1: Enabling compatibility mode for protocol 2.0
    debug1: Local version string SSH-1.99-OpenSSH_3.9p1
    ... Lots more output follows ...

Alternately, if the restart mechanism itself is being debugged, the -e option can be used to prevent the diversion of debug output from syslog to stderr after the server restarts:

    # OpenSSH
    $ sshd -d -e -p 2222
    debug1: sshd version OpenSSH_3.9p1
    debug1: private host key: #0 type 0 RSA1
    debug1: read PEM private key done: type RSA
    debug1: private host key: #1 type 1 RSA
    debug1: read PEM private key done: type DSA
    debug1: private host key: #2 type 2 DSA
    debug1: rexec_argv[0]='/usr/sbin/sshd'
    debug1: rexec_argv[1]='-d'
    debug1: rexec_argv[2]='-e'
    debug1: rexec_argv[3]='-p'
    debug1: rexec_argv[4]='2222'
    debug1: Bind to port 2222 on 0.0.0.0.
    Server listening on 0.0.0.0 port 2222.
    Generating 768 bit RSA key.
    RSA key generation complete.
    ... The server waits for an incoming connection request, and then ...
    debug1: Server will not fork when running in debugging mode.
    debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7
    ... The restarted process rereads the host keys as it repeats all of the initializations ...
    debug1: sshd version OpenSSH_3.9p1
    debug1: private host key: #0 type 0 RSA1
    debug1: read PEM private key done: type RSA
    debug1: private host key: #1 type 1 RSA
    debug1: read PEM private key done: type DSA
    debug1: private host key: #2 type 2 DSA
    ... The restarted process uses the SSH socket accepted by the original process ...
    debug1: inetd sockets after dupping: 3, 3
    ... Finally, the server continues to handle the session, as before ...
    Connection from 10.1.2.3 port 32778
    debug1: Client protocol version 2.0; client software version OpenSSH_3.9p1
    debug1: match: OpenSSH_3.9p1 pat OpenSSH*
    debug1: Enabling compatibility mode for protocol 2.0
    debug1: Local version string SSH-1.99-OpenSSH_3.9p1
    ... Lots more output follows ...

When the OpenSSH server is running in debug mode, extra information is also sent to (and displayed by) the client, such as environment variables, initialization scripts, xauth actions, etc., which aid in debugging connection problems.

For example, a connection to the server on the alternate port shown earlier produces diagnostic output like this:

    $ ssh -p 2222 server.example.com
    Environment:
     USER=elvis
     LOGNAME=elvis
     HOME=/u/elvis
     PATH=/usr/local/bin:/bin:/usr/bin
     MAIL=/var/mail/elvis
     SHELL=/bin/tcsh
     SSH_CLIENT=10.1.2.3 1059 2222
     SSH_CONNECTION=10.1.2.3 1059 10.4.5.6 2222
     SSH_TTY=/dev/pts/2
     TERM=xterm
     DISPLAY=localhost:10.0
     SSH_AUTH_SOCK=/tmp/ssh-XXg0cfvG/agent.1989
    Running /bin/tcsh -c '/bin/sh .ssh/rc'
    ... or ...
    Running /bin/sh /etc/ssh/sshrc
    ... or ...
    Running /usr/X11R6/bin/xauth remove unix:13.0
    /usr/X11R6/bin/xauth add unix:13.0 MIT-MAGIC-COOKIE-1 007ab9e94cf72f081390f46ab0d92f1f

The OpenSSH server ignores the LoginGraceTime keyword [5.3.3.6] when it runs in debug mode, since debugging sessions often last much longer!

5.9.2 Tectia Logging and Debugging

Debug mode for Tectia is also controlled by the -d command-line option,^[89] but the option requires an argument indicating the debug level.

Tip

We strongly recommend compiling Tectia with heavy debugging turned on, using the --enable-debug-heavy configure option. [4.3.5.9] The resulting log messages are far more detailed than those printed by default.

Debug levels may be indicated in a variety of ways. The simplest is a nonnegative integer:

    # Tectia
    $ sshd -d 2

Specifying a debug level means that messages for all lower levels will be printed as well. Higher numbers indicate increased verbosity. The approximate meanings of the integer debug levels are:

Level	Approximate meaning
0-2	Software malfunctions
3	Non-fatal, high-level errors caused by data received from the network
4	Successful, high-level operations
5	Start of high-level operations
6	Uncommon situations that might indicate bugs
7	Successful, mid-level operations
8	Data block dumps
9	Protocol packet dumps
10	Successful, low-level operations
11-15	Miscellaneous, extremely low-level operations

The -v command line option is equivalent to -d 2:

    # Tectia
    $ sshd -v

Alternatively, the VerboseMode keyword (or the abbreviated synonym Verbose) is equivalent to the -v option:

    # Tectia
    VerboseMode yes

Since debug logging isn't recommended for normal operation, the VerboseMode keyword is useful primarily in alternate configuration files that are specified with the -f command-line option [5.2.1], or in subconfiguration files. [11.6.2]

The integer debug levels affect all aspects of Tectia's operation. Debug levels can also be set differently for each module in the Tectia source distribution. This permits much finer-grained control over logging.

To use module-based debugging effectively, you should have some understanding of C programming, and consult the source code (especially the header file lib/sshutil/sshcore/sshdebug.h). Each source file is considered to be a "module" for debugging purposes, as determined by the definition of SSH_DEBUG_MODULE within the file. For example, the file apps/ssh/authspasswd.c has the module name Ssh2AuthPasswdServer because it contains the line:

    #define SSH_DEBUG_MODULE "Ssh2AuthPasswdServer"

The complete set of module names for Tectia at press time is found in Appendix C. To extract the current set of module names from the source code, search for SSH_DEBUG_MODULE definitions in all source files from within the Tectia distribution:

    $ find . -type f -print | xargs grep "define.*SSH_DEBUG_MODULE"

Module names are case-sensitive. Once you have identified the name of your desired module, run the server in debug mode, providing the module's name and debug level. For example, to cause the Ssh2AuthPasswdServer module to log at debug level 2:

    # Tectia
    $ sshd -d "Ssh2AuthPasswdServer=2"

If the debug level is omitted (i.e., only the module name is specified), then the debug level is taken to be zero, so either of the following forms can be used:

    # Tectia
    $ sshd -d "Ssh2AuthPasswdServer"
    $ sshd -d "Ssh2AuthPasswdServer=0"

The special module name global refers to all modules, and is equivalent to specifying an integer debug level. For example, the following two commands function identically:

    # Tectia
    $ sshd -d "global=2"
    $ sshd -d 2

The default global debug level is zero.

Multiple modules may be specified, separated by commas, each set to individual debug levels:

    # Tectia
    $ sshd -d "Ssh2AuthPasswdServer=2,SshAdd=3,SshSftpServer=5"

Add whitespace to improve readability:

    # Tectia
    $ sshd -d "Ssh2AuthPasswdServer = 2, SshAdd = 3, SshSftpServer = 5"

If the -d option is repeated, the debug levels are concatenated. This is an alternative to comma-separated lists:

    # Tectia
    $ sshd -d "Ssh2AuthPasswdServer=2" -d "SshAdd=3" -d "SshSftpServer=5"

More generally, module names are patterns that can contain the wildcards * and ? to match multiple modules:

    # Tectia
    $ sshd -d "Ssh2Auth*=3"

Warning

These two wildcards have the same meaning as for zsh_fileglob or traditional regex syntax, but debug module patterns are not full regular expressions: no other wildcards or regex syntax is recognized.

Remember to enclose wildcards for the patterns in quotes to prevent their expansion by the Unix shell.

Wildcards cannot match the special global module name, so the following does not work:

    # Tectia: does not work
    $ sshd -d "glo*=2"

Setting the global debug level (using either a simple integer or the special global module name) causes all earlier module debug level assignments to be ignored, so global assignments should always be specified first:

    # Tectia
    $ sshd -d 1 -d "Ssh2AuthPasswdServer=2,SshAdd=3,SshSftpServer=5"
    $ sshd -d "global=1, Ssh2AuthPasswdServer=2,SshAdd=3,SshSftpServer=5"

The global debug level is used as the default for all modules; otherwise, the debug level for a specific module is determined by the last match in the list. This rule, when combined with wildcards, can be used to conveniently set debug levels for entire categories of modules, by overriding earlier, more general assignments with a sequence of increasingly specific patterns. For example:

    # Tectia
    $ sshd -d "global = 1, Ssh2* = 2, Ssh2Auth* = 3, Ssh2AuthPasswd* = 4"

The "match anything" pattern * functions similarly to the global debug level:

    # Tectia
    $ sshd -d "* = 1, Ssh2* = 2, Ssh2Auth* = 3, Ssh2AuthPasswd* = 4"

Debug output lines always start with the word "debug," followed by the process ID in square brackets. Messages for specific modules mention the module name, and provide the name of the source file (with a line number) in which the code is found, plus the name of the function in which they occur. For example:

    # Tectia
    $ sshd -d "Ssh2AuthPasswdServer=2"
    ...
    debug[2665]: Ssh2AuthPasswdServer/auths-passwd.c:136/ssh_server_auth_passwd: 
password auth.
    debug[2665]: Ssh2AuthPasswdServer/auths-passwd.c:138/ssh_server_auth_passwd: op = 0  
user = elvis
    ...
    debug[2665]: Ssh2AuthPasswdServer/auths-passwd.c:250/ssh_
    server_auth_passwd: ssh_server_auth_passwd: accepted by local passwd
    ...

Some debug output isn't associated with any module, and is printed for all debug levels. In addition, some modules produce output even for debug level 0:

    # Tectia
    $ sshd -d 0
    debug[3320]: Host key pair is not specified, trying to use default 'hostkey'.
    debug[3320]: Becoming server.
    debug[3320]: Creating listener(s)
    ...
    debug[3320]: Listeners created
    debug[3320]: no udp listener created.
    ...
    debug[3320]: Running event loop
    ...
    debug[3320]: Ssh2Common/sshcommon.c:510/ssh_common_wrap: local ip = 10.1.2.3, local 
port = 22
    debug[3320]: Ssh2Common/sshcommon.c:512/ssh_common_wrap: remote ip = 10.1.2.3, 
remote port = 32793
    ...
    debug[3320]: Sshd2/sshd2.c:334/server_disconnect: locally_generated = TRUE

Warning

Just because a source code file has a debugging module name associated with it doesn't mean it actually logs any information that way. You may find that turning on debugging for specific modules doesn't produce any extra debugging output.

The sshd-check-conf program [5.2.2] also accepts the debug options -d and -v. Use the module names SshdCheckConf, SshConfigParse, or SshConfig to see more details about parsing of configuration files:

    # Tectia
    $ sshd-check-conf -d "SshConfigParse=9"
    debug: SshConfigParse/sshconfig_parse.c:224/ssh_parse_config_ext: Got metaconfig line
    `## REGEX-SYNTAX egrep'.
    debug: SshConfigParse/sshconfig_parse.c:246/ssh_parse_config_ext: Metaconfig
    specifies regex style 'EGREP'.
    debug: SshConfigParse/sshconfig_parse.c:252/ssh_parse_config_ext: Metaconfig parsing
    stopped at line 3.
    debug: SshConfigParse/sshconfig_parse.c:464/ssh_config_parse_line: n_
    var = `Port', n_val = `22'
    debug: SshConfigParse/sshconfig_parse.c:464/ssh_config_parse_line: n_var
    = `SettableEnvironmentVars', n_val = `LANG,LC_
    (ALL|COLLATE|CTYPE|MONETARY|NUMERIC|TIME),PATH,TERM,TZ'
    debug: SshConfigParse/sshconfig_parse.c:464/ssh_config_parse_line: n_var =
    `subsystem-sftp', n_val = `sftp-server'
    ...

As for OpenSSH, the -d command-line option causes the Tectia server to run in the foreground, processing a single connection, and then exiting.

Tip

Although the VerboseMode keyword is equivalent to the -v option, which in turn means the same as -d 2, the keyword cannot prevent forking if it is used in a subconfiguration file [11.6.2], because forking will have already occurred when the subconfiguration file is read. Therefore, VerboseMode in a subconfiguration file only determines the debug level. In the main configuration file, the keyword controls forking too.

To continue listening for more connections, use the -D option instead of -d:

    # Tectia
    $ sshd -D "Ssh*TCP*=8"

When the Tectia server is started with the -D option, it runs in the foreground, but subsequently forks to spawn a separate child process to handle the session for each client connection. In all other respects, the -D and -d options function identically.

Tectia doesn't provide any means to run the server in the foreground without enabling debug mode. However, debug output can be minimized by using the -D option with a debug level of zero, and the relatively small amount of unneeded debug information can be discarded:

    # Tectia
    $ sshd -D 0 2> /dev/null

If you need this quieter mode of operation frequently, consider rebuilding the server without debugging support. [4.3.5.9]

Tip

When specifying debug options (-d, -D, or -v) on the sshd command line, list them first so that debugging output starts as early as possible. This is especially important if you are investigating the parsing of command-line options or configuration files.

Tectia always sends debug output to the standard error, distinct from the messages sent to syslog. In debug mode, messages continue to be sent to syslog as they are for normal operation, but these messages are also copied to the standard error, and intermingled with the debug output. The copied syslog messages are annotated with the name of the Tectia server program (usually "sshd2") instead of "debug," and they are unaffected by the debug level:

    # Tectia
    $ sshd -d 0
    sshd2[3320]: Listener created on  *** SSH_IPADDR_ANY ***:22.
    sshd2[3320]: Daemon is running.
    sshd2[3320]: connection from "10.1.2.3" (listen iface: *** SSH_IPADDR_ANY ***:22)
    ...
    sshd2[3320]: Destroying session channel 0
    sshd2[3320]: Local disconnected: Connection closed.
    sshd2[3320]: connection lost: 'Connection closed.'
    sshd2[3320]: Logout for user elvis.

If syslog output is not desired when debugging Tectia, it can be directed to some syslog facility that is discarded by syslogd:

    # Tectia
    $ sshd -d 0 -o "SysLogFacility LOCAL3"

The Tectia server catches the signal SIGUSR1 after it accepts a connection from a client, and finishes authentication and authorization. When SIGUSR1 is received, the server prints detailed information about the connection to its standard error stream. This is useful only when the server is running in the foreground (i.e., with the -d or -D options), since output to stderr is discarded when sshd is running in the background, as a daemon.

If the -d option is used, no forking occurs, and SIGUSR1 can be sent to the single server process anytime after the single session starts. For the -D option, however, a separate child process is used for each connection, and SIGUSR1 must be sent to children, not the original parent process that continues to listen for connections:^[90]

    # Tectia
    $ sshd -D 0 -p 2222
    ...
    debug[1234]: Becoming server.
    debug[1234]: Creating listener(s)
    sshd2[1234]: Listener created on  *** SSH_IPADDR_ANY ***:2222.
    debug[1234]: Listeners created
    debug[1234]: no udp listener created.
    sshd2[1234]: Daemon is running.
    ...
    sshd2[5678]: Public key authentication for user elvis accepted.
    sshd2[5678]: User elvis (uid 501), coming from client.friendly.org, authenticated.
    sshd2[5678]: Received a channel open request, type session, channel id 0
    sshd2[5678]: Received a session channel extension request of type x11-req for 
channel number 0
    sshd2[5678]: Received a session channel extension request of type exec for channel 
number 0
    ...

Here the parent process that is listening for connections is 1234, while the child that accepted the connection is 5678. If we send SIGUSR1 to the latter:

    $ kill -USR1 5678

then the server responds with the requested information:

    *** Config Data ***
    Server Protocol Version String: 4.1.0.34 SSH Secure Shell

    *** Connection Data ***
    Server on host: client.friendly.org (10.1.2.3)
    Server listening on port: 2222
    Connection from 10.1.2.3
    Client hostname: client.friendly.org

    *** Algorithm Data ***
    Chosen Hostkey Algorithm: ssh-dss

    Client to Server Algorithms:
    Chosen Cipher: aes128-cbc
    Chosen MAC: hmac-sha1
    Chosen Compression: none

    Server to Client Algorithms:
    Chosen Cipher: aes128-cbc
    Chosen MAC: hmac-sha1
    Chosen Compression: none

    *** Channel Data ***
    Number of Channels: 1
     Channel 0 (session):
      Sent bytes: 0
      Received bytes: 0

      Incoming window size: 100000
      Incoming window left: 100000
      Outgoing window left: 99249

    *** Connection Statistics ***
    compressed bytes in: 3918
    uncompressed bytes in: 3918
    compressed bytes out: 5418
    uncompressed bytes out: 5418
    packets in: 22
    packets out: 22
    rekeys: 0

    *** User Data ***
    Username: elvis
    User's uid: 501
    User belongs to the following groups:
    Group: memphis, gid: 501
    User's home directory: /u/elvis
    User's shell: /bin/tcsh

    *** Local/Remote Tunnel Data ***
    No active local forwards.
    No active remote forwards.

In debug mode, the Tectia server sends extra information to the client. The content and format are similar to information sent by the OpenSSH server, except for Tectia's annotations identifying debug and (copied) syslog messages, with the process ID of the server after it forks to launch the user's shell:

    # Tectia
    $ ssh -p 2222 server.example.com
    debug[2045]: /etc/nologin_server.example.com does not exist.
    sshd2[2045]: Now running on elvis's privileges.
    debug[2045]: Environment:
    debug[2045]:   HOME=/u/elvis
    debug[2045]:   USER=elvis
    debug[2045]:   LOGNAME=elvis
    debug[2045]:   PATH=/usr/local/bin:/bin:/usr/bin:/usr/X11R6/bin
    debug[2045]:   MAIL=/var/spool/mail/elvis
    debug[2045]:   SHELL=/bin/tcsh
    debug[2045]:   SSH2_CLIENT=10.1.2.3 32781 10.1.2.3 2222
    debug[2045]:   DISPLAY=server.example.com:10.0
    debug[2045]:   SSH2_SFTP_LOG_FACILITY=-1
    debug[2045]: Running /bin/tcsh /u/elvis/.ssh2/rc
    ... or ...
    debug[2045]: Running /bin/sh /etc/ssh2/sshrc
    ... or ...
    debug[2045]: Running /usr/X11R6/bin/xauth add server.example.com:10.0 MIT-MAGIC-
    COOKIE-1 81e51d2ccefaf62b288e9f772cdaa21d
    debug[2045]: Running /usr/X11R6/bin/xauth add 10.1.2.3:10.0 MIT-MAGIC-COOKIE-1
    81e51d2ccefaf62b288e9f772cdaa21d

5.9.3 Debugging Under inetd or xinetd

If you run the SSH server from inetd or xinetd using the -i command-line option [5.3.3.2], debugging can be tricky. It is necessary for sshd to avoid sending any extra debugging output to the standard error, since it would be relayed by inetd or xinetd to the SSH client along with the normal SSH protocol conversation, messing it up and causing the connection to fail.

OpenSSH forces all debug output to be sent to syslog if the -i option is used, which neatly solves the problem. For Tectia, however, the easiest approach is to redirect the debug output from the standard error to a file. Because many versions of inetd or xinetd do not support shell metacharacters in their configuration files, it's best to use a short shell script to invoke sshd with the redirected output:

    #!/bin/sh
    # redirect Tectia sshd standard error to a file
    exec /usr/local/sbin/sshd -d 2 -i 2> /tmp/sshd2.debug

Simply specify this shell script in place of sshd in the inetd or xinetd configuration files.

Alternately, you can send debug output to syslog using the logger program:

    #!/bin/sh
    # send Tectia sshd debug output to syslog
    exec /usr/local/sbin/sshd -d 2 -i 2>&1 | grep "^debug" | logger -p local3.debug

grep selects only the debug output, discarding the duplicate syslog messages that are also sent to the standard error in debug mode.

^[86] The system logger adds other information to each log message, such as a timestamp, the name of the machine, and the process ID of the SSH server, so lines in the log files will actually look like:

Aug 30 17:41:47 graceland sshd[731]: Illegal user elvis from 10.11.12.13

^[87]These names are not syslog priority levels, although some of the names are similar.

^[88]DEBUG is a synonym for DEBUG1.

^[89]The -d option has no corresponding keyword.

^[90]If SIGUSR1 is sent to the parent, it will die, since it has not arranged to catch the signal.