月度归档:2015年08月

我们为什么不采用ning的AsyncHttpClient

坦白的说,现在的量没有到非要用高性能异步httpclient的时候,用jdk自身提供的URLConnection足够了,最多为便捷性封装一下。真要考虑性能的话还有其他的解决方案未必一定要选择AsyncHttpClient。它依赖了netty已经不那么轻巧;另外去年我们遇到过tomcat不能正常退出的情况,发现是由这个框架里的某个non-daemon线程引起的,当时在微博上贴过:

ning的AsyncHttpClient 里启动了一个 netty 的 HashedWheelTimer 线程,这个线程挺有意思的,本来父线程已经是 daemon 的了,但使用 jdk 的 DefaultThreadFactory 给显式的 setDaemon(false) 了,致使这个线程一直以 non-daemon 方式运行, tomcat正常的stop没法结束这个 non-daemon 线程,要kill才行

"Hashed wheel timer #3" #44 prio=5 os_prio=0 tid=0x000000000a3a5000 nid=0x1ac5 waiting on condition [0x0000000043c70000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.jboss.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:445)
    at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:364)
    at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
    at java.lang.Thread.run(Thread.java:745)

估计作者并未考虑在servlet容器里使用的情况,当时没有找到有效的方法解决,也没时间去深入了解,直接切换到JDK的URLConnection

当然我是针对我们的场景,如果你在使用AsyncHttpClient时也遇到non-daemon线程的问题,可以参考一下当时姜宁的回复(可以给AsycnClient提个patch, Netty HashedWheelTimer 的构造支持替换 ThreadFactory),对创建HashedWheelTimer的线程工厂做一下手脚。

jstack不可用的原因

上午遇到的jstack没有输出的问题,印象里在阿里前几年也遇到过,不记得细节了;晚上查了一下,是jdk1.6的某些特定版本存在的bug,见这篇blog,简单的说就是本来hsperfdata_$user 这个目录一直约定是在系统的临时目录下的,对linux来说是”/tmp”

用 strace 来看一下正常版本启动jvm,hsperfdata_$user目录不受java.io.tmpdir变量影响

$ strace -ff -e trace=file  java -Djava.io.tmpdir=/data/test -version 2>&1 | perl -ne 's/^[^"]+"(([^\\"]|\\[\\"nt])*)".*/$1/ && print'  | grep hsperfdata

/tmp/hsperfdata_hongjiang
/tmp/hsperfdata_hongjiang/17019

而在 jdk1.6.0_21到24引入了bug,使用了jvm的环境变量-Djava.io.tmpdir做为了hsperfdata_$user的路径,正好一些应用比如tomcat是对这个变量设置了自己的路径的,比如”/server/tomcat/temp”,存在bug的这些版本把hsperfdata_$user目录也放到tomcat环境变量指定的目录下了,结果 jps, jstack, 之类工具都不能找到目标了。根据bug报告里给出的一种变通方式,在运行jstack时设置-J-Djava.io.tmpdir=$CATALINA_HOME/temp 也并未能工作。对于这个问题最佳的处理方式还是升级jdk版本。

补充:

虽然对jstack设置变量并不工作,但发现对jinfo设置该变量是有效的,比如:jinfo -J-Djava.io.tmpdir=/server/tomcat/temp -sysprops $pid 在jdk1.6.0_24下是可以工作的。

通过strace查看一个进程的标准输出内容

线上某个业务java进程出了一些麻烦,去诊断的时候发现jstack无法输出,可能是jdk或os版本的问题。这时还可以尝试一下kill -3,它默认会输出到进程的标准输出。如果不幸这个进程的标准输出被重定向到了 /dev/null 或者重定向到某个文件,但却因为很多其他日志也在大量的输出,导致日志文件过大,要从中找出线程栈相关的日志,还要耗点时间;这个时候,可以通过strace来跟踪一个进程的标准输入。

strace输出的信息需要一些处理,可以通过管道与其他命令组合(通过-o参数或-ff参数)

这里 -o 参数后边是一个字符串表示输出文件,如果字符串开头是一个"|"会被strace识别为管道

$ strace -f -e trace=write -e verbose=none -e write=1,2 -q -p $pid -o "| grep '^ |' | cut -c11-60 | sed -e 's/ //g' | xxd -r -p"

