Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Crash when defterm handoff'ing a bat file? #15245

Closed
zadjii-msft opened this issue Apr 26, 2023 · 10 comments · Fixed by #15298
Closed

Crash when defterm handoff'ing a bat file? #15245

zadjii-msft opened this issue Apr 26, 2023 · 10 comments · Fixed by #15298
Labels
Area-DefApp In-PR This issue has a related PR Issue-Bug It either shouldn't be doing this or needs an investigation. Needs-Tag-Fix Doesn't match tag requirements Product-Conhost For issues in the Console codebase Severity-Blocking We won't ship a release like this! No-siree. Severity-Crash Crashes are real bad news.

Comments

@zadjii-msft
Copy link
Member

  1. Terminal preview 1.18.1041
  2. Save the following as a bat file:
    echo foo
    
    for /L %%i  IN (0,1,100000) DO echo Line %%i 
    
    pause
  3. add "windowingBehavior": "useAnyExisting",
  4. Set Terminal Preview as the default terminal
  5. Open a Terminal window
  6. double click the .bat in file explorer
  7. OpenConsole crashes into the post-mortem debugger‼️

Other bat files are fine?

It also doesn't crash if you run it manually?

@zadjii-msft zadjii-msft added Issue-Bug It either shouldn't be doing this or needs an investigation. Product-Terminal The new Windows Terminal. Area-DefApp labels Apr 26, 2023
@microsoft-github-policy-service microsoft-github-policy-service bot added the Needs-Triage It's a new issue that the core contributor team needs to triage at the next triage meeting label Apr 26, 2023
@zadjii-msft zadjii-msft removed the Needs-Triage It's a new issue that the core contributor team needs to triage at the next triage meeting label Apr 26, 2023
@zadjii-msft zadjii-msft added this to the Terminal v1.18 milestone Apr 27, 2023
@zadjii-msft zadjii-msft added Severity-Crash Crashes are real bad news. Product-Conhost For issues in the Console codebase and removed Product-Terminal The new Windows Terminal. labels Apr 27, 2023
@zadjii-msft
Copy link
Member Author

Oh and it worked fine on 1.16.10262.0

@zadjii-msft
Copy link
Member Author

............ aaaaaand it works fine in a dev build. I'm guessing this is just more of my machine's "defterm is messed up yo". That or 1041 had bugs (not unlikely)

@zadjii-msft zadjii-msft closed this as not planned Won't fix, can't repro, duplicate, stale Apr 27, 2023
@zadjii-msft zadjii-msft removed this from the Terminal v1.18 milestone Apr 27, 2023
@microsoft-github-policy-service microsoft-github-policy-service bot added the Needs-Tag-Fix Doesn't match tag requirements label Apr 27, 2023
@zadjii-msft zadjii-msft added Resolution-No-Repro We couldn't get this to happen, or it stopped happening entirely. and removed Needs-Tag-Fix Doesn't match tag requirements labels Apr 27, 2023
@microsoft-github-policy-service microsoft-github-policy-service bot added the Needs-Tag-Fix Doesn't match tag requirements label Apr 27, 2023
@zadjii-msft
Copy link
Member Author

HMMMMMM I GOT IT TO HAPPEN AGAIN

image
image

0:007> k
 # Child-SP          RetAddr               Call Site
