test binarytrees working with only one thread #42774

Activity

1. mscdex

   transferred this issue fromnodejs/nodeon Apr 16, 2022
2. gireeshpunathil commented on Apr 16, 2022

   

   gireeshpunathil

   on Apr 16, 2022

   Member

   More actions

   @mr-ackerman - your program is not multi-threaded (does not make use of worker-threads module), so the the concurrency that you are talking about is not real. The code is always run on the main thread. The additional CPU usage you are observing in other threads may be running something else in the runtime (for example gc threads) and their behaviour can potentially change the overall performance of the code too.
3. C-Ackerman commented on Apr 18, 2022

   

   C-Ackerman

   on Apr 18, 2022

   Author

   More actions

   @gireeshpunathil
   Thank you, I checked the test results locally. The performance of the v16 version is not as good as that of the v12 when the binarytree is 21 layers, but when the number of binarytree layers is less than 18, the performance of the v16 version is much better than that of the v12. Please what is the reason for this problem

   cpu：Intel(R) Core(TM) i7-8700 CPU @ 3.20GHz
   20.04.1-Ubuntu
4. gireeshpunathil commented on Apr 18, 2022

   

   gireeshpunathil

   on Apr 18, 2022

   Member

   More actions

   @mr-ackerman - let me see if I can recreate this behaviour at my end.stay tuned!
5. gireeshpunathil commented on Apr 18, 2022

   

   gireeshpunathil

   on Apr 18, 2022

   Member

   More actions

   • I see what you are saying.
   • on the other hand, if I remove the console.log statements, the difference goes away!
   • can you confirm this behaviour at your end too?

   also, what tool / method you are using to measure performance?
6. C-Ackerman commented on Apr 18, 2022

   

   C-Ackerman

   on Apr 18, 2022

   Last edited by C-Ackerman

   Author

   More actions

   @gireeshpunathil
   Yes, console.log does affect performance. I use the stopwatch of the mobile phone to time the execution time of this binarytrees code (because the running time is very long and does not need to be very precise). When using v16.14.2 to run the following code, if there is console.log It took 23s, and it took 13s to delete all console.log. The checksum(longLivedTree) function needs to be executed. In the v12 version, the console.log does not affect the performance. It takes 15s to delete and not delete the console.log

   node 1.js 21
   

   /* The Computer Language Benchmarks Game
    * https://salsa.debian.org/benchmarksgame-team/benchmarksgame/
    *
    * contributed by François Pirsch
    * Based on the node.js program from Léo Sarrazin and Andrey Filatkin
    * Remove worker_threads usage by hanabi1224
   */
   console.log(process.version)
   console.time()
   
   
   function main() {
   
       const maxDepth = Math.max(6, +process.argv[2] || 0);
       const stretchDepth = maxDepth + 1;
       const stretchTree = createTree(stretchDepth)
       // console.log(`stretch tree of depth ${stretchDepth}\t check: ${checksum(stretchTree)}`)
       const longLivedTree = createTree(maxDepth);
   
       for (let depth = 4; depth <= maxDepth; depth += 2) {
           const iterations = 1 << maxDepth - depth + 4;
           let sum = 0;
           for (var i = 0; i < iterations; i++) {
               const tree = createTree(depth)
               sum += checksum(tree)
           }
           // console.log(`${iterations}\t trees of depth ${depth}\t check: ${sum}`)
       }
   
       console.log(`long lived tree of depth ${maxDepth}\t `);
       checksum(longLivedTree);
       // console.log(
       //     `long lived tree of depth ${maxDepth}\t check: ${checksum(longLivedTree)}`
       // );
       console.log(`--long lived tree of depth ${maxDepth}\t `);
   }
   
   function checksum(node) {
       if (!node.left) {
           return 1;
       }
       return 1 + checksum(node.left) + checksum(node.right);
   }
   
   function createTree(depth) {
       return depth-- > 0
           ? { left: createTree(depth), right: createTree(depth) }
           : { left: null, right: null };
   }
   
   main()
   
   console.timeEnd()
   
   

   👍React with 👍1Reacted by Gireesh Punathil
7. gireeshpunathil commented on Apr 18, 2022

   

   gireeshpunathil

   on Apr 18, 2022

   Last edited by gireeshpunathil

   Member

   More actions

   thanks @mr-ackerman - with that, I am able to recreate the issue in a smaller test case, showing more than 100% perf degradation.

   let t1 = Date.now();
   const o = {}
   let temp = o
   for(var i=0; i < process.argv[2] * 1000000; i++) {
     temp[i] = {}
     temp = temp[i]
   }
   let t2  = Date.now();
   console.log(`time: ${t2 - t1}`)

   # n12/node rec 10
   time: 2660
   # n16/node rec 10
   time: 6045
   

   Not sure what is responsible for this, and whether this is expected or documented somewhere.

   Will check with v8 team to see what do they recommend. Also let this go back to core.

   /cc @nodejs/v8

   👍React with 👍1Reacted by Ackerman
