Skip to content

Commit 641968f

Browse files
tranhelentranhelen
committedMar 29, 2015
Add new design files
1 parent f30775c commit 641968f

File tree

10 files changed

+1056
-280
lines changed

10 files changed

+1056
-280
lines changed
 

‎design-wip/css/style.css

+1-1
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎design-wip/img/avatar10.png

2.64 KB
Loading

‎design-wip/img/avatar5.png

9.61 KB
Loading

‎design-wip/img/avatar9.png

73.7 KB
Loading

‎design-wip/index.html

+210-178
Large diffs are not rendered by default.

‎design-wip/js/highlight.js

+1
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎design-wip/protip.html

+337
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,337 @@
1+
<!DOCTYPE html>
2+
<!--[if lt IE 7]> <html class="lt-ie9 lt-ie8 lt-ie7"> <![endif]-->
3+
<!--[if IE 7]> <html class="lt-ie9 lt-ie8"> <![endif]-->
4+
<!--[if IE 8]> <html class="lt-ie9"> <![endif]-->
5+
<!--[if gt IE 8]><!--> <html class=""> <!--<![endif]-->
6+
<head>
7+
<meta charset="utf-8">
8+
<meta http-equiv="X-UA-Compatible" content="IE=edge">
9+
<title>ChronoLogger logging is 1.5x faster than ruby's stdlib Logger - Protip - Coderwall</title>
10+
<meta name="viewport" content="width=device-width, initial-scale=1">
11+
12+
<link rel="stylesheet" href="css/style.css">
13+
</head>
14+
15+
<body>
16+
<header class="site-header">
17+
<div class="container">
18+
19+
<div class="main-nav">
20+
<div class="logo">
21+
<a href="index.html"><img src="img/logo.png"></a>
22+
</div>
23+
<ul class="inline menu">
24+
<li><a href="index.html" class="active">Protips</a></li>
25+
<li><a href="#">Job Board</a></li>
26+
</ul>
27+
<a href="#" class="user-block">
28+
<img src="img/user-avatar.png" class="user-block__img"> <span class="user-block__user">tranhelen</span>
29+
</a>
30+
</div>
31+
32+
</div>
33+
</header>
34+
35+
<nav class="secondary-menu">
36+
<div class="container">
37+
38+
<div class="grid">
39+
<div class="grid__item small--hide medium--two-thirds large--three-quarters">
40+
<ul class="inline">
41+
<li class="active"><a href="#">Latest</a></li>
42+
<li><a href="#">Popular</a></li>
43+
</ul>
44+
</div>
45+
<div class="grid__item medium--one-third large--one-quarter">
46+
<a href="#" class="btn addprotip">
47+
<span class="icon icon-plus"></span> New Protip
48+
</a>
49+
</div>
50+
</div>
51+
52+
</div>
53+
</nav>
54+
55+
<div class="page-body">
56+
<div class="container">
57+
58+
<div class="grid">
59+
60+
<div class="grid__item push--large--one-twelfth large--ten-twelfths">
61+
<header class="protip-header">
62+
<div class="grid">
63+
<div class="grid__item small--one-quarter medium--one-sixth large--one-eighth">
64+
<a class="upvote--popular">
65+
<span class="icon icon-arrow-up-upload"></span> 2
66+
</a>
67+
</div>
68+
<div class="grid__item small--three-quarters medium--five-sixths large--seven-eighths">
69+
<ul class="tag-block inline">
70+
<li><a href="" class="tag">#browser</a></li>
71+
<li><a href="" class="tag">#html5</a></li>
72+
<li><a href="" class="tag">#notepad</a></li>
73+
</ul>
74+
</div>
75+
</div>
76+
</header>
77+
</div>
78+
</div>
79+
80+
<div class="grid">
81+
82+
<article class="grid__item push--large--one-twelfth large--ten-twelfths">
83+
<div class="protip-single">
84+
<header>
85+
<h1>ChronoLogger logging is 1.5x faster than ruby's stdlib Logger</h1>
86+
<div class="protip-meta">
87+
<p>Posted by <a href=""><img src="img/avatar9.png" class="protip-avatar"> Tim</a> from <a href=""><img src="img/avatar10.png" class="protip-avatar"> Shopify</a> on December 4, 2014</p>
88+
</div>
89+
</header>
90+
91+
<h2>Introduction</h2>
92+
<p>Recently I created a ruby logger library named ChronoLogger (gem name is chrono_logger) that has lock free writing and time based file rotation. This post introduces ChronoLogger features and what I learned throughout created it.</p>
93+
<p>Let's just start with, see the following result comparing logging speed by ChronoLogger from ruby's stdlib Logger (hereinafter: ::Logger). The condition is 100,000 writings by 2 threads at the same time. ChronoLogger's logging speed is 1.5x faster, more than ::Logger.</p>
94+
95+
<pre>
96+
<code>
97+
user system total real
98+
std_logger: 20.220000 14.530000 34.750000 ( 24.209075)
99+
chrono_logger: 11.950000 8.650000 20.600000 ( 13.843873)
100+
</code>
101+
</pre>
102+
103+
<p>The code is here to profiling it.</p>
104+
105+
<pre>
106+
<code>
107+
require 'benchmark'
108+
require 'parallel'
109+
110+
std_logger = ::Logger.new('_std_logger')
111+
chrono_logger = ChronoLogger.new('_chrono_logger.%Y%m%d')
112+
113+
COUNT = 100_000
114+
Benchmark.bm(10) do |bm|
115+
bm.report('std_logger:') do
116+
Parallel.map(['1 logged', '2 logged'], in_threads: 2) do |letter|
117+
COUNT.times { std_logger.info letter }
118+
end
119+
end
120+
bm.report('chrono_logger:') do
121+
Parallel.map(['1 logged', '2 logged'], in_threads: 2) do |letter|
122+
COUNT.times { chrono_logger.info letter }
123+
end
124+
end
125+
end
126+
</code>
127+
</pre>
128+
129+
<p>Why fast? There is secret that Chronologger has the advantage in the above case. I'm writing details about it by introducing features.</p>
130+
131+
<h2>ChronoLogger's features</h2>
132+
133+
<p>ChronoLogger has 2 features comparing with ::Logger.</p>
134+
135+
<ul>
136+
<li>Lock free when logging</li>
137+
<li>Time based file rotation</li>
138+
</ul>
139+
140+
<p>Let's see the details.</p>
141+
142+
<h2>Lock free log writing</h2>
143+
144+
<h3>What is lock?</h3>
145+
146+
<p>What is the lock in this article? It's a ::Logger's mutex for writing atomicity when multi-threading. Specifically, mutex block in ::Logger::LogDevice class's write method.</p>
147+
148+
<h3>Why Chronologger could be lock free logger?</h3>
149+
150+
<p>::Logger locked for atomicity, why it can be removed? In fact, log writing is atomicly by OS in some specific environments. See the linux documentation, write(2) provides atomic writing when data size is under PIPEBUF, but does not say atomic when data size more than PIPEBUF. However some file system takes lock when writing any size of data, so writing is atomic in these environments. Therefore ChronoLogger removed lock when writing and reduce it's cost.</p>
151+
152+
<p>Please note it's not always true about lock, for this reason it's safe to check multi process behaviour in your environment. In real, logs aren't mixed in my CentOS envirionments that has ext4 file system. On the other hand logs are mixed when writing to pipe when data size more than PIPE_BUF.</p>
153+
154+
<h3>Lock free world</h3>
155+
156+
<p>Limiting environment leads lock free logger. ChronoLogger's 1.5x faster writing is removing mutex when multi threading on top of the article. That solves ChronoLogger's advantage in multi threading. I also tried checking performance in multi processing its results only small percent faster.</p>
157+
158+
<h3>Break time :coffee:</h3>
159+
160+
<p>The idea about lock free is originally from MonoLogger project. My colleague @yteraoka told me MonoLogger a year or so ago. MonoLogger has no file rotation function so we could not use it in production. Anyway, it's benefit existing expert colleague, I'm thankful to my environments. :)</p>
161+
162+
<h3>Time based file rotation</h3>
163+
164+
<h4>Logging to file having time based filename</h4>
165+
166+
<p>You would notice ::Logger already has daily file rotation. That's right, but there is a difference the way to rotate file. Actually, ::Logger rotates file when first writing to log file in the next day. Specifically, there is not rotated file existed when first writing in the next day.</p>
167+
168+
<pre>
169+
<code>
170+
# 2015/02/01
171+
logger = Logger.new('stdlib.log', 'daily')
172+
# => stdlib.log generated
173+
logger.info 'today'
174+
175+
# 2015/02/02
176+
logger.info 'next day'
177+
# => stdlib.log.20150201 generated
178+
</code>
179+
</pre>
180+
181+
<p>This makes a tiny problem. For instance, you would compress the log file when starting the next day. You cannot compress rotated file if first writing is not started. ChronoLogger solves this problem the way to writing a file that has time based filename. This way is same as cronolog. The result is the following when using ChronoLogger.</p>
182+
183+
<pre>
184+
<code>
185+
# 2015/02/01
186+
logger = ChronoLogger.new('chrono.log.%Y%m%d')
187+
# => chrono.log.20150201 generated
188+
logger.info 'today'
189+
190+
# 2015/02/02
191+
logger.info 'next day'
192+
# => chrono.log.20150202 generated
193+
</code>
194+
</pre>
195+
196+
<p>ChronoLogger ensure existing rotated log file when starting the next day. Except there is no writing during a day... This is fitted about the last use case to compressing a log file. Additionally, this way only writes to file that has a new name so it's simple, this simplicity leads also simple code.</p>
197+
198+
<h3>Wrap up</h3>
199+
200+
<p>ChronoLogger's pros comparing with ::Logger's are</p>
201+
202+
<ul>
203+
<li>Logging faster when multi threading by lock free</li>
204+
<li>Ensure rotated file existence when starting the next day by time based file rotation</li>
205+
</ul>
206+
207+
<p>ChronoLogger's cons is a risk that logs are mixed depending on environment. I'm beginning to use ChronoLogger and currently there is no problem in my Rails project. I'm looking forward to receive your feedback. HackerNews post is <a href="https://news.ycombinator.com/item?id=8991004">here</a>. Thanks for reading.</p>
208+
209+
<p>If you like ChronoLogger, checkout the <a href="https://github.com/ma2gedev/chrono_logger">github repository.</a></p>
210+
211+
<h3>References</h3>
212+
213+
<h4>ChronoLogger</h4>
214+
215+
<ul>
216+
<li>github
217+
<ul>
218+
<li><a href="https://github.com/ma2gedev/chrono_logger">https://github.com/ma2gedev/chrono_logger</a></li>
219+
</ul>
220+
</li>
221+
<li>rubygems.org
222+
<ul>
223+
<li><a href="https://rubygems.org/gems/chrono_logger">https://rubygems.org/gems/chrono_logger</a></li>
224+
</ul>
225+
</li>
226+
</ul>
227+
228+
<h4>about <b>the lock</b></h4>
229+
230+
<ul>
231+
<li>Pointing out mutex block in ruby's logger code
232+
<ul>
233+
<li><a href="https://github.com/ruby/ruby/blob/8be3f74e19492a313c930e031254116df3994078/lib/logger.rb#L595">https://github.com/ruby/ruby/blob/8be3f74e19492a313c930e031254116df3994078/lib/logger.rb#L595</a></li>
234+
</ul>
235+
</li>
236+
<li>Is lock-free logging safe?
237+
<ul>
238+
<li><a href="http://www.jstorimer.com/blogs/workingwithcode/7982047-is-lock-free-logging-safe">http://www.jstorimer.com/blogs/workingwithcode/7982047-is-lock-free-logging-safe</a></li>
239+
</ul>
240+
</li>
241+
<li>write(2) documentation
242+
<ul>
243+
<li><a href="http://pubs.opengroup.org/onlinepubs/9699919799/functions/write.html">http://pubs.opengroup.org/onlinepubs/9699919799/functions/write.html</a></li>
244+
</ul>
245+
</li>
246+
</ul>
247+
248+
<p>Enjoy!</p>
249+
250+
<hr>
251+
252+
<div class="protip-comments">
253+
<h2>Comments</h2>
254+
255+
<!-- If there are no comments -->
256+
<!-- <p>There are currently no comments.</p> -->
257+
258+
<div class="protip-comment">
259+
<h5><img src="img/avatar1.png" class="comment-avatar"> Doug</h5>
260+
<div class="comment-body">
261+
<p>I made a version that is a full blown Ruby editor with syntax highlighting from Ace.

