ip分片与重组

December 19th, 2014 No comments

最近在做udp pump, 突然手贱的想要知道一个udp包的最大负载的是多少.
于是写了一个简单的程序来测试了一下, client不断的发送payload size不断增加的包, 然后在server端收数据包. 当然了由于IP的最大payload只有65535-sizeof(IP Header).所以Udp的最大负载也就是只有大约65535-20-8 = 65507个. 如果超过这个大小以后,不是收不到, 而是client根本发不出去这个数据包

#!/usr/bin/env python
#-*- coding:utf-8 -*-

import socket
import random
import string
import sys
import hashlib

def sendData(udp, ip,port, size):
    data = ''.join(random.choice(string.ascii_uppercase + string.digits) for _ in range(size))
    md5 = hashlib.new('md5')
    md5.update(data)
    udp.getsockname()
    udp.sendto(data,(ip,port))
    print "%s :: sending %08d bytes to %s:%d   --> %s" % ( udp.getsockname(), len(data), ip,port, md5.hexdigest())


def run(ip,port,begin,inc,end):
    udp = socket.socket(socket.AF_INET, socket.SOCK_DGRAM, socket.IPPROTO_IP)
    udp.bind(("0.0.0.0",0))
    sendData(udp, ip, port, 65507)
    sendData(udp, ip, port, 65508)

用上面的代码发送可以很轻松的验证,发送65507个字节的时候是OK的,但是65508的数据就会得到Message Too Long的错误.

接下来呢, 我做了一件错误的事情,然后导致了后来一系列的事情的发生.
我在server端使用tcpdump来查看网络数据包, udp server listen在6666端口.所以我使用命令来查看数据包

sudo tcpdump -i any -nnn -vvv "port 666"

注意我的 tcpdump的filter是”port 6666″,也就是采用过滤端口的方式.这个也就是我想当然的认为ip fragment以后的每一个udp packet的port应该和原始数据是一致.

拿到tcpdump的数据以后我下了一大跳

17:06:09.875525 IP (tos 0x0, ttl 61, id 28605, offset 0, flags [+], proto UDP (17), length 1500)
    192.168.80.233.52099 > 10.15.10.50.6666: UDP, length 65507

请看IP的段显示的数据大小为1500, 这个很容易理解,毕竟大部分的网络的MTU都是1500,这里也不例外.但是UDP段显示的length是65507, 这个也说得过去, 我发送的数据就是这么大的. 但是问题来了,为啥只有这么一个数据包. 于是我猜测抓包显示的数据错掉了.我把抓包数据存下来以后发现文件大小也就是1500多一点大.那么很明显这个数据包里面的数据真的只有1500 bytes. 这里的事情被我认为是非常诡异的, 因为我发送数据的时候对数据做了一个md5,udpserver收到数据以后也会做一个md5. 这两个md5是一模一样的,那么很明显证明了server端收到的数据和client发送的数据是一样的.
但是抓的包却只有1500 bytes啊,剩下的数据死到哪里去了呢?
我一度怀疑tcpdump有bug,于是换成了wireshark(tshark). 但是得到的结果是一样,见鬼了. 于是乎一阵google以后找到了使用raw socket来抓数据包的代码在这里.感谢作者的无私分享. 用这个程序跑了一下,只抓udp的包. 从抓包数据看,端口为6666的仍旧只有1500字节的ip数据, 但是很奇怪的是不是6666端口的其他数据包里面的数据和我发送的数据十分相似–随机的字符数字组合. 然后我发现了一个东西,也是这个东西让我明白了这到底是怎么回事.

IP Header
   |-IP Version        : 4
   |-IP Header Length  : 5 DWORDS or 20 Bytes
   |-Type Of Service   : 0
   |-IP Total Length   : 1500  Bytes(Size of Packet)
   |-Identification    : 63208
   |-Dont Fragment Field   : 0
   |-More Fragment Field   : 0
   |-TTL      : 62
   |-Protocol : 17
   |-Checksum : 35759

