Sorry for causing confusion.
The “Log enabled:” is the label on the page in front of the checkbox.
So my proxy settings.
I already enabled debug_options ALL,9 in squid config but after restart nothing is written into log.
I’m not programmer so I don’t really understand what should be done here
https://git.ipfire.org/?p=ipfire-2.x.git;a=blob;f=src/misc-progs/squidctrl.c;h=b1b9067319ad9929d1ab56f3c794047b2104bc7f;hb=HEAD
But if there is problem with proxy config then it wouldn’t by possible start it manualy.
But manual start is interesting also.
The reason you have no logs is that you have not enabled the logs on your web proxy screen. In your image, 4 sections down is the label Log settings
Then there is a line with the label text Log enabled:
To the right of that is a checkbox. You need to click on that checkbox so that it is enabled and then press the Save and Restart button at the bottom of the page.
From then on you will get some proxy logs being created.
If you are manually changing the squid.conf file and then pressing the Save and Restart button then the contents of squid.conf will be rewritten based on the Web Proxy WUI page.
If you want additional web proxy options you have to put them in the
/var/ipfire/proxy/advanced/acls/include.acl file as mentioned at the top of the squid.conf file.
1 Like
Got it again and this time I have a cache log file:
2023/10/02 15:53:44| WARNING: BCP 177 violation. Detected non-functional IPv6 loopback.
2023/10/02 15:53:44| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:53:44| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:53:44| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:53:44| Processing Configuration File: /etc/squid/squid.conf (depth 0)
2023/10/02 15:53:44| Starting Authentication on port 172.24.0.254:3128
2023/10/02 15:53:44| Disabling Authentication on port 172.24.0.254:3128 (interception enabled)
2023/10/02 15:53:44| Starting Authentication on port 172.25.0.254:3128
2023/10/02 15:53:44| Disabling Authentication on port 172.25.0.254:3128 (interception enabled)
2023/10/02 15:53:44| WARNING: HTTP requires the use of Via
2023/10/02 15:53:44| Created PID file (/var/run/squid.pid)
2023/10/02 15:53:44 kid1| WARNING: BCP 177 violation. Detected non-functional IPv6 loopback.
2023/10/02 15:53:44 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:53:44 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:53:44 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:53:44 kid1| Processing Configuration File: /etc/squid/squid.conf (depth 0)
2023/10/02 15:53:44 kid1| Starting Authentication on port 172.24.0.254:3128
2023/10/02 15:53:44 kid1| Disabling Authentication on port 172.24.0.254:3128 (interception enabled)
2023/10/02 15:53:44 kid1| Starting Authentication on port 172.25.0.254:3128
2023/10/02 15:53:44 kid1| Disabling Authentication on port 172.25.0.254:3128 (interception enabled)
2023/10/02 15:53:44 kid1| WARNING: HTTP requires the use of Via
2023/10/02 15:53:44 kid1| Current Directory is /
2023/10/02 15:53:44 kid1| Creating missing swap directories
2023/10/02 15:53:44 kid1| No cache_dir stores are configured.
2023/10/02 15:53:44| Removing PID file (/var/run/squid.pid)
after restarting squid I get this:
2023/10/02 15:57:20| WARNING: BCP 177 violation. Detected non-functional IPv6 loopback.
2023/10/02 15:57:20| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:20| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:20| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:20| Processing Configuration File: /etc/squid/squid.conf (depth 0)
2023/10/02 15:57:20| Starting Authentication on port 172.24.0.254:3128
2023/10/02 15:57:20| Disabling Authentication on port 172.24.0.254:3128 (interception enabled)
2023/10/02 15:57:20| Starting Authentication on port 172.25.0.254:3128
2023/10/02 15:57:20| Disabling Authentication on port 172.25.0.254:3128 (interception enabled)
2023/10/02 15:57:20| WARNING: HTTP requires the use of Via
2023/10/02 15:57:20| Created PID file (/var/run/squid.pid)
2023/10/02 15:57:20 kid1| WARNING: BCP 177 violation. Detected non-functional IPv6 loopback.
2023/10/02 15:57:20 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:20 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:20 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:20 kid1| Processing Configuration File: /etc/squid/squid.conf (depth 0)
2023/10/02 15:57:20 kid1| Starting Authentication on port 172.24.0.254:3128
2023/10/02 15:57:20 kid1| Disabling Authentication on port 172.24.0.254:3128 (interception enabled)
2023/10/02 15:57:20 kid1| Starting Authentication on port 172.25.0.254:3128
2023/10/02 15:57:20 kid1| Disabling Authentication on port 172.25.0.254:3128 (interception enabled)
2023/10/02 15:57:20 kid1| WARNING: HTTP requires the use of Via
2023/10/02 15:57:20 kid1| Current Directory is /srv/web/ipfire/cgi-bin
2023/10/02 15:57:20 kid1| Creating missing swap directories
2023/10/02 15:57:20 kid1| No cache_dir stores are configured.
2023/10/02 15:57:20| Removing PID file (/var/run/squid.pid)
2023/10/02 15:57:21| WARNING: BCP 177 violation. Detected non-functional IPv6 loopback.
2023/10/02 15:57:21| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:21| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:21| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:21| Processing Configuration File: /etc/squid/squid.conf (depth 0)
2023/10/02 15:57:21| Starting Authentication on port 172.24.0.254:3128
2023/10/02 15:57:21| Disabling Authentication on port 172.24.0.254:3128 (interception enabled)
2023/10/02 15:57:21| Starting Authentication on port 172.25.0.254:3128
2023/10/02 15:57:21| Disabling Authentication on port 172.25.0.254:3128 (interception enabled)
2023/10/02 15:57:21| WARNING: HTTP requires the use of Via
2023/10/02 15:57:21| Created PID file (/var/run/squid.pid)
2023/10/02 15:57:21 kid1| WARNING: BCP 177 violation. Detected non-functional IPv6 loopback.
2023/10/02 15:57:21 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:21 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:21 kid1| aclIpParseIpData: IPv6 has not been enabled.
2023/10/02 15:57:21 kid1| Processing Configuration File: /etc/squid/squid.conf (depth 0)
2023/10/02 15:57:21 kid1| Starting Authentication on port 172.24.0.254:3128
2023/10/02 15:57:21 kid1| Disabling Authentication on port 172.24.0.254:3128 (interception enabled)
2023/10/02 15:57:21 kid1| Starting Authentication on port 172.25.0.254:3128
2023/10/02 15:57:21 kid1| Disabling Authentication on port 172.25.0.254:3128 (interception enabled)
2023/10/02 15:57:21 kid1| WARNING: HTTP requires the use of Via
2023/10/02 15:57:21 kid1| Current Directory is /srv/web/ipfire/cgi-bin
2023/10/02 15:57:21 kid1| Starting Squid Cache version 6.3 for x86_64-pc-linux-gnu...
2023/10/02 15:57:21 kid1| Service Name: squid
2023/10/02 15:57:21 kid1| Process ID 9899
2023/10/02 15:57:21 kid1| Process Roles: worker
2023/10/02 15:57:21 kid1| With 16384 file descriptors available
2023/10/02 15:57:21 kid1| Initializing IP Cache...
2023/10/02 15:57:21 kid1| DNS IPv4 socket created at 0.0.0.0, FD 7
2023/10/02 15:57:21 kid1| Adding domain mmworx from /etc/resolv.conf
2023/10/02 15:57:21 kid1| Adding nameserver 127.0.0.1 from /etc/resolv.conf
2023/10/02 15:57:21 kid1| helperOpenServers: Starting 8/8 'redirect_wrapper' processes
2023/10/02 15:57:21 kid1| helperOpenServers: Starting 2/10 'asnbl-helper.py' processes
2023/10/02 15:57:21 kid1| Logfile: opening log stdio:/var/log/squid/access.log
2023/10/02 15:57:21 kid1| Store logging disabled
2023/10/02 15:57:21 kid1| Swap maxSize 0 + 4194304 KB, estimated 322638 objects
2023/10/02 15:57:21 kid1| Target number of buckets: 16131
2023/10/02 15:57:21 kid1| Using 16384 Store buckets
2023/10/02 15:57:21 kid1| Max Mem size: 4194304 KB
2023/10/02 15:57:21 kid1| Max Swap size: 0 KB
2023/10/02 15:57:21 kid1| Using Least Load store dir selection
2023/10/02 15:57:21 kid1| Current Directory is /srv/web/ipfire/cgi-bin
Oct 02 15:57:21 squid-asnbl-helper[9922] WARN: No ASNBL configured. This is acceptable as long as this script is configured to do anything, you just have been warned...
Oct 02 15:57:21 squid-asnbl-helper[9921] WARN: No ASNBL configured. This is acceptable as long as this script is configured to do anything, you just have been warned...
2023/10/02 15:57:21 kid1| Finished loading MIME types and icons.
2023/10/02 15:57:21 kid1| HTCP Disabled.
2023/10/02 15:57:21 kid1| Squid plugin modules loaded: 0
2023/10/02 15:57:21 kid1| Adaptation support is off.
2023/10/02 15:57:21 kid1| Accepting HTTP Socket connections at conn26 local=172.24.0.254:800 remote=[::] FD 29 flags=9
listening port: 172.24.0.254:800
2023/10/02 15:57:21 kid1| Accepting NAT intercepted HTTP Socket connections at conn28 local=172.24.0.254:3128 remote=[::] FD 30 flags=41
listening port: 172.24.0.254:3128
2023/10/02 15:57:21 kid1| Accepting HTTP Socket connections at conn30 local=172.25.0.254:800 remote=[::] FD 31 flags=9
listening port: 172.25.0.254:800
2023/10/02 15:57:21 kid1| Accepting NAT intercepted HTTP Socket connections at conn32 local=172.25.0.254:3128 remote=[::] FD 32 flags=41
listening port: 172.25.0.254:3128
2023/10/02 15:57:22 kid1| storeLateRelease: released 0 objects
Oct 02 16:01:52 squid-asnbl-helper[9921] INFO: Unable to resolve A/AAAA record of queried destination 'pti.store.microsoft.com', returning ERR...
What is it in the logs that you see as being a problem. I have very similar entries in my logs, except that you have the transparent proxy enabled and I don’t and it looks like you have authentication enabled with your transparent proxy
Besides that our logs for the parent and the child versions that are created seem to be very similar. My proxy is working fine with that and all my browsing is going through the proxy.
What problems are you seeing with the proxy browsing.
The warnings about IPv6 and the squid-asnbl-helper are normal and can be ignored.
Do you see the child proxy coming and going multiple times. That I don’t see. I only see the parent followed by the kid then the parent removing the kid and then creating the kid again. That sequence is just run once when I restart the proxy from the WUI page. After that nothing changes again.
If you are having the child die continuously then maybe something has gone wrong with the squid.conf file.
The first part is what I see if the webproxy failed to start after booting ipfire. The second part is after restarting squid via the webinterface.
I don’t have authentification enabled.
None.
No. Just happens sometimes after starting/restating ipfire. Haven’t had that problems before. Started about 1 week ago.
It dies again when I shutdown ipfire 
.
Okay. Unfortunately, there is nothing in there that indicates why it stopped, because those lines are also seen when the proxy does start.
If at bootup the proxy does all those lines in your cache.log and ends with
then that indicates that the web proxy tried to start and went quite a way through what would normally work but then just stopped after removing the kid1 pid file without giving any indication for why it stopped.
Interesting. Your log has
which I thought was related to authentication of the web browser usage.
It is obviously related to the transparent usage as it refers to port 3128, but the transparent only relates to http traffic, so I am not sure what the Starting and Disabling Authentication bit means.
I am just using the classical proxy with port 800 and I don’t get those Authentication messages at all.
You say that you are not seeing any problems with browsing but I suppose if you are using transparent proxy then if the web proxy is not running after booting then the browsers will just bypass the proxy because you are relying on the proxy to tell the browser to use it.
I don’t reboot my IPFire that often, usually only when a core update is carried out and so far that has always had the web proxy restart.
Occasionally I have that problem in my dev vm testbed when I am changing between different IPFire instances with the same uuid’s, same nic mac addresses and the same nic IP’s. Then it can be that the newly started cloned instance does not always start the web proxy.
However after restarting the web proxy on the new vm instance, if I then reboot that same vm instance several times then the web proxy has always started each time. The problem only seems to happen sometimes when I swap between different IPFire vm instances.
Even after that there is no log created
I know about this rewriting so I’m using just console.
And after restart, changes in squid.conf are still there.
Question is how to force start proxy automatically after system startup if manual start works correctly. This worked before a few updates correctly, but now I’m not sure which update was funcional lastly.
After clicking on the checkbox for logging enabled did you press the save and restart button or did you just do a restart from the console.
If the latter then nothing in the squid.conf file will have been updated from the web proxy WUI page because the console restart does not run any of the cgi code to update the configuration file.
Rather than doing manual changes to the squid.conf file you should use the include.acl file as mentioned earlier in this thread. Details can be found in this wiki page.
Manually editing the Squid configuration
This allows you to add additional squid configuration options and still press the save and restart button.
The automatic startup should be happening anyway at boot and from the logs of @xperimental the startup is mostly occurring but then stopping after having carried out around half of the startup and without any indication of why it has stopped.
You could of course create a script that checks if the web proxy is running and if not restarts it and put it into rc.local
https://wiki.ipfire.org/pkgs/rc-local
That of course doesn’t solve the problem but it provides a workaround.
This has been reported occasionally by people at various core updates over the last couple of years but no problem has ever been found in any of the logs that indicates what stopped squid from fully starting up.
Unfortunately neither myself nor any of the other core developers I spoke to last night are seeing, or have seen, this problem on their systems which makes it very hard to fault find the root cause.
After some change in WUI I use Save and restart button.
For future testing I will use that include acl.
OK
I try this solution.
Wouldn’t be easier to keep startup process of proxy just on link to rc3.d. Just asking.
Thank you for advice, I hope I solve it 
No.
I am not so familiar with the proxy and how it is integrated into the other IPFire functions but after searching through the code I now better understand.
The symlink for the squid program is tied to the red networking functions.
ls -hal /etc/rc.d/init.d/networking/red.up/27-RS-squid
lrwxrwxrwx 1 root root 11 Jun 9 20:31 /etc/rc.d/init.d/networking/red.up/27-RS-squid → …/…/squid
There are a range of programs in the red.up directory. When the networking brings the red interface up, via static, dhcp, ppp then once the red interface is considered up and active there is a function run_subdir which goes and runs all the programs that are in the red.up directory.
So squid is started automatically at boot after the red interface has been successfully brought up.
So there is a connection of squid to rc3.d but it is driven by S20network symlink which triggers the network initscript which after red has been successfully brought up triggers the squid initscript via the 27-RS-squid symlink.
I wonder if this is related to the red interface. I’ve tested the scenario a couple of time with my vm installation (identical to the native installation) and didn’t have problems with squid.
What red connection are you using on the machine having the problem. Are you using dhcp, static or ppp. I am using dhcp on all my IPFire systems.
I could test out static on my vm systems but I don’t have any opportunity to test out ppp.
The run_subdir is not code that is directly linked to the red interface code. It is a subroutine that is run after the red interface has come up. Basically the run_subdir is code that cycles through all the programs in the given subdirectory and executes all the executable scripts in it.
The programs in that subdirectory on my system are:-
ls -hal /etc/rc.d/init.d/networking/red.up/
total 60K
drwxr-xr-x 2 root root 4.0K Sep 4 15:39 .
drwxr-xr-x 4 root root 4.0K Sep 19 15:39 …
-rwxr-xr-- 1 root root 727 Jun 9 20:31 01-conntrack-cleanup
-rwxr-xr-- 1 root root 189 Jun 9 20:31 10-multicast
-rwxr-xr-- 1 root root 83 Jun 9 20:31 10-static-routes
-rwxr-xr-- 1 root root 47 Jun 9 20:31 20-firewall
-rwxr-xr-- 1 root root 1.1K Jun 9 20:31 23-suricata
lrwxrwxrwx 1 root root 36 Jun 9 20:31 24-RS-qos → …/…/…/…/…/usr/local/bin/qosctrl
-rwxr-xr-- 1 root root 80 Jun 9 20:31 25-update-dns-forwarders
lrwxrwxrwx 1 root root 11 Jun 9 20:31 27-RS-squid → …/…/squid
-rwxr-xr-- 1 root root 43 Jun 9 20:31 30-ddns
-rwxr-xr-- 1 root root 45 Jun 9 20:31 50-ipsec
-rwxr-xr-- 1 root root 118 Jun 9 20:31 50-ovpn
-rwxr-xr-- 1 root root 54 Jun 9 20:31 98-leds
-rwxr-xr-- 1 root root 71 Jun 9 20:31 99-beep
-rwxr-xr-- 1 root root 209 Jun 9 20:31 99-fireinfo
-rwxr-xr-- 1 root root 76 Jun 9 20:31 99-pakfire-update
As you can see most are executables directly in that subdirectory with two being symlinks to executables in other locations.
Forgot to mention earlier, this morning I deliberately rebooted my production CU179 IPFire system. When it came back up the web proxy was running.
DHCP via WLAN. But it’s the same as the VM, but different interfaces (PCIe vs. USB).
This is very valuable information for me, I’ll look there.
Thanks
Just had the same with my VM.
FYI: Same problem here after Update from 173 to 179. Any solution is appreciated.
With my personal device, I have that issue every time I start IPFire now. Whenever red is not ready - always, if IPFire is set up with a USB-tethering device on red - squid won’t start.
After updating from 178 to 180 with 179 i had some problems to starting the ppp after the reboot.
I had to click on the connect-button in the gui.
The log for red with 178:
> |12:25:01|pppd[2221]:|secondary DNS address xxx|
> |12:25:01|pppd[2221]:|primary DNS address xxx|
> |12:25:01|pppd[2221]:|remote IP address xxx|
> |12:25:01|pppd[2221]:|local IP address xxx|
> |12:25:01|pppd[2221]:|peer from calling number F0:xxxx authorized|
> |12:25:01|pppd[2221]:|CHAP authentication succeeded|
> |12:25:01|pppd[2221]:|CHAP authentication succeeded|
> |12:25:00|pppd[2221]:|Connect: ppp0 <--> red0.132|
> |12:25:00|pppd[2221]:|Using interface ppp0|
> |12:25:00|pppd[2221]:|Connected to f0:xxxx via interface red0.132|
> |12:25:00|pppd[2221]:|PPP session is 18983|
> |12:24:55|pppd[2221]:|pppd 2.4.9 started by root, uid 0|
> |12:24:55|pppd[2221]:|PPPoE plugin from pppd 2.4.9|
> |12:24:55|pppd[2221]:|Plugin rp-pppoe.so loaded.|
The log for red with 179/180:
|11:44:19|pppd[3714]:|secondary DNS address xxx|
|11:44:19|pppd[3714]:|primary DNS address xxx|
|11:44:19|pppd[3714]:|remote IP address xxx|
|11:44:19|pppd[3714]:|local IP address xxx|
|11:44:19|pppd[3714]:|peer from calling number F0:xxx authorized|
|11:44:19|pppd[3714]:|CHAP authentication succeeded|
|11:44:19|pppd[3714]:|CHAP authentication succeeded|
|11:44:19|pppd[3714]:|Connect: ppp0 <--> red0.132|
|11:44:19|pppd[3714]:|Using interface ppp0|
|11:44:19|pppd[3714]:|Connected to F0:xxx via interface red0.132|
|11:44:19|pppd[3714]:|PPP session is 6627|
|11:44:19|pppd[3714]:|pppd 2.5.0 started by root, uid 0|
|11:44:19|pppd[3714]:|PPPoE plugin from pppd 2.5.0|
|11:44:19|pppd[3714]:|Plugin pppoe.so loaded.|
|11:43:48|pppd[2746]:|Exit.|
|11:43:48|pppd[2746]:|Unable to complete PPPoE Discovery phase 1|
|11:43:48|pppd[2746]:|Timeout waiting for PADO packets|
|11:42:33|pppd[2746]:|pppd 2.5.0 started by root, uid 0|
|11:42:33|pppd[2746]:|PPPoE plugin from pppd 2.5.0|
|11:42:33|pppd[2746]:|Plugin pppoe.so loaded.|
|11:42:03|pppd[2329]:|Exit.|
|11:42:03|pppd[2329]:|Unable to complete PPPoE Discovery phase 1|
|11:42:03|pppd[2329]:|Timeout waiting for PADO packets|
|11:40:48|pppd[2329]:|pppd 2.5.0 started by root, uid 0|
|11:40:48|pppd[2329]:|PPPoE plugin from pppd 2.5.0|
|11:40:48|pppd[2329]:|Plugin pppoe.so loaded.|
After a 2nd reboot, the ppp-connection was established immediately.
Maybe this has something to do with the problem here?
I have no idea, I just wanted to share this information.
Looks like with core update 181 this problem is solved. I’ve restarted the device several times and never had to start squid manually.
2 Likes