00 000000c2`3dcfeb00 00007ff6`4c02586a     OpenConsole!TextBuffer::GetRowByOffset+0x61 [D:\dev\public\terminal\src\buffer\out\textBuffer.cpp @ 96] 
01 000000c2`3dcfeb50 00007ff6`4c01e576     OpenConsole!Microsoft::Console::VirtualTerminal::AdaptDispatch::_DoLineFeed+0x3da [D:\dev\public\terminal\src\terminal\adapter\adaptDispatch.cpp @ 2161] 
02 000000c2`3dcfed60 00007ff6`4c05e6e1     OpenConsole!Microsoft::Console::VirtualTerminal::AdaptDispatch::LineFeed+0xa6 [D:\dev\public\terminal\src\terminal\adapter\adaptDispatch.cpp @ 2207] 
03 000000c2`3dcfedb0 00007ff6`4c05a39d     OpenConsole!Microsoft::Console::VirtualTerminal::OutputStateMachineEngine::ActionExecute+0x211 [D:\dev\public\terminal\src\terminal\parser\OutputStateMachineEngine.cpp @ 75] 
04 000000c2`3dcfeeb0 00007ff6`4c05c926     OpenConsole!`Microsoft::Console::VirtualTerminal::StateMachine::_ActionExecute'::`2'::<lambda_1>::operator()+0x6d [D:\dev\public\terminal\src\terminal\parser\stateMachine.cpp @ 393] 
05 000000c2`3dcfef00 00007ff6`4c05770f     OpenConsole!Microsoft::Console::VirtualTerminal::StateMachine::_SafeExecute<`Microsoft::Console::VirtualTerminal::StateMachine::_ActionExecute'::`2'::<lambda_1> >+0x26 [D:\dev\public\terminal\src\terminal\parser\stateMachine.cpp @ 2054] 
06 000000c2`3dcfef50 00007ff6`4c058787     OpenConsole!Microsoft::Console::VirtualTerminal::StateMachine::_ActionExecute+0x5f [D:\dev\public\terminal\src\terminal\parser\stateMachine.cpp @ 391] 
07 000000c2`3dcfefa0 00007ff6`4c056ccb     OpenConsole!Microsoft::Console::VirtualTerminal::StateMachine::_EventGround+0x67 [D:\dev\public\terminal\src\terminal\parser\stateMachine.cpp @ 990] 
08 000000c2`3dcfefe0 00007ff6`4c056ff1     OpenConsole!Microsoft::Console::VirtualTerminal::StateMachine::ProcessCharacter+0x17b [D:\dev\public\terminal\src\terminal\parser\stateMachine.cpp @ 1740] 
09 000000c2`3dcff040 00007ff6`4bd3c912     OpenConsole!Microsoft::Console::VirtualTerminal::StateMachine::ProcessString+0x171 [D:\dev\public\terminal\src\terminal\parser\stateMachine.cpp @ 1856] 
0a 000000c2`3dcff1e0 00007ff6`4bd3cb79     OpenConsole!WriteChars+0x282 [D:\dev\public\terminal\src\host\_stream.cpp @ 770] 
0b 000000c2`3dcff2b0 00007ff6`4bd3ce7e     OpenConsole!DoWriteConsole+0x219 [D:\dev\public\terminal\src\host\_stream.cpp @ 837] 
0c 000000c2`3dcff3c0 00007ff6`4bd3a561     OpenConsole!WriteConsoleWImplHelper+0x13e [D:\dev\public\terminal\src\host\_stream.cpp @ 878] 
0d 000000c2`3dcff450 00007ff6`4bf8ca03     OpenConsole!ApiRoutines::WriteConsoleWImpl+0x121 [D:\dev\public\terminal\src\host\_stream.cpp @ 1110] 
0e 000000c2`3dcff540 00007ff6`4bf9bc52     OpenConsole!ApiDispatchers::ServerWriteConsole+0x3d3 [D:\dev\public\terminal\src\server\ApiDispatchers.cpp @ 420] 
0f 000000c2`3dcff7d0 00007ff6`4bf87ec0     OpenConsole!ApiSorter::ConsoleDispatchRequest+0x242 [D:\dev\public\terminal\src\server\ApiSorter.cpp @ 178] 
10 000000c2`3dcff8b0 00007ff6`4bf871a4     OpenConsole!IoDispatchers::ConsoleDispatchRequest+0x20 [D:\dev\public\terminal\src\server\IoDispatchers.cpp @ 593] 
11 000000c2`3dcff8e0 00007ff6`4bc6da4e     OpenConsole!IoSorter::ServiceIoOperation+0xe4 [D:\dev\public\terminal\src\server\IoSorter.cpp @ 33] 
12 000000c2`3dcff960 00007ffc`5bd6292d     OpenConsole!ConsoleIoThread+0x28e [D:\dev\public\terminal\src\host\srvinit.cpp @ 1061] 

