0

EDIT:

The if statement that determines whether to continue processing leads is not wrapped in an #if DEBUG...#else directive so it should execute in all cases.

TL;DR Some part of my code is returning different results when I run in debug to what it returns when I'm running a release build. Why would this happen and how do I fix it?

My app processes follow up emails on the client's mailing list. How it does this is not important for this post, but its a WPF app that gets all leads that are older than 2 weeks and meet some other conditions.

First, leads are loaded into memory:

public class MainViewModel : BaseViewModel
{
    public ContactsViewModel Contacts { get; }
    public EmailsViewModel Emails { get; }
    public FollowUpsViewModel FollowUps { get; }
    public GroupsViewModel Groups { get; }
    public LeadsViewModel Leads { get; }
    public LeadStatusesViewModel LeadStatuses { get; }

    public MainViewModel(LoadingViewModel loadingVM)
    {
        Groups = new GroupsViewModel();
        LeadStatuses = new LeadStatusesViewModel();
        Contacts = new ContactsViewModel(Groups);
        Emails = new EmailsViewModel(Campaigns, Templates);
        Leads = new LeadsViewModel(Campaigns, Emails, LeadStatuses, Groups);
        FollowUps = new FollowUpsViewModel(Leads);
    }

    public async Task Load()
    {
        // Contacts data is loaded ad hoc when requested.
        await Groups.Load();
        await Emails.Load();
        await LeadStatuses.Load();
        await Leads.Load();

        // Delegate follow ups to a new thread so as to keep the UI responsive.
        new Thread(delegate () { FollowUps.FollowUp(this); }).Start();
    }
}

The leads are loaded into an ObservableCollection on the LeadsViewModel:

public class LeadsViewModel : BaseViewModel
{
    public ObservableCollection<LeadViewModel> AllLeads = new ObservableCollection<LeadViewModel>();

   public LeadsViewModel(CampaignsViewModel campaigns, EmailsViewModel emails, LeadStatusesViewModel statuses, GroupsViewModel groups)
    {
        // Loads other ObservableCollections... These aren't really relevant to this question for the most part.
        _campaigns = campaigns;
        _emails = emails;
        _statuses = statuses;
        _groups = groups;
    }

    public async Task Load()
    {
        var contacts = await Dal.Instance.Contacts.GetDictionaryAsync();
        var models = await TrackerDal.Instance.Leads.ListAsync();
        foreach (var m in models)
        {
            var lead = new EmailStatus();
            lead = m;

            // Make VERY sure that the error is that the associated contact doesn't exist.
            if (!contacts.TryGetValue(lead.ContactId, out var contact))
            {
                TrackerDal.Instance.Leads.Delete(lead, false);
            }
            else
            { 
                // Add the lead.
                AllLeads.Add(new LeadViewModel(this, m, _emails, _statuses, _groups, contact));
            }
        }
    }
}

Now here's the fun bit... The follow ups process reads the leads and checks that the associated email is not null. If there are leads where the email is not null, it'll proceed, else it'll just end the process.

This works fine and updates leads, even sending follow up emails to my inbox, ONLY when I run it in debug. I logged conditionally to determine this.

If I'm using a release build (#if !DEBUG), it returns no leads data.

public class FollowUpsViewModel : BaseViewModel
{
    private readonly LeadsViewModel _leads;

