Connecttoserver error

JamesCook · December 1, 2024, 7:24pm

In a procedure that opens a shared file, which usually works, the file sometimes fails to connect.

After opening the file, I tried to head off the issue by adding a check to the procedure using info(“serverconnection”) and if it’s false invoke connecttoserver.

connecttoserver frequently, but not always, draws a WaitForTask statement cannot wait error.

When the connection has failed and instead of having the procedure try handling it, I choose Check Server Connection and get the following dialog:

Not connected to server
The server XYZ is available but this database is not connected at this time. The database cannot be modified until it is re-connected to the server.

In this case I can choose the provided option to connect to the server and here too, I get the WaitForTask error.

I don’t know why it fails to connect in the first place. It always detects the server - which in this case is running on the same machine. info(“serverconnection”) correctly detects the condition and proceeds as intended. But connecttoserver is unreliable and I don’t know how to correct it.

admin · December 2, 2024, 3:04am

Rather than trying to figure out how to patch around this, it seems to me that the correct approach is to figure out what the actual problem is and get it to work the first time.

When you open the database, part of that process is running connecttoserver internally. So it’s not surprising to me that if it failed once, it would fail again when tried a fraction of a second later.

Does this failure only happen when you open the shared file from a procedure? In other words, if you open the file by double clicking on it or using the Open File dialog, does it always work then?

If it only fails when opened from a procedure, what does your procedure look like?

All of the code involved in opening and connecting to a shared database is heavily instrumented, so you could enable that instrumentation and see exactly what is going on inside Panorama. Or at least give me a clue as to what is going on. You could use this link to enable instrumentation on the code that does the open and connect operations.

panoramax://zlog?_EnterpriseClientLib=CLIENTOPENSHAREDDATABASE,CLIENTSYNC,CONNECTTOSERVER,DOWNLOADDATAFROMSERVER

This will enable instrumentation on four procedures in _EnterpriseClientLib, as shown here:

I think this means that you are making a second attempt to connect to the server when it is still waiting for the first attempt to complete. Going back to Henny Youngman, I think the correct approach is to figure out the original problem, not to attempt to patch it over with repeated connection attempts. Hopefully the instrumentation log will contain something useful.

JamesCook · December 2, 2024, 6:49pm

Thanks, Henny.