Wow that all looks super fucked.

@zadjii-msft zadjii-msft reopened this May 4, 2023
@microsoft-github-policy-service microsoft-github-policy-service bot removed the Needs-Tag-Fix Doesn't match tag requirements label May 4, 2023
@zadjii-msft
Copy link
Member Author

AND there are crashes for this that aren't just me!
MSFT:44310564 is {a4569db1-0940-c9d3-8768-caa7607e965c} a

@zadjii-msft zadjii-msft added Severity-Blocking We won't ship a release like this! No-siree. and removed Resolution-No-Repro We couldn't get this to happen, or it stopped happening entirely. labels May 4, 2023
@zadjii-msft zadjii-msft added this to the Terminal v1.18 milestone May 4, 2023
@zadjii-msft
Copy link
Member Author

zadjii-msft commented May 4, 2023

Oh dear

In the PtySignal thread:

[0x9]   OpenConsole!LockConsole + 0x2e   
[0xa]   OpenConsole!Microsoft::Console::PtySignalInputThread::_DoResizeWindow + 0x48   
[0xb]   OpenConsole!Microsoft::Console::PtySignalInputThread::_InputThread + 0x21c   
[0xc]   OpenConsole!Microsoft::Console::PtySignalInputThread::StaticThreadProc + 0x2a   
[0xd]   KERNEL32!BaseThreadInitThunk + 0x1d   

The signal thread is waiting for a chance to resize the conpty to (in this case) (0x52,0x19). BUT IT KEEPS ON GOING ANYWAYS. It's printed 26 lines... to.. the... textbuffer?

I'd reckon this might even be the root cause of #14512. There's a miscommunication between the Terminal and conpty on how big it should be.

@zadjii-msft
Copy link
Member Author

Interesting. Looking through the dump, the text buffer of OpenConsole!Microsoft::Console::Interactivity::ServiceLocator::s_globals.ciConsoleInformation.pCurrentScreenBuffer does actually look sane

0:007> dx -r1 (*((OpenConsole!std::unique_ptr<TextBuffer,std::default_delete<TextBuffer> > *)0x20e19689b98))
(*((OpenConsole!std::unique_ptr<TextBuffer,std::default_delete<TextBuffer> > *)0x20e19689b98))                 [Type: std::unique_ptr<TextBuffer,std::default_delete<TextBuffer> >]
    [<Raw View>]     [Type: std::unique_ptr<TextBuffer,std::default_delete<TextBuffer> >]
    [+0x000] _renderer        : 0x20e19687520 [Type: Microsoft::Console::Render::Renderer &]
    [+0x008] _hyperlinkMap    : { size=0x0 } [Type: std::unordered_map<unsigned short,std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::hash<unsigned short>,std::equal_to<unsigned short>,std::allocator<std::pair<unsigned short const ,std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > > > >]
    [+0x058] _hyperlinkCustomIdMap : { size=0x0 } [Type: std::unordered_map<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,unsigned short,std::hash<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::equal_to<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > >,std::allocator<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,unsigned short> > >]
    [+0x0a8] _currentHyperlinkId : 0x1 [Type: unsigned short]
    [+0x0b0] _idsAndPatterns  : { size=0x0 } [Type: std::unordered_map<unsigned __int64,std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >,std::hash<unsigned __int64>,std::equal_to<unsigned __int64>,std::allocator<std::pair<unsigned __int64 const ,std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > > > >]
    [+0x100] _currentPatternId : 0x0 [Type: unsigned __int64]
    [+0x108] _charBuffer      [Type: wistd::unique_ptr<enum std::byte,wil::virtualalloc_deleter>]
    [+0x110] _storage         : { size=30 } [Type: std::vector<ROW,std::allocator<ROW> >]
    [+0x130] _currentAttributes [Type: TextAttribute]
    [+0x13c] _firstRow        : 0 [Type: int]
    [+0x140] _cursor          [Type: Cursor]
    [+0x170] _size            : {LT(0, 0) RB(119, 29) [120 x 30]} [Type: Microsoft::Console::Types::Viewport]
    [+0x180] _isActiveBuffer  : true [Type: bool]

