ssh2-streams icon indicating copy to clipboard operation
ssh2-streams copied to clipboard

getting wierd error after client disconnects (winScp)

Open arthurvaverko-kaltura opened this issue 5 years ago • 6 comments

all goes well until a client discinnects .. this is when the server crashes .. and i cant find the reason :\

ncaught error: { Error: write ECONNABORTED at afterWriteDispatched (internal/stream_base_commons.js:78:25) at writeGeneric (internal/stream_base_commons.js:73:3) at Socket._writeGeneric (net.js:717:5) at Socket._write (net.js:729:8) at doWrite (_stream_writable.js:410:12) at writeOrBuffer (_stream_writable.js:394:5) at Socket.Writable.write (_stream_writable.js:294:11) at SSH2Stream.ondata (_stream_readable.js:666:20) at SSH2Stream.emit (events.js:182:13) at addChunk (_stream_readable.js:283:12) errno: 'ECONNABORTED', code: 'ECONNABORTED', syscall: 'write' }

arthurvaverko-kaltura avatar Jul 24 '19 10:07 arthurvaverko-kaltura

here are some debug logs.. looks like the server is trying to send an EOF but the client is already siconnecde ..

[2019-07-24T14:26:38.243] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:38.244] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:38.244] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:38.244] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:38.244] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:38.245] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:38.246] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_REQUEST (0, subsystem) [2019-07-24T14:26:38.246] [DEBUG] SftpApiProxyServer - Client SFTP session [2019-07-24T14:26:38.247] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_SUCCESS (256) [2019-07-24T14:26:38.250] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:38.284] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:38.285] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:38.286] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:9,remainLen:16 [2019-07-24T14:26:38.286] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:38.287] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:38.287] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:38.287] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:38.288] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:38.288] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:38.289] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:38.292] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:38.293] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:38.294] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:38.295] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:38.296] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:4,remainLen:16 [2019-07-24T14:26:38.297] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:38.297] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:38.298] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:38.299] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:38.299] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:38.300] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:38.302] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:38.303] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Parser: Request: REALPATH [2019-07-24T14:26:38.304] [DEBUG] SftpApiProxyServer - REALPATH req:[3088], path:[/] user:[arthur1] [2019-07-24T14:26:38.309] [INFO] SftpApiProxyServer - setting ks:[djJ8MTk4fC8SDLCMaDHAykX-ZWlS33P1KOUq0Ag87W252irSKl6CumCVoy4LGj_4804NIufVJwHi4CaC0hnEi_wIGunTJL37ntZO9STvwyBlJG-VKnfyKInkielXd7tYlT3JJYeJq6UpPLTacQbGjo8i-mokGmU=] [2019-07-24T14:26:38.310] [INFO] Kaltura.Client - URL: http://localhost:8080//api_v3/service/ingestprofile/action/list, JSON: {"format":1,"apiVersion":"5.2.5.17649","clientTag":"node:19-07-17","ks":"djJ8MTk4fC8SDLCMaDHAykX-ZWlS33P1KOUq0Ag87W252irSKl6CumCVoy4LGj_4804NIufVJwHi4CaC0hnEi_wIGunTJL37ntZO9STvwyBlJG-VKnfyKInkielXd7tYlT3JJYeJq6UpPLTacQbGjo8i-mokGmU=","kalsig":"c4fb1d35b17dca01ffb7f04adf19a012"} [2019-07-24T14:26:38.311] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.183] [DEBUG] Kaltura.Client - Response server [undefined] session [1355d0a5-e96a-4ac4-958e-5229957afeec]: {"executionTime": 0.8669413, "result": {"objectType": "KalturaIngestProfileListResponse", "totalCount": 2, "objects": [{"objectType": "KalturaIngestProfile", "assetTypeId": 0, "defaultAutoFillPolicy": "", "defaultOverlapPolicy": "", "externalId": "WITH_XSL_ADAPATER", "id": 1029, "name": "WITH_XSL_ADAPATER", "transformationAdapterSettings": {}, "transformationAdapterSharedSecret": "3f01d4ce0bae4b76", "transformationAdapterUrl": "http://localhost:5000/api/Transformation/"}, {"objectType": "KalturaIngestProfile", "assetTypeId": 0, "defaultAutoFillPolicy": "", "defaultOverlapPolicy": "", "externalId": "NO_ADAPATER", "id": 2003, "name": "NO_ADAPATER", "transformationAdapterSettings": {}, "transformationAdapterSharedSecret": "bcb2a5eb83f84b88", "transformationAdapterUrl": ""}]}} [2019-07-24T14:26:39.184] [DEBUG] SftpApiProxyServer - REALPATH req:[3088], return:[/] [2019-07-24T14:26:39.185] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Outgoing: Writing NAME [2019-07-24T14:26:39.186] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:39.187] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:39.188] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.188] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:4,remainLen:16 [2019-07-24T14:26:39.189] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:39.189] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.189] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:39.189] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:39.190] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:39.190] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:39.191] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:39.191] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Parser: Request: LSTAT [2019-07-24T14:26:39.192] [DEBUG] SftpApiProxyServer - LSTAT req:[3335], path:[/] user:[arthur1] [2019-07-24T14:26:39.193] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.193] [DEBUG] SftpApiProxyServer - LSTAT req:[3335] return:[{"gid":0,"mode":16384,"uid":0,"size":0,"atime":0,"mtime":0}] [2019-07-24T14:26:39.194] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Outgoing: Writing ATTRS [2019-07-24T14:26:39.194] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:39.281] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:39.282] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.283] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:4,remainLen:16 [2019-07-24T14:26:39.283] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:39.284] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.285] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:39.285] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:39.286] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:39.286] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:39.287] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:39.287] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Parser: Request: OPENDIR [2019-07-24T14:26:39.288] [DEBUG] SftpApiProxyServer - OPENDIR req:[3595], path:[/] user:[arthur1] [2019-07-24T14:26:39.288] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.289] [DEBUG] SftpApiProxyServer - OPENDIR req:[3595] return:[/] [2019-07-24T14:26:39.290] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Outgoing: Writing HANDLE [2019-07-24T14:26:39.290] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:39.291] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:39.292] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.294] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:4,remainLen:16 [2019-07-24T14:26:39.296] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:39.296] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.298] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:39.298] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:39.299] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:39.299] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:39.300] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:39.301] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Parser: Request: READDIR [2019-07-24T14:26:39.303] [DEBUG] SftpApiProxyServer - READDIR req:[3852], path:[/] user:[arthur1] [2019-07-24T14:26:39.303] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.307] [DEBUG] SftpApiProxyServer - READDIR req:[3852], return dirs.length:[2] [2019-07-24T14:26:39.308] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Outgoing: Writing NAME [2019-07-24T14:26:39.309] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:39.311] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:39.311] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.312] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:4,remainLen:16 [2019-07-24T14:26:39.312] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:39.313] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.313] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:39.313] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:39.313] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:39.314] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:39.314] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:39.315] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Parser: Request: READDIR [2019-07-24T14:26:39.315] [DEBUG] SftpApiProxyServer - READDIR req:[4108], path:[/] user:[arthur1] [2019-07-24T14:26:39.315] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.316] [DEBUG] SftpApiProxyServer - READDIR req:[4108], return:[EOF] [2019-07-24T14:26:39.317] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Outgoing: Writing STATUS [2019-07-24T14:26:39.318] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:39.319] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:39.319] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.320] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:28,padLen:4,remainLen:16 [2019-07-24T14:26:39.320] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:39.320] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.321] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:39.321] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:39.322] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:39.322] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:39.323] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0) [2019-07-24T14:26:39.324] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Parser: Request: CLOSE [2019-07-24T14:26:39.326] [DEBUG] SftpApiProxyServer - CLOSE req:[4356], handle:[/], user:[arthur1] [2019-07-24T14:26:39.327] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG[SFTP]: Outgoing: Writing STATUS [2019-07-24T14:26:39.328] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_DATA (256) [2019-07-24T14:26:39.328] [DEBUG] SftpApiProxyServer - CLOSE req:[4356], return:[0] [2019-07-24T14:26:39.329] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.912] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKET [2019-07-24T14:26:39.913] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Decrypting [2019-07-24T14:26:39.913] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: pktLen:12,padLen:6,remainLen:0 [2019-07-24T14:26:39.915] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATA [2019-07-24T14:26:39.915] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: HMAC size:32 [2019-07-24T14:26:39.916] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY [2019-07-24T14:26:39.916] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: Verifying MAC [2019-07-24T14:26:39.916] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC) [2019-07-24T14:26:39.917] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_EOF (0) [2019-07-24T14:26:39.917] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Parser: IN_PACKETBEFORE (expecting 16) [2019-07-24T14:26:39.918] [DEBUG] SftpApiProxyServer - [250781.947001100] DEBUG: Outgoing: Writing CHANNEL_EOF (256) [2019-07-24T14:26:39.920] [ERROR] GlobalErrorHandler - Uncaught error: { Error: write ECONNABORTED at afterWriteDispatched (internal/stream_base_commons.js:78:25) at writeGeneric (internal/stream_base_commons.js:73:3) at Socket._writeGeneric (net.js:717:5) at Socket._write (net.js:729:8) at doWrite (_stream_writable.js:410:12) at writeOrBuffer (_stream_writable.js:394:5) at Socket.Writable.write (_stream_writable.js:294:11) at SSH2Stream.ondata (_stream_readable.js:666:20) at SSH2Stream.emit (events.js:182:13) at addChunk (_stream_readable.js:283:12) errno: 'ECONNABORTED', code: 'ECONNABORTED', syscall: 'write' } npm ERR! code ELIFECYCLE npm ERR! errno 1 npm ERR! [email protected] compile: tsc && ncp ./log4js.json ./dist/log4js.json && node ./dist/sftp-api-proxy-server.js npm ERR! Exit status 1 npm ERR! npm ERR! Failed at the [email protected] compile script. npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in: npm ERR! C:\Users\arthur.vaverko\AppData\Roaming\npm-cache_logs\2019-07-24T11_26_39_967Z-debug.log [nodemon] app crashed - waiting for file changes before starting...

arthurvaverko-kaltura avatar Jul 24 '19 11:07 arthurvaverko-kaltura

You should be able to handle these by adding an 'error' event handler.

mscdex avatar Jul 24 '19 15:07 mscdex

On the sftpStream object, Session object or client object ?

Also assuming ill handle and swallow the error, and manage to keep the server running.. any idea as to why this could happen ?

arthurvaverko-kaltura avatar Jul 24 '19 17:07 arthurvaverko-kaltura

The Client object.

As to why it's happening, it's hard to say. Is your server terminating the connection or is the client? If it's the latter, then there's not much that can be done since it is disconnecting seemingly abruptly.

mscdex avatar Jul 24 '19 21:07 mscdex

So error event does not get caught when i subscribe to on 'error'

export class SftpSessionHandler {

    private Logger: log4js.Logger;
    private IngestProfileDirectories: InMemoryDirectoryList;
    private ProfileDirectories: InMemoryDirectory[];
    private KalturaClient: KalturaClientWrapper;

    constructor(private authenticatedUser: AuthenticatedUser, private sftpStream: SFTPStream, ) {
        this.Logger = ServiceFactory.GetLogger("SftpApiProxyServer");
        this.KalturaClient = ServiceFactory.GetKalturaClient();

        this.sftpStream.on('REALPATH', async (reqId, path) => await this.onRealPath(reqId, path).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('SETSTAT', async (reqId, path, attrs) => await this.onSetStat(reqId, path, attrs).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('OPENDIR', async (reqId, path) => await this.OpenDir(reqId, path).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('READDIR', async (reqId, handle) => await this.onReadDir(reqId, handle).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('LSTAT', async (reqId, path) => await this.onLStat(reqId, path).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('OPEN', async (reqId, filename, flags, attrs) => await this.onOpen(reqId, filename, flags, attrs).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('WRITE', async (reqId, handle, offset, data) => await this.onWrite(reqId, handle, offset, data).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('REMOVE', async (reqId, path) => await this.onRemove(reqId, path).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('RENAME', async (reqId, oldPath, newPath) => await this.onRename(reqId, oldPath, newPath).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('CLOSE', async (reqId, handle) => await this.onClose(reqId, handle).catch((reason) => this.handleSftpError(reqId, reason)));

        this.sftpStream.on('FSETSTAT', async (reqId, handle) => await this.onFsetStat(reqId, handle).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('READ', async (reqId, handle, offset, length) => await this.onRead(reqId, handle, offset, length).catch((reason) => this.handleSftpError(reqId, reason)));
        this.sftpStream.on('STAT', async (reqId, path) => await this.onStat(reqId, path).catch((reason) => this.handleSftpError(reqId, reason)));

        this.sftpStream.on('close', async ()=> this.onDisconnectOrError(null));
        this.sftpStream.on('end', async ()=> this.onDisconnectOrError(null));
        this.sftpStream.on('error', async (err)=> this.onDisconnectOrError(err));
    }

....


public async onDisconnectOrError(err:any) {
        this.Logger.debug(`DISCONNECT OR ERROR user:[${this.authenticatedUser.username}]`);
        this.Logger.error('ERROR:',err);
        this.sftpStream.end();
    }

I don't see the log message ..

arthurvaverko-kaltura avatar Jul 25 '19 02:07 arthurvaverko-kaltura

well workaround works by attaching to

client.on('error', (err) => { this.Logger.error("client err...", err); });

arthurvaverko-kaltura avatar Jul 25 '19 03:07 arthurvaverko-kaltura