C/C++:pthread_cond_timedwaitブロックに失敗しました(すぐにタイムアウトして戻ります)

36794 ワード
C-C++ LINUX
C/C++:pthread_cond_timedwaitブロックに失敗しました(すぐにタイムアウトして戻ります)
先日、現ネットでソフトウェアを導入した時、一つのプロセスがCPUを占有するのが非常に高いことを発見しました.原因をよく調べてみると、メッセージを処理する時pthread_であることがわかりました.cond_timedwaitブロックに失敗した、あるいは、所定の時間に達していないうちにタイムアウトして戻ってきた.
コードの例は次のとおりです.
#include 
#include 
#include time.h>

using namespace std;

class Ebupt
{
public:
    Ebupt();
    virtual ~Ebupt();
    void dealMsg(long wait_ns);
private:
    pthread_mutex_t mutex;
    pthread_cond_t cond;
};

Ebupt::Ebupt()
{
    pthread_mutex_init(&mutex, NULL);
    pthread_cond_init(&cond, NULL);
}

Ebupt::~Ebupt()
{
    pthread_mutex_destroy(&mutex);
    pthread_cond_destroy(&cond);
}

void Ebupt::dealMsg(long wait_ns)
{
    pthread_mutex_lock(&mutex);

    struct timeval now;
    gettimeofday(&now, NULL);
    struct timespec abstime;

    if (now.tv_usec*1000 + (wait_ns%1000000000) >= 1000000000)
    {
        abstime.tv_sec = now.tv_sec + wait_ns/1000000000 + 1;
        abstime.tv_nsec = (now.tv_usec*1000 + wait_ns%1000000000)%1000000000;
    }
    else
    {
        abstime.tv_sec = now.tv_sec + wait_ns/1000000000;
        abstime.tv_nsec = now.tv_usec*1000 + wait_ns%1000000000;
    }

    pthread_cond_timedwait(&cond, &mutex, &abstime);
    pthread_mutex_unlock(&mutex);
}

int main()
{
    Ebupt e;
    struct timeval now;
    while (true)
    {
        gettimeofday(&now, NULL);
        cout<<"++"<<now.tv_sec<<":"<<now.tv_usec<200000000);
        gettimeofday(&now, NULL);
        cout<<"--"<<now.tv_sec<<":"<<now.tv_usec<0;
}

コンパイルおよび出力は次のとおりです.
[ismp@cn3 20171026]$ g++ -o main main.C -lpthread
[ismp@cn3 20171026]$ ./main
++1509023506:721641
--1509023506:721706
++1509023506:721710
--1509023506:721716
++1509023506:721718
--1509023506:721724
++1509023506:721726
--1509023506:721731
++1509023506:721733
--1509023506:721739
++1509023506:721741
--1509023506:721750
++1509023506:721753
--1509023506:721761
++1509023506:721763
--1509023506:721769
……
（CTRL+C）

理論上、私はsignalを持っていないので、200 msをブロックして、ブロックからタイムアウトして戻るべきですが、実際には、ブロックしていません.手綱を外した野馬のように、直接タイムアウトして戻ります.dealMsgはまだwhileサイクルの中で、死のサイクルのように、CPUの高さはもちろん正常です.
トップを見てみろ
top - 21:15:52 up 419 days,  7:30,  2 users,  load average: 9.57, 8.94, 8.32
Tasks: 241 total,   3 running, 238 sleeping,   0 stopped,   0 zombie
Cpu(s): 10.6%us, 63.1%sy,  0.0%ni, 24.6%id,  0.0%wa,  0.0%hi,  1.6%si,  0.0%st
Mem:  32879016k total, 32578784k used,   300232k free,   217448k buffers
Swap:  2097144k total,   749020k used,  1348124k free, 28921976k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                       
22096 ismp      20   0 13904 1116  956 S  3.7  0.0   0:01.84 main                                                                                                           
20409 ismp      20   0  109m 1956 1556 S  0.0  0.0   0:00.02 bash

無閉塞死サイクルだ...
この簡単な例はまあまあですが、CPUは4%未満になりましたが、私のプロセスは70%以上になりました.
後でいろいろな問題を探して、gettimeofdayが使っている時計とpthread_ではないかと思ったことがあります.cond_timedwaitが実際に使っている時計は同じではありませんか?
では、変更してみます.以下のようにします.
#include 
#include 
#include 
#include 

using namespace std;

class Ebupt
{
public:
    Ebupt();
    virtual ~Ebupt();
    void dealMsg(long wait_ns);
private:
    pthread_mutex_t mutex;
    pthread_cond_t cond;
};

Ebupt::Ebupt()
{
    pthread_mutex_init(&mutex, NULL);
    pthread_cond_init(&cond, NULL);
}

Ebupt::~Ebupt()
{
    pthread_mutex_destroy(&mutex);
    pthread_cond_destroy(&cond);
}

void Ebupt::dealMsg(long wait_ns)
{
    pthread_mutex_lock(&mutex);

    struct timespec now;
    clock_gettime(CLOCK_REALTIME, &now);
    struct timespec abstime;

    if (now.tv_nsec + (wait_ns%1000000000) >= 1000000000)
    {
        abstime.tv_sec = now.tv_sec + wait_ns/1000000000 + 1;
        abstime.tv_nsec = (now.tv_nsec + wait_ns%1000000000)%1000000000;
    }
    else
    {
        abstime.tv_sec = now.tv_sec + wait_ns/1000000000;
        abstime.tv_nsec = now.tv_nsec + wait_ns%1000000000;
    }

    pthread_cond_timedwait(&cond, &mutex, &abstime);
    pthread_mutex_unlock(&mutex);
}

int main()
{
    Ebupt e;
    struct timeval now;
    while (true)
    {
        gettimeofday(&now, NULL);
        cout<<"++"<":"<200000000);
        gettimeofday(&now, NULL);
        cout<<"--"<":"<return 0;
}

[ismp@cn3 20171026]$ g++ -o main main.C -lpthread -lrt
[ismp@cn3 20171026]$ ./main
++1509024234:822675
--1509024234:822733
++1509024234:822737
--1509024234:822748
++1509024234:822751
--1509024234:822761
……
（CTRL+C）

やはりブロックされていないのは、それではないようです(gettimeofdayとpthread_cond_timedwaitが使用するクロックが同じではない).
条件変数に属性を付けてみたら?次のようになります.
#include 
#include 
#include 
#include 

using namespace std;

class Ebupt
{
……
Ebupt::Ebupt()
{
    pthread_mutex_init(&mutex, NULL);

    pthread_condattr_t condattr;
    pthread_condattr_init(&condattr);
    pthread_condattr_setclock(&condattr, CLOCK_REALTIME);
    pthread_cond_init(&cond, &condattr);
    pthread_condattr_destroy(&condattr);
}
……（  ）
[ismp@cn3 20171026]$ g++ -o main main.C -lpthread -lrt
[ismp@cn3 20171026]$ ./main
++1509024510:358162
--1509024510:358221
++1509024510:358225
--1509024510:358236
++1509024510:358239
--1509024510:358249
……
（CTRL+C）

その後、この問題を解決するには時計を変えて、MONOTONICという時計を使うことができます.
#include 
#include 
#include 
#include 

using namespace std;

class Ebupt
{

……

Ebupt::Ebupt()
{
    pthread_mutex_init(&mutex, NULL);

    pthread_condattr_t condattr;
    pthread_condattr_init(&condattr);
    pthread_condattr_setclock(&condattr, CLOCK_MONOTONIC);
    pthread_cond_init(&cond, &condattr);
    pthread_condattr_destroy(&condattr);
}

……

void Ebupt::dealMsg(long wait_ns)
{
    pthread_mutex_lock(&mutex);

    struct timespec now;
    clock_gettime(CLOCK_MONOTONIC, &now);
    struct timespec abstime;

    if (now.tv_nsec + (wait_ns%1000000000) >= 1000000000)
    {
        abstime.tv_sec = now.tv_sec + wait_ns/1000000000 + 1;
        abstime.tv_nsec = (now.tv_nsec + wait_ns%1000000000)%1000000000;
    }
    else
    {
        abstime.tv_sec = now.tv_sec + wait_ns/1000000000;
        abstime.tv_nsec = now.tv_nsec + wait_ns%1000000000;
    }

    pthread_cond_timedwait(&cond, &mutex, &abstime);
    pthread_mutex_unlock(&mutex);
}

……
[ismp@cn3 20171026]$ g++ -o main main.C -lpthread -lrt
[ismp@cn3 20171026]$ ./main
++1509024798:440277
--1509024798:640389
++1509024798:640400
--1509024798:840413
++1509024798:840424
--1509024799:40507
++1509024799:40517
--1509024799:240565
++1509024799:240581
--1509024799:440595
（CTRL+C）

つまり、最終的な解決策は、
条件変数にクロックを設定し、REALTIMEではなくMONOTONICを使用します.
MONOTONICはjiffies変数を使用して時間を計算し、単調に増加した時間であり、bootの現在の機械の時間を表し、boot後にjiffiesが0に初期化される.
REALTIMEはxtimeを使用していますが、このxtimeはboot後にマザーボード上のハードウェアクロック(RTC)から読み出され、実行時刻も特権ユーザー(例えばroot)がdateのようなコマンドを使用することに影響されます.例えば、1 h後にタイムアウトするように設定しますが、このブロックされたタイムウィンドウでdateコマンドを使用してシステム時間を(またはwall timeと呼ばれる)1 hに調整すると、ブロックされた文は、pthread_cond_timedwaitのようにすぐにタイムアウトして返されます.
結局何が原因なのか分からなかったpthread_cond_timedwaitブロックに失敗したのは、偶然に得られた一時的な解決策にすぎず、その後、なぜpthread_を研究する時間があるのか.cond_timedwaitブロックに失敗したでしょう...
後記:
現在のネットワークのプロセスのCPUの割合はすべて少し正常ではありませんことを発見します:
top - 21:45:30 up 419 days,  8:00,  1 user,  load average: 8.85, 8.37, 8.38
Tasks: 238 total,   4 running, 234 sleeping,   0 stopped,   0 zombie
Cpu(s): 10.4%us, 65.4%sy,  0.0%ni, 23.5%id,  0.0%wa,  0.0%hi,  0.7%si,  0.0%st
Mem:  32879016k total, 32650184k used,   228832k free,   218716k buffers
Swap:  2097144k total,   749020k used,  1348124k free, 28992212k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                       
12303 sdc       20   0 3517m 864m 7176 S 344.1  2.7  5125261h java                                                                                                          
    9 root      20   0     0    0    0 S 50.5  0.0 144940:15 ksoftirqd/1                                                                                                    
   13 root      20   0     0    0    0 R 48.9  0.0 157182:21 ksoftirqd/2                                                                                                    
    4 root      20   0     0    0    0 R 46.9  0.0 153791:36 ksoftirqd/0                                                                                                    
   33 root      20   0     0    0    0 S 46.5  0.0 148379:24 ksoftirqd/7                                                                                                    
   21 root      20   0     0    0    0 R 44.2  0.0 156277:16 ksoftirqd/4                                                                                                    
   29 root      20   0     0    0    0 S 43.2  0.0 154775:19 ksoftirqd/6                                                                                                    
   17 root      20   0     0    0    0 S 30.9  0.0 174973:53 ksoftirqd/3                                                                                                    
   25 root      20   0     0    0    0 S 10.0  0.0 156328:27 ksoftirqd/5                                                                                                    
27888 www       20   0  177m 121m 1900 S  1.3  0.4   1167:11 nginx                                                                                                          
   41 root      20   0     0    0    0 S  0.3  0.0  17:36.77 events/6                                                                                                       
21937 sdc       20   0  134m 7564 1136 S  0.3  0.0  57:06.09 redis-server                                                                                                   
24218 ismp      20   0 15164 1344  944 R  0.3  0.0   0:00.01 top                                                                                                            
27890 www       20   0  180m 124m 1900 S  0.3  0.4   1163:55 nginx                                                                                                          
27891 www       20   0  170m 114m 1912 S  0.3  0.4   1069:01 nginx                                                                                                          
    1 root      20   0 19348  852  544 S  0.0  0.0   0:01.41 init                                                                                                           
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 kthreadd                                                                                                       
    3 root      RT   0     0    0    0 S  0.0  0.0   1:02.86 migration/0                                                                                                    
    5 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 migration/0

特にjavaバックグラウンドプロセスとksoftirqd.
Javaも下位レベルで条件変数を使用した結果、ブロックされていないのではないかと推測します.
その後...現網の機械を再起動すると、各プロセスが占有するCPUが下がり、上のブロックに失敗する問題もなくなりました......
もし小さい仲间がかつてこの问题を见たことがあるならば、指导を歓迎して、へへ~
OpenStreetMap データ（japan-latest.osm.pbf）から指定範囲切り出し
Angularでleafletを使っちゃうぞ