ScriptMaster Plug-In Failing

[daehl]

I am using 360Works' ScriptMaster Plug-In (1.66) on a Mac running FileMaker Pro Server Advanced 9.0.3.325.

It is installed for use with IWP in the folder:

FileMaker Server/Web Publishing/publishing-engine/wpc/Plugin

Twice now in the last ten days, the plug-in has stopped working in IWP. In each case, simply stopping web publishing in the FMP Admin Console and immediately restarting it made the plug-in start working again. Of course, clients running FMP (with ScriptMaster installed locally) were unaffected and continued to work properly.

So I'm trying to figure out whether the problem is with FMP's web publishing engine or with ScriptMaster. I'm not sure how to determine this, but I found the following entry in FileMaker's stderr Log file

May 8, 2008 8:26:18 AM com.prosc.fmkit.PluginBridge fmxInit

INFO: Creating shared PluginBridge instance with plugin bridge version 1.5

bundlePath: /Library/FileMaker Server/Web Publishing/publishing-engine/wpc/Plugins/360Works_ScriptMaster.fmplugin/Contents/Resources

jvm version: 1.5.0_13-121 from /System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home

Operating system info: Mac OS X 10.4.11 running on ppc architecture

I don't really see an error listed in that message, and I don't know exactly when ScriptMaster stopped working, but I believe it was around 11am (after this message was logged), so I'm not sure if that note is directly related to the problem. But I don't see any other errors logged and am at a loss as to how to deal with this.

I'm hoping that ScriptMaster will continue to operate, and not stop working every few days. Any tips or advice on how to proceed?

Edited May 8, 2008 by Guest

[shmert]

Those log messages are normal, they appear during startup. Do you think it's a certain script you're running that's causing it to become unresponsive?

What version of ScriptMaster are you using?

[daehl]

I'm using ScriptMaster version 1.66.

Presently, I'm only using a single ScriptMaster command in my database:

new URL(url).getText();

Which is being used it to import data by parsing the results from a web service URL.

I'd say that this command has been used approximately 50 times a day in the last week. But usage will be increasing drastically soon.

It's a major part of my solution, so I really need it to work dependably. And if ScriptMaster just stops working every few days it probably won't be viable.

Maybe need to look for another plug-in to do similar functionality...

[Jesse Barnum]

After the plugin stops working, could you post your 360Plugin server log file? it's here:

/Library/FileMaker Server/Library/Logs/360Works FM Server/360Plugin.log

That folder is owned by FM Server, so you might need to change the permissions to allow yourself read access to get the log file.

[daehl]

Thanks! I found that log, but noticed there's also another one in a folder named .../Logs/360Works FM WPE/360Plugin.log

My guess if the first one (360Works FM Server/360Plugin.log) is for databases being shared to FileMaker clients, while the second is for Web Publishing. Apparently the log zeros out after every restart, because when I opened it I only see info from the point after which I restarted the web server portion of FMPAS9.

May 8, 2008 11:24:31 AM com.prosc.fmkit.PluginBridge initLogging

CONFIG: Created normal log file at /Library/FileMaker Server/Library/Logs/360Works FM WPE/360Plugin.log

May 8, 2008 11:24:31 AM com.prosc.fmkit.PluginBridge fmxInit

INFO: Creating shared PluginBridge instance with plugin bridge version 1.5

bundlePath: /Library/FileMaker Server/Web Publishing/publishing-engine/wpc/Plugins/360Works_ScriptMaster.fmplugin/Contents/Resources

jvm version: 1.5.0_13-121 from /System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home

Operating system info: Mac OS X 10.4.11 running on ppc architecture

May 8, 2008 11:24:31 AM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Initialize 360Works ScriptMaster

May 8, 2008 11:24:31 AM com.prosc.beanshell.BeanShellPlugin customizeFunction

INFO: Function PluginFunction{name='EvaluateGroovy', functionID=28121} runs in swing

May 8, 2008 11:24:31 AM com.prosc.fmkit.Plugin init

CONFIG: Created new plugin instance: com.prosc.beanshell.BeanShellPlugin named 360Works ScriptMaster; version: 1.66

May 8, 2008 11:24:31 AM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Return VERSION_CURRENT: 51

I also noticed a java.crash.log nearby. It didn't have anything from yesterday, but it did have an entry from 4/30 (which might correspond to the first time ScriptMaster stopped working--just guessing though).

