Mysterious Script Compile Failure after period of long running successful compile/execution

May 22, 2014 at 3:54 PM
Edited May 22, 2014 at 4:25 PM
Environment:
  • Windows Server 2008 R2 SP1 x64, patched up.
  • .NET 4.0, patched up.
  • Long-Running ASP.NET Web App "Daemons" in IIS 7.5
  • * Basically, long-running apps without the suck of Windows Service applications
  • Javascript.net 0.7 x64 Release
  • v8 3.14.3.0 x64 Release
We've been using Javascript.NET for more than 2 years very successfully. We use server-side configuration scripts that change rarely and that are executed several million times a day over a farm of more than 20 servers. Script execution is highly-concurrent across CLR Thread Pool threads, but of course of JavascriptContexts are not shared across threads.

I have one particular script that runs very, very frequently on a portion of the server farm, and it works flawlessly in multiple applications. These processes are restarted only once every 2 weeks when we deploy.

This same script runs on another "newer" portion of the server farm and in another "newer" application. This newer application runs the same identical script, but it is running much less frequently than the other applications elsewhere in the server farm. After roughly about 11 hours or so, we start to get compile errors from this script (the script code is not changing anywhere) only on the "newer" application on the "newer" portion of the server farm.

Once these compiler errors begin, they continue until the process is restarted.

Process memory on the "newer" application is stable throughout, and the application otherwise continues to function absolutely normally.

Unfortunately, we've never been able to re-create this problem in non-production environments, even with similar servers and under load tests.

The exception we get is:
Noesis.Javascript.JavascriptException
   at Noesis.Javascript.CompileScript(Local<v8::Script>* , Char* source_code, Char* resource_name) in c:\src\thirdpartyroot\src\javascript.net\branches\0.7\source\noesis.javascript\javascriptcontext.cpp:line 304
   at Noesis.Javascript.JavascriptContext.Run(String iSourceCode) in c:\src\thirdpartyroot\src\javascript.net\branches\0.7\source\noesis.javascript\javascriptcontext.cpp:line 145
The code we're using is quite simple:
    MyResponse response = new MyResponse();

    using (JavascriptContext javascriptContext = new JavascriptContext())
    {
        javascriptContext.SetParameter("output", response);

        if (null != objectInput)
        {
            javascriptContext.SetParameter("input", objectInput);
        }

        try
        {
            javascriptContext.Run(script);

            return response;
        }
        catch (JavascriptException jx)
        {
            // Log and handle the error
        }
    }
We have ensured that the app servers are identical. We have added logging to emit the script when this occurs, and the script is always intact (unchanged). Interestingly (confusingly?), if we run the "newer" application on the "older" portion of the server farm, alongside other applications, this script compile error never occurs (even over weeks).

We are currently auto-recycling our "newer" application every 11-ish hours to work-around this problem.

Has anyone run into anything similar?

Is there something that we're doing wrong that we're just missing?

Does anyone know of any v8 or Javascript.NET issues that might be related here?

Is there anyway to re-initialize Javascript.NET without an application or AppDomain restart?

Things we're investigating:
  • Running an additional canary script to see if the failure is script-specific
  • * Since the problematic servers are only using this one script
  • Upgrading to latest GitHub code, latest stable v8
  • Adding alternative support for ClearScript
  • * But the performance is not nearly as good there for our use cases
  • Compiling/running scripts in an isolated app domain, so we can destroy/re-create when this problem appears
Developer
May 23, 2014 at 12:27 AM
Your code looks OK to me. I have not seen anything like this, and I must admit I have run into problems using the latest v8, but only when running the same source code multiple times without recompiling (not possible using Javascript.Net normally, but I have a hacked version), and only in rare cases. What is the compile error you are seeing?
May 23, 2014 at 5:09 AM
I guess our error logging must not be handling the error gracefully enough, because all I'm seeing is the above exception.

I see now that JavascriptException can contain source/line/column information. We definitely need to add that info to our logging (ToString doesn't seem to be including it automatically, unfortunately).

Is there something else we can do to get more details on the script compilation error?

If my canary script test doesn't reveal anything new, then I'm going to try deploying the GitHub version of Javascript.NET with v8 3.25.28 from 2014-03-27 on a few target servers to see if that changes our result.
Developer
May 23, 2014 at 7:33 AM
It should also include the Message property, describing a Syntax error, or whatever.
Jun 4, 2014 at 2:35 PM
Unfortunately, even after adding all of the information exposed by JavascriptException to our logs, we get no information (all properties are null/empty).

We finally had this error show up on one of our "older" application servers, in one of our "older" apps that had never experienced this problem before.

I'm still trying to figure out what exactly was changed, but I do know for sure that one of the significant changes was enablement of IIS Advanced Logging on that server. IIS Advanced Logging has always been enabled on the "newer" app servers that have always had this problem.

I think we may have our root cause here, but we're still working on digging into what this might be the case.
Jun 5, 2014 at 2:52 PM
I can randomly reproduce this problem with this code:
    static void Main(string[] args)
    {
      string script = "function test(a,b){return a+b;} test('abc','def');";

      try { 
        using (JavascriptContext context = new JavascriptContext()) {
          string result = (string)context.Run(script, "test");
          Console.WriteLine(result);
        }
      } catch (Exception ex) {
        Console.WriteLine(ex.Message);
        Console.WriteLine(ex.StackTrace);
      }
    }
If I run this code 10 times I can see that sometimes it works (result == "abcdef") but most of the time I get an exception with empty message.
Developer
Jun 6, 2014 at 1:11 AM
Are you saying that if you run the same .exe from the command line then mostly it runs correctly and sometimes it doesn't? This is very odd because there ought to be no difference between executions of the same binary other than external factors like clock times and the file system. I don't know about this, but I would imagine that even memory layout ought to be identical between runs, so far as user-space pointers are concerned.

I compiled your code and have run it 100+ times without problems. Therefore assuming there isn't something broken about your machine, then the differences ought to come down to environment: Javascript.Net source code, .Net framework version, v8 source code. I am using VS 2012 target .Net 4 x64. My v8 and Javascript.Net source code comes from https://github.com/oliverbock/Javascript.Net, which has the Javascript.Net fixes I have made in the last month, but excludes the upgraded v8 version and associated changes because I am having a separate problem with it (see http://code.google.com/p/v8/issues/detail?id=3332).

Have you tried configuring your debugger to stop when the exception is thrown? Where is that?
Jun 6, 2014 at 7:23 AM
Edited Jun 6, 2014 at 7:46 AM
Yes: running the same exe sometimes work, sometimes not:
c:\Users\paolo.TERADP\Documents\Visual Studio 2013\Projects\ConsoleApplication
6\ConsoleApplication6\bin\x64\Debug>ConsoleApplication6.exe
abcdef

c:\Users\paolo.TERADP\Documents\Visual Studio 2013\Projects\ConsoleApplication
6\ConsoleApplication6\bin\x64\Debug>ConsoleApplication6.exe

   at Noesis.Javascript.CompileScript(Local<v8::Script>* , Char* source_code, Ch
ar* resource_name)
   at Noesis.Javascript.JavascriptContext.Run(String iScript, String iScriptReso
urceName)
   at ConsoleApplication6.Program.Main(String[] args) in c:\Users\paolo.TERADP\D
ocuments\Visual Studio 2013\Projects\ConsoleApplication6\ConsoleApplication6\Pro
gram.cs:line 18

c:\Users\paolo.TERADP\Documents\Visual Studio 2013\Projects\ConsoleApplication
6\ConsoleApplication6\bin\x64\Debug>ConsoleApplication6.exe
abcdef

c:\Users\paolo.TERADP\Documents\Visual Studio 2013\Projects\ConsoleApplication
6\ConsoleApplication6\bin\x64\Debug>ConsoleApplication6.exe

   at Noesis.Javascript.CompileScript(Local<v8::Script>* , Char* source_code, Ch
ar* resource_name)
   at Noesis.Javascript.JavascriptContext.Run(String iScript, String iScriptReso
urceName)
   at ConsoleApplication6.Program.Main(String[] args) in c:\Users\paolo.TERADP\D
ocuments\Visual Studio 2013\Projects\ConsoleApplication6\ConsoleApplication6\Pro
gram.cs:line 18
The same happens if I run the code directly from VS in debug mode.
I didn't use the Javascript.Net source code, I just linked the latest version downloaded from here.
I'm using VS 2013 Premium (v. 12.0.30501.00 Update 2) on a Windows 8.1 Enterprise x64.

This week end I'll try to use the newest source code.
Jun 6, 2014 at 12:17 PM
I built the source code from git (I had to change the vs version in the bat file to use the VS20013 compiler for v8) and now the application does not crash).
Thanks for your help! ;)
Jun 6, 2014 at 6:45 PM
@sakya, I think you were experiencing something completely different than us.

Updating on my problem, I think now that I've found the culprit. Things are looking good, but I'm not at 100% confidence yet until we get more production runtime.

Basically, it looks like our V8 Script Compile failures may actually be out-of-memory failures, triggered by a memory leak bug in the IIS Advanced Logging module. This is a known bug and Microsoft has released a Hot Fix: http://support.microsoft.com/kb/2925138/EN-US

We've experimented with both the work-around and the installed Hot Fix, and with those applied we've not seen the error since.

It looks as if this memory leak bug impacts the native heap, but not the managed heap, which may be why we've not experienced any other problems within our applications.
Jun 7, 2014 at 6:16 AM
Yes, my problem was definetely different (but with the same symptom and very strange). ;)
Feb 25, 2016 at 2:30 PM
@jeremyremington I know I'm probably way too late, but do you remember which workaround you're talking about?

I experience the same issue in a IIS application, no informations in the exception, and sometimes it works, sometimes not (since mirgating to a new server).
Feb 25, 2016 at 2:42 PM
@guillaume86 Our issue was the result of a memory leak in the IIS Advanced Logging that was installed on the servers that exhibited the problem. Patching the known Microsoft bug in the IIS Advanced Logging module completely eliminated these errors for us. So there wasn't really a work-around, we patched the bug in IIS Advanced Logging and that fixed the memory leak that it caused in our app pool/application.