Issue Details (XML | Word | Printable)

Key: CORE-6080
Type: Bug Bug
Status: Resolved Resolved
Resolution: Fixed
Priority: Major Major
Assignee: Vlad Khorsun
Reporter: Pavel Zotov
Votes: 0
Watchers: 2
Operations

If you were logged in you would be able to see more operations.
Firebird Core

Attempt to drop existing user randomly fails with "336723990 : record not found for user"

Created: 10/Jun/19 03:29 PM   Updated: 08/Jul/19 08:48 PM
Component/s: Engine
Affects Version/s: 4.0 Beta 1
Fix Version/s: 4.0 Beta 2

Environment: v4 Classic Server only

QA Status: Covered by another test(s)
Test Details:
Test not needed - see CORE-6038 (current ticket was created after fails of core_6038.fbt for 4.0 Cs).
Checked on 4.0.0.1530 Classic mode, ran 262 iterations -- all fine (previous builds failed at ~20...30 th iter.)


 Description  « Hide
This ticket was created by Vlad request after discuss failures in test for CORE-6038 when it is launched
Consider following batch:
=====
@echo off
setlocal enabledelayedexpansion enableextensions
for /f "delims=." %%a in ('wmic os get localdatetime ^| findstr /i /r /b /c:"[0-9]"') do (
  set dts=%%a
  set ymd=!dts:~2,6!
  set hms=!dts:~8,6!
)

set fbc=C:\FB\40CS
set dbpath=c:\temp
set authplg=Srp
@rem set authplg=Legacy_UserManager

set dbnm=!dbpath!\c6038.fdb.tmp
set sql=!dbpath!\%~n0.sql.tmp
set tmp=!dbpath!\%~n0.tmp.tmp
set err=!dbpath!\%~n0.err.tmp

set log=%~dpn0.!ymd!_!hms!.log

if exist !dbnm! del !dbnm!
(
    echo set bail on;
    echo create database 'localhost:!dbnm!' user sysdba password 'masterkey';
    echo commit;
    echo alter database set linger to 30;
    echo commit;
    echo show database;
) >!tmp!
!fbc!\isql.exe -z -q -i !tmp!

!fbc!\gfix.exe -w async localhost:!dbnm! -user sysdba -password masterkey

(
    echo connect 'localhost:!dbnm!' user sysdba password 'masterkey';
    echo create or alter user c6038_srp password 'c6038_srp' using plugin !authplg!;
    echo commit;
    echo connect 'localhost:!dbnm!' user c6038_srp password 'c6038_srp';
    echo commit;
    echo connect 'localhost:!dbnm!' user sysdba password 'masterkey';
    echo drop user c6038_srp using plugin !authplg!;
) > !sql!


!fbc!\fbsvcmgr.exe localhost:service_mgr user sysdba password masterkey info_server_version >!tmp!
type !tmp!
type !tmp! >>!log!
echo !date! !time! Started.

if exist !err! del !err!
set verb=1
set /a n=300
set /a i=0
:m1
    set /a i=!i!+1
    if !verb! EQU 1 (
        echo !date! !time!, attempt !i! >!tmp!
        type !tmp!
        type !tmp! >>!log!
        del !tmp!
        for /f "usebackq tokens=*" %%a in ('!err!') do set size=%%~za
        if !size! gtr 0 (
            echo CONNECTION FAILED IN ITERATION # !i!. CHECK ERROR LOG:
            type !err!
            type !err! >>!log!
            exit
        )
    )
    !fbc!\isql.exe -q -i !sql! 1>>!err! 2>&1
    if !i! GEQ !n! (
        echo !date! !time! Completed.
        for /f "usebackq tokens=*" %%a in ('!err!') do set size=%%~za
        if !size! gtr 0 (
            echo CHECK ERROR LOG AFTER ALL ITERATIONS:
            type !err!
            type !err! >>!log!
        )
        exit
    )
goto m1
=====

Change in it only these three settings: fbc, dbpath and authplg.
Prepare FB to work as Classic and run this batch.

On WI-T4.0.0.1524 you will soon encounter with:
=====
10.06.2019 18:13:19.67, attempt 1
10.06.2019 18:13:20.72, attempt 2
. . .
10.06.2019 18:13:49.75, attempt 27
10.06.2019 18:13:50.79, attempt 28
Statement failed, SQLSTATE = HY000
modify record error
After line 1 in file c:\temp\c6038.leg.sql.tmp
Statement failed, SQLSTATE = 28000
Your user name and password are not defined. Ask your database administrator to set up a Firebird login.
After line 3 in file c:\temp\c6038.leg.sql.tmp
Statement failed, SQLSTATE = HY000
record not found for user: C6038_SRP
=====

Trace with 'log_prepare_statements = true' will show:

1) TWO prepare_statement events before point when error raises:

PREPARE_STATEMENT
drop user c6038_srp using plugin Srp
....
PREPARE_STATEMENT
drop user c6038_srp using plugin Srp

2) SUCCESSFUL finish of executed statement:

EXECUTE_STATEMENT_FINISH
drop user c6038_srp using plugin Srp
    0 records fetched
          0 ms

and immediately after this - error:

3) ERROR AT JTransaction::commit
        C:\TEMP\C6038.FDB.TMP (ATT_55, SYSDBA:NONE, NONE, TCPv6:::1/63982)
        C:\FB\40SS\isql.exe:5124
    336723990 : record not found for user: C6038_SRP

 All   Comments   Change History   Subversion Commits      Sort Order: Ascending order - Click to sort in descending order
Vlad Khorsun added a comment - 10/Jun/19 05:14 PM
The issue is introduced in fb4 with a new implementation od TIP cache and related with initialization of few shared memory blocks as single atomic operation

Artyom Smirnov added a comment - 02/Jul/19 02:48 PM
Looks like fix for this issue caused some regressions. Test bugs.core_2018 hanging server on Classic (all OK on Super) after commit 3bfa5fa100800c79b7edc5415d8e58625c8c4682.

Two hanged server processes backtraces:

https://gist.github.com/artyom-smirnov/1954fa1cd58f6886784a5dca9f7152cb

https://gist.github.com/artyom-smirnov/30cd05ab7b28326bf8195e3746985b10

Isql backtrace:

https://gist.github.com/artyom-smirnov/cf3c452a13f4ea206cea980fe6a5f3bd

Vlad Khorsun added a comment - 02/Jul/19 04:13 PM
Re-opened to fix a bug, introduced by initial attempt

Vlad Khorsun added a comment - 02/Jul/19 10:35 PM
Should be fixed now.

Vlad Khorsun added a comment - 04/Jul/19 01:01 PM
Artyom, Pavel : could you verify last fix and let me close the ticket, please ?

Pavel Zotov added a comment - 05/Jul/19 08:07 PM - edited
I confirm that there are no problems in Classic with test for core-2018 when it is launched on following builds:
1) 4.0.0.1556: OK, 2.929s.
2) 3.0.5.33152: OK, 2.157s.