[pgpool-hackers: 2163] Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
Tatsuo Ishii
ishii at sraoss.co.jp
Fri Mar 17 17:21:42 JST 2017
> Yes, this what we are doing now. Trying to create a synthetic test.
>
> But can you comment my discovery about broken balancing? The very first version of the regarding the current issue was not violating the bakancing schema. I'm just thinking there can be the same root cause for for the "mismatch" and balancing errors.
No idea. I couldn't reproduce it using your test program here.
If you enable the debug output of Pgpool-II, now it will print why it
cannot load balance the query. For example,
could not load balance because of too much replication delay
Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp
> Sergey.
> ________________________________
> From: Tatsuo Ishii <ishii at sraoss.co.jp>
> Sent: Friday, March 17, 2017 9:15:37 AM
> To: Sergey Kim
> Cc: pgpool-hackers at pgpool.net; Boris Voskanov
> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>
>> Tatsuo,
>>
>> the problem is reproduced with this patch (((
>
> Ok, I will wait for a new test program for this issue.
>
>> There are also 2 strange facts:
>>
>> 1) Pgpool forwards all requests to backend 0 nevertheless the next configuration is in place:
>>
>> backend_hostname0='a.db.node'
>> backend_port0=15432
>> backend_weight0=0
>> backend_data_directory0 = '/var/lib/pgsql/9.6/data'
>> backend_flag0 = 'ALLOW_TO_FAILOVER'
>>
>> backend_hostname1='b.db.node'
>> backend_port1=15432
>> backend_weight1=100
>> backend_data_directory1 = '/var/lib/pgsql/9.6/data'
>> backend_flag1 = 'ALLOW_TO_FAILOVER'
>>
>> Created by me test #271 easily confirms this fact.
>>
>> 2) We didn't detect the clean root cause but our system 'hangs' on startup until we kill (killall -9 pgpool) pgpool processes. Only after that killing it continues starting with error
>>
>> When this 'hang' happens we the following pgpool log:
>>
>> 2017-03-17T08:28:31.249651+03:00 OAA-54999c4d7735 pgpool[25614]: [3620-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.249954+03:00 OAA-54999c4d7735 pgpool[25614]: [3621-1] LOG: DB node id: 0 backend pid: 25808 statement: B message
>> 2017-03-17T08:28:31.250122+03:00 OAA-54999c4d7735 pgpool[25614]: [3621-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.250285+03:00 OAA-54999c4d7735 pgpool[25614]: [3622-1] LOG: DB node id: 0 backend pid: 25808 statement: D message
>> 2017-03-17T08:28:31.250467+03:00 OAA-54999c4d7735 pgpool[25614]: [3622-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.250623+03:00 OAA-54999c4d7735 pgpool[25614]: [3623-1] LOG: DB node id: 0 backend pid: 25808 statement: Execute: select 1 from domain_registration_tlds where tld_name = 'ac'
>> 2017-03-17T08:28:31.250799+03:00 OAA-54999c4d7735 pgpool[25614]: [3623-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.255389+03:00 OAA-54999c4d7735 pgpool[25614]: [3624-1] LOG: DB node id: 0 backend pid: 25808 statement: B message
>> 2017-03-17T08:28:31.255628+03:00 OAA-54999c4d7735 pgpool[25614]: [3624-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.255852+03:00 OAA-54999c4d7735 pgpool[25614]: [3625-1] LOG: DB node id: 1 backend pid: 23137 statement: B message
>> 2017-03-17T08:28:31.256071+03:00 OAA-54999c4d7735 pgpool[25614]: [3625-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.256306+03:00 OAA-54999c4d7735 pgpool[25614]: [3626-1] LOG: DB node id: 0 backend pid: 25808 statement: Execute: COMMIT
>> 2017-03-17T08:28:31.256511+03:00 OAA-54999c4d7735 pgpool[25614]: [3626-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:31.256681+03:00 OAA-54999c4d7735 pgpool[25614]: [3627-1] LOG: DB node id: 1 backend pid: 23137 statement: Execute: COMMIT
>> 2017-03-17T08:28:31.256847+03:00 OAA-54999c4d7735 pgpool[25614]: [3627-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:34.977877+03:00 OAA-54999c4d7735 pgpool[25614]: [3628-1] LOG: DB node id: 1 backend pid: 23137 statement: Parse:
>> 2017-03-17T08:28:34.978159+03:00 OAA-54999c4d7735 pgpool[25614]: [3628-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:34.978405+03:00 OAA-54999c4d7735 pgpool[25614]: [3629-1] LOG: DB node id: 0 backend pid: 25808 statement: Parse:
>> 2017-03-17T08:28:34.978694+03:00 OAA-54999c4d7735 pgpool[25614]: [3629-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:34.978952+03:00 OAA-54999c4d7735 pgpool[25614]: [3630-1] LOG: DB node id: 0 backend pid: 25808 statement: B message
>> 2017-03-17T08:28:34.979191+03:00 OAA-54999c4d7735 pgpool[25614]: [3630-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:34.979434+03:00 OAA-54999c4d7735 pgpool[25614]: [3631-1] LOG: DB node id: 0 backend pid: 25808 statement: D message
>> 2017-03-17T08:28:34.979679+03:00 OAA-54999c4d7735 pgpool[25614]: [3631-2] LOCATION: pool_proto_modules.c:3202
>> 2017-03-17T08:28:34.979929+03:00 OAA-54999c4d7735 pgpool[25614]: [3632-1] LOG: DB node id: 0 backend pid: 25808 statement: Execute:
>> 2017-03-17T08:28:34.980171+03:00 OAA-54999c4d7735 pgpool[25614]: [3632-2] LOCATION: pool_proto_modules.c:3202
>>
>> Sergey.
>>
>>
>> ________________________________
>> From: Tatsuo Ishii <ishii at sraoss.co.jp>
>> Sent: Friday, March 17, 2017 5:24 AM
>> To: Sergey Kim
>> Cc: pgpool-hackers at pgpool.net; Boris Voskanov
>> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>
>> Sergey,
>>
>> Thanks for the testing.
>>
>>> It seems the pgpool forwards the "parse" message to the backend
>>> #0. But it seems this should not happen.
>>
>> Yes, you are right.
>>
>> I found a bug with the code which could cause the problem.
>>
>> Execute() mistakenly set the writing transaction flag even if a write
>> query is issued (in particular case, "BEGIN"). The reason why it did
>> not found before was, the code path only works when the transaction
>> state is 'T' (in transaction). Before it was only set at
>> CommandComplete but previous commit set the state at Execute(). This
>> leads to a SELECT not being load balanced.
>>
>> Attached patch tries to fix the problem. I also pushed the changes to
>> the git repository.
>>
>> Best regards,
>> --
>> Tatsuo Ishii
>> SRA OSS, Inc. Japan
>> English: http://www.sraoss.co.jp/index_en.php
>> Japanese:http://www.sraoss.co.jp
>>
>>> Tatsuo,
>>>
>>>
>>> We performed series of different tests, and every time application fails in different cases. But having compared the failed cases against their normal executions we extracted the following log case(s):
>>>
>>> It seems the pgpool forwards the "parse" message to the backend #0. But it seems this should not happen.
>>>
>>>
>>> Log of normal execution:
>>>
>>> 2017-03-16T17:07:45.250703+03:00 OAA-54999c4d7735 pgpool[16386]: [4643-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: Execute: SELECT typinput='array_in'::regproc, typtype FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T17:07:45.251667+03:00 OAA-54999c4d7735 pgpool[16386]: [4643-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.251849+03:00 OAA-54999c4d7735 pgpool[16386]: [4644-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: B message
>>> 2017-03-16T17:07:45.252098+03:00 OAA-54999c4d7735 pgpool[16386]: [4644-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.252252+03:00 OAA-54999c4d7735 pgpool[16386]: [4645-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: Execute: SELECT typinput='array_in'::regproc, typtype FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T17:07:45.253172+03:00 OAA-54999c4d7735 pgpool[16386]: [4645-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.253326+03:00 OAA-54999c4d7735 pgpool[16386]: [4646-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 1 backend pid: 20117 statement: Parse: select current_schema()
>>> 2017-03-16T17:07:45.253470+03:00 OAA-54999c4d7735 pgpool[16386]: [4646-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.253628+03:00 OAA-54999c4d7735 pgpool[16386]: [4647-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 1 backend pid: 20117 statement: B message
>>> 2017-03-16T17:07:45.253791+03:00 OAA-54999c4d7735 pgpool[16386]: [4647-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.253947+03:00 OAA-54999c4d7735 pgpool[16386]: [4648-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 1 backend pid: 20117 statement: D message
>>> 2017-03-16T17:07:45.254093+03:00 OAA-54999c4d7735 pgpool[16386]: [4648-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.254239+03:00 OAA-54999c4d7735 pgpool[16386]: [4649-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 1 backend pid: 20117 statement: Execute: select current_schema()
>>> 2017-03-16T17:07:45.254385+03:00 OAA-54999c4d7735 pgpool[16386]: [4649-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.254540+03:00 OAA-54999c4d7735 pgpool[16386]: [4650-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: Parse: SELECT t.typname,t.oid FROM pg_catalog.pg_type t JOIN pg_catalog.pg_namespace n ON (t.typnamespace = n.oid) WHERE n.nspname != 'pg_toast'
>>> 2017-03-16T17:07:45.254693+03:00 OAA-54999c4d7735 pgpool[16386]: [4650-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.254855+03:00 OAA-54999c4d7735 pgpool[16386]: [4651-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: B message
>>> 2017-03-16T17:07:45.255015+03:00 OAA-54999c4d7735 pgpool[16386]: [4651-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.255169+03:00 OAA-54999c4d7735 pgpool[16386]: [4652-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: D message
>>> 2017-03-16T17:07:45.255308+03:00 OAA-54999c4d7735 pgpool[16386]: [4652-2] 2017-03-16 17:07:45: pid 16386:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:07:45.255445+03:00 OAA-54999c4d7735 pgpool[16386]: [4653-1] 2017-03-16 17:07:45: pid 16386:LOG: DB node id: 0 backend pid: 17303 statement: Execute: SELECT t.typname,t.oid FROM pg_catalog.pg_type t JOIN pg_catalog.pg_namespace n ON (t.typnamespace = n.oid) WHERE n.nspname != 'pg_toast'
>>>
>>>
>>> The failed execution:
>>>
>>> FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T17:49:42.503476+03:00 OAA-54999c4d7735 pgpool[21183]: [3116-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.503643+03:00 OAA-54999c4d7735 pgpool[21183]: [3117-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 0 backend pid: 21241 statement: B message
>>> 2017-03-16T17:49:42.503858+03:00 OAA-54999c4d7735 pgpool[21183]: [3117-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.504016+03:00 OAA-54999c4d7735 pgpool[21183]: [3118-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 0 backend pid: 21241 statement: Execute: SELECT typinput='array_in'::regproc, typtype FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T17:49:42.504765+03:00 OAA-54999c4d7735 pgpool[21183]: [3118-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.574664+03:00 OAA-54999c4d7735 pgpool[21183]: [3119-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 1 backend pid: 21152 statement: Parse: select current_schema()
>>> 2017-03-16T17:49:42.574941+03:00 OAA-54999c4d7735 pgpool[21183]: [3119-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.575109+03:00 OAA-54999c4d7735 pgpool[21183]: [3120-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 0 backend pid: 21241 statement: Parse: select current_schema()
>>> 2017-03-16T17:49:42.575286+03:00 OAA-54999c4d7735 pgpool[21183]: [3120-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.575455+03:00 OAA-54999c4d7735 pgpool[21183]: [3121-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 0 backend pid: 21241 statement: B message
>>> 2017-03-16T17:49:42.575630+03:00 OAA-54999c4d7735 pgpool[21183]: [3121-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.575790+03:00 OAA-54999c4d7735 pgpool[21183]: [3122-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 0 backend pid: 21241 statement: D message
>>> 2017-03-16T17:49:42.575931+03:00 OAA-54999c4d7735 pgpool[21183]: [3122-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.576082+03:00 OAA-54999c4d7735 pgpool[21183]: [3123-1] 2017-03-16 17:49:42: pid 21183:LOG: DB node id: 0 backend pid: 21241 statement: Execute: select current_schema()
>>> 2017-03-16T17:49:42.576230+03:00 OAA-54999c4d7735 pgpool[21183]: [3123-2] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T17:49:42.576376+03:00 OAA-54999c4d7735 pgpool[21183]: [3124-1] 2017-03-16 17:49:42: pid 21183:FATAL: failed to read kind from backend
>>> 2017-03-16T17:49:42.576522+03:00 OAA-54999c4d7735 pgpool[21183]: [3124-2] 2017-03-16 17:49:42: pid 21183:DETAIL: kind mismatch among backends. Possible last query was: "select current_schema()" kind details are: 0[Z] 1[1]
>>> 2017-03-16T17:49:42.576676+03:00 OAA-54999c4d7735 pgpool[21183]: [3124-3] 2017-03-16 17:49:42: pid 21183:HINT: check data consistency among db nodes
>>> 2017-03-16T17:49:42.576815+03:00 OAA-54999c4d7735 pgpool[21183]: [3124-4] 2017-03-16 17:49:42: pid 21183:LOCATION: pool_process_query.c:3731
>>> 2017-03-16T17:49:42.580320+03:00 OAA-54999c4d7735 pgpool[21175]: [9-1] 2017-03-16 17:49:42: pid 21175:LOG: child process with pid: 21183 exits with status 512
>>>
>>>
>>> ________________________________
>>> From: Sergey Kim
>>> Sent: Thursday, March 16, 2017 2:48 PM
>>> To: Tatsuo Ishii
>>> Cc: pgpool-hackers at pgpool.net; Boris Voskanov
>>> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>>
>>>
>>> Tatsuo,
>>>
>>>
>>> we continue attempts to reproduce the problem in a self contained test.
>>>
>>>
>>> BTW plese see the attached log file of pgpool. Probably it can help.
>>>
>>>
>>>
>>> Sergey.
>>>
>>>
>>> ________________________________
>>> From: Sergey Kim
>>> Sent: Thursday, March 16, 2017 11:31 AM
>>> To: Tatsuo Ishii
>>> Cc: pgpool-hackers at pgpool.net; Boris Voskanov
>>> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>>
>>>
>>> Hi Tatsuo,
>>>
>>>
>>> the verification failed again (((
>>>
>>>
>>> Though test created tests could pass smoothly the system failed to start with error (kind mismatch among backends. Possible last query was: "select current_schema()" kind details are: 0[Z] 1[1]) which is detected in pgpool logs. Now we are fighting to create the artificial test.
>>>
>>>
>>> See the pgpool logs:
>>>
>>> 2017-03-16T11:20:56.401312+03:00 OAA-54999c4d7735 pgpool[1213]: [25442-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: B message
>>> 2017-03-16T11:20:56.401450+03:00 OAA-54999c4d7735 pgpool[1213]: [25442-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.401586+03:00 OAA-54999c4d7735 pgpool[1213]: [25443-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: Execute: SELECT typinput='array_in'::regproc, typtype FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T11:20:56.402316+03:00 OAA-54999c4d7735 pgpool[1213]: [25443-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.402462+03:00 OAA-54999c4d7735 pgpool[1213]: [25444-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: B message
>>> 2017-03-16T11:20:56.402608+03:00 OAA-54999c4d7735 pgpool[1213]: [25444-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.402745+03:00 OAA-54999c4d7735 pgpool[1213]: [25445-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: Execute: SELECT typinput='array_in'::regproc, typtype FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T11:20:56.403474+03:00 OAA-54999c4d7735 pgpool[1213]: [25445-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.403614+03:00 OAA-54999c4d7735 pgpool[1213]: [25446-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: B message
>>> 2017-03-16T11:20:56.403748+03:00 OAA-54999c4d7735 pgpool[1213]: [25446-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.403884+03:00 OAA-54999c4d7735 pgpool[1213]: [25447-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: Execute: SELECT typinput='array_in'::regproc, typtype FROM pg_catalog.pg_type LEFT JOIN (select ns.oid as nspoid, ns.nspname, r.r from pg_namespace as ns join ( select s.r, (current_schemas(false))[s.r] as nspname from generate_series(1, array_upper(current_schemas(false), 1)) as s(r) ) as r using ( nspname ) ) as sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC LIMIT 1
>>> 2017-03-16T11:20:56.404543+03:00 OAA-54999c4d7735 pgpool[1213]: [25447-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.404612+03:00 OAA-54999c4d7735 pgpool[1213]: [25448-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 1 backend pid: 12520 statement: Parse: select current_schema()
>>> 2017-03-16T11:20:56.404678+03:00 OAA-54999c4d7735 pgpool[1213]: [25448-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.404736+03:00 OAA-54999c4d7735 pgpool[1213]: [25449-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: Parse: select current_schema()
>>> 2017-03-16T11:20:56.404839+03:00 OAA-54999c4d7735 pgpool[1213]: [25449-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.404899+03:00 OAA-54999c4d7735 pgpool[1213]: [25450-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: B message
>>> 2017-03-16T11:20:56.404957+03:00 OAA-54999c4d7735 pgpool[1213]: [25450-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.405013+03:00 OAA-54999c4d7735 pgpool[1213]: [25451-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: D message
>>> 2017-03-16T11:20:56.405069+03:00 OAA-54999c4d7735 pgpool[1213]: [25451-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.405144+03:00 OAA-54999c4d7735 pgpool[1213]: [25452-1] 2017-03-16 11:20:56: pid 1213:LOG: DB node id: 0 backend pid: 1708 statement: Execute: select current_schema()
>>> 2017-03-16T11:20:56.405219+03:00 OAA-54999c4d7735 pgpool[1213]: [25452-2] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_proto_modules.c:3211
>>> 2017-03-16T11:20:56.405282+03:00 OAA-54999c4d7735 pgpool[1213]: [25453-1] 2017-03-16 11:20:56: pid 1213:FATAL: failed to read kind from backend
>>> 2017-03-16T11:20:56.405346+03:00 OAA-54999c4d7735 pgpool[1213]: [25453-2] 2017-03-16 11:20:56: pid 1213:DETAIL: kind mismatch among backends. Possible last query was: "select current_schema()" kind details are: 0[Z] 1[1]
>>> 2017-03-16T11:20:56.405400+03:00 OAA-54999c4d7735 pgpool[1213]: [25453-3] 2017-03-16 11:20:56: pid 1213:HINT: check data consistency among db nodes
>>> 2017-03-16T11:20:56.405483+03:00 OAA-54999c4d7735 pgpool[1213]: [25453-4] 2017-03-16 11:20:56: pid 1213:LOCATION: pool_process_query.c:3731
>>> 2017-03-16T11:20:56.405643+03:00 OAA-54999c4d7735 pgpool[10877]: [22781-1] 2017-03-16 11:20:56: pid 10877:LOG: child process with pid: 1213 exits with status 512
>>>
>>>
>>>
>>> Sergey.
>>> ________________________________
>>> From: Tatsuo Ishii <ishii at sraoss.co.jp>
>>> Sent: Thursday, March 16, 2017 8:29 AM
>>> To: Sergey Kim
>>> Cc: pgpool-hackers at pgpool.net; Boris Voskanov
>>> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>>
>>> Hi Sergey,
>>>
>>> Attached is a patch against master branch as usual.
>>> I also push the changes to the git repository.
>>>
>>> https://git.postgresql.org/gitweb/?p=pgpool2.git;a=shortlog;h=refs/heads/bug271
>>>
>>> When an INSERT is executed in a transaction, a "writing_transaction"
>>> is set. The flag is checked by a succeeding SELECT to decide if
>>> parse_before_bind (which resend the parse message to primary node if
>>> it is executed on the standby) needs to be executed. The flag is
>>> reset when a command complete message for BEGIN is arrived. Problem
>>> is, it is possible that the command complete message could arrive
>>> before the bind for the SELECT is executed, and at this point the flag
>>> is already cleared.
>>>
>>> Solution is, do not reset the flag when the command complete message
>>> arrives if in streaming replication mode.
>>>
>>> I tested using your tool and the test case #231 and #271 have been
>>> passed here.
>>>
>>> Best regards,
>>> --
>>> Tatsuo Ishii
>>> SRA OSS, Inc. Japan
>>> English: http://www.sraoss.co.jp/index_en.php
>>> Japanese:http://www.sraoss.co.jp
>>>
>>>> Tatsuo,
>>>>
>>>> I have updated the test tool:
>>>>
>>>>
>>>> There is the 'target' folder in the attached tarball (and source codes). The folder contains jar file that implements tests for #231 & #271 issues.
>>>>
>>>> please run it as:
>>>> # java -jar target/tests-1.0-SNAPSHOT-jar-with-dependencies.jar PGPOOL_HOST PGPOOL_PORT DB_NAME DB_USER DB_PASSWORD 271
>>>>
>>>> '271' here means the ID of the test to run, currently there are 2 IDs possible - 231 & 271. Each test launched for 1000 times. This is the code level constant so far.
>>>>
>>>> For example launch for the test 271 on the HEAD of bug271 git branch ends with error:
>>>> [skim at localhost pgpool]$ java -jar target/tests-1.0-SNAPSHOT-jar-with-dependencies.jar 10.28.64.176 5432 oss oss WfovD22ufP78Wq 271
>>>> Test iteration '0'
>>>> Test iteration '1'
>>>> Exception in thread "main" java.lang.RuntimeException: Balanced
>>>> at com.pgpool.tests.Issue271_SingleThread.runTest(Issue271_SingleThread.java:52)
>>>> at com.pgpool.tests.TestStarter.main(TestStarter.java:44)
>>>> [skim at localhost pgpool]$ echo $?
>>>> 1
>>>>
>>>> And the following pgpool log is generated (syslog):
>>>>
>>>> 2017-03-14T20:44:09.859057+03:00 OAA-54999c4d7735 pgpool[1041]: [129385-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: Parse: BEGIN
>>>> 2017-03-14T20:44:09.859206+03:00 OAA-54999c4d7735 pgpool[1041]: [129385-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.859385+03:00 OAA-54999c4d7735 pgpool[1041]: [129386-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: Parse: BEGIN
>>>> 2017-03-14T20:44:09.859558+03:00 OAA-54999c4d7735 pgpool[1041]: [129386-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.859702+03:00 OAA-54999c4d7735 pgpool[1041]: [129387-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: B message
>>>> 2017-03-14T20:44:09.859856+03:00 OAA-54999c4d7735 pgpool[1041]: [129387-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.860000+03:00 OAA-54999c4d7735 pgpool[1041]: [129388-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: B message
>>>> 2017-03-14T20:44:09.860158+03:00 OAA-54999c4d7735 pgpool[1041]: [129388-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.860323+03:00 OAA-54999c4d7735 pgpool[1041]: [129389-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: Execute: BEGIN
>>>> 2017-03-14T20:44:09.860557+03:00 OAA-54999c4d7735 pgpool[1041]: [129389-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.860778+03:00 OAA-54999c4d7735 pgpool[1041]: [129390-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: Execute: BEGIN
>>>> 2017-03-14T20:44:09.860992+03:00 OAA-54999c4d7735 pgpool[1041]: [129390-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.861217+03:00 OAA-54999c4d7735 pgpool[1041]: [129391-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: Parse: insert into write_table(id) values($1)
>>>> 2017-03-14T20:44:09.861423+03:00 OAA-54999c4d7735 pgpool[1041]: [129391-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.861686+03:00 OAA-54999c4d7735 pgpool[1041]: [129392-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: B message
>>>> 2017-03-14T20:44:09.861904+03:00 OAA-54999c4d7735 pgpool[1041]: [129392-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.862148+03:00 OAA-54999c4d7735 pgpool[1041]: [129393-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: D message
>>>> 2017-03-14T20:44:09.862360+03:00 OAA-54999c4d7735 pgpool[1041]: [129393-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.862592+03:00 OAA-54999c4d7735 pgpool[1041]: [129394-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: Execute: insert into write_table(id) values($1)
>>>> 2017-03-14T20:44:09.862826+03:00 OAA-54999c4d7735 pgpool[1041]: [129394-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.863058+03:00 OAA-54999c4d7735 pgpool[1041]: [129395-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: B message
>>>> 2017-03-14T20:44:09.863306+03:00 OAA-54999c4d7735 pgpool[1041]: [129395-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.863502+03:00 OAA-54999c4d7735 pgpool[1041]: [129396-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: Execute: select id from write_table where id = $1
>>>> 2017-03-14T20:44:09.863665+03:00 OAA-54999c4d7735 pgpool[1041]: [129396-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.864601+03:00 OAA-54999c4d7735 pgpool[1041]: [129397-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: ABORT
>>>> 2017-03-14T20:44:09.864761+03:00 OAA-54999c4d7735 pgpool[1041]: [129397-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.864914+03:00 OAA-54999c4d7735 pgpool[1041]: [129398-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: ABORT
>>>> 2017-03-14T20:44:09.865097+03:00 OAA-54999c4d7735 pgpool[1041]: [129398-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.865322+03:00 OAA-54999c4d7735 pgpool[1041]: [129399-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 0 backend pid: 1513 statement: DISCARD ALL
>>>> 2017-03-14T20:44:09.865606+03:00 OAA-54999c4d7735 pgpool[1041]: [129399-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.865844+03:00 OAA-54999c4d7735 pgpool[1041]: [129400-1] 2017-03-14 20:44:09: pid 1041:LOG: DB node id: 1 backend pid: 28847 statement: DISCARD ALL
>>>> 2017-03-14T20:44:09.866101+03:00 OAA-54999c4d7735 pgpool[1041]: [129400-2] 2017-03-14 20:44:09: pid 1041:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T20:44:09.866976+03:00 OAA-54999c4d7735 pgpool[1041]: [129401-1] 2017-03-14 20:44:09: pid 1041:LOG: child exiting, 1 connections reached
>>>> 2017-03-14T20:44:09.867095+03:00 OAA-54999c4d7735 pgpool[1041]: [129401-2] 2017-03-14 20:44:09: pid 1041:LOCATION: child.c:406
>>>>
>>>>
>>>> If you wish I can put the source codes into some git repository.
>>>>
>>>>
>>>> Sergey.
>>>> ________________________________
>>>> From: Sergey Kim
>>>> Sent: Tuesday, March 14, 2017 4:19 PM
>>>> To: Tatsuo Ishii
>>>> Cc: pgpool-hackers at pgpool.net; Boris Voskanov
>>>> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>>>
>>>>
>>>> Tatsuo,
>>>>
>>>>
>>>> this time all previously created tests succeeded but out application failed to start. So we started searching for the problem and could reproduce "balanced select problem". The test can run for minutes before reproduction of the problem (((
>>>>
>>>> I'm not sure if it can help but please pay attention that time lag between insert is select requests is very small.
>>>>
>>>>
>>>> Please see the pgpool logs:
>>>>
>>>> 2017-03-14T16:06:37.889485+03:00 OAA-54999c4d7735 pgpool[25595]: [79-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: B message
>>>> 2017-03-14T16:06:37.889702+03:00 OAA-54999c4d7735 pgpool[25595]: [79-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.889924+03:00 OAA-54999c4d7735 pgpool[25595]: [80-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 1 backend pid: 27691 statement: B message
>>>> 2017-03-14T16:06:37.890090+03:00 OAA-54999c4d7735 pgpool[25595]: [80-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.890248+03:00 OAA-54999c4d7735 pgpool[25595]: [81-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: Execute: BEGIN
>>>> 2017-03-14T16:06:37.890378+03:00 OAA-54999c4d7735 pgpool[25595]: [81-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.890535+03:00 OAA-54999c4d7735 pgpool[25595]: [82-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 1 backend pid: 27691 statement: Execute: BEGIN
>>>> 2017-03-14T16:06:37.890693+03:00 OAA-54999c4d7735 pgpool[25595]: [82-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.890863+03:00 OAA-54999c4d7735 pgpool[25595]: [83-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: Parse: insert into write_table(id) values($1)
>>>> 2017-03-14T16:06:37.891144+03:00 OAA-54999c4d7735 pgpool[25595]: [83-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.891390+03:00 OAA-54999c4d7735 pgpool[25595]: [84-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: B message
>>>> 2017-03-14T16:06:37.891637+03:00 OAA-54999c4d7735 pgpool[25595]: [84-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.891895+03:00 OAA-54999c4d7735 pgpool[25595]: [85-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: D message
>>>> 2017-03-14T16:06:37.892091+03:00 OAA-54999c4d7735 pgpool[25595]: [85-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.892272+03:00 OAA-54999c4d7735 pgpool[25595]: [86-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: Execute: insert into write_table(id) values($1)
>>>> 2017-03-14T16:06:37.892442+03:00 OAA-54999c4d7735 pgpool[25595]: [86-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.892642+03:00 OAA-54999c4d7735 pgpool[25595]: [87-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 1 backend pid: 27691 statement: B message
>>>> 2017-03-14T16:06:37.892828+03:00 OAA-54999c4d7735 pgpool[25595]: [87-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.892998+03:00 OAA-54999c4d7735 pgpool[25595]: [88-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 1 backend pid: 27691 statement: Execute: select id from write_table where id = $1
>>>> 2017-03-14T16:06:37.893187+03:00 OAA-54999c4d7735 pgpool[25595]: [88-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.893359+03:00 OAA-54999c4d7735 pgpool[25595]: [89-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 1 backend pid: 27691 statement: ABORT
>>>> 2017-03-14T16:06:37.893584+03:00 OAA-54999c4d7735 pgpool[25595]: [89-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.893839+03:00 OAA-54999c4d7735 pgpool[25595]: [90-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: ABORT
>>>> 2017-03-14T16:06:37.894039+03:00 OAA-54999c4d7735 pgpool[25595]: [90-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.894220+03:00 OAA-54999c4d7735 pgpool[25595]: [91-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 0 backend pid: 25885 statement: DISCARD ALL
>>>> 2017-03-14T16:06:37.894403+03:00 OAA-54999c4d7735 pgpool[25595]: [91-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.894587+03:00 OAA-54999c4d7735 pgpool[25595]: [92-1] 2017-03-14 16:06:37: pid 25595:LOG: DB node id: 1 backend pid: 27691 statement: DISCARD ALL
>>>> 2017-03-14T16:06:37.894753+03:00 OAA-54999c4d7735 pgpool[25595]: [92-2] 2017-03-14 16:06:37: pid 25595:LOCATION: pool_proto_modules.c:3208
>>>> 2017-03-14T16:06:37.894944+03:00 OAA-54999c4d7735 pgpool[25595]: [93-1] 2017-03-14 16:06:37: pid 25595:LOG: child exiting, 1 connections reached
>>>> 2017-03-14T16:06:37.895079+03:00 OAA-54999c4d7735 pgpool[25595]: [93-2] 2017-03-14 16:06:37: pid 25595:LOCATION: child.c:406
>>>> 2017-03-14T16:06:37.895371+03:00 OAA-54999c4d7735 pgpool[25566]: [47-1] 2017-03-14 16:06:37: pid 25566:LOG: child process with pid: 25595 exits with status 256
>>>> 2017-03-14T16:06:37.895635+03:00 OAA-54999c4d7735 pgpool[25566]: [47-2] 2017-03-14 16:06:37: pid 25566:LOCATION: pgpool_main.c:2380
>>>> 2017-03-14T16:06:37.895943+03:00 OAA-54999c4d7735 pgpool[25566]: [48-1] 2017-03-14 16:06:37: pid 25566:LOG: fork a new child process with pid: 25887
>>>> 2017-03-14T16:06:37.896174+03:00 OAA-54999c4d7735 pgpool[25566]: [48-2] 2017-03-14 16:06:37: pid 25566:LOCATION: pgpool_main.c:2466
>>>>
>>>>
>>>>
>>>> And java client logs:
>>>> 16:06:37.890 (2) simple execute, handler=org.postgresql.jdbc.PgStatement$StatementResultHandler at 689604d9, maxRows=0, fetchSize=0, flags=1
>>>> 16:06:37.890 (2) FE=> Parse(stmt=null,query="BEGIN",oids={})
>>>> 16:06:37.890 (2) FE=> Bind(stmt=null,portal=null)
>>>> 16:06:37.890 (2) FE=> Execute(portal=null,limit=0)
>>>> 16:06:37.890 (2) FE=> Parse(stmt=null,query="insert into write_table(id) values($1)",oids={23})
>>>> 16:06:37.890 (2) FE=> Bind(stmt=null,portal=null,$1=<-613120604>)
>>>> 16:06:37.890 (2) FE=> Describe(portal=null)
>>>> 16:06:37.890 (2) FE=> Execute(portal=null,limit=0)
>>>> 16:06:37.890 (2) FE=> Sync
>>>> 16:06:37.892 (2) <=BE ParseComplete [null]
>>>> 16:06:37.892 (2) <=BE BindComplete [unnamed]
>>>> 16:06:37.892 (2) <=BE CommandStatus(BEGIN)
>>>> 16:06:37.892 (2) <=BE ParseComplete [null]
>>>> 16:06:37.892 (2) <=BE BindComplete [unnamed]
>>>> 16:06:37.892 (2) <=BE NoData
>>>> 16:06:37.892 (2) <=BE CommandStatus(INSERT 0 1)
>>>> 16:06:37.893 (2) <=BE ReadyForQuery(T)
>>>> 16:06:37.893 (2) simple execute, handler=org.postgresql.jdbc.PgStatement$StatementResultHandler at 18078bef, maxRows=0, fetchSize=0, flags=0
>>>> 16:06:37.893 (2) FE=> Bind(stmt=S_1,portal=null,$1=<-613120604>)
>>>> 16:06:37.893 (2) FE=> Execute(portal=null,limit=0)
>>>> 16:06:37.893 (2) FE=> Sync
>>>> 16:06:37.895 (2) <=BE BindComplete [unnamed]
>>>> 16:06:37.895 (2) <=BE CommandStatus(SELECT 0)
>>>> 16:06:37.895 (2) <=BE ReadyForQuery(T)
>>>> 16:06:37.895 (2) FE=> Terminate
>>>> Exception in thread "main" java.lang.RuntimeException: Balanced
>>>> at com.pgpool.tests.Issue271_SingleThread.runTest(Issue271_SingleThread.java:57)
>>>> at com.pgpool.tests.TestStarter.main(TestStarter.java:37)
>>>>
>>>>
>>>> The java test is attached:
>>>>
>>>> P/S:
>>>> Pgpool was build from branch bug271:
>>>> [root at OAA-54999c4d7735 pgpool2]# git log -2
>>>> commit 0955a22fb7f30c5b9c1fabe2873c09246453ee50
>>>> Author: Tatsuo Ishii <ishii at postgresql.org>
>>>> Date: Tue Mar 14 19:03:02 2017 +0900
>>>>
>>>> Fix problem described in [pgpool-hackers: 2125].
>>>>
>>>> Two problems are fixed:
>>>>
>>>> - The writing_transaction flag is not reset at transaction
>>>> committed/aborted. Before it was done in CommandComplete but now it
>>>> is possible that we need to check the flag before a command complete
>>>> message arrives. So at Execute, it is taken care by
>>>> handle_query_context() which used to be a static function in
>>>> CommandComplete.c. Also the session context memory is always cleared
>>>> before start a session context.
>>>>
>>>> - Ready for query Re-sync code path in read_kind_from_backend did not
>>>> work. The pending message corresponding to the ready for query
>>>> message could be a sync message, which does not have query
>>>> context. But before we checked if there's a query context
>>>> exists. The check is bogus and removed.
>>>>
>>>> commit 7c955b2a2dfb77623055b5eae9afe041de3105ee
>>>> Author: Tatsuo Ishii <ishii at postgresql.org>
>>>> Date: Sun Mar 12 10:19:34 2017 +0900
>>>>
>>>> Downgrade 1 more ereport from LOG to DEBUG1.
>>>>
>>>>
>>>>
>>>>
>>>> Sergey
>>>> ________________________________
>>>> From: Tatsuo Ishii <ishii at sraoss.co.jp>
>>>> Sent: Tuesday, March 14, 2017 1:28 PM
>>>> To: Sergey Kim
>>>> Cc: pgpool-hackers at pgpool.net
>>>> Subject: Re: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>>>
>>>> Hi Sergey,
>>>>
>>>> I have created a new branch named "bug271" which has been used to
>>>> develop the patch for bug 271 on private git repository. Now you could
>>>> use either the email attached patches or the branch if it's
>>>> convieninet for you. The branch was created against the master
>>>> branch. I will occasionaly rebase it with the master branch. In the
>>>> near future the branch will be merged into the master branch (and I
>>>> plan to back-patch it to 3.6 stable tree).
>>>>
>>>> Best regards,
>>>> --
>>>> Tatsuo Ishii
>>>> SRA OSS, Inc. Japan
>>>> English: http://www.sraoss.co.jp/index_en.php
>> SRA OSS, Inc. Japan<http://www.sraoss.co.jp/index_en.php>
>> www.sraoss.co.jp<http://www.sraoss.co.jp>
>> We, SRA OSS, Inc., as a total solution supplier of open source software, provide consulting, software support and training services, as well as supply the PostgreSQL ...
>>
>>
>>
>>>> Japanese:http://www.sraoss.co.jp
>>>>
>>>> From: pgpool-committers-bounces at pgpool.net
>>>> Subject: [pgpool-committers: 3836] pgpool: Branch refs/heads/bug271 was created
>>>> Date: Tue, 14 Mar 2017 10:19:33 +0000
>>>> Message-ID: <E1cnjYD-0005zz-GZ at gothos.postgresql.org>
>>>>
>>>>> Branch refs/heads/bug271 was created.
>>>>>
>>>>> View: http://git.postgresql.org/gitweb?p=pgpool2.git;a=shortlog;h=refs/heads/bug271
More information about the pgpool-hackers
mailing list