Created attachment 340224 [details] A custom bash cgi script Description of problem: For two years now we're running printer servers on RHEL 5,5.1,5.2 x86_64 (and before that on Fedora) - atop cups 1.2.4. We have a custom _bash_ cgi script (attached) that basically outputs something like: Location: /printers/ Set-Cookie: RASHUT=SUPPORT; path=/ (ex. in response to /rashut.cgi?RASHUT=SUPPORT) to set a cookie and redirect the client to the printers page. This works fine on the above mentioned platforms. We set up a test system running RHEL 5.3 - with cups 1.3.7 - and now this script fails in the following way: Every 2 out of 5 (40% of) request fails: 1. The client (IE 7/Win XP) stalls for 300 seconds 2. The log file - error_log - shows this: D [18/Apr/2009:01:50:05 +0300] cupsdAcceptClient: skipping getpeercon() D [18/Apr/2009:01:50:05 +0300] cupsdAcceptClient: 13 from 10.236.33.36:631 (IPv4) D [18/Apr/2009:01:50:05 +0300] cupsdReadClient: 13 GET /rashut.cgi?RASHUT=YVN HTTP/1.1 D [18/Apr/2009:01:50:05 +0300] cupsdAuthorize: No authentication data provided. D [18/Apr/2009:01:50:05 +0300] cupsdIsAuthorized: username="" D [18/Apr/2009:01:50:05 +0300] cupsdSendError: 13 code=401 (Unauthorized) D [18/Apr/2009:01:50:05 +0300] cupsdSendHeader: WWW-Authenticate: Basic realm="CUPS" D [18/Apr/2009:01:50:05 +0300] cupsdCloseClient: 13 D [18/Apr/2009:01:50:05 +0300] cupsdAcceptClient: skipping getpeercon() D [18/Apr/2009:01:50:05 +0300] cupsdAcceptClient: 13 from 10.236.33.36:631 (IPv4) D [18/Apr/2009:01:50:05 +0300] cupsdReadClient: 13 GET /rashut.cgi?RASHUT=YVN HTTP/1.1 D [18/Apr/2009:01:50:05 +0300] cupsdAuthorize: Authorized as 022419873 using Basic D [18/Apr/2009:01:50:05 +0300] cupsdIsAuthorized: username="022419873" D [18/Apr/2009:01:50:05 +0300] [CGI] /usr/share/doc/cups-1.3.7/he/rashut.cgi started - PID = 31846 I [18/Apr/2009:01:50:05 +0300] Started "/usr/share/doc/cups-1.3.7/he/rashut.cgi" (pid=31846) D [18/Apr/2009:01:50:05 +0300] cupsdSendCommand: 13 file=16 D [18/Apr/2009:01:50:06 +0300] PID 31846 (/usr/share/doc/cups-1.3.7/he/rashut.cgi) exited with no errors. ...[snip]... D [18/Apr/2009:01:55:07 +0300] Closing client 13 after 300 seconds of inactivity... D [18/Apr/2009:01:55:07 +0300] cupsdCloseClient: 13 3. At that point the client (IE 7/Win XP) continues and shows this in its logs: HTTP/1.0 200 This buggy server did not return headers HTTP/1.1 303 See Other Date: Sat, 18 Apr 2009 00:46:08 GMT Server: CUPS/1.2 Connection: Keep-Alive Keep-Alive: timeout=60 Content-Language: he_IL Content-Length: 0 Location: /printers/?QUERY=NAT 4. Notice that the `Set-Cookie' header was not received nor the `blank' line after the last header. I have found (after 3 hours of scratching and standing on my head) two workarounds. Detailed later under `Additional info'. Version-Release number of selected component (if applicable): RHEL 5.3, cups 1.3.7-8, bash 3.2-24, ksh 20080202-2, coreutils 5.97-19 How reproducible: Very. Steps to Reproduce: 1. Place rashut.cgi in /usr/share/cups/doc 2. Require authentication for the CUPS server. eg. in cupsd.conf Listen *:631 <Location /> AuthType Basic Require valid-user Satisfy any Order allow,deny Allow localhost </Location> 3. Configure cups to handle cgi scripts. In /etc/cups/cgi.types add: application/x-httpd-cgi cgi 4. Restart cups 5. From a client machine browse to: http://server.domain:631/rashut.cgi?RASHUT=SUPPORT Actual results: In 2 out of 5 requests the browser stalls for 300 seconds. Expected results: Always be promptly redirected to /printers and get the cookie RASHUT. Additional info: As mentioned I have found (after 3 hours of scratching and standing on my head) two workarounds: 1. make the rashut.cgi script a ksh script. eg. change #!/bin/bash to #!/bin/ksh or 2. add `|cat' to the `echo' command in rashut.cgi. eg.: echo -e "Location: /printers/${RASHUT:+?QUERY=$RASHUT} Set-Cookie: RASHUT=${COOKIE:-$RASHUT}; path=/ "|cat then all request are answered correctly.
I wonder if this might be related to a bug I've investigated recently. I reported it upstream here: http://www.cups.org/str.php?L3194 Does it look like it might be the cause?
Hello, I'm not sure. At least the output of strace gives different results for bash and ksh: # echo 'RASHUT=SUPPORT echo -e "Location: /printers/${RASHUT:+?QUERY=$RASHUT} Set-Cookie: RASHUT=${COOKIE:-$RASHUT}; path=/ " >~/a.a'|strace -ewrite -s80 bash write(1, "Location: /printers/?QUERY=SUPPORT\n", 35) = 35 write(1, "Set-Cookie: RASHUT=SUPPORT; path=/\n", 35) = 35 write(1, "\n", 1) = 1 # echo 'RASHUT=SUPPORT echo -e "Location: /printers/${RASHUT:+?QUERY=$RASHUT} Set-Cookie: RASHUT=${COOKIE:-$RASHUT}; path=/ " >~/a.a'|strace -ewrite -s80 ksh write(1, "Location: /printers/?QUERY=SUPPORT\nSet-Cookie: RASHUT=SUPPORT; path=/\n\n", 71) = 71
Are you able to try the patch (str3194.patch) from that CUPS bug report to see if it makes a difference? I see you've also reported STR #3221 -- is that related to this bug at all?
Hello, I'll give the patch for STR #3194 a try; It'll take me to the and of this week, though. As for STR #3221, it is unrelated.
Any news on testing STR #3194? Thanks & regards, Phil
wow ... terribly sorry. It's been more than a week :) I never got to checking this (the workarounds were acceptable). I'll try the patch and post on any news, not this week though. Thanks for the reminder. Opher.
Any news?
RHEL-5.10 (the next RHEL-5 minor release) is going to be the first production phase 2 [1] release of RHEL-5. Since phase 2 we'll be addressing only security and critical issues. I'm closing this ticket because it's neither security nor critical. [1] https://access.redhat.com/support/policy/updates/errata/