.NET 6.0 application some times takes long time to create objects

Question

We see a strange behaviour in my .NET 6.0 application in my production environment. Shortly described the applications endpoint does the follwoing:

1. Fetches a list of objects from a database
2. Maps the objects from SQLReader to a model (with some custom logic)
3. Returns the list

Seems simple and it runs very fast for the most time being. But some times we see a very long running task between the mapping of SQLReader output to the model class.

The mapping follows this object creation:

private static MyCustomObject MapRecord(int indexNo, long id, IDataReader reader)
   return new MyCustomObject(indexNo,
            reader.GetDateTime(DATE),
            id,
            reader.GetString(ID),
            reader.TryRead(TEXT, string.Empty),
            reader.GetDecimal(NUMBER1),
            reader.GetDecimal(NUMBER2),
            reader.TryRead(DATA, string.Empty),
            reader.TryRead(CATEGORY_ID, 0),
            GetCategoryScores(reader.TryRead(CATEGORIES, string.Empty)),
            reader.TryRead<bool?>(SOMEBOOL, null),
            reader.TryRead(SOMEOTHERBOOL, false),
            reader.TryRead(COMMENT, string.Empty),
        );
}

At first we suspected the GetCategoryScores, which does a string split in two dimensions:

 private static IList<(int, double)>? GetCategoryScores(string? scores)
    {
        if (scores != null)
        {
            return scores.Split(';' , StringSplitOptions.RemoveEmptyEntries)
                .Select(x =>
                {
                    var split = x.Split(':');
                    var categoryScore = string.IsNullOrEmpty(split[1]) ? 0 : double.Parse(split[1], CultureInfo.InvariantCulture);
                    return (int.Parse(split[0]), categoryScore);
                }).ToList();
        }
        return null;
    }

My Jaeger traces showed that, it was NOT the case, hence i can only see the "TryRead" function to be the sinner. It looks like this:

 public static T? TryRead<T>(this IDataReader reader, int ordinal, T? defaultOnNull) =>
        reader.IsDBNull(ordinal)
            ? defaultOnNull
            : (T)reader[ordinal];

My other suspicion is that it is when the GC collects unused objects, it takes time. Usually the execution time of the MapRecord function is negligible, but when it takes time it takes between 1s and 1.5s. The application is deployed as a docker container and runs on a kubernetes cluster.

Has anyone seen anything like this before and have any suggestions of what to do?

Answer 1

If it's not GC, my guess is that it's the reader having to wait for data being streamed back from the database, most likely because other queries are locking tables and delaying the result, but maybe also due to general CPU/disk contention or networking issues.