这个让我感觉很奇妙的东西就是Identification. 因为抓包数据中的所有包头都含有相同的Identification. 这个不免让我觉得其实IP分片以后实际上是靠Identification来决定是不是同一个上层数据包的内容的. 于是我查看了一下ip分片的实现

/* Find the correct entry in the "incomplete datagrams" queue for
 * this IP datagram, and create new one, if nothing is found.
 */
static inline struct ipq *ip_find(struct net *net, struct iphdr *iph, u32 user)
{
        struct inet_frag_queue *q;
        struct ip4_create_arg arg;
        unsigned int hash;

        arg.iph = iph;
        arg.user = user;

        read_lock(&ip4_frags.lock);
        hash = ipqhashfn(iph->id, iph->saddr, iph->daddr, iph->protocol);

        q = inet_frag_find(&net->ipv4.frags, &ip4_frags, &arg, hash);
        if (q == NULL)
                goto out_nomem;

        return container_of(q, struct ipq, q);

out_nomem:
        LIMIT_NETDEBUG(KERN_ERR "ip_frag_create: no memory left !\n");
        return NULL;
}

上面的ip_find是从ip_local_deliver => ip_defrag => ip_find这个调用链过来的. 我们可以看到这里使用ip header里面的id, source addr, dest addr和protocol来做一个hash, 远没有port啥事.
到这里已经很清楚了, udp发的数据的最大负载是65535-20 -8 = 65507. 但是到了ip层的话还是需要被分片的, 否则过不了交换机. ip分片的依据的ip header中的id, 当然还需要由frags来指明fragment的offset之类的信息.
这个时候再回头来想想当初为何就没有想到, port是udp/tcp层的东西, ip层是没有这个玩意儿的. 那么分片自然就是和port无关的了.

Categories: programming Tags: , , ,

Debug Heap Corrupt

December 12th, 2014 No comments

c/c++代码对内存操作有着极强的控制力, 但是也很容易造成问题。 特别是内存访问越界这类问, 一旦出现了,在很多情况下是很难查找的。 如果软件中的某个模块因为单元测试没有完全覆盖(这个通常也很难)然后集成起来以后出来的这类问题就更加难以查找。 很多时候出现问题的地方根本就不是你看到的地方。 我们来举个例子, 这个也是我们遇到的问题的一个简化版本。 直接上代码

#include <stdio.h>
#include <string.h>
#include <stdlib.h>
#include <vector>

void corrupt( ) {
    char* p = (char*)malloc(1);
    memset(p,0x47,32);//fill some garbage to corrupt the heap
}

void victim( ) {
    std::vector<int> arr;
    for(int i = 0 ; i < 100; i ++ ) {
        arr.push_back(i);
    }
}

int main(int argc, char* argv[]){
    corrupt();
    victim();
    return 0;
}

上面的代码在corrupt函数中分配了一个字节的空间,接着调用memset向分配的地址写入32个0x47. 那么很明显,写越界了。 这样的操作会把heap的维护链表弄坏,导致以后再次进行内存分配释放的时候出现错误,也可能写入另外一块分配的内存区域。
在vc(visual studio 2005)下面编译运行以后在

        arr.push_back(i);

出现错误。 output窗口(调试模式下面)输出

First-chance exception at 0x7c922bb3 (ntdll.dll) in heap_corrupt.exe: 0xC0000005: Access violation reading location 0x003b6000.

很明显出现错误的地方并不是造成问题的地方, 这个简单的程序你可能很容易就可以看出问题出在什么位置。但是如果是一个很复杂的大型工程,那么很可能就没有那么容易了。如果没有其他的帮助工具的话估计要花很大的时间和精力来逐步收缩出问题的范围。
上面的代码在g++下面(需要增加一些include的头文件)编译运行以后也会显示是arr.push_back(i)这一行除了问题。
为了能有效的快速定位此类问题, 我们通常需要借助其他的工具。 在windows上面我们可以使用gflags来做到这一点。
使用如下命令,monitor heap的操作

