Add an SSH access log

Summary: Ref T4107. Ref T4189. This implements an SSH access log, similar to the HTTP access log.

Test Plan:
  [Thu, 05 Dec 2013 13:45:41 -0800]	77841	orbital	::1	dweller	epriestley	epriestley	git-receive-pack	/diffusion/POEMS/	0	324765	402	232
  [Thu, 05 Dec 2013 13:45:48 -0800]	77860	orbital	::1	dweller	epriestley	epriestley	git-receive-pack	/diffusion/POEMS/	0	325634	402	232

Reviewers: btrahan

Reviewed By: btrahan

CC: aran

Maniphest Tasks: T4107, T4189

Differential Revision: https://secure.phabricator.com/D7719

Author: epriestley

scripts/ssh/ssh-exec.php

@@ -1,9 +1,13 @@
 #!/usr/bin/env php
 <?php
 
+$ssh_start_time = microtime(true);
+
 $root = dirname(dirname(dirname(__FILE__)));
 require_once $root.'/scripts/__init_script__.php';
 
+$ssh_log = PhabricatorSSHLog::getLog();
+
 // First, figure out the authenticated user.
 $args = new PhutilArgumentParser($argv);
 $args->setTagline('receive SSH requests');
@@ -38,6 +42,12 @@
     throw new Exception("Invalid username.");
   }
 
+  $ssh_log->setData(
+    array(
+      'u' => $user->getUsername(),
+      'P' => $user->getPHID(),
+    ));
+
   if (!$user->isUserActivated()) {
     throw new Exception(pht("Your account is not activated."));
   }
@@ -54,6 +64,15 @@
   if (!$original_argv) {
     throw new Exception("No interactive logins.");
   }
+
+  $ssh_log->setData(
+    array(
+      'C' => $original_argv[0],
+      'U' => phutil_utf8_shorten(
+        implode(' ', array_slice($original_argv, 1)),
+        128),
+    ));
+
   $command = head($original_argv);
   array_unshift($original_argv, 'phabricator-ssh-exec');
 
@@ -98,12 +117,35 @@
   $workflow->setIOChannel($metrics_channel);
   $workflow->setErrorChannel($error_channel);
 
-  $err = $workflow->execute($original_args);
+  $rethrow = null;
+  try {
+    $err = $workflow->execute($original_args);
 
+    $metrics_channel->flush();
+    $error_channel->flush();
+  } catch (Exception $ex) {
+    $rethrow = $ex;
+  }
 
-  $metrics_channel->flush();
-  $error_channel->flush();
+  // Always write this if we got as far as building a metrics channel.
+  $ssh_log->setData(
+    array(
+      'i' => $metrics_channel->getBytesRead(),
+      'o' => $metrics_channel->getBytesWritten(),
+    ));
+
+  if ($rethrow) {
+    throw $ex;
+  }
 } catch (Exception $ex) {
   fwrite(STDERR, "phabricator-ssh-exec: ".$ex->getMessage()."\n");
-  exit(1);
+  $err = 1;
 }
+
+$ssh_log->setData(
+  array(
+    'c' => $err,
+    'T' => (int)(1000000 * (microtime(true) - $ssh_start_time)),
+  ));
+
+exit($err);

src/__phutil_library_map__.php

@@ -996,7 +996,7 @@
     'Phabricator404Controller' => 'applications/base/controller/Phabricator404Controller.php',
     'PhabricatorAWSConfigOptions' => 'applications/config/option/PhabricatorAWSConfigOptions.php',
     'PhabricatorAccessControlTestCase' => 'applications/base/controller/__tests__/PhabricatorAccessControlTestCase.php',
-    'PhabricatorAccessLog' => 'infrastructure/PhabricatorAccessLog.php',
+    'PhabricatorAccessLog' => 'infrastructure/log/PhabricatorAccessLog.php',
     'PhabricatorAccessLogConfigOptions' => 'applications/config/option/PhabricatorAccessLogConfigOptions.php',
     'PhabricatorActionHeaderExample' => 'applications/uiexample/examples/PhabricatorActionHeaderExample.php',
     'PhabricatorActionHeaderView' => 'view/layout/PhabricatorActionHeaderView.php',
