Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 285252 - net-print/cups-1.4.1: REGRESSION: stopping the service takes too long
Summary: net-print/cups-1.4.1: REGRESSION: stopping the service takes too long
Status: RESOLVED FIXED
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: Current packages (show other bugs)
Hardware: All Linux
: High normal (vote)
Assignee: Printing Team
URL: http://cups.org/str.php?L3679
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-09-16 21:09 UTC by Martin Mokrejš
Modified: 2011-01-27 16:02 UTC (History)
3 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Martin Mokrejš 2009-09-16 21:09:56 UTC
# /etc/init.d/cupsd -d stop
+ _conf_d=/etc/init.d/../conf.d
+ _c=cupsd
+ '[' -n cupsd -a cupsd '!=' cupsd ']'
+ unset _c
+ '[' -e /etc/init.d/../conf.d/cupsd.default ']'
+ '[' -e /etc/init.d/../conf.d/cupsd ']'
+ unset _conf_d
+ '[' -e /etc/rc.conf ']'
+ . /etc/rc.conf
++ rc_parallel=NO
++ rc_interactive=YES
++ rc_depend_strict=YES
++ rc_logger=NO
++ unicode=YES
++ net_fs_list='afs cifs coda davfs fuse gfs ncpfs nfs nfs4 ocfs2 shfs smbfs'
++ rc_tty_number=12
+ '[' -n '' ']'
+ . /etc/init.d/cupsd
+ unset _d
+ unset _f
+ '[' -n stop ']'
+ for _cmd in describe start stop status '${extra_commands:-${opts}}' '${extra_started_commands}'
+ '[' describe = stop ']'
+ for _cmd in describe start stop status '${extra_commands:-${opts}}' '${extra_started_commands}'
+ '[' start = stop ']'
+ for _cmd in describe start stop status '${extra_commands:-${opts}}' '${extra_started_commands}'
+ '[' stop = stop ']'
++ command -v stop
+ '[' stop = stop ']'
+ yesno
+ '[' -z '' ']'
+ return 1
+ unset _cmd
++ command -v stop_pre
+ '[' '' = stop_pre ']'
+ stop
+ ebegin 'Stopping cupsd'
* Stopping cupsd...
+ start-stop-daemon --stop --quiet --exec /usr/sbin/cupsd

[looooooooong pause for several minutes]

+ eend 0                                                                                                                                                                                                                        [ ok ]
++ command -v stop_post
+ '[' '' = stop_post ']'
+ shift
+ continue 2
+ '[' -n '' ']'
#

This does not happen with net-print/cups-1.3.11 which I just upgraded away from.
Comment 1 Martin Mokrejš 2009-09-16 21:13:58 UTC
# emerge --info
Portage 2.1.6.13 (default/linux/x86/2008.0/desktop, gcc-4.4.1, glibc-2.10.1-r0, 2.6.30.6 i686)
=================================================================
System uname: Linux-2.6.30.6-i686-Mobile_Intel-R-_Pentium-R-_4_-_M_CPU_1.80GHz-with-gentoo-2.0.1
Timestamp of tree: Tue, 15 Sep 2009 18:45:02 +0000
distcc 3.1 i686-pc-linux-gnu [disabled]
app-shells/bash:     4.0_p33
dev-java/java-config: 1.3.7-r1, 2.1.9
dev-lang/python:     2.5.4-r3, 2.6.2-r1, 3.1.1
dev-python/pycrypto: 2.0.1-r8
dev-util/cmake:      2.6.4-r2
sys-apps/baselayout: 2.0.1
sys-apps/openrc:     0.4.3-r3
sys-apps/sandbox:    2.1
sys-devel/autoconf:  2.13, 2.63-r1
sys-devel/automake:  1.4_p6, 1.5, 1.6.3, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2, 1.10.2, 1.11
sys-devel/binutils:  2.19.1-r1
sys-devel/gcc-config: 1.4.1
sys-devel/libtool:   2.2.6a
virtual/os-headers:  2.6.30-r1
ACCEPT_KEYWORDS="x86 ~x86"
CBUILD="i686-pc-linux-gnu"
CFLAGS="-O2 -march=pentium4 -mmmx -msse -msse2 -pipe -fno-strict-aliasing -ggdb"
CHOST="i686-pc-linux-gnu"
CONFIG_PROTECT="/etc /var/bind /var/lib/hsqldb /var/qmail/alias /var/qmail/control /var/vpopmail/etc"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/ /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo /etc/texmf/language.dat.d /etc/texmf/langu
age.def.d /etc/texmf/updmap.d /etc/texmf/web2c /etc/udev/rules.d"
CXXFLAGS="-O2 -march=pentium4 -mmmx -msse -msse2 -pipe -fno-strict-aliasing -ggdb"
DISTDIR="/usr/portage/distfiles"
FEATURES="distlocks fixpackages metadata-transfer nostrip parallel-fetch protect-owned sandbox sfperms splitdebug strict unmerge-orphans userfetch"
GENTOO_MIRRORS="http://gentoo.mirror.web4u.cz"
LDFLAGS="-Wl,-O1"
LINGUAS="en cs cz"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY="/usr/local/portage/layman/science /usr/local/portage/layman/sunrise /usr/local/portage"
SYNC="rsync://rsync.europe.gentoo.org/gentoo-portage"
USE="7zip R X Xaw3d a52 aac aalib ace acl acpi alsa amr amrnb amrwb apache audacious audiofile bash-completion bcmath berkdb blas bluetooth boost branding bzip2 cairo cblas cddb cdparanoia cdr clamav cli colordiff compr
ess cpio cracklib crypt cscope css ctype cups curl curlwrappers cxx dbi dbus dga dia directfb djbfft dri dts dv dvb dvd dvdr dvdread eds emacs emboss emf enblend encode enscript exif expat faad fam fame fat fbcon ffmpeg
 fftw firefox flac flash foomaticdb fortran fpx ftp gcj gd gdbm ggi gif gimp gimpprint glibc-compat20 glibc-omitfp glut gmp gnuplot gnutls gpgme gphoto2 gpm graphviz gs gsl gsm gstreamer gtk gtkhtml hal hdf hdf5 hp2xx i
