Opus 12.6 - File list not updating for local/network/ftp folders

I think I should maybe make sure that we're clear on something where perhaps I've recently introduced some confusion.

We're seeing that changes we make to files/folders (e.g. rename, create, delete,..) using Opus 12.6 are not being reflected in the Opus file list window reliably.

If I made it seem like I'm reporting that changes made outside Opus are not reflected in Opus that's not what I meant to convey. Opus isn't showing "its own" changes reliably. It also doesn't reliably show changes made outside of Opus, either but that's not the specific issue I was trying to focus on.

On then same PCs or different PCs?
You use dopus to change a file name then on another pc you don’t see that change until you refresh?

Best thing to do is log what happens when making some changes outside of Opus, and then also some inside of Opus.

If you use file/folder names that indicate which you're doing at the time (internal or external changes), that will help us know which is which when examining the logs.

I was able to install the debug version of Opus on Saturday night but so far I've been unable to catch it not updating the file list so I don't yet have any new output to send to you. Because of that I've left it installed on the server. So far no one has reported any slowness with it so I'm hoping I can leave it there until I catch the problem while it's happening again.

I've been able to catch the problem happening again and I've send the DebugView LOG file to crashdumps@gpsoft.com.au.

It should contain records for the creation of 50 folders by a process running outside of Opus and 2 folders created within Opus. The creation of these folders was not reflected in the Opus file list window. The time was ~12:10 pm.

The folders created outside Opus where named like r:\sastemp\ test_2017-10-02_hh-mm-ss

The folders created inside Opus where named like createdinOpus_x

Many thanks for the new log file.

Is the log filtered in any way? Either after generating it, or from DebugView itself?

It appears to be missing a lot of lines, both based on what is (and is not) included in the log, and based on the line numbers.

e.g. The line numbers in the first column should be consecutive, but there are large gaps throughout:

00229518	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229526	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229534	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229542	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229554	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229565	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229573	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229581	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229589	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229597	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229605	12:11:16 PM	[37528] [54108] dopus: FileDisplay...
00229613	12:11:16 PM	[37528] [54108] dopus: FileDisplay...

If you click 200dpi_wc10392_Dbgview on DebugView's toolbar, it will show you if it is filtering things:

200dpi_wc10393_Dbgview

The Reset button there will clear any filters that had been applied.

If the log was filtered, is it possible to get a copy of the original, or to generate a new log without filtering?

Leo, it was filtered to include only events in the parent folder. that filter was in place in the first capture, too. I was trying to weed out stuff I didn't think would be relevant. I can generate a new one but I'll have to look through it for confidential information and remove or obfuscate it.

That explains the "impossible" output we were seeing with events missing. :slight_smile:

We need an unfiltered log, please.

I'm working on a new unfiltered log....just waiting for a time when I catch the issue happening again

An unfiltered DebugView log file has been sent to crashdumps@gpsoft.com.au.

As before 50 folders were created outside Opus and 2 folders were created within Opus. None appeared until the file list was manually refreshed.

The folders created outside Opus where named like r:\sastemp\ test_2017-10-02_hh-mm-ss

The folders created inside Opus where named like createdinOpus_x

1 Like

Many thanks! The new logs look very useful and have given us some theories as to what is happening. We still need to test those more, but should have something for you to try later in the week.

Thanks. I think I have some new information to include. I am trying to do some file cleanup on the server today using the Opus Search feature and it's not returning files that I know exist. This is happening at the same time that it's not updating the file window with file deletes/renames/...

I search the entire c:\ for *.log and it finds no matches yet WinDirStat says there are 22,884 *.log files on the c:\ drive and Windows Explorer finds ~22K *.log files.

Even a search for star.star returns nothing. for some reason I couldn't use the actual symbol here.

Yes, I am including the option to 'use wildcards'.

I'm seeing other odd behavior with the Search feature today.

A new search completes FAR too quickly, returns no results (there should be results), and doesn't clear the previous results even though 'clear previous results' is checked.

I don't know if these are for sure related to the issue that's the focus of this thread but I'm mentioning it in case it helps.

That probably is not related. Such issues are usually just due to the Find panel being misconfigured in some way.

Please start a new thread for it and post a screenshot of the Find panel as you have it set up, and another showing some things you expect it to find that it doesn't see.

