Segmentation Fault in record_repr at asyncpg/protocol/record/recordobj.c:462

[ShahriyarR]

• asyncpg version: 0.22.0
• PostgreSQL version: PostgreSQL 10.16 (Ubuntu 10.16-1.pgdg18.04+1)
• Do you use a PostgreSQL SaaS? If so, which? Can you reproduce
  the issue with a local PostgreSQL install?: Local 10.16
• Python version: 3.9.0+ (heads/3.9:5b1fdcacfc, Oct 18 2020, 00:00:17) \n[GCC 7.5.0]
• Platform: Ubuntu 18.04 (5.4.0-73-generic "RuntimeError: no codec for array element type 17189" with $1::citext[] #82~18.04.1-Ubuntu)
• Do you use pgbouncer?: No
• Did you install asyncpg with pip?: YES
• If you built asyncpg locally, which version of Cython did you use?: No
• Can the issue be reproduced under both asyncio and
  uvloop?: N/D

The reproducible full project code is located here:
https://github.com/ShahriyarR/ecommerce-nuxtjs-fastapi-backend/tree/episode-5

Steps to start:

• clone the branch
• activate python3.9 venv
• do poetry install
• uvicorn backend.app.main:app

NOTE: There is no such issue with Python 3.8, spotted only with 3.9

The pyproject.toml:

[tool.poetry]
name = "backend"
version = "0.1.0"
description = ""
authors = ["Shahriyar Rzayev <rzayev.sehriyar@gmail.com>"]

[tool.poetry.dependencies]
python = "^3.7"
fastapi = "^0.64.0"
gino = {extras = ["pg", "starlette"], version = "^1.0.1"}
uvicorn = "^0.13.4"
gunicorn = "^20.1.0"
alembic = "^1.6.2"
psycopg2 = "^2.8.6"
passlib = {extras = ["bcrypt"], version = "^1.7.4"}
pydantic = {extras = ["dotenv"], version = "^1.8.2"}

[tool.poetry.dev-dependencies]
pytest = "^5.2"
pytest-cov = "^2.10.1"
requests = "^2.25.1"

[build-system]
requires = ["poetry-core>=1.0.0"]
build-backend = "poetry.core.masonry.api"

Basically, I am trying to use FastAPI & Gino to build a simple user registration endpoint.

Start the GDB session:

(gdb) run -X tracemalloc -m uvicorn app.main:app
Starting program: /home/shako/REPOS/Learning_FastAPI/Djackets/.venv/bin/python -X tracemalloc -m uvicorn app.main:app
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
INFO:     Started server process [10345]
INFO:     Waiting for application startup.
[New Thread 0x7fffede85700 (LWP 10346)]
[New Thread 0x7fffed432700 (LWP 10348)]
app started
INFO:     Application startup complete.
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)

Sending POST request:

curl -X POST http://127.0.0.1:8000/users/create -d '{"email": "example@gmail.com", "password": "12345789", "username": "example"}' | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100    77    0     0    0    77      0      0 --:--:--  0:52:57 --:--:--     0

Got the following from gdb side:

email='example@gmail.com' username='example' email_verified=False is_active=True is_superuser=False created_at=datetime.datetime(2021, 5, 16, 12, 38, 11, 847838) updated_at=datetime.datetime(2021, 5, 16, 12, 38, 11, 847874) password='$2b$12$VfJuQRvRMeFWrvwcbgZHsO3V2gGeigcXEvIePfQEEJqzgy/LdDHxC' salt='$2b$12$3FB/lyWlyPU.WcK8K2WKgu'
[New Thread 0x7fffeca31700 (LWP 10361)]
[New Thread 0x7fffdffff700 (LWP 10362)]
Modules/gcmodule.c:2163: visit_validate: Assertion failed: PyObject_GC_Track() object is not valid
Memory block allocated at (most recent call first):
  File "/usr/local/lib/python3.9/asyncio/sslproto.py", line 545

