[9.5.452 Pro] - Sqlassist.sas cannot be written

May I ask which SQL Assistant target environments you use often? Maybe you don't need that system tray app starting on startup automatically and then trying to follow everything? That may solve the issue too.

I use pgAdmin, NotePad++ and recently I'm trying to get used to SA Editor.
I'm using systray as quickest way to modify configuration, run SA Editor or jump to this forum ;)

Is it really systray related?

With use of ProcessMonitor I tracked down what happened when Spotify is being started.
Unfortunately adding Spotify.exe and SpotifyWebHelper.exe to SA exceptions doesn't help.

I have a dump from ProcessMonitor but I don't know how to attache it to forum post.

In fact there are 3 processes involved:

Spotify.exe opens file:

Code:

"14:02:04,6527508","Spotify.exe","4436","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"14:02:04,6528726","Spotify.exe","4436","CreateFileMapping","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","SyncType: SyncTypeOther"
"14:02:04,6530117","Spotify.exe","4436","QueryBasicInformationFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","CreationTime: 28.02.2018 18:27:12, LastAccessTime: 28.02.2018 18:27:12, LastWriteTime: 02.05.2018 16:07:27, ChangeTime: 02.05.2018 16:07:27, FileAttributes: A"
"14:02:04,6530281","Spotify.exe","4436","CloseFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS",""
"14:02:04,6531897","Spotify.exe","4436","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Disallow Exclusive, Attributes: N, ShareMode: Read, AllocationSize: n/a, OpenResult: Opened"

It fires ESET Antivirus

Code:

"14:02:04,6535372","ekrn.exe","3680","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","REPARSE","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, Impersonating: AD\kozmic, OpenResult: <unknown>"
"14:02:04,6536845","ekrn.exe","3680","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","REPARSE","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Open For Backup, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, Impersonating: AD\kozmic, OpenResult: <unknown>"

After that Spotify reads content of the file:

Code:

"14:02:04,6538236","Spotify.exe","4436","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 0, Length: 128, Priority: Normal"
"14:02:04,6538716","Spotify.exe","4436","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 0, Length: 4 096, I/O Flags: Non-cached, Paging I/O, Priority: Normal"
"14:02:04,6542302","Spotify.exe","4436","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 128, Length: 128"
"14:02:04,6542507","Spotify.exe","4436","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 256, Length: 128"
"14:02:04,6542835","Spotify.exe","4436","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 384, Length: 128"
"14:02:04,6542999","Spotify.exe","4436","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 512, Length: 128"
... and so on ...
"14:02:05,8398151","Spotify.exe","11188","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","END OF FILE","Offset: 2 219 528, Length: 128"
"14:02:05,8398298","Spotify.exe","11188","CloseFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS",""

After a lot of reads another spotify process reads the SA config file, also secured by antivirus process:

Code:

"14:02:06,4632434","SpotifyWebHelper.exe","4136","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"14:02:06,4633205","SpotifyWebHelper.exe","4136","QueryBasicInformationFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","CreationTime: 28.02.2018 18:27:12, LastAccessTime: 28.02.2018 18:27:12, LastWriteTime: 02.05.2018 16:07:27, ChangeTime: 02.05.2018 16:07:27, FileAttributes: A"
"14:02:06,4633402","SpotifyWebHelper.exe","4136","CloseFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS",""
"14:02:06,4643236","SpotifyWebHelper.exe","4136","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Disallow Exclusive, Attributes: N, ShareMode: Read, AllocationSize: n/a, OpenResult: Opened"
"14:02:06,4647958","ekrn.exe","3680","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","REPARSE","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, Impersonating: AD\kozmic, OpenResult: <unknown>"
"14:02:06,4649718","ekrn.exe","3680","CreateFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","REPARSE","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Open For Backup, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, Impersonating: AD\kozmic, OpenResult: <unknown>"
"14:02:06,4653854","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 0, Length: 128, Priority: Normal"
"14:02:06,4654535","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 128, Length: 128"
"14:02:06,4654818","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 256, Length: 128"
"14:02:06,4655433","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 384, Length: 128"
"14:02:06,4655749","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 512, Length: 128"
"14:02:06,4656016","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS","Offset: 640, Length: 128"
... and so on ...
"14:02:07,0784904","SpotifyWebHelper.exe","4136","ReadFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","END OF FILE","Offset: 2 219 528, Length: 128"
"14:02:07,0785109","SpotifyWebHelper.exe","4136","CloseFile","C:\Users\kozmic\AppData\Local\Packages\SpotifyAB.SpotifyMusic_zpdnekdrzrea0\LocalCache\Roaming\SQL Assistant\9.5\SqlAssist.sas","SUCCESS",""

If you look closer, there is CloseFile event missing executed by ekrn.exe. It, on the other hand, is in pair with my previous finding that the handle is locked by a system process (antivirus)

