Line data    Source code

       1             : // Copyright (C) 2009 The Android Open Source Project
       2             : //
       3             : // Licensed under the Apache License, Version 2.0 (the "License");
       4             : // you may not use this file except in compliance with the License.
       5             : // You may obtain a copy of the License at
       6             : //
       7             : // http://www.apache.org/licenses/LICENSE-2.0
       8             : //
       9             : // Unless required by applicable law or agreed to in writing, software
      10             : // distributed under the License is distributed on an "AS IS" BASIS,
      11             : // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
      12             : // See the License for the specific language governing permissions and
      13             : // limitations under the License.
      14             : 
      15             : package com.google.gerrit.sshd;
      16             : 
      17             : import com.google.common.collect.ListMultimap;
      18             : import com.google.common.collect.Multimap;
      19             : import com.google.common.collect.MultimapBuilder;
      20             : import com.google.gerrit.extensions.events.LifecycleListener;
      21             : import com.google.gerrit.server.CurrentUser;
      22             : import com.google.gerrit.server.IdentifiedUser;
      23             : import com.google.gerrit.server.PeerDaemonUser;
      24             : import com.google.gerrit.server.audit.SshAuditEvent;
      25             : import com.google.gerrit.server.config.ConfigKey;
      26             : import com.google.gerrit.server.config.ConfigUpdatedEvent;
      27             : import com.google.gerrit.server.config.ConfigUpdatedEvent.ConfigUpdateEntry;
      28             : import com.google.gerrit.server.config.ConfigUpdatedEvent.UpdateResult;
      29             : import com.google.gerrit.server.config.GerritConfigListener;
      30             : import com.google.gerrit.server.config.GerritServerConfig;
      31             : import com.google.gerrit.server.group.GroupAuditService;
      32             : import com.google.gerrit.server.ioutil.HexFormat;
      33             : import com.google.gerrit.server.util.SystemLog;
      34             : import com.google.gerrit.server.util.time.TimeUtil;
      35             : import com.google.gerrit.sshd.SshScope.Context;
      36             : import com.google.inject.Inject;
      37             : import com.google.inject.Provider;
      38             : import com.google.inject.Singleton;
      39             : import org.apache.log4j.AsyncAppender;
      40             : import org.apache.log4j.Level;
      41             : import org.apache.log4j.Logger;
      42             : import org.apache.log4j.spi.LoggingEvent;
      43             : import org.eclipse.jgit.lib.Config;
      44             : 
      45             : @Singleton
      46             : class SshLog implements LifecycleListener, GerritConfigListener {
      47          17 :   private static final Logger log = Logger.getLogger(SshLog.class);
      48             : 
      49             :   private static final String JSON_SUFFIX = ".json";
      50             : 
      51             :   protected static final String LOG_NAME = "sshd_log";
      52             :   protected static final String P_SESSION = "session";
      53             :   protected static final String P_USER_NAME = "userName";
      54             :   protected static final String P_ACCOUNT_ID = "accountId";
      55             :   protected static final String P_WAIT = "queueWaitTime";
      56             :   protected static final String P_EXEC = "executionTime";
      57             :   protected static final String P_STATUS = "status";
      58             :   protected static final String P_AGENT = "agent";
      59             :   protected static final String P_MESSAGE = "message";
      60             :   protected static final String P_TOTAL_CPU = "totalCpu";
      61             :   protected static final String P_USER_CPU = "userCpu";
      62             :   protected static final String P_MEMORY = "memory";
      63             : 
      64             :   private final Provider<SshSession> session;
      65             :   private final Provider<Context> context;
      66             :   private volatile AsyncAppender async;
      67             :   private final GroupAuditService auditService;
      68             :   private final SystemLog systemLog;
      69             : 
      70             :   private final boolean json;
      71             :   private final boolean text;
      72             : 
      73          17 :   private final Object lock = new Object();
      74             : 
      75             :   @Inject
      76             :   SshLog(
      77             :       final Provider<SshSession> session,
      78             :       final Provider<Context> context,
      79             :       SystemLog systemLog,
      80             :       @GerritServerConfig Config config,
      81          17 :       GroupAuditService auditService) {
      82          17 :     this.session = session;
      83          17 :     this.context = context;
      84          17 :     this.auditService = auditService;
      85          17 :     this.systemLog = systemLog;
      86             : 
      87          17 :     this.json = config.getBoolean("log", "jsonLogging", false);
      88          17 :     this.text = config.getBoolean("log", "textLogging", true) || !json;
      89             : 
      90          17 :     if (config.getBoolean("sshd", "requestLog", true)) {
      91           5 :       enableLogging();
      92             :     }
      93          17 :   }
      94             : 
      95             :   /** Returns true if a change in state has occurred */
      96             :   public boolean enableLogging() {
      97           5 :     synchronized (lock) {
      98           5 :       if (async == null) {
      99           5 :         async = new AsyncAppender();
     100             : 
     101           5 :         if (text) {
     102           5 :           async.addAppender(systemLog.createAsyncAppender(LOG_NAME, new SshLogLayout()));
     103             :         }
     104             : 
     105           5 :         if (json) {
     106           0 :           async.addAppender(
     107           0 :               systemLog.createAsyncAppender(LOG_NAME + JSON_SUFFIX, new SshLogJsonLayout()));
     108             :         }
     109           5 :         return true;
     110             :       }
     111           0 :       return false;
     112             :     }
     113             :   }
     114             : 
     115             :   /** Returns true if a change in state has occurred */
     116             :   public boolean disableLogging() {
     117          17 :     synchronized (lock) {
     118          17 :       if (async != null) {
     119           5 :         async.close();
     120           5 :         async = null;
     121           5 :         return true;
     122             :       }
     123          13 :       return false;
     124             :     }
     125             :   }
     126             : 
     127             :   @Override
     128          17 :   public void start() {}
     129             : 
     130             :   @Override
     131             :   public void stop() {
     132          17 :     disableLogging();
     133          17 :   }
     134             : 
     135             :   void onLogin() {
     136          17 :     LoggingEvent entry = log("LOGIN FROM " + session.get().getRemoteAddressAsString());
     137          17 :     if (async != null) {
     138           5 :       async.append(entry);
     139             :     }
     140          17 :     audit(context.get(), "0", "LOGIN");
     141          17 :   }
     142             : 
     143             :   void onAuthFail(SshSession sd) {
     144           1 :     final LoggingEvent event =
     145             :         new LoggingEvent( //
     146           1 :             Logger.class.getName(), // fqnOfCategoryClass
     147             :             log, // logger
     148           1 :             TimeUtil.nowMs(), // when
     149             :             Level.INFO, // level
     150           1 :             "AUTH FAILURE FROM " + sd.getRemoteAddressAsString(), // message text
     151             :             "SSHD", // thread name
     152             :             null, // exception information
     153             :             null, // current NDC string
     154             :             null, // caller location
     155             :             null // MDC properties
     156             :             );
     157             : 
     158           1 :     event.setProperty(P_SESSION, id(sd.getSessionId()));
     159           1 :     event.setProperty(P_USER_NAME, sd.getUsername());
     160             : 
     161           1 :     final String error = sd.getAuthenticationError();
     162           1 :     if (error != null) {
     163           1 :       event.setProperty(P_STATUS, error);
     164             :     }
     165           1 :     if (async != null) {
     166           1 :       async.append(event);
     167             :     }
     168           1 :     audit(null, "FAIL", "AUTH");
     169           1 :   }
     170             : 
     171             :   void onExecute(DispatchCommand dcmd, int exitValue, SshSession sshSession) {
     172           9 :     onExecute(dcmd, exitValue, sshSession, null);
     173           9 :   }
     174             : 
     175             :   void onExecute(DispatchCommand dcmd, int exitValue, SshSession sshSession, String message) {
     176           9 :     final Context ctx = context.get();
     177           9 :     ctx.finish();
     178             : 
     179           9 :     String cmd = extractWhat(dcmd);
     180             : 
     181           9 :     final LoggingEvent event = log(cmd);
     182           9 :     event.setProperty(P_WAIT, ctx.getWait() + "ms");
     183           9 :     event.setProperty(P_EXEC, ctx.getExec() + "ms");
     184           9 :     event.setProperty(P_TOTAL_CPU, ctx.getTotalCpu() + "ms");
     185           9 :     event.setProperty(P_USER_CPU, ctx.getUserCpu() + "ms");
     186           9 :     event.setProperty(P_MEMORY, String.valueOf(ctx.getAllocatedMemory()));
     187             : 
     188             :     final String status;
     189           9 :     switch (exitValue) {
     190             :       case BaseCommand.STATUS_CANCEL:
     191           5 :         status = "killed";
     192           5 :         break;
     193             : 
     194             :       case BaseCommand.STATUS_NOT_FOUND:
     195           0 :         status = "not-found";
     196           0 :         break;
     197             : 
     198             :       case BaseCommand.STATUS_NOT_ADMIN:
     199           1 :         status = "not-admin";
     200           1 :         break;
     201             : 
     202             :       default:
     203           9 :         status = String.valueOf(exitValue);
     204             :         break;
     205             :     }
     206           9 :     event.setProperty(P_STATUS, status);
     207           9 :     String peerAgent = sshSession.getPeerAgent();
     208           9 :     if (peerAgent != null) {
     209           2 :       event.setProperty(P_AGENT, peerAgent);
     210             :     }
     211             : 
     212           9 :     if (message != null) {
     213           3 :       event.setProperty(P_MESSAGE, message);
     214             :     }
     215             : 
     216           9 :     if (async != null) {
     217           4 :       async.append(event);
     218             :     }
     219           9 :     audit(context.get(), status, dcmd);
     220           9 :   }
     221             : 
     222             :   private ListMultimap<String, ?> extractParameters(DispatchCommand dcmd) {
     223           9 :     if (dcmd == null) {
     224           0 :       return MultimapBuilder.hashKeys(0).arrayListValues(0).build();
     225             :     }
     226           9 :     String[] cmdArgs = dcmd.getArguments();
     227           9 :     String paramName = null;
     228           9 :     int argPos = 0;
     229           9 :     ListMultimap<String, String> parms = MultimapBuilder.hashKeys().arrayListValues().build();
     230           9 :     for (int i = 2; i < cmdArgs.length; i++) {
     231           5 :       String arg = cmdArgs[i];
     232             :       // -- stop parameters parsing
     233           5 :       if (arg.equals("--")) {
     234           1 :         for (i++; i < cmdArgs.length; i++) {
     235           1 :           parms.put("$" + argPos++, cmdArgs[i]);
     236             :         }
     237             :         break;
     238             :       }
     239             :       // --param=value
     240           5 :       int eqPos = arg.indexOf('=');
     241           5 :       if (arg.startsWith("--") && eqPos > 0) {
     242           1 :         parms.put(arg.substring(0, eqPos), arg.substring(eqPos + 1));
     243           1 :         continue;
     244             :       }
     245             :       // -p value or --param value
     246           5 :       if (arg.startsWith("-")) {
     247           3 :         if (paramName != null) {
     248           1 :           parms.put(paramName, null);
     249             :         }
     250           3 :         paramName = arg;
     251           3 :         continue;
     252             :       }
     253             :       // value
     254           5 :       if (paramName == null) {
     255           5 :         parms.put("$" + argPos++, arg);
     256             :       } else {
     257           3 :         parms.put(paramName, arg);
     258           3 :         paramName = null;
     259             :       }
     260             :     }
     261           9 :     if (paramName != null) {
     262           2 :       parms.put(paramName, null);
     263             :     }
     264           9 :     return parms;
     265             :   }
     266             : 
     267             :   void onLogout() {
     268          17 :     LoggingEvent entry = log("LOGOUT");
     269          17 :     if (async != null) {
     270           5 :       async.append(entry);
     271             :     }
     272          17 :     audit(context.get(), "0", "LOGOUT");
     273          17 :   }
     274             : 
     275             :   private LoggingEvent log(String msg) {
     276          17 :     final SshSession sd = session.get();
     277          17 :     final CurrentUser user = sd.getUser();
     278             : 
     279          17 :     final LoggingEvent event =
     280             :         new LoggingEvent( //
     281          17 :             Logger.class.getName(), // fqnOfCategoryClass
     282             :             log, // logger
     283          17 :             TimeUtil.nowMs(), // when
     284             :             Level.INFO, // level
     285             :             msg, // message text
     286          17 :             Thread.currentThread().getName(), // thread name
     287             :             null, // exception information
     288             :             null, // current NDC string
     289             :             null, // caller location
     290             :             null // MDC properties
     291             :             );
     292             : 
     293          17 :     event.setProperty(P_SESSION, id(sd.getSessionId()));
     294             : 
     295          17 :     String userName = "-";
     296          17 :     String accountId = "-";
     297             : 
     298          17 :     if (user != null && user.isIdentifiedUser()) {
     299          17 :       IdentifiedUser u = user.asIdentifiedUser();
     300          17 :       userName = u.getUserName().orElse(null);
     301          17 :       accountId = "a/" + u.getAccountId().toString();
     302             : 
     303          17 :     } else if (user instanceof PeerDaemonUser) {
     304           1 :       userName = PeerDaemonUser.USER_NAME;
     305             :     }
     306             : 
     307          17 :     event.setProperty(P_USER_NAME, userName);
     308          17 :     event.setProperty(P_ACCOUNT_ID, accountId);
     309             : 
     310          17 :     return event;
     311             :   }
     312             : 
     313             :   private static String id(int id) {
     314          17 :     return HexFormat.fromInt(id);
     315             :   }
     316             : 
     317             :   void audit(Context ctx, Object result, String cmd) {
     318          17 :     audit(ctx, result, cmd, null);
     319          17 :   }
     320             : 
     321             :   void audit(Context ctx, Object result, DispatchCommand cmd) {
     322           9 :     audit(ctx, result, extractWhat(cmd), extractParameters(cmd));
     323           9 :   }
     324             : 
     325             :   private void audit(Context ctx, Object result, String cmd, ListMultimap<String, ?> params) {
     326             :     String sessionId;
     327             :     CurrentUser currentUser;
     328             :     long created;
     329          17 :     if (ctx == null) {
     330           1 :       sessionId = null;
     331           1 :       currentUser = null;
     332           1 :       created = TimeUtil.nowMs();
     333             :     } else {
     334          17 :       SshSession session = ctx.getSession();
     335          17 :       sessionId = HexFormat.fromInt(session.getSessionId());
     336          17 :       currentUser = session.getUser();
     337          17 :       created = ctx.getCreated();
     338             :     }
     339          17 :     auditService.dispatch(new SshAuditEvent(sessionId, currentUser, cmd, created, params, result));
     340          17 :   }
     341             : 
     342             :   private String extractWhat(DispatchCommand dcmd) {
     343           9 :     if (dcmd == null) {
     344           0 :       return "Command was already destroyed";
     345             :     }
     346           9 :     StringBuilder commandName = new StringBuilder(dcmd.getCommandName());
     347           9 :     String[] args = dcmd.getArguments();
     348           9 :     for (int i = 1; i < args.length; i++) {
     349           9 :       commandName.append(".").append(args[i]);
     350             :     }
     351           9 :     return commandName.toString();
     352             :   }
     353             : 
     354             :   @Override
     355             :   public Multimap<UpdateResult, ConfigUpdateEntry> configUpdated(ConfigUpdatedEvent event) {
     356           0 :     ConfigKey sshdRequestLog = ConfigKey.create("sshd", "requestLog");
     357           0 :     if (!event.isValueUpdated(sshdRequestLog)) {
     358           0 :       return ConfigUpdatedEvent.NO_UPDATES;
     359             :     }
     360             :     boolean stateUpdated;
     361             :     try {
     362           0 :       boolean enabled = event.getNewConfig().getBoolean("sshd", "requestLog", true);
     363           0 :       if (enabled) {
     364           0 :         stateUpdated = enableLogging();
     365             :       } else {
     366           0 :         stateUpdated = disableLogging();
     367             :       }
     368           0 :       return stateUpdated ? event.accept(sshdRequestLog) : ConfigUpdatedEvent.NO_UPDATES;
     369           0 :     } catch (IllegalArgumentException iae) {
     370           0 :       return event.reject(sshdRequestLog);
     371             :     }
     372             :   }
     373             : }