D [16/Sep/2022:11:03:30 +0200] [Client 100] 2.1 Print-Job 1
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest(0x55b931aa8a00[100]): operation_id=0002(Print-Job)
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: operation-attributes-tag
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: attributes-charset charset 'utf-8'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: attributes-natural-language naturalLanguage 'pl-pl'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: requesting-user-name nameWithoutLanguage 'XXXUSERNAMEXXX'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: printer-uri uri 'ipp://localhost:631/printers/XXXPRINTERQUEUEXXX'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: job-name nameWithoutLanguage 'XXXDOCUMENTNAMEXXX'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: job-attributes-tag
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: ColorModel nameWithoutLanguage 'RGB'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: OutputBin nameWithoutLanguage 'FaceDown'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: MediaType nameWithoutLanguage 'Unspecified'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: job-priority integer '50'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: Duplex nameWithoutLanguage 'DuplexNoTumble'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: number-up integer '1'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: PageSize nameWithoutLanguage 'A4'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: InputSlot nameWithoutLanguage 'Auto'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: Collate boolean 'false'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: job-sheets 1setOf nameWithoutLanguage 'none,none'
d [16/Sep/2022:11:03:30 +0200] cupsdProcessIPPRequest: cupsPrintQuality nameWithoutLanguage 'Normal'
D [16/Sep/2022:11:03:30 +0200] Print-Job ipp://localhost:631/printers/XXXPRINTERQUEUEXXX
d [16/Sep/2022:11:03:30 +0200] print_job(0x55b931aa8a00[100], ipp://localhost:631/printers/XXXPRINTERQUEUEXXX)
D [16/Sep/2022:11:03:30 +0200] [Job ???] Auto-typing file...
I [16/Sep/2022:11:03:30 +0200] [Job ???] Request file type is application/pdf.
d [16/Sep/2022:11:03:30 +0200] add_job(0x55b931aa8a00[100], 0x55b931a65230(XXXPRINTERQUEUEXXX), 0x55b93196ba30(application/pdf))
d [16/Sep/2022:11:03:30 +0200] cupsdFindPolicyOp(p=0x55b9319711b0, op=2(Print-Job))
d [16/Sep/2022:11:03:30 +0200] cupsdFindPolicyOp: Found exact match...
d [16/Sep/2022:11:03:30 +0200] cupsdIsAuthorized: con->uri="/printers/XXXPRINTERQUEUEXXX", con->best=0x55b931971ca0((null))
d [16/Sep/2022:11:03:30 +0200] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [16/Sep/2022:11:03:30 +0200] cupsdIsAuthorized: op=2(Print-Job)
d [16/Sep/2022:11:03:30 +0200] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [16/Sep/2022:11:03:30 +0200] check_quotas(0x55b931aa8a00[100], 0x55b931a65230[XXXPRINTERQUEUEXXX])
D [16/Sep/2022:11:03:30 +0200] cupsdMarkDirty(---J-)
D [16/Sep/2022:11:03:30 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [16/Sep/2022:11:03:30 +0200] [Job 4] Applying default options...
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default copies=1
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default cups-browsed=true
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default finishings=3
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default job-cancel-after=10800
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default job-hold-until=no-hold
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default media=iso_a4_210x297mm
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default notify-events=job-completed
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default notify-lease-duration=86400
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default orientation-requested=3
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default output-bin=face-down
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default print-color-mode=color
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default printer-resolution=600x600dpi
D [16/Sep/2022:11:03:30 +0200] [Job 4] Adding default sides=one-sided
D [16/Sep/2022:11:03:30 +0200] add_job: requesting-user-name="XXXUSERNAMEXXX"
I [16/Sep/2022:11:03:30 +0200] [Job 4] Adding start banner page "none".
d [16/Sep/2022:11:03:30 +0200] copy_banner(con=0x55b931aa8a00[100], job=0x55b931aaa3d0[4], name="none")
d [16/Sep/2022:11:03:30 +0200] cupsdAddEvent(event=job-created, dest=0x55b931a65230(XXXPRINTERQUEUEXXX), job=0x55b931aaa3d0(4), text="Job created.", ...)
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1c20(580), event=0x55b931aae7e0(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=14
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1d80(584), event=0x55b931aaed10(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=15
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1ee0(586), event=0x55b931aaf1d0(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=16
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a2040(588), event=0x55b931aaf690(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=17
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a21a0(590), event=0x55b931aafb50(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=18
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a2250(595), event=0x55b931ab0010(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=19
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b931a64850(597), event=0x55b931ab03d0(job-created))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=24
D [16/Sep/2022:11:03:30 +0200] cupsdMarkDirty(----S)
D [16/Sep/2022:11:03:30 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [16/Sep/2022:11:03:30 +0200] add_file(con=0x55b931aa8a00[100], job=4, filetype=application/pdf, compression=0)
D [16/Sep/2022:11:03:30 +0200] cupsdMarkDirty(---J-)
D [16/Sep/2022:11:03:30 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [16/Sep/2022:11:03:30 +0200] [Job 4] Adding end banner page "none".
d [16/Sep/2022:11:03:30 +0200] copy_banner(con=(nil)[-1], job=0x55b931aaa3d0[4], name="none")
I [16/Sep/2022:11:03:30 +0200] [Job 4] File of type application/pdf queued by "XXXUSERNAMEXXX".
D [16/Sep/2022:11:03:30 +0200] [Job 4] hold_until=0
I [16/Sep/2022:11:03:30 +0200] [Job 4] Queued on "XXXPRINTERQUEUEXXX" by "XXXUSERNAMEXXX".
d [16/Sep/2022:11:03:30 +0200] cupsdCheckJobs: 1 active jobs, sleeping=0, ac-power=-1, reload=0, curtime=1663319010
d [16/Sep/2022:11:03:30 +0200] cupsdCheckJobs: Job 4 - dest="XXXPRINTERQUEUEXXX", printer=(nil), state=3, cancel_time=0, hold_until=0, kill_time=0, pending_cost=0, pending_timeout=0
d [16/Sep/2022:11:03:30 +0200] start_job(job=0x55b931aaa3d0(4), printer=0x55b931a65230(XXXPRINTERQUEUEXXX))
d [16/Sep/2022:11:03:30 +0200] cupsdSetJobState(job=0x55b931aaa3d0(4), state=3, newstate=5, action=0, message="(null)")
D [16/Sep/2022:11:03:30 +0200] [Job 4] time-at-processing=1663319010
D [16/Sep/2022:11:03:30 +0200] cupsdMarkDirty(---J-)
D [16/Sep/2022:11:03:30 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [16/Sep/2022:11:03:30 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [16/Sep/2022:11:03:30 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x55b931a65230(XXXPRINTERQUEUEXXX), job=(nil)(0), text="%s \"%s\" state changed to %s.", ...)
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319931c0(579), event=0x55b9319bfd30(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1c20(580), event=0x55b931ab1d70(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=14
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1cd0(583), event=0x55b931ab20f0(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1d80(584), event=0x55b931ab2470(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=15
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1e30(585), event=0x55b931ab27f0(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1ee0(586), event=0x55b931ab2b70(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=16
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a1f90(587), event=0x55b931ab2ef0(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a2040(588), event=0x55b931ab3270(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=17
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a20f0(589), event=0x55b931ab35f0(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a21a0(590), event=0x55b931ab3970(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=18
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b9319a2250(595), event=0x55b931ab3cf0(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=19
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b931a58210(596), event=0x55b931ab4070(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] cupsd_send_notification(sub=0x55b931a64850(597), event=0x55b931ab43f0(printer-state-changed))
d [16/Sep/2022:11:03:30 +0200] sub->pipe=24
D [16/Sep/2022:11:03:30 +0200] cupsdMarkDirty(----S)
D [16/Sep/2022:11:03:30 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
d [16/Sep/2022:11:03:30 +0200] cupsdSetPrinterReasons(p=0x55b931a65230(XXXPRINTERQUEUEXXX),s="-paused"
d [16/Sep/2022:11:03:30 +0200] cupsdSetPrinterReasons(p=0x55b931a65230(XXXPRINTERQUEUEXXX),s="-cups-remote-pending,cups-remote-pending-held,cups-remote-processing,cups-remote-stopped,cups-remote-canceled,cups-remote-aborted,cups-remote-completed"
d [16/Sep/2022:11:03:30 +0200] cupsdSetPrinterReasons(p=0x55b931a65230(XXXPRINTERQUEUEXXX),s="-cups-missing-filter-warning,cups-insecure-filter-warning"
d [16/Sep/2022:11:03:30 +0200] cupsdCreateProfile(job_id=4, allow_networking=0) = NULL
d [16/Sep/2022:11:03:30 +0200] cupsdCreateProfile(job_id=4, allow_networking=1) = NULL
d [16/Sep/2022:11:03:30 +0200] cupsdContinueJob(job=0x55b931aaa3d0(4)): current_file=0, num_files=1
D [16/Sep/2022:11:03:30 +0200] [Job 4] 3 filters for job:
D [16/Sep/2022:11:03:30 +0200] [Job 4] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [16/Sep/2022:11:03:30 +0200] [Job 4] - (application/vnd.cups-pdf to printer/XXXPRINTERQUEUEXXX/application/pdf, cost 0)
D [16/Sep/2022:11:03:30 +0200] [Job 4] - (printer/XXXPRINTERQUEUEXXX/application/pdf to printer/XXXPRINTERQUEUEXXX, cost 0)
D [16/Sep/2022:11:03:30 +0200] [Job 4] job-sheets=none,none
d [16/Sep/2022:11:03:30 +0200] [Job 4] Mapping cupsPrintQuality=Normal to print-quality=4
d [16/Sep/2022:11:03:30 +0200] [Job 4] After mapping finishings print-quality=4
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[0]="XXXPRINTERQUEUEXXX"
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[1]="4"
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[2]="XXXUSERNAMEXXX"
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[3]="XXXDOCUMENTNAMEXXX"
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[4]="1"
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[5]="ColorModel=RGB OutputBin=FaceDown MediaType=Unspecified Duplex=DuplexNoTumble number-up=1 PageSize=A4 InputSlot=Auto noCollate cupsPrintQuality=Normal job-uuid=urn:uuid:3128c20d-c9ed-3f54-7163-cf34812f1f7d cups-browsed finishings=3 media=iso_a4_210x297mm orientation-requested=3 output-bin=face-down print-color-mode=color printer-resolution=600x600dpi sides=one-sided job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1663319010 time-at-processing=1663319010 print-quality=4"
D [16/Sep/2022:11:03:30 +0200] [Job 4] argv[6]="/var/spool/cups/d00004-001"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[2]="CUPS_DOCROOT=/usr/share/cups/html"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[3]="CUPS_REQUESTROOT=/var/spool/cups"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[4]="CUPS_SERVERBIN=/usr/libexec/cups"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[5]="CUPS_SERVERROOT=/etc/cups"
D [16/Sep/2022:11:03:30 +0200] [Job 4] envp[6]="CUPS_STATEDIR=/run/cups"