Unfortunately I have no rights to modify antivirus program settings. I could ask user support but it would involve more resources I would like to avoid.

I also use ESET and I don't see this problem, though I'm not using the spotify app either. So I'm not entirely convinced ESET is the culprit.

In response to "Is it really systray related?"

systray is the visual element of that. It's really the case of how the application is used. When it's is used only as a plugin to SSMS, or standalone as SQL Editor, there are no conflicts. In case of systray there is a resident program that monitors start/stop of development tools, it enumerates all processes and and attaches to them when native plugins aren't available. It normally starts on computer startup, and that sometimes lead to the weird conflict described here, looks like Windows or something else gets confused and starts mixing up things, running them out of sequence or doing something else unclear to us yet. However if you start the systray app manually after all these spotify and similar things have been already loaded, it wouldn't not lead to the issues described here as far as I know.

It seems to be systray related in the sense that in case the resident part of the systray is present, it "interviews" the apps you're starting, sort of making them open the Sqlite.sas file (to check if they're potential targets?), and that's when things can go awry. It looks like some apps get consumed by bloodlust and that opening is made through System copying/hijacking the Sqlite.sas file and then the file gets locked. If the systray app is not running, this whole shebang does not happen.

I'm not sure messing with the starting order of things would be a good workaround. While it might prevent apps like Spotify (or any other app) cause the permanent file lock at their first start, closing (eg. for freeing up resources) those apps and restarting them later will either require stopping the systray app first and restart it later or unavoidably result in the file lock anyway. Now, not starting the systray app in case you don't need it might be a viable option. Adding the greedy apps to the ignored list also helps (or at least it did for me).

Problem is that closing SA (systray) and Spotify doesn't solve the issue.
The file remains locked by System process, which I identified to be very likely ESET antivir.
It might be a conjunction of the issue identified by you and ESET which takes the handle and not close it.
As the result, once file is being locked on my end, I have to restart the system to release the lock.

What I suggest, SA should give some notification about inability to save settings. Right now it suppresses the issue leaving the user with confidence that changes has been stored.

The trouble is it doesn't know about the issue. The files are virtualized and from the application point of view all I/O operations complete successfully, there are no errors reported by the operating system. That's why you don't see any errors shown on the screen. They are not being suppressed or ignored.

Like I said before, I have reservations that ESET is the issue as I don't see this issue. But I don't run Spotify desktop.

Can you perhaps whitelist *.SAS files in ESET and see if that helps?

I cannot do it on my own, I have to ask UserSupport dep for that.
I going to continue the investigation next week

By the way, not starting the systray app has the unwanted side-effect of NOT checking automatically for updates.

Hello
I think I've found something interesting. It's been after I installed Slack to my computer, and found again, saving SA settings is impossible .
Look at the picture:

SA configuration file is stored into 3 different locations, including Slack and Spotify location. It's weird. Could it be a bug of SA? If you look at those paths closer, it seems like SA config path (AppData/Roaming/SQL Assistant) is added to mentioned packages paths...

For sure, there is a behavior pattern right here.

Edit:
Since we are using Eset Antivirus Software and special security Windows policy against ransom ware, I asked our user support for temporal disabling both of those solutions on my computer. Unfortunately it changed nothing.

My further test has been executed shuffling with Slack.
If Slack is running, SA has no access to overwrite own configuration file located in AppData\Roaming\SQL Assistant\9.5\. I cannot edit this file too.
If Slack is not running (never started after system start, or after exit from the program) SA can overwrite configuration file in own location. I also have access to modify this file
SA files stored in Slack location are unavailable for me even for read. Therefore I cannot compare content of configuration file located here
However I succeeded in removing whole SA directory from Slack location.
And now most creepy thing: SA directory including .log and .sas files is being created in Slack space immediately after Slack start. Such created file has the same size as the in AppData\Roaming\SQL Assistant\9.5\ (reported by Total Commander, because windows properties shows zero) but creation date is about right now, while original file is older.

To me it looks like running Slack/Spotify changes context of AppData somehow. SA intercepts it writing to wrong location. But it's only hypothesis.

I did opposite test:
The recent finding is valid only if SA is running. If not, SA directory is not being created in Slack location.
Starting SA at time Slack is already run doesn't create SA directory in Slack space. It appears after first change to SA configuration.

With regards.

Last edited by michalk on Tue Aug 07, 2018 9:57 am; edited 2 times in total

This is very helpful. Thank you. I have forwarded your screenshot and asked to add to the existing ticket for that issue.

In the meantime I've added a few more findings to my previous post (in case you were answering before I've saved changes)

Hi, it appears a fix for this is pending for release in version 10. A workaround in version 9.x is adding each of these applications to the exception list in SA Options.