Jump to: output_first_mismatch    outcomes_full_history    elapsed_time_chart
Show cross-report outcomes.

Annotation type Annotation details
2 @message
IndexError: list index out of range

LOG DETAILS:

2024-05-12 19:15:55.447
2024-05-12 19:15:55.452 act = <firebird.qa.plugin.Action object at [hex]>
2024-05-12 19:15:55.457 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2024-05-12 19:15:55.462
2024-05-12 19:15:55.467 @pytest.mark.version('>=3.0.6')
2024-05-12 19:15:55.473 def test_1(act: Action, capsys):
2024-05-12 19:15:55.477
2024-05-12 19:15:55.482
2024-05-12 19:15:55.487 with act.trace(db_events=trace):
2024-05-12 19:15:55.492 with act.db.connect() as con_aux:
2024-05-12 19:15:55.496 with act.db.connect() as con:
2024-05-12 19:15:55.501 cur = con.cursor()
2024-05-12 19:15:55.506 con.execute_immediate('insert into test(x) values(123)')
2024-05-12 19:15:55.510 con.commit(retaining = True)                    # (TRA_12, ... ; next line: "New number 13"
2024-05-12 19:15:55.515 cur.callproc('sp_worker', [456])                # (TRA_13, INIT_12, ...
2024-05-12 19:15:55.520 con.commit(retaining = True)                    # (TRA_13, INIT_12, ... ; next line: "New number 14"
2024-05-12 19:15:55.525 con.execute_immediate('delete from test')       # (TRA_14, INIT_12, ...
2024-05-12 19:15:55.530 con.commit(retaining = True)                    # (TRA_14, INIT_12, ... ; next line: "New number 15"
2024-05-12 19:15:55.535
2024-05-12 19:15:55.541 # Process trace
2024-05-12 19:15:55.545 tx_base = -1
2024-05-12 19:15:55.551 tx_init_set = set() # at finish it must contain only one element
2024-05-12 19:15:55.556 tx_for_subsequent_changes = -1
2024-05-12 19:15:55.561 for line in act.trace_log:
2024-05-12 19:15:55.567 if line.rstrip().split():
2024-05-12 19:15:55.573 #print(line.strip())
2024-05-12 19:15:55.578 for p in allowed_patterns:
2024-05-12 19:15:55.583 if p.search(line):
2024-05-12 19:15:55.588 print(line.strip())
2024-05-12 19:15:55.593
2024-05-12 19:15:55.598 if '(TRA_' in line:
2024-05-12 19:15:55.603 words = line.replace(',',' ').replace('_',' ').replace('(',' ').split()
2024-05-12 19:15:55.608 # Result:
2024-05-12 19:15:55.612 # 1) for tx WITHOUT retaining: ['TRA', '12', 'READ', 'COMMITTED', '|', 'REC', 'VERSION', '|', 'WAIT', '|', 'READ', 'WRITE)']
2024-05-12 19:15:55.617 # 2) for tx which is RETAINED: ['TRA', '13', 'INIT', '12', 'READ', 'COMMITTED', '|', 'REC', 'VERSION', '|', 'WAIT', '|', 'READ', 'WRITE)']
2024-05-12 19:15:55.622 #                                 0      1     2       3
2024-05-12 19:15:55.627 tx_base = int(words[1]) if tx_base == -1 else tx_base
2024-05-12 19:15:55.632 if words[2] == 'INIT':
2024-05-12 19:15:55.636
2024-05-12 19:15:55.641 tx_init_set.add( int(words[3]) )
2024-05-12 19:15:55.646 assert len(tx_init_set) == 1, 'Multiple transactions are specified in "INIT_nnn" tags in the trace: {tx_init_set}'
2024-05-12 19:15:55.652
2024-05-12 19:15:55.660 tx_that_finished_now = int(words[1])
2024-05-12 19:15:55.665 assert tx_that_finished_now == tx_for_subsequent_changes, 'Finished Tx: {tx_that_finished_now} - NOT equals to "New number": {tx_for_subsequent_changes}'
2024-05-12 19:15:55.670
2024-05-12 19:15:55.675 #tx_origin_of_changes = int(words[3]) - tx_base
2024-05-12 19:15:55.680 #tx_that_finished_now = int(words[1]) - tx_base
2024-05-12 19:15:55.685 # print('Found "INIT_" token in "TRA_" record. Tx that is origin of changes: ', tx_origin_of_changes, '; Tx that finished now:', tx_that_finished_now)
2024-05-12 19:15:55.690 elif 'number' in line:
2024-05-12 19:15:55.695 tx_for_subsequent_changes = int(line.split()[2]) # 'New number 15' --> 15
2024-05-12 19:15:55.701 tx_base = tx_for_subsequent_changes if tx_base < 0 else tx_base
2024-05-12 19:15:55.706 # print('Found record with "NEW NUMBER" for subsequent Tx numbers: ', tx_for_subsequent_changes)
2024-05-12 19:15:55.711
2024-05-12 19:15:55.716
2024-05-12 19:15:55.721 expected_stdout = f"""
2024-05-12 19:15:55.725 New number {tx_base}
2024-05-12 19:15:55.732 >           (TRA_{tx_base}, INIT_{list(tx_init_set)[0]}, CONCURRENCY | WAIT | READ_WRITE)
2024-05-12 19:15:55.737 New number {tx_base+1}
2024-05-12 19:15:55.744 (TRA_{tx_base+1}, INIT_{list(tx_init_set)[0]}, CONCURRENCY | WAIT | READ_WRITE)
2024-05-12 19:15:55.749 New number {tx_base+2}
2024-05-12 19:15:55.754 (TRA_{tx_base+2}, INIT_{list(tx_init_set)[0]}, CONCURRENCY | WAIT | READ_WRITE)
2024-05-12 19:15:55.759 """
2024-05-12 19:15:55.764 E       IndexError: list index out of range
2024-05-12 19:15:55.769
2024-05-12 19:15:55.773 tests/bugs/core_6095_test.py:116: IndexError
2024-05-12 19:15:55.778 ---------------------------- Captured stdout setup -----------------------------
2024-05-12 19:15:55.783 Cached db: db-12.0-None-None-NONE.fdb [page_size=None, sql_dialect=None, charset='NONE'
3 #text
act = <firebird.qa.plugin.Action pytest object at [hex]>
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    @pytest.mark.version('>=3.0.6')
    def test_1(act: Action, capsys):
    
    
        with act.trace(db_events=trace):
            with act.db.connect() as con_aux:
                with act.db.connect() as con:
                    cur = con.cursor()
                    con.execute_immediate('insert into test(x) values(123)')
                    con.commit(retaining = True)                    # (TRA_12, ... ; next line: "New number 13"
                    cur.callproc('sp_worker', [456])                # (TRA_13, INIT_12, ...
                    con.commit(retaining = True)                    # (TRA_13, INIT_12, ... ; next line: "New number 14"
                    con.execute_immediate('delete from test')       # (TRA_14, INIT_12, ...
                    con.commit(retaining = True)                    # (TRA_14, INIT_12, ... ; next line: "New number 15"
    
        # Process trace
        tx_base = -1
        tx_init_set = set() # at finish it must contain only one element
        tx_for_subsequent_changes = -1
        for line in act.trace_log:
            if line.rstrip().split():
                #print(line.strip())
                for p in allowed_patterns:
                    if p.search(line):
                        print(line.strip())
    
                        if '(TRA_' in line:
                            words = line.replace(',',' ').replace('_',' ').replace('(',' ').split()
                            # Result:
                            # 1) for tx WITHOUT retaining: ['TRA', '12', 'READ', 'COMMITTED', '|', 'REC', 'VERSION', '|', 'WAIT', '|', 'READ', 'WRITE)']
                            # 2) for tx which is RETAINED: ['TRA', '13', 'INIT', '12', 'READ', 'COMMITTED', '|', 'REC', 'VERSION', '|', 'WAIT', '|', 'READ', 'WRITE)']
                            #                                 0      1     2       3
                            tx_base = int(words[1]) if tx_base == -1 else tx_base
                            if words[2] == 'INIT':
    
                                tx_init_set.add( int(words[3]) )
                                assert len(tx_init_set) == 1, 'Multiple transactions are specified in "INIT_nnn" tags in the trace: {tx_init_set}'
    
                                tx_that_finished_now = int(words[1])
                                assert tx_that_finished_now == tx_for_subsequent_changes, 'Finished Tx: {tx_that_finished_now} - NOT equals to "New number": {tx_for_subsequent_changes}'
    
                                #tx_origin_of_changes = int(words[3]) - tx_base
                                #tx_that_finished_now = int(words[1]) - tx_base
                                # print('Found "INIT_" token in "TRA_" record. Tx that is origin of changes: ', tx_origin_of_changes, '; Tx that finished now:', tx_that_finished_now)
                        elif 'number' in line:
                            tx_for_subsequent_changes = int(line.split()[2]) # 'New number 15' --> 15
                            tx_base = tx_for_subsequent_changes if tx_base < 0 else tx_base
                            # print('Found record with "NEW NUMBER" for subsequent Tx numbers: ', tx_for_subsequent_changes)
    
    
        expected_stdout = f"""
            New number {tx_base}
>           (TRA_{tx_base}, INIT_{list(tx_init_set)[0]}, CONCURRENCY | WAIT | READ_WRITE)
            New number {tx_base+1}
            (TRA_{tx_base+1}, INIT_{list(tx_init_set)[0]}, CONCURRENCY | WAIT | READ_WRITE)
            New number {tx_base+2}
            (TRA_{tx_base+2}, INIT_{list(tx_init_set)[0]}, CONCURRENCY | WAIT | READ_WRITE)
        """
E       IndexError: list index out of range

tests/bugs/core_6095_test.py:116: IndexError
Full history of outcomes and elapsed time, ms:
NN SNAP_INFO CS_outcome SS_outcome CS_run_time SS_run_time CS_run_beg CS_run_end SS_run_beg SS_run_end
1 3.0.13.33809 2025.05.06 28ad0 P P 3541 2746 2025.06.30 15:03:30.873 2025.06.30 15:03:34.414 2025.06.30 14:07:24.016 2025.06.30 14:07:26.762
2 3.0.13.33808 2025.04.25 28426 P P 3776 2860 2025.05.06 14:05:44.330 2025.05.06 14:05:48.106 2025.05.06 12:59:36.862 2025.05.06 12:59:39.722
3 3.0.13.33803 2025.02.25 08ebd P P 3652 2821 2025.04.25 17:20:31.694 2025.04.25 17:20:35.346 2025.04.25 16:15:04.332 2025.04.25 16:15:07.153
4 3.0.13.33796 2025.01.29 0ab85 P P 1570 971 2025.02.25 15:53:10.712 2025.02.25 15:53:12.282 2025.02.25 14:47:33.080 2025.02.25 14:47:34.051
5 3.0.13.33796 2025.01.14 99b3b P P 1730 1211 2025.01.28 18:08:12.066 2025.01.28 18:08:13.796 2025.01.28 17:00:32.192 2025.01.28 17:00:33.403
6 3.0.13.33795 2024.11.24 b8847 P P 1702 1206 2025.01.13 15:45:09.567 2025.01.13 15:45:11.269 2025.01.13 14:38:48.837 2025.01.13 14:38:50.043
7 3.0.13.33794 2024.10.15 abe09 P P 1212 849 2024.11.23 06:47:13.934 2024.11.23 06:47:15.146 2024.11.23 05:57:20.759 2024.11.23 05:57:21.608
8 3.0.13.33793 2024.10.04 82ccc P P 1405 816 2024.10.14 04:44:54.144 2024.10.14 04:44:55.549 2024.10.14 03:49:23.111 2024.10.14 03:49:23.927
9 3.0.13.33792 2024.08.31 d8791 P P 1467 1061 2024.10.03 09:52:29.280 2024.10.03 09:52:30.747 2024.10.03 08:53:06.476 2024.10.03 08:53:07.537
10 3.0.13.33787 2024.08.17 2e0d6 P P 3357 1479 2024.08.25 15:58:20.305 2024.08.25 15:58:23.662 2024.08.25 13:48:09.987 2024.08.25 13:48:11.466
11 3.0.13.33787 2024.08.09 df740 P P 1628 965 2024.08.16 13:09:39.633 2024.08.16 13:09:41.261 2024.08.16 12:02:46.206 2024.08.16 12:02:47.171
12 3.0.12.33746 2024.07.15 11dd4 P P 2012 1059 2024.08.09 13:05:37.145 2024.08.09 13:05:39.157 2024.08.09 11:57:28.089 2024.08.09 11:57:29.148
13 3.0.12.33746 2024.06.11 8a5eb P P 1256 778 2024.07.15 10:55:37.428 2024.07.15 10:55:38.684 2024.07.15 09:58:21.340 2024.07.15 09:58:22.118
14 3.0.12.33744 2024.05.09 9cf37 F P 1136 694 2024.05.12 16:01:08.449 2024.05.12 16:01:09.585 2024.05.12 15:09:29.404 2024.05.12 15:09:30.098
15 3.0.12.33744 2024.04.20 af6b2 P P 1081 637 2024.05.08 17:16:29.009 2024.05.08 17:16:30.090 2024.05.08 16:26:55.068 2024.05.08 16:26:55.705

Elapsed time, ms. Chart for last 15 runs:

Last commits information (all timestamps in UTC):