[pgpool-general: 7447] Re: Supported python async drivers
Anton Melser
anton at transcrob.es
Thu Mar 18 16:27:31 JST 2021
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/29d2c3c7/attachment-0001.htm>
More information about the pgpool-general
mailing list