1 /*
  2  * Copyright (c) 2021, Amazon.com, Inc. All rights reserved.
  3  * Copyright (c) 2015, 2021, Oracle and/or its affiliates. All rights reserved.
  4  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  5  *
  6  * This code is free software; you can redistribute it and/or modify it
  7  * under the terms of the GNU General Public License version 2 only, as
  8  * published by the Free Software Foundation.
  9  *
 10  * This code is distributed in the hope that it will be useful, but WITHOUT
 11  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
 12  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
 13  * version 2 for more details (a copy is included in the LICENSE file that
 14  * accompanied this code).
 15  *
 16  * You should have received a copy of the GNU General Public License version
 17  * 2 along with this work; if not, write to the Free Software Foundation,
 18  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
 19  *
 20  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
 21  * or visit www.oracle.com if you need additional information or have any
 22  * questions.
 23  *
 24  */
 25 
 26 #include "precompiled.hpp"
 27 #include "jvm.h"
 28 #include "logging/logConfiguration.hpp"
 29 #include "logging/logFileStreamOutput.hpp"
 30 #include "runtime/arguments.hpp"
 31 #include "runtime/os.inline.hpp"
 32 #include "runtime/perfData.inline.hpp"
 33 #include "utilities/globalDefinitions.hpp"
 34 #include "utilities/defaultStream.hpp"
 35 
 36 #include "gc/shenandoah/shenandoahLogFileOutput.hpp"
 37 
 38 const char* const ShenandoahLogFileOutput::Prefix = "file=";
 39 const char* const ShenandoahLogFileOutput::FileOpenMode = "w+";
 40 const char* const ShenandoahLogFileOutput::PidFilenamePlaceholder = "%p";
 41 const char* const ShenandoahLogFileOutput::TimestampFilenamePlaceholder = "%t";
 42 const char* const ShenandoahLogFileOutput::TimestampFormat = "%Y-%m-%d_%H-%M-%S";
 43 char        ShenandoahLogFileOutput::_pid_str[PidBufferSize];
 44 char        ShenandoahLogFileOutput::_vm_start_time_str[StartTimeBufferSize];
 45 
 46 #define WRITE_LOG_WITH_RESULT_CHECK(op, total)                \
 47 {                                                             \
 48   int result = op;                                            \
 49   if (result < 0) {                                           \
 50     if (!_write_error_is_shown) {                             \
 51       jio_fprintf(defaultStream::error_stream(),              \
 52                   "Could not write log: %s\n", name());       \
 53       jio_fprintf(_stream, "\nERROR: Could not write log\n"); \
 54       _write_error_is_shown = true;                           \
 55       return -1;                                              \
 56     }                                                         \
 57   }                                                           \
 58   total += result;                                            \
 59 }
 60 
 61 ShenandoahLogFileOutput::ShenandoahLogFileOutput(const char* name, jlong vm_start_time)
 62   : _name(os::strdup_check_oom(name, mtLogging)), _file_name(NULL), _stream(NULL) {
 63   set_file_name_parameters(vm_start_time);
 64   _file_name = make_file_name(name, _pid_str, _vm_start_time_str);
 65 }
 66 
 67 ShenandoahLogFileOutput::~ShenandoahLogFileOutput() {
 68   if (_stream != NULL) {
 69     if (fclose(_stream) != 0) {
 70       jio_fprintf(defaultStream::error_stream(), "Could not close log file '%s' (%s).\n",
 71                   _file_name, os::strerror(errno));
 72     }
 73   }
 74   os::free(_file_name);
 75   os::free(const_cast<char*>(_name));
 76 }
 77 
 78 bool ShenandoahLogFileOutput::flush() {
 79   bool result = true;
 80   if (fflush(_stream) != 0) {
 81     if (!_write_error_is_shown) {
 82       jio_fprintf(defaultStream::error_stream(),
 83                   "Could not flush log: %s (%s (%d))\n", name(), os::strerror(errno), errno);
 84       jio_fprintf(_stream, "\nERROR: Could not flush log (%d)\n", errno);
 85       _write_error_is_shown = true;
 86     }
 87     result = false;
 88   }
 89   return result;
 90 }
 91 
 92 void ShenandoahLogFileOutput::initialize(outputStream* errstream) {
 93   _stream = os::fopen(_file_name, ShenandoahLogFileOutput::FileOpenMode);
 94   if (_stream == NULL) {
 95     errstream->print_cr("Error opening log file '%s': %s", _file_name, os::strerror(errno));
 96     _file_name = make_file_name("./shenandoahSnapshots_pid%p.log", _pid_str, _vm_start_time_str);
 97     _stream = os::fopen(_file_name, ShenandoahLogFileOutput::FileOpenMode);
 98     errstream->print_cr("Writing to default log file: %s", _file_name);
 99   }
100 }
101 
102 int ShenandoahLogFileOutput::write_snapshot(PerfLongVariable** regions,
103                                             PerfLongVariable* ts,
104                                             PerfLongVariable* status,
105                                             size_t num_regions,
106                                             size_t rs) {
107   int written = 0;
108   FileLocker flocker(_stream);
109   WRITE_LOG_WITH_RESULT_CHECK(jio_fprintf(_stream, "%lli %lli %u %u\n",
110                                           ts->get_value(),
111                                           status->get_value(),
112                                           num_regions,
113                                           rs),written);
114   if (num_regions > 0) {
115     WRITE_LOG_WITH_RESULT_CHECK(jio_fprintf(_stream, "%lli", regions[0]->get_value()), written);
116   }
117   for (uint i = 1; i < num_regions; ++i) {
118     WRITE_LOG_WITH_RESULT_CHECK(jio_fprintf(_stream, " %lli", regions[i]->get_value()), written);
119   }
120   jio_fprintf(_stream, "\n");
121   return flush() ? written : -1;
122 }
123 
124 void ShenandoahLogFileOutput::set_file_name_parameters(jlong vm_start_time) {
125   int res = jio_snprintf(_pid_str, sizeof(_pid_str), "%d", os::current_process_id());
126   assert(res > 0, "PID buffer too small");
127 
128   struct tm local_time;
129   time_t utc_time = vm_start_time / 1000;
130   os::localtime_pd(&utc_time, &local_time);
131   res = (int)strftime(_vm_start_time_str, sizeof(_vm_start_time_str), TimestampFormat, &local_time);
132   assert(res > 0, "VM start time buffer too small.");
133 }
134 
135 char* ShenandoahLogFileOutput::make_file_name(const char* file_name,
136                                               const char* pid_string,
137                                               const char* timestamp_string) {
138   char* result = NULL;
139 
140   // Lets start finding out if we have any %d and/or %t in the name.
141   // We will only replace the first occurrence of any placeholder
142   const char* pid = strstr(file_name, PidFilenamePlaceholder);
143   const char* timestamp = strstr(file_name, TimestampFilenamePlaceholder);
144 
145   if (pid == NULL && timestamp == NULL) {
146     // We found no place-holders, return the simple filename
147     return os::strdup_check_oom(file_name, mtLogging);
148   }
149 
150   // At least one of the place-holders were found in the file_name
151   const char* first = "";
152   size_t first_pos = SIZE_MAX;
153   size_t first_replace_len = 0;
154 
155   const char* second = "";
156   size_t second_pos = SIZE_MAX;
157   size_t second_replace_len = 0;
158 
159   // If we found a %p, then setup our variables accordingly
160   if (pid != NULL) {
161     if (timestamp == NULL || pid < timestamp) {
162       first = pid_string;
163       first_pos = pid - file_name;
164       first_replace_len = strlen(PidFilenamePlaceholder);
165     } else {
166       second = pid_string;
167       second_pos = pid - file_name;
168       second_replace_len = strlen(PidFilenamePlaceholder);
169     }
170   }
171 
172   if (timestamp != NULL) {
173     if (pid == NULL || timestamp < pid) {
174       first = timestamp_string;
175       first_pos = timestamp - file_name;
176       first_replace_len = strlen(TimestampFilenamePlaceholder);
177     } else {
178       second = timestamp_string;
179       second_pos = timestamp - file_name;
180       second_replace_len = strlen(TimestampFilenamePlaceholder);
181     }
182   }
183 
184   size_t first_len = strlen(first);
185   size_t second_len = strlen(second);
186 
187   // Allocate the new buffer, size it to hold all we want to put in there +1.
188   size_t result_len =  strlen(file_name) + first_len - first_replace_len + second_len - second_replace_len;
189   result = NEW_C_HEAP_ARRAY(char, result_len + 1, mtLogging);
190 
191   // Assemble the strings
192   size_t file_name_pos = 0;
193   size_t i = 0;
194   while (i < result_len) {
195     if (file_name_pos == first_pos) {
196       // We are in the range of the first placeholder
197       strcpy(result + i, first);
198       // Bump output buffer position with length of replacing string
199       i += first_len;
200       // Bump source buffer position to skip placeholder
201       file_name_pos += first_replace_len;
202     } else if (file_name_pos == second_pos) {
203       // We are in the range of the second placeholder
204       strcpy(result + i, second);
205       i += second_len;
206       file_name_pos += second_replace_len;
207     } else {
208       // Else, copy char by char of the original file
209       result[i] = file_name[file_name_pos++];
210       i++;
211     }
212   }
213   // Add terminating char
214   result[result_len] = '\0';
215   return result;
216 }