Author Topic: Bug: Autosave lockup while trying to restore  (Read 9341 times)

chrisant

  • Senior Community Member
  • Posts: 1410
  • Hero Points: 131
Bug: Autosave lockup while trying to restore
« on: March 25, 2008, 03:59:22 am »
SE 12.0.3 r35, on Vista Ultimate:

While using the Regex Evaluator, I locked up SE at 100% CPU (I had a regex that appeared to match the whole line but I thought should match two separate substrings in the line, and it occurred to me that depending on how the regex is evaulated it could match three times that overlapped each other, so I appended \c to the regex to see if that would help, but SE went to 100% CPU and Ctrl+Shift+Alt+F2 could not break in).  I killed SE.

When I restarted SE, it went to 100% CPU again.  Ctrl+Shift+Alt+F2 gave me a stack:

Quote
c.ex 4337 _clex_skip_blanks(m)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 2066 c_smartpaste(0,1,733)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 1305 e_smartpaste(0,1,733)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 4819 static(3488,C,,,1,e,1)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 4573 static(3488,24,C,,,1,e,1)   p_window_id: 5   p_object: OI_FORM  p_name:
smartp.ex 566 static(24,C,,1)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 118 smart_paste(24,C,,1,)   p_window_id: 15   p_object: OI_FORM   p_name:
stdcmds.ex 15497 _copy_or_move(24,C)   p_window_id: 15   p_object: OI_FORM   p_name:
stdcmds.ex 15335 copy_to_cursor(24)   p_window_id: 15   p_object: OI_FORM   p_name:
put.ex 447 get(c:\slick\config\autosave\FindIn.e,,A,0,0,)   p_window_id: 15   p_object: OI_FORM   p_name:
autosave.ex 2155 static()   p_window_id: 15   p_object: OI_FORM   p_name:
 Slick-C STACK TRACE ******************************
 Created on 3/24/2008 at 20:19:29 (335 ms)

After some poking around and using another instance of vs.exe to edit and recompile autosave.e with debug trace output, I found that it is trying to recover an autosaved file, but it gets into an infinite loop inside _autosave_check:

Code: [Select]
static void _autosave_check()
{
   if ((def_as_flags & AS_SAMEFN)) return;
   // For each of the buffers, check for an autosave file.
   int orig_view_id;
   get_window_id(orig_view_id);
messageNwait('BEFORE-BEFORE:  orig_view_id='orig_view_id', p_buf_id='p_buf_id);
   activate_window(VSWID_HIDDEN);
   _safe_hidden_window();
   //activate_window orig_view_id
   int orig_buf_id = p_buf_id;
messageNwait('BEFORE:  p_buf_id='p_buf_id', p_buf_name="'p_buf_name'" ... '_time());
   int count=0;
   for (;;) {
      _str filename=_mkautosave_filename();
      if (filename!='') {
         typeless bfiledate=_file_date(filename,'B');
         if (bfiledate!='' && p_file_date<bfiledate) {
            typeless p=p_line;save_pos(p);
            _lbclear();
            get(maybe_quote_filename(filename),'','A');
            //p_modify=1;  get() will set ModifyFlags to 1
            ++count;
            //message_up=1;messageNwait('p_buf_name='p_buf_name'p='p);message_up=0;
            restore_pos(p);
         }
      }
      _next_buffer('hr');
messageNwait('NEXT:  next buffer='p_buf_id' ... '_time());
      if (p_buf_id == orig_buf_id) {
         break;
      }
   }
   p_window_id=orig_view_id;
   if (count) {
      refresh();
      message_up=1;
      _message_box("AutoSave has detected an abnormal exit.  The window/buffer configuration has been restored.  Modified files have been restored to last AutoSave.");
      message_up=0;
   }
}

The BEFORE-BEFORE: message shows orig_view_id=15, p_buf_id=9.
The BEFORE: message shows p_buf_id=0, p_buf_name=".command".
The NEXT: message cycles through p_buf_id=7, 8, 9, 7, 8, 9, 7, 8, 9, ... and never gets back to 0, so it never breaks out of the loop.

