Bug 128302

Summary: CUPS not fuctioning after default install
Product: [Fedora] Fedora Reporter: RW <rw>
Component: cupsAssignee: Tim Waugh <twaugh>
Status: CLOSED CANTFIX QA Contact:
Severity: medium Docs Contact:
Priority: medium    
Version: 2CC: rw
Target Milestone: ---   
Target Release: ---   
Hardware: i686   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2006-04-24 20:19:10 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description RW 2004-07-21 15:33:51 UTC
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.6) Gecko/20040510

Description of problem:
After a default install of FC2 with CUPS running I have problems
launching OpenOffice and GNOME Print Manager. 

Looking at ps shows this command is hanging:
rw       26093  0.0  0.1  4084  868 ?        S    08:28   0:00 /bin/sh
-c LC_ALL=C lpstat -d | awk 'BEGIN { device = "" } /^system default/ {
device = $4 } END { print device }'

If I /etc/init.d/cups restart both applications work only one time,
then return to hanging. 

Version-Release number of selected component (if applicable):
cups-1.1.20-11.1

How reproducible:
Always

Steps to Reproduce:
1. Start Cups after default install
2. Attempt to launch Gnome Print Manager, or lpstat, or OpenOffice
3. Applications hang until cupsd restarted
    

Actual Results:  Application hangs

Expected Results:  Application does not hang

Additional info:

Comment 1 Tim Waugh 2004-07-21 15:38:15 UTC
Please attach the output of 'printconf-tui --Xexport', after making
sure to edit out any sensitive passwords it may contain.

I need to see the full ps axf output to see which process is causing
the problem -- the line you included is not enough (it's just the
shell, which will be waiting for child processes).

Comment 2 RW 2004-07-26 21:15:38 UTC
Sorry for the delay, I forgot to Cc myself.

earth% printconf-tui --Xexport
<?xml version="1.0"?>
<adm_context VERSION="0">
  <id NAME="local" SERIAL="1090451586">
    <null/>
    <null/>
    </id>
  <datatree>
    <printconf TYPE="LIST">
      <print_queues TYPE="LIST">
        <crayola ATOMIC="TRUE" TYPE="LIST">
          <alias_list ANONYMOUS="TRUE" TYPE="LIST">
            </alias_list>
          <lpoptions TYPE="LIST">
            <page-bottom TYPE="STRING" VALUE="86"/>
            <cpi TYPE="STRING" VALUE="12"/>
            <page-right TYPE="STRING" VALUE="57"/>
            <page-left TYPE="STRING" VALUE="57"/>
            <page-top TYPE="STRING" VALUE="72"/>
            <scaling TYPE="STRING" VALUE="100"/>
            <lpi TYPE="STRING" VALUE="7"/>
            <wrap TYPE="STRING" VALUE="true"/>
            </lpoptions>
          <queue_type TYPE="STRING" VALUE="JETDIRECT"/>
          <queue_data TYPE="LIST">
            <jetdirect_ip TYPE="STRING" VALUE="crayola.hq.tensilica.com"/>
            <jetdirect_port TYPE="STRING" VALUE="9100"/>
            </queue_data>
          <filter_data TYPE="LIST">
            <mf_type TYPE="STRING" VALUE="MFOMATIC"/>
            <flags TYPE="LIST">
              <assume_data_is_text TYPE="BOOL" VALUE="FALSE"/>
              <rerender_Postscript TYPE="BOOL" VALUE="FALSE"/>
              <convert_text_to_Postscript TYPE="BOOL" VALUE="TRUE"/>
              </flags>
            <printer_id TYPE="STRING" VALUE="HP-Color_LaserJet_8550GN"/>
            <gs_driver TYPE="STRING" VALUE="Postscript"/>
            <foomatic_defaults ANONYMOUS="TRUE" TYPE="LIST">
              </foomatic_defaults>
            </filter_data>
          <filter_type TYPE="STRING" VALUE="MAGICFILTER"/>
          </crayola>
        </print_queues>
      <sharing_globals TYPE="LIST">
        <browsing TYPE="BOOL" VALUE="TRUE"/>
        </sharing_globals>
      </printconf>
    </datatree>
  </adm_context>

earth% ps axf
  PID TTY      STAT   TIME COMMAND
    1 ?        S      0:01 init [5]
    2 ?        SWN    0:00 [ksoftirqd/0]
    3 ?        SW<    0:00 [events/0]
    4 ?        SW<    0:00  \_ [khelper]
    5 ?        SW<    0:00  \_ [kblockd/0]
   33 ?        SW     0:02  \_ [pdflush]
   34 ?        SW     0:00  \_ [pdflush]
   36 ?        SW<    0:00  \_ [aio/0]
    6 ?        SW     0:00 [khubd]
   31 ?        SW     0:00 [kapmd]
   35 ?        SW     0:00 [kswapd0]
  141 ?        SW     0:00 [kseriod]
  180 ?        SW     0:00 [kjournald]
 1047 ?        SW     0:00 [kjournald]
 1436 ?        S      0:00 syslogd -m 0
 1440 ?        S      0:00 klogd -x
 1461 ?        S      0:19 portmap
 1481 ?        S      0:00 rpc.statd
 1508 ?        S      0:00 rpc.idmapd
 1570 ?        S      0:00 /usr/sbin/apmd -p 10 -w 5 -W -P
