问题信息
出现问题的环境
Linux + Tomcat + jdk1.8
Mybatis + 阿里的druid数据源
问题描述
通过手机号去数据库里面查询数据，手机号太多就会出现栈溢出异常。
linux 300+作业出现溢出
错误代码信息
错误信息
Caused by: java.lang.StackOverflowError
at com.alibaba.druid.sql.visitor.SQLASTOutputVisitor.print(SQLASTOutputVisitor.java:182) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.sql.dialect.oracle.visitor.OracleParameterizedOutputVisitor.visit(OracleParameterizedOutputVisitor.java:79) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.sql.ast.expr.SQLCharExpr.accept0(SQLCharExpr.java:44) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.sql.ast.SQLObjectImpl.accept(SQLObjectImpl.java:43) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.sql.visitor.SQLASTOutputVisitor.printAndAccept(SQLASTOutputVisitor.java:226) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.sql.visitor.SQLASTOutputVisitor.visit(SQLASTOutputVisitor.java:499) ~[druid-0.2.22.jar:0.2.22]
…
at com.alibaba.druid.filter.stat.StatFilter.mergeSql(StatFilter.java:145) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.filter.stat.StatFilter.createSqlStat(StatFilter.java:629) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.filter.stat.StatFilter.internalBeforeStatementExecute(StatFilter.java:397) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.filter.stat.StatFilter.statementExecuteBefore(StatFilter.java:345) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:438) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:2927) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.execute(PreparedStatementProxyImpl.java:118) ~[druid-0.2.22.jar:0.2.22]
at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:493) ~[druid-0.2.22.jar:0.2.22]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_73]
at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_73]
at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:55) ~[mybatis-3.2.1.jar:3.2.1]
at com.sun.proxy.
P
r
o
x
y
282.
e
x
e
c
u
t
e
(
U
n
k
n
o
w
n
S
o
u
r
c
e
)
[
?
:
?
]
a
t
o
r
g
.
a
p
a
c
h
e
.
i
b
a
t
i
s
.
e
x
e
c
u
t
o
r
.
s
t
a
t
e
m
e
n
t
.
P
r
e
p
a
r
e
d
S
t
a
t
e
m
e
n
t
H
a
n
d
l
e
r
.
q
u
e
r
y
(
P
r
e
p
a
r
e
d
S
t
a
t
e
m
e
n
t
H
a
n
d
l
e
r
.
j
a
v
a
:
56
)
[
m
y
b
a
t
i
s
−
3.2.1.
j
a
r
:
3.2.1
]
a
t
o
r
g
.
a
p
a
c
h
e
.
i
b
a
t
i
s
.
e
x
e
c
u
t
o
r
.
s
t
a
t
e
m
e
n
t
.
R
o
u
t
i
n
g
S
t
a
t
e
m
e
n
t
H
a
n
d
l
e
r
.
q
u
e
r
y
(
R
o
u
t
i
n
g
S
t
a
t
e
m
e
n
t
H
a
n
d
l
e
r
.
j
a
v
a
:
70
)
[
m
y
b
a
t
i
s
−
3.2.1.
j
a
r
:
3.2.1
]
a
t
s
u
n
.
r
e
f
l
e
c
t
.
G
e
n
e
r
a
t
e
d
M
e
t
h
o
d
A
c
c
e
s
s
o
r
78.
i
n
v
o
k
e
(
U
n
k
n
o
w
n
S
o
u
r
c
e
)
[
?
:
?
]
a
t
s
u
n
.
r
e
f
l
e
c
t
.
D
e
l
e
g
a
t
i
n
g
M
e
t
h
o
d
A
c
c
e
s
s
o
r
I
m
p
l
.
i
n
v
o
k
e
(
D
e
l
e
g
a
t
i
n
g
M
e
t
h
o
d
A
c
c
e
s
s
o
r
I
m
p
l
.
j
a
v
a
:
43
)
[
?
:
1.8.
0
7
3
]
a
t
j
a
v
a
.
l
a
n
g
.
r
e
f
l
e
c
t
.
M
e
t
h
o
d
.
i
n
v
o
k
e
(
M
e
t
h
o
d
.
j
a
v
a
:
497
)
[
?
:
1.8.
0
7
3
]
a
t
o
r
g
.
a
p
a
c
h
e
.
i
b
a
t
i
s
.
p
l
u
g
i
n
.
P
l
u
g
i
n
.
i
n
v
o
k
e
(
P
l
u
g
i
n
.
j
a
v
a
:
59
)
[
m
y
b
a
t
i
s
−
3.2.1.
j
a
r
:
3.2.1
]
a
t
c
o
m
.
s
u
n
.
p
r
o
x
y
.
Proxy282.execute(Unknown Source) ~[?:?] at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:56) ~[mybatis-3.2.1.jar:3.2.1] at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:70) ~[mybatis-3.2.1.jar:3.2.1] at sun.reflect.GeneratedMethodAccessor78.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_73] at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_73] at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:59) ~[mybatis-3.2.1.jar:3.2.1] at com.sun.proxy.
Proxy282.execute(UnknownSource) [?:?]atorg.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:56) [mybatis−3.2.1.jar:3.2.1]atorg.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:70) [mybatis−3.2.1.jar:3.2.1]atsun.reflect.GeneratedMethodAccessor78.invoke(UnknownSource) [?:?]atsun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [?:1.8.073]atjava.lang.reflect.Method.invoke(Method.java:497) [?:1.8.073]atorg.apache.ibatis.plugin.Plugin.invoke(Plugin.java:59) [mybatis−3.2.1.jar:3.2.1]atcom.sun.proxy.Proxy280.query(Unknown Source) ~[?:?]
at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:57) ~[mybatis-3.2.1.jar:3.2.1]
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:259) ~[mybatis-3.2.1.jar:3.2.1]
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:132) ~[mybatis-3.2.1.jar:3.2.1]
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:115) ~[mybatis-3.2.1.jar:3.2.1]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:104) ~[mybatis-3.2.1.jar:3.2.1]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:98) ~[mybatis-3.2.1.jar:3.2.1]
at sun.reflect.GeneratedMethodAccessor90.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_73]
at java.lang.reflect.Method.invoke(Method.java:497) ~[?:1.8.0_73]
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:354) ~[mybatis-spring-1.2.0.jar:1.2.0]
排查过程
初次排查
由于是stackOverFlowError, 错误日志里面，有很长的日志都是druid在设置参数，怀疑是递归层级太深，超过了栈允许的最大深度。
想在自己的开发环境重现， Windows + Junit + jdk1.7，使用相同数据库，一次测试300+手机号，正常。 直接改成上限1000 (oracle in 传参上限)，运行多次正常。
此时初步判断不是调用层级太深， 环境问题？
此时查看Linux上的JVM启动参数配置，-Xss256k (Thread Stack Size)
本地开发环境再验证时，增加-Xss256k设置，手机号一次验证数量到660左右时，出现相同的异常。 将Xss修改为512k，问题解决，Linux上问题也解决。
问题圆满解决？
补充点：
JVM栈出现StackOverFlowError的场景：栈调用层级太深，或栈申请不到内存
再起波澜
反馈给运维的同学， Xss需要设置为512k。 运维的同学不同意！！！ 原该参数为128k，后来不满足需求调整为256k， 不同意再调大了。建议我们优化代码 ( 内存大小固定的情况下，单个线程占用的内存越大，总线程数量就会越少 )
what can I do ?
- 提示日志级别， 出现问题时是debug，改成error ？ 因为debug输出的日志多，会多定义一些局部变量 。 No，不行
- 使用到Long类型的修改为Integer. 栈内存中，Long需要占用2个slot， Integer只需要占用一个。 No，不行
…
没有想到好的头绪，先自己手工调整了服务器上的JVM参数. Xss修改为512k - 拖了几天，有次骑车突然闪现了一个很笨的办法 (当时自得意为灵光一闪)。 既然300+无法查询，内部实现的时候，每100个号查询一次，然后拼装结果？
当时的想法是，300个号码能查询， 每次100个肯定可以查询，然后外层方法调用里面的具体实现，里层方法退出时栈 (栈帧)占用的空间释放掉，则应该不会超过256k的限制
回来后进行验证， 不行， 为什么， - 后来查看druid连接池的具体实现，网上搜索了一些资料。需要先做SQL解析，生成语法树，然后根据目标数据库类型生成对应的SQL。 怀疑由于SQL太复杂导致解析复杂，方法调用太多，大量局部变量 ？
对SQL进行修改，还原成最初的SQL (原来是由于有性能问题，每次in遍历的时候，所有手机号均需做一次加密操作)， 该问题不再出现。
后来SQL改写了下，避免了SQL union的问题，但有个新的性能问题：对每个手机号需要做一次解密操作。 新问题尚未想到解决方案（文章后面有后来想到的其他思路）
问题原因
Thread Stack Size大小，问题环境设置为256k，内存申请不到，所以出现栈溢出的异常
阿里的druid框架，做SQL解析(visitor模式), 由于SQL很复杂, 很多SQL做union拼接, SQL解析时构造了很复杂的语法树
解决方案
修改JVM大小
-Xss参数由256k改到512k后，一次查询1000个手机号，不会出现栈溢出异常
##方法优化，降低占用的栈内存
没找到好的方案
SQL优化
同样带来了一个新问题, 每个手机号都需要做一次解密操作。
后来换了个角度想了下，把解密这个，可以先在程序里面做掉。或者反过来对外层数据加密也可以。
1871
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
