[socket.io.js] document.createElement is not a function

[dtopuzov]

From @warren-bank on September 21, 2016 23:48

(edit: you can jump ahead to my final comment.. to see the very minor code patch I would suggest be applied, which would fix this issue)

I was super pleased to discover that the karma test runner could be used in conjunction with the interactive debugger:
tns test android --debug-brk

However, I did want to raise one small issue..

The application crashed because of an uncaught exception. You can look at "stackTrace" or "nativeException" for more detailed information about the exception.
com.tns.NativeScriptException: 
Calling js method run failed

TypeError: document.createElement is not a function
File: "/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js, line: 201, column: 25

StackTrace: 
    Frame: function:'JSONPPolling.doPoll', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 1085, column: 25
    Frame: function:'Polling.poll', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 1740, column: 8
    Frame: function:'Polling.doOpen', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 1684, column: 8
    Frame: function:'Transport.open', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 827, column: 10
    Frame: function:'Socket.open', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 248, column: 13
    Frame: function:'Socket', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 129, column: 8
    Frame: function:'Socket', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 55, column: 41
    Frame: function:'Manager.open.Manager.connect', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 4549, column: 17
    Frame: function:'', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/socket.io.js', line: 4859, column: 12
    Frame: function:'ZoneDelegate.invokeTask', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js', line: 323, column: 38
    Frame: function:'Zone.runTask', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js', line: 223, column: 48
    Frame: function:'ZoneTask.invoke', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js', line: 391, column: 34
    Frame: function:'ZoneDelegate.invoke', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js', line: 290, column: 29
    Frame: function:'Zone.runGuarded', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js', line: 197, column: 48
    Frame: function:'', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/zone.js/dist/zone-node.js', line: 173, column: 30
    Frame: function:'java.lang.Runnable.run', file:'/data/data/org.nativescript.ExampleProject/files/app/tns_modules/timer/timer.js', line: 17, column: 13

the file nativescript-unit-test-runner/socket.io.js is pretty much littered with references to the DOM, and attempts to perform DOM updates.

in particular:

• JSONPPolling.prototype.doPoll
• JSONPPolling.prototype.doWrite
• useColors
• localstorage
• various references to: navigator.userAgent

I haven't done any digging into this.
I'm not aware of the low-level details of precisely how socket.io is used by the test runner,
or why the debugger would trigger additional polling,
or why this error didn't occur while either:

• debugging "app/main.js"
• unit testing "app/tests/*.js"

and only occurs while debugging these unit tests.

Maybe this is nothing more than pilot error (on my part)..
I wouldn't rule it out, though I don't think that I've done anything wrong.

In any case, I just wanted to share my observations..
in case somebody who knows the code and how things are glued together..
might read this and mutter: "oh shoot, yep.. easy fix"

Copied from original issue: NativeScript/nativescript-unit-test-runner#17

[dtopuzov]

From @warren-bank on September 22, 2016 0:55

wait.. there's a chance this is the result of something I did wrong (pilot error)..
I'm re-running some tests now, and will report back shortly..

[dtopuzov]

From @warren-bank on September 22, 2016 1:48

ok.. it's a legit issue.. has nothing to do with a bit of zone.js error-catching trickery that I had in place.

• commented the trickery out entirely.. so zone.js wasn't even included under tns_modules
• added a single breakpoint in socket.io.js within the function JSONPPolling.prototype.doPoll at the line where document.createElement is first used
• ran the tests until the breakpoint was reached (it was)
• stepped over it.. and sure enough.. uncaught exception

[dtopuzov]

From @warren-bank on September 22, 2016 1:57

incidentally.. and feel free to completely ignore this suggestion.. which has very little to do with the issue at hand (though it may actually help to catch this and other uncaught exceptions, and conditionally ignore them).. but is just a feature that you may want to consider including.. possibly as an optional feature that could be toggled on/off with a boolean flag in karma.conf.js

and please keep in mind that this code is very rough.. and I'm still working on getting it right.. but something along the lines of:

/* ------------------------------------------------------------------
 * summary:
 * --------
 * all tests are passed to the testing framework
 * using the function signature:
 *     it('Do this and then do that', function (done) {...}
 *
 * when timers (ex: setTimeout) are called by the code under test,
 * Exceptions that may occur when the timer triggers will NOT
 * be caught by the testing framework,
 * and will result in the test suite ending prematurely,
 * with a terse error message about an "uncaught Exception".
 *
 * the purpose of this file is to use "zone.js"
 * to wrap the "it" function,
 * in such a way that Exceptions raised by asynchronous timers
 * will NOT result in an "uncaught Exception".
 *
 * the Zone will report the error to mocha,
 * which will then fail the particular test,
 * and then continue processing the remainder of the test suite.
 * ------------------------------------------------------------------
 * references:
 * -----------
 * https://github.com/angular/zone.js/
 * https://github.com/angular/zone.js/issues/418
 * https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Function/length
 * ------------------------------------------------------------------
 */