/etc/sysconfig/apm-scripts/apmscript
 1587 ?        S      0:00 ypbind
 1665 ?        S      0:00 /usr/sbin/automount --timeout=60 /project
yp auto.project
 1703 ?        S      0:00 /usr/sbin/automount --timeout=60 /home yp
auto.home
 1744 ?        S      0:00 /usr/sbin/automount --timeout=60 /fac yp
auto.fac
 1785 ?        S      0:00 /usr/sbin/automount --timeout=60 /cad yp
auto.cad
 1800 ?        S      0:00 /usr/sbin/smartd
 2011 ?        S      0:00 /usr/sbin/sshd
 2026 ?        S      0:00 xinetd -stayalive -pidfile /var/run/xinetd.pid
 2527 ?        S      0:34  \_ fam
 2040 ?        SL     0:00 ntpd -U ntp -p /var/run/ntpd.pid
 2059 ?        S      0:00 sendmail: accepting connections
 2068 ?        S      0:00 sendmail: Queue runner@01:00:00 for
/var/spool/clientmqueue
 2079 ?        S      0:00 gpm -m /dev/input/mice -t imps2
 2090 ?        S      0:00 crond
 2112 ?        S      0:01 xfs -droppriv -daemon
 2131 ?        S      0:00 /usr/sbin/atd
 2150 ?        S      0:00 dbus-daemon-1 --system
 2166 ?        S      0:00 mdadm --monitor --scan
 2196 tty1     S      0:00 /sbin/mingetty tty1
 2202 tty2     S      0:00 /sbin/mingetty tty2
 2208 tty3     S      0:00 /sbin/mingetty tty3
 2214 tty4     S      0:00 /sbin/mingetty tty4
 2220 tty5     S      0:00 /sbin/mingetty tty5
 2226 tty6     S      0:00 /sbin/mingetty tty6
 2232 ?        S      0:00 /usr/bin/gdm-binary -nodaemon
 2415 ?        S      0:00  \_ /usr/bin/gdm-binary -nodaemon
 2426 ?        S     97:32      \_ /usr/X11R6/bin/X :0 -audit 0 -auth
/var/gdm/:0.Xauth -nolisten tcp vt7
 2463 ?        S      0:00      \_ -/bin/tcsh -c /usr/bin/ssh-agent
/etc/X11/xinit/Xclients
 2509 ?        S      0:03          \_ /usr/bin/gnome-session
 2510 ?        S      0:00              \_ /usr/bin/ssh-agent
/etc/X11/xinit/Xclients
 2461 ?        SW     0:07 [rpciod]
 2462 ?        SW     0:00 [lockd]
 2514 ?        S      0:07 /usr/libexec/gconfd-2 5
 2518 ?        S      0:00 /usr/bin/gnome-keyring-daemon
 2520 ?        S      0:00 /usr/libexec/bonobo-activation-server
--ac-activate --ior-output-fd=18
 2522 ?        S      0:04 /usr/libexec/gnome-settings-daemon
--oaf-activate-iid=OAFIID:GNOME_SettingsDaemon --oaf-ior-fd=23
 2581 ?        S      0:05 xscreensaver -nosplash
 2605 ?        S      1:27 /usr/bin/metacity --sm-client-id=default1
 2611 ?        S      0:14 gnome-panel --sm-client-id default2
 2613 ?        S      0:15 nautilus --no-default-window --sm-client-id
default3
 2615 ?        S      0:55 magicdev --sm-client-id default4
 2621 ?        S      0:00 /usr/libexec/gnome-vfs-daemon
--oaf-activate-iid=OAFIID:GNOME_VFS_Daemon_Factory --oaf-ior-fd=29
 2677 ?        S      0:00 /usr/libexec/mapping-daemon
 2808 ?        S      0:08 /usr/libexec/clock-applet
--oaf-activate-iid=OAFIID:GNOME_ClockApplet_Factory --oaf-ior-fd=31
 2810 ?        S      0:02 /usr/libexec/notification-area-applet
--oaf-activate-iid=OAFIID:GNOME_NotificationAreaApplet_Factory
--oaf-ior-fd 2812 ?        S      0:03 /usr/libexec/mixer_applet2
--oaf-activate-iid=OAFIID:GNOME_MixerApplet_Factory --oaf-ior-fd=35
 2820 ?        S      0:32 /usr/libexec/wnck-applet
--oaf-activate-iid=OAFIID:GNOME_Wncklet_Factory --oaf-ior-fd=37
 2962 ?        S      0:01 pam-panel-icon --sm-client-id default0
 2965 ?        S      0:00  \_ /sbin/pam_timestamp_check -d root
 2964 ?        RN     1:33 /usr/bin/python /usr/bin/rhn-applet-gui
