search

onsip / SIP.js

A simple, intuitive, and powerful JavaScript signaling library
https://sipjs.com
MIT License
1.9k stars 702 forks source link

warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit. #565

Closed i-kitchen closed 6 years ago

i-kitchen commented 6 years ago

After switching to 0.11.0 I am now getting a possible EventEmitter memory leak error in the console. Here is the trace that is provided with the error: From Firefox:

EventEmitter.prototype.addListener    webpack://SIP/./node_modules/events/events.js?:138:7
InviteClientTransaction               webpack://SIP/./src/Transactions.js?:148:5
send                                  webpack://SIP/./src/RequestSender.js?:40:36
sendRequest                           webpack://SIP/./src/Session.js?:198:7
sendReinvite/<                        webpack://SIP/./src/Session.js?:466:9

From Chrome:

EventEmitter.addListener | @ | events.js:144
InviteClientTransaction | @ | Transactions.js:148
send | @ | RequestSender.js:40
sendRequest | @ | Session.js:209
(anonymous) | @ | Session.js:466
Promise.then (async) |   |  
sendReinvite | @ | Session.js:465
unhold | @ | Session.js:359

This happens when I un-hold a call. Please let me know if there's more information I can provide.

JimGreenberg commented 6 years ago

Could you post full logs?

i-kitchen commented 6 years ago 

raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | configuration parameters after validation:
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · viaHost: "a6dspn71f48f.invalid"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · uri: sip:1060@127.0.0.1.net
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · custom: {}
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · displayName: "Softphone"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · password: NOT SHOWN
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · registerExpires: 600
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · register: true
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · registrarServer: sip:ian-web-phone.datto.net
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · transportConstructor: undefined
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · transportOptions: {"wsServers":"wss://127.0.0.1:8089/ws"}
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · userAgentString: "SIP.js/0.11.0"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · noAnswerTimeout: 30000
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · hackViaTcp: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · hackIpInContact: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · hackWssInTransport: true
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · hackAllowUnregisteredOptionTags: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · sessionDescriptionHandlerFactoryOptions: {"constraints":{"audio":true,"video":false}}
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · contactName: "jiavbjr5"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · contactTransport: "wss"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · forceRport: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · autostart: true
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · autostop: true
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · rel100: "none"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · dtmfType: "info"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · replaces: "none"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · sessionDescriptionHandlerFactory: function defaultFactory(session, observer, options) {
    return new SessionDescriptionHandler(session, observer, options);
  }
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · authenticationFactory: undefined
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · allowLegacyNotifications: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · allowOutOfDialogRefers: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · authorizationUser: "1060"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · instanceId: "96fb555d-f116-41d6-8ced-bc5e7a47f0cd"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · sipjsId: "k6gsk"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | · hostportParams: "ian-web-phone.datto.net"
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.ua | user requested startup...
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | configuration parameters after validation:
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · wsServers: [{"ws_uri":"wss://ian-web-phone.datto.net:8089/ws","sip_uri":"<sip:ian-web-phone.datto.net:8089;transport=ws;lr>","weight":0,"isError":false,"scheme":"WSS"}]
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · connectionTimeout: 5
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · maxReconnectionAttempts: 3
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · reconnectionTimeout: 4
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · keepAliveInterval: 0
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · keepAliveDebounce: 10
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | · traceSip: false
raven.js:55 Fri Jun 08 2018 10:58:18 GMT-0400 (Eastern Daylight Time) | sip.transport | connecting to WebSocket wss://ian-web-phone.datto.net:8089/ws
raven.js:55 Fri Jun 08 2018 10:58:19 GMT-0400 (Eastern Daylight Time) | sip.transport | WebSocket wss://ian-web-phone.datto.net:8089/ws connected
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | SessionDescriptionHandlerOptions: {"constraints":{"audio":true,"video":false}}
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | initPeerConnection
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | New peer connection created
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | acquiring local media
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | acquired local media streams
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | RTCIceGatheringState changed: gathering
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | ICE candidate received: candidate:1051995033 1 udp 2122260223 172.18.0.1 33419 typ host generation 0 ufrag hUwX network-id 1 network-cost 50
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | ICE candidate received: candidate:434636113 1 udp 2122194687 10.70.81.124 52730 typ host generation 0 ufrag hUwX network-id 2 network-cost 10
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | ICE candidate received: candidate:3717574005 1 udp 1686052607 69.195.39.134 1929 typ srflx raddr 172.18.0.1 rport 33419 generation 0 ufrag hUwX network-id 1 network-cost 50
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | ICE candidate received: candidate:4026039429 1 udp 1685987071 69.195.39.134 26353 typ srflx raddr 10.70.81.124 rport 52730 generation 0 ufrag hUwX network-id 2 network-cost 10
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | ICE candidate received: candidate:1882707817 1 tcp 1518280447 172.18.0.1 9 typ host tcptype active generation 0 ufrag hUwX network-id 1 network-cost 50
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | ICE candidate received: candidate:1466694049 1 tcp 1518214911 10.70.81.124 9 typ host tcptype active generation 0 ufrag hUwX network-id 2 network-cost 10
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | RTCIceGatheringState changed: complete
raven.js:55 Fri Jun 08 2018 10:58:26 GMT-0400 (Eastern Daylight Time) | sip.dialog | new UAC dialog created with status EARLY
raven.js:55 {success: true, returnValue: {…}, errors: null}
raven.js:55 Fri Jun 08 2018 10:58:28 GMT-0400 (Eastern Daylight Time) | sip.dialog | dialog k6gsk85mol4dbbf6tmqhlmvr81j9b1as6550d4ad  changed to CONFIRMED state
raven.js:55 Fri Jun 08 2018 10:58:28 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | track added
raven.js:55 (node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.
EventEmitter.addListener @ events.js:138
InviteClientTransaction @ Transactions.js:148
send @ RequestSender.js:40
sendRequest @ Session.js:209
(anonymous) @ Session.js:466
Promise.then (async)
sendReinvite @ Session.js:465
unhold @ Session.js:359
unholdCall @ Phone.js:621
toggleHold @ Phone.js:568
raven.js:55 Fri Jun 08 2018 10:58:31 GMT-0400 (Eastern Daylight Time) | sip.invitecontext.sessionDescriptionHandler | track added
egreenmachine commented 6 years ago

I am not seeing this in my testing. Why does everything say raven.js and the line numbers don't really make sense. Do you have some custom code that could be causing this?

i-kitchen commented 6 years ago

I'm using Sentry for logging which uses raven and that's where raven.js and line 55 are coming from. If I disable Sentry I still get the same error and instead of raven it's LoggerFactory.js:78. The softphone is acting as a CTI adapter for salesforce, but even outside of salesforce I still get the error. I wasn't seeing this in 0.10.0, so I was wondering if it was related to the transport changes.

egreenmachine commented 6 years ago

New event listeners were internally added to SIP.js for the Transport work, so that could definitely explain why you are seeing it. And that is what we were trying to determine. That being said, it is just a warning and if the number is not growing out of control, it can safely be ignored.

@JimGreenberg will investigate increasing this limit within SIP.js so that the warnings will disappear in a future release. Alternatively, you could submit a PR to resolve this. Thanks

i-kitchen commented 6 years ago

Upon further investigation and increasing the listener count, I found that there might indeed be an issue with ever growing listeners. In EventEmitter.js I added NodeEventEmitter.prototype._maxListeners = 15 and the error appeared after a couple of un-holds saying 16 listeners. Then I increased it to 100 and got the same error after many more un-holds. The error states that 101 listeners had been added.

JimGreenberg commented 6 years ago

Yeah, this seems related to the transport work. We moved some of the responsibilities over to individual components, and the issue you're seeing probably is related. I'm going to get a patch out for this hopefully by monday or tuesday. Huge thanks for spending the time to track this down.

egreenmachine commented 6 years ago

This is fixed in 0.11.1+