8. gireeshpunathil

   transferred this issue fromnodejs/helpon Apr 18, 2022
9. gireeshpunathil

   added

   performanceIssues and PRs related to the performance of Node.js.Issues and PRs related to the performance of Node.js.

   on Apr 18, 2022
10. camillobruni commented on Apr 19, 2022

    

    camillobruni

    on Apr 19, 2022

    Contributor

    More actions

    It's not as easy to assess the true performance here.

    • process.argv[2] seems like something you want to store in separate variable
    • Does the performance diff go away if you don't create a new object here: temp[i] = {};?

    If you can, maybe try to run a linux-perf profile to see where we spend time (or --runtime-call-stats)
11. C-Ackerman commented on Apr 19, 2022

    

    C-Ackerman

    on Apr 19, 2022

    Last edited by C-Ackerman

    Author

    More actions

    @camillobruni
    Creating a new object (temp[i] = {};) will affect performance, grab the trace as shown, GC takes up a lot of time

    let t1 = Date.now();
    const o = {}
    const o1 = {}
    let temp = o
    for(var i=0; i < process.argv[2] * 1000000; i++) {
    //   temp[i] = {}
      temp[i] = o1
      temp = temp[i]
    }
    let t2  = Date.now();
    console.log(`time: ${t2 - t1}`)
    

    //v16.14.2
    // temp[i] = o1
    @:bin$ ./node --trace-event-categories=v8,node,node.async_hooks,node.console,node.environment --trace-event-file-pattern='node-trace-nodeo1.log' test.js 10
    time: 576
    
    // temp[i] = {}
    @:bin$ ./node --trace-event-categories=v8,node,node.async_hooks,node.console,node.environment --trace-event-file-pattern='node-trace-node.log' test.js 10
    time: 5146
    

    v16：
    
    

    v12：
    
    
12. camillobruni commented on Apr 19, 2022

    

    camillobruni

    on Apr 19, 2022

    Contributor

    More actions

    Perfect, could you check that this is still the case in node v17.
13. C-Ackerman commented on Apr 19, 2022

    

    C-Ackerman

    on Apr 19, 2022

    Last edited by C-Ackerman

    Author

    More actions

    v17.9.0 no difference
    test.js
    
    

    👍React with 👍1Reacted by Gireesh Punathil
14. gireeshpunathil commented on Apr 19, 2022

    

    gireeshpunathil

    on Apr 19, 2022

    Member

    More actions

    looks like there are more gc activities in v16 and v17:

    #grep "Mark-sweep" 12 | wc -l
           2
    #grep "Mark-sweep" 16 | wc -l
          57
    #grep "Mark-sweep" 17 | wc -l
          57
    #grep "Scavenge" 12 | wc -l
         132
    #grep "Scavenge" 16 | wc -l
         246
    #grep "Scavenge" 17 | wc -l
         246
    #
    

    wherein the files with numbers are all output of --trace-gc of corresponding runs with matching versions.

    • are there changes in sizes in the semi-space and old space between versions?
    • are there changes in conditions for kicking in gc (minor/major) between versions?
15. C-Ackerman commented on Apr 19, 2022

    

    C-Ackerman

    on Apr 19, 2022

    Last edited by C-Ackerman

    Author

    More actions

    @camillobruni
    But executing the binarytrees code I modified before, whether or not the console.log is executed, v17 does not perform well.

    v17.9.0：
    
    

    v16.14.2：
    

    

    v12.18.4：
    
    
16. mlippautz commented on Apr 19, 2022

    

    mlippautz

    on Apr 19, 2022

    More actions

    Can you file a bug on crbug.com/v8 mentioning the corresponding V8 versions? Thanks a lot!
17. C-Ackerman commented on Apr 20, 2022

    

    C-Ackerman

    on Apr 20, 2022

    Author

    More actions

    Can you file a bug on crbug.com/v8 mentioning the corresponding V8 versions? Thanks a lot!
    bug has been submitted:
    https://bugs.chromium.org/p/v8/issues/detail?id=12812
18. gireeshpunathil

    added

    confirmed-bugIssues and PRs for confirmed bugs.Issues and PRs for confirmed bugs.

    v8 engineIssues and PRs related to the V8 dependency.Issues and PRs related to the V8 dependency.

    on Apr 20, 2022
19. inoway46 commented on Jul 31, 2026

    

    inoway46

    on Jul 31, 2026

    Contributor

    More actions

    https://bugs.chromium.org/p/v8/issues/detail?id=12812
    This upstream issue was closed as WontFix. The affected Node.js versions (12, 16, and 17) are now EOL, and no Node.js-specific fix remains to track.
    Should we close this as not planned?
20. inoway46

    closed this as not plannedon Sep 18, 2026