Return-Path: Delivered-To: apmail-geronimo-activemq-dev-archive@www.apache.org Received: (qmail 59229 invoked from network); 8 Jun 2006 20:49:57 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (209.237.227.199) by minotaur.apache.org with SMTP; 8 Jun 2006 20:49:57 -0000 Received: (qmail 42043 invoked by uid 500); 8 Jun 2006 20:49:57 -0000 Delivered-To: apmail-geronimo-activemq-dev-archive@geronimo.apache.org Received: (qmail 41922 invoked by uid 500); 8 Jun 2006 20:49:56 -0000 Mailing-List: contact activemq-dev-help@geronimo.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: activemq-dev@geronimo.apache.org Delivered-To: mailing list activemq-dev@geronimo.apache.org Received: (qmail 41905 invoked by uid 99); 8 Jun 2006 20:49:56 -0000 Received: from asf.osuosl.org (HELO asf.osuosl.org) (140.211.166.49) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 08 Jun 2006 13:49:56 -0700 X-ASF-Spam-Status: No, hits=0.0 required=10.0 tests=UPPERCASE_25_50 X-Spam-Check-By: apache.org Received: from [209.237.227.198] (HELO brutus.apache.org) (209.237.227.198) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 08 Jun 2006 13:49:55 -0700 Received: from brutus (localhost [127.0.0.1]) by brutus.apache.org (Postfix) with ESMTP id C6E747142CF for ; Thu, 8 Jun 2006 20:48:51 +0000 (GMT) Message-ID: <9999574.1149799731812.JavaMail.jira@brutus> Date: Thu, 8 Jun 2006 20:48:51 +0000 (GMT+00:00) From: "Maxim Fateev (JIRA)" To: activemq-dev@geronimo.apache.org Subject: [jira] Commented: (AMQ-732) Infinite recovery loop. In-Reply-To: <22656735.1149026932289.JavaMail.jira@brutus> MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit X-Virus-Checked: Checked by ClamAV on apache.org X-Spam-Rating: minotaur.apache.org 1.6.2 0/1000/N [ https://issues.apache.org/activemq/browse/AMQ-732?page=comments#action_36270 ] Maxim Fateev commented on AMQ-732: ---------------------------------- I've attached storatge files. > Infinite recovery loop. > ----------------------- > > Key: AMQ-732 > URL: https://issues.apache.org/activemq/browse/AMQ-732 > Project: ActiveMQ > Type: Bug > Components: Broker > Versions: 4.0 > Environment: Linux RHEL 3 > Reporter: Maxim Fateev > Assignee: Hiram Chirino > Attachments: activemq-data-1-journal.tar.gz, activemq-data-2-journal.tar.gz > > > The simplest way to reproduce the problem: > 1. Remove storage directory. > 2. Start broker using the following code: > public static void main(String[] args) throws Exception { > BrokerService broker = new BrokerService(); > broker.setPersistent(true); > DefaultPersistenceAdapterFactory pFactory = new DefaultPersistenceAdapterFactory(); > pFactory.setJournalLogFiles(1); > pFactory.setJournalLogFileSize(2048); > broker.setPersistenceFactory(pFactory); > broker.setUseJmx(false); > broker.addConnector("tcp://localhost:61616"); > broker.start(); > Thread.sleep(1000000000000l); > } > 3. Shutdown the broker. > 4. Start broker. > It enters infinite loop > [ main] BrokerService INFO ActiveMQ null JMS Message Broker (localhost) is starting > [ main] BrokerService INFO For help or more information please see: http://incubator.apache.org/activemq/ > [ main] JDBCPersistenceAdapter INFO Database driver recognized: [apache_derby_embedded_jdbc_driver] > [ main] DefaultJDBCAdapter DEBUG Executing SQL: CREATE TABLE ACTIVEMQ_MSGS(ID INTEGER NOT NULL, CONTAINER VARCHAR(250), MSGID_PROD VARCHAR(250), MSGID_SEQ INTEGER, EXPIRATION BIGINT, MSG BLOB, PRIMARY KEY ( ID ) ) > [ main] DefaultJDBCAdapter DEBUG Could not create JDBC tables; The message table already existed. Failure was: CREATE TABLE ACTIVEMQ_MSGS(ID INTEGER NOT NULL, CONTAINER VARCHAR(250), MSGID_PROD VARCHAR(250), MSGID_SEQ INTEGER, EXPIRATION BIGINT, MSG BLOB, PRIMARY KEY ( ID ) ) Message: Table/View 'ACTIVEMQ_MSGS' already exists in Schema 'APP'. SQLState: X0Y32 Vendor code: 20000 > [ main] DefaultJDBCAdapter DEBUG Executing SQL: CREATE INDEX ACTIVEMQ_MSGS_MIDX ON ACTIVEMQ_MSGS (MSGID_PROD,MSGID_SEQ) > [ main] DefaultJDBCAdapter DEBUG Executing SQL: CREATE INDEX ACTIVEMQ_MSGS_CIDX ON ACTIVEMQ_MSGS (CONTAINER) > [ main] DefaultJDBCAdapter DEBUG Executing SQL: CREATE INDEX ACTIVEMQ_MSGS_EIDX ON ACTIVEMQ_MSGS (EXPIRATION) > [ main] DefaultJDBCAdapter DEBUG Executing SQL: CREATE TABLE ACTIVEMQ_ACKS(CONTAINER VARCHAR(250) NOT NULL, CLIENT_ID VARCHAR(250) NOT NULL, SUB_NAME VARCHAR(250) NOT NULL, SELECTOR VARCHAR(250), LAST_ACKED_ID INTEGER, PRIMARY KEY ( CONTAINER, CLIENT_ID, SUB_NAME)) > [ main] DefaultJDBCAdapter DEBUG Could not create JDBC tables; The message table already existed. Failure was: CREATE TABLE ACTIVEMQ_ACKS(CONTAINER VARCHAR(250) NOT NULL, CLIENT_ID VARCHAR(250) NOT NULL, SUB_NAME VARCHAR(250) NOT NULL, SELECTOR VARCHAR(250), LAST_ACKED_ID INTEGER, PRIMARY KEY ( CONTAINER, CLIENT_ID, SUB_NAME)) Message: Table/View 'ACTIVEMQ_ACKS' already exists in Schema 'APP'. SQLState: X0Y32 Vendor code: 20000 > [ main] JDBCPersistenceAdapter DEBUG Cleaning up old messages. > [ main] DefaultJDBCAdapter DEBUG Executing SQL: DELETE FROM ACTIVEMQ_MSGS WHERE ( EXPIRATION<>0 AND EXPIRATION [ main] DefaultJDBCAdapter DEBUG Deleted 0 old message(s). > [ main] JDBCPersistenceAdapter DEBUG Cleanup done. > [ main] JournalPersistenceAdapter INFO Journal Recovery Started from: Active Journal: using 1 x 0.001953125 Megs at: /workplace/fateev/install/activemq-4.0-SNAPSHOT/activemq-core/activemq-data/journal > [ main] JournalPersistenceAdapter DEBUG TRACE Entry: RECOVERED > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation offset=53 > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation offset=97 > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation overflowing into next logFile=0 > [ main] JournalPersistenceAdapter DEBUG TRACE Entry: RECOVERED > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation offset=53 > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation offset=97 > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation overflowing into next logFile=0 > [ main] JournalPersistenceAdapter DEBUG TRACE Entry: RECOVERED > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation offset=53 > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation offset=97 > [ Journal Writer] LogFileManager DEBUG getNextDataRecordLocation overflowing into next logFile=0 > The log entry from getNextDataRecordLocation is coming from log statement I've added to LogFileManager.getNextDataRecordLocation: > public Location getNextDataRecordLocation(Location lastLocation) throws IOException, InvalidRecordLocationException { > RecordInfo ri = readRecordInfo(lastLocation); > while (true) { > int logFileId = ri.getLocation().getLogFileId(); > int offset = ri.getNextLocation(); > log.debug("getNextDataRecordLocation offset=" + offset); > // Are we overflowing into next logFile? > if (offset >= ri.getLogFileState().getAppendOffset()) { > LogFileNode nextActive = ri.getLogFileState().getNextActive(); > log.debug("getNextDataRecordLocation overflowing into next logFile=" + (nextActive == null ? "null" : String.valueOf(nextActive.getId()))); > if (nextActive == null) { > return null; > } > logFileId = nextActive.getId(); > offset = 0; > } > try { > ri = readRecordInfo(new Location(logFileId, offset)); > } catch (InvalidRecordLocationException e) { > return null; > } > // Is the next record the right record type? > if (ri.getHeader().getRecordType() == DATA_RECORD_TYPE) { > return ri.getLocation(); > } > // No? go onto the next record. > } > } > It looks like recovery doesn't take into account that journaling storage file should have some end at some point. > Similar problem happens if multiple files of bigger size are used. It happens every time one of the log files grows bigger then size specified in pFactory.setJournalLogFileSize(...) call. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/activemq/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira