FSQL Service unable to start/connect

Archived Topics
1

Our customer decided to change IP address schemes on us, and ever since I changed the IP of the PC that is running FSQL, I have had problems. I am not 100% sure the problem is with FSQL, but I am ruling out RSLinx as the culprit for now because it works OK with an OPC quick client. The problem might be with RSLinx when FSQL tries to use it as the OPC server, but I am not sure how to test that.

In general, the PC runs agonizingly slow as soon as the FSQL service is started. If I stop the service, performance returns to normal. After I start the service, the tray icon says ‘Attempting to start service…’ for a very long time. I let it sit like this for about an hour and saw no change.

If I bring up the Service Status window, it says ‘Service Connection Not Available’, and briefly switches to ‘Unable to Connect to Service’ before going back to the first message.

I have tried reinstalling FSQL, but I didn’t reboot after the uninstall and before the reinstall. Next step will be to do a proper reboot, then reinstall RSLinx as well.

When FSQL is uninstalled, does the configuration/project get deleted as well? If not, where is it so I can delete it and restore an older backup in case it was corrupted.

Can you guys think of any reasons why this might be happening? Corrupt configuration maybe? Anything else I can try to fix it? Thanks for your help!

UPDATE:
If I open the frontend and try to connect to the service manually, it gives an unexpected error. Copied and pasted the message here:

Error Message: Object reference not set to an instance of an object. Stack trace: at FactorySQL.frmMain.ShowEditConnections(Boolean NewConnection) at FactorySQL.frmMain.msiConnection_NewConn_Click(Object sender, EventArgs e) at System.Windows.Forms.ToolStripItem.RaiseEvent(Object key, EventArgs e) at System.Windows.Forms.ToolStripMenuItem.OnClick(EventArgs e) at System.Windows.Forms.ToolStripItem.HandleClick(EventArgs e) at System.Windows.Forms.ToolStripItem.HandleMouseUp(MouseEventArgs e) at System.Windows.Forms.ToolStripItem.FireEventInteractive(EventArgs e, ToolStripItemEventType met) at System.Windows.Forms.ToolStripItem.FireEvent(EventArgs e, ToolStripItemEventType met) at System.Windows.Forms.ToolStrip.OnMouseUp(MouseEventArgs mea) at System.Windows.Forms.ToolStripDropDown.OnMouseUp(MouseEventArgs mea) at System.Windows.Forms.Control.WmMouseUp(Message& m, MouseButtons button, Int32 clicks) at System.Windows.Forms.Control.WndProc(Message& m) at System.Windows.Forms.ScrollableControl.WndProc(Message& m) at System.Windows.Forms.ToolStrip.WndProc(Message& m) at System.Windows.Forms.ToolStripDropDown.WndProc(Message& m) at System.Windows.Forms.Control.ControlNativeWindow.OnMessage(Message& m) at System.Windows.Forms.Control.ControlNativeWindow.WndProc(Message& m) at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)

2

Hmm… That error does seem to indicate that there might be a problem with your config file. However, it could also be caused by a different error occuring while loading the file.

The config is stored in system_database.fdb under the install directory. It is not deleted when FSQL is uninstalled, so you’ll what to manually delete it to start from scratch and reload a backup.

FIRST, however, take a look in the install directory for data_cache_db.fdb. How big is it? This is the data cache file, where data is written while the database is not available. We’ve had users have problems similar to what you’re describing when their datacache files got fairly large, and especially when the queries stored might be erroring out on reload. If the file has data in it (that is, the size is > 100kb or so), try stopping the service, renaming/deleting the file, and restarting the service before doing a full system restore.

Hope this helps, if you’d like to have us take a look at it feel free to call the 800 number.

Regards,

3

The cache file is 3kb, so that should be OK. I found the core_log_service.txt file there as well and found some goodies (note: timestamps are in dd/mm/yyyy format for the UK):

[code]FactorySQL 07/05/2008 15:47 Event Count:1 Category:SubSystemManager Type:Information Status:Other
FactorySQL started. Beginning to initialize subsystems…

FactorySQL 07/05/2008 15:47 Event Count:1 Category:SystemMessage Type:Information Status:Success
Subsystem ‘SystemMessagingSystem’ started sucessfully.

07/05/2008 15:48 Event Count:1 Category:InternalDB Type:Error Status:Failure
Error initializing project view.
Some kind of disk I/O error occurred
disk I/O error
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteDataReader.Read()
at System.Data.Common.DataAdapter.FillLoadDataRow(SchemaMapping mapping)
at System.Data.Common.DataAdapter.FillFromReader(DataSet dataset, DataTable datatable, String srcTable, DataReaderContainer dataReader, Int32 startRecord, Int32 maxRecords, DataColumn parentChapterColumn, Object parentChapterValue)
at System.Data.Common.DataAdapter.Fill(DataSet dataSet, String srcTable, IDataReader dataReader, Int32 startRecord, Int32 maxRecords)
at System.Data.Common.DbDataAdapter.FillInternal(DataSet dataset, DataTable[] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet)
at FactorySQL.InternalDB.ExecuteQuery(String Query)
at FactorySQL.Project.IOManagers.DBIOManager.RefreshProjectView()
at FactorySQL.Project.IOManagers.DBIOManager.InitializeProject()

07/05/2008 15:48 Event Count:1 Category:InternalDB Type:Error Status:Failure
Error initializing database.
Some kind of disk I/O error occurred
disk I/O error
at FactorySQL.InternalDB.InitializeDataStore()

FactorySQL 07/05/2008 15:48 Event Count:1 Category:SystemMessage Type:Information Status:Other
Error initializing internal db.
System.Data.SQLite.SQLiteException: Some kind of disk I/O error occurred
disk I/O error
at FactorySQL.InternalDB.InitializeDataStore()