My procedure:

    OpenFile lvDataPath+"Contacts"
    If Error
		ErrorLog = strip(ErrorLog+¶+"Contacts was not opened.”)
       Rtn
    EndIf
    If info("serverconnection")=false()
        connecttoserver
        If info("serverconnection")=false()
            CloseDatabase "Contacts"
            ErrorLog = strip(ErrorLog+¶+"Contacts did not connect to the server.")
        Rtn
        Endif
    Endif
    ForceSynchronize

Opening the file myself, it connects reliably. Sometimes when it has failed via the procedure, it will show as being connected, but was that after some time passed?

In that vein I added Wait 5 ahead of connecttoserver. With the problem not occurng every time I won’t know for sure immediately but so far it has run successfully.

The blog you requested, with server name and IP address altered:


CONNECT TO SERVER ==================================================
[CONNECTTOSERVER] targetDatabase: Contacts
[CONNECTTOSERVER] taskid: /Users/……../Contacts.pandb
CLIENT OPEN DATABASE ==================================================
[CLIENTOPENSHAREDDATABASE] targetDatabase: Contacts
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Database IS SHARED
[CLIENTOPENSHAREDDATABASE] hostServer: XYZ Server
[CLIENTOPENSHAREDDATABASE] serverURL -->http://1234567<---
[CLIENTOPENSHAREDDATABASE] openRetry
[CLIENTOPENSHAREDDATABASE] secretDatabase: false
[CLIENTOPENSHAREDDATABASE] Start connection.
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Client logon.
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] hostDatabaseName: Contacts
[CLIENTOPENSHAREDDATABASE] hostDatabaseID: E4C34B93-2C6A-4705-9F82-1E1B636F46D2-21237-00002DA506C8129C+3815038105
[CLIENTOPENSHAREDDATABASE] sessionID: 720
[CLIENTOPENSHAREDDATABASE] === DICTIONARY xreply ============
[CLIENTOPENSHAREDDATABASE] STATUS="OK"
[CLIENTOPENSHAREDDATABASE] LOOPBACK=""
[CLIENTOPENSHAREDDATABASE] === END OF DICTIONARY xreply ============
[CLIENTOPENSHAREDDATABASE] CLIENTMODE CONNECTED
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Connected - sessionFiles: Contacts
CLIENT SYNC ==================================================
[CLIENTSYNC] hostDatabaseName: Contacts on hostServer: XYZ Server
[CLIENTSYNC] sessionID: 720
[CLIENTSYNC] hostDatabaseID: E4C34B93-2C6A-4705-9F82-1E1B636F46D2-21237-00002DA506C8129C+3815038105
[CLIENTSYNC] lastSyncTS: 9807
[CLIENTSYNC] === DICTIONARY xreply ============
[CLIENTSYNC] STATUS="OK"
[CLIENTSYNC] DELETEDRECORDS=""
[CLIENTSYNC] SYNCTIMESTAMP=9807
[CLIENTSYNC] LOOPBACK=""
[CLIENTSYNC] === END OF DICTIONARY xreply ============
[CLIENTSYNC] tempFileID: 
[CLIENTSYNC] Client is already synchronized.
[CLIENTSYNC] syncNotificationMessage: Already synchronized with XYZ Server
[CLIENTSYNC] syncExtraMessage: 
[CLIENTOPENSHAREDDATABASE] OpenComplete: false
[CLIENTOPENSHAREDDATABASE] No procedure was running, triggered by AppKit (open menu or double clicking on file)
CLIENT OPEN DATABASE ==================================================
[CLIENTOPENSHAREDDATABASE] targetDatabase: Contacts
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Database IS SHARED
[CLIENTOPENSHAREDDATABASE] hostServer: XYZ Server
[CLIENTOPENSHAREDDATABASE] serverURL -->http://1234567<---
[CLIENTOPENSHAREDDATABASE] openRetry
[CLIENTOPENSHAREDDATABASE] secretDatabase: false
[CLIENTOPENSHAREDDATABASE] Start connection.
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Client logon.
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] hostDatabaseName: Contacts
[CLIENTOPENSHAREDDATABASE] hostDatabaseID: E4C34B93-2C6A-4705-9F82-1E1B636F46D2-21237-00002DA506C8129C+3815038105
[CLIENTOPENSHAREDDATABASE] sessionID: 720
[CLIENTOPENSHAREDDATABASE] === DICTIONARY xreply ============
[CLIENTOPENSHAREDDATABASE] STATUS="OK"
[CLIENTOPENSHAREDDATABASE] LOOPBACK=""
[CLIENTOPENSHAREDDATABASE] === END OF DICTIONARY xreply ============
[CLIENTOPENSHAREDDATABASE] CLIENTMODE CONNECTED
[CLIENTOPENSHAREDDATABASE] Contacts OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Connected - === sessionFiles ============
[CLIENTOPENSHAREDDATABASE] Contacts
[CLIENTOPENSHAREDDATABASE] Contacts
[CLIENTOPENSHAREDDATABASE] === END OF sessionFiles ============
CLIENT SYNC ==================================================
[CLIENTSYNC] hostDatabaseName: Contacts on hostServer: XYZ Server
[CLIENTSYNC] sessionID: 720
[CLIENTSYNC] hostDatabaseID: E4C34B93-2C6A-4705-9F82-1E1B636F46D2-21237-00002DA506C8129C+3815038105
[CLIENTSYNC] lastSyncTS: 9807
[CLIENTSYNC] === DICTIONARY xreply ============
[CLIENTSYNC] STATUS="OK"
[CLIENTSYNC] DELETEDRECORDS=""
[CLIENTSYNC] SYNCTIMESTAMP=9807
[CLIENTSYNC] LOOPBACK=""
[CLIENTSYNC] === END OF DICTIONARY xreply ============
[CLIENTSYNC] tempFileID: 
[CLIENTSYNC] Client is already synchronized.
[CLIENTSYNC] syncNotificationMessage: Already synchronized with XYZ Server
[CLIENTSYNC] syncExtraMessage: 
[CLIENTOPENSHAREDDATABASE] OpenComplete: false
[CLIENTOPENSHAREDDATABASE] No procedure was running, triggered by AppKit (open menu or double clicking on file)

Mini M4 Pro on Sequoia 15.1.1

admin · December 3, 2024, 8:23am

As far as I can see, this log shows that the Contacts database opened and connected just fine. You ran the procedure twice, right? Did the connection work? The log is only going to be of any value if it shows what happens when the connection failed.

