Re: Pgbouncer and postgres

Fabio Pardi <f.pardi@xxxxxxxxxxxx> · Wed, 19 Sep 2018 16:07:02 +0200



    On 19/09/18 15:34, Adrian Klaver wrote:

    
    On
      9/19/18 5:40 AM, ncontu wrote:
      

      Hi Fabio,
        

        It used to work before, even without installing updates.
        

      Exactly, the suspicion is that something in the updates changed
      the behavior of your system.
      

    Yes, that's the suspicion. Or at least was..

    
    I tried to update all the available packages available as of today
    for Centos7-OS and Centos7-updates hosted at:

    
    http://ftp.nluug.nl/ftp/pub/os/Linux/distr/CentOS/7/os/x86_64

    
    and

    
    http://ftp.nluug.nl/ftp/pub/os/Linux/distr/CentOS/7/updates/x86_64/
    

    With an up to date system, I m still able to use pgbouncer.

    
    For the records, I m also posting the log lines showing up when
    pgbouncer is asked to start:

    
    2018-09-19 15:49:42.574 9979 DEBUG parse_ini_file: 'verbose' = '3'
    ok:1

    2018-09-19 15:49:42.575 9979 DEBUG loading auth_file:
    "/etc/pgbouncer/users.txt"

    2018-09-19 15:49:42.576 9979 NOISE event: 136, SBuf: 200, PgSocket:
    408, IOBuf: 4108

    2018-09-19 15:49:42.577 9979 LOG File descriptor limit: 1024
    (H:4096), max_client_conn: 100, max fds possible: 140

    2018-09-19 15:49:42.577 9979 DEBUG pktbuf_dynamic(128): 0x82a790

    2018-09-19 15:49:42.577 9979 DEBUG make_room(0x82a790, 4): realloc
    newlen=256

    2018-09-19 15:49:42.577 9979 DEBUG pktbuf_dynamic(128): 0x82a970

    2018-09-19 15:49:42.577 9979 NOISE connect(4,
    unix:/tmp/.s.PGSQL.6543) = No such file or directory

    2018-09-19 15:49:42.577 9979 NOISE safe_close(4) = 0

    2018-09-19 15:49:42.578 9981 DEBUG adns_create_context: c-ares
    1.10.0

    2018-09-19 15:49:42.578 9981 DEBUG add_listen: 0.0.0.0:6543

    2018-09-19 15:49:42.578 9981 NOISE old TCP_DEFER_ACCEPT on 7 = 0

    2018-09-19 15:49:42.578 9981 NOISE install TCP_DEFER_ACCEPT on 7

    2018-09-19 15:49:42.578 9981 LOG listening on 0.0.0.0:6543

    2018-09-19 15:49:42.578 9981 DEBUG add_listen: ::/6543

    2018-09-19 15:49:42.578 9981 NOISE old TCP_DEFER_ACCEPT on 8 = 0

    2018-09-19 15:49:42.578 9981 NOISE install TCP_DEFER_ACCEPT on 8

    2018-09-19 15:49:42.578 9981 LOG listening on ::/6543

    2018-09-19 15:49:42.578 9981 DEBUG add_listen:
    unix:/tmp/.s.PGSQL.6543

    2018-09-19 15:49:42.579 9981 LOG listening on
    unix:/tmp/.s.PGSQL.6543

    2018-09-19 15:49:42.579 9981 LOG process up: pgbouncer 1.8.1,
    libevent 2.0.21-stable (epoll), adns: c-ares 1.10.0, tls: OpenSSL
    1.0.2k-fips  26 Jan 2017

    
    and this part shows up when the user connects:

    
    psql -h /tmp -p 6543 -U someuser mydb

    
    2018-09-19 16:02:12.125 10457 NOISE C-0x1391120:
    (nodb)/(nouser)@unix(10465):6543 pkt='!' len=77

    2018-09-19 16:02:12.125 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10465):6543 got var: user=someuser

    2018-09-19 16:02:12.125 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10465):6543 got var: database=mydb

    2018-09-19 16:02:12.125 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10465):6543 using application_name: psql

    2018-09-19 16:02:12.125 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10465):6543 got var: client_encoding=UTF8

    2018-09-19 16:02:12.125 10457 NOISE safe_send(10, 13) = 13

    2018-09-19 16:02:12.125 10457 NOISE resync: done=77, parse=77,
    recv=77

    2018-09-19 16:02:12.125 10457 NOISE resync: done=0, parse=0, recv=0

    2018-09-19 16:02:12.125 10457 NOISE safe_recv(10, 4096) = 0

    2018-09-19 16:02:12.126 10457 NOISE safe_close(10) = 0

    2018-09-19 16:02:19.094 10457 NOISE safe_accept(9) = 10 (unix:)

    2018-09-19 16:02:19.094 10457 NOISE new fd from accept=10

    2018-09-19 16:02:19.094 10457 NOISE unix peer uid: 0

    2018-09-19 16:02:19.094 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10470):6543 P: got connection: unix->unix

    2018-09-19 16:02:19.094 10457 NOISE safe_accept(9) = Resource
    temporarily unavailable

    2018-09-19 16:02:19.094 10457 NOISE resync: done=0, parse=0, recv=0

    2018-09-19 16:02:19.094 10457 NOISE safe_recv(10, 4096) = 77

    2018-09-19 16:02:19.094 10457 NOISE C-0x1391120:
    (nodb)/(nouser)@unix(10470):6543 pkt='!' len=77

    2018-09-19 16:02:19.094 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10470):6543 got var: user=someuser

    2018-09-19 16:02:19.094 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10470):6543 got var: database=mydb

    2018-09-19 16:02:19.094 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10470):6543 using application_name: psql

    2018-09-19 16:02:19.094 10457 DEBUG C-0x1391120:
    (nodb)/(nouser)@unix(10470):6543 got var: client_encoding=UTF8

    2018-09-19 16:02:19.094 10457 NOISE safe_send(10, 13) = 13

    2018-09-19 16:02:19.094 10457 NOISE resync: done=77, parse=77,
    recv=77

    2018-09-19 16:02:19.094 10457 NOISE resync: done=0, parse=0, recv=0

    2018-09-19 16:02:19.094 10457 NOISE safe_recv(10, 4096) = 0

    2018-09-19 16:02:19.095 10457 NOISE safe_close(10) = 0

    
    after providing the password, connection works as usual. 

    
    As mentioned earlier by Adrian, the offending line is probably:

    
    2018-09-17
      12:21:48.917 88424 WARNING tune_socket(13) failed: Operation not
      supported
    

        I tried installing it from source, from git repo. Can't find the
        RPM, do you
        

        have any link for centos7?
        

      I believe Fabio is talking about the Postgres community repo:
      

      https://yum.postgresql.org/
      

    I m pointing to: 

    
    https://yum.postgresql.org/9.6/redhat/rhel-7-x86_64/

    
    At the time of writing 1.9.0 is available, while the mirror i have
    in house (and i m pointing to) only has 1.8.1

    
    This
      would be a repo change if you are currently using the CentOS
      repos.