Ufdbguard stopped working

webproxy

(Michael Träumner) #1

NethServer Version: 7.4
Module: ufdbguard

Today I registered that proxy stopped it’s work. I could navigate to all sites, also the blocked ones.
After restarting squid and ufdbguard everything went fine, but perhaps somebody can help finding out what happens before. Here is the ufdbguard log with the errors:

The ufdbGuard (1.33.4) software suite is free and Open Source Software. Copyright (C) 2005-2017 by URLfilterDB B.V. and others. 
2018-04-16 03:32:00 [19585] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 2018-04-16 03:32:00 [19585] ufdbgclient 1.33.4 started 
2018-04-16 03:32:00 [19585] cannot connect to ufdbguardd daemon - is it running? If yes, check the -p option.
2018-04-16 03:32:00 [19588] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 
2018-04-16 03:32:00 [19588] ufdbgclient 1.33.4 started 
2018-04-16 03:32:00 [19588] cannot connect to ufdbguardd daemon - is it running? If yes, check the -p option. 
2018-04-16 03:32:02 [19585] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 
2018-04-16 03:32:02 [19585] after sleeping 2 seconds I still could not connect to the ufdbguardd daemon 
2018-04-16 03:32:02 [19585] 
2018-04-16 03:32:02 [19585] FATAL ERROR: cannot connect to ufdbguardd daemon socket: No such file or directory 
2018-04-16 03:32:02 [19585] Check if ufdbguardd is running and if the -p option is required. ***** 
2018-04-16 03:32:02 [19585] 
2018-04-16 03:32:02 [19584] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 
2018-04-16 03:32:02 [19584] after sleeping 2 seconds I still could not connect to the ufdbguardd daemon 
2018-04-16 03:32:02 [19586] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 
2018-04-16 03:32:02 [19586] after sleeping 2 seconds I still could not connect to the ufdbguardd daemon 
2018-04-16 03:32:02 [19587] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 
2018-04-16 03:32:02 [19587] after sleeping 2 seconds I still could not connect to the ufdbguardd daemon 
2018-04-16 03:32:02 [19588] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977 
2018-04-16 03:32:02 [19588] after sleeping 2 seconds I still could not connect to the ufdbguardd daemon

(Filippo Carletti) #2

Those log lines don’t tell me what’s the problem.
Hints may be somewhere else in /var/log/ufdbguard/ufdbguardd.log or in other logs (/var/log/messages, /var/log/squid/cache.log).
Search around the time of the problem (03:32:00).


(Michael Träumner) #3

Thanks for your answer Filippo.
/var/log/ufdbguard/ufdbgardd stopped logging a time ago at the 6th April and started logging again after I restarted the service today. The log says, that it killed the process because there are running two of them.

Here are the last lines of the old log (it was already zipped)

2018-03-06 09:58:25 [1194] database status: up to date
2018-03-06 09:58:25 [1194] license status: unknown
2018-03-06 09:58:25 [1194] configuration status: ok
2018-03-06 09:58:25 [1194]  
2018-03-06 09:58:25 [1194] using OpenSSL library 1.0.1e R (OpenSSL 1.0.1e-fips 11 Feb 2013)
2018-03-06 09:58:26 [1194] HTTPS/SSL verification with trusted certificates from file "/var/ufdbguard/blacklists/security/cacerts" and directory "none"
2018-03-06 09:58:26 [1194] LC_CTYPE is not set
2018-03-06 09:58:26 [1194] LANG is 'C'
2018-03-06 09:58:26 [1194] 32 HTTPS verification threads created.
2018-03-06 09:58:26 [1194] time definitions are used; evaluating current ACLs
2018-03-06 09:58:26 [1194] Changing daemon status to "started"
2018-03-06 09:58:26 [1194] raising privileges to check if an other ufdbguardd process exists
2018-03-06 09:58:26 [1194] dropped privileges and became user 'ufdb'
2018-03-06 09:58:26 [1194] 
2018-03-06 09:58:26 [1194]    FATAL ERROR: another instance of ufdbguardd with pid 1194 is running.  *****
2018-03-06 09:58:26 [1194]     
2018-03-06 09:58:26 [1194] 
2018-03-06 09:58:26 [1194]    FATAL ERROR: cannot bind daemon socket: Success (protocol=UNIX)  *****
2018-03-06 09:58:26 [1194]     
2018-03-06 09:58:26 [1194] check for and kill old daemon processes
2018-03-06 09:58:26 [1194] and remove UNIX socket file "/tmp/ufdbguardd-03977"
2018-03-06 09:58:26 [1194] Changing daemon status to "error"
2018-03-06 09:58:26 [1194] terminating connections with clients
2018-03-06 09:58:26 [1194] Changing daemon status to "terminated"
2018-03-06 09:58:26 [1194] ufdbGuard daemon stopped

(Michael Träumner) #4

Some tips for me how to find the reason? messages.log from 6th April are deleted by system.


