microsoft / pylance-release

Documentation and issues for Pylance
Creative Commons Attribution 4.0 International
1.72k stars 766 forks source link

Sometimes the referenced objects and methods may appear as Unknown #4684

Closed hidaris closed 1 year ago

hidaris commented 1 year ago

Environment data

Code Snippet

PP.zip

Repro Steps

  1. Open the project using VSCode, place the mouse over self.brain.generate_reaction(objective), and both "brain" and "generate_reaction" will display as "unknown"
  2. Note that not every time you open VSCode will result in a failure displaying "unknown." I don't know how to reproduce it consistently; sometimes the occurrence rate is surprisingly high, and other times, it might only happen once after opening it twenty-something times in a row.

Expected behavior

It should complete indexing normally and display the corresponding type.

Actual behavior

Didn't see 'index done' in the log, and the type is 'Unknown'.

Logs

trace_log.txt

debonte commented 1 year ago

This isn't the kind of issue that we can figure out from a log. Please file a new issue when you are able to provide code the reproduces what you are seeing.

hidaris commented 1 year ago

Okay, I will try to provide a small code that can be shared publicly, and then file a new issue.

hidaris commented 1 year ago

This issue is not reproducible 100%. I would like to ask what possible factors need to be taken into consideration to narrow down the scope

debonte commented 1 year ago

Well, I don't have a lot of context so it's tough to speculate, but here are some ideas:

hidaris commented 1 year ago

Thank you for your suggestion.

hidaris commented 1 year ago

I've tried to provide a reduced-scope project code, but I can't reliably reproduce the issue. It still occurs probabilistically. I've updated the issue description.

hidaris commented 1 year ago

Could you reopen this issue? I have to go to the hospital now and might not have time to filea new issue.

hidaris commented 1 year ago

After updating the github copilot extension and reloading the window, I also encounter this issue.

hidaris commented 1 year ago

Hello, can the information currently provided help identify the problem?

debonte commented 1 year ago

Sorry for the delayed response. I was on vacation last week.

I was just able to reproduce the issue! Only once so far, but that's promising. I wasn't seeing it when just starting VS Code. But you mentioned that it repro'd after reloading the window due to updating an extension. The same thing happened when I downgraded Pylance from 2023.8.20 to 2023.8.10 and reloaded the window.

I'll continue investigating.

hidaris commented 1 year ago

No problem, hope you had a great vacation!

I'm glad you were able to reproduce this issue. It has indeed caused some inconvenience to my current work.

debonte commented 1 year ago

Repro steps:

  1. Unzip https://github.com/microsoft/pylance-release/files/12257143/PP.zip
  2. poetry install
  3. Open folder in VS Code
  4. Select the poetry environment.
  5. After Pyright/Pylance initializes, mouse over brain in _action__todo.
  6. If hover says that the type is Unknown, congrats you repro'd it. If not, try one of the following: Developer: Reload Window, restart VS Code, or delete + re-paste file contents.
debonte commented 1 year ago

@erictraut, could you take a look at this? I think it's a type evaluation issue. A race condition of some sort? It repros in both Pylance (2023.8.10+, and possibly earlier) and Pyright (1.1.322 and tip of main -- https://github.com/microsoft/pyright/commit/393be11e9dd2551d84edead7b21aaf10d1406c7d).

See repro steps in my previous comment.

The type shown when hovering over self.brain in _action__todo is inconsistent. Usually, it's GenerativeAgent (the type assigned in __init__), but sometimes (this issue) it's Unknown.

There are a couple other symbols, all base class-related, that are also curiously Unknown when it repros:

I can repro it fairly easily -- maybe 10-20% of the time -- but have never managed to repro it in the debugger.

I was able to simplify main.py to the following while still getting an occasional repro. I wasn't able to repro it after removing the unused imports or the 3 lines of code above BrainAgent though.

import openai
import langchain
import faiss

from langchain.cache import SQLiteCache
from langchain.chat_models import ChatOpenAI
from langchain.embeddings import OpenAIEmbeddings
from langchain.vectorstores import FAISS
from langchain.docstore import InMemoryDocstore
from langchain.retrievers import TimeWeightedVectorStoreRetriever

from pydantic import BaseModel
from agency.agent import Agent, access_policy, ACCESS_PERMITTED
from agency.amqp_space import AMQPSpace
from pp import GenerativeAgent, GenerativeAgentMemory

langchain.llm_cache = SQLiteCache(database_path=".langchain.db")

