denismfmcmahon at gmail
Jun 25, 2013, 8:19 AM
Post #20 of 26
(310 views)
Permalink
|
On 24/06/13 18:34, Dennis Peterson wrote:
> On 6/23/13 6:28:23PM, Denis McMahon wrote:
>> On 23/06/13 23:10, Dennis Peterson wrote:
>>> One 'stupid' question and another test. Do you have any host table
>>> entries that can be confusing your resolver?
>>>
>>> Try running (via sudo or as root)
>>>
>>> strace -f freshclam >/tmp/freshclam.txt 2>&1
>>>
>>> then post the result on your web page - it will be quite long and will
>>> clutter the mail list.
>> http://www.sined.co.uk/tmp/freshclam.txt
>>
>>> You're not running any proxies so there should be no passwords in the
>>> output, but check anyway before posting it on the web. What to look for
>>> here are successful socket operations to external DNS servers. All
>>> indications are there will be none, but it will help to see what is
>>> going on in your stack.
>> As I said before, I have two machines on the LAN, one (with dhcp)
>> appears to update fine, the other with static ip doesn't. All the manual
>> tests I try from the system that doesn't update seem to suggest it
>> should be fine. DNS appears to resolve. I've just enabled apache reverse
>> dns lookups for logging on the problem system, and a quick test suggests
>> they're working. Here are the last few lines of the freshclam log from
>> the good machine:
>>
>>
> We're pretty well into the "Something we're sure of is wrong" territory,
> so nothing can be overlooked. I see no attempt in your strace dump to
> create a TCPIP socket, nor any attempt to resolve
> current.cvd.clamav.net. What was the result of examining your host
> table? How many instances of freshclam are running at the present time?
> What do you suppose is responsible for this:
>
> write(1, "ERROR: /var/log/clamav/freshclam"..., 66ERROR:
> /var/log/clamav/freshclam.log is locked by another process) = 66
>
> What do you see if you run this command?
>
> lsof |grep clam
I suspect that's a consequence of running freshclam on the command line
while freshclam is also running as a daemon.
> I'm still wondering what would have prevented your seeing something like
> this DNS query in your strace dump.
>
> uname({sys="Linux", node="example.com", ...}) = 0
> socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 4
> connect(4, {sa_family=AF_INET, sin_port=htons(53),
> sin_addr=inet_addr("xx.xxx.xxx.xx")}, 16) = 0
> poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}])
> sendto(4, "\1\335\1\0\0\1\0\0\0\0\0\0\7current\3cvd\6clamav\3"..., 40,
> MSG_NOSIGNAL, NULL, 0) = 40
> poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
> recvfrom(4, "\1\335\201\200\0\1\0\1\0\5\0\7\7current\3cvd\6clamav\3"...,
> 512, 0, {sa_family=AF_INET, sin_port=htons(53),
> sin_addr=inet_addr("xx.xxx.xxx.xx")}, [16]) = 320
> close(4) = 0
I think I see these (I'm no expert on interpreting the output) in this
trace:
http://www.sined.co.uk/tmp/fcbiglog.txt
This has verbose and debug flags to freshclam as well as being made
using strace ... (I hope that was a valid command) and was carried out
while the freshclam daemon was halted:
uname({sys="Linux", node="server.lan", ...}) = 0
stat64("/var/log/clamav/freshclam.log", {st_mode=S_IFREG|0640,
st_size=251671, ...}) = 0
time(NULL) = 1372098561
write(3, "Mon Jun 24 19:29:21 2013 -> Quer"..., 60) = 60
write(1, "Querying current.cvd.clamav.net\n", 32Querying
current.cvd.clamav.net
) = 32
stat64("/etc/resolv.conf", {st_mode=S_IFREG|0777, st_size=69, ...}) = 0
open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = -1 EACCES (Permission denied)
socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 4
connect(4, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
gettimeofday({1372098561, 362090}, NULL) = 0
poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}])
send(4, "\375\325\1\0\0\1\0\0\0\0\0\0\7current\3cvd\6clamav\3"..., 40,
MSG_NOSIGNAL) = 40
poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLERR}])
close(4) = 0
stat64("/var/log/clamav/freshclam.log", {st_mode=S_IFREG|0640,
st_size=251731, ...}) = 0
time(NULL) = 1372098561
The bit in the middle occurs 8 times.
$ ls -l /etc/resolv.conf
lrwxrwxrwx 1 root root 24 Oct 9 2012 /etc/resolv.conf ->
/etc/network/nameservers
$ ls -l /etc/network/nameservers
-rwxrwxr-x 1 root root 75 Jun 24 19:54 /etc/network/nameservers
$ cat /etc/network/nameservers
nameserver 8.8.4.4
nameserver 8.8.8.8
nameserver 192.168.1.254
search lan
$
I'm guessing that the interesting data here is:
open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = -1 EACCES (Permission denied)
and
sin_addr=inet_addr("127.0.0.1")}, 16) = 0
which, at a guess, I'd say meant that freshclam had been unable to open
/etc/resolv.conf to get a list of nameservers, was using localhost as a
nameserver, and was getting nothing back from localhost?
$ host current.cvd.clamav.net localhost
;; connection timed out; no servers could be reached
$ host current.cvd.clamav.net 127.0.0.1
;; connection timed out; no servers could be reached
$
Tends to confirm the latter ....
So I installed dnsproxy, that didn't seem to help.
Then looking in syslog I saw a lot of:
Jun 25 15:55:34 server kernel: [883159.006897] type=1400
audit(1372172134.934:1143): apparmor="DENIED" operation="open"
parent=25929 profile="/usr/bin/freshclam"
name="/etc/network/nameservers" pid=25930 comm="freshclam"
requested_mask="r" denied_mask="r" fsuid=107 ouid=0
So the issue is that apparmor is blocking freshclam?
After adding:
/etc/resolv.conf r,
/etc/network/nameservers r,
in:
/etc/apparmor.d/local/usr.bin.freshclam
freshclam updated fine!
Why dnsproxy didn't fix it I have no idea, but I'll remove it as I don't
seem to need it anyway.
Rgds
Denis McMahon
_______________________________________________
Help us build a comprehensive ClamAV guide: visit http://wiki.clamav.net
http://www.clamav.net/support/ml
|
1
