WMSWebServiceExtension 使用，支持压缩; BeforeSerialize \AfterSerialize \BeforeDeserialize\AfterDeserialize 四个时刻
using System;
using System.Collections.Generic;
using System.IO.Compression;
using System.Diagnostics;
using System.Text;
using System.IO;
using System.Net;
using System.Text.RegularExpressions;
using System.Web.Services.Protocols;
using System.Windows.Forms;
using Best.Utility;
using System.Reflection;
using Best.Utility.BestLog;
namespace Best.WMS.IService
{
public class WMSWebServiceExtension : SoapExtension
{
private Stream _oldStream;
private Stream _newStream;
private SoapMessage _curSoapMessage;
private DateTime _dtBeginSerializeTime = new DateTime(); //开始序列化时间
private DateTime _dtEndSerializeTime = new DateTime(); //结束序列化时间
private DateTime _dtBeginDeserializeTime = new DateTime(); //开始反序列化时间
private DateTime _dtEndDeserializeTime = new DateTime(); //结束反序列化时间
private string _udf6;
private const double ThresholdTime = 10 * 1000; //时间过长阀值，10秒
private readonly object _obj = new object();
public override void ProcessMessage(SoapMessage message)
{
lock (_obj)
{
_curSoapMessage = message;
switch (message.Stage)
{
case SoapMessageStage.BeforeSerialize:
_dtBeginSerializeTime = DateTime.Now;
break;
case SoapMessageStage.AfterSerialize:
_dtEndSerializeTime = DateTime.Now;
AfterSerialize(message);
break;
case SoapMessageStage.BeforeDeserialize:
_dtBeginDeserializeTime = DateTime.Now;
BeforeDeserialize(message);
break;
case SoapMessageStage.AfterDeserialize:
_dtEndDeserializeTime = DateTime.Now;
GetUdf6();
SoapLogHelper.LogInfo(GetLogLineStr());
break;
default:
throw new Exception("invalid stage");
}
}
}
public override Stream ChainStream(Stream stream)
{
lock (_obj)
{
_oldStream = stream;
_newStream = new MemoryStream();
return _newStream;
}
}
//序列化请求之后(此时可对数据进行压缩)
public void AfterSerialize(SoapMessage message)
{
_newStream.Position = 0;
//if (string.IsNullOrEmpty(ClientConfig.IsWhDefaul))
//{
// Copy(_newStream, _oldStream);
//}
//else
{
Copy2(_newStream, _oldStream);
}
}
//反序列化响应之前(此时可对数据进行解压缩)
public void BeforeDeserialize(SoapMessage message)
{
Copy(_oldStream, _newStream);
_newStream.Position = 0;
}
void Copy(Stream from, Stream to)
{
TextReader reader = new StreamReader(from);
TextWriter writer = new StreamWriter(to);
string strContent = reader.ReadToEnd();
writer.WriteLine(strContent);
writer.Flush();
}
void Copy2(Stream from, Stream to)
{
var zipStream = new GZipStream(to, CompressionMode.Compress);
var data = StreamToBytes(from);
zipStream.Write(data, 0, data.Length);//将数据压缩并写到基础流中
zipStream.Close();
}
/// <summary>
/// 将 Stream 转成 byte[]
/// </summary>
public byte[] StreamToBytes(Stream stream)
{
byte[] bytes = new byte[stream.Length];
stream.Read(bytes, 0, bytes.Length);
// 设置当前流的位置为流的开始
stream.Seek(0, SeekOrigin.Begin);
return bytes;
}
/// <summary>
/// 获取IP地址
/// </summary>
private string GetHostIP()
{
try
{
return new IPAddress(Dns.GetHostByName(Dns.GetHostName()).AddressList[0].Address).ToString();
}
catch
{
return "";
}
}
private string GetLogLineStr()
{
ParameterInfo[] piList = _curSoapMessage.MethodInfo.Parameters;
string parameter = "";
for (int i = 0; i < piList.Length; i++)
{
if (i == 0)
{
parameter += piList[i].ParameterType.Name;
}
else
{
parameter += ", " + piList[i].ParameterType.Name;
}
}
var sb = new StringBuilder();
TimeSpan totalSpan = _dtEndDeserializeTime.Subtract(_dtBeginSerializeTime); //服务总时间
double totalTime = totalSpan.TotalMilliseconds;
TimeSpan serialize = _dtEndSerializeTime.Subtract(_dtBeginSerializeTime); //序列化消耗时间
double serializeTime = serialize.TotalMilliseconds;
string serializeTimeVal = String.Format("{0:F}", serializeTime) + "ms";
TimeSpan deserialize = _dtEndDeserializeTime.Subtract(_dtBeginDeserializeTime); //序反列化消耗时间
double deserializeTime = deserialize.TotalMilliseconds;
string deserializeTimeVal = String.Format("{0:F}", deserializeTime) + "ms";
double udf6;
double serverTime = double.TryParse(_udf6, out udf6) ? udf6 : 0;
string serverTimeVal = String.Format("{0:F}", serverTime) + "ms"; //服务端消耗时间
double netWorkTime = totalTime - serializeTime - deserializeTime - serverTime;
string netWorkTimeVal = String.Format("{0:F}", netWorkTime) + "ms"; //网络消耗时间
sb.Append("IP address: " + GetHostIP() + "\r\n");
if (ClientService.CurrentUserInfo == null)
{
sb.Append("User: " + "Null" + "\r\n");
sb.Append("Org: " + "Null" + "\r\n");
}
else
{
sb.Append("User: " + ClientService.CurrentUserInfo.userName + "\r\n");
sb.Append("Org: " + ClientService.CurrentOrgName + "\r\n");
}
sb.Append("WebService: " + _curSoapMessage.Url + "\r\n");
sb.Append("WebMethod: " + _curSoapMessage.MethodInfo.Name + "(" + parameter + ")" + "\r\n");
sb.Append("InvokeTime: " + _dtBeginSerializeTime.ToString() + "\r\n");
sb.Append("serializeTime: " + serializeTimeVal + "\r\n");
sb.Append("deserializeTime: " + deserializeTimeVal + "\r\n");
sb.Append("ServerTime:" + serverTimeVal + "\r\n");
sb.Append("NetConsumeTime:" + netWorkTimeVal + "\r\n");
if (serializeTime > ThresholdTime)
{
LogTimeOutWarning("序列化消耗时间过长", serializeTime);
}
if (deserializeTime > ThresholdTime)
{
LogTimeOutWarning("序反列化消耗时间过长", deserializeTime);
}
if (serverTime > ThresholdTime)
{
LogTimeOutWarning("服务端返回时间过长", serverTime);
}
return sb.ToString();
}
/// <summary>
/// 记录各个环节超时日志
/// </summary>
private void LogTimeOutWarning(string warningMsg, double time)
{
var udfs = new List<string>
{
string.Format("WebService: {0}", _curSoapMessage.Url),
string.Format("WebMethod: {0}", _curSoapMessage.MethodInfo.Name),
string.Format("{0}：{1}ms", warningMsg, time)
};
try
{
SysLogger.LogWarn(LoggerService.CreateLogMsg(SysLogger.SysLogCode, "WebService", "WMSWebServiceExtension", "LogTimeOutWarning", null, udfs.ToArray()));
}
catch (Exception e)
{
NLogHelper.Warn(e.ToString());
}
}
void GetUdf6()
{
try
{
_newStream.Position = 0;
string soapMessage = new StreamReader(_newStream).ReadToEnd();
if (string.IsNullOrEmpty(soapMessage))
return;
if (soapMessage.Contains("<code>") && soapMessage.Contains("</code>"))
{
//强制更新
var codeArray = Regex.Split(soapMessage, "<code>", RegexOptions.IgnoreCase);
var codeStr = codeArray[1];
var messageCodeArray = Regex.Split(codeStr, "</code>", RegexOptions.IgnoreCase);
var messageCode = messageCodeArray[0];
if (messageCode.Trim() == "ERR_SECURITY_FORCE_RELOAD")
{
var forceExit = new ForceExitForm();
forceExit.ShowDialog();
if (forceExit.DialogResult != DialogResult.OK)
return;
var appFile = Application.StartupPath + "\\" + "Main.exe";
if (File.Exists(appFile))
Process.Start(appFile);
Environment.Exit(0);
}
}
if (!soapMessage.Contains("</udf6>") || !soapMessage.Contains("<udf6>"))
return;
var beforeArray = Regex.Split(soapMessage, "<udf6>", RegexOptions.IgnoreCase);
var firstStr = beforeArray[1];
var afterArray = Regex.Split(firstStr, "</udf6>", RegexOptions.IgnoreCase);
_udf6 = afterArray[0];
}
catch (Exception ex)
{
SysLogger.LogError(LoggerService.CreateLogMsg(SysLogger.SysLogCode, "WebService", "WMSWebServiceExtension", "GetUdf6", ex));
}
}
public override object GetInitializer(LogicalMethodInfo methodInfo, SoapExtensionAttribute attribute)
{
lock (_obj)
{
return DBNull.Value;
}
}
public override void Initialize(object initializer)
{
}
public override object GetInitializer(Type serviceType)
{
lock (_obj)
{
return DBNull.Value;
}
}
}
[AttributeUsage(AttributeTargets.Method)]
public class WMSExtensionAttribute : SoapExtensionAttribute
{
int priority;
public override Type ExtensionType
{
get { return typeof(WMSWebServiceExtension); }
}
public override int Priority
{
get
{
return priority;
}
set
{
priority = value;
}
}
}
}
有时在网络差、数据量大 的情况下，序列化 和 反序列化特别久的原因
使用wireshark可看出
上面计算的序列化时间：包含了 TCP3次握手的时间，一般都是慢在第一次和第二次握手之间
反序列化开始时间，收到第一个包 就认为开始序列化了（此时序列化出来的xml是不完整的），直到最后一个包传输完成，反序列化结束
所以，反序列化时间：包含了 接受后面数据包的时间（网络差，接收就慢，时间就大了）
