Very slow website compilation

View: New views
5 Messages — Rating Filter:   Alert me  

Very slow website compilation

by aps-3 :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hi,

I have a big issue on a web application I'm running using mod_mono with Apache 2.
I have only one application configured and running it (with or without batch compilation) I'm experiencing a very long delay waiting for the application to compile.
I can see in logs that the assemblies inside bin directory is added to domain the first time it's found, here is an example

Mono-INFO: Assembly Loader probing location: '/var/www/hypersic/bin/templatelibrary.dll'.
Mono-INFO: Assembly Loader shadow-copied assembly to: '/tmp/apache-temp-aspnet-0/ddd13fb8/assembly/shadow/3c8e4077/5cab6a9f_60252ae8_00000001/templatelibrary.dll'.
Mono-INFO: Image addref templatelibrary 0x3367100 -> /tmp/apache-temp-aspnet-0/ddd13fb8/assembly/shadow/3c8e4077/5cab6a9f_60252ae8_00000001/templatelibrary.dll 0x3365ab0: 2

Mono-INFO: Assembly templatelibrary 0x3367100 added to domain 8ce83063, ref_count=1

Mono-INFO: Assembly Loader loaded assembly from location: '/var/www/hypersic/bin/templatelibrary.dll'.
Mono-INFO: Config attempting to parse: '/tmp/apache-temp-aspnet-0/ddd13fb8/assembly/shadow/3c8e4077/5cab6a9f_60252ae8_00000001/templatelibrary.dll.config'.
Mono-INFO: Config attempting to parse: '/usr/local/etc/mono/assemblies/templatelibrary/templatelibrary.config'.
Mono-INFO: Config attempting to parse: '/var/www/.mono/assemblies/templatelibrary/templatelibrary.config'.

then it starts with web pages and every time it loads a new ascx/ascx file there's a log like that:

Mono-INFO: Assembly Loader probing location: '/tmp/apache-temp-aspnet-0/ddd13fb8/App_Web_6d545f95.dll'.
Mono-INFO: Image addref App_Web_6d545f95 0x2aaab828ebb0 -> /tmp/apache-temp-aspnet-0/ddd13fb8/App_Web_6d545f95.dll 0x2aaab8229e00: 2

Mono-INFO: Assembly App_Web_6d545f95 0x2aaab828ebb0 added to domain 8ce83063, ref_count=1

Mono-INFO: Assembly Loader loaded assembly from location: '/tmp/apache-temp-aspnet-0/ddd13fb8/App_Web_6d545f95.dll'.
Mono-INFO: Config attempting to parse: '/tmp/apache-temp-aspnet-0/ddd13fb8/App_Web_6d545f95.dll.config'.
Mono-INFO: Config attempting to parse: '/usr/local/etc/mono/assemblies/App_Web_6d545f95/App_Web_6d545f95.config'.
Mono-INFO: Config attempting to parse: '/var/www/.mono/assemblies/App_Web_6d545f95/App_Web_6d545f95.config'.
Mono-INFO: Assembly Ref addref App_Web_6d545f95 0x2aaab828ebb0 -> WebSicDotNet 0x11dbdd00: 3

after that it starts probing form System libraries and it apparently it found them inside gac

Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System/2.0.0.0__b77a5c561934e089/System.dll'.
Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System.Configuration/2.0.0.0__b03f5f7f11d50a3a/System.Configuration.dll'.
Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System.Data/2.0.0.0__b77a5c561934e089/System.Data.dll'.
Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System.Drawing/2.0.0.0__b03f5f7f11d50a3a/System.Drawing.dll'.
Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System.Web/2.0.0.0__b03f5f7f11d50a3a/System.Web.dll'.
Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System.Web.Services/2.0.0.0__b03f5f7f11d50a3a/System.Web.Services.dll'.
Mono-INFO: Assembly Loader probing location: '/usr/local/lib/mono/gac/System.Xml/2.0.0.0__b77a5c561934e089/System.Xml.dll'.

