diff --git a/.gitignore b/.gitignore index 8f36ee7c2..26181d3dd 100644 --- a/.gitignore +++ b/.gitignore @@ -44,3 +44,7 @@ Testing .settings /bin/ + +.project +.cproject + diff --git a/README.md b/README.md index d9470b9f2..54b560080 100644 --- a/README.md +++ b/README.md @@ -7,3 +7,11 @@ A usable and honest profiler for the JVM. For documentation please refer to * [Download the Binary](http://insightfullogic.com/honest-profiler.zip) * [How to Build](https://github.com/RichardWarburton/honest-profiler/wiki/How-to-build) +UNITTEST_INCLUDE_DIRS="/usr/local/Cellar/unittest-cpp/2.0.0/include/UnitTest++/" UNITTEST_LIBRARIES="UnitTest++" cmake CMakeLists.txt + +[MAC] +# Use brew to install unittest++ + +# make sure unittest++ available to compliers : export paths +export LIBRARY_PATH=/usr/local/Cellar/unittest-cpp/2.0.0/lib/ +export CPLUS_INCLUDE_PATH="/usr/local/Cellar/unittest-cpp/2.0.0/include/" diff --git a/src/main/cpp/agent.cpp b/src/main/cpp/agent.cpp index 47b45b92b..4a3bef896 100644 --- a/src/main/cpp/agent.cpp +++ b/src/main/cpp/agent.cpp @@ -281,6 +281,10 @@ static void parseArguments(char *options, ConfigurationOptions &configuration) { configuration.samplingIntervalMax = atoi(value); } else if (strstr(key, "interval") == key) { configuration.samplingIntervalMin = configuration.samplingIntervalMax = atoi(value); + } else if (strstr(key, "rotateNum") == key) { + configuration.rotateNum = atoi(value); + } else if (strstr(key, "rotateSizeMB") == key) { + configuration.rotateSizeMB = atoi(value); } else if (strstr(key, "logPath") == key) { configuration.logFilePath.assign(value, STR_SIZE(value, next)); } else if (strstr(key, "start") == key) { diff --git a/src/main/cpp/globals.h b/src/main/cpp/globals.h index f83f2c232..c2e117bd9 100755 --- a/src/main/cpp/globals.h +++ b/src/main/cpp/globals.h @@ -25,6 +25,8 @@ void setProfiler(Profiler *p); const int DEFAULT_SAMPLING_INTERVAL = 1; const int DEFAULT_MAX_FRAMES_TO_CAPTURE = 128; const int MAX_FRAMES_TO_CAPTURE = 2048; +const int DEFAULT_ROTATE_SIZE_MB = 5; +const int DEFAULT_ROTATE_NUM = 5; #if defined(STATIC_ALLOCATION_ALLOCA) #define STATIC_ARRAY(NAME, TYPE, SIZE, MAXSZ) TYPE *NAME = (TYPE*)alloca((SIZE) * sizeof(TYPE)) @@ -41,6 +43,8 @@ char *safe_copy_string(const char *value, const char *next); struct ConfigurationOptions { /** Interval in microseconds */ int samplingIntervalMin, samplingIntervalMax; + /** RotateSize in MB */ + int rotateNum, rotateSizeMB; std::string logFilePath; std::string host; std::string port; @@ -50,6 +54,8 @@ struct ConfigurationOptions { ConfigurationOptions() : samplingIntervalMin(DEFAULT_SAMPLING_INTERVAL), samplingIntervalMax(DEFAULT_SAMPLING_INTERVAL), + rotateNum(DEFAULT_ROTATE_NUM), + rotateSizeMB(DEFAULT_ROTATE_SIZE_MB), logFilePath(""), host(""), port(""), @@ -60,6 +66,8 @@ struct ConfigurationOptions { ConfigurationOptions(const ConfigurationOptions &config) : samplingIntervalMin(config.samplingIntervalMin), samplingIntervalMax(config.samplingIntervalMax), + rotateNum(config.rotateNum), + rotateSizeMB(config.rotateSizeMB), logFilePath(config.logFilePath), host(config.host), port(config.port), diff --git a/src/main/cpp/log_writer.cpp b/src/main/cpp/log_writer.cpp index 489e16153..20bc2b6fc 100644 --- a/src/main/cpp/log_writer.cpp +++ b/src/main/cpp/log_writer.cpp @@ -1,7 +1,10 @@ -#include - #include "log_writer.h" +#include +#include +#include +#include + using std::copy; bool isLittleEndian() { @@ -12,49 +15,64 @@ bool isLittleEndian() { static bool IS_LITTLE_ENDIAN = isLittleEndian(); -LogWriter::LogWriter(std::string &fileName, jvmtiEnv *jvmti) : - file(fileName, std::ofstream::out | std::ofstream::binary), output_(this->file), +LogWriter::LogWriter(std::string &fileName, int rotateNum, int rotateSizeMB, jvmtiEnv *jvmti) : + fileName(fileName), + rotateNum(rotateNum), + rotateSize(rotateSizeMB * 1024 * 1024), + size(0), + file(NULL), + output_(NULL), frameInfoFoo(NULL), jvmti_(jvmti) { - if (output_.fail()) { + file = new std::ofstream(fileName, std::ofstream::out | std::ofstream::binary); + output_ = this->file; + if (output_->fail()) { // The JVM will still continue to run though; could call abort() to terminate the JVM abnormally. logError("ERROR: Failed to open file %s for writing\n", fileName.c_str()); } } -LogWriter::LogWriter(ostream &output, GetFrameInformation frameLookup, jvmtiEnv *jvmti) : - file(), output_(output), frameInfoFoo(frameLookup), jvmti_(jvmti) { +LogWriter::LogWriter(ostream &output, int rotateNum, int rotateSizeMB, GetFrameInformation frameLookup, jvmtiEnv *jvmti) : + fileName(), + rotateNum(rotateNum), + rotateSize(rotateSizeMB * 1024 * 1024), + size(0), + file(NULL), + output_(&output), + frameInfoFoo(frameLookup), + jvmti_(jvmti) { // Old interface for backward compatibility and testing purposes } template -void LogWriter::writeValue(const T &value) { +void LogWriter::writeValue(ostream & fout, const T &value) { if (IS_LITTLE_ENDIAN) { const char *data = reinterpret_cast(&value); for (int i = sizeof(value) - 1; i >= 0; i--) { - output_.put(data[i]); + fout.put(data[i]); } } else { - output_.write(reinterpret_cast(&value), sizeof(value)); + fout.write(reinterpret_cast(&value), sizeof(value)); } + size += sizeof(value); } static jint bci2line(jint bci, jvmtiLineNumberEntry *table, jint entry_count) { - jint line_number = -101; - if ( entry_count == 0 ) { - return line_number; - } - line_number = -102; + jint line_number = -101; + if ( entry_count == 0 ) { + return line_number; + } + line_number = -102; // We're looking for a line whose 'start_location' is nearest AND >= BCI - // We assume the table is sorted by 'start_location' + // We assume the table is sorted by 'start_location' // Do a binary search to quickly approximate 'start_index" in table - int half = entry_count >> 1; + int half = entry_count >> 1; int start_index = 0; while ( half > 0 ) { jint start_location = table[start_index + half].start_location; if ( bci > start_location ) { start_index = start_index + half; } else if ( bci == start_location ) { - // gotcha + // gotcha return table[start_index + half].line_number; } half = half >> 1; @@ -62,13 +80,13 @@ static jint bci2line(jint bci, jvmtiLineNumberEntry *table, jint entry_count) { /* Now start the table search from approximated start_index */ for (int i = start_index ; i < entry_count ; i++ ) { - // start_location > BCI: means line starts after the BCI, we'll take the previous match + // start_location > BCI: means line starts after the BCI, we'll take the previous match if ( bci < table[i].start_location ) { break; } else if (bci == table[i].start_location) { - // gotcha - return table[i].line_number; + // gotcha + return table[i].line_number; } line_number = table[i].line_number; } @@ -102,7 +120,8 @@ void LogWriter::record(const JVMPI_CallTrace &trace, ThreadBucketPtr info) { } void LogWriter::record(const timespec &ts, const JVMPI_CallTrace &trace, ThreadBucketPtr info) { - recordTraceStart(trace.num_frames, (map::HashType)trace.env_id, ts, info); + ostream & fout = getOut(); + recordTraceStart(fout, trace.num_frames, (map::HashType)trace.env_id, ts, info); for (int i = 0; i < trace.num_frames; i++) { JVMPI_CallFrame frame = trace.frames[i]; @@ -112,16 +131,16 @@ void LogWriter::record(const timespec &ts, const JVMPI_CallTrace &trace, ThreadB jint bci = frame.lineno; if (bci > 0) { jint lineno = getLineNo(bci, frame.method_id); - recordFrame(bci, lineno, methodId); + recordFrame(fout, bci, lineno, methodId); } else { - recordFrame(bci, methodId); + recordFrame(fout, bci, methodId); } - inspectMethod(methodId, frame); + inspectMethod(fout, methodId, frame); } } -void LogWriter::inspectMethod(const method_id methodId, const JVMPI_CallFrame &frame) { +void LogWriter::inspectMethod(ostream & fout, const method_id methodId, const JVMPI_CallFrame &frame) { if (knownMethods.count(methodId) > 0) { return; } @@ -135,7 +154,7 @@ void LogWriter::inspectMethod(const method_id methodId, const JVMPI_CallFrame &f } } -void LogWriter::inspectThread(map::HashType &threadId, ThreadBucketPtr& info) { +void LogWriter::inspectThread(ostream & fout, map::HashType &threadId, ThreadBucketPtr& info) { std::string threadName; if (info.defined()) { @@ -149,80 +168,90 @@ void LogWriter::inspectThread(map::HashType &threadId, ThreadBucketPtr& info) { knownThreads.insert(threadId); - output_.put(THREAD_META); - writeValue(threadId); - writeWithSize(threadName.c_str()); - output_.flush(); + fout.put(THREAD_META); + size++; + writeValue(fout, threadId); + writeWithSize(fout, threadName.c_str()); + fout.flush(); } -void LogWriter::recordTraceStart(const jint numFrames, map::HashType envHash, ThreadBucketPtr& info) { +void LogWriter::recordTraceStart(ostream & fout, const jint numFrames, map::HashType envHash, ThreadBucketPtr& info) { map::HashType threadId = -envHash; - inspectThread(threadId, info); + inspectThread(fout, threadId, info); - output_.put(TRACE_START); - writeValue(numFrames); - writeValue(threadId); - output_.flush(); + fout.put(TRACE_START); + size++; + writeValue(fout, numFrames); + writeValue(fout, threadId); + fout.flush(); } -void LogWriter::recordTraceStart(const jint numFrames, map::HashType envHash, const timespec &ts, ThreadBucketPtr& info) { +void LogWriter::recordTraceStart(ostream & fout, const jint numFrames, map::HashType envHash, const timespec &ts, ThreadBucketPtr& info) { map::HashType threadId = -envHash; // mark unrecognized threads with negative id's - inspectThread(threadId, info); - - output_.put(TRACE_WITH_TIME); - writeValue(numFrames); - writeValue(threadId); - writeValue((int64_t)ts.tv_sec); - writeValue((int64_t)ts.tv_nsec); - output_.flush(); + inspectThread(fout, threadId, info); + + fout.put(TRACE_WITH_TIME); + size++; + writeValue(fout, numFrames); + writeValue(fout, threadId); + writeValue(fout, (int64_t)ts.tv_sec); + writeValue(fout, (int64_t)ts.tv_nsec); + fout.flush(); } -void LogWriter::recordFrame(const jint bci, const jint lineNumber, const method_id methodId) { - output_.put(FRAME_FULL); - writeValue(bci); - writeValue(lineNumber); - writeValue(methodId); - output_.flush(); +void LogWriter::recordFrame(ostream & fout, const jint bci, const jint lineNumber, const method_id methodId) { + fout.put(FRAME_FULL); + size++; + writeValue(fout, bci); + writeValue(fout, lineNumber); + writeValue(fout, methodId); + fout.flush(); } // kept for old format tests -void LogWriter::recordFrame(const jint bci, const method_id methodId) { - output_.put(FRAME_BCI_ONLY); - writeValue(bci); - writeValue(methodId); - output_.flush(); +void LogWriter::recordFrame(ostream & fout, const jint bci, const method_id methodId) { + fout.put(FRAME_BCI_ONLY); + size++; + writeValue(fout, bci); + writeValue(fout, methodId); + fout.flush(); } -void LogWriter::writeWithSize(const char *value) { +void LogWriter::writeWithSize(ostream & fout, const char *value) { jint size = (jint) strlen(value); - writeValue(size); - output_.write(value, size); + writeValue(fout, size); + fout.write(value, size); + this->size+=sizeof(jint); } void LogWriter::recordNewMethod(const map::HashType methodId, const char *fileName, const char *className, const char *methodName) { - output_.put(NEW_METHOD); - writeValue(methodId); - writeWithSize(fileName); - writeWithSize(className); - writeWithSize(methodName); - output_.flush(); + ostream & fout = getOut(); + fout.put(NEW_METHOD); + size++; + writeValue(fout, methodId); + writeWithSize(fout, fileName); + writeWithSize(fout, className); + writeWithSize(fout, methodName); + fout.flush(); } void LogWriter::recordNewMethod(const map::HashType methodId, const char *fileName, const char *className, const char *genericClassName, const char *methodName, const char *methodSignature, const char *genericMethodSignature) { - output_.put(NEW_METHOD_SIGNATURE); - writeValue(methodId); - writeWithSize(fileName); - writeWithSize(className); - writeWithSize(genericClassName ? genericClassName : ""); - writeWithSize(methodName); - writeWithSize(methodSignature); - writeWithSize(genericMethodSignature ? genericMethodSignature : ""); - output_.flush(); + ostream & fout = getOut(); + fout.put(NEW_METHOD_SIGNATURE); + size++; + writeValue(fout, methodId); + writeWithSize(fout, fileName); + writeWithSize(fout, className); + writeWithSize(fout, genericClassName ? genericClassName : ""); + writeWithSize(fout, methodName); + writeWithSize(fout, methodSignature); + writeWithSize(fout, genericMethodSignature ? genericMethodSignature : ""); + fout.flush(); } bool LogWriter::lookupFrameInformation(const JVMPI_CallFrame &frame) { @@ -281,4 +310,49 @@ bool LogWriter::lookupFrameInformation(const JVMPI_CallFrame &frame) { ); return true; -} \ No newline at end of file +} + +ostream& LogWriter::getOut() { + // std::thread::id this_id = std::this_thread::get_id(); + if (!fileName.empty() && size >= rotateSize) { + // rotate + file->close(); + delete file; + file = NULL; + size = 0; + // std::cout <<" threadId: " << this_id << " rotating file start >>> \n"; + for (int i = rotateNum; i > 0; --i) { + // rename files: delete logN, rename logN-1 to logN; ...; delete log1, log to log1 + char buff[1024]; + if (i > 1) { + snprintf(buff, sizeof(buff), "%s.%d", fileName.c_str(), i - 1); + } else { + snprintf(buff, sizeof(buff), "%s", fileName.c_str()); + } + char buff_target[1024]; + snprintf(buff_target, sizeof(buff_target), "%s.%d", fileName.c_str(), i); + + // std::cout <<" threadId: " << this_id << " remove target " << buff_target << " \n"; + std::remove(buff_target); + std::rename(buff, buff_target); + // std::cout <<" threadId: " << this_id << " rename from " << buff << " to " << buff_target << " \n"; + } + // std::cout <<" threadId: " << "rotating file end <<< \n"; + // recreate log + file = new std::ofstream(fileName, std::ofstream::out | std::ofstream::binary); + output_ = file; + return *output_; + } else { + // std::cout <<" threadId: " << "rotateSize: " << rotateSize << + // ", rotateNum: " << rotateNum << " current size: " << size << "\n"; + return *output_; + } +} + +LogWriter::~LogWriter() { + if (file != NULL) { + file->close(); + delete file; + file = NULL; + } +} diff --git a/src/main/cpp/log_writer.h b/src/main/cpp/log_writer.h index a3edf4c53..2664b623d 100644 --- a/src/main/cpp/log_writer.h +++ b/src/main/cpp/log_writer.h @@ -1,11 +1,12 @@ #include - -#include #include +#include -#include "thread_map.h" #include "circular_queue.h" +#include "concurrent_map.h" +#include "globals.h" #include "stacktraces.h" +#include "thread_map.h" #ifndef LOG_WRITER_H #define LOG_WRITER_H @@ -51,23 +52,27 @@ const jint ERR_NO_LINE_FOUND= -101; class LogWriter : public QueueListener, public MethodListener { public: - explicit LogWriter(std::string &fileName, jvmtiEnv *jvmti); + explicit LogWriter(std::string &fileName, int rotateNum, int rotateSizeMB, jvmtiEnv *jvmti); - explicit LogWriter(ostream &output, GetFrameInformation frameLookup, jvmtiEnv *jvmti); + explicit LogWriter(ostream &output, int rotateNum, int rotateSizeMB, GetFrameInformation frameLookup, jvmtiEnv *jvmti); virtual void record(const timespec &ts, const JVMPI_CallTrace &trace, ThreadBucketPtr info = ThreadBucketPtr(nullptr)); void record(const JVMPI_CallTrace &trace, ThreadBucketPtr info = ThreadBucketPtr(nullptr)); - void recordTraceStart(const jint numFrames, map::HashType envHash, ThreadBucketPtr& info); + void inspectMethod(ostream& fout, const method_id methodId, const JVMPI_CallFrame &frame); - void recordTraceStart(const jint numFrames, map::HashType envHash, const timespec &ts, ThreadBucketPtr& info); + void inspectThread(ostream& fout, map::HashType &threadId, ThreadBucketPtr& info); + + void recordTraceStart(ostream& fout, const jint numFrames, map::HashType envHash, ThreadBucketPtr& info); + + void recordTraceStart(ostream& fout, const jint numFrames, map::HashType envHash, const timespec &ts, ThreadBucketPtr& info); // method are unique pointers, use a long to standardise // between 32 and 64 bits - void recordFrame(const jint bci, const jint lineNumber, method_id methodId); + void recordFrame(ostream& fout, const jint bci, const jint lineNumber, method_id methodId); - void recordFrame(const jint bci, method_id methodId); + void recordFrame(ostream& fout, const jint bci, method_id methodId); bool lookupFrameInformation(const JVMPI_CallFrame &frame); @@ -78,9 +83,16 @@ class LogWriter : public QueueListener, public MethodListener { const char *className, const char *genericClassName, const char *methodName, const char *methodSignature, const char *genericMethodSignature); + virtual ~LogWriter(); + private: - ofstream file; - ostream& output_; + std::string fileName; + int rotateNum; + int rotateSize; + int size; + + ofstream* file; + ostream* output_; GetFrameInformation frameInfoFoo; jvmtiEnv *const jvmti_; @@ -90,13 +102,12 @@ class LogWriter : public QueueListener, public MethodListener { unordered_set knownThreads; template - void writeValue(const T &value); + void writeValue(ostream& fout, const T &value); - void writeWithSize(const char *value); + void writeWithSize(ostream& fout, const char *value); - void inspectMethod(const method_id methodId, const JVMPI_CallFrame &frame); - void inspectThread(map::HashType &threadId, ThreadBucketPtr& info); + ostream& getOut(); jint getLineNo(jint bci, jmethodID methodId); diff --git a/src/main/cpp/profiler.cpp b/src/main/cpp/profiler.cpp index 383afa993..41dc4f5a4 100755 --- a/src/main/cpp/profiler.cpp +++ b/src/main/cpp/profiler.cpp @@ -159,7 +159,7 @@ void Profiler::configure() { } else { configuration_.logFilePath = liveConfiguration.logFilePath; } - writer = std::unique_ptr(new LogWriter(liveConfiguration.logFilePath, jvmti_)); + writer = std::unique_ptr(new LogWriter(liveConfiguration.logFilePath, liveConfiguration.rotateNum, liveConfiguration.rotateSizeMB, jvmti_)); } needsUpdate = needsUpdate || diff --git a/src/test/cpp/test_log_writer.cpp b/src/test/cpp/test_log_writer.cpp index 1d3fcdec5..fc25e8695 100644 --- a/src/test/cpp/test_log_writer.cpp +++ b/src/test/cpp/test_log_writer.cpp @@ -1,12 +1,13 @@ +#include #include #include #include #include -#include "fixtures.h" -#include "ostreambuf.h" #include "test.h" +#include "fixtures.h" #include "../../main/cpp/log_writer.h" +#include "ostreambuf.h" using std::ostream; using std::ofstream; @@ -26,7 +27,7 @@ bool stubFrameInformation(const JVMPI_CallFrame &frame, MethodListener &listener char buffer[100] = {}; \ ostreambuf outputBuffer(buffer, sizeof(buffer)); \ ostream output(&outputBuffer); \ - LogWriter logWriter(output, &stubFrameInformation, NULL); \ + LogWriter logWriter(output, 5, 5, &stubFrameInformation, NULL); \ CircularQueue *queue = new CircularQueue(logWriter, DEFAULT_MAX_FRAMES_TO_CAPTURE); #define done() delete queue; @@ -37,7 +38,7 @@ TEST(RecordsStartOfStackTrace) { timespec tspec = {44, 55}; ThreadBucketPtr tptr(threadInfo.get(), false); - logWriter.recordTraceStart(2, 3, tspec, tptr); + logWriter.recordTraceStart(output, 2, 3, tspec, tptr); int cnt = 0; CHECK_EQUAL(THREAD_META, buffer[cnt]); @@ -64,7 +65,7 @@ TEST(SupportsHighThreadId) { // LONG_MAX long bigNumber = std::numeric_limits::max(); ThreadBucketPtr tBuck(nullptr); - logWriter.recordTraceStart(2, (map::HashType)bigNumber, tspec, tBuck); + logWriter.recordTraceStart(output, 2, (map::HashType)bigNumber, tspec, tBuck); CHECK_EQUAL(THREAD_META, buffer[0]); CHECK_EQUAL(0, buffer[12]); @@ -78,7 +79,7 @@ TEST(SupportsHighThreadId) { TEST(RecordsStackFrames) { givenLogWriter(); - logWriter.recordFrame(5, 6); + logWriter.recordFrame(output, 5, 6); CHECK_EQUAL(FRAME_BCI_ONLY, buffer[0]); CHECK_EQUAL(5, buffer[4]); CHECK_EQUAL(0, buffer[3]); @@ -186,8 +187,22 @@ TEST(DumpTestFile) { givenStackTrace(); ofstream output("dump.hpl", ofstream::out | ofstream::binary); - LogWriter logWriter(output, &dumpStubFrameInformation, NULL); + LogWriter logWriter(output, 5, 5, &dumpStubFrameInformation, NULL); logWriter.record(trace); logWriter.record(trace); } + +TEST(FileRotation) { + givenStackTrace(); + ofstream output("dump-rotate.hpl", ofstream::out | ofstream::binary); + LogWriter logWriter(output, 3, 1, &dumpStubFrameInformation, NULL); + + // write 1M times, which must exceeds 1M log rotation size + for (int i = 0; i < 1024*1024; i++) { + logWriter.record(trace); + } + // Now verify the rotated file exists, and it's readable by the log reader + std::ifstream infile("dump-rotate.hpl.1"); + CHECK_EQUAL(0, infile.good()); +}