View Issue Details

IDProjectCategoryView StatusLast Update
0022015LazarusIDEpublic2012-06-03 12:29
ReporterLudo BrandsAssigned ToMartin Friebe 
PrioritynormalSeveritymajorReproducibilitysometimes
Status closedResolutionfixed 
Product Version1.1 (SVN)Product Build 
Target VersionFixed in Version1.1 (SVN) 
Summary0022015: Division by zero when closing editor files
DescriptionClosing multiple files with Ctrl F4 raises sometimes a division by zero exception. Happened twice in last week.

Console output:
ERROR in LCL: TNBPages.Get Index out of bounds
Creating gdb catchable error:

  $004C1D2D TLAZLOGGER__DEBUGLNSTACK, line 676 of lazloggerbase.pas
  $0043CF4C DUMPSTACK, line 1406 of lclproc.pas
  $0043C54B RAISEGDBEXCEPTION, line 864 of lclproc.pas
  $0055B923 TNBPAGES__GET, line 56 of ./include/customnotebook.inc
  $007F327B TSOURCEEDITOR__UPDATEPAGENAME, line 4275 of sourceeditor.pp
  $007F95E0 TSOURCENOTEBOOK__UPDATEPAGENAMES, line 5951 of sourceeditor.pp
  $007FC921 TSOURCENOTEBOOK__CLOSEFILE, line 7017 of sourceeditor.pp
  $008038C7 TSOURCEEDITORMANAGER__CLOSEFILE, line 9321 of sourceeditor.pp
  $0046072B TMAINIDE__DOCLOSEEDITORFILE, line 9499 of main.pp
TApplication.HandleException Division by zero
  Stack trace:
  $0043C575 RAISEGDBEXCEPTION, line 865 of lclproc.pas
  $0055B923 TNBPAGES__GET, line 56 of ./include/customnotebook.inc
  $007F327B TSOURCEEDITOR__UPDATEPAGENAME, line 4275 of sourceeditor.pp
  $007F95E0 TSOURCENOTEBOOK__UPDATEPAGENAMES, line 5951 of sourceeditor.pp
  $007FC921 TSOURCENOTEBOOK__CLOSEFILE, line 7017 of sourceeditor.pp
  $008038C7 TSOURCEEDITORMANAGER__CLOSEFILE, line 9321 of sourceeditor.pp
  $0046072B TMAINIDE__DOCLOSEEDITORFILE, line 9499 of main.pp
  $0044A2A7 TMAINIDE__MNUCLOSECLICKED, line 3062 of main.pp
  $006F5C02 TIDECOMMAND__EXECUTE, line 961 of idecommands.pas
  $0044B826 TMAINIDE__ONPROCESSIDECOMMAND, line 3522 of main.pp
  $007FDE16 TSOURCENOTEBOOK__PROCESSPARENTCOMMAND, line 7479 of sourceeditor.p
p
  $007EF617 TSOURCEEDITOR__PROCESSUSERCOMMAND, line 3210 of sourceeditor.pp
  $0098674B TCUSTOMSYNEDIT__DOONPROCESSCOMMAND, line 6523 of synedit.pp
  $009836F7 TCUSTOMSYNEDIT__COMMANDPROCESSOR, line 5923 of synedit.pp
  $00977672 TCUSTOMSYNEDIT__KEYDOWN, line 2713 of synedit.pp
  $0058F286 TWINCONTROL__KEYDOWNBEFOREINTERFACE, line 5540 of ./include/wincon
trol.inc
  $0058F51C TWINCONTROL__DOKEYDOWNBEFOREINTERFACE, line 5669 of ./include/winc
ontrol.inc



