The Plastic SCM GUI occasionally freezes for 5-10 seconds when switching tabs

[Mikael Kalms]

Hi,

over the past month-or-two several of the developers on my team have noticed that, occasionally, the Plastic SCM GUI freezes for a couple of seconds when switching between tabs in the UI. The frequency which I observe this myself at is - say, 2-3 times over the past month, but I work only rarely within the editor. Others experience it more often.

In the most recent case, the freeze occurred when I switched from a Branch Explorer view to a Pending Changes view by pressing Shift-Tab. The GUI froze for about 7 seconds. After that, I could switch back and forth freely without seeing any freezes.

I run Plastic SCM with file system watching enabled. I have Plastic configured to determine file differences based on file hash, not just timestamp. I had sum total of 1 changed file on the machine.

 

When I look within the Plastic SCM application log, I notice a sequence - about 7 seconds in length, which corresponds to the freeze I experienced - with entries like this:

2020-10-13 22:15:22,240 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - Watcher <REDACTED1> - Processing change b for <REDACTED2>
2020-10-13 22:15:22,240 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher <REDACTED1>. Speed: 1 events/s
2020-10-13 22:15:22,312 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher. Event path:<REDACTED3> type:Changed
2020-10-13 22:15:22,312 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher <REDACTED1>. Speed: 2 events/s
2020-10-13 22:15:22,312 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - Watcher <REDACTED1> - Processing change a for <REDACTED4>
2020-10-13 22:15:22,685 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher. Event path:'<REDACTED2>' type:Changed
2020-10-13 22:15:22,685 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher <REDACTED1>. Speed: 3 events/s
2020-10-13 22:15:22,685 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - Watcher <REDACTED1> - Processing change a for <REDACTED2>
2020-10-13 22:15:22,689 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher. Event path:<REDACTED5> type:Deleted
2020-10-13 22:15:22,690 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher <REDACTED1>. Speed: 4 events/s
2020-10-13 22:15:22,690 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher. Event path:<REDACTED5> type:Renamed
2020-10-13 22:15:22,690 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher <REDACTED1>. Speed: 5 events/s
2020-10-13 22:15:22,691 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher. Event path:<REDACTED6> type:Changed
2020-10-13 22:15:22,691 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher <REDACTED1>. Speed: 6 events/s
2020-10-13 22:15:22,690 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - Watcher <REDACTED1> - Processing change c for <REDACTED7>
2020-10-13 22:15:22,691 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - Watcher <REDACTED1> - Processing change d for <REDACTED7>
2020-10-13 22:15:22,692 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - Watcher <REDACTED1> - Processing change a for <REDACTED8>
2020-10-13 22:15:22,936 KALMSHOMEDESKTO\Kalms DEBUG WatcherFsNodeReader - FsWatcher. Event path:<REDACTED3> type:Changed

No associated errors. It appears that the FsWatcher processed 33 changes in 7 seconds. That sounds low to me.

6 of those 33 changes are for a file that is ~45MB in size. All the other changes are for much smaller files (1MB or smaller), as far as I can tell.

Is there any chance that the FsWatcher is related to the stalls we are experiencing?

[calbzam]

Hi Mikael,

Do you have any user who is able to easily reproduce it?

The log information you are attaching is everything for the same second (not 7 seconds). Could you attach the full log and let us know the stimated time when the freeze happened?

Regards,

Carlos.

[Mikael Kalms]

We are not able to easily reproduce it, sorry. The general repro steps are:

1. do a bunch of work in other applications

2. switch to Plastic SCM (which is already running)

3. switch tab within Plastic

then, at step 3, sometimes there is a multi-second freeze.

 

I have attached a redacted & cut-down version of the Plastic SCM logfile. Since I shut down the Plastic SCM client shortly after experiencing the freeze, I believe that the interesting part starts at 2020-10-13 22:15:20,498 .

If you want the full, unredacted log, let me know and I will file a support ticket + include the log file.

log_redacted.txt

[Mikael Kalms]

Side note; one of my colleague reports that this happens to him multiple times per day. Once I have some more logs I will provide them to you via a support ticket.

[calbzam]

Quote

Side note; one of my colleague reports that this happens to him multiple times per day. Once I have some more logs I will provide them to you via a support ticket.

If you somehow find a reproducible scenario, we would like to get connected with him.

You can temporary disable the FsWatcher with the following setting in your "client.conf" (although I still don't have any certany that this is the problem).

<WatcherEnabled>no</WatcherEnabled>

Regards,

Carlos.

[Mikael Kalms]

One in our team disabled the FsWatcher. It made no difference.

We do not have a reproducible scenario. We observe it happen during regular work. It is always after having been busy in other programs and switching back to Plastic SCM. Sometimes directly after alt-tab. sometimes at the first tab switch within Plastic SCM. When the freeze has occurred once, it will not happen again until we switch to other programs and work elsewhere for a while.

I am personally experiencing this 1-3 times per day now (because I am doing more hands-on work than I used to). Freezes last typically 2-4 seconds for me.

[calbzam]

Hi,

Could you include some new client logs and reported the estimated time when thje issue happens?

I'm guessing the client has something cached and at some point it needs to connect again to the server. But we should see some clue in the logs. Are you using a remote on-premise server?

Regards,

Carlos.

[Mikael Kalms]

We are using a cloud server. I have provided four logs via ticket #23929.