I'll be sure to check these log files immediately if ScriptMaster stops working again.

[Jesse Barnum]

OK, sounds good. Please post all log information after the next time it stops working, and we can hopefully troubleshoot from there.

[daehl]

Just an FYI, my FMP Server has been running for almost a month now without any further problems with the ScriptMaster plug-in, and the user-load has continued to increase during that same time period. So -- without meaning to jinx my server -- it's looking like the problems I encountered were out of the ordinary.

[Jesse Barnum]

Great! Thanks for the update.

[daehl]

Well, looks like my ScriptMaster plug-in stopped working again this morning. (it had been continuously running since June 8th). I immediately stopped & restarted IWP on my FMPAS9 server and all ScriptMaster functionality immediately resumed.

Of course, this could be a problem with FMP and not ScriptMaster. But ScriptMaster is the only plug-in I'm using, and no other functionality stopped working on my IWP-hosted database.

I checked the 360Plugin logs, but apparently too late, because it looks like the log is automatically cleared on IWP restart. I don't see any entries prior to restarting this morning:

/Library/FileMaker Server/Library/Logs/360Works FM Server/360Plugin.log

Jun 8, 2008 7:44:36 PM com.prosc.fmkit.PluginBridge initLogging

CONFIG: Created normal log file at /Library/FileMaker Server/Library/Logs/360Works FM Server/360Plugin.log

Jun 8, 2008 7:44:36 PM com.prosc.fmkit.PluginBridge fmxInit

INFO: Creating shared PluginBridge instance with plugin bridge version 1.5

bundlePath: /Library/FileMaker Server/Database Server/Extensions/360Works_ScriptMaster.fmplugin/Contents/Resources

jvm version: 1.5.0_13-121 from /System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home

Operating system info: Mac OS X 10.4.11 running on ppc architecture

Jun 8, 2008 7:44:36 PM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Initialize 360Works ScriptMaster

Jun 8, 2008 7:44:37 PM com.prosc.beanshell.BeanShellPlugin customizeFunction

INFO: Function PluginFunction{name='EvaluateGroovy', functionID=28121} runs in swing

Jun 8, 2008 7:44:37 PM com.prosc.fmkit.Plugin init

CONFIG: Created new plugin instance: com.prosc.beanshell.BeanShellPlugin named 360Works ScriptMaster; version: 1.66

Jun 8, 2008 7:44:37 PM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Return VERSION_CURRENT: 51

 

/Library/FileMaker Server/Library/Logs/360Works FM WPE/360Plugin.log 

Jul 22, 2008 9:01:21 AM com.prosc.fmkit.PluginBridge initLogging

CONFIG: Created normal log file at /Library/FileMaker Server/Library/Logs/360Works FM WPE/360Plugin.log

Jul 22, 2008 9:01:21 AM com.prosc.fmkit.PluginBridge fmxInit

INFO: Creating shared PluginBridge instance with plugin bridge version 1.5

bundlePath: /Library/FileMaker Server/Web Publishing/publishing-engine/wpc/Plugins/360Works_ScriptMaster.fmplugin/Contents/Resources

jvm version: 1.5.0_13-121 from /System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home

Operating system info: Mac OS X 10.4.11 running on ppc architecture

Jul 22, 2008 9:01:21 AM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Initialize 360Works ScriptMaster

Jul 22, 2008 9:01:21 AM com.prosc.beanshell.BeanShellPlugin customizeFunction

INFO: Function PluginFunction{name='EvaluateGroovy', functionID=28121} runs in swing

Jul 22, 2008 9:01:21 AM com.prosc.fmkit.Plugin init

CONFIG: Created new plugin instance: com.prosc.beanshell.BeanShellPlugin named 360Works ScriptMaster; version: 1.66

Jul 22, 2008 9:01:21 AM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Return VERSION_CURRENT: 51

Jul 22, 2008 9:04:22 AM com.prosc.fmkit.Plugin pushContext

WARNING: pushContext called when stack size is 1; this either means it was called re-entrantly, an idle handler was called without waiting for a return from a previous call, or pop was not called from last invocation.

java.lang.RuntimeException: This is not an error, it's just a stack trace

	at com.prosc.fmkit.Plugin.pushContext(Plugin.java:149)

	at com.prosc.fmkit.PluginBridge.pushContext(PluginBridge.java:869)

	at com.prosc.fmkit.PluginBridge.doFunction(PluginBridge.java:803)

