// Copyright 2013 Google Inc. All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//      http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
//
// Author: bvb@google.com (Ben VanBerkum)
// Author: sligocki@google.com (Shawn Ligocki)

#include "pagespeed/kernel/util/statistics_logger.h"

#include <cstddef>
#include <map>
#include <memory>
#include <set>
#include <utility>                      // for pair
#include <vector>

#include "pagespeed/kernel/base/abstract_mutex.h"
#include "pagespeed/kernel/base/basictypes.h"
#include "pagespeed/kernel/base/escaping.h"
#include "pagespeed/kernel/base/file_writer.h"
#include "pagespeed/kernel/base/file_system.h"
#include "pagespeed/kernel/base/message_handler.h"
#include "pagespeed/kernel/base/statistics.h"
#include "pagespeed/kernel/base/string.h"
#include "pagespeed/kernel/base/string_util.h"
#include "pagespeed/kernel/base/timer.h"
#include "pagespeed/kernel/base/writer.h"
#include "pagespeed/kernel/html/html_keywords.h"

namespace net_instaweb {

namespace {

// Note that some of the statistics named below are really
// UpDownCounters.  For now, we don't segregate them, but we just
// figure out at initialization time which is which.

// Variables used in /pagespeed_console. These will all be logged and
// are the default set of variables sent back in JSON requests.
const char* const kConsoleVars[] = {
  "serf_fetch_failure_count", "serf_fetch_request_count",
  "resource_url_domain_rejections", "resource_url_domain_acceptances",
  "num_cache_control_not_rewritable_resources",
  "num_cache_control_rewritable_resources",
  "cache_backend_misses", "cache_backend_hits", "cache_expirations",
  "css_filter_parse_failures", "css_filter_blocks_rewritten",
  "javascript_minification_failures", "javascript_blocks_minified",
  "image_rewrites", "image_rewrites_dropped_nosaving_resize",
  "image_rewrites_dropped_nosaving_noresize",
  "image_norewrites_high_resolution",
  "image_rewrites_dropped_decode_failure",
  "image_rewrites_dropped_server_write_fail",
  "image_rewrites_dropped_mime_type_unknown",
  "image_norewrites_high_resolution",
  "css_combine_opportunities", "css_file_count_reduction",
};

// Other variables we want to log.
const char* const kOtherLoggedVars[] = {
  // Variables used by /mod_pagespeed_temp_statistics_graphs
  // Note: It's fine that there are duplicates here.
  // TODO(sligocki): Remove this in favor of the /pagespeed_console vars.
  // Should we also add other stats for future/other use?
  "num_flushes", "cache_hits", "cache_misses",
  "num_fallback_responses_served", "slurp_404_count", "page_load_count",
  "total_page_load_ms", "num_rewrites_executed", "num_rewrites_dropped",
  "resource_404_count", "serf_fetch_request_count",
  "serf_fetch_bytes_count", "image_ongoing_rewrites",
  "javascript_total_bytes_saved", "css_filter_total_bytes_saved",
  "image_rewrite_total_bytes_saved", "image_norewrites_high_resolution",
  "image_rewrites_dropped_due_to_load", "image_rewrites_dropped_intentionally",
  "flatten_imports_charset_mismatch", "flatten_imports_invalid_url",
  "flatten_imports_limit_exceeded", "flatten_imports_minify_failed",
  "flatten_imports_recursion", "css_filter_parse_failures",
  "converted_meta_tags", "javascript_minification_failures",
};

const char* const kGraphsVars[] = {
  // Variables used in /pagespeed_admin/graphs.
  // Note: It's fine that some variables here are already listed above.
  "pcache-cohorts-dom_deletes", "pcache-cohorts-beacon_cohort_misses",
  "pcache-cohorts-dom_inserts", "pcache-cohorts-dom_misses",
  "pcache-cohorts-beacon_cohort_deletes", "pcache-cohorts-beacon_cohort_hits",
  "pcache-cohorts-beacon_cohort_inserts", "pcache-cohorts-dom_hits",
  "rewrite_cached_output_missed_deadline", "rewrite_cached_output_hits",
  "rewrite_cached_output_misses", "url_input_resource_hit",
  "url_input_resource_recent_fetch_failure", "serf_fetch_bytes_count",
  "url_input_resource_recent_uncacheable_miss",
  "url_input_resource_recent_uncacheable_failure",
  "url_input_resource_miss", "serf_fetch_request_count", "lru_cache_hits",
  "serf_fetch_time_duration_ms", "serf_fetch_cancel_count",
  "serf_fetch_timeout_count", "serf_fetch_failure_count", "http_bytes_fetched",
  "serf_fetch_active_count", "lru_cache_deletes", "serf_fetch_cert_errors",
  "lru_cache_inserts", "lru_cache_misses", "file_cache_bytes_freed_in_cleanup",
  "file_cache_cleanups", "file_cache_disk_checks", "file_cache_evictions",
  "file_cache_write_errors", "file_cache_deletes", "file_cache_hits",
  "file_cache_inserts", "file_cache_misses", "http_fetches",
  "http_approx_header_bytes_fetched", "image_rewrite_total_bytes_saved",
  "image_rewrite_total_original_bytes", "image_rewrite_uses",
  "image_rewrite_latency_total_ms", "image_rewrites_dropped_intentionally",
  "image_rewrites_dropped_decode_failure", "cache_misses", "ipro_not_in_cache",
  "image_rewrites_dropped_mime_type_unknown", "cache_fallbacks",
  "image_rewrites_dropped_server_write_fail", "cache_inserts",
  "image_rewrites_dropped_nosaving_resize", "cache_flush_timestamp_ms",
  "image_rewrites_dropped_nosaving_noresize", "ipro_served",
  "ipro_not_rewritable", "ipro_recorder_resources", "cache_deletes",
  "ipro_recorder_inserted_into_cache", "ipro_recorder_not_cacheable",
  "ipro_recorder_failed", "ipro_recorder_dropped_due_to_load",
  "ipro_recorder_dropped_due_to_size", "shm_cache_deletes", "shm_cache_hits",
  "shm_cache_inserts", "shm_cache_misses", "memcached_async_deletes",
  "memcached_async_hits", "memcached_async_inserts", "memcached_async_misses",
  "memcached_blocking_deletes", "memcached_blocking_hits", "cache_expirations",
  "memcached_blocking_inserts", "memcached_blocking_misses", "cache_time_us",
  "cache_hits", "cache_backend_hits", "cache_backend_misses",
  "cache_extensions", "cache_batcher_dropped_gets", "cache_flush_count",
};

}  // namespace

StatisticsLogger::StatisticsLogger(
    int64 update_interval_ms, int64 max_logfile_size_kb,
    const StringPiece& logfile_name, MutexedScalar* last_dump_timestamp,
    MessageHandler* message_handler, Statistics* stats,
    FileSystem* file_system, Timer* timer)
    : last_dump_timestamp_(last_dump_timestamp),
      message_handler_(message_handler),
      statistics_(stats),
      file_system_(file_system),
      timer_(timer),
      update_interval_ms_(update_interval_ms),
      max_logfile_size_kb_(max_logfile_size_kb) {
  logfile_name.CopyToString(&logfile_name_);
}

StatisticsLogger::~StatisticsLogger() {
}

void StatisticsLogger::Init() {
  variables_to_log_.clear();

  // List of statistics to log.
  for (int i = 0, n = arraysize(kConsoleVars); i < n; ++i) {
    AddVariable(kConsoleVars[i]);
  }
  for (int i = 0, n = arraysize(kOtherLoggedVars); i < n; ++i) {
    AddVariable(kOtherLoggedVars[i]);
  }
  for (int i = 0, n = arraysize(kGraphsVars); i < n; ++i) {
    AddVariable(kGraphsVars[i]);
  }
}

void StatisticsLogger::InitStatsForTest() {
  // List of statistics to log.
  for (int i = 0, n = arraysize(kConsoleVars); i < n; ++i) {
    statistics_->AddVariable(kConsoleVars[i]);
  }
  for (int i = 0, n = arraysize(kOtherLoggedVars); i < n; ++i) {
    statistics_->AddVariable(kOtherLoggedVars[i]);
  }
  for (int i = 0, n = arraysize(kGraphsVars); i < n; ++i) {
    statistics_->AddVariable(kGraphsVars[i]);
  }
  Init();
}

void StatisticsLogger::AddVariable(StringPiece var_name) {
  VariableOrCounter var_or_counter;
  var_or_counter.first = statistics_->FindVariable(var_name);
  if (var_or_counter.first == NULL) {
    var_or_counter.second = statistics_->GetUpDownCounter(var_name);
  }
  variables_to_log_[var_name] = var_or_counter;
}

void StatisticsLogger::UpdateAndDumpIfRequired() {
  int64 current_time_ms = timer_->NowMs();
  AbstractMutex* mutex = last_dump_timestamp_->mutex();
  if (mutex == NULL) {
    return;
  }
  // Avoid blocking if the dump is already happening in another thread/process.
  if (mutex->TryLock()) {
    if (current_time_ms >=
        (last_dump_timestamp_->GetLockHeld() + update_interval_ms_)) {
      // It's possible we'll need to do some of the following here for
      // cross-process consistency:
      // - flush the logfile before unlock to force out buffered data
      FileSystem::OutputFile* statistics_log_file =
          file_system_->OpenOutputFileForAppend(
              logfile_name_.c_str(), message_handler_);
      if (statistics_log_file != NULL) {
        FileWriter statistics_writer(statistics_log_file);
        DumpConsoleVarsToWriter(current_time_ms, &statistics_writer);
        statistics_writer.Flush(message_handler_);
        file_system_->Close(statistics_log_file, message_handler_);

        // Trim logfile if it's over max size.
        TrimLogfileIfNeeded();
      } else {
        message_handler_->Message(kError,
                                  "Error opening statistics log file %s.",
                                  logfile_name_.c_str());
      }
      // Update timestamp regardless of file write so we don't hit the same
      // error many times in a row.
      last_dump_timestamp_->SetLockHeld(current_time_ms);
    }
    mutex->Unlock();
  }
}

void StatisticsLogger::DumpConsoleVarsToWriter(
    int64 current_time_ms, Writer* writer) {
  writer->Write(StringPrintf("timestamp: %s\n",
      Integer64ToString(current_time_ms).c_str()), message_handler_);

  for (VariableMap::const_iterator iter = variables_to_log_.begin();
       iter != variables_to_log_.end(); ++iter) {
    StringPiece var_name = iter->first;
    VariableOrCounter var_or_counter = iter->second;
    int64 val = (var_or_counter.first != NULL) ? var_or_counter.first->Get()
        : var_or_counter.second->Get();
    writer->Write(StrCat(var_name, ": ", Integer64ToString(val), "\n"),
                  message_handler_);
  }

  writer->Flush(message_handler_);
}

void StatisticsLogger::TrimLogfileIfNeeded() {
  int64 size_bytes;
  if (file_system_->Size(logfile_name_, &size_bytes, message_handler_) &&
      size_bytes > max_logfile_size_kb_ * 1024) {
    // TODO(sligocki): Rotate a set of logfiles and just delete the
    // oldest one each time instead of deleting the entire log.
    // NOTE: Update SharedMemStatisticsTestBase.TestLogfileTrimming when we
    // make this change so that it correctly tests the total log size.
    file_system_->RemoveFile(logfile_name_.c_str(), message_handler_);
  }
}

void StatisticsLogger::DumpJSON(
    bool dump_for_graphs, const StringSet& var_titles,
    int64 start_time, int64 end_time, int64 granularity_ms,
    Writer* writer, MessageHandler* message_handler) const {
  FileSystem::InputFile* log_file =
      file_system_->OpenInputFile(logfile_name_.c_str(), message_handler);
  if (log_file == NULL) {
    // If logfile_name_ represents a file that doesn't exist, OpenInputFile
    // logged an error and log_file will be null.  Return an empty json object.
    writer->Write("{}", message_handler);
    return;
  }
  VarMap parsed_var_data;
  std::vector<int64> list_of_timestamps;
  StatisticsLogfileReader reader(log_file, start_time, end_time,
                                 granularity_ms, message_handler);
  if (dump_for_graphs) {
    ParseDataForGraphs(&reader, &list_of_timestamps, &parsed_var_data);
  } else {
    ParseDataFromReader(var_titles, &reader, &list_of_timestamps,
                        &parsed_var_data);
  }
  PrintJSON(list_of_timestamps, parsed_var_data, writer, message_handler);
  file_system_->Close(log_file, message_handler);
}

void StatisticsLogger::ParseDataFromReader(
    const StringSet& var_titles,
    StatisticsLogfileReader* reader,
    std::vector<int64>* timestamps, VarMap* var_values) const {
  // curr_timestamp starts as 0 because we need to compare it to the first
  // timestamp pulled from the file. The current timestamp should always be
  // less than the timestamp after it due to the fact that the logfile dumps
  // data periodically. This makes sure that all timestamps are >= 0.
  int64 curr_timestamp = 0;
  // Stores data associated with current timestamp.
  GoogleString data;
  while (reader->ReadNextDataBlock(&curr_timestamp, &data)) {
    // Parse variable data.
    std::map<StringPiece, StringPiece> parsed_var_data;
    ParseVarDataIntoMap(data, &parsed_var_data);

    timestamps->push_back(curr_timestamp);
    // Push all variable values. Note: We only save the variables listed in
    // var_titles, the rest are disregarded.
    for (StringSet::const_iterator iter = var_titles.begin();
         iter != var_titles.end(); ++iter) {
      const GoogleString& var_title = *iter;

      std::map<StringPiece, StringPiece>::const_iterator value_iter =
          parsed_var_data.find(var_title);
      if (value_iter != parsed_var_data.end()) {
        (*var_values)[var_title].push_back(value_iter->second.as_string());
      } else {
        // If data is not available in this segment, we just push 0 as a place
        // holder. We must push something or else it will be ambiguous which
        // timestamp corresponds to which variable values.
        (*var_values)[var_title].push_back("0");
      }
    }
  }
}

void StatisticsLogger::ParseDataForGraphs(StatisticsLogfileReader* reader,
                                          std::vector<int64>* timestamps,
                                          VarMap* var_values) const {
  int64 curr_timestamp = 0;
  GoogleString data;
  while (reader->ReadNextDataBlock(&curr_timestamp, &data)) {
    std::map<StringPiece, StringPiece> parsed_var_data;
    ParseVarDataIntoMap(data, &parsed_var_data);
    timestamps->push_back(curr_timestamp);
    for (int i = 0, n = arraysize(kGraphsVars); i < n; ++i) {
      const GoogleString& var_title = kGraphsVars[i];
      std::map<StringPiece, StringPiece>::const_iterator value_iter =
          parsed_var_data.find(var_title);
      if (value_iter != parsed_var_data.end()) {
        value_iter->second.CopyToString(
            StringVectorAdd(&((*var_values)[var_title])));
      } else {
        (*var_values)[var_title].push_back("0");
      }
    }
  }
}

void StatisticsLogger::ParseVarDataIntoMap(
    StringPiece logfile_var_data,
    std::map<StringPiece, StringPiece>* parsed_var_data) const {
  std::vector<StringPiece> lines;
  SplitStringPieceToVector(logfile_var_data, "\n", &lines, true);
  for (size_t i = 0; i < lines.size(); ++i) {
    size_t end_index_of_name = lines[i].find_first_of(":");
    StringPiece var_name = lines[i].substr(0, end_index_of_name);
    StringPiece var_value_string = lines[i].substr(end_index_of_name + 2);
    (*parsed_var_data)[var_name] = var_value_string;
  }
}

void StatisticsLogger::PrintJSON(
    const std::vector<int64>& list_of_timestamps,
    const VarMap& parsed_var_data,
    Writer* writer, MessageHandler* message_handler) const {
  writer->Write("{", message_handler);
  writer->Write("\"timestamps\": [", message_handler);
  PrintTimestampListAsJSON(list_of_timestamps, writer, message_handler);
  writer->Write("],", message_handler);
  writer->Write("\"variables\": {", message_handler);
  PrintVarDataAsJSON(parsed_var_data, writer, message_handler);
  writer->Write("}", message_handler);
  writer->Write("}", message_handler);
}

void StatisticsLogger::PrintTimestampListAsJSON(
    const std::vector<int64>& list_of_timestamps, Writer* writer,
    MessageHandler* message_handler) const {
  for (size_t i = 0; i < list_of_timestamps.size(); ++i) {
    writer->Write(Integer64ToString(list_of_timestamps[i]), message_handler);
    if (i != list_of_timestamps.size() - 1) {
      writer->Write(", ", message_handler);
    }
  }
}

void StatisticsLogger::PrintVarDataAsJSON(
    const VarMap& parsed_var_data, Writer* writer,
    MessageHandler* message_handler) const {
  for (VarMap::const_iterator iterator =
      parsed_var_data.begin(); iterator != parsed_var_data.end();
      ++iterator) {
    StringPiece var_name = iterator->first;
    VariableInfo info = iterator->second;
    // If we are at the last entry in the map, we do not
    // want the trailing comma as per JSON format.
    if (iterator != parsed_var_data.begin()) {
      writer->Write(",", message_handler);
    }
    GoogleString html_name, json_name;
    HtmlKeywords::Escape(var_name, &html_name);
    EscapeToJsStringLiteral(html_name, true /* add_quotes*/, &json_name);

    writer->Write(json_name, message_handler);
    writer->Write(": [", message_handler);
    for (size_t i = 0; i < info.size(); ++i) {
      writer->Write(info[i], message_handler);
      // If we are at the last recorded variable, we do not want the
      // trailing comma as per JSON format.
      if (i != info.size() - 1) {
        writer->Write(", ", message_handler);
      }
    }
    writer->Write("]", message_handler);
  }
}

StatisticsLogfileReader::StatisticsLogfileReader(
    FileSystem::InputFile* file, int64 start_time, int64 end_time,
    int64 granularity_ms, MessageHandler* message_handler)
        : file_(file),
          start_time_(start_time),
          end_time_(end_time),
          granularity_ms_(granularity_ms),
          message_handler_(message_handler) {
}

StatisticsLogfileReader::~StatisticsLogfileReader() {
}

bool StatisticsLogfileReader::ReadNextDataBlock(int64* timestamp,
                                                GoogleString* data) {
  if (buffer_.size() < 1) {
    FeedBuffer();
  }
  size_t offset = 0;
  // The first line should always be "timestamp: xxx".
  // If it's not, we're done; otherwise, we grab the timestamp value.
  while (StringPiece(buffer_).substr(offset).starts_with("timestamp: ")) {
    int64 old_timestamp = *timestamp;
    // If the timestamp was cut off in the middle of the buffer, we need to
    // read more into the buffer.
    size_t newline_pos = BufferFind("\n", offset);
    // Separate the current timestamp from the rest of the data in the buffer.
    size_t timestamp_size = STATIC_STRLEN("timestamp: ");
    StringPiece timestamp_str = StringPiece(buffer_).substr(
        offset + timestamp_size, newline_pos - timestamp_size);
    StringToInt64(timestamp_str, timestamp);
    // Before ReadNextDataBlock returns, it finds the next occurrence of the
    // full string "timestamp: " so that it knows it contains the full data
    // block. It then separates the data block from the rest of the data,
    // meaning that "timestamp:  " should always be the first thing in the
    // buffer.
    size_t next_timestamp_pos = BufferFind("timestamp: ",
                                           offset + newline_pos + 1);
    // Check to make sure that this timestamp fits the criteria. If it doesn't,
    // the loop restarts.
    if (*timestamp >= start_time_ && *timestamp <= end_time_ &&
        *timestamp >= old_timestamp + granularity_ms_) {
      *data = buffer_.substr(newline_pos + 1,
                             next_timestamp_pos - (newline_pos + 1));
      buffer_.erase(0, next_timestamp_pos);
      return true;
    } else {
      *timestamp = old_timestamp;
      offset = next_timestamp_pos;
    }
  }
  return false;
}

// Finds the string constant search_for in the buffer, continually reading more
// into the buffer if search_for is not found and trying again. Returns the
// position of first occurrence of search_for. If search_for is not found,
// npos is returned.
size_t StatisticsLogfileReader::BufferFind(const char* search_for,
                                           size_t start_at) {
  size_t position = buffer_.find(search_for, start_at);
  while (position == buffer_.npos) {
    int read = FeedBuffer();
    if (read == 0) {
      return buffer_.npos;
    }
    position = buffer_.find(search_for,
                            buffer_.size() - read - strlen(search_for));
  }
  return position;
}

int StatisticsLogfileReader::FeedBuffer() {
  const int kChunkSize = 3000;
  char buf[kChunkSize];
  int num_read = file_->Read(buf, kChunkSize, message_handler_);
  StrAppend(&buffer_, StringPiece(buf, num_read));
  return num_read;
}

}  // namespace net_instaweb