microsoft / AL

Home of the Dynamics 365 Business Central AL Language extension for Visual Studio Code. Used to track issues regarding the latest version of the AL compiler and developer tools available in the Visual Studio Code Marketplace or as part of the AL Developer Preview builds for Dynamics 365 Business Central.
MIT License
744 stars 245 forks source link

AL Language Extension Misidentifies Code As Invalid, Formatter Scrambles Lines of Code During Save #6829

Closed bernalfr closed 2 years ago

bernalfr commented 2 years ago

1. Describe the bug Every so often, the language extension fails to properly identify lines of code as valid. The analyzer reports errors that contain incomplete segments of the code in question.

image

In the screenshot above, lines of code are highlighted by the analyzer as containing the following errors:

Screen Shot 2021-11-10 at 12 28 13

When this occurs, it is usually preceded by an error from the AL Language extension (see attached text file containing sample error messages):

ALLangErrTxt.txt

Attempting to save the source file (to restart VS Code) results in the language formatter scrambling the lines of code:

Screen Shot 2021-11-10 at 12 10 03

2. To Reproduce The conditions that lead to this issue are unknown. It seems to occur at random, usually as the language extension tries to keep up with tracking and validating code modifications as they are made (it is excruciatingly slow at this sometimes). Notably, this seems to occur whenever a "request failed" error raised by the language extension appears in the VS Code notifications (i.e., the language extension barfs on itself, requiring a restart of VS Code).

3. Expected behavior The expected behavior is that this should never occur. At the very least, the formatter function should not modify code based on misinterpretations by the code analyzer.

4. Actual behavior See "Describe the bug" section.

5. Versions:

thloke commented 2 years ago

We've seen this before, usually when our incremental parsing doesn't do the right thing for a specific syntax construct. When this happens, does it always happen in the same file(s)? If so, then it's probably another case of wrong syntax handling. If it happens in all files at random, then it's something else. Either way, this is a bug.

If it happens in specific file(s), could you share the syntax around the area where the spurious errors are reported? We can start investigating with the syntax in your screenshot, but additional examples will help a lot. Thanks!

bernalfr commented 2 years ago

I'm afraid that I have not paid close enough attention to notice whether this occurs when working within specific files. The AL project consists of approximately 200 objects, each one stored in its own file. This is an issue that has occurred throughout the recent past (it's been happening long enough that I thought it would make sense to report it). It is not specific to the current version of the AL Language extension.

Below is the function containing the code in the screenshot that was provided in the opening comment. I can provide additional examples if the issue happens again.

`

procedure UpdateToteLine(var ToteNo: Code[20]; var WhseActivitySubline: Record "LAX Whse Activity Subline"; SessionID: Text[250])
var
    ToteLine: Record "LAX Tote Line";
    CustomHandled: Boolean;
    _isExistingTote: Boolean;
begin
    OnBeforeUpdateToteLine(ToteNo, WhseActivitySubline, SessionID, CustomHandled);

    if CustomHandled then
        exit;

    ToteLine.SetRange("Activity Type", WhseActivitySubline."Activity Type");
    ToteLine.SetRange("No.", WhseActivitySubline."No.");
    ToteLine.SetRange("Line No.", WhseActivitySubline."Line No.");
    ToteLine.SetRange("Subline No.", WhseActivitySubline."Subline No.");
    ToteLine.SetRange("Tote No.", ToteNo);

    _isExistingTote := not (ToteLine.IsEmpty());

    if (_isExistingTote) and
       (WhseActivitySubline."Qty. Scanned" = 0)
    then
        ToteLine.DeleteAll(true);

    if not (ToteLine.FindFirst()) then begin
        ToteLine.Init();
        ToteLine."Tote No." := ToteNo;

        SetToteLine(ToteLine, WhseActivitySubline);

        if not (ToteLine.Insert(true)) then
            Remark := DeviceMgt.GetSessionMessage(SessionID, 'REM_TOTEDETFAIL');
    end;

    if (Remark = '') then begin
        ToteLine."Qty. to Handle" := WhseActivitySubline."Qty. Scanned";
        ToteLine."Qty. to Handle (Base)" := WhseActivitySubline."Qty. Scanned (Base)";

        if (InputQtyScanned <> 0) and
           (InputQtyScannedBase <> 0) and not
           (_isExistingTote)
        then begin
            //Implies a new tote for a whse. activity line with existing tote assignments.
            //Set the quantity to handle on the tote line to the quantity scanned, instead of the quantity to handle on the related whse. activity line.
            ToteLine."Qty. to Handle" := InputQtyScanned;
            ToteLine."Qty. to Handle (Base)" := InputQtyScannedBase;
        end;

        if not (ToteLine.Modify(true)) then
            Remark := DeviceMgt.GetSessionMessage(SessionID, 'REM_TOTEDETFAIL');
    end;
end;

`

thloke commented 2 years ago

No problem, this is still enough information for us to start investigating at least. If you do notice a pattern (or lack thereof) in the future, definitely update this issue.

bernalfr commented 2 years ago

Here is the complete source file, if it will help things on your end.

Cod14002817.RFWhseActivityLine.txt

There are dozens of codeunits within the AL project that are similar in structure. This codeunit in particular is worked on frequently and contains the most lines of code, compared to the others. I can say with certainty that this issue has occurred on multiple occasions whilst working within this object. Unfortunately, I cannot recall the specific areas where it happened.

If this is attributed to the way that the code is structured, then it would be good to get a basic understanding on how to address it. Hopefully the source file will provide you with enough material to analyze.

NKarolak commented 2 years ago

This issue reminds me a bit of my former one: https://github.com/microsoft/AL/issues/6170#issuecomment-700503071 Is your VS Code probably using CR instead CRLF?

bernalfr commented 2 years ago

This issue reminds me a bit of my former one: #6170 (comment) Is your VS Code probably using CR instead CRLF?

My hopes were raised for a moment, but no... line endings are formatted with CRLF.

Screen Shot 2021-11-11 at 12 48 43

Thank you for the suggestion. =0)

bernalfr commented 2 years ago

Hi, @thloke.

Here is another example (lns. 730 - 732), if it helps.

Screen Shot 2021-11-12 at 15 08 18

thloke commented 2 years ago

It does help. @nndobrev - FYI, since you're looking into this.

bernalfr commented 2 years ago

Today's example (lns. 1130 to 1153):

Screen Shot 2021-11-15 at 16 53 15

Is there any logging for this that one should turn on and provide to you?

thloke commented 2 years ago

@bernalfr - yes, I actually thought I posted something about logfiles yesterday, but apparently I didn't press the comment button. ):

There's a logfile under the following path which will be very helpful (adjust for the version of the AL extension you have installed):

C:\Users\<username>\.vscode\extensions\ms-dynamics-smb.al-8.1.540594\bin\win32\editorservices.log

That should contain the exceptions from the failed requests that precede this strange behaviour. You can send it to me directly at: thloke@microsoft.com

thloke commented 2 years ago

@bernalfr - sent this by email, but reposting here just in case it was missed:

If you can try something for me, that would be great. I can’t repro the issue yet, but there are a few things I’d like to rule out based on the exceptions in the logfile.

Can you either:

  1. Set "al.backgroundCodeAnalysis" : "false" in your settings.json or
  2. Remove CodeCop from your list of enabled analyzers

If this stops the issue from happening, I’d like to then try suppressing this specific rule (set action to none in a custom ruleset): AA0021

thloke commented 2 years ago

Closing due to lack of feedback.