0

As I am trying to figure out why the loading process of my webpage (dxview) takes so long, I decided to put some console.log() statements in both the code before and after an eval() (part of that process) and the string inside that very eval(). It looks somewhat like this:

console.log("Timestamp before eval: " + (new Date().getTime()));
eval("... console.log('Some log in here'); ...");
console.log("Timestamp after eval: " + (new Date().getTime()));

Interestingly, the result was in another order than I expected:

"Timestamp before eval: 1423852110738"
"Timestamp after eval: 1423852110787"
"Some log in here"

This makes it very hard to detect the actual time consuming part as using timestamps this way does not even indicate whether the eval is the problem.

Putting logs at the beginning and end of the eval'ed string indicate that the eval actually takes 250 to 350 ms to process while the difference between the two timestamps is just 49 ms. But until the viewShown method is invoked, it takes another 23,000+ ms.

AFAIK, if you don't use web workers or timeouts/intervals, JS should continue with the code just after (and not before) a statement is done. I might be confusing something here, but how could this work then?

Kind regards,
jaySon

jaySon
  • 795
  • 2
  • 7
  • 20
  • ps, for quick and dirty timestamps in the console, you can be lazier: `console.log("Timestamp before eval: ", +new Date );` – dandavis Feb 13 '15 at 19:15
  • Or on any modern browser: `console.log(Date.now() + " ... ");` – T.J. Crowder Feb 13 '15 at 19:18
  • @dandavis: `console.log` is **not** async. But if you log objects, with the console open, in some versions of the console, display of their *content* may be done later when you expand them. But logging simple strings doesn't exhibit that behavior. – T.J. Crowder Feb 13 '15 at 19:19
  • **It doesn't.** jaySon, the code you've shown does not produce the output you describe: http://jsbin.com/bamupucaci/1 My guess is that the content of the `...` matters. – T.J. Crowder Feb 13 '15 at 19:21
  • What is the magical code in the eval. My guess is you are doing something asynchronous. – epascarello Feb 13 '15 at 19:22
  • @T.J.Crowder: i misread the question and thought it took 23 seconds for the log to show up. the console rendering is async, or at least buffered internally, the actual log() call (like all js function calls) is sync. – dandavis Feb 13 '15 at 19:30

1 Answers1

0

The only reason I can think of is that, in eval(), did you put the console.log() inside of an async callback, which would explain the order of the console.log messages.

If everything is sync, the order of the messages should be :

"Timestamp before eval: 1423852110738"
"Some log in here"
"Timestamp after eval: 1423852110787"

My suggestion is, instead of logging end time after eval(), figure out when the eval() part actually ends (meaning that all the async methods finished), and log the end time right there.

for example, if you have an async function inside of the eval():

console.log("Timestamp before eval: " + (new Date().getTime()));
eval("setTimeout(function(){
    console.log('Timestamp after eval: ' + (new Date().getTime()));
}, 1000);");

In this fashion, you should be able to figure out exactly how long does it take for all the functions to complete.

Thanks.

Levi Lu
  • 66
  • 2