Mailing-List: contact derby-user-help@db.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Derby Discussion" <derby-user@db.apache.org>
Received-SPF: pass (herse.apache.org: domain of igor.minar@gmail.com
 designates 66.249.92.171 as permitted sender)
DomainKey-Signature: a=rsa-sha1; c=nofws;
        d=gmail.com; s=beta;
        h=received:in-reply-to:references:mime-version:content-type:message-id:content-transfer-encoding:subject:date:to:x-mailer:from;
        b=AqOr9yCQdSeFhOcAtV2oYU41Al2WkLWeY4++Hq7lVwssxQ0EEYzpMOQ/6oRitX9yefIZ3Hujl/85rRKjcVbQgPrOsxey3ZZV5VwAMRh5G3rB3mS0NJYE+0/CWyFIrPdp2OJNOCjF/vnqzMPEg5B34cWwmgHHNpl+mPNZy6wuX14=
In-Reply-To: 
 <374710983-1171757437-cardhu_blackberry.rim.net-24894-@engine03-cell05>
References: <2544B48B-B633-4B79-8C41-C43C17862364@gmail.com>
 <374710983-1171757437-cardhu_blackberry.rim.net-24894-@engine03-cell05>
Mime-Version: 1.0 (Apple Message framework v752.3)
Content-Type: text/plain; charset=US-ASCII; delsp=yes; format=flowed
Message-Id: <8095FFD6-884E-4BC9-9DD1-9CE1E8EA0D62@gmail.com>
Content-Transfer-Encoding: 7bit
Subject: Re: Multiple transactions and unexpected permanent row lock in
 SYSCOLUMNS table
Date: Sun, 18 Feb 2007 01:19:07 +0100
To: Derby Discussion <derby-user@db.apache.org>
From: Igor Minar <igor.minar@gmail.com>


On Feb 18, 2007, at 1:10 AM, Michael Segel wrote:

> Making a big assumption...
>
> If each thread has its own connection, you will be blocked on your  
> identity column.

Yes, each thread has its own connection retrieved from  
ClientConnectionPoolDataSource

> But you shouldn't be blocked longer than it takes to get the  
> identity value.

That's what I'm expecting as well, but it doesn't seem to be the case.

> 100 threads w n records per transaction?

Number of records per transaction is configurable. I was testing the  
app with 500-800 records per commit.

> How much memory have you allocated to your app?

-Xms10m -Xmx200m

but I hardly ever need more than 16MB

> And is the app on the same machine as derby? Same jvm?

same machine, using networked mode = different JVM

cheers,
i

>
> Hth
> Sent via BlackBerry.
>
> -Mike Segel
> Principal
> MSCC
> 312 952 8175
>
>
> -----Original Message-----
> From: Igor Minar <iiminar@gmail.com>
> Date: Sun, 18 Feb 2007 00:34:06
> To:derby-user@db.apache.org
> Subject: Multiple transactions and unexpected permanent row lock in  
> SYSCOLUMNS table
>
> Hi!
>
> After hours and hours of debugging I'm still seeing something that I
> can't explain. Can anyone help please?
>
> I have multiple threads (10-100 threads) simultaneously inserting
> records into table A. Each thread has its own transaction and commits
> only when all the records allocated for this thread are inserted. DB
> isolation level is the default.
>
> CREATE TABLE A (
>      id                  bigint NOT NULL GENERATED ALWAYS AS IDENTITY
> (START WITH 1, INCREMENT BY 1),
>     extra_col	 bigint NOT NULL,
>     CONSTRAINT pk_records PRIMARY KEY(id)
> );
>
> INSERT INTO A(extra_col) VALUES (?);
>
>
> Everything is fine until one of the threads inserts 2nd-5th record in
> its transaction (this number varies) as the first thread out of all
> of the threads running.
>
> By doing that, for some to me unknown reason it acquires some
> "special" lock on and blocks all the other threads that try to insert
> into this table.
>
>  From there on the app continues as a single threaded because all the
> other threads are blocked. If the thread manages to finish importing
> all the records into db before the time out for the blocked threads,
> one of the blocked threads acquires this "special" lock  and this
> continues until all the threads are finished. If the blocked threads
> time out, an exception is thrown:
>
> ERROR 40XL2: A lock could not be obtained within the time requested.
> The lockTable dump is:
> XID       |TYPE         |MODE|LOCKCOUNT|
> LOCKNAME
>          |STATE|TABLETYPE / LOCKOBJ                   |INDEXNAME /
> CONTAINER_ID / (MODE for LATCH only)  |TABLENAME /
> CONGLOM_ID                |
> ---------------------------------------------------------------------- 
> --
> ---------------------------------------------------------------------- 
> --
> ---------------------------------------------------------------------- 
> --
> ----------------------------------------
> *** The following row is the victim ***
> 8666203   |ROW          |X   |0        |
> (5,639)
>          |WAIT |S                                     |
> NULL                                              |
> SYSCOLUMNS                            |
> *** The above row is the victim ***
> 8666254   |ROW          |X   |144      |
> (5,639)
>          |GRANT|S                                     |
> NULL                                              |
> SYSCOLUMNS                            |
> 8666246   |ROW          |X   |0        |
> (5,639)
>          |WAIT |S                                     |
> NULL                                              |
> SYSCOLUMNS                            |
> 8666254   |ROW          |X   |1        |
> (4757,10)
>          |GRANT|T                                     |
> NULL                                              |
> RECORDS                               |
> 8666254   |ROW          |X   |1        |
> (4755,13)
>          |GRANT|T                                     |
> NULL                                              |
> RECORDS                               |
> 8666254   |ROW          |X   |1        |
> (4757,11)
>          |GRANT|T                                     |
> NULL                                              |
> RECORDS                               |
> 8666254   |ROW          |X   |1        |
> (4755,14)
>          |GRANT|T                                     |
> NULL                                              |RECORDS
>
>
>
> So it seems that the running thread is blocking all the other threads
> on table SYSCOLUMNS.  I suppose that this is because of the A.id
> column that is generated from SYSCOLUMNS table, however what is the
> reason for this row to be permanently locked by this thread?
>
> This is what the output from my log looks like:
>
> timestamp | threadname  | log
> 1171751801235 Thread-2 - saved record 3
> 1171751801236 Thread-5 - saved record 4
> 1171751801238 Thread-6 - saved record 5
> 1171751801240 Thread-4 - saved record 2
> 1171751801240 Thread-7 - saved record 6
> 1171751801241 Thread-8 - saved record 7
> 1171751801243 Thread-9 - saved record 8
> 1171751801244 Thread-10 - saved record 9
> 1171751801245 Thread-11 - saved record 10
> 1171751801247 Thread-3 - saved record 1
> 1171751802244 Thread-2 - saved record 11
> 1171751802255 Thread-5 - saved record 12
> 1171751802257 Thread-6 - saved record 13
> 1171751802258 Thread-4 - saved record 14
> 1171751802260 Thread-7 - saved record 15
> 1171751802266 Thread-8 - saved record 16
> 1171751802266 Thread-9 - saved record 17
> 1171751802267 Thread-10 - saved record 18
> 1171751802267 Thread-11 - saved record 19
> 1171751802268 Thread-3 - saved record 20
> 1171751803246 Thread-2 - saved record 21
> 1171751803257 Thread-5 - saved record 22
> 1171751803261 Thread-6 - saved record 23
> 1171751803262 Thread-4 - saved record 24
> 1171751803263 Thread-7 - saved record 25
> 1171751804265 Thread-7 - saved record 35
> 1171751805267 Thread-7 - saved record 36
> 1171751806269 Thread-7 - saved record 37
> 1171751807272 Thread-7 - saved record 38
> 1171751808273 Thread-7 - saved record 39
> ...
> ...
> 1171751827315 Thread-7 - saved record 138
> 1171751828316 Thread-7 - saved record 139
> ...
> ...
>
> Thread7 locked the relevant SYSCOLUMNS row and doesn't let any other
> thread acquire lock on that row.
>
>
> If I don't run all inserts within a thread as one transaction and
> leave autocommit on, I see this:
> 1171754035170 Thread-3 - saved record 2
> 1171754035172 Thread-6 - saved record 5
> 1171754035172 Thread-2 - saved record 1
> 1171754035173 Thread-4 - saved record 3
> 1171754035173 Thread-5 - saved record 4
> 1171754035175 Thread-9 - saved record 8
> 1171754035177 Thread-8 - saved record 7
> 1171754035177 Thread-11 - saved record 10
> 1171754035179 Thread-10 - saved record 9
> 1171754035180 Thread-7 - saved record 6
> 1171754036238 Thread-3 - saved record 11
> 1171754036319 Thread-4 - saved record 12
> 1171754036321 Thread-6 - saved record 14
> 1171754036322 Thread-5 - saved record 13
> 1171754036326 Thread-8 - saved record 15
> 1171754036327 Thread-11 - saved record 16
> 1171754036327 Thread-9 - saved record 17
> 1171754036328 Thread-7 - saved record 18
> 1171754036328 Thread-10 - saved record 19
> 1171754036329 Thread-2 - saved record 20
> 1171754037241 Thread-3 - saved record 21
> 1171754037322 Thread-4 - saved record 22
> 1171754037324 Thread-6 - saved record 23
> 1171754037325 Thread-5 - saved record 24
> 1171754037329 Thread-8 - saved record 25
> 1171754037331 Thread-9 - saved record 27
> 1171754037331 Thread-11 - saved record 26
> 1171754037331 Thread-7 - saved record 28
> 1171754037333 Thread-2 - saved record 30
> ...
> ...
>
> Threads are equally competing for privilege to insert record into db
> and none of them is dominant.
> This is exactly what I'd like to see with the autocommit set to off.
> Am I missing something? Is there a way how to achieve that?
>
> Thanks for help.
>
> Igor
>
> derby:  v10.2.2.0
> OS: MacOS Intel
> java version "1.6.0-dp"
> Java(TM) SE Runtime Environment (build 1.6.0-dp-b88-34)
> Java HotSpot(TM) Client VM (build 1.6.0-b88-17-release, mixed mode,
> sharing)
>
>
>