8x0 icc iconv icu id3 ieee1394 ifc imagemagick imlib inifile innodb isdnlog ithreads jack java javascript jbig jce jikes jpeg jpeg2k kdtree kerberos lame lapack laptop lcms leim libcaca libedit libnotify libwww live lzo
 lzw mad maildir matroska mhash mikmod mime ming mjpeg mmap mmx mng mod_python modperl modplug motif mozilla moznoirc mp2 mp3 mp4 mpeg mpi mpi_njtree mpich2 mplayer mudflap mule musepack mxdatetime mysql mysqli ncurses 
netcdf netpbm network nls nntp nptl nptlonly nsplugin ntfs numeric ogg opengl openmp openssl pam pango pcmcia pcntl pcre pdf perl plotutils plugin png pnm postproc postscript ppds pppd procmail pymol python qt3 qt3suppo
rt qt4 quicktime rar raw readline recode reflection reiserfs rpm samba sasl scanner scp seamonkey server session sftp sift slp smime sndfile soap sockets spell spl sqlite srt sse sse2 ssl startup-notification subtitles 
subversion svg svgz sysfs sysvipc t1lib tcl tcpd tetex theora threads thunar tidy tiff tk transcode truetype unicode urandom usb userlocales utils uuencode v4l v4l2 vcd vhook vim-syntax vim-with-x vorbis wifi win32codec
s wmf wxwindows x264 x86 xanim xcf xfs xft xinerama xinetd xml xorg xpm xsl xslt xulrunner xv xvid xvmc yv12 zip zlib" ALSA_CARDS="intel-8x0m" ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file
 hooks iec958 ioplug ladspa lfloat linear meter mmap_emul mulaw multi null plug rate route share shm softvol" APACHE2_MODULES="actions alias auth_basic auth_digest authn_anon authn_dbd authn_dbm authn_default authn_file
 authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache dbd deflate dir disk_cache env expires ext_filter file_cache filter headers ident imagemap include info log_config mem_cache mim
e mime_magic rewrite setenvif speling status unique_id userdir usertrack vhost_alias negotiation" ELIBC="glibc" INPUT_DEVICES="keyboard mouse evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 
lcdm001 mtxorb ncurses text" LINGUAS="en cs cz" USERLAND="GNU" VIDEO_CARDS="radeon vesa"
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, FFLAGS, INSTALL_MASK, LANG, LC_ALL, MAKEOPTS, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS
Comment 2 Martin Mokrejš 2009-09-23 16:50:29 UTC
I just found it creates hundreds of dead processes on shutdown:

root      2482     1  0 10:40 ?        00:00:19 /usr/sbin/cupsd -C /etc/cups/cupsd.conf
root      4073  4069  0 18:46 pts/2    00:00:00 /sbin/runscript /etc/init.d/cupsd stop
root      4074  4073  0 18:46 pts/2    00:00:00 /bin/sh /lib/rc/sh/runscript.sh /etc/init.d/cupsd stop
root      4081  4074 30 18:46 pts/2    00:00:39 start-stop-daemon --stop --quiet --exec /usr/sbin/cupsd
root      4088  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4089  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4090  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4098  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4099  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4104  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4105  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4106  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4107  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4108  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4109  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4110  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4111  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4112  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4113  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4114  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4115  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4116  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4117  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4118  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
root      4119  2482  0 18:46 ?        00:00:00 [cupsd] <defunct>
[cut]
Comment 3 Simeon Maryasin 2009-10-12 19:12:00 UTC
When loglevel set to Debug, CUPS writes the following lines to error_log many times during shutdown:

I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/bannertops (PID 29219)
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/pstops (PID 29220)   
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/pstoraster (PID 29221)         
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/rastertogutenprint.5.2 (PID 29222)
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started backend /usr/libexec/cups/backend/usb (PID 29223)  
D [12/Oct/2009:23:10:20 +0400] Discarding unused job-state-changed event...
D [12/Oct/2009:23:10:20 +0400] cupsdMarkDirty(----J-)
D [12/Oct/2009:23:10:20 +0400] Discarding unused printer-state-changed event...
D [12/Oct/2009:23:10:20 +0400] cupsdMarkDirty(----J-)
D [12/Oct/2009:23:10:20 +0400] Discarding unused printer-state-changed event...
D [12/Oct/2009:23:10:20 +0400] [Job 76] job-sheets=none,none
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[0]="Canon_S200_USB_1"
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[1]="76"
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[2]="anonymous" 
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[3]="Test Page"
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[4]="1"
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[5]="job-uuid=urn:uuid:e219cb90-e6a3-3860-4584-99a480957afd job-originating-host-name=localhost"
D [12/Oct/2009:23:10:20 +0400] [Job 76] argv[6]="/var/spool/cups/d00076-001"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[2]="CUPS_DOCROOT=/usr/share/cups/html"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[5]="CUPS_SERVERBIN=/usr/libexec/cups"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[8]="HOME=/var/spool/cups/tmp"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[9]="PATH=/usr/libexec/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[10]="SERVER_ADMIN=root@marsmain"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[11]="SOFTWARE=CUPS/1.4.1"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[13]="USER=root"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[15]="CUPS_ENCRYPTION=IfRequested"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[16]="IPP_PORT=631"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[17]="CHARSET=utf-8"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[18]="LANG=ru.UTF-8"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[19]="PPD=/etc/cups/ppd/Canon_S200_USB_1.ppd"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[20]="RIP_MAX_CACHE=8m"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[21]="CONTENT_TYPE=application/vnd.cups-banner"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[22]="DEVICE_URI=usb://Canon/S200"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[23]="PRINTER_INFO=Canon S200"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[24]="PRINTER_LOCATION=Local Printer"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[25]="PRINTER=Canon_S200_USB_1"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[26]="CUPS_FILETYPE=document"
D [12/Oct/2009:23:10:20 +0400] [Job 76] envp[27]="FINAL_CONTENT_TYPE=printer/Canon_S200_USB_1"
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/bannertops (PID 29224)
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/pstops (PID 29225)   
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/pstoraster (PID 29226)         
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started filter /usr/libexec/cups/filter/rastertogutenprint.5.2 (PID 29228)
I [12/Oct/2009:23:10:20 +0400] [Job 76] Started backend /usr/libexec/cups/backend/usb (PID 29229)
D [12/Oct/2009:23:10:20 +0400] Discarding unused job-state-changed event...
D [12/Oct/2009:23:10:20 +0400] cupsdMarkDirty(----J-)
Comment 4 Martin Mokrejš 2009-10-12 21:04:06 UTC
(In reply to comment #3)
> When loglevel set to Debug, CUPS writes the following lines to error_log many
> times during shutdown:

I had the impression that cupsd tries to pull out all remaining jobs in the queue, but am not not expert in cupsd nor do remember why I had the impression.
Comment 5 Johannes Rauh 2010-03-18 12:22:38 UTC
I also had this problem.  Then I found out that cups had still registered a job for a printer which was not there anymore.  Apparently, each time at shutdown, cups tried to contact this printer (which led to my whole machine not shutting down properly anymore...).

Anyway, removing the job via the cups administration page solved the issue for me.
Comment 6 Timo Gurr (RETIRED) gentoo-dev 2011-01-27 16:02:38 UTC
CHANGES IN CUPS V1.4.5:
- The scheduler would restart jobs while shutting down (STR #3679)

Closing as fixed, please reopen if it's still an issue for you with >=cups-1.4.5.