[cups] Having trouble with CUPS 2.0.x(3)

Jim Anderson jim_anderson at jjajava.com
Wed Jun 10 09:08:35 PDT 2015


Hi,

I was having trouble building and testing cups 2.0.1, so I have moved on 
to 2.0.3.
I have downloaded, configured and built cups 2.0.3, with no apparent 
errors during
the build process. I'm build on the waldorf version of Crunchbang linux, 
and 'uname -a'
yields:

    *Linux labine 3.2.0-4-amd64 #1 SMP Debian 3.2.63-2+deb7u1 x86_64
    GNU/Linux**
    *


When I run 'make check', I get error messages, but I don't know what 
they mean.
I will attach the log files I am looking, but last time I posted, the 
attachments got
filtered out. Is there a way to share files with the mailing list?

I'm also including some excerpts from two files, 'test.log', my own log 
file and
from /tmp/cups-jja/log/error_log which was created by 'make check'.

 From /tmp/cups-jja/log/error_log, where the first number shown is the 
line number:

    *132 E [10/Jun/2015:11:15:20.885659 -0400] Unable to open listen
    socket for address [v1.::1]:8631 - Address already in u    se.**
    **133 E [10/Jun/2015:11:15:20.885696 -0400] Unable to open listen
    socket for address 127.0.0.1:8631 - Address already in     use.**
    **...**
    **410 E [10/Jun/2015:11:29:28.729443 -0400] Job 2 not found on line
    8 of subscriptions.conf.**
    **...**
    **413 E [10/Jun/2015:11:29:28.729496 -0400] Job 55 not found on line
    28 of subscriptions.conf.**
    **...**
    **417 E [10/Jun/2015:11:29:28.729614 -0400] Unable to open listen
    socket for address [v1.::1]:8631 - Address already in u    se.**
    **418 E [10/Jun/2015:11:29:28.729649 -0400] Unable to open listen
    socket for address 127.0.0.1:8631 - Address already in     use.*

 From test.log:

    *155 Running IPP compliance tests...**
    **156 Performing 4.1-requests.test: PASS**
    **157 Performing 4.2-cups-printer-ops.test: FAIL**
    **158 Performing 4.3-job-ops.test: FAIL**
    **159 Performing 4.4-subscription-ops.test: FAIL**
    **160 Performing ipp-2.1.test: FAIL**
    **...**
    **177 FAIL: Printer 'Test2' produced 0 page(s), expected 23.**
    **178 FAIL: Printer 'Test3' produced 0 page(s), expected 2.**
    **179 FAIL: 0 requests logged, expected 165.**
    **...**
    **184 FAIL: 6 error messages, expected 33.**
    **185 E [10/Jun/2015:11:15:20.885659 -0400] Unable to open listen
    socket for address [v1.::1]:8631 - Address already in u    se.**
    **186 E [10/Jun/2015:11:15:20.885696 -0400] Unable to open listen
    socket for address 127.0.0.1:8631 - Address already in     use.**
    **187 E [10/Jun/2015:11:29:28.729443 -0400] Job 2 not found on line
    8 of subscriptions.conf.**
    **188 E [10/Jun/2015:11:29:28.729496 -0400] Job 55 not found on line
    28 of subscriptions.conf.**
    **189 E [10/Jun/2015:11:29:28.729614 -0400] Unable to open listen
    socket for address [v1.::1]:8631 - Address already in u    se.**
    **190 E [10/Jun/2015:11:29:28.729649 -0400] Unable to open listen
    socket for address 127.0.0.1:8631 - Address already in     use.*


It looks like there are problems. I'm reluctant to assume these error 
messages are errors in the test process as opposed to errors with the 
cups build.

Can help interpret these results?

Thanks in advance for any suggestions.

Jim A.


