Data migration script really slows down after 300 rows

Question

I am currently migrating data from an old MS Infopath based application to an asp.net core app. I have written a .net console app to read from four tables (tblcreated, tblPDI, tblHistory, tblDekadenplanung, tblAdv) containing the old data, manipulating some attributes (e.g. dates) and writing it back to the new table structures (table VehicleFiles, Deliveries, CustomerPayment, comments). Because VehicleFiles holds the foreign keys of the deliveries and customer payment data, i have to save them to DB to get the ID and then store the ID in the vehiclefiles row, which might cause a high load due to the 2 separate write processes). Its 30.000 rows in total.

When I have the migration app running on my web server to avoid latency, it starts very fast, processing around 20 rows per second. But as soon as it hits the 300 rows mark it gradually starts to slow down. At the 25000 mark it took about 3 to 4 minutes to process 10 rows yesterday. I just post the code, maybe someone will find obvious flaws or memory leaks in my code and give me notice.

static void Main(string[] args) {
var logRepository = LogManager.GetRepository(Assembly.GetEntryAssembly());
XmlConfigurator.Configure(logRepository, new FileInfo("log4net.config"));

log.InfoFormat("Running as {0}", WindowsIdentity.GetCurrent().Name);

var Configuration = new ConfigurationBuilder().SetBasePath(Path.Combine(AppContext.BaseDirectory)).AddJsonFile("appsettings.json", optional: true).Build();

var serviceProvider = new ServiceCollection().AddDbContext < AutolineContext > ...
// ...Removed bc password

var autolineContext = serviceProvider.GetRequiredService < AutolineContext > ();
var samContext = serviceProvider.GetRequiredService < SAMContext > ();
var luxWebContext = serviceProvider.GetRequiredService < LUX_WEB_SAMContext > ();

var tblCreated = samContext.TblCreated.OrderBy(x = >x.Id).ToList();
var tblPDIAll = samContext.TblPdi.ToList();
var tblHistoryAll = samContext.TblTerminHistorie.ToList();
var tblDekadenplanungAll = samContext.TblDekadenplanung.ToList();
var tblAdvAll = samContext.TblAdV.ToList();

var tblPDI = new TblPdi();
var tblHistory = new TblTerminHistorie();
var tblDekadenplanung = new TblDekadenplanung();
var tblAdv = new TblAdV();

int counter = 0;
var begin = DateTime.Now;
var lastTime = DateTime.Now;
Deliveries delivery = new Deliveries();
CustomerPayments customerPayments = new CustomerPayments();

foreach(var item in tblCreated) {
    counter++;

    if (counter % 10 == 0) {
        Console.WriteLine("\nNächstes Element: " + item.Id + "\nVerarbeitet: " + counter + "\nSekunden seit Beginn: " + (DateTime.Now - begin).TotalSeconds + "\nDauer letzte Zehn: " + (DateTime.Now - lastTime).Seconds);
    }

    VehicleFiles vf = luxWebContext.OrderNumbers.Where(x = >x.CommissionNumber == item.Kommissionsnummer).Select(x = >x.FkVehicleFileNavigation).SingleOrDefault();

    delivery = new Deliveries();
    customerPayments = new CustomerPayments();

    tblPDI = tblPDIAll.SingleOrDefault(x = >x.Kommissionsnummer == item.Kommissionsnummer);
    tblHistory = tblHistoryAll.Where(x = >x.Kommissionsnummer == item.Kommissionsnummer).OrderBy(x = >x.CreationDate).LastOrDefault();
    tblDekadenplanung = tblDekadenplanungAll.SingleOrDefault(x = >x.Kommissionsnummer == item.Kommissionsnummer);
    tblAdv = tblAdvAll.SingleOrDefault(x = >x.Kommissionsnummer == item.Kommissionsnummer);

    // PDI
    delivery.Pdichecker = tblPDI.PdiPruefer;
    delivery.Pdistatus = tblPDI.PdiOk == "OK" ? "1": "";
    if (!string.IsNullOrEmpty(tblPDI.Pdi)) {
        log.Info("Speichere PDI-Datum: " + DateTime.ParseExact(tblPDI.Pdi, "dd/MM/yyyy", CultureInfo.InvariantCulture));
        delivery.Pdidate = DateTime.ParseExact(tblPDI.Pdi, "dd/MM/yyyy", CultureInfo.InvariantCulture);
    }

    DateTime dateValue;
    if (!string.IsNullOrEmpty(tblPDI.ZurReinigung) && DateTime.TryParse(tblPDI.ZurReinigung.Replace("h", ":"), out dateValue)) {
        log.Info("Speichere Reinigung-Datum: " + DateTime.Parse(tblPDI.ZurReinigung.Replace("h", ":")));
        delivery.ForCleaning = DateTime.Parse(tblPDI.ZurReinigung.Replace("h", ":"));
    }

    // Registrierung
    delivery.PlateMounted = tblPDI.Montiert == "OK";
    delivery.RegistrationStatus = tblPDI.AnmeldungOk == "Ok";

    // Auslieferung
    if (tblHistory != null && !string.IsNullOrEmpty(tblHistory.DeliveryDate)) {
        log.Info("Speichere Plan-Delivery-Datum: " + DateTime.Parse(tblHistory.DeliveryDate.Split(" ")[0]));
        delivery.PlanDeliveryDate = DateTime.Parse(tblHistory.DeliveryDate.Split(" ")[0]);
    }

    if (!string.IsNullOrEmpty(item.DatumAuslieferung)) {
        log.Info("Speichere Delivery-Datum: " + DateTime.Parse(item.DatumAuslieferung));
        delivery.DeliveryActual = DateTime.Parse(item.DatumAuslieferung);
    }
    delivery.DeliveryPerson = tblDekadenplanung.Auslieferer;

    if (tblDekadenplanung.Teamleiter != null) delivery.TeamLead = DateTime.Parse(tblDekadenplanung.Teamleiter);

    delivery.CreationDate = DateTime.Now;
    delivery.CreationUser = "MigrationJob";

    // Zahlungsart
    decimal value;
    customerPayments.Value1 = Decimal.TryParse(tblDekadenplanung.Betrag, out value) ? Convert.ToDecimal(tblDekadenplanung.Betrag) : default;
    customerPayments.Value2 = Decimal.TryParse(tblDekadenplanung.Betrag2, out value) ? Convert.ToDecimal(tblDekadenplanung.Betrag2) : default;
    customerPayments.PaymentTyp1 = string.IsNullOrEmpty(customerPayments.PaymentTyp1) ? PaymentMethodConverter(tblDekadenplanung.Zahlungsart) : null;
    customerPayments.PaymentTyp2 = string.IsNullOrEmpty(customerPayments.PaymentTyp2) ? PaymentMethodConverter(tblDekadenplanung.Zahlungsart2) : null;
    customerPayments.CreationDate = DateTime.Now;
    customerPayments.CreationUser = "MigrationJob";
    customerPayments.LastEditedBy = tblDekadenplanung.LastUser;

    if (!string.IsNullOrEmpty(tblDekadenplanung.UpdateDate)) customerPayments.LastEditedDate = DateTime.Parse(tblDekadenplanung.UpdateDate);

    log.Info("Schreibe CreationDate: " + item.Creationdate.Value.ToUniversalTime());
    vf.CreationDate = item.Creationdate.HasValue ? item.Creationdate.Value.ToUniversalTime() : new DateTime();
    vf.CreationUser = item.AnlageUser;
    vf.Active = item.Archive == "False" ? false: true;
    vf.Concluded = item.Abgeschlossen == "Ja" ? true: false;
    vf.ConclusionDate =
default; // Nicht gesetzt im alten SAM

    vf.HolUndBringDauer = item.HolBringDauer != "0" ? Convert.ToInt32(item.HolBringDauer) : default;

    if (delivery.DeliveryActual.HasValue) vf.HolUndBringEnde = delivery.DeliveryActual.Value.AddMonths(Convert.ToInt32(item.HolBringDauer)).AddDays( - 1);

    // Kommentare

    if (!string.IsNullOrEmpty(tblDekadenplanung.KommentarAus) && tblDekadenplanung.KommentarAus != "-") {
        CommentsSam deliveryComment = new CommentsSam {
            FkVehicleFile = vf.PkVehicleFile,
            Comment = tblDekadenplanung.KommentarAus,
            User = "Sys",
            CommentType = "Delivery",
            Date = DateTime.Now
        };
        luxWebContext.Add(deliveryComment);

    }

    if (!string.IsNullOrEmpty(tblPDI.KommentarLog)) {
        CommentsSam pdiComment = new CommentsSam {
            FkVehicleFile = vf.PkVehicleFile,
            Comment = tblPDI.KommentarLog,
            User = "Sys",
            CommentType = "PDI",
            Date = DateTime.Now
        };
        luxWebContext.Add(pdiComment);
    }

    if (!string.IsNullOrEmpty(tblAdv.KommentarZah)) {
        CommentsSam advComment = new CommentsSam {
            FkVehicleFile = vf.PkVehicleFile,
            Comment = tblAdv.KommentarZah,
            User = "Sys",
            CommentType = "ADV",
            Date = DateTime.Now
        };
        luxWebContext.Add(advComment);
    }

    try {
        luxWebContext.Add(delivery);
        luxWebContext.Add(customerPayments);
        luxWebContext.SaveChanges();

        vf.FkDelivery = delivery.PkDelivery;
        vf.FkCustomerPayment = customerPayments.PkCustomerPayment;
        luxWebContext.Update(vf);
        log.Info("Daten erfolgreich geschrieben. VehicleFile-ID: " + vf.PkVehicleFile);
        lastTime = DateTime.Now;

        delivery = null;
        customerPayments = null;
    }
    catch(Exception e) {
        log.Error("Fehler beim Schreiben der Daten: " + e);
    }

}

The process memory in visual studio 2019 is capped at ~261 mb. This is what the diagnosis looks like in the first 6 mins:

I have found this blog post that deals with the same problem but I don't know how to apply it to my specific case:

https://weblog.west-wind.com/posts/2014/dec/21/gotcha-entity-framework-gets-slow-in-long-iteration-loops

Answer 1

Alright, I figured out how to solve this issue. I added the disposal and new creation of my luxWebContext on every foreach iteration with the using keyword, which disposes the luxWebContext automatically after leaving the brackets. Looks like this:

foreach(var item in tblCreated) {
  counter++;
  using(var luxWebContext = new LUX_WEB_SAMContext(optionsBuilder.Options)) {



    if (counter % 100 == 0) {
     Console.WriteLine("\nNächstes Element: " + item.Id + "\nVerarbeitet: " + counter + "\nSekunden seit Beginn: " + (DateTime.Now - begin).TotalSeconds + "\nDauer letzte Zehn: " + (DateTime.Now - lastTime).Milliseconds);
     lastTime = DateTime.Now;


    }

...

Answer 2

One of the issues with your code

foreach(var item in tblCreated) {
// ..
VehicleFiles vf = luxWebContext.OrderNumbers.Where(x = >x.CommissionNumber == item.Kommissionsnummer).Select(x = >x.FkVehicleFileNavigation).SingleOrDefault();

assuming luxWebContext is your EF context. For each item in tblCreated you fire a query to SQL server. This is a huge performance hit.

Rather fetch your data before your for loop and convert it to a Dictionary or Lookup.

// Before loop
var orderNumerbsByCommsionNumber = luxWebContext.OrderNumbers.ToLookup(x => x.CommissionNumber) 
// Or ToDictionary(x => x.CommissionNumber) if the CommissionNumber is unique.

foreach(var item in tblCreated) {
// ..
VehicleFiles vf = orderNumerbsByCommsionNumber[item.Kommissionsnummer].Select(x => x.FkVehicleFileNavigation).SingleOrDefault();

You can do the same for every where/first/single in your loops. In your example:

tblPDI = tblPDIAll.SingleOrDefault(x = >x.Kommissionsnummer == item.Kommissionsnummer);
tblHistory = tblHistoryAll.Where(x = >x.Kommissionsnummer == item.Kommissionsnummer).OrderBy(x = >x.CreationDate).LastOrDefault();
tblDekadenplanung = tblDekadenplanungAll.SingleOrDefault(x = >x.Kommissionsnummer == item.Kommissionsnummer);
tblAdv = tblAdvAll.SingleOrDefault(x = >x.Kommissionsnummer == item.Kommissionsnummer);

if you want you can batch commit, add this line to the end of your loop

if(counter % 100 = 0)
{
   luxWebContext.SaveChanges(); // Or async version
}

This commits the changes to the database every time the counter is divisible by 100.