hazardfn

hazardfn

Use of "inspect" in log messages

Just wanted to throw a quick question out there regarding ‘inspect’ in Elixir – for a while we were using it in our logs to print out different structures.

We then got round to doing performance testing on our project and noticed it was incredibly slow, we ran :eprof and almost all the percentage of time was spent in some whitespace_removal function and we had no idea why.

Eventually we decided logging was to blame as it’s really the only place we use strings, we played around a bit then once we removed inspect we went (as an example of just how slow it was) from processing around 300 messages a sec to 1000.

Before (Slow):

Logger.info(“Payload received: #{inspect pl}”)

After (Much faster):

Logger.info([“Payload received: “, pl])

My question is, were we using inspect wrong? Is it a kind of debugging function not to be used in production code?

I am also wondering why inspect feels it had to do all this extra processing when the second alternative I showed is much faster?

Hopefully this post also helps those struggling with performance without any idea why :stuck_out_tongue:

Marked As Solved

josevalim

josevalim

Creator of Elixir

So inspect is going to check a data structure and represent as accurately as possible using Elixir syntax. This means that, if you have a binary, it will check if it is valid utf-8 codepoints, and then format it, looking for escape characters, quotes, etc. There is a chance inspect could be made faster for binaries, I don’t remember anyone particularly optimizing it, but in your case, no work will always be faster than doing any work, and if you already have a binary, you can just log the binary as is with a list.

Actually, I would say inspecting a json blob will actually make things worse, because instead of seeing {"foo": "bar"}, you will now see "{\"foo\": \"bar\"}".

Others have touched important points that arise when measuring code. For example, if you are measuring Elixir scripts, there is no protocol consolidation and that takes the hit. And I would like to add one other tip. If your log call needs to do a good amount of work, pass it an anonymous function:

Logger.info(fn -> “Payload received: #{inspect pl}” end)

The anonymous function will only be invoked if you are interested in the log level. This is specially important for info and debug messages.

Also Liked

josevalim

josevalim

Creator of Elixir

The first two are now 2.5 times faster on master. The third one no longer exists. :slight_smile:

hazardfn

hazardfn

I might give master a try for curiosities sake later. I forgot to mention for clarities sake it was in those 3 calls (printable?, escape and append) where much of the time was being chewed up.

Thanks for all the help and advice everyone! The elixir forum does not disappoint!

belaustegui

belaustegui

In the After, you are using a IOList instead of a string.
This article has a good explanation on why it is faster: https://www.bignerdranch.com/blog/elixir-and-io-lists-part-1-building-output-efficiently/

Where Next?

Popular in Discussions Top

jswny
I would like to better understand what the advantages/disadvantages of umbrella applications are compared to structuring your app as as s...
New
mikl
I wanted to capitalize a string, and tried using String.capitalize(). That generally works well, until you try to capitalize a word like...
New
arpan
Hello everyone :wave: Today I am very excited to announce a project that I have been working on for almost 3 months now. The project is...
New
Ankhers
Just a little information upfront. Generally speaking, if I feel like I need to either break a pipe chain or use an anonymous function in...
New
AstonJ
Please see the new poll here: Which code editor or IDE do you use? (Poll) (2022 Edition) It’s been a while since we first asked this, I...
208 31265 143
New
marciol
Please, let me know if this kind of discussion already took place in another topic . Hi all, how do you consider if is better to build ...
New
klo
Got a question about when to concat vs. prepending items to list then reversing to achieve appending. So i know lists boil down to [1 | ...
New
cblavier
Hey there, It’s been more than a year since we started using LiveView as our main UI library and building a whole library of UI componen...
New
New
sashaafm
Piggy backing a bit on @dvcrn topic BEAM optimization for functions with static return type?, I’ve been trying to understand in a deeper ...
New

Other popular topics Top

axelson
This post is a wiki (feel free to hit the edit button near the bottom right of this post to add your own changes!) This post collects co...
239 48342 226
New
electic
Hi, I am new to Elixir. I am trying to use the DateTime component to insert a date into MySQL however the there seems to be no way to fo...
New
msaraiva
Surface is an experimental library built on top of Phoenix LiveView and its new LiveComponent API that aims to provide a more declarative...
564 43757 214
New
belgoros
I’m not a pro in using Regex and can’t figure out why the following behaviour happens, especially if we take into account the difference ...
New
freewebwithme
Using vs code and installed ElixirLS: support and debugger. And I got an error popped up on start up says Failed to run ‘elixir’ comma...
New
aesmail
Hello guys, I have finally made it. I created an admin interface for a framework. It’s been on my todo list for years and with the curre...
New
romenigld
I am trying to run a deploy with docker and I successfully runned with this command: docker build -t romenigld/blog-prod . but when I t...
New
klo
Got a question about when to concat vs. prepending items to list then reversing to achieve appending. So i know lists boil down to [1 | ...
New
openscript
Hello! Sorry for this astonishing simple question, but I’m really stuck. I try to set up the intellij-elixir plugin, but I don’t know ho...
New
dokuzbir
I want to highlight html closing tags when i click a html tag. That works in .html files but doesnt work for html.eex templates. How can...
New

Latest on Elixir Forum

Elixir Forum

We're in Beta

About us Mission Statement