search

ArcadeData / arcadedb

ArcadeDB Multi-Model Database, one DBMS that supports SQL, Cypher, Gremlin, HTTP/JSON, MongoDB and Redis. ArcadeDB is a conceptual fork of OrientDB, the first Multi-Model DBMS. ArcadeDB supports Vector Embeddings.
https://arcadedb.com
Apache License 2.0
498 stars 60 forks source link

Postgres broken with ArcadeDB on Elixir - Cannot connect, Bug Project included #1815

Open jonmdev opened 1 week ago

jonmdev commented 1 week ago

ArcadeDB Version:

24.10.1

OS and JDK Version:

Running on Linux 5.15.153.1-microsoft-standard-WSL2 - OpenJDK 64-Bit Server VM 11.0.24

Expected behavior

Should be able to connect with Postgres in Elixir (it is very much needed).

Actual behavior

On connection attempt, the following error returns in Elixir:

19:08:00.052 [error] Postgrex.Protocol (#PID<0.394.0>) failed to connect: ** 
(Postgrex.Error) ERROR 42601 (syntax_error) Syntax error on executing query: 
Encountered "(" "(" at line 2, column 73.
Was expecting one of:
    <EOF>
    <LIMIT> ...
    <SKIP2> ...
    <OFFSET> ...
    <TIMEOUT> ...
    <AS> ...
    <LET> ...
    <UNWIND> ...
    ";" ...
    "," ...
    ":" ...
    ":" ...
    <AS> ...
    "," ...

BUG PROJECT

https://github.com/jonmdev/postgres_bug

Steps to reproduce

1) Start an Arcade Db system that has a database (eg. mydb) already created on Ubuntu terminal as follows:

bin/server.sh -Darcadedb.server.plugins="Postgres:com.arcadedb.postgres.PostgresProtocolPlugin"

2) Open another terminal on same system to the directory of the bug project (Elixir project) and run mix deps.get to get dependencies, then iex -S mix to start it.

3) See from the Elixir terminal that Postgres does not connect and instead gives the error above.

ELIXIR CODE EXPLANATION

The bug project uses Postgrex which is the primary package for Postgres in Elixir: https://hex.pm/packages/postgrex

Full steps to recreate the bug project (just for reference/understanding of what is in there, many aren't familiar with Elixir):

1) Create empty project:

mix new postgres_bug --sup

2) Add to mix.exs dependency for postgrex under defp deps as {:postgrex, "~> 0.19.2"} 3) Add simple code to lib/postgres_bug/application.ex under start to start the Postgres system and attempt to connect:

 children = [{
            Postgrex,
            hostname: "localhost",
            port: 5432,
            username: "root",
            password: "password",
            database: "mydb"
        }]

        opts = [strategy: :one_for_one, name: My.PostgresSupervisor] # restart options for the supervisor, not relevant
        start_result = Supervisor.start_link(children, opts)  # start the Postgres connection based on tuple configuration above

IO.puts("STARTED POSTGRES WITH STATUS: " <> inspect(start_result))

That is it. That's the whole bug project.

It will keep trying to connect despite the error, and keep reproducing the error repeatedly.

FURTHER INFO

The Postgrex Postgres adapter is explained here: https://hexdocs.pm/postgrex/Postgrex.html#start_link/1

Further parameters that can be added are listed there if needed to the children configuration code above like ssl:false. But this in particular doesn't help as this is already the default. I also tried adding parameters: [{:preferQueryMode, "simple" }] but no help. Perhaps that is not where that would need to go, but we have no other place in Elixir to put it.

INSTALLING ELIXIR

If you don't have it, you will of course need to install Erlang/Elixir. Good thing to have in my opinion. 🙂 Instructions are here: https://elixir-lang.org/install.html

I do this with asdf as follows (these are a copy of my own notes I keep for when I have to install it):

# https://github.com/asdf-vm/asdf-erlang?tab=readme-ov-file#before-asdf-install
# add erlang dependencies as listed above:

apt-get -y install build-essential autoconf m4 libncurses5-dev libwxgtk3.0-gtk3-dev libwxgtk-webview3.0-gtk3-dev libgl1-mesa-dev libglu1-mesa-dev libpng-dev libssh-dev unixodbc-dev xsltproc fop libxml2-utils libncurses-dev openjdk-11-jdk

//===========ERLANG:
asdf plugin add erlang https://github.com/asdf-vm/asdf-erlang.git
asdf install erlang latest

# make global:
erl
asdf global erlang 27.1.1

//===========ELIXIR:
# https://github.com/asdf-vm/asdf-elixir
asdf plugin-add elixir https://github.com/asdf-vm/asdf-elixir.git
asdf install elixir latest
elixir
asdf global elixir 1.17.3-otp-27

You can confirm they are installed by running erl -version & elixir -v

REASON NEEDED

Elixir/Erlang is a top class server system with amazing concurrency and fault tolerance. Arcade is the best DB out there. 🙂 They are a great match. HTTP Request is fine for testing (I added the method examples for Elixir in the Arcade docs here a while back). But we need Postgres for better connection maintenance and safety over HTTP Request in real production.

Thank you very much for any help or solutions.

gramian commented 1 week ago

What are the ArcadeDB logs saying when you connect? This looks like an SQL grammar error(?).

jonmdev commented 1 week ago

Hey @gramian ! Thanks for the quick reply.

On the Arcade end, I am not sure what to make of it. I just get:

# bin/server.sh -Darcadedb.server.databaseDirectory=/usr/local/arcade_db/arcade_data -Darcadedb.server.plugins="Postgres:com.arcadedb.postgres.PostgresProtocolPlugin"

 █████╗ ██████╗  ██████╗ █████╗ ██████╗ ███████╗██████╗ ██████╗
██╔══██╗██╔══██╗██╔════╝██╔══██╗██╔══██╗██╔════╝██╔══██╗██╔══██╗
███████║██████╔╝██║     ███████║██║  ██║█████╗  ██║  ██║██████╔╝
██╔══██║██╔══██╗██║     ██╔══██║██║  ██║██╔══╝  ██║  ██║██╔══██╗
██║  ██║██║  ██║╚██████╗██║  ██║██████╔╝███████╗██████╔╝██████╔╝
╚═╝  ╚═╝╚═╝  ╚═╝ ╚═════╝╚═╝  ╚═╝╚═════╝ ╚══════╝╚═════╝ ╚═════╝
PLAY WITH DATA                                    arcadedb.com

removing old pid file /usr/local/arcade_db/arcadedb-24.10.1/bin/arcadedb.pid

2024-11-05 03:37:23.169 INFO  [ArcadeDBServer] <ArcadeDB_0> ArcadeDB Server v24.10.1 (build ac46a0da6ebe4f5d337e50874f3d8a0d1bf092b1/1728751149872/main) is starting up...
2024-11-05 03:37:23.179 INFO  [ArcadeDBServer] <ArcadeDB_0> Running on Linux 5.15.153.1-microsoft-standard-WSL2 - OpenJDK 64-Bit Server VM 11.0.24
2024-11-05 03:37:23.186 INFO  [ArcadeDBServer] <ArcadeDB_0> Starting ArcadeDB Server in development mode with plugins [Postgres] ...
2024-11-05 03:37:23.187 INFO  [ArcadeDBServer] <ArcadeDB_0> - Metrics Collection Started...WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.arcadedb.engine.PaginatedComponentFile (file:/usr/local/arcade_db/arcadedb-24.10.1/lib/arcadedb-engine-24.10.1.jar) to field java.nio.channels.spi.AbstractInterruptibleChannel.interruptor
WARNING: Please consider reporting this to the maintainers of com.arcadedb.engine.PaginatedComponentFile
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release

2024-11-05 03:37:23.593 INFO  [PostgresNetworkListener] <ArcadeDB_0> Listening for incoming connections on 0.0.0.0:5432 (protocol v.-1)
2024-11-05 03:37:23.594 INFO  [ArcadeDBServer] <ArcadeDB_0> - Postgres plugin started
2024-11-05 03:37:23.595 INFO  [HttpServer] <ArcadeDB_0> - Starting HTTP Server (host=0.0.0.0 port=2480-2489 httpsPort=2490-2499)...
2024-11-05 03:37:23.648 INFO  [undertow] starting server: Undertow - 2.3.17.Final
2024-11-05 03:37:23.658 INFO  [xnio] XNIO version 3.8.16.Final
2024-11-05 03:37:23.667 INFO  [nio] XNIO NIO Implementation Version 3.8.16.Final
2024-11-05 03:37:23.691 INFO  [threads] JBoss Threads version 3.5.0.Final
2024-11-05 03:37:23.732 INFO  [HttpServer] <ArcadeDB_0> - HTTP Server started (host=0.0.0.0 port=2480 httpsPort=2490)
2024-11-05 03:37:23.734 INFO  [ArcadeDBServer] <ArcadeDB_0> Available query languages: [sqlscript, mongo, gremlin, java, cypher, js, graphql, sql]
2024-11-05 03:37:23.736 INFO  [ArcadeDBServer] <ArcadeDB_0> ArcadeDB Server started in 'development' mode (CPUs=8 MAXRAM=7.80GB)
2024-11-05 03:37:23.748 INFO  [ArcadeDBServer] <ArcadeDB_0> Studio web tool available at http://[ip-address]:2480

That is the initial normal start up. It idles there until I try to run the Elixir test project, which then triggers the following:

2024-11-05 03:38:03.707 INFO  [PostgresNetworkExecutor] PSQL: Received cancel request pid 0
2024-11-05 03:38:03.710 INFO  [PostgresNetworkExecutor] PSQL: Canceling session 0Error on reading any message: Socket closed
com.arcadedb.postgres.PostgresProtocolException: Error on reading any message: Socket closed
        at com.arcadedb.postgres.PostgresNetworkExecutor.readMessage(PostgresNetworkExecutor.java:1077)
        at com.arcadedb.postgres.PostgresNetworkExecutor.run(PostgresNetworkExecutor.java:149)
Caused by: java.net.SocketException: Socket closed
        at java.base/java.net.SocketInputStream.socketRead0(Native Method)
        at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
        at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
        at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
        at java.base/java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
        at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:271)
        at java.base/java.io.DataInputStream.readUnsignedByte(DataInputStream.java:293)
        at com.arcadedb.network.binary.ChannelBinary.readUnsignedByte(ChannelBinary.java:64)
        at com.arcadedb.postgres.PostgresNetworkExecutor.readNextByte(PostgresNetworkExecutor.java:1088)
        at com.arcadedb.postgres.PostgresNetworkExecutor.readMessage(PostgresNetworkExecutor.java:1045)
        ... 1 more

2024-11-05 03:38:03.714 SEVER [PostgresNetworkExecutor] PSQL: Closing connection with client

This repeats every time Elixir tries to connect again, as it tries every 1-3 seconds or so repeatedly.

Thanks again for any thoughts or solutions.

jonmdev commented 7 hours ago

I found a thread here: https://github.com/ArcadeData/arcadedb/issues/1525

Which looked like a similar problem perhaps though from Rust where @lvca suggested using

    -Darcadedb.postgres.debug=true

So I tried that, and this is what I got. I am not sure if it is meaningful toward a solution, but I am hopeful that it is. Any thoughts?

