sql1-logging-risk

SQL1 Logging & Session Stability

Critical architectural findings: SQL1 is in the performance-critical path of every PSI application via synchronous log4net writes, and UDNetSession has endemic null-check gaps causing NullReferenceExceptions across the application ecosystem.

---

Overview

Two related architectural issues were discovered in March 2026 that affect all PSI .NET applications:

1. SQL1 as a performance bottleneck — Every PSI application writes log entries synchronously to SQL1 with zero buffering, making SQL1 an invisible single point of failure for application performance.
2. UDNetSession null-check gaps — The UniData session layer silently returns null from Open() and DictOpen() when connections drop, and callers never check the return values, producing NullReferenceExceptions across the entire application ecosystem.

These issues are endemic (present since the code was written) and interact: SQL1 slowdowns block application threads, which can cause UniData session timeouts, which produce more errors, which generate more log writes, further loading SQL1.

---

Issue 1: SQL1 Synchronous Logging

The Problem

Every PSI .NET application uses log4net with a custom PSIAdoNetAppender that writes to the DotNetLog table on SQL1. The configuration is:

<bufferSize value="0"/>           <!-- Every log call = immediate SQL INSERT -->
<level value="DEBUG"/>            <!-- Maximum verbosity -->

This means every single log.Debug(), log.Info(), log.Error() call in every PSI application blocks the calling thread until the SQL INSERT completes on SQL1.

Impact

PSI Application Thread
    │
    ▼
log.Debug("some message")
    │
    ▼
[BLOCKED] ── SQL INSERT into DotNetLog on SQL1 ──► waits for SQL1
    │
    ▼
Application continues (only after INSERT completes)

• 172 million rows accumulated in DotNetLog over ~2 years (Feb 2024 – Mar 2026)
• Every ProApp, WCF service, Windows service is affected
• When SQL1 is under load, all PSI applications slow down simultaneously
• Users experience hangs and timeouts with no obvious cause

The Feedback Loop

When SQL1 becomes slow (from any cause — heavy queries, maintenance, resource contention):

1. Log INSERTs slow down → application threads block
2. Blocked threads cause UniData session timeouts
3. Session timeouts produce errors → more log entries
4. More log entries → more INSERTs → SQL1 gets slower
5. Repeat — cascading degradation across all PSI apps

Root Cause in Code

File: C:\git\PSI.All\PSI.Shared\trunk\PSI.Common\Logging\PSIAdoNetAppender.cs

public class PSIAdoNetAppender : log4net.Appender.AdoNetAppender
{
    public new string ConnectionString
    {
        get { return base.ConnectionString; }
        set { base.ConnectionString = "server=sql1; uid=PSIUser; pwd=***; database=PSI"; }
    }
 
    public new string CommandText
    {
        get { return base.CommandText; }
        set { base.CommandText = "INSERT INTO DotNetLog ..."; }
    }
}

Configuration (in every PSI app’s App.config):

<log4net>
  <root>
    <level value="DEBUG"/>                    <!-- Problem: too verbose for production -->
    <appender-ref ref="AdoNetAppender"/>
  </root>
  <appender name="AdoNetAppender" type="PSI.Common.Logging.PSIAdoNetAppender,PSI.Common">
    <bufferSize value="0"/>                   <!-- Problem: synchronous, no batching -->
  </appender>
</log4net>

Database Details

Detail	Value
Server	SQL1
Database	PSI
Table	DotNetLog
Row Count	~172 million (as of March 2026)
Date Range	Feb 2024 – present
Columns	Date, Thread, Level, Logger, Message, Exception, PSIUserName, ComputerName, DNSCaller, IPCaller
Indexes	None on Message/Exception (LIKE queries cause full table scans)

Hardcoded “WS2” Computer Name

The ComputerName column in DotNetLog is misleading. In UDNetSession.cs, every error handler sets:

MDC.Set("pcname", "WS2");  // hardcoded 25+ times

This runs inside PSI Local Service on every user’s PC. All 214K+ “WS2” entries are actually from dozens of different machines — not a single server. “WS2” was likely the original server name when the code was written and was never updated to use Environment.MachineName.

The old VB.NET version (PSI.UniDataSession) had it as “WS1”; when ported to C#, it became “WS2”. Neither reflects reality.

Fix: Replace all MDC.Set("pcname", "WS2") with MDC.Set("pcname", Environment.MachineName) in UDNetSession.cs.

---

Issue 2: UDNetSession Null-Check Gaps

The Problem

UDNetSession.Open() and UDNetSession.DictOpen() silently return null when the UniData connection is unavailable. The calling code in UDSessionController never checks the return value before using it.

Error Frequency

Year	UDNetSession Errors
2024	10,874
2025	(data unavailable)
2026 (Jan–Mar)	8,302

These errors affect multiple PSI components simultaneously — desktop ProApps, WCF services, and Windows services all share the same vulnerable code path.

Affected Code Paths

Path A: ReadDictionaryValue (affects UniCacheXML WO Cache)

File: PSI.Common.Models\UDSessionController.cs (~line 890)

var uDict = UD.DictOpen(TableName, sessionGuid);  // Returns null if session dropped
uDict.RecordID = FieldName;                         // NullReferenceException!

Called by WorkOrderController.GetFocusPriority() → WOService.UpdateALL() → UniCacheXML “WO Cache Files” task.

Path B: Read via Open (affects all data reads)

File: PSI.Common.Models\UDSessionController.cs (~line 1046)

var uniFile = UD.Open(tableName, sessionGuid);     // Returns null if session dropped
var result = UD.Read(uniFile, recordID, sessionGuid); // Passes null into Read()
uniFile.Close();                                     // Also crashes

This pattern repeats at lines ~1046, ~1060, ~1073, ~1087.

Path C: Inside Read() itself

File: PSI.UniSessionManager\UDNetSession.cs (~line 533)

// Inner catch block (line ~556) — NO null check:
var record = uniFile.Record;    // NullReferenceException if uniFile is null
 
// Outer catch block (line ~582) — HAS null check:
var fileName = uniFile != null ? uniFile.FileName : "";   // Defensive ✓
 
// Return statement (line ~596) — NO null check:
return uniFile.Record;          // NullReferenceException if uniFile is null

Why Open() Returns Null

File: PSI.UniSessionManager\UDNetSession.cs (~line 302)

Open() returns null when:

• udConnector is null (session disposed or never initialized)
• session is null (connection pool exhausted)
• session.IsActive is false (connection dropped)
• Any exception during CreateUniFile() (caught, logged, returns null)

DictOpen() follows the same pattern (~line 673).

Session Management Context

• PSISessionManager pools up to 2 sessions per user
• Sessions are reused via round-robin
• Session timeout is set to 0 (infinite) — but connections can still drop due to network issues or UniData server restarts
• No reconnection logic exists when a session becomes inactive

---

Recommended Fixes

Fix 1: Log4net Configuration (High Priority)

Goal: Remove SQL1 from the performance-critical path.

Change	Current	Recommended	Impact
bufferSize	0	100	Batches INSERTs — 100x fewer round-trips to SQL1
Log level	DEBUG	INFO (production)	Dramatically reduces log volume
Appender type	Synchronous	AsyncAppender wrapper	Log calls never block app threads

Implementation

1. In PSI.Common\Logging\, create PSIAsyncAdoNetAppender wrapping the existing appender
2. In every App.config (Release/Production), change:
   • bufferSize from 0 to 100
   • Root log level from DEBUG to INFO
3. Add an index to DotNetLog: CREATE INDEX IX_DotNetLog_Date ON DotNetLog ([Date]) INCLUDE ([Level], [Logger])
4. Consider a retention policy — 172M rows is excessive; archive or purge entries older than 6 months

Fix 2: Null Checks in UDSessionController (High Priority)

Goal: Prevent NullReferenceExceptions when UniData sessions drop.

Add null checks after every Open() and DictOpen() call:

// ReadDictionaryValue
var uDict = UD.DictOpen(TableName, sessionGuid);
if (uDict == null)
{
    log.Error($"DictOpen returned null for table {TableName}");
    UD.SetInUse(sessionGuid, false);
    return "";
}
 
// Read methods
var uniFile = UD.Open(tableName, sessionGuid);
if (uniFile == null)
{
    log.Error($"Open returned null for table {tableName}");
    UD.SetInUse(sessionGuid, false);
    return null;
}

Fix the inconsistent null handling inside UDNetSession.Read():

• Add if (uniFile == null) return null; at method entry
• Guard the inner catch block’s uniFile.Record access
• Guard the return statement’s uniFile.Record access

Fix 3: Session Reconnection (Medium Priority)

Goal: Self-heal from transient UniData connection drops.

In UDNetSession.Open() and DictOpen(), when session.IsActive == false:

1. Attempt to re-authenticate the session
2. Retry the open operation once
3. If still failing, return null (callers now handle null safely)

---

Related Pages

• UniCacheXML Service — Primary consumer affected by both issues
• PSI.All Architecture — Codebase structure and data access patterns
• PSI.All Architecture — .NET codebase and data access patterns
• ProApps — Desktop apps affected by logging bottleneck

---

Discovered: March 2026 Last updated: March 2026