Sybase NNTP forums - End Of Life (EOL)

The NNTP forums from Sybase - forums.sybase.com - are now closed.

All new questions should be directed to the appropriate forum at the SAP Community Network (SCN).

Individual products have links to the respective forums on SCN, or you can go to SCN and search for your product in the search box (upper right corner) to find your specific developer center.

Create indexes taking long time and slow DB response

7 posts in General Discussion Last posting was on 2010-03-17 22:59:29.0Z
Yog Posted on 2010-02-28 04:43:51.0Z
Sender: 3ab3.4b89f361.1804289383@sybase.com
From: Yog
Newsgroups: sybase.public.ase.general
Subject: Create indexes taking long time and slow DB response
X-Mailer: WebNews to Mail Gateway v1.1t
Message-ID: <4b89f487.3aee.1681692777@sybase.com>
NNTP-Posting-Host: 10.22.241.41
X-Original-NNTP-Posting-Host: 10.22.241.41
Date: 27 Feb 2010 20:43:51 -0800
X-Trace: forums-1-dub 1267332231 10.22.241.41 (27 Feb 2010 20:43:51 -0800)
X-Original-Trace: 27 Feb 2010 20:43:51 -0800, 10.22.241.41
Lines: 21
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29005
Article PK: 78243

I am running
1. sp_rename on few table with approximately 40 million
records (to replace them with a smaller subset 20 million)
2. after rename, recompiled the procedures, triggers and
views
3. The index in the old table still remains
4. Creating new indexes on the smaller subset of table

e.g. table, table_new
1. sp_rename table, table_old
2. sp_rename table_new, table
3. recompile procs, views, triggers
4. create new indexes on table.

Being a developer and not a DBA, I couldn't find out why the
DB is getting slow. (very slow). And the indexes are running
more hours than it usually does.

Any help on why this happens ?

Yog


Yog Posted on 2010-02-28 04:44:58.0Z
Sender: 3ab3.4b89f361.1804289383@sybase.com
From: Yog
Newsgroups: sybase.public.ase.general
Subject: Re: Create indexes taking long time and slow DB response
X-Mailer: WebNews to Mail Gateway v1.1t
Message-ID: <4b89f4ca.3afb.1681692777@sybase.com>
References: <4b89f487.3aee.1681692777@sybase.com>
NNTP-Posting-Host: 10.22.241.41
X-Original-NNTP-Posting-Host: 10.22.241.41
Date: 27 Feb 2010 20:44:58 -0800
X-Trace: forums-1-dub 1267332298 10.22.241.41 (27 Feb 2010 20:44:58 -0800)
X-Original-Trace: 27 Feb 2010 20:44:58 -0800, 10.22.241.41
Lines: 2
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29006
Article PK: 78244

I checked the sybase log, it doesn't has anything. The only
thing I noticed is DBA adding more disk space.


"Mark A. Parsons" <iron_horse Posted on 2010-02-28 18:34:54.0Z
From: "Mark A. Parsons" <iron_horse@no_spamola.compuserve.com>
User-Agent: Thunderbird 1.5.0.10 (Windows/20070221)
MIME-Version: 1.0
Newsgroups: sybase.public.ase.general
Subject: Re: Create indexes taking long time and slow DB response
References: <4b89f487.3aee.1681692777@sybase.com>
In-Reply-To: <4b89f487.3aee.1681692777@sybase.com>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit
X-Antivirus: avast! (VPS 100227-0, 02/27/2010), Outbound message
X-Antivirus-Status: Clean
NNTP-Posting-Host: vip152.sybase.com
X-Original-NNTP-Posting-Host: vip152.sybase.com
Message-ID: <4b8ab74e@forums-1-dub>
Date: 28 Feb 2010 10:34:54 -0800
X-Trace: forums-1-dub 1267382094 10.22.241.152 (28 Feb 2010 10:34:54 -0800)
X-Original-Trace: 28 Feb 2010 10:34:54 -0800, vip152.sybase.com
Lines: 77
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29009
Article PK: 78246

