[FLOG] Optimizate Log system about final_libs HOT 7 CLOSED

Sorry, my bad, I open 4 working threads for writing logs to test my program, but actually, I only have 4 cpus in my testing environment, so, one use to fetcher, only last 3 cpus for 4 working threads, that lead to one thread can not work.

So, I adjust my testing program, only open 3 working threads, finally, I got a better result:
single thread: 638269 msg/s
multithread(3 working threads, 1 fetcher thread): 2242930 msg/s

Btw, the testing program in https://github.com/finaldie/final_test , find in "log" folder

So next, find out the hotspot in code, do some deep optimization. Action items:

1. hotspot
2. branch predict
3. hold time string within one second
   ...

from final_libs.

I have updated the testing program in https://github.com/finaldie/final_test
I tested it through 4 ways:

1. sync mode, single thread writing
2. sync mode, multithread writing
3. async mode, single thread writing
4. async mode, multithread wrting

My environment of testing machine is:

1. CPU: Intel(R) Core(TM) i5-2500 CPU @ 3.30GHz * 4
2. DISK: 120G, BuffSize=14111kB
3. MEMORY: 4G

Program setting:

1. Flush interval: 2 seconds
2. Buffer Size per-thread: 10M
3. 3 threads in multithread mode

Testing Result:

1. Sync mode, single thread: [ 1089947 msg/s ]
2. Sync mode, multithread: [ 2688969 msg/s ]
3. Async mode, single thread: [ 619730 msg/s ]
4. Async mode, multithread: [ 2229928 msg/s ]

from final_libs.

The testing result above is only for testing ability of writing.
The call time per-interface has not started.

I have finished draw a call graph, the hotspot at "snprintf".

So next, find out the hotspot in code, do some deep optimization. Action items:

1. hotspot
2. branch predict
3. hold time string within one second
   ...

from final_libs.

When I testing on a 24 cores machine, I found it better than my local 4 cores machine.
The async interface much faster than sync interface ( improvement 100% )

from final_libs.

I have updated the testing program in https://github.com/finaldie/final_test and testing the last commit of final_libs (443e13b)
I tested it through 4 ways:

1. sync mode, single thread writing
2. sync mode, multithread writing
3. async mode, single thread writing
4. async mode, multithread wrting

My environment of testing machine is:

1. CPU: Intel(R) Core(TM) i5-2500 CPU @ 3.30GHz * 4
2. DISK: 120G, BuffSize=14111kB
3. MEMORY: 4G

Program setting:

1. Flush interval: 2 seconds
2. Buffer Size per-thread: 10M
3. 3 threads in multithread mode

Testing Result call interface time (3000000 msg total):

1. sync mode, single thread: 510193 microseconds
2. sync mode, multithread: 1037439 microseconds
3. async mode, single thread: 1513447 microseconds
4. async mode, multithread: 470537 microseconds

The last version call interface time (3000000 msg total):

1. sync mode, single thread: 2663160 microseconds
2. sync mode, multithread: 1140176 microseconds
3. async mode, single thread: 4867738 microseconds
4. async mode, multithread: 1351146 microseconds

from final_libs.

Almost done~ Has a great improvement.

from final_libs.

The some environment above, the last testing result: ( run ftest/log/test: ./test 1000000 3 )

startup mode = 4 ..
log system init complete
[SYNC]start single testing...
writing thread id = 47059976517376 startup
tid=47059976517376, max_num_per_group:5000, group:200, last_miss_count:0, sleep_step:5000
tid=47059976517376, call interface time cost (usec):605103, writen msg:1000000, final:1652611.208340 count/s
pid=1168, tid=47059966025888, call interface time cost (usec):605475 write_msg:1000000 miss_msg:0 miss_rate:0.000000 final:1651595.854494 count/s
[SYNC]end single testing

[SYNC]start multip testing ( totally, we start 3 threads for testing)...
writing thread id = 47059976517376 startup
tid=47059976517376, max_num_per_group:5000, group:66, last_miss_count:0, sleep_step:5000
writing thread id = 47059999762176 startup
tid=47059999762176, max_num_per_group:5000, group:66, last_miss_count:0, sleep_step:5000
writing thread id = 47059989272320 startup
tid=47059989272320, max_num_per_group:5000, group:66, last_miss_count:0, sleep_step:5000
tid=47059976517376, call interface time cost (usec):699984, writen msg:333333, final:476200.884592 count/s
tid=47059999762176, call interface time cost (usec):700692, writen msg:333333, final:475719.717080 count/s
tid=47059989272320, call interface time cost (usec):703390, writen msg:333333, final:473894.994242 count/s
pid=1168, tid=47059966025888, call interface time cost (usec):703670 write_msg:1000000 miss_msg:0 miss_rate:0.000000 final:1421120.695781 count/s
[SYNC]end multip testing

[ASYNC]start single testing...
current buffer size per-thread = 209715200
log work thread start
writing thread id = 47059989272320 startup
tid=47059989272320, max_num_per_group:5000, group:200, last_miss_count:0, sleep_step:5000
tid=47059989272320, call interface time cost (usec):503826, writen msg:1000000, final:1984812.216916 count/s
pid=1168, tid=47059966025888, call interface time cost (usec):503942 write_msg:1000000 miss_msg:0 miss_rate:0.000000 final:1984355.342480 count/s
get_log_event(tid=47059999762176): event_id=2
[ASYNC]end single testing

[ASYNC]start multip testing ( totally, we start 3 threads for testing)...
current buffer size per-thread = 209715200
writing thread id = 47059989272320 startup
tid=47059989272320, max_num_per_group:5000, group:66, last_miss_count:0, sleep_step:5000
writing thread id = 47060101367552 startup
tid=47060101367552, max_num_per_group:5000, group:66, last_miss_count:0, sleep_step:5000
writing thread id = 47059976517376 startup
tid=47059976517376, max_num_per_group:5000, group:66, last_miss_count:0, sleep_step:5000
tid=47060101367552, call interface time cost (usec):213521, writen msg:333333, final:1561125.135233 count/s
tid=47059989272320, call interface time cost (usec):215646, writen msg:333333, final:1545741.632119 count/s
tid=47059976517376, call interface time cost (usec):217472, writen msg:333333, final:1532762.838434 count/s
pid=1168, tid=47059966025888, call interface time cost (usec):219598 write_msg:1000000 miss_msg:0 miss_rate:0.000000 final:4553775.535296 count/s
get_log_event(tid=47059999762176): event_id=2
get_log_event(tid=47059999762176): event_id=2
get_log_event(tid=47059999762176): event_id=2
[ASYNC]end multip testing

So, we can see the result of async writing is much better than before.
congratulations!

from final_libs.