(Markus Neuberger) #5

Maybe cross checking other logs to see if something “strange” happened on 2018-03-06 9:58?
I suspect a one time hanging process.
I did some research and there were not much satisfying results, a sudden shutdown could be a reason:

https://sourceforge.net/p/ufdbguard/discussion/454412/thread/4113f11c/
https://ubuntuforums.org/archive/index.php/t-2205242.html


(Michael Träumner) #6

Thanks for your answer Markus, I think I have no chance. Other logs like messages, squid and ufdbguard were deleted by system.

I’ve checked the uptime and I restarted the server at 6th March around 12 o’clock.
I remember I had a problem that it wasn’t reachable before, so I killed it by power-of.


(ConnieTAN) #7

Hello guys,

I really want to know how you fix this issue, I met the same error:
2018-08-30 16:04:52 [4530] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977
2018-08-30 16:04:52 [4527] ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977


(Michael Träumner) #8

I restarted the squid and ufdbguard service.


(ConnieTAN) #9

I restarted the server, but the error still be here :sleepy:


(Michael Träumner) #10

Can you find something at the messages.log for the time you try to start the service?


(ConnieTAN) #11

I can’t find messages.log on my server, do you have any other idea to check?


(Markus Neuberger) #12

It’s located in /var/log/messages.

You may use the Log viewer in the web UI too.


(ConnieTAN) #13

Hello Mrmarkuz, here is the log in message:
Sep 3 22:50:01 vm-squid-ppd systemd: Created slice User Slice of root.
Sep 3 22:50:01 vm-squid-ppd systemd: Starting User Slice of root.
Sep 3 22:50:01 vm-squid-ppd systemd: Started Session 57 of user root.
Sep 3 22:50:01 vm-squid-ppd systemd: Starting Session 57 of user root.
Sep 3 22:50:01 vm-squid-ppd systemd: Removed slice User Slice of root.
Sep 3 22:50:01 vm-squid-ppd systemd: Stopping User Slice of root.
Sep 3 22:50:54 vm-squid-ppd systemd: Created slice User Slice of nsoc.
Sep 3 22:50:54 vm-squid-ppd systemd: Starting User Slice of nsoc.
Sep 3 22:50:54 vm-squid-ppd systemd-logind: New session 58 of user nsoc.
Sep 3 22:50:54 vm-squid-ppd systemd: Started Session 58 of user nsoc.
Sep 3 22:50:54 vm-squid-ppd systemd: Starting Session 58 of user nsoc.
Sep 3 22:50:55 vm-squid-ppd dbus[567]: [system] Activating service name=‘org.freedesktop.problems’ (using servicehelper)
Sep 3 22:50:55 vm-squid-ppd dbus[567]: [system] Successfully activated service ‘org.freedesktop.problems’
Sep 3 22:52:26 vm-squid-ppd dbus[567]: [system] Activating via systemd: service name=‘net.reactivated.Fprint’ unit=‘fprintd.service’
Sep 3 22:52:26 vm-squid-ppd systemd: Starting Fingerprint Authentication Daemon…
Sep 3 22:52:26 vm-squid-ppd dbus[567]: [system] Successfully activated service ‘net.reactivated.Fprint’
Sep 3 22:52:26 vm-squid-ppd systemd: Started Fingerprint Authentication Daemon.
Sep 3 22:52:26 vm-squid-ppd fprintd: Launching FprintObject
Sep 3 22:52:26 vm-squid-ppd journal: D-Bus service launched with name: net.reactivated.Fprint
Sep 3 22:52:26 vm-squid-ppd journal: entering main loop
Sep 3 22:52:32 vm-squid-ppd su: (to root) nsoc on pts/0
Sep 3 22:52:56 vm-squid-ppd journal: No devices in use, exit
Sep 3 22:53:57 vm-squid-ppd systemd: Stopping Squid caching proxy…
Sep 3 22:53:58 vm-squid-ppd systemd: Starting Squid caching proxy…
Sep 3 22:53:58 vm-squid-ppd squid[14255]: Squid Parent: will start 1 kids
Sep 3 22:53:58 vm-squid-ppd squid[14255]: Squid Parent: (squid-1) process 14257 started
Sep 3 22:53:58 vm-squid-ppd systemd: Started Squid caching proxy.


(ConnieTAN) #14

and one more error information from /var/log/squid/cache.log:
2018/09/03 23:50:13 kid1| PROXY protocol error: invalid header from local=10.70.1.4:312 8 remote=10.70.1.4:46492 FD 10 flags=1
2018/09/03 23:50:13.761 kid1| 33,2| client_side.cc(817) swanSong: local=10.70.1.4:3128 remote=10.70.1.4:46492 FD 10 flags=1


(Markus Neuberger) #15

You may try to restart the services squid and ufdb by using the web UI/Services or by using command line with systemctl restart ufdb squid

After that check the logs /var/log/messages and /var/log/ufdbguard/ufdbguardd.log for errors related to squid or ufdbguard.


