Improved logger for SNES solver

[RemDelaporteMathurin]

Following @jorgensd suggestion we should implement our own logger for the new SNES solver and/or the KSP solve:

from mpi4py import MPI

import dolfinx.fem.petsc
import ufl


mesh = dolfinx.mesh.create_unit_square(MPI.COMM_WORLD, 10, 10)
V = dolfinx.fem.functionspace(mesh, ("Lagrange", 1))
u = dolfinx.fem.Function(V)

v = ufl.TestFunction(V)
x = ufl.SpatialCoordinate(mesh)
F = ufl.inner((u + 0.1) ** 2, v) * ufl.dx - ufl.inner(x[0] + x[1], v) * ufl.dx

solver = dolfinx.fem.petsc.NonlinearProblem(
    F,
    u,
    petsc_options_prefix="test",
    petsc_options={
        "snes_type": "newtonls",
        "snes_linesearch_type": "basic",
        "ksp_type": "cg",
        "pc_type": "jacobi",
        "snes_error_if_not_converged": True,
        "ksp_error_If_not_converged": True,
    },
)


def SnesMonitor(snes, iter, rnorm):
    if MPI.COMM_WORLD.rank == 0:
        dolfinx.log.log(dolfinx.log.LogLevel.DEBUG, f"SNES {iter=} {rnorm=:.5e}")


def KSPMonitor(ksp, iter, rnorm):
    if MPI.COMM_WORLD.rank == 0:
        dolfinx.log.log(dolfinx.log.LogLevel.DEBUG, f"KSP {iter=} {rnorm=:.5e}")


solver.solver.setMonitor(SnesMonitor)
solver.solver.getKSP().setMonitor(KSPMonitor)

dolfinx.log.set_log_level(dolfinx.log.LogLevel.INFO)
solver.solve()
print("Here", flush=True)
u.x.array[:] = 0.0
dolfinx.log.set_log_level(dolfinx.log.LogLevel.DEBUG)
solver.solve()

print("Again", flush=True)

Produces:

Here
[2026-01-30 19:11:50.207] [debug] SNES iter=0 rnorm=1.00943e-01
[2026-01-30 19:11:50.208] [debug] KSP iter=0 rnorm=1.18656e+02
[2026-01-30 19:11:50.208] [debug] KSP iter=1 rnorm=2.04703e+00
[2026-01-30 19:11:50.208] [debug] KSP iter=2 rnorm=3.97473e-01
[2026-01-30 19:11:50.208] [debug] KSP iter=3 rnorm=1.25271e-01
[2026-01-30 19:11:50.208] [debug] KSP iter=4 rnorm=3.75967e-02
[2026-01-30 19:11:50.208] [debug] KSP iter=5 rnorm=1.12621e-02
[2026-01-30 19:11:50.208] [debug] KSP iter=6 rnorm=2.94067e-03
[2026-01-30 19:11:50.208] [debug] KSP iter=7 rnorm=1.19636e-03
[2026-01-30 19:11:50.208] [debug] KSP iter=8 rnorm=3.84433e-04
[2026-01-30 19:11:50.208] [debug] SNES iter=1 rnorm=3.27225e+00
[2026-01-30 19:11:50.208] [debug] KSP iter=0 rnorm=5.84664e+01
[2026-01-30 19:11:50.208] [debug] KSP iter=1 rnorm=1.40899e+00
[2026-01-30 19:11:50.208] [debug] KSP iter=2 rnorm=2.56435e-01
[2026-01-30 19:11:50.208] [debug] KSP iter=3 rnorm=7.83224e-02
[2026-01-30 19:11:50.209] [debug] KSP iter=4 rnorm=2.37615e-02
[2026-01-30 19:11:50.209] [debug] KSP iter=5 rnorm=7.09366e-03
[2026-01-30 19:11:50.209] [debug] KSP iter=6 rnorm=2.18399e-03
[2026-01-30 19:11:50.209] [debug] KSP iter=7 rnorm=9.17072e-04
[2026-01-30 19:11:50.209] [debug] KSP iter=8 rnorm=3.42421e-04
[2026-01-30 19:11:50.209] [debug] SNES iter=2 rnorm=7.94238e-01
[2026-01-30 19:11:50.209] [debug] KSP iter=0 rnorm=2.73856e+01
[2026-01-30 19:11:50.209] [debug] KSP iter=1 rnorm=6.51996e-01
[2026-01-30 19:11:50.209] [debug] KSP iter=2 rnorm=1.23954e-01
[2026-01-30 19:11:50.209] [debug] KSP iter=3 rnorm=3.79617e-02
[2026-01-30 19:11:50.209] [debug] KSP iter=4 rnorm=1.15046e-02
[2026-01-30 19:11:50.209] [debug] KSP iter=5 rnorm=3.44549e-03
[2026-01-30 19:11:50.209] [debug] KSP iter=6 rnorm=1.05694e-03
[2026-01-30 19:11:50.209] [debug] KSP iter=7 rnorm=4.34063e-04
[2026-01-30 19:11:50.209] [debug] KSP iter=8 rnorm=1.60589e-04
[2026-01-30 19:11:50.210] [debug] SNES iter=3 rnorm=1.76924e-01
[2026-01-30 19:11:50.210] [debug] KSP iter=0 rnorm=1.08085e+01
[2026-01-30 19:11:50.210] [debug] KSP iter=1 rnorm=2.61704e-01
[2026-01-30 19:11:50.210] [debug] KSP iter=2 rnorm=5.37957e-02
[2026-01-30 19:11:50.210] [debug] KSP iter=3 rnorm=1.66686e-02
[2026-01-30 19:11:50.210] [debug] KSP iter=4 rnorm=5.06807e-03
[2026-01-30 19:11:50.210] [debug] KSP iter=5 rnorm=1.53103e-03
[2026-01-30 19:11:50.210] [debug] KSP iter=6 rnorm=4.73391e-04
[2026-01-30 19:11:50.210] [debug] KSP iter=7 rnorm=1.85648e-04
[2026-01-30 19:11:50.210] [debug] KSP iter=8 rnorm=6.83191e-05
[2026-01-30 19:11:50.210] [debug] SNES iter=4 rnorm=2.89091e-02
[2026-01-30 19:11:50.211] [debug] KSP iter=0 rnorm=2.56927e+00
[2026-01-30 19:11:50.211] [debug] KSP iter=1 rnorm=7.15442e-02
[2026-01-30 19:11:50.211] [debug] KSP iter=2 rnorm=1.57787e-02
[2026-01-30 19:11:50.211] [debug] KSP iter=3 rnorm=5.00565e-03
[2026-01-30 19:11:50.211] [debug] KSP iter=4 rnorm=1.54031e-03
[2026-01-30 19:11:50.211] [debug] KSP iter=5 rnorm=4.74790e-04
[2026-01-30 19:11:50.211] [debug] KSP iter=6 rnorm=1.48857e-04
[2026-01-30 19:11:50.211] [debug] KSP iter=7 rnorm=5.62283e-05
[2026-01-30 19:11:50.211] [debug] KSP iter=8 rnorm=2.03586e-05
[2026-01-30 19:11:50.211] [debug] SNES iter=5 rnorm=1.83228e-03
[2026-01-30 19:11:50.211] [debug] KSP iter=0 rnorm=1.87817e-01
[2026-01-30 19:11:50.211] [debug] KSP iter=1 rnorm=7.23101e-03
[2026-01-30 19:11:50.211] [debug] KSP iter=2 rnorm=1.68362e-03
[2026-01-30 19:11:50.211] [debug] KSP iter=3 rnorm=5.27558e-04
[2026-01-30 19:11:50.211] [debug] KSP iter=4 rnorm=1.63903e-04
[2026-01-30 19:11:50.211] [debug] KSP iter=5 rnorm=5.19838e-05
[2026-01-30 19:11:50.212] [debug] KSP iter=6 rnorm=1.70709e-05
[2026-01-30 19:11:50.212] [debug] KSP iter=7 rnorm=6.35636e-06
[2026-01-30 19:11:50.212] [debug] KSP iter=8 rnorm=2.33176e-06
[2026-01-30 19:11:50.212] [debug] KSP iter=9 rnorm=8.29627e-07
[2026-01-30 19:11:50.212] [debug] SNES iter=6 rnorm=1.18601e-05
[2026-01-30 19:11:50.212] [debug] KSP iter=0 rnorm=1.30972e-03
[2026-01-30 19:11:50.212] [debug] KSP iter=1 rnorm=8.11400e-05
[2026-01-30 19:11:50.212] [debug] KSP iter=2 rnorm=1.98743e-05
[2026-01-30 19:11:50.212] [debug] KSP iter=3 rnorm=6.19430e-06
[2026-01-30 19:11:50.212] [debug] KSP iter=4 rnorm=1.93971e-06
[2026-01-30 19:11:50.212] [debug] KSP iter=5 rnorm=6.43799e-07
[2026-01-30 19:11:50.212] [debug] KSP iter=6 rnorm=2.29625e-07
[2026-01-30 19:11:50.212] [debug] KSP iter=7 rnorm=8.58918e-08
[2026-01-30 19:11:50.212] [debug] KSP iter=8 rnorm=3.17049e-08
[2026-01-30 19:11:50.212] [debug] KSP iter=9 rnorm=1.12098e-08
[2026-01-30 19:11:50.213] [debug] SNES iter=7 rnorm=7.28683e-10
Again

