RFC: facilitate the debug when a contract fails to create the invoice (from a batch run)

[jcdrubay]

Is your feature request related to a problem?

When running the scheduler to create invoices, in case of exception, it can be tricky to know which contract is the source of the problem as the contract name / id are not visible, even in the logs.

Describe the solution you'd like

At least, display in the logs an error message which specifies the contract database ID which is the source of the exception.

Describe alternatives you've considered

Since invoices are created in batch and that we want to keep this to speed up invoice creation process from contracts, in case of exception do a retry the generation of invoices contract by contract (one by one) for the sole purpose of displaying an helpful log.

Suggested code

In contract/models/contract.py:

Replace

    def _recurring_create_invoice(self, date_ref=False):
        invoices_values = self._prepare_recurring_invoices_values(date_ref)
        moves = self.env["account.move"].create(invoices_values)
        self._invoice_followers(moves)
        self._compute_recurring_next_date()
        return moves

By

    def _recurring_create_invoice(self, date_ref=False, disable_raise=True):
        try:
            invoices_values = self._prepare_recurring_invoices_values(date_ref)
            moves = self.env["account.move"].create(invoices_values)
            self._invoice_followers(moves)
            self._compute_recurring_next_date()
            return moves
        except Exception as e:
            import logging
            logging.error("Exception in _recurring_create_invoice: %s", e)
            for rec in self:
                logging.info("Retrying for contract: %s", rec)
                rec._recurring_create_invoice(date_ref=date_ref, disable_raise=False)
            raise  # We should always raise because the list of invoice is expected in
            # return

or by this one raising a UserError

def _recurring_create_invoice(self, date_ref=False, disable_raise=True):
        try:
            invoices_values = self._prepare_recurring_invoices_values(date_ref)
            moves = self.env["account.move"].create(invoices_values)
            self._invoice_followers(moves)
            self._compute_recurring_next_date()
            return moves
        except Exception as e:
            import logging
            msg = "Retrying for contract: %s", rec
            logging.error("Exception in _recurring_create_invoice: %s", e)
            for rec in self:
                logging.info(msg)
                try:
                    rec._recurring_create_invoice(date_ref=date_ref, disable_raise=False)
                except Exception as e:
                     raise UserEror(_("The contract with name %(name)s fails to generate invoice. Try from the contract for more details.", ("name": rec.name)))
            raise  # We should always raise because the list of invoice is expected in
            # return

[pedrobaeza]

I don't agree on that, as that supposes to do 2 times the same process. It's better to log info/debug message each time you are invoicing a contract, so when it hangs, last contract logged is the one with the error.

[jcdrubay]

Thanks for answering so fast @pedrobaeza

I am probably mistaken but it seems to me that invoices are created with a batch create:

invoices_values = self._prepare_recurring_invoices_values(date_ref)
moves = self.env["account.move"].create(invoices_values)

and I think it is good like this so we can have better performance when there are no issues. We would run two times only in case of exception.

Also, the exception could occur either in _prepare_recurring_invoices_values or in create.

I cannot imagine how to implement the solution you describe.

Maybe with 2 logs:

• one in the loop on contract of _prepare_recurring_invoices_values.
• one in the create of account.move.line when "contract_line_id" is set

[pedrobaeza]

OK, correct, but what are the root causes to fail this? I don't have such problem yet, and going here to ease a problem in other part may not be the correct path.

[jcdrubay]

For us and for some customers, there are regularly some new contracts which have not been input correctly or some new constraints added on invoices which will block the invoice generation from contract.

Each time, the accountant will need support to find out which contract is blocking the process. And each time a developer needs to debug to find out which is the contract blocking the invoicing process.

[pedrobaeza]

OK, I see. Then I would propose a flag to pass to the method with default value to do it grouped, and put such flag in the wizard mentioned in the other issue, and if something fails with this flag activated doing it serialized, then show which contract fails. What do you think?

[jcdrubay]

It sounds good to me. I will submit a PR. Thanks for your time to review this RFC.

I will also add this flag to the cron if you don't mind.

[pedrobaeza]

I prefer not. Cron job should be executed as fast as possible. Only when the cron fails, you do the manual debug with the wizard.

[jcdrubay]

Actually, we have this code in the wizard to create contracts:

    def create_invoice(self):
        self.ensure_one()
        invoices = self.env["account.move"]
        for contract in self.contract_to_invoice_ids:
            invoices |= contract.recurring_create_invoice()
            ...

Which means that contracts are already processed one by one from the wizard, while they are processed in batch from the wizard.

I plan to catch the UserError and re-raise the error message enriched with the contract info.

something like this:

    def create_invoice(self):
        self.ensure_one()
        invoices = self.env["account.move"]
        for contract in self.contract_to_invoice_ids:
            try:
                invoices |= contract.recurring_create_invoice()
            except UserError as ue:
                raise UserError(
                    _(
                        "Failed to process the contract %(name)s [id: %(id)s]: %(ue)s",
                        {"name": contract.name, "id": contract.id, "ue": str(ue)}
                    )
                )

            ...

[pedrobaeza]

Yeah, seems good

[github-actions[bot]]

There hasn't been any activity on this issue in the past 6 months, so it has been marked as stale and it will be closed automatically if no further activity occurs in the next 30 days. If you want this issue to never become stale, please ask a PSC member to apply the "no stale" label.