after system libraries it starts looking for all the files in bin directory and for every file it makes something like

Mono-INFO: Assembly Loader probing location: '/var/www/hypersic/bin/APS.API.dll'.
Mono-INFO: Assembly Loader shadow-copied assembly to: '/tmp/apache-temp-aspnet-0/ddd13fb8/assembly/shadow/dcbea906/bc9b83ee_60252ae8_00000001/APS.API.dll'.
Mono-INFO: Assembly Loader probing location: '/var/www/hypersic/bin/APS.BaseClasses.dll'.
Mono-INFO: Assembly Loader shadow-copied assembly to: '/tmp/apache-temp-aspnet-0/ddd13fb8/assembly/shadow/97cc1381/f7e93969_60252ae8_00000001/APS.BaseClasses.dll'.
Mono-INFO: Assembly Loader probing location: '/var/www/hypersic/bin/APS.Chart.dll'.
Mono-INFO: Assembly Loader shadow-copied assembly to: '/tmp/apache-temp-aspnet-0/ddd13fb8/assembly/shadow/f7c1e34a/97e4c9a2_60252ae8_00000001/APS.Chart.dll'.

and so on, for the thousands of files placed inside the bin directory.
It seems to me that there's some problem cause all the files seems missing even if they are there and it always redo the copying.
Most of the loading time is spent in this multiple shadow copying, as I have many assemblies inside bin directory this cause an heavy disk usage and many minutes of wait.
It doesn't seems to be a correct behavior, an assembly should be shadow copied only one time so I'm try to find out if it's a mono/mod-mono-server bug or if it's due to some wrong configuration.
Please help me cause it a very big issue for my customers.
Thanks in advance. 

_______________________________________________
Mono-aspnet-list mailing list
Mono-aspnet-list@...
http://lists.ximian.com/mailman/listinfo/mono-aspnet-list

Re: Very slow website compilation

by Robert Jordan :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hi,

APS wrote:
> and so on, for the thousands of files placed inside the bin directory.
> It seems to me that there's some problem cause all the files seems
> missing even if they are there and it always redo the copying.
> Most of the loading time is spent in this multiple shadow copying, as I
> have many assemblies inside bin directory this cause an heavy disk usage
> and many minutes of wait.

The log message might be misleading: it is even emitted when
the assembly was not actually shadow-copied due to mtime
equality.

Try the attached patch to see if the copy operations are
actually skipped (grep for "up-to-date" in your logs).

Robert

Index: metadata/appdomain.c
===================================================================
--- metadata/appdomain.c (revision 142262)
+++ metadata/appdomain.c (working copy)
@@ -1431,8 +1431,10 @@
  mono_raise_exception (exc);
  }
 
- if (!private_file_needs_copying (filename, &src_sbuf, shadow))
+ if (!private_file_needs_copying (filename, &src_sbuf, shadow)) {
+ mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_ASSEMBLY, "Shadow copy %s of %s is up-to-date.\n", shadow, filename);
  return (char*) shadow;
+ }
 
  orig = g_utf8_to_utf16 (filename, strlen (filename), NULL, NULL, NULL);
  dest = g_utf8_to_utf16 (shadow, strlen (shadow), NULL, NULL, NULL);

_______________________________________________
Mono-aspnet-list mailing list
Mono-aspnet-list@...
http://lists.ximian.com/mailman/listinfo/mono-aspnet-list

Re: Very slow website compilation

by aps-3 :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hi,

I tried your patch adding some other message and I found that the problem is inside private_file_needs_copying where there's a check on field st_mode of stat structure.
The problem is that in my installation the source file have not the same access rights of the shadow copy so mono copies the files everytime.
I can change access rights to source files but I think it's wrong to check the access mode because it's not a value that helps to understand if a file is up-to-date, size and mtime should be enough. Do you agree?
Another thing. I saw on the same function that at the first run after apache restart mono doesn't find the assembly in cache directoryƬ and it makes a copy.
This is because every time the service is stopped the user-temp-aspnet directory is cleaned. But in this way everytime we restart apache we need to wait the same loading time of the first time after site installation. Temporary files could be kept in cache directory in order to avoid reloading, this should dramatically increase mono asp.net loading time.
I think MS.NET act like this cause the second run after site installation is quicker than the first, in mono is everytime equal.

As for private_file_needs_copying I think it could be modified like this, hope this helps:

static gboolean
private_file_needs_copying (const char *src, struct stat *sbuf_src, char *dest)
{
        struct stat sbuf_dest;
        
        if (stat (src, sbuf_src) == -1 || stat (dest, &sbuf_dest) == -1)
                 return TRUE;
        if (sbuf_src->st_size == sbuf_dest.st_size &&
             sbuf_src->st_mtime == sbuf_dest.st_mtime)
                 return FALSE;
        return TRUE;
}


At 13.30 02/10/2009, Robert Jordan wrote:
Hi,

APS wrote:
and so on, for the thousands of files placed inside the bin directory.
It seems to me that there's some problem cause all the files seems missing even if they are there and it always redo the copying.
Most of the loading time is spent in this multiple shadow copying, as I have many assemblies inside bin directory this cause an heavy disk usage and many minutes of wait.

The log message might be misleading: it is even emitted when
the assembly was not actually shadow-copied due to mtime
equality.

Try the attached patch to see if the copy operations are
actually skipped (grep for "up-to-date" in your logs).

Robert

--
Il messaggio e' stato analizzato alla ricerca di virus o
contenuti pericolosi da MailScanner, ed e'
risultato non infetto.



Index: metadata/appdomain.c
===================================================================
--- metadata/appdomain.c         (revision 142262)
+++ metadata/appdomain.c         (working copy)
@@ -1431,8 +1431,10 @@
                  mono_raise_exception (exc);
        }        
 
-       if (!private_file_needs_copying (filename, &src_sbuf, shadow))
+       if (!private_file_needs_copying (filename, &src_sbuf, shadow)) {
+                mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_ASSEMBLY, "Shadow copy %s of %s is up-to-date.\n", shadow, filename);
                 return (char*) shadow;
+       }
 
        orig = g_utf8_to_utf16 (filename, strlen (filename), NULL, NULL, NULL);
        dest = g_utf8_to_utf16 (shadow, strlen (shadow), NULL, NULL, NULL);

_______________________________________________
Mono-aspnet-list mailing list
Mono-aspnet-list@...
http://lists.ximian.com/mailman/listinfo/mono-aspnet-list

_______________________________________________
Mono-aspnet-list mailing list
Mono-aspnet-list@...
http://lists.ximian.com/mailman/listinfo/mono-aspnet-list

Re: Very slow website compilation

by Robert Jordan :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Marek,

do you remember why private_file_needs_copying () is checking st_mode?

Robert

APS wrote:

> Hi,
>
> I tried your patch adding some other message and I found that the
> problem is inside private_file_needs_copying where there's a check on
> field st_mode of stat structure.
> The problem is that in my installation the source file have not the same
> access rights of the shadow copy so mono copies the files everytime.
> I can change access rights to source files but I think it's wrong to
> check the access mode because it's not a value that helps to understand
> if a file is up-to-date, size and mtime should be enough. Do you agree?
> Another thing. I saw on the same function that at the first run after
> apache restart mono doesn't find the assembly in cache directoryƬ and it
> makes a copy.
> This is because every time the service is stopped the user-temp-aspnet
> directory is cleaned. But in this way everytime we restart apache we
> need to wait the same loading time of the first time after site
> installation. Temporary files could be kept in cache directory in order
> to avoid reloading, this should dramatically increase mono asp.net
> loading time.
> I think MS.NET act like this cause the second run after site
> installation is quicker than the first, in mono is everytime equal.
>
> As for private_file_needs_copying I think it could be modified like
> this, hope this helps:
>
> static gboolean
> private_file_needs_copying (const char *src, struct stat *sbuf_src, char
> *dest)
> {
>         struct stat sbuf_dest;
>
>         if (stat (src, sbuf_src) == -1 || stat (dest, &sbuf_dest) == -1)
>                 return TRUE;
>         if (sbuf_src->st_size == sbuf_dest.st_size &&
>             sbuf_src->st_mtime == sbuf_dest.st_mtime)
>                 return FALSE;
>         return TRUE;
> }
>
>
> At 13.30 02/10/2009, Robert Jordan wrote:
>> Hi,
>>
>> APS wrote:
>>> and so on, for the thousands of files placed inside the bin directory.
>>> It seems to me that there's some problem cause all the files seems
>>> missing even if they are there and it always redo the copying.
>>> Most of the loading time is spent in this multiple shadow copying, as
>>> I have many assemblies inside bin directory this cause an heavy disk
>>> usage and many minutes of wait.
>>
>> The log message might be misleading: it is even emitted when
>> the assembly was not actually shadow-copied due to mtime
>> equality.
>>
>> Try the attached patch to see if the copy operations are
>> actually skipped (grep for "up-to-date" in your logs).
>>
>> Robert
>>
>> --
>> Il messaggio e' stato analizzato alla ricerca di virus o
>> contenuti pericolosi da MailScanner, ed e'
>> risultato non infetto.
>>
>>
>>
>> Index: metadata/appdomain.c
>> ===================================================================
>> --- metadata/appdomain.c        (revision 142262)
>> +++ metadata/appdomain.c        (working copy)
>> @@ -1431,8 +1431,10 @@
>>                 mono_raise_exception (exc);
>>         }
>>
>> -       if (!private_file_needs_copying (filename, &src_sbuf, shadow))
>> +       if (!private_file_needs_copying (filename, &src_sbuf, shadow)) {
>> +               mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_ASSEMBLY,
>> "Shadow copy %s of %s is up-to-date.\n", shadow, filename);
>>                 return (char*) shadow;
>> +       }
>>
>>         orig = g_utf8_to_utf16 (filename, strlen (filename), NULL,
>> NULL, NULL);
>>         dest = g_utf8_to_utf16 (shadow, strlen (shadow), NULL, NULL,
>> NULL);
>>
>> _______________________________________________
>> Mono-aspnet-list mailing list
>> Mono-aspnet-list@...
>> http://lists.ximian.com/mailman/listinfo/mono-aspnet-list
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Mono-aspnet-list mailing list
> Mono-aspnet-list@...
> http://lists.ximian.com/mailman/listinfo/mono-aspnet-list

_______________________________________________
Mono-aspnet-list mailing list
Mono-aspnet-list@...
http://lists.ximian.com/mailman/listinfo/mono-aspnet-list

Re: Very slow website compilation

by aps-3 :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

I reported a bug https://bugzilla.novell.com/show_bug.cgi?id=545276
Hope this helps, it can be closed if you think it's junk.

At 20.05 05/10/2009, Robert Jordan wrote:

>Marek,
>
>do you remember why private_file_needs_copying () is checking st_mode?
>
>Robert
>
>APS wrote:
> > Hi,
> >
> > I tried your patch adding some other message and I found that the
> > problem is inside private_file_needs_copying where there's a check on
> > field st_mode of stat structure.
> > The problem is that in my installation the source file have not the same
> > access rights of the shadow copy so mono copies the files everytime.
> > I can change access rights to source files but I think it's wrong to
> > check the access mode because it's not a value that helps to understand
> > if a file is up-to-date, size and mtime should be enough. Do you agree?
> > Another thing. I saw on the same function that at the first run after
> > apache restart mono doesn't find the assembly in cache directoryƬ and it
> > makes a copy.
> > This is because every time the service is stopped the user-temp-aspnet
> > directory is cleaned. But in this way everytime we restart apache we
> > need to wait the same loading time of the first time after site
> > installation. Temporary files could be kept in cache directory in order
> > to avoid reloading, this should dramatically increase mono asp.net
> > loading time.
> > I think MS.NET act like this cause the second run after site
> > installation is quicker than the first, in mono is everytime equal.
> >
> > As for private_file_needs_copying I think it could be modified like
> > this, hope this helps:
> >
> > static gboolean
> > private_file_needs_copying (const char *src, struct stat *sbuf_src, char
> > *dest)
> > {
> >         struct stat sbuf_dest;
> >
> >         if (stat (src, sbuf_src) == -1 || stat (dest, &sbuf_dest) == -1)
> >                 return TRUE;
> >         if (sbuf_src->st_size == sbuf_dest.st_size &&
> >             sbuf_src->st_mtime == sbuf_dest.st_mtime)
> >                 return FALSE;
> >         return TRUE;
> > }
> >
> >
> > At 13.30 02/10/2009, Robert Jordan wrote:
> >> Hi,
> >>
> >> APS wrote:
> >>> and so on, for the thousands of files placed inside the bin directory.
> >>> It seems to me that there's some problem cause all the files seems
> >>> missing even if they are there and it always redo the copying.
> >>> Most of the loading time is spent in this multiple shadow copying, as
> >>> I have many assemblies inside bin directory this cause an heavy disk
> >>> usage and many minutes of wait.
> >>
> >> The log message might be misleading: it is even emitted when
> >> the assembly was not actually shadow-copied due to mtime
> >> equality.
> >>
> >> Try the attached patch to see if the copy operations are
> >> actually skipped (grep for "up-to-date" in your logs).
> >>
> >> Robert
> >>
> >> --
> >> Il messaggio e' stato analizzato alla ricerca di virus o
> >> contenuti pericolosi da MailScanner, ed e'
> >> risultato non infetto.
> >>
> >>
> >>
> >> Index: metadata/appdomain.c
> >> ===================================================================
> >> --- metadata/appdomain.c        (revision 142262)
> >> +++ metadata/appdomain.c        (working copy)
> >> @@ -1431,8 +1431,10 @@
> >>                 mono_raise_exception (exc);
> >>         }
> >>
> >> -       if (!private_file_needs_copying (filename, &src_sbuf, shadow))
> >> +       if (!private_file_needs_copying (filename, &src_sbuf, shadow)) {
> >> +               mono_trace (G_LOG_LEVEL_INFO, MONO_TRACE_ASSEMBLY,
> >> "Shadow copy %s of %s is up-to-date.\n", shadow, filename);
> >>                 return (char*) shadow;
> >> +       }
> >>
> >>         orig = g_utf8_to_utf16 (filename, strlen (filename), NULL,
> >> NULL, NULL);
> >>         dest = g_utf8_to_utf16 (shadow, strlen (shadow), NULL, NULL,
> >> NULL);
> >>
> >> _______________________________________________
> >> Mono-aspnet-list mailing list
> >> Mono-aspnet-list@...
> >> http://lists.ximian.com/mailman/listinfo/mono-aspnet-list
> >
> >
> > ------------------------------------------------------------------------
> >
> > _______________________________________________
> > Mono-aspnet-list mailing list
> > Mono-aspnet-list@...
> > http://lists.ximian.com/mailman/listinfo/mono-aspnet-list
>
>_______________________________________________
>Mono-aspnet-list mailing list
>Mono-aspnet-list@...
>http://lists.ximian.com/mailman/listinfo/mono-aspnet-list
>
>--
>Il messaggio e' stato analizzato alla ricerca di virus o
>contenuti pericolosi da MailScanner, ed e'
>risultato non infetto.


_______________________________________________
Mono-aspnet-list mailing list
Mono-aspnet-list@...
http://lists.ximian.com/mailman/listinfo/mono-aspnet-list