(ConnieTAN) #16

When I restart squid, no log.
When I restart ufdb, here are the log in each file:
/var/log/message:
Sep 4 13:10:11 vm-squid-ppd systemd: Stopping LSB: ufdbguardd daemons from URLfilterDB…
Sep 4 13:10:11 vm-squid-ppd ufdb: sent signal sigterm to ufdbguardd (pid=917)
Sep 4 13:10:12 vm-squid-ppd ufdb: Shutting down URLfilterDB daemons OK
Sep 4 13:10:12 vm-squid-ppd systemd: Starting LSB: ufdbguardd daemons from URLfilterDB…
Sep 4 13:10:13 vm-squid-ppd ufdb: Starting URLfilterDB daemons OK
Sep 4 13:10:13 vm-squid-ppd systemd: Started LSB: ufdbguardd daemons from URLfilterDB.

/var/ufdbguard/logs: no other log except reminding the database update.

/var/log/squid/ufdbgclient.log: ERROR: cannot connect to UNIX socket /tmp/ufdbguardd-03977
/var/log/squid/cache.log
2018/09/04 13:09:15 kid1| Set Current Directory to /var/spool/squid
2018/09/04 13:09:15 kid1| Finished loading MIME types and icons.
2018/09/04 13:09:15.025 kid1| 33,2| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x55bf37a246d0 [call26]
2018/09/04 13:09:15.025 kid1| 33,2| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=0.0.0.0:3128 remote=[::] FD 26 flags=9, err=0, HTTP Socket port=0x55bf37a24730) [call26]
2018/09/04 13:09:15.025 kid1| HTCP Disabled.
2018/09/04 13:09:15.025 kid1| Squid plugin modules loaded: 0
2018/09/04 13:09:15.025 kid1| Adaptation support is off.
2018/09/04 13:09:15.026 kid1| 33,2| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=0.0.0.0:3128 remote=[::] FD 26 flags=9, err=0, HTTP Socket port=0x55bf37a24730)
2018/09/04 13:09:15.026 kid1| 33,2| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call26]
2018/09/04 13:09:15.026 kid1| Accepting HTTP Socket connections at local=0.0.0.0:3128 remote=[::] FD 26 flags=9
2018/09/04 13:09:15.026 kid1| 33,2| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=0.0.0.0:3128 remote=[::] FD 26 flags=9, err=0, HTTP Socket port=0x55bf37a24730)
2018/09/04 13:09:16 kid1| storeLateRelease: released 0 objects


(Michael Träumner) #17

Which version of nethserver do you run? Is your system up to date. I’ve read about a problem with an old ufdbguard and squid 3.4.

https://bugs.mageia.org/show_bug.cgi?id=16734


(ConnieTAN) #18

Hi, Now it works for http but https is bad.
Error:
Proxy tunneling failed: ForbiddenUnable to establish SSL connection.
in/var/log/squid/access/log:
2018-09-06 11:19:40 CST 1 ms 10.70.2.4 TCP_DENIED/403 3890 bits CONNECT www.urlfilterdb.com:443 HIER_NONE/- text/html - Wget/1.14%20(linux-gnu)


(Michael Träumner) #19

What did you do?

Could you please show us your configuration?


(ConnieTAN) #20

Here is my config:

#
acl CONNECT method CONNECT

#Debug option
debug_options ALL,1 33,2

#Source IP object
acl src_ip_127.0.0.1/32 src 127.0.0.1/32

#Source ip object
include /etc/squid/source_ip.conf

#Source network object
include /etc/squid/source_network.conf

#Destination ip object
include /etc/squid/destination_ip.conf

#Destination network object
include /etc/squid/destination_network.conf

#Destination domain object
include /etc/squid/destination_domain.conf

#Port object
include /etc/squid/port.conf

# Leave coredumps in the first cache dir
coredump_dir /var/spool/squid

# Squid normally listens to port 3128
#http_port 0.0.0.0:3128 require-proxy-header
http_port 3128 **// delete "require-proxy-header"**
proxy_protocol_access allow src_ip_127.0.0.1/32
proxy_protocol_access allow src_net_10.0.0.0/8
proxy_protocol_access allow src_net_172.16.0.0/12
proxy_protocol_access allow src_net_192.168.0.0/16

#Rules
include /etc/squid/rules.conf

# Configuration recommend by ufdbGuard
url_rewrite_children 32 startup=8 idle=4 concurrency=4
url_rewrite_program /usr/sbin/ufdbgclient -m 4 -l /var/log/squid/
url_rewrite_extras "%>a/%>A %un %>rm bump_mode=%ssl::bump_mode sni='%ssl::>sni' referer='%{Referer}>h'"

# And finally deny all other access to this proxy
http_access deny all
http_access deny all
cache deny all

now, http and the domain was defined in my rule.conf works well, just https bad.
PS: I use squid with ufdbguard