object address  : 0x7fffeca32eb0
object refcount : 1
object type     : 0x7fffee424a20
object type name: asyncpg.Record
object repr     : 
Thread 1 "python" received signal SIGSEGV, Segmentation fault.
0x00007fffee2028ae in record_repr (v=0x7fffeca32eb0) at asyncpg/protocol/record/recordobj.c:462
462	asyncpg/protocol/record/recordobj.c: No such file or directory.

bt:

(gdb) bt
#0  0x00007fffee2028ae in record_repr (v=0x7fffeca32eb0) at asyncpg/protocol/record/recordobj.c:462
#1  0x00005555555fd868 in PyObject_Repr (v=v@entry=0x7fffeca32eb0) at Objects/object.c:420
#2  0x00005555555fdb39 in PyObject_Print (op=op@entry=0x7fffeca32eb0, fp=0x7ffff740a680 <_IO_2_1_stderr_>, flags=flags@entry=0) at Objects/object.c:275
#3  0x00005555555fdd48 in _PyObject_Dump (op=op@entry=0x7fffeca32eb0) at Objects/object.c:378
#4  0x00005555555fdf17 in _PyObject_AssertFailed (obj=obj@entry=0x7fffeca32eb0, expr=expr@entry=0x0, msg=msg@entry=0x55555587e860 "PyObject_GC_Track() object is not valid", 
    file=file@entry=0x55555587e348 "Modules/gcmodule.c", line=line@entry=2163, function=function@entry=0x55555587ec68 <__func__.16393> "visit_validate") at Objects/object.c:2192
#5  0x00005555556ec022 in visit_validate (op=<optimized out>, parent_raw=parent_raw@entry=0x7fffeca32eb0) at Modules/gcmodule.c:2162
#6  0x00007fffee2021c2 in record_traverse (o=0x7fffeca32eb0, visit=0x5555556ebfe6 <visit_validate>, arg=0x7fffeca32eb0) at asyncpg/protocol/record/recordobj.c:125
#7  0x00005555556ee67b in PyObject_GC_Track (op_raw=op_raw@entry=0x7fffeca32eb0) at Modules/gcmodule.c:2188
#8  0x00007fffee20347b in ApgRecord_New (type=type@entry=0x7fffee424a20 <ApgRecord_Type>, desc=desc@entry=0x7fffeca60370, size=size@entry=10)
    at asyncpg/protocol/record/recordobj.c:57
#9  0x00007fffee1bc186 in __pyx_f_7asyncpg_8protocol_8protocol_22PreparedStatementState__decode_row (__pyx_v_self=0x7fffecaeb680, __pyx_v_cbuf=<optimized out>, 
    __pyx_v_buf_len=<optimized out>) at asyncpg/protocol/protocol.c:52281
#10 0x00007fffee1bcf90 in __pyx_f_7asyncpg_8protocol_8protocol_12BaseProtocol__decode_row (__pyx_v_self=<optimized out>, __pyx_v_buf=<optimized out>, __pyx_v_buf_len=<optimized out>)
    at asyncpg/protocol/protocol.c:68934
#11 0x00007fffee1b9860 in __pyx_f_7asyncpg_8protocol_8protocol_12CoreProtocol__parse_data_msgs (__pyx_v_self=0x7fffedefebd0) at asyncpg/protocol/protocol.c:41432
#12 0x00007fffee18d6fa in __pyx_f_7asyncpg_8protocol_8protocol_12CoreProtocol__process__bind_execute (__pyx_v_self=0x7fffedefebd0, __pyx_v_mtype=21 '\025')
    at asyncpg/protocol/protocol.c:39047
#13 0x00007fffee18a683 in __pyx_f_7asyncpg_8protocol_8protocol_12CoreProtocol__read_server_messages (__pyx_v_self=0x7fffedefebd0) at asyncpg/protocol/protocol.c:37586
#14 0x00007fffee183079 in __pyx_pf_7asyncpg_8protocol_8protocol_12BaseProtocol_61data_received (__pyx_v_data=<optimized out>, __pyx_v_self=0x7fffedefebd0)
    at asyncpg/protocol/protocol.c:71031
