[FIXED v13.10.0120] List Refreshing Disruptions

[TheQwerty]

Code: Select all

v9.90.0601 - 2011-03-29 14:50
    ! Auto-Refresh: Improved on files created by other apps like WinZip.

I believe this change is responsible for the BC drop-list and drop-target selection disappearing when browsing the root of my system drive, as first discovered here.

I'm not sure which program is causing the events which XY responds to - on my configured system it seems to be that just having SyncBackPro running is enough to cause disruptions every second or more frequently, but I have not been able to recreate this in a VM.

For comparison below are two GIFs that show me repeatedly dragging 'New Folder' over 'New Folder-01' and hovering.
In v9.90.0519, when hovering over the drop target it is highlighted and stays that way until I cancel the drag.
In v9.90.0601 the drop target loses its highlight - presumably when the list is repainted - until I hover over the target again.

Enabling Suspend Auto-Refresh does not change the behavior.
However, disabling Auto-Refresh prevents the disruptions from occurring.


While I attempt to recreate the conditions in a VM is there anything else I can do to help you debug this, Don?

v9.90.0519

XY-Repainting-9.90.0519.gif (94.65 KiB) Viewed 2638 times

v9.90.0601

XY-Repainting-9.90.0601.gif (124.25 KiB) Viewed 2638 times

XYplorer: 13.10.0116 (Pro Edition - Lifetime License Pro)
Loaded in: 4,271 ms at 10/21/2013 12:53:36 PM
Uptime: 1 hr, 48 mins, 39 secs
Memory Usage: 55,540 KB, Virtual Memory Size: 32,820 KB

OS: Windows 7 Professional (Service Pack 1), 64-bit (6.1)
OS Uptime: 35 days, 2 hrs, 12 mins, 17 secs
UTC Offset: --04:00
User Role: User
Themes: Yes (Aero)

System Locale ID: 1033
Thread Locale ID: 1033
Default ANSI Code Page: 1252
Active Code Page: 1252 (ANSI - Latin I)
DBCS Code Page: No

DblClick Time: 550 ms
Screen DPI: 96 (100%)
Screen Color Depth: 32
UseDPIAwareIconSizes: No, Yes
Icon Size: small=16, large=32
Icon Size Recommended: small=16, large=32

Command:
CommandW:
Command Normalized:

App: C:\Zen\Apps\XYplorer\XYplorer.exe
Ini File: C:\Zen\Apps\XYplorer\Data\XYplorer.ini
App Data Path: C:\Zen\Apps\XYplorer\Data\
Pane 1 Data Path: C:\Zen\Apps\XYplorer\Data\Panes\Default\
Pane 2 Data Path: C:\Zen\Apps\XYplorer\Data\Panes\AuditTool\
Catalogs Path: C:\Zen\Apps\XYplorer\Data\Catalogs\
Icons Path: C:\Zen\Apps\XYplorer\Data\Icons\
New Items Path: C:\Zen\Apps\XYplorer\Data\NewItems\
Scripts Path: C:\Zen\Apps\XYplorer\Data\Scripts\
Thumbs Cache: C:\Zen\Apps\XYplorer\Data\Thumbnails\
Catalog: C:\Zen\Apps\XYplorer\Data\Catalogs\catalog.dat
Tags Database: C:\Zen\Apps\XYplorer\Data\tag.dat

Language Support: 8.38
Language: No language loaded

[Filehero]

Hi TheQuerty,

wow, great analysis!

Just to make clear: SyncBackPro runs some sync-/backup tasks thereby writing somewhere else in the file system but is leaving C:\ untouched?

Edit: Confirmed. Though it took nearly 30 sec to happen I could reproduce what is shown by the animated gif.

Test:
- created the background file-op noise by copying roughly 30.000 audio-files to a deeper folder of my backup drive via two Windows Explorer instances
- in the root folder of the very same drive I also saw a drop-onto highlight suddenly getting cleared

Auto-Refresh=on, Refresh during file operations doesn't matter. I also have the size column displayed.


Cheers,
Filehero

[TheQwerty]

Just to make clear: SyncBackPro runs some sync-/backup tasks thereby writing somewhere else in the file system but is leaving C:\ untouched?

SyncBackPro is running in the background but none of its profiles are, so it shouldn't be doing anything other than monitoring according to the profile settings.
Where it gets strange is I see the disruptions in XY even if I disable all of the profiles in SyncBack.


Putting Process Monitor on the two processes and doing nothing but typing this message I see that between the two of them procmon is logging tens of thousands of events, even though both are in the background and shouldn't be doing much of anything.

It's a lot of IRP_MJ_* events, mostly IRP_MJ_CLOSE, IRP_MJ_CREATE, IRP_MJ_CLEANUP, and IRP_MJ_DIRECTORY_CONTROL which are completely outside my realm of understanding.

If I kill SyncBack and watch XYplorer.exe:
With auto-refresh enabled I see many of the same events but after minutes there's still fewer than 500.
With auto-refresh disabled I see zero events and have lost patience waiting for them.


Now note that this is my work computer and it is beholden to IT meaning there are AV, disk encryption, monitoring software, TortoiseCVS, and a number of other services and processes that could be cooperating to create this situation. However...
v9.90.0519 does not exhibit these disruptions even when SyncBack is running.
v9.90.0601+ only exhibit these disruptions when SyncBack is running.



My hope is that by identifying the change-sets where this first became an issue it might provide insight for Don in helping track this down - because trying to reproduce it in the VM is becoming frustrating.

[TheQwerty]

Edit: Confirmed. Though it took nearly 30 sec to happen I could reproduce what is shown by the animated gif.

Test:
- created the background file-op noise by copying roughly 30.000 audio-files to a deeper folder of my backup drive via two Windows Explorer instances
- in the root folder of the very same drive I also saw a drop-onto highlight suddenly getting cleared

Auto-Refresh=on, Refresh during file operations doesn't matter. I also have the size column displayed.

Yay!!! I'm not completely losing it!

Thanks for attempting and verifying!

[Filehero]

Thanks for attempting and verifying!

You're welcome!

Missing control: a complete copy run with Auto-Refresh=off was without any signs of abnormality.


Cheers,
Filehero

[TheQwerty]

That only leaves the question of what is SyncBack doing when it shouldn't be doing anything to cause XY to think the list needs refreshed.

Guess I may have to venture to their forums.

[Filehero]

That only leaves the question of what is SyncBack doing when it shouldn't be doing anything to cause XY to think the list needs refreshed.

Bug?

Or by design: limited event messaging and consuming to prevent system overload.

With auto-refresh enabled I see many of the same events but after minutes there's still fewer than 500.

I suppose SyncBack is caching all events in real-time and sends them out at a much lower rate. On XY's side the event consuming might also occur at a constant and limited rate. This could explain the fade out you've observed. However, since SyncBack was killed this 'theory' requires SyncBack's event cache to be a system ressource. Hmm, just speculations.

Well, Don will tell us.


Cheers,
Filehero

[admin]

Sorry, but no clue what's going on. Is the problem still confined to the existence of vertical scrollbars?

Whatever, I tried something.

[admin]

Better now? (v13.10.0118)

[TheQwerty]

Better now? (v13.10.0118)

The BC list no longer closes but the drop-target continues to lose its highlight when the list repaints.


As to the cause of the events that trigger XY to repaint - I now believe it is a combination of SyncBack and Bins, and can recreate it in my VM.

If I start SB without Bins running it behaves and does not show any events in procmon. If Bins is running when I start SB then SB creates all those requests. I believe the reason for this is that SB has a continuous overlay on their taskbar icon and it and Bins start to fight over a bitmap in %appdata%\Microsoft\Internet Explorer\Quick Launch\User Pinned\Settings\IconOverlays\, since this location is one of the ones seeing a lot of hits in procmon during the storms. I'm still not sure exactly what the two of them are doing but it's the combination that causes SB to apparently create all the IRP_MJ* requests.

So that leaves me thinking there is a bug in SB and/or Bins.


However, all of these I/O requests and events which are happening deep on my system drive really shouldn't be having an impact on XY's display of the volume's root - especially in a fresh install - and in the very least XY shouldn't be repainting and disrupting the list when there are not any visible changes.

So there is still a bug, or at least annoyance, in XY too.



To recreate it you need to install SyncBack and Bins.
Unfortunately the latter is not free - I'll buy you a copy if you want to fix this Don.

[admin]

OK, this way you can find out what's going on:

You can log the events that are causing an auto-refresh in XYplorer.

1. Switch on the logger. There are 3 possible output channels:

Switch on the logger and output to msgbox:
::logchange 1;
Switch on the logger and output to debuglog:
::logchange 5;
Switch on the logger and output to status bar:
::logchange 9;

Note: output to debuglog is the preferred method since it does not block
the flow of messages like with msgbox, and you can see all messages (not
just one like with status bar.

Note: output to status bar will only be supported in v13.10.0120 and later.

2. (Do what you got to do to) Let the action happen.

3. If you did output to debuglog, this is the way to show the debuglog:
::text get("debuglog");

[TheQwerty]

EDIT: These aren't much different than the log I'm replacing but I tried to let everything sit for around a minute before taking the next action.

This also shows the difference that the start order makes, since SyncBack continues to spew updates even when Bins is closed.

Archives includes two log files.

[admin]

Code: Select all

v9.90.0601 - 2011-03-29 14:50
    ! Auto-Refresh: Improved on files created by other apps like WinZip.

I believe this change is responsible for the BC drop-list and drop-target selection disappearing when browsing the root of my system drive, as first discovered here.

Brilliant analysis! The responsible code goes even back a bit further:

Code: Select all

v9.11.0009 - 2010-05-25 20:33
    ! Auto-updating of Icon Overlays should be improved.

These two changes together led to a lot of superfluous list refreshes (at least when processes like SyncBack constantly fire update events in some deep sub folder of the current drive) which will not happen again in the next version. Great find!

[TheQwerty]

These two changes together led to a lot of superfluous list refreshes (at least when processes like SyncBack constantly fire update events in some deep sub folder of the current drive) which will not happen again in the next version. Great find!

Nice - really glad you could fix this!

Confirmed that v13.10.0120 is showing no disruptions in my main config or a fresh copy in my host OS.
I cannot verify it works in the VM because I had to enable networking to install Bins yesterday and now it is installing 128 updates.


There's probably no reason to do so but with that fixed are you going to back out this change?

Code: Select all

v13.10.0118 - 2013-10-22 16:10
     ! Breadcrumbs: Dropdown vanished when list was auto-refreshed. 
       Attempt to limit this somewhat.

[admin]

IMO no need to verify in virtual machine.

There's probably no reason to do so but with that fixed are you going to back out this change?

Code: Select all

v13.10.0118 - 2013-10-22 16:10
     ! Breadcrumbs: Dropdown vanished when list was auto-refreshed. 
       Attempt to limit this somewhat.

No, it can be useful e.g. when something is being downloaded into the current list, so a constant list refresh is justified.