Multiple copies in selfwritten backend
Mario Goppold
ml at goppold.net
Wed Jul 18 13:41:21 PDT 2007
I have more tested and found that there are no backend calls for the 2,3,... files:
1 d [18/Jul/2007:22:20:47 +0200] POST /printers/MYTEST
2 d [18/Jul/2007:22:20:47 +0200] CONTENT_TYPE = application/ipp
3 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=255, con->file=-1
4 d [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest(0x8007dc50[7]): operation_id = 0005
5 D [18/Jul/2007:22:20:47 +0200] Create-Job ipp://localhost/printers/MYTEST
6 d [18/Jul/2007:22:20:47 +0200] create_job(0x8007dc50[7], ipp://localhost/printers/MYTEST)
7 d [18/Jul/2007:22:20:47 +0200] add_job(0x8007dc50[7], ipp://localhost/printers/MYTEST)
8 d [18/Jul/2007:22:20:47 +0200] cupsdFindPolicyOp(p=0x8005ffb0, op=5(Create-Job))
9 d [18/Jul/2007:22:20:47 +0200] cupsdFindPolicyOp: Found wildcard match...
10 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: con->uri="/printers/MYTEST", con->best=0x80061200((null))
11 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: level=AUTH_ANON, type=AUTH_NONE, satisfy=AUTH_SATISFY_ALL, num_names=0
12 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: op=0(unknown-0000)
13 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: auth=AUTH_ALLOW...
14 d [18/Jul/2007:22:20:47 +0200] check_quotas(0x8007dc50[7], 0x8006cea8[MYTEST])
15 D [18/Jul/2007:22:20:47 +0200] add_job: requesting-user-name="mario"
16 I [18/Jul/2007:22:20:47 +0200] Adding start banner page "none" to job 129.
17 d [18/Jul/2007:22:20:47 +0200] copy_banner(0x8007dc50[7], 0x80074a78[129], none)
18 d [18/Jul/2007:22:20:47 +0200] add_job_state_reasons(0x8007dc50[7], 129)
19 d [18/Jul/2007:22:20:47 +0200] cupsdAddEvent(event=job-created, dest=0x8006cea8(MYTEST), job=0x80074a78(129), text="Job created.", ...)
20 D [18/Jul/2007:22:20:47 +0200] Discarding unused job-created event...
21 d [18/Jul/2007:22:20:47 +0200] cupsdSaveJob(job=0x80074a78(129)): job->attrs=0x800739e0
22 I [18/Jul/2007:22:20:47 +0200] Job 129 created on "MYTEST" by "mario".
23 D [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest: 7 status_code=0 (successful-ok)
24 d [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest: Adding fd 7 to OutputSet...
25 d [18/Jul/2007:22:20:47 +0200] cupsdWriteClient: 7 bytes < 0
26 d [18/Jul/2007:22:20:47 +0200] cupsdWriteClient: Removing fd 7 from OutputSet...
27 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7, used=0, file=-1 state=0
28 D [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 POST /printers/MYTEST HTTP/1.1
29 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: uri = "/printers/MYTEST"...
30 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
31 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location /admin/conf Limit 7f
32 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location /admin Limit 7f
33 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location / Limit 7f
34 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: best = /
35 d [18/Jul/2007:22:20:47 +0200] cupsdAuthorize: con->uri="/printers/MYTEST", con->best=0x8005fdb0(/)
36 d [18/Jul/2007:22:20:47 +0200] cupsdAuthorize: Authorization=""
37 D [18/Jul/2007:22:20:47 +0200] cupsdAuthorize: No authentication data provided.
38 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: con->uri="/printers/MYTEST", con->best=0x8005fdb0(/)
39 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: level=AUTH_ANON, type=AUTH_NONE, satisfy=AUTH_SATISFY_ALL, num_names=0
40 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: auth=AUTH_ALLOW...
41 d [18/Jul/2007:22:20:47 +0200] POST /printers/MYTEST
42 d [18/Jul/2007:22:20:47 +0200] CONTENT_TYPE = application/ipp
43 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1907, con->file=-1
44 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 REQUEST /var/spool/cups/00000002=9
45 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 writing 1687 bytes to 9
46 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 Closing data file 9, size=1687.
47 d [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest(0x8007dc50[7]): operation_id = 0006
48 D [18/Jul/2007:22:20:47 +0200] Send-Document ipp://localhost/jobs/129
49 d [18/Jul/2007:22:20:47 +0200] send_document(0x8007dc50[7], ipp://localhost/jobs/129)
50 d [18/Jul/2007:22:20:47 +0200] validate_user(job=129, con=7, owner="mario", username=0xbf815a72, userlen=1024)
51 d [18/Jul/2007:22:20:47 +0200] cupsdFindPolicyOp(p=0x8005ffb0, op=6(Send-Document))
52 d [18/Jul/2007:22:20:47 +0200] cupsdFindPolicyOp: Found exact match...
53 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: con->uri="/printers/MYTEST", con->best=0x8005ffe0((null))
54 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: owner="mario"
55 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: level=AUTH_USER, type=AUTH_NONE, satisfy=AUTH_SATISFY_ALL, num_names=2
56 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: op=6(Send-Document)
57 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: auth=AUTH_ALLOW...
58 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: requesting-user-name="mario"
59 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: Checking user membership...
60 D [18/Jul/2007:22:20:47 +0200] send_document: auto-typing file...
61 D [18/Jul/2007:22:20:47 +0200] send_document: request file type is text/plain.
62 d [18/Jul/2007:22:20:47 +0200] add_file(con=0x8007dc50[7], job=129, filetype=text/plain, compression=0)
63 I [18/Jul/2007:22:20:47 +0200] File of type text/plain queued in job #129 by "mario".
64 d [18/Jul/2007:22:20:47 +0200] cupsdSaveJob(job=0x80074a78(129)): job->attrs=0x800739e0
65 d [18/Jul/2007:22:20:47 +0200] add_job_state_reasons(0x8007dc50[7], 129)
66 D [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest: 7 status_code=0 (successful-ok)
67 d [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest: Adding fd 7 to OutputSet...
68 d [18/Jul/2007:22:20:47 +0200] cupsdWriteClient: 7 bytes < 0
69 d [18/Jul/2007:22:20:47 +0200] cupsdWriteClient: Removing fd 7 from OutputSet...
70 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7, used=0, file=-1 state=0
71 D [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 POST /printers/MYTEST HTTP/1.1
72 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: uri = "/printers/MYTEST"...
73 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
74 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location /admin/conf Limit 7f
75 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location /admin Limit 7f
76 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: Location / Limit 7f
77 d [18/Jul/2007:22:20:47 +0200] cupsdFindBest: best = /
78 d [18/Jul/2007:22:20:47 +0200] cupsdAuthorize: con->uri="/printers/MYTEST", con->best=0x8005fdb0(/)
79 d [18/Jul/2007:22:20:47 +0200] cupsdAuthorize: Authorization=""
80 D [18/Jul/2007:22:20:47 +0200] cupsdAuthorize: No authentication data provided.
81 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: con->uri="/printers/MYTEST", con->best=0x8005fdb0(/)
82 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: level=AUTH_ANON, type=AUTH_NONE, satisfy=AUTH_SATISFY_ALL, num_names=0
83 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: auth=AUTH_ALLOW...
84 d [18/Jul/2007:22:20:47 +0200] POST /printers/MYTEST
85 d [18/Jul/2007:22:20:47 +0200] CONTENT_TYPE = application/ipp
86 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=926, con->file=-1
87 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 REQUEST /var/spool/cups/00000003=9
88 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 writing 688 bytes to 9
89 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7 Closing data file 9, size=688.
90 d [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest(0x8007dc50[7]): operation_id = 0006
91 D [18/Jul/2007:22:20:47 +0200] Send-Document ipp://localhost/jobs/129
92 d [18/Jul/2007:22:20:47 +0200] send_document(0x8007dc50[7], ipp://localhost/jobs/129)
93 d [18/Jul/2007:22:20:47 +0200] validate_user(job=129, con=7, owner="mario", username=0xbf815a72, userlen=1024)
94 d [18/Jul/2007:22:20:47 +0200] cupsdFindPolicyOp(p=0x8005ffb0, op=6(Send-Document))
95 d [18/Jul/2007:22:20:47 +0200] cupsdFindPolicyOp: Found exact match...
96 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: con->uri="/printers/MYTEST", con->best=0x8005ffe0((null))
97 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: owner="mario"
98 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: level=AUTH_USER, type=AUTH_NONE, satisfy=AUTH_SATISFY_ALL, num_names=2
99 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: op=6(Send-Document)
100 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: auth=AUTH_ALLOW...
101 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: requesting-user-name="mario"
102 d [18/Jul/2007:22:20:47 +0200] cupsdIsAuthorized: Checking user membership...
103 D [18/Jul/2007:22:20:47 +0200] send_document: auto-typing file...
104 D [18/Jul/2007:22:20:47 +0200] send_document: request file type is text/plain.
105 d [18/Jul/2007:22:20:47 +0200] add_file(con=0x8007dc50[7], job=129, filetype=text/plain, compression=0)
106 I [18/Jul/2007:22:20:47 +0200] File of type text/plain queued in job #129 by "mario".
107 I [18/Jul/2007:22:20:47 +0200] Adding end banner page "none" to job 129.
108 d [18/Jul/2007:22:20:47 +0200] copy_banner(0x8007dc50[7], 0x80074a78[129], none)
109 d [18/Jul/2007:22:20:47 +0200] cupsdSaveJob(job=0x80074a78(129)): job->attrs=0x800739e0
110 d [18/Jul/2007:22:20:47 +0200] cupsdCheckJobs: 1 active jobs, sleeping=0, reload=0
111 d [18/Jul/2007:22:20:47 +0200] cupsdCheckJobs: Job 129: state_value=3, loaded=yes
112 d [18/Jul/2007:22:20:47 +0200] start_job: id = 129, file = 0/2
113 D [18/Jul/2007:22:20:47 +0200] [Job 129] Sending job to queue tagged as raw...
114 d [18/Jul/2007:22:20:47 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x8006cea8(MYTEST), job=(nil)(0), text="%s "%s" state changed.", ...)
115 D [18/Jul/2007:22:20:47 +0200] Discarding unused printer-state-changed event...
116 D [18/Jul/2007:22:20:47 +0200] job-sheets=none,none
117 D [18/Jul/2007:22:20:47 +0200] banner_page = 0
118 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[0]="MYTEST"
119 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[1]="129"
120 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[2]="mario"
121 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[3]="passwd"
122 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[4]="1"
123 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[5]="job-uuid=urn:uuid:f578adf9-bea6-30ef-515d-504bef710bec"
124 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[6]="/var/spool/cups/d00129-001"
125 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
126 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[1]="CUPS_DATADIR=/usr/share/cups"
127 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[2]="CUPS_DOCROOT=/usr/share/doc/packages/cups"
128 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
129 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
130 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
131 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[6]="CUPS_SERVERROOT=/etc/cups"
132 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[7]="CUPS_STATEDIR=/var/run/cups"
133 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
134 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[9]="SERVER_ADMIN=root at localhost"
135 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[10]="SOFTWARE=CUPS/1.2.7"
136 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[11]="TMPDIR=/var/spool/cups/tmp"
137 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[12]="USER=root"
138 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
139 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[14]="CUPS_ENCRYPTION=IfRequested"
140 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[15]="IPP_PORT=631"
141 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[16]="CHARSET=iso-8859-15"
142 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[17]="LANG=C"
143 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[18]="PPD=/etc/cups/ppd/MYTEST.ppd"
144 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[19]="RIP_MAX_CACHE=8m"
145 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[20]="CONTENT_TYPE=text/plain"
146 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[21]="DEVICE_URI=mytest://dummy"
147 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[22]="PRINTER=MYTEST"
148 d [18/Jul/2007:22:20:47 +0200] start_job: status_pipes = [ 11 12 ]
149 d [18/Jul/2007:22:20:47 +0200] start_job: backend="/usr/lib/cups/backend/mytest"
150 d [18/Jul/2007:22:20:47 +0200] start_job: filterfds[0] = [ -1 -1 ]
151 d [18/Jul/2007:22:20:47 +0200] cupsdStartProcess("/usr/lib/cups/backend/mytest", 0x80084158, 0xbf8120e8, -1, -1, 12)
152 I [18/Jul/2007:22:20:47 +0200] Started backend /usr/lib/cups/backend/mytest (PID 14872) for job 129.
153 d [18/Jul/2007:22:20:47 +0200] start_job: Closing filter pipes for slot 0 [ -1 -1 ]...
154 d [18/Jul/2007:22:20:47 +0200] start_job: Adding fd 11 to InputSet...
155 d [18/Jul/2007:22:20:47 +0200] cupsdAddEvent(event=job-state, dest=0x8006cea8(MYTEST), job=0x80074a78(129), text="Job #%d started.", ...)
156 D [18/Jul/2007:22:20:47 +0200] Discarding unused job-state event...
157 d [18/Jul/2007:22:20:47 +0200] add_job_state_reasons(0x8007dc50[7], 129)
158 D [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest: 7 status_code=0 (successful-ok)
159 d [18/Jul/2007:22:20:47 +0200] cupsdProcessIPPRequest: Adding fd 7 to OutputSet...
160 d [18/Jul/2007:22:20:47 +0200] cupsdWriteClient: 7 bytes < 0
161 d [18/Jul/2007:22:20:47 +0200] cupsdWriteClient: Removing fd 7 from OutputSet...
162 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: 7, used=0, file=-1 state=0
163 d [18/Jul/2007:22:20:47 +0200] cupsdReadClient: httpGets returned EOF...
164 D [18/Jul/2007:22:20:47 +0200] cupsdCloseClient: 7
165 d [18/Jul/2007:22:20:47 +0200] cupsdCloseClient: Removing fd 7 from InputSet and OutputSet...
166 D [18/Jul/2007:22:20:47 +0200] [Job 129] job =129
167 D [18/Jul/2007:22:20:47 +0200] [Job 129] user =mario
168 D [18/Jul/2007:22:20:47 +0200] [Job 129] title =passwd
169 D [18/Jul/2007:22:20:47 +0200] [Job 129] copies =1
170 D [18/Jul/2007:22:20:47 +0200] [Job 129] options =job-uuid=urn:uuid:f578adf9-bea6-30ef-515d-504bef710bec
171 D [18/Jul/2007:22:20:47 +0200] [Job 129] filename=/var/spool/cups/d00129-001
172 D [18/Jul/2007:22:20:47 +0200] [Job 129] CUPS_SERVERADMIN=root at localhost
173 D [18/Jul/2007:22:20:47 +0200] [Job 129] cmdln=/usr/bin/wc -c /var/spool/cups/d00129-001 >> /tmp/debug_cups_test
174 D [18/Jul/2007:22:20:47 +0200] [Job 129] realprinter=dummy
175 d [18/Jul/2007:22:20:47 +0200] process_children()
176 D [18/Jul/2007:22:20:47 +0200] PID 14872 (/usr/lib/cups/backend/mytest) exited with no errors.
177 D [18/Jul/2007:22:20:47 +0200] [Job 129] File 0 is complete.
178 d [18/Jul/2007:22:20:47 +0200] cupsdFinishJob: job->status is 0
179 d [18/Jul/2007:22:20:47 +0200] start_job: id = 129, file = 1/2
180 D [18/Jul/2007:22:20:47 +0200] [Job 129] Sending job to queue tagged as raw...
181 D [18/Jul/2007:22:20:47 +0200] job-sheets=none,none
182 D [18/Jul/2007:22:20:47 +0200] banner_page = 0
183 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[0]="MYTEST"
184 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[1]="129"
185 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[2]="mario"
186 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[3]="passwd"
187 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[4]="1"
188 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[5]="job-uuid=urn:uuid:f578adf9-bea6-30ef-515d-504bef710bec"
189 D [18/Jul/2007:22:20:47 +0200] [Job 129] argv[6]="/var/spool/cups/d00129-002"
190 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
191 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[1]="CUPS_DATADIR=/usr/share/cups"
192 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[2]="CUPS_DOCROOT=/usr/share/doc/packages/cups"
193 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
194 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
195 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
196 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[6]="CUPS_SERVERROOT=/etc/cups"
197 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[7]="CUPS_STATEDIR=/var/run/cups"
198 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[8]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
199 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[9]="SERVER_ADMIN=root at localhost"
200 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[10]="SOFTWARE=CUPS/1.2.7"
201 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[11]="TMPDIR=/var/spool/cups/tmp"
202 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[12]="USER=root"
203 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[13]="CUPS_SERVER=/var/run/cups/cups.sock"
204 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[14]="CUPS_ENCRYPTION=IfRequested"
205 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[15]="IPP_PORT=631"
206 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[16]="CHARSET=iso-8859-15"
207 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[17]="LANG=C"
208 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[18]="PPD=/etc/cups/ppd/MYTEST.ppd"
209 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[19]="RIP_MAX_CACHE=8m"
210 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[20]="CONTENT_TYPE=text/plain"
211 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[21]="DEVICE_URI=mytest://dummy"
212 D [18/Jul/2007:22:20:47 +0200] [Job 129] envp[22]="PRINTER=MYTEST"
213 d [18/Jul/2007:22:20:47 +0200] start_job: Closing print pipes [ -1 -1 ]...
214 d [18/Jul/2007:22:20:47 +0200] start_job: Closing back pipes [ 9 10 ]...
215 d [18/Jul/2007:22:20:47 +0200] start_job: Closing status output pipe 12...
216 d [18/Jul/2007:22:20:47 +0200] start_job: Closing filter pipes for slot 0 [ -1 -1 ]...
217 d [18/Jul/2007:22:20:47 +0200] start_job: Adding fd 11 to InputSet...
218 d [18/Jul/2007:22:20:47 +0200] cupsdAddEvent(event=job-state, dest=0x8006cea8(MYTEST), job=0x80074a78(129), text="Job #%d started.", ...)
219 D [18/Jul/2007:22:20:47 +0200] Discarding unused job-state event...
220 D [18/Jul/2007:22:20:47 +0200] [Job 129] File 1 is complete.
221 d [18/Jul/2007:22:20:47 +0200] cupsdFinishJob: job->status is 0
222 d [18/Jul/2007:22:20:47 +0200] cupsdFinishJob: Removing fd 11 from InputSet...
223 d [18/Jul/2007:22:20:47 +0200] cupsdFinishJob: Closing status pipes [ 11 -1 ]...
224 d [18/Jul/2007:22:20:47 +0200] cupsdCancelJob: id = 129
225 d [18/Jul/2007:22:20:47 +0200] cupsdStopJob: id = 129, force = 0
226 d [18/Jul/2007:22:20:47 +0200] cupsdAddEvent(event=printer-state-changed, dest=0x8006cea8(MYTEST), job=(nil)(0), text="%s "%s" state changed.", ...)
227 D [18/Jul/2007:22:20:47 +0200] Discarding unused printer-state-changed event...
228 d [18/Jul/2007:22:20:47 +0200] cupsdStopJob: Closing print pipes [ -1 -1 ]...
229 d [18/Jul/2007:22:20:47 +0200] cupsdStopJob: Closing back pipes [ -1 -1 ]...
230 d [18/Jul/2007:22:20:47 +0200] cupsdAddEvent(event=job-completed, dest=0x8006cea8(MYTEST), job=0x80074a78(129), text="Job completed.", ...)
231 D [18/Jul/2007:22:20:47 +0200] Discarding unused job-completed event...
232 d [18/Jul/2007:22:20:47 +0200] cupsdSaveJob(job=0x80074a78(129)): job->attrs=0x800739e0
233 d [18/Jul/2007:22:20:47 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
234 D [18/Jul/2007:22:20:48 +0200] Unloading job 129...
235 d [18/Jul/2007:22:20:48 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
236 d [18/Jul/2007:22:20:48 +0200] select_timeout: 22 seconds to send browse update
237 d [18/Jul/2007:22:21:10 +0200] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
238 d [18/Jul/2007:22:21:10 +0200] stringpool: 725 strings, 7320 allocated, 12984 total bytes
239 d [18/Jul/2007:22:21:10 +0200] select_timeout: 5 seconds to send browse update
The lp command was: lp -d MYTEST /etc/passwd /etc/group
In Line 150 you can see the backend call but no one after the line 212!
Mario
More information about the cups
mailing list