262+
<br><a href="">https://gist.github.com/4666256</a></p>
263+
<div class="comment-meta">
264+
<a href=""><span class="icon icon-heart"></span> Like</a> • <a href="">Flag</a> • <time>12 minutes ago</time>
265+
</div>
266+
</div>
267+
</div>
268+
<div class="protip-comment">
269+
<h5><img src="img/avatar2.png" class="comment-avatar"> Steve</h5>
270+
<div class="comment-body">
271+
<p>Forgive me for the shameless plug, but thought this might be useful for others. I put together a little project that uses the browsers localstorage so you can jot notes down and Forgive me for the shameless plus, but thought this might be useful for others. I put together a little p</p>
272+
<div class="comment-meta">
273+
<a href=""><span class="icon icon-heart"></span> Like</a> • <a href="">Flag</a> • <time>12 minutes ago</time>
274+
</div>
275+
</div>
276+
</div>
277+
278+
<div class="protip-comment comment-box">
279+
<h5><img src="img/user-avatar.png" class="comment-avatar"> tranhelen</h5>
280+
<form>
281+
<div class="grid">
282+
<div class="grid__item three-quarters">
283+
<textarea placeholder="Start writing here..."></textarea>
284+
</div>
285+
<div class="grid__item one-quarter">
286+
<a href="" class="btn btn--small">Send</a>
287+
</div>
288+
</div>
289+
</form>
290+
</div>
291+
292+
</div>
293+
294+
</div>
295+
296+
</article>
297+
298+
</div>
299+
</div>
300+
</div>
301+
302+
<footer class="site-footer">
303+
<div class="container">
304+
<div class="grid">
305+
<div class="grid__item large--two-quarters small--text-center medium--text-center">
306+
<ul class="inline footer-nav">
307+
<li><a href="">API & Hacks</a></li>
308+
<li><a href="">Privacy</a></li>
309+
<li><a href="">Terms of Service</a></li>
310+
</ul>
311+
<p class="copy">Copyright &copy; 2014 Assembly Made, Inc. All rights reserved.</p>
312+
</div>
313+
<div class="grid__item large--two-quarters small--text-center medium--text-center large--text-right">
314+
<a href="https://twitter.com/coderwall" class="twitter-follow-button" data-show-count="false">Follow @coderwall</a>
315+
<script>!function(d,s,id){var js,fjs=d.getElementsByTagName(s)[0],p=/^http:/.test(d.location)?'http':'https';if(!d.getElementById(id)){js=d.createElement(s);js.id=id;js.src=p+'://platform.twitter.com/widgets.js';fjs.parentNode.insertBefore(js,fjs);}}(document, 'script', 'twitter-wjs');</script>
316+
<a href="https://mixpanel.com/f/partner" class="mixpanel"><img src="http://cdn.mxpnl.com/site_media/images/partner/badge_light.png" alt="Mobile Analytics" /></a>
317+
</div>
318+
</div>
319+
</div>
320+
</footer>
321+
322+
<script src="http://ajax.googleapis.com/ajax/libs/jquery/2.1.1/jquery.min.js"></script>
323+
<script src="js/highlight.js"></script>
324+
<script>
325+
hljs.initHighlightingOnLoad();
326+
327+
$('.upvote').on('click', function() {
328+
$(this).toggleClass('upvote--voted');
329+
});
330+
331+
$('.upvote--popular').on('click', function() {
332+
$(this).toggleClass('upvote--popvoted');
333+
});
334+
</script>
335+
336+
</body>
337+
</html>

0 commit comments

Comments
 (0)
Please sign in to comment.