Re: could not create IO::Socket::IP socket on [127.0.0.1]:783: Address already in use

2014-11-26 Thread Thomas Schulz
> Thanks, that explains how we get to 'Address already in use'.
> 
> This opens up a couple of questions:
> 
> - creating a socket listening on '::' apparently does work
> (it is tested in the BEGIN phase, and reported by 'have PF_INET6'),
> but creating a socket listening on '::1' (i.e. a loopback address)
> fails. Are you running spamd in jail? Does a loopback interface
> have an IPv6 address assigned? Is it '::1'? Or if you think the
> IPv6 is not supported on that host, why then does creating a
> socket listening on '::' succeed?
> 
> - why did it work with older versions of perl and modules
> 
> - this chain of events shows that the logic in server_sock_setup_inet()
> and/or its caller is flawed. When multiple sockets are to be created
> and not all succeed, we'd need to undo the successfully created
> sockets before bailing out on error - or alternatively, make do
> with partially fulfilling the request.
> 
> Please open up a ticket on the bugzilla.
> 
>Mark

Bug 7106 has been created. For the benefit of those reading this thead,
here is a last bit of information.

The operating system (Solaris 10) supports IPV6 but there are no IPV6
interfaces defined. So binding to ::1 can not succeed.
Here is the debug output with the old Perl and old modules:

dbg: spamd: socket module of choice: IO::Socket::IP 0.27, Socket 2.013, have
PF_INET, no PF_INET6, using Socket::getaddrinfo, AI_ADDRCONFIG is suported
dbg: spamd: socket specification: "localhost", IP address: localhost, port: 783
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, port 783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: 127.0.0.1,
LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1

Tom Schulz
Applied Dynamics Intl.
sch...@adi.com


Re: could not create IO::Socket::IP socket on [127.0.0.1]:783: Address already in use

2014-11-24 Thread Mark Martinec

Tom Schulz wrote:

Here is my debug output. It looks like the socket is created for
127.0.0.1 and then an attempt is also made for ::1. That fails as
expected. But in my case that failure causes a retry that includes
retrying for 127.0.0.1. This now fails because the port has already
been created (as noted in the error message). Retries then continue
until the retry limit is reached.

dbg: spamd: socket module of choice: IO::Socket::IP 0.32, Socket 2.013,
have PF_INET, have PF_INET6, using Socket::getaddrinfo, AI_ADDRCONFIG 
is

supported
dbg: spamd: socket specification: "localhost", IP address: localhost,
port: 783
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr:
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: 
::1,

LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
server socket setup failed, retry 1: spamd: could not create
IO::Socket::IP socket on [::1]:783: Cannot assign requested address
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr:
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
server socket setup failed, retry 2: spamd: could not create
IO::Socket::IP socket on [127.0.0.1]:783: Address already in use
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr:
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
server socket setup failed, retry 3: spamd: could not create
IO::Socket::IP socket on [127.0.0.1]:783: Address already in use


Thanks, that explains how we get to 'Address already in use'.

This opens up a couple of questions:

- creating a socket listening on '::' apparently does work
(it is tested in the BEGIN phase, and reported by 'have PF_INET6'),
but creating a socket listening on '::1' (i.e. a loopback address)
fails. Are you running spamd in jail? Does a loopback interface
have an IPv6 address assigned? Is it '::1'? Or if you think the
IPv6 is not supported on that host, why then does creating a
socket listening on '::' succeed?

- why did it work with older versions of perl and modules

- this chain of events shows that the logic in server_sock_setup_inet()
and/or its caller is flawed. When multiple sockets are to be created
and not all succeed, we'd need to undo the successfully created
sockets before bailing out on error - or alternatively, make do
with partially fulfilling the request.

Please open up a ticket on the bugzilla.

  Mark


Re: could not create IO::Socket::IP socket on [127.0.0.1]:783: Address already in use

