2

私のUAT環境で非常に奇妙な問題が発生しています。WCF相互に通信する2 つのサービスがあります。大まかに言うと、Web アプリケーションはビジネス層と通信し、そこから wcf 要求をトランザクション層に渡します。トランザクション層はすべての要求を処理して応答を返します。私が直面している問題は、トランザクション層がビジネス層から送信された要求を受信するのに約 1 分かかることです。サービスは同じサーバーにWCFデプロイされており、このアプリケーションのセットアップは本番環境で完全に実行されるため、何が起こっているのかわかりません...

例:

Web フロントエンドは、ビジネス層に wcf リクエストを送信して、すべての広告のリストを取得します。ビジネス レイヤーはいくつかのセキュリティ チェック (例から削除しました) を実行し、別の WCF リクエストを介してトランザクション レイヤーにリクエストを渡すだけです。ただし、トランザクション レイヤーがこの要求を受信するのに 1 分かかります。

ビジネス層:

    public partial class AdsManagementService : IAdsManagementService
{
    public ListAdvertisementResponse ListAdvertisement(ListAdvertisementRequest request)
    {
        LogManager.Write("Initiated AdsManagement.AdsManagentService.ListAdvertisement()", LogCategory.Trace.ToString());

        var response = new ListAdvertisementResponse();
        response.Advertisements = new List<Advertisement>();

        LogManager.Write("Authentication token validated in AdsManagement.AdsManagentService.ListAdvertisement()", LogCategory.Event.ToString());
        var client = new AdService.AdsManagementServiceClient();

        try
        {
            response = client.ListAdvertisement(request);
            LogManager.Write("response received by AdsManagement.AdsManagentService.ListAdvertisement()", LogCategory.Event.ToString());
        }
        finally
        {
            try
            {
                client.Close();
            }
            catch (Exception ex)
            {
                LogManager.ExceptionHandler(ex);
            }
        }
    }
}

トランザクション層

各メソッド呼び出しの開始/終了にログ トレース (BEGIN,END) を追加して、そのメソッドの処理にかかる時間を示しました。

 public ListAdvertisementResponse ListAdvertisement(ListAdvertisementRequest request)
    {
        LogManager.Write("BEGIN - ListAdvertisement", LogCategory.Event);
        var response = new ListAdvertisementResponse();

        try
        {                
            response.Advertisements = new List<AdvertisementType>();

            var ads = AdvertisementDataContextInstance.Advertisements;

            foreach (var ad in ads)
            {
                AdvertisementType advertisement = ConvertToAdvertisementType(ad);

                string filePath = AdFilePath + @"\" + ad.Code;

                if (Directory.Exists(filePath))
                {
                    string[] files = Directory.GetFiles(filePath);

                    foreach (string file in files)
                    {
                        advertisement.Files.Add(file);
                    }
                }

                response.Advertisements.Add(advertisement);
            }
        }
        catch (Exception ex)
        {
            response.ErrorAction = ResponseActionEnum.GeneralException;
            response.ErrorDetails = ex.Message;
            response.ErrorMessage = "Unable to list advertisements.";
        }

        LogManager.Write("END - ListAdvertisement", LogCategory.Event);
        return response;
    }

ビジネス層のログトレース

**Timestamp: 2/04/2013 9:23:08 AM**
Thread Name: 
Category: Trace
Severity: Information
Message: Initiated AdsManagement.AdsManagentService.ListAdvertisement()

**Timestamp: 2/04/2013 9:23:08 AM**
Thread Name: 
Category: Event
Severity: Information
Message: Authentication token validated in AdsManagement.AdsManagentService.ListAdvertisement()


**Timestamp: 2/04/2013 9:24:02 AM**
Thread Name: 
Category: Event
Severity: Information
Message: Response received by AdsManagement.AdsManagentService.ListAdvertisement()

**Timestamp: 2/04/2013 9:24:02 AM**
Thread Name: 
Category: Trace
Severity: Information
Message: Completed AdsManagement.AdsManagentService.ListAdvertisement()

**TRANSACTION LAYER LOG TRACE**

**2/04/2013 9:24:02 AM** - BEGIN - ListAdvertisement

**2/04/2013 9:24:02 AM** - BEGIN - ConvertToAdvertisementType

2/04/2013 9:24:02 AM - END - ConvertToAdvertisementType

2/04/2013 9:24:02 AM - BEGIN - ConvertToAdvertisementType

2/04/2013 9:24:02 AM - END - ConvertToAdvertisementType

2/04/2013 9:24:02 AM - BEGIN - ConvertToAdvertisementType

2/04/2013 9:24:02 AM - END - ConvertToAdvertisementType

**2/04/2013 9:24:02 AM** - END - ListAdvertisement


As you can see, there is roughly a 1 minute delay before the Transaction layer receives the request. I have no idea what is causing this. I think it might be the logging system (Microsoft.Practices.EnterpriseLibrary.Logging). I've noticed that it creates a separate log file almost every time it receives a request, almost as if the original log file is being kept open which stops it from writing to that file. Perhaps there is a 1 minute timeout on the logging before it decides to create a new log file and write to that?

I have the following log files in the logging directory for today's date: Every time I send a new request to the Transaction Layer, there is a 1min delay and then it creates a new log file:

RTITraceGeneral.log          02/04/2013 9:20 AM

RTIEvent.log                 02/04/2013 9:20 AM

c9d64c18-80d9-4993-b167-2070190fce51RTITraceGeneral.log    02/04/2013 9:20 AM

a7acf427-a919-4fe4-9832-d186e9e28c0cRTIEvent.log           02/04/2013 9:24 AM

8e35dbdc-3c94-4e93-866a-3affcbf5f082RTITraceGeneral.log    02/04/2013 9:24 AM
4

1 に答える 1

1

私はそれを理解することができました。IIS の WCF アプリケーションがマルチプロセス アプリケーション プールに設定されていたため、問題が発生したようです。これを変更して、すべての WCF サービスに対して単一のプロセス アプリケーション プールを使用すると、ログ ファイルが単一のファイルに作成されるようになり、遅延がなくなりました。

于 2013-04-02T00:31:26.060 に答える