lizongbo at 618119.com 工作,生活,Android,前端,Linode,Ubuntu,nginx,java,apache,tomcat,Resin,mina,Hessian,XMPP,RPC

2010年10月24日

在Ubuntu 10.04上安装JDK1.6.0_21和编译配置Resin4.0.12

Filed under: Java,JVM,Linux,Resin,RMI — 标签:, , , , , , , — lizongbo @ 00:37

在Ubuntu 10.04上安装JDK1.6.0_21和编译配置Resin4.0.12

1.首先是安装最新版的jdk,先下载JDK 1.6.0_21(来源:http://www.oracle.com/technetwork/java/javase/downloads/index.html):
root@618119.com:/usr/local/app$ wget “http://cds.sun.com/***/jdk-6u21-linux-x64.bin”
这个url里带有会话信息,现在已经无效,JDK的官方下载不提供简洁的下载地址,需要每次到页面区获取下载地址)
2.再将下载到的文件改名:
root@618119.com:/usr/local/app$ mv jdk-6u21-linux-x64.bin\?BundledLineItemUUID\=SSeJ_hCwV9QAAAEroI4AHoII\&OrderID\=gVSJ_hCwmL8AAAErko4AHoII\&ProductID\=xKiJ_hCySHIAAAEpT7wzBGsB\&FileName\=%2Fjdk-6u21-linux-x64.bin   jdk-6u21-linux-x64.bin
3.给安装程序加上可执行权限:
root@618119.com:/usr/local/app$ chmod +x ./jdk-6u21-linux-x64.bin
4.开始安装JDK:
root@618119.com:/usr/local/app$ ./jdk-6u21-linux-x64.bin
(JDK安装好之后,可以通过符号连接建立jdk目录,这样在一行升级jdk版本的时候通过修改符号连接自动切换到新版本jdk:
root@618119.com:/usr/local/app# ln -s ./jdk1.6.0_21/ ./jdk )
5.然后添加环境变量到系统:
编辑 /etc/enviroment增加下面一行:
JAVA_HOME=”/usr/local/app/jdk1.6.0_21″
添加后的/etc/environment内容如下:
root@618119.com:/etc# more /etc/environment
PATH=”/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games”
JAVA_HOME=”/usr/local/app/jdk1.6.0_21″
6.再开始下载resin4.0.12(来源:http://www.caucho.com/download/)
root@618119.com:/usr/local/app# wget http://www.caucho.com/download/resin-4.0.12.tar.gz
7.解压安装文件:
root@618119.com:/usr/local/app# tar -zxvf resin*
7.进入resin目录开始编译安装,安装目录设置为:/usr/local/app/resin
root@618119.com:/usr/local/app# cd resin*
root@618119.com:/usr/local/app/resin-4.0.12# ./configure –prefix=/usr/local/app/resin
root@618119.com:/usr/local/app/resin-4.0.12# make
root@618119.com:/usr/local/app/resin-4.0.12# make install
8.可以看到系统服务脚本已经生成:
root@618119.com:/etc/init.d# more /etc/init.d/resin
9.尝试启动resin 4.0.12,失败了:
root@618119.com:/usr/local/app/resin/log# /usr/local/app/resin/bin/resin.sh start启动不了:
启动不了的原因是因为是root登录的。
Resin从4.0版本起,在默认的resin.xml里配置判断条件,如果当前用户名是root,则resin的watchdog监控进程使用www-data这个用户名来启动真正的resin进程。
root@618119.com:/usr/local/app/resin/bin# ./resin.sh start
然后root@618119.com:/usr/local/app/resin/bin# ./resin.sh shutdown
root@618119.com:/usr/local/app/resin/bin# tail ../log/*.log
可以看到出错日志如下:
—————————————————————————–

com.caucho.config.ConfigRuntimeException: java.io.IOException: Cannot create directory: /usr/local/app/resin/resin-data/default
at com.caucho.config.ConfigException.create(ConfigException.java:168)
at com.caucho.server.resin.Resin.configure(Resin.java:1006)
at com.caucho.server.resin.Resin.initMain(Resin.java:983)
at com.caucho.server.resin.Resin.main(Resin.java:1230)
Caused by: java.io.IOException: Cannot create directory: /usr/local/app/resin/resin-data/default
at com.caucho.vfs.FilePath.mkdirs(FilePath.java:489)
at com.caucho.env.service.RootDirectoryService.<init>(RootDirectoryService.java:81)
at com.caucho.server.resin.Resin.configureRoot(Resin.java:1073)
at com.caucho.server.resin.Resin.configure(Resin.java:1001)
… 2 more

—————————————————————————–

[2010/10/18 15:35:45.200] http listening to localhost:6600
[2010/10/18 15:35:45.289]
[2010/10/18 15:35:47.084] Watchdog detected close of Resin[,pid=20430]
exit reason: BAD_CONFIG (exit code=2)
[2010/10/18 15:35:48.814] Watchdog detected close of Resin[,pid=20454]
exit reason: BAD_CONFIG (exit code=2)
[2010/10/18 15:35:50.563] Watchdog detected close of Resin[,pid=20476]
exit reason: BAD_CONFIG (exit code=2)
[2010/10/18 15:35:52.470] Watchdog detected close of Resin[,pid=20508]
exit reason: BAD_CONFIG (exit code=2)

—————————————————————————–

10.解决办法为:注释resin.xml里的第147到150行:
root@618119.com:/usr/local/app/resin/conf# vi ./resin.xml

147 <!–      <resin:if test=”${resin.userName == ‘root’}”>
148         <user-name>www-data</user-name>
149         <group-name>www-data</group-name>
150       </resin:if> –>

11.然后再运行
root@618119.com:/usr/local/app/resin/bin# ./resin.sh start
或者root@618119.com:/usr/local/app/resin/bin# /etc/init.d/resin start
均可正常启动了。

12.再运行下面的命令将resin也添加为系统默认的服务:
root@618119.com:/etc# sudo /usr/sbin/update-rc.d -f resin defaults

13.修改resin配置允许外网访问resin-admin,编辑/usr/local/app/resin/conf/resin.xml,找到
<resin:set var=”resin_admin_external” value=”false”/>
改为:
<resin:set var=”resin_admin_external” value=”true”/>
保存resin.xml,重启resin。
root@618119.com:/usr/local/app/resin/conf# /usr/local/app/resin/bin/resin.sh restart

14:访问http://618119.com:8080/resin-admin/,因为是第一次访问,可以生成帐号和密码。
我的username设置为:resinadmin,Password设置为:618119.com(密码一定要用不容易被人猜到的),Realm保持为resin不变。
点“Create Configuration File”进行提交,生成的文件为:/usr/local/app/resin/conf/admin-users.xml.generated
15.将生成的文件改名为admin-users.xml:
root@618119.com:/usr/local/app/resin/conf# mv admin-users.xml.generated  admin-users.xml
然后resin会自动重新加载.
16.再访问http://localhost:8080/resin-admin/,输入刚才帐号和密码,登录之后,就可以看到服务器状态信息了。

接下来配置外网访问JMX管理。
由于jdk的jmx管理端口启动时无法绑定指定的ip,默认是绑定到所有ip的,因此在公网上开放jmx端口时,必须设置jmx访问的帐号和密码:
操作步骤如下:
在/usr/local/app/resin/conf建立jmx权限配置文件:
1.复制jdk提供的jmx帐号和密码配置文件模板到resin的conf目录:
root@618119.com:/usr/local/app/resin/conf# cp /usr/local/app/jdk1.6.0_21/jre/lib/management/jmxremote.* /usr/local/app/resin/conf
查看文件:
root@618119.com:/usr/local/app/resin/conf# ls -alh jmxremote.*
-rw-r–r– 1 root root 4.0K Oct 23 14:49 jmxremote.access
-r–r–r– 1 root root 2.8K Oct 23 14:49 jmxremote.password.template
2.在/usr/local/app/resin/conf下重命名:jmxremote.password.template为jmxremote.password:
root@618119.com:/usr/local/app/resin/conf# mv jmxremote.password.template  jmxremote.password
3.给密码文件加上写权限:
root@618119.com:/usr/local/app/resin/conf# chmod +w jmxremote.password
查看文件:
root@618119.com:/usr/local/app/resin/conf# ls -alh jmxremote.*
-rw-r–r– 1 root root 4.0K Oct 23 14:49 jmxremote.access
-rw-r–r– 1 root root 2.8K Oct 23 14:49 jmxremote.password
4.以追加文件方式往jmx权限控制文件中加入一个有读写权限的帐号,帐号名字是resinjmx
root@618119.com:/usr/local/app/resin/conf# echo “resinjmx         readwrite” >> jmxremote.access
查看帐号添加是否ok:
root@618119.com:/usr/local/app/resin/conf# tail jmxremote.access
# Default access control entries:
# o The “monitorRole” role has readonly access.
# o The “controlRole” role has readwrite access and can create the standard
#   Timer and Monitor MBeans defined by the JMX API.

monitorRole   readonly
controlRole   readwrite \
create javax.management.monitor.*,javax.management.timer.* \
unregister
resinjmx         readwrite
5.往jmx权限控制的密码文件中加入resinjmx帐号的密码:618119
root@618119.com:/usr/local/app/resin/conf# echo “resinjmx 618119” >> jmxremote.password
查看密码信息是否添加ok:
root@618119.com:/usr/local/app/resin/conf# tail jmxremote.password
# or specify another, less accessible file in the management config file
# as described above.
#
# Following are two commented-out entries.  The “measureRole” role has
# password “QED”.  The “controlRole” role has password “R&D”.
#
# monitorRole  QED
# controlRole   R&D

resinjmx 618119

6.修改jmxremote.*的权限,只允许启动resin的用户名对该文件拥有读写权限:
root@618119.com:/usr/local/app/resin/conf# chmod 600 jmxremote.access
root@618119.com:/usr/local/app/resin/conf# chmod 600 jmxremote.password
root@618119.com:/usr/local/app/resin/conf# ls -alh jmxremote.*
-rw——- 1 root root 4.0K Oct 23 14:54 jmxremote.access
-rw——- 1 root root 2.9K Oct 23 14:57 jmxremote.password
(如果文件权限没有正确设置,在启动使用了jmx的resin时,jvm-default.log中的出错信息为:
Error: Password file read access must be restricted: /usr/local/app/resin//conf/jmxremote.password,可以参考:http://www.opennms.org/wiki/Tomcat_6_JMX_How-To
)
7.配置/usr/local/app/resin/conf的resin.xml
在<server-default>节点下加入下列启动参数,并保存resin.xml
<!–
需要在远程服务器上运行hostname -i,如果显示的127.0.0.1,则需要加上下面一行来指定hostname为公网ip
<jvm-arg>-Djava.rmi.server.hostname=75.126.115.214</jvm-arg>
配置该项的时候,java.rmi.server.hostname=127.0.0.1是肯定不行的,我就是这样绕了弯路:
root@618119.com:/usr/local/app/resin/log# hostname -i
75.126.115.214
–>
<jvm-arg>-Dcom.sun.management.jmxremote.port=50000</jvm-arg>
<jvm-arg>-Dcom.sun.management.jmxremote.ssl=false</jvm-arg>
<jvm-arg>-Dcom.sun.management.jmxremote.authenticate=true</jvm-arg>
<jvm-arg>-Dcom.sun.management.jmxremote.password.file=${resin.root}/conf/jmxremote.password</jvm-arg>
<jvm-arg>-Dcom.sun.management.jmxremote.access.file=${resin.root}/conf/jmxremote.access</jvm-arg>

8.重启resin:
root@618119.com:/usr/local/app/resin/conf# /usr/local/app/resin/bin/resin.sh shutdown
Resin/4.0.12 shutdown watchdog at 127.0.0.1:6600
root@618119.com:/usr/local/app/resin/conf# /usr/local/app/resin/bin/resin.sh start
Resin/4.0.12 launching watchdog at 127.0.0.1:6600
Resin/4.0.12 started -server ” for watchdog at 127.0.0.1:6600

9.在本地电脑运行/usr/local/app/jdk1.6.0_21/bin/jconsole,远程进程填上:618119.com:50000,
点“连接”,提示连接失败。
重新在用户名填resinjmx,口令填:618119.com.
连接成功。

resin.xml中的其它设置:
1.resin4.0默认启动了https端口在8443,可以将resin.xm中下面几行注释掉来关闭https功能:

<http address=”127.0.0.1″ port=”8443″>
<jsse-ssl self-signed-certificate-name=”resin@localhost”/>
</http>
2.resin4.0的resin.xml里没将stdout和stderr显示的声明出来了,
可以将stdout,stderr,accesslog配置成按天输出:
<stdout-log path-format=”log/stdout.log.%Y%m%d”
timestamp=”%Y-%m-%d %H:%M:%S”
rollover-period=”1D”/>
<stderr-log path-format=”log/stderr.log.%Y%m%d”
timestamp=”%Y-%m-%d %H:%M:%S”
rollover-period=”1D”/>
<access-log path-format=”log/access.log.%Y%m%d”
format=’%h %l %u %t “%r” %s %b “%{Referer}i” “%{User-Agent}i” “%{X-Real-IP}i”‘
rollover-period=”1D”/>
stdout-log和stderr-log放到resin元素节点下面.
参考:http://618119.com/archives/2009/02/18/135.html

3.增加Java虚拟机 其它的jvm启动参数:
<!–以server方式启动java虚拟机–>
<jvm-arg>-server</jvm-arg>
<!–指定文件编码默认为UTF-8–>
<jvm-arg>-Dfile.encoding=UTF-8</jvm-arg>
<!–输出log4j自身的调试信息–>
<jvm-arg>-Dlog4j.debug=true</jvm-arg>
<!–指定默认语言为英语–>
<jvm-arg>-Duser.language=en</jvm-arg>
<!–启用gc日志–>
<jvm-arg>-verbose:gc</jvm-arg>
<!–指定输出gc日志的路径–>
<jvm-arg>-Xloggc:${resin.root}/log/gc.log</jvm-arg>
<!–gc日志打印gc详细信息–>
<jvm-arg>-XX:+PrintGCDetails</jvm-arg>
<!–gc日志打印时间戳–>
<jvm-arg>-XX:+PrintGCTimeStamps</jvm-arg>

4.配置泛域名方式的虚拟主机(将发给*.lizongbo.com的请求全部转给一个webapp):

<host id=”lizongbo.com” root-directory=”/usr/local/app/resin/vhost/lizongbo.com”>
<host-alias-regexp>^([^/]*).lizongbo.com</host-alias-regexp>
<web-app id=”/” root-directory=”webapps/ROOT”/>
</host>

(host-alias-regexp的正则表达式是用的java的Pattern.compile(name, Pattern.CASE_INSENSITIVE); ,因此是java的标准正则。

lizongbo.com是才申请的,因此使用301永久重定向跳转到 http://618119.com

index.jsp的代码为:<?xml version=”1.0″ encoding=”UTF-8″?>
<%@page contentType=”text/html; charset=UTF-8″ language=”java”
pageEncoding=”UTF-8″%>
<%@ page import=”java.util.*” session=”false”%>
<%
String goURL=”http://618119.com/”;
response.setHeader(“Location”, goURL);
response.setStatus(HttpServletResponse.SC_MOVED_PERMANENTLY);
%>)

5.通过ps aux|grep java可以看到最终启动的resin进程命令为:
/usr/local/app/jdk1.6.0_21/bin/java -server -Dfile.encoding=UTF-8 -Dcom.sun.management.jmxremote.port=50000 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=true -Dcom.sun.management.jmxremote.password.file=/usr/local/app/resin//conf/jmxremote.password -Dcom.sun.management.jmxremote.access.file=/usr/local/app/resin//conf/jmxremote.access -Dlog4j.debug=true -Duser.language=en -verbose:gc -Xloggc:/usr/local/app/resin//log/gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Dresin.server=1 -Djava.util.logging.manager=com.caucho.log.LogManagerImpl -Djava.system.class.loader=com.caucho.loader.SystemClassLoader -Djavax.management.builder.initial=com.caucho.jmx.MBeanServerBuilderImpl -Djava.awt.headless=true -Dresin.home=/usr/local/app/resin/ -Xss1m -Xmx256m -Dresin.watchdog= -Djava.util.logging.manager=com.caucho.log.LogManagerImpl -Djavax.management.builder.initial=com.caucho.jmx.MBeanServerBuilderImpl -Djava.awt.headless=true -Dresin.home=/usr/local/app/resin/ -Dresin.root=/usr/local/app/resin/ -Dresin.watchdog= -Djava.util.logging.manager=com.caucho.log.LogManagerImpl -Djavax.management.builder.initial=com.caucho.jmx.MBeanServerBuilderImpl -Djava.awt.headless=true -Dresin.home=/usr/local/app/resin/ -Dresin.root=/usr/local/app/resin/ com.caucho.server.resin.Resin –root-directory /usr/local/app/resin/ -conf /usr/local/app/resin/conf/resin.xml -socketwait 37260 start –log-directory /usr/local/app/resin/log

2009年02月21日

服务器从jdk1.6.0升级到1.6.0_12的过程记录

Filed under: Java,JVM,Linux — 标签:, , , , , — lizongbo @ 00:21

服务器从jdk1.6.0升级到1.6.0_12的过程记录

前段时间系统存在问题,在java程序运行几天之后,就会出现物理内存被耗尽的情况。
服务器8G内存,启动两个进程,Xmx=3000m,而程序运行一段时间后,物理内存消耗达到了95%,
然后再持续一段时间之后,服务器就出现死机现象,通过“-verbosegc -XX:+PrintGCDetails”生成的gc log里可以发现,死机前java进程通常会有一大堆Full GC记录。
top -s
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
618119 lizongbo 16 0 7533m 4.8G 1692 S 28 61.0 3309:35 java

当时采取的临时办法是在监控到内存超过95%十分钟后,就通过监控kill其中一个进程,并重启该进程。
这样的处理方式虽然避免了死机情况的出现,但是没想到的时候,没有kill的这个进程,
在持续运行一段时间后,居然占用物理内存到了60%。(linux通过top -s 看%MEM的值)
当时查遍所有的代码,没能找到出现问题的原因。
用命令jmap -heap 618119也没看出不对劲的地方。
然后jmap -histo:live 618119|head -n 40 查看数量最多的对象,发现
java.lang.ThreadLocal$ThreadLocalMap$Entry
[Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
java.util.concurrent.locks.ReentrantReadWriteLock$Sync$HoldCounter
java.util.concurrent.LinkedBlockingQueue$Node
java.util.concurrent.locks.ReentrantReadWriteLock$Sync$ThreadLocalHoldCounter这几个类的实例非常多。
在反复查找代码之后,怀疑是其中用到的ReentrantReadWriteLock出了问题。
关于ReentrantReadWriteLock,可参考:jdk中文本的java doc:
http://download.developers.sun.com.cn/javadoc/jdk6/docs/zh/api/java/util/concurrent/locks/ReentrantReadWriteLock.html
程序里用到了readLock和writeLock的lock与unlock方法,但是试用的方式和官方例子一致,看不出什么问题。
由于曾经看到 阿里的岑文初提到过LinkedBlockingQueue存在内存泄漏:
参考: http://www.blogjava.net/cenwenchu/archive/2008/09/18/229809.html
关于LinkedBlockingQueue可以参考:
http://download.developers.sun.com.cn/javadoc/jdk6/docs/zh/api/java/util/concurrent/LinkedBlockingDeque.html

于是查看linux服务器上的jdk版本:
java -version
java version “1.6.0”
Java(TM) SE Runtime Environment (build 1.6.0-b105)
Java HotSpot(TM) 64-Bit Server VM (build 1.6.0-b105, mixed mode)
原来jdk1.6正式发布时的第一个build正式版本。
因为程序改动并不大,而刚好最近发生这样奇怪的事情,但是拿不出直接证据证明。
于是初步猜测该问题是sun的jdk的bug所致,到sun的官方网站阅读jdk的Update Release Notes日志。

于是在Update Release Notes里找到了以下几个bug修复的记录:

1.6.0_01-b06 修复的关于并发和gc的bug有:
6433335 hotspot garbage_collector ParNewGC times spiking, eventually taking up 20 out of every 30 seconds
6459113 hotspot garbage_collector CMS+ParNew: wildly different ParNew pause times depending on heap shape caused by allocation spread
来源:http://java.sun.com/javase/6/webnotes/6u1.html

1.6.0_02-b06 修复的关于并发和gc的bug有:
6468516 hotspot garbage_collector CMS: deal correctly with concurrently cleared or enqueued Reference objects
6468290 hotspot garbage_collector Divide and allocate out of eden on a per cpu basis
6460501 java classes_util_concurrent Synchronizer timed acquire still leaks memory
6497138 java classes_util_concurrent Scalability limitation in ConcurrentHashMap on Java 6
来源:http://java.sun.com/javase/6/webnotes/6u2.html

1.6.0_04-b12 修复的关于并发和gc的bug有一大堆,就不列出来了:

来源:http://java.sun.com/javase/6/webnotes/6u4.html

1.6.0_10-b33 修复的关于并发和gc的bug有:
6635560 hotspot garbage_collector segv in reference processor on t1000
6642634 hotspot garbage_collector Test nsk/regression/b6186200 crashed with SIGSEGV
6662086 hotspot garbage_collector 6u4+, 7b11+: CMS never clears referents when -XX:+ParallelRefProcEnabled
6676016 hotspot garbage_collector ParallelOldGC leaks memory
6576792 java classes_util_concurrent ThreadPoolExecutor methods leak interrupts when run in pool threads
6639183 java classes_util_concurrent Scheduling large negative delay hangs entire ScheduledExecutor

来源:http://java.sun.com/javase/6/webnotes/6u10.html

1.6.0_12-b04 修复的关于并发和gc的bug有:
6722112 hotspot garbage_collector CMS: Incorrect encoding of overflown object arrays during concurrent precleaning
6722116 hotspot garbage_collector CMS: Incorrect overflow handling when using parallel concurrent marking
6739357 hotspot garbage_collector CMS: Switch off CMSPrecleanRefLists1 until 6722113 can be fixed

来源:http://java.sun.com/javase/6/webnotes/6u12.html

经过对jdk1.6修复bug的记录的分析,怀疑是重点是Synchronizer的这个bug引发的问题
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6460501
从bug描述及java源代码分析,java并发库里的大量的并发组件都依赖于AbstractQueuedSynchronizer,
LinkedBlockingQueue,Semaphore,ReentrantLock,ReentrantReadWriteLock等,均有继承AbstractQueuedSynchronizer的Sync。

由此进一步怀疑是jdk的bug造成内存泄漏的问题。
于是先升级了其中一台服务器的jdk到最新版本,
java -version
java version “1.6.0_12”
Java(TM) SE Runtime Environment (build 1.6.0_12-b04)
Java HotSpot(TM) 64-Bit Server VM (build 11.2-b01, mixed mode)

升级之后,程序连续运行7天没出任何问题,内存回收也十分正常。
运行jmap -histo:live 618119|head -n 40 再次查看对象数量的时候,数量排在前10的实例和存在问题之前的顺序不再一样了。
num #instances #bytes class name
———————————————-
1: 12805991 813400696 [B
2: 8575933 205822392 java.lang.Integer
3: 246199 107685936 [[B
4: 344259 98264616 [Ljava.lang.Object;
5: 1621708 90815648 java.lang.ThreadLocal$ThreadLocalMap$Entry
6: 824 63288512 [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
7: 1620504 51856128 java.util.concurrent.locks.ReentrantReadWriteLock$Sync$HoldCounter
8: 925444 37017760 java.lang.String
9: 333234 30753832 [C
10: 354863 17033424 java.util.HashMap$Entry

于是对改该程序的其它服务器也进行了jdk升级,升级为1.6.0_12-b04。
观察几天后发现,不再出现物理内存耗尽的情况,而且单进程的java内存消耗不再超过Xmx设置的值,在在线用户低谷时候内存也能够顺利回收了。观察一段时间确认jdk升级的效果后,对其他业务的jdk也进行了升级,相关业务也连续几天没在收到告警了。

JDK7.0引入了新的jdk算法,叫做:G1 (The Garbage-First garbage collector),
尤其适合大用户,高并发,容易产生大量临时对象的业务。
参考:http://blogs.sun.com/theplanetarium/entry/java_vm_trying_a_new
该算法也将在jdk1.6的jdk1.6.0_14中引入,目前jdk1.6 u14已经有ea测试版了,
下载地址为:http://download.java.net/jdk6/binaries/ (http://download.java.net/jdk6/6u14/)
试用G1算法的命令行参数为:-XX:+UnlockExperimentalVMOptions -XX:+UseG1GC
参考:http://oss-tw.blogspot.com/2009/02/java-jvm-g1-java-hotspot-14.html

期待JDK1.6 u14早期发布正式版,也期待JDK1.7(JDK7.0)早日正式发布。
到那时候,有jdk的高性能支撑,一些需求就可以轻松搞定了。

2009年02月18日

调整resin的resin.conf优化access-log输出日志

Filed under: Resin — 标签:, — lizongbo @ 00:25

目前服务器上resin.conf的日志配置一般是:
《stdout -log path=”log/stdout.log” timestamp=”[%Y-%m-%d %H:%M:%S] ” rollover-size=”200mb” /》
《stderr -log path=”log/stderr.log” timestamp=”[%Y-%m-%d %H:%M:%S] ” rollover-size=”200mb” /》
《access -log path=”logs/access.log” rollover-period=”1D” rollover-size=”200mb”/》

在这种情况下,日志始终是先输出到logs/access.log这样的固定文件里,待文件大小满200M的时候,resin先锁住所有写日志操作,将文件的内容复制到文件名带时间戳的文件里,再清空当前日志文件的内容。
这种情况下,既多增加了磁盘io操作,也因为锁机制导致线程容易满,以至resin被webapp监控重启。
以前出现该问题的时候,只简单的通过关闭access-log绕了过去,而最近web网站的resin也出现了重启,
由于web是lvs负载均衡,因此不能通过关闭accesslog来解决问题。

经过查看resin的源代码分析,结合现在业务的实际情况,可以通过调整日志的配置为按时间周期切割来解决问题。
通过分析和实验,将resin的配置调整后大致为:

《stdout -log path-format=”log/stdout.log.%Y%m%d” timestamp=”[%Y-%m-%d %H:%M:%S] ” rollover-period=”1D” /》
《stderr -log path-format=”log/stderr.log.%Y%m%d” timestamp=”[%Y-%m-%d %H:%M:%S] ” rollover-period=”1D” /》
《access -log path-format=”logs/access.log.%Y%m%d_%H” rollover-period=”1h”/》
(默认format是combined格式)
上面的是stdout和stderr按天切割(如果代码里异常输出比较多的话,也可以配制成按小时打,例如有:ex.printStackTrace();),access.log按小时切割。

大致分析过程:

访问高峰期时,日志滚动时候,导致线程锁住了。
JMX监控查看线程堆栈可以得知,可以看出大量的线程都 在执行com.caucho.server.log.AccessLog.log的时候BLOCKED了。
[code]
==============================
“resin-tcp-connection-*:80-5973” Id=41812 in BLOCKED on lock=java.lang.Object@14dca59
owned by resin-tcp-connection-*:80-5545 Id=41588
at com.caucho.server.log.AccessLog.log(AccessLog.java:310)
at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:206)
at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:229)
at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:268)
at com.caucho.server.port.TcpConnection.run(TcpConnection.java:389)
at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:507)
at com.caucho.util.ThreadPool.run(ThreadPool.java:433)
at java.lang.Thread.run(Thread.java:619)

[/code]

先下载resin的源代码: http://www.caucho.com/download/resin-3.0.19-src.tar.gz

接下来分析AccessLog的log方法。

可以看到:
if (_isSharedBuffer && ! _isAutoFlush) {
synchronized (_sharedBufferLock) {

而这两个选项的默认值是:_isSharedBuffer=true,_isAutoFlush=false;
(因为resin.conf没有配置对应的属性,例如: shared-buffer=”false” auto-flush=”false”)
而这两个属性在官方文档里并没有直接列出。
http://caucho.com/resin-3.0/config/log.xtp#rollover

(测试了不能设置 auto-flush=”true”,因为没缓冲,还没判断好滚动就直接打到文件了,rollover-size几乎等同失效)

com.caucho.vfs. AbstractRolloverLog.java中:
private static final long DEFAULT_ROLLOVER_CHECK_PERIOD = 600L * 1000L;

private long _rolloverCheckPeriod = DEFAULT_ROLLOVER_CHECK_PERIOD;
滚动日志检测周期默认是10分钟。
而该参数没法在resin.conf中动态配置。

在文件超过指定大小之后,日志滚动的方法为:com.caucho.vfs. AbstractRolloverLog 里的rolloverLog, 这个也是个同步方法:

而执行文件内容的操作是movePathToArchive方法:
而movePathToArchive的做法是:

关键代码是: path.writeToStream(out);和path.truncate()
前一个方法,是表示把当前文件的内容读出来,再写到out里。
后一个方法是,把当前文件内容清空。
而其对应的实现是:
com.caucho.vfs.Path和com.caucho.vfs.FilePath。

从整个代码分析可以得知,resin在按文件大小滚动日志的时候,是检测到当前文件超过200M,就先把缓冲全部写入当前日志文件access.log里,再将access.log的内容读出,再写到 access.log.20090206.1047 这样的文件里,写完之后,再通过truncate利用FileOutputStream的append为false将access.log内容清空。相当于先复制内容到新文件,然后再清空当前文件内容。

而这整个过程中,是同步的,因此在执行复制201M日志的时候,线程全部锁住,而这个时候大量的用户请求正在涌来,导致jmx线程过高且webapp监控告警,于是resin被监控重启。

解决办法:
使用path-format属性替代 path,
例如配置:
《access -log path-format=”logs/access.log.%Y%m%d_%H” rollover-period=”1h”/》
这样就是每小时打一个文件,切换日志输出时候,自动切换,不再产生movePathToArchive操作。
jvm.Log里也没了”Archiving access log to “这样的日志。
Stdout和stderr也是同样处理,有这两个日志的内不会太多,可以配置成按天滚动。
stdout-log元素和stderr-log也有path-format属性。

为什么resin不用File的renameTo通过重命名来切换日志呢,这是因为java的io里,只有所有的流都关闭之后,且操作系统中没有程序对文件持有引用时,文件重命名才能够成功,且renameTo是依赖操作系统的,而这种正在对文件进行读写操作的,执行renameTo无法做到一定成功的。Resin也是因为此,在按文件大小进行滚动的时候,才不得已使用复制文件加清空内容的做法。

Older Posts »

Powered by WordPress