2014-11-21 Thread Thomas Schulz
> Tom Schulz wrote:
>> I am not sure if this is a bug or a usage problem.
>> 
>> I have been running spamd on Solaris 10 and Perl v5.8.9 for years, 
>> starting
>> it with the command:
>> spamd -d -c -m 18 --min-spare=1 --max-spare=4 --syslog-socket=inet
>> 
>> I upgraded Perl to v5.20.1 and installed the current modules. When I
>> try to start spamd with that command, I get the following errors:
>> 
>> setlogsock(): type='tcp': TCP service unavailable at
>> /opt/local/lib/perl5/site_perl/5.20.1/Mail/SpamAssassin/Logger/Syslog.pm
>> line 100.
> 
> This one is normal if your syslogd listens only on an UDP socket.
> 
> The setlogsock("inet") tries TCP first, and if that fails it tries UDP.
> When warnings are enabled (like in spamd), you see the TCP attempt
> failure as a warning, but then the UDP is used.
> 
> So if you know the syslogd only listens on UDP, you should
> specify this explicitly: --syslog-socket=udp
> 
> I don't know if this worked differently previously. Possibly the
> version of Sys::Syslog brought some changes in warnings issued.
> 
> 
>> server socket setup failed, retry 1: spamd: could not create
>> IO::Socket::IP socket on [::1]:783: Cannot assign requested address
>> server socket setup failed, retry 2: spamd: could not create
>> IO::Socket::IP socket on [127.0.0.1]:783: Address already in use
>> 
>> And spamd does not start. If I add '-4' to the above command [...]
>> And spamd does start and I do have logging.
> 
>> I conclude that the failed attempt to create an IPv6 socket blocks
>> the ability to later create IPv4 sockets to the same port.
> 
> Yes, so it seems.
> 
> Please start spamd without option '-d' (daemonize) and with '-D spamd',
> and note the logged order of socket bind attempts. Mine shows:
> 
> dbg: spamd: socket module of choice: IO::Socket::IP 0.32, Socket 2.015, 
> have PF_INET, have PF_INET6, using Socket::getaddrinfo, AI_ADDRCONFIG is 
> supported
> dbg: spamd: socket specification: "localhost", IP address: localhost, 
> port: 783
> dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port 
> 783
> dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: 
> 127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 1, V6Only: 1
> dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: ::1, 
> LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 1, V6Only: 1
> 
> Note the order: tries 127.0.0.1 first, only then the ::1.
> Note also the reported 'V6Only: 1' and a version of IO::Socket::IP
> (or maybe it's IO::Socket::INET6 in your case???).
> 
>> But note that with
>> Perl v5.8.9 and the module versions available in Dec 2013, there was no
>> problem without the '-4' switch. This sounds like it could be a bug
>> somewhere.
> 
> 
>> And why does setlogsock complain about type='tcp now when
>> it did not with the older Perl?
> 
> Probably unrelated to a version of perl, but has to do with
> a version of Sys::Syslog or a version of the 'warnings' pragma.
> 
>Mark

Here is my debug output. It looks like the socket is created for
127.0.0.1 and then an attempt is also made for ::1. That fails as
expected. But in my case that failure causes a retry that includes
retrying for 127.0.0.1. This now fails because the port has already
been created (as noted in the error message). Retries then continue
until the retry limit is reached.


dbg: spamd: socket module of choice: IO::Socket::IP 0.32, Socket 2.013,
have PF_INET, have PF_INET6, using Socket::getaddrinfo, AI_ADDRCONFIG is
supported
dbg: spamd: socket specification: "localhost", IP address: localhost,
port: 783
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr:
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: ::1,
LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
server socket setup failed, retry 1: spamd: could not create
IO::Socket::IP socket on [::1]:783: Cannot assign requested address
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr:
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
server socket setup failed, retry 2: spamd: could not create
IO::Socket::IP socket on [127.0.0.1]:783: Address already in use
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr:
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 2, V6Only: 1
server socket setup failed, retry 3: spamd: could not create
IO::Socket::IP socket on [127.0.0.1]:783: Address already in use

Tom Schulz
Applied Dynamics Intl.
sch...@adi.com


Re: could not create IO::Socket::IP socket on [127.0.0.1]:783: Address already in use

2014-11-20 Thread Mark Martinec

Tom Schulz wrote:

I am not sure if this is a bug or a usage problem.

I have been running spamd on Solaris 10 and Perl v5.8.9 for years, 
starting

it with the command:
spamd -d -c -m 18 --min-spare=1 --max-spare=4 --syslog-socket=inet

I upgraded Perl to v5.20.1 and installed the current modules. When I
try to start spamd with that command, I get the following errors:

setlogsock(): type='tcp': TCP service unavailable at
/opt/local/lib/perl5/site_perl/5.20.1/Mail/SpamAssassin/Logger/Syslog.pm
line 100.


This one is normal if your syslogd listens only on an UDP socket.

The setlogsock("inet") tries TCP first, and if that fails it tries UDP.
When warnings are enabled (like in spamd), you see the TCP attempt
failure as a warning, but then the UDP is used.

So if you know the syslogd only listens on UDP, you should
specify this explicitly: --syslog-socket=udp

I don't know if this worked differently previously. Possibly the
version of Sys::Syslog brought some changes in warnings issued.



server socket setup failed, retry 1: spamd: could not create
IO::Socket::IP socket on [::1]:783: Cannot assign requested address
server socket setup failed, retry 2: spamd: could not create
IO::Socket::IP socket on [127.0.0.1]:783: Address already in use

And spamd does not start. If I add '-4' to the above command [...]
And spamd does start and I do have logging.



I conclude that the failed attempt to create an IPv6 socket blocks
the ability to later create IPv4 sockets to the same port.


Yes, so it seems.

Please start spamd without option '-d' (daemonize) and with '-D spamd',
and note the logged order of socket bind attempts. Mine shows:

dbg: spamd: socket module of choice: IO::Socket::IP 0.32, Socket 2.015, 
have PF_INET, have PF_INET6, using Socket::getaddrinfo, AI_ADDRCONFIG is 
supported
dbg: spamd: socket specification: "localhost", IP address: localhost, 
port: 783
dbg: spamd: attempting to listen on IP addresses: 127.0.0.1, ::1, port 
783
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: 
127.0.0.1, LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 1, V6Only: 1
dbg: spamd: creating IO::Socket::IP socket: Listen: 128, LocalAddr: ::1, 
LocalPort: 783, Proto: tcp, ReuseAddr: 1, Type: 1, V6Only: 1


Note the order: tries 127.0.0.1 first, only then the ::1.
Note also the reported 'V6Only: 1' and a version of IO::Socket::IP
(or maybe it's IO::Socket::INET6 in your case???).


But note that with
Perl v5.8.9 and the module versions available in Dec 2013, there was no
problem without the '-4' switch. This sounds like it could be a bug
somewhere.




And why does setlogsock complain about type='tcp now when
it did not with the older Perl?


Probably unrelated to a version of perl, but has to do with
a version of Sys::Syslog or a version of the 'warnings' pragma.

  Mark