I don’t immediately see how this could happen, but I’m wondering if the active database is actually Contacts when you use the info(“serverconnection”) function. If it was some other database, it would return false. You could use dbinfo( instead, and/or check to make sure that the Contacts database is the active database.

It doesn’t have anything to do with this issue, but why are you using forcesynchronize? This is not intended to be used in a routine manner like this, it should only be used if there is some reason to think that synchronization has failed. You have designed this code on the assumption that normal synchronization will never work, is that really what you want to do? Early beta versions of Panorama X Server did sometimes have sync problems, but I haven’t heard of anything like that for a couple of years.

You started out by saying that sometimes the file fails to connect. How did you originally come to that conclusion?

I’m guessing that perhaps the procedure you have posted here is only part of the actual procedure you are using? Does this procedure go ahead and perform further operations with the Contacts database?

Hugo Alvarez has reported a problem with “stray clicks” on other windows while a shared database is being opened. Could this be what is happening in your case?

JamesCook · December 3, 2024, 1:02pm

Auto-corrected from zlog

This procedure opens shared files and imports their data into matching single user files. We were convinced that all of the new records weren’t being imported every time. That was also why I started checking the server connection.

The Contacts file is opened, data imported and Contacts is closed and untouched again for 24 hours. That’s because this is the procedure I’ve been working on for months ( and posting about ) to generate PDFs to update web-accessed accounts at 12 AM each day.

It’s all done on the server with no human interaction on the machine at all in most cases.

I would expect that OpenFile “Contacts” makes Contacts the active file. When I tried to use secret windows I used setactivedatabase throughout the procedure, but ran into issues that went away when I eliminated it. (Noted in a previous post)

There are no longer any sercret windows involved since PDFs can’t be generated.

I am familiar with the stray clicks issue though. All users have been taught to keep their hnds off the computer entirely when they first open the file set and the files are initializing.

JamesCook · December 11, 2024, 8:20pm

With the zlog script for _EnterpriseClientLib still active, I happened to catch the WaitForTask error without thousands of lines in the zlog.

There were 7 attempts to open a shared file. All were consistent based on zlog, except for the last.

The first several showed this:

[CLIENTOPENSHAREDDATABASE] secretDatabase: false
[CLIENTOPENSHAREDDATABASE] Start connection.

The difference in the last was this:

[CLIENTOPENSHAREDDATABASE] secretDatabase: true
[CLIENTOPENSHAREDDATABASE] Start connection. (with secret database)

This is a repeating process, so why is it suddenly secret? There are no secret references in the procedure and it was the same procedure every time.

There was just one error message up. Being called by a timer, the procedure that opens the file runs again and again in spite of the error message on the screen. As the only zlog lines with any difference other than the secretDatabase lines, is that the one that triggered the error?

While I don’t know how to interpret all of this, I see in each one: Client is already synchronized and OpenComplete: false.

Here’s the entire log for the last

CLIENT OPEN DATABASE ==================================================
[CLIENTOPENSHAREDDATABASE] targetDatabase: ChoresDB
[CLIENTOPENSHAREDDATABASE] ChoresDB OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Database IS SHARED
[CLIENTOPENSHAREDDATABASE] hostServer: XXXX
[CLIENTOPENSHAREDDATABASE] serverURL --> XXXX <---
[CLIENTOPENSHAREDDATABASE] openRetry
[CLIENTOPENSHAREDDATABASE] secretDatabase: false
[CLIENTOPENSHAREDDATABASE] Start connection.
[CLIENTOPENSHAREDDATABASE] ChoresDB OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Client logon.
[CLIENTOPENSHAREDDATABASE] ChoresDB OpenComplete: false
[CLIENTOPENSHAREDDATABASE] hostDatabaseName: ChoresDB
[CLIENTOPENSHAREDDATABASE] hostDatabaseID: F8419986-89F5-4779-B609-5B6D4787EB8F-65634-00001C0A2B4C1862+3814188341
[CLIENTOPENSHAREDDATABASE] sessionID: 176
[CLIENTOPENSHAREDDATABASE] === DICTIONARY xreply ============
[CLIENTOPENSHAREDDATABASE] STATUS="OK"
[CLIENTOPENSHAREDDATABASE] LOOPBACK=""
[CLIENTOPENSHAREDDATABASE] === END OF DICTIONARY xreply ============
[CLIENTOPENSHAREDDATABASE] CLIENTMODE CONNECTED
[CLIENTOPENSHAREDDATABASE] ChoresDB OpenComplete: false
[CLIENTOPENSHAREDDATABASE] Connected - sessionFiles: ChoresDB
CLIENT SYNC ==================================================
[CLIENTSYNC] hostDatabaseName: ChoresDB on hostServer: XXXX
[CLIENTSYNC] sessionID: 176
[CLIENTSYNC] hostDatabaseID: F8419986-89F5-4779-B609-5B6D4787EB8F-65634-00001C0A2B4C1862+3814188341
[CLIENTSYNC] lastSyncTS: 1602
[CLIENTSYNC] === DICTIONARY xreply ============
[CLIENTSYNC] STATUS="OK"
[CLIENTSYNC] DELETEDRECORDS=""
[CLIENTSYNC] SYNCTIMESTAMP=1602
[CLIENTSYNC] LOOPBACK=""
[CLIENTSYNC] === END OF DICTIONARY xreply ============
[CLIENTSYNC] tempFileID:
[CLIENTSYNC] Client is already synchronized.
[CLIENTSYNC] syncNotificationMessage: Already synchronized with XXXX
[CLIENTSYNC] syncExtraMessage:
[CLIENTOPENSHAREDDATABASE] OpenComplete: false

admin · December 11, 2024, 9:22pm

This code isn’t making the database secret - it’s checking to see if it is secret. Here’s how it’s doing that.

let secretDatabase = targetDatabase<>windowinfo("","Database")
zlog "secretDatabase: "+boolstr(secretDatabase)

I’m not sure what you mean by “secret references”, but somehow the ChoresDB was not the active window when this was called. Maybe I should add instrumentation to show what the active window actually is, though the following code is supposed to work no matter what the window is.

You can also see that this is true. The client contacts the server to find out if it needs synching - the client currently has the database up to time stamp 1602.

[CLIENTSYNC] hostDatabaseName: ChoresDB on hostServer: XXXX
[CLIENTSYNC] sessionID: 176
[CLIENTSYNC] hostDatabaseID: F8419986-89F5-4779-B609-5B6D4787EB8F-65634-00001C0A2B4C1862+3814188341
[CLIENTSYNC] lastSyncTS: 1602

The server replies that time stamp 1602 is the most recent time stamp - in other words, the database hasn’t been modified since the last time this database was synchronized.

[CLIENTSYNC] === DICTIONARY xreply ============
[CLIENTSYNC] STATUS="OK"
[CLIENTSYNC] DELETEDRECORDS=""
[CLIENTSYNC] SYNCTIMESTAMP=1602
[CLIENTSYNC] LOOPBACK=""
[CLIENTSYNC] === END OF DICTIONARY xreply ============

I’m guessing you are thinking that this means that the open didn’t complete, however, that is not what this means. The CLIENTOPENSHAREDDATABASE code is called in two situations - when opening a database, and when using the CONNECTTOSERVER statement on a database that is already open. In the latter case some steps need to be skipped, for example running the .Initialize procedure. OpenComplete will always be false when opening the database, and always be true when using connecttoserver.

WaitForTask is not even going to be invoked unless a synchronization of a large amount of data is needed. It does the waitfortask while waiting for the large amount of data to download. In this case, no synchronization is needed, so no waitfortask.

Bottom line, unfortunately I don’t see anything in this log that provides a useful clue.

All this is being called by a timer? I wonder if that is a clue.

Are these databases so large that you can’t keep them all in memory all the time? These days that would be very unusually large. Seems to me like a lot of hassle could be avoided by opening the databases once when you start up, and leaving them up all the time. Just synchronize before generating the PDFs. But I’m not familiar with your application, so maybe there’s something I’m not understanding. Of course 30 years ago memory was dear and we wouldn’t do that sort of thing, but times have changed.

JamesCook · December 11, 2024, 9:49pm

admin:

JamesCook:

There are no secret references in the procedure and it was the same procedure every time.

I’m not sure what you mean by “secret references”, but somehow the ChoresDB was not the active window when this was called. Maybe I should add instrumentation to show what the active window actually is, though the following code is supposed to work no matter what the window is.

By “secret references” I mean there is no MakeSecret, OpenSecret, etc anywhere in my procedures.

ChoresDB should be active since this is following OpenFile path+“ChoresDB”. I can try adding SetActiveDatabase. So I still wonder why in this one case, it apparently draws an error and a different assessment in the zlog entry.

ChoresDB is a very small database but it can be left open.

As far as leaving bigger shared files open, there are just four that get accessed for a few seconds, once every 24 hours, in order to extract data. There’s no need to keep them open if they’re opening properly. They contain sensitive info and there’s no good reason to leave them vulnerable to some obscure error.