It's the one in the actual adapter call that looks messed up.

I don't think anyone can go through and change the screen buffer while the ConsoleIO thread is processing that string, but maybe I'm just bad at windbg:

image

@zadjii-msft
Copy link
Member Author

Thoughts while trying to fall asleep:

  • Maybe defterm should always make a new window (not glom). We could add a separate compatibility.allowDefaultTerminalGlomming: false to re-enable if users REALLY want
    • We've got tear-out now. We can always just re-attach
  • maybe defterm should pass the requested size of the pty TO the terminal handler, so that the terminal starts at the size the conpty does
  • ALTERNATIVELY, the terminal handler could give back to the pty how big it should start
    • This would probably pretty negatively impact pty startup time though. Don't love that.
  • None of this remedies the issue where this adapter call is getting mysteriously dispatched to a text buffer that doesn't exist?

@zadjii-msft
Copy link
Member Author

Let's assume my windbg skills around pointers/refs is just bad. REGARDLESS, in this call to AdaptDispatch::_DoLineFeed,

  • bufferHeight is 9001, which would imply that was evaluated BEFORE the console host got itself into conpty mode. That should have resized the buffer to something smaller (probably 30 rows).
  • textBuffer.GetRowByOffset is literally called on L2126, and there it didn't divide by zero. SO
  • the textBuffer got changed between L2126 and L2161. How?
  • ApiRoutines::WriteConsoleWImpl takes the lock
  • currentPosition.y == bottomMargin == 29
  • topMargin=0 !> viewport.top=0
  • viewport.bottom=30 < bufferHeight=9001 -> true
    • _api.SetViewportPosition calls to ApiRoutines::SetConsoleWindowInfoImpl
      • the first thing that does is take the console lock. Hmm. Now that this lock is a ticket_lock, is the lock re-entrant? Yea okay it's a recursive_ticket_lock
      • Then it does
          if (g.getConsoleInformation().IsInVtIoMode())
          {
              // SetViewportRect doesn't cause the buffer to resize. Manually resize the buffer.
              RETURN_IF_NTSTATUS_FAILED(context.ResizeScreenBuffer(Viewport::FromInclusive(Window).Dimensions(), false));
          }
    • AHA
    • That's a call to SCREEN_INFORMATION::ResizeScreenBuffer, which found that gci._bWrapText was true, then called ResizeWithReflow, which sure enough, replaces the text buffer.

@zadjii-msft
Copy link
Member Author

NOW here's a question. Why was the original text buffer 9001 rows tall? Did something happen to not immediately replace the text buffer?

If CONSOLE_INFORMATION::AllocateConsole -> output.cpp@DoCreateScreenBuffer is called before... basically the bottom of ConsoleEstablishHandoff, then the first screen buffer would be created before it's in VtIo mode.

  • IoDispatchers::ConsoleHandleConnectionRequest
    • attemptHandoff (L450)
    • ConsoleAllocateConsole (L478)
      • SetUpConsole (L906)
        • CONSOLE_INFORMATION::AllocateConsole
      • This later sets up the VtIo, so I really think this has to be after handoff

Okay, so that first screen info is created after we setup handoff. Maybe there's something in the way it's created that ignores the VtIo setup we do for defterm. Maybe we never noticed, cause terminal's usually really good about immediately requesting a resize, but in this case, the CLI app really wants to get going, before Terminal's even had it's coffee

