Bug 737230 - [socket activation] http://localhost:631 returns "Bad Request"
Summary: [socket activation] http://localhost:631 returns "Bad Request"
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: cups
Version: 16
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Tim Waugh
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 743585 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-09-10 07:28 UTC by Joachim Frieben
Modified: 2011-10-19 04:42 UTC (History)
5 users (show)

Fixed In Version: cups-1.5.0-16.fc16
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-10-19 04:42:15 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
CUPS Bugs and Features 3955 0 None None None Never

Description Joachim Frieben 2011-09-10 07:28:29 UTC
Description of problem:
Because system-config-printer does not allow me currently to add a parallel printer, see bug  , I have tried to use the CUPS web interface for setting it up. However, the only thing displayed after entering the approrpiate URL http://localhost:631 is

  "Bad Request" .

Version-Release number of selected component (if applicable):
cups-1.5.0-6.fc16

How reproducible:
Always.

Steps to Reproduce:
1. Start system.
2. Check that CUPS is actually running.
3. Enter http://localhost:631.
  
Actual results:
Browser displays "Bad Request".

Expected results:
CUPS web interface allows to configure a new printer.

Additional info:
None.

Comment 1 Joachim Frieben 2011-09-10 07:31:53 UTC
The following entry is appended to /var/log/cups/error_log:
E [10/Sep/2011:09:29:37 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"

Comment 2 Tim Waugh 2011-09-15 15:31:08 UTC
That's odd, it works fine for me.

Does this still happen for you today? (And has the machine been rebooted since you reported the bug?)

That said, there do seem to be some oddities in the systemd socket activation support: running 'cupsctl --debug-logging', for instance, seems to kill the UNIX domain socket. :-(

Comment 3 Tim Waugh 2011-09-15 15:38:03 UTC
I've filed the other problems as bug #738709 and bug #738710.

Comment 4 Jiri Popelka 2011-09-27 14:34:14 UTC
I'm running cups-1.5.0-9.fc16 and see this problem every time.

I see 'Bad Request' when visiting http://localhost:631
and 'Forbidden' on http://127.0.0.1:631
but http://[::1]:631 works as expected.

From error_log
D systemd_checkin: Matched existing listener /var/run/cups/cups.sock with fd 3...
D systemd_checkin: Adding new listener [v1.::+3561226240] with fd 4...
E Unable to bind socket for address [v1.::1]:631 - Address already in use.
E Unable to bind socket for address 127.0.0.1:631 - Address already in use.
I Listening to /var/run/cups/cups.sock:631 on fd 3...
I Listening to [v1.::+3561226240]:631 on fd 4...

The work-around for me is to:
systemctl stop cups.service
systemctl stop cups.socket
systemctl start cups.service

Comment 5 Tim Waugh 2011-10-03 11:45:48 UTC
I think http://127.0.0.1:631/ is expected to say "Forbidden" nowadays unless ServerAlias is used.

The http://localhost:631/ address should work though -- and works for me with Fedora 16 and cups-1.5.0-10.fc16.  What does error_log say is the reason for the error?

Comment 6 Jiri Popelka 2011-10-03 12:51:49 UTC
The error_log snippet from comment #4 I see when restarting cups service.

When accessing http://localhost:631 I see 
E Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"

I'm also running cups-1.5.0-10.fc16 (with default cupsd.conf).

Comment 7 Tim Waugh 2011-10-04 12:55:08 UTC
Please try with cups-1.5.0-12.fc16.  I've included a fix which may well address this (addrlen is now initialised before calling getsockaddr()).

Comment 8 Jiri Popelka 2011-10-04 13:23:48 UTC
Hmm, seems fixed (however after couple rounds of stopping/starting of socket/service).
Great !

Comment 9 Joachim Backes 2011-10-05 06:34:37 UTC
No fix with cups-1.5.0-13.fc16.x86_64 (after yum update on Oct 05): getting "bad request on "localhost:631"

Comment 10 Joachim Backes 2011-10-05 07:31:16 UTC
(In reply to comment #9)
> No fix with cups-1.5.0-13.fc16.x86_64 (after yum update on Oct 05): getting
> "bad request on "localhost:631"

/var/log/cups/error_log
-----------------------

E [05/Oct/2011:08:28:34 +0200] Unable to bind socket for address [v1.::1]:631 - Address already in use.
E [05/Oct/2011:08:28:34 +0200] Unable to bind socket for address 127.0.0.1:631 - Address already in use.
E [05/Oct/2011:08:28:53 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"
E [05/Oct/2011:08:28:53 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"
E [05/Oct/2011:08:28:54 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"
E [05/Oct/2011:08:28:54 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"
E [05/Oct/2011:08:28:56 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"
E [05/Oct/2011:08:28:56 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"
E [05/Oct/2011:08:29:20 +0200] Request from "[v1.::127.0.0.1]" using invalid Host: field "localhost:631"

Comment 11 Tim Waugh 2011-10-05 08:43:13 UTC
Joachim: just to be sure, did you stop the cups.service and cups.socket services, before starting cups.socket and cups.service again? (Or reboot?)

Comment 12 Joachim Backes 2011-10-05 09:29:41 UTC
(In reply to comment #11)
> Joachim: just to be sure, did you stop the cups.service and cups.socket
> services, before starting cups.socket and cups.service again? (Or reboot?)

I rebooted several times! Always the same result.

rpm -q cups
cups-1.5.0-13.fc16.x86_64

Comment 13 Tim Waugh 2011-10-05 10:35:45 UTC
OK, I think I see what might be happening.  But: what does this say?:

python -c 'import socket;print socket.getaddrinfo("localhost", 631)'

Comment 14 Joachim Backes 2011-10-05 11:28:51 UTC
(In reply to comment #13)
> OK, I think I see what might be happening.  But: what does this say?:
> 
> python -c 'import socket;print socket.getaddrinfo("localhost", 631)'

python -c 'import socket;print socket.getaddrinfo("localhost", 631)'
[(2, 1, 6, '', ('127.0.0.1', 631)), (2, 2, 17, '', ('127.0.0.1', 631)), (2, 3, 0, '', ('127.0.0.1', 631))]

Comment 15 Tim Waugh 2011-10-05 11:59:16 UTC
OK.  So it's only resolving to IPv4 addresses.

What does "ip addr show dev lo" say?

Comment 16 Joachim Backes 2011-10-05 14:03:29 UTC
ip addr show dev lo

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN 
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever

Comment 17 Tim Waugh 2011-10-05 14:06:39 UTC
Thanks.  So there is an AF_INET6 loopback address for it.

What's in /etc/hosts?

Comment 18 Joachim Backes 2011-10-05 14:15:31 UTC
# hostname eule added to /etc/hosts by anaconda
127.0.0.1	eule	localhost.localdomain	localhost
::1	eule	localhost6.localdomain6	localhost6

192.168.100.1				router
131.246.137.16  			lindb
131.246.137.2   			lindc
131.246.119.65	   			linda
2001:638:208:ef44:0:ff:fe00:65 		linda6
131.246.113.225				head1	
131.246.137.121				aixd3
131.246.137.118				aixd4
131.246.113.242				smp1
#2002:5f59:ca04:0:219:66ff:fe38:46aa	eule6
192.168.100.112				kaba-pc

Comment 19 Tim Waugh 2011-10-05 17:42:27 UTC
*** Bug 743585 has been marked as a duplicate of this bug. ***

Comment 20 Fedora Update System 2011-10-05 17:53:55 UTC
cups-1.5.0-14.fc16 has been submitted as an update for Fedora 16.
https://admin.fedoraproject.org/updates/FEDORA-2011-13168

Comment 21 nucleo 2011-10-05 18:03:01 UTC
Almost everything works with cups-1.5.0-14.fc16 - http://localhost:631, http://localhost.localdomain:631, http://127.0.0.1:631, http://[::1]:631 but for http://localhost6:631 and http://localhost6.localdomain6:631 opened "Bad Request - CUPS v1.5.0".

Comment 22 Joachim Backes 2011-10-05 19:05:12 UTC
cups-1.5.0-14.fc16 works for me. Thank you!

Comment 23 Tim Waugh 2011-10-06 08:03:39 UTC
(In reply to comment #21)
> Almost everything works with cups-1.5.0-14.fc16 - http://localhost:631,
> http://localhost.localdomain:631, http://127.0.0.1:631, http://[::1]:631 but
> for http://localhost6:631 and http://localhost6.localdomain6:631 opened "Bad
> Request - CUPS v1.5.0".

That's the same as in Fedora 15 (cups 1.4.x) though.  If you want to use localhost6 or localhost6.localdomain6 that way, you can add ServerAlias lines to /etc/cups/cupsd.conf.  The default for Fedora is that "localhost" resolves to an IPv6 address (::1).

Comment 24 Fedora Update System 2011-10-06 21:21:17 UTC
Package cups-1.5.0-14.fc16:
* should fix your issue,
* was pushed to the Fedora 16 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing cups-1.5.0-14.fc16'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2011-13168
then log in and leave karma (feedback).

Comment 25 Fedora Update System 2011-10-08 23:34:04 UTC
Package cups-1.5.0-15.fc16:
* should fix your issue,
* was pushed to the Fedora 16 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing cups-1.5.0-15.fc16'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2011-13168
then log in and leave karma (feedback).

Comment 26 Tim Waugh 2011-10-10 15:29:03 UTC
The upstream approach is to use the IPV6_V6ONLY socket option, so we'll follow suit in the systemd support by using the BindIPv6Only keyword in the cups.socket unit file.

Comment 27 Fedora Update System 2011-10-12 16:48:41 UTC
Package cups-1.5.0-16.fc16:
* should fix your issue,
* was pushed to the Fedora 16 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing cups-1.5.0-16.fc16'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2011-13168
then log in and leave karma (feedback).

Comment 28 Fedora Update System 2011-10-19 04:42:15 UTC
cups-1.5.0-16.fc16 has been pushed to the Fedora 16 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.