OpenPrinting
Busy CUPS doesn't return time-at-creation for recent completed jobs
A busy CUPS server doesn't return time-at-creation attribute when asked for job-id,job-uri,job-state,time-at-creation attributes of the recent ( less than 6 hours) completed jobs only.
Here is a get-completed-jobs.test request:
# Get a list of completed jobs.
#
# Usage:
#
# ./ipptool printer-uri get-jobs.test
{
# The name of the test...
NAME "Get completed jobs"
# The operation to use
OPERATION Get-Jobs
# Attributes, starting in the operation group...
GROUP operation-attributes-tag
ATTR charset attributes-charset utf-8
ATTR language attributes-natural-language en
ATTR keyword which-jobs completed
ATTR uri printer-uri $uri
ATTR keyword requested-attributes
job-id,job-uri,job-state,time-at-creation
# What statuses are OK?
STATUS successful-ok
# What attributes to display
DISPLAY job-id
DISPLAY job-state
DISPLAY time-at-creation
}
On my server ipptool -tv ipp://localhost/ ./get-completed-jobs.test returns this :
"./get-completed-jobs.test":
Get-Jobs:
attributes-charset (charset) = utf-8
attributes-natural-language (naturalLanguage) = en
which-jobs (keyword) = completed
printer-uri (uri) = ipp://localhost:631/
requested-attributes (1setOf keyword) = job-id,job-uri,job-state,time-at-creation
Get pending jobs [PASS]
RECEIVED: 885100 bytes in response
status-code = successful-ok (successful-ok)
attributes-charset (charset) = utf-8
attributes-natural-language (naturalLanguage) = en
job-uri (uri) = ipp://localhost:631/jobs/5836275
job-id (integer) = 5836275
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5836357
job-id (integer) = 5836357
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5836347
job-id (integer) = 5836347
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5836361
job-id (integer) = 5836361
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5836304
job-id (integer) = 5836304
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5836354
job-id (integer) = 5836354
job-state (enum) = completed
Down this list, for the jobs submitted 6+ hours ago, the time-at-creation begins to appear. For aborted/cancelled jobs it appears regardless of the recency.
This is not reproducible on an idle CUPS, only on CUPS that is printing a few jobs per second.
If I request a longer list of attributes, like job-id,job-uri,job-state,job-state-reasons,time-at-creation,time-at-completed,date-time-at-creation,date-time-at-completed, it returns time-at-creation correctly:
"./get-jobs.test":
Get-Jobs:
attributes-charset (charset) = utf-8
attributes-natural-language (naturalLanguage) = en
printer-uri (uri) = ipp://localhost:631/
which-jobs (keyword) = completed
requested-attributes (1setOf keyword) = job-id,job-uri,job-state,job-state-reasons,time-at-creation,time-at-completed,date-time-at-creation,date-time-at-completed
Get pending jobs [PASS]
RECEIVED: 126050 bytes in response
status-code = successful-ok (successful-ok)
attributes-charset (charset) = utf-8
attributes-natural-language (naturalLanguage) = en
limit (integer) = 500
job-uri (uri) = ipp://localhost:631/jobs/5836448
date-time-at-completed (dateTime) = 2025-12-02T19:02:25Z
date-time-at-creation (dateTime) = 2025-12-02T19:01:51Z
time-at-completed (integer) = 1764702145
time-at-creation (integer) = 1764702111
job-id (integer) = 5836448
job-state (enum) = completed
job-state-reasons (keyword) = job-completed-successfully
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5836449
date-time-at-completed (dateTime) = 2025-12-02T19:02:23Z
date-time-at-creation (dateTime) = 2025-12-02T19:02:01Z
time-at-completed (integer) = 1764702143
time-at-creation (integer) = 1764702121
job-id (integer) = 5836449
job-state (enum) = completed
job-state-reasons (keyword) = job-completed-successfully
-- separator --
Am I creating these requests incorrectly, or is it a bug? (I'm just trying to monitor cups for completed/failed jobs here.)
Hmm, that is weird for sure, and you aren't doing anything wrong and it shouldn't matter whether you have a long or short list of requested attributes. The [date-]time-at-creation value is set when the job is created and the requested attributes code is dead simple (a CUPS array of sorted strings) so it shouldn't matter how busy cupsd is...
Investigating...
Can you try requesting time-at-creation first in the short list and see if that makes a difference? I can't reproduce on my Mac...
Nope, no difference.
For some reason CUPS needs to be busy for this issue to be reproducible, processing several jobs per second.
Get-Jobs:
attributes-charset (charset) = utf-8
attributes-natural-language (naturalLanguage) = en
which-jobs (keyword) = completed
printer-uri (uri) = ipp://localhost:631/
requested-attributes (1setOf keyword) = time-at-creation,job-id,job-uri,job-state
Get pending jobs [PASS]
RECEIVED: 879629 bytes in response
status-code = successful-ok (successful-ok)
attributes-charset (charset) = utf-8
attributes-natural-language (naturalLanguage) = en
job-uri (uri) = ipp://localhost:631/jobs/5837700
job-id (integer) = 5837700
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5837703
job-id (integer) = 5837703
job-state (enum) = completed
-- separator --
job-uri (uri) = ipp://localhost:631/jobs/5837534
job-id (integer) = 5837534
job-state (enum) = completed