Additional Informationlazarus 37146 with fpc trunk.
TagsNo tags attached.
Fixed in Revision37273, 37471
LazTarget-
Widgetset
Attached Files
  • sourceeditor_close_log.patch (1,844 bytes)
    Index: ide/sourceeditor.pp
    ===================================================================
    --- ide/sourceeditor.pp	(revision 37254)
    +++ ide/sourceeditor.pp	(working copy)
    @@ -4260,10 +4260,12 @@
       NewPageName: String;
     begin
       if SourceNotebook.FUpdateLock > 0 then begin
    +debugln('UpdatePageName DEFER ',DbgS(self));
         include(SourceNotebook.FUpdateFlags, ufPageNames);
         exit;
       end;
       p:=SourceNotebook.FindPageWithEditor(Self);
    +debugln(['UpdatePageName ',p,' ',Dbgs(self)]);
       if EditorOpts.ShowTabNumbers and (p < 10) then
         // Number pages 1, ..., 9, 0 -- according to Alt+N hotkeys.
         NewPageName:=Format('%s:%d', [FPageName, (p+1) mod 10])
    @@ -7001,7 +7003,7 @@
       TempEditor:=FindSourceEditorWithPageIndex(APageIndex);
       if TempEditor=nil then exit;
       WasSelected:=PageIndex=APageIndex;
    -  //debugln(['TSourceNotebook.CloseFile ',TempEditor.FileName,' ',TempEditor.APageIndex]);
    +  debugln(['TSourceNotebook.CloseFile ',TempEditor.FileName,' ',TempEditor.PageIndex,' ', APageIndex, DbgS(TempEditor)]);
       EndIncrementalFind;
       TempEditor.Close;
       NoteBookDeletePage(APageIndex); // delete page before sending notification senEditorDestroyed
    @@ -7400,6 +7402,7 @@
       CaretXY: TPoint;
       TopLine: Integer;
     Begin
    +debugln(['TSourceNotebook.NotebookPageChanged ']);
       if (not assigned(Manager)) or (FUpdateLock > 0) Then begin
         Include(States, snNotbookPageChangedNeeded);
         exit;
    @@ -7409,7 +7412,7 @@
       if (FHintWindow <> nil) and FHintWindow.Visible then
         HideHint;
     
    -  //debugln('TSourceNotebook.NotebookPageChanged ',Pageindex,' ',TempEditor <> nil,' fAutoFocusLock=',fAutoFocusLock);
    +  debugln(['TSourceNotebook.NotebookPageChanged ',Pageindex,' ',TempEditor <> nil,' fAutoFocusLock=',fAutoFocusLock]);
       if TempEditor <> nil then
       begin
         if not TempEditor.Visible then begin
    
  • log.zip (2,471 bytes)
  • log-14.05.2012-12.18.53.931000.zip (23,081 bytes)
  • log2.zip (1,798 bytes)
  • log3.zip (16,245 bytes)
  • log4.zip (10,076 bytes)
  • log5.zip (13,828 bytes)
  • log6.zip (9,411 bytes)

Relationships

related to 0022172 closedMartin Friebe Division by zero when closing editor files 

Activities

2012-05-12 14:45

 

sourceeditor_close_log.patch (1,844 bytes)
Index: ide/sourceeditor.pp
===================================================================
--- ide/sourceeditor.pp	(revision 37254)
+++ ide/sourceeditor.pp	(working copy)
@@ -4260,10 +4260,12 @@
   NewPageName: String;
 begin
   if SourceNotebook.FUpdateLock > 0 then begin
+debugln('UpdatePageName DEFER ',DbgS(self));
     include(SourceNotebook.FUpdateFlags, ufPageNames);
     exit;
   end;
   p:=SourceNotebook.FindPageWithEditor(Self);
+debugln(['UpdatePageName ',p,' ',Dbgs(self)]);
   if EditorOpts.ShowTabNumbers and (p < 10) then
     // Number pages 1, ..., 9, 0 -- according to Alt+N hotkeys.
     NewPageName:=Format('%s:%d', [FPageName, (p+1) mod 10])
@@ -7001,7 +7003,7 @@
   TempEditor:=FindSourceEditorWithPageIndex(APageIndex);
   if TempEditor=nil then exit;
   WasSelected:=PageIndex=APageIndex;
-  //debugln(['TSourceNotebook.CloseFile ',TempEditor.FileName,' ',TempEditor.APageIndex]);
+  debugln(['TSourceNotebook.CloseFile ',TempEditor.FileName,' ',TempEditor.PageIndex,' ', APageIndex, DbgS(TempEditor)]);
   EndIncrementalFind;
   TempEditor.Close;
   NoteBookDeletePage(APageIndex); // delete page before sending notification senEditorDestroyed
@@ -7400,6 +7402,7 @@
   CaretXY: TPoint;
   TopLine: Integer;
 Begin
+debugln(['TSourceNotebook.NotebookPageChanged ']);
   if (not assigned(Manager)) or (FUpdateLock > 0) Then begin
     Include(States, snNotbookPageChangedNeeded);
     exit;
@@ -7409,7 +7412,7 @@
   if (FHintWindow <> nil) and FHintWindow.Visible then
     HideHint;
 
-  //debugln('TSourceNotebook.NotebookPageChanged ',Pageindex,' ',TempEditor <> nil,' fAutoFocusLock=',fAutoFocusLock);
+  debugln(['TSourceNotebook.NotebookPageChanged ',Pageindex,' ',TempEditor <> nil,' fAutoFocusLock=',fAutoFocusLock]);
   if TempEditor <> nil then
   begin
     if not TempEditor.Visible then begin

Martin Friebe

2012-05-12 14:49

manager   ~0059518

Please apply the patch, and run with --debug-log=C:\log.txt. Upload the log after the crash happened.

- "Closing multiple files" refers to "one after the other"?
  Does "speed" have an impact. Does the crash happen, if there is a one second pause between each close?
- Do you use any (which) docking mgr?
- Do you have one or multiply Source Editor Windows open
- Which version of Windows

Ludo Brands

2012-05-12 15:20

developer   ~0059522

>"Closing multiple files" refers to "one after the other"?
Yes. Cleaning up the ide after a long debugging session withe lazarus and fpc debug build
> Does "speed" have an impact. Does the crash happen, if there is a one second pause between each close?
No. Speed is important. Had crashes before since months (without this debug info, reason why I didn't report it before) but always under the same circumstances. On top of that, my system has a slow disk and is rather low on memory (a lot of swapping). It is very well possible the ide isn't keeping up with the key strokes when this happens.
> Do you use any (which) docking mgr?
No
> Do you have one or multiply Source Editor Windows open
No
> Which version of Windows
XP sp 2

> Please apply the patch
I'll report back when it happens again.

Martin Friebe

2012-05-12 15:58

manager   ~0059526

Thanks, if it may be speed related you may wan to try a "sleep(300);" in strategic places, such as, first line of:
Procedure TSourceNotebook.NotebookPageChanged(Sender: TObject);
procedure TSourceNotebook.CloseFile(APageIndex:integer);
procedure TCustomSynEdit.WMKillFocus(var Msg: TWMKillFocus);
procedure TCustomSynEdit.WMSetFocus(var Msg: TLMSetFocus);


This will any changing of editors. But it could force the IDE to get sufficiently behind. (It'll be a killer to close the IDE...)

It didn't help me getting the error, but I am on Vista.

Ludo Brands

2012-05-12 16:46

developer   ~0059530

> (It'll be a killer to close the IDE...)

It never happened when closing the IDE or changing projects. Only when closing the editor files with Ctrl F4.

> It didn't help me getting the error, but I am on Vista.

I can't reproduce it at will neither.

Martin Friebe

2012-05-13 03:46

manager   ~0059546

Do you remember if this happens:
- only if the debugger is running
- only if not
- both

If not, please make note of it in future cases.

If it is while the debugger is running, what state is it in?
- running (app is running)
- paused (at breakpoint or otherwise)

Ludo Brands

2012-05-13 08:45

developer   ~0059548

I only remember the last time: finished debugging a program, opened a new program (20+ files in the editor) and closed several of them. So no active debugging session.

Martin Friebe

2012-05-13 12:11

manager   ~0059556

Can you run the IDE in the debugger and see, if anything calls Application.ProcessMessages when you close/change a tab?
You need a LCL with debug info to set the breakpoint on ProcessMessages.

Martin Friebe

2012-05-14 00:29

manager   ~0059570

The issue appears to be caused by TSourceNotebook.CloseFile being re-entered to close a 2nd tab, while closing the first tab is between:
- NoteBookDeletePage // whic removes the Tab
and
- TempEditor.Free; // which removes the Editor from the internal list.

Therefore during the inner run, the editor for the outer run exists but has no tab. This is not handled in UpdatePageNames

This issue could have been caused by the debugger, which would be called in NoteBookDeletePage, to load line info (blue dots) for the newly activated tab.
The debugger issues Application.ProcessMessages
This part has been fixed in r37273

Ludo Brands

2012-05-14 09:31

developer   ~0059575

The problem happened again. Closing windows inside a debug session (debugger break). Attached the log. I deleted the 46500 first lines which are probably of no interest;) I kept the full log if needed.

I'll update lazarus now. Since I rarely turn of my computer but hibernate it overnight, I had hibernation on my list of suspecting factors and didn't wan't to restart lazarus this morning in the hope the error would reproduce.

Since the error occurs in the conditions you described and is probably fixed, I suggest you mark the issue as resolved. I'll wait a week or 2 before closing it in case it re-happens. In the mean time I continue logging with your "sourceeditor_close_log" patch.

Thanks.

2012-05-14 09:32

 

log.zip (2,471 bytes)

Cyrax

2012-05-14 11:51

reporter   ~0059576

Free Pascal trunk 2.7.1-r21290, Lazarus trunk 1.1-r37273.

When closing editor files during debug session via mouse right button click -> "Close page", I get SIGSEGV. If I close them via mouse middle button click, all works as excepted.

Attached file (log-14.05.2012-12.18.53.931000.zip) contains both log files which gives more info.

2012-05-14 11:51

 

log-14.05.2012-12.18.53.931000.zip (23,081 bytes)

Ludo Brands

2012-05-14 14:24

developer   ~0059579

This time a different crash with r37273. Breakpoint hit. Close with ctrl-f4 several windows. No problem. Hit F7 to step to next instruction: Exception Control 'SynEdit7' has no parent window

Log2.zip attached.

2012-05-14 14:24

 

log2.zip (1,798 bytes)

Martin Friebe

2012-05-14 14:36

manager   ~0059580

@Cyrax: Your issue is not related. I committed a fix in r37274. If it should happen again, please open a new issue.

Some info: It is *not* triggered by closing the tab, nor by the debugger. It is triggered by activating a window (popup activates SourceEditor)

Cyrax

2012-05-14 23:13

reporter   ~0059596

OK. It did happen again, so I created separate issue for it. See http://bugs.freepascal.org/view.php?id=22035

Martin Friebe

2012-05-17 15:17

manager   ~0059668

@Ludo:
As for the first issue, has it happen again? (since the change)

As for the 2nd issue. I can not reproduce it. Please compile SourceEditor.pp with VerboseFocus defined. (Define it only in SourceEditor, otherwise many other units will add a lot of logging).
Then supply a log when the error happens.

Also start the IDE with --debug-enable=DBG_CMD_ECHO,DBGMI_QUEUE_DEBUG

Ludo Brands

2012-05-17 15:51

developer   ~0059671

Reproduced a problem immediately after rebuilding and running as requested.
Breakpoint hit. Close with ctrl-f4 several windows. No problem. Hit several times F8 to step to next instruction. After several steps: Bad Index Exception.
Log3.zip attached.

2012-05-17 15:52

 

log3.zip (16,245 bytes)

Martin Friebe

2012-05-17 16:01

manager   ~0059675

Last edited: 2012-05-17 16:04

Sorry, that appears to bo yet another issue.
 TApplication.HandleException Bad index
    Stack trace:
    $00AF0DED TEXTENDEDNOTEBOOK__BEGINDRAGTAB, line 487 of extendednotebook.pas
    $00AEFCC2 TEXTENDEDNOTEBOOK__MOUSEMOVE, line 191 of extendednotebook.pas

Please keep trying for the "no parent window"

Please additional to the above defines, define: ExtNBookDebug
Then if you hit this again, please open a new bug

Ludo Brands

2012-05-17 16:25

developer   ~0059677

Where do you want me to put the ExtNBookDebug? I have put it with --debug-enable=DBG_CMD_ECHO,DBGMI_QUEUE_DEBUG since it is not used in SourceEditor.pp and you referred to "additional to the above defines". The bad index problem occurred again but I don't see any additional info in the log so I guess the define has to be defined somewhere else. Extendednotebook.pas?

Martin Friebe

2012-05-17 16:41

manager   ~0059678

Either global defines (config build laz) or $DEFINE on top of components\lazcontrols\extendednotebook.pas

Ludo Brands

2012-05-17 17:42

developer   ~0059681

The Bad index problem isn't easily reproducible anymore since the define. Crashed however with an access violation in TSOURCEEDITOR__UNBINDEDITOR. Don't ask me what exactly lead to this. I have been closing windows, single stepping, closing newly opened windows, etc to reproduce a crash. Unfortunately I clicked on cancel instead of close and hope the log was flushed correctly. The stack trace is in there but not the exception in the exception. log4.zip contains the last 3000 lines out of almost 200.000 lines.

2012-05-17 17:43

 

log4.zip (10,076 bytes)

Martin Friebe

2012-05-17 21:19

manager   ~0059695

Please upgrade to 37310. A added more logs.

--debug-enable=DBG_CMD_ECHO,DBGMI_QUEUE_DEBUG,SRCED_LOCK,SRCED_OPEN,SRCED_CLOSE,SRCED_PAGES

keep ExtNBookDebug defined / you can drop VerboseFocus

The "Bad Index" in ExtNotebook might be fixed. I added a couple of checks.

Ludo Brands

2012-05-18 09:40

developer   ~0059702

Thanks. Updated lazarus and running with debug flags indicated. So far so good.

Ludo Brands

2012-06-01 09:11

developer   ~0060101

2 weeks without a single problem. I'm going to turn off the debugging flags now starting with ExtNBookDebug. The "Bad Index" went away when that one was defined.

Martin Friebe

2012-06-01 11:25

manager   ~0060103

As in 0022015:0059695 >>The "Bad Index" in ExtNotebook might be fixed. I added a couple of checks.<<

Also the original trace might be fixed (at least one reason was found and fixed). Note 0022015:0059570 (I don't know, if in 0022015:0059575 you had updated)

That would leave the "Exception Control 'SynEdit7' has no parent window" from 0022015:0059579

Please remember: If you have a stack-trace, with some lines address only, send your lazarus.exe (the same build, that throw the error). Then I might be able to resolve some of them (you can do, using leak-view, but then you can not copy the result)

Ludo Brands

2012-06-01 12:42

developer   ~0060104

Last edited: 2012-06-01 12:46

Just hit the Exception "Control 'SynEdit15' has no parent window". Log attached.
ExtNBookDebug not defined.
Debugging lazarus debugger in lazarus. Breakpoint hit. Closed several windows and hit F8 several times. First F8 took an awful long time to come back, reason why I hit several times the key thinking the IDE ignored it, clicked also on "Step Over" button and entered also F7. Then "life came back". Stepped over several code lines and then stopped with above exception.
Edit: svn 37401 with some local mods. I sent you the diff before and am testing a new mod in gdbmidebugger.pp

2012-06-01 12:43

 

log5.zip (13,828 bytes)

Martin Friebe

2012-06-01 14:29

manager   ~0060108

Ok, I can reproduce.

The actual issue happens, when you switch to a tab, and close it *while* the blue dots are loaded.

In your case that happened long before the error. The error is only displayed, when the debugger returned the line info (that takes time in gdb, if files are big).

The huge timeout you got, was because every time you closed a tab, another tab was made visible. And line info requested. Those requests piled up, while you kept closing tabs. By the time the debugger did the step (F8), you had again queued further line-info requests....

Even if (to be implemented...) requests gets cancelled, if the file is closed (closed in all windows), the problem will still exist, if you just view each tab for a moment...

Martin Friebe

2012-06-01 16:25

manager   ~0060113

Fixed the "no parent window" in 37471

Please test, and close if ok.

Ludo Brands

2012-06-02 11:21

developer   ~0060145

A new "division by zero". Same circumstances as Note 0060104. svn 37471.
log6.zip attached.

2012-06-02 11:22

 

log6.zip (9,411 bytes)

Issue History

Date Modified Username Field Change
2012-05-12 13:54 Ludo Brands New Issue
2012-05-12 13:54 Ludo Brands Widgetset => Win32/Win64
2012-05-12 14:45 Martin Friebe File Added: sourceeditor_close_log.patch
2012-05-12 14:49 Martin Friebe LazTarget => -
2012-05-12 14:49 Martin Friebe Note Added: 0059518
2012-05-12 14:49 Martin Friebe Assigned To => Martin Friebe
2012-05-12 14:49 Martin Friebe Status new => feedback
2012-05-12 15:20 Ludo Brands Note Added: 0059522
2012-05-12 15:58 Martin Friebe Note Added: 0059526
2012-05-12 16:46 Ludo Brands Note Added: 0059530
2012-05-13 03:46 Martin Friebe Note Added: 0059546
2012-05-13 08:45 Ludo Brands Note Added: 0059548
2012-05-13 12:11 Martin Friebe Note Added: 0059556
2012-05-14 00:29 Martin Friebe Note Added: 0059570
2012-05-14 09:31 Ludo Brands Note Added: 0059575
2012-05-14 09:32 Ludo Brands File Added: log.zip
2012-05-14 11:51 Cyrax Note Added: 0059576
2012-05-14 11:51 Cyrax File Added: log-14.05.2012-12.18.53.931000.zip
2012-05-14 14:24 Ludo Brands Note Added: 0059579
2012-05-14 14:24 Ludo Brands File Added: log2.zip
2012-05-14 14:36 Martin Friebe Note Added: 0059580
2012-05-14 23:13 Cyrax Note Added: 0059596
2012-05-17 15:17 Martin Friebe Note Added: 0059668
2012-05-17 15:51 Ludo Brands Note Added: 0059671
2012-05-17 15:52 Ludo Brands File Added: log3.zip
2012-05-17 16:01 Martin Friebe Note Added: 0059675
2012-05-17 16:04 Martin Friebe Note Edited: 0059675
2012-05-17 16:25 Ludo Brands Note Added: 0059677
2012-05-17 16:41 Martin Friebe Note Added: 0059678
2012-05-17 17:42 Ludo Brands Note Added: 0059681
2012-05-17 17:43 Ludo Brands File Added: log4.zip
2012-05-17 21:19 Martin Friebe Note Added: 0059695
2012-05-18 09:40 Ludo Brands Note Added: 0059702
2012-06-01 09:11 Ludo Brands Note Added: 0060101
2012-06-01 11:25 Martin Friebe Note Added: 0060103
2012-06-01 12:42 Ludo Brands Note Added: 0060104
2012-06-01 12:43 Ludo Brands File Added: log5.zip
2012-06-01 12:46 Ludo Brands Note Edited: 0060104
2012-06-01 14:29 Martin Friebe Note Added: 0060108
2012-06-01 14:31 Martin Friebe Status feedback => assigned
2012-06-01 16:25 Martin Friebe Fixed in Revision => 37273, 37471
2012-06-01 16:25 Martin Friebe Widgetset Win32/Win64 =>
2012-06-01 16:25 Martin Friebe Status assigned => resolved
2012-06-01 16:25 Martin Friebe Fixed in Version => 1.1 (SVN)
2012-06-01 16:25 Martin Friebe Resolution open => fixed
2012-06-01 16:25 Martin Friebe Note Added: 0060113
2012-06-02 11:21 Ludo Brands Status resolved => assigned
2012-06-02 11:21 Ludo Brands Resolution fixed => reopened
2012-06-02 11:21 Ludo Brands Note Added: 0060145
2012-06-02 11:22 Ludo Brands File Added: log6.zip
2012-06-02 13:12 Martin Friebe Status assigned => resolved
2012-06-02 13:12 Martin Friebe Resolution reopened => fixed
2012-06-02 13:29 Ludo Brands Status resolved => closed
2012-06-02 16:27 Martin Friebe Status closed => resolved
2012-06-02 22:03 Martin Friebe Relationship added related to 0022172
2012-06-03 12:29 Ludo Brands Status resolved => closed