Hi,

We are having trouble with the web publishing engine. It works fine most of the time, then for no apparent reason a request will take ten second instead of less than one - it isn't any particular page, and a page can work fine on minute and then take 10 seconds, and then be fine again.

System is a server with Xeon processor, 2Gb ram running Windows Server 2003. Its sole purpose is as a Filemaker server.

IIS logs simply show an increase in the amount of time required. A trace on the servers shows as follows. The slow requests take about 10000ms , while normal ones are so fast they show up as 0ms. The delay occurs between CALL_ISAPI_EXTENSION and ISAPI_EXTENSION_DONE - on a normal request there will be not be ten seconds between the timestamps!

-----------------------------------------------------------------------------

Request n.57: http://localhost:80/fmi/xml/fmresultset.xml?-db=News_and_Events&-lay=news_web_short_data&published_date=10%2F04%2F2006&published_date.op=lte&type=Splashback&type.op=eq&-max=10&-sortfield.1=published_date&-sortorder.1=descend&-skip=0&-find {00000000-0000-0000-b80a-0060000000fe} 2006-9-4 3:10:41



  IISGeneral: GENERAL_REQUEST_START - IIS starts processing a new request

    SiteId: 1

    AppPoolId: DefaultAppPool

    ConnId: 1073744567

    RawConnId: 0

    RequestURL: http://localhost:80/fmi/xml/fmresultset.xml?-db=News_and_Events&-lay=news_web_short_data&published_date=10%2F04%2F2006&published_date.op=lte&type=Splashback&type.op=eq&-max=10&-sortfield.1=published_date&-sortorder.1=descend&-skip=0&-find

    RequestVerb: GET

    ContextIDSeq: 57

    Timestamp: 03:10:41.509.610900



  IISGeneral: GENERAL_GET_URL_METADATA - IIS gets URL metadata

    PhysicalPath: c:inetpubwwwrootfmixmlfmresultset.xml

    AccessPerms: Read+Exec+Script

    ContextIDSeq: 57

    Timestamp: 03:10:41.509.610900



  IISGeneral: GENERAL_GET_URL_METADATA - IIS gets URL metadata

    PhysicalPath: C:Program FilesFileMakerFileMaker ServerWeb Publishingweb-configurationweb-server-moduleisapi_redirect.dll

    AccessPerms: Read+Exec+Script

    ContextIDSeq: 57

    Timestamp: 03:10:41.509.610900



  IISISAPI: ISAPI_START - IIS starts processing an ISAPI Request

    ContextIDSeq: 57

    Timestamp: 03:10:41.509.610900



  IISGeneral: GENERAL_ISAPI_HANDLER - IIS processes an in-proc ISAPI request

    ContextIDSeq: 57

    Timestamp: 03:10:41.509.610900



  W3Isapi: CALL_ISAPI_EXTENSION - Call Isapi Extension

    DllName: C:Program FilesFileMakerFileMaker ServerWeb Publishingweb-configurationweb-server-moduleisapi_redirect.dll

    ContextIDSeq: 57

    Timestamp: 03:10:41.509.610900



  W3Isapi: ISAPI_EXTENSION_DONE - Isapi Extension Done

    ContextIDSeq: 57

    Timestamp: 03:10:51.588.251900



  IISISAPI: ISAPI_END - IIS ends processing an ISAPI Request

    ContextIDSeq: 57

    Timestamp: 03:10:51.588.251900



  IISGeneral: GENERAL_REQUEST_END - IIS ends processing a request

    HttpStatus: 200

    HttpSubStatus: 0

    BytesSent: 5421

    BytesReceived: 316

    ContextIDSeq: 57

    Timestamp: 03:10:51.588.251900



 Total time: 10000 msecs

-------------------------------------

I set up logging on the isapi_redirect to see if it could shed any light on the situation.  The full log for a working request and a slow request follows, but it seems to get hung up on the following....

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (884)]: ajp_send_request 2: request body to send 0 - request body to resend 0

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #319

Does this look like a problem with Filemaker?  Any suggestions you have would be appreciated.

Many thanks,

Sean

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (696)]: HttpFilterProc started

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (759)]: In HttpFilterProc Virtual Host redirection of /localhost/fmi/xml/fmresultset.dtd

[Wed Oct 04 12:04:26 2006]  [jk_uri_worker_map.c (460)]: Into jk_uri_worker_map_t::map_uri_to_worker

[Wed Oct 04 12:04:26 2006]  [jk_uri_worker_map.c (477)]: Attempting to map URI '/localhost/fmi/xml/fmresultset.dtd'

