search

dvankley / firefly-plaid-connector-2

Connector to pull Plaid financial data into the Firefly finance tool
GNU General Public License v3.0
94 stars 14 forks source link

client_id must be a properly formatted #115

Closed WEBENGi closed 1 month ago

WEBENGi commented 1 month ago

Despite clearing having the client_id in the yaml file, I'm getting this error when I run it.

2024-08-02T09:56:38.065-04:00 INFO 1 --- [ main] .d.f.FireflyPlaidConnector2ApplicationKt : Starting FireflyPlaidConnector2ApplicationKt v1.2.0 using Java 17.0.11 with PID 1 (/workspace/BOOT-INF/classes started by cnb in /workspace) 2024-08-02T09:56:38.073-04:00 DEBUG 1 --- [ main] .d.f.FireflyPlaidConnector2ApplicationKt : Running with Spring Boot v3.3.1, Spring v6.1.10 2024-08-02T09:56:38.075-04:00 INFO 1 --- [ main] .d.f.FireflyPlaidConnector2ApplicationKt : No active profile set, falling back to 1 default profile: "default" 2024-08-02T09:56:40.767-04:00 INFO 1 --- [ main] .d.f.FireflyPlaidConnector2ApplicationKt : Started FireflyPlaidConnector2ApplicationKt in 3.371 seconds (process running for 3.917) 2024-08-02T09:56:42.160-04:00 DEBUG 1 --- [ main] n.d.f.sync.BatchSyncRunner : Fetching Plaid data for access token access-sandbox- and account ids 2024-08-02T09:56:42.547-04:00 ERROR 1 --- [ main] n.d.f.sync.BatchSyncRunner : Error requesting Plaid transactions. Request: TransactionsGetRequest(accessToken=access-sandbox-, startDate=, endDate=, clientId=null, options=TransactionsGetRequestOptions(accountIds=[], count=100, offset=0, includeOriginalDescription=true, includePersonalFinanceCategoryBeta=false, includePersonalFinanceCategory=true), secret=null); 2024-08-02T09:56:42.586-04:00 ERROR 1 --- [ main] o.s.boot.SpringApplication : Application run failed io.ktor.client.plugins.ClientRequestException: Client request(POST https://sandbox.plaid.com/transactions/get) invalid: 400 Bad Request. Text: "{ "display_message": null, "documentation_url": "https://plaid.com/docs/?ref=error#invalid-request-errors", "error_code": "INVALID_FIELD", "error_message": "client_id must be a properly formatted, non-empty string", "error_type": "INVALID_REQUEST", "request_id": "", "suggested_action": null }"

dvankley commented 1 month ago

The log line

Request: TransactionsGetRequest(accessToken=access-sandbox-, startDate=, endDate=, clientId=null, options=TransactionsGetRequestOptions(accountIds=[], count=100, offset=0, includeOriginalDescription=true, includePersonalFinanceCategoryBeta=false, includePersonalFinanceCategory=true), secret=null)

implies that your configuration values aren't getting picked up properly.

Looks like you're using the Docker version of the connector. What's your Docker compose file, where in your filesystem is your application.yml file, and how are you starting the container? Also please double check your application.yml to ensure you've populated the required fields and don't have any goofy whitespace (for instance with something like https://www.yamllint.com).

WEBENGi commented 1 month ago

Thanks for the fast response. Yeah I figured as much and I'm not familiar/fluent with the compilation of the language used in order to debug where the value is being lost at. The application.yml with private data removed was copied here: https://pastebin.com/9k6B6adP and the file is UTF-8 encoded. The dockcer-compose.yml is: plaid_connector_2: image: ghcr.io/dvankley/firefly-plaid-connector-2:latest hostname: plaidconnector restart: always volumes:

dvankley commented 1 month ago

Your config looks reasonable.

Is the /fireflyiii/Plaid/plaid-connector-2/ directory readable by all (or at least UID 1000 or GID 1000, which are the ids of the cnb user the image runs as)?

You might also try enabling debug logging in Spring to get a better idea of what's going on in the config file resolution and reading process. You could start with these environment variables:

LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_BOOT=DEBUG
LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_CORE_ENV=DEBUG
LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB=DEBUG
WEBENGi commented 1 month ago

As far as I can tell its readable by #1000 and it looks like its reading it, id think its definitely getting some values from the yaml file as evidenced by the other info from the log.

2024-08-06T18:22:26.501-04:00 DEBUG 1 --- [ main] o.s.c.e.PropertySourcesPropertyResolver : Found key 'fireflyPlaidConnector2.plaid.maxRetries' in PropertySource 'environmentProperties' with value of type String 2024-08-06T18:22:26.502-04:00 DEBUG 1 --- [ main] ySourcesPropertyResolver$DefaultResolver : Found key 'fireflyPlaidConnector2.plaid.clientId' in PropertySource 'Config resource 'file [/opt/fpc-config/application.yml]' via location '/opt/fpc-config/application.yml'' with value of type String 2024-08-06T18:22:26.502-04:00 DEBUG 1 --- [ main] o.s.c.e.PropertySourcesPropertyResolver : Found key 'fireflyPlaidConnector2.plaid.clientId' in PropertySource 'environmentProperties' with value of type String 2024-08-06T18:22:26.502-04:00 DEBUG 1 --- [ main] ySourcesPropertyResolver$DefaultResolver : Found key 'fireflyPlaidConnector2.plaid.secret' in PropertySource 'Config resource 'file [/opt/fpc-config/application.yml]' via location '/opt/fpc-config/application.yml'' with value of type String 2024-08-06T18:22:26.503-04:00 DEBUG 1 --- [ main] o.s.c.e.PropertySourcesPropertyResolver : Found key 'fireflyPlaidConnector2.plaid.secret' in PropertySource 'environmentProperties' with value of type String

Do you have any other ideas or know of an easy way I can step through the code debugging by writing output statements along the way?

dvankley commented 1 month ago 
2024-08-06T18:22:26.502-04:00 DEBUG 1 --- [ main] ySourcesPropertyResolver$DefaultResolver : Found key 'fireflyPlaidConnector2.plaid.clientId' in PropertySource 'Config resource 'file [/opt/fpc-config/application.yml]' via location '/opt/fpc-config/application.yml'' with value of type String
2024-08-06T18:22:26.502-04:00 DEBUG 1 --- [ main] o.s.c.e.PropertySourcesPropertyResolver : Found key 'fireflyPlaidConnector2.plaid.clientId' in PropertySource 'environmentProperties' with value of type String

That seems odd to me that it's finding clientId in both the config file and in your environment variables. Env vars take precedence in Spring, so maybe something is setting the env var to an invalid value and screwing up your config?

dvankley commented 1 month ago

As for debugging it yourself, there's an (admittedly pretty barebones) section on it in the README. Feel free to update that section or ask for any missing details. You should be able to run the connector locally with ./gradlew bootRun and use SPRING_PROFILES_ACTIVE to set the Spring profile you want to run. I like to run against a local instance of Firefly, but you can run against any instance that's accessible via HTTP.

That said, I'm not sure how much value that's going to give you. The Plaid creds are injected from config here and set here, so there's not much to go wrong there.

WEBENGi commented 1 month ago

I just now noticed this and I might be misunderstanding but it appears as if the clientid is never being put into the api request in the first place! https://github.com/dvankley/firefly-plaid-connector-2/blob/940943a0ac5b2fdc6679e00ecd0ae54c04cfc4d7/src/main/kotlin/net/djvk/fireflyPlaidConnector2/sync/BatchSyncRunner.kt#L82

Also One thing I wanted to mention before was that the url, which is in the sample application.yml "develelopment.plaid.com" is depreciated and I think you need to use sandbox now.

Edit: Oh I think I see now that the clientId is being set in the header and not the request. Is there a way to see what the full header was at the time of error?

dvankley commented 1 month ago

Also One thing I wanted to mention before was that the url, which is in the sample application.yml "develelopment.plaid.com" is depreciated and I think you need to use sandbox now.

Valid point, I will fix that.

dvankley commented 1 month ago

Oh I think I see now that the clientId is being set in the header and not the request

Correct.

Is there a way to see what the full header was at the time of error?

You could set up Ktor debug logging, but that's going to be kind of a pain because that config will need to happen in net.djvk.fireflyPlaidConnector2.api.plaid.infrastructure.ApiClient, which is generated and will take a bit more work to change. You might be better off running in the debugger or adding a log line and seeing what value ends up loaded here.

dvankley commented 1 month ago

You can also try setting the FIREFLYPLAIDCONNECTOR2_PLAID_CLIENTID env var and see if you get a different result.

dvankley commented 1 month ago

I've confirmed that I also see the behavior described here in my successful run locally, so that's not worth chasing up.

WEBENGi commented 1 month ago

I tried changing Default API versions in the plaid backend. I tried making the request carry the client_id forward too. Also tried using the ENV variable like you gave me. One idea I got from finding someone else who had a similar issue was to contact Plaid support to see if they can identify the issue with a certain API reqeust. So today I made a ticket with the request_id. Unfortunetly the request_id doesnt make it to my accounts API log. So

So I guess Ill wait on that since this is so baffling. If I change the client_id to a bad one it tells me its bad! The only thing I havent tried yet was posting the data outside of an app environment.

On a different note: do you know if these messages like these are normal?

TaskSchedulingConfigurations.SimpleAsyncTaskSchedulerBuilderConfiguration#simpleAsyncTaskSchedulerBuilder matched:

dvankley commented 1 month ago

One idea I got from finding someone else who had a similar issue was to contact Plaid support

The only thing I havent tried yet was posting the data outside of an app environment.

These are both good ideas, especially together. If you can reproduce the problem with a simple curl or similar call, that will make it much easier for Plaid support to reproduce and fix the issue.

dvankley commented 1 month ago

do you know if these messages like these are normal?

What context and logging level are you seeing these in? I have not seen them myself. Hard to say what they mean definitively.

WEBENGi commented 1 month ago

do you know if these messages like these are normal?

What context and logging level are you seeing these in? I have not seen them myself. Hard to say what they mean definitively.

Here is a log file (running it manually, adding a couple extra loggings that I dont think impacted this: https://pastebin.com/LUP4KTPH

WEBENGi commented 1 month ago

I think the issue is resolved. I cant say FOR SURE if funny business was going on. But the client id in my profile ended up being different than the one I think i copy and pasted from the plaid back end before. I wonder if my client id changed because of the changes that happened to my accounts access or I just copied it incorrectly somehow. I highlighted the text and copy and pasted vs using the copy ICON, I dont know if that could be a thing.

So now the plaid connector ends with: 2024-08-14T12:22:33.844Z DEBUG 1 --- [ main] n.d.f.transactions.TransactionConverter : Batch sync converting Plaid transactions to Firefly transactions Native Memory Tracking: Total: reserved=38121800010, committed=543510858 malloc: 85356874 #281876 mmap: reserved=38036443136, committed=458153984

So now im trying to figure out why the data isnt in my firefly install... Is there a step I missed? Do I need to create some kind of thing in the firefly backend to receive these transactions, does it not work in sandbox mode? Is it actually finishing its conversion process before ending the run of the docker application (i see no errors)? Ill try some things but maybe you can get me some insight asap.

dvankley commented 1 month ago

Glad you've made some progress.

Hard to say what's happening there, you don't have much in the logs. Here's an example of my logs from a successful non-docker run, for what it's worth:

2024-08-14T21:13:16.051-04:00  INFO 50284 --- [           main] .d.f.FireflyPlaidConnector2ApplicationKt : Starting FireflyPlaidConnector2ApplicationKt using Java 17 with PID 50284 (path stuff lol)
2024-08-14T21:13:16.053-04:00 DEBUG 50284 --- [           main] .d.f.FireflyPlaidConnector2ApplicationKt : Running with Spring Boot v3.3.1, Spring v6.1.10
2024-08-14T21:13:16.053-04:00  INFO 50284 --- [           main] .d.f.FireflyPlaidConnector2ApplicationKt : The following 1 profile is active: "dev-mysql"
2024-08-14T21:13:16.895-04:00  INFO 50284 --- [           main] .d.f.FireflyPlaidConnector2ApplicationKt : Started FireflyPlaidConnector2ApplicationKt in 1.01 seconds (process running for 1.248)
2024-08-14T21:13:17.206-04:00 DEBUG 50284 --- [           main] n.d.f.sync.BatchSyncRunner               : Fetching Plaid data for access token fake-access-token and account ids fakeaccountid
2024-08-14T21:13:18.147-04:00 DEBUG 50284 --- [           main] n.d.f.sync.BatchSyncRunner               :  Received a batch of 0 Plaid transactions
2024-08-14T21:13:18.147-04:00 DEBUG 50284 --- [           main] n.d.f.sync.BatchSyncRunner               : Done fetching Plaid data for access token fake-access-token and account ids fakeaccountid
2024-08-14T21:13:18.147-04:00 DEBUG 50284 --- [           main] n.d.f.sync.BatchSyncRunner               : Fetching Plaid data for access token fake-access-token and account ids fakeaccountid
2024-08-14T21:13:18.753-04:00 DEBUG 50284 --- [           main] n.d.f.sync.BatchSyncRunner               :  Received a batch of 7 Plaid transactions
2024-08-14T21:13:18.753-04:00 DEBUG 50284 --- [           main] n.d.f.sync.BatchSyncRunner               : Done fetching Plaid data for access token fake-access-token and account ids fakeaccountid
2024-08-14T21:13:18.754-04:00 DEBUG 50284 --- [           main] n.d.f.transactions.TransactionConverter  : Batch sync converting Plaid transactions to Firefly transactions
2024-08-14T21:13:18.764-04:00 DEBUG 50284 --- [           main] n.d.f.sync.SyncHelper                    : Optimistic insert of 7 txs into Firefly

What is in your logs before the part you shared? Do you see the "received a batch of X Plaid transactions" log lines?

WEBENGi commented 1 month ago

Okay I got it working! The secret was mismatched this time around. But ill close this for now. Thank you for your time. Now what I need to figure out is how to set it up properly. The instructions are probably lacking some clarity but I can see all the moving parts I need to work with. Creating the accounts on ff side, linking the accounts and getting the right ids/keys from quickstart.

One thing I dont know yet Is there any use for the current balance when you retrieve the account information from quick plaid?

dvankley commented 3 weeks ago

The instructions are probably lacking some clarity

Feel free to open a PR to update the README if you have any suggestions, although I would recommend making the changes in small chunks.

dvankley commented 3 weeks ago

One thing I dont know yet Is there any use for the current balance when you retrieve the account information from quick plaid?

I don't fully understand the question here. The only relevant information from Plaid Quickstart is item ids. Is it also displaying account balance too?

WEBENGi commented 3 weeks ago

One thing I dont know yet Is there any use for the current balance when you retrieve the account information from quick plaid?

I don't fully understand the question here. The only relevant information from Plaid QuickStart is item ids. Is it also displaying account balance too?

Oh yeah I see you recommend a manual call with the command line outside of QuickStart. I found you can stay in QuickStart and scroll to the bottom (at least currently) and click the button for "get accounts" and then with the web debug tool bar open you can see the response with all the ids we want. Although it would be easier if it just showed them in the output within the QuickStart.

dvankley commented 3 weeks ago

Oh, cool, thanks for pointing that out. That's either a recent change or I didn't notice it the first time around. I'll update the docs.