require('zone.js/dist/zone-node');

var old_it = global.it;

var new_it = function(desc, test){
  // it.skip()
  if (test === undefined){
    return old_it(desc);
  }

  var my_done;
  var my_zone = global.Zone.current.fork({
    onHandleError: function(){
      var error = arguments[3];
      my_done(error);

      // zone-node.js, lines: 201, 292
      // return value serves as a boolean flag for whether or not to throw the exception.
      //   - truthy: throw, which will be uncaught and crash the test runner.
      return false;
    }
  });

  return old_it(desc, function(done){
    my_done = done;

    my_zone.run(function(){
      test(done);

      if (test.length === 0){
        done();
      }
    });
  });
};

new_it.skip    = old_it.skip;
new_it.only    = old_it.only;
new_it.retries = old_it.retries;

global.it = new_it;

• I save this file to: "app/tests/lib/zones.js"
• I configure karma.conf.js:

...
    files: [
      'app/components/**/*.js',
      'app/*.js',
      'app/tests/*.js'
    ],
    frameworks: ['mocha', 'chai'],
    reporters: ['mocha'],
    colors: false,
    singleRun: true,
    captureTimeout             : 300000,  // default: 60,000
    browserDisconnectTimeout   :  10000,  // default:  2,000
    browserDisconnectTolerance :      1,  // default:      0
    browserNoActivityTimeout   :  50000,  // default: 10,000
...

• all of the actual tests are saved to: "app/tests/units/*.js"
• the main testing entry point is saved to: "app/tests/run_all.js"
  
  this file contains:

require('./lib/zones.js');

global.mocha.setup({
  timeout: 300000
});

global.chai.config.includeStack      = true;
global.chai.config.truncateThreshold = 0;

global.chai.use( require('./lib/chai-as-promised.js') );

describe('test suite', function () {
  require('./units/test.01.js');
  require('./units/test.02.js');
  require('./units/test.03.js');
});

[dtopuzov]

From @warren-bank on September 22, 2016 5:29

sorry for being so verbose, but i have a few additional observations regarding the issue..

• base directory for filepaths:
  ExampleProject/platforms/android/src/main/assets/app/tns_modules/nativescript-unit-test-runner
• file: config.js
  
  contents: module.exports = {"port":"9876","ips":["192.168.1.104","127.0.0.1"],"options":{"debugTransport":false,"debugBrk":true,"watch":false}}
• file: main-view-model.js
  
  contents:

...
function enableSocketIoDebugging() {
    console.log('enabling socket.io debugging');
    global.localStorage = {
        debug: "*"
    };
    global.window = global;
}
var config = require('./config');
...
if (config.options.debugTransport) {
    enableSocketIoDebugging();
}
...
var io = require('./socket.io');
var socket = this.socket = io.connect(this.baseUrl, {forceBase64: true});
...
if (config.options.debugBrk) {
    debugger;
}
...

• file: socket.io.js
  
  contents:

module.exports = exports = lookup;
exports.connect = lookup;

function lookup(uri, opts) {
  ...
  io = Manager(source, opts);
  ...
  return io.socket(parsed.path);
}

Manager.prototype.socket = function(nsp){
  ...
  socket = new Socket(this, nsp);
  ...
};

function Socket(uri, opts){
  ...
  this.transports = opts.transports || ['polling', 'websocket'];
  ...
}

• this makes me think that the fix is as simple as passing an additional option in..
  
  file: main-view-model.js
  
  code: var socket = this.socket = io.connect(this.baseUrl, {forceBase64: true, transports: ['websocket']});
• testing now..

[dtopuzov]

From @warren-bank on September 22, 2016 6:36

(update: please disregard the information in this comment)

yeah, looks good now.

I'm stepping through an enormous test suite..
giving it plenty of time to poll or do whatever else might cause a problem..
I left the breakpoint in "socket.io.js" but it hasn't been hit at all..
it may be premature to call this patch a fix, but it certainly appears to be.

short tldr; version

• file: nativescript-unit-test-runner/main-view-model.js
• code:
  • current value:
    var socket = this.socket = io.connect(this.baseUrl, {forceBase64: true});
  • new/updated value:
    var socket = this.socket = io.connect(this.baseUrl, {forceBase64: true, transports: ['websocket']});

[dtopuzov]

From @warren-bank on September 22, 2016 7:36

(update: please disregard the information in this comment)

I have another observation, which is loosely related and most-likely a fairly minor issue..

• I walked away from my debug session for a long time, leaving execution halted at a breakpoint
• I returned and attempted to continue the session
• the following log message appeared in the output console:

NSUTR-socket.io: transport close
    /data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/main-view-model.js:90

NSUTR-socket.io: 1
    /data/data/org.nativescript.ExampleProject/files/app/tns_modules/nativescript-unit-test-runner/main-view-model.js:90

