postgresqldockerdocker-composepsqlguacamole

Docker postgres 12 and guacamole error "incomplete message from client"

Im using docker 20.10.9 on ubuntu18, i have compose project with guacamole and guacd 1.3 with postgres 12.3 , out of the blue with no changes on the containers or host my guacamole stopped working and i have these error messages:

postgres_gqm_1    | 2022-01-13T19:32:24.187916615Z 2022-01-13 19:32:24.187 UTC [4394] LOG:  incomplete message from client

guacamole_1       | 2022-01-13T19:32:24.214231454Z 19:32:24.214 [http-nio-8080-exec-6] ERROR o.a.g.rest.RESTExceptionMapper - Unexpected internal error:
guacamole_1       | 2022-01-13T19:32:24.214398980Z ### Error rolling back transaction.  Cause: org.postgresql.util.PSQLException: This connection has been closed.
guacamole_1       | 2022-01-13T19:32:24.214445260Z ### Cause: org.postgresql.util.PSQLException: This connection has been closed.
guacamole_1       | 2022-01-13T19:32:24.496644124Z 19:32:24.496 [http-nio-8080-exec-1] INFO  o.a.g.r.auth.AuthenticationService - User "guacadmin" successful

from guacamole team they said "You need to check your PostgreSQL DB server and make sure it is healthy - for some reason rejecting requests from the the Guacamole Client system, which is what is causing the error you're seeing."

I didnt make any changes and i can log in to the DB and the container is healthy this is the docker network:

br-f326529eaab0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 172.18.0.1  netmask 255.255.0.0  broadcast 172.18.255.255
        inet6 fe80::42:38ff:fedb:b859  prefixlen 64  scopeid 0x20<link>
        ether 02:42:38:db:b8:59  txqueuelen 0  (Ethernet)
        RX packets 41155862  bytes 21949886776 (21.9 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 41787311  bytes 104021450183 (104.0 GB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

docker0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet 172.17.0.1  netmask 255.255.0.0  broadcast 172.17.255.255
        ether 02:42:38:c8:46:85  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

I don't have high cpu \disk space problems \ i checked for query's running on the psql and all looks ok and there are some query's that run there from guacamole and go through fine, is there any way to get more info from psql to see what is the issue? or any other idea i can check?

also try restart all docker + docker service + rebooted the server

from compose:

postgres_gqm:
        image: postgres:12.3
        environment:
              PGDATA: /var/lib/postgresql/data/guacamole
              POSTGRES_DB: db
              POSTGRES_PASSWORD: XXX
              POSTGRES_USER: user
        restart: always
        volumes:
              - ./init:/docker-entrypoint-initdb.d:ro
              - ./data:/var/lib/postgresql/data:rw
        logging:
              driver: "json-file"
              options:
                    max-size: "750m"

no special psql conf files

postgres logs from container:

postgres_gqm_1    | 2022-01-13T12:00:50.261340648Z
postgres_gqm_1    | 2022-01-13T12:00:50.261369022Z PostgreSQL Database directory appears to contain a database; Skipping initialization
postgres_gqm_1    | 2022-01-13T12:00:50.261372995Z
postgres_gqm_1    | 2022-01-13T12:00:50.279414293Z 2022-01-13 12:00:50.276 UTC [1] LOG:  starting PostgreSQL 12.3 (Debian 12.3-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
postgres_gqm_1    | 2022-01-13T12:00:50.279436073Z 2022-01-13 12:00:50.276 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
postgres_gqm_1    | 2022-01-13T12:00:50.279439637Z 2022-01-13 12:00:50.276 UTC [1] LOG:  listening on IPv6 address "::", port 5432
postgres_gqm_1    | 2022-01-13T12:00:50.283140828Z 2022-01-13 12:00:50.283 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
postgres_gqm_1    | 2022-01-13T12:00:50.299483405Z 2022-01-13 12:00:50.299 UTC [27] LOG:  database system was shut down at 2022-01-13 11:50:48 UTC
postgres_gqm_1    | 2022-01-13T12:00:50.308479194Z 2022-01-13 12:00:50.308 UTC [1] LOG:  database system is ready to accept connections
postgres_gqm_1    | 2022-01-13T12:13:37.071961111Z 2022-01-13 12:13:37.071 UTC [50] LOG:  incomplete message from client
postgres_gqm_1    | 2022-01-13T12:16:36.454145261Z 2022-01-13 12:16:36.453 UTC [34] LOG:  incomplete message from client
postgres_gqm_1    | 2022-01-13T13:22:07.250077256Z 2022-01-13 13:22:07.249 UTC [36] LOG:  incomplete message from client
postgres_gqm_1    | 2022-01-13T17:35:23.387228077Z 2022-01-13 17:35:23.386 UTC [4073] LOG:  incomplete message from client
postgres_gqm_1    | 2022-01-13T19:32:24.187916615Z 2022-01-13 19:32:24.187 UTC [4394] LOG:  incomplete message from client

Thanks.

Solution

  • Solved it by starting the postgres guacamole with clean db by

    mv data data_back
mkdir data

    then i restarted docker compose

    docker-compose down
docker-compose up -d

    and then i made a script to copy all active connections from my regular DB to guacamole using API request and it copied all 550 machines. now it all works fine, it seems like DB corruption.