[Wed Oct 04 12:04:26 2006]  [jk_uri_worker_map.c (599)]: jk_uri_worker_map_t::map_uri_to_worker, done without a match

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (765)]: In HttpFilterProc test Default redirection of /fmi/xml/fmresultset.dtd

[Wed Oct 04 12:04:26 2006]  [jk_uri_worker_map.c (460)]: Into jk_uri_worker_map_t::map_uri_to_worker

[Wed Oct 04 12:04:26 2006]  [jk_uri_worker_map.c (477)]: Attempting to map URI '/fmi/xml/fmresultset.dtd'

[Wed Oct 04 12:04:26 2006]  [jk_uri_worker_map.c (502)]: jk_uri_worker_map_t::map_uri_to_worker, Found a context match wpc -> /fmi/xml/

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (775)]: HttpFilterProc [/fmi/xml/fmresultset.dtd] is a servlet url - should redirect to wpc

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (838)]: HttpFilterProc check if [/fmi/xml/fmresultset.dtd] is points to the web-inf directory

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (878)]: HttpExtensionProc started

[Wed Oct 04 12:04:26 2006]  [jk_worker.c (132)]: Into wc_get_worker_for_name wpc

[Wed Oct 04 12:04:26 2006]  [jk_worker.c (136)]: wc_get_worker_for_name, done  found a worker

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (913)]: HttpExtensionProc got a worker for name wpc

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (1404)]: Into jk_worker_t::get_endpoint

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (1448)]: In jk_endpoint_t::ajp_get_endpoint, time elapsed since last request = 4 seconds

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (1116)]: Into jk_endpoint_t::service

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (295)]: Into ajp_marshal_into_msgb

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (432)]: ajp_marshal_into_msgb - Done

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (642)]: sending to ajp13 #187

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (884)]: ajp_send_request 2: request body to send 0 - request body to resend 0

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (729)]: received from ajp13 #321

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (483)]: ajp_unmarshal_response: status = 200

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (488)]: ajp_unmarshal_response: Number of headers is = 9

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[0] [Date] = [Wed, 04 Oct 2006 04:04:26 GMT]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[1] [server] = [localhost]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[2] [MIME-Version] = [1.0]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[3] [Cache-control] = [no-cache="set-cookie"]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[4] [Cache-control] = [must-revalidate]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[5] [set-Cookie] = [fmi-cookie=fmi-cookie; Path=/; Version=1]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[6] [Connection] = [Close]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[7] [Content-Type] = [text/plain; charset=utf-8]

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[8] [Expires] = [Tue, 03 May 1988 14:40:00 GMT]

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (432)]: Into jk_ws_service_t::start_response

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (729)]: received from ajp13 #1027

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (566)]: Into jk_ws_service_t::write

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (729)]: received from ajp13 #744

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (566)]: Into jk_ws_service_t::write

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (729)]: received from ajp13 #2

[Wed Oct 04 12:04:26 2006]  [jk_isapi_plugin.c (925)]: HttpExtensionProc service() returned OK

[Wed Oct 04 12:04:26 2006]  [jk_ajp_common.c (1382)]: Into jk_endpoint_t::done, recycling connection



[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (696)]: HttpFilterProc started

[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (759)]: In HttpFilterProc Virtual Host redirection of /localhost/fmi/xml/fmresultset.xml

[Wed Oct 04 12:05:35 2006]  [jk_uri_worker_map.c (460)]: Into jk_uri_worker_map_t::map_uri_to_worker

[Wed Oct 04 12:05:35 2006]  [jk_uri_worker_map.c (477)]: Attempting to map URI '/localhost/fmi/xml/fmresultset.xml'

[Wed Oct 04 12:05:35 2006]  [jk_uri_worker_map.c (599)]: jk_uri_worker_map_t::map_uri_to_worker, done without a match

[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (765)]: In HttpFilterProc test Default redirection of /fmi/xml/fmresultset.xml

[Wed Oct 04 12:05:35 2006]  [jk_uri_worker_map.c (460)]: Into jk_uri_worker_map_t::map_uri_to_worker

[Wed Oct 04 12:05:35 2006]  [jk_uri_worker_map.c (477)]: Attempting to map URI '/fmi/xml/fmresultset.xml'

[Wed Oct 04 12:05:35 2006]  [jk_uri_worker_map.c (502)]: jk_uri_worker_map_t::map_uri_to_worker, Found a context match wpc -> /fmi/xml/

[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (775)]: HttpFilterProc [/fmi/xml/fmresultset.xml] is a servlet url - should redirect to wpc

[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (838)]: HttpFilterProc check if [/fmi/xml/fmresultset.xml] is points to the web-inf directory

[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (878)]: HttpExtensionProc started

[Wed Oct 04 12:05:35 2006]  [jk_worker.c (132)]: Into wc_get_worker_for_name wpc

[Wed Oct 04 12:05:35 2006]  [jk_worker.c (136)]: wc_get_worker_for_name, done  found a worker

[Wed Oct 04 12:05:35 2006]  [jk_isapi_plugin.c (913)]: HttpExtensionProc got a worker for name wpc

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (1404)]: Into jk_worker_t::get_endpoint

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (1448)]: In jk_endpoint_t::ajp_get_endpoint, time elapsed since last request = 73 seconds

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (1116)]: Into jk_endpoint_t::service

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (295)]: Into ajp_marshal_into_msgb

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (432)]: ajp_marshal_into_msgb - Done

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (642)]: sending to ajp13 #336

[Wed Oct 04 12:05:35 2006]  [jk_ajp_common.c (884)]: ajp_send_request 2: request body to send 0 - request body to resend 0

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #319

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (483)]: ajp_unmarshal_response: status = 200

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (488)]: ajp_unmarshal_response: Number of headers is = 9

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[0] [Date] = [Wed, 04 Oct 2006 04:05:35 GMT]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[1] [server] = [localhost]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[2] [MIME-Version] = [1.0]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[3] [Cache-control] = [no-cache="set-cookie"]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[4] [Cache-control] = [must-revalidate]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[5] [set-Cookie] = [fmi-cookie=fmi-cookie; Path=/; Version=1]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[6] [Connection] = [Close]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[7] [Content-Type] = [text/xml; charset=utf-8]

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (532)]: ajp_unmarshal_response: Header[8] [Expires] = [Tue, 03 May 1988 14:40:00 GMT]

[Wed Oct 04 12:05:45 2006]  [jk_isapi_plugin.c (432)]: Into jk_ws_service_t::start_response

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #1027

[Wed Oct 04 12:05:45 2006]  [jk_isapi_plugin.c (566)]: Into jk_ws_service_t::write

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #1027

[Wed Oct 04 12:05:45 2006]  [jk_isapi_plugin.c (566)]: Into jk_ws_service_t::write

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #1027

[Wed Oct 04 12:05:45 2006]  [jk_isapi_plugin.c (566)]: Into jk_ws_service_t::write

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #736

[Wed Oct 04 12:05:45 2006]  [jk_isapi_plugin.c (566)]: Into jk_ws_service_t::write

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (729)]: received from ajp13 #2

[Wed Oct 04 12:05:45 2006]  [jk_isapi_plugin.c (925)]: HttpExtensionProc service() returned OK

[Wed Oct 04 12:05:45 2006]  [jk_ajp_common.c (1382)]: Into jk_endpoint_t::done, recycling connection

Edited October 5, 200619 yr by Guest

Since you have so detailed reports, I suggest that you send them to http://www.filemaker.com/company/problems.html

Another comment: I would never ever enable the fmxml privilege with guest access, but assign an account and password to it. With a little knowledge of how to write XML queries, I and others are able to read out the complete database structure and all the data of your databases that are CWP enabled.

Hi Martin, thanks for your help, I have submitted a problem report with FileMaker and will post any updates here .

As for security...thanks for the tip. (We do already have it set up to not allow anonymous access, it just doesn't show in the trace logs!)

I was considering restricting access to IIS on the Filemaker server to the webserver that serves the site - would this prevent unauthorised access from FileMaker experts, or is there another backdoor to the Filemaker fmxml data that we need to close?

Cheers,

Sean

I am experiencing this exact problem. We found that as soon as the load increases on the FMSA server, the response times to queries go up MASSIVELY. ie: a 10% increase in load causes a ~580% drop in performance.

We have extensive logging and graphing of CPU utilization/load/etc vs query times, and the end result is that if ANYTHING significant is happening on the FM server, the WPE basically hangs.

This has been replicated and reported to FileMaker (Australia in my case) and has been escalated to engineering in the US.

No response as yet....

What amount of RAM do you fellows who are having this problem have installed on your Servers?

Steven

Steven,

I don't think this is a problem of RAM. The WPE has huge problems if several queries which result in large answer sets come in at a time, although it should not and according to the specifications should be able to serve 100 concurrent connections. We are now able to reproduce this behavior, and will send in a problem report soon.

Not making excuses for FMI here because I do believe we need to press FMI for better performance.

But keep in mind that the WPE really behaves like a copy of FMP. So to maximize performance we really should look hard at the specs on the machine that runs WPE and on the connections (bandwidth) between the machine running WPE and the machines running the Web server and FMS.

Having said that, only by collecting good monitoring data and sending that to FMI will we be able to convince them to go where we want to go.

Just an update...no response from FileMaker so far.

We have 2 gigabytes of ram on our server, 3.2Ghz Xeon processor, and it is dedicated to being a FileMaker server. IIS is installed with the tomcat installation that FileMaker WPE creates, but it doesn't do anything else...all requests come from a different webserver on our network which passes the FileMaker query in an HTTP request to IIS and expects an XML document back as a result.

I still haven't been able to diagnose the problem, but there is no doubt in my mind that this is not about the specs of the machine that it is installed on, unless FileMaker has unpublished or unidentified compatibility issues.

The trace logs on the FileMaker machine show a ten second wait at ISAPI level, and the Tomcat logs show a ten second delay at the AJP request level. At this level the only communication that is going on is tomcat<->filemaker, both of which are FileMaker installations. Whether the problem is with the IWP Tomcat setup or FileMaker itself I don't know, but the problem is definitely in communications between sofware that is installed as part of FileMaker and FileMaker IWP.

One thing that I have considered is to install Apache on the server with a tomcat connector and use that to connect to FileMaker. FileMaker don't support this so I don't even know if it's possible or what configuration will be necessary to make it work...before I reinvent the wheel, has anybody else tried Apache/Tomcat/FileMaker combination on a windows machine?

Cheers,

Sean

Edited October 16, 200619 yr by Guest

Apache on Windows won't work at all. Good info on the trace logs! That's the kind of info we need to send to FMI and let them explain it. And work on it.

Our machines (DB server & WPE) both have 8GB of RAM, of which only 4GB is addressable by windows (hah!).

They are both quad CPU 3.2Ghz Xeons with GigE between them.

They (IMHO) should be well and truly massively overspec'ed for what we are attempting to do.

Interestingly, once the WPE slows down, the size of the resultsets becomes irrelevent. You can execute a query that results in a single integer being returned, and the performance is still absolutely atrocious (ie: 2-3 minutes).

This is a very real and severe issue.

We have had no response from FileMaker (US) yet either.

Wim,

I used an understatement. The WPE can be reproducibly crashed with our procedure (only 5-10 bigger queries in a fast series). Hardware in our setup is state of the art. E.g., our servers are on a 1 Gigabit ethernet, cable connection between the FMS and the WPE server is 40 cm and they communicate between each other with dedicated NICs.

Edited October 16, 200619 yr by Guest

An update for those experiencing this problem..

I decided to try reinstalling to rule out faulty windows installation...

I created a temporary server to transfer our databases to while wiping the server, with a clean windows install, clean filemaker install, and no other sofware at all. Got everything hooked up to this and it was quite snappy. This machine is a P4 desktop with 1Gb of ram.

I wiped the server, and did exactly the same thing, clean windows install, clean filemaker install, no other software at all. Hooked everything back up to this, and guess what? Ten second queries.

What's different I wonder? The server is on the domain but the desktop isn't. I add the desktop to our domain, no apparent problems. Server has the v4 updates installed, desktop doesnt. I ugrade the desktop FM server to v4, no apparent problems. I upgrade the desktop WPE to v4 and it seems OK, but I start getting 10 second queries.

I didn't test thoroughly enough to be certain that there were no problems between the updates, but I'm fairly certain the problem started with the WPE update. I'm going to try an installation without applying the WPE update. Will keep you posted on how it goes...

This is interesting stuff (nice work by the way)!

I'll be very interested in the results you get here.

That said, are the performance issues you experience easy to replicate just by increasing load slightly (ie: submitting multiple queries at once)?

The reason I ask is that my setup is fairly snappy in a test environment (and for a portion of the time in production, for that matter), it just all falls apart horribly when load increases even slightly.

Cheers again for the efforts.

We didn't even get to the point of testing under load! But it seemed to happen after a number of requests rather than straight away, so I wonder if perhaps there is something unhealthy going on in the way Tomcat is trying to reuse its workers, which would mean load would cause the problem too.

Set everything up again on the server this morning with no V4 updates, and it's fine so far. Too early to be confident about it being fixed, but its looking hopeful.

Do you have an official Tech Support case with a case number open at FMI?

Regarding RAM, as discussed earlier in this thread, the reason I asked that question originally, is that your symptoms are very similar, although not identical, to an earlier issue with IWP under load. That issue was addressed by adding RAM. Now, you are not running IWP, and now you note 2 GB of installed RAM. So, let's see what happens. But please do keep us posted.

Steven

Hi Steven,

No we don't have a support case at FMI. I've filed a problem report, but we don't have any sort of support contract with them - 99% of problems I can sort out without any help, and the 1% are the impossible things like this where no one knows what is going on!

As far as the setup is going... the configuration is exactly the same is it was when we were having trouble, IWP is still enabled with the same four databases accessible, the same seven are used for XML access vie the WPE, other databases on the server are used (sparingly) by client machines for office management tasks. There has always been 2GB of ram. The only thing different is we haven't applied the v4 updates, and it is still working fine.

Monitoring TDI traffic to look at the tomcat/filemaker communication causes FileMaker to have all sorts of problems, which is making me think that there is something seriously wrong with the way Tomcat gets data from FileMaker at a very low level. If I was working at FileMaker, it be starting to look very hard at what was changed between v1 and v4.

Cheers,

Sean

Hi Mr F,

I don't know how much trouble it would be for you, but a reinstall with no V4 updates to FileMAker server or the WPE does seem to have fixed the problem so far. If you want to try it, it might help to know that tried on the test machine doing an uninstall and reinstall of just the WPE and it didn't fix the problem.

If you aren;t looking urgently for things to try, I'll keep an eye on it for the next week and post back whether it has had any problems.

Cheers,

Sean

If I was working at FileMaker, it be starting to look very hard at what was changed between v1 and v4.

That's why I am trying to find out if you have a Tech Support case number. It might be a good idea to open a Tech Support case here.

Steven

I have a tech support case open and have spoken to the head engineer at FileMaker Asia-Pacific.

So far, they don't know what causes this, but it's been escalated to US Engineering.

I am currently working through that process with them.

I'll keep you guys updated as to how I go, but so far, the progress has been quite slow. The indication/feeling I got from speaking with them (the Asia-Pac engineering were very helpful/thorough) is that it could take a long time to solve (ie: many months).

Any info that we're able to work out independently would be greatly appreciated.

I'll keep you guys updated as to how I go.

I don't know how to open a Tech Support case from here, but if someone points me in the right directions I am happy to do so.

Its still running with no problems. Load testing will come next...

Cheers,

Sean

It's either 800-325-2747 or 408-727-9004, I don't rememebr which. I believe there is a card in your installation information with more details.

Steven

Steven, I don't know if it works differently here (Australia) but we get one tech support case for free, which we used trying to solve this issue. I've filed a problem report, to which they responded with a "can you tell use more information about your installation" email, but I'm not going to pay for the privilege of helping them troubleshoot their software!

Sean

I think that's the way it works in the US as well. I am usually on the receiving end of Tech Support calls, so I am not 100% sure. I had originally asked you for your Case Number so I could make some inquiries towards solving your issue.

Best of luck.

Steven

I've got some questions of my own about the performance of CWP. I've got some pages setup to display products from our database. One set uses the XML API in FM and the other set uses ODBC. ODBC wins the speed battle more often than not, which was surprising to me.

In any case, with both methods I notice that when a query hits the CPU on the server jumps to about 25% - 35% for a second or 2 and then goes back to normal. Is this to be expected..?? I'm the only one hitting the database that way right now and if it's jumping to 30% with just me doing a single query I can't imagine it would be able to handle web traffic...would it?

If I have 100+ on there at any given time all browsing through product pages..well I don't know that I'd even get 100+ people on there like this.

Will it be ok? Is that a normal spike? Any information would be greatly appreciated. Thanks!

That's a question with no easy answer: you need to do baselining for that. Hit it with 5-10-20-50-100 whatever requests and monitor all of the system. See what parts fluke out and how you can counter it. A lot depends on how your system is built. Another big part is that FMSA is not a speed daemon. But it's only with proper monitoring and then working with FMI that we can get them convinced to do something about it.

For you personally: you do *not* want to commit to going live without having tested this and found the proper hardware combination that will give you the best result.

Hey DrewAngell,

This sort of CPU spike is the sort of performance issues we've seen (see previous posts by myself).

In answer to your question - from our experience, the XML interface does NOT scale well, particularly with parallelizing requests.

We found we had to implement write-back caching and write all data syncronously just to keep performance even slightly vaguely acceptable.

Combining this with very heavy caching of reads has been the only way we've been able to maintain stable (if fairly awful) performance.

Keep in mind, this is running on two very high end quad-CPU xeons with 4GB RAM each and you can barely maintain a few simultaneous requests.

We have a support process happening with FM, and I'll post my results/experiences as I move forwards.

Cheers!

Mr F.

Would it be feasible to create one giant XML that contains all of the product data and then just parse from that? Then I could just run a script to generate that XML for me however often and whenever it can stand it. Wouldn't be completely real-time for displaying current products, but then I could probably get away will running inserts and updates directly since there won't be near as many.

Does that sound like something that could work? Or, maybe there's a way one could create that giant XML that contains everything, and then sync that XML with the FM server so that it would receive small updates in real-time...: Pulling from a static XML would likely be faster and take less server load since it's not actually querying everytime.

I'm gonna be spending some time on experts-exchange.com trying to figure this one out. : Anybody care to join the project?

Or...even better...maybe FM will fix the problem..??

Hi there,

If you have no major requirement for data to be realtime, then you'd be better off doing a batch export of data from FileMaker to flat XML (then into a MySQL DB or somesuch), or to propegate it via ODBC.

Alternately, FX.php does contain a caching module (PHPCACHE which is fairly undocumented), which you could very possibly use to get around most problems.

Unfortunately, for our application, a lot of the data MUST be realtime, which is what causes all our problems.

You might be OK, but I certainly wouldn't attempt to run any sort of website that relied on FMP queries via XML to serve pages to give any sort of reasonable performance.

Cheers,

Mr F.

Well, I've tried the same pages using ODBC and I get the same 25% - 35% spike on the CPU for those queries as well. Should that not be happening?

Do you have the Web Publishing Engine installed on it's own server beside your FM Server or do you have both installed on the same machine? According to this FM book I have you'll gain performance by putting the WPE on it's own dedicated server instead of being on the same machine as FM Server.

Have you tried that?

I went ahead and created a script that generates static xml's for each of my product categories and then I can pull from those separately.

I'm actually using CWP to generate these XML's, so my CPU takes about a 50% hit for a good 2 min. or so while it's generating these XML's. It creates the new file to a temp directory and then moves it to the live location overwriting the previous so hopefully I won't have too much of an issue with people trying to browse while the file is locked.

We'll have to play around and see how often we can run the updates.

It'd sure be nice to be able to use the XML API the way its intended. As it stands now I don't know what I get from Advanced Server..??

DrewAngell, can you first describe your hardware setup?

AMD Opteron 254 2.81GHz w/ 2GB RAM. I saw somebody else that mentioned they're running dual Xeon's though, and 4GB RAM and they have the same problems. Our hard disk is a SCSI 15k rpm.

Well, its been a while now and the database is still holding up without the v4 updates and without the long query times. I don't know if it will fix anyone elses problems, but it seems to have fixed mine.

Though we have a slightly different problem now...sometimes it will just stop sorting results by fields passed to it and sort by record id instead, so our "recent news" suddenly starts being the news from 2001. Ho hum.

Cheers,

Sean

Though we have a slightly different problem now...sometimes it will just stop sorting results by fields passed to it and sort by record id instead, so our "recent news" suddenly starts being the news from 2001. Ho hum.

I believe this is a known issue. I will check to see something about this and report back.

Steven

Just a further update on my investigations - the below is essentially paraphrased from part of my FileMaker support process:

-----

It appears that the WPE doesn't thread properly, or has some sort of locking/race-condition issue in some cases.

I set up a test suit that attempted to gather performance metrics in pulling up a record via primary/indexed key and the impact of threading/multitasking (ie: what number of simultaneous queries gave the best performance).

To my surprise, I have found that the WPE does NOT answer multiple requests at once, or rather, some sort of locking issue causes them all to be answered asynchronously, ie: 1 query takes 3.5 seconds, 2 queries take 7 seconds, 3 queries takes 10.5 seconds (etc, etc) - See attached PDF for full results. In this case, NONE of the queries respond until all have completed, making it look like there is some sort of race-condition/locking type issue, which explains the terrible performance (in our particular setup).

So far, the problem is 100% replicatable all the time on all machines tested (tried both on single CPU FMSA/WPE combined server and separated 2 x 4 x CPU separated FMSA/WPE servers).

I would hazard a guess that it is due to the number of complex relationships in our particular setup, but have so far not narrowed it down to precisely what recipe of relationships/etc allows this specific problem to occur.

Either way, it does highlight some sort of very real problem with the way the WPE is locking/querying, where it becomes impossible for us to run more than 1 query at a time on a given table via XML.

------

I'd be interested in seeing if anyone else is able to replicate/has seen similar issues with their own FileMaker/WPE/XML setups.

Will let you guys know how I proceed,

Mr F.

FileMaker_non-threading_performance.pdf

I haven't gotten that detailed with my investigation, but that does seem to be similar to what we're experiencing.

I know you take a large hit with unstored, calculated fields. We had some fields that were being calculated on other calculated fields and it was really taking its toll. We were able to boost performance a little bit by cleaning up some of these calculations so that it didn't use so many unstored fields.

That allowed the actually queries to return quicker, however, the CPU spikes have not been solved. Each query spikes the CPU to about 30%, so you can't get many people using it at the same time. Definitely won't work for live web applications. The same thing happens with ODBC. A single query will be nice and quick, but spikes the CPU.

I've resorted to creating a script that syncs our product data into an Access database and I use that for any product queries.

My checkout system is connected directly to FileMaker and while the same spikes occur during a checkout we don't get many simoultaneous checkouts so I'm hoping it won't cause an issue, but I won't know for sure until we try.

I have to say this is very frustrating. When I was first introduced to FileMaker I didn't like it at all. After having no choice but to work with it it's definitely grown on me and I even began to praise it when I learned about the WPE/XML stuff. But then we've gotten slapped in the face again since we can't even connect it to our web site. :

Hey FileMaker...I know you didn't start out as a SQL based database and I know the XML stuff is new. But you guys are obviously pretty sophisticated. Is this really that hard to fix...? There's no reason a simple SQL query should spike a CPU to 35% or more.

Please help us out!

Just adding on to my own findings, here's further info we've worked out/sent through to FileMaker engineering:

-----

Furthering to this, we've been doing some further investigation - We've noticed that the web publishing engine seems to be able to get itself into a state where it will get stuck in a loop of some sort and utilize all CPU's at around 35% forever, until the service is forcibly terminated and restarted.

We've had this a couple of times, including today, where we cut off all external access to the WPE. At this point, we proved there was NO traffic hitting the WPE front end (via netstat) making requests, yet the WPE (wpc.exe) sat utilizing all 4 CPU's non stop, seemingly forever (see attached image, right side of graph).

When this is occuring, the WPE runs VERY slowly - ie: 2-3 minutes to answer ANY request. It also will not terminate gracefully via the services manager, and has to be forcibly killed and restarted to fix the problem.

This does not happen all the time and is separate from our general bad performance issues, but I thought the info may help the engineers track down where the problem lies.

-----

I've experienced these same issues with both the XML and ODBC connections. If you accidentally find yourself throwing an unstored calculation into the mix of your queries then you're screwed.

The CPU spikes and sticks at about 70% on our AMD Opteron and will not stop until we shut down the service.

Here's something kind of interesting regarding the last statement about the CPU sticking until you turn off the service.

I was working on some scripts that I've run many times before. It uses ODBC and it's relatively complicated insert into FileMaker.

Well, I had run about 10 of them with no problem and then the 11th one hung on me. CPU got stuck about 45% and sat there and wouldn't stop. I let this go for about 3 hours with no change hoping that it would eventually just stop without me having to shut everybody out of FM and shut down the service.

Well, it never stopped...until...

I was just about to the point of shutting everybody out and restarting the service when I figure well I'm gonna try another one to see what happens before I do that.

this time, the insert worked without much delay, and when it was done the CPU went back to 0%.

so it seems that running another and getting it to complete solved the problem of the one that was stuck....though the one that was seemingly stuck did NOT end up in FileMaker once the CPU stopped.

So, I don't know if that was a big coincidence or what, but I figured I'd let it be known what happened.

Still waiting on an update for these problems. I've got a checkout system that's working perfectly with FileMaker now about 85% of the time. the other 15% of the time customers complain that when they hit submit and wait a good 3 or 4 min and nothing happens they get impatient and close it.

This seems to be a case of FM just lagging on them because i haven't noticed the CPU getting stuck on a spike from a customer checkout yet.

I just got off the phone with a FileMaker tech support guy. Used the free support code I got with one of our FileMaker Pro 8.5 clients. I couldn't believe what they told me.

Without getting into a huge schpeal about the whole conversation, he basically left me by saying that "FileMaker knows about the performance issues and it has not been considered a matter of importance."

No joke. Apparently they don't think the business of web developers is important.

I will take this matter up with the head of Tech Support on Monday. This was a Tech Support agent who told you this, not a customer service agent, right?

Steven

Yes. I called the tech support line from this link:

http://www.filemaker.com/support/phone.html.

There's actually quite a bit to the story. I first called yesterday afternoon and spoke with somebody. Explained everything I've mentioned in this thread and more, and was told "I'll research this issue and get back with you." He gave me a case number.

Today, having not heard anything back I called again. I gave my case number and explained everything over again to this guy. This guy told me he was a web designer himself and he seemed to understand what I was talking about when I mentioned Custom Web Publishing, ODBC, and web applications. This is the guy that told me they knew about the problems but it hasn't been brought high enough on the importance scale to expect anything to be done. He gave me the impression that since the performance hit is minimal in the fact that the CPU only spikes for an instant and then goes back to normal is the reason they don't think it's very important.

They seemingly fail to understand that you can't have multiple people hitting the server in this manner, constantly spiking the CPU leaving it un-usable and resulting in hanging web pages. He agreed with me on this fact and said he'd send me an email in which I could respond with these details, including a link to this thread which I mentioned to him, and then he would flag it and make sure they saw it. So that's good...if it actually happens.

Anyway, I responded with plenty of details only to get an email back that said the email he sent that to wasn't the email in my filemaker.com profile and could not be added to the case. Upon clicking the update profile and logging in I could see that yes, the email was not the same. I tried updating the email but it said that email already in use in another account. So then I tried looking up the password for that email address and it said that account didn't exist in the DB. Even when I left the PW blank like it says could be it said not found.

So at this point I called the tech support line back. I got another guy on the phone who was absolutely clueless. He read over the case information they had and then I once again had to explain everything. He was asking me questions about the CWP and ODBC and kept confusing the 2, and sometimes thought they were the same thing. I ended up having to explain how CWP works through the Web Publishing Engine, which is seperate from FileMaker Server and ODBC, but both ways cause the CPU spike. He then basically admitted he couldn't help me and sent the email to the address that was already in the profile.

So now, I responded to that email and I haven't gotten anything back, which means it should have gone through. I also submitted the problem to the problem submission of filemaker.com for the second time. Firs time was more than a month ago and I never heard anything back.

I also explained to them that my biggest fear right now is that I'm going to create an entire new solution that involves using mySQL as my database for web applications and then importing/exporting to/from FileMaker (which really sucks for many reasons) and then right when I get it all done they release a fix for this problem. How I'd probably just dump FM and use another product if not for my employer insisting on having everything in FM like I know other developers have done because of this exact problem.

Finally, I also praised them for the Custom Web Publishing features because I think that's really cool...but you can't even use it in any actual application because of the CPU problem. I explained that if this was fixed I WOULD choose FileMaker over other databases.

I finished up my conversations with all 3 people by stating that I would simply like some kind of an answer. If they're going to continue ignoring the problem then I'd like to know. If they didn't know was a problem, I'd like to make sure they do know, and how can that be done? If they need any other info I'm happy to help, etc. etc.

So, we'll see what happens. It'd be really neat to just make this work. I've got an entire solution completed and working great...when I'm the only one using it.

Anyway, I'm done ranting now. Anything you can do to get any information would be greatly appreciated. Thanks!!!!

Edited December 2, 200619 yr by Guest

No joke. Apparently they don't think the business of web developers is important.

Honest to god, i don't think the support portion of FileMaker thinks that anyone is important -- ESPECIALLY when they bring to their attention potentially serious issues with their software.

Further -- either they deliberately don't follow up things they say they will -- or there's something wrong with the software they use (more likely the first than the second).

FileMaker really needs to re-think the way it treat's existing clients - especially developers.

Be assured that I will invite their attention to this, both the process you endured and the substance of your issue as well.

Steven

That is much appreciated, thank you!

I am advised that management will conduct a review of this matter, both for its substance and for its manner of presentation.

Steven

Did they give you any idea on when/if they're going to get back with you on that?

I got a call from 2nd tier support tech from FileMaker yesterday. I explained everything again to him and he asked me to reproduce the error, yet again, on yet another machine.

I did this on a brand new install of Windows / FM Server 8 Advanced v4 / Web Publishing Engine. I also installed the ODBC drivers.

I provided them with 2 .vbs scripts that pull data from FileMaker. 1 uses ODBC and the other uses the XML API (CWP). I included my own logs of the CPU spiking when the scripts are run.

I gave them the actual file I'm using, my logs, the .vbs scripts, and detailed instructions on the steps I took to configure everything. They have absolutely everything they need now to reproduce the problem.

He said that if he can reproduce the problem he'll escalate this again to the actual engineers.

I'll update when I know more.

Please keep me posted on this issue and any progress or the lack thereof.

Steven