Investigate Node.js High CPU issue in Linux App Service

Published Sep 21 2021 10:45 PM 2,339 Views
Microsoft

When running your Node.js application in Azure Linux App Service, you may encounter High CPU consumption issue.

 

v8-profiler-node8 is one of the tools that can help us profile the CPU usage of a Node.js application.
Normally, we need to explicitly insert code to control where to start and stop profiling in the application code. But for complex applications running in production mode, it's hard to decide at which position of the code to start/stop profiling. Also, it will generate too many profiler result files if we continuously profiling a running App Service.

 

This article describes an idea of how to control the v8 profiler using process signal in Linux App Service.
You can find the detailed steps of:

  • How to install and inject v8 CPU profiler in your Node.js application code
  • How to capture CPU profiler dump in Linux App Service
  • How to use Google Chrome Developer tools to analyze the profiler file.

 

How to install and inject v8 CPU profiler in your Node.js application code

  1. Install the "v8-profiler-node8" module
    In general, we just need to use npm to install the "heapdump" module 
    npm install v8-profiler-node8​

    For your Node.js application going to deploy to Azure App Service, we can define it in your package.json "dependencies" section like the following:
    Hanli_Ren_1-1630739142227.png

     

  2. Then, you need to load the v8-profiler-node8 module into your application

    For example, in my Node Express project, I put the following line in my app.js file.

    var heapdump = require(' v8-profiler-node8 ')

    Hanli_Ren_2-1630739235879.png

     

  3. To make the CPU profiler able to be controlled by process Signal, we can use the following code in the app.js file
    const profiler = require('v8-profiler-node8');
    const fs = require('fs');
    var profilerRunning = false;
    	 
    function toggleProfiling () {
      if (profilerRunning) {
    	const profile = profiler.stopProfiling();
    	console.log('>>>>stopped profiling at '+Date.now());
    	profile.export()
    	      .pipe(fs.createWriteStream('./v8-'+Date.now()+'.cpuprofile'))
    	      .once('error',  profiler.deleteAllProfiles)
    	      .once('finish', profiler.deleteAllProfiles);
    	profilerRunning = false;
    	return;
       }
       profiler.startProfiling();
       profilerRunning = true;
       console.log('>>>>>>started profilingat '+Date.now());
    }
    
    process.on('SIGUSR1', toggleProfiling);
    

    Hanli_Ren_3-1630739475716.png


How to capture CPU profiler dump in Linux App Service

  1. Login to your Node.js Linux App Service WEBSSH console.
    https://<webapp-name>.scm.azurewebsites.net/webssh/host

     

  2. Find your Node.js application process ID
    # ps aux | grep node 

    Hanli_Ren_1-1630739999129.png

     

  3. Capture CPU profiler while running performance test on the website.
    ○ Start the CPU profiling by send the First -SIGUSR1 signal to the running Node process
    ○ Run test on the website
       For example:
       Accessing the https://<web-app-name>.azurewebsites.net/highCpuCall
    ○ Stop the CPU profiling by send the Second -SIGUSR1 signal to the same Node process
       The v8 profiler will generate a v8-<timestamp>.cpuprofile file under /home/site/wwwroot folder.
    Hanli_Ren_0-1630739926397.png

     

How to use Google Chrome Developer tools to analyze the profiler file

  1. In you local machine, open your Google Chrome Browser.
    Then use F12 to open Chrome Dev Tools.
    Find and open "More tools" -> "JavaScript Profiler"
    Hanli_Ren_0-1630740149705.png

     

    Load the v8-<timestamp>.cpuprofile file into it:
    Hanli_Ren_1-1630740173691.png

     

  2. You can use "Heavy(Bottom Up)" view to check those .js files and functions that consumed most of the CPU time
    Hanli_Ren_2-1630740262059.pngYou can also use "Chart" view to find the function that consumed high CPU time.
    Hanli_Ren_3-1630740284393.png

     