07/05/2008 15:48 Event Count:1 Category:FileManagerSubsystem Type:Error Status:Failure
Error loading project io manager.
Database IO Manager has not been initialized.
at FactorySQL.Project.IOManagers.DBIOManager.ReadSettings(String Category)
at FactorySQL.Settings.SettingsManager.RefreshSettings()
at FactorySQL.SubSystems.FileManagerSubsystem.StartSystem()

FactorySQL 07/05/2008 15:48 Event Count:1 Category:SystemMessage Type:Information Status:Failure
Subsystem Failed to Start.
Subsystem ‘FileManagerSystem’ failed to start, with error message: Database IO Manager has not been initialized.

FactorySQL 07/05/2008 15:48 Event Count:1 Category:SystemMessage Type:Information Status:Other
The internal database error logger is taking over. All messages should be logged to that logger, and any messages that follow below indicate a failure to write to that log.

FactorySQL 07/05/2008 15:48 Event Count:1 Category:SystemMessage Type:Error Status:Success
Error logging message to internal db log. Original message: Subsystem ‘ErrorLoggingSystem’ started sucessfully.
System.Data.SQLite.SQLiteException: The database disk image is malformed
database disk image is malformed
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
at FactorySQL.InternalDB.ExecuteNonQuery(String Query, IDataParameter[] Parameters, Int32 Timeout)
at FactorySQL.Project.IOManagers.InternalDBIOManager.StoreLog(ILog Log)
Original details:

is malformed
database disk image is malformed
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteCommand.ExecuteScalar()
at FactorySQL.InternalDB.ExecuteScalar(String Query, Int32 Timeout)
at FactorySQL.Project.IOManagers.InternalDBIOManager.CleanLogs(Int32 Value, StoreRestrictionType Mode)
at FactorySQL.SubSystems.ErrorLoggingSubSystem.HouseKeeping(ExecutionToken Token)[/code]

The last message there repeats about 10 times but looks exactly the same. So I’d say it looks like the config is corrupt. I’ll try and fix it, thanks for your help.

4

I uninstalled FSQL and then tried to copy all the left over files to another location, but I get errors copying the system_database.fdb file. Looks like a filesystem error is the real problem here. I also just learned that last night my coworkers were killing power to the machine over and over to test disaster recovery, which meant that none of the PCs were properly shut down however many times. It is starting to look fairly obvious that this is what caused the corruption, so thanks for pointing me in the right direction to figure it out! Now to find the smallest panel mount UPS possible…

5

Yeah, sounds like there could be some bigger problems involved. However, make sure that all 3 FSQL applications are shut down before trying to move file: FactorySQLFrontend.exe, FactorySQL Service.exe and FactorySQL Tray Application.exe.

Regards,

6

I have another problem now, but it might be related, so I’m going to keep on in this topic.
I uninstalled FSQL, reinstalled, got everything working again. However, now sometimes when FSQL starts it makes thousands of groups in the OPC server and never successfully starts. As I watch it, subscription_1 toggles between active and inactive, while other groups are added with 1 tag each. Normally there are 4 groups with various amounts of tags in them. It happens on reboot, but never when restarting the service from the service management screen in windows. Attached screenshot to illustrate. (StaXCSV are my groups, ignore them)

On a side note, where is the update rate of 70/170 ms set? All my groups are set to update at 500 ms or more and 70 seems a little low.

fsql_starting.jpg853×537 105 KB

7

That’s very strange, especially since you say it only happens on reboot, and not on restarting the service.

Is RSLinx set to run as a service? (I imagine it is, but worth checking). Also, are there any errors that show up in the FactorySQL error log (Help->Log Viewer) while it’s starting up like that? If you hit “cancel” on that dialog, you can still go view the errors for the local machine, even while “offline”.

Finally, if it’s not too big, you could send your system_database.fdb (or system backup) to support AT inductiveautomation DOT com and we’ll take a look.

Regards,

8

RSLinx is running as a service.

I was messing around with things trying to debug this couple days ago, and I found that if I remove my other program using the same Linx OPC server, FSQL can start OK. So what I ended up doing was creating a script that runs on startup that waits 2 minutes, then launches my OPC program. FSQL has started OK every time so far. I don’t know where the problem really lies again, but this workaround is acceptable. I sent in my system_database.fdb anyways, but I think it will end up looking fine.

From this latest reboot I see no errors in the log except expected group errors (group has no tag data yet but tries to execute, SQL server rejects null values on insert.)

I also don’t see thousands of groups anymore, only about 170, which is much more than I saw last time, but it is working so I’m not worried.

It is hard to tell where the problem really is, but I suspect Linx was wigging out with all the demands from my program and FSQL connecting at the same time, perhaps sending FSQL feedback that was unexpected, causing FSQL to create those thousands of groups.

Thanks again for your help.

9

I’m glad that you’ve got it stabilized. There was a bug fixed in 4.2 (the beta is currently available to integrators in the integrator portal) which would cause this due to a problem with how FSQL handled “revised update rates”. That’s when FactorySQL says “I want a subscription at 500ms” and the OPC server replies “Here’s a subscription, but it’s at 70ms”. FactorySQL would then end up creating many subscriptions, never connecting that 70 was always going to be the response to 500.

I don’t know if this is what was happening in your case, but it’s the only thing I’ve seen cause this behavior. I’ve looked at your project, and from what I can see there should never be a subscription created at 70ms, let alone so many. There should be a number of 330ms, and a few a bit quicker, so that might also point to this “revised rate” problem. Like I said, it’s been fixed in 4.2, so that might help. The final version should be released on friday.

Regards,