Why is time_total much higher than the sum of other reported times?

[alexbuyval]

First of all, thanks a lot for the great l4acados project!

I’m using ResidualLearningMPC on a pendulum-on-cart model. The MLP residual model has 2 hidden layers with 32 neurons each. During closed-loop runs, I see logs like:
Time total: 87.915 ms, feedback: 0.154 ms, preparation: 0.727 ms,to_tensor: 5.723 ms, residual: 0.374 ms, nominal: 0.114 ms
The time_total (~87.9 ms) is far larger than the sum of the sub-timings (~7.1 ms). Could you clarify:
What’s included in time_total that isn’t in feedback/preparation/to_tensor/residual/nominal?
Are there additional phases (overhead, Python↔C crossings, memory copies) contributing to time_total?
Any tips to measure or reduce this gap?

[lahramon]

Hi, and sorry for the late response!
Can you provide which exact timings you are referring to (see get_stats interface)?

In case you are running many iterations, one factor could be that time_feedback and time_preparation do only provide the value of the last iteration, not the value for all iterations, which is in line with the functionality of the acados Python interface.
I hope this helps!

[alexbuyval]

Hi.

Yes, I used get_stats interface. I hope the code below clarify it more.

    for i in range(n_sim_steps):
        # Set current state
        solver.set(0, "lbx", simX[i, :])
        solver.set(0, "ubx", simX[i, :])
        solver.set(0, "x", simX[i, :])
        
        # Solve OCP
        status = solver.solve()

        t_total = solver.get_stats('time_tot')*1000
        t_feedback = solver.get_stats('time_feedback')*1000
        t_preparation = solver.get_stats('time_preparation')*1000
        if use_residual_model:
            t_to_tensor = solver.residual_model.to_tensor_time*1000
            t_residual = solver.time_residual[0]*1000
            t_nominal = solver.time_nominal[0]*1000 
        else:
            t_to_tensor = 0.0
            t_residual = 0.0
            t_nominal = 0.0

        print(f"Time total: {t_total:.3f} ms, feedback: {t_feedback:.3f} ms, preparation: {t_preparation:.3f} ms, to_tensor: {t_to_tensor:.3f} ms, residual: {t_residual:.3f} ms, nominal: {t_nominal:.3f} ms")

I run only one SQP_RTI iteration before the time output, so I am still confused regarding the total time.

[lahramon]

Thanks - can you check the value of solver.time_iter and the acados solver option nlp_solver_max_iter? time_tot should be the sum of times for all iterations, which would only significantly differ from time_feedback + time_preparation in case more iterations are run.