Jul 22, 2008 9:04:22 AM com.prosc.fmkit.Plugin pushContext

WARNING: pushContext called when stack size is 1; this either means it was called re-entrantly, an idle handler was called without waiting for a return from a previous call, or pop was not called from last invocation.

java.lang.RuntimeException: This is not an error, it's just a stack trace

	at com.prosc.fmkit.Plugin.pushContext(Plugin.java:149)

	at com.prosc.fmkit.PluginBridge.pushContext(PluginBridge.java:869)

	at com.prosc.fmkit.PluginBridge.doFunction(PluginBridge.java:803)

However, I did see something relevant in FMPAS9's stderr log. A similar error text block appeared numerous times this morning. Here's the first two instances



/Library/FileMaker Server/Logs/stderr

Jun 8, 2008 7:44:53 PM com.prosc.beanshell.BeanShellPlugin customizeFunction

INFO: Function PluginFunction{name='EvaluateGroovy', functionID=28121} runs in swing

Jul 22, 2008 8:51:00 AM com.prosc.fmkit.Plugin setLastError

SEVERE: PluginFunction PluginFunction{name='EvaluateGroovy', functionID=28121} got an error with converted args [new URL(url).getText();]

java.net.SocketException: Connection reset

	at java.net.SocketInputStream.read(SocketInputStream.java:168)

	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)

	at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)

	at java.io.BufferedInputStream.read(BufferedInputStream.java:313)

	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:680)

	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:625)

	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:645)

	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:957)

	at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7246)

	at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7232)

	at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)

	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

	at java.lang.reflect.Method.invoke(Method.java:585)

	at org.codehaus.groovy.runtime.metaclass.ReflectionMetaMethod.invoke(ReflectionMetaMethod.java:51)

	at org.codehaus.groovy.runtime.metaclass.NewInstanceMetaMethod.invoke(NewInstanceMetaMethod.java:54)

	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:226)

	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:899)

	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:740)

	at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:765)

	at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:753)

	at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:167)

	at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethod0(ScriptBytecodeAdapter.java:195)

	at Script1.run(Script1.groovy:1)

	at groovy.lang.GroovyShell.evaluate(GroovyShell.java:543)

	at groovy.lang.GroovyShell.evaluate(GroovyShell.java:518)

	at com.prosc.beanshell.BeanShellModel.evaluateGroovy(BeanShellModel.java:158)

	at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovyNoUI(BeanShellPlugin.java:175)

	at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovy(BeanShellPlugin.java:156)

	at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)

	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

	at java.lang.reflect.Method.invoke(Method.java:585)

	at com.prosc.fmkit.PluginFunction.invoke(PluginFunction.java:276)

	at com.prosc.fmkit.Plugin.invokeFunction(Plugin.java:234)

	at com.prosc.fmkit.Plugin.invokeFunctionNoErrors(Plugin.java:220)

	at com.prosc.fmkit.PluginBridge$2.run(PluginBridge.java:789)

	at com.prosc.fmkit.PluginBridge.runTask(PluginBridge.java:844)

	at com.prosc.fmkit.PluginBridge.doFunction(PluginBridge.java:806)

Jul 22, 2008 8:51:15 AM com.prosc.fmkit.Plugin setLastError

SEVERE: PluginFunction PluginFunction{name='EvaluateGroovy', functionID=28121} got an error with converted args [new URL(url).getText();]