@@ -1811,6 +1811,7 @@
     'PhabricatorRepositoryVCSPassword' => 'applications/repository/storage/PhabricatorRepositoryVCSPassword.php',
     'PhabricatorS3FileStorageEngine' => 'applications/files/engine/PhabricatorS3FileStorageEngine.php',
     'PhabricatorSQLPatchList' => 'infrastructure/storage/patch/PhabricatorSQLPatchList.php',
+    'PhabricatorSSHLog' => 'infrastructure/log/PhabricatorSSHLog.php',
     'PhabricatorSSHPassthruCommand' => 'infrastructure/ssh/PhabricatorSSHPassthruCommand.php',
     'PhabricatorSSHWorkflow' => 'infrastructure/ssh/PhabricatorSSHWorkflow.php',
     'PhabricatorSavedQuery' => 'applications/search/storage/PhabricatorSavedQuery.php',
@@ -4337,6 +4338,7 @@
     'PhabricatorRepositoryTransactionQuery' => 'PhabricatorApplicationTransactionQuery',
     'PhabricatorRepositoryVCSPassword' => 'PhabricatorRepositoryDAO',
     'PhabricatorS3FileStorageEngine' => 'PhabricatorFileStorageEngine',
+    'PhabricatorSSHLog' => 'Phobject',
     'PhabricatorSSHPassthruCommand' => 'Phobject',
     'PhabricatorSSHWorkflow' => 'PhutilArgumentWorkflow',
     'PhabricatorSavedQuery' =>

src/applications/config/option/PhabricatorAccessLogConfigOptions.php

@@ -4,48 +4,56 @@ final class PhabricatorAccessLogConfigOptions
   extends PhabricatorApplicationConfigOptions {
 
   public function getName() {
-    return pht("Access Log");
+    return pht("Access Logs");
   }
 
   public function getDescription() {
-    return pht("Configure the access log, which logs all requests.");
+    return pht("Configure the access logs, which log HTTP/SSH requests.");
   }
 
   public function getOptions() {
-    $map = array(
-      'c' => pht("The HTTP response code."),
-      'C' => pht("The controller which handled the request."),
+    $common_map = array(
+      'C' => pht("The controller or workflow which handled the request."),
+      'c' => pht("The HTTP response code or process exit code."),
       'D' => pht("The request date."),
       'e' => pht("Epoch timestamp."),
       'h' => pht("The webserver's host name."),
       'p' => pht("The PID of the server process."),
-      'R' => pht("The HTTP referrer."),
       'r' => pht("The remote IP."),
       'T' => pht("The request duration, in microseconds."),
-      'U' => pht("The request path."),
+      'U' => pht("The request path, or request target."),
+      'm' => pht("For conduit, the Conduit method which was invoked."),
       'u' => pht("The logged-in username, if one is logged in."),
       'P' => pht("The logged-in user PHID, if one is logged in."),
+      'i' => pht("Request input, in bytes."),
+      'o' => pht("Request output, in bytes."),
+    );
+
+    $http_map = $common_map + array(
+      'R' => pht("The HTTP referrer."),
       'M' => pht("The HTTP method."),
-      'm' => pht("For conduit, the Conduit method which was invoked."),
     );
 
-    $fdesc = pht("Format for the access log. Available variables are:");
-    $fdesc .= "\n\n";
-    foreach ($map as $key => $desc) {
-      $fdesc .= "  - %".$key." ".$desc."\n";
-    }
-    $fdesc .= "\n";
-    $fdesc .= pht(
-      "If a variable isn't available (for example, %%m appears in the file ".
-      "format but the request is not a Conduit request), it will be rendered ".
-      "as '-'");
-    $fdesc .= "\n\n";
-    $fdesc .= pht(
-      "Note that the default format is subject to change in the future, so ".
-      "if you rely on the log's format, specify it explicitly.");
+    $ssh_map = $common_map + array(
+      's' => pht("The system user."),
+      'S' => pht("The system sudo user."),
+    );
+
+    $http_desc = pht(
+      "Format for the HTTP access log. Use {{log.access.path}} to set the ".
+      "path. Available variables are:");
+    $http_desc .= "\n\n";
+    $http_desc .= $this->renderMapHelp($http_map);
+
+    $ssh_desc = pht(
+      "Format for the SSH access log. Use {{log.ssh.path}} to set the ".
+      "path. Available variables are:");
+    $ssh_desc .= "\n\n";
+    $ssh_desc .= $this->renderMapHelp($ssh_map);
 
     return array(
       $this->newOption('log.access.path', 'string', null)
+        ->setLocked(true)
         ->setSummary(pht("Access log location."))
         ->setDescription(
           pht(
@@ -57,19 +65,61 @@ public function getOptions() {
             "If not set, no log will be written."))
         ->addExample(
           null,
-          pht('Disable access log'))
+          pht('Disable access log.'))
         ->addExample(
           '/var/log/phabricator/access.log',
-          pht('Write access log here')),
+          pht('Write access log here.')),
       $this->newOption(
         'log.access.format',
         // NOTE: This is 'wild' intead of 'string' so "\t" and such can be
         // specified.
         'wild',
         "[%D]\t%p\t%h\t%r\t%u\t%C\t%m\t%U\t%R\t%c\t%T")
+        ->setLocked(true)
         ->setSummary(pht("Access log format."))
-        ->setDescription($fdesc),
+        ->setDescription($http_desc),
+      $this->newOption('log.ssh.path', 'string', null)
+        ->setLocked(true)
+        ->setSummary(pht("SSH log location."))
+        ->setDescription(
+          pht(
+            "To enable the Phabricator SSH log, specify a path. The ".
+            "access log can provide more detailed information about SSH ".
+            "access than a normal SSH log (for instance, it can show ".
+            "logged-in users, commands, and other application data).\n\n".
+            "If not set, no log will be written."))
+        ->addExample(
+          null,
+          pht('Disable SSH log.'))
+        ->addExample(
+          '/var/log/phabricator/ssh.log',
+          pht('Write SSH log here.')),
+      $this->newOption(
+        'log.ssh.format',
+        'wild',
+        "[%D]\t%p\t%h\t%r\t%s\t%S\t%u\t%C\t%U\t%c\t%T\t%i\t%o")
+        ->setLocked(true)
+        ->setSummary(pht("SSH log format."))
+        ->setDescription($ssh_desc),
     );
   }
 
+  private function renderMapHelp(array $map) {
+    $desc = '';
+    foreach ($map as $key => $kdesc) {
+      $desc .= "  - `%".$key."` ".$kdesc."\n";
+    }
+    $desc .= "\n";
+    $desc .= pht(
+      "If a variable isn't available (for example, %%m appears in the file ".
+      "format but the request is not a Conduit request), it will be rendered ".
+      "as '-'");
+    $desc .= "\n\n";
+    $desc .= pht(
+      "Note that the default format is subject to change in the future, so ".
+      "if you rely on the log's format, specify it explicitly.");
+
+    return $desc;
+  }
+
 }

