昨天苗同学发现了一个很奇怪的BUG ： ZCMS 中有一个栏目修改信息后不能保存，也不报任何异常，就一直在那等着。我听了以后认为是有人用了类似 PLSQL Developer 之类的工具编辑了栏目表的数据，然后忘了提交了，导致相关记录被锁住，从而使别的用户 update 相关记录时一直处于等待的状态。这种忘了提交导致别人线程挂起的事情在基于 oracle 的项目中时有发生。

　　我就让他去找锁。苗同学果然发现数据库中有锁，但还是有问题，他的描述是：

　　a ，这个栏目信息修改时不会加锁，则是在该栏目的上级栏目使用“应用到子栏目”功能时每次都会加锁，并且一直不释放。

　　b ，只有这个栏目有问题。

　　c ，锁不能直接kill杀掉，只能重启oracle进程。

　　这是一个很奇怪的现象。这个问题最后就转到我手上来了。我测试发现：

　　a，在这个栏目的上级栏目使用“应用到子栏目”功能时确实每次都会加锁。

　　b，但换了一个栏目也会加锁，不是只有这个栏目有问题。

　　c，关掉java进程则锁会自然释放。

　　然后我就去调试代码，找到“应用到子栏目”对应的UI方法，代码如下：

　　代码一：

　　@Priv(CatalogExtendAdminPriv.ID + ".${ID}") public void applyToChildren() { String id = $V("ID"); if (ObjectUtil.empty(id)) { return; } Transaction trans = new Transaction(); ZCCatalog catalog = CatalogUtil.getDAO(Long.parseLong(id)); DAOSet<ZCCatalog> set = new ZCCatalog().query(new Q().where("ContentType", catalog.getContentType()).and() .likeRight("InnerCode", catalog.getInnerCode())); for (ZCCatalog child : set) { child.setConfigProps(catalog.getConfigProps()); ExtendManager.invoke(BeforeCatalogPropSave.ExtendPointID, new Object[] { trans, child });// Extend Point } trans.add(set, Transaction.UPDATE); if (trans.commit()) { for (ZCCatalog child : set) { CacheManager.set(ContentCoreCache.ProviderID, "Catalog", child.getID(), child);// 更新缓存 } success(Lang.get("Common.SaveSuccess")); } }

　　这段代码非常简单，实际上就是一个DAOSet的update动作。调试进去，发现线程会停留在DAOSet.update()方法中调用PreparedStatement.executeBatch()这个方法中。

　　我于把这段代码移出来，新建一个有main()方法的类，在这个类中调用UI方法，代码如下：

　　代码二：

　　public static void main(String[] args) { Config.isPluginContext = true; ExtendManager.getInstance().start(); Current.prepare(null); Current.getRequest().put("ID", "9195"); new CatalogUI().applyToChildren(); }

　　执行这个方法，结果和在tomcat中一样会导致线程挂起。

　　但如果改成更简单的方法就没有问题，如下所示：

　　代码三：

　　public static void main(String[] args) { Q q = new Q("where ContentType='Article' and InnerCode like '000023%'"); new ZCCatalog().query(q).update(); }

　　这两个main方法的区别有两个：

　　a，前一个使用了事务，后一个没有。

　　b，前一个在插件环境下运行，后一个没有。

　　然后进一步排除插件环境的影响，发现只有使用了事务和没有使用事务这一个区别。

　　我再将改造出一个main方法，使用DataAccess手工控制事务，代码如下：

　　代码四：

　　public static void main(String[] args) { DataAccess da = new DataAccess(); try { da.setAutoCommit(false); Q q = new Q("where ContentType='Article' and InnerCode like '000023%'"); DAOSet<ZCCatalog> set = new ZCCatalog().query(q); set.setDataAccess(da); set.update(); da.commit(); da.setAutoCommit(true); } catch (Exception e) { e.printStackTrace(); } finally { da.close(); } }

　　这段代码和代码二实际上等价，结果也一致，都会导致线程挂起。

　　然后进一步改造，代码如下：

　　代码五：

　　public static void main(String[] args) { DataAccess da = new DataAccess(); try { da.setAutoCommit(false); Q q = new Q("where ContentType='Article' and InnerCode like '000023%'"); DAOSet<ZCCatalog> set = new ZCCatalog().query(q); for (ZCCatalog c : set) { c.setDataAccess(da); c.update(); } da.commit(); da.setAutoCommit(true); } catch (Exception e) { e.printStackTrace(); } finally { da.close(); } }

　　这段代码将使用DAOSet.update()调用改成了逐个调用DAO类的update()，结果没有问题，不会导致线程挂起。而DAOSet.update()中使用了PreparedStatement.addBatch()和executeBatch()来批量更新数据，它和DAO.update()就这一点区别。这就很神奇了：

　　a， 在事务中使用批量模式就会导致线程挂起。

　　b，  如果单个更新则没有问题。

　　c， 不使用事务批量更新也没有问题。

　　d， 只有这个表有问题，其他表用类似的代码试了，没有问题。

　　要知道这几种情况都是使用的一模一样的数据，而且都没有任何异常，oracle也没有任何错误日志输出。

　　如果在事务中使用了批量模式导致线程挂起后，在oracle下执行SQL:select * from v$sqlarea where address in (select sql_address from v$session where sid in (select session_id from v$locked_object))

　　发现ZCCatalog确实被锁了。然后再执行：select * from v$session_wait where sid in (select session_id from v$locked_object)

　　发现这个会话的当前事件是SQL*Net message from client，然后去搜了一堆文章，最后发现这是很正常的事件，所以的oracle会话在没有执行SQL时都可能会是这个事件。

　　这个事件似乎是表明oracle在等待jdbc返回进一步的信息，我就怀疑是不是jdbc驱动有问题？然后从oracle官网上下载了好几个版本的驱动，一一尝试后发现都有问题。因此排除了jdbc驱动的原因。

　　从java端彻底没什么办法可想了，只能从oracle端想办法。百度了一大堆文章，没有找到一篇对这个问题有帮助的。我对oracle也不是很熟，根据一篇文章的建议开启一下会话跟踪，尝试了好几个办法，都是在命令行开启的，但我的问题是在jdbc端才能重现，没法使用。折腾了好久，找到了一个有效的办法，如下所示：

　　da.executeNoQuery(new Q("alter session set sql_trace=true")); da.executeNoQuery(new Q("alter session set events '10046 trace name context forever,level 8'"));

　　即在执行其他SQL之前先执行这两个，这样就会在oracle的udump目录下生成会话对应的trc文件。

　　看了生成的trc文件好久，包括使用了tkprof工具分析，试了又试，也没得到什么结果。最后发现有时候jvm退出后trc文件中会追加几句话，如下所示：

　　STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='UPDATE  (cr=1 pr=0 pw=0 time=77 us)'

　　STAT #2 id=2 cnt=1 pid=1 pos=1 obj=162560 op='INDEX UNIQUE SCAN OBJ#(162560) (cr=1 pr=0 pw=0 time=11 us)'

　　WAIT #0: nam='log file sync' ela= 221 p1=855 p2=0 p3=0

　　于是就去搜索这个'log file sync'，又是看了一堆资料，还是没什么收获。突然想起这台机器的另一个端口上有另外的oracle实例，我就在那台机器上试了一下类似的代码（只是改了一个栏目ID），发现没有问题。

　　我仔细检查了两个实例上的代码，发现只有数据上的差异，能在事务中使用批量模式正常update的实例中的数据只有一点和有问题的实例不同：ConfigProps字段时的数据要短一些。

　　但ConfigProps可是varchar2(4000)，存的数据最长也只有1200个字符，并且都是英文。

　　我又人工把正常的实例中的数据的ConfigProps字段加长到和有问题的实例一样大，结果还是可以正常执行。

　　很显然，问题就在于两个实例的配置有差异。但我分析不出是什么原因，就把两个实例的spfile都尽量改成一致。特别是根据那个'log file sync'的提示，将两者的log_buffer都改成一样了。

　　结果有问题的还是有问题，正常的还是正常。我又发现两个实例的Redo日志的大小不一样，正常的那个是每个日志文件100M，不正常的是10M，怀疑是不是因为日志文件太小了，导致频繁切换日志，就把两者调成一样的。结果问题依旧。

　　然后又回来折腾java代码，将更新所有字段改成只更新ConfigProps字段，代码如下：

　　public static void main() { DataAccess da = new DataAccess(); try { da.executeNoQuery(new Q("alter session set sql_trace=true")); da.executeNoQuery(new Q("alter session set events '10046 trace name context forever,level 8'")); Q q = new Q("where ContentType='Article' and InnerCode like '000023%'"); ZCCatalog catalog = new ZCCatalog(); catalog.setDataAccess(da); DAOSet<ZCCatalog> set = catalog.query(q); set.setOperateColumns("ConfigProps"); set.setDataAccess(da); set.update(); } catch (Exception e) { e.printStackTrace(); } finally { da.close(); } }

　　问题依旧。

　　不死心，换成了同一个实例下的另一个栏目：

　　Q q = new Q("where ContentType='Article' and InnerCode like '000021%'");

　　结果发现竟然没有问题！苗同学的描述是有正确的地方的，这个问题是和数据有关的！

　　然后分析两个栏目的数据，依然发现正常的栏目的ConfigProps字段时的数据要短一些。

　　试了又试，最后发现如果ConfigProps字段中的字符数正好是1000个的时候能执行，但1001个就不行。又是一通百度，发现oracle这个坑爹的地方：如果使用的AL32UTF8字符集，1个英文要占4个字节！

　　这个违反我心中的常识：存英文字符所有字符集都最多只有两个字节，UTF8甚至只需要1个。这就导致虽然ConfigProps的差异在解决问题的过程中一再被发现，但我一直都没重视。

　　更坑爹的是：oracle只在有事务的批量模式的时候限制varchar2(4000)只能存1000个字符，其他情况没问题，你可以正常保存1001个！

　　问题终于找到，这只是个测试库，明天重做数据库，把字符集改成符合预期的AMERICAN_AMERICA.UTF8就可以了。

　　总结如下：

　　a，国外的IT公司也会有很多坑爹的BUG。

　　b ，其他同事因为各种原因会向你描述一些不太正确的现象，这也很正常的，你自己也会想偏。

　　c ，软件给出的各种信息有时候也具有误导性。

　　d，解决问题的过程就是排除各种可能的过程，运气不好的话可能要到只剩下唯一的可能才会找到根源。