I could detect the cycle using any of the typical cycle detection algorithms (e.g. a hash table, tortoise and hare, countdown, etc), but p_buf_id starts as 9 which gets hit repeatedly during the cycle, so I'm certain there is a better fix that avoids the cycle altogether.  Can a Slick team member suggest an elegant fix?  For the moment I've used a workaround to put the visited buffer ids in a hash table and break when it finds a collision, because that's a quick'n'simple surefire workaround.  But it's not a very nice solution.

As an aside:  The hash table successfully broke out of the loop, and then I discovered that the autosave file was unexpectedly empty (only contained a single blank line, and confirmed that the autosave disk file was only two bytes).
« Last Edit: March 25, 2008, 04:21:45 am by chrisant »

chrisant

  • Senior Community Member
  • Posts: 1410
  • Hero Points: 131
Re: Bug: Autosave lockup while trying to restore
« Reply #1 on: March 25, 2008, 05:40:01 am »
Additional:  The hash table successfully breaks out of the loop, but the autosave file is not actually getting restored properly -- it basically replaces the entire buffer with a single blank line.

I confirmed with a couple tests:
  • The autosave file starts out correct on disk.
  • I kill SlickEdit.
  • Confirm the autosave file is still correct on disk.
  • Launch SlickEdit.
  • --> The autosave file and the buffer in memory are both truncated to a single blank line.
I'm still debugging through why that's happening.

These seem like such basic bugs in autosave, but is autosave broken in general right now or is it just my install that's broken?  If these can't be reproduced by the Slick team, I'll try to track down further what settings/etc are contributing to the problems.

chrisant

  • Senior Community Member
  • Posts: 1410
  • Hero Points: 131
Re: Bug: Autosave lockup while trying to restore
« Reply #2 on: March 25, 2008, 08:34:55 am »
Aha, victory:
  • 100% consistent lockup with a stock SE 12.0.3 installation.  The only settings I changed were:  selected CUA emulation, enabled autosave.
  • Smart paste needs to be disabled in _autosave_check().  After working around the infinite cycle bug, if smart paste is on then the file gets truncated to a single blank line on restore.  But turn off smart paste, and the file gets restored correctly.  Edit: actually I get only intermittent success turning off smart paste, but see below...