java.net.SocketException: Connection reset

	at java.net.SocketInputStream.read(SocketInputStream.java:168)

	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)

	at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)

	at java.io.BufferedInputStream.read(BufferedInputStream.java:313)

	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:680)

	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:625)

	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:645)

	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:957)

	at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7246)

	at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7232)

	at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)

	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

	at java.lang.reflect.Method.invoke(Method.java:585)

	at org.codehaus.groovy.runtime.metaclass.ReflectionMetaMethod.invoke(ReflectionMetaMethod.java:51)

	at org.codehaus.groovy.runtime.metaclass.NewInstanceMetaMethod.invoke(NewInstanceMetaMethod.java:54)

	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:226)

	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:899)

	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:740)

	at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:765)

	at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:753)

	at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:167)

	at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethod0(ScriptBytecodeAdapter.java:195)

	at Script1.run(Script1.groovy:1)

	at groovy.lang.GroovyShell.evaluate(GroovyShell.java:543)

	at groovy.lang.GroovyShell.evaluate(GroovyShell.java:518)

	at com.prosc.beanshell.BeanShellModel.evaluateGroovy(BeanShellModel.java:158)

	at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovyNoUI(BeanShellPlugin.java:175)

	at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovy(BeanShellPlugin.java:156)

	at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)

	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

	at java.lang.reflect.Method.invoke(Method.java:585)

	at com.prosc.fmkit.PluginFunction.invoke(PluginFunction.java:276)

	at com.prosc.fmkit.Plugin.invokeFunction(Plugin.java:234)

	at com.prosc.fmkit.Plugin.invokeFunctionNoErrors(Plugin.java:220)

	at com.prosc.fmkit.PluginBridge$2.run(PluginBridge.java:789)

	at com.prosc.fmkit.PluginBridge.runTask(PluginBridge.java:844)

	at com.prosc.fmkit.PluginBridge.doFunction(PluginBridge.java:806)

There's a lot of java-related errors here. But java is otherwise working fine on this server (as far as I can tell).

Hopefully these logs are of some help. Next time, I'll remember to save the logs prior to restarting IWP.

[shmert]

Hi Daehl,

The relevant parts of the errors appear to be:

WARNING: pushContext called when stack size is 1; this either means it was called re-entrantly, an idle handler was called without waiting for a return from a previous call, or pop was not called from last invocation.

And there's a connection reset error in the URL. Can you paste the script you're evaluating in here? Are you using timers or script scheduling?

[daehl]

Thanks, shmert.

I am using ScriptMaster to allow IWP users to import data via a web service.

Basically, there's a button on the main layout that calls a FMP script. The script forms a URL (stored in $url) that addresses a private corporate web service using the following calculation:

Let (

  [

    $x = SMSetVariable ( "url" ; $url ) & EvaluateGroovy ( "new URL(url).getText();" ) ; // Groovy method for obtaining http result.

    $x = xmlCleanup ( $x ) // Convert XML entities to ASCII (ampersand, apostrophe, quote, etc.)

  ] ;

  $x

)

That's it. That's the only Groovy code I'm using.

It stores the result (a large block of text containing XML records) in a variable, and the rest of the script parses that result and stores the info it gathers in a variety of fields.

The button is set to EXIT any current script.

So maybe, the problem is being triggered by someone activating the script again while that calculation (above) was in process?

Could it also happen if two separate users simultaneously activated the script and made the same call at the same time?

If either are the case, I'm not sure how to best avoid this problem. If ScriptMaster can lock-up by repeated (or simultaneous) use, I would think that would be something that needs to be trapped within ScriptMaster itself. But I am open to suggestions for workarounds of course.

[shmert]

It won't matter if another user calls the same script, it's running in a totally different process. I think the problem is just that the URL you're trying to reach wasn't available for some reason, either load on the server or a network outage.

The message about the idle handler is just an informational message, it shouldn't cause your script to fail.

When the script doesn't work, what gets returned in $x? Or does FileMaker completely quit?

Are you using scheduling anywhere in ScriptMaster?

[daehl]

Ugh! ScriptMaster stopped working again this morning. That's twice in two days. This could be a more severe problem than originally expected. When the problem occurs, no data is returned. Nothing crashes, but the database fails to be fully useful because it cannot gather new data.

But I found something interesting this morning... while the ScriptMaster has stopped working in IWP (for all clients), it continues to work fine via FMP client.

So this problem seems to be associated with both IWP and ScriptMaster. Because, as I just mentioned, when the problem arose again this morning (within the IWP interface), for comparison's sake, I also opened up the same database in a FMP client, and activated the same script on the same layout and it functioned correctly (multiple times) at the exact same time that it continued to not function at all when activated within the IWP interface.

And as before, only when I stopped & restarted IWP on my FMP server did the Groovy code work again within IWP.

Since I made quite a few attempts (virtually simultaneously) from both FMP & IWP and got consistant results. I believe that definitively demonstrates that the problem is not related to the web service (URL) I'm accessing or any type of network slowness or outage.

Also, there is no other ScriptMaster code in my solution, so I would expect I'm not using "scheduling" in any way. But since I'm not familiar with what ScriptMaster "scheduling" is, I suppose there's still a chance I'm mistaken.

I haven't been able to cause the problem to re-occur after I've restarted IWP. But it seems likely that it may be triggered by a single IWP user activating the script while it's still in the middle of executing (maybe they double-clicked the button at just the right time). And that presumably causes ScriptMaster to stop working properly in IWP (or possibly causes ScriptMaster to fail to receive the instructions) until IWP is restarted.

I will try to duplicate the problem myself, and see if I can avoid the problem by disabling the button while the script is in operation.

But I wonder if there is any other error log or debug information that might be useful for ScriptMaster experts to help troubleshoot? It does still seem like a ScriptMaster problem to me, but it's definitely entangled with IWP use.

[shmert]

Can you try upgrading to the latest version (ScriptMaster 2.0) and see if the problem persists?

[daehl]

Yes, I will upgrade to version 2.0

(Actually, I didn't know it was even released. I usually check Versiontracker.com for all my updates, but that still lists version 1.0 as current. So thanks for the suggestion)

But first I want to see if I can make the problem re-occur myself. Unfortunately, no luck so far. I've tried repeated clicking of my script button within a variety of Web browsers (Firefox 3 Mac, Safarti 3 Mac, IE 6 Windows) and have not been able to recreate the ScriptMaster failure. I've also tried combinations with refreshing the browser window in between and afterwards. But still no failure.

Neverthelees, it has failed twice in the last 48hours, and four times in the last three months. So I need to figure out how to avoid this (or find an alternative plug-in). Otherwise my Filemaker database may be too unreliable for use.

Edited July 24, 2008 by Guest

[daehl]

I updated to ScriptMaster 2.0.3 a couple months ago. And ScriptMaster has been working steadily since then. But now, twice in two days it stopped working. Stopping/Restarting IWP gets it working again, but maybe the error log info might be helpful in tracking down the problem. I saved the log 360Works ScriptMaster_WPE.log and I see multiple instances of this error when the problem is occurring:

Dec 9, 2008 3:10:32 PM com.prosc.fmkit.Plugin setLastError

SEVERE: PluginFunction PluginFunction{name='EvaluateGroovy', functionID=28121, minArgs=null, maxArgs=1} got an error with converted args [new URL(url).getText();]

java.net.SocketException: Connection reset

at java.net.SocketInputStream.read(SocketInputStream.java:168)

at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)

at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)

at java.io.BufferedInputStream.read(BufferedInputStream.java:313)

at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:680)

at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:625)

at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:645)

at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:957)

at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7246)

at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7232)

at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

at java.lang.reflect.Method.invoke(Method.java:585)

at org.codehaus.groovy.runtime.metaclass.ReflectionMetaMethod.invoke(ReflectionMetaMethod.java:51)

at org.codehaus.groovy.runtime.metaclass.NewInstanceMetaMethod.invoke(NewInstanceMetaMethod.java:54)

at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:226)

at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:899)

at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:740)

at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:765)

at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:753)

at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:167)

at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethod0(ScriptBytecodeAdapter.java:195)

at Script1.run(Script1.groovy:1)

at groovy.lang.GroovyShell.evaluate(GroovyShell.java:543)

at groovy.lang.GroovyShell.evaluate(GroovyShell.java:518)

at com.prosc.beanshell.BeanShellModel.evaluateGroovy(BeanShellModel.java:159)

at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovyNoUI(BeanShellPlugin.java:240)

at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovy(BeanShellPlugin.java:221)

at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

at java.lang.reflect.Method.invoke(Method.java:585)

at com.prosc.fmkit.StaticFunction.invoke(StaticFunction.java:228)

at com.prosc.fmkit.Plugin.invokeFunction(Plugin.java:237)

at com.prosc.fmkit.Plugin.invokeFunctionNoErrors(Plugin.java:221)

at com.prosc.fmkit.PluginBridge$3.run(PluginBridge.java:886)

at com.prosc.fmkit.PluginBridge.runTask(PluginBridge.java:945)

at com.prosc.fmkit.PluginBridge.doFunction(PluginBridge.java:902)

The primary function I'm using ScriptMaster for is to obtain http web service data within IWP.

So basically, the FMP script steps are as simple as:

$x = SMSetVariable ( "url" ; $url ) & EvaluateGroovy ( "new URL(url).getText();" ) ;

