pfSense: High CPU Load with Videocache 1.9.3.
by andylai on 27 Mar 2010I just updated my pfSense box (1.2.2) previously running Videocache 1.9.2 to 1.9.3 (just receive from admin). After configuring the /etc/videocache.conf and /usr/local/pkg/squid.inc as running with old version 1.9.2. But this time I didn't change the /usr/share/videocache/videocache.py cause I believe admin had make the necessary modification on it.
Right after I restarted Squid, the pfSense starting to overload on its CPU. System log showing error on Squid,
Mar 27 14:02:44 php: /pkg_edit.php: Reloading Squid for configuration sync
Mar 27 14:02:49 check_reload_status: reloading filter
Mar 27 14:03:32 php: /pkg_edit.php: Reloading Squid for configuration sync
Mar 27 14:03:44 squid[6726]: The url_rewriter helpers are crashing too rapidly, need help!
Mar 27 14:03:44 kernel: pid 6726 (squid), uid 62: exited on signal 6
Mar 27 14:03:44 squid[6713]: Squid Parent: child process 6726 exited due to signal 6
Mar 27 14:03:52 squid[6713]: Squid Parent: child process 8019 started
The Videocache log starting to grow very big (over 100MB) containing same message,
2010-03-27 14:10:20,899 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,912 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,913 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,913 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,913 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,914 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,914 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,914 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,915 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,915 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,915 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,916 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,916 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,917 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,917 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:10:20,917 8020 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,158 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,158 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,158 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,159 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,159 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,159 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,160 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,160 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,160 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,161 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,161 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,161 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,162 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,162 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,163 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,164 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,164 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,164 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,165 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,165 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,165 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,166 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,166 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,166 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,167 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,167 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,167 8022 - - RELOAD - videocache plugin was reloaded.
2010-03-27 14:12:47,168 8022 - - RELOAD - videocache plugin was reloaded.
Here I also paste,
Squid ACLs added inside /usr/local/pkg/squid.inc : http://pastebin.com/XwyvqhJu
/etc/videocache.conf : http://pastebin.com/vb8xTnXt
Note,
Because I updated the 1.9.3 on active production pfSense system so when error occur I had to temporary move back to 1.9.2 first cause it is crashing the pfSense system. But when I downgraded back to 1.9.2 (redo all configuration) the pfSense system when back normal after reboot (no more high CPU load).
10 Answers
Hi!
Please do according to this checklist
1. Determine the user who owns/runs squid process (it'll either with proxy or squid).
2. Check if /var/spool/videocache is owned by squid user.
3. Check if /var/log/videocache is owned by squid user.
4. Check if any python process is listening on port 9100.
Plus your squid.conf contains old acls. Please update them from installation page.
Please report your observations.
Thank You!
While waiting for admin respond, I had configure another non production testing platform with pfSense 1.2.2 to test the VideoCache 1.9.3.
After successfully install and configure pfSense 1.2.2 with Squid 2.7.7 and tested in working condition. I started to install necessary python packages,
python26-2.6.4
py26-bsddb
py26-gdbm
py26-sqlite3
py26-tkinter
and also the critical component to run VideoCache,
py26-urlgrabber
py26-iniparse
then of course the VideoCache 1.9.3 bundle.
I had make some changes in /etc/videocache.conf like,
cache_host = 192.168.1.1
proxy = http://192.168.1.1:3128/
max_parallel_downloads = 3
video_lifetime = 90
rpc_host = 192.168.1.1
follow by editing the /usr/local/pkg/squid.inc by adding what instructed by admin from last reply (using the original alcs provided).
I link /var/spool/videocache to /usr/local/www/videocache.
Then I change owner of /var/spool/videocache, /var/log/videocache and /usr/local/www/videocache/ to proxy:proxy as Squid Owner in pfSense (FreeBSD).
# chown -R proxy:proxy /var/spool/videocache
# chown -R proxy:proxy /usr/local/www/videocache
# touch /var/log/videocache/videocache.log
# chown -R proxy:proxy /var/log/videocache/
# chmod -R 755 /var/log/videocache/
/var/log/
drwxr-xr-x 2 proxy proxy 512B Mar 29 02:18 videocache
/var/spool/
drwxr-xr-x 17 proxy proxy 512B Mar 29 02:16 videocache
This end my configuration on VideoCache in pfSense. So I reboot the pfSense for all setting to take place.
At first everything seem fine, but after a while the system starting to show high CPU load again. There is no error message in System Log, everything in pfSense seem OK and proxy service still working. I can still serf the internet with proxy enable.
Mar 29 02:37:48 php: /pkg_edit.php: Reloading Squid for configuration sync
Mar 29 02:37:59 check_reload_status: reloading filter
Mar 29 02:38:05 php: /pkg_edit.php: Reloading Squid for configuration sync
After 2 minutes I check the /var/log/videocache/ thing starting to get really wrong,
total 337860
-rwxr-xr-x 1 proxy proxy 165M Mar 29 02:39 videocache.log.1
-rw-r----- 1 proxy proxy 444B Mar 29 02:38 videocache.log
The videocache.log file starting to grow bigger and bigger. I think that was causing the high CPU load. I checked the content of the log file. It's all make out of this line,
2010-03-29 02:38:17,777 4955 - - RELOAD - videocache plugin was reloaded.
2010-03-29 02:38:17,779 4960 - - RELOAD - videocache plugin was reloaded.
2010-03-29 02:38:17,780 4961 - - RELOAD - videocache plugin was reloaded.
2010-03-29 02:38:17,781 4962 - - RELOAD - videocache plugin was reloaded.
2010-03-29 02:38:17,782 4963 - - RELOAD - videocache plugin was reloaded.
2010-03-29 02:38:17,783 4964 - - RELOAD - videocache plugin was reloaded.
continuing non stop. I have no idea on what's related to the above problem.
Hope to see admin reply soon. Thanks.
ln -s /dev/null /var/log/videocache/videocache.log is not going to work. I just tested it. It still load the CPU to 100%.
Hi!
Thanks for the detailed report. I was helping a client with videocache yesterday. Everything was fine other than similar reload messages in videocache.log. And later it turned out that his SELinux was in Enforcing mode and it was not allowing videocache to work properly.
Can you please check your selinux settings? And if it is enabled (which is the default for most linux/unix operating systems), try disabling it and then restarting squid.
Thank You!
I had open a thread at pfSense forum to ask about disabling SELinux Enforcing Mode. I am not sure how to disable it because I didn't install GRUB (add enforcing=0 behind kernel). I guest it should be adding "enforcing=0" or "selinux=0" in /boot/loader.conf. Anyway I was waiting for pfSense expert to verify that.
While waiting I was continuing testing VideoCache at my testing platform. And I had found something interesting about this problem.
1) First I boot up pfSense without adding the VideoCache ACLs into /usr/local/pkg/squid.inc (all other setting was configure properly like /etc/videocache.conf).
2) After pfSense successfully booted up. I add the ACLs into /usr/local/pkg/squid.inc. Then I refresh squid service. And WAHLA....it works (look like working).
/var/log/videocache/videocache.log
2010-03-31 10:29:59,858 3167 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:29:59,859 3167 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:29:59,859 3167 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:29:59,941 3157 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:29:59,942 3157 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:29:59,942 3157 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:00,206 3163 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:00,207 3163 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:00,208 3163 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:00,462 3158 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:00,463 3158 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:00,463 3158 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:02,927 3161 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:02,927 3161 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:02,927 3161 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:03,782 3166 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:03,783 3166 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:03,783 3166 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,055 3168 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:04,056 3168 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:04,056 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,066 3168 - - RELOAD - videocache plugin was reloaded.
.........
......... same RELOAD message (85 lines)
.........
2010-03-31 10:30:04,150 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,150 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,151 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,151 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,151 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,151 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,151 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,152 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,152 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,152 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,152 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,152 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,153 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,153 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,153 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,153 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,153 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,153 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,154 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,154 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,154 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,154 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,154 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,155 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,155 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,155 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,155 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,155 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,156 3168 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:04,928 3165 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:04,928 3165 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:04,928 3165 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:05,589 3164 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:05,589 3164 - - SCHEDULEDER - Download Scheduler starting.
2010-03-31 10:30:05,590 3164 - - RELOAD - videocache plugin was reloaded.
2010-03-31 10:30:05,762 3195 - - XMLRPCSERVER - Starting XMLRPCServer on port 9100.
2010-03-31 10:30:05,763 3195 - - SCHEDULEDER - Download Scheduler starting.
Altought is still contain lot of noisy stack print but it eventually stop. And it didn't overload the CPU anymore.
3) So I test play some Youtube video and the log show,
(Downloading Video)
2010-03-31 09:29:44,621 6538 192.168.1.201 - REQUEST - http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 09:29:44,621 6538 192.168.1.201 xm01KrsO8KY URL_HIT YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 09:29:44,621 6538 192.168.1.201 xm01KrsO8KY CACHE_MISS YOUTUBE Requested video was not found in cache.
2010-03-31 09:29:44,630 6538 192.168.1.201 xm01KrsO8KY NEW_URL YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 09:29:46,908 6538 192.168.1.201 xm01KrsO8KY SCHEDULED YOUTUBE Video scheduled for download.
2010-03-31 09:29:46,931 6538 192.168.1.1 - REQUEST - http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2
2010-03-31 09:29:46,931 6538 192.168.1.1 xm01KrsO8KY URL_HIT YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2
2010-03-31 09:29:46,932 6538 192.168.1.1 xm01KrsO8KY CACHE_MISS YOUTUBE Requested video was not found in cache.
2010-03-31 09:29:46,936 6538 192.168.1.1 xm01KrsO8KY NEW_URL YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2
2010-03-31 09:34:35,897 10272 192.168.1.201 xm01KrsO8KY DOWNLOAD YOUTUBE 12567290 Video was downloaded and cached.
(Serving Video)
2010-03-31 10:34:11,149 3195 192.168.1.201 - REQUEST - http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFOK5au1XUKtRp26okU6tOFSQsQYlllONvM=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 10:34:11,151 3195 192.168.1.201 xm01KrsO8KY URL_HIT YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFOK5au1XUKtRp26okU6tOFSQsQYlllONvM=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 10:34:11,186 3195 192.168.1.201 xm01KrsO8KY CACHE_HIT YOUTUBE Video was served from cache.
2010-03-31 10:34:11,186 3195 192.168.1.201 xm01KrsO8KY NEW_URL YOUTUBE 303:http://192.168.1.1/videocache/youtube/xm01KrsO8KY?video_id=xm01KrsO8KY&t=vjVQa1PpcFOK5au1XUKtRp26okU6tOFSQsQYlllONvM=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
Everthing seem fine.
4) Then I record down the python process while the system was still alright.
USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND
proxy 1966 0.0 0.7 18428 10804 ?? I 9:14AM 0:01.71 (squid) -D (squi
proxy 6538 0.0 0.6 11228 8884 ?? I 9:21AM 0:00.26 (python) /usr/sh
proxy 7574 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7575 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7576 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7577 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7578 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7579 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7580 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7581 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7582 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
proxy 7583 0.0 0.6 10844 8672 ?? I 9:22AM 0:00.13 (python) /usr/sh
5) Then I reboot the pfSense with the ACLs in /usr/local/pkg/squid.inc
6) The system immediately start to "BERSERK". CPU overload at 100% and /var/log/videocache/videocache.log starting to pile up again.
total 189248
-rw-r----- 1 proxy proxy 92M Mar 31 09:46 videocache.log.1
-rw-r----- 1 proxy proxy 0B Mar 31 09:42 videocache.log
7) Then I try record the python process again. This time thing look very difference while the system was BERSERKING.
USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND
proxy 2007 0.0 0.7 17404 10168 ?? I 9:40AM 0:00.10 (squid) -D (squi
proxy 2014 6.5 0.6 11228 8776 ?? R 9:40AM 0:09.14 (python) /usr/sh
proxy 1873 6.4 0.6 11228 8772 ?? R 9:40AM 0:08.64 (python) /usr/sh
proxy 1886 5.6 0.6 11228 8756 ?? R 9:40AM 0:08.79 (python) /usr/sh
proxy 2009 5.6 0.6 11228 8776 ?? R 9:40AM 0:08.56 (python) /usr/sh
proxy 2019 5.6 0.6 11228 8776 ?? R 9:40AM 0:08.68 (python) /usr/sh
proxy 1890 5.3 0.6 11228 8756 ?? R 9:40AM 0:08.69 (python) /usr/sh
proxy 2017 5.3 0.6 11228 8764 ?? R 9:40AM 0:08.80 (python) /usr/sh
proxy 2011 4.9 0.6 11228 8776 ?? R 9:40AM 0:09.02 (python) /usr/sh
proxy 1893 4.6 0.6 11228 8768 ?? R 9:40AM 0:08.36 (python) /usr/sh
proxy 2016 4.6 0.6 11228 8776 ?? R 9:40AM 0:08.37 (python) /usr/sh
proxy 1869 4.5 0.6 11228 8768 ?? R 9:40AM 0:08.44 (python) /usr/sh
proxy 1891 4.5 0.6 11228 8756 ?? R 9:40AM 0:08.39 (python) /usr/sh
proxy 1892 4.5 0.6 11228 8760 ?? R 9:40AM 0:08.40 (python) /usr/sh
proxy 2013 4.5 0.6 11228 8780 ?? R 9:40AM 0:08.25 (python) /usr/sh
proxy 2020 4.4 0.6 11228 8776 ?? R 9:40AM 0:08.25 (python) /usr/sh
proxy 2018 4.3 0.6 11228 8776 ?? R 9:40AM 0:08.42 (python) /usr/sh
proxy 1872 4.2 0.6 11228 8760 ?? R 9:40AM 0:07.40 (python) /usr/sh
proxy 1888 4.2 0.6 11228 8824 ?? R 9:40AM 0:07.72 (python) /usr/sh
proxy 2010 4.0 0.6 11228 8764 ?? R 9:40AM 0:08.10 (python) /usr/sh
proxy 1880 3.6 0.6 11228 8756 ?? R 9:40AM 0:08.08 (python) /usr/sh
it seem like python process grow in double compare to while the system was alright. And it is taking up %CPU.
8) It make me think that VideoCache is actually double loaded if the system reboot. That's when I noticed pfSense actually had Squid exit and start back again everytime when pfSense is starting even there is no VideoCache enable.
Mar 31 10:37:59 php: : Reloading Squid for configuration sync
Mar 31 10:38:00 last message repeated 6 times
Mar 31 10:38:00 squid[1862]: Squid Parent: child process 1864 started
Mar 31 10:38:00 check_reload_status: check_reload_status is starting
Mar 31 10:38:05 Squid_Alarm[1957]: Squid has exited. Reconfiguring filter.
Mar 31 10:38:05 Squid_Alarm[1959]: Attempting restart...
Mar 31 10:38:05 squid[1966]: Squid Parent: child process 1969 started
Mar 31 10:38:08 Squid_Alarm[1976]: Reconfiguring filter...
Mar 31 10:38:09 Squid_Alarm[2505]: Squid has resumed. Reconfiguring filter.
Mar 31 12:06:33 php: /pkg_edit.php: Reloading Squid for configuration sync
Mar 31 12:06:35 php: /pkg_edit.php: Reloading Squid for configuration sync
Mar 31 12:06:37 check_reload_status: reloading filter
9) Anyway I was thinking to keep on testing in my testing platform by not adding the ACLs into /usr/local/pkg/squid.inc. It sound ridiculous to put into a production system cause it will BERSERK if the system were to reboot. I will wait for pfSense Team to give result on disabling the "enforcing mode"
Now assume that I continue this temporary by adding in the ACLs after the system start and VideoCache should had been working.
I had try let VideoCache download some Youtube video.
/var/spool/videocache/youtube/
total 157536
-rw-r--r-- 1 proxy proxy 12M Mar 31 10:34 xm01KrsO8KY
-rw-r--r-- 1 proxy proxy 11M Mar 31 09:23 29NXaLxMIoY
-rw-r--r-- 1 proxy proxy 30M Mar 31 09:22 Bh2mE6K7y1g
-rw-r--r-- 1 proxy proxy 12M Mar 31 04:01 DDjIBG5RBo8
-rw-r--r-- 1 proxy proxy 12M Mar 31 03:58 HK15Fwho6Ys
Then I play it back again on the same PC after clearing and restart Mozilla. It (same Youtube video) actually re-download again and not getting it from the cache. Altought the videocache.log show the video is served from cache.
/var/log/videocache/videocache.log
(download video)
2010-03-31 09:29:44,621 6538 192.168.1.201 - REQUEST - http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 09:29:44,621 6538 192.168.1.201 xm01KrsO8KY URL_HIT YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 09:29:44,621 6538 192.168.1.201 xm01KrsO8KY CACHE_MISS YOUTUBE Requested video was not found in cache.
2010-03-31 09:29:44,630 6538 192.168.1.201 xm01KrsO8KY NEW_URL YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 09:29:46,908 6538 192.168.1.201 xm01KrsO8KY SCHEDULED YOUTUBE Video scheduled for download.
2010-03-31 09:29:46,931 6538 192.168.1.1 - REQUEST - http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2
2010-03-31 09:29:46,931 6538 192.168.1.1 xm01KrsO8KY URL_HIT YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2
2010-03-31 09:29:46,932 6538 192.168.1.1 xm01KrsO8KY CACHE_MISS YOUTUBE Requested video was not found in cache.
2010-03-31 09:29:46,936 6538 192.168.1.1 xm01KrsO8KY NEW_URL YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFM25ICe02xhMhVOVRp4N7_OH_9zrBNY-aY=&el=detailpage&ps=&fmt=34&asv=2
2010-03-31 09:34:35,897 10272 192.168.1.201 xm01KrsO8KY DOWNLOAD YOUTUBE 12567290 Video was downloaded and cached.
(serving video)
2010-03-31 10:34:11,149 3195 192.168.1.201 - REQUEST - http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFOK5au1XUKtRp26okU6tOFSQsQYlllONvM=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 10:34:11,151 3195 192.168.1.201 xm01KrsO8KY URL_HIT YOUTUBE http://www.youtube.com/get_video?video_id=xm01KrsO8KY&t=vjVQa1PpcFOK5au1XUKtRp26okU6tOFSQsQYlllONvM=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
2010-03-31 10:34:11,186 3195 192.168.1.201 xm01KrsO8KY CACHE_HIT YOUTUBE Video was served from cache.
2010-03-31 10:34:11,186 3195 192.168.1.201 xm01KrsO8KY NEW_URL YOUTUBE 303:http://192.168.1.1/videocache/youtube/xm01KrsO8KY?video_id=xm01KrsO8KY&t=vjVQa1PpcFOK5au1XUKtRp26okU6tOFSQsQYlllONvM=&el=detailpage&ps=&fmt=34&asv=2&noflv=1
(serving video)
2010-03-31 09:22:38,946 6538 192.168.1.201 - REQUEST - http://www.youtube.com/get_video?fmt=34&asv=3&video_id=Bh2mE6K7y1g&el=detailpage&t=vjVQa1PpcFMJiU5dGDiOq9_ivPXrZQ9stb4IteNCTZ8=&noflv=1
2010-03-31 09:22:38,947 6538 192.168.1.201 Bh2mE6K7y1g URL_HIT YOUTUBE http://www.youtube.com/get_video?fmt=34&asv=3&video_id=Bh2mE6K7y1g&el=detailpage&t=vjVQa1PpcFMJiU5dGDiOq9_ivPXrZQ9stb4IteNCTZ8=&noflv=1
2010-03-31 09:22:38,948 6538 192.168.1.201 Bh2mE6K7y1g CACHE_HIT YOUTUBE Video was served from cache.
2010-03-31 09:22:38,948 6538 192.168.1.201 Bh2mE6K7y1g NEW_URL YOUTUBE 303:http://192.168.1.1/videocache/youtube/Bh2mE6K7y1g?fmt=34&asv=3&video_id=Bh2mE6K7y1g&el=detailpage&t=vjVQa1PpcFMJiU5dGDiOq9_ivPXrZQ9stb4IteNCTZ8=&noflv=1
(serving video)
2010-03-31 09:23:59,777 6538 192.168.1.201 - REQUEST - http://www.youtube.com/get_video?asv=3&fmt=34&el=detailpage&noflv=1&t=vjVQa1PpcFP25XR4uTrxvNzIb9y2fOiBDHY_tit4MSY=&video_id=29NXaLxMIoY
2010-03-31 09:23:59,778 6538 192.168.1.201 29NXaLxMIoY URL_HIT YOUTUBE http://www.youtube.com/get_video?asv=3&fmt=34&el=detailpage&noflv=1&t=vjVQa1PpcFP25XR4uTrxvNzIb9y2fOiBDHY_tit4MSY=&video_id=29NXaLxMIoY
2010-03-31 09:23:59,778 6538 192.168.1.201 29NXaLxMIoY CACHE_HIT YOUTUBE Video was served from cache.
2010-03-31 09:23:59,778 6538 192.168.1.201 29NXaLxMIoY NEW_URL YOUTUBE 303:http://192.168.1.1/videocache/youtube/29NXaLxMIoY?asv=3&fmt=34&el=detailpage&noflv=1&t=vjVQa1PpcFP25XR4uTrxvNzIb9y2fOiBDHY_tit4MSY=&video_id=29NXaLxMIoY
Funny!!!!! I was wondering where's the video served to?
Yet if I paste the http://192.168.1.1/videocache/youtube/29NXaLxMIoY?asv=3&fmt=34&el=detailpage&noflv=1&t=vjVQa1PpcFP25XR4uTrxvNzIb9y2fOiBDHY_tit4MSY=&video_id=29NXaLxMIoY into Mozilla address bar. Mozilla can actually download that file from VideoCache.
http://i889.photobucket.com/albums/ac92/ltetlie/VideoCache/proxysavevideo.png
oppssss.....pfSense admin return my thread saying that's is no SELinux support in Freebsd.
http://forum.pfsense.org/index.php/topic,23965.0.html
T.T
Hi!
It must be a pfsense specific problem because I myself have it working on CentOS 5.4 and Fedora and other are also using it on other platforms. Please let me know if you are in for live support kind of thing where we can debug the problem together.
Thank You!
I think it's pfSense specific problem also. Consider seeing all VideoCache users already start caching with the new 1.9.3. bundle.
I try to search for VideoCache user at pfSense forum but there were not much pfSense user using VideoCache and most of them who did haven't got any luck.
For pfSense base system I'll going to give up on VideoCache and switch to Lusca. I temporary was not good enough to configure a Fedora or other Linux OS. I just start using Linux base system not long ago (newbie). I started to use pfSense bacause it didn't need to much knowledge on Linux in order to use it.
Maybe I'll wait for some other pfSense user who was more knowledgeable to fix those errors.
Thanks for all the help. Thank you very much.