TypeError: Cannot read property 'substring' of undefined - RESTART!

[micah]

We have a very active set of pads, with several hundred users on them. Unfortunately, something is causing etherpad to restart on a regular basis, this is the log of when it does:

[2015-11-17 07:27:54.247] [WARN] client - Uncaught TypeError: Cannot read property 'data' of undefined -- { errorId: 'ZdIdZ8nXVLQTE9tVbPgb',
  msg: 'Uncaught TypeError: Cannot read property \'data\' of undefined',
  url: '[REDACTED]',
  linenumber: 3902,
  userAgent: 'Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36' }
[2015-11-17 07:28:13.168] [WARN] client - TypeError: undefined is not an object (evaluating 'rowsPresent[index].data') -- { errorId: '7FGxdP5milNbRykoStKV',
  msg: 'TypeError: undefined is not an object (evaluating \'rowsPresent[index].data\')',
  url: '[REDACTED]',
  linenumber: 3902,
  userAgent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/601.2.7 (KHTML, like Gecko) Version/9.0.1 Safari/601.2.7' }
[2015-11-17 07:28:45.256] [WARN] client - SyntaxError: expected expression, got ')' -- { errorId: 'X45Sz4e8TZIuMmRRkoCA',
  msg: 'SyntaxError: expected expression, got \')\'',
  url: '[REDACTED]',
  linenumber: 1,
  userAgent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:38.0) Gecko/20100101 Firefox/38.0' }
[2015-11-17 07:28:46.691] [WARN] client - Uncaught Error: Failed assertion: mismatched apply: 6831 / 6841 -- { errorId: 'I07sb37FnB4hqN8MEU8S',
  msg: 'Uncaught Error: Failed assertion: mismatched apply: 6831 / 6841',
  url: '[REDACTED]',
  linenumber: 492,
  userAgent: 'Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36' }
[2015-11-17 07:28:46.779] [WARN] client - Error: Failed assertion: mismatched apply: 6831 / 6840 -- { errorId: 'mpoHFiJQyUqHJG6BmXc1',
  msg: 'Error: Failed assertion: mismatched apply: 6831 / 6840',
  url: '[REDACTED]',
  linenumber: 5871,
  userAgent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:42.0) Gecko/20100101 Firefox/42.0' }
[2015-11-17 07:28:56.631] [ERROR] console - TypeError: Cannot read property 'substring' of undefined
    at Object.insert (/srv/etherpad-lite/src/static/js/Changeset.js:794:44)
    at Object.exports.mutateTextLines (/srv/etherpad-lite/src/static/js/Changeset.js:966:11)
    at /srv/etherpad-lite/src/node/handler/PadMessageHandler.js:1511:19
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:610:21
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:249:17
    at iterate (/srv/etherpad-lite/src/node_modules/async/lib/async.js:149:13)
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:160:25
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:251:21
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:615:34
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:254:17
RESTART!

[webzwo0i]

which commit are you using? can you cherry pick #2801

[micah]

8359756

[micah]

I tried to cherry-pick 1ee1f81 to start, but got a conflict that I was not sure how to resolve. I suspect your version is based off of a different place than the 1.5.7 release?

[webzwo0i]

try cherry-picking 31f7c7e before 1ee1f81

[micah]

thanks, cherry-picked both of those and restarted the server, will report back

[micah]

Just got another restart:

[2015-11-17 09:51:37.247] [ERROR] console - TypeError: Cannot read property 'substring' of undefined
    at Object.insert (/srv/etherpad-lite/src/static/js/Changeset.js:794:44)
    at Object.exports.mutateTextLines (/srv/etherpad-lite/src/static/js/Changeset.js:966:11)
    at /srv/etherpad-lite/src/node/handler/PadMessageHandler.js:1517:19
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:610:21
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:249:17
    at iterate (/srv/etherpad-lite/src/node_modules/async/lib/async.js:149:13)
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:160:25
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:251:21
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:615:34
    at /srv/etherpad-lite/src/node_modules/async/lib/async.js:254:17
RESTART!

[webzwo0i]

ok I try to find the bug.
as a workaround you can filter GET requests to /p//timeslider (which will block accessing timeslider and clients from accidently triggering the bug) or insert "return" right at the beginning of handleChangesetRequest in PadMessageHandler.js

[micah]

Do you mean in the function, like this:

function handleChangesetRequest(client, message)
{
+  return;
  //check if all ok
  if(message.data == null)
  {
    messageLogger.warn("Dropped message, changeset request has no data!");
    return;
  }

Because I tried that and the timeslider is still working.

[webzwo0i]

yep, it's loading timeslider's html but you won't be able to issue requests to the timeslider (which contain the actual revisions) - at least it should work like this imo :)

[JohnMcLear]

*bump

[webzwo0i]

I can reproduce the bug now but the test data is huge and the area it occurs is not documented. investigating now, but not sure I'll find it today...

[joergludwig]

I have got the same problem over here:
[2016-01-11 13:17:46.347] [ERROR] console - TypeError: Cannot call method 'substring' of undefined
at Object.insert (/usr/share/etherpad-lite/src/static/js/Changeset.js:794:45)
at Object.exports.mutateTextLines (/usr/share/etherpad-lite/src/static/js/Changeset.js:966:11)
at async.series.callback.forwardsChangesets (/usr/share/etherpad-lite/src/node/handler/PadMessageHandler.js:1540:19)
at /usr/share/etherpad-lite/src/node_modules/async/lib/async.js:610:21
at /usr/share/etherpad-lite/src/node_modules/async/lib/async.js:249:17
at iterate (/usr/share/etherpad-lite/src/node_modules/async/lib/async.js:149:13)
at /usr/share/etherpad-lite/src/node_modules/async/lib/async.js:160:25
at /usr/share/etherpad-lite/src/node_modules/async/lib/async.js:251:21
at /usr/share/etherpad-lite/src/node_modules/async/lib/async.js:615:34
at /usr/share/etherpad-lite/src/node_modules/async/lib/async.js:254:17

I was able to reproduce the problem on a different server by exporting and importing the affected etherpad. Unfortunately I cannot publish the file as it contains data of our customers.

[joergludwig]

I was able to remove all custom text from the etherpad while preserving the error.

Steps to reproduce:

1. Download and unzip attached file.
2. Create new pad.
3. Import etherpad file.
4. Open history.
5. Jump back some time.
6. Etherpad crashes.

[micah]

Just wanted to add some additional missing information here... we were also getting restarts/crashes when the export was done. Not always, but probably with certain pads with characters/character sets that were not filtered properly. This was causing us such a problem that we had to disable pad exports... but this is something people need so we would like to be able to re-enable it!