或者 -ff 参数,用管道与其他命令组合,注意strace的错误输出也要重定向

$ strace -ff -e trace=write -e write=1,2 -s 1024 -q -p $pid 2>&1 | cut -c11-60 | sed -e 's/ //g' | xxd -r -p

不过这两种方式都遇到一个问题,因为buffer的问题导致管道后边的命令没能完全处理strace跟踪到的数据(要等到后续的数据塞满buffer),有点像grep需要--line-buffer解决缓冲区问题,但不知道这里有什么方式,尝试过stdbuf也没有解决。最后只能分两步,先把strace的内容输出到文件,然后再对内容解析:

$ strace -f -e trace=write -e write=1,2 -q -p $pid  -o /tmp/slog

$ grep " |" /tmp/slog | cut -c11-60 | sed -e 's/ //g' | xxd -r -p

starling和kestrel这两只鸟的来由

虽然SK组合子早有所闻,但这两个字母所代表的意思却一直不知道,原来是出自于《To Mock a Mockingbird and Other Logic Puzzles》这本书,作者用starlingkestrel这两只鸟来演绎哥德尔的证明。SK是这两只鸟的缩写,我是看到这篇Blog才了解到的。

早先只知道starlingkestrel是twitter的消息中间件产品,原来产品名还有这个来由。

BoneCP的线程阻塞问题

某个业务采用BoneCP连接池遇到的情况,200个dubbo线程都阻塞在com.jolbox.bonecp.BoneCPDataSource.maybeInit方法上,这里wait的是同一个锁:

"DubboServerHandler-thread-203" daemon prio=10 tid=0x00007fc2400e7800 nid=0x658c waiting on condition [0x00007fc233dbb000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c071f518> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)
at com.jolbox.bonecp.BoneCPDataSource.maybeInit(BoneCPDataSource.java:133)
at com.jolbox.bonecp.BoneCPDataSource.getConnection(BoneCPDataSource.java:112)
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
at org.mybatis.spring.SqlSessionUtils.getSqlSession(SqlSessionUtils.java:116)
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:333)
at com.sun.proxy.$Proxy11.selectList(Unknown Source)
at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:189)
at org.apache.ibatis.binding.MapperMethod.executeForList(MapperMethod.java:100)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:70)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:38)

从BoneCP的代码里看不出直接问题,是一个ReentrantReadWriteLock去获取锁的逻辑:

private void maybeInit() throws SQLException {
    this.rwl.readLock().lock();  // ------->  133行,所有线程都阻塞在这里
    if (this.pool == null){
        this.rwl.readLock().unlock();
        this.rwl.writeLock().lock();
        if (this.pool == null){ //read might have passed, write might not
            try {
                if (this.getDriverClass() != null){
                    loadClass(this.getDriverClass());
                }
            }
            catch (ClassNotFoundException e) {
                throw new SQLException(PoolUtil.stringifyException(e));
            }


            logger.debug(this.toString());

            this.pool = new BoneCP(this);
        }

        this.rwl.writeLock().unlock(); // Unlock write
    } else {
        this.rwl.readLock().unlock(); // Unlock read
    }
}

按说通常如果是死锁的话,应该是某个线程A先获取到锁X,然后再去获取另一个锁Y时发被线程B占用,且线程B又要获取锁X,但这里的现象却是都在等同一把锁,并且一直处于这种状态导致服务不可用。jstack -F看看是否能检测到死锁,输出也是No deadlocks found. (也可能是ReentrantLock的读锁没有ownership的原因,jvm无法跟踪并检测出来,参考这篇这个bug里Doug Lea的回复),怀疑也可能跟jdk和os的版本有关,可能是该版本的bug(或其他我不了解的)。

Underground & Red Violin

从google doc里翻出2006年写的两部电影评论,现在看这两部电影都算得上经典,尤其《地下》这部电影,在我心中或许能与之媲美只有《霸王别姬》了,近十年来极少看再到这样精彩绝伦的电影了,如果没看过的话强烈推荐一下。

2006.4.11