src/infrastructure/PhabricatorAccessLog.php renamed to src/infrastructure/log/PhabricatorAccessLog.php

@@ -0,0 +1,52 @@
+<?php
+
+final class PhabricatorSSHLog extends Phobject {
+
+  static $log;
+
+  public static function getLog() {
+    if (!self::$log) {
+      $path = PhabricatorEnv::getEnvConfig('log.ssh.path');
+      $format = PhabricatorEnv::getEnvConfig('log.ssh.format');
+      $format = nonempty(
+        $format,
+        "[%D]\t%p\t%h\t%r\t%s\t%S\t%u\t%C\t%U\t%c\t%T\t%i\t%o");
+
+      // NOTE: Path may be null. We still create the log, it just won't write
+      // anywhere.
+
+      $data = array(
+        'D' => date('r'),
+        'h' => php_uname('n'),
+        'p' => getmypid(),
+        'e' => time(),
+      );
+
+      $sudo_user = PhabricatorEnv::getEnvConfig('phd.user');
+      if (strlen($sudo_user)) {
+        $data['S'] = $sudo_user;
+      }
+
+      if (function_exists('posix_geteuid')) {
+        $system_uid = posix_geteuid();
+        $system_info = posix_getpwuid($system_uid);
+        $data['s'] = idx($system_info, 'name');
+      }
+
+      $client = getenv('SSH_CLIENT');
+      if (strlen($client)) {
+        $remote_address = head(explode(' ', $client));
+        $data['r'] = $remote_address;
+      }
+
+      $log = id(new PhutilDeferredLog($path, $format))
+        ->setFailQuietly(true)
+        ->setData($data);
+
+      self::$log = $log;
+    }
+
+    return self::$log;
+  }
+
+}