%3CLINGO-SUB%20id%3D%22lingo-sub-2719333%22%20slang%3D%22en-US%22%3EInvestigate%20Node.js%20High%20CPU%20issue%20in%20Linux%20App%20Service%3C%2FLINGO-SUB%3E%3CLINGO-BODY%20id%3D%22lingo-body-2719333%22%20slang%3D%22en-US%22%3E%3CP%3EWhen%20running%20your%20Node.js%20application%20in%20Azure%20Linux%20App%20Service%2C%20you%20may%20encounter%20High%20CPU%20consumption%20issue.%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%3E%3CA%20href%3D%22https%3A%2F%2Fmicrosoftapc-my.sharepoint.com%2Fpersonal%2Fhanren_microsoft_com%2F_layouts%2FOneNote.aspx%3Fid%3D%252Fpersonal%252Fhanren_microsoft_com%252FDocuments%252FHanli%2520%2540%2520Microsoft%26amp%3Bwd%3Dtarget%2528Blog.one%257CCF92B782-A906-4CA4-BA04-5B073D18B634%252FInvestigate%2520Node.js%2520High%2520CPU%2520issue%2520in%2520Linux%2520App%2520Service%257CEBC50B81-75BA-49F0-82EA-C48EB8CAFC91%252F%2529%2520onenote%3Ahttps%3A%2F%2Fmicrosoftapc-my.sharepoint.com%2Fpersonal%2Fhanren_microsoft_com%2FDocuments%2FHanli%2520%40%2520Microsoft%2FBlog.one%23Investigate%2520Node.js%2520High%2520CPU%2520issue%2520in%2520Linux%2520App%2520Service%26amp%3Bsection-id%3D%7BCF92B782-A906-4CA4-BA04-5B073D18B634%7D%26amp%3Bpage-id%3D%7BEBC50B81-75BA-49F0-82EA-C48EB8CAFC91%7D%26amp%3Bobject-id%3D%7B377DBE2F-E9EC-0972-3387-2FA1B3674D70%7D%26amp%3B28%22%20target%3D%22_self%22%20rel%3D%22nofollow%20noopener%20noreferrer%22%3Ev8-profiler-node8%3C%2FA%3E%20is%20one%20of%20the%20tools%20that%20can%20help%20us%20profile%20the%20CPU%20usage%20of%20a%20Node.js%20application.%3CBR%20%2F%3ENormally%2C%20we%20need%20to%20explicitly%20insert%20code%20to%20control%20where%20to%20start%20and%20stop%20profiling%20in%20the%20application%20code.%20But%20for%20complex%20applications%20running%20in%20production%20mode%2C%20it's%20hard%20to%20decide%20at%20which%20position%20of%20the%20code%20to%20start%2Fstop%20profiling.%20Also%2C%20it%20will%20generate%20too%20many%20profiler%20result%20files%20if%20we%20continuously%20profiling%20a%20running%20App%20Service.%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%3EThis%20article%20describes%20an%20idea%20of%20how%20to%20control%20the%20v8%20profiler%20using%20process%20signal%20in%20Linux%20App%20Service.%3CBR%20%2F%3EYou%20can%20find%20the%20detailed%20steps%20of%3A%3C%2FP%3E%0A%3CUL%3E%0A%3CLI%3EHow%20to%20install%20and%20inject%20v8%20CPU%20profiler%20in%20your%20Node.js%20application%20code%3C%2FLI%3E%0A%3CLI%3EHow%20to%20capture%20CPU%20profiler%20dump%20in%20Linux%20App%20Service%3C%2FLI%3E%0A%3CLI%3EHow%20to%20use%20Google%20Chrome%20Developer%20tools%20to%20analyze%20the%20profiler%20file.%3C%2FLI%3E%0A%3C%2FUL%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CH2%20id%3D%22toc-hId--355993178%22%20id%3D%22toc-hId--350656808%22%3EHow%20to%20install%20and%20inject%20v8%20CPU%20profiler%20in%20your%20Node.js%20application%20code%3C%2FH2%3E%0A%3COL%3E%0A%3CLI%3EInstall%20the%20%22v8-profiler-node8%22%20module%3CBR%20%2F%3EIn%20general%2C%20we%20just%20need%20to%20use%20npm%20to%20install%20the%20%22heapdump%22%20module%26nbsp%3B%3CPRE%20class%3D%22lia-code-sample%20language-bash%22%3E%3CCODE%3Enpm%20install%20v8-profiler-node8%E2%80%8B%3C%2FCODE%3E%3C%2FPRE%3E%3CBR%20%2F%3EFor%20your%20Node.js%20application%20going%20to%20deploy%20to%20Azure%20App%20Service%2C%20we%20can%20define%20it%20in%20your%20package.json%20%22dependencies%22%20section%20like%20the%20following%3A%20%3CBR%20%2F%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_1-1630739142227.png%22%20style%3D%22width%3A%20305px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308110i5E8C8D37D5CD459C%2Fimage-dimensions%2F305x381%3Fv%3Dv2%22%20width%3D%22305%22%20height%3D%22381%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_1-1630739142227.png%22%20alt%3D%22Hanli_Ren_1-1630739142227.png%22%20%2F%3E%3C%2FSPAN%3E%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FLI%3E%0A%3CLI%3EThen%2C%20you%20need%20to%20load%20the%20v8-profiler-node8%20module%20into%20your%20application%3CP%3EFor%20example%2C%20in%20my%20Node%20Express%20project%2C%20I%20put%20the%20following%20line%20in%20my%20app.js%20file.%3CBR%20%2F%3E%3CBR%20%2F%3Evar%20heapdump%20%3D%20require('%20v8-profiler-node8%20')%3C%2FP%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_2-1630739235879.png%22%20style%3D%22width%3A%20556px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308111iADB03EF837463F48%2Fimage-dimensions%2F556x274%3Fv%3Dv2%22%20width%3D%22556%22%20height%3D%22274%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_2-1630739235879.png%22%20alt%3D%22Hanli_Ren_2-1630739235879.png%22%20%2F%3E%3C%2FSPAN%3E%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FLI%3E%0A%3CLI%3E%3CSPAN%20style%3D%22font-family%3A%20inherit%3B%22%3ETo%20make%20the%20CPU%20profiler%20able%20to%20be%20controlled%20by%20process%20Signal%2C%20we%20can%20use%20the%20following%20code%20in%20the%20app.js%20file%3C%2FSPAN%3E%3CPRE%20class%3D%22lia-code-sample%20language-javascript%22%3E%3CCODE%3Econst%20profiler%20%3D%20require('v8-profiler-node8')%3B%0Aconst%20fs%20%3D%20require('fs')%3B%0Avar%20profilerRunning%20%3D%20false%3B%0A%20%20%0Afunction%20toggleProfiling%20()%20%7B%0A%20%20if%20(profilerRunning)%20%7B%0A%20const%20profile%20%3D%20profiler.stopProfiling()%3B%0A%20console.log('%26gt%3B%26gt%3B%26gt%3B%26gt%3Bstopped%20profiling%20at%20'%2BDate.now())%3B%0A%20profile.export()%0A%20%20%20%20%20%20%20.pipe(fs.createWriteStream('.%2Fv8-'%2BDate.now()%2B'.cpuprofile'))%0A%20%20%20%20%20%20%20.once('error'%2C%20%20profiler.deleteAllProfiles)%0A%20%20%20%20%20%20%20.once('finish'%2C%20profiler.deleteAllProfiles)%3B%0A%20profilerRunning%20%3D%20false%3B%0A%20return%3B%0A%20%20%20%7D%0A%20%20%20profiler.startProfiling()%3B%0A%20%20%20profilerRunning%20%3D%20true%3B%0A%20%20%20console.log('%26gt%3B%26gt%3B%26gt%3B%26gt%3B%26gt%3B%26gt%3Bstarted%20profilingat%20'%2BDate.now())%3B%0A%7D%0A%0Aprocess.on('SIGUSR1'%2C%20toggleProfiling)%3B%0A%3C%2FCODE%3E%3C%2FPRE%3E%0A%3CP%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_3-1630739475716.png%22%20style%3D%22width%3A%20464px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308112i09F1694CD4E4CA1B%2Fimage-dimensions%2F464x464%3Fv%3Dv2%22%20width%3D%22464%22%20height%3D%22464%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_3-1630739475716.png%22%20alt%3D%22Hanli_Ren_3-1630739475716.png%22%20%2F%3E%3C%2FSPAN%3E%3C%2FP%3E%0A%3C%2FLI%3E%0A%3C%2FOL%3E%0A%3CH2%20id%3D%22toc-hId-2131519655%22%20id%3D%22toc-hId-2136856025%22%3E%3CBR%20%2F%3EHow%20to%20capture%20CPU%20profiler%20dump%20in%20Linux%20App%20Service%3C%2FH2%3E%0A%3COL%3E%0A%3CLI%3ELogin%20to%20your%20Node.js%20Linux%20App%20Service%20WEBSSH%20console.%20%3CBR%20%2F%3E%3CA%20href%3D%22https%3A%2F%2F%26lt%3Bwebapp-name%26gt%3B.scm.azurewebsites.net%2Fwebssh%2Fhost%22%20target%3D%22_blank%22%20rel%3D%22noopener%20nofollow%20noreferrer%22%3Ehttps%3A%2F%2F%3CWEBAPP-NAME%3E.scm.azurewebsites.net%2Fwebssh%2Fhost%3C%2FWEBAPP-NAME%3E%3C%2FA%3E%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FLI%3E%0A%3CLI%3EFind%20your%20Node.js%20application%20process%20ID%3CPRE%20class%3D%22lia-code-sample%20language-bash%22%3E%3CCODE%3E%23%20ps%20aux%20%7C%20grep%20node%20%3C%2FCODE%3E%3C%2FPRE%3E%0A%3CP%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_1-1630739999129.png%22%20style%3D%22width%3A%20837px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308114iD1F369AB0BEFEC2D%2Fimage-dimensions%2F837x73%3Fv%3Dv2%22%20width%3D%22837%22%20height%3D%2273%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_1-1630739999129.png%22%20alt%3D%22Hanli_Ren_1-1630739999129.png%22%20%2F%3E%3C%2FSPAN%3E%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FLI%3E%0A%3CLI%3ECapture%20CPU%20profiler%20while%20running%20performance%20test%20on%20the%20website.%20%3CBR%20%2F%3E%E2%97%8B%20Start%20the%20CPU%20profiling%20by%20send%20the%20First%20-SIGUSR1%20signal%20to%20the%20running%20Node%20process%3CBR%20%2F%3E%E2%97%8B%20Run%20test%20on%20the%20website%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BFor%20example%3A%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BAccessing%20the%20https%3A%2F%2F%3CWEB-APP-NAME%3E.azurewebsites.net%2FhighCpuCall%3CBR%20%2F%3E%E2%97%8B%20Stop%20the%20CPU%20profiling%20by%20send%20the%20Second%20-SIGUSR1%20signal%20to%20the%20same%20Node%20process%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BThe%20v8%20profiler%20will%20generate%20a%20v8-%3CTIMESTAMP%3E.cpuprofile%20file%20under%20%2Fhome%2Fsite%2Fwwwroot%20folder.%3CBR%20%2F%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_0-1630739926397.png%22%20style%3D%22width%3A%20852px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308113i575A7B30573CC400%2Fimage-dimensions%2F852x233%3Fv%3Dv2%22%20width%3D%22852%22%20height%3D%22233%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_0-1630739926397.png%22%20alt%3D%22Hanli_Ren_0-1630739926397.png%22%20%2F%3E%3C%2FSPAN%3E%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FTIMESTAMP%3E%3C%2FWEB-APP-NAME%3E%3C%2FLI%3E%0A%3C%2FOL%3E%0A%3CH2%20id%3D%22toc-hId-324065192%22%20id%3D%22toc-hId-329401562%22%3EHow%20to%20use%20Google%20Chrome%20Developer%20tools%20to%20analyze%20the%20profiler%20file%3C%2FH2%3E%0A%3COL%3E%0A%3CLI%3EIn%20you%20local%20machine%2C%20open%20your%20Google%20Chrome%20Browser.%3CBR%20%2F%3EThen%20use%20F12%20to%20open%20Chrome%20Dev%20Tools.%20%3CBR%20%2F%3EFind%20and%20open%20%22More%20tools%22%20-%26gt%3B%20%22JavaScript%20Profiler%22%3CBR%20%2F%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_0-1630740149705.png%22%20style%3D%22width%3A%20910px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308115i851FAE0984981443%2Fimage-dimensions%2F910x295%3Fv%3Dv2%22%20width%3D%22910%22%20height%3D%22295%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_0-1630740149705.png%22%20alt%3D%22Hanli_Ren_0-1630740149705.png%22%20%2F%3E%3C%2FSPAN%3E%3CP%3E%26nbsp%3B%3C%2FP%3ELoad%20the%20v8-%3CTIMESTAMP%3E.cpuprofile%20file%20into%20it%3A%3CBR%20%2F%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_1-1630740173691.png%22%20style%3D%22width%3A%20658px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308116iA73E74B475B46B7F%2Fimage-dimensions%2F658x284%3Fv%3Dv2%22%20width%3D%22658%22%20height%3D%22284%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_1-1630740173691.png%22%20alt%3D%22Hanli_Ren_1-1630740173691.png%22%20%2F%3E%3C%2FSPAN%3E%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FTIMESTAMP%3E%3C%2FLI%3E%0A%3CLI%3EYou%20can%20use%20%22Heavy(Bottom%20Up)%22%20view%20to%20check%20those%20.js%20files%20and%20functions%20that%20consumed%20most%20of%20the%20CPU%20time%3CBR%20%2F%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_2-1630740262059.png%22%20style%3D%22width%3A%20999px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308117iBBFF47D09F1A4557%2Fimage-size%2Flarge%3Fv%3Dv2%26amp%3Bpx%3D999%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_2-1630740262059.png%22%20alt%3D%22Hanli_Ren_2-1630740262059.png%22%20%2F%3E%3C%2FSPAN%3EYou%20can%20also%20use%20%22Chart%22%20view%20to%20find%20the%20function%20that%20consumed%20high%20CPU%20time.%3CBR%20%2F%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20image-alt%3D%22Hanli_Ren_3-1630740284393.png%22%20style%3D%22width%3A%20999px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Ftechcommunity.microsoft.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F308118i94A1174D4EAD4A80%2Fimage-size%2Flarge%3Fv%3Dv2%26amp%3Bpx%3D999%22%20role%3D%22button%22%20title%3D%22Hanli_Ren_3-1630740284393.png%22%20alt%3D%22Hanli_Ren_3-1630740284393.png%22%20%2F%3E%3C%2FSPAN%3E%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3C%2FLI%3E%0A%3C%2FOL%3E%3C%2FLINGO-BODY%3E%3CLINGO-LABS%20id%3D%22lingo-labs-2719333%22%20slang%3D%22en-US%22%3E%3CLINGO-LABEL%3ENode.js%3C%2FLINGO-LABEL%3E%3C%2FLINGO-LABS%3E
Co-Authors
Version history
Last update:
‎Sep 04 2021 12:25 AM
Updated by: