用于文件上传的 ASP.Net 页面在日志语句中间停止处理

Question

我们有一个非常简单的 ASP.Net 页面，用于将文件上传到我们的网络服务器。该页面没有控件 - 客户端使用它每晚自动向我们发送一个文件。

有时，我们似乎没有收到该文件，但客户报告说他们已发送该文件。

我们在页面中添加了一些日志语句，并发现了一些非常奇怪的东西。该页面在日志语句中间停止执行。没有异常(exception)，只是起来然后死去。

这是隐藏代码:

protected void Page_Load(object sender, EventArgs e) {
    try {
        // record that request came in at all
        log.Debug("Update Inventory page requested through HTTP {2} on {0} {1}", DateTime.Now.ToShortDateString(), DateTime.Now.ToLongTimeString(), IsPostBack ? "POST" : "GET");

        // make sure directory exists
        string basePath = Server.MapPath("~/admin/uploads/");
        log.Debug("Saving to folder {0}", basePath);

        if (!Directory.Exists(basePath)) {
            log.Debug("Creating folder {0}", basePath);
            Directory.CreateDirectory(basePath);
        }

    // generate a unique file name
        string fileName = DateTime.Now.Ticks.ToString() + ".dat";
        string path = basePath + fileName;
        log.Debug("Filename to save is {0}", fileName);

    // record initial bytes of stream/file
    StreamReader reader = new StreamReader(stream);
    string fileContents = reader.ReadToEnd();

    log.Debug("File received by GET is " + fileContents.Length + " characters long and begins with: " 
        + Environment.NewLine + fileContents.Substring(0, Math.Min(fileContents.Length, 1000)));

    // write out file
    File.WriteAllText(path, fileContents);

        log.Debug("Update Inventory page processing finished.");
        // trap for and record any and all exceptions
    } 
    catch (Exception ex) {
        log.Debug(ex);
    }
}

处理似乎在输出 fileContents 变量的长度和第一部分的日志语句中间终止。进程失败时发生的日志记录如下所示:

2010-08-02 02:46:01.7342|DEBUG|UpdateInventory|Update Inventory page requested through HTTP GET on 8/2/2010 2:46:01 AM
2010-08-02 02:46:01.7655|DEBUG|UpdateInventory|Saving to folder c:\hosting\sites\musicgoround.com\wwwroot\admin\uploads\
2010-08-02 02:46:01.7811|DEBUG|UpdateInventory|Filename to save is 634163139617811250.dat
2010-08-02 02:48:02.3905|DEBUG|UpdateInventory|

我真的不明白这是怎么回事。

我假设如果文件传输中出现错误，则 reader.ReadToEnd() 行会抛出异常。如果不是异常(exception)，我希望页面处理继续，但我可能只收到文件的一部分(在这种情况下它应该记录一些内容)。

日志记录语句仅访问字符串变量，并且它位于 try-catch 内。 NLog 是我们使用的日志组件，我们通过 Codeplex 上的 Simple Logging Facade 项目提供的 Facade 来访问它。因此，我们相信日志记录组件或多或少是万无一失的 - 我们在此处使用它时当然没有看到任何会导致问题的内容。

所以，这是怎么回事？到底为什么这个页面会像这样启动并停止处理？

事实上，我们得到了一个半完成的日志记录语句，这似乎表明日志系统中存在一个错误 - 但这似乎不太可能 - 而且我们有 NLog 的内部日志记录，并且它没有报告任何问题。

Answer 1

最有可能的候选者是这一行:

2010-08-02 02:48:02.3905|DEBUG|UpdateInventory|

是这样造成的:

log.Debug(ex);

即它抛出异常，但记录器没有记录任何有用的内容。为什么不尝试稍微切换一下日志级别，例如将异常日志记录级别更改为错误:

log.Error(ex);

这样你就可以看到它是否真的抛出了异常，而只是记录器没有正确记录异常字符串。