一个用libcurl多线程下载断言错误问题的排查

某数据下载程序，相同版本的代码，在64位系统中运行正常，但在32位系统中概率性出现断言错误。一旦出现，程序无法正常继续，即使重启亦不行。从年前会上领导提出要追到根，跟到底，到年后的今天，经过排查、自测、试点，算是告一段落了。文中没有很难的技术问题，但过程还是值得记录的。本文从后来者角度总结一下解决问题的过程，同时给出相关测试代码。

由于本文没有技术含量，请谨慎按需阅读。

起因

当运维人员把出错的截图发给我时，我回想起1年半前的那个夏天，那天下午，运维人员将同一个错误截图给我，后来回退版本了，再也没出现了。这次，运维人员上报给了领导。会上我也答不出来为什么在32位系统上会报错，而在64位系统中却不行，也回答不了为什么回退版本又可以。下面这个错误，在笔记里躺了很久，现在又要翻出来，一点也没变化：

ath.c:193: _gcry_ath_mutex_lock: Assertion `*lock == ((ath_mutex_t) 0)' failed.

这是某个动态库报的断言错误，不是业务程序直接提示的。虚拟机模拟不出问题，现场机器没有gdb，也无法生成coredump，也没有pstrace，只能靠头脑分析排查了。

排查及解决

动态库定位

报错信息关键信息为ath.c、_gcry_ath_mutex_lock、ath_mutex_t。

经搜索，得到了一些有用的信息。

在libssh2官方网站上，找到一篇关于FIPS兼容性的帖子FIPS Compliance，提问者的错误是用sftp通过libcurl下载文件时产生的。路线和所遇问题几乎一样，出现断言错误的库为libgcrypt。在stackoverflow网站上找到这个帖子，帖子回答者提到：

Obviously you are using libgcrypt in there, either directly or through some library (liboauth?). Multithreaded use of gcrypt requires initialization, as documented at gnupg.org/documentation/manuals/gcrypt/Multi_002dThreading.html - either you forgot it, or one of the maintainers of libraries you used did. Check the documentation… –
DevSolar
Dec 13, 2011 at 17:00
The problem was that more than one thread tries to get a http request at the same time. That’s not possible. So I used mutexes to avoid that.

使用libgcrypt时，在多线程中要初始化，至于初始化什么，怎么初始化，谁初始化，由于涉及libcurl->libssh2->libgcrypt等库，路径较深，鞭长莫及，代码人一声叹气。

关于ath.c断言语句的跟踪记录

前面定位到了libgcrypt库，在32位系统上用strings命令查找出错关键字：

 strings /lib/i386-linux-gnu/libgcrypt.so.11.7.0 | grep "*lock =="
*lock == ((ath_mutex_t) 0)
*lock == ((ath_mutex_t) 1)

strings /lib/i386-linux-gnu/libgcrypt.so.11.7.0 | grep "_gcry_ath_mutex_lock"
_gcry_ath_mutex_lock

是这个库无疑了。但11.7.0版本找不到ath.c文件。再在64位系统上查：

 strings /lib64/libgcrypt.so.11.8.2 | grep "*lock =="
*lock == ((ath_mutex_t) 0)
*lock == ((ath_mutex_t) 1)

strings /lib64/libgcrypt.so.11.8.2 | grep "_gcry_ath_mutex_lock"
_gcry_ath_mutex_lock

find /usr/ -name "libgcrypt*"
/usr/lib64/libgcrypt.so.11.8.2
/usr/lib64/libgcrypt.so.11
/usr/share/doc/libgcrypt-1.5.3

从信息中猜测，可能的版本是1.5.3。下载该版本解压，得到ath.c关键语句：
在这里插入图片描述

第193行，正是这多天魂牵梦萦想看到的语句。

但是，这只是知道了出错的地方而已，还不知道如何出错。

问题定位

从错误信息上看，和锁有关，进而推断和多线程有关。分析业务代码，的确有多线程下载。起初，跟踪线程内部的curl变量，但没有出现越界使用情况，都在相同内部线程完成了，每次下载，都用curl_easy_init初始化，最后用curl_easy_cleanup清理，通过打印跟踪可以确认这一点。

回到业务程序上。既然是多线程下载出错，就将多线程改成单线程，或者加上互斥锁，不让他们同时运行。这份代码比大锤的年龄还大，有一定的历史沉淀，且有较多名称相近的函数，类似于北湖北路，北湖南路，北湖东路等，不好改动。于是加上锁，再测试，没有发现问题。

解决方法

但依然没有找到原因。

访问libcurl官方示例页面，找到多线程例子，但参考价值不大，于是搭建sftp服务器，写了测试程序。经摸索，发现在一线程下载过程的同时另一线程也下载，则必然出错。开始时，下载的文件小，很快下载完毕，下载大文件时问题即刻暴露了。

回查业务代码，在两线程启动时，人工加了10秒的延时，当数据量较多大了，前一线程未下载完毕，后一线程启动，因此报错了。之前相安无事，应该是两线程下载的数据量并非都大，前一线程较快完成了下载。

但无论如何，在两线程之间加锁，的确能解决问题。

反馈

在试点跑了3天，暂时没有收到问题反馈。应该大概的确解决了这个问题。

小结

至于为何libcurl无法多线程下载，为何偏偏在32位系统上出现，其实还没有找到根本问题所在。多方测试，64位系统的确未发现有。于是在业务代码中通过宏定义限定只在32位系统才加锁。

附：自测程序

源码：

#include <stdio.h>
#include <errno.h>
#include <string.h>
#include <unistd.h>
#include <pthread.h>
#include <curl/curl.h>

#define DOWNLOAD_LOCK

static pthread_mutex_t connlock;

void init_locks(void)
{
    pthread_mutex_init(&connlock, NULL);
}

void kill_locks(void)
{
    pthread_mutex_destroy(&connlock);
}

void my_locks(void)
{
#ifdef DOWNLOAD_LOCK
    pthread_mutex_lock(&connlock);
#endif
}    

void my_unlocks(void)
{
#ifdef DOWNLOAD_LOCK
    pthread_mutex_unlock(&connlock);
#endif
}

//lldebug LoginStr aftp:123456 RemoteFile: sftp://192.168.168.88/DataStorary/Server/MyData/BigFile.dat LocalFile: /tmp/data/download/BigFile.dat

static size_t my_write(void *buffer, size_t size, size_t nmemb, void *stream)
{

    /* not interested in the downloaded bytes, return the size */ 
    (void)buffer;  /* unused */ 
    (void)stream; /* unused */ 
    return (size_t)(size * nmemb);
}

void downloadFile(CURL *curl, const char *LoginStr, const char * RemoteFile, const char *LocalFile)
{
	//CURL *curl = InitCurl();
	if(curl == NULL)
	{
		return;
	}
    curl_easy_setopt(curl, CURLOPT_USERPWD, LoginStr);
    curl_easy_setopt(curl, CURLOPT_URL, RemoteFile);
    curl_easy_setopt(curl, CURLOPT_WRITEFUNCTION, my_write);
    printf("lldebug %s().%d before curl_easy_perform ptr: %p\n", __func__, __LINE__, curl);

    CURLcode code = curl_easy_perform(curl);
    if(CURLE_OK != code)
    {
        printf("curl_easy_perform failed, %d: %s\n", code, curl_easy_strerror(code));
    }
}


static void *download_1(void *url)
{
    CURL *curl;
    const char* loginStr = "aftp:123456";
    //const char* rfile = "sftp://192.168.168.88/DataStorary/Server/MyData/smallfile.txt";
    const char* rfile = "sftp://192.168.168.88/DataStorary/Server/MyData/BigFile.dat";
    const char* lfile = "/tmp/file_1.txt";
    

    my_locks();
    
    printf("lldebug %s().%d begin++++++++++++++++++\n", __func__, __LINE__);
    
    curl = curl_easy_init();

    printf("lldebug %s().%d >>>>>>>> init curl ptr: %p\n", __func__, __LINE__, curl);

    downloadFile(curl, loginStr, rfile, lfile);

    printf("lldebug %s().%d <<<<<<<< download done curl ptr: %p\n", __func__, __LINE__, curl);

    
    curl_easy_cleanup(curl);
    
    printf("lldebug %s().%d end++++++++++++++++++\n", __func__, __LINE__);

    my_unlocks();
}

static void *download_2(void *url)
{
    CURL *curl;
    const char* loginStr = "aftp:123456";
    const char* rfile = "sftp://192.168.168.88/DataStorary/Server/MyData/smallfile.txt";
    const char* lfile = "/tmp/file_2.txt";

    my_locks();
        
    printf("lldebug %s().%d begin------------------\n", __func__, __LINE__);

    
    curl = curl_easy_init();

    printf("lldebug %s().%d >>>>>>>> init curl ptr: %p\n", __func__, __LINE__, curl);

    downloadFile(curl, loginStr, rfile, lfile);

    printf("lldebug %s().%d <<<<<<<< download done curl ptr: %p\n", __func__, __LINE__, curl);

    curl_easy_cleanup(curl);

    printf("lldebug %s().%d end------------------\n", __func__, __LINE__);

    my_unlocks();
}


int main(int argc, char **argv)
{
    pthread_t tid1;
    pthread_t tid2;

    init_locks();
    
    curl_global_init(CURL_GLOBAL_ALL);

    pthread_create(&tid1, NULL, download_1, NULL);

    usleep(1000);

    pthread_create(&tid2, NULL, download_2, NULL);

    pthread_join(tid1, NULL);
    pthread_join(tid2, NULL);

    kill_locks();
    
    curl_global_cleanup();

    return 0;
}

编译：

g++ test_thread.cpp  -I/usr/local/curl/include -I/usr/include -lcurl

加锁情况下运行结果：

lldebug download_1().78 begin++++++++++++++++++
lldebug download_1().82 >>>>>>>> init curl ptr: 0x9216340
lldebug downloadFile().57 before curl_easy_perform ptr: 0x9216340
lldebug download_1().86 <<<<<<<< download done curl ptr: 0x9216340
lldebug download_1().91 end++++++++++++++++++
lldebug download_2().105 begin------------------
lldebug download_2().110 >>>>>>>> init curl ptr: 0x9216340
lldebug downloadFile().57 before curl_easy_perform ptr: 0x9216340
lldebug download_2().114 <<<<<<<< download done curl ptr: 0x9216340
lldebug download_2().118 end------------------

不加锁情况下运行结果：

lldebug download_1().78 begin++++++++++++++++++
lldebug download_1().82 >>>>>>>> init curl ptr: 0x9d37340
lldebug downloadFile().57 before curl_easy_perform ptr: 0x9d37340
lldebug download_2().105 begin------------------
lldebug download_2().110 >>>>>>>> init curl ptr: 0x9d4de18
lldebug downloadFile().57 before curl_easy_perform ptr: 0x9d4de18
a.out: ath.c:193: _gcry_ath_mutex_lock: Assertion `*lock == ((ath_mutex_t) 0)' failed.
Aborted

