13
13
1) "INIT_" token with ID of transaction that originated changes; it must be shown in the same line with "TRA_" info;
14
14
2) "New number <NN>" - ID that will be assigned to the next transaction in this 'chain'; it must be shown in separate line.
15
15
16
- All lines containing "INIT_" must have the same value of transaction that started changes but this value itself can depend
17
- on FB major version and (maybe) of server mode: CS / SC /SS. For this reason we must save this number as special 'base' that
18
- will be subtracted from concrete values during parsing of trace lines - see 'tx_base' variable here.
19
-
20
16
We parse trace log and pay attention for lines like: "(TRA_nnn, INIT_mmm, ..." and "New number <XXX>".
21
17
Each interesting numbers are extracted from these lines and <tx_base> is subtracted from them.
22
- Finally, we display resulting values.
23
- 1) number after phrase "Tx that is origin of changes:" must always be equal to zero;
24
- 2) number after phrase "Tx that finished now" must be:
25
- 2.1) LESS for 1 than value in the next line: "NEW NUMBER" for subsequent Tx..." - for all DML statements EXCEPT LAST;
26
- 2.2) EQUALS to "NEW NUMBER" for subsequent Tx..." for LAST statement because it does not change anything (updates empty table);
27
18
JIRA: CORE-6095
28
19
FBTEST: bugs.core_6095
29
20
NOTES:
30
- [05-mar-2023] pzotov
31
- 1. Additional transaction is started by Garbage Collector when SuperServer is checked.
32
- This transaction starts first so it will be seen as Tx with minimal number in the trace log.
33
- But on some hosts *message* in the trace for this tx can appear *after* common transactions.
34
- In order to force GC transaction appear always as FIRST in the trace log, we launch AUX connection here, see 'con_aux'.
35
- 2. In SuperServer mode we have to take in account as minimal user Tx = 3 (see START_TX).
36
- In Classic this tx = 0.
37
- 3. Expected outputs:
38
- For Classic and SuperClassic:
39
- Found record with "NEW NUMBER" for subsequent Tx numbers: 1
40
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 0 ; Tx that finished now: 1
41
- Found record with "NEW NUMBER" for subsequent Tx numbers: 2
42
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 0 ; Tx that finished now: 2
43
- Found record with "NEW NUMBER" for subsequent Tx numbers: 3
44
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 0 ; Tx that finished now: 3
45
- Found record with "NEW NUMBER" for subsequent Tx numbers: 3
46
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 0 ; Tx that finished now: 3
47
-
48
- For SuperServer:
49
- Found record with "NEW NUMBER" for subsequent Tx numbers: 4
50
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 3 ; Tx that finished now: 4
51
- Found record with "NEW NUMBER" for subsequent Tx numbers: 5
52
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 3 ; Tx that finished now: 5
53
- Found record with "NEW NUMBER" for subsequent Tx numbers: 6
54
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 3 ; Tx that finished now: 6
55
- Found record with "NEW NUMBER" for subsequent Tx numbers: 6
56
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: 3 ; Tx that finished now: 6
57
- 4. Checked on 5.0.0.970 SS/CS/SC
21
+ [07-mar-2023] pzotov
22
+ Re-implemented once again in order to escape dependency on differencies between FB major versions and ServerMode value.
23
+ Two asserts play main role:
24
+ * all lines with 'INIT_nnn' must contain only one value (see assert len(tx_init_set) == 1)
25
+ * value in line "New number nnn" must be equal to the value that is specified on NEXT line in "TRA_nnn"
26
+ Checked on 3.0.11.33665, 4.0.3.2904, 5.0.0.970
58
27
"""
59
28
60
29
import pytest
85
54
86
55
trace = ['log_initfini = false' ,
87
56
'log_transactions = true' ,
88
- 'time_threshold = 0'
89
57
]
90
58
91
- allowed_patterns = [re .compile ('\\ s*\\ (TRA_\\ d+,' , re .IGNORECASE ),
92
- re .compile ('\\ s*New\\ s+number\\ s+\\ d+\\ s*' , re .IGNORECASE ),
93
- ]
59
+ allowed_patterns = [
60
+ re .compile ('\\ s*\\ (TRA_\\ d+,\\ s+INIT_\\ d+' , re .IGNORECASE )
61
+ ,re .compile ('\\ s*New\\ s+number\\ s+\\ d+\\ s*' , re .IGNORECASE )
62
+ ]
94
63
95
64
@pytest .mark .version ('>=3.0.6' )
96
65
def test_1 (act : Action , capsys ):
@@ -106,17 +75,18 @@ def test_1(act: Action, capsys):
106
75
con .commit (retaining = True ) # (TRA_13, INIT_12, ... ; next line: "New number 14"
107
76
con .execute_immediate ('delete from test' ) # (TRA_14, INIT_12, ...
108
77
con .commit (retaining = True ) # (TRA_14, INIT_12, ... ; next line: "New number 15"
109
- # This statement does not change anything:
110
- con .execute_immediate ('update test set x = -x' ) # (TRA_15, INIT_12, ...
111
- con .commit (retaining = True ) # (TRA_15, INIT_12, ... ; next line: "New number 15" -- THE SAME AS PREVIOUS!
78
+
112
79
# Process trace
113
80
tx_base = - 1
81
+ tx_init_set = set () # at finish it must contain only one element
82
+ tx_for_subsequent_changes = - 1
114
83
for line in act .trace_log :
115
84
if line .rstrip ().split ():
116
85
#print(line.strip())
117
86
for p in allowed_patterns :
118
87
if p .search (line ):
119
- #print(line.strip())
88
+ print (line .strip ())
89
+
120
90
if '(TRA_' in line :
121
91
words = line .replace (',' ,' ' ).replace ('_' ,' ' ).replace ('(' ,' ' ).split ()
122
92
# Result:
@@ -125,23 +95,29 @@ def test_1(act: Action, capsys):
125
95
# 0 1 2 3
126
96
tx_base = int (words [1 ]) if tx_base == - 1 else tx_base
127
97
if words [2 ] == 'INIT' :
128
- tx_origin_of_changes = int (words [3 ]) - tx_base
129
- tx_that_finished_now = int (words [1 ]) - tx_base
130
- 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 )
98
+
99
+ tx_init_set .add ( int (words [3 ]) )
100
+ assert len (tx_init_set ) == 1 , 'Multiple transactions are specified in "INIT_nnn" tags in the trace: {tx_init_set}'
101
+
102
+ tx_that_finished_now = int (words [1 ])
103
+ assert tx_that_finished_now == tx_for_subsequent_changes , 'Finished Tx: {tx_that_finished_now} - NOT equals to "New number": {tx_for_subsequent_changes}'
104
+
105
+ #tx_origin_of_changes = int(words[3]) - tx_base
106
+ #tx_that_finished_now = int(words[1]) - tx_base
107
+ # 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)
131
108
elif 'number' in line :
132
- tx_for_subsequent_changes = int (line .split ()[2 ]) - tx_base # New number 15 --> 15
133
- print ('Found record with "NEW NUMBER" for subsequent Tx numbers: ' , tx_for_subsequent_changes )
109
+ tx_for_subsequent_changes = int (line .split ()[2 ]) # 'New number 15' --> 15
110
+ tx_base = tx_for_subsequent_changes if tx_base < 0 else tx_base
111
+ # print('Found record with "NEW NUMBER" for subsequent Tx numbers: ', tx_for_subsequent_changes)
112
+
134
113
135
- START_TX = 0 if 'classic' .lower () in act .vars ['server-arch' ].lower () else 3
136
114
expected_stdout = f"""
137
- Found record with "NEW NUMBER" for subsequent Tx numbers: { START_TX + 1 }
138
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: { START_TX } ; Tx that finished now: { START_TX + 1 }
139
- Found record with "NEW NUMBER" for subsequent Tx numbers: { START_TX + 2 }
140
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: { START_TX } ; Tx that finished now: { START_TX + 2 }
141
- Found record with "NEW NUMBER" for subsequent Tx numbers: { START_TX + 3 }
142
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: { START_TX } ; Tx that finished now: { START_TX + 3 }
143
- Found record with "NEW NUMBER" for subsequent Tx numbers: { START_TX + 3 }
144
- Found "INIT_" token in "TRA_" record. Tx that is origin of changes: { START_TX } ; Tx that finished now: { START_TX + 3 }
115
+ New number { tx_base }
116
+ (TRA_{ tx_base } , INIT_{ list (tx_init_set )[0 ]} , CONCURRENCY | WAIT | READ_WRITE)
117
+ New number { tx_base + 1 }
118
+ (TRA_{ tx_base + 1 } , INIT_{ list (tx_init_set )[0 ]} , CONCURRENCY | WAIT | READ_WRITE)
119
+ New number { tx_base + 2 }
120
+ (TRA_{ tx_base + 2 } , INIT_{ list (tx_init_set )[0 ]} , CONCURRENCY | WAIT | READ_WRITE)
145
121
"""
146
122
147
123
act .expected_stdout = expected_stdout
0 commit comments