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.

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

PostgREST Dart Client - new payload in _getStreamData on 'UPDATE' missing column #627

Closed
MelbourneDeveloper opened this issue Sep 16, 2023 · 15 comments
Labels
bug Something isn't working

Comments

@MelbourneDeveloper
Copy link

MelbourneDeveloper commented Sep 16, 2023

  • PostgreSQL version: PostgreSQL 15.1 (Ubuntu 15.1-1.pgdg20.04+1) on aarch64-unknown-linux-gnu, compiled by gcc (Ubuntu 9.4.0-1ubuntu1~20.04.1) 9.4.0, 64-bit
  • PostgREST version: 1.5
  • Operating system: macOS

Description of Issue

Issue One - Missing Column (resume)

Supabase seems to limit one of the columns in the payload of incoming websocket calls. This is probably just a quote issue, however, I'm not seeing any error logs on the back-end or through the websocket client.

If I send an UPDATE (PATCH) to the server for the resume column, the record appears in the payload via the websocket, and the record column (quite large) is in the payload. If I send an UPDATE for a different column, a similar payload appears, but the resume column is missing, perhaps because of a quota issue.

The problem is that I don't see anything in the back-end logs, and I don't see anything in the websocket payload

Server logs
image

Incoming Websocket Payloads
You can see here that it has removed the resume column.

{
    "data": {
        "columns": [
            {
                "name": "id",
                "type": "varchar"
            },
            {
                "name": "resume",
                "type": "text"
            },
            {
                "name": "embedding",
                "type": "vector"
            },
            {
                "name": "minsalaryperday",
                "type": "int4"
            },
            {
                "name": "minsalaryperyear",
                "type": "int4"
            },
            {
                "name": "locationtext",
                "type": "varchar"
            },
            {
                "name": "location",
                "type": "geography"
            },
            {
                "name": "preferredworktypes",
                "type": "_text"
            },
            {
                "name": "preferredcommutetypes",
                "type": "_text"
            }
        ],
        "commit_timestamp": "2023-09-16T20:58:03.554Z",
        "errors": null,
        "old_record": {
            "id": "c315090a-0cca-4f07-adfa-78c6fe433f2a"
        },
        "record": {
            "embedding": null,
            "id": "c315090a-0cca-4f07-adfa-78c6fe433f2a",
            "location": "0101000020E61000004703780B24E842C0789CA223B9844140",
            "locationtext": "Melbourne",
            "minsalaryperday": 156,
            "minsalaryperyear": 1003,
            "preferredcommutetypes": [
                "remote"
            ],
            "preferredworktypes": [
                "contract"
            ]
        },
        "schema": "public",
        "table": "profiles",
        "type": "UPDATE"
    },
    "ids": [
        109688006,
        12391632,
        13182892
    ]
}

I am logging the incoming websocket payloads - possibly only the non-errors. But, I don't see anything about quota errors:
image

So, the question is how one would see incoming websocket errors... I believe this may be a necessary enhancement for the library. Please read on.

Issue 2 - Unnecessary Exception

This is probably unrelated, but it's the reason I original started investigating.

The endpoint returns 204 with an empty body, but the code tries to parse the response.

image

This is a problem with the _parseResponse method. It is trying to decode an empty body. This gets caught and handled, but it breaks the execution flow of the debugging experience, and this led me to log the bug. I would recommend fixing this one. It is a slight performance hit at least.

Pull Request Draft - Allow Websocket Payload Logging

This is only a rough draft PR, and far from perfect. The aim here is to add a callback so consumers can see all incoming websocket data. The aim here would be to see the incoming error so the consumer can tell when data has been removed due to quotas or any other reason.

If Supabase is sending a quote error, the would be that we the error here. Please review and let me know what needs to be done to bring this up to the standard for the codebase.

Historical Information

This bug started out because I noticed and exception. It then evolved because it got a lot more complicated. This is here for a historical log of what happened.

Edit: this was the problem when I first logged it, but it is not the actual problem. The bug is that when I listen to a stream on the table, the first emitted value is correct, but the second emitted value (after updating the record) is missing a column from the table. See this comment

Edit: I just revered to http: ^0.13.6 and the problem is still occurring. This seems to have nothing to do with the http package.
I just upgraded to http ^1.1.0. It looks like it's not compatible with the PostgREST SDK V1.5.0

The endpoint returns 204 with an empty body, but the code tries to parse the response.

image

The problem is happening in _parseResponse. You can see that the body is an empty string here.

image

It was a query for a table with an eq on the ID column. The method is PATCH. The content length here is actually 0, so it should be hitting a different code path, I would say.

@MelbourneDeveloper
Copy link
Author

MelbourneDeveloper commented Sep 16, 2023

More info. Actually, the exception is getting caught and they the body local gets set to null

This may not technically be a bug, but this could be handled without throwing an exception.

At the same time, code that was working with the previous version of the http package is now broken after the upgrade. For some reason, the from -> stream call is returning a list of maps, and in the map, one of my columns is missing. This was working before, and since the upgrade it got broken.

image

@MelbourneDeveloper
Copy link
Author

MelbourneDeveloper commented Sep 16, 2023

The bug I am experiencing is this...

I open a stream for the profiles table with from -> stream.

This correctly includes the resume column the first time I get data. Later, I update (patch) the record with some unrelated values, and this is where I see the exception above occur.

Then, another value gets emitted on the stream for the table. This time, the resume value is missing from the map, even though it's on the record in Supabase.

I have no evidence that the update affects the stream's second emitted value. But it's odd that the incorrect value on the stream happens after the update has an exception.

@MelbourneDeveloper
Copy link
Author

I've further pinned this down. When I update the table, it triggers the UPDATE event to appear on the stream.

The new map in payload has 8 values instead of 9. It is missing resume. This later shows up on the stream and the value is missing.

image

@MelbourneDeveloper
Copy link
Author

Notice that streamData does have the resume column, but the payload doesn't. So, the question is why the new payload is missing the column.

image

@MelbourneDeveloper MelbourneDeveloper changed the title PostgREST Dart Client - jsonDecode on Empty String PostgREST Dart Client - new payload in _getStreamData on 'UPDATE' missing column Sep 16, 2023
@MelbourneDeveloper
Copy link
Author

One piece of information is the resume column is a text column and quite long. Perhaps the server is deciding not to send the column to avoid bandwidth use.

@MelbourneDeveloper
Copy link
Author

This is the payload data that arrives in the trigger method in the RealtimeChannel class. It seems that the incoming JSON is missing the resume column even though the payload explicitly mentions the column. Could supabase be omitting this column accidentally?

{
    "data": {
        "columns": [
            {
                "name": "id",
                "type": "varchar"
            },
            {
                "name": "resume",
                "type": "text"
            },
            {
                "name": "embedding",
                "type": "vector"
            },
            {
                "name": "minsalaryperday",
                "type": "int4"
            },
            {
                "name": "minsalaryperyear",
                "type": "int4"
            },
            {
                "name": "locationtext",
                "type": "varchar"
            },
            {
                "name": "location",
                "type": "geography"
            },
            {
                "name": "preferredworktypes",
                "type": "_text"
            },
            {
                "name": "preferredcommutetypes",
                "type": "_text"
            }
        ],
        "commit_timestamp": "2023-09-16T04:25:21.598Z",
        "errors": null,
        "old_record": {
            "id": "c315090a-0cca-4f07-adfa-78c6fe433f2a"
        },
        "record": {
            "embedding": null,
            "id": "c315090a-0cca-4f07-adfa-78c6fe433f2a",
            "location": "",
            "locationtext": "Melbourne",
            "minsalaryperday": 156,
            "minsalaryperyear": 1003,
            "preferredcommutetypes": [
                "nonMandated"
            ],
            "preferredworktypes": [
                "permanent"
            ]
        },
        "schema": "public",
        "table": "profiles",
        "type": "UPDATE"
    },
    "ids": [
        109688006,
        12391632,
        13182892
    ]
}

@MelbourneDeveloper
Copy link
Author

And when I explicitly update the resume column, it does send the resume column:

{
    "data": {
        "columns": [
            {
                "name": "id",
                "type": "varchar"
            },
            {
                "name": "resume",
                "type": "text"
            },
            {
                "name": "embedding",
                "type": "vector"
            },
            {
                "name": "minsalaryperday",
                "type": "int4"
            },
            {
                "name": "minsalaryperyear",
                "type": "int4"
            },
            {
                "name": "locationtext",
                "type": "varchar"
            },
            {
                "name": "location",
                "type": "geography"
            },
            {
                "name": "preferredworktypes",
                "type": "_text"
            },
            {
                "name": "preferredcommutetypes",
                "type": "_text"
            }
        ],
        "commit_timestamp": "2023-09-16T04:31:13.660Z",
        "errors": null,
        "old_record": {
            "id": "c315090a-0cca-4f07-adfa-78c6fe433f2a"
        },
        "record": {
            "embedding": null,
            "id": "c315090a-0cca-4f07-adfa-78c6fe433f2a",
            "location": "",
            "locationtext": "Melbourne",
            "minsalaryperday": 156,
            "minsalaryperyear": 1003,
            "preferredcommutetypes": [
                "hybrid"
            ],
            "preferredworktypes": [
                "contract"
            ],
            "resume": "dfsdfsdf"
        },
        "schema": "public",
        "table": "profiles",
        "type": "UPDATE"
    },
    "ids": [
        109688006,
        12391632,
        13182892
    ]
}

Now that I understand more about this, I'm left wondering why Supabase sends the full record at all...

Why doesn't Supabase only send the updated columns? Perhaps I might want to know what the full record is, but I can calculate that myself. I'm really only interested in the changed values and streaming the rest eats bandwidth.

@MelbourneDeveloper
Copy link
Author

MelbourneDeveloper commented Sep 16, 2023

Lastly, I made a change in a couple of libraries to listen to incoming data from Supabase. You can see the changes here:

Is it worth cleaning this up and submitting it as a PR?

main...MelbourneDeveloper:supabase-flutter:main

Here is the example usage:

supabase.client.from(table).stream(
  primaryKey: ['id'],
  onTrigger: (
    type, [
    payload,
    ref,
  ]) {
    final json = jsonEncode(payload);
    // ignore: avoid_print
    print(json);
  },
).eq(column, value);

This is the JSON output that gets printed to the console. It's very useful for debugging what is coming in from Supabase

image

@Vinzent03
Copy link
Collaborator

It's a bit hard to follow your issue, because you are mentioning many different aspects. Please delete anything related to the http package when you already know now that it's not the reason.

So what exactly is your issue now? When updating a column other than the resume column in a row, the resume column is missing in the payload. But when updating the resume column, it is present in the payload?
Have you read the quotas documentation?

@MelbourneDeveloper
Copy link
Author

MelbourneDeveloper commented Sep 16, 2023 via email

@MelbourneDeveloper
Copy link
Author

The other bug mentioned in the first comment is that the _parseResponse method is throwing an exception because it's trying to decode an empty body. This gets caught and handled, but it still causes an exception when debugging that breaks flow of the debugging experience.

@MelbourneDeveloper
Copy link
Author

@Vinzent03

Have you read the quotas documentation?

I suspect that the issue may be quota-related. The payload removes the resume column when it is very long, and only on UPDATE calls where I don't update that column.

However, the documentation says I will see the error in the backend logs and the client-side websocket logs. I don't see anything in the server-side logs:

image

I don't see anything on the client-side web socket logs when I write up to print all the incoming payloads. This is a log of all the incoming payloads. I don't see any errors here:
image

@MelbourneDeveloper
Copy link
Author

@Vinzent03 please see the edited issue at the top

@Vinzent03
Copy link
Collaborator

@w3b6x9 Are you the correct person to be tagged for the above comment ?

Will fix the format exception issue.

@dshukertjr
Copy link
Member

@MelbourneDeveloper
Thanks for the detailed issue. My one small ask is to open one GitHub issue per issue instead of including two different issues. That way, we can transfer the issue to other repo that might have more to do with it then this repo.

For your issue 1 about the missing column, would you be able to open an issue in the walrus repo providing (if possible) your table schema and how long your resume column could be specifically? I think those information would help out the team to find the cause.

For issue 2, @Vinzent03 has created an amazing fix for it, which we plan to ship in the next 24 hours.

Lastly about the question of whether to finalize the exposing raw web socket messages PR or not, let's discuss anything about it in the PR itself 👍

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants