gitMirror/spdlog
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

easylogging bench and fix async compare with g2log

Browse Source
This commit is contained in:
gabime
2014-12-20 22:25:55 +02:00
parent 37a14f0d22
commit 4250796aea
9 changed files with 126 additions and 145 deletions
Download Patch File Download Diff File Expand all files Collapse all files

20
README.md
View File

@@ -35,10 +35,22 @@ Just copy the files to your build tree and use a C++11 compiler
Below are some [benchmarks](bench) comparing the time needed to log 1,000,000 lines to file under Ubuntu 64 bit, Intel i7-4770 CPU @ 3.40GHz (the best of 3 runs for each logger): Below are some [benchmarks](bench) comparing the time needed to log 1,000,000 lines to file under Ubuntu 64 bit, Intel i7-4770 CPU @ 3.40GHz (the best of 3 runs for each logger):
|threads|boost log|glog|g2log <sup>async mode</sup>|spdlog|spdlog <sup>async mode</sup>| ### Synchronous mode
|-------|:-------:|:-----:|------:|------:|------:| |threads|boost log|glog |easylogging |spdlog|
|1|4.779s|1.109s|3.155s|0.319s|0.212s |-------|:-------:|:-----:|----------:|------:|
|10|15.151ss|3.546s|3.500s|0.641s|0.199s| |1| 4.169s |1.066s |0.975s :|0.302s|
|10| 16.029 |3.032s |2.857 :|0.968s|
|100| 15.008 |1.139s |4.512s :|0.497s|
### ASynchronous mode
|threads|g2log |spdlog<sup>async mode</sup>|
|:-------|----- :|:-------------------------:|
|1| 1.850s |0.216s
|10| 0.943s |0.173s
|100| 0.959s |0.202
## Usage Example ## Usage Example

15
bench/Makefile
View File

@@ -3,7 +3,7 @@ CXXFLAGS = -march=native -Wall -Wextra -pedantic -std=c++11 -pthread -Wl,--no-as
CXX_RELEASE_FLAGS = -O3 -flto CXX_RELEASE_FLAGS = -O3 -flto
binaries=spdlog-bench spdlog-bench-mt spdlog-bench-async spdlog-bench-mt-async boost-bench boost-bench-mt glog-bench glog-bench-mt g2log-bench g2log-bench-mt easylogging-bench easylogging-bench-mt binaries=spdlog-bench spdlog-bench-mt spdlog-async boost-bench boost-bench-mt glog-bench glog-bench-mt g2log-async easylogging-bench easylogging-bench-mt
all: $(binaries) all: $(binaries)
@@ -13,11 +13,9 @@ spdlog-bench: spdlog-bench.cpp
spdlog-bench-mt: spdlog-bench-mt.cpp spdlog-bench-mt: spdlog-bench-mt.cpp
$(CXX) spdlog-bench-mt.cpp -o spdlog-bench-mt $(CXXFLAGS) $(CXX_RELEASE_FLAGS) $(CXX) spdlog-bench-mt.cpp -o spdlog-bench-mt $(CXXFLAGS) $(CXX_RELEASE_FLAGS)
spdlog-bench-async: spdlog-bench-async.cpp spdlog-async: spdlog-async.cpp
$(CXX) spdlog-bench-async.cpp -o spdlog-bench-async $(CXXFLAGS) $(CXX_RELEASE_FLAGS) $(CXX) spdlog-async.cpp -o spdlog-async $(CXXFLAGS) $(CXX_RELEASE_FLAGS)
spdlog-bench-mt-async: spdlog-bench-mt-async.cpp
$(CXX) spdlog-bench-mt-async.cpp -o spdlog-bench-mt-async $(CXXFLAGS) $(CXX_RELEASE_FLAGS)
BOOST_FLAGS = -DBOOST_LOG_DYN_LINK -I/home/gabi/devel/boost_1_56_0/ -L/home/gabi/devel/boost_1_56_0/stage/lib -lboost_log -lboost_log_setup -lboost_filesystem -lboost_system -lboost_thread -lboost_regex -lboost_date_time -lboost_chrono BOOST_FLAGS = -DBOOST_LOG_DYN_LINK -I/home/gabi/devel/boost_1_56_0/ -L/home/gabi/devel/boost_1_56_0/stage/lib -lboost_log -lboost_log_setup -lboost_filesystem -lboost_system -lboost_thread -lboost_regex -lboost_date_time -lboost_chrono
@@ -37,12 +35,9 @@ glog-bench-mt: glog-bench-mt.cpp
G2LOG_FLAGS = -I/home/gabi/devel/g2log/g2log/src -L/home/gabi/devel/g2log/g2log -llib_g2logger G2LOG_FLAGS = -I/home/gabi/devel/g2log/g2log/src -L/home/gabi/devel/g2log/g2log -llib_g2logger
g2log-bench: g2log-bench.cpp g2log-async: g2log-async.cpp
$(CXX) g2log-bench.cpp -o g2log-bench $(CXXFLAGS) $(G2LOG_FLAGS) $(CXX_RELEASE_FLAGS) $(CXX) g2log-async.cpp -o g2log-async $(CXXFLAGS) $(G2LOG_FLAGS) $(CXX_RELEASE_FLAGS)
g2log-bench-mt: g2log-bench-mt.cpp
$(CXX) g2log-bench-mt.cpp -o g2log-bench-mt $(CXXFLAGS) $(G2LOG_FLAGS) $(CXX_RELEASE_FLAGS)