llm = ChatOpenAI(client=openai.Completion)
embeddings_model = OpenAIEmbeddings(client=openai.Embedding)

class BrainAgent(Agent):
    def __init__(self, id: str):
        super().__init__(id)
        self.brain = "str"

    def _action__todo(self, objective: str) -> None:
        res = self.brain
erictraut commented 1 year ago

This isn't a race condition, since we don't have any asynchronous code within the type evaluator. However, it does smell like a case where different evaluation order produces different results. A hover request is a high priority, so if it gets queued before the lower-priority full type check of the file, it will cause the types of some nodes to be evaluated.

I've done my best to repro the problem, but I'm not able to. I even tried increasing the _userActivityBackoffTimeInMs time to 10s to delay the full type check. Normally that makes it easier to repro bugs like this. But alas, I haven't been able to repro it.

If you're able to repro it semi-consistently, let's take advantage of that and try to diagnose the problem on your machine. Here's the process I recommend. First, set _userActivityBackoffTimeInMs temporarily to 10000 (ms). Now run the language server and set a breakpoint in the hover provider. Then carefully move the mouse pointer over the node that repros the problem. You should then be able to use the debugger to step through the type evaluator and figure out where the Undefined type is coming from.

debonte commented 1 year ago

set _userActivityBackoffTimeInMs temporarily to 10000 (ms)...

I wasn't able to repro the issue that way. But I also remembered that when reproing this I've been waiting for the variable res in _action__todo to get grayed out ("res" is not accessed) before hovering over brain. I'm assuming that that diagnostic hint indicates that the file has been checked?

erictraut commented 1 year ago

That's correct. The diagnostic hint is generated as part of the checking process, so if you see the grayed-out text appear, then check() has completed.

debonte commented 1 year ago

To be clear, I'm saying that the issue repros when I hover after that diagnostic hint appears. Any other theories as to what might be going on here?

erictraut commented 1 year ago

No, but if you can repro it on a semi-deterministic basis, you could set a conditional breakpoint and step through the code when it hits. For example, if the problem appears to be with evaluating self.brain, you can set a conditional breakpoint toward the top of getTypeOfMemberAccessWithBaseType right after memberName is assigned. The condition would be memberName == 'brain'. Once that hits, step through the code and see if you can figure out how Unknown is being produced. Let me know if you get stuck. Happy to help.

debonte commented 1 year ago

Sadly I still can't repro this in the debugger, but I was able to make some progress by adding extra logging and reproing the issue on a custom vsix.

When the bug repros, the classType object passed to synthesizeTypeVarForSelfCls has zero entries in classType.details.fields. This is the class that is eventually passed by getTypeOfMemberAccessWithBaseType to getTypeOfObjectMember and therefore the brain member isn't found.

I haven't dug into where that classType is coming from and why it's empty yet. But, since synthesizeTypeVarForSelfCls appears to clone the class, I wondered if maybe it is sometimes called before details.fields has been populated and then that field-less clone is not replaced once we have the fields. I don't have any evidence to back this up -- just a guess.

erictraut commented 1 year ago

OK, that's a good clue. It sounds like there's some circular dependency in the code being analyzed. That can lead to type evaluation behaviors that differ based on where in the cycle the evaluation begins.

At the point where synthesizeTypeVarForSelfCls is called, you should be able to see what else is on the stack. That will tell us what else is being evaluated at that time. I'm guessing that the class referenced by classType is partially evaluated. You can look back up on the stack for a frame within the getTypeOfClass function. You can see where fields is assigned within getTypeOfClass; search for classType.details.fields =. This value is assigned only after all of the base classes and the metaclass (if specified) within the class statement are processed.

debonte commented 1 year ago

Stack is below. Turns out that getTypeOfClass has fully completed before synthesizeTypeVarForSelfCls is called. evaluateTypeOfParameter calls getTypeOfClass before calling inferParameterType.

And strangely, when the bug repros, the type returned by getTypeOfClass is pulled from the type cache. Prior to that the class's cached type is correct (has fields) but at some point either the fields are removed or the whole cached type is replaced. Not sure which yet.

at synthesizeTypeVarForSelfCls (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeUtils.ts:1919:28)
at inferParameterType (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:17213:28)
at evaluateTypeOfParameter (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18586:35)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20247:17)
at evaluateTypeForSubnode (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18730:9)
at getInferredTypeOfDeclaration (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20246:20)
at forEach (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20579:36)
at Array.forEach (<anonymous>)
at getEffectiveTypeOfSymbolForUsage (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20523:15)
at getTypeOfName (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:4222:43)
at getTypeOfExpression (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:977:30)
at evaluateTypesForExpressionInContext (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18521:9)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:799:13)
at evaluateTypeForSubnode (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18730:9)
at getType (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:798:20)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:19640:28)
at a.getDeclarationsForNameNode [as timeOperation] (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\common\timing.ts:40:20)
at I._getHoverResult (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageService\hoverProvider.ts:204:48)
at I.getHover (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageService\hoverProvider.ts:129:41)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageServerBase.ts:964:106)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\program.ts:694:64)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:579:20)
at a.runWithCancellationToken [as timeOperation] (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\common\timing.ts:40:20)
at k.run (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\program.ts:694:26)
at S.run (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\service.ts:388:30)
at E.onHover (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageServerBase.ts:963:34)
debonte commented 1 year ago

@erictraut, I finally figured it out. An OperationCanceledException is thrown within getTypeOfClass. See the stack below.

There are two sets of writeTypeCache calls in getTypeOfClass. One set before classType.details.fields is assigned, and one after. This exception is thrown between these two sets of writeTypeCache calls, leaving an incomplete ClassType in the type cache.

Should the class be removed from the type cache in this case?

at throwIfCancellationRequested (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\common\cancellationUtils.ts:42:15)
at checkForCancellation (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:587:13)
at getTypeOfExpression (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:968:9)
at forEach (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:15676:29)
at Array.forEach (<anonymous>)
at getTypeOfClass (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:15659:28)
at evaluateTypeOfParameter (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18621:49)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20309:17)
at evaluateTypeForSubnode (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18792:9)
at getInferredTypeOfDeclaration (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20308:20)
at forEach (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20641:36)
at Array.forEach (<anonymous>)
at getEffectiveTypeOfSymbolForUsage (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:20585:15)
at getTypeOfName (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:4230:43)
at getTypeOfExpression (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:985:30)
at evaluateTypesForExpressionInContext (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18578:9)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:807:13)
at evaluateTypeForSubnode (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:18792:9)
at getType (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:806:20)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:19702:28)
at a.getDeclarationsForNameNode [as timeOperation] (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\common\timing.ts:40:20)
at I._getHoverResult (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageService\hoverProvider.ts:204:48)
at I.getHover (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageService\hoverProvider.ts:129:41)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageServerBase.ts:964:106)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\program.ts:694:64)
at callback (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\typeEvaluator.ts:579:20)
at a.runWithCancellationToken [as timeOperation] (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\common\timing.ts:44:28)
at k.run (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\program.ts:694:26)
at S.run (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\analyzer\service.ts:388:30)
at E.onHover (c:\Users\erikd\.vscode-insiders\extensions\ms-pyright.pyright-1.1.322\dist\pyright-internal\src\languageServerBase.ts:963:34)
erictraut commented 1 year ago

Ah, good find. That explains why I wasn't able to repro this in pyright. I have cancellations disabled in the debug build because they make debugging very difficult.

Removing the type from the type cache would eliminate this problem some of the time, but it's not sufficient to completely fix the problem. Circular references can result in legitimate cases where there are references to a partially-constructed class. For example, one of the base classes of class Foo could use list[Foo] as one of its base classes. The class object is later fully constructed, so those references become valid at that time. If we were to remove the class from the type cache, we'd still have those partially-constructed classes referenced in some cases. :(

The safest thing to do is to completely discard the entire type evaluator instance (i.e. call this._createNewEvaluator in _runEvaluatorWithCancellationToken) when a cancellation exception is caught, but that's a pretty big sledge hammer.

A variant of that idea is to say that cancellation exceptions that happen within certain pieces of code, such as getTypeOfClass, are rethrown as a variant of the OperationCanceledException that indicates that the type evaluator state is potentially corrupt and should be discarded. That way, we could use the sledge hammer only in specific cases where it's needed.

Any other ideas?

debonte commented 1 year ago

cancellation exceptions that happen within certain pieces of code, such as getTypeOfClass, are rethrown as a variant of the OperationCanceledException that indicates that the type evaluator state is potentially corrupt and should be discarded. That way, we could use the sledge hammer only in specific cases where it's needed.

Ok, that sounds good. I'll give that a shot.

debonte commented 1 year ago

This issue has been fixed in prerelease version 2023.8.41, which we've just released. You can find the changelog here: CHANGELOG.md

hidaris commented 1 year ago

Thank you