用gdb调试过程：

(gdb) r
Starting program: /home/latelee/libcurl_test/a.out 
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/i386-linux-gnu/i686/cmov/libthread_db.so.1".
[New Thread 0xb769eb70 (LWP 7680)]
lldebug download_1().101 begin++++++++++++++++++
lldebug download_1().105 >>>>>>>> init curl ptr: 0x805a340
lldebug downloadFile().80 before curl_easy_perform ptr: 0x805a340
[New Thread 0xb6e9db70 (LWP 7681)]
lldebug download_2().128 begin------------------
lldebug download_2().133 >>>>>>>> init curl ptr: 0x8070e18
lldebug downloadFile().80 before curl_easy_perform ptr: 0x8070e18
a.out: ath.c:193: _gcry_ath_mutex_lock: Assertion `*lock == ((ath_mutex_t) 0)' failed.

Program received signal SIGABRT, Aborted.
[Switching to Thread 0xb6e9db70 (LWP 7681)]
0xb7fe1424 in __kernel_vsyscall ()
(gdb) bt
#0  0xb7fe1424 in __kernel_vsyscall ()
#1  0xb7cf5941 in *__GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2  0xb7cf8d72 in *__GI_abort () at abort.c:92
#3  0xb7ceeb58 in *__GI___assert_fail (assertion=0xb7938626 "*lock == ((ath_mutex_t) 0)", file=0xb7938620 "ath.c", line=193, 
    function=0xb7938674 "_gcry_ath_mutex_lock") at assert.c:81
#4  0xb78e9605 in ?? () from /lib/i386-linux-gnu/libgcrypt.so.11
#5  0xb792b02d in ?? () from /lib/i386-linux-gnu/libgcrypt.so.11
#6  0xb792c889 in ?? () from /lib/i386-linux-gnu/libgcrypt.so.11
#7  0xb792ae7d in ?? () from /lib/i386-linux-gnu/libgcrypt.so.11
#8  0xb78f82d9 in ?? () from /lib/i386-linux-gnu/libgcrypt.so.11
#9  0xb78f8a14 in ?? () from /lib/i386-linux-gnu/libgcrypt.so.11
#10 0xb78e078c in gcry_md_open () from /lib/i386-linux-gnu/libgcrypt.so.11
#11 0xb7c603b6 in ?? () from /usr/lib/i386-linux-gnu/libssh2.so.1
#12 0xb7c6f154 in ?? () from /usr/lib/i386-linux-gnu/libssh2.so.1
#13 0xb7c5a2c8 in ?? () from /usr/lib/i386-linux-gnu/libssh2.so.1
#14 0xb7c67108 in ?? () from /usr/lib/i386-linux-gnu/libssh2.so.1
#15 0xb7c67489 in ?? () from /usr/lib/i386-linux-gnu/libssh2.so.1
#16 0xb7c680db in libssh2_sftp_init () from /usr/lib/i386-linux-gnu/libssh2.so.1
#17 0xb7fa0688 in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#18 0xb7fa3f63 in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#19 0xb7fa4595 in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#20 0xb7f80380 in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#21 0xb7f8067a in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#22 0xb7f80732 in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#23 0xb7f8d255 in ?? () from /usr/lib/i386-linux-gnu/libcurl.so.4
#24 0xb7f8e033 in curl_easy_perform () from /usr/lib/i386-linux-gnu/libcurl.so.4
#25 0x08048acf in downloadFile(void*, char const*, char const*, char const*) ()
#26 0x08048c60 in download_2(void*) ()
#27 0xb7cb7c39 in start_thread (arg=0xb6e9db70) at pthread_create.c:304
#28 0xb7da1d4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130
(gdb)