gflags /p /enable heap_corrupt.exe /full

然后再来调试改程序,就会在memset(p,0x47,32);这一行发生异常。 那么我们就可以很快的检查出来是因为对p的写越界造成了这个问题。 但并不是有这个工具就万事OK了。如果我们把memset那一句改成memset(p,0x47,2);的话。那么程序在整个调试过程中是不会出错的,当然了,这个很可能是因为malloc(1)的时候得到的内存块的真是大小不是1而是某个最小的bucket的大小.
在linux上面呢, 我们可以使用AddressSanitizer这种神器来快速定位这个问题。因为我们的gcc版本是4.4.7的,还没有AddressSanitizer的支持,所以可以使用clang.

clang++ -g -fsanitize=address -o t test.cpp

然后直接运行程序就可以在输出上看到一堆东西

[hongquan.zhang@devbox Download]$ ./t
=================================================================
==1216==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x60200000f00f at pc 0x48aaab bp 0x7fff4a1687d0 sp 0x7fff4a1687c8
WRITE of size 32 at 0x60200000f00f thread T0
    #0 0x48aaaa in corrupt() /home/hongquan.zhang/Download/test.cpp:10
    #1 0x48b0d0 in main /home/hongquan.zhang/Download/test.cpp:21
    #2 0x3f7201ecdc in __libc_start_main (/lib64/libc.so.6+0x3f7201ecdc)
    #3 0x48a84c in _start (/home/hongquan.zhang/Download/t+0x48a84c)

0x60200000f00f is located 30 bytes to the right of 1-byte region [0x60200000eff0,0x60200000eff1)
allocated by thread T0 here:
    #0 0x473131 in malloc /home/hongquan.zhang/Work/tools/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:74
    #1 0x48a9cb in corrupt() /home/hongquan.zhang/Download/test.cpp:9
    #2 0x48b0d0 in main /home/hongquan.zhang/Download/test.cpp:21
    #3 0x3f7201ecdc in __libc_start_main (/lib64/libc.so.6+0x3f7201ecdc)

SUMMARY: AddressSanitizer: heap-buffer-overflow /home/hongquan.zhang/Download/test.cpp:10 corrupt()
Shadow bytes around the buggy address:
  0x0c047fff9db0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9dc0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9dd0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9de0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9df0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa 01 fa
=>0x0c047fff9e00: fa[fa]fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9e10: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9e20: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9e30: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9e40: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c047fff9e50: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Heap right redzone:      fb
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack partial redzone:   f4
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Contiguous container OOB:fc
  ASan internal:           fe
==1216==ABORTING

输出的最开始就表明了出错的地方是corrupt函数,可以非常方便的让我们在第一时间发现真正制造问题的地方。而且即便你把memset调用改成memset(p,0x47,1)也依然有效。

上面的方法也许对你在遇到问题的时候有一些帮助,当然了最好还是在操作内存的时候小心一些。如果可以的话,尽量使用c++已经封装好的class。 如果不得已需要直接操作内存需要慎之又慎。

Categories: programming Tags: ,

C++抛exception会主动让出CPU吗?

September 10th, 2014 No comments

虽然我自己并不是很喜欢使用exception.但是在有的场合用exception比return code让代码更具可阅读性.一直以来,我都认为throw exception不会大幅度降低程序的性能, 但是最近线上发生的一件事情却把exception这个东西牵扯了进来.
事情很简单, 现场报说有的请求timeout(500ms超时). 查看log以后发现一部分代码可能造成这个问题,但是当时并无法肯定是哪一个调用造成的耗时长. 后来做了一系列的实验以后发现居然是一个查找部分的代码会很耗时(最长可达1s), 但是这个查找的代码的实现及其的简单.基本上就是这个样子:

void findXXX( ) {
    find in a std::map<std::string, std::string> instance;
    if not found {
        throw InvalidParameter();
    }
}

