wesselt / bunq2ynab

Upload bunq transactions to ynab
Other
72 stars 18 forks source link

Issues with duplicates / transaction not syncing #31

Closed MagicLegend closed 10 months ago

MagicLegend commented 3 years ago

Hi!

I've had the script running for two months now. It works like a charm, except for a single critical bug. Sometimes it refuses to sync a payment between my savings to my checkings account. I suspect it thinks it's a duplicate entry, since the only thing different would be the timestamp (since the amount, source account and target account are the same?). What would be a good way to debug this? Could it have to do with the fact that it already was processing a new transaction: image

I'm also not really sure how to duplicate it; it's just that about once a week it misses one of these payments (which is really frustrating by the way). I've also had that the payment magically reappeared a day later, I guess upon the next sync?

Logs of both invocations:

timestamp timestamp severity file action message
1615295588740 START RequestId: caa7c37e-5c12-49e3-9c2c-23888f35aac0 Version: $LATEST
1615295588741 2021-03-09 13:13:08,741 INFO config.py:77 read_ssm_config Reading config from SSM
1615295590199 2021-03-09 13:13:10,198 INFO credentials.py:1087 load Found credentials in environment variables.
1615295590451 2021-03-09 13:13:10,451 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1615295590451 2021-03-09 13:13:10,451 INFO sync.py:60 populate Retrieving bunq accounts...
1615295590451 2021-03-09 13:13:10,451 INFO state.py:32 load Fetching SSM state bunq2ynab-state
1615295591404 2021-03-09 13:13:11,404 INFO sync.py:62 populate Retrieving ynab accounts...
1615295591873 2021-03-09 13:13:11,873 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1615295591873 2021-03-09 13:13:11,873 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-02-02...
1615295592364 2021-03-09 13:13:12,363 INFO sync.py:166 synchronize_account Retrieved 82 ynab transactions...
1615295592364 2021-03-09 13:13:12,364 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-02-02...
1615295593818 2021-03-09 13:13:13,817 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-30...
1615295593818 2021-03-09 13:13:13,818 INFO sync.py:175 synchronize_account Retrieved 83 bunq payments...
1615295593835 2021-03-09 13:13:13,835 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-02-24...
1615295594273 2021-03-09 13:13:14,273 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 2 duplicates.
1615295594273 2021-03-09 13:13:14,273 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1615295594273 2021-03-09 13:13:14,273 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1615295595081 END RequestId: caa7c37e-5c12-49e3-9c2c-23888f35aac0
1615295595081 REPORT RequestId: caa7c37e-5c12-49e3-9c2c-23888f35aac0 Duration: 6341.23 ms Billed Duration: 6342 ms Memory Size: 512 MB Max Memory Used: 100 MB Init Duration: 627.43 ms
1615295598689 START RequestId: b8fa9e5d-43d9-40d7-beec-3de5676785b9 Version: $LATEST
1615295598693 2021-03-09 13:13:18,693 INFO config.py:77 read_ssm_config Reading config from SSM
1615295598719 2021-03-09 13:13:18,719 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_SAVINGS_IBAN in request body
1615295598719 2021-03-09 13:13:18,719 INFO sync.py:60 populate Retrieving bunq accounts...
1615295599497 2021-03-09 13:13:19,497 INFO sync.py:62 populate Retrieving ynab accounts...
1615295599956 2021-03-09 13:13:19,956 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "SavingsAccount" to "BudgetName" - "SavingsAccount"...
1615295599956 2021-03-09 13:13:19,956 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-02-02...
1615295600428 2021-03-09 13:13:20,427 INFO sync.py:166 synchronize_account Retrieved 20 ynab transactions...
1615295600428 2021-03-09 13:13:20,428 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-02-02...
1615295601796 2021-03-09 13:13:21,796 INFO bunq_api.py:151 get_payments Retrieved back to 2019-02-15...
1615295601796 2021-03-09 13:13:21,796 INFO sync.py:175 synchronize_account Retrieved 22 bunq payments...
1615295601796 2021-03-09 13:13:21,796 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-09...
1615295602391 2021-03-09 13:13:22,390 INFO sync.py:187 synchronize_account "MagicLegend" - "SavingsAccount" to "BudgetName" - "SavingsAccount": Created 2 and patched 0 transactions. There were 2 duplicates.
1615295602391 2021-03-09 13:13:22,391 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1615295602391 2021-03-09 13:13:22,391 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1615295602980 END RequestId: b8fa9e5d-43d9-40d7-beec-3de5676785b9
1615295602980 REPORT RequestId: b8fa9e5d-43d9-40d7-beec-3de5676785b9 Duration: 4288.15 ms Billed Duration: 4289 ms Memory Size: 512 MB Max Memory Used: 100 MB
javydekoning commented 3 years ago

Can you share how you initiate the transaction? (e.g. Make payment, request + accept etc).

MagicLegend commented 3 years ago

@javydekoning I'm sorry; of course. The first was initiated by me manually accepting an direct debit on my checkings account, the second one was initiated by me making the manual payment between my savings and checkings account.

MagicLegend commented 3 years ago

Now that I think about it again; YNAB made me re-approve the manual payment I had created to resolve a previously unsynced payment between my savings and checkings account that was the same amount... Did it squash two payments together even though their timestamps differed by 4 days?

MagicLegend commented 3 years ago

Hah, I was right. Clicking on the manually created payment YNAB merged it together to two dates: image Note: There was no transfer like this on the 4th of March. This is just the date I manually added this transaction to YNAB to fix the amount in the account.

Why would it do this? I don't see any other of these payments (I make them manually, but on regular basis) having two dates. Since the balance was wrong a few times before, I guess it must have synced again and found that it missed a transaction or something.

So, to continue the research: I found the missing transfer. I can see the lambda triggered three times around that time, even though there were only two payments that day (I'm gonna guess the lambda triggers twice on trransfers between accounts?).

Important information:

Between the top-up and the payment there must have been a second or two at most. Why it triggered at 16:00 that day I'm not sure (default sync?). Anyhow; here are the full logs taken from the lambda, I hope they help:

timestamp timestamp severity file action message
1614700826147 START RequestId: 1c45549e-f42f-4f67-85e9-abd1da5b4bf7 Version: $LATEST
1614700826149 2021-03-02 16:00:26,149 INFO config.py:77 read_ssm_config Reading config from SSM
1614700827591 2021-03-02 16:00:27,591 INFO credentials.py:1087 load Found credentials in environment variables.
1614700827812 2021-03-02 16:00:27,812 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614700827812 2021-03-02 16:00:27,812 INFO sync.py:60 populate Retrieving bunq accounts...
1614700827812 2021-03-02 16:00:27,812 INFO state.py:32 load Fetching SSM state bunq2ynab-state
1614700828217 2021-03-02 16:00:28,217 INFO sync.py:62 populate Retrieving ynab accounts...
1614700828715 2021-03-02 16:00:28,714 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614700828715 2021-03-02 16:00:28,715 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614700829193 2021-03-02 16:00:29,193 INFO sync.py:166 synchronize_account Retrieved 77 ynab transactions...
1614700829193 2021-03-02 16:00:29,193 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614700830409 2021-03-02 16:00:30,397 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614700830410 2021-03-02 16:00:30,410 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614700830410 2021-03-02 16:00:30,410 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614700830885 2021-03-02 16:00:30,885 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 4 duplicates.
1614700830885 2021-03-02 16:00:30,885 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614700830885 2021-03-02 16:00:30,885 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614700831456 END RequestId: 1c45549e-f42f-4f67-85e9-abd1da5b4bf7
1614700831456 REPORT RequestId: 1c45549e-f42f-4f67-85e9-abd1da5b4bf7 Duration: 5307.96 ms Billed Duration: 5308 ms Memory Size: 512 MB Max Memory Used: 100 MB Init Duration: 599.57 ms
timestamp timestamp severity file action message
1614700823763 START RequestId: 0d9c321e-390e-4fe3-a560-9008cc854a63 Version: $LATEST
1614700823765 2021-03-02 16:00:23,765 INFO config.py:77 read_ssm_config Reading config from SSM
1614700825174 2021-03-02 16:00:25,174 INFO credentials.py:1087 load Found credentials in environment variables.
1614700825406 2021-03-02 16:00:25,406 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614700825406 2021-03-02 16:00:25,406 INFO sync.py:60 populate Retrieving bunq accounts...
1614700825406 2021-03-02 16:00:25,406 INFO state.py:32 load Fetching SSM state bunq2ynab-state
1614700825509 2021-03-02 16:00:25,509 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700825593 2021-03-02 16:00:25,593 INFO bunq.py:102 get_session_token Requesting session token...
1614700826007 2021-03-02 16:00:26,007 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700826590 2021-03-02 16:00:26,590 INFO sync.py:62 populate Retrieving ynab accounts...
1614700827112 2021-03-02 16:00:27,112 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614700827112 2021-03-02 16:00:27,112 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614700827791 2021-03-02 16:00:27,791 INFO sync.py:166 synchronize_account Retrieved 77 ynab transactions...
1614700827791 2021-03-02 16:00:27,791 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614700830239 2021-03-02 16:00:30,239 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614700830251 2021-03-02 16:00:30,251 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614700830252 2021-03-02 16:00:30,252 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614700830877 2021-03-02 16:00:30,877 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 3 and patched 0 transactions. There were 2 duplicates.
1614700830877 2021-03-02 16:00:30,877 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614700830877 2021-03-02 16:00:30,877 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614700831999 END RequestId: 0d9c321e-390e-4fe3-a560-9008cc854a63
1614700831999 REPORT RequestId: 0d9c321e-390e-4fe3-a560-9008cc854a63 Duration: 8235.48 ms Billed Duration: 8236 ms Memory Size: 512 MB Max Memory Used: 100 MB Init Duration: 582.24 ms
1614700833473 START RequestId: 8aa678f8-f42b-4563-9e73-f18bbbc04743 Version: $LATEST
1614700833476 2021-03-02 16:00:33,475 INFO config.py:77 read_ssm_config Reading config from SSM
1614700833498 2021-03-02 16:00:33,498 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614700833498 2021-03-02 16:00:33,498 INFO sync.py:60 populate Retrieving bunq accounts...
1614700833958 2021-03-02 16:00:33,958 INFO sync.py:62 populate Retrieving ynab accounts...
1614700834427 2021-03-02 16:00:34,426 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614700834427 2021-03-02 16:00:34,427 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614700834939 2021-03-02 16:00:34,939 INFO sync.py:166 synchronize_account Retrieved 78 ynab transactions...
1614700834939 2021-03-02 16:00:34,939 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614700836414 2021-03-02 16:00:36,414 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614700836414 2021-03-02 16:00:36,414 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614700836414 2021-03-02 16:00:36,414 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614700836875 2021-03-02 16:00:36,875 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614700836875 2021-03-02 16:00:36,875 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614700836875 2021-03-02 16:00:36,875 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614700837746 END RequestId: 8aa678f8-f42b-4563-9e73-f18bbbc04743
1614700837746 REPORT RequestId: 8aa678f8-f42b-4563-9e73-f18bbbc04743 Duration: 4271.25 ms Billed Duration: 4272 ms Memory Size: 512 MB Max Memory Used: 100 MB
1614700894212 START RequestId: f2f698c8-edef-4299-a5c1-ae9077bd27ae Version: $LATEST
1614700894214 2021-03-02 16:01:34,214 INFO config.py:77 read_ssm_config Reading config from SSM
1614700894279 2021-03-02 16:01:34,279 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614700894279 2021-03-02 16:01:34,279 INFO sync.py:60 populate Retrieving bunq accounts...
1614700894336 2021-03-02 16:01:34,336 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700894414 2021-03-02 16:01:34,414 INFO bunq.py:102 get_session_token Requesting session token...
1614700894660 2021-03-02 16:01:34,660 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700895208 2021-03-02 16:01:35,208 INFO sync.py:62 populate Retrieving ynab accounts...
1614700895671 2021-03-02 16:01:35,671 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614700895671 2021-03-02 16:01:35,671 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614700896131 2021-03-02 16:01:36,131 INFO sync.py:166 synchronize_account Retrieved 78 ynab transactions...
1614700896131 2021-03-02 16:01:36,131 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614700897315 2021-03-02 16:01:37,314 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614700897315 2021-03-02 16:01:37,315 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614700897315 2021-03-02 16:01:37,315 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614700897860 2021-03-02 16:01:37,860 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614700897860 2021-03-02 16:01:37,860 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614700897860 2021-03-02 16:01:37,860 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614700898461 END RequestId: f2f698c8-edef-4299-a5c1-ae9077bd27ae
1614700898461 REPORT RequestId: f2f698c8-edef-4299-a5c1-ae9077bd27ae Duration: 4248.04 ms Billed Duration: 4249 ms Memory Size: 512 MB Max Memory Used: 100 MB

timestamp timestamp severity file action message
1614700896297 START RequestId: 1a411aac-1597-4ebd-82e1-b91352bf7349 Version: $LATEST
1614700896302 2021-03-02 16:01:36,301 INFO config.py:77 read_ssm_config Reading config from SSM
1614700896357 2021-03-02 16:01:36,357 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_SAVINGS_IBAN in request body
1614700896357 2021-03-02 16:01:36,357 INFO sync.py:60 populate Retrieving bunq accounts...
1614700896413 2021-03-02 16:01:36,413 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700896502 2021-03-02 16:01:36,501 INFO bunq.py:102 get_session_token Requesting session token...
1614700896661 2021-03-02 16:01:36,661 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700897200 2021-03-02 16:01:37,200 INFO sync.py:62 populate Retrieving ynab accounts...
1614700897660 2021-03-02 16:01:37,659 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "SavingsAccount" to "BudgetName" - "SavingsAccount"...
1614700897660 2021-03-02 16:01:37,660 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614700898098 2021-03-02 16:01:38,098 INFO sync.py:166 synchronize_account Retrieved 18 ynab transactions...
1614700898098 2021-03-02 16:01:38,098 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614700899119 2021-03-02 16:01:39,118 INFO bunq_api.py:151 get_payments Retrieved back to 2019-02-15...
1614700899119 2021-03-02 16:01:39,119 INFO sync.py:175 synchronize_account Retrieved 20 bunq payments...
1614700899119 2021-03-02 16:01:39,119 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614700899573 2021-03-02 16:01:39,573 INFO sync.py:187 synchronize_account "MagicLegend" - "SavingsAccount" to "BudgetName" - "SavingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614700899573 2021-03-02 16:01:39,573 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614700899573 2021-03-02 16:01:39,573 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614700900029 END RequestId: 1a411aac-1597-4ebd-82e1-b91352bf7349
1614700900029 REPORT RequestId: 1a411aac-1597-4ebd-82e1-b91352bf7349 Duration: 3728.20 ms Billed Duration: 3729 ms Memory Size: 512 MB Max Memory Used: 100 MB
1614700957343 START RequestId: 2ef53d37-70ee-4353-9a32-4f6d03b86170 Version: $LATEST
1614700957347 2021-03-02 16:02:37,347 INFO config.py:77 read_ssm_config Reading config from SSM
1614700957390 2021-03-02 16:02:37,389 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614700957390 2021-03-02 16:02:37,389 INFO sync.py:60 populate Retrieving bunq accounts...
1614700957439 2021-03-02 16:02:37,439 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700957518 2021-03-02 16:02:37,517 INFO bunq.py:102 get_session_token Requesting session token...
1614700957812 2021-03-02 16:02:37,812 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614700958668 2021-03-02 16:02:38,668 INFO sync.py:62 populate Retrieving ynab accounts...
1614700959132 2021-03-02 16:02:39,131 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614700959132 2021-03-02 16:02:39,132 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614700959606 2021-03-02 16:02:39,606 INFO sync.py:166 synchronize_account Retrieved 78 ynab transactions...
1614700959606 2021-03-02 16:02:39,606 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614700960978 2021-03-02 16:02:40,978 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614700960978 2021-03-02 16:02:40,978 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614700960979 2021-03-02 16:02:40,979 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614700961447 2021-03-02 16:02:41,447 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614700961447 2021-03-02 16:02:41,447 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614700961447 2021-03-02 16:02:41,447 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614700962569 END RequestId: 2ef53d37-70ee-4353-9a32-4f6d03b86170
1614700962569 REPORT RequestId: 2ef53d37-70ee-4353-9a32-4f6d03b86170 Duration: 5222.18 ms Billed Duration: 5223 ms Memory Size: 512 MB Max Memory Used: 100 MB
1614701020612 START RequestId: 4bf62393-f490-4462-8020-e8c0fe9a5df8 Version: $LATEST
1614701020616 2021-03-02 16:03:40,616 INFO config.py:77 read_ssm_config Reading config from SSM
1614701020668 2021-03-02 16:03:40,668 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614701020668 2021-03-02 16:03:40,668 INFO sync.py:60 populate Retrieving bunq accounts...
1614701020728 2021-03-02 16:03:40,728 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614701020812 2021-03-02 16:03:40,812 INFO bunq.py:102 get_session_token Requesting session token...
1614701021109 2021-03-02 16:03:41,109 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614701021635 2021-03-02 16:03:41,635 INFO sync.py:62 populate Retrieving ynab accounts...
1614701022138 2021-03-02 16:03:42,138 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614701022138 2021-03-02 16:03:42,138 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614701022592 2021-03-02 16:03:42,592 INFO sync.py:166 synchronize_account Retrieved 78 ynab transactions...
1614701022592 2021-03-02 16:03:42,592 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614701023637 2021-03-02 16:03:43,620 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614701023637 2021-03-02 16:03:43,637 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614701023637 2021-03-02 16:03:43,637 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614701024131 2021-03-02 16:03:44,131 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614701024131 2021-03-02 16:03:44,131 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614701024131 2021-03-02 16:03:44,131 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614701024626 END RequestId: 4bf62393-f490-4462-8020-e8c0fe9a5df8
1614701024626 REPORT RequestId: 4bf62393-f490-4462-8020-e8c0fe9a5df8 Duration: 4011.16 ms Billed Duration: 4012 ms Memory Size: 512 MB Max Memory Used: 101 MB
1614701083693 START RequestId: 63d9ddc7-9093-4380-997f-4fda16372121 Version: $LATEST
1614701083697 2021-03-02 16:04:43,697 INFO config.py:77 read_ssm_config Reading config from SSM
1614701083748 2021-03-02 16:04:43,748 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614701083748 2021-03-02 16:04:43,748 INFO sync.py:60 populate Retrieving bunq accounts...
1614701083783 2021-03-02 16:04:43,783 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614701083865 2021-03-02 16:04:43,865 INFO bunq.py:102 get_session_token Requesting session token...
1614701084180 2021-03-02 16:04:44,180 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614701084942 2021-03-02 16:04:44,941 INFO sync.py:62 populate Retrieving ynab accounts...
1614701085429 2021-03-02 16:04:45,429 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614701085429 2021-03-02 16:04:45,429 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614701085921 2021-03-02 16:04:45,921 INFO sync.py:166 synchronize_account Retrieved 78 ynab transactions...
1614701085921 2021-03-02 16:04:45,921 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614701087099 2021-03-02 16:04:47,099 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614701087099 2021-03-02 16:04:47,099 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614701087100 2021-03-02 16:04:47,100 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614701087592 2021-03-02 16:04:47,592 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614701087592 2021-03-02 16:04:47,592 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614701087592 2021-03-02 16:04:47,592 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614701088031 END RequestId: 63d9ddc7-9093-4380-997f-4fda16372121
1614701088031 REPORT RequestId: 63d9ddc7-9093-4380-997f-4fda16372121 Duration: 4335.75 ms Billed Duration: 4336 ms Memory Size: 512 MB Max Memory Used: 101 MB
1614701146811 START RequestId: fb6b00e6-772a-4cad-b5af-0f6ccdba4f35 Version: $LATEST
1614701146815 2021-03-02 16:05:46,815 INFO config.py:77 read_ssm_config Reading config from SSM
1614701146869 2021-03-02 16:05:46,868 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1614701146869 2021-03-02 16:05:46,869 INFO sync.py:60 populate Retrieving bunq accounts...
1614701146907 2021-03-02 16:05:46,906 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614701146999 2021-03-02 16:05:46,998 INFO bunq.py:102 get_session_token Requesting session token...
1614701147358 2021-03-02 16:05:47,357 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1614701147927 2021-03-02 16:05:47,927 INFO sync.py:62 populate Retrieving ynab accounts...
1614701148380 2021-03-02 16:05:48,379 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1614701148380 2021-03-02 16:05:48,380 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-01-26...
1614701148855 2021-03-02 16:05:48,855 INFO sync.py:166 synchronize_account Retrieved 78 ynab transactions...
1614701148855 2021-03-02 16:05:48,855 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-01-26...
1614701149963 2021-03-02 16:05:49,963 INFO bunq_api.py:151 get_payments Retrieved back to 2020-11-18...
1614701149963 2021-03-02 16:05:49,963 INFO sync.py:175 synchronize_account Retrieved 80 bunq payments...
1614701149963 2021-03-02 16:05:49,963 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-03-02...
1614701150403 2021-03-02 16:05:50,403 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 3 duplicates.
1614701150403 2021-03-02 16:05:50,403 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1614701150404 2021-03-02 16:05:50,403 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1614701151053 END RequestId: fb6b00e6-772a-4cad-b5af-0f6ccdba4f35
1614701151053 REPORT RequestId: fb6b00e6-772a-4cad-b5af-0f6ccdba4f35 Duration: 4238.88 ms Billed Duration: 4239 ms Memory Size: 512 MB Max Memory Used: 101 MB

wesselt commented 3 years ago

Hi @MagicLegend,

Thanks for your report. I remember transfers were particularly tricky. The last commit is even called "Simpler transfer detection" because I couldn't get the more complete schemes to work. The current version looks at the IBANs involved, and if one of them is for a Bunq account that is also being synched, it marks the transaction as a transfer. This causes YNAB to create two transactions in two accounts. When the second account comes up, YNAB has already created the transaction there, so it should be skipped.

How can I reproduce your problem on my test budget?

Kind regards, Wessel

MagicLegend commented 3 years ago

Hi Wessel,

That flow sounds like it makes sense. I'm not quite sure where it went wrong this time; and I hoped you were able to deduct something from the logging.

I have just tried to reproduce it myself; but I'm afraid there is some odd race condition at play here. Making two identical payments in a very short amount of time (< 30s) does not appear to reproduce it - at least for when I just tried it. Perhaps the even tighter creation of the two payments can reproduce it. I will try this later tonight when I'm at the store again. I'll let you know the results.

Is there additional logging I can enable in the Lambda to aid with the resolving of this?

Thank you.

wesselt commented 3 years ago

Is there additional logging I can enable in the Lambda to aid with the resolving of this?

The --log-level parameter or log_level in config.json can be set to INFO or DEBUG. Especially the later generates a ton of output.

MagicLegend commented 3 years ago

Hey! It went okay since the last comment, but today it bugged out big time again. I still suspect it has to do with payments that are made within a minute of eachother, since that's where it went wrong again. I'll post the logging I can find here later today.

Did you happen to run into this? Would a full resync perhaps also solve it?

wesselt commented 3 years ago

Hey! Thanks for your report. I haven't seen any problems, it's been running perfectly for me.

What happened exactly? Do you sync one or multiple accounts? Was the payment between your own accounts or a different account? Logging will be helpful, especially if it contains the JSON with payments from bunq.

MagicLegend commented 3 years ago

Hey! I'm sorry, I got lost in work & life. But, fear not, I have another sync mistake for you! I did not enable the excessive logging, but I think I just enabled it. However, let's get into it with what we have:

Do you sync one or multiple accounts? I sync multiple accounts - although only two (savings & checkings) are used intensively.

What happened last time: I had 1 payment on 13-05-2021, an incoming payment from ING. I can see in the cloud logs that a sync was triggered, however, the payment has never showed up in YNAB:

timestamp timestamp severity file action message
1620886242375 START RequestId: d3e1ca81-e851-4c53-8477-4dc14e155bee Version: $LATEST
1620886242376 2021-05-13 06:10:42,376 INFO config.py:77 read_ssm_config Reading config from SSM
1620886243794 2021-05-13 06:10:43,794 INFO credentials.py:1087 load Found credentials in environment variables.
1620886244039 2021-05-13 06:10:44,039 INFO lambda_function.py:41 get_iban_from_event Found IBAN NL12BUNQ_CHECKINGS_IBAN in request body
1620886244040 2021-05-13 06:10:44,039 INFO sync.py:60 populate Retrieving bunq accounts...
1620886244040 2021-05-13 06:10:44,040 INFO state.py:32 load Fetching SSM state bunq2ynab-state
1620886244144 2021-05-13 06:10:44,144 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1620886244234 2021-05-13 06:10:44,234 INFO bunq.py:102 get_session_token Requesting session token...
1620886244591 2021-05-13 06:10:44,591 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1620886245413 2021-05-13 06:10:45,413 INFO sync.py:62 populate Retrieving ynab accounts...
1620886245931 2021-05-13 06:10:45,931 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1620886245931 2021-05-13 06:10:45,931 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-04-08...
1620886246474 2021-05-13 06:10:46,473 INFO sync.py:166 synchronize_account Retrieved 87 ynab transactions...
1620886246474 2021-05-13 06:10:46,474 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-04-08...
1620886248331 2021-05-13 06:10:48,331 INFO bunq_api.py:151 get_payments Retrieved back to 2021-02-14...
1620886248331 2021-05-13 06:10:48,331 INFO sync.py:175 synchronize_account Retrieved 88 bunq payments...
1620886248332 2021-05-13 06:10:48,332 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-05-13...
1620886249079 2021-05-13 06:10:49,078 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 2 and patched 0 transactions. There were 1 duplicates.
1620886249079 2021-05-13 06:10:49,079 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1620886249079 2021-05-13 06:10:49,079 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1620886249796 END RequestId: d3e1ca81-e851-4c53-8477-4dc14e155bee
1620886249796 REPORT RequestId: d3e1ca81-e851-4c53-8477-4dc14e155bee Duration: 7420.12 ms Billed Duration: 7421 ms Memory Size: 512 MB Max Memory Used: 100 MB Init Duration: 590.87 ms

Note that the lambda was triggered at the regular 8h intervals as well - if you want I can show the full logs for those as well. The interesting lines:

timestamp severity file action message
2021-05-13 00:32:25,590 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions. There were 1 duplicates.
2021-05-13 08:32:25,367 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 2 and patched 0 transactions.
2021-05-13 16:32:26,087 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions.

Then, today's incident:

(times in UTC+3) All activity on my accounts today - which is only the checkings account: 09:41: Payment 1 of 4,40 10:37: Payment 2 of 4,20 12:29: Payment 3 of 4,20 13:47: Inflow 1

Payment 1 and 2 are to the same company, invoiced on the same Mastercard card. Payment 3 is an Apple Pay payment from a Maestro card. However, it shows up in YNAB like all three payments are to the same company of payment 1 & 2. The lambda has triggered on the following times today:

I'm going to assume the 12:29 log is the most interesting, so let me post it here: timestamp timestamp severity file action message
1622798957558 START RequestId: 5bc723de-0cf8-4d23-9cef-bfaed5bd6b46 Version: $LATEST
1622798957560 2021-06-04 09:29:17,559 INFO config.py:77 read_ssm_config Reading config from SSM
1622798958999 2021-06-04 09:29:18,999 INFO credentials.py:1087 load Found credentials in environment variables.
1622798959256 2021-06-04 09:29:19,255 INFO lambda_function.py:41 get_iban_from_event Found IBAN CheckingsAccount in request body
1622798959256 2021-06-04 09:29:19,256 INFO sync.py:60 populate Retrieving bunq accounts...
1622798959256 2021-06-04 09:29:19,256 INFO state.py:32 load Fetching SSM state bunq2ynab-state
1622798959401 2021-06-04 09:29:19,401 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1622798959490 2021-06-04 09:29:19,489 INFO bunq.py:102 get_session_token Requesting session token...
1622798959693 2021-06-04 09:29:19,692 INFO state.py:65 write_state Writing SSM state bunq2ynab-state
1622798960517 2021-06-04 09:29:20,517 INFO sync.py:62 populate Retrieving ynab accounts...
1622798960949 2021-06-04 09:29:20,949 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1622798960949 2021-06-04 09:29:20,949 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-04-30...
1622798961388 2021-06-04 09:29:21,387 INFO sync.py:166 synchronize_account Retrieved 76 ynab transactions...
1622798961388 2021-06-04 09:29:21,387 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-04-30...
1622798963318 2021-06-04 09:29:23,318 INFO bunq_api.py:151 get_payments Retrieved back to 2021-03-06...
1622798963318 2021-06-04 09:29:23,318 INFO sync.py:175 synchronize_account Retrieved 77 bunq payments...
1622798963338 2021-06-04 09:29:23,338 INFO ynab.py:150 upload_transactions Creating transactions up to 2021-06-04...
1622798963982 2021-06-04 09:29:23,981 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 1 and patched 0 transactions.
1622798963982 2021-06-04 09:29:23,981 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1622798963982 2021-06-04 09:29:23,982 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1622798964514 END RequestId: 5bc723de-0cf8-4d23-9cef-bfaed5bd6b46
1622798964514 REPORT RequestId: 5bc723de-0cf8-4d23-9cef-bfaed5bd6b46 Duration: 6955.16 ms Billed Duration: 6956 ms Memory Size: 512 MB Max Memory Used: 100 MB Init Duration: 623.16 ms
1622798964707 START RequestId: de64affb-3885-4e03-b4ad-a44059d35ec1 Version: $LATEST
1622798964711 2021-06-04 09:29:24,711 INFO config.py:77 read_ssm_config Reading config from SSM
1622798964739 2021-06-04 09:29:24,739 INFO lambda_function.py:41 get_iban_from_event Found IBAN CheckingsAccount in request body
1622798964739 2021-06-04 09:29:24,739 INFO sync.py:60 populate Retrieving bunq accounts...
1622798965163 2021-06-04 09:29:25,163 INFO sync.py:62 populate Retrieving ynab accounts...
1622798965588 2021-06-04 09:29:25,588 INFO sync.py:154 synchronize_account Synching "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount"...
1622798965588 2021-06-04 09:29:25,588 INFO sync.py:163 synchronize_account Reading ynab transactions from 2021-04-30...
1622798966013 2021-06-04 09:29:26,013 INFO sync.py:166 synchronize_account Retrieved 77 ynab transactions...
1622798966013 2021-06-04 09:29:26,013 INFO sync.py:172 synchronize_account Reading bunq payments from 2021-04-30...
1622798966982 2021-06-04 09:29:26,981 INFO bunq_api.py:151 get_payments Retrieved back to 2021-03-06...
1622798966982 2021-06-04 09:29:26,982 INFO sync.py:175 synchronize_account Retrieved 77 bunq payments...
1622798966983 2021-06-04 09:29:26,982 INFO sync.py:187 synchronize_account "MagicLegend" - "CheckingsAccount" to "BudgetName" - "CheckingsAccount": Created 0 and patched 0 transactions.
1622798966997 2021-06-04 09:29:26,997 INFO lambda_function.py:13 add_callbacks SSM callback = "https://execute-api.eu-central-1.amazonaws.com/bunq2ynab-lambda"
1622798966997 2021-06-04 09:29:26,997 INFO lambda_function.py:16 add_callbacks Adding callbacks...
1622798967499 END RequestId: de64affb-3885-4e03-b4ad-a44059d35ec1
1622798967499 REPORT RequestId: de64affb-3885-4e03-b4ad-a44059d35ec1 Duration: 2789.20 ms Billed Duration: 2790 ms Memory Size: 512 MB Max Memory Used: 100 MB

If you want I can share more concrete details with you in private, am I correct in that you are in the BunqDesktop Telegram chat?

If I find more issues with the extensive logging enabled, I'll let you know for sure!

MagicLegend commented 3 years ago

Holy cow it generates a lot of data on DEBUG... Could you maybe create a logging level in between that logs what you think you need? Now it logs payments from 2 months ago as well :smile: I doubt that's useful ;)

wesselt commented 3 years ago

Thanks for the logs! The lines with "duplicate" look suspicious. YNAB has an increasing number for each transaction for the same amount on the same day called "occurrence". I'll try to calculate it in a different way.

How can I give you a new version to test?

MagicLegend commented 3 years ago

@wesselt Sorry, I totally missed the notification in all the work-notifications :sweat_smile: I have sent you a message on what I think is your Telegram. Please contact me there!

wesselt commented 3 years ago

Hi @MagicLegend, Javy reported a similar issue. He said the payee of the original payment overwrote the other payment. This was due to a pretty large bug: the code that calculated occurrence assumed ascended ordering, but the payments where ordered the other way around. I've now fixed the bug and Javy has updated the Serverless script.