I believe the problem you have been seeing is a combination of two things:

  • A fairly large number of events being generated on the machine (although it is not excessively large, so this is not enough on its own).
  • A fairly loaded, multi-user machine where Opus may not always get much uninterrupted CPU time and is frequently preempted by other CPU work. (It could also be caused by very high contention for disk or other resources, virtual memory swapping, etc. I can't tell the exact bottleneck from the logs, only that there appears to be one.)

That combination appears to be causing your Opus windows to be unable to process the changes as fast as they are happening.

We have added two new settings which allow you to tweak how long Opus will process change events for at a time, and my hope is that changing these will solve the problem in your environment.

I have sent a private message with a link to a new test version, which has two new settings:

  • notify_max_time

    The maximum amount of time, in milliseconds, each file display will spend processing change notifications from the filesystem before considering other inputs and events.

    Defaults to 50 milliseconds. In rare situations, you may need to raise this from its default value if events are being generated faster than they are consumed. You can also specify 0 (zero) to process change events indefinitely, although you would probably only want to do so as a test, not as a permanent setting. If this is set to zero, or set too high, file displays could become less responsive to user input when a lot of filesystem events are being generated.

    This is a global setting. If you change it for one user on a machine then it will affect all other users, as is most likely required. On a multi-user system, if the setting is changed by one user, the others will not see the change until they restart Opus.

  • notify_min_items

    The minimum number of events to process before checking the notify_max_time time limit. See the description of notify_max_time, above, for situations where you may wish to raise this, and how the setting behaves for multiple users.

This test version won't output extra debug information like the previous one, as I don't think we will need it now. (Or, if we do, it will likely be different information that we need to look at.)

Initially, the test version will behave the same as older versions, as the new settings need to be changed to make a difference.

When you are able to, please install the new test version and change Preferences / Miscellaneous / Advanced: notify_max_time to 200 as an initial test.

If you still find there are times when changes don't appear (or take a very long time to appear; more than ~4 seconds), try setting it even higher, or set it to 0 (zero).

The higher you go the more possible it is for the file display to become slow to respond to user input while dealing with a flood of events, but the faster it will process the events in turn.

You probably won't need to change notify_min_items, the second setting, unless you find that you need to use really large values (or zero) for the first setting to make a difference. In that eventuality, please post here and we can make recommendations.

Many thanks for your time and help testing this, as always!

Leo,

Thanks for working on this with me. I very much appreciate your time and effort. I'd really like to understand more about how some kind of resource contention (CPU, memory, disk) could be behind this. I struggle to understand how that could be the explanation given the following couple of facts. I'm not trying to argue it's not the cause; I'm really just trying to make sense of the facts at hand.

  1. Opus 11 on the same server with the same number of users didn't exhibit this (over a very long period of time)
  2. I have observed the issue late at night when I am the only user logged on to the server. I really struggle to see how there could be any contention issues when I'm the only logged on.

I will schedule another maintenance window as soon as I can and install this latest version with the suggested configuration settings and see how it goes.

Again, thank you for your help with this. We've been a long time business customer and massive fan of Directory Opus.

Jason

It's hard to say exactly what the cause is from the logs, but we can see the change notification processing in the file display running out of time almost every time it processes a batch of events, leaving more events for the next run, and it looks like the events keep piling up as a result.

There's also a point where there is a 2 second gap between two events being processed from the same batch, which is a little strange.

It's possible there is more to it than that, but I don't want to speculate until the initial theory is tested.

Thanks for the reply. Again, I want to be clear that I'm not arguing against the theory; I'm just trying to reconcile it against the facts that don't quite seem to fit.

I have an especially hard time understanding how it should be CPU contention issues. It's pretty hard to imagine it could be disk contention, either. I just saw it happening when the CPU %idle performance counter was >90% and the disk queue was <0.01. I'm less confident about a memory contention issue (mostly because I don't really understand all the ways you can have a memory contention issue) but if there was a memory issue I'd still have trouble understanding why the issue sometimes occurs when I'm the only logged on user on a 64-bit Windows server with 64 GB of RAM. If I have a memory contention issue in that scenario I'd really be at a loss to know what to do about it.

I can also add that I have observed that at a time when Opus was failing to reflect real-time file changes Windows Explorer was showing those same changes in real-time.

Anyway, let's see what the new version does.

Thank you, again

Jason

Something we've been struggling with here is trying to identify any significant differences between Opus 11 and 12 in the file change notification code. There really don't seem to be any - certainly nothing obvious that could account for the different behavior you're seeing.

There's also the fact that this doesn't seem to be a general problem with Opus 12; maybe we have one or two similar reports but for a whole organisation to have it on all their machines seems very odd.

Is there any other software you can think of that you have installed - antivirus springs to mind, but maybe other "corporatey" type tools might be involved too - where you may have previously "whitelisted" Opus 11 in some way? I.E. is it possible the difference in behavior between 11 and 12 that you're seeing could be due to something else on the affected systems treating the two versions differently in some way?

Jon, thanks for your message. To clarify for you we're having the issue on a single Windows Server 2008 R2 server where we all log in and use various applications including Opus. I have not deployed Opus 12 to the user's individual machines (due to this issue, to be honest).

Nothing else about the server changed at the time Opus 11 was upgraded to Opus 12 and I'm not excluding Opus from AV scanning (which of course does happen on the server). However, I will investigate this idea that something on the server itself could be contributing.

I can add that I've been watching the CPU consumption of the various instances of dopus.exe on the server today and I noticed many times that they are all using quite a lot more CPU than I normally saw with Opus 11. Normally, Opus 11's EXE was showing <0.01% in Process Monitor and today I've seen it be the case that every instance was using much more than that (all of them all showing unusual levels at the same time, as I write this it's happening).