src/osquery/logger/logger.cpp

   1 /**
   2  *  Copyright (c) 2014-present, Facebook, Inc.
   3  *  All rights reserved.
   4  *
   5  *  This source code is licensed in accordance with the terms specified in
   6  *  the LICENSE file found in the root directory of this source tree.
   7  */
   8
   9 #ifndef WIN32
  10 #include <syslog.h>
  11 #endif
  12
  13 #include <algorithm>
  14 #include <future>
  15 #include <queue>
  16 #include <thread>
  17
  18 #include <boost/noncopyable.hpp>
  19
  20 #include <osquery/data_logger.h>
  21 #include <osquery/plugins/logger.h>
  22 #include <osquery/registry_factory.h>
  23
  24 #include <osquery/utils/conversions/split.h>
  25 #include <osquery/utils/json/json.h>
  26 #include <osquery/utils/system/time.h>
  27
  28 namespace rj = rapidjson;
  29
  30 namespace osquery {
  31
  32 CREATE_REGISTRY(LoggerPlugin, "logger");
  33
  34 /**
  35  * @brief A custom Glog log sink for forwarding or buffering status logs.
  36  *
  37  * This log sink has two modes, it can buffer Glog status logs until an osquery
  38  * logger is initialized or forward Glog status logs to an initialized and
  39  * appropriate logger. The appropriateness is determined by the logger when its
  40  * LoggerPlugin::init method is called. If the `init` method returns success
  41  * then a BufferedLogSink will start forwarding status logs to
  42  * LoggerPlugin::logStatus.
  43  *
  44  * This facility will start buffering when first used and stop buffering
  45  * (aka remove itself as a Glog sink) using the exposed APIs. It will live
  46  * throughout the life of the process for two reasons: (1) It makes sense when
  47  * the active logger plugin is handling Glog status logs and (2) it must remove
  48  * itself as a Glog target.
  49  */
  50 class BufferedLogSink : public google::LogSink, private boost::noncopyable {
  51  public:
  52   /// We create this as a Singleton for proper disable/shutdown.
  53   static BufferedLogSink& get();
  54
  55   /// The Glog-API LogSink call-in method.
  56   void send(google::LogSeverity severity,
  57             const char* full_filename,
  58             const char* base_filename,
  59             int line,
  60             const struct ::tm* tm_time,
  61             const char* message,
  62             size_t message_len) override;
  63
  64   /// Pop from the aync sender queue and wait for one send to complete.
  65   void WaitTillSent() override;
  66
  67  public:
  68   /// Accessor/mutator to dump all of the buffered logs.
  69   std::vector<StatusLogLine>& dump();
  70
  71   /// Add the buffered log sink to Glog.
  72   void enable();
  73
  74   /// Start the Buffered Sink, without enabling forwarding to loggers.
  75   void setUp();
  76
  77   /**
  78    * @brief Add a logger plugin that should receive status updates.
  79    *
  80    * Since the logger may support multiple active logger plugins the sink
  81    * will keep track of those plugins that returned success after ::init.
  82    * This list of plugins will received forwarded messages from the sink.
  83    *
  84    * This list is important because sending logs to plugins that also use
  85    * and active Glog Sink (supports multiple) will create a logging loop.
  86    */
  87   void addPlugin(const std::string& name);
  88
  89   /// Clear the sinks list, clear the named plugins added by addPlugin.s
  90   void resetPlugins();
  91
  92   /// Retrieve the list of enabled plugins that should have logs forwarded.
  93   const std::vector<std::string>& enabledPlugins() const;
  94
  95  public:
  96   /// Queue of sender functions that relay status logs to all plugins.
  97   std::queue<std::future<void>> senders;
  98
  99  public:
 100   BufferedLogSink(BufferedLogSink const&) = delete;
 101   void operator=(BufferedLogSink const&) = delete;
 102
 103  private:
 104   /// Create the log sink as buffering or forwarding.
 105   BufferedLogSink() = default;
 106
 107   /// Stop the log sink.
 108   ~BufferedLogSink();
 109
 110  private:
 111   /// Intermediate log storage until an osquery logger is initialized.
 112   std::vector<StatusLogLine> logs_;
 113
 114   /**
 115    * @Brief Is the logger temporarily disabled.
 116    *
 117    * The Google Log Sink will still be active, but the send method also checks
 118    * enabled and drops log lines to the flood if the forwarder is not enabled.
 119    */
 120   std::atomic<bool> enabled_{false};
 121
 122   /// Track multiple loggers that should receive sinks from the send forwarder.
 123   std::vector<std::string> sinks_;
 124 };
 125
 126 /// Mutex protecting accesses to buffered status logs.
 127 Mutex kBufferedLogSinkLogs;
 128
 129 /// Mutex protecting queued status log futures.
 130 Mutex kBufferedLogSinkSenders;
 131
 132 static void serializeIntermediateLog(const std::vector<StatusLogLine>& log,
 133                                      PluginRequest& request) {
 134   auto doc = JSON::newArray();
 135   for (const auto& i : log) {
 136     auto line = doc.getObject();
 137     doc.add("s", static_cast<int>(i.severity), line);
 138     doc.addRef("f", i.filename, line);
 139     doc.add("i", i.line, line);
 140     doc.addRef("m", i.message, line);
 141     doc.addRef("h", i.identifier, line);
 142     doc.addRef("c", i.calendar_time, line);
 143     doc.add("u", i.time, line);
 144     doc.push(line);
 145   }
 146
 147   doc.toString(request["log"]);
 148 }
 149
 150 void initStatusLogger(const std::string& name, bool init_glog) {
 151   // Start the logging, and announce the daemon is starting.
 152   if (init_glog) {
 153     google::InitGoogleLogging(name.c_str());
 154   }
 155 }
 156
 157 void initLogger(const std::string& name) {
 158   BufferedLogSink::get().resetPlugins();
 159
 160   bool forward = false;
 161   PluginRequest init_request = {{"init", name}};
 162   PluginRequest features_request = {{"action", "features"}};
 163   auto logger_plugin = RegistryFactory::get().getActive("logger");
 164   // Allow multiple loggers, make sure each is accessible.
 165   for (const auto& logger : osquery::split(logger_plugin, ",")) {
 166     if (!RegistryFactory::get().exists("logger", logger)) {
 167       continue;
 168     }
 169
 170     Registry::call("logger", logger, init_request);
 171     auto status = Registry::call("logger", logger, features_request);
 172     if ((status.getCode() & LOGGER_FEATURE_LOGSTATUS) > 0) {
 173       // Glog status logs are forwarded to logStatus.
 174       forward = true;
 175       // To support multiple plugins we only add the names of plugins that
 176       // return a success status after initialization.
 177       BufferedLogSink::get().addPlugin(logger);
 178     }
 179   }
 180
 181   if (forward) {
 182     // Begin forwarding after all plugins have been set up.
 183     BufferedLogSink::get().enable();
 184     relayStatusLogs(true);
 185   }
 186 }
 187
 188 BufferedLogSink& BufferedLogSink::get() {
 189   static BufferedLogSink sink;
 190   return sink;
 191 }
 192
 193 void BufferedLogSink::setUp() {
 194   google::AddLogSink(&get());
 195 }
 196
 197 void BufferedLogSink::enable() {
 198   enabled_ = true;
 199 }
 200
 201 void BufferedLogSink::send(google::LogSeverity severity,
 202                            const char* full_filename,
 203                            const char* base_filename,
 204                            int line,
 205                            const struct ::tm* tm_time,
 206                            const char* message,
 207                            size_t message_len) {
 208   // WARNING, be extremely careful when accessing data here.
 209   // This should not cause any persistent storage or logging actions.
 210   {
 211     WriteLock lock(kBufferedLogSinkLogs);
 212     logs_.push_back({(StatusLogSeverity)severity,
 213                      std::string(base_filename),
 214                      static_cast<size_t>(line),
 215                      std::string(message, message_len),
 216                      toAsciiTimeUTC(tm_time),
 217                      toUnixTime(tm_time),
 218                      std::string()});
 219   }
 220 }
 221
 222 void BufferedLogSink::WaitTillSent() {
 223   std::future<void> first;
 224
 225   {
 226     WriteLock lock(kBufferedLogSinkSenders);
 227     if (senders.empty()) {
 228       return;
 229     }
 230     first = std::move(senders.back());
 231     senders.pop();
 232   }
 233
 234   first.wait();
 235 }
 236
 237 std::vector<StatusLogLine>& BufferedLogSink::dump() {
 238   return logs_;
 239 }
 240
 241 void BufferedLogSink::addPlugin(const std::string& name) {
 242   sinks_.push_back(name);
 243 }
 244
 245 void BufferedLogSink::resetPlugins() {
 246   sinks_.clear();
 247 }
 248
 249 const std::vector<std::string>& BufferedLogSink::enabledPlugins() const {
 250   return sinks_;
 251 }
 252
 253 BufferedLogSink::~BufferedLogSink() {
 254   enabled_ = false;
 255 }
 256
 257 Status logString(const std::string& message, const std::string& category) {
 258   return logString(
 259       message, category, RegistryFactory::get().getActive("logger"));
 260 }
 261
 262 Status logString(const std::string& message,
 263                  const std::string& category,
 264                  const std::string& receiver) {
 265   Status status;
 266   for (const auto& logger : osquery::split(receiver, ",")) {
 267     if (Registry::get().exists("logger", logger, true)) {
 268       auto plugin = Registry::get().plugin("logger", logger);
 269       auto logger_plugin = std::dynamic_pointer_cast<LoggerPlugin>(plugin);
 270       status = logger_plugin->logString(message);
 271     } else {
 272       status = Registry::call(
 273           "logger", logger, {{"string", message}, {"category", category}});
 274     }
 275   }
 276   return status;
 277 }
 278
 279 namespace {
 280 const std::string kTotalQueryCounterMonitorPath("query.total.count");
 281 }
 282
 283 Status logQueryLogItem(const QueryLogItem& results) {
 284   return logQueryLogItem(results, RegistryFactory::get().getActive("logger"));
 285 }
 286
 287 Status logQueryLogItem(const QueryLogItem& results,
 288                        const std::string& receiver) {
 289   std::vector<std::string> json_items;
 290   Status status;
 291   std::string json;
 292   status = serializeQueryLogItemJSON(results, json);
 293   json_items.emplace_back(json);
 294
 295   if (!status.ok()) {
 296     return status;
 297   }
 298
 299   for (const auto& json : json_items) {
 300     status = logString(json, "event", receiver);
 301   }
 302   return status;
 303 }
 304
 305 Status logSnapshotQuery(const QueryLogItem& item) {
 306   std::vector<std::string> json_items;
 307   Status status;
 308   std::string json;
 309   status = serializeQueryLogItemJSON(item, json);
 310   json_items.emplace_back(json);
 311
 312   if (!status.ok()) {
 313     return status;
 314   }
 315
 316   for (const auto& json : json_items) {
 317     auto receiver = RegistryFactory::get().getActive("logger");
 318     for (const auto& logger : osquery::split(receiver, ",")) {
 319       if (Registry::get().exists("logger", logger, true)) {
 320         auto plugin = Registry::get().plugin("logger", logger);
 321         auto logger_plugin = std::dynamic_pointer_cast<LoggerPlugin>(plugin);
 322         status = logger_plugin->logSnapshot(json);
 323       } else {
 324         status = Registry::call("logger", logger, {{"snapshot", json}});
 325       }
 326     }
 327   }
 328
 329   return status;
 330 }
 331
 332 size_t queuedStatuses() {
 333   ReadLock lock(kBufferedLogSinkLogs);
 334   return BufferedLogSink::get().dump().size();
 335 }
 336
 337 size_t queuedSenders() {
 338   ReadLock lock(kBufferedLogSinkSenders);
 339   return BufferedLogSink::get().senders.size();
 340 }
 341
 342 void relayStatusLogs(bool async) {
 343   {
 344     ReadLock lock(kBufferedLogSinkLogs);
 345     if (BufferedLogSink::get().dump().size() == 0) {
 346       return;
 347     }
 348   }
 349
 350   auto sender = ([]() {
 351     auto identifier = getHostIdentifier();
 352
 353     // Construct a status log plugin request.
 354     PluginRequest request = {{"status", "true"}};
 355     {
 356       WriteLock lock(kBufferedLogSinkLogs);
 357       auto& status_logs = BufferedLogSink::get().dump();
 358       for (auto& log : status_logs) {
 359         // Copy the host identifier into each status log.
 360         log.identifier = identifier;
 361       }
 362
 363       serializeIntermediateLog(status_logs, request);
 364
 365       // Flush the buffered status logs.
 366       status_logs.clear();
 367     }
 368
 369     auto logger_plugin = RegistryFactory::get().getActive("logger");
 370     for (const auto& logger : osquery::split(logger_plugin, ",")) {
 371       auto& enabled = BufferedLogSink::get().enabledPlugins();
 372       if (std::find(enabled.begin(), enabled.end(), logger) != enabled.end()) {
 373         // Skip the registry's logic, and send directly to the core's logger.
 374         PluginResponse response;
 375         Registry::call("logger", logger, request, response);
 376       }
 377     }
 378   });
 379
 380   if (async) {
 381     sender();
 382   } else {
 383     std::packaged_task<void()> task(std::move(sender));
 384     auto result = task.get_future();
 385     std::thread(std::move(task)).detach();
 386
 387     // Lock accesses to the sender queue.
 388     WriteLock lock(kBufferedLogSinkSenders);
 389     BufferedLogSink::get().senders.push(std::move(result));
 390   }
 391 }
 392
 393 void systemLog(const std::string& line) {
 394 #ifndef WIN32
 395   syslog(LOG_NOTICE, "%s", line.c_str());
 396 #endif
 397 }
 398 }