• then execution stopped at the breakpoint that I had set in socket.io.js at the line in JSONPPolling.prototype.doPoll that touches the DOM and triggers the uncaught exception

so..

• the DOM is no-longer touched during an active session by periodic polling, which is the important thing
• however, when the web socket is closed by the server and code in the mobile app attempts to re-open it.. things blow up, which is less important.. since this shouldn't happen during normal usage

[dtopuzov]

From @warren-bank on September 22, 2016 8:56

ok, this is embarrassing..

• turns out that there's a side-effect to running the command: tns test android --debug-brk
  • the file:
    ExampleProject/platforms/android/src/main/assets/app/tns_modules/nativescript-unit-test-runner/main-view-model.js
  • is over-written by the file:
    ExampleProject/node_modules/nativescript-unit-test-runner/main-view-model.js
  • so any changes made to the contents of the former are lost before the test runner loads
  • and, consequently, all of my "observations" thus far are wrong..

here's what I'm seeing now:

• using the options: forceBase64: true, transports: ['websocket']

  • "socket.io" cannot connect to "karma"

    NSUTR: connecting to karma at http://192.168.1.104:9876
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 1
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 2
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 3
    NSUTR: socket.io error on connect: timeout
    

• using the options: forceBase64: true, transports: ['websocket'], jsonp: false

  • "socket.io" cannot connect to "karma"

    NSUTR: connecting to karma at http://192.168.1.104:9876
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 1
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 2
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 3
    NSUTR: socket.io error on connect: timeout
    

• using the options: forceBase64: true, jsonp: false

  • "socket.io" connects to "karma"

    NSUTR: successfully connected to karma
    ...
    NSUTR: beginning test run
    

  • interactive debugging works well..

  • ok, now I have some real proof that this is the option that prevents the uncaught exception:
    
    a few minutes into my session, the following log messages appeared in the console:

    NSUTR-socket.io: transport close
    NSUTR-socket.io: 1
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 2
    NSUTR: socket.io error on connect: timeout
    NSUTR-socket.io: 3
    

  • however, the breakpoint in socket.io.js at the line in JSONPPolling.prototype.doPoll that touches the DOM and triggers the uncaught exception was not reached

  • so.. the option {jsonp: false} is the one that prevents attempts at intra-session DOM updates (ie: adding jsonp <script> tags)

took a while, but we got there :)

[dtopuzov]

From @warren-bank on September 22, 2016 9:1

updated:

short tldr; version

• file: nativescript-unit-test-runner/main-view-model.js
• code:

  • current value:

        var socket = this.socket = io.connect(this.baseUrl, {
            forceBase64: true
        });

  • new/updated value:

        var socket = this.socket = io.connect(this.baseUrl, {
            forceBase64: true,
            jsonp: false
        });

[dtopuzov]

From @warren-bank on September 22, 2016 22:31

a few closing comments regarding reconnect attempts..

• I have no idea why the connection closes

• I have no idea why attempts to reconnect fail

  • in my karma.conf.js, I had changed the value

    • from: singleRun: false
    • to: singleRun: true

    and thought that maybe that was the reason that the server closed its connection and became unavailable, but I changed the value back to test that assertion and the behavior was unchanged

• after the connection is closed, the debugger continues to function correctly.
  as such..

• if reconnection is not important, then I would recommend that we add the additional option:

    var socket = this.socket = io.connect(this.baseUrl, {
        forceBase64: true,
        jsonp: false,
        reconnection: false
    });

• if completely disabling reconnect attempts is too extreme, then maybe we could set a finite limit on the number of attempts?

    var socket = this.socket = io.connect(this.baseUrl, {
        forceBase64: true,
        jsonp: false,
        reconnectionAttempts: 5
    });

  the default behavior is to make infinite attempts, at intervals determined by a backoff strategy. this results in log messages pertaining to the reconnect attempts being scattered throughout the console output.

[pkoleva]

Hey @warren-bank ,

Do you still have an issue with that or you've found a workaround to the problem?

[warren-bank]

Hi,

Wish I could offer additional insight beyond the original thread of code/observations, but I haven't used NativeScript in quite a while.. so I'm not sure if this has been addressed/solved in the time since then.

As for a workaround, please refer to the 2 comments that precede yours. That's what I ended up doing at the time, and it worked just fine. Specifically:

• in file: nativescript-unit-test-runner/main-view-model.js
• changed code to:

var socket = this.socket = io.connect(this.baseUrl, {
  forceBase64: true,
  jsonp: false,
  reconnection: false
});

I'm a big fan of what you guys are building. When I swing back around to doing mobile UI, I'm sure I'll start using it again.

Sorry I couldn't be more helpful.

[warren-bank]

Hi again,

I just took a quick peek at the repo.
Here is the current version of the (above mentioned) file (before being transpiled to js).
Looks like that line of code hasn't been changed.