It's not clear from your post if the dataserver is slow for other operations besides creating your index so fwiw ...

------------------

How long does/did it take to create your index on the 40 million row table?

How long does/did it take to create your index on the 20 million row table?

Assuming you're running with a minimum ASE version of 12.5.0.3, and MDA tables are installed/configured, run the
following when creating your index:

NOTE: Run the following within a single isql session.

===========================
select convert(varchar,getdate(),109)

select pw.*,wei.Description
from master..monProcessWaits pw,
master..monWaitEventInfo wei
where SPID = @@spid
and pw.WaitEventID = wei.WaitEventID
go

set statistics io on
go

create index ....
go

set statistics io off
go

select convert(varchar,getdate(),109)

select pw.*,wei.Description
from master..monProcessWaits pw,
master..monWaitEventInfo wei
where SPID = @@spid
and pw.WaitEventID = wei.WaitEventID
go
===========================

Then post the results back here to the newsgroup. Please also post the complete 'create index' command.

The objective is to use the monProcessWaits data to see where the 'create index' is spending most of it's wait time.

-------------------

If other processes (besides 'create index') are running slow on your dataserver, there could be any number of issues at
to consider ... slow(er) disks, heavier work load, poorly configured dataserver or caches, poorly (re)designed
application code and queries, etc.

Yog wrote:
> I am running
> 1. sp_rename on few table with approximately 40 million
> records (to replace them with a smaller subset 20 million)
> 2. after rename, recompiled the procedures, triggers and
> views
> 3. The index in the old table still remains
> 4. Creating new indexes on the smaller subset of table
>
> e.g. table, table_new
> 1. sp_rename table, table_old
> 2. sp_rename table_new, table
> 3. recompile procs, views, triggers
> 4. create new indexes on table.
>
> Being a developer and not a DBA, I couldn't find out why the
> DB is getting slow. (very slow). And the indexes are running
> more hours than it usually does.
>
> Any help on why this happens ?
>
> Yog


Yog Posted on 2010-03-01 17:45:55.0Z
Sender: 1f93.4b8bfaac.1804289383@sybase.com
From: Yog
Newsgroups: sybase.public.ase.general
Subject: Re: Create indexes taking long time and slow DB response
X-Mailer: WebNews to Mail Gateway v1.1t
Message-ID: <4b8bfd53.1fd8.1681692777@sybase.com>
References: <4b8ab74e@forums-1-dub>
NNTP-Posting-Host: 10.22.241.41
X-Original-NNTP-Posting-Host: 10.22.241.41
Date: 1 Mar 2010 09:45:55 -0800
X-Trace: forums-1-dub 1267465555 10.22.241.41 (1 Mar 2010 09:45:55 -0800)
X-Original-Trace: 1 Mar 2010 09:45:55 -0800, 10.22.241.41
Lines: 75
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29011
Article PK: 78249

How long does/did it take to create your index on the 40
million row table?
usually in other environments (non prod) it took 4-6 hrs. In
prod, it took about 12-14 hrs.


How long does/did it take to create your index on the 20
million row table?
In non-prod 2-4 hrs, in prod 8-10 hrs

Actually the index creation completed early morning
tommorow, so I wouldn't be able to reproduce the data,
another batch job is running (heavy sql), I am posting the
time for this batch job now.

997 253493925 29 9 0 wait for buffer read to complete
997 253493925 171 98 300 waiting for CTLIB event to complete
997 253493925 250 24 11100 waiting for incoming network data


Actually, CREATE CLUSTERED INDEX , followed by a
NONCLUSTERED was the only script running yesterday (when we
experienced the slowness). I shut down all other online apps
when I ran this.

Below is the index script for 40 m table.

[code]
#!/bin/sh
umask 077
cat <<-endOfCat | isql -U$USERID -S$DSQUERY -P$PASSWORD
use $DATABASE
go
select 'start'
GO
CREATE CLUSTERED INDEX CMCX_CDML_CLUSTER
ON CMC_CDML_CL_LINE
(
MEME_CK,
CDML_FROM_DT
)
ON "default"
go
exec sp_primarykey CMC_CDML_CL_LINE,
CLCL_ID,
CDML_SEQ_NO
go
CREATE UNIQUE INDEX CMCX_CDML_PRIMARY
ON CMC_CDML_CL_LINE
(
CLCL_ID,
CDML_SEQ_NO
)
ON "default"
go
CREATE INDEX CMCX_CDML_PRPR_ID
ON CMC_CDML_CL_LINE
(
PRPR_ID
)
ON "default"
go
CREATE INDEX CMCX_CDML_UMAUTH_ID
ON CMC_CDML_CL_LINE
(
CDML_UMAUTH_ID
)
ON "default"
go
select 'end'
go
endOfCat

[/code]


Yog Posted on 2010-03-02 04:20:43.0Z
Sender: 2d7b.4b8c91c3.1804289383@sybase.com
From: Yog
Newsgroups: sybase.public.ase.general
Subject: Re: Create indexes taking long time and slow DB response
X-Mailer: WebNews to Mail Gateway v1.1t
Message-ID: <4b8c921b.2d8a.1681692777@sybase.com>
References: <4b8bfd53.1fd8.1681692777@sybase.com>
NNTP-Posting-Host: 10.22.241.41
X-Original-NNTP-Posting-Host: 10.22.241.41
Date: 1 Mar 2010 20:20:43 -0800
X-Trace: forums-1-dub 1267503643 10.22.241.41 (1 Mar 2010 20:20:43 -0800)
X-Original-Trace: 1 Mar 2010 20:20:43 -0800, 10.22.241.41
Lines: 8
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29012
Article PK: 78250

Hi Mark,

Sorry please ignore the data from my previous post.

I will try to post the data when I am able to reproduce
something similar.

Yog


Yog Posted on 2010-03-17 19:57:48.0Z
Sender: 69a6.4ba117e2.1804289383@sybase.com
From: Yog
Newsgroups: sybase.public.ase.general
Subject: Re: Create indexes taking long time and slow DB response
X-Mailer: WebNews to Mail Gateway v1.1t
Message-ID: <4ba1343c.6f76.1681692777@sybase.com>
References: <4b8c921b.2d8a.1681692777@sybase.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="-=_forums-1-dub4ba1343c"
NNTP-Posting-Host: 10.22.241.41
X-Original-NNTP-Posting-Host: 10.22.241.41
Date: 17 Mar 2010 11:57:48 -0800
X-Trace: forums-1-dub 1268855868 10.22.241.41 (17 Mar 2010 11:57:48 -0800)
X-Original-Trace: 17 Mar 2010 11:57:48 -0800, 10.22.241.41
Lines: 132
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29050
Article PK: 78288

Please find the data attached,

Yog

1 The command completed with no results returned


1 Mar 9 2010 5:38:28:266PM

SPID KPID WaitEventID Waits WaitTime Description
1 163 435355903 171 19 0 waiting for CTLIB event to complete
2 163 435355903 214 1 0 waiting on run queue after yield
3 163 435355903 250 17 300 waiting for incoming network data
4 163 435355903 251 14 0 waiting for network send to complete


1 Total actual I/O cost for this command: 0.
2 Total writes for this command: 0
3 Total actual I/O cost for this command: 0.
4 Total writes for this command: 1745038
5 Number (832) Severity (20) State (1) Server (sybtest) Unable to place buffer 0xd5fc22e0 holding logical page 0 in sdes for object 'CMC_CDML_CL_LINE' - there is no room in sdes aux keep pool.
6 Total actual I/O cost for this command: 0.
7 Total writes for this command: 0
8 Total actual I/O cost for this command: 0.
9 Total writes for this command: 0
10 Total actual I/O cost for this command: 0.
11 Total writes for this command: 0
12 Total actual I/O cost for this command: 0.
13 Total writes for this command: 0
14 Table: sysobjects scan count 1, logical reads: (regular=2 apf=0 total=2), physical reads: (regular=0 apf=0 total=0), apf IOs used=0
15 Total actual I/O cost for this command: 4.
16 Total writes for this command: 0
17 Table: sysobjects scan count 1, logical reads: (regular=2 apf=0 total=2), physical reads: (regular=0 apf=0 total=0), apf IOs used=0
18 Total actual I/O cost for this command: 4.
19 Total writes for this command: 0
20 Total actual I/O cost for this command: 0.
21 Total writes for this command: 0
22 Table: syskeys scan count 1, logical reads: (regular=2 apf=0 total=2), physical reads: (regular=0 apf=0 total=0), apf IOs used=0
23 Total actual I/O cost for this command: 4.
24 Total writes for this command: 0
25 Total actual I/O cost for this command: 0.
26 Total writes for this command: 0
27 Total actual I/O cost for this command: 0.
28 Total writes for this command: 0
29 Number (17741) Severity (16) State (1) Server (sybtest) Procedure (sp_primarykey) Primary key already exists on table -- drop key first.
30 Total actual I/O cost for this command: 0.
31 Total writes for this command: 220658
32 Your query is blocked because it tried to write and database 'fatestar' is in quiesce state. Your query will proceed after the DBA performs QUIESCE DATABASE RELEASE.
33 Total actual I/O cost for this command: 0.
34 Total writes for this command: 49065
35 Total actual I/O cost for this command: 0.
36 Total writes for this command: 42689
37 The command completed with no results returned


1 Mar 9 2010 11:00:23:166PM

SPID KPID WaitEventID Waits WaitTime Description
1 163 435355903 29 2080 700 wait for buffer read to complete
2 163 435355903 31 16 0 wait for buffer write to complete
3 163 435355903 36 15 400 wait for mass to stop changing
4 163 435355903 51 3716 300 waiting for disk write to complete
5 163 435355903 52 6 1500 waiting for disk write to complete
6 163 435355903 54 1 0 waiting for disk write to complete
7 163 435355903 55 7 0 waiting for disk write to complete
8 163 435355903 124 14 0 wait for someone else to finish reading in mass
9 163 435355903 150 1 208300 waiting for semaphore
10 163 435355903 169 3 5000 wait for message
11 163 435355903 171 87 0 waiting for CTLIB event to complete
12 163 435355903 214 605 100 waiting on run queue after yield
13 163 435355903 250 26 600 waiting for incoming network data
14 163 435355903 251 28 0 waiting for network send to complete
15 163 435355903 266 25 16421400 waiting for message in worker thread mailbox


1 Mar 9 2010 11:00:23:220PM


"Mark A. Parsons" <iron_horse Posted on 2010-03-17 22:59:29.0Z
From: "Mark A. Parsons" <iron_horse@no_spamola.compuserve.com>
User-Agent: Thunderbird 1.5.0.10 (Windows/20070221)
MIME-Version: 1.0
Newsgroups: sybase.public.ase.general
Subject: Re: Create indexes taking long time and slow DB response
References: <4b8c921b.2d8a.1681692777@sybase.com> <4ba1343c.6f76.1681692777@sybase.com>
In-Reply-To: <4ba1343c.6f76.1681692777@sybase.com>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit
X-Antivirus: avast! (VPS 100313-1, 03/13/2010), Outbound message
X-Antivirus-Status: Clean
NNTP-Posting-Host: vip152.sybase.com
X-Original-NNTP-Posting-Host: vip152.sybase.com
Message-ID: <4ba15ed1$1@forums-1-dub>
Date: 17 Mar 2010 14:59:29 -0800
X-Trace: forums-1-dub 1268866769 10.22.241.152 (17 Mar 2010 14:59:29 -0800)
X-Original-Trace: 17 Mar 2010 14:59:29 -0800, vip152.sybase.com
Lines: 91
Path: forums-1-dub!not-for-mail
Xref: forums-1-dub sybase.public.ase.general:29051
Article PK: 78289