Here is a stack from when c_smartpaste() gets called while restoring the autosaved file (I injected a call to a function that doesn't exist).  The stack shows that in _copy_or_move() the arg(3) was interpreted as true, though I don't understand how since as far as I can see the caller only passed two arguments.  And when I injected some say() calls to dump arg(), arg(1), arg(2), arg(3), and arg(4) it shows that arg(3) and arg(4) are empty.

Quote
Stack trace written to file: c:\tmp\vsstack
 Procedure callFunctionThatDoesNotExist not found
smartp.ex 1945 c_smartpaste(0,1,64)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 4824 static(3489,C,,,1,c,1)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 4578 static(3489,23,C,,,1,c,1)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 566 static(23,C,,1)   p_window_id: 5   p_object: OI_FORM   p_name:
smartp.ex 118 smart_paste(23,C,,1,)   p_window_id: 15   p_object: OI_FORM   p_name:
stdcmds.ex 15497 _copy_or_move(23,C)   p_window_id: 15   p_object: OI_FORM   p_name:
stdcmds.ex 15335 copy_to_cursor(23)   p_window_id: 15   p_object: OI_FORM   p_name:
put.ex 447 get(c:\slick\config\autosave\foo.cpp,,A,0,0,)   p_window_id: 15   p_object: OI_FORM   p_name:
autosave.ex 2181 static()   p_window_id: 15   p_object: OI_FORM   p_name:
« Last Edit: March 25, 2008, 09:11:48 am by chrisant »

chrisant

  • Senior Community Member
  • Posts: 1410
  • Hero Points: 131
Re: Bug: Autosave lockup while trying to restore
« Reply #3 on: March 25, 2008, 10:31:52 pm »
I made two workarounds, and now _autosave_check() works on my system.
Here are my workarounds, but I think the Slick team can probably make better fixes.

In the autosave.e file (12.0.3 r35):
Code: [Select]
static void _autosave_check()
{
   if ((def_as_flags & AS_SAMEFN)) return;
   // For each of the buffers, check for an autosave file.
   int orig_view_id;
   get_window_id(orig_view_id);
boolean visited_buffers:[]; // chrisant: temp fix for infinite cycle
   activate_window(VSWID_HIDDEN);
   _safe_hidden_window();
   //activate_window orig_view_id
   int orig_buf_id = p_buf_id;
   int count=0;
   for (;;) {
if (visited_buffers._indexin(p_buf_id)) break; // chrisant: temp fix for infinite cycle
visited_buffers:[p_buf_id] = true; // chrisant: temp fix for infinite cycle
      _str filename=_mkautosave_filename();

In the stdcmds.e file (12.0.3 r35):
Code: [Select]
int _copy_or_move(...)
{
   int status=0;
   typeless markid=arg(1);
   typeless copymove_option=arg(2);
   typeless do_smartpaste=arg(3);
   typeless support_deselect=arg(4);
if (arg() < 3) do_smartpaste=false;    // chrisant: temp fix for autosave recovery
if (arg() < 4) support_deselect=false; // chrisant: temp fix for autosave recovery
   if (do_smartpaste) {

Lee

  • SlickEdit Team Member
  • Senior Community Member
  • *
  • Posts: 1299
  • Hero Points: 130
Re: Bug: Autosave lockup while trying to restore
« Reply #4 on: March 26, 2008, 01:17:06 pm »
There may or may not be a problem in autosave, I'm not so certain of that yet, so let's back up to the start of all this.  My theory is that the Regex Evaluator went into to an unbreakable loop.  I'm thinking that the by repositioning the cursor (\c token) it locked in tight repeat_search on the same line text over and over and over again, and never reaching the end of the document/buffer.  That's definitely a bug, I'm filing a defect to address that.  Now the text markup that the Evaluator does is done on a timer event, and Ctrl+Shift+Alt+F2 does not breaks timer events, Ctrl+Shift+Alt+F9 does break the interpreter on timer events.  Autosave also runs on a timer event, which may be why that appeared in the stack trace instead.  It's also possible that after all that, your state file is just toast.  The regular expression and search settings are not restored because the Regex timer didn't return, and there's may be handful of state globals that in a bad state.  That said, restarting from a fresh configuration may be necessary, or at least start with a fresh default state file in your config, deleting vslick.sta in your configuration directory will force the default one to copy there.

I'll continue to read through the rest of the posts, and see if I can identify any issues with autosave as you describe.

chrisant

  • Senior Community Member
  • Posts: 1410
  • Hero Points: 131
Re: Bug: Autosave lockup while trying to restore
« Reply #5 on: March 26, 2008, 05:28:11 pm »
To clarify:  the stack above was not from the regex evaluator hang -- the hang didn't surprise me that much, I mean sure it's a bug, but it's one that makes sense and isn't surprising.

It was when I tried to restart Slick that I ran into the autosave restore problem.  That's when I broke in and got the stack.  I am able to repro the autosave restore problem 100% on multiple machines with a completely fresh install of SE, so I don't think the autosave restore problem has anything to do with the regex hang.

To repro the autosave restore problem:
0.  Fresh install of SE.
1.  Start SE (click through the post install stuff).
2.  Turn on autosave, 10 seconds (to make the repro go faster ;-)).
3.  Open a file.
4.  Change a line.
5.  Wait for the file to show up in the autosave location.
6.  Kill SE (e.g. via Task Manager).
7.  Start SE.
EXPECTED:  SE starts and recovers the autosaved file.
ACTUAL:  SE goes to 100% CPU and user never gets control back.

Good to know about the C+A+S+F9, I'll try that in the future, thanks.

HTH,
C

Lee

  • SlickEdit Team Member
  • Senior Community Member
  • *
  • Posts: 1299
  • Hero Points: 130
Re: Bug: Autosave lockup while trying to restore
« Reply #6 on: March 26, 2008, 07:01:39 pm »
Thank you for clarifying and narrowing down the issue, things make more sense now.  I was able to repro this and will file a defect.  You've already coded around it so I'll work on getting this into 13.0.1 release.