== Why there is a huge jump in the time used? ==

Discussion in 'ASP .Net Web Services' started by J.J., Dec 14, 2005.

  1. J.J.

    J.J. Guest

    Hi,

    I've a quetion which has bugged me for quite a while.

    I wrote a C#/.NET Web service which is hosted by IIS 5.1 on a Windows XP SP2
    machine. This Web service just get the content of the specified txt file and
    send the content back to the client. The processing time on the server side
    was logged by IIS.
    The file sizes and results are listed below (in millisecond):

    FileSize: 1K 2K 4K 8K 16K 32K 64K 128K
    256K
    TimeUsed: 10.0 10.5 10.5 12.0 14.5 116.0 140.5 141
    151

    As you can seen, the weird thing is, when the file size changes from 16K to
    32K, there is big jump in the processing time on the server side. Actually
    the jump is between 30K and 31K: when file size is 30K, the time used on the
    server side is about 15ms, when file size is 31K, it jumps to about 150ms
    (this is the average value. In one of ten, the value is still very small,
    like 10-20ms, but most of them are about 150-200ms).

    And here is the code I used to implement the Web service:

    public string GetLocalFile(string fileName)
    {
    string returnString = "";

    string filePath = @"C:\Inetpub\wwwroot\Files\";

    string fullName = filePath + fileName;

    StreamReader fs = File.OpenText(fullName);

    returnString = fs.ReadToEnd();

    fs.Close();

    return returnString;
    }

    I am using the following code on the client side to get files:

    private void SendWsFileRequestOut()
    {

    long startTime, endTime, elapseTime;

    startTime = DateTime.Now.Ticks;

    //Call Web service for the specified file
    fileFetcher.GetLocalFile(fileName);

    endTime = DateTime.Now.Ticks;

    elapseTime = endTime - startTime;

    }


    Can anyone help me figure out what the reason could be? Thanks a lot!

    J.J.
     
    J.J., Dec 14, 2005
    #1
    1. Advertising

  2. J.J,

    > The file sizes and results are listed below (in millisecond):
    >
    > FileSize: 1K 2K 4K 8K 16K 32K 64K 128K
    > 256K
    > TimeUsed: 10.0 10.5 10.5 12.0 14.5 116.0 140.5 141
    > 151


    FYI, the profiles that I did (running a local incantation of the code you
    posted) showed these times:

    File Size Time Spent in SendWsFileRequestOut
    (kb) (milliseconds)
    ====== ========================
    262 70
    554 80
    1108 95

    Regards,

    Randy
     
    Randy A. Ynchausti, Dec 14, 2005
    #2
    1. Advertising

  3. J.J.

    J.J. Guest

    Hello Randy,

    For the times you measured, are they logged in IIS log file, or you use some
    kind of profiler to get them? Also, are you using XP sp2 too?

    I think your results should be the normal ones. I just don't know why this
    happened on my computer.

    Actually I tried to install the Web service on another clean XP sp2 machine,
    and request files from the same client machine. I still got the same jump
    between 16K and 32K.



    "Randy A. Ynchausti" wrote:

    > J.J,
    >
    > > The file sizes and results are listed below (in millisecond):
    > >
    > > FileSize: 1K 2K 4K 8K 16K 32K 64K 128K
    > > 256K
    > > TimeUsed: 10.0 10.5 10.5 12.0 14.5 116.0 140.5 141
    > > 151

    >
    > FYI, the profiles that I did (running a local incantation of the code you
    > posted) showed these times:
    >
    > File Size Time Spent in SendWsFileRequestOut
    > (kb) (milliseconds)
    > ====== ========================
    > 262 70
    > 554 80
    > 1108 95
    >
    > Regards,
    >
    > Randy
    >
    >
    >
     
    J.J., Dec 14, 2005
    #3
  4. J.J.

    J.J. Guest

    Hello Randy,

    I saw your another answer to my problem in another discussion group. Thank
    you so much for your help.

    For the "automatic growth" problem, why it doesn't happen in your system?

    Thank you and best wishes,

    J.J.

    > This is probably a result of "automatic growth" (a.k.a. object
    > creation/allocation) in the stream reading the file. You can confirm this
    > by using a good allocation profiling tool.



    "Randy A. Ynchausti" wrote:

    > J.J,
    >
    > > The file sizes and results are listed below (in millisecond):
    > >
    > > FileSize: 1K 2K 4K 8K 16K 32K 64K 128K
    > > 256K
    > > TimeUsed: 10.0 10.5 10.5 12.0 14.5 116.0 140.5 141
    > > 151

    >
    > FYI, the profiles that I did (running a local incantation of the code you
    > posted) showed these times:
    >
    > File Size Time Spent in SendWsFileRequestOut
    > (kb) (milliseconds)
    > ====== ========================
    > 262 70
    > 554 80
    > 1108 95
    >
    > Regards,
    >
    > Randy
    >
    >
    >
     
    J.J., Dec 14, 2005
    #4
  5. J.J.,

    > For the times you measured, are they logged in IIS log file, or you use
    > some
    > kind of profiler to get them? Also, are you using XP sp2 too?


    To get an off-the-cuff understanding of the code, I created a Console
    Application and pasted your code into it with minor changes. I ran the
    DevPartner Profiler free community edition to accumulate the statistics I
    noted previously. I am running Windows XP SP2 on an 2.8GHz Pentinum 4
    machine. Here is part of the profiler output:

    Method Name % in Method % with Children Called Average
    [Program Start] 0 99.6 0 0
    FileReader.Class1.Main 1 25.5 1 3.3
    FileReader.Class1.SendWsFileRequestOut 0.8 24.3 1 2.4
    System.Security.SecurityManager.ResolvePolicy 0.6 23.7 2 1
    FileReader.Class1.GetLocalFile 0.3 23.2 1 0.9
    System.Security.SecurityManager.ResolvePolicy 0.9 22.6 2 1.4
    System.Reflection.Assembly.CreateSecurityIdentity 0.9 13.8 2 1.5
    System.Security.PolicyManager.Resolve 1.8 12.9 2 2.9
    System.IO.File.OpenText 0.3 12.8 1 0.9
    System.AppDomain.SetupDomain 6.3 12.4 1 19.7
    System.IO.StreamReader..ctor 1.2 11.9 1 3.6
    System.Security.Policy.Url..ctor 0.1 11.6 2 0.2
    System.Security.Util.URLString..ctor 1.6 11.4 2 2.5
    System.Security.SecurityManager..cctor 0.1 11.2 1 0.3
    System.Security.SecurityManager.Init 0.1 11.1 1 0.4
    System.Security.SecurityManager.DoInitSecurity 0.2 11 1 0.7
    System.Security.CodeAccessSecurityEngine..ctor 5.5 10.5 1 17.4
    System.IO.StreamReader..ctor 0.5 10.1 1 1.5
    System.Security.Util.URLString.ParseString 1.5 9.6 2 2.4
    System.IO.StreamReader.ReadToEnd 0.5 9.2 1 1.4
    System.IO.FileStream..ctor 2.5 9 1 8
    System.Security.SecurityManager.InitPolicy 0.1 7.8 2 0.1
    System.Security.PolicyManager..ctor 0.7 7.7 1 2.2
    System.Security.Policy.PolicyLevel.Resolve 0.3 7.1 6 0.1
    System.Security.PolicyManager.InitData 1.4 6.8 1 4.4
    System.Security.Policy.PolicyLevel.CheckCache 0.3 6.7 6 0.2
    System.IO.StreamReader.Read 0.2 6.1 555 0
    System.IO.FileStream..ctor 1 5.9 1 3.3
    System.IO.StreamReader.ReadBuffer 0.9 5.9 555 0


    > I think your results should be the normal ones. I just don't know why this
    > happened on my computer.


    Profiling will probably help you understand what is going on.

    > Actually I tried to install the Web service on another clean XP sp2
    > machine,
    > and request files from the same client machine. I still got the same jump
    > between 16K and 32K.


    Interesting. Sounds like fun figuring it out.

    Regards,

    Randy
     
    Randy A. Ynchausti, Dec 15, 2005
    #5
  6. J.J.

    J.J. Guest

    Hi Randy,

    Seems you were testing it as a console application instead of a Web service?
    Also, seems to me the client and the service were on the same machine, right?

    Actually when I test on the same machine, I can also get quite normal
    result. But, if I test the Web service by initiating requests from another
    machine, the results will be the ones I described before.

    Also, I am trying DevPartner free community edition. Since an IE window will
    be opened for the Web service, what I get are all for the IE session while
    not for the Webmethod of the Web service.

    Any thoughts?

    Thank you and best wishes,

    J.J.


    "Randy A. Ynchausti" wrote:

    > J.J.,
    >
    > > For the times you measured, are they logged in IIS log file, or you use
    > > some
    > > kind of profiler to get them? Also, are you using XP sp2 too?

    >
    > To get an off-the-cuff understanding of the code, I created a Console
    > Application and pasted your code into it with minor changes. I ran the
    > DevPartner Profiler free community edition to accumulate the statistics I
    > noted previously. I am running Windows XP SP2 on an 2.8GHz Pentinum 4
    > machine. Here is part of the profiler output:
    >
    > Method Name % in Method % with Children Called Average
    > [Program Start] 0 99.6 0 0
    > FileReader.Class1.Main 1 25.5 1 3.3
    > FileReader.Class1.SendWsFileRequestOut 0.8 24.3 1 2.4
    > System.Security.SecurityManager.ResolvePolicy 0.6 23.7 2 1
    > FileReader.Class1.GetLocalFile 0.3 23.2 1 0.9
    > System.Security.SecurityManager.ResolvePolicy 0.9 22.6 2 1.4
    > System.Reflection.Assembly.CreateSecurityIdentity 0.9 13.8 2 1.5
    > System.Security.PolicyManager.Resolve 1.8 12.9 2 2.9
    > System.IO.File.OpenText 0.3 12.8 1 0.9
    > System.AppDomain.SetupDomain 6.3 12.4 1 19.7
    > System.IO.StreamReader..ctor 1.2 11.9 1 3.6
    > System.Security.Policy.Url..ctor 0.1 11.6 2 0.2
    > System.Security.Util.URLString..ctor 1.6 11.4 2 2.5
    > System.Security.SecurityManager..cctor 0.1 11.2 1 0.3
    > System.Security.SecurityManager.Init 0.1 11.1 1 0.4
    > System.Security.SecurityManager.DoInitSecurity 0.2 11 1 0.7
    > System.Security.CodeAccessSecurityEngine..ctor 5.5 10.5 1 17.4
    > System.IO.StreamReader..ctor 0.5 10.1 1 1.5
    > System.Security.Util.URLString.ParseString 1.5 9.6 2 2.4
    > System.IO.StreamReader.ReadToEnd 0.5 9.2 1 1.4
    > System.IO.FileStream..ctor 2.5 9 1 8
    > System.Security.SecurityManager.InitPolicy 0.1 7.8 2 0.1
    > System.Security.PolicyManager..ctor 0.7 7.7 1 2.2
    > System.Security.Policy.PolicyLevel.Resolve 0.3 7.1 6 0.1
    > System.Security.PolicyManager.InitData 1.4 6.8 1 4.4
    > System.Security.Policy.PolicyLevel.CheckCache 0.3 6.7 6 0.2
    > System.IO.StreamReader.Read 0.2 6.1 555 0
    > System.IO.FileStream..ctor 1 5.9 1 3.3
    > System.IO.StreamReader.ReadBuffer 0.9 5.9 555 0
    >
    >
    > > I think your results should be the normal ones. I just don't know why this
    > > happened on my computer.

    >
    > Profiling will probably help you understand what is going on.
    >
    > > Actually I tried to install the Web service on another clean XP sp2
    > > machine,
    > > and request files from the same client machine. I still got the same jump
    > > between 16K and 32K.

    >
    > Interesting. Sounds like fun figuring it out.
    >
    > Regards,
    >
    > Randy
    >
    >
    >
     
    J.J., Dec 16, 2005
    #6
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. Anand Sagar
    Replies:
    2
    Views:
    1,995
  2. Mr. SweatyFinger
    Replies:
    2
    Views:
    2,072
    Smokey Grindel
    Dec 2, 2006
  3. Replies:
    3
    Views:
    522
  4. Ted Byers
    Replies:
    23
    Views:
    432
    Peter J. Holzer
    Nov 15, 2008
  5. Eadwine Rose
    Replies:
    2
    Views:
    221
    Eadwine Rose
    Oct 15, 2006
Loading...

Share This Page