You haven't told us what commands you were running during this test so I'll have to make some assumptions ...

... snip ...

> 5 Number (832) Severity (20) State (1) Server (sybtest) Unable to place buffer 0xd5fc22e0 holding logical page 0 in sdes for object 'CMC_CDML_CL_LINE' - there is no room in sdes aux keep pool.

The 832 error could be due to a shortage of sort buffers during the command you were running. [Did the associated
command fail?]

The DBA may want to bump up the number of sort buffers to see if this eliminates the 832 error.

If there's a stack trace in the dataserver's errorlog due to this 832 error, the DBA may want to consider opening a case
with Sybase TechSupport to see if there are any known issues with your ASE version and the 832 error.

... snip ...

> 29 Number (17741) Severity (16) State (1) Server (sybtest) Procedure (sp_primarykey) Primary key already exists on table -- drop key first.

Self-explanatory ... someone tried adding a primary key to a table, but the primary key already exists.

> 32 Your query is blocked because it tried to write and database 'fatestar' is in quiesce state. Your query will proceed after the DBA performs QUIESCE DATABASE RELEASE.

Again, self-explanatory ... the DBA put the fatestar database into a quiesced state, which in turn blocks all (write)
activity in the database until the database has been released from a quiesced state.

You'll need to coordinate your database activity with the DBA, eg, make sure your activity is performed outside of the
period in which the DBA has the database in a quiesced state.

As for why the DBA put the database into a quiesced state? *shrug* You'll have to ask your DBA what s/he was doing at
the time

... snip ...

> SPID KPID WaitEventID Waits WaitTime Description
> 15 163 435355903 266 25 16421400 waiting for message in worker thread mailbox

OK, so the majority of your 5 hrs 22 min run time was spent on WaitEventID = 266.

Unfortunately the ASE manuals are next to useless in explaining what 266 is and how/when it occurs.

The fact that there are only 25 Waits but (approx) 4.5 hrs of WaitTime would tend to indicate either a bug with the
dataserver or (more likely) some form of extended blocking (eg, database was in a quiesced state??). My off-the-cuff
guess would be that you were running a query/command that relied on parallel worker threads when the database was put
into a quiesced state. Your query/command was blocked at the point where a 266 would occur, thus leading to an extended
wait for the 266 to complete.

--------------------------

My original test suggestion assumed a single command (create index) was to be run.

From your output it would appear that you ran several commands. While there's nothing wrong with running multiple
commands in your test, the problem we run into in this case is that we only have one set of monitoring numbers
(time/duration, waitevents) to cover all of your commands; in other words, there aren't enough details to know precisely
which commands took the longest to run.

Total runtime was 5 hrs 22 mins, while the wait events total up to (approx) 4 hrs 40 mins. We're missing 42 mins;
granted, some of that 42 minutes would have been spent on cpu cycles (ie, not counted as a wait event), but it seems a
little odd that your queries/commands would have accumulated close to 42 minutes of cpu time (ie, not counted as a wait
event).

I'm wondering if there's some records missing from your monWaitEventInfo which would have caused some monProcessWaits
details to be excluded from the equi-join ... hmmm ...

--------------------------

I'd suggest you work with your DBA to address the 832 error (possible shortage of sort buffers; dataserver bug?) and the
blocking due to the database being placed into a quiesced state. If, after addressing these two issues, you're still
having performance issues, consider modifying your test harness as follows ...

[Note the outer join between monProcessWaits and monWaitEventInfo]

===========================
-- run the following block of SQL at the beginning of your test
-- and after *each* command/query you run in your test

select pw.*,wei.Description
from master..monProcessWaits pw,
master..monWaitEventInfo wei
where SPID = @@spid
and pw.WaitEventID *= wei.WaitEventID

select *
from master..monProcessActivity
where SPID = @@spid

select convert(varchar,getdate(),109)
go
===========================

Please also supply the complete text of all commands/queries in your test so that we can match command/queries with the
various sets of monitoring stats.