后续访问时抛出 Derby LockAcquisitionException答案

【问题标题】：Derby LockAcquisitionException thrown on subsequent accesses后续访问时抛出 Derby LockAcquisitionException
【发布时间】：2023-04-06 08:40:02
【问题描述】：

我有一个用于更新嵌入式 Derby 表的方法。该方法第一次在新数据库上运行时运行良好（即，我删除文件存储，并在创建表时重新创建 Derby）。

在后续执行中，它总是失败并出现 LockAcquisitionException。

有人可以看看这个方法，看看我做错了什么吗？我查看了其他消息：LockAcquisitionException，但似乎没有任何相关性。

private boolean updateTlnDb(Connection connection, ArrayList<TLNDetail> tlnDetails) {
    logger.info("In updateTlnDb.");
    DateFormat etrDateFormat       = new SimpleDateFormat("MM/dd/yyyy HH:mm");
    DateFormat crtDateFormat = new SimpleDateFormat("MM/dd/yyy HH:mm:SS");
    PersistentTransaction t                          = null;
    Date etrDate = null;
    Date crtDate = null;

    // Get our transaction instance
    try {
        t = app.DerbyTLNPersistentManager.instance().getSession().beginTransaction();
    } catch (PersistentException e) {
        logger.error("Could not begin transaction.");
        e.printStackTrace();

        return false;    // Without the transaction, we can't continue.
    }

    app.DAOFactory tlnDaoFactory = app.DAOFactory.getDAOFactory();
    TLNDAO tlndao = tlnDaoFactory.getTLNDAO();

    Collections.sort(tlnDetails, TLNDetail.TLNDetailUpdateIdentifierComparator);

    // Placeholder
    for(TLNDetail tlnDetail: tlnDetails){
        try {
            etrDate = etrDateFormat.parse(tlnDetail.getEtr_dttm());
            crtDate = crtDateFormat.parse(tlnDetail.getTckt_crte_dttm());
        } catch (ParseException e) {
            // Can't proceed without the dates.
            logger.error(e.getMessage());
            return false;
        }

        try {
            if(tlnDetail.getUpdate_identifier().equalsIgnoreCase("A")) {

                app.TLNCriteria tlnCriteria = new TLNCriteria();

                tlnCriteria.txCoordinate.eq(tlnDetail.getTX_coordinate());

                app.TLN tln = tlndao.loadTLNByCriteria(tlnCriteria);

                if(tln==null) {
                    logger.info("Adding " + tlnDetail.getTX_coordinate());
                    app.TLN newTln = tlndao.createTLN();

                    newTln.setTxCoordinate(tlnDetail.getTX_coordinate());
                    newTln.setEtr(new Timestamp(etrDate.getTime()));
                    newTln.setXdate(new Timestamp(crtDate.getTime()));
                    newTln.setBatchkey1("new");

                    tlndao.save(newTln);
                }

            } else if(tlnDetail.getUpdate_identifier().equalsIgnoreCase("C")) {
                app.TLNCriteria tlnCriteria = new TLNCriteria();

                tlnCriteria.txCoordinate.eq(tlnDetail.getTX_coordinate());

                app.TLN tln = tlndao.loadTLNByCriteria(tlnCriteria);
                if(tln!=null) {
                    logger.info("Changing " + tlnDetail.getTX_coordinate());
                    tln.setXdate(new Timestamp(crtDate.getTime()));
                    tln.setEtr(new Timestamp(etrDate.getTime()));
                    tlndao.save(tln);
                }
            } else if(tlnDetail.getUpdate_identifier().equalsIgnoreCase("D")) {
                app.TLNCriteria tlnCriteria = new TLNCriteria();

                tlnCriteria.txCoordinate.eq(tlnDetail.getTX_coordinate());

                app.TLN tln = tlndao.loadTLNByCriteria(tlnCriteria);
                if(tln!=null) {
                    logger.info("Deleting " + tlnDetail.getTX_coordinate());
                    tlndao.delete(tln);
                    tlndao.save(tln);
                }
            }
        } catch (PersistentException e) {
            e.printStackTrace();
        } catch (LockAcquisitionException e) {
            logger.error(e.getMessage());
            return false;
        }
    }

    try {
        t.commit();
    } catch (PersistentException e) {
        e.printStackTrace();
    }
    return false;
}

