Python processes consuming all my CPU time
by StevenHarrison on 22 Jul 2009VideoCache is a great product, and it was easy to get working on our PFSense 1.2.3 box.
One issue with it is the Python child processes that get spawned consume a HUGE amount of CPU time... 20-25% each. I had to reduce the children from the default 7 down to 1 just to keep it within reason on the CPU.
What causes this? How can it be fixed? Surely Python does not have that much work to do.
I notice two other users in the forum experiencing the same issue but no-one bothered to respond to their postings.
I hope that one of you guys with some experience with VideoCache will get back to me with some suggestions.
Thanks,
Steven
27 Answers
Hi Steven,
Thanks for the compliment. Python processes consume huge memory because it calculate disk size that is occupied by videos. And disk size calculation in python is really really slow and CPU intensive. That is the sole reason of high CPU usage.
One of the way to bring down CPU usage would be set the cache directory size to unlimited or zero.
e.g.
base_dir = /store/videocache/:0
See base_dir for more info.
Thank You!
Thanks for the reply, I hadn't seen a large memory foot-print, it was only CPU time that's wrecking my system.
My current config has:
base_dir = /var/spool/videocache/
That is equivalent to "unlimited" is it not?
I'm also not sure this explains the CPU usage being so high, there's hardly any users on this system right now and very little traffic... it seems that Python is stuck in some kind of very intensive loop or task without end.
Should I try the adding the :0 at the end of my base_dir directive? Or is this possibly something else?
Thanks,
Steven
No-one has anything to suggest here? I just can't accept that monitoring disk use would consume all available CPU time on my server. I have it running with less than 5% average CPU use on PFSense with traffic-shaping and Squid... simply turning on VideoCache brings my CPU time to average 95% and higher!
Someone please suggest what might be wrong or what to do to get around this.
i've been using videocache for quite sometime, and its nice until i decided to install it to a pfsense box (previous working rig was ubuntu 8.10 server). unfortunately after several tries of installing it to my pfsense box i'm stucked with it... my cpu usage was very high... and upon checking the processes, i see lots of python processes...
how could this be?
i'm using videcache-1.9.2 on pfsense 1.2.2
thanks in advance..
I also have the same problem. After looking into it, its python processes that are causing it. Maybe it has something to do with pfsense 1.2.3, I don't know. The pfsense people have not been able to help me.
I would appreciate it if anyone could point me in the right direction.
I have the exact same problem! Its python... but I don't know how to fix it. I'm using pfsense 1.2.3.
I take it admin must be very busy. Thats fine.
For now, there is some things that I've found out...
First, many, many pfsense users have mentioned that there is nothing in their /var/log/videocache/videocache.log. The reason for this is because videocache.log is a directory instead of a file. Don't ask me why. So, we need to delete the directory like this:
rm -R /var/log/videocache/videocache.log
Then create a new empty file using a text editor such as ee or vi.
After that, you will have permission problems where it says
2010/01/13 19:58:04| WARNING: url_rewriter #10 (FD 16) exited
2010/01/13 19:58:04| WARNING: url_rewriter #4 (FD 10) exited
2010/01/13 19:58:04| WARNING: url_rewriter #5 (FD 11) exited
2010/01/13 19:58:04| WARNING: url_rewriter #6 (FD 12) exited
2010/01/13 19:58:04| WARNING: url_rewriter #2 (FD 8) exited
2010/01/13 19:58:04| Too few url_rewriter processes are running
2010/01/13 19:58:04| storeDirWriteCleanLogs: Starting...
2010/01/13 19:58:04| Finished. Wrote 7153 entries.
2010/01/13 19:58:04| Took 0.0 seconds (676726.6 entries/sec).
FATAL: The url_rewriter helpers are crashing too rapidly, need help!
This is solved by doing this:
touch /var/log/videocache/videocache.log
chown -R proxy:proxy /var/log/videocache/
chmod -R 755 /var/log/videocache/
Now, after you restart squid... you should see stuff in your videocache.log file. Here is mine: http://pfsense.pastebin.com/m43f63633
So, everything is working good except that its still using 100% cpu. I can't understand it. Nothing in any of my log files seem to point to the problem. But the problem is there regardless.
To find out if it really is python or not though, you can type in ps aux
That will tell you. For me, it shows a lot of python processes that are using up 10-20% on each process.
$ ps aux
USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND
proxy 26112 16.1 0.4 11084 8060 ?? R 7:37PM 7:14.73 (python) /usr/share/videocache/videocache.py
proxy 26111 15.2 0.4 11084 8060 ?? R 7:37PM 7:15.12 (python) /usr/share/videocache/videocache.py
proxy 26110 14.4 0.4 11084 8060 ?? R 7:37PM 7:16.17 (python) /usr/share/videocache/videocache.py
proxy 26116 14.0 0.4 11084 8060 ?? R 7:37PM 7:14.41 (python) /usr/share/videocache/videocache.py
proxy 26114 13.6 0.4 11084 8148 ?? R 7:37PM 6:24.30 (python) /usr/share/videocache/videocache.py
proxy 26115 13.4 0.4 11084 8060 ?? R 7:37PM 7:16.54 (python) /usr/share/videocache/videocache.py
proxy 26113 9.8 0.4 11084 8068 ?? R 7:37PM 5:40.98 (python) /usr/share/videocache/videocache.py
Whatever the problem is... It looks like a lot of pfsense users experience it, and there's got to be a reason for it. Maybe it has something to do with videocache.py?
Thanks a lot!
~Shawn
Hey... this is Shawn Gadwa. I finally got my account working so I will use this username from now on.
Currently, the videocache is not even caching my videos. I'm thinking that its got to be because of permission problems.
I've given all the folders the proper permissions... and it still does not work.
It could be in part because I'm trying to cache videos on a separate hard drive. I have ad1s1a mounted in /cache and I have a folder in /cache called /videocache. So, in /etc/videocache.conf, I set it to cache in /cache/videocache... but its not working.
I don't know what I'm doing wrong.
But, when I do get it working... I'm going to write a wiki install guide on this.
Hi Shawn,
Ok. Lets check the permissions and ownerships once again.
First of all, check who runs squid server daemon. In Red Hat based systems its run as 'squid' user and in Debian based systems, its run as 'proxy' user.
So, all the files, directories and sub-directories (/var/log/videocache/, /cache/videocache/) should have ownership of proxy:proxy or squid:squid. In short, they should be writable by the squid server daemon.
A folder in other disk is not a problem as people are using videocache even with NFS shares and its running successfully for them.
Please reply with the results. And do paste some part of your videocache.log file on http://pastebin.com/ .
Thank You!
It seems like I have to do chown -R proxy:proxy on both /cache and /var/log/videocache every time squid restarts or I restart pfsense.
Right now, squid is working in transparent mode however videocache is still not working and its using 100% cpu.
Here is my videocache.log: http://pfsense.pastebin.com/ma98c067
Here is my cache.log:
2010/01/15 16:27:42| Reconfiguring Squid Cache (version 2.7.STABLE7)...
2010/01/15 16:27:42| FD 19 Closing HTTP connection
2010/01/15 16:27:42| FD 20 Closing HTTP connection
2010/01/15 16:27:42| logfileClose: closing log /dev/null
2010/01/15 16:27:42| Including Configuration File: /usr/local/etc/squid/squid.conf (depth 0)
2010/01/15 16:27:42| Cache dir '/cache' size remains unchanged at 40960000 KB
2010/01/15 16:27:42| parseConfigFile: squid.conf:87 unrecognized: 'delay_pools'
2010/01/15 16:27:42| parseConfigFile: squid.conf:88 unrecognized: 'delay_class'
2010/01/15 16:27:42| parseConfigFile: squid.conf:89 unrecognized: 'delay_parameters'
2010/01/15 16:27:42| parseConfigFile: squid.conf:90 unrecognized: 'delay_initial_bucket_level'
2010/01/15 16:27:42| parseConfigFile: squid.conf:91 unrecognized: 'delay_access'
2010/01/15 16:27:42| Initialising SSL.
2010/01/15 16:27:42| logfileOpen: opening log /dev/null
2010/01/15 16:27:42| Store logging disabled
2010/01/15 16:27:42| DNS Socket created at 0.0.0.0, port 17254, FD 7
2010/01/15 16:27:42| Adding domain local from /etc/resolv.conf
2010/01/15 16:27:42| Adding nameserver 10.0.0.1 from /etc/resolv.conf
2010/01/15 16:27:42| helperOpenServers: Starting 7 'python' processes
2010/01/15 16:27:43| Accepting proxy HTTP connections at 192.168.1.1, port 3128, FD 19.
2010/01/15 16:27:43| Accepting proxy HTTP connections at 10.0.0.5, port 3128, FD 20.
2010/01/15 16:27:43| Accepting transparently proxied HTTP connections at 127.0.0.1, port 80, FD 21.
2010/01/15 16:27:43| WCCP Disabled.
2010/01/15 16:27:43| Loaded Icons.
2010/01/15 16:27:43| Ready to serve requests.
Videocache.conf:
cache_host = 192.168.1.1
# Proxy for http content.
# Example : http_proxy = http://<Proxy_Server_IP_OR_Domain>:<Proxy_port>/
# or http://proxy.example.com:3128/
proxy = http://127.0.0.1:80/
I'm running it as a transparent proxy.
Now I got squid working except that videocache does not work and it still uses 100% cpu. It is not caching videos, or serving them and videocache.log says that it keeps reloading.
Hi Shawn,
Please apply the following patch to /usr/share/videocache/videocache.py file. We'll get the actual python traceback and we'll know the exact problem.
diff --git a/videocache/videocache.py b/videocache/videocache.py
index 2806773..0adcac1 100755
--- a/videocache/videocache.py
+++ b/videocache/videocache.py
@@ -545,9 +545,9 @@ def squid_part():
except IOError, e:
if e.errno == 32:
os.kill(os.getpid(), 1)
- except IndexError, e:
- log(format%(pid, '-', '-', 'RELOAD', '-', 'videocache plugin was reloaded.'))
- os.kill(os.getpid(), 1)
+ #except IndexError, e:
+ # log(format%(pid, '-', '-', 'RELOAD', '-', 'videocache plugin was reloaded.'))
+ # os.kill(os.getpid(), 1)
# Check if videocache plugin is on.
if enable_video_cache:
Restart squid after applying the patch and look cache.log for python tracebacks and paste them here.
Thank you!
I assumed that when you said to paste it into videocache.py, you meant to add it at the bottom of the text. Thats what I did and now in cache.log, I get this:
Squid Cache (Version 2.7.STABLE7): Terminated abnormally.
CPU Usage: 0.060 seconds = 0.026 user + 0.034 sys
Maximum Resident Size: 6628 KB
Page faults with physical i/o: 0
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
2010/01/15 22:45:44| Starting Squid Cache version 2.7.STABLE7 for i386-portbld-freebsd7.0...
2010/01/15 22:45:44| Process ID 8837
2010/01/15 22:45:44| With 11095 file descriptors available
2010/01/15 22:45:44| Using kqueue for the IO loop
2010/01/15 22:45:44| DNS Socket created at 0.0.0.0, port 30610, FD 12
2010/01/15 22:45:44| Adding domain local from /etc/resolv.conf
2010/01/15 22:45:44| Adding nameserver 10.0.0.1 from /etc/resolv.conf
2010/01/15 22:45:44| helperOpenServers: Starting 7 'python' processes
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
2010/01/15 22:45:46| logfileOpen: opening log /dev/null
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
File "/usr/share/videocache/videocache.py", line 870
diff --git a/videocache/videocache.py b/videocache/videocache.py
^
SyntaxError: invalid syntax
2010/01/15 22:45:46| Unlinkd pipe opened on FD 24
2010/01/15 22:45:46| Swap maxSize 40960000 + 1048576 KB, estimated 3231428 objects
2010/01/15 22:45:46| Target number of buckets: 161571
2010/01/15 22:45:46| Using 262144 Store buckets
2010/01/15 22:45:46| Max Mem size: 1048576 KB
2010/01/15 22:45:46| Max Swap size: 40960000 KB
2010/01/15 22:45:46| Store logging disabled
2010/01/15 22:45:46| Rebuilding storage in /cache (DIRTY)
2010/01/15 22:45:46| Using Least Load store dir selection
2010/01/15 22:45:46| Current Directory is /usr/local/www
2010/01/15 22:45:46| Loaded Icons.
2010/01/15 22:45:46| Accepting proxy HTTP connections at 192.168.1.1, port 3128, FD 27.
2010/01/15 22:45:46| Accepting proxy HTTP connections at 10.0.0.5, port 3128, FD 28.
2010/01/15 22:45:46| Accepting transparently proxied HTTP connections at 127.0.0.1, port 80, FD 29.
2010/01/15 22:45:46| WCCP Disabled.
2010/01/15 22:45:46| Ready to serve requests.
2010/01/15 22:45:49| WARNING: url_rewriter #1 (FD 13) exited
2010/01/15 22:45:49| WARNING: url_rewriter #2 (FD 14) exited
2010/01/15 22:45:49| WARNING: url_rewriter #3 (FD 15) exited
2010/01/15 22:45:49| WARNING: url_rewriter #4 (FD 16) exited
2010/01/15 22:45:49| Too few url_rewriter processes are running
FATAL: The url_rewriter helpers are crashing too rapidly, need help!
I think its because a/videocache/videocache.py is not the right path to videocache.py?? I dunno.
Thanks for the help.
~Shawn
Hi Shawn,
No. Thats not what I meant. I asked you to apply the patch. Anyways forget about the patch thing. I have mailed you a new version of videocache.py. Please follow the instruction in mail and report results back here.
Thank you!
Its really weird but ever since I replaced my videocache.py, I've not been getting the 100% cpu thing and my network has been much more reliable to say the least.
I've looked into it and it appears that videocache still is not working, but squid is working and I do not have the 100% cpu thing.
Here is the output of ps aux:
proxy 1068 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
proxy 1070 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
proxy 1071 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
proxy 1072 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
proxy 1074 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
proxy 1082 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
proxy 1083 0.0 0.4 11084 8044 ?? I 2:09AM 0:00.26 (python) /usr/share/videocache/videocache.py (python)
I also am not having the problem with videocache reloading contantly. here is my videocache.log:
2010-01-16 02:10:41,833 993 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-01-16 02:10:41,834 993 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:42,007 990 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:42,414 996 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:43,242 992 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:44,127 995 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:44,209 997 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:44,738 1072 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:45,037 1068 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:45,257 1074 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:46,741 991 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:48,618 1071 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:49,277 1083 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:49,856 1070 - - SCHEDULEDER - Download Scheduler starting.
2010-01-16 02:10:51,026 1082 - - SCHEDULEDER - Download Scheduler starting.
Still not working... but I do love it when I get different computer errors, it shows that we're making progress!
I've been searching the forums and I found a problem from way back that is identical to my problem.
http://cachevideos.com/forum/post/resolved-list-index-out-range
Thats odd, this was supposed to be fixed in >1.6.
Thanks a lot,
~Shawn
Ok, here it is:
http://pfsense.pastebin.com/m2d264390
That was after I restarted squid. Then /var/log/videocache was filling up that it overloaded my system. I had to empty the log files and reboot. After the reboot, I was getting this:
http://pfsense.pastebin.com/m194b9a03
EDIT: added pastebin links.
This is still a problem for me... currently videocache does not work at all. It does not have the cpu problem but it simply does not work. Any help would be appreciated.
I think maybe I'll try reinstalling videocache and then I'll apply the patch you sent me. I don't know that much about python yet... but maybe I'll have to learn ;).
Thanks,
~Shawn
I just reinstalled pfsense 1.2.3 and installed python 2.6 plus the right version of python 2.6 libraries... and still it does not work. My cpu is working like crazy and videocache does not work. Nothing in /var/squid/log/cache.log gives the slightest hit as to what might be the problem. My /var/log/videocache files are filling up REALLY fast with this RELOAD - videocache plugin was reloaded stuff.
I've tried replacing my videocache.py with the one you sent me, but that did not help and it did not make any errors show up in /cache.log. Maybe I need a different videocache.py if I'm using python 2.6.4?
I take that back... there are python traceback errors in my cache.log
Here they are: http://pfsense.pastebin.com/m25089e5d
Well, I could try python 3.1 however the additional libraries that are required are not available for 3.1. Besides... I really highly doubt that that is the problem.
What about /usr/share/videocache? Does that have to be owned by proxy:proxy?
I think I'm getting somewhere...
I've been doing ln -l on videocache folders all on my system...
I found out that /usr/share/videocache is owned by root:wheel. Also /etc/videocache.conf is owned by root (but maybe that does not matter?).
The biggest find was that /usr/local/www/videocache is owned by root:wheel. I've ran chown -R proxy:proxy on it several times, but it still says that its owned by root.
# ls -la /usr/local/www/videocache
lrwxr-xr-x 1 root wheel 17 Jan 18 21:56 /usr/local/www/videocache -> /cache/videocache
I checked /cache/videocache and its owned by proxy:proxy. I even removed the /usr/local/www/videocache link, checked ownerships, and then relinked... same problem. I tried to change ownerships again, but it did not budge.
So, two questions. How can I get /usr/local/www/videocache to be owned by proxy:proxy and how can I start squid as root (to avoid these problems)??
Thanks a lot,
~Shawn
I fixed it!
I had to do chmod -fhv proxy:proxy /usr/local/www/videocache and that forced it to change ownerships. Now, it is working and without using all my cpu. In fact, its using hardly any of my cpu!
I changed /usr/share/videocache to proxy:proxy. Should I change it back to root:wheel?
Also, I'm using the videocache.py that you emailed me... should I reinstall videocache or keep using the videocache.py that you sent me?
Hi Shawn,
I must say that you are a genius. The permissions for /usr/share/videocache doesn't really matter as videocache never tries to write anything there.
Keep using the videocache.py I emailed you and you don't need to reinstall anything till the next version.
Again, congratulation for the setup. I hope you'll find it useful.
Thank You!
Thanks. I'm going to write a guide as soon as I get the time.
So far, its still working smoothly and with no problems. One thing I noticed... and you probably noticed too, is that I meant to say chown -fhv proxy:proxy /usr/local/www/videocache. Not chmod. I must of been tired or something.
I've spent a lot of time trying to get a working squid/videocache setup... but I think it was worth it. And I've learned so much about unix in the process. I've been using Gentoo Linux for over a year now, but there's still so much to learn.
Thanks a lot,
~Shawn