上周末看了两部电影。《地下》讲述了南斯拉夫从二战到南斯拉夫国家易名之间的一段历史。上半部荒诞,下半部沉重;故事的疯狂与宏大让我难以对它做出形容,只有震撼。《红色小提琴》也是一部很不错的电影,内容充实,也很吸引人。讲述了一把小提琴的传奇故事。

这是一把由十七世纪意大利提琴著名工匠师为即将诞生的儿子而准备的小提琴。工匠师的妻子在临产前,向她的仆人(一个吉普赛老太婆)进行了一次占卜,她抽中了五张扑克。但是不久后妻子和婴儿死于难产。工匠师用尽心血完成这把小提琴的最后制作。

第一张扑克“月亮”,你会很长寿,像月亮女神一样,生命充实而丰盛;你将会远行。

之后这把小提琴流落到一家修道院,这里收养很多孤儿。这些孤儿拉小提琴歌颂上帝。这座修道院位于阿尔俾斯山中,电影中的景色很美。这把提琴在这些孤儿中一代代传递,只到一天修道院发现一个小孩的能力非凡,于是找来了维也纳的音乐老师,请他收养这个小孩带他到维也纳去学习。在维也纳,这位老师有机会将这个小孩引荐给一位王子,然而就在准备为王子演奏的时候小孩却突然心脏病发作去世了。在小孩埋葬后,修道院也决定用这把提琴作为孩子的陪葬品。

第二张扑克“吊死者”,预见危险,虚弱和疾病。

不知过了多久,坟墓被盗墓者打开,这把小提琴又流落人间,几转他手,被吉卜赛人带到了英国。他落到了具有魔鬼一样才华的音乐家费迪之手,费迪用它创作出了惊人的作品。费迪深爱着一位女作家维多利亚,她给予他创作的灵感。而她为完成她的小说,远去俄罗斯。费迪陷入空虚,没有了灵感,也不再读维多利亚写给他的信,并开始吸食鸦片。就在维多利亚返回的时候却看到了费迪的背叛,愤怒中她开枪打中了这把小提琴的颈部。费迪在失去了维多利亚后自杀,这把琴落入了他的仆人,一位中国人的手中。

第三张扑克“魔鬼”,你会预见一个男人,聪明英俊,但他是魔鬼,会用他的才华引诱你,使你陷入情欲。

这位中国人带着这把琴回到了上海,在一家当铺把这把琴当了出去。之后到了上个世纪的30年代,一位母亲带着她的女儿项蓓,来到这家当铺并买下了这把提琴。转眼到了文革时期,反四旧和反资本主义最严重的时期,一切和西方有关的东西都是有罪的。项蓓知道自己无法保管这把琴,把它交给了一位音乐教师。

第四张“法官”,你会受审判,在最严峻的地方法官面前,你会被判为有罪。

时来运转,到了当代,中国发生了巨大的变化。那位音乐老师死在了他的家中,警察来了,发现他的房间中有非常多的西方乐器。几经周转这些乐器最终到了蒙特利尔的拍卖台。为了鉴定这把小提琴是否是传说中的红提琴,专门请来了鉴定专家。鉴定师仔细的研究分析,为小提琴表面的漆做了物质分析,发现原来它的成分竟有人的血液。原来小提琴最后一道工序,工匠师给小提琴涂的漆是用的妻子的血液。鉴定师和同伙买来了这把琴的仿制品,在拍卖会上他们调换了这把琴,最终它落入了这位鉴定师的手中。他把它作为送给女儿的礼物。

最后一张扑克“骷髅”,预示重生。

maven wrapper script

这个脚本用于简化mvn的操作,在mac/bash, linux/bash, cygwin/bash下测试过

#!/bin/bash - 

TOP_PID=$$
PROG_NAME=$0
ACTION=$1

function get_children() {
  ps -ef | grep $$ | grep -v grep | awk '$3=='"$$"'{print $2}' | xargs
}

trap "kill $(get_children) >/dev/null 2>&1; exit 1" SIGINT SIGTERM

function usage() {
  echo "Usage: $PROG_NAME {verify|compile|run|debug|package|eclipse|get-src|dep-tree}"
  exit 1;
}

function get_mvn_cmd() {
  if [[ "$OSTYPE" == *cygwin* ]];then
    ppid=$( ps -ef -p $$ | awk 'NR==2{print $3}' )
    user_shell=$( ps -p $ppid | awk 'NR==2{print $8}' )
    #has some trouble with cygwin, while Ctrl-c cannot terminal
    set -m
  else
    ppid=$( ps -oppid= $$ )
    user_shell=$( ps -ocomm= -p $ppid )
  fi

  mvn=$( $user_shell -ic "alias mvn" 2>/dev/null | cut -d'=' -f2 | sed "s/'//g" )

  if [ -z "$mvn" ];then
    $user_shell -ic "which mvn" >/dev/null
    if [ $? -eq 0 ];then
      mvn=$( $user_shell -ic "which mvn" | head -1 )
    fi
  fi

  if [ -z "$mvn" ]; then 
    echo "mvn command not found" >&2
    kill -s TERM $TOP_PID
  else
    echo $mvn
  fi
}

MVN=$( get_mvn_cmd )

function mvn_verify() {
  $MVN verify $@
}

function mvn_compile() {
  $MVN clean compile $@
}

function mvn_run() {
  $MVN scala:run $@
}

function mvn_debug() {
  $MVN scala:run -Dlauncher=debug $@
}

function classpath_check() {
  if [ $# -eq 0 ];then
    echo "please enter classpath dir"
    exit 1
  fi

  if [ ! -d "$1" ]; then 
    echo "not a directory"
    exit 2
  fi

  tmpfile="/tmp/.cp$(date +%s)"
  tmphash="/tmp/.hash$(date +%s)"
  verbose="/tmp/cp-verbose.log"

  declare -a files=(`find "$1" -name "*.jar"`)
  for ((i=0; i < ${#files[@]}; i++)); do
    jarName=`basename ${files[$i]}`
    list=`unzip -l ${files[$i]} | awk -v fn=$jarName '/\.class$/{print $NF,fn}'`
    size=`echo "$list" | wc -l`
    echo $jarName $size >> $tmphash
    echo "$list" 
  done | sort | awk 'NF{
      a[$1]++;m[$1]=m[$1]","$2}END{for(i in a) if(a[i] > 1) print i,substr(m[i],2)
  }' > $tmpfile

  awk '{print $2}' $tmpfile | 
  awk -F',' '{i=1;for(;i<=NF;i++) for(j=i+1;j<=NF;j++) print $i,$j}' | 
  sort | uniq -c | sort -nrk1 | while read line; do
    dup=${line%% *} 
    jars=${line#* }
    jar1=${jars% *}
    jar2=${jars#* }
    len_jar1=`grep -F "$jar1" $tmphash | grep ^"$jar1" | awk '{print $2}'`
    len_jar2=`grep -F "$jar2" $tmphash | grep ^"$jar2" | awk '{print $2}'`
    len=$(($len_jar1 > $len_jar2 ? $len_jar1 : $len_jar2))
    per=$(echo "scale=2; $dup/$len" | bc -l)
    echo ${per/./} $dup $jar1 $jar2 
  done | sort -nr -k1 -k2 | 
  awk 'NR==1{print "Similarity DuplicateClasses File1 File2"}{print "%"$0}'| column -t  

  sort $tmpfile | awk '{print $1,"\n\t\t",$2}' > $verbose
  echo "See $verbose for more details."

  rm -f $tmpfile
  rm -f $tmphash
}

function mvn_package() {
  $MVN clean package -Dmaven.javadoc.skip -Dmaven.test.skip $@
  if [ $? -eq 0 ];then
    echo ""
    classpath_check ./target/lib
  fi
}

function mvn_src() {
  $MVN dependency:sources
}

function mvn_dep_tree() {
  $MVN dependency:tree -Dverbose
}

function mvn_eclipse() {
  $MVN eclipse:eclipse
}

case "$ACTION" in
  verify)
    shift && mvn_verify $@
  ;;
  compile)
    shift && mvn_compile $@
  ;;
  run)
    shift && mvn_run $@
  ;;
  debug)
    shift && mvn_debug $@
  ;;
  package)
    shift && mvn_package $@
  ;;
  get-src)
    mvn_src
  ;;
  dep-tree)
    mvn_dep_tree
  ;;
  eclipse)
    mvn_eclipse
  ;;
  *)
    usage
  ;;
esac

servlet模型(3.1之前)对InputStream的处理是阻塞模式

同事聊起这个话题,当请求建立时是否tomcat就为每个连接分配线程了? 是否只要发起足够多的连接不必发送任何数据就可以DDoS了?对于DDoS这个话题不展开,这里仅仅说一下连接过来时,服务器端是否就一定分配了线程。这取决于tomcat配置的connector模式,只讨论一下bio和nio的情况。

以bio模式启动tomcat,然后建立3个连接(不发送任何数据):

$ nc localhost 8080 &
$ nc localhost 8080 &
$ nc localhost 8080 &

这时我们来看tomcat的bio执行线程是与连接数一对一的:

$ ./appctrl.sh jstack | grep http-bio-8080-exec
"http-bio-8080-exec-3" #24 daemon prio=5 os_prio=31 tid=0x00007fdd7a840800 nid=0x6607 runnable [0x000000011d78b000]
"http-bio-8080-exec-2" #23 daemon prio=5 os_prio=31 tid=0x00007fdd7a83f800 nid=0x6507 runnable [0x000000011d618000]
"http-bio-8080-exec-1" #22 daemon prio=5 os_prio=31 tid=0x00007fdd7a800000 nid=0x4107 runnable [0x000000011addd000]

而在nio模式下,请求建立时,并不会有执行线程,只有接收到数据发时,才会有线程分配:

$ nc localhost 8080
POST /test/post?name=foo HTTP/1.1
Host: localhost:8080
Context-Length: 10000 

上面在nc建立连接后,发送了一段http header(还未发送body,请求保持中),这时才会对这些请求数据分配线程阻塞执行:

$ ./appctrl.sh jstack | grep http-nio-8080-exec
"http-nio-8080-exec-3" #26 daemon prio=5 os_prio=31 tid=0x00007ffefb001800 nid=0x6007 waiting on condition [0x0000000123af7000]
"http-nio-8080-exec-2" #25 daemon prio=5 os_prio=31 tid=0x00007ffefa029000 nid=0x5d07 waiting on condition [0x000000012351c000]
"http-nio-8080-exec-1" #24 daemon prio=5 os_prio=31 tid=0x00007ffef900a000 nid=0x680b waiting on condition [0x000000012328f000] 

上面的测试是在tomcat7下测试的,nio在处理http request的时候是非阻塞的,但读取数据的时候是模拟阻塞的,因为servlet3.1之前对input的处理就是一种阻塞模式,参考以前的一张截图:

tmux下显示ssh目标host的问题

当在tmux下ssh到远程机器时,希望显示远程host,google后找到了一段对ssh封装过的函数:

ssh() {
    if [ "$(ps -p $(ps -p $$ -o ppid=) -o comm=)" = "tmux" ]; then
        tmux rename-window "$*"
        command ssh "$@"
        tmux set-window-option automatic-rename "on" 1>/dev/null
    else
        command ssh "$@"
    fi
}

这段函数在我的mac上运行效果正常,如下图

但当我在一台linux上运行时,ctrl-d退出远程ssh时,会一直卡在退出状态,不管ctrl-c或什么操作也无法回到原bash,如下图

此时只通过tmux的kill-window的操作方式来关掉这个窗口,而在mac下是没有这个问题的,分析了一下,发现在我的mac上,tmux被oh-my-zsh给alias成了一个_zsh_tmux_plugin_run函数:

➜  which ssh
ssh () {
    if [ "$(ps -p $(ps -p $$ -o ppid=) -o comm=)" = "tmux" ]
    then
        _zsh_tmux_plugin_run rename-window "$*"
        command ssh "$@"
        _zsh_tmux_plugin_run set-window-option automatic-rename "on" 1>/dev/null
    else
        command ssh "$@"
    fi
}

_zsh_tmux_plugin_run又做了一些环境变量的判断和处理,猜测可能是因为这些环境变量的差异所导致,先去掉tmux set-window-option automatic-rename "on" 这句最后对标准输出的重定向,看看输出什么信息,结果在修改之后却可以正常了:

还不太清楚为何这个重定向导致了ssh退出后没法回到原shell下,先记录下这个现象。