Forum: >>> Magnum BBS <<<

[Info-ingres] duplicate entries in iirelation (1/2)

From Paul White@21:1/5 to All on Tue Apr 27 11:25:57 2021

This is a multi-part message in MIME format.
Good morning all.

On a busy server, I found a duplicate user table in iirelation with
duplicated records in iiattributes. The two entries have different reltids.

There is no physical table or index corruption in the system catalog
tables. There have been no unusual events on the 24x7 server and no downtime. I found this:

https://communities.actian.com/s/article/Why-Are-Duplicate-Rows-Allowed-in-iirelation-with-Ingres-II-10
<https://communities.actian.com/s/article/Why-Are-Duplicate-Rows-Allowed-in-iirelation-with-Ingres-II-10>

iirelation has a hash index on owner and name but it is not marked as
unique.

How does does Ingres guarantee uniqueness for tables and columns -
clearly it cannot.

I have a reproducible case lodged with Actian support and will send an
update when there is an outcome. Technical goodies follow...

I captured the event with SET SERVER TRACE. On this server, I have
trace active all the time, with a script to rotate the log directory
daily and keeping a month archived. There is no detectable impact on operations. I found this feature valuable to help track down elusive
problems after the fact. It provides a useful daily summary /
exceptions report.

The trace provided clear evidence (down to nanosecond timing) to show
there were two sessions connected with the same credentials running the
same OpenROAD application. It creates a local user temp table for an
enquiry function. The code is faulty with the transaction running READ UNCOMMITTED and DBMS error checking is missing for some statements.
Where an error is successfully captured, the ROLLBACK/COMMIT sequence is faulty.

The first session is running a batch job like this:

Check for table in iitables returns 1 row
drop table
create table as select...
commit

a few seconds later

Check for table in iitables returns 0 rows
create table as select...
US07DA Duplicate object name '%0c'.
commit

a few minutes later

Check for table in iitables returns 2 rows
drop table
create table as select...
US07DA Duplicate object name '%0c'.
commit

This last sequence repeats until the end of the job. The code can run with the duplicate tables.

The second session:

Check for table in iitables returns 1 row
drop table
create table as select...
E_US13EE Duplicate table name
rollback

Ingres version is:

Version: II 11.1.0 (a64.lnx/100) + P15546

Duplicate table is here:

* select table_owner, varchar( table_name,20) tab, create_date,
table_reltid from iitables where table_owner= 'sbradfor'\g
Executing . . .

┌────────────────────────────────┬────────────────────┬─────────────────────────┬────
─────────┐ │table_owner │tab │create_date
│table_reltid │ ├────────────────────────────────┼────────────────────┼─────────────────────────┼────
─────────┤ │sbradfor │tmp_cur_pricelist │2021_04_20 05:13:31
GMT │ 382408│ │sbradfor │tmp_cur_pricelist │2021_04_20 05:13:46
GMT │ 382414│ └────────────────────────────────┴────────────────────┴─────────────────────────┴────
─────────┘
(2 rows)

* select table_owner, varchar( table_name,20) tab,
varchar(column_name,20) col from iicolumns where table_owner= 'sbradfor'
order by column_name\g
Executing . . .

┌────────────────────────────────┬────────────────────┬────────────────────┐
│table_owner │tab │col │
├────────────────────────────────┼────────────────────┼────────────────────┤
│sbradfor │tmp_cur_pricelist │catlog_code │
│sbradfor │tmp_cur_pricelist │catlog_code │
│sbradfor │tmp_cur_pricelist │cust_code │
│sbradfor │tmp_cur_pricelist │cust_code │
│sbradfor │tmp_cur_pricelist │disc_percent │
│sbradfor │tmp_cur_pricelist │disc_percent │
│sbradfor │tmp_cur_pricelist │price │
│sbradfor │tmp_cur_pricelist │price │
└────────────────────────────────┴────────────────────┴────────────────────┘
(8 rows)
continue

I used rollforwarddb on the replica server to track down the exact
timing of the event, and correlate it with the SERVER TRACE logs

The SESSION BEGINS show user sbradfor is in two DB sessions running simultaneously from different client PCs. At this site, the user name is
hard coded in the vnodes.

Session 1 08:29:30 - 16:15:21

Session 2 08:25:50 - 15:56:22

Here is an example of overlapping events:

Note that 1618895626 = 15:13:46

qtrace_ctrust_168856_7f570eae5100.log

1618895626.089771974 check iitables, one row is returned,

1618895626.094464779 drop table,

1618895626.139567455 create table gives E_US13EE Duplicate table name

1618895626.549601019 rollback

qtrace_ctrust_168856_7f570f808440.log

1618895626.125806952 check iitables, zero rows returned

1618895626.129856430 create table gives E_US07DA Duplicate Object name

