Personal computing discussed

Moderators: renee, SecretSquirrel, just brew it!

 
cphite
Graphmaster Gerbil
Topic Author
Posts: 1031
Joined: Thu Apr 29, 2010 9:28 am

Weird bug and weirder solution...

Mon Jul 22, 2019 12:28 pm

This is more of a curiosity thing, so I don't expect folks to spend any real time on this... it's just something I found really odd, and was hoping to find out why it might have occurred.

Some background... I am not a VB coder... I know enough that I can get by for simple things, but usually only after looking at examples online. But I occasionally get tasked with stuff that involves some light coding.

In this case, we have a file that we send to our parent company. I wrote a program that does the following things:
1. Run an Reporting Services report and dump the results to a text file
2. FTP that text file to the company
3. Attach that same text file to an email
4. Attach the log of the program running to the same email
5. Send the email

The problem is related to step four... trying to attach the log file while the program is still running. The log is written out by a sub that opens the file, writes a line, then immediately closes the file. It worked fine for almost three years, and then last week we started getting failures. Ran the program manually and it turned out that it was failing to attach the log to the email, and even though I was using a Try-Catch, the program was crashing on that attempt.

A new log file is created every time, so it wasn't being locked by any other process.

While tinkering with the thing, I added a write to the console to show the file name - the second "Console.Writeline" in the code below - just to double check that it was getting the name right. Lo and behold, it worked. Took the new line out, and it failed again. Put it back in and it works.

How does sending the name of the log file to console fix the issue of it failing to attach the log file to an email?

                              
                Try
                    Console.WriteLine("Attaching Logfile to email.")

                    Console.WriteLine("\\utilserver\c$\DAILY_report\log\DAILY_" +
                                                      DateAndTime.Now.ToString("yyyy_MM_dd") + ".log")

                    e_mail.Attachments.Add(New Attachment("\\utilserver\c$\DAILY_report\log\DAILY_" +
                                                      DateAndTime.Now.ToString("yyyy_MM_dd") + ".log"))
                   

                Catch ex As Exception
                    Console.WriteLine("Failed to attach log to email: " + ex.Message)
                    LogMessage("Failed to attach log to the email: " + ex.Message)
                End Try
 
just brew it!
Gold subscriber
Administrator
Posts: 53069
Joined: Tue Aug 20, 2002 10:51 pm
Location: Somewhere, having a beer

Re: Weird bug and weirder solution...

Mon Jul 22, 2019 1:17 pm

Sounds like a race condition. There is some transient state which is preventing the e-mail attach code from successfully opening the file; adding the extra debug code delays execution of the e-mail attach operation just enough that you're no longer hitting the problem.

Race conditions are unpredictable by definition. Hardware changes, OS update, or some other change to the execution environment could've exposed the issue (which I'll bet was there all along, but odds of hitting it were previously low).

Unless you identify and correct the underlying race, the problem may come back in the future, even if you leave your console write in place.
Nostalgia isn't what it used to be.
 
cphite
Graphmaster Gerbil
Topic Author
Posts: 1031
Joined: Thu Apr 29, 2010 9:28 am

Re: Weird bug and weirder solution...

Mon Jul 22, 2019 2:16 pm

just brew it! wrote:
Sounds like a race condition. There is some transient state which is preventing the e-mail attach code from successfully opening the file; adding the extra debug code delays execution of the e-mail attach operation just enough that you're no longer hitting the problem.

Race conditions are unpredictable by definition. Hardware changes, OS update, or some other change to the execution environment could've exposed the issue (which I'll bet was there all along, but odds of hitting it were previously low).

Unless you identify and correct the underlying race, the problem may come back in the future, even if you leave your console write in place.


We did move our VMs to a new location, so that adds up.

Seems kinda wild that the time it takes to write a line to console is enough of a delay to make the difference, but it's the best theory I've heard :D
 
Redocbew
Gold subscriber
Minister of Gerbil Affairs
Posts: 2088
Joined: Sat Mar 15, 2014 11:44 am

Re: Weird bug and weirder solution...

Mon Jul 22, 2019 2:49 pm

That's what we call a hisenbug. :P

Relatively speaking, printing to console has always seemed weirdly slow to me also, but I've never looked into the reason why.
Do not meddle in the affairs of archers, for they are subtle and you won't hear them coming.
 
just brew it!
Gold subscriber
Administrator
Posts: 53069
Joined: Tue Aug 20, 2002 10:51 pm
Location: Somewhere, having a beer

Re: Weird bug and weirder solution...

Mon Jul 22, 2019 3:28 pm

FWIW the odds of weird race conditions multiplies exponentially if the application makes use of multi-threading and fails to employ mutexes where appropriate. Moving to a host with more cores/threads will tend to exacerbate these types of issues.

Edit: A significant chunk of my day job is chasing bugs like this... you'd be amazed at all the wonderfully "creative" ways people can create really hard-to-find race conditions.
Nostalgia isn't what it used to be.
 
meerkt
Graphmaster Gerbil
Posts: 1307
Joined: Sun Aug 25, 2013 2:55 am

Re: Weird bug and weirder solution...

Tue Jul 23, 2019 12:31 pm

What happens if you use a local file instead of on \\utilserver?
 
UberGerbil
Grand Admiral Gerbil
Posts: 10368
Joined: Thu Jun 19, 2003 3:11 pm

Re: Weird bug and weirder solution...

Thu Jul 25, 2019 1:35 pm

It's been a long time since I've thought about the internals of VB, but it's possible the Try...Catch construct itself is fixing the problem as a side effect (there's a bunch more work done to set up and tear down the error handling and there's probably some serialization happening inside of it as well).

The right way to do this would through async methods and the await operator, though for this purpose you could just essentially spin lock on a test to see if the file exists/isn't in use.

Who is online

Users browsing this forum: No registered users and 3 guests
GZIP: On