An Opened File That's Actually Closed

Heads-Up!
, ,
1

I just solved a problem and thought it good to share my experience.

Some of you have seen the following post: 802 Error. This post is related to it.

I use OttoFMS for its webhook feature with SimpleQ. For those who don't know, OttoFMS can act as a webhook receiver. OttoFMS integrates with a FileMaker file called SimpleQ. SimpleQ acts as a publish and subscribe dispatcher.

Things weren't going well. Every morning, OttoFMS would be unable to refresh its authentication token to SimpleQ. FileMaker Server's fmdapi log would first show a 952 error (Invalid FileMaker Data API token) followed by a 802 error (Unable to open file), followed again by a 952 error. Yet the file was open on the server.

Stopping and restarting the database engine made everything work again… but that just couldn't be the solution. I did a little more digging.

One sleepless night, I decided to go to Postman to send a request to OttoFMS every time I woke up. My goal was to find out when, during the night, the issue started. Unfortunately for me, OttoFMS had no issue during the night or morning. The next day, however, the issue came up again.

I asked myself the question: Could FileMaker Pro open the file when OttoFMS could not? I waited another day and, lo and behold, FileMaker gave me the message "File close by host". Yet the file was open on the server.

It dawned on me that a server schedule should fail to run a script if the script's file is closed on the server. SimpleQ has a flush script that runs at regular intervals to dispatch webhook messages to subscribers. Everything clicked when I opened the server's events log and looked for these flushes.

My server runs a DB Verify schedule at 03:00 every night. This closes all the databases, then re-opens them all while also performing a consistency check. It so happens that the flush schedule also runs every five minutes on the hour. This is what the events log says:

  • The DB Verify schedule started;
  • The flush schedule started;
  • The flush schedule performed a script;
  • The SimpleQ file started closing;
  • The flush script completed;
  • The flush schedule was set for its next execution;
  • The SimpleQ file was closed;
  • The SimpleQ file was opened with a consistency check;
  • The consistency check for the SimpleQ file was successful;
  • The SimpleQ file was opened;
  • The SimpleQ file was closed;
  • The DB Verification schedule was set for its next execution.

From then on, the flush schedule failed with error 802. I have no idea why the SimpleQ file was closed a second time. I am chalking it up to a FileMaker Server bug. Though I haven't tested it, I am fairly certain that any file, not just SimpleQ, that performs a schedule script at the same time as the database verification schedule will encounter the same issue.

But what about the Postman night? Everything worked as expected that day. It so happens I did a Postman test at 02:58. Did this prevent SimpleQ from closing again a few minutes later? It looks like it but I really have no idea. As I can’t guarantee when there will be webhook calls, I cannot rely on the frequency of webhook calls as a potential solution.

I chose to implement a simple workaround to avoid this issue altogether: Exclude SimpleQ from the nightly verification. Since then, no more problem!

That was my nightmare for a few days. Hope this helps you if you encounter a similar situation.

4 Likes
2

Just to be clear… the events log said the server closed SimpleQ a second time. The database tab, however, kept saying SimpleQ was open.