The Uniface test that "hung" had died - finding a silent crash with SQLite

This is a side story from the series Building a customer app in Uniface 10. It stands on its own: you only need to know that the app is a Uniface 10 desktop application on a SQLite database, and that every service has a test service written in ProcScript.

The short version: a test run stopped somewhere in the middle. It looked like a hang. It was a crash, and the log file pointed at the wrong place. The cause was a single SELECT without a FROM clause.

Tested with Rocket Uniface 10.4.03 Community Edition (10.4.03.021) and the SQLite version of its SLE driver (3.50.2), October 2026.

The symptom

The feature in question is an ABC classification of customers: points for recent activities and complete data, and two limits from the settings table that decide between class A, B and C. The limits are configurable, so they have to be validated - a setting ABC_B = "abc" must not break the report.

The test suite for it is a normal ProcScript test service. It logs one PASS or FAIL line per check with putmess, prints a summary at the end and rolls back. Started with Compile & Test in the IDE, the run never printed its summary. The log stopped after a PASS line of the previous test group, and nothing came after it.

Two more things were wrong afterwards:

• a test process was still listed by tasklist /FI "IMAGENAME eq ide.exe" and had to be ended with taskkill /PID <pid> /F,
• next to the database there was a customers.db-journal file. SQLite rolls it back the next time the database is opened, so no data was lost - the tests always end with rollback anyway - but it shows that the process stopped in the middle of a transaction.

The wrong suspects

Because it looked like a hang, I first looked for something slow or blocking. Two candidates were in the test data setup of that group:

• the test activities were inserted with one INSERT statement built on a common table expression (WITH ...),
• the classification query had grown into one large statement.

I replaced the CTE insert with a loop over a small helper entry and rewrote the query with LEFT JOINs on grouped subqueries. Both changes were fine on their own. Neither changed anything: the run still stopped at the same PASS line.

That was the moment to stop guessing.

Why the log pointed at the wrong place

The log in the IDE's log folder is written in blocks, not line by line. When the process ends normally, everything is flushed. When it dies, the last block is lost. So the last line in the log was not the last line that ran - it was the last line that happened to be written before the crash. Everything after it, possibly several test groups, was simply missing.

The lesson is general: if a process dies, its buffered output lies by omission. The last thing you see is not the last thing that happened.

A trace that cannot be lost

The fix for the diagnosis was a trace that writes every line to disk immediately. In ProcScript, lfiledump/append does exactly that - it opens the file, appends, and closes it again:

entry TRACE
params
    string pText : IN
endparams
    lfiledump/append "%%(pText)%%^", "C:/Projects/customers/export/test/trace.txt"
    return 0
end

(The path is shortened here.) Then call TRACE("...") between the steps of the test - and, once the test steps were narrowed down, inside the service under test as well:

    call TRACE("ABC step 3 activities")
    activate "REPORT3_SVC".ABC_CLASS(999831, vClass, vPoints, vError)
    call TRACE("ABC step 4 first class")

This is slow and ugly, and it is only meant to live for a few runs. But it survives a crash. The trace of the second run ended like this:

ABC step 3 activities
R3 class enter
R3 thresholds enter
R3 thresholds settings 70 40
R3 thresholds before sql

So the process died inside the entry that reads and checks the two limits, right at its sql statement - and with the default values 70 and 40, not with a broken setting.

The statement

Here is the entry as it was:

entry THRESHOLDS
params
    string pA : OUT
    string pB : OUT
endparams
variables
    string vA, vB, vSql
endvariables
    activate "SETTINGS_SVC".GET_SETTING("ABC_A", "70", vA)
    activate "SETTINGS_SVC".GET_SETTING("ABC_B", "40", vB)
    call SQL_ESCAPE(vA)
    call SQL_ESCAPE(vB)
    vSql = "SELECT CASE WHEN '%%(vA)' <> '' AND '%%(vA)' NOT GLOB '*[^0-9]*' AND '%%(vB)' <> '' AND '%%(vB)' NOT GLOB '*[^0-9]*' AND CAST('%%(vA)' AS INTEGER) BETWEEN 2 AND 100 AND CAST('%%(vB)' AS INTEGER) BETWEEN 1 AND CAST('%%(vA)' AS INTEGER) - 1 THEN 1 ELSE 0 END"
    sql vSql, "CUSTOMERS"
    if ($status >= 0 & $result = 1)
        pA = vA
        pB = vB
    else
        pA = "70"
        pB = "40"
    endif
    return 0
end

The idea was to let SQLite do the validation in one go: digits only, A between 2 and 100, B below A. As plain SQL, the statement is valid - run through Python's sqlite3 module, it returns 1 for "70"/"40" and 0 for "70"/"abc", as intended. Through the sql statement of ProcScript and the SLE driver, it ended the process. No error status, no message, no log line.

What I did not do is isolate which part of it is responsible. The application runs other SELECTs without a FROM all the time, for example this one for the current time in milliseconds:

    sql "SELECT CAST((julianday('now') - 2440587.5) * 86400000 AS INTEGER)", "CUSTOMERS"

So "no FROM" alone is not the problem, and neither is CAST alone. The candidates left are the CASE expression, the GLOB with a character class, or the combination. If you know the SLE driver well enough to explain it, I would like to read that in the comments.

The fix: validation belongs in ProcScript

Instead of hunting for the exact trigger, I moved the validation to where it belongs anyway - into the code:

entry THRESHOLDS
params
    string pA : OUT
    string pB : OUT
endparams
variables
    string vA, vB
    numeric vNumA, vNumB
    boolean vOkA, vOkB
endvariables
    pA = "70"
    pB = "40"
    activate "SETTINGS_SVC".GET_SETTING("ABC_A", "70", vA)
    activate "SETTINGS_SVC".GET_SETTING("ABC_B", "40", vB)
    call TRIM_TEXT(vA)
    call TRIM_TEXT(vB)
    call IS_INT(vA, vOkA)
    call IS_INT(vB, vOkB)
    if (vOkA & vOkB)
        vNumA = vA
        vNumB = vB
        if (vNumA >= 2 & vNumA <= 100 & vNumB >= 1 & vNumB < vNumA)
            pA = vA
            pB = vB
        endif
    endif
    return 0
end

entry IS_INT
params
    string pText : IN
    boolean pOk : OUT
endparams
variables
    numeric vI, vLen
endvariables
    pOk = 0
    vLen = $length(pText)
    if (vLen < 1 | vLen > 3)
        return 0
    endif
    vI = 1
    while (vI <= vLen)
        if ($scan("0123456789", pText[vI:1]) = 0)
            return 0
        endif
        vI = vI + 1
    endwhile
    pOk = 1
    return 0
end

It is longer, but every line can be read and tested on its own. The defaults are set first, so every path that does not end in "valid" keeps 70 and 40. With this version the suite ran through - 61 tests - and the full run with all suites passed, with the database file unchanged afterwards.

The trace calls were removed again. They had done their job.

Takeaways

A run that stops is not necessarily a hang. Check whether the process is still alive before you look for something slow.

Buffered logs lose their tail when a process dies. Don't trust the last line. For a crash, write a trace with lfiledump/append, which appends and closes on every call.

Narrow down with the trace, then fix the cause you can prove. I could prove "this statement ends the process". I could not prove which part of it. That was enough to fix it.

Keep validation in ProcScript and use SQL for data. A clever one-line check in SQL saves ten lines of code - until the driver disagrees with it.

Look for leftovers. A journal file next to the database and a lingering process are both signs of a crash, not of a slow query.