I [01/Sep/2017:18:04:28 -0100] Listening to 0.0.0.0:631 (IPv4)
d [01/Sep/2017:18:04:28 -0100] cupsdAddLocation: Added location "/"
d [01/Sep/2017:18:04:28 -0100] cupsdAddIPMask(masks=0x200356e4(0), address=0:0:0:0, netmask=0:0:0:0)
d [01/Sep/2017:18:04:28 -0100] cupsdAddLocation: Added location "/admin"
d [01/Sep/2017:18:04:28 -0100] cupsdAddIPMask(masks=0x20036184(0), address=0:0:0:0, netmask=0:0:0:0)
d [01/Sep/2017:18:04:28 -0100] cupsdAddLocation: Added location "/admin/conf"
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20036320, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddIPMask(masks=0x20036344(0), address=0:0:0:0, netmask=0:0:0:0)
d [01/Sep/2017:18:04:28 -0100] cupsdAddLocation: Added location "/admin/log"
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20036620, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddIPMask(masks=0x20036644(0), address=0:0:0:0, netmask=0:0:0:0)
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0, op=5(Create-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044940, op=2(Print-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044940, op=3(Print-URI))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044940, op=4(Validate-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0, op=6(Send-Document))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20044aa0, name="@OWNER")
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20044aa0, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=7(Send-URI))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=c(Hold-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=d(Release-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=e(Restart-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=12(Purge-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=14(Set-Job-Attributes))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=17(Create-Job-Subscriptions))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=1a(Renew-Subscription))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=1b(Cancel-Subscription))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=1c(Get-Notifications))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=2c(Reprocess-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=2d(Cancel-Current-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=2e(Suspend-Current-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=2f(Resume-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=39(Cancel-My-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=3b(Close-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=400d(CUPS-Move-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x20044aa0, op=4027(CUPS-Get-Document))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0, op=4003(CUPS-Add-Modify-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x200460c0, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200460c0, op=4004(CUPS-Delete-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200460c0, op=4006(CUPS-Add-Modify-Class))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200460c0, op=4007(CUPS-Delete-Class))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200460c0, op=400a(CUPS-Set-Default))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200460c0, op=400b(CUPS-Get-Devices))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0, op=10(Pause-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x200467e0, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=11(Resume-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=22(Enable-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=23(Disable-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=24(Pause-Printer-After-Current-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=25(Hold-New-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=26(Release-Held-New-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=27(Deactivate-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=28(Activate-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=29(Restart-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=2a(Shutdown-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=2b(Startup-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=30(Promote-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=31(Schedule-Job-After))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=4008(CUPS-Accept-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0x200467e0, op=4009(CUPS-Reject-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0, op=400e(CUPS-Authenticate-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20047c00, name="@OWNER")
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20047c00, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20043fa0, po=0, op=0(0x0000))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=4(Validate-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=39(Cancel-My-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=3b(Close-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=4027(CUPS-Get-Document))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0, op=5(Create-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048700, op=2(Print-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048700, op=3(Print-URI))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048700, op=4(Validate-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0, op=6(Send-Document))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20048860, name="@OWNER")
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20048860, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=7(Send-URI))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=c(Hold-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=d(Release-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=e(Restart-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=12(Purge-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=14(Set-Job-Attributes))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=17(Create-Job-Subscriptions))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=1a(Renew-Subscription))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=1b(Cancel-Subscription))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=1c(Get-Notifications))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=2c(Reprocess-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=2d(Cancel-Current-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=2e(Suspend-Current-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=2f(Resume-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=39(Cancel-My-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=3b(Close-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=400d(CUPS-Move-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20048860, op=4027(CUPS-Get-Document))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0, op=4003(CUPS-Add-Modify-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x20049e80, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20049e80, op=4004(CUPS-Delete-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20049e80, op=4006(CUPS-Add-Modify-Class))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20049e80, op=4007(CUPS-Delete-Class))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x20049e80, op=400a(CUPS-Set-Default))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0, op=10(Pause-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x2004a480, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=11(Resume-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=22(Enable-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=23(Disable-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=24(Pause-Printer-After-Current-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=25(Hold-New-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=26(Release-Held-New-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=27(Deactivate-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=28(Activate-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=29(Restart-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=2a(Shutdown-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=2b(Startup-Printer))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=30(Promote-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=31(Schedule-Job-After))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=4008(CUPS-Accept-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004a480, op=4009(CUPS-Reject-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0, op=8(Cancel-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x2004b8a0, name="@OWNER")
d [01/Sep/2017:18:04:28 -0100] cupsdAddName(loc=0x2004b8a0, name="@SYSTEM")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0x2004b8a0, op=400e(CUPS-Authenticate-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdAddPolicyOp(p=0x20047dc0, po=0, op=0(0x0000))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20047dc0, op=4(Validate-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20047dc0, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20047dc0, op=39(Cancel-My-Jobs))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20047dc0, op=3b(Close-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20047dc0, op=4027(CUPS-Get-Document))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
I [01/Sep/2017:18:04:28 -0100] Remote access is enabled.
D [01/Sep/2017:18:04:28 -0100] Added auto ServerAlias ECSGIULIO
I [01/Sep/2017:18:04:28 -0100] Loaded configuration file "/@unixroot/etc/cups/cupsd.conf"
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_CACHEDIR=/@unixroot/var/cache/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_DATADIR=/@unixroot/usr/share/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_DOCROOT=/@unixroot/usr/share/doc/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_REQUESTROOT=/@unixroot/var/spool/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_SERVERBIN=/@unixroot/usr/lib/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_SERVERROOT=/@unixroot/etc/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_STATEDIR=/@unixroot/var/run/cups
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: HOME=/@unixroot/var/spool/cups/tmp
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: SERVER_ADMIN=root@ECSGIULIO
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: SOFTWARE=CUPS/2.1.3
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: TMPDIR=/@unixroot/var/spool/cups/tmp
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: TZ=CET-1CES,3,-1,0,7200,10,-1,0,3600,3600
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: USER=root
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: UNIXROOT=N:
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_MAX_MESSAGE=2047
I [01/Sep/2017:18:04:28 -0100] Configured for up to 100 clients.
I [01/Sep/2017:18:04:28 -0100] Allowing up to 100 client connections per host.
I [01/Sep/2017:18:04:28 -0100] Using policy "default" as the default.
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: NumPolicies=2
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: Policies[0]="authenticated"
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: Policies[1]="default"
I [01/Sep/2017:18:04:28 -0100] Full reload is required.
I [01/Sep/2017:18:04:28 -0100] Loaded MIME database from "/@unixroot/usr/share/cups/mime" and "/@unixroot/etc/cups": 44 types, 53 filters...
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/g-code
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/octet-stream
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/pdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/postscript
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/rss+xml
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/sla
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.adobe-reader-postscript
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-banner
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-command
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-pdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-pdf-banner
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-postscript
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-ppd
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-raster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.cups-raw
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/vnd.makerbot-s3g
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/x-cshell
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/x-csource
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/x-perl
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type application/x-shell
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/gif
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/jpeg
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/png
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/pwg-raster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/tiff
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/urf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-alias
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-bitmap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-icon
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-photocd
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-portable-anymap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-portable-bitmap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-portable-graymap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-portable-pixmap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-sgi-rgb
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-sun-raster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-xbitmap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-xpixmap
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type image/x-xwindowdump
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type model/amf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type model/vnd.collada+xml
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type text/css
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type text/html
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: type text/plain
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/octet-stream to application/vnd.cups-raw 0 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/pdf to application/vnd.cups-pdf 66 pdftopdf.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/postscript to application/pdf 0 gstopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/postscript to application/vnd.cups-postscript 66 pstops
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.adobe-reader-postscript to application/vnd.cups-postscript 66 pstops.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.cups-pdf to application/vnd.cups-postscript 100 pdftops.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.cups-pdf to application/vnd.cups-raster 99 gstoraster.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.cups-pdf to image/pwg-raster 99 gstoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.cups-pdf-banner to application/pdf 32 bannertopdf.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.cups-postscript to application/vnd.cups-raster 175 gstoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/vnd.cups-raster to image/pwg-raster 100 rastertopwg.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-cshell to application/pdf 32 texttopdf.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-cshell to text/plain 100 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-csource to application/pdf 32 texttopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-csource to text/plain 100 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-perl to application/pdf 32 texttopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-perl to text/plain 100 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-shell to application/pdf 32 texttopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter application/x-shell to text/plain 100 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/gif to application/vnd.cups-pdf 65 imagetopdf.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/gif to application/vnd.cups-raster 100 imagetoraster.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/jpeg to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/jpeg to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/png to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/png to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/pwg-raster to application/pdf 32 rastertopdf.exe
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/tiff to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/tiff to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-bitmap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-bitmap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-photocd to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-photocd to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-anymap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-anymap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-bitmap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-bitmap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-graymap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-graymap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-pixmap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-portable-pixmap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-sgi-rgb to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-sgi-rgb to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-sun-raster to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-sun-raster to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-xbitmap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-xbitmap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-xpixmap to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-xpixmap to application/vnd.cups-raster 100 imagetoraster
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter image/x-xwindowdump to application/vnd.cups-pdf 65 imagetopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter text/css to text/plain 100 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter text/html to application/pdf 32 texttopdf
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter text/html to text/plain 100 -
d [01/Sep/2017:18:04:28 -0100] cupsdReadConfiguration: filter text/plain to application/pdf 32 texttopdf
D [01/Sep/2017:18:04:28 -0100] Loading printer HPOFFICE...
d [01/Sep/2017:18:04:28 -0100] cupsdAddPrinter("HPOFFICE")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPrinter: Adding HPOFFICE to Printers
d [01/Sep/2017:18:04:28 -0100] cupsdSetPrinterReasons(p=0x2005f360(HPOFFICE),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: uri="/printers/HPOFFICE", limit=10...
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=2(Print-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
D [01/Sep/2017:18:04:28 -0100] load_ppd: Loading /@unixroot/var/cache/cups/HPOFFICE.data...
d [01/Sep/2017:18:04:28 -0100] cupsdSetPrinterReasons(p=0x2005f360(HPOFFICE),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [01/Sep/2017:18:04:28 -0100] add_printer_filter(p=0x2005f360(HPOFFICE), filtertype=0x2003cee0(printer/HPOFFICE), filter="application/vnd.cups-raw application/octet-stream 0 -")
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPOFFICE: adding filter application/vnd.cups-raw printer/HPOFFICE/application/octet-stream 0 -
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPOFFICE: adding filter printer/HPOFFICE/application/octet-stream printer/HPOFFICE 0 -
d [01/Sep/2017:18:04:28 -0100] add_printer_filter(p=0x2005f360(HPOFFICE), filtertype=0x2003cee0(printer/HPOFFICE), filter="application/vnd.cups-raster 0 hpcups")
d [01/Sep/2017:18:04:28 -0100] HPOFFICE: File \"/@unixroot/usr/lib/cups/filter/hpcups.exe\" permessi OK (040755/uid=0/gid=0).
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPOFFICE: adding filter application/vnd.cups-raster printer/HPOFFICE 0 hpcups
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: 46 types, 56 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/g-code not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/octet-stream needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/pdf needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/postscript needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/rss+xml not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/sla not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.adobe-reader-postscript needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-banner not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-command not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-pdf needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-pdf-banner needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-postscript needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-ppd not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-raster needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-raw needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.makerbot-s3g not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-cshell needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-csource needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-perl needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-shell needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/gif needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/jpeg needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/png needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/pwg-raster needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/tiff needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/urf not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-alias not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-bitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-icon not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-photocd needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-anymap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-bitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-graymap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-pixmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-sgi-rgb needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-sun-raster needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-xbitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-xpixmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-xwindowdump needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: model/amf not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: model/vnd.collada+xml not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: text/css needs 4 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: text/html needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: text/plain needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: 32 supported types
D [01/Sep/2017:18:04:28 -0100] cupsdRegisterPrinter(p=0x2005f360(HPOFFICE))
d [01/Sep/2017:18:04:28 -0100] cupsdSetPrinterReasons(p=0x2005f360(HPOFFICE),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: uri="/printers/HPOFFICE", limit=10...
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=2(Print-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
D [01/Sep/2017:18:04:28 -0100] load_ppd: Loading /@unixroot/var/cache/cups/HPOFFICE.data...
d [01/Sep/2017:18:04:28 -0100] cupsdSetPrinterReasons(p=0x2005f360(HPOFFICE),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [01/Sep/2017:18:04:28 -0100] add_printer_filter(p=0x2005f360(HPOFFICE), filtertype=0x2003cee0(printer/HPOFFICE), filter="application/vnd.cups-raw application/octet-stream 0 -")
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPOFFICE: adding filter application/vnd.cups-raw printer/HPOFFICE/application/octet-stream 0 -
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPOFFICE: adding filter printer/HPOFFICE/application/octet-stream printer/HPOFFICE 0 -
d [01/Sep/2017:18:04:28 -0100] add_printer_filter(p=0x2005f360(HPOFFICE), filtertype=0x2003cee0(printer/HPOFFICE), filter="application/vnd.cups-raster 0 hpcups")
d [01/Sep/2017:18:04:28 -0100] HPOFFICE: File \"/@unixroot/usr/lib/cups/filter/hpcups.exe\" permessi OK (040755/uid=0/gid=0).
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPOFFICE: adding filter application/vnd.cups-raster printer/HPOFFICE 0 hpcups
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: 46 types, 56 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/g-code not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/octet-stream needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/pdf needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/postscript needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/rss+xml not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/sla not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.adobe-reader-postscript needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-banner not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-command not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-pdf needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-pdf-banner needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-postscript needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-ppd not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-raster needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.cups-raw needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/vnd.makerbot-s3g not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-cshell needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-csource needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-perl needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: application/x-shell needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/gif needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/jpeg needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/png needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/pwg-raster needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/tiff needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/urf not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-alias not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-bitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-icon not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-photocd needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-anymap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-bitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-graymap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-portable-pixmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-sgi-rgb needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-sun-raster needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-xbitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-xpixmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: image/x-xwindowdump needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: model/amf not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: model/vnd.collada+xml not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: text/css needs 4 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: text/html needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: text/plain needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPOFFICE: 32 supported types
D [01/Sep/2017:18:04:28 -0100] cupsdRegisterPrinter(p=0x2005f360(HPOFFICE))
D [01/Sep/2017:18:04:28 -0100] Loading printer HPPSC1610...
d [01/Sep/2017:18:04:28 -0100] cupsdAddPrinter("HPPSC1610")
d [01/Sep/2017:18:04:28 -0100] cupsdAddPrinter: Adding HPPSC1610 to Printers
d [01/Sep/2017:18:04:28 -0100] cupsdSetPrinterReasons(p=0x20086260(HPPSC1610),s="-cups-insecure-filter-warning,cups-missing-filter-warning"
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: uri="/printers/HPPSC1610", limit=10...
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:28 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=2(Print-Job))
d [01/Sep/2017:18:04:28 -0100] cupsdFindPolicyOp: Found exact match...
D [01/Sep/2017:18:04:28 -0100] load_ppd: Loading /@unixroot/var/cache/cups/HPPSC1610.data...
d [01/Sep/2017:18:04:28 -0100] cupsdSetPrinterReasons(p=0x20086260(HPPSC1610),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [01/Sep/2017:18:04:28 -0100] add_printer_filter(p=0x20086260(HPPSC1610), filtertype=0x200600a0(printer/HPPSC1610), filter="application/vnd.cups-raw application/octet-stream 0 -")
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPPSC1610: adding filter application/vnd.cups-raw printer/HPPSC1610/application/octet-stream 0 -
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPPSC1610: adding filter printer/HPPSC1610/application/octet-stream printer/HPPSC1610 0 -
d [01/Sep/2017:18:04:28 -0100] add_printer_filter(p=0x20086260(HPPSC1610), filtertype=0x200600a0(printer/HPPSC1610), filter="application/vnd.cups-raster 0 hpcups")
d [01/Sep/2017:18:04:28 -0100] HPPSC1610: File \"/@unixroot/usr/lib/cups/filter/hpcups.exe\" permessi OK (040755/uid=0/gid=0).
d [01/Sep/2017:18:04:28 -0100] add_printer_filter: HPPSC1610: adding filter application/vnd.cups-raster printer/HPPSC1610 0 hpcups
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: 48 types, 59 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/g-code not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/octet-stream needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/pdf needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/postscript needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/rss+xml not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/sla not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.adobe-reader-postscript needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-banner not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-command not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-pdf needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-pdf-banner needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-postscript needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-ppd not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-raster needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.cups-raw needs 1 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/vnd.makerbot-s3g not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/x-cshell needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/x-csource needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/x-perl needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: application/x-shell needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/gif needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/jpeg needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/png needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/pwg-raster needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/tiff needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/urf not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-alias not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-bitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-icon not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-photocd needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-portable-anymap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-portable-bitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-portable-graymap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-portable-pixmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-sgi-rgb needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-sun-raster needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-xbitmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-xpixmap needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: image/x-xwindowdump needs 2 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: model/amf not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: model/vnd.collada+xml not supported
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: text/css needs 4 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: text/html needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: text/plain needs 3 filters
d [01/Sep/2017:18:04:28 -0100] add_printer_formats: HPPSC1610: 32 supported types
D [01/Sep/2017:18:04:28 -0100] cupsdRegisterPrinter(p=0x20086260(HPPSC1610))
I [01/Sep/2017:18:04:28 -0100] Loading job cache file "/@unixroot/var/cache/cups/job.cache"...
D [01/Sep/2017:18:04:28 -0100] [Job 1] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 2] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 3] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 4] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 4] Loading attributes...
d [01/Sep/2017:18:04:28 -0100] cupsdLoadJob: JobHistoryUpdate=1503998653
D [01/Sep/2017:18:04:28 -0100] [Job 4] Unloading...
D [01/Sep/2017:18:04:28 -0100] [Job 5] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 6] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 7] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 8] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 9] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 10] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 11] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 12] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 13] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 14] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 15] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 16] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 16] Loading attributes...
d [01/Sep/2017:18:04:28 -0100] cupsdLoadJob: JobHistoryUpdate=1503998653
D [01/Sep/2017:18:04:28 -0100] [Job 16] Unloading...
D [01/Sep/2017:18:04:28 -0100] [Job 17] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 18] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 19] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 20] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 21] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 22] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 22] Loading attributes...
d [01/Sep/2017:18:04:28 -0100] cupsdLoadJob: JobHistoryUpdate=1503998653
D [01/Sep/2017:18:04:28 -0100] [Job 22] Unloading...
D [01/Sep/2017:18:04:28 -0100] [Job 23] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 24] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 25] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 26] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 27] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 28] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 29] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 30] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 31] Loading from cache...
D [01/Sep/2017:18:04:28 -0100] [Job 32] Loading from cache...
I [01/Sep/2017:18:04:28 -0100] Full reload complete.
D [01/Sep/2017:18:04:28 -0100] cupsdCleanFiles(path="/@unixroot/var/spool/cups/tmp", pattern="(null)")
I [01/Sep/2017:18:04:28 -0100] Cleaning out old files in "/@unixroot/var/spool/cups/tmp".
D [01/Sep/2017:18:04:28 -0100] cupsdCleanFiles(path="/@unixroot/var/cache/cups", pattern="*.ipp")
I [01/Sep/2017:18:04:28 -0100] Cleaning out old files in "/@unixroot/var/cache/cups".
d [01/Sep/2017:18:04:28 -0100] cupsdCreateProfile(job_id=0, allow_networking=1) = NULL
d [01/Sep/2017:18:04:28 -0100] cupsdStartListening: 1 Listeners
I [01/Sep/2017:18:04:28 -0100] Listening to 0.0.0.0:631 on fd 6...
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_SERVER=localhost
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: CUPS_ENCRYPTION=IfRequested
d [01/Sep/2017:18:04:28 -0100] cupsdSetEnv: IPP_PORT=631
I [01/Sep/2017:18:04:28 -0100] Resuming new connection processing...
d [01/Sep/2017:18:04:28 -0100] cupsdResumeListening: Setting input bits...
d [01/Sep/2017:18:04:28 -0100] cupsdAddSelect(fd=6, read_cb=0x1691e, write_cb=0, data=0x200358c0)
d [01/Sep/2017:18:04:28 -0100] cupsdAddSelect(fd=7, read_cb=0x1c2b7, write_cb=0, data=0)
D [01/Sep/2017:18:04:28 -0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [01/Sep/2017:18:04:28 -0100] cupsdAddCert: Adding certificate for PID 0
d [01/Sep/2017:18:04:28 -0100] cupsdAddCert: NumSystemGroups=1
d [01/Sep/2017:18:04:28 -0100] cupsdAddEvent(event=server-started, dest=0(), job=0(0), text="Scheduler started in foreground.", ...)
D [01/Sep/2017:18:04:28 -0100] Discarding unused server-started event...
d [01/Sep/2017:18:04:28 -0100] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1504281868
d [01/Sep/2017:18:04:28 -0100] select_timeout: JobHistoryUpdate=1503998653
d [01/Sep/2017:18:04:29 -0100] cupsdCleanJobs: MaxJobs=500, JobHistory=2147483647, JobFiles=86400
D [01/Sep/2017:18:04:29 -0100] [Job 4] Removing document files.
D [01/Sep/2017:18:04:29 -0100] cupsdMarkDirty(---J-)
D [01/Sep/2017:18:04:29 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Not busy"
D [01/Sep/2017:18:04:29 -0100] [Job 16] Removing document files.
D [01/Sep/2017:18:04:29 -0100] cupsdMarkDirty(---J-)
D [01/Sep/2017:18:04:29 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [01/Sep/2017:18:04:29 -0100] [Job 22] Removing document files.
D [01/Sep/2017:18:04:29 -0100] cupsdMarkDirty(---J-)
D [01/Sep/2017:18:04:29 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
d [01/Sep/2017:18:04:29 -0100] cupsdCleanJobs: JobHistoryUpdate=0
D [01/Sep/2017:18:04:29 -0100] Report: clients=0
D [01/Sep/2017:18:04:29 -0100] Report: jobs=32
D [01/Sep/2017:18:04:29 -0100] Report: jobs-active=0
D [01/Sep/2017:18:04:29 -0100] Report: printers=2
D [01/Sep/2017:18:04:29 -0100] Report: stringpool-string-count=27732
D [01/Sep/2017:18:04:29 -0100] Report: stringpool-alloc-bytes=11208
D [01/Sep/2017:18:04:29 -0100] Report: stringpool-total-bytes=513904
d [01/Sep/2017:18:04:29 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:29 -0100] select_timeout(0): 31 seconds to write dirty config/state files
d [01/Sep/2017:18:04:35 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=0
D [01/Sep/2017:18:04:35 -0100] [Client 1] Accepted from localhost:53873 (IPv4)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=9, read_cb=0x1915c, write_cb=0, data=0x202765a0)
D [01/Sep/2017:18:04:35 -0100] [Client 1] Waiting for request.
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=1
D [01/Sep/2017:18:04:35 -0100] [Client 2] Accepted from localhost:53874 (IPv4)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=10, read_cb=0x1915c, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] Waiting for request.
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] [Client 2] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 2] POST /printers/HPPSC1610 HTTP/1.1
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [01/Sep/2017:18:04:35 -0100] [Client 2] Read: status=200
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: uri="/printers/HPPSC1610", limit=10...
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:35 -0100] [Client 2] con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:35 -0100] [Client 2] No authentication data provided.
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [01/Sep/2017:18:04:35 -0100] [Client 2] pipe_command: infile=11, outfile=0x2005da3c, command="/@unixroot/usr/lib/cups/cgi-bin/printers.cgi", options="/HPPSC1610", root=0
D [01/Sep/2017:18:04:35 -0100] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[8] = "HOME=/@unixroot/var/spool/cups/tmp"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[11] = "SERVER_ADMIN=root@ECSGIULIO"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[13] = "TMPDIR=/@unixroot/var/spool/cups/tmp"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[14] = "TZ=CET-1CES,3,-1,0,7200,10,-1,0,3600,3600"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[15] = "USER=root"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[16] = "UNIXROOT=N:"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[18] = "CUPS_SERVER=localhost"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[20] = "IPP_PORT=631"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[21] = "LANG=en_US.UTF8"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[22] = "REDIRECT_STATUS=1"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[24] = "SERVER_NAME=localhost"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[25] = "SERVER_PORT=631"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[27] = "REMOTE_HOST=localhost"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[28] = "SCRIPT_NAME=/printers/HPPSC1610"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HPPSC1610"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[30] = "PATH_INFO=/HPPSC1610"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=3a182577254f961f9d2266e4b01b552a"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[34] = "HTTP_REFERER=http://localhost:631/printers/HPPSC1610?which_jobs=all"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[35] = "REQUEST_METHOD=POST"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[36] = "CONTENT_LENGTH=60"
D [01/Sep/2017:18:04:35 -0100] [CGI] envp[37] = "CONTENT_TYPE=application/x-www-form-urlencoded"
d [01/Sep/2017:18:04:35 -0100] File \"/@unixroot/usr/lib/cups/cgi-bin/printers.cgi\" permessi OK (040755/uid=0/gid=0).
d [01/Sep/2017:18:04:35 -0100] cupsdStartProcess: Preparing to start "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi", arguments:
d [01/Sep/2017:18:04:35 -0100] cupsdStartProcess: argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
d [01/Sep/2017:18:04:35 -0100] cupsdStartProcess(command="/@unixroot/usr/lib/cups/cgi-bin/printers.cgi", argv=0x1655a0, envp=0x165730, infd=11, outfd=13, errfd=8, backfd=-1, sidefd=-1, root=0, profile=0, job=0(0), pid=0x165494) = 332
D [01/Sep/2017:18:04:35 -0100] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 332)
I [01/Sep/2017:18:04:35 -0100] [Client 2] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=332, file=12)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=12, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=2
D [01/Sep/2017:18:04:35 -0100] [Client 3] Accepted from localhost:53875 (IPv4)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0, data=0x2028ca40)
D [01/Sep/2017:18:04:35 -0100] [Client 3] Waiting for request.
D [01/Sep/2017:18:04:35 -0100] [CGI] org.cups.sid cookie is \"3a182577254f961f9d2266e4b01b552a\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: org.cups.sid=\"3a182577254f961f9d2266e4b01b552a\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: OP=\"cancel-jobs\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HPPSC1610\"
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] [Client 3] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 3] POST /printers/HPPSC1610 HTTP/1.1
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [01/Sep/2017:18:04:35 -0100] [Client 3] Read: status=200
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: uri="/printers/HPPSC1610", limit=10...
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:35 -0100] [Client 3] con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:35 -0100] [Client 3] No authentication data provided.
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:35 -0100] [Client 3] 2.0 Cancel-Jobs 1
d [01/Sep/2017:18:04:35 -0100] cupsdProcessIPPRequest(0x2028ca40[3]): operation_id = 0038
D [01/Sep/2017:18:04:35 -0100] Cancel-Jobs ipp://localhost/printers/HPPSC1610
d [01/Sep/2017:18:04:35 -0100] cancel_all_jobs(0x2028ca40[3], ipp://localhost/printers/HPPSC1610)
d [01/Sep/2017:18:04:35 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:35 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: con->uri="/printers/HPPSC1610", con->best=0x200478a0((null))
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=Basic, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=1
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: op=38(Cancel-Jobs)
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: username=""
D [01/Sep/2017:18:04:35 -0100] [Client 3] Returning HTTP Non autorizzato for Cancel-Jobs (ipp://localhost/printers/HPPSC1610) from localhost
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: uri="/printers/HPPSC1610", limit=10...
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:35 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:35 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:35 -0100] [Client 3] cupsdSendError code=401, auth_type=1
D [01/Sep/2017:18:04:35 -0100] [Client 3] cupsdSendHeader: code=401, type="text/html", auth_type=1
D [01/Sep/2017:18:04:35 -0100] [Client 3] WWW-Authenticate: Basic realm=\"CUPS\", trc=\"y\"
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=3
D [01/Sep/2017:18:04:35 -0100] [Client 4] Accepted from localhost:53876 (IPv4)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=13, read_cb=0x1915c, write_cb=0, data=0x20290c60)
D [01/Sep/2017:18:04:35 -0100] [Client 4] Waiting for request.
d [01/Sep/2017:18:04:35 -0100] [Client 3] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0x2005e900(IPP_STATE_DATA), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:35 -0100] [Client 3] Closing connection.
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=11)
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=3
D [01/Sep/2017:18:04:35 -0100] [Client 5] Accepted from localhost:53877 (IPv4)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0, data=0x2028ca40)
D [01/Sep/2017:18:04:35 -0100] [Client 5] Waiting for request.
d [01/Sep/2017:18:04:35 -0100] [Client 4] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:35 -0100] [Client 4] Closing connection.
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=13)
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=3
D [01/Sep/2017:18:04:35 -0100] [Client 6] Accepted from localhost:53878 (IPv4)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=13, read_cb=0x1915c, write_cb=0, data=0x20290c60)
D [01/Sep/2017:18:04:35 -0100] [Client 6] Waiting for request.
d [01/Sep/2017:18:04:35 -0100] [Client 5] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:35 -0100] [Client 5] Closing connection.
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=11)
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] [Client 6] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 6] POST /printers/HPPSC1610 HTTP/1.1
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [01/Sep/2017:18:04:35 -0100] [Client 6] Read: status=200
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: uri="/printers/HPPSC1610", limit=10...
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:35 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:35 -0100] [Client 6] con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:35 -0100] cupsdFindCert(certificate=E20107173395C6084DB98874DEC804BC)
d [01/Sep/2017:18:04:35 -0100] cupsdFindCert: Returning "root".
D [01/Sep/2017:18:04:35 -0100] [Client 6] Authorized as root using Local.
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:35 -0100] [Client 6] 2.0 Cancel-Jobs 1
d [01/Sep/2017:18:04:35 -0100] cupsdProcessIPPRequest(0x20290c60[6]): operation_id = 0038
D [01/Sep/2017:18:04:35 -0100] Cancel-Jobs ipp://localhost/printers/HPPSC1610
d [01/Sep/2017:18:04:35 -0100] cancel_all_jobs(0x20290c60[6], ipp://localhost/printers/HPPSC1610)
d [01/Sep/2017:18:04:35 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=38(Cancel-Jobs))
d [01/Sep/2017:18:04:35 -0100] cupsdFindPolicyOp: Found exact match...
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: con->uri="/printers/HPPSC1610", con->best=0x200478a0((null))
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=Basic, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=1
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: op=38(Cancel-Jobs)
d [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:35 -0100] cupsdIsAuthorized: username="root"
I [01/Sep/2017:18:04:35 -0100] All jobs on "HPPSC1610" were canceled by "root".
d [01/Sep/2017:18:04:35 -0100] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1504281875
D [01/Sep/2017:18:04:35 -0100] [Client 6] Returning IPP successful-ok for Cancel-Jobs (ipp://localhost/printers/HPPSC1610) from localhost
D [01/Sep/2017:18:04:35 -0100] [Client 6] Content-Length: 75
D [01/Sep/2017:18:04:35 -0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=13, read_cb=0x1915c, write_cb=0x18138, data=0x20290c60)
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:35 -0100] [Client 6] con->http=0x20291de0
D [01/Sep/2017:18:04:35 -0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x2005ede0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [01/Sep/2017:18:04:35 -0100] [Client 6] bytes=0, http_state=0, data_remaining=75
D [01/Sep/2017:18:04:35 -0100] [Client 6] Flushing write buffer.
D [01/Sep/2017:18:04:35 -0100] [Client 6] New state is HTTP_STATE_WAITING
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=13, read_cb=0x1915c, write_cb=0, data=0x20290c60)
D [01/Sep/2017:18:04:35 -0100] [Client 6] Waiting for request.
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: refresh_page=\"5;URL=/printers/HPPSC1610\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: TITLE=\"Cancel Jobs\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [01/Sep/2017:18:04:35 -0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
d [01/Sep/2017:18:04:35 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"header.tmpl\")
d [01/Sep/2017:18:04:35 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:35 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/header.tmpl\"...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{refresh_page?\" at 294, result=1...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 294...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{refresh_page}\" at 344...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 347 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 347...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 348 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{refresh_page?\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{display:none;}\" at 493...
d [01/Sep/2017:18:04:35 -0100] [CGI] Lone { at 633...
d [01/Sep/2017:18:04:35 -0100] [CGI] Lone { at 708...
d [01/Sep/2017:18:04:35 -0100] [CGI] Lone { at 843...
d [01/Sep/2017:18:04:35 -0100] [CGI] Lone { at 877...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{title}\" at 1081...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{SECTION=admin\" at 1315, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1315...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1331 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1331...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1332 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{SECTION=admin\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{SECTION=classes\" at 1396, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1396...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1412 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1412...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1413 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{SECTION=classes\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{SECTION=help\" at 1470, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1470...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1486 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1486...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1487 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [Client 2] write_pipe: CGI output on fd 12.
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=12)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] CGI data ready to be sent.
d [01/Sep/2017:18:04:35 -0100] [Client 6] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:35 -0100] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:35 -0100] [Client 6] Closing connection.
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=13)
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{SECTION=help\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{SECTION=jobs\" at 1538, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1538...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1554 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1554...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1555 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{SECTION=jobs\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{SECTION=printers\" at 1610, result=1...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1610...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1626 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 1626...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1627 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{SECTION=printers\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{title}\" at 1750...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 1757 on EOF...
d [01/Sep/2017:18:04:35 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"printer-cancel-jobs.tmpl\")
d [01/Sep/2017:18:04:35 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:35 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/printer-cancel-jobs.tmpl\"...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{is_class?\" at 43, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 43...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 49 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 49...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 57 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{is_class?\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{printer_name}\" at 72...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{is_class?\" at 104, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 104...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 110 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 110...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 118 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{is_class?\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting \"{is_class?\" at 139, result=0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 139...
D [01/Sep/2017:18:04:35 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:35 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=332, file=12
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=12, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] Waiting for CGI data.
D [01/Sep/2017:18:04:35 -0100] [Client 2] Script header: Content-Type: text/html;charset=utf-8
D [01/Sep/2017:18:04:35 -0100] [Client 2] Script header: 
D [01/Sep/2017:18:04:35 -0100] [Client 2] Sending status 200 for CGI.
D [01/Sep/2017:18:04:35 -0100] [Client 2] cupsdSendHeader: code=200, type="(null)", auth_type=0
d [01/Sep/2017:18:04:35 -0100] process_children()
d [01/Sep/2017:18:04:35 -0100] cupsdFinishProcess(pid=332, name=0x17f6d0, namelen=1024, job_id=0x17f6cc(0)) = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
D [01/Sep/2017:18:04:35 -0100] PID 332 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 147 on character \':\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 147...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 156 on character \'}\'...
d [01/Sep/2017:18:04:35 -0100] [CGI] Finished \"{is_class?\", out=0x18228ffc...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{printer_name}\" at 171...
d [01/Sep/2017:18:04:35 -0100] [CGI] \"{printer_name}\" at 187...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 216 on EOF...
d [01/Sep/2017:18:04:35 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"trailer.tmpl\")
d [01/Sep/2017:18:04:35 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:35 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/trailer.tmpl\"...
d [01/Sep/2017:18:04:35 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:35 -0100] [CGI] Returning at file position 218 on EOF...
D [01/Sep/2017:18:04:35 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:35 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=332, file=12
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=12, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=10)
d [01/Sep/2017:18:04:35 -0100] [Client 2] write_pipe: CGI output on fd 12.
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=12)
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] CGI data ready to be sent.
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:35 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:35 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=332, file=12
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=12, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] Waiting for CGI data.
D [01/Sep/2017:18:04:35 -0100] [Client 2] Sending 0-length chunk.
D [01/Sep/2017:18:04:35 -0100] [Client 2] Flushing write buffer.
D [01/Sep/2017:18:04:35 -0100] [Client 2] New state is HTTP_STATE_WAITING
d [01/Sep/2017:18:04:35 -0100] cupsdAddSelect(fd=10, read_cb=0x1915c, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:35 -0100] [Client 2] Waiting for request.
d [01/Sep/2017:18:04:35 -0100] cupsdRemoveSelect(fd=12)
d [01/Sep/2017:18:04:35 -0100] cupsdEndProcess(pid=332, force=0)
D [01/Sep/2017:18:04:35 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:35 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:37 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:37 -0100] select_timeout(0): 23 seconds to write dirty config/state files
d [01/Sep/2017:18:04:40 -0100] [Client 1] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:40 -0100] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:40 -0100] [Client 1] Closing connection.
D [01/Sep/2017:18:04:40 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
d [01/Sep/2017:18:04:40 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:40 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:40 -0100] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1504281880
d [01/Sep/2017:18:04:40 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:40 -0100] [Client 2] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:40 -0100] [Client 2] GET /printers/HPPSC1610 HTTP/1.1
D [01/Sep/2017:18:04:40 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [01/Sep/2017:18:04:40 -0100] [Client 2] Read: status=200
d [01/Sep/2017:18:04:40 -0100] cupsdFindBest: uri="/printers/HPPSC1610", limit=2...
d [01/Sep/2017:18:04:40 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:40 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:40 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:40 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:40 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:40 -0100] [Client 2] con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:40 -0100] [Client 2] No authentication data provided.
d [01/Sep/2017:18:04:40 -0100] cupsdIsAuthorized: con->uri="/printers/HPPSC1610", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:40 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:40 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:40 -0100] [Client 2] Processing GET /printers/HPPSC1610
d [01/Sep/2017:18:04:40 -0100] [Client 2] pipe_command: infile=-1, outfile=0x2005da3c, command="/@unixroot/usr/lib/cups/cgi-bin/printers.cgi", options="/HPPSC1610", root=0
D [01/Sep/2017:18:04:40 -0100] [CGI] argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[0] = "CUPS_CACHEDIR=/@unixroot/var/cache/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[1] = "CUPS_DATADIR=/@unixroot/usr/share/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[2] = "CUPS_DOCROOT=/@unixroot/usr/share/doc/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[3] = "CUPS_FONTPATH=/@unixroot/usr/share/cups/fonts"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/@unixroot/var/spool/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[5] = "CUPS_SERVERBIN=/@unixroot/usr/lib/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[6] = "CUPS_SERVERROOT=/@unixroot/etc/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[7] = "CUPS_STATEDIR=/@unixroot/var/run/cups"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[8] = "HOME=/@unixroot/var/spool/cups/tmp"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[9] = "NLSPATH=C:\\MPTN\\MSG\\NLS\\%N;C:\\TCPIP\\msg\\ENUS850\\%N;"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[10] = "PATH=/@unixroot/usr/lib/cups/filter;/@unixroot/usr/bin;/@unixroot/usr/sbin;/bin;/usr/bin"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[11] = "SERVER_ADMIN=root@ECSGIULIO"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[12] = "SOFTWARE=CUPS/2.1.3"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[13] = "TMPDIR=/@unixroot/var/spool/cups/tmp"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[14] = "TZ=CET-1CES,3,-1,0,7200,10,-1,0,3600,3600"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[15] = "USER=root"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[16] = "UNIXROOT=N:"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[17] = "CUPS_MAX_MESSAGE=2047"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[18] = "CUPS_SERVER=localhost"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[19] = "CUPS_ENCRYPTION=IfRequested"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[20] = "IPP_PORT=631"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[21] = "LANG=en_US.UTF8"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[22] = "REDIRECT_STATUS=1"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[23] = "GATEWAY_INTERFACE=CGI/1.1"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[24] = "SERVER_NAME=localhost"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[25] = "SERVER_PORT=631"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[26] = "REMOTE_ADDR=127.0.0.1"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[27] = "REMOTE_HOST=localhost"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[28] = "SCRIPT_NAME=/printers/HPPSC1610"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[29] = "SCRIPT_FILENAME=/@unixroot/usr/share/doc/cups/printers/HPPSC1610"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[30] = "PATH_INFO=/HPPSC1610"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[31] = "SERVER_PROTOCOL=HTTP/1.1"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[32] = "HTTP_COOKIE=org.cups.sid=3a182577254f961f9d2266e4b01b552a"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[33] = "HTTP_USER_AGENT=Mozilla/5.0 (OS/2; Warp 4.5; rv:45.0) Gecko/20100101 Firefox/45.0"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[34] = "REQUEST_METHOD=GET"
D [01/Sep/2017:18:04:40 -0100] [CGI] envp[35] = "QUERY_STRING="
d [01/Sep/2017:18:04:40 -0100] File \"/@unixroot/usr/lib/cups/cgi-bin/printers.cgi\" permessi OK (040755/uid=0/gid=0).
d [01/Sep/2017:18:04:40 -0100] cupsdStartProcess: Preparing to start "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi", arguments:
d [01/Sep/2017:18:04:40 -0100] cupsdStartProcess: argv[0] = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
d [01/Sep/2017:18:04:41 -0100] cupsdStartProcess(command="/@unixroot/usr/lib/cups/cgi-bin/printers.cgi", argv=0x1655a0, envp=0x165730, infd=-1, outfd=11, errfd=8, backfd=-1, sidefd=-1, root=0, profile=0, job=0(0), pid=0x165494) = 334
D [01/Sep/2017:18:04:41 -0100] [CGI] Started /@unixroot/usr/lib/cups/cgi-bin/printers.cgi (PID 334)
I [01/Sep/2017:18:04:41 -0100] [Client 2] Started "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi" (pid=334, file=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] org.cups.sid cookie is \"3a182577254f961f9d2266e4b01b552a\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HPPSC1610\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=1
D [01/Sep/2017:18:04:41 -0100] [Client 7] Accepted from localhost:53879 (IPv4)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0, data=0x202765a0)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Waiting for request.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] POST / HTTP/1.1
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [01/Sep/2017:18:04:41 -0100] [Client 7] Read: status=200
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: uri="/", limit=10...
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:41 -0100] [Client 7] con->uri="/", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:41 -0100] [Client 7] No authentication data provided.
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:41 -0100] [Client 7] 2.0 CUPS-Get-Default 1
d [01/Sep/2017:18:04:41 -0100] cupsdProcessIPPRequest(0x202765a0[7]): operation_id = 4001
D [01/Sep/2017:18:04:41 -0100] CUPS-Get-Default
d [01/Sep/2017:18:04:41 -0100] get_default(0x202765a0[7])
d [01/Sep/2017:18:04:41 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=4001(CUPS-Get-Default))
d [01/Sep/2017:18:04:41 -0100] cupsdFindPolicyOp: Found wildcard match...
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/", con->best=0x20047d80((null))
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: op=0(0x0000)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [01/Sep/2017:18:04:41 -0100] printer-uri-supported="ipp://localhost:631/printers/HPPSC1610"
d [01/Sep/2017:18:04:41 -0100] copy_attrs(to=0x2005ece0, from=0x200607c0, ra=0x2028ca40, group=0, quickcopy=0)
d [01/Sep/2017:18:04:41 -0100] copy_attrs(to=0x2005ece0, from=0x20087b80, ra=0x2028ca40, group=0, quickcopy=0)
d [01/Sep/2017:18:04:41 -0100] copy_attrs(to=0x2005ece0, from=0x2003ce20, ra=0x2028ca40, group=0, quickcopy=-2147483648)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [01/Sep/2017:18:04:41 -0100] [Client 7] Content-Length: 166
D [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0x18138, data=0x202765a0)
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [Client 7] con->http=0x20285e60
D [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=166, response=0x2005ece0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [01/Sep/2017:18:04:41 -0100] [Client 7] bytes=0, http_state=0, data_remaining=166
D [01/Sep/2017:18:04:41 -0100] [Client 7] Flushing write buffer.
D [01/Sep/2017:18:04:41 -0100] [Client 7] New state is HTTP_STATE_WAITING
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0, data=0x202765a0)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Waiting for request.
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: DEFAULT_NAME=\"HPPSC1610\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: DEFAULT_URI=\"/printers/HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] show_printer(http=0x2003c300, printer=\"HPPSC1610\")
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] POST / HTTP/1.1
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [01/Sep/2017:18:04:41 -0100] [Client 7] Read: status=200
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: uri="/", limit=10...
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:41 -0100] [Client 7] con->uri="/", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:41 -0100] [Client 7] No authentication data provided.
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:41 -0100] [Client 7] 2.0 Get-Printer-Attributes 2
d [01/Sep/2017:18:04:41 -0100] cupsdProcessIPPRequest(0x202765a0[7]): operation_id = 000b
D [01/Sep/2017:18:04:41 -0100] Get-Printer-Attributes ipp://localhost/printers/HPPSC1610
d [01/Sep/2017:18:04:41 -0100] get_printer_attrs(0x202765a0[7], ipp://localhost/printers/HPPSC1610)
d [01/Sep/2017:18:04:41 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=b(Get-Printer-Attributes))
d [01/Sep/2017:18:04:41 -0100] cupsdFindPolicyOp: Found wildcard match...
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/", con->best=0x20047d80((null))
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: op=0(0x0000)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [01/Sep/2017:18:04:41 -0100] printer-uri-supported="ipp://localhost:631/printers/HPPSC1610"
d [01/Sep/2017:18:04:41 -0100] copy_attrs(to=0x2005ed20, from=0x200607c0, ra=0x2028cc00, group=0, quickcopy=0)
d [01/Sep/2017:18:04:41 -0100] copy_attrs(to=0x2005ed20, from=0x20087b80, ra=0x2028cc00, group=0, quickcopy=0)
d [01/Sep/2017:18:04:41 -0100] copy_attrs(to=0x2005ed20, from=0x2003ce20, ra=0x2028cc00, group=0, quickcopy=-2147483648)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HPPSC1610) from localhost
D [01/Sep/2017:18:04:41 -0100] [Client 7] Content-Length: 732
D [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0x18138, data=0x202765a0)
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [Client 7] con->http=0x20285e60
D [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=732, response=0x2005ed20(IPP_STATE_DATA), pipe_pid=0, file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [01/Sep/2017:18:04:41 -0100] [Client 7] bytes=0, http_state=0, data_remaining=732
D [01/Sep/2017:18:04:41 -0100] [Client 7] Flushing write buffer.
D [01/Sep/2017:18:04:41 -0100] [Client 7] New state is HTTP_STATE_WAITING
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0, data=0x202765a0)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Waiting for request.
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetIPPVars(response=0x20047820, filter_name=\"(null)\", filter_value=\"(null)\", prefix=\"(null)\", parent_el=0)
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetIPPObjectVars(obj=0x2003f520, prefix=\"(null)\", element=0)
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_is_accepting_jobs[0]=\"1\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_is_shared[0]=\"1\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_state[0]=\"3\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_state[0]=\"3\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HPPSC1610\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_uri_supported[0]=\"/printers/HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_name[0]=\"HPPSC1610\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_name[0]=\"HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_location[0]=\"CASA\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_location[0]=\"CASA\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_info[0]=\"HP PSC 1600 series\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_info[0]=\"HP PSC 1600 series\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
d [01/Sep/2017:18:04:41 -0100] [CGI] job_sheets_default[0]=\"none, none\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: device_uri[0]=\"usb://HP/PSC%201600%20series?serial=MY517D30GML0&interface=1\"
d [01/Sep/2017:18:04:41 -0100] [CGI] device_uri[0]=\"usb://HP/PSC%201600%20series?serial=MY517D30GML0&interface=1\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: color_supported[0]=\"1\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] color_supported[0]=\"1\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_make_and_model[0]=\"HP PSC 1600 Series, hpcups 3.16.11\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_make_and_model[0]=\"HP PSC 1600 Series, hpcups 3.16.11\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
d [01/Sep/2017:18:04:41 -0100] [CGI] media_default[0]=\"iso_a4_210x297mm\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
d [01/Sep/2017:18:04:41 -0100] [CGI] sides_supported[0]=\"one-sided, two-sided-long-edge, two-sided-short-edge\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
d [01/Sep/2017:18:04:41 -0100] [CGI] sides_default[0]=\"one-sided\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
d [01/Sep/2017:18:04:41 -0100] [CGI] printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"0\"
d [01/Sep/2017:18:04:41 -0100] [CGI] server_is_sharing_printers[0]=\"0\"
d [01/Sep/2017:18:04:41 -0100] [CGI] Returing 1 from cgiSetIPPVars()...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: TITLE=\"HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.3\"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"header.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/header.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{refresh_page?\" at 294, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 294...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{refresh_page}\" at 344...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 347 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 347...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 348 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{refresh_page?\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{display:none;}\" at 493...
d [01/Sep/2017:18:04:41 -0100] [CGI] Lone { at 633...
d [01/Sep/2017:18:04:41 -0100] [CGI] Lone { at 708...
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
D [01/Sep/2017:18:04:41 -0100] [Client 2] Script header: Content-Type: text/html;charset=utf-8
D [01/Sep/2017:18:04:41 -0100] [Client 2] Script header: 
D [01/Sep/2017:18:04:41 -0100] [Client 2] Sending status 200 for CGI.
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdSendHeader: code=200, type="(null)", auth_type=0
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Lone { at 843...
d [01/Sep/2017:18:04:41 -0100] [CGI] Lone { at 877...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{title}\" at 1081...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=admin\" at 1315, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1315...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1331 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1331...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1332 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=admin\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=classes\" at 1396, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1396...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1412 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1412...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1413 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=classes\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=help\" at 1470, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1470...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1486 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1486...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1487 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=help\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=jobs\" at 1538, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1538...
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1554 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1554...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1555 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=jobs\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=printers\" at 1610, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1610...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1626 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1626...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1627 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=printers\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{title}\" at 1750...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1757 on EOF...
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"printer.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/printer.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_uri_supported}\" at 50...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_name}\" at 66...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_state=3\" at 89, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 89...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 94 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 94...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_state=4\" at 111, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 111...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 122 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 122...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 129 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_state=4\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 130 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_state=3\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_is_accepting_jobs=0\" at 161, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 161...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 176 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 176...
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] POST / HTTP/1.1
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [01/Sep/2017:18:04:41 -0100] [Client 7] Read: status=200
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: uri="/", limit=10...
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:41 -0100] [Client 7] con->uri="/", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:41 -0100] [Client 7] No authentication data provided.
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:41 -0100] [Client 7] 2.0 Get-Jobs 3
d [01/Sep/2017:18:04:41 -0100] cupsdProcessIPPRequest(0x202765a0[7]): operation_id = 000a
D [01/Sep/2017:18:04:41 -0100] Get-Jobs ipp://localhost:631/printers/HPPSC1610
d [01/Sep/2017:18:04:41 -0100] get_jobs(0x202765a0[7], ipp://localhost:631/printers/HPPSC1610)
d [01/Sep/2017:18:04:41 -0100] cupsdFindPolicyOp(p=0x20043fa0, op=a(Get-Jobs))
d [01/Sep/2017:18:04:41 -0100] cupsdFindPolicyOp: Found wildcard match...
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/", con->best=0x20047d80((null))
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: op=0(0x0000)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [01/Sep/2017:18:04:41 -0100] get_jobs: count=0
D [01/Sep/2017:18:04:41 -0100] [Client 7] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HPPSC1610) from localhost
D [01/Sep/2017:18:04:41 -0100] [Client 7] Content-Length: 75
D [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0x18138, data=0x202765a0)
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 191 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_is_accepting_jobs=0\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{server_is_sharing_printers=0\" at 223, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 223...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 227 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 227...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_is_shared=0\" at 248, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 248...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 252 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 252...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 253 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_is_shared=0\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 254 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{server_is_sharing_printers=0\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{default_name=HPPSC1610\" at 290, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 290...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 307 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 307...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 308 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{default_name=HPPSC1610\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_uri_supported}\" at 367...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 452...
D [01/Sep/2017:18:04:41 -0100] [CGI] Regular expression \".*Clean.*\"
D [01/Sep/2017:18:04:41 -0100] [CGI] matches[0].rm_so=0
D [01/Sep/2017:18:04:41 -0100] [CGI] matches[1].rm_so=-1
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_commands~.*Clean.*\" at 639, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 639...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 700 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 700...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 701 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_commands~.*Clean.*\", out=0x18228ffc...
D [01/Sep/2017:18:04:41 -0100] [CGI] Regular expression \".*PrintSelfTestPage.*\"
D [01/Sep/2017:18:04:41 -0100] [CGI] matches[0].rm_so=0
D [01/Sep/2017:18:04:41 -0100] [CGI] matches[1].rm_so=-1
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
D [01/Sep/2017:18:04:41 -0100] [Client 7] con->http=0x20285e60
D [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x2005ed40(IPP_STATE_DATA), pipe_pid=0, file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [01/Sep/2017:18:04:41 -0100] [Client 7] bytes=0, http_state=0, data_remaining=75
D [01/Sep/2017:18:04:41 -0100] [Client 7] Flushing write buffer.
D [01/Sep/2017:18:04:41 -0100] [Client 7] New state is HTTP_STATE_WAITING
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=11, read_cb=0x1915c, write_cb=0, data=0x202765a0)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Waiting for request.
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_commands~.*PrintSelfTestPage.*\" at 742, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 742...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 809 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 809...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 810 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_commands~.*PrintSelfTestPage.*\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_state=5\" at 828, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 828...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 882 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 882...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 934 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_state=5\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{printer_is_accepting_jobs=0\" at 964, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 964...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1013 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1013...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1062 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{printer_is_accepting_jobs=0\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{admin_uri}\" at 1277...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 1365...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_name}\" at 1430...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_name}\" at 1939...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_info}\" at 2012...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_location}\" at 2094...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_make_and_model}\" at 2180...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{color_supported=1\" at 2201, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2201...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2207 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2207...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2217 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{color_supported=1\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{sides_supported=one-sided\" at 2244, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2244...
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=10)
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2245 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2245...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2264 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{sides_supported=one-sided\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{device_uri}\" at 2337...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_sheets_default}\" at 2432...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{media_default?\" at 2454, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2454...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{media_default}\" at 2469...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2470 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2470...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2478 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{media_default?\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{sides_default?\" at 2494, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2494...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{sides_default}\" at 2515...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2516 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2516...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2517 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{sides_default?\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2537 on EOF...
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"printer-jobs-header.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/printer-jobs-header.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 28 on EOF...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiClearVariables called.
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: ORDER=\"asc\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: SECTION=\"printers\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: TOTAL=\"0\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: PRINTER_NAME=\"HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: THISURL=\"/printers/HPPSC1610\"
D [01/Sep/2017:18:04:41 -0100] [CGI] cgiSetVariable: SEARCH_DEST=\"HPPSC1610\"
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"search.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/search.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{SECTION}\" at 24...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{?SEARCH_DEST}\" at 39...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{WHICH_JOBS?\" at 67, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 67...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{WHICH_JOBS}\" at 125...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 128 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 128...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 129 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{WHICH_JOBS?\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{ORDER?\" at 137, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 137...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{ORDER}\" at 185...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 188 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 188...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 189 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{ORDER?\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SEARCH_DEST?\" at 235, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 235...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{SEARCH_DEST}\" at 248...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 249 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 249...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=classes\" at 266, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 266...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 274 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 274...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{SECTION=jobs\" at 288, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 288...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 293 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 293...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 302 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=jobs\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 303 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SECTION=classes\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 304 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{SEARCH_DEST?\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{?QUERY}\" at 359...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{SECTION}\" at 415...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 530 on EOF...
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"jobs-header.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/jobs-header.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?which_jobs=\" at 14, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 14...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 15 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 15...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?printer_name=\" at 45, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 45...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 51 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 51...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_uri_supported}\" at 74...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 75 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?printer_name=\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 144 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?which_jobs=\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?which_jobs=completed\" at 168, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 168...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 169 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 169...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?printer_name=\" at 199, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 199...
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 205 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 205...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_uri_supported}\" at 228...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 229 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?printer_name=\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 358 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?which_jobs=completed\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?which_jobs=all\" at 376, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 376...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 377 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 377...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?printer_name=\" at 407, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 407...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 413 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 413...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{printer_uri_supported}\" at 436...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 437 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?printer_name=\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 554 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?which_jobs=all\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{total=0\" at 583, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 583...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 591 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 591...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{#job_id}\" at 608...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{total}\" at 619...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?which_jobs=\" at 634, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 634...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 641 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 641...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{which_jobs=all\" at 657, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 657...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 658 on character \':\'...
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=10)
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 658...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 668 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{which_jobs=all\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 669 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?which_jobs=\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{total=1\" at 682, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 682...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 683 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 683...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 685 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{total=1\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 686 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{total=0\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 692 on EOF...
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"jobs.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/jobs.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{#job_id=0\" at 11, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 11...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 12 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 12...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{THISURL}\" at 87...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{?QUERY}\" at 102...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{?WHICH_JOBS}\" at 131...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{FIRST}\" at 149...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{ORDER=dec\" at 171, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 171...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 175 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 175...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 179 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{ORDER=dec\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{ORDER=dec\" at 192, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 192...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 243 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 243...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 294 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{ORDER=dec\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Looping on \"job_id\" at 418, count=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 418...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_uri}\" at 467...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_name}\" at 487...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_id}\" at 500...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?phone?\" at 508, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 508...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{phone}\" at 517...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 519 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 519...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 520 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?phone?\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?job_name=\" at 548, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 548...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 556 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 556...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_name}\" at 566...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 567 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?job_name=\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{?job_originating_user_name=\" at 612, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 612...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 621 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 621...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_originating_user_name}\" at 648...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 649 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{?job_originating_user_name=\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_k_octets}\" at 679...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_media_sheets_completed=0\" at 726, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 726...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 734 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 734...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{?job_media_sheets_completed}\" at 763...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 764 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_media_sheets_completed=0\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=3\" at 793, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 793...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{time_at_creation}\" at 828...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 829 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 829...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=4\" at 842, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 842...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{time_at_creation}\" at 874...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 875 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 875...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=5\" at 889, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 889...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{time_at_processing}\" at 929...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 930 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 930...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=6\" at 943, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 943...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 951 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 951...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=7\" at 965, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 965...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{time_at_completed}\" at 999...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1000 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1000...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=8\" at 1013, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1013...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1021 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1021...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{time_at_completed}\" at 1056...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1057 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=8\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1058 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=7\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1059 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=6\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1060 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=5\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1061 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=4\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1062 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=3\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_printer_state_message?\" at 1095, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1095...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_state_message}\" at 1132...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1139 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1139...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1140 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_printer_state_message?\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_preserved>0\" at 1168, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1168...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state>5\" at 1181, result=1...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1181...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 1281...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_id}\" at 1384...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_uri}\" at 1454...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1505 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1505...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1506 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state>5\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1507 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1507...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1508 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_preserved>0\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=4\" at 1522, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1522...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 1622...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_id}\" at 1725...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_uri}\" at 1795...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1847 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1847...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 1848 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=4\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state=3\" at 1862, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 1862...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 1962...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_id}\" at 2062...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_uri}\" at 2132...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2181 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2181...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2182 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state=3\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting \"{job_state<7\" at 2196, result=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Skip first part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2196...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 2296...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_id}\" at 2398...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_printer_uri}\" at 2468...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{$org.cups.sid}\" at 2618...
d [01/Sep/2017:18:04:41 -0100] [CGI] \"{job_id}\" at 2718...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2766 on character \':\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Output second part...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 2766...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2767 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{job_state<7\", out=0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2787 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
d [01/Sep/2017:18:04:41 -0100] [Client 7] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:41 -0100] [Client 7] Closing connection.
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=11)
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished looping on \"job_id\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2807 on character \'}\'...
d [01/Sep/2017:18:04:41 -0100] [CGI] Finished \"{#job_id=0\", out=0x18228ffc...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 2808 on EOF...
d [01/Sep/2017:18:04:41 -0100] [CGI] cgiCopyTemplateLang(tmpl=\"trailer.tmpl\")
d [01/Sep/2017:18:04:41 -0100] [CGI] lang=\"en_US.UTF8\", locale=\"/en_US\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Template file is \"/@unixroot/usr/share/cups/templates/trailer.tmpl\"...
d [01/Sep/2017:18:04:41 -0100] [CGI] Starting at file position 0...
d [01/Sep/2017:18:04:41 -0100] [CGI] Returning at file position 218 on EOF...
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
d [01/Sep/2017:18:04:41 -0100] process_children()
d [01/Sep/2017:18:04:41 -0100] cupsdFinishProcess(pid=334, name=0x17f6d0, namelen=1024, job_id=0x17f6cc(0)) = "/@unixroot/usr/lib/cups/cgi-bin/printers.cgi"
D [01/Sep/2017:18:04:41 -0100] PID 334 (/@unixroot/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [Client 2] write_pipe: CGI output on fd 9.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0, write_cb=0x18138, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] CGI data ready to be sent.
D [01/Sep/2017:18:04:41 -0100] [Client 2] con->http=0x20288ec0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=0(), pipe_pid=334, file=9
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=9, read_cb=0x146e4, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for CGI data.
D [01/Sep/2017:18:04:41 -0100] [Client 2] Sending 0-length chunk.
D [01/Sep/2017:18:04:41 -0100] [Client 2] Flushing write buffer.
D [01/Sep/2017:18:04:41 -0100] [Client 2] New state is HTTP_STATE_WAITING
d [01/Sep/2017:18:04:41 -0100] cupsdAddSelect(fd=10, read_cb=0x1915c, write_cb=0, data=0x2005d400)
D [01/Sep/2017:18:04:41 -0100] [Client 2] Waiting for request.
d [01/Sep/2017:18:04:41 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:04:41 -0100] cupsdEndProcess(pid=334, force=0)
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:41 -0100] [Client 2] GET /cups.css HTTP/1.1
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [01/Sep/2017:18:04:41 -0100] [Client 2] Read: status=200
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: uri="/cups.css", limit=2...
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/log(10) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin/conf(11) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /admin(6) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: Location /(1) Limit 7f
d [01/Sep/2017:18:04:41 -0100] cupsdFindBest: best=/
d [01/Sep/2017:18:04:41 -0100] [Client 2] con->uri="/cups.css", con->best=0x200356c0(/)
D [01/Sep/2017:18:04:41 -0100] [Client 2] No authentication data provided.
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: con->uri="/cups.css", con->best=0x200356c0(/)
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [01/Sep/2017:18:04:41 -0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [01/Sep/2017:18:04:41 -0100] [Client 2] Processing GET /cups.css
d [01/Sep/2017:18:04:41 -0100] [Client 2] get_file: filestats=0x173604, filename=0x173670, len=1024, returning "/@unixroot/usr/share/doc/cups/cups.css".
D [01/Sep/2017:18:04:41 -0100] [Client 2] filename="/@unixroot/usr/share/doc/cups/cups.css", type=text/css
d [01/Sep/2017:18:04:41 -0100] [Client 2] is_cgi: filename="/@unixroot/usr/share/doc/cups/cups.css", filestats=0x173604, type=text/css, returning 0.
d [01/Sep/2017:18:04:41 -0100] [Client 2] check_if_modified: filestats=0x173604(9961, 1503410768)) If-Modified-Since="Tue, 22 Aug 2017 14:06:08 GMT"
d [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdSendError code=304, auth_type=0
D [01/Sep/2017:18:04:41 -0100] [Client 2] cupsdSendHeader: code=304, type="(null)", auth_type=0
D [01/Sep/2017:18:04:41 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
d [01/Sep/2017:18:04:41 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:42 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:42 -0100] select_timeout(0): 18 seconds to write dirty config/state files
d [01/Sep/2017:18:04:51 -0100] [Client 2] cupsdReadClient: error=0, used=0, state=HTTP_STATE_WAITING, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=0, request=0(), file=-1
D [01/Sep/2017:18:04:51 -0100] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [01/Sep/2017:18:04:51 -0100] [Client 2] Closing connection.
D [01/Sep/2017:18:04:51 -0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
d [01/Sep/2017:18:04:51 -0100] cupsdRemoveSelect(fd=10)
d [01/Sep/2017:18:04:51 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:04:51 -0100] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1504281891
d [01/Sep/2017:18:04:51 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:52 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:04:52 -0100] select_timeout(0): 8 seconds to write dirty config/state files
I [01/Sep/2017:18:05:00 -0100] Saving job.cache...
D [01/Sep/2017:18:05:00 -0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
d [01/Sep/2017:18:05:00 -0100] select_timeout: JobHistoryUpdate=0
d [01/Sep/2017:18:05:00 -0100] select_timeout(0): 86400 seconds to do nothing
W [01/Sep/2017:18:05:05 -0100] cupsdDoSelect: select() returned -1... pause and retry select()
d [01/Sep/2017:18:05:06 -0100] cupsdAcceptClient(lis=0x200358c0(6)) Clients=0
D [01/Sep/2017:18:05:06 -0100] [Client 8] Accepted from localhost:53881 (IPv4)
d [01/Sep/2017:18:05:06 -0100] cupsdAddSelect(fd=9, read_cb=0x1915c, write_cb=0, data=0x2005d2e0)
D [01/Sep/2017:18:05:06 -0100] [Client 8] Waiting for request.
d [01/Sep/2017:18:05:06 -0100] cupsdCheckJobs: 0 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1504281906
I [01/Sep/2017:18:05:06 -0100] Scheduler shutting down normally.
d [01/Sep/2017:18:05:06 -0100] cupsdAddEvent(event=server-stopped, dest=0(), job=0(0), text="Scheduler shutting down normally.", ...)
D [01/Sep/2017:18:05:06 -0100] Discarding unused server-stopped event...
d [01/Sep/2017:18:05:06 -0100] cupsdCloseAllClients() Clients=1
D [01/Sep/2017:18:05:06 -0100] [Client 8] Closing connection.
D [01/Sep/2017:18:05:06 -0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
d [01/Sep/2017:18:05:06 -0100] cupsdRemoveSelect(fd=9)
d [01/Sep/2017:18:05:06 -0100] cupsdRemoveSelect(fd=-1)
d [01/Sep/2017:18:05:06 -0100] cupsdStopListening: closing all listen sockets.
d [01/Sep/2017:18:05:06 -0100] cupsdPauseListening: Clearing input bits...
d [01/Sep/2017:18:05:06 -0100] cupsdRemoveSelect(fd=6)
d [01/Sep/2017:18:05:06 -0100] cupsdRemoveSelect(fd=7)
d [01/Sep/2017:18:05:06 -0100] cupsdDeleteProfile(profile="(null)")
I [01/Sep/2017:18:05:06 -0100] Saving job.cache...
D [01/Sep/2017:18:05:06 -0100] cupsdStopSelect()