wxFileSystemWatcher: unexpectedly getting inotify events after IN_IGNORED

[dghart]

I inadvertently discovered a way to stress-test the wxGTK wxFileSystemWatcher: run your wxLogTrace-enabled app inside konsole, then set a watch on the file to which konsole logs. Lots of IN_ACCESS events get produced.

This revealed three problems with the current code:

First, IN_Q_OVERFLOW events have a wd of -1, which will currently trigger the 'unknown watch descriptor' wxFAIL_MSG before the 'warnings' section is reached. Also, in the patch committed as r72986, I forgot to 'return' after catching an error or warning; so the event continues to be processed. Both of these errors are fixed in patch1.diff.

Second, I've received occasional non-IN_Q_OVERFLOW events with a wd of -1. Presumably other warnings/errors will have this wd, but for me they've all been IN_ACCESS or IN_CREATE. I don't know why it happens, but patch2.diff adds a wxLogWarning for them.

Third, and rarer, are IN_ACCESS events that arrive just _after_ the wd's IN_IGNORED event. This means that the wd is no longer in the stale-descriptors map, so the wxFAIL_MSG is triggered. I don't know why this can happen but it seems quite sensitive to the amount of tracing that gets logged, so there may be a race condition somewhere. I can't see one in the wx code; perhaps it's in inotify itself.

One fix would be to delay removing the wd after IN_IGNORED, i.e. derive from wxEvtHandler, post an wxEvent when IN_IGNORED arrives and do the removal in the handler. I've successfully tested that here and I could create a patch; but you may feel it's an overreaction to a rare situation.
Meanwhile patch3.diff just changes the wxFAIL_MSG to a less-intrusive wxLogWarning.

[dghart]

patch2.diff adds a wxLogWarning for them.

I've changed my mind about this. I got several -1 IN_MODIFYs, just from watching the dir while rebuilding wxGTK. As wxLogWarning raises the calling app, this is far too intrusive.

I've successfully tested that here and I could create a patch; but you may feel it's an overreaction to a rare situation.

I've changed my mind about this too. Again, just building wxGTK is enough to make this happen, so it's not at all rare for me.

So instead of a wxLogWarning, patch2.diff now sends a notifying wxFileSystemWatcherEvent. patch3.diff now uses wxEvtHandler::CallAfter, which I'd forgotten is now available, to remove watches after a delay.

[vadz]

It's very strange that we can get events after IN_IGNORED, this is really not supposed to happen according to everything I could find :-( But well, if we do get them, we need to be able to do something about it so I'll apply your patches, thanks.

BTW, I've had a brief look at the newest iteration of Linux file change notifications API, fanotify, and it looks like it could make some things simpler. I wonder if it could be worthwhile to try using it instead of inotify for wxFileSystemWatcher...

[vadz]

Wait, just thought about something: wxFileSystemWatcher could be used without a running event loop, couldn't it? In which case, CallAfter() wouldn't work...

So perhaps a simpler and more reliable fix would be to just replace wxFAIL_MSG triggered when we get an event for unknown wd with another wxFSW_EVENT_WARNING event?

[VZ]

(In [73063]) Correct handling of IN_Q_OVERFLOW in wxFileSystemWatcher Linux code.

Don't use wd field if it's -1 which can happen for IN_Q_OVERFLOW.

See #14854.

[VZ]

(In [73064]) Log invalid inotify() events without a valid watch descriptor.

Apparently we can get events without any valid watch descriptor, even though
this is not supposed to happen. At least warn about them.

See #14854.

[dghart]

Replying to vadz:

Wait, just thought about something: wxFileSystemWatcher could be used without a running event loop, couldn't it? In which case, CallAfter() wouldn't work...

I'm fairly sure it can't, at least at present. wxFSWatcherImplUnix::Init checks for an active event loop and asserts if it's not found. Then it uses wxEventLoopBase::AddSourceForFD to monitor the inotify fd.

BTW, I've had a brief look at the newest iteration of Linux file change notifications API, fanotify, and it looks like it could make some things simpler. I wonder if it could be worthwhile to try using it instead of inotify for wxFileSystemWatcher

I've just had an inadequate look at its available information and rumour. It seems to be designed for a different use: permitting/denying changes, rather than just reporting them; and has or had missing features e.g. not reporting file deletion.

[vadz]

I'm still somewhat uncomfortable with this patch, it makes things (slightly) more complex and less predictable/reproducible for not much gain. Is there any real problem with just replacing wxFAIL_MSG with a warning as I wrote instead?

[dghart]

Is there any real problem with just replacing wxFAIL_MSG with a warning as I wrote instead?

That had been my original plan. The problem is that wxLogWarning, at least by default, raises the app. So I would start building wx, which takes a few minutes, and changed desktop to do something else while it compiled. All of a sudden I'd be interrupted by the wxLogWarning telling me something that really isn't that urgent.

It's also not likely to be of interest to the end-user. If modifying a file results in 100 IN_MODIFYs but the user only receives 99 wxFileSystemWatcherEvents as the last IN_MODIFY arrives slightly late, no harm should result.

OTOH there clearly should be some notification, available in a release build too. Another wxLogTrace message will be lost in the crowd. How would you feel about:

wxLog* oldLog = wxLog::SetActiveTarget(new wxLogStderr);
wxLogMessage(" ... ");
delete wxLog::SetActiveTarget(oldLog);

Otherwise I'll redo the patch with a plain wxLogWarning. The caller can always redirect it in his own code, or use wxLogNull.

[vadz]

Sorry, I think there was a misunderstanding. By warning, I meant an event of wxFSW_EVENT_WARNING type, not a wxLogWarning().

[dghart]

Replying to vadz:

Sorry, I think there was a misunderstanding. By warning, I meant an event of wxFSW_EVENT_WARNING type, not a wxLogWarning().

My fault, I somehow managed to read 'wxFSW_EVENT_WARNING' as 'wxLogWarning'.

I'm very happy with sending a wxFSW_EVENT_WARNING event. UnknownDescriptor.diff implements this.

[VZ]

(In [73100]) Warn, don't assert, about unexpected inotify events.

In practice we seem to be getting some unexpected inotify() events during
heavy IO activity. This shouldn't happen but it does, so at least don't
prevent the program from running by popping up the assertion dialog when it
happens.

Closes #14854.