MySql 延迟/丢弃 UPDATE/INSERT/DELETE 语句答案

【问题标题】：MySql delays/discards UPDATE/INSERT/DELETE statementsMySql 延迟/丢弃 UPDATE/INSERT/DELETE 语句
【发布时间】：2012-06-27 14:16:21
【问题描述】：

我使用 MySQL 5.5 作为 Web 应用程序的基于 EclipseLink 的持久性后端的数据库。 Web 应用程序是在 Java 7 上使用 Wicket 1.5 构建的。测试环境在 Jetty 7/Mac OSX Lion 上运行，生产环境在 Tomcat 6/Red Hat Enterprise 6.1 上运行。

会发生这种情况：在 web 应用程序上，一个轻量级的 cms，在执行了多次写入操作后，写入操作开始被延迟或丢弃。阅读查询日志显示，不知何故，这些操作不会立即执行（即使我在代码中明确执行所有事务提交），但后来，由另一个写操作触发，突然执行较旧的写操作（在单个交易）。请注意，它们不一定按顺序执行（可能是线程问题？）。

该错误在生产环境中比在测试环境中发生得更早，但最终都会在两者中发生。它仅在我使用 MySql 数据库时发生，而不是在我用于单元测试代码的内存 H2 数据库中发生。我开始认为这是 Tomcat 以某种方式缓存表单提交的问题，但由于在 Jetty 测试环境中，我可以重现我专注于 MySQL 的问题。

现在我绝不是 MySQL 专家，但我尝试了一些对 query_cache 系统变量的摆弄，但无济于事。我还希望设置 flush=on 会有所帮助，但它没有。

我基于上述问题提出的问题是，这确实是 MySQL 问题，还是我必须检查其他地方？如果是这样，任何人都可以指出出了什么问题吗？也许这是一个相当广泛的问题，但如果它的任何部分对某人敲响了警钟，那真的很有帮助。

提前致谢。

编辑：

我包含了 EclipseLink 日志的一部分。如我所见，Thread ...-20,5 使用 UoW ...7099 进行所有工作。然后由于某种原因它切换到线程…-17,5。该线程请求新的 UoW …1848。到目前为止一切顺利，但是在这段摘录的最后，EL 实际上将持久化操作分配给 ...7099，同时提交 ...1848。请注意，我没有在我的代码中明确请求 UoW，我只使用 EntityManager。在日志下方，您还可以找到 persistence.xml。

EclipseLink 日志


[EL Finest]: 2012-07-10 14:52:16.113--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--persist() operation called on: NewsItem(id=0, header=7, content=7, timeStamp=2012-07-10T14:52:16.113+02:00).
[EL Finest]: 2012-07-10 14:52:16.114--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--assign sequence to the object (258 -> NewsItem(id=0, header=7, content=7, timeStamp=2012-07-10T14:52:16.113+02:00))
[EL Finer]: 2012-07-10 14:52:16.114--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--begin unit of work commit
[EL Finest]: 2012-07-10 14:52:16.115--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--Execute query InsertObjectQuery(NewsItem(id=258, header=7, content=7, timeStamp=2012-07-10T14:52:16.113+02:00))
[EL Finest]: 2012-07-10 14:52:16.115--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--Connection acquired from connection pool [default].
[EL Finer]: 2012-07-10 14:52:16.116--ClientSession(1223119569)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--begin transaction
[EL Fine]: 2012-07-10 14:52:16.116--ClientSession(1223119569)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--INSERT INTO NEWSITEM (ID, CONTENT, HEADER, TIMESTAMP) VALUES (?, ?, ?, ?)
    bind => [258, 7, 7, 10 juli 2012 14:52]
[EL Finer]: 2012-07-10 14:52:16.118--ClientSession(1223119569)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--commit transaction
[EL Finest]: 2012-07-10 14:52:16.118--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--Connection released to connection pool [default].
[EL Finer]: 2012-07-10 14:52:16.119--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--end unit of work commit
[EL Finer]: 2012-07-10 14:52:16.119--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--resume unit of work
[EL Finest]: 2012-07-10 14:52:16.12--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--Execute query ReportQuery(referenceClass=NewsItem sql="SELECT COUNT(ID) FROM NEWSITEM")
[EL Finest]: 2012-07-10 14:52:16.12--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--Connection acquired from connection pool [default].
[EL Fine]: 2012-07-10 14:52:16.12--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--SELECT COUNT(ID) FROM NEWSITEM
[EL Finest]: 2012-07-10 14:52:16.122--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--Connection released to connection pool [default].
[EL Finest]: 2012-07-10 14:52:16.122--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-20,5,main])--Execute query ReadAllQuery(referenceClass=NewsItem sql="SELECT ID, CONTENT, HEADER, TIMESTAMP FROM NEWSITEM ORDER BY TIMESTAMP DESC")
[EL Finest]: 2012-07-10 14:52:16.122--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--Connection acquired from connection pool [default].
[EL Fine]: 2012-07-10 14:52:16.122--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--SELECT ID, CONTENT, HEADER, TIMESTAMP FROM NEWSITEM ORDER BY TIMESTAMP DESC
[EL Finest]: 2012-07-10 14:52:16.124--ServerSession(1463061321)--Connection(1934751546)--Thread(Thread[qtp1629549850-20,5,main])--Connection released to connection pool [default].
[EL Finer]: 2012-07-10 14:59:32.322--ServerSession(1463061321)--Thread(Thread[qtp1629549850-17,5,main])--client acquired: 1003847240
[EL Finer]: 2012-07-10 14:59:32.322--ClientSession(1003847240)--Thread(Thread[qtp1629549850-17,5,main])--acquire unit of work: 1029031848
[EL Finest]: 2012-07-10 14:59:32.322--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-17,5,main])--persist() operation called on: NewsItem(id=0, header=8, content=8, timeStamp=2012-07-10T14:59:32.322+02:00).
[EL Finest]: 2012-07-10 14:59:32.323--UnitOfWork(1257127099)--Thread(Thread[qtp1629549850-17,5,main])--assign sequence to the object (259 -> NewsItem(id=0, header=8, content=8, timeStamp=2012-07-10T14:59:32.322+02:00))
[EL Finer]: 2012-07-10 14:59:32.323--UnitOfWork(1029031848)--Thread(Thread[qtp1629549850-17,5,main])--begin unit of work commit
[EL Finer]: 2012-07-10 14:59:32.323--UnitOfWork(1029031848)--Thread(Thread[qtp1629549850-17,5,main])--end unit of work commit
[EL Finer]: 2012-07-10 14:59:32.323--UnitOfWork(1029031848)--Thread(Thread[qtp1629549850-17,5,main])--resume unit of work
[EL Finer]: 2012-07-10 14:59:32.324--UnitOfWork(1029031848)--Thread(Thread[qtp1629549850-17,5,main])--release unit of work

persistence.xml

<persistence-unit name="mySqlJpaPu" transaction-type="RESOURCE_LOCAL">
  <properties>
    <property name="javax.persistence.jdbc.driver" value="com.mysql.jdbc.Driver" />
    <property name="javax.persistence.jdbc.url" value="jdbc:mysql://localhost/xxx" />
    <property name="javax.persistence.jdbc.user" value="xxx" />
    <property name="javax.persistence.jdbc.password" value="xxx" />
    <property name="eclipselink.ddl-generation" value="create-tables" />
    <property name="eclipselink.logging.level" value="ALL"/>
  </properties>
</persistence-unit>

【问题讨论】：

您是否尝试过进行一些线程转储并查看是否存在慢线程？这里的一种思路可能是您的应用程序和 mysql 之间的传输会比内存 Db 慢，如果您有任何同步代码，它可能会阻塞。这反过来看起来你的写入被延迟了，而实际上你的代码还没有发送请求
@Sean 我（还）没有检查线程转储本身，但 MySQL 正在每个连接一个线程的基础上工作，所以我希望所有写入都在该线程上按顺序完成.或者你说的是jetty/tomcat中的线程？
来自应用层。所以是的，来自码头/Tomcat

标签： mysql jpa eclipselink

【解决方案1】：

我严重怀疑这是 MySQL 数据库的问题。相反，我怀疑这是 EclipseLink 与事务管理器交互的问题。您没有提及您是否使用外部事务管理器（JTA 或 OTS）。

当调用 UnitOfWork commit 方法时，应该会导致将更改应用于数据库。这是真的，除非 UnitOfWork 是父 UnitOfWork 的子代。对于子 UnitOfWork，commit 方法不会将更改应用到数据库；而是将任何更改传递给其父 UnitOfWork。

如果是我的代码，我会检查它以确认我没有处理嵌套的工作单元。我会验证对 acquireUnitOfWork 方法的调用是在会话对象上，而不是在另一个 UnitOfWork 对象上。

【讨论】：

我所做的所有事情都是相当直接的 CRUD，即，我从不接触代码中的 UnitOfWork 对象。如果这是问题所在，它不会从一开始就发生，而是在任意数量的写入之后发生吗？我不使用外部事务管理器。这会在这里有所作为吗？

【解决方案2】：

在 EclipseLink 中启用日志记录并检查日志。事务在日志中显示是否正确，事务的写入部分是否符合您的预期？

您使用的是什么类型的连接池和事务控制？包括您的 persistence.xml。

您是如何创建 EntityManagers 的（我假设您正在使用 JPA？）。听起来您正在与不同的线程/请求共享同一个 EntityManager。每个线程/请求/事务都应该有自己的 EntityManager。

【讨论】：

是的，它是 EclipseLink JPA。我启用了日志，并且能够看到出了什么问题，但我不知道（还）为什么。我已将日志添加到原始问题中。
为每个线程创建一个新的 EntityManager 并传递它。您永远不应该将 EntityManager 或事务用作单例。如果你很绝望，你可以使用 ThreadLocal 来存储你的持久化上下文。

【解决方案3】：

您如何获得 EntityManager 并开始/提交事务？看起来您可能正在获取一个新的 EntityManager 并使用它来开始/提交事务，而不是您进行更改的那个。

【讨论】：