Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pgbouncer reporting "FIXME: query end, but query_start == 0" on what appears to be each sql statement issued #2522

Open
joecarr opened this issue Jul 10, 2019 · 3 comments

Comments

@joecarr
Copy link

commented Jul 10, 2019

Steps to reproduce

I can reproduce at will locally, but do not know how to tell someone else to repro.

The issue

Here is an excerpt from our pgbouncer log file:
2019-07-06 06:27:04.066 WARNING C-0x1340a40: DB/user@192.168.0.17:30031 FIXME: query end, but query_start == 0
2019-07-06 06:27:04.066 WARNING C-0x1342558: DB/user@192.168.0.17:30030 FIXME: query end, but query_start == 0
2019-07-06 06:27:04.067 WARNING C-0x134f538: DB/user@192.168.0.17:30032 FIXME: query end, but query_start == 0
2019-07-06 06:27:04.254 WARNING C-0x1332ea8: DB/user@192.168.0.16:44225 FIXME: query end, but query_start == 0
2019-07-06 06:27:04.258 WARNING C-0x1332ea8: DB/user@192.168.0.16:44225 FIXME: query end, but query_start == 0
2019-07-06 06:27:04.320 WARNING C-0x134ed40: DB/user@192.168.0.18:24411 FIXME: query end, but query_start == 0
2019-07-06 06:27:04.357 WARNING C-0x134ed40: DB/user@192.168.0.18:24411 FIXME: query end, but query_start == 0

This doesn't appear to have any known adverse affect other than adding quite a bit more hay to the haystack of our pgbouncer log files, thereby making the needles harder to find.

We can easily reproduce, so if you potentially have a debug build that we could run against our dev server, perhaps we can determine exactly why pgbouncer isn't seeing our query_start.

Further technical details

Configuration string: No Reset On Close=true;Pooling=false
Npgsql: 4.0.7
Postgres: 10.7
Pgbouncer: 1.9.0
NHibernate: 4.0.0.4000
.Net Framework: 4.8

@roji

This comment has been minimized.

Copy link
Member

commented Jul 11, 2019

@joecarr without any sort of repro it won't be possible to do much...

But if you can repro reliably on your end, it shouldn't be too hard. I suggest trying to narrow down the scenario, isolating the statement (or statements) that triggers the error, to the minimal set of actions required to trigger this. Then, you'd ideally post the database schema and sequence of actions and the pgbouncer folks should be able to take it from there.

You can easily do a debug build of Npgsql but I'm not too sure that will help you much. If you want to build, simply clone the repo, checkout the v4.0.7 tag and build.

@topharley

This comment has been minimized.

Copy link

commented Jul 17, 2019

Hi!

Repro steps:

SQL:

CREATE OR REPLACE FUNCTION test1()  RETURNS int LANGUAGE sql AS $$ select 100500; $$;

c#:

using (var con = new NpgsqlConnection("User ID=user;Password=pass;Host=myip;Port=6432;Database=postgres"))
{
	con.Open();
	using (var trans = con.BeginTransaction())
	{
		var readCommand = new NpgsqlCommand("test1", con, trans);
		readCommand.CommandType = CommandType.StoredProcedure;
		var res = readCommand.ExecuteScalar(); //spammed here
		trans.Commit();
	}
}

And this will write 2 lines in pgbouncer log on each call:

FIXME: query end, but query_start == 0
FIXME: query end, but query_start == 0
@roji

This comment has been minimized.

Copy link
Member

commented Jul 17, 2019

Thanks @topharley! As soon as I find some spare time I'll drill into this and find what exactly is happening at the wire level to trigger those messages.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.