    public FollowUpsViewModel(LeadsViewModel leads)
    {
        _leads = leads;
    }

public void FollowUp(MainViewModel mvm)
{
    try
    {
        UpdateMessage(mvm, $"Follow up started.");
        Logger.Instance.LogInfo("Follow ups started...");
        int leadNumber = 1;
        int leadsCount = 0;

#if DEBUG
        Logger.Instance.LogDebug($"[Follow Up] Connection string is {TrackerDal.Instance.ConnectionString}");
#else
        Logger.Instance.LogInfo($"[Follow Up] Connection string is {TrackerDal.Instance.ConnectionString}");
#endif

#if DEBUG
        Logger.Instance.LogDebug("[Follow Up] Checking valid leads exist...");
#else
        Logger.Instance.LogInfo("[Follow Up] Checking valid leads exist...");
#endif
        if (_leads.AllLeads.Where(x => x.Email != null).Count() >= 1)
        {
            // At this point, the code loops through existing leads to send follow up emails and updates the database.
        }
        else
        {
#if DEBUG
            Logger.Instance.LogDebug("None found...");
#else
            Logger.Instance.LogInfo("None found...");
#endif
        }
    }
    catch(Exception ex)
    {
        // Do error handling stuff
    }
}

Here's log files:

Debug log - this is what gets logged when the app is running in the debugger:

2018-07-19 16:25:14,701 [16] INFO Follow ups started...
2018-07-19 16:25:14,745 [16] DEBUG [Follow Up] Connection string is Data Source=ortund; Initial Catalog=ortund; user id=ortund; password=gwrhw4h;MultipleActiveResultSets=True
2018-07-19 16:25:14,745 [16] DEBUG [Follow Up] Checking valid leads exist...
2018-07-19 16:25:14,747 [16] DEBUG [Follow Up] Valid leads found...
2018-07-19 16:25:14,748 [16] DEBUG [Follow Up] 2 valid leads found for processing...
2018-07-19 16:25:14,749 [16] DEBUG [Follow Up] Started lead #1
2018-07-19 16:25:14,798 [16] DEBUG [Follow Up] Sending follow up email for lead #1
2018-07-19 16:25:15,078 [16] DEBUG [Follow Up] lead #1 updated in database
2018-07-19 16:25:15,078 [16] DEBUG [Follow Up] lead #1 processing complete.
2018-07-19 16:25:15,078 [16] DEBUG [Follow Up] Started lead #2
2018-07-19 16:25:15,080 [16] DEBUG [Follow Up] Sending follow up email for lead #2
2018-07-19 16:25:15,155 [16] DEBUG [Follow Up] lead #2 updated in database
2018-07-19 16:25:15,157 [16] DEBUG [Follow Up] lead #2 processing complete.

Info log - this one gets logged after a release build and publish:

2018-07-19 16:27:57,562 [16] INFO Follow ups started...
2018-07-19 16:27:57,629 [16] INFO [Follow Up] Connection string is Data Source=ortund; Initial Catalog=ortund; user id=ortund; password=gwrhw4h;MultipleActiveResultSets=True
2018-07-19 16:27:57,629 [16] INFO [Follow Up] Checking valid leads exist...
2018-07-19 16:27:57,630 [16] INFO None found...

Community
  • 1
  • 1
Ortund
  • 8,095
  • 18
  • 71
  • 139
  • 1
    Isn´t that obvious? Running on release will turn off all debug-messages as the `#DEBUG`-variable isn´t defined. That´s the main purpose if a **release**-build – MakePeaceGreatAgain Jul 19 '18 at 14:54
  • 2
    So why is the `if (_leads.AllLeads.Where(x => x.Email != null).Count() >= 1)` returning `true` on DEBUG but `false` on RELEASE? – Ortund Jul 19 '18 at 14:55
  • @HimBromBeere That seems to be the answer. – Scriven Jul 19 '18 at 14:56
  • 1
    Have you tried stepping through the Release build with the debugger? – PaulF Jul 19 '18 at 14:56
  • 1
    In the projects properties, you can define the DEBUG constant in the Release build - if that fixes the issue then you know it is related to conditional compilation, if not then it is something else - check to see any differences between builds in the project properties. – PaulF Jul 19 '18 at 15:09
  • I would say it's pretty bad form to have different logging for debug/release builds. There should be one set of logging code, and then you control which log levels are recorded via configuration. If you are using something like nlog, you can even configure log levels down to class level. – Neil Jul 19 '18 at 15:18
  • All those `Instance` variables are suspicious too. If you are using EntityFramework, each request should use a new DbContext. If you have a single connection to the database, then other threads could screw around with your data at the same time as you are using it here. – Neil Jul 19 '18 at 15:21
  • @Neil I did it this way because at one point I was running into errors where the app couldn't connect to the database or send the query because there was still a query pending or something. This has worked for at least several months; its only with a recent update that its broken and I don't know what I changed to break it... – Ortund Jul 20 '18 at 07:21
  • 1
    @Neil also regarding the logging, I did it that way so that I could see if Release was executing differently to Debug. The `.Instance` variables are there because my [logger is a singleton](https://hastebin.com/ikutotikot.cs) and different levels are handled [in my config](https://hastebin.com/amaruxitap.xml) ... Ideally I'd like debug logs to go in the debug log file while info logs go in the info log file... this currently puts everything in all files... but this is actually beside the issue. – Ortund Jul 20 '18 at 07:59
  • NLog can do things like putting different levels in different places (e.g. debug goes in console window, errors go in a database etc). You really are reinventing the wheel creating your own logger these days. – Neil Jul 20 '18 at 09:02
  • I didn't create my own logging, I used log4net but again, the implementation of the logging isn't relevant to the question – Ortund Jul 20 '18 at 09:03
  • Let us [continue this discussion in chat](https://chat.stackoverflow.com/rooms/176401/discussion-between-neil-and-ortund). – Neil Jul 20 '18 at 09:04
  • "...there was still a query pending" - so there ARE other threads using the same database connection string. That's my point. You are slowing down your application by only having one connection, and possibly creating race conditions on the data. Something like EF will allow multiple asynchronous connections to the same database without threading problems. – Neil Jul 20 '18 at 09:08

0 Answers0