Commit f9e33ecd authored by Hardy Simpson's avatar Hardy Simpson

bugfix: fwrite is not atomic, back to write...speed is down, but no interlace will happen

parent e4dd43f1
......@@ -15,9 +15,11 @@
[ ] format,spec,level采用直接数组的方式重写
[ ] hex那段重写,内置到buf内
--- 1.1.1 ---
[o] 修正rule.c, 不使用FILE*, 避免日志交错
--- 1.1.0 ---
[x] spec改为switch循环, 如果可能的话rule也照样, 发现switch的效率不如函数指针
[x] 把__LINE__ 变成string, 需要改接口
[x] spec改为switch循环, 如果可能的话rule也照样--发现switch的效率不如函数指针
[x] 把__LINE__ 变成string--需要改接口
[o] 建立bit位来判断,无锁判断
[o] 寻找快速的方法把us, srcline变成字符串
[o] 在一开始就判断是否需要输出,
......@@ -83,7 +85,7 @@
[o] zlog-gen-conf
[o] rotate控制个数
--- 废弃想法 ---
[x] 使用writev来写日志,提高效率,达到一次形成,多次输出的目的
[x] 使用writev来写日志,提高效率,达到一次形成,多次输出的目的, writev内部也是开buffermemcpy
[x] 尝试信号量的方法来打成线程安全的转档互斥问题
[x] zlog.h变长参数宏的问题(参考glib的log解决)
[x] rule的dynamic] file可以从format获取
......
AC_PREREQ(2.59)
AC_INIT([zlog], [1.1.0], [HardySimpson1984@gmail.com])
AC_INIT([zlog], [1.1.1], [HardySimpson1984@gmail.com])
AM_INIT_AUTOMAKE([foreign -Wall -Werror])
AC_CONFIG_SRCDIR([libzlog/zlog.h])
AC_CONFIG_HEADER([config.h])
......
......@@ -2,15 +2,26 @@
using makefile.linux for test, libzlog compile in O2
-------------------------------------------------
[direct write, no logging library] - The Sky!
$ time ./test_press_fwrite 1 10 100000
real 0m0.227s
user 0m0.070s
sys 0m0.180s
$ time ./test_press_write 1 10 100000
real 0m1.872s
user 0m0.140s
sys 0m3.290s
$ time ./test_press_fwrite2 1 10 100000
real 0m0.123s
user 0m0.060s
sys 0m0.130s
$ time ./test_press_write2 1 10 100000
real 0m0.909s
user 0m0.080s
sys 0m1.710s
-------------------------------------------------
v1.1.1 (fwrite is not atomic, so backup to write)
$ time ./test_press_zlog 1 10 100000
real 0m2.334s
user 0m1.780s
sys 0m2.710s
$ time ./test_press_zlog2 1 10 100000
real 0m2.134s
user 0m1.840s
sys 0m1.990s
-------------------------------------------------
v1.1.0
$ time ./test_press_zlog 1 10 100000
......
......@@ -45,7 +45,7 @@ void zlog_rule_profile(zlog_rule_t * a_rule, int flag)
zlog_spec_t *a_spec;
zc_assert(a_rule,);
zc_profile(flag, "---rule:[%p][%s%c%d]-[%s,%p,(%d,%p)(%d:%ld*%d)][%d][%s:%s:%p];[%p]---",
zc_profile(flag, "---rule:[%p][%s%c%d]-[%s,%p,(%d)(%d:%ld*%d)][%d][%s:%s:%p];[%p]---",
a_rule,
a_rule->category,
a_rule->compare_char,
......@@ -54,7 +54,6 @@ void zlog_rule_profile(zlog_rule_t * a_rule, int flag)
a_rule->file_path,
a_rule->dynamic_file_specs,
a_rule->static_file_descriptor,
a_rule->static_file_stream,
a_rule->file_open_flags,
a_rule->file_max_size,
......@@ -84,17 +83,16 @@ static int zlog_rule_output_static_file_single(zlog_rule_t * a_rule, zlog_thread
return -1;
}
if (fwrite(zlog_buf_str(a_thread->msg_buf), zlog_buf_len(a_thread->msg_buf),
1, a_rule->static_file_stream) != 1) {
zc_error("fwrite fail, errno[%d]", errno);
if (write(a_rule->static_file_descriptor,
zlog_buf_str(a_thread->msg_buf),
zlog_buf_len(a_thread->msg_buf)) < 0) {
zc_error("write fail, errno[%d]", errno);
return -1;
}
if (a_rule->fsync_period && ++a_rule->fsync_count >= a_rule->fsync_period) {
a_rule->fsync_count = 0;
if (fflush(a_rule->static_file_stream)) {
zc_error("fflush[%p] fail, errno[%d]", a_rule->static_file_stream, errno);
} else if (fsync(a_rule->static_file_descriptor)) {
if (fsync(a_rule->static_file_descriptor)) {
zc_error("fsync[%d] fail, errno[%d]", a_rule->static_file_descriptor, errno);
}
}
......@@ -115,16 +113,16 @@ static int zlog_rule_output_static_file_rotate(zlog_rule_t * a_rule, zlog_thread
pthread_rwlock_rdlock(&(a_rule->static_reopen_lock));
len = zlog_buf_len(a_thread->msg_buf);
if (fwrite(zlog_buf_str(a_thread->msg_buf), len, 1, a_rule->static_file_stream) != 1) {
zc_error("fwrite fail, errno[%d]", errno);
if (write(a_rule->static_file_descriptor,
zlog_buf_str(a_thread->msg_buf),
zlog_buf_len(a_thread->msg_buf)) < 0) {
zc_error("write fail, errno[%d]", errno);
return -1;
}
if (a_rule->fsync_period && ++a_rule->fsync_count >= a_rule->fsync_period) {
a_rule->fsync_count = 0;
if (fflush(a_rule->static_file_stream)) {
zc_error("fflush[%p] fail, errno[%d]", a_rule->static_file_stream, errno);
} else if (fsync(a_rule->static_file_descriptor)) {
if (fsync(a_rule->static_file_descriptor)) {
zc_error("fsync[%d] fail, errno[%d]", a_rule->static_file_descriptor, errno);
}
}
......@@ -148,23 +146,18 @@ static int zlog_rule_output_static_file_rotate(zlog_rule_t * a_rule, zlog_thread
return -1;
}
if (fclose(a_rule->static_file_stream)) {
zc_error("fclose fail, maybe cause by write, errno[%d]", errno);
if (close(a_rule->static_file_descriptor)) {
zc_error("close fail, maybe cause by write, errno[%d]", errno);
}
a_rule->static_file_descriptor = open(a_rule->file_path,
O_WRONLY | O_APPEND | O_CREAT, a_rule->file_perms);
O_WRONLY | O_APPEND | O_CREAT | a_rule->file_open_flags,
a_rule->file_perms);
if (a_rule->static_file_descriptor < 0) {
zc_error("open file[%s] fail, errno[%d]", a_rule->file_path, errno);
goto err;
}
a_rule->static_file_stream = fdopen(a_rule->static_file_descriptor, "a");
if (!a_rule->static_file_stream) {
zc_error("fdopen fd[%d] fail, errno[%d]", a_rule->static_file_descriptor, errno);
goto err;
}
rd = pthread_rwlock_unlock(&(a_rule->static_reopen_lock));
if (rd) {
zc_error("pthread_rwlock_unlock fail, rd=[%d]", rd);
......@@ -216,10 +209,10 @@ static int zlog_rule_output_dynamic_file_single(zlog_rule_t * a_rule, zlog_threa
return -1;
}
fd = open(a_thread->path_buf->start,
fd = open(zlog_buf_str(a_thread->path_buf),
a_rule->file_open_flags | O_WRONLY | O_APPEND | O_CREAT, a_rule->file_perms);
if (fd < 0) {
zc_error("open file[%s] fail, errno[%d]", a_thread->path_buf->start, errno);
zc_error("open file[%s] fail, errno[%d]", zlog_buf_str(a_thread->path_buf), errno);
return -1;
}
......@@ -257,10 +250,10 @@ static int zlog_rule_output_dynamic_file_rotate(zlog_rule_t * a_rule, zlog_threa
return -1;
}
fd = open(a_thread->path_buf->start,
fd = open(zlog_buf_str(a_thread->path_buf),
a_rule->file_open_flags | O_WRONLY | O_APPEND | O_CREAT, a_rule->file_perms);
if (fd < 0) {
zc_error("open file[%s] fail, errno[%d]", a_thread->path_buf->start, errno);
zc_error("open file[%s] fail, errno[%d]", zlog_buf_str(a_thread->path_buf), errno);
return -1;
}
......@@ -282,7 +275,7 @@ static int zlog_rule_output_dynamic_file_rotate(zlog_rule_t * a_rule, zlog_threa
}
if (zlog_rotater_rotate(a_rule->rotater,
a_thread->path_buf->start,
zlog_buf_str(a_thread->path_buf),
a_rule->file_max_size,
a_rule->file_max_count,
len) < 0) {
......@@ -633,13 +626,7 @@ zlog_rule_t *zlog_rule_new(char *line,
}
/* try to figure out if the log file path is dynamic or static */
if (strchr(a_rule->file_path, '%') == NULL
&& (a_rule->file_open_flags != O_SYNC)) {
/* no % means static, using cached FILE* to fwrite
* but if O_SYNC('-' before path),
* dynamic open write close each time is fast and safe
*/
if (strchr(a_rule->file_path, '%') == NULL) {
if (a_rule->file_max_size <= 0) {
a_rule->output = zlog_rule_output_static_file_single;
} else {
......@@ -648,18 +635,13 @@ zlog_rule_t *zlog_rule_new(char *line,
}
a_rule->static_file_descriptor = open(a_rule->file_path,
O_WRONLY | O_APPEND | O_CREAT, a_rule->file_perms);
O_WRONLY | O_APPEND | O_CREAT | a_rule->file_open_flags,
a_rule->file_perms);
if (a_rule->static_file_descriptor < 0) {
zc_error("open file[%s] fail, errno[%d]", a_rule->file_path, errno);
goto err;
}
a_rule->static_file_stream = fdopen(a_rule->static_file_descriptor, "a");
if (!a_rule->static_file_stream) {
zc_error("fdopen fd[%d] fail, errno[%d]", a_rule->static_file_descriptor, errno);
goto err;
}
} else {
zlog_spec_t *a_spec;
......@@ -734,9 +716,9 @@ void zlog_rule_del(zlog_rule_t * a_rule)
zc_arraylist_del(a_rule->dynamic_file_specs);
a_rule->dynamic_file_specs = NULL;
}
if (a_rule->static_file_stream) {
if (fclose(a_rule->static_file_stream)) {
zc_error("fclose fail, maybe cause by write, errno[%d]", errno);
if (a_rule->static_file_descriptor) {
if (close(a_rule->static_file_descriptor)) {
zc_error("close fail, maybe cause by write, errno[%d]", errno);
}
}
free(a_rule);
......
......@@ -61,7 +61,7 @@ struct zlog_rule_s {
int file_max_count;
size_t fsync_period;
volatile sig_atomic_t fsync_count;
size_t fsync_count;
zc_arraylist_t *levels;
int syslog_facility;
......
......@@ -50,7 +50,7 @@ int zc_profile_inner(int flag, const char *file, const long line, const char *fm
static char *debug_log = NULL;
static char *error_log = NULL;
static volatile sig_atomic_t init_flag = 0;
static size_t init_flag = 0;
if (!init_flag) {
init_flag = 1;
......
......@@ -40,7 +40,7 @@ static zc_arraylist_t *zlog_env_threads;
static zc_hashtable_t *zlog_env_categories;
static zc_hashtable_t *zlog_env_records;
static zlog_category_t *zlog_default_category;
static volatile sig_atomic_t zlog_env_reload_conf_count;
static size_t zlog_env_reload_conf_count;
static int zlog_env_init_flag = -1;
/*******************************************************************************/
/* inner no need thread-safe */
......
......@@ -17,8 +17,8 @@ noinst_PROGRAMS = \
test_press_zlog \
test_press_zlog2 \
test_press_syslog \
test_press_fwrite \
test_press_fwrite2 \
test_press_write \
test_press_write2 \
test_syslog \
test_conf \
test_mdc \
......@@ -38,8 +38,8 @@ test_hex_SOURCES = test_hex.c
test_init_SOURCES = test_init.c
test_press_zlog_SOURCES = test_press_zlog.c
test_press_zlog2_SOURCES = test_press_zlog2.c
test_press_fwrite_SOURCES = test_press_fwrite.c
test_press_fwrite2_SOURCES = test_press_fwrite2.c
test_press_write_SOURCES = test_press_write.c
test_press_write2_SOURCES = test_press_write2.c
test_press_syslog_SOURCES = test_press_syslog.c
test_syslog_SOURCES = test_syslog.c
test_mdc_SOURCES = test_mdc.c
......
......@@ -13,8 +13,8 @@ exe = \
test_record \
test_press_zlog \
test_press_zlog2 \
test_press_fwrite \
test_press_fwrite2 \
test_press_write \
test_press_write2 \
test_press_syslog \
test_syslog \
test_default \
......
......@@ -29,7 +29,6 @@
#include "zlog.h"
FILE *fp;
int fd;
static long loop_count;
......@@ -37,11 +36,12 @@ static long loop_count;
void * work(void *ptr)
{
long j = loop_count;
int rc;
static char aa[] = "2012-06-14 20:30:38.481187 INFO 24536:140716226213632:test_press_zlog.c:36 loglog\n";
while(j-- > 0) {
// fprintf(fp, "2012-05-16 17:24:58.282603 INFO 22471:test_press_zlog.c:33 loglog\n");
fwrite(aa, sizeof(aa)-1, 1, fp);
// write(fd, aa, sizeof(aa)-1);
// fwrite(aa, sizeof(aa)-1, 1, fp);
rc = write(fd, aa, sizeof(aa)-1);
}
return 0;
}
......@@ -61,7 +61,7 @@ int test(long process_count, long thread_count)
pthread_t tid[thread_count];
for (j = 0; j < thread_count; j++) {
pthread_create(&(tid[j]), NULL, work, fp);
pthread_create(&(tid[j]), NULL, work, NULL);
}
for (j = 0; j < thread_count; j++) {
pthread_join(tid[j], NULL);
......@@ -87,10 +87,11 @@ int main(int argc, char** argv)
fd = open("press.log", O_CREAT | O_WRONLY | O_APPEND, 0644);
fp = fdopen(fd, "a");
//fp = fdopen(fd, "a");
loop_count = atol(argv[3]);
test(atol(argv[1]), atol(argv[2]));
fclose(fp);
//fclose(fp);
close(fd);
return 0;
......
......@@ -34,23 +34,21 @@ static long loop_count;
void * work(void *ptr)
{
long j = loop_count;
int rc;
static char log[] = "2012-06-14 20:30:38.481187 INFO 24536:140716226213632:test_press_zlog.c:36 loglog\n";
char file[20];
sprintf(file, "press.%ld.log", (long)ptr);
/*
int fd;
fd = open(file, O_CREAT | O_WRONLY | O_APPEND , 0644);
*/
FILE *fp;
fp = fopen(file, "a");
//FILE *fp;
while(j-- > 0) {
//write(fd, log, sizeof(log)-1);
fwrite(log, sizeof(log)-1, 1, fp);
rc = write(fd, log, sizeof(log)-1);
//fwrite(log, sizeof(log)-1, 1, fp);
}
fclose(fp);
//close(fd);
//fclose(fp);
close(fd);
return 0;
}
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment