Please let me know what tool do you want me to run, parameters and so on. I tried to profile this with callgrind, but I couldn't find much.
Also remember that is system time what is high, user time is quite low. From: [email protected] [mailto:[email protected]] On Behalf Of Fedor Indutny Sent: Thursday, March 27, 2014 10:27 AM To: [email protected] Subject: Re: [libuv] High CPU usage for file writes (Linux) -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hello again! Sorry, forgot to say one more thing. Could you please try profiling application to obtain some hot stack traces. This could be quite useful for figure it out. Cheers, Fedor. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1 iQIcBAEBAgAGBQJTNF8wAAoJEPsOEJWxeXmZ0OsP/1xwzZhb8GwEpPdDzM6ONZ8n lfEIJMbyDmADzO9vlYPmjZn4g3zjkJttUt7VRkKagMz6WtrnTCBLQHlfgAj8r00j JE2ThlhOnshFysug0tiESCbjX8X409hd2FHZaF1SypQyOBVkjA9hYp6TBMBD0Gu0 7dyDxbg0OSwDBrPR/nF5QFC/h4qApSWTR/9zQu+rdiN68o4dHDWvkPuCMKCh5WpN 7Ou03oOMSij/crpxaVJ1oQpzyufMNJ5oXOOg9su1EqpymSFXpQDwFp98AAcBtfWh tInBLEMZfdyvEqeuGszr9P1KneVNp2MWzOUxNs66aOL0sxTGggRWmYyUdDSseNgc lzN51cifh6AZApEyIE2e4j5UBLyk+Sa7hnUFmWL5p3eSLYQ58e8DQrlKAlQjeZEC i/xXzuXHKQae9GnV+mGbghRA4XO8OxbbbMSAOCDOMn3PkOp65AkE8jMKDqxqk7D1 BaB/uKLSNmx1t5mPcDXI61M+pDSP1T+TTPvCE5eHorxM814zhG5n8WQCC4SiN5EL sfK8FI6v3LP1h+JZhAmnD9cK1MftC4xJCVjVWrjZOCRX9+kiu6XZpyPu/6deuLvW MaoWjv9fP/A81JDQNU67pz5CfHn8YMSb0d3EqV/I3LORU7Z1RKpGAZmGKcw9zWYd /La+3V70KdJIVoFp9PgK =t2qj -----END PGP SIGNATURE----- On Thu, Mar 27, 2014 at 9:23 PM, Damian Lezama <[email protected]<mailto:[email protected]>> wrote: Thanks for looking into the trace. I'm not forking, so it has to be libuv. You say it's not that bad, but the CPU usage is quite high, I'd not expect the main loop thread at 50%+ CPU and the worker threads at 20%+ CPU for just doing file writes... From: [email protected]<mailto:[email protected]> [mailto:[email protected]<mailto:[email protected]>] On Behalf Of Fedor Indutny Sent: Thursday, March 27, 2014 10:01 AM To: [email protected]<mailto:[email protected]> Subject: Re: [libuv] High CPU usage for file writes (Linux) -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hm... I don't see any oddities in this trace. Does libcurl fork or what? I'm totally unaware of how it works, but from the trace it seems that there is some sort of lock contention between processes. Though, it is not really that bad. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1 iQIcBAEBAgAGBQJTNFkqAAoJEPsOEJWxeXmZGF4P/iHHUXJvM7HiL7p9kUxqfCfD wnaFxsbq/sZsoAAttMw2MN6zW2YgdmRh477TGNZDElfaqsr58bwYvITSSWEp5BuW J/HAi21kVyDH1HVW1G3oO32V8FMLD2SA9TCl8p/7WUGg05Np6D4L/ix9CCD+mPBZ qIV2d4u3ld+MbI1N3TPlmQQJa+DdTx5Et8+RSwMSysOi4W+ke8zxTs+nkvyCD9Oz q6gDq2hK3uFpJ92AZN0nfMk5fd8gnK8WYJAimEcUxhsNEyrO5C05hSYWw1B3WHp/ N/5+bwldv6AS8US+Dd003C3JR+y5nyjBrnH76S0uRcUikoS/ktTn2M+7RHKbyJIg BmTDdYJOGUz+N+YJZ/rwNWxI5R7kjtVdVcGzKRjdgbOl0xXevo23LRHKaMBcBU5E y1oDCmrHGeX4k/3j53yczmEY9Hv4JDy4Xx/drwvN11B6E9QZcj5w+Fe0A/7P0Zm0 mztM19hSj69H+Cwun30lzjTqCxkyncwK4Gdu5bTlveVrizCFDd5xh5UDlLBuGfsP SoHTiNohO1hbjutv1Q0QnKcuABZ+3x6wvj1iGNRsiWVoevdv8+T9kGuy6A9Py3n4 yzfN3H8jAN1ZOmClIojfVUe4cMyV7+ZHHjFFbWDddV08/EDGm1Cm8orWewen/Mq8 9hh6rrCF50TvDwQugMjC =MadL -----END PGP SIGNATURE----- On Thu, Mar 27, 2014 at 12:56 AM, Damián Lezama <[email protected]<mailto:[email protected]>> wrote: You are right, there were child processes. I wasn't expecting that, shouldn't everything run in the same process? In any case, I ran this: time strace -f -T -o trace <my test> And since the trace is quite big I'm sharing it here: https://drive.google.com/file/d/0B5b62mktIEdjTlQzVHh2VXpSYmc/edit?usp=sharing On Wednesday, March 26, 2014 3:28:15 AM UTC-7, Fedor Indutny wrote: -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hello Damian! It is quite odd, but I can't see any informative system calls in the trace that you have attached. May I ask you to try running `strace` with a `-f` flag just to make sure that we are not missing anything valuable. Thank you, Fedor. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1 iQIcBAEBAgAGBQJTMqurAAoJEPsOEJWxeXmZCtUP/3snL8KwgWJb8P/4U0+JLDQo npG9b9t1ox6i0KFoJH0vec02VS5mpaD9jffP3reKC+2Y/RDWAtH8MM22+tuWk1t+ WYZQbnqQZ7x4V0UnrL0IhdQGlBSCTE/SAKaFZQfnXJr156Ik/oNJlwYyqb2qNR3y j5rfwBRSTPi0qYfmRmhnWCEJH5iP6vLh3b9Q1mPA2EXzKRNr/A+HiY1FLR3/M0Oy LicwtIg43EW+b/rejlGh796oLZF733pKAo+K4HRE1md3pkXuAgAcGYwcjrQfXzmC ZtkryN2CTSXrhmOs8Zr+Uf002rqXvWiM8gTGLcEj0eSEGM42ZIVXvJVdgYZYWpm8 qdd7MQIyER92mhRqUjxqrfgHmjTfVK5BI4mfpzPCb4/bga+Qm+RHw9dDUhA7OAG/ LLaaCFHDxl+KvFZmEzIqx/ICdcoQq1XVN3Dd9/lV1sCZ0Ier0Jyxd3cM0e6v3xCq uME1k8PHUhJrACd3XW0aTXrNIun4Q4/peFd6+v0q86RpAM7eHBdjrXVRsVu2QQWZ Ux6UV3GVQWd11CtU6Bh/IBVQpfQdURbMxoka5ZJgVzyKSciPMdgjnz3jIefNiRFi LNDbPcmlmAVrxByya7OLgHJKJex0PJ8n4ZINCV4xyL+hbYgVFagBDfl2PtNJ24ug 1oUG0c2F209XqrhGTUO8 =XP8c -----END PGP SIGNATURE----- On Tue, Mar 25, 2014 at 2:06 AM, Damián Lezama <[email protected]<mailto:[email protected]>> wrote: I'm attaching strace output. Looks like just a single call to futex is responsible for most of the spinning. I'm not an expert here, I'm not sure I'm reading this correctly. Let me know if you want me to send other traces. On Monday, March 24, 2014 2:09:04 PM UTC-7, Fedor Indutny wrote: My guess would be that it waits a lot in `epoll_wait()`... Anyway, it would be good to take a look at some source sample, or just to have a test case. On Tue, Mar 25, 2014 at 1:04 AM, Damián Lezama <[email protected]<mailto:[email protected]>> wrote: Let's see if this helps. It is from a test run that took less than 5 seconds, where I downloaded 100 files *one at a time*. There should not be much contention here, and it is very strange that only 9 calls to futex can spin so much. Any ideas? % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 99.94 4.150578 461175 9 1 futex 0.01 0.000599 5 119 mmap 0.01 0.000550 6 85 mprotect 0.01 0.000354 9 40 read 0.01 0.000247 6 41 open 0.00 0.000190 5 42 42 access 0.00 0.000140 3 41 fstat 0.00 0.000125 3 42 close 0.00 0.000065 22 3 clone 0.00 0.000031 5 6 brk 0.00 0.000019 5 4 munmap 0.00 0.000014 5 3 clock_gettime 0.00 0.000012 6 2 eventfd2 0.00 0.000012 6 2 pipe2 0.00 0.000007 2 4 write 0.00 0.000007 4 2 rt_sigaction 0.00 0.000005 5 1 epoll_create1 0.00 0.000004 4 1 rt_sigprocmask 0.00 0.000004 4 1 execve 0.00 0.000004 4 1 getrlimit 0.00 0.000004 4 1 set_tid_address 0.00 0.000003 3 1 arch_prctl 0.00 0.000003 3 1 set_robust_list ------ ----------- ----------- --------- --------- ---------------- 100.00 4.152977 452 43 total On Monday, March 24, 2014 11:00:11 AM UTC-7, Damián Lezama wrote: Let me see what I can do about collecting strace data or sharing code. I wonder if you had some profiling/metrics to know how to expect. I'm writing to the disk as fast as I can (in my setup network is not the bottleneck, the disk is), and I'm writing in quite small chunks (16k because of libcurl). On Friday, March 21, 2014 11:23:05 AM UTC-7, Fedor Indutny wrote: Hi! I'm afraid it is hard to say what's going on without taking a look at actual implementation. Is it opensource? If not - could you please provide `strace` output of your program execution? Cheers, Fedor. On Fri, Mar 21, 2014 at 10:20 PM, Damián Lezama <[email protected]<mailto:[email protected]>> wrote: > Hi, > > I have a prototype that downloads multiple files at the same time with libuv > and libcurl. On my tests with very high bandwidth, the main loop thread gets > close to 100% CPU usage, while every thread pool thread is at about 20% or > 30%. If I run my prototype using the time command, I get very high system > time. If I remove the file system operations and just download and discard > the data, the CPU usage is very low and libcurl and libuv do a great job. > What may be going on here? > > Thanks, > Damian > > -- > You received this message because you are subscribed to the Google Groups > "libuv" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to [email protected]<mailto:[email protected]>. > To post to this group, send email to > [email protected]<mailto:[email protected]>. > Visit this group at http://groups.google.com/group/libuv. > For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout. -- You received this message because you are subscribed to the Google Groups "libuv" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To post to this group, send email to [email protected]. Visit this group at http://groups.google.com/group/libuv. For more options, visit https://groups.google.com/d/optout.
