Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

List Collections Bug #65

Open
intelligencecompany opened this issue Feb 17, 2025 · 5 comments
Open

List Collections Bug #65

intelligencecompany opened this issue Feb 17, 2025 · 5 comments
Assignees
@diipak-bisht
Labels
bug Something isn't working

Comments

@intelligencecompany
Copy link

SELECT cursorpage FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');

disconnects the server after creating a collection.

SELECT documentdb_api.create_collection('documentdb', 'patient')

ERROR:
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
The connection to the server was lost. Attempting reset: Failed.
@intelligencecompany intelligencecompany added the bug Something isn't working label Feb 17, 2025
@diipak-bisht diipak-bisht self-assigned this Feb 18, 2025
@diipak-bisht
Copy link
Contributor

Hi @intelligencecompany , can you share the repro steps for this please? I tried the above commands in all different orders and looks like they are returning the expected output.

postgres=# SELECT documentdb_api.create_collection('documentdb', 'patient');
NOTICE:  creating collection
 create_collection 
-------------------
 t
(1 row)

postgres=# SELECT cursorpage FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
                                                                                                                                                                                         
                             cursorpage                                                                                                                                                  
                                                                     
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------
 { "cursor" : { "id" : { "$numberLong" : "0" }, "ns" : "documentdb.$cmd.ListCollections", "firstBatch" : [ { "name" : "patient", "type" : "collection", "options" : {  }, "info" : { "rea
dOnly" : false, "uuid" : { "$binary" : { "base64" : "ulhZWb+RR/qT1s6zxohDCQ==", "subType" : "04" } } }, "idIndex" : { "v" : { "$numberInt" : "2" }, "name" : "_id_", "key" : { "_id" : { 
"$numberInt" : "1" } } } } ] }, "ok" : { "$numberDouble" : "1.0" } }
(1 row)

Similarly the other way round

postgres=# SELECT cursorpage FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
                                                                      cursorpage                                                                      
------------------------------------------------------------------------------------------------------------------------------------------------------
 { "cursor" : { "id" : { "$numberLong" : "0" }, "ns" : "documentdb.$cmd.ListCollections", "firstBatch" : [  ] }, "ok" : { "$numberDouble" : "1.0" } }
(1 row)

postgres=# SELECT documentdb_api.create_collection('documentdb', 'patient');
NOTICE:  creating collection
 create_collection 
-------------------
 t
(1 row)

postgres=# SELECT cursorpage FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
                                                                                                                                                                                         
                             cursorpage                                                                                                                                                  
                                                                     
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------
 { "cursor" : { "id" : { "$numberLong" : "0" }, "ns" : "documentdb.$cmd.ListCollections", "firstBatch" : [ { "name" : "patient", "type" : "collection", "options" : {  }, "info" : { "rea
dOnly" : false, "uuid" : { "$binary" : { "base64" : "pnItZe2SR6+M5dOrO8P5gw==", "subType" : "04" } } }, "idIndex" : { "v" : { "$numberInt" : "2" }, "name" : "_id_", "key" : { "_id" : { 
"$numberInt" : "1" } } } } ] }, "ok" : { "$numberDouble" : "1.0" } }
(1 row)

@intelligencecompany
Copy link
Author

intelligencecompany commented Feb 19, 2025 •
edited
Loading

Hi @diipak-bisht,

Thank you for investigating. I did a clean install and tried it again, however I keep having that the connection closes.

CREATE EXTENSION
  oid  |  extname   | extowner | extnamespace | extrelocatable | extversion | extconfig | extcondition
-------+------------+----------+--------------+----------------+------------+-----------+--------------
 18551 | documentdb |       10 |         2200 | f              | 0.102-0    |           |
(1 row)

documentdb@b33cb046e3fe:~/code$ psql -p 9712 -d postgres
SET
SET
psql (16.2)
Type "help" for help.

postgres=# SELECT * FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
                                                                      cursorpage
                              | continuation | persistconnection | cursorid
------------------------------------------------------------------------------------------------------------------------
------------------------------+--------------+-------------------+----------
 { "cursor" : { "id" : { "$numberLong" : "0" }, "ns" : "documentdb.$cmd.ListCollections", "firstBatch" : [  ] }, "ok" :
{ "$numberDouble" : "1.0" } } |              | f                 |        0
(1 row)

postgres=# SELECT documentdb_api.create_collection('documentdb', 'patient');
NOTICE:  creating collection
 create_collection
-------------------
 t
(1 row)

postgres=# SELECT * FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
The connection to the server was lost. Attempting reset: Failed.
!?>

I pulled the latest version from github
Run it in a docker container, using docker desktop on Windows

@diipak-bisht
Copy link
Contributor

I created a whole new github workspace but still couldn't get this.

Can you help share any error logs that you see in pg log file which should be around this path /home/documentdb/documentdb_test/pglog.log

@intelligencecompany
Copy link
Author

Sure, see here the log after executing the query:

2025-02-25 18:46:31.762 UTC [44] LOG: server process (PID 584) was terminated by signal 11: Segmentation fault
2025-02-25 18:46:31.762 UTC [44] DETAIL: Failed process was running: SELECT * FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
2025-02-25 18:46:31.762 UTC [44] LOG: terminating any other active server processes
2025-02-25 18:46:31.766 UTC [44] LOG: all server processes terminated; reinitializing
2025-02-25 18:46:31.810 UTC [585] LOG: database system was interrupted; last known up at 2025-02-24 16:33:00 UTC
2025-02-25 18:46:32.154 UTC [585] LOG: database system was not properly shut down; automatic recovery in progress
2025-02-25 18:46:32.160 UTC [585] LOG: redo starts at 0/3A29AB0
2025-02-25 18:46:32.160 UTC [585] LOG: invalid record length at 0/3A29B98: expected at least 24, got 0
2025-02-25 18:46:32.160 UTC [585] LOG: redo done at 0/3A29B60 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2025-02-25 18:46:32.164 UTC [586] LOG: checkpoint starting: end-of-recovery immediate wait
2025-02-25 18:46:32.181 UTC [586] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.002 s, total=0.019 s; sync files=2, longest=0.002 s, average=0.001 s; distance=0 kB, estimate=0 kB; lsn=0/3A29B98, redo lsn=0/3A29B98
2025-02-25 18:46:32.185 UTC [44] LOG: database system is ready to accept connections
2025-02-25 18:46:32.211 UTC [590] LOG: pg_cron scheduler started
2025-02-25 18:46:33.925 UTC [44] LOG: server process (PID 593) was terminated by signal 11: Segmentation fault
2025-02-25 18:46:33.925 UTC [44] DETAIL: Failed process was running: SELECT * FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
2025-02-25 18:46:33.925 UTC [44] LOG: terminating any other active server processes
2025-02-25 18:46:33.926 UTC [44] LOG: all server processes terminated; reinitializing
2025-02-25 18:46:33.958 UTC [594] LOG: database system was interrupted; last known up at 2025-02-25 18:46:32 UTC
2025-02-25 18:46:34.301 UTC [594] LOG: database system was not properly shut down; automatic recovery in progress
2025-02-25 18:46:34.305 UTC [594] LOG: invalid record length at 0/3A29C10: expected at least 24, got 0
2025-02-25 18:46:34.306 UTC [594] LOG: redo is not required
2025-02-25 18:46:34.313 UTC [595] LOG: checkpoint starting: end-of-recovery immediate wait
2025-02-25 18:46:34.327 UTC [595] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.002 s, total=0.016 s; sync files=2, longest=0.001 s, average=0.001 s; distance=0 kB, estimate=0 kB; lsn=0/3A29C10, redo lsn=0/3A29C10
2025-02-25 18:46:34.331 UTC [44] LOG: database system is ready to accept connections
2025-02-25 18:46:34.338 UTC [599] LOG: pg_cron scheduler started
2025-02-25 18:46:36.049 UTC [44] LOG: server process (PID 602) was terminated by signal 11: Segmentation fault
2025-02-25 18:46:36.049 UTC [44] DETAIL: Failed process was running: SELECT * FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
2025-02-25 18:46:36.049 UTC [44] LOG: terminating any other active server processes
2025-02-25 18:46:36.050 UTC [44] LOG: all server processes terminated; reinitializing
2025-02-25 18:46:36.078 UTC [603] LOG: database system was interrupted; last known up at 2025-02-25 18:46:34 UTC
2025-02-25 18:46:36.383 UTC [603] LOG: database system was not properly shut down; automatic recovery in progress
2025-02-25 18:46:36.386 UTC [603] LOG: invalid record length at 0/3A29C88: expected at least 24, got 0
2025-02-25 18:46:36.386 UTC [603] LOG: redo is not required
2025-02-25 18:46:36.390 UTC [604] LOG: checkpoint starting: end-of-recovery immediate wait
2025-02-25 18:46:36.403 UTC [604] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.002 s, total=0.014 s; sync files=2, longest=0.001 s, average=0.001 s; distance=0 kB, estimate=0 kB; lsn=0/3A29C88, redo lsn=0/3A29C88
2025-02-25 18:46:36.406 UTC [44] LOG: database system is ready to accept connections
2025-02-25 18:46:36.410 UTC [608] LOG: pg_cron scheduler started
2025-02-25 18:46:38.795 UTC [44] LOG: server process (PID 611) was terminated by signal 11: Segmentation fault
2025-02-25 18:46:38.795 UTC [44] DETAIL: Failed process was running: SELECT * FROM documentdb_api.list_collections_cursor_first_page('documentdb', '{ "listCollections": 1 }');
2025-02-25 18:46:38.795 UTC [44] LOG: terminating any other active server processes
2025-02-25 18:46:38.796 UTC [44] LOG: all server processes terminated; reinitializing
2025-02-25 18:46:38.817 UTC [612] LOG: database system was interrupted; last known up at 2025-02-25 18:46:36 UTC
2025-02-25 18:46:39.272 UTC [612] LOG: database system was not properly shut down; automatic recovery in progress
2025-02-25 18:46:39.275 UTC [612] LOG: invalid record length at 0/3A29D00: expected at least 24, got 0
2025-02-25 18:46:39.275 UTC [612] LOG: redo is not required
2025-02-25 18:46:39.280 UTC [613] LOG: checkpoint starting: end-of-recovery immediate wait
2025-02-25 18:46:39.299 UTC [613] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.002 s, total=0.021 s; sync files=2, longest=0.001 s, average=0.001 s; distance=0 kB, estimate=0 kB; lsn=0/3A29D00, redo lsn=0/3A29D00
2025-02-25 18:46:39.302 UTC [44] LOG: database system is ready to accept connections
2025-02-25 18:46:39.306 UTC [617] LOG: pg_cron scheduler started

Will this help?

@diipak-bisht
Copy link
Contributor

Thanks for sharing the logs, not much debugging information though. Will it be possible for you to share the core dump for further analysis as this is hard to repro in any of my environments. I tried with Docker Desktop too as you mentioned earlier.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@diipak-bisht diipak-bisht

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@intelligencecompany @diipak-bisht