davidmarkclements / 0x

🔥 single-command flamegraph profiling 🔥
MIT License
3.23k stars 106 forks source link

How to read Flamegraph for reply.send fastify perf issue #236

Closed matt212 closed 3 years ago

matt212 commented 3 years ago

Hi All, below is my graph generated from autocannon and 0x image rather than issue my concern is how to find find bottleneck and optimized the code the problem here is the reply.send is fastify function and it is pointing to that line so how can one optimize in that situation. any help or pointer would suffice

mcollina commented 3 years ago

There is a lot of inlining happening in your application. One of the things reply.send() does is calling the JSON serializers... You can visualize all of those by passing --interpreted-frames-native-stack to Node.js

matt212 commented 3 years ago

Hi @mcollina , Sure on it and would provide an update on same thanks again also how one can call JSON serializer kinda new to fastify that's all

mcollina commented 3 years ago

how one can call JSON serializer kinda new to fastify that's all

I don't understand... reply.send({ hello: 'world' }) would render that as JSON.

matt212 commented 3 years ago

HI @mcollina this is my reply.send json content

reply.send({
    "rows": [
      {
        "employeesid": 20667907,
        "first_name": "Xinglin",
        "last_name": "Morrin",
        "gender": "F",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667906,
        "first_name": "Xinglin",
        "last_name": "Morrin",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667905,
        "first_name": "Ortrud",
        "last_name": "Binding",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667904,
        "first_name": "Gennady",
        "last_name": "Thiran",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667903,
        "first_name": "Goh",
        "last_name": "Demke",
        "gender": "F",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667902,
        "first_name": "Taegyun",
        "last_name": "Zschoche",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667901,
        "first_name": "Sugwoo",
        "last_name": "Muniz",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667900,
        "first_name": "Haldun",
        "last_name": "Peek",
        "gender": "F",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667899,
        "first_name": "Tsz",
        "last_name": "England",
        "gender": "F",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667898,
        "first_name": "Gererd",
        "last_name": "Plesums",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667897,
        "first_name": "Prasadram",
        "last_name": "Dusink",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667896,
        "first_name": "Basem",
        "last_name": "Ashish",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667895,
        "first_name": "Lenore",
        "last_name": "Schieder",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667894,
        "first_name": "Francesca",
        "last_name": "Covnot",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667893,
        "first_name": "Aiman",
        "last_name": "Vecchi",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667892,
        "first_name": "Mechthild",
        "last_name": "Luft",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667891,
        "first_name": "Goh",
        "last_name": "Ermel",
        "gender": "F",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667890,
        "first_name": "Dzung",
        "last_name": "Candan",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667889,
        "first_name": "Mabry",
        "last_name": "Berstel",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      },
      {
        "employeesid": 20667888,
        "first_name": "Sanjiv",
        "last_name": "Frezza",
        "gender": "M",
        "birth_date": "2018-01-11T18:30:00.000Z",
        "recordstate": true,
        "created_date": "2019-02-28T16:38:09.849Z",
        "updated_date": "2019-02-28T16:38:09.849Z"
      }
    ],
    "count": "2088338"
  })
matt212 commented 3 years ago

Hi @mcollina I tried to run 0x with --interpreted-frames-native-stack but I am getting below error is not a recognized flag `yarn run v1.22.5 $ cd ./app/utils && 0x --interpreted-frames-native-stack app2.js

Error: � --interpreted-frames-native-stack is not a recognized flag` Since I am using 0x to generate the heat graph could you please suggest how should use --interpreted-frames-native-stack in 0x run

matt212 commented 3 years ago

Hi @mcollina got it using below snippet 0x -- node --interpreted-frames-native-stack --perf-basic-prof-only-functions app2.js

matt212 commented 3 years ago

Hi @mcollina I tried running with flag mentioned and please find below zip file for end result 31042.0x.zip In essence, the view is the same . it would great if you have look at it and suggest pointers on the same

mcollina commented 3 years ago

If you click on "native", you'd see that the hottest function is within Node.js core, called from .send(). There is likely some inlined function, try running it with --no-turbo-inlining

matt212 commented 3 years ago

Hi @mcollina thanks for looking into it and sure would run using --no-turbo-inlining and provide an update accordingly

matt212 commented 3 years ago

Hi @mcollina sorry for delayed response , could you please find below performgraph with --no-turbo-inlining 21290.0x.zip

mcollina commented 3 years ago

As you can see, all the time is spent in node.js core writing down your output to the sockets. There is nothing to optimize here.

matt212 commented 3 years ago

Hi @mcollina Thanks for the confirmation and also if you have some time could you please have look at below https://github.com/matt212/Nodejs_Postgresql_VanillaJS_Fastify and provide some feedback thanks again!