(where $url is the URL to the web service).

I just noticed that ScriptMaster 2.0.5a was released last month. I checked the ChangeLog, and the only fix it lists is related to passing text larger than 1M characters. But I know I'm not passing any text that large to ScriptMaster, and I doubt I would be receiving any text that large either--but it's possible. I'll give the upgrade a try as soon as I can.

Nevertheless, hopefully the error log entry (above) might be helpful in some way to pinpoint the problem? The entry:

java.net.SocketException: Connection reset

seems the most significant to me, but I don't know what it means.

[Jesse Barnum]

The 'Connection reset' message just means that the network lost the connection. I don't think that this is an indication of a problem with ScriptMaster.

[daehl]

That's why I think it's a problem with Scriptmaster, because while these errors continued to appear, the iMac had no disruption to it's network connection. FMPAS was still serving databases via both FMPnet & IWP, and I was also able to connected from another computer via FMP Admin Console.

Stopping IWP and restarting it immediately made the problem go away. and ScriptMaster is the only plug-in I have loaded on this server. I'm hoping to get a chance to upgrade to 2.0.5a today.

[daehl]

Last week I upgraded my FMP Advanced Server 9 to use ScriptMaster 2.0.8 in WPE (as well as Mac OS 10.5.6). I was hoping that upgrading might make these problems disappear, but ScriptMaster still continues to stop working occasionally. I have checked the stderr and 360Works ScriptMaster_WPE.log files and both contain the same entries when the problem occurs. Here's an example from yesterday:

Feb 25, 2009 8:44:59 AM com.prosc.fmkit.Plugin setLastError

SEVERE: PluginFunction PluginFunction{name='EvaluateGroovy', functionID=28121, minArgs=null, maxArgs=1} got an error with converted args [new URL(url).getText();]

java.net.SocketException: Connection reset

at java.net.SocketInputStream.read(SocketInputStream.java:168)

at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)

at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)

at java.io.BufferedInputStream.read(BufferedInputStream.java:313)

at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:681)

at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:626)

at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:646)

at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:957)

at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7246)

at org.codehaus.groovy.runtime.DefaultGroovyMethods.getText(DefaultGroovyMethods.java:7232)

at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

at java.lang.reflect.Method.invoke(Method.java:585)

at org.codehaus.groovy.runtime.metaclass.ReflectionMetaMethod.invoke(ReflectionMetaMethod.java:51)

at org.codehaus.groovy.runtime.metaclass.NewInstanceMetaMethod.invoke(NewInstanceMetaMethod.java:54)

at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:226)

at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:899)

at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:740)

at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:765)

at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:753)

at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:167)

at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethod0(ScriptBytecodeAdapter.java:195)

at Script1.run(Script1.groovy:1)

at groovy.lang.GroovyShell.evaluate(GroovyShell.java:543)

at groovy.lang.GroovyShell.evaluate(GroovyShell.java:518)

at com.prosc.beanshell.BeanShellModel.evaluateGroovy(BeanShellModel.java:159)

at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovyNoUI(BeanShellPlugin.java:241)

at com.prosc.beanshell.BeanShellPlugin.EvaluateGroovy(BeanShellPlugin.java:222)

at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

at java.lang.reflect.Method.invoke(Method.java:585)

at com.prosc.fmkit.StaticFunction.invoke(StaticFunction.java:229)

at com.prosc.fmkit.Plugin.invokeFunction(Plugin.java:237)

at com.prosc.fmkit.Plugin.invokeFunctionNoErrors(Plugin.java:221)

at com.prosc.fmkit.PluginBridge$3.run(PluginBridge.java:895)

at com.prosc.fmkit.PluginBridge.runTask(PluginBridge.java:954)

at com.prosc.fmkit.PluginBridge.doFunction(PluginBridge.java:911)

Feb 25, 2009 8:44:59 AM com.prosc.beanshell.BeanShellPlugin setLastError

SEVERE: ScriptMaster bound variables: Parameters:

{url=http://appwebservice.xxx.com:80/ix_web/default.aspx?db=DBXXXX&operator=XXXX&fn=job_info&job_nbr=A9086J0)}

The primary reason I'm using ScriptMaster is for obtaining http web service data within IWP.

So basically, the FMP script steps that immediately precede these errors are similar to:

$url = "http://appwebservice.xxx.com:80/ix_web/default.aspx?db=DBXXXX&operator=XXXX&fn=job_info&job_nbr=A9086J0"

$x = SMSetVariable ( "url" ; $url ) & EvaluateGroovy ( "new URL(url).getText();" ) ;

The result of which is an XML record, usually around 600 bytes but can be as large as 16K.

Please let me know if there's any other relevant information I could add. I'm not aware of any other applicable log files.

These errors have been occurring about 1-3 times per month on average. And once they start, the fastest way to get ScriptMaster to start working again is to stop and restart Web Publishing in the FMP Server Admin Console.

All other aspects of database instant web sharing (IWP) continue to work as normal when this problem exists. Only ScriptMaster is affected and that's the main reason why I think it's a ScriptMaster issue.

Any help would be appreciated in troubleshooting this problem. Thanks!

[shmert]

From the error message it sounds like the URL isn't reachable, or maybe is taking too long to respond leading to a connection reset / timout. How quickly does the script fail? I'd be curious if it worked with another URL instead?

[daehl]

From the error message it sounds like the URL isn't reachable, or maybe is taking too long to respond leading to a connection reset / timout. How quickly does the script fail? I'd be curious if it worked with another URL instead?

Thanks for responding shmert.

The URL is still reachable when the error condition occurs. I can access it directly via web browser or CURL command on other computers or from the same iMac that is my FMPAS server. It is also accessible via other FMP clients that have ScriptMaster loaded. It just stops working in the Server's WPE environment, and will not start working again (all subsequent Scriptmaster commands error out in WPE) until I stop and restart web publishing.

Not sure by what you mean by "how quickly does the script fail?"

This is not a repeatable error. It happens (seemingly randomly) about 1-3 times per month on average. I've gone as long as a couple months without it occurring, but some months it happens multiple times. I just completely reinstalled my FMPAS9 server last week (upgraded from Tiger to Leopard and Scriptmaster 2.05 to 2.08), and it's happened only once since then (and once prior to that just this month). To put this in perspective, the ScriptMaster script step I listed is probably executed at least 3-4 hundred times a day by coworkers using my main database. And identical parameters are used many times a day (so I'd estimate about 100 unique GET URLs are executed each day). I have never encountered a situation where the results of the web service query were not returned in less than a second--usually instantaneously since it's a local server.

I've also tried rapidly issuing these queries, either by repeatedly executing them manually or with repeat loops, and I have never been able to trigger the problem that way. So the speed or rapid succession of which the script is triggered does not seem to be a factor.

But lets assume that the problem is related to a delayed response or unreachable URL. I can simulate the latter by just feeding scriptmaster a bogus URL, right? I've tested that and that doesn't trigger the problem. ScriptMaster just immediately returns "ERROR" in such cases. So I would tend to rule out an delayed or unreachable URL as a candidate for this problem. At least when ScriptMaster is operating as normal.

I keep posting the error logs in hope that there's some useful information listed there. By virtue of the fact that I'm not getting any specific answers, it seems as though the error logs are not recording information useful in diagnosing this problem. I'm not sure exactly what conclusion to draw from that, but since only ScriptMaster stops working (only) in WPE, my guess is it's still a problem with ScriptMaster, and it's a problem which it doesn't know to check for or record in the logs. But I could be completely wrong. I'm hoping Jesse or someone from 360works might be able to help me pinpoint why this is happening. I really like their product, and am hoping that this feedback will make it even better.

[shmert]

The connection reset is being done by the java IO classes, not ScriptMaster. For whatever reason, while reading the header data from the HTTP response the socket connection between the server and the client (ScriptMaster) is being broken. Beyond that, it's hard to tell why.

Instead of using new URL(url).getText() you might try more standard Java IO method calls and see if that works for you. The "getText()" method is a convenience method added by Groovy, and I'm not sure what it's actually doing behind the scenes (maybe it's forgetting to close a connection somewhere?)

[daehl]

Instead of using new URL(url).getText() you might try more standard Java IO method calls and see if that works for you.

Thanks again, shmert.

I'd definitely like to try that, but unfortunately, I don't have any java experience, and I can't say that I really understand Groovy that much either.

I've dabbled in C/C++ a bit, so I'm hoping I could muddle thru this, but when I google java.io, all I can find are lists of abstract classes, and no specific methods.

So, any chance you'd be willing to help out a bit more with specifics?