[$250] Another invoice can't be sent after one is paid
If you havenโt already, check out our contributing guidelines for onboarding and email [email protected] to request to join our Slack channel!
Version Number: 9.0.66-0 Reproducible in staging?: y Reproducible in production?: y If this was caught on HybridApp, is this reproducible on New Expensify Standalone?: If this was caught during regression testing, add the test name, ID and link from TestRail: Email or phone of affected tester (no customers): Logs: https://stackoverflow.com/c/expensify/questions/4856 Expensify/Expensify Issue URL: Issue reported by: @neil-marcellini Slack conversation (hyperlinked to channel name): Expensify billpay
Action Performed:
- Go to staging.new.expensify.com
- Create a workspace if needed
- Go to More features, scroll down and enable Invoices
- Click green plus, Send invoice
- Send an invoice to User B
- As User B Go to invoice chat and pay the invoice as business
- [User A] Go to invoice report
- [User A] Click Add bank account
- [User A] In settings Add bank account
- Click on the bank account for invoicing and choose to make it the default
- Click the green plus, send a $2 to user B
- Open the invoice report
Expected Result:
The invoice report can be opened
Actual Result:
The invoice report is not found, because it failed to actually be created even though there was no error message shown in product. The Network response shows 400 Unique Constraints Violation Backlogs : https://www.expensify.com/_devportal/tools/logSearch/#query=request_id:(%228e6c7cac282da4d0-MIA%22)+AND+timestamp:[2024-11-22T21:51:56.285Z+TO+2024-11-22T23:51:56.285Z]&index=logs_expensify-031332
Workaround:
unknown
Platforms:
Which of our officially supported platforms is this issue occurring on?
- [ ] Android: Standalone
- [ ] Android: HybridApp
- [ ] Android: mWeb Chrome
- [ ] iOS: Standalone
- [ ] iOS: HybridApp
- [ ] iOS: mWeb Safari
- [x] MacOS: Chrome / Safari
- [ ] MacOS: Desktop
Screenshots/Videos
Add any screenshot/video evidence
https://github.com/user-attachments/assets/11425189-c45d-4c3e-b95a-873ffadb5657
https://github.com/user-attachments/assets/88a5178c-bc2b-46c3-ac90-b5449c2ee59d
Upwork Automation - Do Not Edit
- Upwork Job URL: https://www.upwork.com/jobs/~021861805315178904377
- Upwork Job ID: 1861805315178904377
- Last Price Increase: 2024-12-04
Issue Owner
Current Issue Owner: @allgandalf
Triggered auto assignment to @zanyrenney (Bug), see https://stackoverflow.com/c/expensify/questions/14418 for more details. Please add this bug to a GH project, as outlined in the SO.
@zanyrenney Whoops! This issue is 2 days overdue. Let's get this updated quick!
triaged the bug.
Job added to Upwork: https://www.upwork.com/jobs/~021861805315178904377
Triggered auto assignment to Contributor-plus team member for initial proposal review - @allgandalf (External)
Waiting for proposals
๐ฃ It's been a week! Do we have any satisfactory proposals yet? Do we need to adjust the bounty for this issue? ๐ธ
Not sure if this is purely FE, @neil-marcellini can you provide any more data from the logs, can you provide the data received in the logs to see if we send everything correctly ?
Yeah fair, this is probably internal, at least to identify the root cause.
@neil-marcellini @zanyrenney @allgandalf this issue was created 2 weeks ago. Are we close to a solution? Let's make sure we're treating this as a top priority. Don't hesitate to create a thread in #expensify-open-source to align faster in real time. Thanks!
@neil-marcellini any updates here ? can you share some logs from devportal ?
It looks like the problem is that we try to create the invoice room report again vs re-using the one that already exists. The invoiceRoomReportID is 1915196797357303 and that's where we get the unique constraints violation. So now it's time to figure out why that happens.
Logs
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 284 | [email protected] | staging-www1.sjc | info | Bedrock\Client - Starting a request ~~ command: 'SendInvoice' clusterName: 'auth' headers: '[authToken: '<REDACTED>' senderPolicyID: '65D0DCB20D56CBCD' receiverEmail: '[email protected]' receiverInvoiceRoomID: '0' amount: '200' currency: 'USD' comment: 't2' merchant: '(none)' date: '2024-11-22' category: '' invoiceRoomReportID: '1915196797357303' createdChatReportActionID: '7119337413948476846' invoiceReportID: '8474422852713015' createdIOUReportActionID: '5945907154987080997' reportActionID: '1873530802046189827' reportPreviewReportActionID: '680976267448613529' transactionID: '2148214281977961263' transactionThreadReportID: '4106816954743422' createdReportActionIDForThread: '6699656931864550903' idempotent: '' companyName: '' companyWebsite: '' ip: '104.28.157.233' logParam: '[email protected]' urlToNewDot: 'https://staging.new.expensify.com/' shouldReadUsingThreads: '' shouldHandleOnyxUpdates: '1' isNewDotRequest: '1' clientUpdateID: '3078029124' maxNumberOfUpdates: '500' requestID: '8e6c7cac282da4d0-MIA' lastIP: '104.28.157.233' writeConsistency: 'ASYNC' priority: '500' timeout: '110000']' |
|---|---|---|---|---|---|
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 284 | [email protected] | staging-www1.sjc | info | Bedrock\Client - APC fetch host configs ~~ 0: 'db1.sjc' 1: 'db2.sjc' 2: 'db1.lax' 3: 'db2.lax' 4: 'db1.rno' 5: 'db2.rno' |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 284 | [email protected] | staging-www1.sjc | info | Bedrock\Client - Possible hosts ~~ nonBlacklistedHosts: '[0: 'db1.sjc' 1: 'db2.sjc' 2: 'db1.rno' 3: 'db2.rno' 4: 'db2.lax' 5: 'db1.lax']' |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 284 | [email protected] | staging-www1.sjc | info | Bedrock\Client - Reusing socket ~~ host: 'db1.sjc' cluster: 'auth' pid: '2450273' |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 284 | [email protected] | db1.sjc | info | [concurrent] Beginning transaction |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 284 | [email protected] | db1.sjc | info | Checking authToken validity for accountID=2777229 / partnerID=83 / partnerUserID=expensify.cash-e000bd93-c3d2-0063-da4e-2e6914511ce7 / isValidated=true / expiresAt=1732322754363771 / isPasswordless=true |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | db1.sjc | info | CreateReport::process reportID 1915196797357303 |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | db1.sjc | info | {SQLITE} Code: 1555, Message: abort at 28 in [INSERT INTO reports ( reportID, created, state, accountID, reportName, currency ) VALUES ( 1915196797357303, '2024-11-22 22:51:56', 0, 0, 'Chat Report', 'USD' );]: UNIQUE constraint failed: reports.reportID |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | db1.sjc | info | 'read/write transaction', query failed with error #19 (UNIQUE constraint failed: reports.reportID): INSERT INTO reports ( reportID, created, state, accountID, reportName, currency ) VALUES ( 1915196797357303, '2024-11-22 22:51:56', 0, 0, 'Chat Report', 'USD' ); |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | db1.sjc | alrt | ENSURE_BUGBOT Encountered random reportID collision! It happened! |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | db1.sjc | warn | Unique Constraints Violation, command: SendInvoice |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | db1.sjc | info | command 'SendInvoice' timing info (ms): prePeek:0 (count: 0), peek:0 (count:1), process:0 (count:1), postProcess:0 (count:0), total:1, unaccounted:0, blockingCommitThreadTime:0, exclusiveTransactionLockTime:0. Commit: worker:0, sync:0. Queue: worker:0, sync:0, blocking:0, pageLock:0, escalation:0. Blocking: prePeek:0, peek:0, process:0, postProcess:0, commit:0. Upstream: peek:0, process:0, total:0, unaccounted:0. |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | staging-www1.sjc | info | Bedrock\Client - Request finished ~~ host: 'db1.sjc' command: 'SendInvoice' jsonCode: '400 Unique Constraints Violation' duration: '2' net: '0.869' wait: '0.331' proc: '0.8' commitCount: '' |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | staging-www1.sjc | info | Auth - AuthRequest #2 ~~ command: 'SendInvoice' jsonCode: '400' size: '183' duration: '2ms' host: 'db1.sjc' transactionID: '2148214281977961263' |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 285 | [email protected] | staging-www1.sjc | info | Auth - Call SendInvoice return 400 |
| 8e6c7cac282da4d0-MIA | 2024-11-22 22:51:56 286 | [email protected] | staging-www1.sjc | hmmm | Throw ExpException - 20d0858735b59a0bea5fdc18a980d9d0 ~~ message: '400 Unique Constraints Violation' exceptionMessage: 'Auth SendInvoice returned an error' exceptionFile: '/git/releases/expensify.com/535064a/lib/Auth.php' exceptionLine: '133' exceptionCode: '400' |
After some digging around I've found that we fail to get the receiverInvoiceRoomID here when sending the invoice. The reason is that we try to get it with receiver type set to individual, but it has been changed to the policy type when the receiver chooses to pay the invoice with a business bank account.
I also noticed that in App that the invoiceReceiver value still has the accountID set within it, but the type is updated to policy. I think maybe the Onyx update doesn't clear the accountID properly, though maybe that's not a big deal.
In Auth we should not be trying the get the invoice room with the receiver type sent to individual when it's been changed to policy, so is App passing the wrong parameters? I see that it's passing the receiverEmail, and in App it looks like it should probably pass the receiverInvoiceRoomID as it would do here if the invoiceChatReport.reportID is set. Evidently it's not.
2024-12-13T16:56:16.463627+00:00 expensidev2004 php-fpm: HOhGcU /api.php [email protected] !ecash9.0.76-0! ?api? [info] Processing 'SendInvoice' for 'expensify.com' from '10.2.2.1' ~~ command: 'SendInvoice' createdIOUReportActionID: '7853016652172516058' createdReportActionIDForThread: '5342542468315827578' reportActionID: '5442056646700209901' senderWorkspaceID: 'B1E844D99AF93E5C' accountID: '30' amount: '200' currency: 'USD' comment: '' merchant: '(none)' category: '' date: '2024-12-13' invoiceRoomReportID: '6356206350481224' createdChatReportActionID: '1887148289277430468' invoiceReportID: '263505571434242' reportPreviewReportActionID: '7400900744724627612' transactionID: '6793522903945149606' transactionThreadReportID: '2577528467645857' receiverEmail: '[email protected]' pusherSocketID: '810396.164154' authToken: '<REDACTED>' referer: 'ecash' platform: 'web' api_setCookie: 'false' email: '[email protected]' isFromDevEnv: 'true' appversion: '9.0.76-0' clientUpdateID: '1956' partnerName: 'expensify.com' browserGUID: '675c673071051' HTTP_CF_BOT_SCORE: '' HTTP_CF_JA3_HASH: '' HTTP_CF_JA4: ''
If the receiverInvoiceRoomID is set and the receiverEmail is not set, then Auth will hit this block and properly set the invoiceManagerID. Then we won't try and fail to get receiverInvoiceRoomID, nor will we try to create one in these blocks, and so there will be no error and the invoice will be properly created.
So it looks like the next step is to figure out why the invoiceChatReport.reportID is not set in App. I don't like that App has so much control over whether this succeeds in Auth, but I'm not sure there is a way to fix that given the design.
In this flow the user sends the second invoice to the individual (userB) via global create, and it's created as an invoice sent on the chat between userA's workspace and userB's, because userB chose to pay the invoice as a business the first time. That's actually kind of an odd UX, because once userB pays an invoice from you as a business you can't send them an invoice individually. I don't think we should force that. Maybe it's ok if userB can choose to pay it as an individual later, but I'm not sure due to this bug.
Given all that, I will fix it in App for now, then start a discussion about whether we want to change the UX.
I've been digging into how App behaves, and the first thing I found is that creating another invoice will succeed if the sender signs out and back in, and the Onyx data is refreshed. In that case when you choose the individual from global create, the app will not find an existing invoice chat report between your workspace and the individual, so it will create a new one, pass the optimistic invoiceRoomReportID, and Auth will properly create it. It seems like invoiceChatReport is always undefined in this flow, btw.
It looks like the root cause of the problem is this:
I also noticed that in App that the invoiceReceiver value still has the accountID set within it, but the type is updated to policy.
In that case when getInvoiceChatByParticipants runs it finds an invoice report with data like this. The report shown in the screenshot is the one we're viewing data for, and it's the invoice chat that used to be individual, and is now a policy receiver type.
The key part is that invoiceReceiver.accountID is still set for the individual invoice receiver type. So the function picks this report and will pass it's reportID as the invoiceRoomReportID. Then Auth tries to create a new report with that existing ID, because it can't find the receiverInvoiceRoomID which has an individual receiver type.
To fix this, I will have App's getInvoiceChatByParticipants check the receiver type before picking the report. That should be enough, but I'll also make sure the backend clears out the accountID field when the invoice is converted to the policy receiver type.
The App PR with the fix is ready to go, I just need to write the manual test and record a video.
@neil-marcellini kudos with the RCA investigation, I was ๐ฎ reading traces and logs and your explanation !! (Wish i had access to auth repo to look more ๐ฌ )
PR is ready for review!
๐ด Hopeful to get the PR merged this week
โป๏ธ PR was merged!!
๐ด PR yet to hit staging
Reviewing label has been removed, please complete the "BugZero Checklist".
The solution for this issue has been :rocket: deployed to production :rocket: in version 9.0.80-6 and is now subject to a 7-day regression period :calendar:. Here is the list of pull requests that resolve this issue:
- https://github.com/Expensify/App/pull/54138
If no regressions arise, payment will be issued on 2025-01-13. :confetti_ball:
For reference, here are some details about the assignees on this issue:
- @allgandalf requires payment (Needs manual offer from BZ)
@allgandalf @zanyrenney @allgandalf The PR fixing this issue has been merged! The following checklist (instructions) will need to be completed before the issue can be closed. Please copy/paste the BugZero Checklist from here into a new comment on this GH and complete it. If you have the K2 extension, you can simply click: [this button]
BugZero Checklist:
- [x] [Contributor] Classify the bug:
Bug classification
Source of bug:
- [ ] 1a. Result of the original design (eg. a case wasn't considered)
- [ ] 1b. Mistake during implementation
- [ ] 1c. Backend bug
- [x] 1z. Other: There is no source this case was never considered!
Where bug was reported:
- [x] 2a. Reported on production (eg. bug slipped through the normal regression and PR testing process on staging)
- [ ] 2b. Reported on staging (eg. found during regression or PR testing)
- [ ] 2d. Reported on a PR
- [ ] 2z. Other:
Who reported the bug:
- [ ] 3a. Expensify user
- [x] 3b. Expensify employee
- [ ] 3c. Contributor
- [ ] 3d. QA
- [ ] 3z. Other:
-
[x] [Contributor] The offending PR has been commented on, pointing out the bug it caused and why, so the author and reviewers can learn from the mistake.
Link to comment: N/A (This was never considered, it has been this way since the beginning)
-
[x] [Contributor] If the regression was CRITICAL (e.g. interrupts a core flow) A discussion in #expensify-open-source has been started about whether any other steps should be taken (e.g. updating the PR review checklist) in order to catch this type of bug sooner.
Link to discussion:
-
[x] [Contributor] If it was decided to create a regression test for the bug, please propose the regression test steps using the template below to ensure the same bug will not reach production again.
-
[ ] [BugZero Assignee] Create a GH issue for creating/updating the regression test once above steps have been agreed upon.
Link to issue:
Regression Test Proposal
Precondition:
Test:
- Create a workspace > Go to More features, scroll down and enable Invoices
- Click green plus, Send invoice
- Send an invoice to User B
- As User B Go to invoice chat and pay the invoice as business
- [User A] Go to invoice report
- [User A] Click Add bank account
- [User A] In settings Add bank account
- Click on the bank account for invoicing and choose to make it the default
- Click the green plus, send any amount to user B
- Open the invoice report and verify it loads successfully
Do we agree ๐ or ๐
Payment Summary
- ROLE: @allgandalf paid $(AMOUNT) via Upwork (LINK)
BugZero Checklist (@zanyrenney)
- [ ] I have verified the correct assignees and roles are listed above and updated the neccesary manual offers
- [ ] I have verified that there are no duplicate or incorrect contracts on Upwork for this job (https://www.upwork.com/ab/applicants/1861805315178904377/hired)
- [ ] I have paid out the Upwork contracts or cancelled the ones that are incorrect
- [ ] I have verified the payment summary above is correct
https://github.com/Expensify/Expensify/issues/459966
@allgandalf invited you to the job!
https://www.upwork.com/jobs/~021878885655406455636
Accepted thanks!!
can you double-check @allgandalf - it doesn't look like you have in upwork. Thanks! normally here we see "view hires" here if the offer has been accepted
payment summary
paid $250 to @allgandalf via upwork.