1618895626.486972175 commit

Verifydb cannot run on the 24x7 production server because it needs
exclusive access. On the DR server verifydb aborts.

(be sure to upvote enhancement requests here:https://communities.actian.com/s/actian-communities-ideas#0874y000000kCs7AAE
<https://communities.actian.com/s/actian-communities-ideas#0874y000000kCs7AAE> )

verifydb -MREPORT -SDBNAME ctrust -ODBMS_CATALOGS

S_DU04C0_CKING_CATALOGS VERIFYDB: beginning check of DBMS catalogs for database ctrust
Aborting because of error
E_LQ006A The result of a singleton SELECT query or EXECUTE PROCEDURE with
 RESULT ROW clause contains more than one row.

Clearing the problem proved simple:

* select table_owner, varchar( table_name,20) tab, create_date, table_reltid from iitables where table_owner= 'sbradfor'\g
Executing . . .

┌────────────────────────────────┬────────────────────┬─────────────────────────┬────
─────────┐

│table_owner │tab │create_date │table_reltid │

├────────────────────────────────┼────────────────────┼─────────────────────────┼────
─────────┤
│sbradfor │tmp_cur_pricelist │2021_04_20 05:13:31 GMT │ 382408│
│sbradfor │tmp_cur_pricelist │2021_04_20 05:13:46 GMT │ 382414│
└────────────────────────────────┴────────────────────┴─────────────────────────┴────
─────────┘

(2 rows)
continue
* drop table tmp_cur_pricelist;\g
Executing . . .

continue
* commit\g
Executing . . .

continue
* select table_owner, varchar( table_name,20) tab, create_date, table_reltid from iitables where table_owner= 'sbradfor'\g
Executing . . .

┌────────────────────────────────┬────────────────────┬─────────────────────────┬────
─────────┐
│table_owner │tab │create_date │table_reltid │
├────────────────────────────────┼────────────────────┼─────────────────────────┼────
─────────┤
│sbradfor │tmp_cur_pricelist │2021_04_20 05:13:46 GMT │ 382414│
└────────────────────────────────┴────────────────────┴─────────────────────────┴────
─────────┘

(1 row)
continue
* drop table tmp_cur_pricelist;\g
Executing . . .

continue
* commit\g
Executing . . .

continue
* select table_owner, varchar( table_name,20) tab, create_date, table_reltid from iitables where table_owner= 'sbradfor'\g
Executing . . .

┌────────────────────────────────┬────────────────────┬─────────────────────────┬────
─────────┐
│table_owner │tab │create_date │table_reltid │
├────────────────────────────────┼────────────────────┼─────────────────────────┼────
─────────┤ └────────────────────────────────┴────────────────────┴─────────────────────────┴────
─────────┘

(0 rows)
continue
* \q
Your SQL statement(s) have been committed.

In my test case I can generate several duplicated instances. I can alter
the table structure and insert data. HELP TABLE returns an error.

[ingres@ckrs_linux 20210422]$ sql pw123
INGRES TERMINAL MONITOR Copyright 2019 Actian Corporation
Ingres Linux Version II 11.1.0 (a64.lnx/100) login
Tue Apr 27 11:05:56 2021
Enter \g to execute commands, "help help\g" for general help,
"help tm\g" for terminal monitor help, \q to quit

continue
* select varchar(table_name,10), varchar(table_owner,10), count(*)
* from iitables
* group by table_name, table_owner
* having count(*) > 1;\g
Executing . . .

┌──────────┬──────────┬─────────────┐
│col1 │col2 │col3 │ ├──────────┼──────────┼─────────────┤
│pw1 │user4 │ 2│ │pw1 │user9 │ 2│ └──────────┴──────────┴─────────────┘
(2 rows)
continue
* \q
Your SQL statement(s) have been committed.

Ingres Version II 11.1.0 (a64.lnx/100) logout
Tue Apr 27 11:06:10 2021

[ingres@ckrs_linux 20210422]$ sql pw123 -uuser4
INGRES TERMINAL MONITOR Copyright 2019 Actian Corporation
Ingres Linux Version II 11.1.0 (a64.lnx/100) login
Tue Apr 27 11:06:19 2021
Enter \g to execute commands, "help help\g" for general help,
"help tm\g" for terminal monitor help, \q to quit

continue
* help table pw1\g
Executing . . .

Sorry, Error(s) occurred obtaining Help from system catalogs
on object 'pw1'.
You may not have permissions to access this object.

continue
* alter table pw1 add column fred varchar(10)\g
Executing . . .

continue
* commit\g
Executing . . .

continue
* select table_owner, varchar( table_name,20) tab,
varchar(column_name,20) col from iicolumns where table_owner= 'user4'\g Executing . . .

┌────────────────────────────────┬────────────────────┬────────────────────┐
│table_owner │tab │col │
├────────────────────────────────┼────────────────────┼────────────────────┤
│user4 │pw1 │cust_code │
│user4 │pw1 │catlog_code │
│user4 │pw1 │price │
│user4 │pw1 │disc_percent │
│user4 │pw1 │fred │
│user4 │pw1 │cust_code │
│user4 │pw1 │catlog_code │
│user4 │pw1 │price │
│user4 │pw1 │disc_percent │
└────────────────────────────────┴────────────────────┴────────────────────┘
(9 rows)
continue
* continue
* insert into pw1 values ('cust','cat',123.45, 67.89)\g
Executing . . .

E_US0AD7 INSERT: number of target columns must equal the number of
 specified values.
 (Tue Apr 27 11:12:23 2021)

continue
* insert into pw1 values ('cust','cat',123.45, 67.89,'fred')\g
Executing . . .

(1 row)
continue
* select * from pw1\g
Executing . . .

┌─────────┬────────────┬───────────┬────────────┬──────────┐
│cust_code│catlog_code │price │disc_percent│fred │
├─────────┼────────────┼───────────┼────────────┼──────────┤
│SIDWILV0 │OLIVEOILP │ 82.000│ 0.000│ │
│SIDWILV0 │UCO │ 0.000│ 0.000│ │
│SIDWILV0 │XLFRY │ 2.500│ 0.000│ │
│SIDWILV0 │XLFRYBAX15BB│ 37.500│ 0.000│ │
│cust │cat │ 123.450│ 67.890│fred │
└─────────┴────────────┴───────────┴────────────┴──────────┘
(5 rows)
continue
*
* drop table pw1\g
Executing . . .

continue
* select * from pw1\g
Executing . . .

┌─────────┬────────────┬───────────┬────────────┐
│cust_code│catlog_code │price │disc_percent│ ├─────────┼────────────┼───────────┼────────────┤
│SIDWILV0 │OLIVEOILP │ 82.000│ 0.000│ │SIDWILV0 │UCO │ 0.000│ 0.000│ │SIDWILV0 │XLFRY │ 2.500│ 0.000│ │SIDWILV0 │XLFRYBAX15BB│ 37.500│ 0.000│ └─────────┴────────────┴───────────┴────────────┘
(4 rows)
continue

<html>
<head>

<meta http-equiv="content-type" content="text/html; charset=UTF-8">
</head>
<body>
Good morning all. 
<div class="moz-forward-container">
On a busy server, I found a duplicate user table in iirelation
with duplicated records in iiattributes. The two entries have
different reltids.
There is no physical table or index corruption in the system
catalog tables. There have been no unusual events on the 24x7
server and no downtime. I found this: 

<a moz-do-not-send="true" href="https://communities.actian.com/s/article/Why-Are-Duplicate-Rows-Allowed-in-iirelation-with-Ingres-II-10">https://communities.actian.com/s/article/Why-Are-Duplicate-Rows-Allowed-in-iirelation-with-Ingres-II-10</a>
iirelation has a hash index on owner and name but it is not
marked as unique.
How does does Ingres guarantee uniqueness for tables and
columns - clearly it cannot. 

I have a reproducible case lodged with Actian support and will
send an update when there is an outcome. Technical goodies
follow... 

 

I captured the event with SET SERVER TRACE. On this server, I
have trace active all the time, with a script to rotate the log
directory daily and keeping a month archived. There is no
detectable impact on operations. I found this feature valuable
to help track down elusive problems after the fact. It provides
a useful daily summary / exceptions report.
The trace provided clear evidence (down to nanosecond timing)
to show there were two sessions connected with the same
credentials running the same OpenROAD application. It creates a
local user temp table for an enquiry function. The code is
faulty with the transaction running READ UNCOMMITTED and DBMS
error checking is missing for some statements. Where an error
is successfully captured, the ROLLBACK/COMMIT sequence is
faulty. 

The first session is running a batch job like this:
<pre>Check for table in iitables returns 1 row
drop table
create table as select...
commit
</pre>
<pre>a few seconds later

Check for table in iitables returns 0 rows
create table as select...
US07DA Duplicate object name '%0c'.
commit
</pre>
<pre>a few minutes later

Check for table in iitables returns 2 rows
drop table
create table as select...
US07DA Duplicate object name '%0c'.
commit

This last sequence repeats until the end of the job. The code can run with the duplicate tables.

</pre>
The second session: 
</div>
<div class="moz-forward-container">
<pre><pre>Check for table in iitables returns 1 row
drop table
create table as select...
E_US13EE Duplicate table name
rollback</pre>

</pre>
</div>
<div class="moz-forward-container">Ingres version is: 
Version:
II 11.1.0 (a64.lnx/100) + P15546
 

Duplicate table is here: 

* select
table_owner, varchar( table_name,20) tab, create_date,
table_reltid from iitables where table_owner= 'sbradfor'\g 
Executing . . . 
 
 ┌────────────────────────────────┬────────────────────┬─────────────────────────┬────
─────────┐ 
│table_owner │tab
│create_date │table_reltid │ ├────────────────────────────────┼────────────────────┼─────────────────────────┼────
─────────┤ 
│sbradfor │tmp_cur_pricelist
│2021_04_20 05:13:31 GMT │ 382408│ 
│sbradfor │tmp_cur_pricelist
│2021_04_20 05:13:46 GMT │ 382414│ └────────────────────────────────┴────────────────────┴─────────────────────────┴────
─────────┘ 
(2 rows) 

* select
table_owner, varchar( table_name,20) tab,
varchar(column_name,20) col from iicolumns where table_owner=
'sbradfor' order by column_name\g 
Executing . . . 
 
 ┌────────────────────────────────┬────────────────────┬────────────────────┐ 
│table_owner │tab
│col │ ├────────────────────────────────┼────────────────────┼────────────────────┤ 
│sbradfor │tmp_cur_pricelist
│catlog_code │ 
│sbradfor │tmp_cur_pricelist
│catlog_code │ 
│sbradfor │tmp_cur_pricelist
│cust_code │ 
│sbradfor │tmp_cur_pricelist
│cust_code │ 
│sbradfor │tmp_cur_pricelist
│disc_percent │ 
│sbradfor │tmp_cur_pricelist
│disc_percent │ 
│sbradfor │tmp_cur_pricelist
│price │ 
│sbradfor │tmp_cur_pricelist
│price │ └────────────────────────────────┴────────────────────┴────────────────────┘ 
(8 rows) 
continue
 
I used rollforwarddb on the replica server to track down the
exact timing of the event, and correlate it with the SERVER
TRACE logs
The SESSION
BEGINS show user sbradfor is in two DB sessions running
simultaneously from different client PCs. At this site, the user
name is hard coded in the vnodes. 

 
 Session 1
08:29:30 - 16:15:21
 Session 2
08:25:50 - 15:56:22
 
 
 Here is an
example of overlapping events:
 
 Note that
1618895626 = 15:13:46
 
 qtrace_ctrust_168856_7f570eae5100.log
 1618895626.089771974
check iitables, one row is returned, 
 1618895626.094464779
drop table, 
 1618895626.139567455
create table gives E_US13EE Duplicate table name
 1618895626.549601019
rollback
 
 qtrace_ctrust_168856_7f570f808440.log
 1618895626.125806952
check iitables, zero rows returned
 1618895626.129856430
create table gives E_US07DA Duplicate Object name
1618895626.486972175
commit</div>
<div class="moz-forward-container"> 

Verifydb cannot run on the 24x7 production server because it
needs exclusive access. On the DR server verifydb aborts.
(be sure to upvote enhancement requests here:<a
title="verifydb" moz-do-not-send="true" href="https://communities.actian.com/s/actian-communities-ideas#0874y000000kCs7AAE">
https://communities.actian.com/s/actian-communities-ideas#0874y000000kCs7AAE</a>
) 

<pre>verifydb -MREPORT -SDBNAME ctrust -ODBMS_CATALOGS</pre>
<pre>S_DU04C0_CKING_CATALOGS VERIFYDB: beginning check of DBMS catalogs for database ctrust
Aborting because of error
E_LQ006A The result of a singleton SELECT query or EXECUTE PROCEDURE with RESULT ROW clause contains more than one row.

</pre>
 

Clearing the problem proved simple:
<pre>* select table_owner, varchar( table_name,20) tab, create_date, table_reltid from iitables where table_owner= 'sbradfor'\g
Executing . . .

┌────────────────────────────────┬────────────────────┬─────────────────────────┬────
─────────┐

│table_owner │tab │create_date │table_reltid │

[continued in next message]

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Who's Online
Recent Visitors
- Jasonrx8
  Wed Apr 17 13:08:27 2024
  from Sydney Nsw via SSH
- Bob Worm
  Thu Apr 18 21:44:01 2024
  from Wales, Uk via Telnet
- Bob Worm
  Thu Apr 18 13:24:26 2024
  from Wales, Uk via Telnet
- Chippey
  Fri Apr 19 02:45:49 2024
  from Winnipeg, Canada via Telnet

System Info

Sysop:	Keyop
Location:	Huddersfield, West Yorkshire, UK
Users:	293
Nodes:	16 (2 / 14)
Uptime:	212:08:28
Calls:	6,619
Calls today:	1
Files:	12,168
Messages:	5,317,365

[Info-ingres] duplicate entries in iirelation (1/2)

Who's Online

Recent Visitors

System Info