Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

internal Firebird consistency check (Incorrect snapshot deallocation - too few slots) [CORE5930] #6187

Closed
firebird-issue-importer opened this issue Sep 30, 2018 · 8 comments

Comments

@firebird-issue-importer

Submitted by: @mrotteveel

I was just running the Jaybird tests against Firebird-4.0.0.1227-0_x64 (Windows 10). It has been a while since I tested with Firebird 4, so I don't know when this problem was introduced.

When running the test org.firebirdsql.gds.TestReconnectTransaction.testReconnectTransaction, I get an error when trying to rollback a limbo transaction:

java.sql.SQLException: internal Firebird consistency check (Incorrect snapshot deallocation - too few slots) [SQLState:XX000, ISC error code:335544333]

In short this test will create a connection, start a transaction, prepare that transaction and then close the connection. This will create a limbo transaction.

It then creates a new connection, start a transaction, look for the limbo transaction, reconnects the limbo transaction, and then rolls back the limbo transaction.

The rollback of the limbo transaction is what fails.

Test: https://github.com/FirebirdSQL/jaybird/blob/master/src/test/org/firebirdsql/gds/TestReconnectTransaction.java#L86

I have tried setting ReadConsistency = 0 in firebird.conf, but that has made no difference.

After running this test, the log contains the following entries:

"""
RAMONA Sat Sep 29 18:05:26 2018
Database: D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB
internal Firebird consistency check (Incorrect snapshot deallocation - too few slots)

RAMONA Sat Sep 29 18:05:27 2018
INET/inet_error: read errno = 10054, client host = Ramona, address = 127.0.0.1/61486, user = Mark

RAMONA Sat Sep 29 18:05:27 2018
I/O error during "WriteFile" operation for file "D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB"
Error while trying to write to file
The handle is invalid.

RAMONA Sat Sep 29 18:05:27 2018
Database: D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB
I/O error during "WriteFile" operation for file "D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB"
Error while trying to write to file
The handle is invalid.
"""

After this error has occurred, it also doesn't seem possible to gracefully shutdown Firebird. It seems to hang. After shutting down, new connections are rejected, but the process does not stop and needs to be killed.

Attempting to connect after trying to stop Firebird logs:

"""
RAMONA Sat Sep 29 18:07:55 2018
Authentication error
connection shutdown
"""

Likely a related issue, another test (org.firebirdsql.gds.ng.wire.version10.TestV10Transaction.testBasicPrepareAndRollback) gets stuck.

This test creates a connection, starts a transaction (read committed record version wait), inserts a value into a table, prepares the transaction (to be committed later in the test).

Test: https://github.com/FirebirdSQL/jaybird/blob/master/src/test/org/firebirdsql/gds/ng/AbstractTransactionTest.java#L154 (it hangs on assertValueForKey(key, false, null);)

Then in a separate connection + transaction (also read committed record version wait), the test attempts to select from the table. This connection is stuck fetching rows (even when setting ReadConsistency = 0 in firebird.conf).

This works fine in Firebird 3 and earlier.

With setting ReadConsistency = 0 in firebird.conf this is logged (after killing the test):

"""
RAMONA Sat Sep 29 18:28:36 2018
INET/inet_error: read errno = 10054, client host = Ramona, address = 127.0.0.1/61927, user = Mark

RAMONA Sat Sep 29 18:28:36 2018
INET/inet_error: read errno = 10054, client host = Ramona, address = 127.0.0.1/61926, user = Mark
"""

With setting ReadConsistency = 1 in firebird.conf:

"""
RAMONA Sat Sep 29 18:31:27 2018
INET/inet_error: read errno = 10054, client host = Ramona, address = 127.0.0.1/61943, user = Mark

RAMONA Sat Sep 29 18:31:27 2018
INET/inet_error: read errno = 10054, client host = Ramona, address = 127.0.0.1/61944, user = Mark

RAMONA Sat Sep 29 18:31:27 2018
Database: D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB
internal Firebird consistency check (TPC: Attempt to mark inactive transaction to be in limbo)

RAMONA Sat Sep 29 18:31:27 2018
I/O error during "WriteFile" operation for file "D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB"
Error while trying to write to file
The handle is invalid.

RAMONA Sat Sep 29 18:31:27 2018
Database: D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB
I/O error during "WriteFile" operation for file "D:\DEVELOPMENT\PROJECT\JAYBIRD\JAYBIRD\FBTEST.FDB"
Error while trying to write to file
The handle is invalid.
"""

Interestingly after this test, Firebird has no problem shutting down with setting ReadConsistency = 0, but hangs with setting ReadConsistency = 1.

Commits: b197763 ab794fc 02dc5fe

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Sep 30, 2018

Modified by: @mrotteveel

assignee: Vlad Khorsun [ hvlad ]

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Sep 30, 2018

Commented by: @hvlad

The first case is a bug - when reconnected transaction is committed\rolled back, engine tries to release not existing transaction snapshot.
It is easy to fix, fortunately.

At the second case i see no reason for second transaction (read committed record version wait) to not wait for the first (still active) transaction.

As for the bugcheck "TPC: Attempt to mark inactive transaction to be in limbo" - i think i can fix it too.

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Sep 30, 2018

Commented by: @hvlad

Both bugchecks should be fixed now.

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Sep 30, 2018

Commented by: @mrotteveel

Given the use of read committed record version (instead of no record version), it should read the last committed record and not wait on not yet committed changes. That is how it has worked up to now. If this is going to change because of the read consistency change, then I think we have a big regression in read committed transaction behavior.

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Oct 2, 2018

Commented by: @hvlad

It should be fixed now.

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Oct 5, 2018

Commented by: @hvlad

Mark,
could you check last snapshot build, please ?

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Oct 6, 2018

Commented by: @mrotteveel

Tested with Firebird-4.0.0.1234-0_x64 and tests now work as expected (both with ReadConsistency = 0 and ReadConsistency = 1)

@firebird-issue-importer
Copy link
Author

@firebird-issue-importer firebird-issue-importer commented Oct 6, 2018

Modified by: @hvlad

status: Open [ 1 ] => Resolved [ 5 ]

resolution: Fixed [ 1 ]

Fix Version: 4.0 Beta 1 [ 10750 ]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
2 participants