@zadjii-msft
Copy link
Member Author

This later sets up the VtIo

we're really gonna gloss over that huh?

CONSOLE_INFORMATION::IsInVtIoMode === VtIo::IsUsingVt === VtIo._objectsCreated, which is only set after VtIo::CreateIoHandlers.

VtIo::CreateIoHandlers is called on srvinit.cppL978, after the call to SetUpConsole on L906

zadjii-msft added a commit that referenced this issue May 5, 2023
This is a theory. I want to audit the uses of `CONSOLE_INFORMATION::IsInVtIoMode` before I commit to this.

But I think this:
* fixes #15245
* fixes #14512

Because basically, we'd create the first screen buffer with 9001 rows, because it would be created _before_ VtIo would be in a state to say "yes, we're a conpty"
@microsoft-github-policy-service microsoft-github-policy-service bot added the In-PR This issue has a related PR label May 5, 2023
zadjii-msft added a commit that referenced this issue May 10, 2023
We need to act like a ConPTY just a little earlier in startup. My relevant notes start here: #15245 (comment). 

Basically, we'd create the first screen buffer with 9001 rows, because it would be created _before_ VtIo would be in a state to say "yes, we're a conpty". Then, if a CLI app emits an entire screenful of text _before_ the terminal has a chance to resize the conpty, then the conpty will explode during `_DoLineFeed`. That method is absolutely not expecting the buffer to get resized (and the old text buffer deallocated). 

Instead, this will treat the console as in ConPty mode as soon as `VtIo::Initialize` is called (this is during `ConsoleCreateIoThread`, which is right at the end of `ConsoleEstablishHandoff`, which is before the API server starts to process the client connect message).  THEORETICALLY, `VtIo` could `Initialize` then fail to create objects in `CreateIoHandlers` (which is what we used to treat as the moment that we were in conpty mode). However, if we do fail out of `CreateIoHandlers`, then the console itself will fail to start up, and just die. So I don't think that's needed.

This fixes #15245. I think this is PROBABLY also the solution to #14512, but I'm not gonna explicitly mark closed. We'll loop back on it.
@microsoft-github-policy-service microsoft-github-policy-service bot added the Needs-Tag-Fix Doesn't match tag requirements label May 10, 2023
DHowett pushed a commit that referenced this issue Nov 28, 2023
We need to act like a ConPTY just a little earlier in startup. My relevant notes start here: #15245 (comment).

Basically, we'd create the first screen buffer with 9001 rows, because it would be created _before_ VtIo would be in a state to say "yes, we're a conpty". Then, if a CLI app emits an entire screenful of text _before_ the terminal has a chance to resize the conpty, then the conpty will explode during `_DoLineFeed`. That method is absolutely not expecting the buffer to get resized (and the old text buffer deallocated).

Instead, this will treat the console as in ConPty mode as soon as `VtIo::Initialize` is called (this is during `ConsoleCreateIoThread`, which is right at the end of `ConsoleEstablishHandoff`, which is before the API server starts to process the client connect message).  THEORETICALLY, `VtIo` could `Initialize` then fail to create objects in `CreateIoHandlers` (which is what we used to treat as the moment that we were in conpty mode). However, if we do fail out of `CreateIoHandlers`, then the console itself will fail to start up, and just die. So I don't think that's needed.

This fixes #15245. I think this is PROBABLY also the solution to #14512, but I'm not gonna explicitly mark closed. We'll loop back on it.

(cherry picked from commit 6ad8cd0)
Service-Card-Id: 89112504
Service-Version: 1.17
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area-DefApp In-PR This issue has a related PR Issue-Bug It either shouldn't be doing this or needs an investigation. Needs-Tag-Fix Doesn't match tag requirements Product-Conhost For issues in the Console codebase Severity-Blocking We won't ship a release like this! No-siree. Severity-Crash Crashes are real bad news.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant