TypeScript Service: canceled request with sequence number

[Pajn]

TypeScript Version: 2.2.2

This is a continuation of #10735.
I tried to create a repo but failed, however I have it happening in multiple larger projects so the bug is there but I can't say what is causing it.

I tried to capture a tssever log file as @mhegazy suggested but as soon as it happened, the tsserver destroyed it completely and filled it with null bytes.
Hexdump:

0000000 6e49 6f66 3020 2020 2020 6942 646e 6e69
0000010 2e67 2e2e 000a 0000 0000 0000 0000 0000
0000020 0000 0000 0000 0000 0000 0000 0000 0000
*
0001a10 0000 0000 4900 666e 206f 3133 2020 4520
0001a20 6978 6974 676e 2e2e 0a2e               
0001a2a

The none-null bytes reads as (the null bytes are between the Info rows):

Info 0    Binding...
Info 31   Exiting...

This is the trace from vscode

[Info  - 6:31:24 PM] Using tsserver from location: /home/rasmus/Development/RAXA/node_modules/typescript/lib/tsserver.js
[Trace - 6:31:25 PM] Sending request: configure (0). Response expected: yes. Current queue length: 0
Arguments: {
    "hostInfo": "vscode"
}
[Trace - 6:31:25 PM] Response received: configure (0). Request took 649 ms. Success: true 
[Trace - 6:31:25 PM] Sending request: compilerOptionsForInferredProjects (1). Response expected: yes. Current queue length: 3
Arguments: {
    "options": {
        "module": "CommonJS",
        "target": "ES6",
        "allowSyntheticDefaultImports": true,
        "allowNonTsExtensions": true,
        "allowJs": true,
        "jsx": "Preserve"
    }
}
[Trace - 6:31:25 PM] Response received: compilerOptionsForInferredProjects (1). Request took 655 ms. Success: true 
Result: true
[Trace - 6:31:25 PM] Sending request: getSupportedCodeFixes (2). Response expected: yes. Current queue length: 2
[Trace - 6:31:25 PM] Response received: getSupportedCodeFixes (2). Request took 639 ms. Success: true 
Result: [
    "2304",
    "2339",
    "2377",
    "2420",
    "2503",
    "2515",
    "2653",
    "2663",
    "2686",
    "2689",
    "6133",
    "6138",
    "17009"
]
[Trace - 6:31:25 PM] Sending request: getSupportedCodeFixes (3). Response expected: yes. Current queue length: 1
[Trace - 6:31:25 PM] Response received: getSupportedCodeFixes (3). Request took 626 ms. Success: true 
Result: [
    "2304",
    "2339",
    "2377",
    "2420",
    "2503",
    "2515",
    "2653",
    "2663",
    "2686",
    "2689",
    "6133",
    "6138",
    "17009"
]
[Trace - 6:31:25 PM] Sending request: open (4). Response expected: no. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "fileContent": "import * as React from 'react'\nimport {Route} from 'react-router'\nimport compose from 'recompose/compose'\nimport {SectionProps} from './section'\n\nexport type RouteSectionProps = SectionProps & {\n  url: string\n}\nexport type PrivateRouteSectionProps = RouteSectionProps & {}\n\nexport const enhance = compose()\n\nexport const RouteSectionView = ({url}: PrivateRouteSectionProps) =>\n  <Route path={url} />\n\nexport const RouteSection = enhance(RouteSectionView) as React.ComponentClass<RouteSectionProps>\n",
    "scriptKindName": "TSX"
}
[Trace - 6:31:25 PM] Sending request: geterr (5). Response expected: no. Current queue length: 0
Arguments: {
    "delay": 0,
    "files": [
        "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx"
    ]
}
[Trace - 6:31:29 PM] Event received: configFileDiag (0).
Data: {
    "triggerFile": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "configFile": "/home/rasmus/Development/RAXA/packages/web/tsconfig.json",
    "diagnostics": []
}
[Trace - 6:31:29 PM] Event received: syntaxDiag (0).
Data: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "diagnostics": []
}
[Trace - 6:31:29 PM] Event received: semanticDiag (0).
Data: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "diagnostics": []
}
[Trace - 6:31:29 PM] Event received: requestCompleted (0).
Data: {
    "request_seq": 5
}
[Trace - 6:31:30 PM] Sending request: occurrences (6). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 16,
    "offset": 20
}
[Trace - 6:31:30 PM] Response received: occurrences (6). Request took 36 ms. Success: true 
Result: [
    {
        "start": {
            "line": 16,
            "offset": 14
        },
        "end": {
            "line": 16,
            "offset": 26
        },
        "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
        "isWriteAccess": true
    }
]
[Trace - 6:31:32 PM] Sending request: quickinfo (7). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 16,
    "offset": 20
}
[Trace - 6:31:32 PM] Response received: quickinfo (7). Request took 2 ms. Success: true 
Result: {
    "kind": "const",
    "kindModifiers": "export",
    "start": {
        "line": 16,
        "offset": 14
    },
    "end": {
        "line": 16,
        "offset": 26
    },
    "displayString": "const RouteSection: React.ComponentClass<RouteSectionProps>",
    "documentation": ""
}
[Trace - 6:31:33 PM] Sending request: definition (8). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 13,
    "offset": 15
}
[Trace - 6:31:33 PM] Response received: definition (8). Request took 12 ms. Success: true 
Result: [
    {
        "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
        "start": {
            "line": 13,
            "offset": 14
        },
        "end": {
            "line": 13,
            "offset": 30
        }
    }
]
[Trace - 6:31:34 PM] Sending request: definition (9). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 11,
    "offset": 13
}
[Trace - 6:31:34 PM] Response received: definition (9). Request took 2 ms. Success: false . Message: No content available.
[Trace - 6:31:34 PM] Sending request: definition (10). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 13,
    "offset": 10
}
[Trace - 6:31:34 PM] Response received: definition (10). Request took 1 ms. Success: false . Message: No content available.
[Trace - 6:31:34 PM] Sending request: definition (11). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 14,
    "offset": 8
}
[Trace - 6:31:34 PM] Response received: definition (11). Request took 2 ms. Success: true 
Result: [
    {
        "file": "/home/rasmus/Development/RAXA/node_modules/@types/react-router/index.d.ts",
        "start": {
            "line": 71,
            "offset": 9
        },
        "end": {
            "line": 71,
            "offset": 14
        }
    }
]
[Trace - 6:31:34 PM] Sending request: open (12). Response expected: no. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/node_modules/@types/react-router/index.d.ts",
    "fileContent": "// Type definitions for React Router 4.0\r\n// Project: https://github.com/ReactTraining/react-router\r\n// Definitions by: Sergey Buturlakin <https://github.com/sergey-buturlakin>\r\n//                 Yuichi Murata <https://github.com/mrk21>\r\n//                 Václav Ostrožlík <https://github.com/vasek17>\r\n//                 Nathan Brown <https://github.com/ngbrown>\r\n//                 Alex Wendland <https://github.com/awendland>\r\n//                 Kostya Esmukov <https://github.com/KostyaEsmukov>\r\n//                 John Reilly <https://github.com/johnnyreilly>\r\n//                 Karol Janyst <https://github.com/LKay>\r\n//                 Dovydas Navickas <https://github.com/DovydasNavickas>\r\n//                 Tanguy Krotoff <https://github.com/tkrotoff>\r\n//                 Huy Nguyen <https://github.com/huy-nguyen>\r\n// Definitions: https://github.com/DefinitelyTyped/DefinitelyTyped\r\n// TypeScript Version: 2.2\r\n\r\ndeclare module 'react-router' {\r\n  import * as React from 'react';\r\n  import * as H from 'history';\r\n\r\n\t// This is the type of the context object that will be passed down to all children of\r\n\t// a `Router` component:\r\n\tinterface RouterChildContext<P> {\r\n\t\trouter: {\r\n\t\t\thistory: H.History\r\n\t\t\troute: {\r\n\t\t\t\tlocation: H.Location,\r\n\t\t\t\tmatch: match<P>\r\n\t\t\t}\r\n\t\t}\r\n\t}\r\n  interface MemoryRouterProps {\r\n    initialEntries?: H.Location[];\r\n    initialIndex?: number;\r\n    getUserConfirmation?: () => void;\r\n    keyLength?: number;\r\n  }\r\n  class MemoryRouter extends React.Component<MemoryRouterProps, void> {}\r\n\r\n\r\n  interface PromptProps {\r\n    message: string | ((location: H.Location) => void);\r\n    when?: boolean;\r\n  }\r\n  class Prompt extends React.Component<PromptProps, void> {}\r\n\r\n\r\n  interface RedirectProps {\r\n    to: H.LocationDescriptor;\r\n    push?: boolean;\r\n    from?: string;\r\n  }\r\n  class Redirect extends React.Component<RedirectProps, void> {}\r\n\r\n\r\n  interface RouteComponentProps<P> {\r\n    match: match<P>;\r\n    location: H.Location;\r\n    history: H.History;\r\n  }\r\n\r\n  interface RouteProps {\r\n    location?: H.Location;\r\n    component?: React.SFC<RouteComponentProps<any> | void> | React.ComponentClass<RouteComponentProps<any> | void>;\r\n    render?: (props: RouteComponentProps<any>) => React.ReactNode;\r\n    children?: (props: RouteComponentProps<any>) => React.ReactNode | React.ReactNode;\r\n    path?: string;\r\n    exact?: boolean;\r\n    strict?: boolean;\r\n  }\r\n  class Route extends React.Component<RouteProps, void> {}\r\n\r\n\r\n  interface RouterProps {\r\n    history: any;\r\n  }\r\n  class Router extends React.Component<RouterProps, void> {}\r\n\r\n\r\n  interface StaticRouterProps {\r\n    basename?: string;\r\n    location?: string | object;\r\n    context?: object;\r\n  }\r\n  class StaticRouter extends React.Component<StaticRouterProps, void> {}\r\n\r\n\r\n  interface SwitchProps extends RouteProps {\r\n  }\r\n  class Switch extends React.Component<SwitchProps, void> {}\r\n\r\n\r\n  interface match<P> {\r\n    params: P;\r\n    isExact: boolean;\r\n    path: string;\r\n    url: string;\r\n  }\r\n\r\n\r\n  function matchPath<P>(pathname: string, props: RouteProps): match<P> | null;\r\n\r\n\r\n  function withRouter(component: React.SFC<RouteComponentProps<any>> | React.ComponentClass<RouteComponentProps<any>>): React.ComponentClass<any>;\r\n\r\n\r\n  export {\r\n    MemoryRouter,\r\n    Prompt,\r\n    Redirect,\r\n    RouteComponentProps, // TypeScript specific, not from React Router itself\r\n    RouteProps, // TypeScript specific, not from React Router itself\r\n    Route,\r\n    Router,\r\n    StaticRouter,\r\n    Switch,\r\n    match, // TypeScript specific, not from React Router itself\r\n    matchPath,\r\n\t\twithRouter,\r\n\t\tRouterChildContext\r\n  }\r\n}\r\n",
    "scriptKindName": "TS"
}
[Trace - 6:31:34 PM] Sending request: quickinfo (13). Response expected: yes. Current queue length: 0
Arguments: {
    "file": "/home/rasmus/Development/RAXA/packages/web/src/components/ui/scaffold/route-section.tsx",
    "line": 14,
    "offset": 7
}
[Trace - 6:31:35 PM] TypeScript Service: tried to cancel request with sequence number 13. But request got already delivered.
[Trace - 6:31:38 PM] TypeScript Service: canceled request with sequence number 17
[Trace - 6:31:42 PM] TypeScript Service: canceled request with sequence number 20
[Trace - 6:31:42 PM] TypeScript Service: canceled request with sequence number 15
[Error - 6:32:26 PM] TSServer exited with code: unknown
[Info  - 6:32:26 PM] Using tsserver from location: /home/rasmus/Development/RAXA/node_modules/typescript/lib/tsserver.js
[Trace - 6:32:55 PM] TypeScript Service: canceled request with sequence number 32
[Trace - 6:32:59 PM] TypeScript Service: canceled request with sequence number 33
[Trace - 6:33:03 PM] TypeScript Service: canceled request with sequence number 37
[Trace - 6:33:04 PM] TypeScript Service: canceled request with sequence number 38
[Trace - 6:33:04 PM] TypeScript Service: canceled request with sequence number 39
[Trace - 6:33:04 PM] TypeScript Service: canceled request with sequence number 40
[Trace - 6:33:05 PM] TypeScript Service: canceled request with sequence number 41
[Trace - 6:33:05 PM] TypeScript Service: canceled request with sequence number 42
[Trace - 6:33:06 PM] TypeScript Service: canceled request with sequence number 43
[Trace - 6:33:07 PM] TypeScript Service: canceled request with sequence number 44
[Trace - 6:33:08 PM] TypeScript Service: canceled request with sequence number 45
[Trace - 6:33:09 PM] TypeScript Service: canceled request with sequence number 47
[Trace - 6:33:11 PM] TypeScript Service: canceled request with sequence number 46
[Trace - 6:33:28 PM] TypeScript Service: canceled request with sequence number 50
[Trace - 6:33:29 PM] TypeScript Service: canceled request with sequence number 51
[Trace - 6:33:29 PM] TypeScript Service: canceled request with sequence number 53
[Trace - 6:34:27 PM] TypeScript Service: canceled request with sequence number 56
[Trace - 6:34:27 PM] TypeScript Service: canceled request with sequence number 54
[Trace - 6:35:06 PM] TypeScript Service: canceled request with sequence number 61

tsserver.log when just having caused the bug but before tsserver hangs or crashed (before the request times out?)
https://gist.github.com/Pajn/706265d7f61e89bab5b3bcfe93ce068d

In this particular project it seems like I can reproduce it every time by doing go to definition in a specific JSX element.

[westonpace]

I can reproduce this reliably in my project. I turned on debugging in tsserver.js and it appears to be getting stuck in some kind of infinite loop. I suspect it is eventually terminating due to a stack overflow or something of the sort. I can't get the node debugger to print a full stack trace but every time I pause it in the bowels of the request I get something that looks like:

#0 tsserver.js:29018:17
#1 tsserver.js:28797:38
#2 tsserver.js:29230:43
#3 tsserver.js:29123:38
#4 tsserver.js:29020:53
#5 tsserver.js:28797:38
#6 tsserver.js:28455:35
#7 tsserver.js:29316:24
#8 tsserver.js:29300:39
#9 tsserver.js:29125:43

I will attach the version of tsserver.js that I am using (I had to change the extension to txt to make Github happy).
tsserver.txt

The infinite loop is always in response to a quickinfo request.

[westonpace]

I also cannot reproduce this on 2.2.2 with the exact same behavior. I will try and narrow down the versions affected.

[westonpace]

Fails on 2.3.0, 2.3.1, and 2.3.2 so it definitely seems to be a result of changes added as part of 2.3.

[westonpace]

Dug up the stack trace a little and it seems to start here:

#0 tsserver.js:33372:37
#1 tsserver.js:33690:30
#2 tsserver.js:33610:26
#3 tsserver.js:33804:24
#4 tsserver.js:33936:28
#5 tsserver.js:33954:26
#6 checker.getResolvedSignature tsserver.js:21910:31
#7 tsserver.js:66069:49
#8 tsserver.js:71636:70
#9 Session.getQuickInfoWorker tsserver.js:77166:62

@westonpace Based on your stack trace, this looks like a long recursion in recursiveTypeRelatedTo. This function is supposed to have a maximum of 100 recursions, so it's probably not a stack overflow, but it could take long enough to get services requests cancelled.

#0 tsserver.js:29018:17
    in `recursiveTypeRelatedTo`:
    if (!(expandingFlags & 2) && isDeeplyNestedType(target, targetStack, depth))

#1 tsserver.js:28797:38
    in `isRelatedTo`:
    if (result = recursiveTypeRelatedTo(source, target, reportErrors)) {

#2 tsserver.js:29230:43
    in `propertiesRelatedTo`:
    var related = isRelatedTo(getTypeOfSymbol(sourceProp), getTypeOfSymbol(targetProp), reportErrors);

#3 tsserver.js:29123:38
    in `structuredTypeRelatedTo`:
    result = propertiesRelatedTo(source, target, reportStructuralErrors);

#4 tsserver.js:29020:53
    in `recursiveTypeRelatedTo`:
    var result = expandingFlags !== 3 ? structuredTypeRelatedTo(source, target, reportErrors) : 1;

#5 tsserver.js:28797:38
    in `isRelatedTo`:
    if (result = recursiveTypeRelatedTo(source, target, reportErrors)) {

#6 tsserver.js:28455:35
    in `compareSignaturesRelated`:
    var related = compareTypes(sourceThisType, targetThisType, false)
                        || compareTypes(targetThisType, sourceThisType, reportErrors);

#7 tsserver.js:29316:24
    in `signatureRelatedTo`:
    return compareSignaturesRelated(source, target, false, reportErrors, reportError, isRelatedTo);

#8 tsserver.js:29300:39
    in `signatureRelatedTo`:
    var related = signatureRelatedTo(s, t, shouldElaborateErrors);

#9 tsserver.js:29125:43
    in `structuredTypeRelatedTo`:
    result &= signaturesRelatedTo(source, target, 0, reportStructuralErrors);

@sandersn pointed out that this is similar to #15443, in that it only fails in ts2.3+, and (as of #15519) it only fails in services, not in batch compilation.

Could you check that you're using typescript@next, and try getting some code that can reproduce this error?

[westonpace]

I tried with typescript@next (specifically 2.4.0-dev.20170512) and the issue did not occur.