Windows 服务 程序开发之异常日志

Windows 服务 程序开发之异常日志

 

事情概况 ： 昨天Windows服务程序里面的linq to sql 报了个错误,如下

“System.Data.Linq.ChangeConflictException: 找不到行或行已更改。”

这个错本身属于并发的问题，可是我这里要说的却是另外一回事。发现这个问题以后，便把服务程序停掉，然后再起动，结果还是一样的，这个错仍然存在，最后把服务程序卸载了，然后再安装一次就没有问题了。这样一个奇怪的问题，写一篇日志把它记录下来,作为教训,服务程序每秒执行一次，一个小小的bug就会引起重大影响，这个问题导致短时间内出现了1000多封拉圾邮件，让邮件服务程序承受不了。

程序大致是这样的

Windows服务程序大致如下

using System;
using System.Data.SqlClient;
using System.Linq;
using System.ServiceProcess;
using System.Timers;

using log4net;

namespace Avantouch.Platform.WinServices.Topup
{
    internal partial class TopupService3 : ServiceBase
    {

        private static readonly ILog SubmitLog = LogManager.GetLogger("DFSubmitLog");

        private static readonly ILog VerifyLog = LogManager.GetLogger("DFVerifyLog");

        private static PlatformDataContext _submitDataContext;

        private static PlatformDataContext _verifyDataContext;

        private static PlatformDataContext _NewOrderDataContext;

        private readonly Timer _submitTimer;

        private readonly Timer _verifyTimer;

        #endregion

        public TopupService3()
        {
            InitializeComponent();

            _submitDataContext = new PlatformDataContext(Settings.Default.ServicesConnectionString);
            _verifyDataContext = new PlatformDataContext(Settings.Default.ServicesConnectionString);
            _submitTimer = new Timer(1000);
            _submitTimer.Elapsed += SubmitTimerElapsed;

            _verifyTimer = new Timer(5 * 60 * 1000);
            _verifyTimer.Elapsed += VerifyTimerElapsed;
        }

        protected override void OnStart(string[] args)
        {
            _submitTimer.Start();

            _verifyTimer.Start();
        }

        protected override void OnStop()
        {
            _submitTimer.Stop();

            _verifyTimer.Stop();
        }

        internal void SubmitTimerElapsed(object sender, ElapsedEventArgs e)
        {
            _submitTimer.Stop();
            try
            {
                IQueryable<Order> orders = from t in _submitDataContext.Orders
                                           join t0 in _submitDataContext.Product on t.ProductId equals t0.ProductId
                                           where t.CategoryId == 1 && t0.SupplierId == 5 && t.Submitted == false && t.Deleted 

== "0"
                                           select t;
                Order record = orders.FirstOrDefault();
                if (record != null)
                {
                   
                    //处理程序
                    _submitDataContext.SubmitChanges();
                }
            }
            catch (SqlException sqlException)
            {
                SubmitLog.Error("数据库错误", sqlException);
                Alert("0003", "1");
            }
            catch (Exception exception)
            {
                SubmitLog.Error("异常错误", exception);
                Alert("0004", "1");
            }
            finally
            {
                _submitTimer.Start();
            }
        }




        internal void VerifyTimerElapsed(object sender, ElapsedEventArgs e)
        {
            _verifyTimer.Stop();
            VerifyLog.Info("--------------------------------------------------");
            VerifyLog.InfoFormat("德丰充值查询验证服务时间：{0}信息输出......", System.DateTime.Now);
            try
            {

                IQueryable<Order> orders = from t in _verifyDataContext.Orders
                                           join t0 in _verifyDataContext.Product on t.ProductId equals t0.ProductId
                                           where t.CategoryId == 1 && t0.SupplierId == 5 && t.Submitted && !t.Verified && 

t.Deleted == "0" && t.SubmitTime.Value.AddMinutes(5) < DateTime.Now
                                           select t;

                foreach (Order record in orders)
                {
                   //处理程序
                     _verifyDataContext.SubmitChanges();
                }
            }
            catch (SqlException sqlException)
            {
                //邮件
                VerifyLog.Error("数据库错误", sqlException);
                Alert("0003", "2");
            }
            catch (Exception exception)
            {
                //TODO：邮件
                VerifyLog.Error("异常错误", exception);
                Alert("0004", "2");
            }
            finally
            {
                _verifyTimer.Start();
            }
        }

 

       

    }
}

  