而当时的情况是, map中是没有数据的,也就是说一定会出发抛出异常. 开始我怎么都觉得throw exception会那么耗时.可是多次的测试下来却发现总是在这个点上可能耗时很长.那么无论如何这个抛异常看起来都有点问题.
于是我做了一个小程序,就是很简单的抛异常100w次.但是没有发现耗时很长的情况发生(至少和我预期是一样的). 那么为何线上程序总是在这个抛异常的地方出现问题呢? 于是对比了自己的模拟程序和线上程序,发现了一个很大的不同点,那就是线上程序是多线程的,而且线程相当多(500+),而我的测试程序是单线程的.那么有没有可能是抛异常会导致线程切换,最终引发耗时长呢?
于是我修改了一下测试程序,加入线程,线程run里面就是不断的++一个long long,过一会儿sleep 30ms. 我一共new了800个线程(我也是够猛的). 这次测试程序我做了两个版本,一个是抛异常的,另外一个是不抛异常,取而代之的是循环++10次,然后return的.
从这两个版本的测试结果来看,在同一个环境(CentOS5, 4core cpu, 16G mem)上测试10次,平均下来,抛异常的版本运行时间为26s,而不抛异常的版本运行时间为1.5s左右. 同时抛异常的版本中能监测到有很50+次调用函数耗时达1ms以上的.而不抛异常的版本平均只有2次不到.
基于这些测试, 我猜测很可能抛异常会引发context switch. 同时由于线程数量巨大,线程切换十分频繁. 最终造成这个简单的findXXX耗时很大.
当然了,这个只是我的猜测,没有证实. 希望以后可以继续看看是不是真的造成了主动的线程切换.

PS: google了好一阵, 还没有直接证据可以证明throw exception可能导致线程上下文切换. 以后有空倒是可以看看libstdc++的实现.

Categories: programming Tags: ,

一个简单的rolling filelog,written in go

August 29th, 2014 No comments

使用了go-logging但是发现它只有logging format部分,没有数据输出部分(直接使用os.File进行输出). 所以自己做了一个简单的rolling file log. 可以设置保留的log文件个数,每一个log文件的最大字节数,强制flush的时间间隔.
使用方法如下:

func main() {
    l := rolling_filelog.LogFile{BaseName: "./test.log",
                MaxSize: 5*1024*1024,
                FileCount: 10,
                FlushInterval: 2*time.Second,
                BufferSize: 10*1024,
                BufferCount: 3}
    err := l.Open()
    if err != nil {
        fmt.Printf("failed to open log file,%s: %s\n", l.BaseName, err)
        return
    }
    data := make([]byte,10)
    copy(data[:],"1234567890")

    for i := 0 ; i < 10000000; i ++ {
        n,err := l.Write(data)
        if err != nil {
            fmt.Printf("failed to write data to %s :%s\n", l.BaseName, err )
            return
        }
        if n <= 0 {
            fmt.Printf("failed to write data to %s : %s\n", l.BaseName, "0 bytes written")
            return
        }
    }
    l.Close()

当然了,这个是用作其他logging的backend的,例go-logging

 logFile := utils.LogFile{BaseName: "./test.log",
                MaxSize: 8*1024,
                FileCount: 3,
                FlushInterval: 2*time.Second,
                BufferSize: 1*1024,
                BufferCount: 3}
    if logFile == nil {
        fmt.Println("failed to open log file")
        return nil
    }

    logger := logging.MustGetLogger("")
    if logger == nil {
        logFile.Close()
        return nil
    }

    logging.SetFormatter(logging.MustStringFormatter(" %{level:.4s} %{message}"))
    logBackend := logging.NewLogBackend( logFile, "", stdlog.LstdFlags|stdlog.Lmicroseconds)
    logging.SetBackend(logBackend)
    logging.SetLevel(logging.INFO,"")

这样以来, 日志文件就会保持在FileCount指定的数量上滚动, 以防止日志文件的无限制增长而吃光存储空间.

Categories: programming Tags: , ,

不要随意设置SO_LINGER为0

August 26th, 2014 No comments

我们的一个应用频繁的使用http协议传输数据, 由于一开始没有使用keep-alive. 导致server端有大量的TIME_WAIT的socket, 当时server端的解决办法是设置SO_LINGER为{l_onoff=1,l_linger=0}.这样close的时候就会直接发送RST而不是FIN,绕过了TIME_WAIT这个状态. 经过一些简单测试,看起来是解决了TIME_WAIT的问题. 但其实这样做是非常不妥的.
当设置SO_LINGER=0以后,我们调用close, tcp会直接丢弃当前在write buffer中的数据,而直接发送RST到对端. 那么意味着如果你在调用close的时候,不管何种原因导致write buffer还有数据没有被发送的话,那么对端将无法接收到完整的数据.
我们来看看linux是如何处理close的

void tcp_close(struct sock *sk, long timeout)
{
       ...

       while ((skb = __skb_dequeue(&sk->sk_receive_queue)) != NULL) {
                u32 len = TCP_SKB_CB(skb)->end_seq - TCP_SKB_CB(skb)->seq -
                          tcp_hdr(skb)->fin;
                data_was_unread += len;
                __kfree_skb(skb);
        }

        sk_mem_reclaim(sk);

        ...

         if (data_was_unread) {
                /* Unread data was tossed, zap the connection. */
                NET_INC_STATS_USER(sock_net(sk), LINUX_MIB_TCPABORTONCLOSE);
                tcp_set_state(sk, TCP_CLOSE);
                tcp_send_active_reset(sk, sk->sk_allocation);
        } else if (sock_flag(sk, SOCK_LINGER) && !sk->sk_lingertime) {
                /* Check zero linger _after_ checking for unread data. */
                sk->sk_prot->disconnect(sk, 0);
                NET_INC_STATS_USER(sock_net(sk), LINUX_MIB_TCPABORTONDATA);
        } else if (tcp_close_state(sk)) {

            ...
            tcp_send_fin(sk);
        }
        ...
}

int tcp_disconnect(struct sock *sk, int flags)
{
        /* ABORT function of RFC793 */
        if (old_state == TCP_LISTEN) {
                inet_csk_listen_stop(sk);
        } else if (tcp_need_reset(old_state) ||
                   (tp->snd_nxt != tp->write_seq &&
                    (1 << old_state) & (TCPF_CLOSING | TCPF_LAST_ACK))) {
                /* The last check adjusts for discrepancy of Linux wrt. RFC
                 * states
                 */
                tcp_send_active_reset(sk, gfp_any());
                sk->sk_err = ECONNRESET;
        } else if (old_state == TCP_SYN_SENT)
                sk->sk_err = ECONNRESET;
        ...
         tcp_clear_xmit_timers(sk);
        __skb_queue_purge(&sk->sk_receive_queue);
        tcp_write_queue_purge(sk);
        __skb_queue_purge(&tp->out_of_order_queue);
        ...
}

void tcp_send_active_reset(struct sock *sk, gfp_t priority)
{
        struct sk_buff *skb;

        /* NOTE: No TCP options attached and we never retransmit this. */
        skb = alloc_skb(MAX_TCP_HEADER, priority);
        if (!skb) {
                NET_INC_STATS(sock_net(sk), LINUX_MIB_TCPABORTFAILED);
                return;
        }

        /* Reserve space for headers and prepare control bits. */
        skb_reserve(skb, MAX_TCP_HEADER);
        tcp_init_nondata_skb(skb, tcp_acceptable_seq(sk),
                             TCPCB_FLAG_ACK | TCPCB_FLAG_RST);
        /* Send it off. */
        TCP_SKB_CB(skb)->when = tcp_time_stamp;
        if (tcp_transmit_skb(sk, skb, 0, priority))
                NET_INC_STATS(sock_net(sk), LINUX_MIB_TCPABORTFAILED);

        TCP_INC_STATS(sock_net(sk), TCP_MIB_OUTRSTS);
}
void tcp_send_fin(struct sock *sk)
{
        ...
       if (tcp_send_head(sk) != NULL) {
                TCP_SKB_CB(skb)->flags |= TCPCB_FLAG_FIN;
                TCP_SKB_CB(skb)->end_seq++;
                tp->write_seq++;
        } else {
                ...
                tcp_queue_skb(sk, skb);
        }
        __tcp_push_pending_frames(sk, mss_now, TCP_NAGLE_OFF);
}

在这里的代码, 从tcp_close里面可以看到,

  1. 在close的时候如果socket上还有数据没有被读取,那么会直接调用tcp_send_active_reset发送RST到对端.
  2. 如果设置linger为0,那么调用disconnect函数,在这里是tcp_disconnect
  3. 第三种情况会调用tcp_send_fin
    tcp_diconnect也会调用 tcp_send_active_reset函数(我们只关心established的socket的close). 而我们看看tcp_send_active_reset可以发现它是直接发送RST包,也就是并没有把数据包加入到sending window里面.调用完tcp_send_active_reset以后我们回到tcp_disconnect函数,可以发现这是socket的write buffer已经清空.当然这个动作对于对端来说没法意义,因为对端已经收到RST了.
    对于调用tcp_send_fin的情况,就是完全不一样的情景了.在tcp_send_fin里面要么给未flush的数据加上FIN标志,要么生成一个新的FIN数据包,加入到write队列中. 然后强制发送当前未发送的数据.

所以特别是对于发送数据的一段,不要轻易的设置SO_LINGER=0,否则有一定的概率出现对端收不到完整的数据的情况. 而应该使用长连接(keep-alive)并且由数据接收端来判断数据是否接受完整从而决定是否关闭连接

Categories: programming Tags: , , ,

daemon平滑升级

March 15th, 2014 No comments

对于socket server来说,平滑升级对于用户体验是一个很好的加分。这样可以不对用户操作造成任何影响。而平滑升级的最直接最核心的应该就是不在升级的过程中关掉listen端口,也不断掉当前的连接,同时还可以接受新的连接,所有的已被接受的请求必须要完整的执行完毕,不能因为升级步骤而终止.

为了到达以上几点,一般来说可以如下来达到平滑升级的目的。
1. 分区域升级。 首先在总控部分,禁掉某些部分server接受新请求的能力。然后等待这些server的当前请求全部执行完毕以后开始升级这些server上的服务。采用这种方法逐步升级所有的server
2. 采用类似nginx的平滑升级的方法。

第一种方法对于那些直接面对客户端的server是行不通的,因为一旦停掉一会儿,客户端就无法正常连接了。还有就是即便是分布式的后台加上一个proxy, 也可能会因为某些特定的请求很难在短时间内完成而无法升级(例如,一个广播流的频道请求),对于这些特定的就需要在指定的维护窗口时间强行升级服务了。
第二种方法看起来比较的容易接受。google了一下nginx的平滑升级的办法。其主要使用到了如下几点技术:

1. 未设置FD_CLOEXEC 属性的文件描述符在fork以后会被child process继承,一般来说除了listen socket和log以外的fd都会设置这个属性
2. 把需要在child process里面使用的文件描述符通过env或者命令行参数在调用execv的时候传入新的process
3. 在启动child process之前,停止accept新的请求。
4. parent process一直服务到所有的请求执行完毕以后正常退出。
5. child process在收到传入的文件描述符(通常是用于listen的那个socket的fd)以后使用这个fd来做accept操作。

这个方法解决了socket连接的平滑升级,但是对于log的问题,我还不是特别肯定。如果parent process和child process都是用同一个log文件的描述符,那么必然会造成打印出的日志是混乱的。当然如果你的日志写入是严格按照一个信息块的方式写入的话(也就是不是几个字节几个自己的写入),而vfs_write又是对inode加锁的,那么虽然会有parent process和child process的日志混杂在一起,但是每一条日志内容本身应该是有完整信息的。(这个还需要核实)。

在这里有相关的测试代码

 

Written with StackEdit.

Categories: programming Tags:

program killed by signal 4

March 4th, 2014 No comments

一个跑在linux上的程序crash了,coredump的文件名显示是被signal 4干掉的。哎呀,第一次见到signal 4. 赶紧kill -l看了一下,原来4是指SIGILL,就是invalid instruction. 一般来说我会认为这个东西是stack buffer overflow。 对我们自己的程序来说最可能出错的地方就是打印日志的时候参数类型和format里面指定的类型不一致。特别是fmt=”%s”但是传入了一个sd::string。但是我记得以前这种问题貌似都不会是SIGILL,要么SIGABORT要么SIGSEGV。那么这次是咋回事呢。

上gdb,同时把symbol文件放上去了。看了一下callstack。



(gdb) bt

0x00000000004ab9cc in waitForResponse (this=0x7f12e80804d8, cseq=2)

0x0000000000525920 in SsServiceImpl::doCommit (ss=..., ctx=..., )

0x0000000000570ecd in SsStreamCommitRequest::run (this=0x7f125c001330)

0x00007f12f51318ca in SlaveThread::run (this=0x7f12e80260d0)

0x00007f12f5120fc2 in NativeThread::_execute (thread=0x7f12e80260d0)

0x00007f12f2dba851 in start_thread () from /lib64/libpthread.so.0

0x00007f12f30b767d in clone () from /lib64/libc.so.6

其中waitForResponse里面主要是等待一个信号量。检查其代码没有发现啥问题,而且该函数内部没有任何日志打印的调用。

在老半天没有进展的境况下,我尝试着看了一下反汇编的结果



(gdb) set disassembly-flavor intel

(gdb) disas

...

   0x00000000004ab9ca <+256>:   leave

   0x00000000004ab9cb <+257>:   ret

=> 0x00000000004ab9cc <+258>:   ud2a

   0x00000000004ab9ce <+260>:   mov    ebx,edx

   0x00000000004ab9d0 <+262>:   mov    r12,rax

   0x00000000004ab9d3 <+265>:   lea    rax,[rbp-0x40]

箭头所指的地方就是crash的点,但是,但是ud2a是个神马玩意儿,对汇编不甚了解啊。

还是求助于google大神吧。

一阵瞎找以后看到了这篇文章里面解释了gcc在遇到format里面的参数类型和传入参数类型不匹配的时候报了warning,但是同时可能会产生出ud2a之类的代码,让程序在运行时挂掉。

例如:



struct A {

    int a,b,c,d;

};

A a;

log.info("What a stupid error [%p]",a);

呵呵,我们的代码中就犯了这样的错误。

修改以后让同事们多加注意代码问题以及build时候的warning.



t.c:9:2: warning: format ‘%p’ expects argument of type ‘void *’, but argument 2 has type ‘struct AA’ [-Wformat=]

  log.info("What a stupid error [%p]\n",a);

  ^

Written with StackEdit.

Categories: Uncategorized Tags:

go的测试程序,与预期不符合。不知道是哪里理解不正确了

March 1st, 2014 No comments

在学习go的时候,按照[go语言编程]第94页的例子写了一个测试程序,如下

package main
import  (
    "fmt"
)
func Count( ch chan int, value int ) {
    ch <- value
    fmt.Println("Counting")
}
func main( ) {
    chs :=make( []chan int, 10 )
    for i := 0; i < 10; i++ {
        chs[i] = make(chan int) //请注意这一行
        go Count(chs[i],i)
    }
    var value int
    for _, ch := range(chs) {
        value = <-ch
        fmt.Printf("got value %d\n",value)
    }
}


但是运行的时候发现结果与我预期的不一样。本来我认为这个程序会打印10行Counting, 但实际上只有1行Counting出现。
于是我把标示那一行改成

chs[i] = make(chan int,1)

就这样,运行的时候就可以打印出10行Counting来了。是在不明白这个到底是咋回事啊。
继续修改有标示的那一行发现,如果make( chan int, 0 )或者make( chan int)那么就只会打印一行Counting.如果make的第二个参数>= 1,那么就会如预期一般打印10行Counting.
这让我更加糊涂了,按照书上所讲。make( chan int, x)的方式是建立一个有缓冲区且大小为x的channel。而且测试程序始终能够输出如下:

got value 0
got value 1
got value 2
got value 3
got value 4
got value 5
got value 6
got value 7
got value 8
got value 9

 

那么至少代表建立的10个 go routine是开始执行了的。看起来当make( chan int, 0)的时候只有一个Count的go routine在向channel写入数据以后被切换回去继续执行了,而剩下的Count的go routine都没有得到执行机会。不过这个不能解释为何make( chan int, x) x >=1 的时候所有的go routine就都机会执行完毕了。

嗯,我的go的版本是:

$ go version
go version go1.2 linux/amd64

Written with StackEdit.

Categories: programming Tags: ,

为何多线程程序占用这么多内存(linux)(续)

January 26th, 2014 2 comments

上一篇文章指出了在Centos6.4 x86_64下面多线程程序会相当占用内存资源。经过一番google和代码查看。终于知道了原来是glibc的malloc在这里捣鬼。请看developerworks该文章指出在glibc 2.10以上的版本会有这个问题,我的glibc版本是2.12

lrwxrwxrwx 1 root root 12 Oct 21 21:29 /lib64/libc.so.6 -> libc-2.12.so

glibc为了分配内存的性能的问题,使用了很多叫做arena的memory pool,缺省配置在64bit下面是每一个arena为64M,一个进程可以最多有 cores * 8个arena。假设你的机器是4核的,那么最多可以有4 * 8 = 32个arena,也就是使用32 * 64 = 2048M内存。 当然你也可以通过设置环境变量来改变arena的数量.例如export MALLOC_ARENA_MAX=1
hadoop推荐把这个值设置为4。当然了,既然是多核的机器,而arena的引进是为了解决多线程内存分配竞争的问题,那么设置为cpu核的数量估计也是一个不错的选择。设置这个值以后最好能对你的程序做一下压力测试,用以看看改变arena的数量是否会对程序的性能有影响。

后记:如果你打算在程序代码中来设置这个东西,那么可以调用mallopt(M_ARENA_MAX, xxx)来实现,不过很奇怪的是我在centos6.4上面居然看不到mallopt的man page,最后实在我的ubuntu 12.04的虚拟机上看到这个函数解释,而且里面并没有M_ARENA_MAX这个宏的解释。最后我实在glibc2.12的malloc/malloc.c的mALLOPt函数实现中才看到M_ARENA_MAX的。

Categories: programming Tags: , ,

记一个subclass gevent.Greenlet遇到的问题

January 22nd, 2014 No comments

打算子类化gevent.Greenlet,大致样子如下:


from gevent import Greenlet
class Runner( Greenlet ):
  def __init__(self):
      Greenlet.__init__(self)
  def _run( self ):
      self.run() # invoke the real run

class Downloader( Runner ):
  def __init__(self):
      Runner.__init__(self)
  def run(self):
      print "processing ..."

d = Downloader()
d.start()
d.join()

结果一运行就出错了,

processing ...
Traceback (most recent call last):
  File "test.py", line 30, in <module>
    d.join()
  File "/usr/local/lib/python2.7/dist-packages/gevent/greenlet.py", line 290, in join
    result = self.parent.switch()
  File "/usr/local/lib/python2.7/dist-packages/gevent/hub.py", line 331, in switch
    return greenlet.switch(self)
gevent.hub.LoopExit: This operation would block forever

一时间没有搞懂是怎么回事,于是google了一下,但是看起来别人的问题和我这个不相关。
于是看了一下greenlet.py里面的Greenlet的时间,结果发现一个问题Greenlet里面有一个run函数。所以我这里的Downloader申明run函数以后覆盖了Greenlet本身的run,结果就出现了你看到的这个错误。 所以解决方法也很简单,就是不要用run这个名字。

Categories: programming Tags: ,