NGspice 28 in Kicad 5.0.0 shows real time incorrectly

[Steve Wood]

The Spice Simulator window of KiCAD 5.0.0 running NGspice 28 shows the elapsed time since the KiCAD Project was opened, and not the elapsed time since the simulation was started.

Linux Mint 19 Tara

Application: kicad
Version: 5.0.0-fee4fd1~66~ubuntu18.04.1, release build
Libraries:
    wxWidgets 3.0.4
    libcurl/7.58.0 OpenSSL/1.1.0g zlib/1.2.11 libidn2/2.0.4 libpsl/0.19.1 (+libidn2/2.0.4) nghttp2/1.30.0 librtmp/2.3
Platform: Linux 4.15.0-32-generic x86_64, 64 bit, Little endian, wxGTK
Build Info:
    wxWidgets: 3.0.4 (wchar_t,wx containers,compatible with 2.8) GTK+ 2.24
    Boost: 1.65.1
    OpenCASCADE Community Edition: 6.9.1
    Curl: 7.58.0
    Compiler: GCC 7.3.0 with C++ ABI 1011

Build settings:
    USE_WX_GRAPHICS_CONTEXT=OFF
    USE_WX_OVERLAY=OFF
    KICAD_SCRIPTING=ON
    KICAD_SCRIPTING_MODULES=ON
    KICAD_SCRIPTING_WXPYTHON=OFF
    KICAD_SCRIPTING_ACTION_MENU=ON
    BUILD_GITHUB_PLUGIN=ON
    KICAD_USE_OCE=ON
    KICAD_USE_OCC=OFF
    KICAD_SPICE=ON

[Holger Vogt (h+vogt)]

The ngspice command
rusage time
will print the total analysis time

[Steve Wood (steve+ubuntu)]

I tried adding a line with "rusage time" as well as ".option rusage time" in the Simulation settings / Custom tab of the KiCAD GUI, but the behaviour is unchanged. Having the simulation time read out correctly is not a big deal, but I just wanted to note the bug. Perhaps it only occurs when "cheating" by using NGspice 28 instead of the included version 26 with KiCAD5.0.0.

[Steve Wood (steve+ubuntu)]

I had "set ngdebug" in my .spiceinit. I have removed this line, and now I see
"
 Reference value : 0.00000e+00
 Reference value : 2.03435e-02
 Reference value : 4.55745e-02
 .
 .
 .
"
This does indicate the time correctly. It seems the bug is only applicable to NGspice debug mode, where the time elapsed reads as a percentage (correctly) and a time (incorrect starting point).

[Steve Wood (steve+ubuntu)]

@ Holger
Now that I'm non longer in Debug mode, I tried "rusage time" between ".control" and ".endc", but the KiCAD GUI always shows:

Circuit: KiCad schematic
Total analysis time (seconds) = 0
Background thread stopped with timeout = 0
Doing analysis at TEMP = 27.000000 and TNOM = 27.000000
Initial Transient Solution

It only shows the "Total analysis time (seconds) = 0" if have included the "rusage time" command. This message appears before the simulation runs. I've run a simulation for up to 30 seconds, but the time is still reported as 0.

[Holger Vogt (h+vogt)]

The same reason as we have in https://bugs.launchpad.net/kicad/+bug/1788676:

The .control section is executed before the simulation run has finished, probably it is executed immediately after or even before starting the simulation when the time is still 0.

We either have to enhance the eeschema interface or add some code to ngspice to improve the handling of the threads and the .control section.

[Holger Vogt (h+vogt)]

ngspice-30 is available with a patch (variable 'controlswait') to allow executing 'rusage' after the simulation.

Holger

[Nick Østergaard (nickoe)]

@Holder, is any change required anywhere to kicad to make this work if it is already using ngspice 30?

[Nick Østergaard (nickoe)]

This windows build should include ngspice 30:
https://kicad-downloads.s3.cern.ch/windows/testing/patched/kicad-patched-372-eb1faebf1-x86_64.exe

[Holger Vogt (h+vogt)]

With the advent of ngspice-30 there is a ngspice solution available.

Reason for the cited behavior:
.control section commands are stated in the main thread at the same time or even before simulation is started in a second thread. Thus simulation time is still 0, as reported by the rusage command.

Remedy
Add:
set controlswait
to .spiceinit or as the first command in the .control section.
This holds back all commands following until the simulation has finished.

There is no need to touch eeschema code.

[Wayne Stambaugh (stambaughw)]

@Holger, so this is a configuration issue rather than a KiCad bug correct?

[Nick Østergaard (nickoe)]

Where is this elapsed time visible in the GUI?

[Nick Østergaard (nickoe)]

I tried to make the testbox in the sallen_key demos as follows on linux with ngspice 30.

.ac dec 10 1 1Meg
.control
set controlswait
rusage
write /tmp/fisk/ees_out.raw all
.endc

The elapsed time will grow monotonically every time I hit simulate. I don't think it is interpreting the controlswait properly or something.

[Holger Vogt (h+vogt)]

command rusage (without arguments) will yield

total analysis time (cpu time required for the current simulation run, about 1ms only for sallen_key)

total elapsed time (time since ngspice has been invoked for the first time, thus the time passed after hitting the simulation button for the first time).

If you are interested in the total analysis time only, the command is

rusage time

For other rusage outputs please see chapt. 17.5.60 of the ngspice manual.

[KiCad Janitor (kicad-janitor)]

KiCad bug tracker has moved to Gitlab. This report is now available here: https://gitlab.com/kicad/code/kicad/-/issues/2544