Shockingly slow form realisation

Posted by jmls on 24-Jan-2009 10:02

I've got a form that is taking upwards of 10s to initialise and display on the screen. I have put some "rough" diagnostics in, and the time is taken up by the initialize component call (5.5 seconds) and a data bound grid initialisation (5 seconds).

This, obviously, is not acceptable to my users.

The form in question has 5 ultragrid editors and a user-inherited infragistics data combo.

On my development machine, the time to realise the form is about 2 seconds (not ideal, but manageable).

The target machine is a quad processor dual-core dell 2950 with 4gb ram, running windows 2003 server (cpu% is 1%)

The development machine is a quad-core intel with 4 gb ram, running vista.

One wrinkle may be that I am running the development machine with OEA, but the target machine is a pure application machine (application runtime only, no development)

Where can I begin to try and identify why these machines are running soooo differently ?

The login screen of the application creates a default, hidden form, so I would assume that the .net runtime has been initiated before they get anywhere near this slow window.

All Replies

Posted by jmls on 24-Jan-2009 10:06

meh. update.

It's the init of the usercombo that is taking the time. I had a call to the init method in twice (once in the user control, and once in the form).

Comment out the init, and the form itself takes milliseconds to load.

Now, onto why the combo takes soooooooo long .

Posted by jmls on 24-Jan-2009 10:19

right. the line of code causing all the problems is

THIS-OBJECT:DataSource = BindSource.

the bindsource in question is created thus:

where lv_Query is

and lv_Columns is

the UserCode table has only 200 records in it ...

what do I do now ?

Posted by jmls on 24-Jan-2009 10:58

hacked the user control to use a temp-table instead.

loop through all user records, buffer-copy to tt.

create binding source for the tt instead of the database table

it now takes 600 milliseconds to run. 10x faster that reading the database record directly. Even though I am reading all of the records in order to copy them to the TT !!

Something is not right here.

Posted by Admin on 24-Jan-2009 11:44

Well, I doubt it's the processor of the target machine that's causing the problem. I also do not believe, that it's the fact, that it's a runtime license and not the dev license.

Do you connect to the same instance of the database on both machines? Or are you using a local (shared memory) DB for dev and a remote DB on the target machine?

Try a PRESELECT Query.

How does the performence change, when you run the same Form a second time from the same runtime session? You have been assuming, that the .NET runtime is already loaded in the prowin32. But loading the required Infragistics libraries (~ one per namespace) takes also some time when a Control is used the first time. Even when the library for the "normal" input Controls is loaded, the UltraGrid assemblies needs to be loaded at it's first usage. The assemblies.xml file does not cause a preloading of the assemblies at runtime.

Posted by jmls on 24-Jan-2009 11:56

Do you connect to the same instance of the database

on both machines? Or are you using a local (shared

memory) DB for dev and a remote DB on the target

machine?

Local on dev, remote on target . However, it is a really small table, with only 200 records in total.

Try a PRESELECT Query.

Did already - no effect whatsoever.

How does the performence change, when you run the

same Form a second time from the same runtime

session? You have been assuming, that the .NET

it doesn't change.

Look at my last post : reading the db table into a temp-table, and then binding the temp-table to the control is 10x faster than binding the db table to the control ...

Posted by Admin on 24-Jan-2009 12:01

Look at my last post : reading the db table into a

temp-table, and then binding the temp-table to the

control is 10x faster than binding the db table to

the control ...

I've seen that. The question is, how good is 10x faster compared to the local DB? Do you have some absolute numbers?

Posted by jmls on 24-Jan-2009 12:05

I've seen that. The question is, how good is 10x

faster compared to the local DB? Do you have some

absolute numbers?

In my first post, I mentioned that it takes 10s on target and 2+s on the dev.

However, I was calling the method that binds twice, so the times are really 5s target and 1s+ on dev.

I've gotten target down to 600ms, and dev to around 200ms

Posted by jmls on 24-Jan-2009 17:06

and try as I might, I can't reproduce this against the sports database ...

Posted by Thomas Mercer-Hursh on 24-Jan-2009 17:30

Can you reproduce it on any other table for the same two databases? I.e., everything the same except the table?

Assuming, of course, that you can still reproduce it on this table ...

Posted by jmls on 25-Jan-2009 03:52

Can you reproduce it on any other table for the same

two databases? I.e., everything the same except the

table?

Haven't tried that, because I simply can't reproduce this in any other code. I have taken the basics of the code around where the delay occurs, pasted it into the editor and it runs in 10ms or less ... even on the target machine

Assuming, of course, that you can still reproduce it

on this table ...

Not yet I can't. I suspect that there is a bug lurking around here, one that only raises itself under a very particular set of circumstances

Posted by Thomas Mercer-Hursh on 25-Jan-2009 11:37

This is just a single table? Smells a bit like a non-indexed read or something.

What about 1st pass versus second pass, i.e., faster once the records are in memory?

Are the parameters of the two sessions equivalent, i.e., equal temp-table space to work in?

Posted by jmls on 25-Jan-2009 11:46

This is just a single table?

Yes, single table

>Smells a bit like a

non-indexed read or something.

Nope, indexed - and there is only 200 records in the table

What about 1st pass versus second pass, i.e., faster

once the records are in memory?

No difference.

Are the parameters of the two sessions equivalent,

i.e., equal temp-table space to work in?

No temp-tables at all - just a pure, small, db table

What is really strange is that there seems to be no rhyme or reason for this slowdown. I am trying to get the simplest code to show the problem, but am struggling to reproduce it.

Posted by Thomas Mercer-Hursh on 25-Jan-2009 11:58

If the simplest case does display the behavior, but the complex case does, I suppose you are stuck building the former up into the latter or tearing down the latter in the direction of the former until you see a change in behavior. Is ti possible to just start commenting out pieces of the complex case?

Posted by jmls on 26-Jan-2009 06:21

I haven't been able to reproduce against the sports database, but it definately related to the number of records in the query.

If my query is

then it takes 3000ms (3 seconds +) to execute the command

Change the query to

and the time is 10ms

I must stress that there are only 200 records in total in this table. Not 2000 nor 20000, but 200

If I do a "for each" on the table in the ABL, it takes less than 5ms to execute. I have even gone so far as to read through all of the records in the ABL just before the bind just to "preload" them into buffers, but it makes no difference. This "for each" read takes less than 4 ms to complete.

So, I don't think that it's the database, nor the query as the ABL side works perfectly.

This is the Infragistics.Win.UltraWinGrid.UltraCombo control that I am talking about, not the ComboEditor.

It's also not the number of columns in the grid, nor the appearance.

I am still trying to build this into a sports demo

Posted by Thomas Mercer-Hursh on 26-Jan-2009 11:34

I haven't played with this stuff at all, but I'm wondering it the issue is the way in which the query and binding source interact. I don't know if this is possible or meaningful, but didn't you say above that it was a lot faster with a temp-table than the database? So, is it possible that if one is going to the database that it is fetching each record individually and it needs to go through a bunch of internal stuff putting that record in place (I'm thinking something like we used to go through dealing with non-indexed work-tables and trying to get them in sort order.) Is there a syntax that allows you to prepare the data in advance and hand it over all at once?

As you can tell, I'm really poking about in the dark on instinct here ... just making guesses based on what it seems like you are seeing.

Posted by jmls on 26-Jan-2009 12:08

I keep running into blind alleys here. However, I think that I am narrowing this down to the actual control itself. The form takes ages to load if there is a substantial (50+!) number of records.

I am now rewriting it to use a tt to see what difference it makes now.

Posted by Admin on 26-Jan-2009 12:14

How many fields are in your table? I know, that you are only using two in the binding source, but maybe that's a difference to the customer table?

Posted by Tim Kuehn on 26-Jan-2009 12:28

If you can run this on a db where you're the only user, you'll be able to see how many read ops are done on the db and see if that's the cause of the problem. If the read counts are low, then the problem is somewhere else.

Posted by jmls on 26-Jan-2009 12:35

I've attached some code that shows symptoms of the problem. When you run this code (see below for a bootstrap), look at the screen, and how long the items take to draw. comment out the initgrid and see how they are drawn instantaneously.

If you change the data to use order-line instead, you will see the real problem with a large number of records.

What is really interesting are the timings. I have put in two timings: from construction to initgrid, and the time for initgrid to complete. If you use order-line particularly, the timings are way, way out from reality. It looks like the form is available for viewing a long time before the combo-box is populated, hence the apparent delay.

If the db is remote instead of local, then the problem is highlighted further.

I would appreciate any comments on this.


[View:~/cfs-file.ashx/__key/communityserver-discussions-components-files/19/demo.cls:550:0]

Posted by Thomas Mercer-Hursh on 26-Jan-2009 12:47

I would say that the experiments Julian has done so far suggest strongly that the issue is not read operations, although there is no harm in checking. But, were I Julian, I would be focusing on the interface between the data and the control.

BTW, Julian, is the data available in the order that the control needs it?

Posted by jmls on 26-Jan-2009 12:57

the interface between the control and the data is now "none" IOW, I am reading straight from the db into the control via a query handle (see demo above). I am still facing the same problem.

This seems to be generic - data from my userCode table, the customer, order and order-line table all exhibit the same behaviour.

Posted by Tim Kuehn on 26-Jan-2009 13:44

I would say that the experiments Julian has done so far suggest strongly that the issue is not read operations, although there is no harm in checking.

I'd be inclined to concur. But the only way to conclusively eliminate that as a/the source of the problem is to do the test.

Posted by Peter Judge on 26-Jan-2009 13:57

Here's something else interesting. Move the code from demo_shown to the constructor, after the InitializeComponent call. I now see the title go to 20/28 (or something similar*).

Now, however, the big pause comes during the wait-for a:ShowDialog() call. It also comes if I change that to an Application:Run() call. So the stuff that's causing the slowdown is happening during the painting/showing of the form.

-- peter

  • I can see a difference between a 1st and 2+ run, in the same session, but it's not the big pause.

Posted by jmls on 26-Jan-2009 14:09

I originally had the code there, but was trying all sort of "tricks" to find where the problem may be. I thought that if the form was "shown" I may be able to populate the combo box quicker.

Now, however, the big pause comes during the wait-for

a:ShowDialog() call. It also comes if I change that

to an Application:Run() call. So the stuff that's

causing the slowdown is happening during the

painting/showing of the form.

No, I don't think that is the case. Enable the InitGrid call, but comment out the following line

and you see that the form is drawn instantly. It is the binding to the control that is causing the slowdown. That's why the number of records is proportional to the slowdown.

Change the query to "FOR EACH order-line where order-line.linenum eq 1 NO-LOCK" and the screen is painted instantly as well.

-- peter

  • I can see a difference between a 1st and 2+ run, in

the same session, but it's not the big pause.Here's something else interesting. Move the code from

demo_shown to the constructor, after the

InitializeComponent call. I now see the title go to

20/28 (or something similar*).

Posted by Peter Judge on 26-Jan-2009 14:14

I originally had the code there, but was trying all

sort of "tricks" to find where the problem may be. I

thought that if the form was "shown" I may be able to

populate the combo box quicker.

Another data point: I just added event handlers in the PBS and none of them fire during the Great Wait.

Now, however, the big pause comes during the

wait-for

a:ShowDialog() call. It also comes if I change

that

to an Application:Run() call. So the stuff that's

causing the slowdown is happening during the

painting/showing of the form.

No, I don't think that is the case. Enable the

InitGrid call, but comment out the following line

and you see that the form is drawn instantly. It is

the binding to the control that is causing the

slowdown. That's why the number of records is

proportional to the slowdown.

It strikes me that there's some deferred processing going on (since it doesn't matter where the DS = BS call is made, it's in the visualisation that the waiting happens.

If you haven't already, I'd log this.

-- peter

Posted by Thomas Mercer-Hursh on 26-Jan-2009 14:19

Especially since he now has a test case against sports to give them ... an unusual pleasure. Of course, Julian would rather just have a fix ...

Posted by jmls on 26-Jan-2009 14:22

it gets better. Replace the ultracombo with a telerik radMultiColumnComboBox and the speed problem is gone. Screen is ready in 139/9 using orderlines

Using the original "Order" table gives me 124/4, available instantly.

Posted by Thomas Mercer-Hursh on 26-Jan-2009 14:24

Sounds like a smoking gun ...

Posted by Admin on 26-Jan-2009 14:25

Similar observation here (well, I used a Sports2000).

PROCESS EVENTS in the demo_Shown between this-object:InitGrid(). and the assignment of the Text with the etime values also makes a difference.

Posted by jmls on 26-Jan-2009 14:29

Sounds like a smoking gun ...

heh, what exactly does a smoking gun sound like ?

"you smell a funny colour"

Posted by Thomas Mercer-Hursh on 26-Jan-2009 14:35

what exactly does a smoking gun sound like ?

Purple, of course.

Posted by jmls on 26-Jan-2009 14:54

works perfectly well with a BinaryMission multi-column databound control as well. Looks as if it is a problem with the IG control.

I have logged a bug, haven't had the WR back just yet.

Posted by Admin on 26-Jan-2009 18:03

If you can hack the init code manually try inserting a UltraCombo:BeginUpdate() before assigning the data source and then UltraCombo:EndUpdate() following the return from the init call.

This will suspend the painting of the control as data is injected into the control from the data source, plus suspend any event handlers that may be firing - for example check if any ValueChanged/RowSelected (basically any events) are being fired as each row from the data source is added, can behave a little differently to PSC 'on value-changed' event which will only fire once. Could be that the "trigger" code is being run for each row added and causing the delay you see.

Another test: while the data source is connected to the DB (not the TT) place a 'on find' session event against that same table - see how many times your 200 records are read. Check the currency manager sync setting - again as each row is added into the combo the selectedrow changes (and events fire - as above) however this will also raise a sync against the currency manager, which may in turn issue another find against the db table. On a TT this will not be noticed, but the DB table will - especially if non no-lock access is requested.

- Colin

Posted by jmls on 27-Jan-2009 00:48

Logged as W901270002

Posted by Admin on 27-Jan-2009 00:52

And results of the begin/end update test?

and/or currency sync test using a find trigger?

Posted by jmls on 27-Jan-2009 00:53

Jeez - you are keen It's only 6:50 here ....

And results of the begin/end update test?

Nada. No difference.

and/or currency sync test using a find trigger?

working on it

Posted by Admin on 27-Jan-2009 00:58

Dateline fun, almost finished with Tuesday here

Nada >> do you have any event/triggers associated with the widget itself?

If so, are they firing one during the init code, or multiple (ie for each record, 200 times)? The control does not have to follow the advice of begin/end update invokes.

Posted by jmls on 27-Jan-2009 00:59

and/or currency sync test using a find trigger?

I must be stupid, or need a serious dose of caffeine. I can't get a find trigger to work. No matter where I put it, the trigger never gets executed.

Posted by jmls on 27-Jan-2009 01:04

I must be stupid, or need a serious dose of caffeine.

I can't get a find trigger to work. No matter where I

put it, the trigger never gets executed.

heh. It was caffeine

added the following to the start code:

y = 10707 !!

maybe I need more coffee.

Posted by Admin on 27-Jan-2009 01:05

Within your bootstrap.p you should have;

on find of order do:

output to trace.log append.

export 'find' order.youruniquefieldnamehere.

output close.

end.

compile demo.cls save.

...

...

and then within any NUI event code, also;

output to trace.log append.

export 'event xxx fired'.

output close.

Start app, wait until form is loaded and check log.

Posted by Admin on 27-Jan-2009 01:18

Not quick enough, or perhaps stong coffee.

10k plus finds ... say you have found your smoking gun.

The contol should know it is in initialization mode (via CAST(THIS-OBJECT:ultraCombo1, System.ComponentModel.ISupportInitialize):BeginInit()), however noticed that you are assigning the datasource outside of the init code - so ignore this - but the currency sync should not be happening.

However given your code ... try changing the example code to;

BindSource = NEW Progress.Data.BindingSource(lv_Query,lv_Columns,"").

ultraCombo1:BeginUpdate().

ultraCombo1:DataSource = BindSource.

ultraCombo1:EndUpdate().

May even be worth reseting your count just before doing the binding, so you can tell how many finds resulted from the query open v's the binding itself. I suspect this is related to the currency managers attempt to keep in sync with data loading, and the widget itself setting a selected item, and then goinf back to the currency manager to tell it to move on, and thus an extra find fires. PSC browse widgets had something similar depending on the viewport size of the browse - but not even close to the number you are seeing.

The overhead on a TT would not be as obvious, but still in play I would guess.

From memory the ultra controls also enabled you to turn off the sync, perhaps a toggle of this during the load would ease the pain.

Fun will be applying to to other NUI controls

Posted by jmls on 27-Jan-2009 01:21

there is something strange happening here.

The number of reads is not a multiplier of the number of records. If you limit the query to 10 record, the number of find triggers is 221.

records => find trigger executions

1 => 1

2 => 3

3 => 23

4 => 45

5 => 63

6 => 79

7 => 127

8 => 143

9 => 171

10 => 221

however, in the combo box there are only the appropriate number of items (1,2,3, etc)

Posted by jmls on 27-Jan-2009 01:24

Not quick enough, or perhaps stong coffee.

However given your code ... try changing the example

code to;

BindSource = NEW

Progress.Data.BindingSource(lv_Query,lv_Columns,"").

ultraCombo1:BeginUpdate().

ultraCombo1:DataSource = BindSource.

ultraCombo1:EndUpdate().

already did this - no effect.

May even be worth reseting your count just before

doing the binding, so you can tell how many

finds resulted from the query open v's the

binding itself. I suspect this is related to the

currency managers attempt to keep in sync with data

loading, and the widget itself setting a selected

item, and then goinf back to the currency manager to

tell it to move on, and thus an extra find fires. PSC

browse widgets had something similar depending on the

viewport size of the browse - but not even close to

the number you are seeing.

See my previous post - there is no direct correlation between the number of records and the number of find triggers

The overhead on a TT would not be as obvious, but

still in play I would guess.

From memory the ultra controls also enabled you to

turn off the sync, perhaps a toggle of this during

the load would ease the pain.

I will try that next.

Fun will be applying to to other NUI controls

Other controls seemed to work ok (see previous posts) - I'll run the same test on them

Posted by Admin on 27-Jan-2009 01:26

This is when a stack trace would come in handy (one that covered both p4gl & .Net stackframe). You need to trace where the find is being raised.

Try isolating/resetting the find count to before/during the binding.

Also try SuspendRowSynchronization and ResumeRowSynchronization calls on the combo (rather than Begin/EndUpdate - see last post).

Posted by Admin on 27-Jan-2009 01:29

Bit of cross posting creeping in.

no direct correlation between the number of records and the number of find triggers>> did you change the count (or add a second) so that we know how many finds are a result of the QUERY-OPEN v's the assign of the datasource?

Try with TT >> wont be as lucky, no find trigger with TT's (me thinks?!?)

Posted by jmls on 27-Jan-2009 01:34

Try isolating/resetting the find count to

before/during the binding.

I have done - it's the same value.

Also try SuspendRowSynchronization and

ResumeRowSynchronization calls on the combo (rather

than Begin/EndUpdate - see last post).

tried that - no effect

Posted by Admin on 27-Jan-2009 01:36

May not help, but you may not be alone;

http://devcenter.infragistics.com/Support/KnowledgeBaseArticle.aspx?ArticleID=9280

Again with the currency manager trying to stay in sync with the control during the load of data.

Came across this from point 6 of http://forums.infragistics.com/forums/p/15306/57637.aspx. However you may get away with the sync manager changes from bottom of point 1 (basically do both of my prior suggestions - ie BeginUpdate & SuspendRowSynchronization

Posted by Admin on 27-Jan-2009 01:46

You should be able to build a sportsdb test example for your report - not sure how easy it will be to solve though, as what you are seeing is correct when the user picks an item (ie you want the select Orders recorded to be loaded/positioned), just not desired when loading data.

Perhaps in the 'next release' the probinding can have a begindataload/enddataload to indicate if it should ignore currency position requests (and only position to the last request at the enddataload invoke).

The equiv in pure .Net would be the dataset/datatable, which is disconnected much like your TT observation. Came across a few posts like yours related to both the grid & combo ultra controls - so you may need to keep a watch on these as well.

Posted by jmls on 27-Jan-2009 01:59

I did write some code against the sports database : See demo.cls attached to an earlier posting.

This all came about because I was trying to load 100 records into a combo for a user to choose, and the delay was really noticeable.

Unless I can find something to "fix" this, I will need to move to another control like the radcombo - there is no performance problem with this one. Again, see the earlier posts.

Posted by jmls on 27-Jan-2009 04:56

This has got really interesting now. This is a simplified demo program now - with a find trigger built into the class, and an option to use a TT instead.

To run, use the following code:

attempt#1

run the program above.

the number of records read goes to 10707 - there are 207 records in the table

every time you drop down the combo-box, note that the number of records read increases by over a 100 every time ....

attempt#2

change UseTT to "yes" in demo.cls

run the program above.

note that the form appears instantly, with all records in.

Posted by Tim Kuehn on 27-Jan-2009 07:24

attempt#1

run the program above.

the number of records read goes to 10707 - there

are 207 records in the table

every time you drop down the combo-box, note that the

number of records read increases by over a 100 every

time ....

I'm curious if this shows up when running promon against the db?

This also confirms that the problem was an excessive amount of reads, as I'd posited earlier!

Posted by jmls on 27-Jan-2009 07:28

I'm curious if this shows up when running promon

against the db?

It does indeed.

Record Reads: 11171 385/2 per seconds

This also confirms that the problem was an excessive

amount of reads, as I'd posited earlier!

Hail! Hail! All hail Tim !

Posted by jmls on 27-Jan-2009 07:33

when I use the radcombo control instead of the IG, promon only gives 465 reads ...

Posted by Tim Kuehn on 27-Jan-2009 07:49

Hail! Hail! All hail Tim !

LOL - let's not get too silly. I'd prefer tweaking TMH on the nose for dismissing this as a possible cause (or effect, if the problem's actually in the control)...

Posted by jmls on 27-Jan-2009 08:12

 * jmls tweaks TMH's nose ...

Posted by jmls on 27-Jan-2009 08:13

I would like to say thanks to all for looking at this and suggesting various things. It's actually a very nice "trail" for Tech Support to follow and hopefully identify the problem.

Thanks again to everyone.

Posted by jmls on 27-Jan-2009 10:04

Woot! Psc Tech support have reproduced the problem .. yay ..

Posted by jmls on 30-Jan-2009 04:39

Logged has bug#OE00180488

speeelin is niot my strung poitn

Message was edited by:

Julian Lyndon-Smith

This thread is closed