Chinaunix首页 | 论坛 | 博客
  • 博客访问: 97761
  • 博文数量: 10
  • 博客积分: 207
  • 博客等级: 入伍新兵
  • 技术积分: 380
  • 用 户 组: 普通用户
  • 注册时间: 2012-11-10 12:44
文章存档

2015年(2)

2013年(1)

2012年(7)

我的朋友

分类: 系统运维

2015-01-25 00:27:58

前些日子,做了一些日志优化,我的某个程序,打开日志的情况下单机性能非常差。。
看不下去了,着手改了下,开着日志,打了点压力,问题出来了,在压力下延时明显增加,perf看到spin_lock出来了。。
继续加压,性能不能增加,看来各线程都被spin_lock给锁住了。。
我们的日志模式理论上不应该有这种问题,是多个worker线程,通过无锁ring把日志传到某个线程上,由这个线程单独写日志。
我们使用的是多生产者,单消费者模式的无锁ring。
刚开始觉得难道是dpdk这个无锁ring的问题?可是不能啊,实现上就多了那么点CAS指令就这么差了?
无锁ring的性能不可能这么差,搂了下dpdk 无锁ring的实现,并没有什么地方调用spin_lock。。
dpdk 的ring就是多了个CAS指令,可是理论上CAS指令也是非常快的呀。。
遗漏了什么?
回到最初的问题,开日志,性能很差,不开日志,性能还不错。差别在各线程多了构造日志,通过无锁ring发过来。
忽略了构造日志这个基本环节了!

点击(此处)折叠或打开

  1. static void log_fmt_msg(struct log_msg *log, int type, int level, const char *fmt, va_list args)
  2. {
  3.     int size;
  4.     long ts = time(NULL);
  5.     struct tm *ptm = localtime(&ts);
  6.   ...
  7.     }
  8. }

good,都忘了调用的是glibc的localtime()了,下载glibc 2.12 看了下localtime()的实现,

点击(此处)折叠或打开

  1. /* The C Standard says that localtime and gmtime return the same pointer. */
  2. struct tm _tmbuf;
  3.                               
  4.         
  5. /* Return the `struct tm' representation of *T in local time,
  6.    using *TP to store the result. */
  7. struct tm *
  8. __localtime_r (t, tp)
  9.      const time_t *t;
  10.      struct tm *tp;
  11. {
  12.   return __tz_convert (t, 1, tp);
  13. }
  14. weak_alias (__localtime_r, localtime_r)
  15.     
  16.       
  17. /* Return the `struct tm' representation of *T in local time. */
  18. struct tm *
  19. localtime (t)
  20.      const time_t *t;
  21. {
  22.   return __tz_convert (t, 1, &_tmbuf);
  23. }
  24. ~

  25. ~

点击(此处)折叠或打开

  1. struct tm *
  2. __tz_convert (const time_t *timer, int use_localtime, struct tm *tp)
  3. {
  4.   long int leap_correction;
  5.   int leap_extra_secs;

  6.   if (timer == NULL)
  7.     {
  8.       __set_errno (EINVAL);
  9.       return NULL;
  10.     }

  11.   __libc_lock_lock (tzset_lock);
  12.       
  13.   /* Update internal database according to current TZ setting.
  14.      POSIX.1 8.3.7.2 says that localtime_r is not required to set tzname.
  15.      This is a good idea since this allows at least a bit more parallelism.
  16.      By analogy we apply the same rule to gmtime_r. */
  17.   tzset_internal (tp == &_tmbuf);

  18.   if (__use_tzfile)
  19.     {
  20.       if (! __tzfile_compute (*timer, use_localtime,
  21.                               &leap_correction, &leap_extra_secs, tp))
  22.         tp = NULL;
  23.     }
  24.   else
  25.     {
  26.       if (! (__offtime (timer, 0, tp) && tz_compute (tp)))
  27.         tp = NULL;
  28.       leap_correction = 0L;
  29.       leap_extra_secs = 0;
  30.     }

  31.   if (tp)
  32.     {
  33.       if (use_localtime)
  34.         {
  35.           if (!__use_tzfile)
  36.             {
  37.               int isdst = (*timer >= tz_rules[0].change
  38.                            && *timer < tz_rules[1].change);
  39.               tp->tm_isdst = isdst;
  40.               tp->tm_zone = __tzname[isdst];
  41.               tp->tm_gmtoff = tz_rules[isdst].offset;
  42.             }
  43.         }
  44.       else
  45.         {
  46.           tp->tm_isdst = 0;
  47.           tp->tm_zone = "GMT";
  48.           tp->tm_gmtoff = 0L;
  49.         }

  50.       if (__offtime (timer, tp->tm_gmtoff - leap_correction, tp))
  51.         tp->tm_sec += leap_extra_secs;
  52.       else
  53.         tp = NULL;
  54.     }

  55.   __libc_lock_unlock (tzset_lock);

  56.   return tp;
  57. }

good,问题出来了,锁在__tz_convert()中
那也就是我每个worker线程调用localtime()函数就有很大问题了,相互之间有竞争抢锁问题
网上搜了下,用gettimeofday稍微合适点,但是也有系统调用问题
知道原因就简单了,解决:在某个线程中每10ms调用一次gettimeofday,把时间字符串构造出来,赋值给一个全局变量。每个worker线程直接去读取这个时间字符串变量就好了,毕竟目前我们日志的精度到秒就行了。
改完后试了下,锁没了,性能上去了。

问题:这个故事告诉我们,glibc提供的函数,不是随便可以调用的。

阅读(2771) | 评论(0) | 转发(0) |
0

上一篇:Redis random()函数问题

下一篇:没有了

给主人留下些什么吧!~~
评论热议
请登录后评论。

登录 注册