24
bench/g2log-bench-mt.cpp → bench/g2log-async.cpp
View File

@@ -2,19 +2,22 @@
#include <vector> #include <vector>
#include <atomic> #include <atomic>
#include <iostream> #include <iostream>
#include <chrono>
#include "g2logworker.h" #include "g2logworker.h"
#include "g2log.h" #include "g2log.h"
using namespace std; using namespace std;
template<typename T> std::string format(const T& value);
int main(int argc, char* argv[]) int main(int argc, char* argv[])
{ {
using namespace std::chrono;
using clock=steady_clock;
int thread_count = 10; int thread_count = 10;
if(argc > 1) if(argc > 1)
thread_count = atoi(argv[1]); thread_count = atoi(argv[1]);
int howmany = 1000000; int howmany = 1000000;
g2LogWorker g2log(argv[0], "logs"); g2LogWorker g2log(argv[0], "logs");
@@ -23,7 +26,7 @@ int main(int argc, char* argv[])
std::atomic<int > msg_counter {0}; std::atomic<int > msg_counter {0};
vector<thread> threads; vector<thread> threads;
auto start = clock::now();
for (int t = 0; t < thread_count; ++t) for (int t = 0; t < thread_count; ++t)
{ {
threads.push_back(std::thread([&]() threads.push_back(std::thread([&]()
@@ -41,9 +44,14 @@ int main(int argc, char* argv[])
for(auto &t:threads) for(auto &t:threads)
{ {
t.join(); t.join();
}; };
duration<float> delta = clock::now() - start;
float deltaf = delta.count();
return 0; auto rate = howmany/deltaf;
cout << "Total: " << howmany << std::endl;
cout << "Threads: " << thread_count << std::endl;
std::cout << "Delta = " << deltaf << " seconds" << std::endl;
std::cout << "Rate = " << rate << "/sec" << std::endl;
} }

16
bench/g2log-bench.cpp
View File

@@ -1,16 +0,0 @@
#include "g2logworker.h"
#include "g2log.h"
int main(int, char* argv[])
{
int howmany = 1000000;
g2LogWorker g2log(argv[0], "logs");
g2::initializeLogging(&g2log);
for(int i = 0 ; i < howmany; ++i)
LOG(INFO) << "g2log message # " << i << ": This is some text for your pleasure";
return 0;
}

2
bench/glog-bench-mt.cpp
View File

@@ -41,7 +41,5 @@ int main(int argc, char* argv[])
t.join(); t.join();
}; };
return 0; return 0;
} }

129
bench/run_all.sh
View File

@@ -1,81 +1,80 @@
#~/bin/bash #~/bin/bash
#execute each bench 3 times and print the timing
exec 2>&1 exec 2>&1
#execute and time given exe 3 times
bench_exe ()
{
echo "**************** $1 ****************"
for i in {1..3}; do
time ./$1 $2;
rm -f logs/*
sleep 3
done;
}
echo "Running benchmakrs (all with 1000,000 writes to the logs folder)" #execute given async tests 3 times (timing is already builtin)
echo bench_async ()
echo "boost-bench (single thread).." {
for i in {1..3}; do time ./boost-bench; done echo "**************** $1 ****************"
rm -f logs/* for i in {1..3}; do
echo ./$1 $2;
echo rm -f logs/*
sleep 5 sleep 3
done;
}
echo "glog-bench (single thread).."
for i in {1..3}; do time ./glog-bench; done
rm -f logs/*
echo
echo
sleep 5
echo "g2log-bench (single thread).." echo "----------------------------------------------------------"
for i in {1..3}; do time ./g2log-bench; done echo "Single threaded benchmarks.. (1 thread, 1,000,000 lines)"
rm -f logs/* echo "----------------------------------------------------------"
echo for exe in boost-bench glog-bench easylogging-bench spdlog-bench;
echo do
sleep 5 bench_exe $exe 1
done;
echo "spdlog-bench (single thread)" echo "----------------------------------------------------------"
for i in {1..3}; do time ./spdlog-bench; done echo "Multi threaded benchmarks.. (10 threads, 1,000,000 lines)"
rm -f logs/* echo "----------------------------------------------------------"
echo for exe in boost-bench-mt glog-bench-mt easylogging-bench-mt spdlog-bench-mt;
echo do
sleep 5 bench_exe $exe 10
echo "------------------------------------" done;
echo "Multithreaded benchmarks.."
echo "------------------------------------"
echo "boost-bench-mt (10 threads, single logger)"..
for i in {1..3}; do ./boost-bench-mt; done
rm -f logs/*
echo
echo
sleep 5
echo "glog-bench-mt (10 threads, single logger)".. echo "----------------------------------------------------------"
for i in {1..3}; do time ./glog-bench-mt; done echo "Multi threaded benchmarks.. (100 threads, 1,000,000 lines)"
rm -f logs/* echo "----------------------------------------------------------"
echo for exe in boost-bench-mt glog-bench-mt easylogging-bench-mt spdlog-bench-mt;
echo do
sleep 5 bench_exe $exe 100
done;
echo "g2log-bench-mt (10 threads, single logger)".. echo "---------------------------------------------------------------"
for i in {1..3}; do time ./g2log-bench-mt; done echo "Async, single threaded benchmark.. (1 thread, 1,000,000 lines)"
rm -f logs/* echo "---------------------------------------------------------------"
echo for exe in spdlog-async g2log-async
echo do
sleep 5 bench_async $exe 1
done;
echo "spdlog-bench-mt (10 threads, single logger)".. echo "---------------------------------------------------------------"
for i in {1..3}; do time ./spdlog-bench-mt; done echo "Async, multi threaded benchmark.. (10 threads, 1,000,000 lines)"
rm -f logs/* echo "---------------------------------------------------------------"
echo for exe in spdlog-async g2log-async
echo do
sleep 5 bench_async $exe 10
done;
echo "------------------------------------"
echo "Async benchmarks.."
echo "------------------------------------"
echo "spdlog-bench-async (single thread)".. echo "---------------------------------------------------------------"
for i in {1..3}; do time ./spdlog-bench-async; done echo "Async, multi threaded benchmark.. (100 threads, 1,000,000 lines)"
rm -f logs/* echo "---------------------------------------------------------------"
echo for exe in spdlog-async g2log-async
echo do
sleep 5 bench_async $exe 100
done;
echo "spdlog-bench-mt-async (10 threads, single logger)"..
for i in {1..3}; do time ./spdlog-bench-mt-async; done

41
bench/spdlog-bench-mt-async.cpp → bench/spdlog-async.cpp
View File

@@ -1,31 +1,34 @@
#include <thread> #include <thread>
#include <vector> #include <vector>
#include <atomic> #include <atomic>
#include <iostream>
#include <chrono>
#include "spdlog/spdlog.h" #include "spdlog/spdlog.h"
#include <iostream>
using namespace std; using namespace std;
int main(int argc, char* argv[]) int main(int argc, char* argv[])
{ {
using namespace std::chrono;
using clock=steady_clock;
namespace spd = spdlog;
int thread_count = 10; int thread_count = 10;
if(argc > 1) if(argc > 1)
thread_count = atoi(argv[1]); thread_count = atoi(argv[1]);
int howmany = 1000000;
int howmany = 1048576;
spd::set_async_mode(1048576);
namespace spd = spdlog; auto logger = spdlog::create<spd::sinks::simple_file_sink_mt>("file_logger", "logs/spd-bench-async.txt", false);
spd::set_async_mode(howmany);
///Create a file rotating logger with 5mb size max and 3 rotated files
auto logger = spd::rotating_logger_mt("file_logger", "logs/spd-sample", 10 *1024 * 1024 , 5);
logger->set_pattern("[%Y-%b-%d %T.%e]: %v"); logger->set_pattern("[%Y-%b-%d %T.%e]: %v");
std::atomic<int > msg_counter {0}; std::atomic<int > msg_counter {0};
vector<thread> threads; vector<thread> threads;
auto start = clock::now();
for (int t = 0; t < thread_count; ++t) for (int t = 0; t < thread_count; ++t)
{ {
threads.push_back(std::thread([&]() threads.push_back(std::thread([&]()
@@ -39,13 +42,17 @@ int main(int argc, char* argv[])
})); }));
} }
for(auto &t:threads) for(auto &t:threads)
{ {
t.join(); t.join();
}; };
//because spdlog async logger waits for the back thread logger to finish all messages upon destrcuting, duration<float> delta = clock::now() - start;
//and we want to measure only the time it took to push those messages to the backthread.. float deltaf = delta.count();
abort(); auto rate = howmany/deltaf;
cout << "Total: " << howmany << std::endl;
cout << "Threads: " << thread_count << std::endl;
std::cout << "Delta = " << deltaf << " seconds" << std::endl;
std::cout << "Rate = " << rate << "/sec" << std::endl;
} }

22
bench/spdlog-bench-async.cpp
View File

@@ -1,22 +0,0 @@
#include "spdlog/spdlog.h"
int main(int, char* [])
{
int howmany = 1048576;
namespace spd = spdlog;
spd::set_async_mode(howmany);
///Create a file rotating logger with 5mb size max and 3 rotated files
auto logger = spd::rotating_logger_mt("file_logger", "logs/spd-sample", 10 *1024 * 1024 , 5);
logger->set_pattern("[%Y-%b-%d %T.%e]: %v");
for(int i = 0 ; i < howmany; ++i)
logger->info() << "spdlog message #" << i << ": This is some text for your pleasure";
//because spdlog async logger waits for the back thread logger to finish all messages upon destrcuting,
//and we want to measure only the time it took to push those messages to the backthread..
abort();
return 0;
}

2
bench/spdlog-bench.cpp
View File

@@ -7,7 +7,7 @@ int main(int, char* [])
int howmany = 1000000; int howmany = 1000000;
namespace spd = spdlog; namespace spd = spdlog;
///Create a file rotating logger with 5mb size max and 3 rotated files ///Create a file rotating logger with 5mb size max and 3 rotated files
auto logger = spd::rotating_logger_st("file_logger", "logs/spd-sample", 10 *1024 * 1024 , 5); auto logger = spdlog::create<spd::sinks::simple_file_sink_st>("file_logger", "logs/spd-bench-st.txt", false);
logger->set_pattern("[%Y-%b-%d %T.%e]: %v"); logger->set_pattern("[%Y-%b-%d %T.%e]: %v");
for(int i = 0 ; i < howmany; ++i) for(int i = 0 ; i < howmany; ++i)