Dispose taking too long

Discussion of open issues, suggestions and bugs regarding ADO.NET provider for PostgreSQL
Post Reply
tomcat2001
Posts: 21
Joined: Wed 10 Sep 2008 20:29

Dispose taking too long

Post by tomcat2001 » Tue 21 Oct 2008 20:29

We make extensive use of data readers in our code and we've noticed a slowdown for some client. We traced this back the dispose method on the datareader. I have a code sample below. Now I want to say for our machines this is fine. But that doesn't help our client and the time is coming down in the code. We used a profiler once, but it was showing all kinds of crazy method names since they've been obfuscated. Here's a snippet for what we're doing in this test. I get the time before and the time after dispose. And the difference we've been seeing is 150ms. So each dispose is costing us 150ms and those are adding up way too quick as we're doing quite a few database calls. Any help appreciated. The client is on xp sp3. If we do this on the server, the times are 0ms or 15ms.

PgSqlConnection newConnection = new PgSqlConnection();
newConnection.ConnectionTimeout = 15;
newConnection.Database = textBox3.Text;
newConnection.Host = textBox1.Text;
newConnection.Password = textBox2.Text;
newConnection.UserId = "postgres";
newConnection.Port = (int)numericUpDown1.Value;
newConnection.Open();

PgSqlCommand command = new PgSqlCommand("Select * From soapware_admin_adminglobalsettings", newConnection);
PgSqlDataReader reader = command.ExecuteReader(CommandBehavior.CloseConnection);

try
{

}
finally
{
startTime = DateTime.Now;
reader.Dispose();
endTime = DateTime.Now;

}

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Post by Shalex » Wed 22 Oct 2008 09:14

The reason of the delay is the following. When you are calling the Dispose method of the PgSqlDataReader object, the portal for this object closes at the server side. The round trip for local requests is faster than for remote ones.

tomcat2001
Posts: 21
Joined: Wed 10 Sep 2008 20:29

Post by tomcat2001 » Wed 22 Oct 2008 12:08

I'm sorry, but that cannot be the explanation here. You're trying to tell me the latency on a local network is so bad it takes that long for a message to get there and one to get back? I could maybe see 10 ms, but we're talking about 100ms here.

I can run pings on their network and each one is less than 10ms, so I can't see how this is the problem. I've run similar tests here on our network and they also don't take very long.

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Post by Shalex » Wed 22 Oct 2008 13:32

Closing a portal during network interoperation requires more time. It is not a time for closing it locally plus a ping time. It is a feature of internal implementation of PostgreSQL server for network request processing.

tomcat2001
Posts: 21
Joined: Wed 10 Sep 2008 20:29

Post by tomcat2001 » Wed 22 Oct 2008 13:52

So if I understand correctly you're telling me that have a 150 ms time to do any kind of query is normal? Is there nothing that can be done to get around this?

This seems like a serious problem.

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Post by Shalex » Thu 23 Oct 2008 16:20

Please give us more clear description of the problem you are experiencing when disposing takes 150 ms.

tomcat2001
Posts: 21
Joined: Wed 10 Sep 2008 20:29

Post by tomcat2001 » Thu 23 Oct 2008 16:43

Well I thought the problem was stated clear, but here's the dilemma. We're doing a bunch of queries to get values from the database. So this table has say 20 rows and we do a different query to get each one. So that's 3000 ms right there (150ms for each one) for just the dispose. We're also getting similar times on the actual reading of data. So we're talking about 6 seconds to get the data from the table.

We have connection pooling turned on and such, so I wouldn't think this would be bad. All our tests here have been good and I think for most of our users it's find also. But this user of ours is running into this. The software is just running extremely slow and the culprit is the database calls and we need to figure out why. Since running this on the server is not seeing the same delay, we don't think it's the server itself as far as getting the data. What can we do to provide you with the information you need? Is there something we can do to trace this down better? I know this is a strange issue, but telling me that 150ms to dispose a connection is normal is incorrect.

AndreyR
Devart Team
Posts: 2919
Joined: Mon 07 Jul 2008 13:16

Post by AndreyR » Fri 24 Oct 2008 14:13

When performing Execute, server selects and sends to client the first packet of data, no matter if it is selected by client or ignored. Dispose clears pipe and by this selects the packet, and sends the port closing request. It explains the fact that the select time and dispose time are equal.

You can verify this information by using any sniffer program displaying the packet exchange between server and client.

tomcat2001
Posts: 21
Joined: Wed 10 Sep 2008 20:29

Post by tomcat2001 » Mon 03 Nov 2008 21:18

OK. I have some new information that may be of some use, but there's some problem here and we need some more info since this seems to be pretty important. Now this is our only site having this problem that we KNOW of. If I turn the connection pooling off, the close takes 0ms. With connection pooling on it's taking close to 200ms to close. To take this 1 step further, I tried this out with the pgfoundry driver and it's 0ms to close with connection pooling off or on. So it seems to be something with the connection pooling. The next part will be what could be causing this problem? This site did not seem to be having this problem when we were on the 3.5 version. When we upgraded to 3.75 it started happening. I have no way to verify for sure that's the case, but that's what they tell us. I've spent a bit of time on this already.

AndreyR
Devart Team
Posts: 2919
Joined: Mon 07 Jul 2008 13:16

Post by AndreyR » Tue 04 Nov 2008 12:32

We will investigate this issue and notify you about the results. But it will take at least a week.

tomcat2001
Posts: 21
Joined: Wed 10 Sep 2008 20:29

Post by tomcat2001 » Fri 05 Dec 2008 14:41

Is there any news on this? Is there anything we can do to provide some more information to you. To our knowledge this is only happening on one site, so it would be something specific to this site. We could run some kind of debugging code or whatever that may generate a log if you have any such functionality.

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Post by Shalex » Tue 09 Dec 2008 11:26

Sorry for inconvenience, but we need more time to process this request.

Post Reply