search

mscdex / ssh2-streams

SSH2 and SFTP client/server protocol streams for node.js
MIT License
204 stars 143 forks source link

getting wierd error after client disconnects (winScp) #138

Open arthurvaverko-kaltura opened 5 years ago

arthurvaverko-kaltura commented 5 years ago

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 commented 5 years ago

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! kaltura-sftp-api-server@1.0.0 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 kaltura-sftp-api-server@1.0.0 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...

mscdex commented 5 years ago

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

arthurvaverko-kaltura commented 5 years ago

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 ?

mscdex commented 5 years ago

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.

arthurvaverko-kaltura commented 5 years ago

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 commented 5 years ago

well workaround works by attaching to

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