--sm-client-id default5
 3224 ?        S      2:20 /usr/bin/gnome-terminal
 3226 ?        S      0:00  \_ gnome-pty-helper
13545 pts/13   S      0:00  \_ -csh
14268 pts/14   S      0:00  \_ -csh
18242 pts/14   R      0:00  |   \_ ps axf
14368 pts/15   S      0:00  \_ -csh
10137 ?        S     32:50 /usr/lib/mozilla-1.6/mozilla-bin -UILocale
en-US
13328 ?        S      0:00 /usr/libexec/evolution/1.4/evolution-wombat
--oaf-activate-iid=OAFIID:GNOME_Evolution_Wombat_InterfaceCheck
--oaf13330 ?        S      0:00
/usr/libexec/evolution/1.4/evolution-alarm-notify
--oaf-activate-iid=OAFIID:GNOME_Evolution_Calendar_AlarmNotify_17911 ?
       S      0:00 cupsd
18234 ?        S      0:00 /usr/bin/perl /usr/bin/tryprint.pl
18235 ?        S      0:00  \_ gnome-print-manager
18237 ?        S      0:00 /bin/sh -c LC_ALL=C lpstat -d | awk 'BEGIN
{ device = "" } /^system default/ { device = $4 } END { print device
}18238 ?        S      0:00  \_ lpstat -d
18239 ?        S      0:00  \_ awk BEGIN { device = "" } /^system
default/ { device = $4 } END { print device }
earth%


Comment 3 Tim Waugh 2004-07-27 11:30:47 UTC
So 'lpstat -d' is the process that's stuck, or else cupsd (which it is
talking to).  Is there anything useful in /var/log/cups/error_log?

Comment 4 RW 2004-07-27 15:18:10 UTC
Don't see anything unusual in cups error log. 

D [26/Jul/2004:14:39:06 -0700] LoadDevices: Added device
"serial:/dev/ttyS7?baud=115200"...
D [26/Jul/2004:14:39:07 -0700] LoadDevices: Added device
"parallel:/dev/lp0"...
D [26/Jul/2004:14:39:07 -0700] LoadDevices: Added device "socket"...
I [26/Jul/2004:14:39:07 -0700] LoadPPDs: Read "/etc/cups/ppds.dat", 13
PPDs...
I [26/Jul/2004:14:39:07 -0700] LoadPPDs: No new or changed PPDs...
D [26/Jul/2004:14:39:07 -0700] LoadAllJobs: Scanning /var/spool/cups...
I [26/Jul/2004:14:39:07 -0700] Full reload complete.
D [26/Jul/2004:14:39:07 -0700] StartListening: NumListeners=1
D [26/Jul/2004:14:39:07 -0700] StartListening: address=00000000 port=631
D [26/Jul/2004:14:39:07 -0700] ResumeListening: setting input bits...
d [26/Jul/2004:14:39:07 -0700] ResumeListening: Adding fd 0 to InputSet...
d [26/Jul/2004:14:39:07 -0700] StartBrowsing: Adding fd 2 to InputSet...
d [26/Jul/2004:14:39:07 -0700] StartServer: Adding fd 3 to InputSet...
d [26/Jul/2004:14:39:07 -0700] AddCert: adding certificate for pid 0

Cups access log doesn't show the connection attempt. An strace of
lpstat seems to show the commands sent but nothing received.

earth% strace lpstat -d

munmap(0x55219000, 4096)                = 0
send(3, "POST / HTTP/1.1\r\n", 17, 0)   = 17
send(3, "Content-Length: 135\r\n", 21, 0) = 21
send(3, "Content-Type: application/ipp\r\n", 31, 0) = 31
send(3, "Host: localhost.localdomain\r\n", 29, 0) = 29
send(3, "\r\n", 2, 0)                   = 2
time(NULL)                              = 1090941062
send(3, "\1\1@\2\0\0\0\1", 8, 0)        = 8
time(NULL)                              = 1090941062
send(3, "\1G\0\22attributes-charset\0\5utf-8", 29, 0) = 29
time(NULL)                              = 1090941062
send(3, "H\0\33attributes-natural-language\0\5"..., 37, 0) = 37
time(NULL)                              = 1090941062
send(3, "D\0\24requested-attributes\0\fprinter"..., 60, 0) = 60
time(NULL)                              = 1090941062
send(3, "\3", 1, 0)                     = 1
recv(3,  <unfinished ...>


Comment 5 Tim Waugh 2004-09-28 12:34:10 UTC
Could you change the 'LogLevel' line in /etc/cups/cupsd.conf so that
it says:

LogLevel debug2

Then restart cups and try again?  The error_log should have more
useful information in it then.

Comment 6 John Thacker 2006-04-24 20:19:10 UTC
Closing to lack of reporter response for a year and a half.