[pgpool-general: 7448] Re: Supported python async drivers
Anton Melser
anton at transcrob.es
Thu Mar 18 16:30:20 JST 2021
Just checked git, it has been committed to master so I'll be looking
forward to 4.2.3!
Thanks a million!
On Thu, 18 Mar 2021 at 15:27, Anton Melser <anton at transcrob.es> wrote:
> Thanks very much, that indeed looks like it has fixed the problem, though
> I confess that I had extra errors that I don't understand
> ...
> 2021-03-18 14:54:47: pid 32308: LOG: find_primary_node:
> make_persistent_db_connection_noerror failed on node 0
> 2021-03-18 14:54:47: pid 32308: LOCATION: pgpool_main.c:3172
> 2021-03-18 14:54:48: pid 32308: ERROR: authentication failed
> ...
> I don't really understand what or how the modification changes things, and
> adding logging *didn't* make things work with the 4.2.2 I compiled without
> the change.
>
> In any case, without your modification it hangs, with your modification it
> doesn't.
>
> Can you confirm that this is a change you are happy to make in the
> official repo?
>
> Thanks for all your help!
>
> On Thu, 18 Mar 2021 at 13:22, Tatsuo Ishii <ishii at sraoss.co.jp> wrote:
>
>> > Thanks for your help. Unfortunately, while I can install gdb and compile
>> > and install the latest version of pgpool2, I only ever played around
>> with
>> > C/C++ when I was a student and never did any debugging. And that was 20
>> > years ago :-(. I wouldn't even know where to start. I did confirm that
>> > exactly the same behaviour appears with the 4.2.2, at least using the
>> > bitnami docker image (https://hub.docker.com/r/bitnami/pgpool/).
>> >
>> > With gdb (attached to the default 4.1.4 deb version available with
>> Ubuntu
>> > 20.04) I get as far as:
>> >
>> > ...
>> > (No debugging symbols found in /lib/x86_64-linux-gnu/libffi.so.7)
>> > Reading symbols from /lib/x86_64-linux-gnu/libnss_files.so.2...
>> > Reading symbols from
>> > /usr/lib/debug//lib/x86_64-linux-gnu/libnss_files-2.31.so...
>> > 0x00007397a9a1e0da in __GI___select (nfds=7, readfds=0x7fffa0c1f3d0,
>> > writefds=0x0, exceptfds=0x0, timeout=0x7fffa0c1f4c0)
>> > at ../sysdeps/unix/sysv/linux/select.c:41
>> > 41 ../sysdeps/unix/sysv/linux/select.c: No such file or directory.
>> > (gdb)
>> >
>> > But then I really have no idea where to even start. Is there anything
>> > particular I could be executing? Might this be a debian issue (the
>> bitnami
>> > images are debian based and so are all the machines I'm testing on).
>>
>> I was expecting you to execute "bt" command of gdb, which prints
>> backtrace of the program.
>>
>> Anyway, I think I found possible cause of the problem. While looking at:
>> https://github.com/MagicStack/asyncpg/issues/573
>>
>> I noticed otsuka's message on 17 May 2020:
>>
>> ------------------------------------------------------------------------------------------------
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG: new
>> connection received
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: DETAIL:
>> connecting host=192.168.34.1 port=51064
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG: md5
>> authentication successful with frontend
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:
>> Parse message from frontend.
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: DETAIL:
>> statement: "__asyncpg_stmt_1__", query: "SELECT 1 WHERE 2 > $1"
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG: DB
>> node id: 0 backend pid: 22328 statement: SELECT version()
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:
>> pool_reuse_block: blockid: 0
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: CONTEXT:
>> while searching system catalog, When relcache is missed
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG: DB
>> node id: 0 backend pid: 22328 statement: Parse: SELECT 1 WHERE 2 > $1
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:
>> Describe message from frontend.
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: DETAIL:
>> statement: "__asyncpg_stmt_1__"
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG: DB
>> node id: 0 backend pid: 22328 statement: D message
>> May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:
>> Flush message from frontend.
>>
>> (Hangs here)
>>
>> ------------------------------------------------------------------------------------------------
>>
>> > May 17 14:26:16 pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:
>> Flush message from frontend.
>>
>> This is interesting since my python program produced "Sync" message,
>> rather than "Flush" message.
>> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Sync message from
>> frontend.
>>
>> So I decided to try to reproduce the problem by using "pgproto" which
>> can send arbitrary message packets to Pgpool-II (or PostgreSQL), and I
>> confirmed that the problem only occurs when "Flush" message is used,
>> but does not occur when "Sync" message is used.
>>
>> Also I guess certain version of asycpg uses "Flush" message (in the
>> case of github issues), while other version of asyncpg uses "Sync"
>> message (in my case).
>>
>> Can you please check your asyncpg uses "Flush" or "Sync" message?
>> (that is possible by enabling log_client_message). If it uses "Flush",
>> attached patch should fix the problem.
>>
>> > On Thu, 18 Mar 2021 at 08:34, Tatsuo Ishii <ishii at sraoss.co.jp>
>> wrote:
>> >
>> >> > Ok, so I was able to get it to work... I thought - why don't I
>> activate
>> >> > logging to see what is happening? And of course it then promptly
>> started
>> >> to
>> >> > work :-).
>> >> >
>> >> > If I set `log_client_messages = on` and `client_min_messages = log`
>> >> (where
>> >> > it has to be *at least* log - notice level doesn't work, all the
>> debugX
>> >> > do). then the asyncpg works fine.
>> >> >
>> >> > Interesting! Any ideas what might be going on?
>> >>
>> >> No idea but I suspect the problem might be triggered by timing: with
>> >> logging, pgpool is somewhat slow down and may not trigger the problem.
>> >> It would be helpful if you attach gdb to hang pgpool process and
>> >> examine the process.
>> >>
>> >> > Thanks again
>> >> >
>> >> > On Wed, 17 Mar 2021 at 23:09, Anton Melser <anton at transcrob.es>
>> wrote:
>> >> >
>> >> >> So I was able to reproduce with just plain pgpool2 on my laptop. I
>> have
>> >> a
>> >> >> WSL2 Ubuntu with postgresql 13 installed from the official
>> Postgresql
>> >> PPA,
>> >> >> and pgpool2 4.1.4 installed from the same.
>> >> >>
>> >> >> The postgresql 13 is on port 5433, the pgpool2 on 5434.
>> >> >>
>> >> >> I kept all default configurations, except for the host0 datadir. If
>> I
>> >> use
>> >> >> psql, I can perform the same query with no problem:
>> >> >>
>> >> >> (broadcaster) anton at dwin:~/dev/tc/transcrobes$ PGPASSWORD=transpass
>> >> psql
>> >> >> -U postgres -h 127.0.0.1 -p 5433 -c 'select username from auth_user
>> >> where
>> >> >> id = 10' transcrobes
>> >> >> Pager usage is off.
>> >> >> username
>> >> >> ----------
>> >> >> user5
>> >> >> (1 row)
>> >> >>
>> >> >> (broadcaster) anton at dwin:~/dev/tc/transcrobes$ PGPASSWORD=transpass
>> >> psql
>> >> >> -U postgres -h 127.0.0.1 -p 5434 -c 'select username from auth_user
>> >> where
>> >> >> id = 10' transcrobes
>> >> >> Pager usage is off.
>> >> >> username
>> >> >> ----------
>> >> >> user5
>> >> >> (1 row)
>> >> >>
>> >> >> But with the following python+asyncpg, it only works when pointing
>> >> >> directly at the postgresql
>> >> >> ````
>> >> >> import sys
>> >> >> import asyncio
>> >> >> import asyncpg
>> >> >>
>> >> >> async def run(host, port):
>> >> >> conn = await asyncpg.connect(user='postgres',
>> password='transpass',
>> >> >> database='transcrobes', host=host,
>> >> >> port=port)
>> >> >> values = await conn.fetch(
>> >> >> 'SELECT username FROM auth_user WHERE id = $1',
>> >> >> 10,
>> >> >> )
>> >> >> await conn.close()
>> >> >> print(values)
>> >> >>
>> >> >> loop = asyncio.get_event_loop()
>> >> >> print(sys.argv)
>> >> >> loop.run_until_complete(run(sys.argv[1], sys.argv[2]))
>> >> >> ````
>> >> >>
>> >> >> (broadcaster) anton at dwin:~/dev/tc/transcrobes$ python
>> >> tmp/asyncpgtest2.py
>> >> >> 127.0.0.1 5433
>> >> >> ['tmp/asyncpgtest2.py', '127.0.0.1', '5433']
>> >> >> [<Record username='user5'>]
>> >> >> (broadcaster) anton at dwin:~/dev/tc/transcrobes$ python
>> >> tmp/asyncpgtest2.py
>> >> >> 127.0.0.1 5434
>> >> >> ['tmp/asyncpgtest2.py', '127.0.0.1', '5434']
>> >> >> !!! Here hangs and doesn't return !!!
>> >> >>
>> >> >> It looks like your attached script was removed by the list software,
>> >> could
>> >> >> you send the text in the body so I can try out on my end? Others
>> also
>> >> >> mentioned fetching/select queries in the ticket I referred to above.
>> >> >>
>> >> >> Thanks!
>> >> >>
>> >> >> On Wed, 17 Mar 2021 at 22:27, Anton Melser <anton at transcrob.es>
>> wrote:
>> >> >>
>> >> >>> Thanks very much for investigating that!. I experienced something
>> very
>> >> >>> similar to https://github.com/MagicStack/asyncpg/issues/573,
>> which was
>> >> >>> also experienced by a few others. I will try and set up a basic
>> >> >>> reproduction use case. I will note that it does appear that *all*
>> of
>> >> us are
>> >> >>> using the Bitnami postgresql-ha images/helm chart... So it may
>> >> actually be
>> >> >>> a special config they use, or possibly related to having it in a
>> docker
>> >> >>> image... I'll investigate further and report back.
>> >> >>>
>> >> >>> Thanks again for your quick reply on this!
>> >> >>>
>> >> >>> On Wed, 17 Mar 2021 at 21:20, Tatsuo Ishii <ishii at sraoss.co.jp>
>> wrote:
>> >> >>>
>> >> >>>> >> Hi,
>> >> >>>> >>
>> >> >>>> >> I am using pgpool2 for failover (and maybe later load
>> balancing,
>> >> it's
>> >> >>>> a
>> >> >>>> >> long story...) and am starting to migrate some of my code to
>> use
>> >> >>>> async.
>> >> >>>> >> Many async projects that support postgres I have seen do so via
>> >> >>>> asyncpg.
>> >> >>>> >> asyncpg doesn't seem to work at all with pgpool2 (at least
>> with my
>> >> >>>> current
>> >> >>>> >> pgpool config, which works perfectly synchronously with
>> psycopg2).
>> >> >>>> Basic
>> >> >>>> >> initial testing suggests aiopg does support pgpool2, at least
>> for
>> >> >>>> what I
>> >> >>>> >> tested it with. This is probably because it is based on
>> >> >>>> psycopg2-binary.
>> >> >>>> >>
>> >> >>>> >> Unfortunately almost all of the projects I have been looking at
>> >> using
>> >> >>>> that
>> >> >>>> >> require async postgres only support asyncpg (Broadcaster,
>> >> >>>> TortoiseORM,...),
>> >> >>>> >> not aiopg.
>> >> >>>> >>
>> >> >>>> >> Is there an officially supported async driver for python? Is
>> one
>> >> >>>> planned?
>> >> >>>> >
>> >> >>>> > I am not familiar with "async" nor "asyncpg". To understand what
>> >> they
>> >> >>>> > are doing, it would be helpful to config Pgpool-II with
>> >> >>>> > log_client_messages = on and share the pgpool log.
>> >> >>>>
>> >> >>>> I have tried with asyncpg myself. (see attached python
>> >> >>>> program. Forgive me if there's something wrong. This is my first
>> >> >>>> python script:-) With log_client_messages = on, and
>> log_connections =
>> >> >>>> on it seems Pgpool-II works fine.
>> >> >>>>
>> >> >>>> 2021-03-17 22:15:33: child pid 28311: LOG: new connection
>> received
>> >> >>>> 2021-03-17 22:15:33: child pid 28311: DETAIL: connecting
>> >> host=127.0.0.1
>> >> >>>> port=33452
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Parse message from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: DETAIL: statement:
>> >> >>>> "__asyncpg_stmt_1__", query: "SELECT 1;"
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 0
>> backend
>> >> >>>> pid: 28670 statement: SELECT version()
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 2
>> backend
>> >> >>>> pid: 28669 statement: Parse: SELECT 1;
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Describe message
>> from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: DETAIL: statement:
>> >> >>>> "__asyncpg_stmt_1__"
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 2
>> backend
>> >> >>>> pid: 28669 statement: D message
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Sync message from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Bind message from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: DETAIL: portal: "",
>> >> >>>> statement: "__asyncpg_stmt_1__"
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 2
>> backend
>> >> >>>> pid: 28669 statement: Bind: SELECT 1;
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Execute message
>> from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: DETAIL: portal: ""
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 2
>> backend
>> >> >>>> pid: 28669 statement: Execute: SELECT 1;
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Sync message from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: Terminate message
>> from
>> >> >>>> frontend.
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 0
>> backend
>> >> >>>> pid: 28670 statement: DISCARD ALL
>> >> >>>> 2021-03-17 22:15:33: [unknown] pid 28311: LOG: DB node id: 2
>> backend
>> >> >>>> pid: 28669 statement: DISCARD ALL
>> >> >>>>
>> >> >>>> Best regards,
>> >> >>>> --
>> >> >>>> Tatsuo Ishii
>> >> >>>> SRA OSS, Inc. Japan
>> >> >>>> English: http://www.sraoss.co.jp/index_en.php
>> >> >>>> Japanese:http://www.sraoss.co.jp
>> >> >>>>
>> >> >>>
>> >>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.pgpool.net/pipermail/pgpool-general/attachments/20210318/3766e4e7/attachment-0001.htm>
More information about the pgpool-general
mailing list