程序里有两个timer，都是查找出记录，处理完了以后再更新，其中_submitTimer是一秒钟更新一次，而_verifyTimer是5分钟后再查询记录更新处理，正常情况下两个timer不会同时处理同一条记录，即linq to sql 不会发生并发的问题。但是如果submitTimer里的程序出了异常，延迟了5分钟，异致两个timer会同时处理同一条记录，linq to sql 导致了并发冲突.。

结果submitTimer处理死循环当中，系统的工作日志如下

2010-12-21 17:27:27,023 [10] INFO  DFSubmitLog - ==================================================
2010-12-21 17:27:27,023 [10] INFO  DFSubmitLog - 开始提交序号为353770的订单......
2010-12-21 17:27:27,042 [10] DEBUG DFSubmitLog - 数据库字段已更新......
2010-12-21 17:37:57,792 [10] ERROR DFSubmitLog - 异常错误
System.Data.Linq.ChangeConflictException: 找不到行或行已更改。
   在 System.Data.Linq.ChangeProcessor.SubmitChanges(ConflictMode failureMode)
   在 System.Data.Linq.DataContext.SubmitChanges(ConflictMode failureMode)
   在 Avantouch.Platform.WinServices.Topup.TopupService3.SubmitTimerElapsed(Object sender, ElapsedEventArgs e)
2010-12-21 17:37:57,793 [10] INFO  DFSubmitLog - 开始下发报警邮件通知......
2010-12-21 17:37:57,803 [10] INFO  DFSubmitLog - 邮件已下发......
2010-12-21 17:37:58,891 [9] INFO  DFSubmitLog - ==================================================
2010-12-21 17:37:58,891 [9] INFO  DFSubmitLog - 开始提交序号为353773的订单......
2010-12-21 17:37:58,909 [9] ERROR DFSubmitLog - 异常错误
System.Data.Linq.ChangeConflictException: 找不到行或行已更改。
   在 System.Data.Linq.ChangeProcessor.SubmitChanges(ConflictMode failureMode)
   在 System.Data.Linq.DataContext.SubmitChanges(ConflictMode failureMode)
   在 Avantouch.Platform.WinServices.Topup.TopupService3.SubmitTimerElapsed(Object sender, ElapsedEventArgs e)
2010-12-21 17:37:58,910 [9] INFO  DFSubmitLog - 开始下发报警邮件通知......
2010-12-21 17:37:58,919 [9] INFO  DFSubmitLog - 邮件已下发......
2010-12-21 17:38:00,013 [9] INFO  DFSubmitLog - ==================================================
2010-12-21 17:38:00,013 [9] INFO  DFSubmitLog - 开始提交序号为353773的订单......
2010-12-21 17:38:00,036 [9] ERROR DFSubmitLog - 异常错误
System.Data.Linq.ChangeConflictException: 找不到行或行已更改。
   在 System.Data.Linq.ChangeProcessor.SubmitChanges(ConflictMode failureMode)
   在 System.Data.Linq.DataContext.SubmitChanges(ConflictMode failureMode)
   在 Avantouch.Platform.WinServices.Topup.TopupService3.SubmitTimerElapsed(Object sender, ElapsedEventArgs e)
