crash with rapid message send / respond

[zetorian]

matrix version: 0.34.1.1
matrix-puppet-hangouts version: b431229

so I have noticed an odd behavior, when using the hangouts puppet. if I send and receive multiple messages through hangouts in rapid succession (under 2-3 mins) and occasionally if I respond quickly to things inside of matrix, the bridge will crash with this error:

verbose:matrix-puppet:hangouts:client got message from hangups before JSON.parse():
+2ms 
undefined 2 


SyntaxError: unexpected end of JSON input 
at JSON.parse(<anonymous>)
at Socket.hangupsProc.stdout.on (/home/zetorian/matrix-puppet-hangouts/client.js:25:23 

from a quick glance at the code by someone who has no JavaScript experience, it looks like the problem might be fixed by validating the JSON received by Socket.hangupsProc.stdout.on() though how we could correct an incomplete JSON message from hangups is beyond me, perhaps request it be sent again?

[michaelnew]

Same issue for me, although it doesn't necessarily seem to be related to message frequency. For this crash the previous log event was around 2 hours before:

Jan 29 11:47:48 droid npm[258]: Tue, 29 Jan 2019 19:47:45 GMT verbose:matrix-puppet:hangouts:client got message from hangups before JSON.parse(): {"status": "success", "type": "message", "content": "Overwatch tonight?", "conversation_id": "Ugx...", "conversation_name": "Stephen, Paul", "photo_url": "//lh3.googleusercontent.com/a-/AAu...", "user": "Paul", "self_user_id": "117...", "user_id": {"chat_id": "112...", "gaia_id": "112..."}}
Jan 29 11:47:48 droid npm[258]: Tue, 29 Jan 2019 19:47:45 GMT verbose:matrix-puppet:hangouts:client emitting message { status: 'success',
Jan 29 11:47:48 droid npm[258]:   type: 'message',
Jan 29 11:47:48 droid npm[258]:   content: 'Overwatch tonight?',
Jan 29 11:47:48 droid npm[258]:   conversation_id: 'Ugx...',
Jan 29 11:47:48 droid npm[258]:   conversation_name: 'Stephen, Paul',
Jan 29 11:47:48 droid npm[258]:   photo_url:
Jan 29 11:47:48 droid npm[258]:    '//lh3.googleusercontent.com/a-/AAu...',
Jan 29 11:47:48 droid npm[258]:   user: 'Paul',
Jan 29 11:47:48 droid npm[258]:   self_user_id: '117...',
Jan 29 11:47:48 droid npm[258]:   user_id:
Jan 29 11:47:48 droid npm[258]:    { chat_id: '112...',
Jan 29 11:47:48 droid npm[258]:      gaia_id: '112...' } }
Jan 29 11:47:48 droid npm[258]: Tue, 29 Jan 2019 19:47:45 GMT verbose:matrix-puppet:hangouts:index incoming message data: { status: 'success',
Jan 29 11:47:48 droid npm[258]:   type: 'message',
Jan 29 11:47:48 droid npm[258]:   content: 'Overwatch tonight?',
Jan 29 11:47:48 droid npm[258]:   conversation_id: 'Ugx...',
Jan 29 11:47:48 droid npm[258]:   conversation_name: 'Stephen, Paul',
Jan 29 11:47:48 droid npm[258]:   photo_url:
Jan 29 11:47:48 droid npm[258]:    '//lh3.googleusercontent.com/a-/AAu...',
Jan 29 11:47:48 droid npm[258]:   user: 'Paul',
Jan 29 11:47:48 droid npm[258]:   self_user_id: '117...',
Jan 29 11:47:48 droid npm[258]:   user_id:
Jan 29 11:47:48 droid npm[258]:    { chat_id: '112...',
Jan 29 11:47:48 droid npm[258]:      gaia_id: '112...' } }
Jan 29 11:47:48 droid npm[258]: Tue, 29 Jan 2019 19:47:45 GMT matrix-puppet:Base:handleThirdPartyRoomMessage:info handling third party room message { roomId: 'Ugx...',
Jan 29 11:47:48 droid npm[258]:   senderName: 'Paul',
Jan 29 11:47:48 droid npm[258]:   senderId: '112...',
Jan 29 11:47:48 droid npm[258]:   text: 'Overwatch tonight?',
Jan 29 11:47:48 droid npm[258]:   avatarUrl:
Jan 29 11:47:48 droid npm[258]:    '//lh3.googleusercontent.com/a-/AAu...' }
Jan 29 11:47:48 droid npm[258]: Tue, 29 Jan 2019 19:47:45 GMT matrix-puppet:Base:getOrCreateMatrixRoomFromThirdPartyRoomId:info looking up Ugx...
Jan 29 11:47:48 droid npm[258]: Tue, 29 Jan 2019 19:47:45 GMT verbose:matrix-puppet:hangouts:client got message from hangups before JSON.parse():
Jan 29 11:47:48 droid npm[258]: undefined:2
Jan 29 11:47:48 droid npm[258]: SyntaxError: Unexpected end of JSON input
Jan 29 11:47:48 droid npm[258]:     at JSON.parse (<anonymous>)
Jan 29 11:47:48 droid npm[258]:     at Socket.hangupsProc.stdout.on (/home/alarm/third-party/matrix-puppet-hangouts/client.js:25:23)
Jan 29 11:47:48 droid npm[258]:     at Socket.emit (events.js:197:13)
Jan 29 11:47:48 droid npm[258]:     at addChunk (_stream_readable.js:288:12)
Jan 29 11:47:48 droid npm[258]:     at readableAddChunk (_stream_readable.js:269:11)
Jan 29 11:47:48 droid npm[258]:     at Socket.Readable.push (_stream_readable.js:224:10)
Jan 29 11:47:48 droid npm[258]:     at Pipe.onStreamRead [as onread] (internal/stream_base_commons.js:145:17)
Jan 29 11:47:48 droid npm[258]: npm ERR! code ELIFECYCLE
Jan 29 11:47:48 droid npm[258]: npm ERR! errno 1
Jan 29 11:47:48 droid npm[258]: npm ERR! matrix-puppet-hangouts@0.0.5 start: `DEBUG=*matrix-puppet:* node index.js`
Jan 29 11:47:48 droid npm[258]: npm ERR! Exit status 1
Jan 29 11:47:48 droid npm[258]: npm ERR!
Jan 29 11:47:48 droid npm[258]: npm ERR! Failed at the matrix-puppet-hangouts@0.0.5 start script.
Jan 29 11:47:48 droid npm[258]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
Jan 29 11:47:48 droid npm[258]: npm ERR! A complete log of this run can be found in:
Jan 29 11:47:48 droid npm[258]: npm ERR!     /home/alarm/.npm/_logs/2019-01-29T19_47_48_290Z-debug.log
Jan 29 11:47:48 droid systemd[1]: hangouts-bridge.service: Main process exited, code=exited, status=1/FAILURE
Jan 29 11:47:48 droid systemd[1]: hangouts-bridge.service: Failed with result 'exit-code'.

[zetorian]

so, it's not a good solution, but it is a solution. if you wrap the JSON.parse() in a try catch block, this problem dissapears. I'm user there is a better way to fix this, but it's worked for me as a hotfix until someone who actually knows what they are doing can get around to it.

[AndrewJDR]

Please test with this branch: https://github.com/matrix-hacks/matrix-puppet-hangouts/tree/add_hangups_client_debug_logging

That will produce a hangouts_client.log file in the bridge directory. After one of these failures occurs, try to find the offending message inside that log and post it here (redacted, but maintaining the portions that allow for debugging)... thanks