[RemDelaporteMathurin]

Update

from mpi4py import MPI
import dolfinx.fem.petsc
import ufl


mesh = dolfinx.mesh.create_unit_square(MPI.COMM_WORLD, 10, 10)
V = dolfinx.fem.functionspace(mesh, ("Lagrange", 1))
u = dolfinx.fem.Function(V)

v = ufl.TestFunction(V)
x = ufl.SpatialCoordinate(mesh)
F = ufl.inner((u + 0.1) ** 2, v) * ufl.dx - ufl.inner(x[0] + x[1], v) * ufl.dx


solver = dolfinx.fem.petsc.NonlinearProblem(
    F,
    u,
    petsc_options_prefix="test",
    petsc_options={
        "snes_type": "newtonls",
        "snes_linesearch_type": "basic",
        "ksp_type": "cg",
        "pc_type": "jacobi",
        "snes_rtol": 1e-10,
        "snes_atol": 1e-10,
        "snes_stol": 2e-1,
        "snes_error_if_not_converged": True,
        "ksp_error_If_not_converged": True,
        # "snes_monitor": None,
    },
)


_residual0 = 0
_prev_xnorm = 0
_corr0 = 0
_vec0 = 0


def convergenceTest(snes, it, norms):
    global _residual0
    xnorm, gnorm, f = norms  # ||x_k||, ||x_k-x_k-1||, ||F(x_k)||

    rtol, atol, stol, max_its = snes.getTolerances()

    if it == 0:
        _residual0 = f
    if it > max_its:
        return snes.ConvergedReason.DIVERGED_MAX_IT
    elif f < atol and it > 0:
        print("Here atol", flush=True)
        return snes.ConvergedReason.CONVERGED_FNORM_ABS
    elif f / _residual0 < rtol:
        print(f"Here rtol {f / _residual0} with rtol = {rtol}", flush=True)
        return snes.ConvergedReason.CONVERGED_FNORM_RELATIVE
    elif gnorm < stol and it > 0:
        print("Here stol", flush=True)
        return snes.ConvergedReason.CONVERGED_SNORM_RELATIVE
    else:
        return snes.ConvergedReason.ITERATING


def SnesMonitor(snes, iter, rnorm):
    global _prev_xnorm
    if MPI.COMM_WORLD.rank == 0:
        rtol, atol, stol, max_its = snes.getTolerances()
        x = snes.getSolution()
        xnorm = x.norm()

        stepsize_rel = abs(xnorm - _prev_xnorm) / xnorm if iter > 0 else float("inf")
        if iter == 0:
            relative_residual = float("inf")
        else:
            relative_residual = rnorm / _residual0

        dolfinx.log.log(
            dolfinx.log.LogLevel.DEBUG,
            f"SNES {iter=} ; {rnorm=:.5e} ({atol=:.5e}) ; {relative_residual=:.5e} ({rtol=:.5e}) ; {stepsize_rel=:.5e} ({stol=:.5e})",
        )

        # Update previous xnorm
        _prev_xnorm = xnorm


def KSPMonitor(ksp, iter, rnorm):
    dolfinx.log.log(dolfinx.log.LogLevel.INFO, f"{iter}, {_residual0=}")
    if MPI.COMM_WORLD.rank == 0:
        dolfinx.log.log(dolfinx.log.LogLevel.DEBUG, f"KSP {iter=} {rnorm=:.5e}")


solver.solver.setMonitor(SnesMonitor)
# solver.solver.getKSP().setMonitor(KSPMonitor)
solver.solver.setConvergenceTest(convergenceTest)

u.x.array[:] = 0.0
dolfinx.log.set_log_level(dolfinx.log.LogLevel.DEBUG)
solver.solve()