2010-12-21 17:38:00,036 [9] INFO  DFSubmitLog - 开始下发报警邮件通知......
2010-12-21 17:38:00,041 [9] INFO  DFSubmitLog - 邮件已下发......
2010-12-21 17:38:01,121 [9] INFO  DFSubmitLog - ==================================================
2010-12-21 17:38:01,121 [9] INFO  DFSubmitLog - 开始提交序号为353773的订单......
2010-12-21 17:38:01,140 [9] ERROR DFSubmitLog - 异常错误
System.Data.Linq.ChangeConflictException: 找不到行或行已更改。
   在 System.Data.Linq.ChangeProcessor.SubmitChanges(ConflictMode failureMode)
   在 System.Data.Linq.DataContext.SubmitChanges(ConflictMode failureMode)
   在 Avantouch.Platform.WinServices.Topup.TopupService3.SubmitTimerElapsed(Object sender, ElapsedEventArgs e)
2010-12-21 17:38:01,140 [9] INFO  DFSubmitLog - 开始下发报警邮件通知......
2010-12-21 17:38:01,146 [9] INFO  DFSubmitLog - 邮件已下发......
2010-12-21 17:38:02,230 [9] INFO  DFSubmitLog - ==================================================

 

这是这样一直处于死循环当中了。这时候把服务停了，然后启动，还是出错，日志记录如下

2010-12-21 18:04:27,848 [8] INFO  DFSubmitLog - 服务已停止......
2010-12-21 18:04:29,156 [9] INFO  DFSubmitLog - 服务已启动......
2010-12-21 18:04:30,241 [9] INFO  DFSubmitLog - ==================================================
2010-12-21 18:04:30,241 [9] INFO  DFSubmitLog - 开始提交序号为353773的订单......
2010-12-21 18:04:30,261 [9] ERROR DFSubmitLog - 异常错误
System.Data.Linq.ChangeConflictException: 找不到行或行已更改。
   在 System.Data.Linq.ChangeProcessor.SubmitChanges(ConflictMode failureMode)
   在 System.Data.Linq.DataContext.SubmitChanges(ConflictMode failureMode)
   在 Avantouch.Platform.WinServices.Topup.TopupService3.SubmitTimerElapsed(Object sender, ElapsedEventArgs e)
2010-12-21 18:04:30,262 [9] INFO  DFSubmitLog - 开始下发报警邮件通知......
2010-12-21 18:04:30,268 [9] INFO  DFSubmitLog - 邮件已下发......
2010-12-21 18:04:31,351 [9] INFO  DFSubmitLog - ==================================================
2010-12-21 18:04:31,351 [9] INFO  DFSubmitLog - 开始提交序号为353773的订单......
2010-12-21 18:04:31,371 [9] ERROR DFSubmitLog - 异常错误
System.Data.Linq.ChangeConflictException: 找不到行或行已更改。
   在 System.Data.Linq.ChangeProcessor.SubmitChanges(ConflictMode failureMode)
   在 System.Data.Linq.DataContext.SubmitChanges(ConflictMode failureMode)
   在 Avantouch.Platform.WinServices.Topup.TopupService3.SubmitTimerElapsed(Object sender, ElapsedEventArgs e)
2010-12-21 18:04:31,372 [9] INFO  DFSubmitLog - 开始下发报警邮件通知......
2010-12-21 18:04:31,378 [9] INFO  DFSubmitLog - 邮件已下发......
2010-12-21 18:04:32,474 [6] INFO  DFSubmitLog - ==================================================

结果把服务卸载了，然后再安装问题便没了.遇到这个问题，然后网上查了一下，也咨询了一相，只能考虑linq to sql 的资源没有释放掉了。这个问题的根源在于submitTimer里的异常，导致两个timer同时处理一条记录，目前先处理掉这个根源问题

 

有关linq to sql 的资源释放问是，可参考以下链接的文章

http://www.cnblogs.com/kirinboy/archive/2010/01/04/dispose-datacontext-or-not.html

http://blog.darkthread.net/blogs/darkthreadtw/archive/2009/10/19/linq-to-sql-connection-issue.aspx

有关解决linq to sql 并发冲突的话，可参考以下文章

http://www.cnblogs.com/sunnyfong/archive/2008/09/25/1298829.html