0

XML ファイルのテレメトリ ログ行のバッチを受け入れ、それらを SQL Server のテーブルに転記する非常に単純なアプリケーションを作成しました。着信データのこれらのブロックのそれぞれを「チャプター」と呼びます。

パフォーマンス上の理由から、100 の暗黙的なトランザクションの代わりに、100 の新しい行に対して 1 つのトランザクションが存在するように、各チャプタはトランザクションにラップされます。

残念ながら、重複があり、トランザクションのコンテキストが共有されているため、章全体が省略されています。これは珍しいことですが、無視できるほどまれではありません。そこで、ループ、再試行フラグ、およびスキップ リストを保持するキャッチ (SqlException) を追加しました。行が挿入時にバーフすると、トランザクションをロールバックし、新しいトランザクションを作成し、行番号をスキップ リストに追加し、再試行フラグを設定して、ループさせます。スキップ リストに含まれる行を除いて、すべての行が再処理されます。2 番目の行が barfs の場合、スキップ リストに 2 つの項目があることを除いて、同じことが起こります。

この配置全体が機能します。私にカレーを与えているのはエンドゲームです。章が例外なくエンドツーエンドで処理されると、ループが終了し、スキップ リストが空かどうかを確認します。空でない場合は、Trace.TraceWarning() を使用して、後でフォレンジックに使用するために、失敗した行と XML のブロックの詳細を示すイベント ログ エントリを書き込もうとします。

物事が南に行くのはこの時点です。この Trace ステートメントは、「デバイスの準備ができていません」と主張する Win32 例外でバーフします。

誰もこのようなものを見たことがありますか？

一晩で、時々問題なく動作することに気付きました。Trace.TraceWarning() の直前に Thread.Sleep() を挿入したので、これで問題が解決するかどうかは興味深いところです。メッセージが Visual Studio のトレース リスナーに正常に記録されていることに気付いたことを付け加えておく必要があります。これが、速度またはタイミングに関連していると思わせる理由です。

1 日後、スレッドをスリープさせても違いがないことは明らかです。StringBuilder が状態を蓄積し、ループの終了後に単一の trace ステートメントが発生するように、ビジネス全体を書き直しました。3 つ以上のパスを必要とする複数の行が拒否された場合でも、Win32Exception はもはや明白ではありません。その特定の例外の正確な原因は、私には不明のままです。誰かがこの暗い隅に光を当ててくれることを願っていますが、章ごとに 1 つのログエントリが理想的であるため、これ以上追加することはありません。「回避策」は、Win32Exception がなくてもコードを改善することです。

話すのが早すぎた。邪悪な Win32Exception が戻ってきました。現状のコードは次のとおりです。

public void Write(string xml)
{
  StringBuilder sb = new StringBuilder();
  //Trace.TraceInformation(xml);
  SqlConnection cxn = new SqlConnection(Properties.Settings.Default.DatabaseBob);
  cxn.Open();
  SqlTransaction txn = null;
  SqlCommand cmd = new SqlCommand("INSERT INTO LOG(MAC, snip more fields ) VALUES(@MAC, snip more params)", cxn);
  var P = cmd.Parameters;
  P.Add(new SqlParameter("@MAC", SqlDbType.BigInt));

  /*snip define more SQL params*/

  XmlDocument doc = new XmlDocument();
  bool barfed = false;
  List<int> skipList = new List<int>();
  _stopwatch.Start();
  int i = 0;
  doc.LoadXml(xml);
  var root = doc.FirstChild.NextSibling;
  P["@MAC"].Value = ulong.Parse(root.Attributes["MAC"].Value, System.Globalization.NumberStyles.AllowHexSpecifier);
  P["@D2"].Value = P["@D3"].Value = 0; //COM2 
  do
    try
    {
      cmd.Transaction = txn = cxn.BeginTransaction();
      i = 0;
      barfed = false;
      for (var n = root.FirstChild; n != null; n = n.NextSibling)
      {
        foreach (XmlAttribute attr in n.Attributes)
        {
          var p = P["@" + attr.Name];
          switch (p.SqlDbType)
          {
            case SqlDbType.DateTime:
              p.Value = DateTime.Parse(attr.Value).ToUniversalTime();
              break;
            case SqlDbType.Float:
              p.Value = float.Parse(attr.Value);
              break;
            case SqlDbType.Bit:
              p.Value = Convert.ToBoolean(int.Parse(attr.Value));
              break;
          }
        }
        i++;
        if (!skipList.Contains(i))
          if ((DateTime)P["@GPSTIME"].Value > DateTime.UtcNow.AddMinutes(1))
          {
            sb.AppendFormat("Node {0} is being skipped because it has a future date.\r\n", i);
            skipList.Add(i);
          }
          else
            cmd.ExecuteNonQuery();
      }
      txn.Commit();
      sb.AppendFormat("{0} logs per {1}ms", i, _stopwatch.ElapsedMilliseconds);
    }
    catch (SqlException)
    {
      sb.AppendFormat("Node {0} is being skipped because it is a duplicate.\r\n", i);
      txn.Rollback();
      skipList.Add(i);
      barfed = true;
    }
    catch (Exception ex)
    {
      sb.AppendLine(ex.Message);
      txn.Rollback();
    }
  while (barfed);
  _stopwatch.Reset();
  if (skipList.Count == 0)
    Trace.TraceInformation(sb.ToString());
  else
  {
    sb.AppendLine();
    sb.Append(xml);
    Trace.TraceWarning(sb.ToString());
  }
}

そして、これは例外からのスタック トレースです。

at System.Diagnostics.EventLogInternal.InternalWriteEvent(UInt32 eventID, UInt16 category, EventLogEntryType type, String[] strings, Byte[] rawData, String currentMachineName)
at System.Diagnostics.EventLogInternal.WriteEvent(EventInstance instance, Byte[] data, Object[] values)
at System.Diagnostics.EventLog.WriteEvent(EventInstance instance, Object[] values)
at System.Diagnostics.EventLogTraceListener.TraceEvent(TraceEventCache eventCache, String source, TraceEventType severity, Int32 id, String message)
at System.Diagnostics.TraceInternal.TraceEvent(TraceEventType eventType, Int32 id, String format, Object[] args)
at System.Diagnostics.Trace.TraceWarning(String message)
at Bob.ChapterWriter.Write(String xml) in I:\Project Bob\LogWriter\ChapterWriter.cs:line 179
at SyncInvokeWrite(Object , Object[] , Object[] )
at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)

Write メソッドは、MSMQ メッセージの到着に応答して WCF によって呼び出されます。メッセージの内容は XML 文字列です。イベントログリスナーを削除すると、問題が解決します (これまでのところ)。

スタック トレースを調べると、179 行目は貼り付けられたコードの最後にあります。ここに再びあります：

Trace.TraceWarning(sb.ToString());

XML によってイベント ログに対してメッセージが大きくなりすぎるためでしょうか。チャプター ファイルのサイズを制限する設定が既にあります。減らして様子を見てみます。

4

1 に答える 1

1

そうです、本当の問題はメッセージ テキストが大きすぎることでした。イベント ログ エントリの最大サイズは、すべての Microsoft ヘッダーなどを含めて 64K です。私はそれを知っていましたが、XML が 32K に制限されていたため、これが問題になる可能性があるとは思いもしませんでした。多すぎる理由は次のとおりです。XML に埋め込むテキストに XML を入れると、エスケープされて、すべての不正な文字のサイズが 4 倍に増加します。すべての山かっこと二重引用符のサイズが 4 倍になりました。そして、それらはたくさんあります。

これからのポイントは次のとおりです。

  • イベント ログ メッセージに大量の XML を入れないでください。
  • Trace からイベント ログに Win32Exception が記録されている場合は、メッセージが大きすぎる可能性があります。
  • この制限を回避する 1 つの方法は、代わりにテキスト ファイル トレース リスナーを使用することです。
于 2012-03-17T06:41:12.487 に答える