一個DBA同事昨天在執行一個命令列工具的時候發現程式hang住，問題挺有意思，值得記錄下。

　　首先用pstack看了下程式的呼叫棧，這是個多執行緒程式，pstack結果看到幾乎所有的執行緒都等在write呼叫上。如下是pt-pmp的輸出結果：

Tue May 27 18:30:06 CST 2014
     55 __lll_lock_wait_private,_L_lock_51,fwrite,LoadConsumer::run,CThread::hook,start_thread,clone
      1 write,_IO_new_file_write,_IO_new_file_xsputn,buffered_vfprintf,vfprintf,fprintf,LoadManager::dump,LoadProducer::load_file,LoadProducer::run,CThread::hook,start_thread,clone

　　直覺上覺得是磁碟空間滿了，讓他看了下，磁碟空間還很富裕，touch建立檔案也沒任何問題，當時此機器上還在跑一個備份程式，IO壓力不小，不過和問題本身應該關係不大。Google了下__lll_lock_wait_private這個錯誤，也沒任何有用的資訊。這個工具程式本身會向一個命令列指定的日誌檔案輸出很多程式執行結果，同時會向stderr輸出程式的執行狀態，gdb attach看了下程式具體的呼叫棧，發現程式都阻塞在fprintf(stderr)上。諮詢了下同事，他使用這個工具是通過一個python指令碼呼叫的，呼叫的程式類似如下：

p = subprocess.Popen(cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT,close_fds=True)

　　cmd是呼叫程式的命令列，包括一系列選項。問題看起來很清晰了，通過python呼叫此命令列工具時，stdout和stderr都被重定向了subprocess.PIPE，但沒有程式從此PIPE讀取，那麼很快這個PIPE自身的buffer都寫滿了，pstack看到的結果就是所有write都阻塞。

　　寫了個小程式重現了下，程式如下（隨手寫的..）:　

  1 #include <stdio.h>
  2 #include <pthread.h>
  3 #include <unistd.h>
  4 void *thr_fn(void
 
 *arg)
  5 {
  6   int i =0;
  7   while(true)
  8   {
  9     i++;
 10     fprintf(stderr, "helloworld %d\t\t\t\t",i);
 11     fprintf(stdout, "kkkkkkkkkk %d\t\t\t\t",i);
 12     sleep(1);
 13   }
 14 }
 15
 16 int main(void)
 17 {
 18   for (int i = 0; i!= 50; i++)
 19   {
 20     pthread_t tid;
 21     pthread_create(&tid, NULL, thr_fn, NULL);
 22   }
 23
 24   sleep(100000);
 25 }

　　呼叫的python指令碼如下：

  1 import subprocess
  2 import os
  3 import time
  4
  5 ret = {}
  6
  7 cmd = "./a.out >/tmp/log"
  8
  9 p = subprocess.Popen(cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT,close_fds=True)
 10
 11 ret['status'] = p.wait()
 12 ret['msg'] = p.stdout.readlines()
 13
 14 time.sleep(100000000);

　　執行此python指令碼，會發現很快a.out就被hang住了，表現是/tmp/log不再有新的輸出，程式呼叫棧如下：

     49 __lll_lock_wait_private,_L_lock_12956,buffered_vfprintf,vfprintf,fprintf,thr_fn,start_thread,clone
      1 write,_IO_new_file_write,_IO_new_file_xsputn,buffered_vfprintf,vfprintf,fprintf,thr_fn,start_thread,clone
      1 nanosleep,sleep,main

　　解決此問題，1）maybe subprocess.Popen這個程式引數可以改改？2）或者在cmd裡邊將stdout/stderr都重定向掉；3）寫命令列程式的時候要注意，呼叫的指令碼各種寫法都可能有，因此寫日誌儘量還是要規範，不要向stdout/stderr輸出過多的東西。

　　組裡開發的同事補充了下MySQL遇到__lll_lock_wait_private 錯誤的常見場景：

　　"這個函式呼叫在mysql上最典型的場景就是開啟cgroup時會經常碰到這個，例如memcpy, mem alloc, free , mutext lock/unlock...."