2024-11-17 02:12:54.214 INFO  [ArcadeDBServer] <ArcadeDB_0> ArcadeDB Server started in 'development' mode (CPUs=8 MAXRAM=7.80GB)
2024-11-17 02:12:54.232 INFO  [ArcadeDBServer] <ArcadeDB_0> Studio web tool available at http://172.30.97.77:2480
2024-11-17 02:46:37.916 INFO  [PostgresNetworkExecutor] PSQL:-> request for password (R - 8b) (thread=36)
2024-11-17 02:46:38.009 INFO  [PostgresNetworkExecutor] PSQL:-> authentication ok (R - 8b) (thread=36)
2024-11-17 02:46:38.010 INFO  [PostgresNetworkExecutor] PSQL:-> backend key data (K - 12b) (thread=36)
2024-11-17 02:46:38.013 INFO  [PostgresNetworkExecutor] PSQL:-> parameter status (S - 24b) (thread=36)
2024-11-17 02:46:38.014 INFO  [PostgresNetworkExecutor] PSQL:-> parameter status (S - 25b) (thread=36)
2024-11-17 02:46:38.015 INFO  [PostgresNetworkExecutor] PSQL:-> parameter status (S - 25b) (thread=36)
2024-11-17 02:46:38.016 INFO  [PostgresNetworkExecutor] PSQL:-> ready for query (Z - 5b) (thread=36)
2024-11-17 02:46:38.055 INFO  [PostgresNetworkExecutor] PSQL: query -> SELECT t.oid, t.typname, t.typsend, t.typreceive, t.typoutput, t.typinput,
       coalesce(d.typelem, t.typelem), coalesce(r.rngsubtype, 0), ARRAY (
  SELECT a.atttypid
  FROM pg_attribute AS a
  WHERE a.attrelid = t.typrelid AND a.attnum > 0 AND NOT a.attisdropped
  ORDER BY a.attnum
)

FROM pg_type AS t
LEFT JOIN pg_type AS d ON t.typbasetype = d.oid
LEFT JOIN pg_range AS r ON r.rngtypid = t.oid OR (t.typbasetype <> 0 AND r.rngtypid = t.typbasetype)
WHERE (t.typrelid = 0)
AND (t.typelem = 0 OR NOT EXISTS (SELECT 1 FROM pg_catalog.pg_type s WHERE s.typrelid != 0 AND s.oid = t.typelem)) (thread=36)
2024-11-17 02:46:38.142 INFO  [PostgresNetworkExecutor] PSQL:-> ready for query (Z - 5b) (thread=36)
2024-11-17 02:46:38.182 INFO  [PostgresNetworkExecutor] PSQL: Received cancel request pid 0
2024-11-17 02:46:38.184 INFO  [PostgresNetworkExecutor] PSQL: Canceling session 0Error on reading any message: Socket closed
com.arcadedb.postgres.PostgresProtocolException: Error on reading any message: Socket closed
        at com.arcadedb.postgres.PostgresNetworkExecutor.readMessage(PostgresNetworkExecutor.java:1077)
        at com.arcadedb.postgres.PostgresNetworkExecutor.run(PostgresNetworkExecutor.java:149)
Caused by: java.net.SocketException: Socket closed
        at java.base/java.net.SocketInputStream.socketRead0(Native Method)
        at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
        at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
        at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
        at java.base/java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
        at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:271)
        at java.base/java.io.DataInputStream.readUnsignedByte(DataInputStream.java:293)
        at com.arcadedb.network.binary.ChannelBinary.readUnsignedByte(ChannelBinary.java:64)
        at com.arcadedb.postgres.PostgresNetworkExecutor.readNextByte(PostgresNetworkExecutor.java:1088)
        at com.arcadedb.postgres.PostgresNetworkExecutor.readMessage(PostgresNetworkExecutor.java:1045)
        ... 1 more

2024-11-17 02:46:38.188 SEVER [PostgresNetworkExecutor] PSQL: Closing connection with client
2024-11-17 02:46:40.018 INFO  [PostgresNetworkExecutor] PSQL:-> request for password (R - 8b) (thread=39)
2024-11-17 02:46:40.019 INFO  [PostgresNetworkExecutor] PSQL:-> authentication ok (R - 8b) (thread=39)
2024-11-17 02:46:40.019 INFO  [PostgresNetworkExecutor] PSQL:-> backend key data (K - 12b) (thread=39)
2024-11-17 02:46:40.019 INFO  [PostgresNetworkExecutor] PSQL:-> parameter status (S - 24b) (thread=39)
2024-11-17 02:46:40.020 INFO  [PostgresNetworkExecutor] PSQL:-> parameter status (S - 25b) (thread=39)
2024-11-17 02:46:40.020 INFO  [PostgresNetworkExecutor] PSQL:-> parameter status (S - 25b) (thread=39)
2024-11-17 02:46:40.020 INFO  [PostgresNetworkExecutor] PSQL:-> ready for query (Z - 5b) (thread=39)
2024-11-17 02:46:40.020 INFO  [PostgresNetworkExecutor] PSQL: query -> SELECT t.oid, t.typname, t.typsend, t.typreceive, t.typoutput, t.typinput,
       coalesce(d.typelem, t.typelem), coalesce(r.rngsubtype, 0), ARRAY (
  SELECT a.atttypid
  FROM pg_attribute AS a
  WHERE a.attrelid = t.typrelid AND a.attnum > 0 AND NOT a.attisdropped
  ORDER BY a.attnum
)

FROM pg_type AS t
LEFT JOIN pg_type AS d ON t.typbasetype = d.oid
LEFT JOIN pg_range AS r ON r.rngtypid = t.oid OR (t.typbasetype <> 0 AND r.rngtypid = t.typbasetype)
WHERE (t.typrelid = 0)
AND (t.typelem = 0 OR NOT EXISTS (SELECT 1 FROM pg_catalog.pg_type s WHERE s.typrelid != 0 AND s.oid = t.typelem)) (thread=39)
2024-11-17 02:46:40.023 INFO  [PostgresNetworkExecutor] PSQL:-> ready for query (Z - 5b) (thread=39)
2024-11-17 02:46:40.024 INFO  [PostgresNetworkExecutor] PSQL: Received cancel request pid 0
2024-11-17 02:46:40.024 INFO  [PostgresNetworkExecutor] PSQL: Canceling session 0Error on reading any message: Socket closed
com.arcadedb.postgres.PostgresProtocolException: Error on reading any message: Socket closed
        at com.arcadedb.postgres.PostgresNetworkExecutor.readMessage(PostgresNetworkExecutor.java:1077)
        at com.arcadedb.postgres.PostgresNetworkExecutor.run(PostgresNetworkExecutor.java:149)
Caused by: java.net.SocketException: Socket closed
        at java.base/java.net.SocketInputStream.socketRead0(Native Method)
        at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
        at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
        at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
        at java.base/java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
        at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:271)
        at java.base/java.io.DataInputStream.readUnsignedByte(DataInputStream.java:293)
        at com.arcadedb.network.binary.ChannelBinary.readUnsignedByte(ChannelBinary.java:64)
        at com.arcadedb.postgres.PostgresNetworkExecutor.readNextByte(PostgresNetworkExecutor.java:1088)
        at com.arcadedb.postgres.PostgresNetworkExecutor.readMessage(PostgresNetworkExecutor.java:1045)
        ... 1 more

2024-11-17 02:46:40.026 SEVER [PostgresNetworkExecutor] PSQL: Closing connection with client
gramian commented 6 minutes ago

So, this gives a hint. Apparantly the following SQL query is send by the Elixir driver:

SELECT t.oid, t.typname, t.typsend, t.typreceive, t.typoutput, t.typinput,
       coalesce(d.typelem, t.typelem), coalesce(r.rngsubtype, 0), ARRAY (
  SELECT a.atttypid
  FROM pg_attribute AS a
  WHERE a.attrelid = t.typrelid AND a.attnum > 0 AND NOT a.attisdropped
  ORDER BY a.attnum
)

FROM pg_type AS t
LEFT JOIN pg_type AS d ON t.typbasetype = d.oid
LEFT JOIN pg_range AS r ON r.rngtypid = t.oid OR (t.typbasetype <> 0 AND r.rngtypid = t.typbasetype)
WHERE (t.typrelid = 0)
AND (t.typelem = 0 OR NOT EXISTS (SELECT 1 FROM pg_catalog.pg_type s WHERE s.typrelid != 0 AND s.oid = t.typelem))

which uses the Postgres system "tables" pg_attribute, pg_type, pg_range and pg_catalog. I guess this causes the execeptions on the ArcadeDB side, as these don't exist, as well as the JOINs.

Maybe there is a way to use Postgrex without this startup query?