Debugging Help Needed

[grantwood]

NOTE: This may not have anything to do with ScriptMaster.

Hello, I have the following setup:

• FileMaker Advanced 9.0v3
• Mac OS X 10.5.1
• ScriptMaster 1.63

When trying to run a script I sometimes get the following errors on the console:

iText library, if that helps. Here's the script I'm using:

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: *** HEY, I GOT A CALLBACK in thread -1607008416! *** 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: Got a lock, clearing keepRunLoopAlive 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: keepRunLoopAlive before stopping 0 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: keepRunLoopAlive after stopping 0 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: After run loop - keepRunLoopAlive is 0 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Finished run loop 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] ---runUiThread--- 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: The UI thread is -1607008416 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Set keepRunLoopAlive flag: 1 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Created local portRef 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Created finishedJavaSourceRef, expecting signal 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Starting UI operation run loop for thread -1607008416 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: keepRunLoopAlive is 1 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 2: Starting graphics operation 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Before run loop - keepRunLoopAlive is 1 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 2: Finished executing graphic operation 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 2: Got a valid remote message port, sending quit request 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 2: Sent request to stop 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: *** HEY, I GOT A CALLBACK in thread -1607008416! *** 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: Got a lock, clearing keepRunLoopAlive 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: keepRunLoopAlive before stopping 0 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 3: keepRunLoopAlive after stopping 0 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: After run loop - keepRunLoopAlive is 0 

2/11/08 9:49:53 PM [0x0-0x91a91a].com.filemaker.pro.advanced[18549] 1: Finished run loop 

I'm trying to populate PDF forms using the  

import com.lowagie.text.*;

import com.lowagie.text.pdf.*;



// variables set from FileMaker

// fm_formInputPath, fm_formOutputPath, fm_keyValueMap, fm_delim, fm_base64_sub



try {

    PdfReader reader;

    PdfStamper stamper;



    reader = new PdfReader(fm_formInputPath);

    stamper = new PdfStamper(reader, new FileOutputStream(fm_formOutputPath));

    AcroFields form = stamper.getAcroFields();

    keyValueMap = fm_keyValueMap.split("n", -1);

    for (keyValuePair in keyValueMap) { 

        keyValueArray = keyValuePair.split(fm_delim, -1);

        key = keyValueArray[1];

        valueTemp = keyValueArray[3].replace(fm_base64_sub, "n");

        value = new String(new sun.misc.BASE64Decoder().decodeBuffer(valueTemp));

        form.setField(key, value);

    } 



    // makes the populated PDF form read-only

    stamper.setFormFlattening(true);

    stamper.close();



} catch (Exception e) {

    e.printStackTrace();

}

Edited February 12, 2008 by Guest

[grantwood]

The console message above probably isn't helpful, so I have another one. I kept clearing the 360PluginBridge.log file until I encountered an error. Here' s the console output:

FYI, I can trigger this error on the Mac (on both Tiger and Leopard) by running the above Groovy script in succession. I haven't seen any problems on Win XP. Usually around the 7th or 8th time I'll get an error.

 Tuesday, February 12, 2008 12:45:30 AM US/Eastern 

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

2: Starting graphics operation

1: Before run loop - keepRunLoopAlive is 1

1: After run loop - keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

2: Starting graphics operation

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

2: Starting graphics operation

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

2: Starting graphics operation

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

2: Starting graphics operation

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

2: Starting graphics operation

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Starting graphics operation

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

2: Starting graphics operation

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Starting graphics operation

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

2: Starting graphics operation

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

2: Finished executing graphic operation

2: Got a valid remote message port, sending quit request

2: Sent request to stop

3: *** HEY, I GOT A CALLBACK in thread -1607008416! ***

3: Got a lock, clearing keepRunLoopAlive

3: keepRunLoopAlive before stopping 0

3: keepRunLoopAlive after stopping 0

1: After run loop - keepRunLoopAlive is 0

1: Finished run loop

---runUiThread---

1: The UI thread is -1607008416

1: Set keepRunLoopAlive flag: 1

1: Created local portRef

1: Created finishedJavaSourceRef, expecting signal

1: Starting UI operation run loop for thread -1607008416

1: keepRunLoopAlive is 1

1: Before run loop - keepRunLoopAlive is 1

 

[Jesse Barnum]

Oops, that's my fault. Those aren't error messages at all, just low-level debugging messages that I meant to get rid of after I was done. I'll fix that in the next release. There is nothing harmful about them at all; they don't indicate errors.

[grantwood]

Hi Jesse,

I'm still having a problem as noted earlier in this thread. On Tiger and Leopard, I can run my Groovy script just fine 6-7 times, then FileMaker becomes unresponsive. I don't know what info I can provide you to help troubleshoot the problem. I can make a short video of the problem if that would help.

Sean

[Jesse Barnum]

Can you paste the error message from the 360Plugin.log? This is a different log than 360PluginBridge.

The log file is here:

/Users/yourName/Library/Logs/360Works FM Pro/360Plugin.log

[grantwood]

Sure, although nothing stands out to me:

Feb 12, 2008 12:13:20 PM com.prosc.fmkit.PluginBridge initLogging

CONFIG: Created normal log file at /Users/grantwood/Library/Logs/360Works FM Pro/360Plugin.log

Feb 12, 2008 12:13:20 PM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Initialize 360Works ScriptMaster

Feb 12, 2008 12:13:20 PM com.prosc.beanshell.BeanShellPlugin customizeFunction

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

Feb 12, 2008 12:13:20 PM com.prosc.fmkit.Plugin init

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

Feb 12, 2008 12:13:20 PM com.prosc.fmkit.PluginBridge fmxInit

CONFIG: Return VERSION_CURRENT: 51

Feb 12, 2008 12:13:53 PM com.prosc.beanshell.BeanShellPlugin SMLoadJar

INFO: Loaded external lib at file:/tmp/ScriptMaster13622iText.jar

The debugging text posted earlier appears to be a series of "runUiThread" blocks, and the last block is a partial one. The next line should have been "Starting graphics operation". Not sure if that means anything.

[Jesse Barnum]

OK, what is the error that you're seeing in FileMaker?

Usually around the 7th or 8th time I'll get an error.

[grantwood]

OK, what is the error that you're seeing in FileMaker?

That's the problem: there is no error from FileMaker. FileMaker just becomes unresponsive.

FWIW, I've made a video showing what happens:

http://www.grantwoodtechnology.com/test/scriptmaster_demo_20080212.mov

Does the following log entry shed light on the problem:

"WARNING: FileReference is for non-existent file: /Volumes/Macintosh HD/Applications/FileMaker Pro 9 Advanced/Extensions/jars/iText.jar"

That was an old path that I used, but according to the latest DDR, I no longer reference that path.

[grantwood]

Some other bits of information:

1) In the video I generate the same PDF five times in succession. That probably won't happen in the real world. However, going to five different records and generating a single PDF causes the same problem (the magic number isn't always five, sometimes six, or seven in my limited testing).

2) The problem occurs even if ScriptMaster is the only third-party plugin installed.

3) I thought maybe there was a problem with generating PDFs in rapid succession (like if you were in batch mode), but I tried generating a PDF once every minute, and still the problem occurred.

[grantwood]

I also tried modifying the Java Application Runtime Settings to use J2SE 1.4.2 instead of J2SE 1.5, but no luck.

[grantwood]

Hey,

Just to try something, I re-downloaded your ScriptMaster plugin, and I noticed that the version was 1.62, which was a little weird considering I was using version 1.63, but I thought I'd give it a shot.

PROBLEM SOLVED! YAYYYY!!!

I noticed that most of the debugging output has been removed. I only see the following line: "Finished executing graphic operation".

Did you do anything else?

[Jesse Barnum]

OK, sorry for the mix-up. There was a problem that was fixed, and the build # was wrong. I've redeployed it as 1.63 - there's no change except for the version #.

There was a threading issue that was fixed that might have been causing your problem. Please let me know if it happens again.