Performance, Profiling, Power-Consumption
Klein, Jens
Plone 5.2.2 performance is way better than before. It has less power consumption and is greener now. But how did we found the bottlenecks? What were the action needed to got it faster? Where are our pain points? Can we improve more?
 Thanks everybody for coming to this third session. I'm here to, I'm glad to introduce Jens Klein from Austria. And he will talk to us about performance profiling and power consumption. Go ahead, thanks. Yeah, hello. My name is Jens Klein from Austria. And so I want to talk about this topic. And as you know, you might get a call from a customer saying, Hey, hello, my site is slow. So what to do about it? And, well, that's the thing, blown slow. And this is about performance. And then you need to ask questions. And this is what happens often to me at some people I never heard about calling a platform site and it's low. I got your name from somewhere in the internet. Then you can ask questions like, well, it's a specific page. Slow is it on high load slow or massive rights or overall and yes, you start asking more questions like, did you check your hardware database network? And I say, I checked everything. Yeah, really check first. But then at some point you see, oh, it is blown. So, blown is slow. And now we have to ask questions again. Or we have to look at the instance and inspect it. And several possible paths to go so often the other seems bloated and can be slow in certain situations. So server side code can be slow or even Volto code can be slow. And then you can cash things. So the back end does not need to deliver this but at some point, caching is not enough. And the next, the next time then you mostly got the pass down to something happens in my Python logic. And this is what I want to talk about about the focus on the Python logic, not about caching, not about database optimization or something like that. And there you need a way to find the performance program. So you need tools. And mainly, these three tools, primary py spy, because it's a runtime profiler, then for specific page loads and so on the repose profile and the disassembler from the Python. So what is py spy? It's a great tool than overall. It has a top like output or you can also store the output for later analyzing. But the top like output is really great because you can plug into a live application and look at the application what's happening there in a live process. And there is repose profile. It's a classical Python profiler. This slows down the side opposed to py spy, which just looks at the running process. The profiler really gets in your way and slows down the application. It's the middle where it works with a new Python five to Python with a risky implementation. And you can profile a single request by really and that does not work in life instance but if you copy the database and everything, you can have a profile in the single request and look what really happens there. Then I'm missing one slide anyway. And then you have the disk disassembler for Python, which is used to look at one function on the bytecode level. This is something I rarely use, but it's very powerful to get an insight on what happens on bytecode level. And if you have functions that are called very, very often and this happens, then you can analyze these functions with this. So with these tools, we've, I found some or we found some improvements to clone. So in the blown 520 to 5123. There was some bottlenecks primary and blown dexterity. We to avoid an early provided by call which is expensive and was called very, very often. There were possibility to extend the list of early exits on common attribute calls because attribute to get at attribute calls indexed here are called very often. We optimized cash is the signable cash schema cash. And there was some leftover we found that there's a threat local synchronization was built in for an ancient caching that was refactored but as thanks as a synchronization stuff was kept in and this is very slow as well. Then there were some fancy things happened in soap interface. I never get my fingers dirty in soap interface before but this point I found that this was a place where things are really slowed down and so interface and we in clone use the component architecture very, very often and any in every place. And if there's something slow or optimize able. This hasn't big impact because it's called so often like I didn't reindex index on a midsize database and this was called like hundred 20,000 times one function. And if you optimize something in there then it has an impact. And I found the leftover of a hash override that was then, which usually is a hash, the classical hash of an object is written in C. So if you override the stuff you have bytecode and that slows down things a lot and even removing this hash override, improve the speed of this domain. Then another hash improvement happened in the interface class itself, and found a way to have a five times in look up look up all in subscriptions which is called very, very often. And this was on a bytecode level analyzed I show it later. And also Jason, who supported and reviewed all the stuff as well and did some improvements and other places found a way to reduce the memory consumption of this of soap interface. So, I really can recommend updating to blown five to one of five to two is it in. Of course that really has an impact. So yeah, I say that's want to demo this a bit. And let's start here. If you have a blown site and want to show a pie spy a bit. Let's start an soap instance with blown. And here, I start pie spy I do this with pseudo because I connect to an existing process. And this is only possible pseudo. I grab here my instance, my my process ID my pit out of it, but you can just do a PS and look for your pit, or look at the pit file and get the pit out of it to connect to it. So, with that pie spy and I feel side with some news items in and zoom out a bit. So, and I call this. And reload the site. Then you see on the in this top like, can you help you can read it I can make it a bit bigger. You can see here on the top like output the own time of the function and the total time a function used. So the own time is what one call of the function would use and the total time is accumulated time to function with all subcalls. And you can switch here and the sorting just different times and see what's cold and how much it used if I reset this and reload the page. Because it wasn't warmed up I get different numbers. And you can see it took me to reload and all calls connected 1.34 seconds in total time and I've switched to on time. You see where the calls happens as a C profile itself that takes a lot of time. And then we see in blown registry record proxy 60 milliseconds. But and there are other calls in here that take some time. And if you want, and like query utility still takes its time. And we could now look into the functions to get an idea what's going on there. If you have a site was really a larger performance problems you can get a good feeling where your time stacks up and I get an idea where to look at. So, in the next thing I want to show is repose profile. I added this the repose profile to my setup. This works in a way that I have this in the build out CFG I can just enable it with profile is on. I use a special branch of the blown recipes up to instance. This is working progress just works it's very similar very simple change but I didn't write any test for it and I didn't match the branch. So in fact it's based on the master of blown recipes up to instance and just need some love. So if I enable this middleware. So, repose profile. Then, if I start the instance. I get this nice few here on the left. Let's look at it. And so, and this is a bit like the soap profiler, but as a whiskey, you can in this few you can sort your output and that's interesting on all time. It's a total time of the calls. I hope I have some data now in here. No, that's not good. So, let's first clear this. So, let's sort the side and now refresh and now I have up to date data. Like on the on the time used for the calls. No, it's total time. I can sort on the cumulative time, which then says all cumulative calls of this built in methods took this time. So, I can sort it on the number of calls, which is very interesting. We find that we have a method as a split is called very often, and that's a records proxy PY of clone registry is called very often and we may want to look at this and may get some better numbers out of it in optimizing the record proxy. And there are a lot of calls, but in fact, also interesting to analyze this is to look and have a different look on it. If you look at what the call is out of our functions, then we get an output that says a record proxy it was called in registry hundred. And then you can get four times and registry PY and so on. You really get an idea how your code is called how often things are called and why and from where it's called and if you need more information you can show the full directories, then you get the full pass of the files and can try and can directly starting to inspect stuff. So, and the last thing I want to show is this bytecode level thing. So, I start the instance in the debug mode. And I took a clone 5 to all with our problem on bytecode level, which is called very often. And I try to analyze why the function is slow or what could be optimized on a micro level. So, it was what I found with the with the repos profile. That is a underscore look up option from soap interface adapter is called very often is not that fast. So I imported. Next I import the Python disassembler and start to look at it on a bytecode level. So, here we go. You have it on a loaded on a bytecode level. And you see the whole function, but without looking at the functions align numbers. Not very interesting so let's look at this functions. So, this is a look up function I expected and this is the version used in blown five to oh, and in this look up function, we see here's a loop and another loop and inside and the loop is that called very often and look up is called very often and it iterates over the components and the look up is called recursively and this is called very often. So, it iterates a tree and looks up components. And the first look, this is like what can I, what can I do here it's called like hundred 20,000 times in a reindex index or more often like million times in larger sites and so let's have a look. We see here in the in the line in the loop. It's the line. Let's go back here it's the line in one loop it's like 675667 3267 7667 9268 So, and if we look here in this in the code. We found in the 67. Three that we have a components load fast components and the load method get all the time and that repeats that repeats inside the other function block as well components and get. If we always have to load components and then load get before I can call it, I can eventually spare some time and make it faster by doing the load of components get before into a local variable before the loop starts. And so we did this, we have this components get here. And this is assigned before all this whole block and then call components gets here. And this eliminates this. And so we just need to have the go load the method and get back in here. So if I do the same. I don't five three would see that is eliminated but I think we don't have time for this. Sorry, but you can try it yourself. So, I use with things I found while looking in the code is looking also at request timings is that blown rest API has a lot of optimization potential. And it's a moment a bit difficult because it supports it down to blown for three and then you have a lot of code pass and tests are getting difficult to manage. So, probably this would need to get rid of blown of Python to support and so on. So, I don't have to ask, but one thing we in front five to the navigation was optimized but blown rest API does not use this optimized code pass and still use old code that's still there for backward compatibility reasons. So, more and more registry is called to often so here also optimizations possible. And then there's a different thing in the page templates page templates and chameleon expressions are called very, very often and Python expressions are very faster than usually Python expressions. So, Python expression is starting with Python and tells expression don't need a prefix. So, if you don't need to use a prefix, then it's a text expression and probably they are way slower. So, that's it. And if you use Python expressions, that's much better. So I recommend this and we should reflect the search price as a blown core code to use Python expressions. And even more introspection can be done probably also in chameleon there's some potential to optimize. Yeah, that's, I think the outcome. And if you if you look deeper and invest more time probably there are more things to do. Also this all says power consumption. Yeah, that's the idea behind also I think is to reduce the carbon footprint not all servers are running on green energy. And I think it's important and also a sink to think about to reduce the power consumption the data size that is transported over the web and so on, not only for the users experience but also for the environment. So my advice, yeah, start introspecting your performance not your performance so the performance of your application. And as usual, a lot of virtual hacks stay healthy. And no following questions can be maybe there were some questions at the slider. Otherwise, we can meet at Jitsi and talk a bit. And I'm happy to answer any questions. Thank you, Jens. And we had a request earlier to specify that Jitsi some people don't her. It's actually not clear at all what how to get to Jitsi. So if you scroll down on the page where you are in the loud form under the video window in the middle column there is a blue button, join face to face. That's the, that's the Jitsi channel where you can go and ask Jens question and chat among your amongst other people who have heard about this, this talk. So thanks again Jens. And we will see you here again in 10 minutes. Okay.
 Thanks everybody for coming to this third session.  I'm here to, I'm glad to introduce Jens Klein from Austria.  And he will talk to us about performance profiling and power consumption.  Go ahead, thanks.  Yeah, hello.  My name is Jens Klein from Austria. And so I want to talk about this topic.  And as you know, you might get a call from a customer saying, Hey, hello, my site is slow. So what to do about it?  And, well, that's the thing, blown slow.  And this is about performance. And then you need to ask questions.  And this is what happens often to me at some people I never heard about calling a platform site and it's low. I got your name from somewhere in the internet.  Then you can ask questions like, well, it's a specific page. Slow is it on high load slow or massive rights or overall and yes,  you start asking more questions like, did you check your hardware database network?  And I say, I checked everything. Yeah, really check first.  But then at some point you see, oh,  it is blown. So,  blown is slow. And now we have to ask questions again. Or we have to look at the instance and inspect it. And several possible paths to go so often the other seems bloated and can be slow in certain situations.  So server side code can be slow or even Volto code can be slow. And then you can cash things. So the back end does not need to deliver this but at some point, caching is not enough.  And the next, the next time then you mostly got the pass down to  something happens in my Python logic.  And this is what I want to talk about about the focus on the Python logic, not about caching, not about database optimization or something like that.  And there you need a way to find the performance program. So you need tools.  And mainly, these three tools, primary py spy, because it's a runtime profiler, then for specific page loads and so on the repose profile and the disassembler from the Python.  So what is py spy?  It's a great tool than overall. It has a top like output or you can also store the output for later analyzing. But the top like output is really great because you can plug into a live application and look at the application what's happening there in a live process.  And there is repose profile. It's a classical Python profiler. This slows down the side opposed to py spy, which just looks at the running process. The profiler really gets in your way and slows down the application.  It's the middle where it works with a new Python five to  Python with a risky implementation. And you can profile a single request by really and that does not work in life instance but if you copy the database and everything, you can have a profile in the single request and look what really happens there.  Then I'm missing one slide anyway. And then you have the disk disassembler for Python, which is used to look at one function on the bytecode level.  This is something I rarely use, but it's very powerful to get an insight on what happens on bytecode level. And if you have functions that are called very, very often and this happens, then you can analyze these functions with this.  So with these tools, we've, I found some or we found some improvements to clone. So in the blown 520 to 5123.  There was some bottlenecks primary and blown dexterity.  We to avoid an early provided by call which is expensive and was called very, very often. There were possibility to extend the list of early exits on common attribute calls because attribute to get at attribute calls indexed here are called very often.  We optimized cash is the signable cash schema cash. And there was some leftover we found that there's a threat local synchronization was built in for an ancient caching that was refactored but as thanks as a synchronization stuff was kept in and this is very slow as well.  Then there were some fancy things happened in soap interface. I never get my fingers dirty in soap interface before but this point I found that this was a place where things are really slowed down and so interface and we in clone use the component architecture very, very often and any in every place.  And if there's something slow or optimize able. This hasn't big impact because it's called so often like I didn't reindex index on a midsize database and this was called like hundred 20,000 times one function.  And if you optimize something in there then it has an impact.  And I found the leftover of a hash override that was then, which usually is a hash, the classical hash of an object is written in C. So if you override the stuff you have bytecode and that slows down things a lot and even removing this hash override, improve the speed of this domain.  Then another hash improvement happened in the interface class itself, and found a way to have a five times in look up look up all in subscriptions which is called very, very often.  And this was on a bytecode level analyzed I show it later.  And also Jason, who supported and reviewed all the stuff as well and did some improvements and other places found a way to reduce the memory consumption of this of soap interface.  So, I really can recommend updating to blown five to one of five to two is it in.  Of course that really has an impact. So yeah, I say that's want to demo this a bit.  And let's start here.  If you have a blown site and want to show a pie spy a bit. Let's start an soap instance with blown.  And here, I start pie spy I do this with pseudo because I connect to an existing process. And this is only possible pseudo.  I grab here my instance, my my process ID my pit out of it, but you can just do a PS and look for your pit, or look at the pit file and get the pit out of it to connect to it.  So, with that pie spy and I feel side with some news items in and zoom out a bit. So, and I call this.  And reload the site. Then you see on the in this top like, can you help you can read it I can make it a bit bigger.  You can see here on the top like output the own time of the function and the total time a function used.  So the own time is what one call of the function would use and the total time is accumulated time to function with all subcalls. And you can switch here and the sorting just different times and see what's cold and how much it used if I reset this and reload the page.  Because it wasn't warmed up I get different numbers. And you can see it took me to reload and all calls connected 1.34 seconds in total time and I've switched to on time.  You see where the calls happens as a C profile itself that takes a lot of time. And then we see in blown registry record proxy 60 milliseconds. But and there are other calls in here that take some time.  And if you want, and like query utility still takes its time.  And we could now look into the functions to get an idea what's going on there.  If you have a site was really a larger performance problems you can get a good feeling where your time stacks up and I get an idea where to look at.  So, in the next thing I want to show is repose profile.  I added this the repose profile to my setup.  This works in a way that I have this in the build out CFG I can just enable it with profile is on.  I use a special branch of the blown recipes up to instance.  This is working progress just works it's very similar very simple change but I didn't write any test for it and I didn't match the branch. So in fact it's based on the master of blown recipes up to instance and just need some love.  So if I enable this middleware.  So, repose profile.  Then, if I start the instance.  I get this nice few here on the left. Let's look at it.  And  so,  and this is a bit like the soap profiler, but as a whiskey, you can in this few you can sort your output and that's interesting on all time.  It's a total time of the calls.  I hope I have some data now in here. No, that's not good. So, let's first clear this.  So, let's sort the side and now refresh and now I have up to date data.  Like on the on the time used for the calls. No, it's total time.  I can sort on the cumulative time, which then says all cumulative calls of this built in methods took this time.  So, I can sort it on the number of calls, which is very interesting.  We find that we have a method as a split is called very often, and that's a records proxy PY of clone registry is called very often and we may want to look at this and may get some better numbers out of it in optimizing the  record proxy.  And there are a lot of calls, but in fact, also interesting to analyze this is to look and have a different look on it. If you look at what the call is out of our functions, then we get an output that says a record proxy it was called in registry  hundred.  And then you can get four times and registry PY and so on. You really get an idea how your code is called how often things are called and why and from where it's called and if you need more information you can show the full directories, then you get the full  pass of the files and can try and can directly starting to inspect stuff.  So, and the last thing I want to show is this bytecode level thing.  So, I start the instance in the debug mode.  And I took a clone 5 to all with our problem on bytecode level, which is called very often. And I try to analyze why the function is slow or what could be optimized on a micro level.  So, it was what I found with the with the repos profile. That is a underscore look up option from soap interface adapter is called very often is not that fast. So I imported.  Next I import the Python disassembler and start to look at it on a bytecode level. So, here we go. You have it on a loaded on a bytecode level.  And you see the whole function, but without looking at the functions align numbers.  Not very interesting so let's look at this functions.  So, this is a look up function I expected and this is the version used in blown five to oh, and in this look up function, we see here's a loop and another loop and inside and the loop is that called very often and look up is called very often and it  iterates over the components and the look up is called recursively and this is called very often.  So, it iterates a tree and looks up components.  And the first look, this is like what can I, what can I do here it's called like hundred 20,000 times in a reindex index or more often like million times in larger sites and  so let's have a look. We see here in the in the line in the loop. It's the line. Let's go back here it's the line in one loop it's like 675667 3267 7667 9268  So, and if we look here in this in the code.  We found in the 67.  Three that we have a components load fast components and the load method get all the time and that repeats that repeats inside the other function block as well components and get.  If we always have to load components and then load get before I can call it, I can eventually spare some time and make it faster by doing the load of components get before into a local variable before the loop starts.  And so we did this, we have this components get here.  And this is assigned before all this whole block and then call components gets here. And this eliminates this.  And so we just need to have the go load the method and get back in here. So if I do the same.  I don't five three would see that is eliminated but I think we don't have time for this. Sorry, but you can try it yourself.  So,  I use with things I found while looking in the code is looking also at request timings is that blown rest API has a lot of optimization potential.  And it's a moment a bit difficult because it supports it down to blown for three and then you have a lot of code pass and tests are getting difficult to manage. So, probably this would need to get rid of blown of Python to support and so on.  So, I don't have to ask, but one thing we in front five to the navigation was optimized but blown rest API does not use this optimized code pass and still use old code that's still there for backward compatibility reasons.  So, more and more registry is called to often so here also optimizations possible. And then there's a different thing in the page templates page templates and chameleon expressions are called very, very often and Python expressions are very faster than usually  Python expressions. So, Python expression is starting with Python and tells expression don't need a prefix. So, if you don't need to use a prefix, then it's a text expression and probably they are way slower.  So, that's it. And if you use Python expressions, that's much better. So I recommend this and we should reflect the search price as a blown core code to use Python expressions. And even more introspection can be done probably also in chameleon there's some potential to optimize.  Yeah, that's, I think the outcome. And if you if you look deeper and invest more time probably there are more things to do.  Also this all says power consumption. Yeah, that's the idea behind also I think is to reduce the carbon footprint not all servers are running on green energy. And I think it's important and also a sink to think about to reduce the power consumption the data size  that is transported over the web and so on, not only for the users experience but also for the environment.  So my advice, yeah, start introspecting your performance not your performance so the performance of your application.  And as usual, a lot of virtual hacks stay healthy. And no following questions can be maybe there were some questions at the slider. Otherwise, we can meet at Jitsi and talk a bit.  And I'm happy to answer any questions.  Thank you, Jens. And we had a request earlier to specify that Jitsi some people don't her. It's actually not clear at all what how to get to Jitsi.  So if you scroll down on the page where you are in the loud form under the video window in the middle column there is a blue button, join face to face. That's the, that's the Jitsi channel where you can go and ask Jens question and chat among your amongst  other people who have heard about this, this talk. So thanks again Jens. And we will see you here again in 10 minutes.  Okay.
Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_0_1163.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_1164_1691.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_1692_2255.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_2256_3671.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_3672_4007.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_4008_4187.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_4188_4703.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_4704_4979.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_4980_11735.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_11736_11807.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_11808_11999.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_12000_12215.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_12216_16931.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_16932_17279.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_17280_17759.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_17760_18911.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_18912_21479.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_21480_21611.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_21612_23279.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_23280_24623.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_24624_24743.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_24744_25091.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_25092_26051.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_26052_26651.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_26652_27071.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_27072_27119.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_27120_27395.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_27396_27455.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_27456_27515.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_27516_27599.png Performance__Profiling__Power-Consumption_-_Jens_K_El5my7yH87I_27600_33884.png
Thanks everybody for coming to this third session. I'm here to, I'm glad to introduce Jens Klein from Austria. And he will talk to us about performance profiling and power consumption. Go ahead, thanks. Yeah, hello. My name is Jens Klein from Austria. And so I want to talk about this topic. And as you know, you might get a call from a customer saying, Hey, hello, my site is slow. So what to do about it? And, well, that's the thing, blown slow. And this is about performance. And then you need to ask questions. And this is what happens often to me at some people I never heard about calling a platform site and it's low. I got your name from somewhere in the internet. Then you can ask questions like, well, it's a specific page. Slow is it on high load slow or massive rights or overall and yes, you start asking more questions like, did you check your hardware database network? And I say, I checked everything. Yeah, really check first. But then at some point you see, oh, it is blown. So, blown is slow. And now we have to ask questions again. Or we have to look at the instance and inspect it. And several possible paths to go so often the other seems bloated and can be slow in certain situations. So server side code can be slow or even Volto code can be slow. And then you can cash things. So the back end does not need to deliver this but at some point, caching is not enough. And the next, the next time then you mostly got the pass down to something happens in my Python logic. And this is what I want to talk about about the focus on the Python logic, not about caching, not about database optimization or something like that. And there you need a way to find the performance program. So you need tools. And mainly, these three tools, primary py spy, because it's a runtime profiler, then for specific page loads and so on the repose profile and the disassembler from the Python. So what is py spy? It's a great tool than overall. It has a top like output or you can also store the output for later analyzing. But the top like output is really great because you can plug into a live application and look at the application what's happening there in a live process. And there is repose profile. It's a classical Python profiler. This slows down the side opposed to py spy, which just looks at the running process. The profiler really gets in your way and slows down the application. It's the middle where it works with a new Python five to Python with a risky implementation. And you can profile a single request by really and that does not work in life instance but if you copy the database and everything, you can have a profile in the single request and look what really happens there. Then I'm missing one slide anyway. And then you have the disk disassembler for Python, which is used to look at one function on the bytecode level. This is something I rarely use, but it's very powerful to get an insight on what happens on bytecode level. And if you have functions that are called very, very often and this happens, then you can analyze these functions with this. So with these tools, we've, I found some or we found some improvements to clone. So in the blown 520 to 5123. There was some bottlenecks primary and blown dexterity. We to avoid an early provided by call which is expensive and was called very, very often. There were possibility to extend the list of early exits on common attribute calls because attribute to get at attribute calls indexed here are called very often. We optimized cash is the signable cash schema cash. And there was some leftover we found that there's a threat local synchronization was built in for an ancient caching that was refactored but as thanks as a synchronization stuff was kept in and this is very slow as well. Then there were some fancy things happened in soap interface. I never get my fingers dirty in soap interface before but this point I found that this was a place where things are really slowed down and so interface and we in clone use the component architecture very, very often and any in every place. And if there's something slow or optimize able. This hasn't big impact because it's called so often like I didn't reindex index on a midsize database and this was called like hundred 20,000 times one function. And if you optimize something in there then it has an impact. And I found the leftover of a hash override that was then, which usually is a hash, the classical hash of an object is written in C. So if you override the stuff you have bytecode and that slows down things a lot and even removing this hash override, improve the speed of this domain. Then another hash improvement happened in the interface class itself, and found a way to have a five times in look up look up all in subscriptions which is called very, very often. And this was on a bytecode level analyzed I show it later. And also Jason, who supported and reviewed all the stuff as well and did some improvements and other places found a way to reduce the memory consumption of this of soap interface. So, I really can recommend updating to blown five to one of five to two is it in. Of course that really has an impact. So yeah, I say that's want to demo this a bit. And let's start here. If you have a blown site and want to show a pie spy a bit. Let's start an soap instance with blown. And here, I start pie spy I do this with pseudo because I connect to an existing process. And this is only possible pseudo. I grab here my instance, my my process ID my pit out of it, but you can just do a PS and look for your pit, or look at the pit file and get the pit out of it to connect to it. So, with that pie spy and I feel side with some news items in and zoom out a bit. So, and I call this. And reload the site. Then you see on the in this top like, can you help you can read it I can make it a bit bigger. You can see here on the top like output the own time of the function and the total time a function used. So the own time is what one call of the function would use and the total time is accumulated time to function with all subcalls. And you can switch here and the sorting just different times and see what's cold and how much it used if I reset this and reload the page. Because it wasn't warmed up I get different numbers. And you can see it took me to reload and all calls connected 1.34 seconds in total time and I've switched to on time. You see where the calls happens as a C profile itself that takes a lot of time. And then we see in blown registry record proxy 60 milliseconds. But and there are other calls in here that take some time. And if you want, and like query utility still takes its time. And we could now look into the functions to get an idea what's going on there. If you have a site was really a larger performance problems you can get a good feeling where your time stacks up and I get an idea where to look at. So, in the next thing I want to show is repose profile. I added this the repose profile to my setup. This works in a way that I have this in the build out CFG I can just enable it with profile is on. I use a special branch of the blown recipes up to instance. This is working progress just works it's very similar very simple change but I didn't write any test for it and I didn't match the branch. So in fact it's based on the master of blown recipes up to instance and just need some love. So if I enable this middleware. So, repose profile. Then, if I start the instance. I get this nice few here on the left. Let's look at it. And so, and this is a bit like the soap profiler, but as a whiskey, you can in this few you can sort your output and that's interesting on all time. It's a total time of the calls. I hope I have some data now in here. No, that's not good. So, let's first clear this. So, let's sort the side and now refresh and now I have up to date data. Like on the on the time used for the calls. No, it's total time. I can sort on the cumulative time, which then says all cumulative calls of this built in methods took this time. So, I can sort it on the number of calls, which is very interesting. We find that we have a method as a split is called very often, and that's a records proxy PY of clone registry is called very often and we may want to look at this and may get some better numbers out of it in optimizing the record proxy. And there are a lot of calls, but in fact, also interesting to analyze this is to look and have a different look on it. If you look at what the call is out of our functions, then we get an output that says a record proxy it was called in registry hundred. And then you can get four times and registry PY and so on. You really get an idea how your code is called how often things are called and why and from where it's called and if you need more information you can show the full directories, then you get the full pass of the files and can try and can directly starting to inspect stuff. So, and the last thing I want to show is this bytecode level thing. So, I start the instance in the debug mode. And I took a clone 5 to all with our problem on bytecode level, which is called very often. And I try to analyze why the function is slow or what could be optimized on a micro level. So, it was what I found with the with the repos profile. That is a underscore look up option from soap interface adapter is called very often is not that fast. So I imported. Next I import the Python disassembler and start to look at it on a bytecode level. So, here we go. You have it on a loaded on a bytecode level. And you see the whole function, but without looking at the functions align numbers. Not very interesting so let's look at this functions. So, this is a look up function I expected and this is the version used in blown five to oh, and in this look up function, we see here's a loop and another loop and inside and the loop is that called very often and look up is called very often and it iterates over the components and the look up is called recursively and this is called very often. So, it iterates a tree and looks up components. And the first look, this is like what can I, what can I do here it's called like hundred 20,000 times in a reindex index or more often like million times in larger sites and so let's have a look. We see here in the in the line in the loop. It's the line. Let's go back here it's the line in one loop it's like 675667 3267 7667 9268 So, and if we look here in this in the code. We found in the 67. Three that we have a components load fast components and the load method get all the time and that repeats that repeats inside the other function block as well components and get. If we always have to load components and then load get before I can call it, I can eventually spare some time and make it faster by doing the load of components get before into a local variable before the loop starts. And so we did this, we have this components get here. And this is assigned before all this whole block and then call components gets here. And this eliminates this. And so we just need to have the go load the method and get back in here. So if I do the same. I don't five three would see that is eliminated but I think we don't have time for this. Sorry, but you can try it yourself. So, I use with things I found while looking in the code is looking also at request timings is that blown rest API has a lot of optimization potential. And it's a moment a bit difficult because it supports it down to blown for three and then you have a lot of code pass and tests are getting difficult to manage. So, probably this would need to get rid of blown of Python to support and so on. So, I don't have to ask, but one thing we in front five to the navigation was optimized but blown rest API does not use this optimized code pass and still use old code that's still there for backward compatibility reasons. So, more and more registry is called to often so here also optimizations possible. And then there's a different thing in the page templates page templates and chameleon expressions are called very, very often and Python expressions are very faster than usually Python expressions. So, Python expression is starting with Python and tells expression don't need a prefix. So, if you don't need to use a prefix, then it's a text expression and probably they are way slower. So, that's it. And if you use Python expressions, that's much better. So I recommend this and we should reflect the search price as a blown core code to use Python expressions. And even more introspection can be done probably also in chameleon there's some potential to optimize. Yeah, that's, I think the outcome. And if you if you look deeper and invest more time probably there are more things to do. Also this all says power consumption. Yeah, that's the idea behind also I think is to reduce the carbon footprint not all servers are running on green energy. And I think it's important and also a sink to think about to reduce the power consumption the data size that is transported over the web and so on, not only for the users experience but also for the environment. So my advice, yeah, start introspecting your performance not your performance so the performance of your application. And as usual, a lot of virtual hacks stay healthy. And no following questions can be maybe there were some questions at the slider. Otherwise, we can meet at Jitsi and talk a bit. And I'm happy to answer any questions. Thank you, Jens. And we had a request earlier to specify that Jitsi some people don't her. It's actually not clear at all what how to get to Jitsi. So if you scroll down on the page where you are in the loud form under the video window in the middle column there is a blue button, join face to face. That's the, that's the Jitsi channel where you can go and ask Jens question and chat among your amongst other people who have heard about this, this talk. So thanks again Jens. And we will see you here again in 10 minutes. Okay.
performance profiling and power consumption. Go we have to look at the instance and inspect it. py spy? It's a great tool than overall. It has a improvements and other places found a way to is called how often things are called and why and