{"action":"created","issue":{"url":"https://api.github.com/repos/freedomjs/freedom-for-firefox/issues/61","labels_url":"https://api.github.com/repos/freedomjs/freedom-for-firefox/issues/61/labels{/name}","comments_url":"https://api.github.com/repos/freedomjs/freedom-for-firefox/issues/61/comments","events_url":"https://api.github.com/repos/freedomjs/freedom-for-firefox/issues/61/events","html_url":"https://github.com/freedomjs/freedom-for-firefox/issues/61","id":73083024,"number":61,"title":"onDisconnect dispatch causes uProxy to close connection","user":{"login":"soycode","id":587921,"avatar_url":"https://avatars.githubusercontent.com/u/587921?v=3","gravatar_id":"","url":"https://api.github.com/users/soycode","html_url":"https://github.com/soycode","followers_url":"https://api.github.com/users/soycode/followers","following_url":"https://api.github.com/users/soycode/following{/other_user}","gists_url":"https://api.github.com/users/soycode/gists{/gist_id}","starred_url":"https://api.github.com/users/soycode/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/soycode/subscriptions","organizations_url":"https://api.github.com/users/soycode/orgs","repos_url":"https://api.github.com/users/soycode/repos","events_url":"https://api.github.com/users/soycode/events{/privacy}","received_events_url":"https://api.github.com/users/soycode/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":{"login":"soycode","id":587921,"avatar_url":"https://avatars.githubusercontent.com/u/587921?v=3","gravatar_id":"","url":"https://api.github.com/users/soycode","html_url":"https://github.com/soycode","followers_url":"https://api.github.com/users/soycode/followers","following_url":"https://api.github.com/users/soycode/following{/other_user}","gists_url":"https://api.github.com/users/soycode/gists{/gist_id}","starred_url":"https://api.github.com/users/soycode/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/soycode/subscriptions","organizations_url":"https://api.github.com/users/soycode/orgs","repos_url":"https://api.github.com/users/soycode/repos","events_url":"https://api.github.com/users/soycode/events{/privacy}","received_events_url":"https://api.github.com/users/soycode/received_events","type":"User","site_admin":false},"milestone":null,"comments":1,"created_at":"2015-05-04T17:48:59Z","updated_at":"2015-05-04T18:07:18Z","closed_at":null,"body":"The issue is arising from a callback to onInputStreamReady that doesn't have data and so closes the socket (https://github.com/freedomjs/freedom-for-firefox/blob/master/providers/client_socket.js#L46). The last possibly relevant thing I see in the logs right beforehand is:\r\n\r\n    console.log: uproxy-firefox: Updating global settings to {\"description\":\"\",\"stunServers\":\r\n    [{\"url: [\"stun:stun.services.mozilla.com\"]},{\"urls\":[\"stun:stun.stunprotocol.org\"]},\r\n     {\"urls\":[\"stun:stun.l.google.com:19302\"]},{\"urls\":[\"stun:stun1.l.google.com:19302\"]},\r\n     {\"urls\":[\"stun:stun2.l.google.com:19302\"]},{\"urls\":[\"stun:stun3.l.google.com:19302\"]},\r\n     {\"urls\":[\"stun:stun4.l.google.com:19302\"]}],\"hasSeenSharingEnabledScreen\":false,\r\n    \"hasSeenWelcome\":true,\"allowNonUnicast\":false,\"mode\":0,\"version\":1,\"statsReportingEnabled\":false}\r\n\r\n    console.log: uproxy-firefox: UI sending Command {\"cmd\":\"emit\",\"type\":1015,\"data\":\r\n    {\"description\":\"\",\"stunServers\":[{\"urls\":[\"stun:stun.services.mozilla.com\"]},\r\n    {\"urls\":[\"stun:stun.stunprotocol.org\"]},{\"urls\":[\"stun:stun.l.google.com:19302\"]},\r\n    {\"urls\":[\"stun:stun1.l.google.com:19302\"]},{\"urls\":[\"stun:stun2.l.google.com:19302\"]},\r\n    {\"urls\":[\"stun:stun3.l.google.com:19302\"]},\r\n    {\"urls\":[\"stun:stun4.l.google.com:19302\"]}],\"hasSeenSharingEnabledScreen\":false,\r\n    \"hasSeenWelcome\":true,\"allowNonUnicast\":false,\"mode\":0,\"version\":1,\"statsReportingEnabled\":false},\r\n    \"promiseId\":0}\r\n\r\nI think this error probably was happening pre-0.6.11, it's just now we actually dispatch onDisconnect whenever we think the socket was closed, and so the error makes it as far as uProxy and actually causes it to give up."},"comment":{"url":"https://api.github.com/repos/freedomjs/freedom-for-firefox/issues/comments/98799797","html_url":"https://github.com/freedomjs/freedom-for-firefox/issues/61#issuecomment-98799797","issue_url":"https://api.github.com/repos/freedomjs/freedom-for-firefox/issues/61","id":98799797,"user":{"login":"soycode","id":587921,"avatar_url":"https://avatars.githubusercontent.com/u/587921?v=3","gravatar_id":"","url":"https://api.github.com/users/soycode","html_url":"https://github.com/soycode","followers_url":"https://api.github.com/users/soycode/followers","following_url":"https://api.github.com/users/soycode/following{/other_user}","gists_url":"https://api.github.com/users/soycode/gists{/gist_id}","starred_url":"https://api.github.com/users/soycode/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/soycode/subscriptions","organizations_url":"https://api.github.com/users/soycode/orgs","repos_url":"https://api.github.com/users/soycode/repos","events_url":"https://api.github.com/users/soycode/events{/privacy}","received_events_url":"https://api.github.com/users/soycode/received_events","type":"User","site_admin":false},"created_at":"2015-05-04T18:07:18Z","updated_at":"2015-05-04T18:07:18Z","body":"The (client) socket is closing normally (`NS_BASE_STREAM_CLOSED`) apparently for reason of not having any bytes left to read, so it's not an error per se - however with the new logic, any and all socket closes result in dispatching an onDisconnect. The possibilities I can conceive:\r\n\r\n- The socket shouldn't be closing at all\r\n- The socket should be closing but uProxy doesn't expect an onDisconnect dispatch from *all* socket closes\r\n- The socket should be closing and dispatch an onDisconnect but is somehow dispatching it to the \"wrong\" place (corresponding to a different socket or such)\r\n\r\nFor now I'm going to assume/investigate more the first possibility, but thoughts are welcome on the latter two. In any case, to reiterate I do believe this socket.close call was happening before, and apparently isn't fatal to the uProxy process, it's just now the onDisconnect causes it to be noticed."}}