这是运行输出...

2014-07-08 22:25:46 INFO  UpdateNG:176 - In doIt()
2014-07-08 22:25:46 INFO  UpdateNG:675 - In parseOptions.
2014-07-08 22:25:46 INFO  UpdateNG:707 - In setupCutover.
2014-07-08 22:25:47 INFO  UpdateNG:549 - In loadDriver.
2014-07-08 22:25:47 INFO  UpdateNG:552 - In loadDriver
2014-07-08 22:25:47 INFO  UpdateNG:556 - Loaded the appropriate driver
2014-07-08 22:25:47 INFO  UpdateNG:458 - In createConnection.
2014-07-08 22:25:48 INFO  UpdateNG:425 - In createDatabase.
2014-07-08 22:25:48 INFO  UpdateNG:623 - In parseTlnFiles.
2014-07-08 22:25:48 INFO  UpdateNG:632 - Opened /export/tfcc/sftpusers/fplsftp/home/fplsftp/fplput/TLN.20140529105428
2014-07-08 22:25:48 ERROR UpdateNG:642 - Could not parse: 'HTimestamp05/29/2014 10:53                                                                                                                                  '
2014-07-08 22:25:48 ERROR UpdateNG:643 - Bad etr type.
2014-07-08 22:25:48 INFO  UpdateNG:655 - TLN records parsed: 6
2014-07-08 22:25:48 INFO  UpdateNG:585 - In moveTlnFiles.
2014-07-08 22:25:48 INFO  UpdateNG:317 - In updateTlnDb.
2014-07-08 22:25:48 INFO  Version:37 - HCANN000001: Hibernate Commons Annotations {4.0.2.Final}
2014-07-08 22:25:48 INFO  Version:41 - HHH000412: Hibernate Core {[WORKING]}
2014-07-08 22:25:48 INFO  Environment:224 - HHH000205: Loaded properties from resource hibernate.properties: {hibernate.max_fetch_depth=1, hibernate.jdbc.use_streams_for_binary=true, hibernate.format_sql=true, hibernate.cache.region.factory_class=org.hibernate.cache.internal.NoCachingRegionFactory, hibernate.query.substitutions=yes 'Y', no 'N', hibernate.proxool.pool_alias=pool1, hibernate.cache.region_prefix=hibernate.test, hibernate.bytecode.use_reflection_optimizer=false, hibernate.jdbc.batch_versioned_data=true, hibernate.connection.pool_size=1}
2014-07-08 22:25:48 INFO  Environment:253 - HHH000407: Using java.io streams to persist binary types
2014-07-08 22:25:48 INFO  Environment:342 - HHH000021: Bytecode provider name : javassist
2014-07-08 22:25:48 INFO  Configuration:2006 - HHH000043: Configuring from resource: /ormmapping/DerbyTLN.cfg.xml
2014-07-08 22:25:48 INFO  Configuration:2025 - HHH000040: Configuration resource: /ormmapping/DerbyTLN.cfg.xml
2014-07-08 22:25:48 INFO  Configuration:728 - HHH000221: Reading mappings from resource: ormmapping/app/TLN.hbm.xml
2014-07-08 22:25:48 INFO  Configuration:2147 - HHH000041: Configured SessionFactory: null
2014-07-08 22:25:48 INFO  Dialect:130 - HHH000400: Using dialect: org.hibernate.dialect.DerbyDialect
2014-07-08 22:25:48 WARN  DerbyDialect:60 - HHH000430: The DerbyDialect dialect has been deprecated; use one of the version-specific dialects instead
2014-07-08 22:25:49 WARN  ConnectionProviderInitiator:222 - HHH000209: proxool properties were encountered, but the org.hibernate.service.jdbc.connections.internal.ProxoolConnectionProvider provider class was not found on the classpath; these properties are going to be ignored.
2014-07-08 22:25:49 INFO  DriverManagerConnectionProviderImpl:98 - HHH000402: Using Hibernate built-in connection pool (not for production use!)
2014-07-08 22:25:49 INFO  DriverManagerConnectionProviderImpl:134 - HHH000115: Hibernate connection pool size: 1
2014-07-08 22:25:49 INFO  DriverManagerConnectionProviderImpl:137 - HHH000006: Autocommit mode: false
2014-07-08 22:25:49 INFO  DriverManagerConnectionProviderImpl:151 - HHH000401: using driver [org.apache.derby.jdbc.EmbeddedDriver] at URL [jdbc:derby:/fpl-derby/tlnDb/;create=true]
2014-07-08 22:25:49 INFO  DriverManagerConnectionProviderImpl:156 - HHH000046: Connection properties: {user=sa, password=****}
2014-07-08 22:25:49 INFO  Dialect:130 - HHH000400: Using dialect: org.hibernate.dialect.DerbyDialect
2014-07-08 22:25:49 WARN  DerbyDialect:60 - HHH000430: The DerbyDialect dialect has been deprecated; use one of the version-specific dialects instead
2014-07-08 22:25:49 INFO  TransactionFactoryInitiator:68 - HHH000399: Using default transaction strategy (direct JDBC transactions)
2014-07-08 22:25:49 INFO  ASTQueryTranslatorFactory:48 - HHH000397: Using ASTQueryTranslatorFactory
2014-07-08 22:26:49 WARN  SqlExceptionHelper:145 - SQL Error: 30000, SQLState: 40XL1
2014-07-08 22:26:49 ERROR SqlExceptionHelper:147 - A lock could not be obtained within the time requested
2014-07-08 22:26:49 ERROR UpdateNG:403 - could not prepare statement
2014-07-08 22:26:49 INFO  UpdateNG:507 - In unloadDriver
2014-07-08 22:26:49 INFO  UpdateNG:523 - Derby shut down normally

这是一个锁跟踪...

XID       |TYPE         |MODE|LOCKCOUNT|LOCKNAME                                                                        |STATE|TABLETYPE / LOCKOBJ                   |INDEXNAME / CONTAINER_ID / (MODE for LATCH only)  |TABLENAME / CONGLOM_ID                |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
*** The following row is the victim ***
754       |ROW          |S   |0        |(1,30)                                                                          |WAIT |S                                     |NULL                                              |SYSTABLES                             |
*** The above row is the victim ***
747       |TABLE        |X   |1        |Tablelock                                                                       |GRANT|T                                     |NULL                                              |*** TRANSIENT_1200                    |
747       |TABLE        |IX  |3        |Tablelock                                                                       |GRANT|S                                     |NULL                                              |SYSTABLES                             |
754       |TABLE        |IS  |2        |Tablelock                                                                       |GRANT|S                                     |NULL                                              |SYSTABLES                             |
747       |ROW          |X   |1        |(1,30)                                                                          |GRANT|S                                     |NULL                                              |SYSTABLES                             |
747       |ROW          |S   |2        |(1,17)                                                                          |GRANT|S                                     |NULL                                              |SYSSCHEMAS                            |
754       |ROW          |S   |2        |(1,17)                                                                          |GRANT|S                                     |NULL                                              |SYSSCHEMAS                            |
747       |ROW          |X   |3        |(9,8)                                                                           |GRANT|S                                     |NULL                                              |SYSTABLES                             |
747       |TABLE        |IS  |2        |Tablelock                                                                       |GRANT|S                                     |NULL                                              |SYSSCHEMAS                            |
754       |TABLE        |IS  |2        |Tablelock                                                                       |GRANT|S                                     |NULL                                              |SYSSCHEMAS                            |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

有趣的是，如果我打开行级锁定，应用程序不会挂起。

【问题讨论】：

你看过Derby lock debug吗？
我确实阅读了 Derby 锁调试的资料，包括与 Sunitha 的 IRC 成绩单。我仍然无法弄清楚为什么表级锁定会导致 Derby 超时。

标签： java hibernate exception derby

【解决方案1】：

从您的锁定调试看来，您在 SYSTABLES 上存在冲突。中止的 tx 等待行锁，但另一个 tx 持有表上的表锁。如果您还启用了已执行语句的日志记录 (derby.language.logStatementText)，您应该能够看到哪些操作导致了此冲突。

【讨论】：