This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.

Bug 165406 - Two events for external modified file
Summary: Two events for external modified file
Status: RESOLVED FIXED
Alias: None
Product: platform
Classification: Unclassified
Component: Filesystems (show other bugs)
Version: 6.x
Hardware: Sun All
: P3 blocker (vote)
Assignee: Jaroslav Tulach
URL:
Keywords: RANDOM, REGRESSION
Depends on:
Blocks:
 
Reported: 2009-05-18 14:00 UTC by Vladimir Voskresensky
Modified: 2010-04-17 08:17 UTC (History)
5 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
Simple C++ project I used to reproduce this issue (10.29 KB, application/x-compressed)
2009-05-25 12:35 UTC, mslama
Details
IDE log (24.34 KB, text/plain)
2009-05-29 14:00 UTC, mslama
Details
Test case. (5.25 KB, text/plain)
2009-06-02 11:56 UTC, Jiri Skrivanek
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Vladimir Voskresensky 2009-05-18 14:00:46 UTC
External modification listener gets 2 notifications about the same event (but FileEvent objects are different) during
refactoring Undo:
I'm printing stacks with Exception + number after "T:" shows event.getTime() value

java.lang.Exception: BaseFileObj$FileEventImpl[file=/home/vv159170/NetBeansProjects/Arguments_4/src/args.c,time=Mon May
18 16:53:50 MSD 2009,expected=false] T:1242651230411
        at
org.netbeans.modules.cnd.modelimpl.platform.ModelSupport$ExternalUpdateListener.fileChanged(ModelSupport.java:662)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEventImpl(FCLSupport.java:136)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEvent(FCLSupport.java:122)
        at org.openide.filesystems.FCLSupport.dispatchEvent(FCLSupport.java:99)
        at org.openide.filesystems.FileObject$ED.dispatch(FileObject.java:1052)
        at org.openide.filesystems.FileSystem$EventDispatcher.run(FileSystem.java:925)
        at org.openide.filesystems.EventControl.dispatchEvent(EventControl.java:77)
        at org.openide.filesystems.FileSystem.dispatchEvent(FileSystem.java:544)
        at org.openide.filesystems.FileObject.dispatchEvent(FileObject.java:469)
        at org.openide.filesystems.FileObject.fireFileChangedEvent(FileObject.java:437)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.fireFileChangedEvent(BaseFileObj.java:509)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObj$1.close(FileObj.java:111)
        at java.io.FilterOutputStream.close(FilterOutputStream.java:143)
        at org.openide.filesystems.FileObject$1.close(FileObject.java:635)
        at org.netbeans.modules.refactoring.spi.BackupFacility$DefaultImpl.copy(BackupFacility.java:281)
        at org.netbeans.modules.refactoring.spi.BackupFacility$DefaultImpl.copy(BackupFacility.java:273)
        at org.netbeans.modules.refactoring.spi.BackupFacility$DefaultImpl.restore(BackupFacility.java:231)
        at org.netbeans.modules.refactoring.spi.BackupFacility$DefaultHandle.restore(BackupFacility.java:168)
        at org.netbeans.modules.cnd.refactoring.support.RefactoringCommit.rollback(RefactoringCommit.java:98)
        at org.netbeans.modules.refactoring.api.RefactoringSession.undoRefactoring(RefactoringSession.java:170)
        at org.netbeans.modules.refactoring.spi.impl.UndoManager$SessionUndoItem.undo(UndoManager.java:597)
        at org.netbeans.modules.refactoring.spi.impl.UndoManager.undo(UndoManager.java:221)
        at org.netbeans.modules.refactoring.spi.impl.UndoAction.performAction(UndoAction.java:96)
        at org.openide.util.actions.CallableSystemAction$1.run(CallableSystemAction.java:118)
        at org.netbeans.modules.openide.util.ActionsBridge$ActionRunnable.actionPerformed(ActionsBridge.java:111)
        at org.netbeans.core.ModuleActions.invokeAction(ModuleActions.java:106)
        at org.netbeans.modules.openide.actions.ActionsBridgeImpl.invokeAction(ActionsBridgeImpl.java:53)
        at org.netbeans.modules.openide.util.ActionsBridge$ActionRunnable.doRun(ActionsBridge.java:102)
        at org.netbeans.modules.openide.util.ActionsBridge$1.run(ActionsBridge.java:71)
        at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:576)
        at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1013)


java.lang.Exception: BaseFileObj$FileEventImpl[file=/home/vv159170/NetBeansProjects/Arguments_4/src/args.c,time=Mon May
18 16:53:50 MSD 2009,expected=false] T:1242651230400
        at
org.netbeans.modules.cnd.modelimpl.platform.ModelSupport$ExternalUpdateListener.fileChanged(ModelSupport.java:662)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEventImpl(FCLSupport.java:136)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEvent(FCLSupport.java:122)
        at org.openide.filesystems.FCLSupport.dispatchEvent(FCLSupport.java:99)
        at org.openide.filesystems.FileObject$ED.dispatch(FileObject.java:1052)
        at org.openide.filesystems.FileSystem$EventDispatcher.run(FileSystem.java:925)
        at org.openide.filesystems.EventControl.dispatchEvent(EventControl.java:77)
        at org.openide.filesystems.FileSystem.dispatchEvent(FileSystem.java:544)
        at org.openide.filesystems.FileObject.dispatchEvent(FileObject.java:469)
        at org.openide.filesystems.FileObject.fireFileChangedEvent(FileObject.java:437)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.fireFileChangedEvent(BaseFileObj.java:509)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObj.refreshImpl(FileObj.java:265)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.refresh(BaseFileObj.java:641)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObj.refresh(FileObj.java:274)
        at org.openide.filesystems.FileObject.refresh(FileObject.java:925)
        at org.netbeans.modules.editor.NbEditorUI$1$1.run(NbEditorUI.java:131)
        at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:576)
        at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1013)
Comment 1 Vladimir Voskresensky 2009-05-18 14:07:39 UTC
(this is NetBeans IDE Dev (Build 090518))
Such behavior cause two reparse tasks + 2 reindex tasks run on each external modification
Comment 2 Quality Engineering 2009-05-19 07:30:29 UTC
Integrated into 'main-golden', will be available in build *200905190201* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main-golden/rev/faeecad09ec7
User: Vladimir Voskresensky <vv159170@netbeans.org>
Log: workaround for IZ#165406: Two events for external modified file
Comment 3 Antonin Nebuzelsky 2009-05-19 12:04:38 UTC
The two events are fired only for the file opened in editor, right?

Is this really a regression? Since when?
Comment 4 Vladimir Voskresensky 2009-05-19 16:23:22 UTC
yes, seems two events only for opened in editor (which is the normal case when use refactoring)
+ always double events for:
External updates: fileChanged
BaseFileObj$FileEventImpl[file=/var/tmp/vv159170/cnd-userdir/var/cache/index/s1/timestamps.properties,time=Tue May 19
19:20:02 MSD 2009,expected=false]
External updates: fileChanged
BaseFileObj$FileEventImpl[file=/var/tmp/vv159170/cnd-userdir/var/cache/index/s8/timestamps.properties,time=Tue May 19
19:20:02 MSD 2009,expected=false]

Not sure since when this regression happens, but our testers found that before Undo in refactoring worked fine, while
now sometimes it's broken
Comment 5 Alexander Simon 2009-05-22 13:36:49 UTC
Also two events on file deleted.
File (configuration.xml) does not opened in the editor.
P2 because two events can create races in client code.

java.lang.Exception: Mark to reload project descriptor MakeConfigurationDescriptor@27216062 for project Freeway_1 in
ConfigurationDescriptorProvider@31993421
        at
org.netbeans.modules.cnd.makeproject.api.configurations.ConfigurationDescriptorProvider$ConfigurationXMLChangeListener.resetConfiguration(ConfigurationDescriptorProvider.java:353)
        at
org.netbeans.modules.cnd.makeproject.api.configurations.ConfigurationDescriptorProvider$ConfigurationXMLChangeListener.fileDeleted(ConfigurationDescriptorProvider.java:375)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEventImpl(FCLSupport.java:139)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEvent(FCLSupport.java:122)
        at org.openide.filesystems.FCLSupport.dispatchEvent(FCLSupport.java:99)
        at org.openide.filesystems.FileObject$ED.dispatch(FileObject.java:1014)
        at org.openide.filesystems.FileSystem$EventDispatcher.run(FileSystem.java:925)
        at org.openide.filesystems.EventControl.dispatchEvent(EventControl.java:77)
        at org.openide.filesystems.FileSystem.dispatchEvent(FileSystem.java:544)
        at org.openide.filesystems.FileObject.dispatchEvent(FileObject.java:469)
        at org.openide.filesystems.FileObject.fireFileDeletedEvent(FileObject.java:445)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.fireFileDeletedEvent(BaseFileObj.java:532)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.FolderObj.delete(FolderObj.java:329)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj$2.call(BaseFileObj.java:580)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj$2.call(BaseFileObj.java:575)
        at org.netbeans.modules.masterfs.filebasedfs.FileBasedFileSystem.runAsInconsistent(FileBasedFileSystem.java:112)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.delete(BaseFileObj.java:588)
        at org.openide.filesystems.FileObject.delete(FileObject.java:359)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation.performDelete(DefaultProjectOperationsImplementation.java:135)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation.access$200(DefaultProjectOperationsImplementation.java:98)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation$1.execute(DefaultProjectOperationsImplementation.java:201)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation$6$1.run(DefaultProjectOperationsImplementation.java:655)
        at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:577)
        at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1030)


java.lang.Exception: Mark to reload project descriptor MakeConfigurationDescriptor@27216062 for project Freeway_1 in
ConfigurationDescriptorProvider@31993421
        at
org.netbeans.modules.cnd.makeproject.api.configurations.ConfigurationDescriptorProvider$ConfigurationXMLChangeListener.resetConfiguration(ConfigurationDescriptorProvider.java:353)
        at
org.netbeans.modules.cnd.makeproject.api.configurations.ConfigurationDescriptorProvider$ConfigurationXMLChangeListener.fileDeleted(ConfigurationDescriptorProvider.java:375)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEventImpl(FCLSupport.java:139)
        at org.openide.filesystems.FCLSupport$DispatchEventWrapper.dispatchEvent(FCLSupport.java:122)
        at org.openide.filesystems.FCLSupport.dispatchEvent(FCLSupport.java:99)
        at org.openide.filesystems.FileObject$ED.dispatch(FileObject.java:1014)
        at org.openide.filesystems.FileSystem$EventDispatcher.run(FileSystem.java:925)
        at org.openide.filesystems.EventControl.dispatchEvent(EventControl.java:77)
        at org.openide.filesystems.FileSystem.dispatchEvent(FileSystem.java:544)
        at org.openide.filesystems.FileObject.dispatchEvent(FileObject.java:469)
        at org.openide.filesystems.FileObject.fireFileDeletedEvent(FileObject.java:445)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.fireFileDeletedEvent(BaseFileObj.java:532)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.FolderObj.delete(FolderObj.java:329)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj$2.call(BaseFileObj.java:580)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj$2.call(BaseFileObj.java:575)
        at org.netbeans.modules.masterfs.filebasedfs.FileBasedFileSystem.runAsInconsistent(FileBasedFileSystem.java:112)
        at org.netbeans.modules.masterfs.filebasedfs.fileobjects.BaseFileObj.delete(BaseFileObj.java:588)
        at org.openide.filesystems.FileObject.delete(FileObject.java:359)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation.performDelete(DefaultProjectOperationsImplementation.java:135)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation.access$200(DefaultProjectOperationsImplementation.java:98)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation$1.execute(DefaultProjectOperationsImplementation.java:201)
        at
org.netbeans.modules.project.uiapi.DefaultProjectOperationsImplementation$6$1.run(DefaultProjectOperationsImplementation.java:655)
        at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:577)
        at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1030)
Comment 6 mslama 2009-05-22 14:57:40 UTC
First case file changed event: It looks like file is modified 2 times
a) first when close output stream is called
b) second when explicit fo.refresh is called from NbEditorUI.java

How to reproduce it? Does it happen always or is it random?

I am not sure how fs could merge these two events together. You talk about external modification but actually first is
internal modification when copy is performed. Second modification could be external in such case who performs file
change? I think if there is only internal change which sends first event then fo.refresh should not generate second
event. So it is important to know who performs external modification.

Regarding delete. How do you reproduce? Delete whole project from IDE? Is your listener added once?

Comment 7 Alexander Simon 2009-05-23 07:14:49 UTC
>Regarding delete. How do you reproduce? Delete whole project from IDE? Is your listener added once?
Yes, delete project with sources.
I think listener added once.
Any way listeners shold be kept in waek hash set.
Comment 8 Alexander Simon 2009-05-23 08:00:35 UTC
sorry, typo, weak
Comment 9 mslama 2009-05-25 11:43:13 UTC
I tested with latest dev build, added logging but I get only first file change event, not second one invoked by refresh.
I have simple C++ App project with main.cpp (no VCS). Is there anything special I need to reproduce this? Is it random?
I am on Linux.

  Product Version         = NetBeans IDE Dev (Build 090525)
  Operating System        = Linux version 2.6.28-12-generic running on i386
  Java; VM; Vendor        = 1.6.0_14; Java HotSpot(TM) Client VM 14.0-b15; Sun Microsystems Inc.
  Runtime                 = Java(TM) SE Runtime Environment 1.6.0_14-b07
  Java Home               = /usr/java/jdk1.6.0_14/jre
  System Locale; Encoding = en_US (nb); UTF-8
Comment 10 mslama 2009-05-25 12:34:27 UTC
It looks like there was something more involved perhaps some VCS? (It looks like something is touching file after first
event.)

I attach my simple project. I renamed int variable to k a Undo this change. I added log to
ModelSupport.ExternalUpdateListener.fileChanged.
Comment 11 mslama 2009-05-25 12:35:53 UTC
Created attachment 82731 [details]
Simple C++ project I used to reproduce this issue
Comment 12 mslama 2009-05-25 13:17:39 UTC
Re delete. Yes I get 2 file deleted events: One for nbproject/configurations.xml, second one for
nbproject/private/configurations.xml. It is correct IMO as code adds FCL to both files. If you want to process only one
event (ie. perform reset configuration just once) you must handle this in your code somehow.
Comment 13 Alexander Simon 2009-05-25 14:05:19 UTC
You are right. Make project add listeners on:
- nbproject/configurations.xml
- nbproject/private/configurations.xml

Comment 14 Vladimir Voskresensky 2009-05-25 14:51:30 UTC
please, do not close this IZ after comment from Alexander. 
The original issues is still in place (any file opened in editor's tabs send two events about modification)
Comment 15 mslama 2009-05-29 13:57:49 UTC
Passing back to Jiri. I am not able to reproduce on Linux (2 machines). I am able to reproduce it on Win XP. On Win
simple test case Refactor -> Rename variable and Undo generates 2 file change events. In this case I get file change
event from refresh before second event. It depends when modified flag is set in fs implementation. Second event is sent
on fo's output stream close but depending when fo is considered as modified it might be correct to fire file change
event when someone calls fo.refresh on fo which is already modified. Not sure if it is possible to synchronize this
somehow or if it is possible to fix this. Jiri please look at it soon. Jiri also works on Windows. I will attach my ide log.
Comment 16 mslama 2009-05-29 14:00:46 UTC
Created attachment 82983 [details]
IDE log
Comment 17 mslama 2009-05-29 14:02:31 UTC
Note: In my ide log first event with call stack comes from Refactor -> Rename. Next 2 events come from Refactor -> Undo.
Comment 18 Jiri Skrivanek 2009-06-02 11:55:53 UTC
I am not able to reproduce it in IDE but I can simulate it in a test. It is really possible that fileChanged event is
fired twice for a single change if a thread is closing output stream and other thread calls FileObject.refresh(). It is
not easy to somehow synchronize it because we don't know when operating system stores a new timestamp for modified file.
There is always some delay. Possibly we can remember a timestamp of lastly fired event but this will add extra bytes for
every FileObject instance.
Comment 19 Jiri Skrivanek 2009-06-02 11:56:48 UTC
Created attachment 83095 [details]
Test case.
Comment 20 Vladimir Voskresensky 2009-06-02 12:18:44 UTC
Jiri, on Solaris box with NFS based project it is reproducible from IDE (but have test is much better :-)).

what i've seen in debugger:
- event object has information about last modified time and both event objects have the same time info. Can it be used
to prevent second event? 
Comment 21 Jiri Skrivanek 2009-06-02 12:44:31 UTC
> - event object has information about last modified time and both event objects have the same time info. Can it be used
to prevent second event? 

It is a time when event was created. Thus it can differ even they are two events for the same change.
Comment 22 Vladimir Voskresensky 2009-06-02 15:01:30 UTC
I meant another field.
BaseFileObje$FileEventImpl has field "file" which is "FileObj" with fields
- "lastModified" and "realLastModifiedCached"
And my remark was that duplicated BaseFileObje$FileEventImpl objects (having different "time" field) points to the same
"file" with correct "lastModified" and "realLastModifiedCached" info

Comment 23 Jiri Skrivanek 2009-06-04 09:35:17 UTC
Yes, it would solve this case. Need to say that two consequent changes in one millisecond will fire just one event.
Maybe not issue in real-life but it is often used in tests.
Comment 24 Jaroslav Tulach 2010-04-16 20:23:52 UTC
I am not sure it is feasible to prevent all sorts of event duplications. We are lucky to deliver at least some events...

But I think I can solve the problem with FileChangeEvent: core-main#
7e87916d8faa, as that is by far the most common manifestation of the problem, I think fixing that might be enough.

Thanks Jirko for writing such nice test!
Comment 25 Quality Engineering 2010-04-17 08:17:33 UTC
Integrated into 'main-golden', will be available in build *201004170515* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main/rev/7e87916d8faa
User: Jaroslav Tulach <jtulach@netbeans.org>
Log: #165406: When FileObject.getOutputStream exist, don't generate superfluous change events during refresh