-------------- next part --------------
d [10/Jun/2015:11:15:20.882345 -0400] cupsdAddPolicyOp(p=0x2aefc8ae8cc0, po=(nil), op=0(0x0000))
d [10/Jun/2015:11:15:20.882419 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=4(Validate-Job))
d [10/Jun/2015:11:15:20.882435 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:15:20.882447 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=2(Print-Job))
d [10/Jun/2015:11:15:20.882457 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:15:20.882468 -0400] No limit for Validate-Job defined in policy default and no suitable template found.
d [10/Jun/2015:11:15:20.882480 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=38(Cancel-Jobs))
d [10/Jun/2015:11:15:20.882490 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:15:20.882501 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=10(Pause-Printer))
d [10/Jun/2015:11:15:20.882512 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:15:20.882523 -0400] No limit for Cancel-Jobs defined in policy default and no suitable template found.
d [10/Jun/2015:11:15:20.882533 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=39(Cancel-My-Jobs))
d [10/Jun/2015:11:15:20.882544 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:15:20.882555 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=6(Send-Document))
d [10/Jun/2015:11:15:20.882565 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:15:20.882576 -0400] No limit for Cancel-My-Jobs defined in policy default and no suitable template found.
d [10/Jun/2015:11:15:20.882587 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=3b(Close-Job))
d [10/Jun/2015:11:15:20.882597 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:15:20.882608 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=6(Send-Document))
d [10/Jun/2015:11:15:20.882618 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:15:20.882629 -0400] No limit for Close-Job defined in policy default and no suitable template found.
d [10/Jun/2015:11:15:20.882640 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=4027(CUPS-Get-Document))
d [10/Jun/2015:11:15:20.882650 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:15:20.882661 -0400] cupsdFindPolicyOp(p=0x2aefc8ae8cc0, op=6(Send-Document))
d [10/Jun/2015:11:15:20.882671 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:15:20.882682 -0400] No limit for CUPS-Get-Document defined in policy default and no suitable template found.
W [10/Jun/2015:11:15:20.882693 -0400] No JobPrivateAccess defined in policy default - using defaults.
W [10/Jun/2015:11:15:20.882705 -0400] No JobPrivateValues defined in policy default - using defaults.
W [10/Jun/2015:11:15:20.882717 -0400] No SubscriptionPrivateAccess defined in policy default - using defaults.
W [10/Jun/2015:11:15:20.882729 -0400] No SubscriptionPrivateValues defined in policy default - using defaults.
I [10/Jun/2015:11:15:20.882745 -0400] Remote access is disabled.
D [10/Jun/2015:11:15:20.882762 -0400] Added auto ServerAlias labine
I [10/Jun/2015:11:15:20.882897 -0400] Loaded configuration file "/tmp/cups-jja/cupsd.conf"
D [10/Jun/2015:11:15:20.882918 -0400] Repairing ownership of "/tmp/cups-jja/spool"
D [10/Jun/2015:11:15:20.882933 -0400] Repairing access permissions of "/tmp/cups-jja/spool"
D [10/Jun/2015:11:15:20.882952 -0400] Repairing ownership of "/tmp/cups-jja/share"
D [10/Jun/2015:11:15:20.882965 -0400] Repairing access permissions of "/tmp/cups-jja/share"
D [10/Jun/2015:11:15:20.882988 -0400] Creating missing directory "/tmp/cups-jja/share/rss"
D [10/Jun/2015:11:15:20.883053 -0400] Repairing ownership of "/tmp/cups-jja/share/rss"
D [10/Jun/2015:11:15:20.883068 -0400] Repairing access permissions of "/tmp/cups-jja/share/rss"
D [10/Jun/2015:11:15:20.883083 -0400] Repairing ownership of "/tmp/cups-jja"
D [10/Jun/2015:11:15:20.883097 -0400] Repairing ownership of "/tmp/cups-jja/certs"
D [10/Jun/2015:11:15:20.883110 -0400] Repairing access permissions of "/tmp/cups-jja/certs"
D [10/Jun/2015:11:15:20.883126 -0400] Repairing ownership of "/tmp/cups-jja"
D [10/Jun/2015:11:15:20.883141 -0400] Repairing ownership of "/tmp/cups-jja/ppd"
D [10/Jun/2015:11:15:20.883164 -0400] Repairing ownership of "/tmp/cups-jja/ssl"
D [10/Jun/2015:11:15:20.883176 -0400] Repairing access permissions of "/tmp/cups-jja/ssl"
D [10/Jun/2015:11:15:20.883194 -0400] Repairing ownership of "/tmp/cups-jja/cupsd.conf"
D [10/Jun/2015:11:15:20.883207 -0400] Repairing access permissions of "/tmp/cups-jja/cupsd.conf"
D [10/Jun/2015:11:15:20.883223 -0400] Repairing ownership of "/tmp/cups-jja/cups-files.conf"
D [10/Jun/2015:11:15:20.883236 -0400] Repairing access permissions of "/tmp/cups-jja/cups-files.conf"
D [10/Jun/2015:11:15:20.883270 -0400] Repairing ownership of "/tmp/cups-jja/spool/temp"
D [10/Jun/2015:11:15:20.883283 -0400] Repairing access permissions of "/tmp/cups-jja/spool/temp"
d [10/Jun/2015:11:15:20.883298 -0400] cupsdSetEnv: CUPS_CACHEDIR=/tmp/cups-jja/share
d [10/Jun/2015:11:15:20.883310 -0400] cupsdSetEnv: CUPS_DATADIR=/tmp/cups-jja/share
d [10/Jun/2015:11:15:20.883321 -0400] cupsdSetEnv: CUPS_DOCROOT=/usr/share/cups/doc
d [10/Jun/2015:11:15:20.883333 -0400] cupsdSetEnv: CUPS_FONTPATH=/tmp/cups-jja/share/fonts
d [10/Jun/2015:11:15:20.883345 -0400] cupsdSetEnv: CUPS_REQUESTROOT=/tmp/cups-jja/spool
d [10/Jun/2015:11:15:20.883356 -0400] cupsdSetEnv: CUPS_SERVERBIN=/tmp/cups-jja/bin
d [10/Jun/2015:11:15:20.883368 -0400] cupsdSetEnv: CUPS_SERVERROOT=/tmp/cups-jja
d [10/Jun/2015:11:15:20.883379 -0400] cupsdSetEnv: CUPS_STATEDIR=/tmp/cups-jja
d [10/Jun/2015:11:15:20.883392 -0400] cupsdSetEnv: DYLD_LIBRARY_PATH=/usr/share/cups/cups:/usr/share/cups/filter:/usr/share/cups/cgi-bin:/usr/share/cups/scheduler:/usr/share/cups/ppdc
d [10/Jun/2015:11:15:20.883404 -0400] cupsdSetEnv: HOME=/tmp/cups-jja/spool/temp
d [10/Jun/2015:11:15:20.883417 -0400] cupsdSetEnv: LD_LIBRARY_PATH=/usr/share/cups/cups:/usr/share/cups/filter:/usr/share/cups/cgi-bin:/usr/share/cups/scheduler:/usr/share/cups/ppdc
d [10/Jun/2015:11:15:20.883430 -0400] cupsdSetEnv: LD_PRELOAD=/usr/share/cups/cups/libcups.so.2:/usr/share/cups/filter/libcupsimage.so.2:/usr/share/cups/cgi-bin/libcupscgi.so.1:/usr/share/cups/scheduler/libcupsmime.so.1:/usr/share/cups/ppdc/libcupsppdc.so.1
d [10/Jun/2015:11:15:20.883445 -0400] cupsdSetEnv: PATH=/tmp/cups-jja/bin/filter:/usr/bin:/usr/sbin:/bin:/usr/bin
d [10/Jun/2015:11:15:20.883457 -0400] cupsdSetEnv: SERVER_ADMIN=root at labine
d [10/Jun/2015:11:15:20.883470 -0400] cupsdSetEnv: SHLIB_PATH=/usr/share/cups/cups:/usr/share/cups/filter:/usr/share/cups/cgi-bin:/usr/share/cups/scheduler:/usr/share/cups/ppdc
d [10/Jun/2015:11:15:20.883482 -0400] cupsdSetEnv: SOFTWARE=CUPS/2.0.3
d [10/Jun/2015:11:15:20.883494 -0400] cupsdSetEnv: TMPDIR=/tmp/cups-jja/spool/temp
d [10/Jun/2015:11:15:20.883507 -0400] cupsdSetEnv: USER=root
d [10/Jun/2015:11:15:20.883520 -0400] cupsdSetEnv: CUPS_MAX_MESSAGE=2047
I [10/Jun/2015:11:15:20.883531 -0400] Configured for up to 100 clients.
I [10/Jun/2015:11:15:20.883542 -0400] Allowing up to 100 client connections per host.
I [10/Jun/2015:11:15:20.883553 -0400] Using policy "default" as the default.
d [10/Jun/2015:11:15:20.883564 -0400] cupsdReadConfiguration: NumPolicies=1
d [10/Jun/2015:11:15:20.883575 -0400] cupsdReadConfiguration: Policies[0]="default"
I [10/Jun/2015:11:15:20.883585 -0400] Full reload is required.
I [10/Jun/2015:11:15:20.884258 -0400] Loaded MIME database from "/tmp/cups-jja/share/mime" and "/tmp/cups-jja": 35 types, 9 filters...
d [10/Jun/2015:11:15:20.884317 -0400] cupsdReadConfiguration: type application/octet-stream
d [10/Jun/2015:11:15:20.884329 -0400] cupsdReadConfiguration: type application/pdf
d [10/Jun/2015:11:15:20.884340 -0400] cupsdReadConfiguration: type application/postscript
d [10/Jun/2015:11:15:20.884350 -0400] cupsdReadConfiguration: type application/rss+xml
d [10/Jun/2015:11:15:20.884361 -0400] cupsdReadConfiguration: type application/vnd.cups-banner
d [10/Jun/2015:11:15:20.884371 -0400] cupsdReadConfiguration: type application/vnd.cups-command
d [10/Jun/2015:11:15:20.884382 -0400] cupsdReadConfiguration: type application/vnd.cups-pdf
d [10/Jun/2015:11:15:20.884392 -0400] cupsdReadConfiguration: type application/vnd.cups-postscript
d [10/Jun/2015:11:15:20.884412 -0400] cupsdReadConfiguration: type application/vnd.cups-ppd
d [10/Jun/2015:11:15:20.884424 -0400] cupsdReadConfiguration: type application/vnd.cups-raster
d [10/Jun/2015:11:15:20.884434 -0400] cupsdReadConfiguration: type application/vnd.cups-raw
d [10/Jun/2015:11:15:20.884444 -0400] cupsdReadConfiguration: type application/x-cshell
d [10/Jun/2015:11:15:20.884455 -0400] cupsdReadConfiguration: type application/x-csource
d [10/Jun/2015:11:15:20.884465 -0400] cupsdReadConfiguration: type application/x-perl
d [10/Jun/2015:11:15:20.884476 -0400] cupsdReadConfiguration: type application/x-shell
d [10/Jun/2015:11:15:20.884486 -0400] cupsdReadConfiguration: type image/gif
d [10/Jun/2015:11:15:20.884497 -0400] cupsdReadConfiguration: type image/jpeg
d [10/Jun/2015:11:15:20.884507 -0400] cupsdReadConfiguration: type image/png
d [10/Jun/2015:11:15:20.884517 -0400] cupsdReadConfiguration: type image/pwg-raster
d [10/Jun/2015:11:15:20.884528 -0400] cupsdReadConfiguration: type image/tiff
d [10/Jun/2015:11:15:20.884538 -0400] cupsdReadConfiguration: type image/x-alias
d [10/Jun/2015:11:15:20.884549 -0400] cupsdReadConfiguration: type image/x-bitmap
d [10/Jun/2015:11:15:20.884559 -0400] cupsdReadConfiguration: type image/x-icon
d [10/Jun/2015:11:15:20.884569 -0400] cupsdReadConfiguration: type image/x-photocd
d [10/Jun/2015:11:15:20.884580 -0400] cupsdReadConfiguration: type image/x-portable-anymap
d [10/Jun/2015:11:15:20.884590 -0400] cupsdReadConfiguration: type image/x-portable-bitmap
d [10/Jun/2015:11:15:20.884601 -0400] cupsdReadConfiguration: type image/x-portable-graymap
d [10/Jun/2015:11:15:20.884611 -0400] cupsdReadConfiguration: type image/x-portable-pixmap
d [10/Jun/2015:11:15:20.884622 -0400] cupsdReadConfiguration: type image/x-sgi-rgb
d [10/Jun/2015:11:15:20.884632 -0400] cupsdReadConfiguration: type image/x-sun-raster
d [10/Jun/2015:11:15:20.884642 -0400] cupsdReadConfiguration: type image/x-xbitmap
d [10/Jun/2015:11:15:20.884653 -0400] cupsdReadConfiguration: type image/x-xpixmap
d [10/Jun/2015:11:15:20.884663 -0400] cupsdReadConfiguration: type text/css
d [10/Jun/2015:11:15:20.884674 -0400] cupsdReadConfiguration: type text/html
d [10/Jun/2015:11:15:20.884684 -0400] cupsdReadConfiguration: type text/plain
d [10/Jun/2015:11:15:20.884697 -0400] cupsdReadConfiguration: filter application/octet-stream to application/vnd.cups-raw 0 -
d [10/Jun/2015:11:15:20.884709 -0400] cupsdReadConfiguration: filter application/pdf to application/postscript 100 pdftops
d [10/Jun/2015:11:15:20.884720 -0400] cupsdReadConfiguration: filter application/pdf to application/vnd.cups-pdf 100 pdftopdf
d [10/Jun/2015:11:15:20.884731 -0400] cupsdReadConfiguration: filter application/pdf to application/vnd.cups-raster 100 pdftoraster
d [10/Jun/2015:11:15:20.884742 -0400] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-postscript 66 pstops
d [10/Jun/2015:11:15:20.884753 -0400] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-raster 100 pstoraster
d [10/Jun/2015:11:15:20.884764 -0400] cupsdReadConfiguration: filter application/vnd.cups-raster to image/pwg-raster 100 rastertopwg
d [10/Jun/2015:11:15:20.884775 -0400] cupsdReadConfiguration: filter image/jpeg to application/pdf 100 imagetopdf
d [10/Jun/2015:11:15:20.884786 -0400] cupsdReadConfiguration: filter text/plain to application/pdf 100 texttopdf
D [10/Jun/2015:11:15:20.885352 -0400] Scanning /tmp/cups-jja/spool for jobs...
I [10/Jun/2015:11:15:20.885408 -0400] Full reload complete.
D [10/Jun/2015:11:15:20.885422 -0400] cupsdCleanFiles(path="/tmp/cups-jja/spool/temp", pattern="(null)")
I [10/Jun/2015:11:15:20.885437 -0400] Cleaning out old files in "/tmp/cups-jja/spool/temp".
D [10/Jun/2015:11:15:20.885456 -0400] cupsdCleanFiles(path="/tmp/cups-jja/share", pattern="*.ipp")
I [10/Jun/2015:11:15:20.885471 -0400] Cleaning out old files in "/tmp/cups-jja/share".
d [10/Jun/2015:11:15:20.885548 -0400] cupsdCreateProfile(job_id=0, allow_networking=1) = NULL
d [10/Jun/2015:11:15:20.885572 -0400] cupsdStartListening: 3 Listeners
E [10/Jun/2015:11:15:20.885659 -0400] Unable to open listen socket for address [v1.::1]:8631 - Address already in use.
E [10/Jun/2015:11:15:20.885696 -0400] Unable to open listen socket for address 127.0.0.1:8631 - Address already in use.
I [10/Jun/2015:11:15:20.885762 -0400] Listening to /tmp/cups-jja/sock on fd 7...
d [10/Jun/2015:11:15:20.885783 -0400] cupsdSetEnv: CUPS_SERVER=/tmp/cups-jja/sock
d [10/Jun/2015:11:15:20.885796 -0400] cupsdSetEnv: CUPS_ENCRYPTION=IfRequested
I [10/Jun/2015:11:15:20.885806 -0400] Resuming new connection processing...
d [10/Jun/2015:11:15:20.885817 -0400] cupsdResumeListening: Setting input bits...
d [10/Jun/2015:11:15:20.885829 -0400] cupsdAddSelect(fd=-1, read_cb=0x2aefc6c435e7, write_cb=(nil), data=0x2aefc8ae8a10)
d [10/Jun/2015:11:15:20.885841 -0400] cupsdAddSelect(fd=-1, read_cb=0x2aefc6c435e7, write_cb=(nil), data=0x2aefc8ae8bb0)
d [10/Jun/2015:11:15:20.885852 -0400] cupsdAddSelect(fd=7, read_cb=0x2aefc6c435e7, write_cb=(nil), data=0x2aefc8ae8820)
d [10/Jun/2015:11:15:20.885888 -0400] cupsdAddSelect(fd=8, read_cb=0x2aefc6c47150, write_cb=(nil), data=(nil))
D [10/Jun/2015:11:15:20.885906 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
d [10/Jun/2015:11:15:20.886446 -0400] cupsdAddEvent(event=server-started, dest=(nil)(), job=(nil)(0), text="Scheduler started in foreground.", ...)
D [10/Jun/2015:11:15:20.886459 -0400] Discarding unused server-started event...
d [10/Jun/2015:11:15:20.886476 -0400] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1433949320
d [10/Jun/2015:11:15:20.886488 -0400] select_timeout: JobHistoryUpdate=0
D [10/Jun/2015:11:15:21.886597 -0400] Report: clients=0
D [10/Jun/2015:11:15:21.886711 -0400] Report: jobs=0
D [10/Jun/2015:11:15:21.886732 -0400] Report: jobs-active=0
D [10/Jun/2015:11:15:21.886753 -0400] Report: printers=0
D [10/Jun/2015:11:15:21.886801 -0400] Report: stringpool-string-count=92
D [10/Jun/2015:11:15:21.886822 -0400] Report: stringpool-alloc-bytes=2896
D [10/Jun/2015:11:15:21.886842 -0400] Report: stringpool-total-bytes=2176
d [10/Jun/2015:11:15:21.886862 -0400] select_timeout: JobHistoryUpdate=0
d [10/Jun/2015:11:15:21.886883 -0400] select_timeout(0): 86400 seconds to do nothing
d [10/Jun/2015:11:29:28.643900 -0400] cupsdCloseAllClients() Clients=0
d [10/Jun/2015:11:29:28.644074 -0400] cupsdStopListening: closing all listen sockets.
d [10/Jun/2015:11:29:28.644101 -0400] cupsdPauseListening: Clearing input bits...
d [10/Jun/2015:11:29:28.644125 -0400] cupsdRemoveSelect(fd=-1)
d [10/Jun/2015:11:29:28.644148 -0400] cupsdRemoveSelect(fd=-1)
d [10/Jun/2015:11:29:28.644171 -0400] cupsdRemoveSelect(fd=7)
d [10/Jun/2015:11:29:28.644430 -0400] cupsdRemoveSelect(fd=8)
d [10/Jun/2015:11:29:28.644600 -0400] cupsdDeleteProfile(profile="(null)")
d [10/Jun/2015:11:29:28.647210 -0400] cupsdAddPolicyOp(p=0x2aefc8ae6bd0, po=(nil), op=0(0x0000))
d [10/Jun/2015:11:29:28.647386 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=4(Validate-Job))
d [10/Jun/2015:11:29:28.647438 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:29:28.647487 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=2(Print-Job))
d [10/Jun/2015:11:29:28.647511 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:29:28.647557 -0400] No limit for Validate-Job defined in policy default and no suitable template found.
d [10/Jun/2015:11:29:28.647601 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=38(Cancel-Jobs))
d [10/Jun/2015:11:29:28.647628 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:29:28.647674 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=10(Pause-Printer))
d [10/Jun/2015:11:29:28.647698 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:29:28.647744 -0400] No limit for Cancel-Jobs defined in policy default and no suitable template found.
d [10/Jun/2015:11:29:28.647769 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=39(Cancel-My-Jobs))
d [10/Jun/2015:11:29:28.647814 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:29:28.647857 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=6(Send-Document))
d [10/Jun/2015:11:29:28.647943 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:29:28.647968 -0400] No limit for Cancel-My-Jobs defined in policy default and no suitable template found.
d [10/Jun/2015:11:29:28.648015 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=3b(Close-Job))
d [10/Jun/2015:11:29:28.648055 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:29:28.648081 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=6(Send-Document))
d [10/Jun/2015:11:29:28.648122 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:29:28.648147 -0400] No limit for Close-Job defined in policy default and no suitable template found.
d [10/Jun/2015:11:29:28.648190 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=4027(CUPS-Get-Document))
d [10/Jun/2015:11:29:28.648213 -0400] cupsdFindPolicyOp: Found wildcard match...
d [10/Jun/2015:11:29:28.648257 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=6(Send-Document))
d [10/Jun/2015:11:29:28.648280 -0400] cupsdFindPolicyOp: Found wildcard match...
W [10/Jun/2015:11:29:28.648323 -0400] No limit for CUPS-Get-Document defined in policy default and no suitable template found.
W [10/Jun/2015:11:29:28.648346 -0400] No JobPrivateAccess defined in policy default - using defaults.
W [10/Jun/2015:11:29:28.648393 -0400] No JobPrivateValues defined in policy default - using defaults.
W [10/Jun/2015:11:29:28.648418 -0400] No SubscriptionPrivateAccess defined in policy default - using defaults.
W [10/Jun/2015:11:29:28.648467 -0400] No SubscriptionPrivateValues defined in policy default - using defaults.
I [10/Jun/2015:11:29:28.648529 -0400] Remote access is disabled.
D [10/Jun/2015:11:29:28.648583 -0400] Added auto ServerAlias labine
I [10/Jun/2015:11:29:28.648993 -0400] Loaded configuration file "/tmp/cups-jja/cupsd.conf"
D [10/Jun/2015:11:29:28.649051 -0400] Repairing ownership of "/tmp/cups-jja/spool"
D [10/Jun/2015:11:29:28.649246 -0400] Repairing ownership of "/tmp/cups-jja/share"
D [10/Jun/2015:11:29:28.649431 -0400] Repairing ownership of "/tmp/cups-jja/share/rss"
D [10/Jun/2015:11:29:28.649708 -0400] Repairing ownership of "/tmp/cups-jja"
D [10/Jun/2015:11:29:28.649923 -0400] Repairing ownership of "/tmp/cups-jja/certs"
D [10/Jun/2015:11:29:28.650106 -0400] Repairing ownership of "/tmp/cups-jja"
D [10/Jun/2015:11:29:28.650984 -0400] Repairing ownership of "/tmp/cups-jja/ppd"
D [10/Jun/2015:11:29:28.651385 -0400] Repairing ownership of "/tmp/cups-jja/ssl"
D [10/Jun/2015:11:29:28.651516 -0400] Repairing ownership of "/tmp/cups-jja/cupsd.conf"
D [10/Jun/2015:11:29:28.651854 -0400] Repairing ownership of "/tmp/cups-jja/cups-files.conf"
D [10/Jun/2015:11:29:28.651895 -0400] Repairing ownership of "/tmp/cups-jja/classes.conf"
D [10/Jun/2015:11:29:28.652094 -0400] Repairing access permissions of "/tmp/cups-jja/classes.conf"
D [10/Jun/2015:11:29:28.652300 -0400] Repairing ownership of "/tmp/cups-jja/printers.conf"
D [10/Jun/2015:11:29:28.652657 -0400] Repairing ownership of "/tmp/cups-jja/spool/temp"
d [10/Jun/2015:11:29:28.652851 -0400] cupsdSetEnv: CUPS_CACHEDIR=/tmp/cups-jja/share
d [10/Jun/2015:11:29:28.653034 -0400] cupsdSetEnv: CUPS_DATADIR=/tmp/cups-jja/share
d [10/Jun/2015:11:29:28.653260 -0400] cupsdSetEnv: CUPS_DOCROOT=/usr/share/cups/doc
d [10/Jun/2015:11:29:28.653591 -0400] cupsdSetEnv: CUPS_FONTPATH=/tmp/cups-jja/share/fonts
d [10/Jun/2015:11:29:28.653627 -0400] cupsdSetEnv: CUPS_REQUESTROOT=/tmp/cups-jja/spool
d [10/Jun/2015:11:29:28.653807 -0400] cupsdSetEnv: CUPS_SERVERBIN=/tmp/cups-jja/bin
d [10/Jun/2015:11:29:28.654400 -0400] cupsdSetEnv: CUPS_SERVERROOT=/tmp/cups-jja
d [10/Jun/2015:11:29:28.654588 -0400] cupsdSetEnv: CUPS_STATEDIR=/tmp/cups-jja
d [10/Jun/2015:11:29:28.654806 -0400] cupsdSetEnv: DYLD_LIBRARY_PATH=/usr/share/cups/cups:/usr/share/cups/filter:/usr/share/cups/cgi-bin:/usr/share/cups/scheduler:/usr/share/cups/ppdc
d [10/Jun/2015:11:29:28.654983 -0400] cupsdSetEnv: HOME=/tmp/cups-jja/spool/temp
d [10/Jun/2015:11:29:28.655014 -0400] cupsdSetEnv: LD_LIBRARY_PATH=/usr/share/cups/cups:/usr/share/cups/filter:/usr/share/cups/cgi-bin:/usr/share/cups/scheduler:/usr/share/cups/ppdc
d [10/Jun/2015:11:29:28.655371 -0400] cupsdSetEnv: LD_PRELOAD=/usr/share/cups/cups/libcups.so.2:/usr/share/cups/filter/libcupsimage.so.2:/usr/share/cups/cgi-bin/libcupscgi.so.1:/usr/share/cups/scheduler/libcupsmime.so.1:/usr/share/cups/ppdc/libcupsppdc.so.1
d [10/Jun/2015:11:29:28.655550 -0400] cupsdSetEnv: PATH=/tmp/cups-jja/bin/filter:/usr/bin:/usr/sbin:/bin:/usr/bin
d [10/Jun/2015:11:29:28.655580 -0400] cupsdSetEnv: SERVER_ADMIN=root at labine
d [10/Jun/2015:11:29:28.655762 -0400] cupsdSetEnv: SHLIB_PATH=/usr/share/cups/cups:/usr/share/cups/filter:/usr/share/cups/cgi-bin:/usr/share/cups/scheduler:/usr/share/cups/ppdc
d [10/Jun/2015:11:29:28.655938 -0400] cupsdSetEnv: SOFTWARE=CUPS/2.0.3
d [10/Jun/2015:11:29:28.655966 -0400] cupsdSetEnv: TMPDIR=/tmp/cups-jja/spool/temp
d [10/Jun/2015:11:29:28.656143 -0400] cupsdSetEnv: USER=root
d [10/Jun/2015:11:29:28.656322 -0400] cupsdSetEnv: CUPS_MAX_MESSAGE=2047
I [10/Jun/2015:11:29:28.656494 -0400] Configured for up to 100 clients.
I [10/Jun/2015:11:29:28.656522 -0400] Allowing up to 100 client connections per host.
I [10/Jun/2015:11:29:28.656701 -0400] Using policy "default" as the default.
d [10/Jun/2015:11:29:28.656725 -0400] cupsdReadConfiguration: NumPolicies=1
d [10/Jun/2015:11:29:28.656903 -0400] cupsdReadConfiguration: Policies[0]="default"
I [10/Jun/2015:11:29:28.657329 -0400] Full reload is required.
I [10/Jun/2015:11:29:28.658327 -0400] Saving job.cache...
I [10/Jun/2015:11:29:28.677628 -0400] Loaded MIME database from "/tmp/cups-jja/share/mime" and "/tmp/cups-jja": 35 types, 9 filters...
d [10/Jun/2015:11:29:28.677742 -0400] cupsdReadConfiguration: type application/octet-stream
d [10/Jun/2015:11:29:28.677754 -0400] cupsdReadConfiguration: type application/pdf
d [10/Jun/2015:11:29:28.677765 -0400] cupsdReadConfiguration: type application/postscript
d [10/Jun/2015:11:29:28.677775 -0400] cupsdReadConfiguration: type application/rss+xml
d [10/Jun/2015:11:29:28.677786 -0400] cupsdReadConfiguration: type application/vnd.cups-banner
d [10/Jun/2015:11:29:28.677796 -0400] cupsdReadConfiguration: type application/vnd.cups-command
d [10/Jun/2015:11:29:28.677807 -0400] cupsdReadConfiguration: type application/vnd.cups-pdf
d [10/Jun/2015:11:29:28.677817 -0400] cupsdReadConfiguration: type application/vnd.cups-postscript
d [10/Jun/2015:11:29:28.677828 -0400] cupsdReadConfiguration: type application/vnd.cups-ppd
d [10/Jun/2015:11:29:28.677838 -0400] cupsdReadConfiguration: type application/vnd.cups-raster
d [10/Jun/2015:11:29:28.677849 -0400] cupsdReadConfiguration: type application/vnd.cups-raw
d [10/Jun/2015:11:29:28.677859 -0400] cupsdReadConfiguration: type application/x-cshell
d [10/Jun/2015:11:29:28.677870 -0400] cupsdReadConfiguration: type application/x-csource
d [10/Jun/2015:11:29:28.677880 -0400] cupsdReadConfiguration: type application/x-perl
d [10/Jun/2015:11:29:28.677891 -0400] cupsdReadConfiguration: type application/x-shell
d [10/Jun/2015:11:29:28.677901 -0400] cupsdReadConfiguration: type image/gif
d [10/Jun/2015:11:29:28.677912 -0400] cupsdReadConfiguration: type image/jpeg
d [10/Jun/2015:11:29:28.677922 -0400] cupsdReadConfiguration: type image/png
d [10/Jun/2015:11:29:28.677933 -0400] cupsdReadConfiguration: type image/pwg-raster
d [10/Jun/2015:11:29:28.677943 -0400] cupsdReadConfiguration: type image/tiff
d [10/Jun/2015:11:29:28.677957 -0400] cupsdReadConfiguration: type image/x-alias
d [10/Jun/2015:11:29:28.677968 -0400] cupsdReadConfiguration: type image/x-bitmap
d [10/Jun/2015:11:29:28.677978 -0400] cupsdReadConfiguration: type image/x-icon
d [10/Jun/2015:11:29:28.677989 -0400] cupsdReadConfiguration: type image/x-photocd
d [10/Jun/2015:11:29:28.677999 -0400] cupsdReadConfiguration: type image/x-portable-anymap
d [10/Jun/2015:11:29:28.678009 -0400] cupsdReadConfiguration: type image/x-portable-bitmap
d [10/Jun/2015:11:29:28.678020 -0400] cupsdReadConfiguration: type image/x-portable-graymap
d [10/Jun/2015:11:29:28.678030 -0400] cupsdReadConfiguration: type image/x-portable-pixmap
d [10/Jun/2015:11:29:28.678057 -0400] cupsdReadConfiguration: type image/x-sgi-rgb
d [10/Jun/2015:11:29:28.678068 -0400] cupsdReadConfiguration: type image/x-sun-raster
d [10/Jun/2015:11:29:28.678078 -0400] cupsdReadConfiguration: type image/x-xbitmap
d [10/Jun/2015:11:29:28.678089 -0400] cupsdReadConfiguration: type image/x-xpixmap
d [10/Jun/2015:11:29:28.678099 -0400] cupsdReadConfiguration: type text/css
d [10/Jun/2015:11:29:28.678110 -0400] cupsdReadConfiguration: type text/html
d [10/Jun/2015:11:29:28.678120 -0400] cupsdReadConfiguration: type text/plain
d [10/Jun/2015:11:29:28.678131 -0400] cupsdReadConfiguration: filter application/octet-stream to application/vnd.cups-raw 0 -
d [10/Jun/2015:11:29:28.678143 -0400] cupsdReadConfiguration: filter application/pdf to application/postscript 100 pdftops
d [10/Jun/2015:11:29:28.678154 -0400] cupsdReadConfiguration: filter application/pdf to application/vnd.cups-pdf 100 pdftopdf
d [10/Jun/2015:11:29:28.678165 -0400] cupsdReadConfiguration: filter application/pdf to application/vnd.cups-raster 100 pdftoraster
d [10/Jun/2015:11:29:28.678176 -0400] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-postscript 66 pstops
d [10/Jun/2015:11:29:28.678187 -0400] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-raster 100 pstoraster
d [10/Jun/2015:11:29:28.678198 -0400] cupsdReadConfiguration: filter application/vnd.cups-raster to image/pwg-raster 100 rastertopwg
d [10/Jun/2015:11:29:28.678209 -0400] cupsdReadConfiguration: filter image/jpeg to application/pdf 100 imagetopdf
d [10/Jun/2015:11:29:28.678221 -0400] cupsdReadConfiguration: filter text/plain to application/pdf 100 texttopdf
D [10/Jun/2015:11:29:28.687543 -0400] Loading printer Test1...
d [10/Jun/2015:11:29:28.687608 -0400] cupsdAddPrinter("Test1")
d [10/Jun/2015:11:29:28.687680 -0400] cupsdAddPrinter: Adding Test1 to Printers
d [10/Jun/2015:11:29:28.687718 -0400] cupsdSetPrinterReasons(p=0x2aefc8af9ac0(Test1),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
d [10/Jun/2015:11:29:28.687733 -0400] cupsdFindBest: uri = "/printers/Test1", limit=10...
d [10/Jun/2015:11:29:28.687744 -0400] cupsdFindBest: best = NONE
d [10/Jun/2015:11:29:28.687757 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=2(Print-Job))
d [10/Jun/2015:11:29:28.687768 -0400] cupsdFindPolicyOp: Found wildcard match...
D [10/Jun/2015:11:29:28.687827 -0400] load_ppd: Loading /tmp/cups-jja/share/Test1.data...
d [10/Jun/2015:11:29:28.695882 -0400] cupsdSetPrinterReasons(p=0x2aefc8af9ac0(Test1),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [10/Jun/2015:11:29:28.695954 -0400] add_printer_filter(p=0x2aefc8af9ac0(Test1), filtertype=0x2aefc8af1d20(printer/Test1), filter="application/vnd.cups-raw application/octet-stream 0 -")
d [10/Jun/2015:11:29:28.696004 -0400] add_printer_filter: Test1: adding filter application/vnd.cups-raw printer/Test1/application/octet-stream 0 -
d [10/Jun/2015:11:29:28.696023 -0400] add_printer_filter: Test1: adding filter printer/Test1/application/octet-stream printer/Test1 0 -
d [10/Jun/2015:11:29:28.696040 -0400] add_printer_filter(p=0x2aefc8af9ac0(Test1), filtertype=0x2aefc8af1d20(printer/Test1), filter="application/vnd.cups-postscript 0 -")
d [10/Jun/2015:11:29:28.696056 -0400] add_printer_filter: Test1: adding filter application/vnd.cups-postscript printer/Test1 0 -
d [10/Jun/2015:11:29:28.696072 -0400] add_printer_filter(p=0x2aefc8af9ac0(Test1), filtertype=0x2aefc8af1d20(printer/Test1), filter="application/vnd.cups-command application/postscript 100 commandtops")
d [10/Jun/2015:11:29:28.696138 -0400] Test1: File "/tmp/cups-jja/bin/filter/commandtops" permissions OK (0100777/uid=1000/gid=0).
d [10/Jun/2015:11:29:28.696152 -0400] add_printer_filter: Test1: adding filter application/vnd.cups-command printer/Test1/application/postscript 100 commandtops
d [10/Jun/2015:11:29:28.696166 -0400] add_printer_filter: Test1: adding filter printer/Test1/application/postscript printer/Test1 0 -
d [10/Jun/2015:11:29:28.696182 -0400] add_printer_formats: 38 types, 14 filters
d [10/Jun/2015:11:29:28.696224 -0400] add_printer_formats: Test1: application/octet-stream needs 2 filters
d [10/Jun/2015:11:29:28.696244 -0400] add_printer_formats: Test1: application/pdf needs 2 filters
d [10/Jun/2015:11:29:28.696259 -0400] add_printer_formats: Test1: application/postscript needs 1 filters
d [10/Jun/2015:11:29:28.696273 -0400] add_printer_formats: Test1: application/rss+xml not supported
d [10/Jun/2015:11:29:28.696285 -0400] add_printer_formats: Test1: application/vnd.cups-banner not supported
d [10/Jun/2015:11:29:28.696300 -0400] add_printer_formats: Test1: application/vnd.cups-command needs 1 filters
d [10/Jun/2015:11:29:28.696313 -0400] add_printer_formats: Test1: application/vnd.cups-pdf not supported
d [10/Jun/2015:11:29:28.696326 -0400] add_printer_formats: Test1: application/vnd.cups-postscript needs 1 filters
d [10/Jun/2015:11:29:28.696338 -0400] add_printer_formats: Test1: application/vnd.cups-ppd not supported
d [10/Jun/2015:11:29:28.696352 -0400] add_printer_formats: Test1: application/vnd.cups-raster not supported
d [10/Jun/2015:11:29:28.696366 -0400] add_printer_formats: Test1: application/vnd.cups-raw needs 1 filters
d [10/Jun/2015:11:29:28.696379 -0400] add_printer_formats: Test1: application/x-cshell not supported
d [10/Jun/2015:11:29:28.696391 -0400] add_printer_formats: Test1: application/x-csource not supported
d [10/Jun/2015:11:29:28.696404 -0400] add_printer_formats: Test1: application/x-perl not supported
d [10/Jun/2015:11:29:28.696416 -0400] add_printer_formats: Test1: application/x-shell not supported
d [10/Jun/2015:11:29:28.696428 -0400] add_printer_formats: Test1: image/gif not supported
d [10/Jun/2015:11:29:28.696449 -0400] add_printer_formats: Test1: image/jpeg needs 3 filters
d [10/Jun/2015:11:29:28.696462 -0400] add_printer_formats: Test1: image/png not supported
d [10/Jun/2015:11:29:28.696474 -0400] add_printer_formats: Test1: image/pwg-raster not supported
d [10/Jun/2015:11:29:28.696486 -0400] add_printer_formats: Test1: image/tiff not supported
d [10/Jun/2015:11:29:28.696498 -0400] add_printer_formats: Test1: image/x-alias not supported
d [10/Jun/2015:11:29:28.696510 -0400] add_printer_formats: Test1: image/x-bitmap not supported
d [10/Jun/2015:11:29:28.696523 -0400] add_printer_formats: Test1: image/x-icon not supported
d [10/Jun/2015:11:29:28.696535 -0400] add_printer_formats: Test1: image/x-photocd not supported
d [10/Jun/2015:11:29:28.696547 -0400] add_printer_formats: Test1: image/x-portable-anymap not supported
d [10/Jun/2015:11:29:28.696559 -0400] add_printer_formats: Test1: image/x-portable-bitmap not supported
d [10/Jun/2015:11:29:28.696571 -0400] add_printer_formats: Test1: image/x-portable-graymap not supported
d [10/Jun/2015:11:29:28.696583 -0400] add_printer_formats: Test1: image/x-portable-pixmap not supported
d [10/Jun/2015:11:29:28.696595 -0400] add_printer_formats: Test1: image/x-sgi-rgb not supported
d [10/Jun/2015:11:29:28.696607 -0400] add_printer_formats: Test1: image/x-sun-raster not supported
d [10/Jun/2015:11:29:28.696619 -0400] add_printer_formats: Test1: image/x-xbitmap not supported
d [10/Jun/2015:11:29:28.696631 -0400] add_printer_formats: Test1: image/x-xpixmap not supported
d [10/Jun/2015:11:29:28.696643 -0400] add_printer_formats: Test1: text/css not supported
d [10/Jun/2015:11:29:28.696656 -0400] add_printer_formats: Test1: text/html not supported
d [10/Jun/2015:11:29:28.696677 -0400] add_printer_formats: Test1: text/plain needs 3 filters
d [10/Jun/2015:11:29:28.696690 -0400] add_printer_formats: Test1: 8 supported types
D [10/Jun/2015:11:29:28.696753 -0400] cupsdRegisterPrinter(p=0x2aefc8af9ac0(Test1))
D [10/Jun/2015:11:29:28.696768 -0400] Loading printer Test2...
d [10/Jun/2015:11:29:28.696779 -0400] cupsdAddPrinter("Test2")
d [10/Jun/2015:11:29:28.696808 -0400] cupsdAddPrinter: Adding Test2 to Printers
d [10/Jun/2015:11:29:28.696837 -0400] cupsdSetPrinterReasons(p=0x2aefc8b364f0(Test2),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
d [10/Jun/2015:11:29:28.696851 -0400] cupsdFindBest: uri = "/printers/Test2", limit=10...
d [10/Jun/2015:11:29:28.696870 -0400] cupsdFindBest: best = NONE
d [10/Jun/2015:11:29:28.696882 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=2(Print-Job))
d [10/Jun/2015:11:29:28.696893 -0400] cupsdFindPolicyOp: Found wildcard match...
D [10/Jun/2015:11:29:28.696935 -0400] load_ppd: Loading /tmp/cups-jja/share/Test2.data...
d [10/Jun/2015:11:29:28.699092 -0400] cupsdSetPrinterReasons(p=0x2aefc8b364f0(Test2),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [10/Jun/2015:11:29:28.699135 -0400] add_printer_filter(p=0x2aefc8b364f0(Test2), filtertype=0x2aefc8b36d80(printer/Test2), filter="application/vnd.cups-raw application/octet-stream 0 -")
d [10/Jun/2015:11:29:28.699161 -0400] add_printer_filter: Test2: adding filter application/vnd.cups-raw printer/Test2/application/octet-stream 0 -
d [10/Jun/2015:11:29:28.699192 -0400] add_printer_filter: Test2: adding filter printer/Test2/application/octet-stream printer/Test2 0 -
d [10/Jun/2015:11:29:28.699209 -0400] add_printer_filter(p=0x2aefc8b364f0(Test2), filtertype=0x2aefc8b36d80(printer/Test2), filter="application/vnd.cups-raster application/vnd.hp-pcl 50 rastertohp")
d [10/Jun/2015:11:29:28.699261 -0400] Test2: File "/tmp/cups-jja/bin/filter/rastertohp" permissions OK (0100777/uid=1000/gid=0).
d [10/Jun/2015:11:29:28.699276 -0400] add_printer_filter: Test2: adding filter application/vnd.cups-raster printer/Test2/application/vnd.hp-pcl 50 rastertohp
d [10/Jun/2015:11:29:28.699291 -0400] add_printer_filter: Test2: adding filter printer/Test2/application/vnd.hp-pcl printer/Test2 0 -
d [10/Jun/2015:11:29:28.699324 -0400] add_printer_formats: 41 types, 18 filters
d [10/Jun/2015:11:29:28.699344 -0400] add_printer_formats: Test2: application/octet-stream needs 2 filters
d [10/Jun/2015:11:29:28.699382 -0400] add_printer_formats: Test2: application/pdf needs 3 filters
d [10/Jun/2015:11:29:28.699403 -0400] add_printer_formats: Test2: application/postscript needs 2 filters
d [10/Jun/2015:11:29:28.699431 -0400] add_printer_formats: Test2: application/rss+xml not supported
d [10/Jun/2015:11:29:28.699445 -0400] add_printer_formats: Test2: application/vnd.cups-banner not supported
d [10/Jun/2015:11:29:28.699460 -0400] add_printer_formats: Test2: application/vnd.cups-command not supported
d [10/Jun/2015:11:29:28.699472 -0400] add_printer_formats: Test2: application/vnd.cups-pdf not supported
d [10/Jun/2015:11:29:28.699502 -0400] add_printer_formats: Test2: application/vnd.cups-postscript not supported
d [10/Jun/2015:11:29:28.699515 -0400] add_printer_formats: Test2: application/vnd.cups-ppd not supported
d [10/Jun/2015:11:29:28.699531 -0400] add_printer_formats: Test2: application/vnd.cups-raster needs 1 filters
d [10/Jun/2015:11:29:28.699565 -0400] add_printer_formats: Test2: application/vnd.cups-raw needs 1 filters
d [10/Jun/2015:11:29:28.699578 -0400] add_printer_formats: Test2: application/x-cshell not supported
d [10/Jun/2015:11:29:28.699591 -0400] add_printer_formats: Test2: application/x-csource not supported
d [10/Jun/2015:11:29:28.699619 -0400] add_printer_formats: Test2: application/x-perl not supported
d [10/Jun/2015:11:29:28.699632 -0400] add_printer_formats: Test2: application/x-shell not supported
d [10/Jun/2015:11:29:28.699644 -0400] add_printer_formats: Test2: image/gif not supported
d [10/Jun/2015:11:29:28.699687 -0400] add_printer_formats: Test2: image/jpeg needs 3 filters
d [10/Jun/2015:11:29:28.699701 -0400] add_printer_formats: Test2: image/png not supported
d [10/Jun/2015:11:29:28.699727 -0400] add_printer_formats: Test2: image/pwg-raster not supported
d [10/Jun/2015:11:29:28.699742 -0400] add_printer_formats: Test2: image/tiff not supported
d [10/Jun/2015:11:29:28.699754 -0400] add_printer_formats: Test2: image/x-alias not supported
d [10/Jun/2015:11:29:28.699766 -0400] add_printer_formats: Test2: image/x-bitmap not supported
d [10/Jun/2015:11:29:28.699793 -0400] add_printer_formats: Test2: image/x-icon not supported
d [10/Jun/2015:11:29:28.699806 -0400] add_printer_formats: Test2: image/x-photocd not supported
d [10/Jun/2015:11:29:28.699829 -0400] add_printer_formats: Test2: image/x-portable-anymap not supported
d [10/Jun/2015:11:29:28.699858 -0400] add_printer_formats: Test2: image/x-portable-bitmap not supported
d [10/Jun/2015:11:29:28.699870 -0400] add_printer_formats: Test2: image/x-portable-graymap not supported
d [10/Jun/2015:11:29:28.699882 -0400] add_printer_formats: Test2: image/x-portable-pixmap not supported
d [10/Jun/2015:11:29:28.699909 -0400] add_printer_formats: Test2: image/x-sgi-rgb not supported
d [10/Jun/2015:11:29:28.699923 -0400] add_printer_formats: Test2: image/x-sun-raster not supported
d [10/Jun/2015:11:29:28.699935 -0400] add_printer_formats: Test2: image/x-xbitmap not supported
d [10/Jun/2015:11:29:28.699947 -0400] add_printer_formats: Test2: image/x-xpixmap not supported
d [10/Jun/2015:11:29:28.699975 -0400] add_printer_formats: Test2: text/css not supported
d [10/Jun/2015:11:29:28.699988 -0400] add_printer_formats: Test2: text/html not supported
d [10/Jun/2015:11:29:28.700030 -0400] add_printer_formats: Test2: text/plain needs 3 filters
d [10/Jun/2015:11:29:28.700045 -0400] add_printer_formats: Test2: 7 supported types
D [10/Jun/2015:11:29:28.700090 -0400] cupsdRegisterPrinter(p=0x2aefc8b364f0(Test2))
D [10/Jun/2015:11:29:28.700104 -0400] Loading printer Test3...
d [10/Jun/2015:11:29:28.700115 -0400] cupsdAddPrinter("Test3")
d [10/Jun/2015:11:29:28.700163 -0400] cupsdAddPrinter: Adding Test3 to Printers
d [10/Jun/2015:11:29:28.700214 -0400] cupsdSetPrinterReasons(p=0x2aefc8b58b70(Test3),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
d [10/Jun/2015:11:29:28.700229 -0400] cupsdFindBest: uri = "/printers/Test3", limit=10...
d [10/Jun/2015:11:29:28.700240 -0400] cupsdFindBest: best = NONE
d [10/Jun/2015:11:29:28.700265 -0400] cupsdFindPolicyOp(p=0x2aefc8ae6bd0, op=2(Print-Job))
d [10/Jun/2015:11:29:28.700278 -0400] cupsdFindPolicyOp: Found wildcard match...
D [10/Jun/2015:11:29:28.700326 -0400] cupsdMarkDirty(P----)
D [10/Jun/2015:11:29:28.700340 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Not busy"
D [10/Jun/2015:11:29:28.700351 -0400] load_ppd: Loading /tmp/cups-jja/ppd/Test3.ppd...
d [10/Jun/2015:11:29:28.700410 -0400] cupsdSetPrinterReasons(p=0x2aefc8b58b70(Test3),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
D [10/Jun/2015:11:29:28.700451 -0400] cupsdRegisterPrinter(p=0x2aefc8b58b70(Test3))
I [10/Jun/2015:11:29:28.719132 -0400] Loading job cache file "/tmp/cups-jja/share/job.cache"...
D [10/Jun/2015:11:29:28.729419 -0400] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
E [10/Jun/2015:11:29:28.729443 -0400] Job 2 not found on line 8 of subscriptions.conf.
D [10/Jun/2015:11:29:28.729461 -0400] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
D [10/Jun/2015:11:29:28.729481 -0400] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
E [10/Jun/2015:11:29:28.729496 -0400] Job 55 not found on line 28 of subscriptions.conf.
I [10/Jun/2015:11:29:28.729514 -0400] Full reload complete.
d [10/Jun/2015:11:29:28.729527 -0400] cupsdCreateProfile(job_id=0, allow_networking=1) = NULL
d [10/Jun/2015:11:29:28.729538 -0400] cupsdStartListening: 3 Listeners
E [10/Jun/2015:11:29:28.729614 -0400] Unable to open listen socket for address [v1.::1]:8631 - Address already in use.
E [10/Jun/2015:11:29:28.729649 -0400] Unable to open listen socket for address 127.0.0.1:8631 - Address already in use.
I [10/Jun/2015:11:29:28.729711 -0400] Listening to /tmp/cups-jja/sock on fd 7...
d [10/Jun/2015:11:29:28.729727 -0400] cupsdSetEnv: CUPS_SERVER=/tmp/cups-jja/sock
d [10/Jun/2015:11:29:28.729740 -0400] cupsdSetEnv: CUPS_ENCRYPTION=IfRequested
I [10/Jun/2015:11:29:28.729751 -0400] Resuming new connection processing...
d [10/Jun/2015:11:29:28.729761 -0400] cupsdResumeListening: Setting input bits...
d [10/Jun/2015:11:29:28.729773 -0400] cupsdAddSelect(fd=-1, read_cb=0x2aefc6c435e7, write_cb=(nil), data=0x2aefc8ae6030)
d [10/Jun/2015:11:29:28.729784 -0400] cupsdAddSelect(fd=-1, read_cb=0x2aefc6c435e7, write_cb=(nil), data=0x2aefc8ae61d0)
d [10/Jun/2015:11:29:28.729813 -0400] cupsdAddSelect(fd=7, read_cb=0x2aefc6c435e7, write_cb=(nil), data=0x2aefc8ae5b90)
d [10/Jun/2015:11:29:28.729843 -0400] cupsdAddSelect(fd=8, read_cb=0x2aefc6c47150, write_cb=(nil), data=(nil))
D [10/Jun/2015:11:29:28.729858 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
d [10/Jun/2015:11:29:28.729871 -0400] cupsdAddEvent(event=server-restarted, dest=(nil)(), job=(nil)(0), text="Scheduler restarted.", ...)
D [10/Jun/2015:11:29:28.729882 -0400] Discarding unused server-restarted event...
d [10/Jun/2015:11:29:28.729893 -0400] select_timeout: JobHistoryUpdate=0
d [10/Jun/2015:11:29:28.729905 -0400] select_timeout(-1): 31 seconds to write dirty config/state files
d [10/Jun/2015:11:29:29.729995 -0400] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1433950169
D [10/Jun/2015:11:29:29.730105 -0400] Report: clients=0
D [10/Jun/2015:11:29:29.730126 -0400] Report: jobs=0
D [10/Jun/2015:11:29:29.730146 -0400] Report: jobs-active=0
D [10/Jun/2015:11:29:29.730165 -0400] Report: printers=3
D [10/Jun/2015:11:29:29.730228 -0400] Report: stringpool-string-count=4119
D [10/Jun/2015:11:29:29.730248 -0400] Report: stringpool-alloc-bytes=7008
D [10/Jun/2015:11:29:29.730268 -0400] Report: stringpool-total-bytes=76488
d [10/Jun/2015:11:29:29.730288 -0400] select_timeout: JobHistoryUpdate=0
d [10/Jun/2015:11:29:29.730310 -0400] select_timeout(0): 30 seconds to write dirty config/state files
I [10/Jun/2015:11:29:38.751950 -0400] Scheduler shutting down normally.
d [10/Jun/2015:11:29:38.752027 -0400] cupsdAddEvent(event=server-stopped, dest=(nil)(), job=(nil)(0), text="Scheduler shutting down normally.", ...)
D [10/Jun/2015:11:29:38.752052 -0400] Discarding unused server-stopped event...
d [10/Jun/2015:11:29:38.752074 -0400] cupsdCloseAllClients() Clients=0
d [10/Jun/2015:11:29:38.752094 -0400] cupsdStopListening: closing all listen sockets.
d [10/Jun/2015:11:29:38.752115 -0400] cupsdPauseListening: Clearing input bits...
d [10/Jun/2015:11:29:38.752136 -0400] cupsdRemoveSelect(fd=-1)
d [10/Jun/2015:11:29:38.752156 -0400] cupsdRemoveSelect(fd=-1)
d [10/Jun/2015:11:29:38.752176 -0400] cupsdRemoveSelect(fd=7)
d [10/Jun/2015:11:29:38.752293 -0400] cupsdRemoveSelect(fd=8)
d [10/Jun/2015:11:29:38.752391 -0400] cupsdDeleteProfile(profile="(null)")
I [10/Jun/2015:11:29:38.752492 -0400] Saving printers.conf...
D [10/Jun/2015:11:29:38.752757 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [10/Jun/2015:11:29:38.752855 -0400] Saving job.cache...
D [10/Jun/2015:11:29:38.753038 -0400] cupsdStopSelect()


More information about the cups mailing list