#15 __pyx_pw_7asyncpg_8protocol_8protocol_12BaseProtocol_62data_received (__pyx_v_self=0x7fffedefebd0, __pyx_v_data=<optimized out>) at asyncpg/protocol/protocol.c:5461
#16 0x000055555578cbe8 in method_vectorcall_O (func=0x7fffee48b6b0, args=0x555558338070, nargsf=<optimized out>, kwnames=<optimized out>) at Objects/descrobject.c:462
#17 0x000055555567caff in _PyObject_VectorcallTstate (kwnames=0x0, nargsf=9223372036854775810, args=0x555558338070, callable=0x7fffee48b6b0, tstate=0x555555bab990)
    at ./Include/cpython/abstract.h:118
#18 PyObject_Vectorcall (kwnames=0x0, nargsf=9223372036854775810, args=0x555558338070, callable=0x7fffee48b6b0) at ./Include/cpython/abstract.h:127

bt full excerpt:

(gdb) bt full
#0  0x00007fffee2028ae in record_repr (v=0x7fffeca32eb0) at asyncpg/protocol/record/recordobj.c:462
        i = <optimized out>
        n = 10
        keys_iter = <optimized out>
        writer = {buffer = 0x1, data = 0x7ffff7bc53bc <__libc_write+92>, kind = PyUnicode_1BYTE_KIND, maxchar = 0, size = 0, pos = 33, min_length = 14, min_char = 3, 
          overallocate = 0 '\000', readonly = 0 '\000'}
#1  0x00005555555fd868 in PyObject_Repr (v=v@entry=0x7fffeca32eb0) at Objects/object.c:420
        res = <optimized out>
        tstate = <optimized out>
        __PRETTY_FUNCTION__ = "PyObject_Repr"
#2  0x00005555555fdb39 in PyObject_Print (op=op@entry=0x7fffeca32eb0, fp=0x7ffff740a680 <_IO_2_1_stderr_>, flags=flags@entry=0) at Objects/object.c:275
        s = <optimized out>
        ret = 0
        __PRETTY_FUNCTION__ = "PyObject_Print"
#3  0x00005555555fdd48 in _PyObject_Dump (op=op@entry=0x7fffeca32eb0) at Objects/object.c:378
        type = <optimized out>
        gil = PyGILState_LOCKED
        error_type = 0x0
        error_value = 0x0
        error_traceback = 0x0
#4  0x00005555555fdf17 in _PyObject_AssertFailed (obj=obj@entry=0x7fffeca32eb0, expr=expr@entry=0x0, msg=msg@entry=0x55555587e860 "PyObject_GC_Track() object is not valid", 
    file=file@entry=0x55555587e348 "Modules/gcmodule.c", line=line@entry=2163, function=function@entry=0x55555587ec68 <__func__.16393> "visit_validate") at Objects/object.c:2192
        ptr = 0x7fffeca32ea0
        type = <optimized out>
        __func__ = "_PyObject_AssertFailed"
#5  0x00005555556ec022 in visit_validate (op=<optimized out>, parent_raw=parent_raw@entry=0x7fffeca32eb0) at Modules/gcmodule.c:2162
        parent = 0x7fffeca32eb0
        __func__ = "visit_validate"
#6  0x00007fffee2021c2 in record_traverse (o=0x7fffeca32eb0, visit=0x5555556ebfe6 <visit_validate>, arg=0x7fffeca32eb0) at asyncpg/protocol/record/recordobj.c:125
        vret = <optimized out>
        i = <optimized out>
#7  0x00005555556ee67b in PyObject_GC_Track (op_raw=op_raw@entry=0x7fffeca32eb0) at Modules/gcmodule.c:2188
        op = 0x7fffeca32eb0
        __func__ = "PyObject_GC_Track"
        traverse = <optimized out>
#8  0x00007fffee20347b in ApgRecord_New (type=type@entry=0x7fffee424a20 <ApgRecord_Type>, desc=desc@entry=0x7fffeca60370, size=size@entry=10)
    at asyncpg/protocol/record/recordobj.c:57
        o = 0x7fffeca32eb0
        i = <optimized out>
#9  0x00007fffee1bc186 in __pyx_f_7asyncpg_8protocol_8protocol_22PreparedStatementState__decode_row (__pyx_v_self=0x7fffecaeb680, __pyx_v_cbuf=<optimized out>, 
    __pyx_v_buf_len=<optimized out>) at asyncpg/protocol/protocol.c:52281
        __pyx_v_codec = 0x0
        __pyx_v_fnum = <optimized out>
---Type <return> to continue, or q <return> to quit---
        __pyx_v_flen = <optimized out>
        __pyx_v_dec_row = 0x0
        __pyx_v_rows_codecs = 0x7fffeca89ef0
        __pyx_v_settings = 0x7fffecaaf2f0
        __pyx_v_i = <optimized out>
        __pyx_v_rbuf = {buf = 0x5555587aa0dc "", len = 180}
        __pyx_v_bl = <optimized out>
        __pyx_v_val = 0x0
        __pyx_r = 0x0
        __pyx_t_1 = 0x7fffee424a20 <ApgRecord_Type>
        __pyx_t_2 = 0xcdcdcdcdcdcdcdcd <error: Cannot access memory at address 0xcdcdcdcdcdcdcdcd>
        __pyx_t_3 = <optimized out>
        __pyx_t_4 = 0x0
        __pyx_t_5 = 0x7fffeca60370
        __pyx_t_6 = 0x0
        __pyx_t_7 = 0x0
        __pyx_t_8 = 0x0
        __pyx_t_9 = 0x0
        __pyx_t_10 = <optimized out>
        __pyx_t_11 = 0x0
        __pyx_t_12 = <optimized out>
        __pyx_t_13 = <optimized out>
        __pyx_t_14 = <optimized out>
        __pyx_t_15 = <optimized out>
        __pyx_lineno = 0
        __pyx_filename = 0x0
        __pyx_clineno = 0
#10 0x00007fffee1bcf90 in __pyx_f_7asyncpg_8protocol_8protocol_12BaseProtocol__decode_row (__pyx_v_self=<optimized out>, __pyx_v_buf=<optimized out>, __pyx_v_buf_len=<optimized out>)
    at asyncpg/protocol/protocol.c:68934
        __pyx_r = 0x0
        __pyx_t_2 = <optimized out>
        __pyx_t_3 = 0x0
        __pyx_lineno = 0
        __pyx_filename = 0x0
        __pyx_clineno = 0
#11 0x00007fffee1b9860 in __pyx_f_7asyncpg_8protocol_8protocol_12CoreProtocol__parse_data_msgs (__pyx_v_self=0x7fffedefebd0) at asyncpg/protocol/protocol.c:41432
        __pyx_v_buf = 0x7fffecae22d0
        __pyx_v_rows = 0x7fffeca8d780
        __pyx_v_decoder = 0x7fffee1bcf80 <__pyx_f_7asyncpg_8protocol_8protocol_12BaseProtocol__decode_row>
        __pyx_v_try_consume_message = 0x7fffedf35590 <__pyx_f_7asyncpg_7pgproto_7pgproto_10ReadBuffer_try_consume_message>
        __pyx_v_take_message_type = 0x7fffedf377e0 <__pyx_f_7asyncpg_7pgproto_7pgproto_10ReadBuffer_take_message_type>
        __pyx_v_cbuf = <optimized out>
        __pyx_v_cbuf_len = 182
---Type <return> to continue, or q <return> to quit---
        __pyx_v_row = 0x0
        __pyx_v_mem = 0x0
        __pyx_r = 0x0
        __pyx_t_1 = 0x0
        __pyx_t_2 = 0
        __pyx_t_5 = <optimized out>
        __pyx_t_6 = <optimized out>
        __pyx_t_9 = <optimized out>
        __pyx_lineno = 0
        __pyx_filename = 0x0
        __pyx_clineno = 0
#12 0x00007fffee18d6fa in __pyx_f_7asyncpg_8protocol_8protocol_12CoreProtocol__process__bind_execute (__pyx_v_self=0x7fffedefebd0, __pyx_v_mtype=21 '\025')
    at asyncpg/protocol/protocol.c:39047
        __pyx_r = 0xcdcdcdcdcdcdcdcd
        __pyx_t_1 = <optimized out>
        __pyx_lineno = 68
        __pyx_filename = <optimized out>
        __pyx_clineno = -303043632
#13 0x00007fffee18a683 in __pyx_f_7asyncpg_8protocol_8protocol_12CoreProtocol__read_server_messages (__pyx_v_self=0x7fffedefebd0) at asyncpg/protocol/protocol.c:37586
        __pyx_tstate = 0x555555bab990
        __pyx_v_mtype = 68 'D'
        __pyx_v_state = __pyx_e_7asyncpg_8protocol_8protocol_PROTOCOL_BIND_EXECUTE
        __pyx_v_take_message = 0x7fffedf377c0 <__pyx_f_7asyncpg_7pgproto_7pgproto_10ReadBuffer_take_message>
        __pyx_v_get_message_type = <optimized out>
        __pyx_v_ex = 0x0
        __pyx_r = 0x0
        __pyx_t_1 = 0x0
        __pyx_t_2 = <optimized out>
        __pyx_t_3 = 1
        __pyx_t_4 = __pyx_e_7asyncpg_8protocol_8protocol_PROTOCOL_BIND_EXECUTE
        __pyx_t_5 = 0x555555b58b00 <_Py_NoneStruct>
        __pyx_t_6 = 0x0
        __pyx_t_7 = 0x0
        __pyx_t_8 = 0x0
        __pyx_t_9 = 0x0
        __pyx_t_10 = <optimized out>
        __pyx_t_11 = <optimized out>
        __pyx_t_12 = 0x0
        __pyx_t_13 = 0x0
        __pyx_t_14 = <optimized out>
        __pyx_t_15 = <optimized out>
        __pyx_t_16 = <optimized out>
        __pyx_t_17 = 0x0
---Type <return> to continue, or q <return> to quit---
        __pyx_t_18 = 0x0
        __pyx_t_19 = 0x0
        __pyx_t_20 = 0x0
        __pyx_t_21 = 0x0
        __pyx_t_22 = 0x0
        __pyx_t_23 = <optimized out>
        __pyx_lineno = <optimized out>
        __pyx_filename = <optimized out>
        __pyx_clineno = <optimized out>
#14 0x00007fffee183079 in __pyx_pf_7asyncpg_8protocol_8protocol_12BaseProtocol_61data_received (__pyx_v_data=<optimized out>, __pyx_v_self=0x7fffedefebd0)
    at asyncpg/protocol/protocol.c:71031
        __pyx_r = 0x0
        __pyx_t_1 = 0x0
        __pyx_lineno = 0
        __pyx_filename = 0x0
        __pyx_clineno = 0
        __pyx_r = <optimized out>
        __pyx_t_1 = <optimized out>
        __pyx_lineno = <optimized out>
        __pyx_filename = <optimized out>
        __pyx_clineno = <optimized out>
#15 __pyx_pw_7asyncpg_8protocol_8protocol_12BaseProtocol_62data_received (__pyx_v_self=0x7fffedefebd0, __pyx_v_data=<optimized out>) at asyncpg/protocol/protocol.c:5461
        __pyx_r = 0x0

[elprans]

I think this was fixed in #719. I'll be making a new release to include that fix soon.

[ShahriyarR]

Confirming. After upgrading to 0.23.0 could not reproduce the same issue.