cancel
Showing results for 
Search instead for 
Did you mean: 

Stored procedure waiting too long to start executing

0 Kudos

Hi,

We have recently migrated from ASE 15.0.3 to ASE 15.7 SP132 on Solaris 10 platform.

A 343 line stored procedure was modified to print a timestamp value at the start of the execution along with one other very minor change.

In an ISQL session with 'set flushmessage on', when this stored procedure is executed, the above timestamp value shows up after 14 minutes!

While monitoring this session with AseTune, I was expecting to see some activity in tempdb right away as it uses temporary tables extensively. Instead, I saw that the stored procedure was waiting to be scheduled.

We had a similar situation a few months back where a stored procedure called from a PERL script was taking too long to start executing. Since we were executing the stored procedure with the 'recompile' clause, Sybase Tech Support advised us to remove this clause and the problem went away. In that instance, the first display statement in the stored procedure showed up in the log after 49 minutes!

It looks like the server is mis-configured/under-configured.

Any help will be highly appreciated.

Thanks in advance,

Anil

0 Kudos

Mark,

Thanks for the response.

Since it happened in the evening when other stored procedures were running and using tempdb resources, I will try to reproduce it this evening by first dropping and recreating that stored procedure and then calling it in the batch script as you suggested. Also, I will try to monitor the session using AseTune to see if I can capture any other useful information.

Thanks,

Anil

former_member188958
Active Contributor
0 Kudos

Is this delay seen if the procedure is executed a second time fairly soon?

As it sounds like it was a constant problem when "with recompile" was on, I'm wondering if a good deal of the time might be in compiling the procedures query plan - which wouldn't have to be done on a second execution unless the plan subsequently aged out of procedure cache.

Does the proc contain any obviously complicated queries (lots of joins in any query)?

Executing dbcc stacktrace on the spid a few times while it is in this state may provide insight on what it is doing.  

set switch on 3604

go

dbcc stacktrace(<spid>)

go

-bret

0 Kudos

Bret,

I wonder if you had a chance to look at the outputs that I attached from my test run with the information you requested.

Thanks,

Anil

Accepted Solutions (0)

Answers (2)

Answers (2)

0 Kudos

Mark,

I repeated Friday's experiment with the session level optimizer goal set to 'allrows_oltp'. The stored procedure compiled and finished execution in 13s.

Also, I ensured that the stored procedure was recompiled by running 'sp_recompile' on a table that is used exclusively by this stored procedure.

Anil

0 Kudos

Mark/Bret,

Bret: Your assumption is correct. The second and subsequent runs execute extremely quickly because the plan is in cache.

Also, the stored procedure has a number of complex joins along with temporary table usage resulting in long compilation times and deferred compilation scenarios.

Mark & Bret: As per your suggestions, I created 2 ISQL sessions; one to run Mark's query and the other to run Bret's stacktrace every 10 seconds on the 1st SPID. I repeated this twice in quick succession. The first one took 24 minutes to run. The second one took under 1 second!

The ASE is running a 'threaded kernel' model. Is there something I can configure at the server level to alter/control this behavior?

Thanks,

Anil

PS: The outputs are attached to this post.