-3

I have this piece of code in a C# program:

ListOfCabins();
ListOfWoodTypes();

The first function looks as follows:

private void ListOfCabins()
{
    Logger.Info($"Start function ListOfCabins()");

    try
    {
    }
    catch (Exception ex)
    {
         ...
    }

    Logger.Info($"End of function ListOfCabins()");
}

The other function goes as follows:

private void ListOfWoodTypes()
{
    Logger.Info($"Start function ListOfWoodTypes()");
    ...

Logger is a typical NLog object:

private static readonly Logger Logger = LogManager.GetCurrentClassLogger();

In the logs, I see:

End of function ListOfCabins()

I do not see:

Start function ListOfWoodTypes()

My application crashes, in the event log I see:

Application: ...
Framework Version: v4.0.30319
Description: The process wa terminated due to an unhandled exception.
Exception Info: System.IO.FileNotFoundException
  at ...ListOfWoodTypes()
  at ...

I have different questions here:

  • A System.IO.FileNotFoundException, does this mean that my application is ok, tries to open some external file which is not present, or is it something like a Java process, missing a *.class file?
  • Why is a System.IO.FileNotFoundException not catched by my try ... catch (Exception ex) clause?
  • What about the logs? I'm expecting to see at least the first line of the ListOfWoodTypes() function. Does this mean that there is some buffering in NLog technology, causing NLog logging to have some delay on a crash?

Edit1, debugging not possible
I'm developping this program on my own PC, I build it here, but I then copy the executable to my customer's PC, so debugging is not possible.

Reopen request
My question has nothing to do with ".NET Global exception handler in console application", it is specific about this one exception. Moreover this particular exception is not handled completely in the Windows event log, as can be seen in my own answer.

Dominique
  • 16,450
  • 15
  • 56
  • 112
  • `Exception Info: System.IO.FileNotFoundException at ...ListOfWoodTypes()` - i'd guess there's something wrong inside your... `ListOfWoodTypes()`-code. which we can't tell, though, because you didn't share it. also: have you tried _stepping through the method,_ to see where exactly it breaks? – Franz Gleichmann Dec 09 '21 at 08:33
  • 2
    It means a file was not found. The exception isn't caught by your handler because it's not occurring inside your `try` block (but on a separate thread, for example). These are things trivially deduced without context. For the rest, a debugger is required. – Jeroen Mostert Dec 09 '21 at 08:35
  • Why would you expect the `catch` block to work when you can see `End of function ListOfCabins()` in your logs? That makes it clear that the code has left the scope of that `try`/`catch` block. – Damien_The_Unbeliever Dec 09 '21 at 08:36
  • As a side note: Yes, Nlog may do some caching, but it should never happen that a later message is visible, while an earlier is not. There's something weird in your code flow. – PMF Dec 09 '21 at 08:38
  • @Damien_The_Unbeliever: indeed my code has left the `ListOfCabins()` function, but then I would expect my code to enter the `ListOfWoodTypes()` function. In that case, I'm expecting to see the first log in my logfile, but I don't. Nevertheless the crash would appear inside my `ListOfWoodTypes()` function, as indicated in the event log. How is this even possible? You're seriously not saying that this simple `Logger.Info()` line is causing the crash, aren't you? – Dominique Dec 09 '21 at 08:46
  • @PMF, I believe you are mistaking: I'm not saying that a log entry is skipped while a second log entry is shown. I'm saying that a first log entry is shown, a second log entry is not shown and my application crashes, while I believe my application to be crashing after the second log entry. So my question: why don't I see that second log entry? – Dominique Dec 09 '21 at 08:49
  • Without knowing how the rest of your code is structured, is it possible that you're actually getting a `TypeLoadException` with this `FileNotFoundException` as its inner exception? – Damien_The_Unbeliever Dec 09 '21 at 08:50
  • @Damien_The_Unbeliever: I don't understand what a `TypeLoadException` is, how could I recognise that? (It's certainly not mentioned in the event logs). I can tell you however that a nearby event log entry mentions Exception code "0xe0434352". – Dominique Dec 09 '21 at 08:53
  • 1
    Nah, in that example the shown exception would be TypeLoadException and - in the application log - the inner exception would just not bevisible. This is a FileNotFoundException on the top level of the possibly exception hierarchy. – TomTom Dec 09 '21 at 09:06

1 Answers1

1

Let me start - this is not as easy as it sounds. The devil is, as they say, in the details...

System.IO.FileNotFoundException

This generally means SOMEONE has thrown it. Period. It is MEANT to be thrown for a file not being found, but I have seen system exceptions abused by stupid programmers, or "file not found" being interpreted quite complicated (network streams CAN be opened using a file api) at times. So, while it is an indication of - you know - a file not found, it is not 100% sure that this is what triggered it.

Why is a System.IO.FileNotFoundException not catched by my try ... catch (Exception ex) clause?

You tell us. It SHOULD be - IF it is thrown within it.

Your own code has logger information before and after. And logging may go into - guess what - a file. It is not totally surreal to assume that possibly the first line throws the error.

WE can not know - you should. In the debugger make a break when this exception is thrown. Get the exact location it is thrown. Look at the call stack. LOOK AT THE PROPERTIES. Exceptions often have additional data in them - message, possibly properties. Just telling us the details is like "a mercedes crashed, what was the error". The debugging details would likely answer all your questions.

What about the logs? I'm expecting to see at least the first line of the ListOfWoodTypes() function.

Yeah, except if THAT LINE THROWS THE EXCEPTION. With no log file I would strongly suggest - you know - logging being the problem.

Does this mean that there is some buffering in NLog technology, causing NLog logging to have some delay on a crash?

Well, that technology being "use standard .NET caching"... it would be utterly stupid NOT to use it. See, the problem being that if you do not cache, you need a lot of disci IO, making logging a major performance hog, possibly. You can not have this.

But: Caching or not, is the file there? If not - there goes your implication. File generation is not cached (writes are, but the file has to be there for a stream to be opened). The file not being there...

TomTom
  • 61,059
  • 10
  • 88
  • 148
  • No. Not necessarily. In the above example, the application START (!) could already be logged and - that would trigger the crash. Once that is over, you do know that logging works. I would not dream of adding logging without an application start logging. It is more like "do not assume your logging works just because you add log entries to all methods WITHOUT TESTING THAT LOGGING WORKS DURING STARTUP. – TomTom Dec 09 '21 at 09:30
  • You just won't believe the structure of the code: `try { Logger.Info(...) ... } catch (Exception ex) {Logger.Error(...);}`, so if the exception is raised because of the `Logger`, I just keep on falling into the same trap :-) – Dominique Dec 09 '21 at 09:46