d [30/Nov/2009:13:35:40 +0100] cupsdAcceptClient(lis=0xb92475c0(8)) Clients=0
D [30/Nov/2009:13:35:40 +0100] cupsdAcceptClient: 12 from localhost (Domain)
d [30/Nov/2009:13:35:40 +0100] cupsdAddSelect(fd=12, read_cb=0xb76ae000, write_cb=(nil), data=0xb9285b20)
d [30/Nov/2009:13:35:40 +0100] cupsdCheckJobs: 0 active jobs, sleeping=0, reload=0
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 12 POST / HTTP/1.1
D [30/Nov/2009:13:35:40 +0100] cupsdSetBusyState: Active clients
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: uri = "/"...
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location / Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: best = /
d [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: con->uri="/", con->best=0xb924c0f0(/)
d [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: Authorization=""
D [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: No authentication data provided.
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb924c0f0(/)
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=688, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=688, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=659, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=659, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=622, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=622, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=579, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=579, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=564, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=564, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=541, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=541, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=518, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=518, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=500, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=500, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=477, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=477, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=459, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=459, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=437, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=437, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=418, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=418, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=401, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=401, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=384, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=384, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=363, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=363, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=342, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=342, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=325, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=325, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=295, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=295, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=273, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=273, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=252, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=252, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=225, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=225, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=208, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=208, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=190, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=190, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=160, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=160, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=134, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=134, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=117, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=117, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=91, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=91, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=62, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=62, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=1, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 12 1.1 Get-Printer-Attributes 1
d [30/Nov/2009:13:35:40 +0100] cupsdProcessIPPRequest(0xb9285b20[12]): operation_id = 000b
D [30/Nov/2009:13:35:40 +0100] Get-Printer-Attributes ipp://localhost:631/printers/FollowPrint-test
d [30/Nov/2009:13:35:40 +0100] get_printer_attrs(0xb9285b20[12], ipp://localhost:631/printers/FollowPrint-test)
d [30/Nov/2009:13:35:40 +0100] cupsdFindPolicyOp(p=0xb924c2d0, op=b(Get-Printer-Attributes))
d [30/Nov/2009:13:35:40 +0100] cupsdFindPolicyOp: Found wildcard match...
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: con->uri="/", con->best=0xb924d868((null))
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: op=0(unknown-0000)
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [30/Nov/2009:13:35:40 +0100] add_printer_state_reasons(0xb9285b20[12], 0xb924ee20[FollowPrint-test])
d [30/Nov/2009:13:35:40 +0100] printer-uri-supported="ipp://localhost:631/printers/FollowPrint-test"
d [30/Nov/2009:13:35:40 +0100] copy_attrs(to=0xb9284dc8, from=0xb9250458, ra=0xb9289c60, group=0, quickcopy=0)
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9250538[printer-name,4,42])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9250578[printer-location,4,41])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9245768[printer-info,4,41])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9245858[auth-info-required,4,44])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb92458a0[job-sheets-default,4,42])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb92458f0[device-uri,4,45])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9251650[copies-default,4,21])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9251678[document-format-default,4,49])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb92516a0[job-hold-until-default,4,44])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb92516e0[job-priority-default,4,21])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9251708[number-up-default,4,21])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9251730[orientation-requested-default,4,13])
d [30/Nov/2009:13:35:40 +0100] copy_attrs(to=0xb9284dc8, from=0xb9245930, ra=0xb9289c60, group=0, quickcopy=0)
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9252ba8[printer-make-and-model,4,41])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9253060[media-default,4,44])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb9253388[sides-default,4,44])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb92536c0[printer-commands,4,44])
d [30/Nov/2009:13:35:40 +0100] copy_attribute(0xb9284dc8, 0xb92537e8[finishings-default,4,23])
d [30/Nov/2009:13:35:40 +0100] copy_attrs(to=0xb9284dc8, from=0xb924f6b8, ra=0xb9289c60, group=0, quickcopy=-2147483648)
D [30/Nov/2009:13:35:40 +0100] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/FollowPrint-test) from localhost
d [30/Nov/2009:13:35:40 +0100] cupsdProcessIPPRequest: ippLength(response)=1013
d [30/Nov/2009:13:35:40 +0100] cupsdAddSelect(fd=12, read_cb=0xb76ae000, write_cb=0xb76ab7c0, data=0xb9285b20)
d [30/Nov/2009:13:35:40 +0100] select_timeout(0): 6 seconds to send browse update
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(0), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdWriteClient(con=0xb9285b20(12)) response=0xb9284dc8(2), file=-1 pipe_pid=0 state=7
d [30/Nov/2009:13:35:40 +0100] cupsdAddSelect(fd=12, read_cb=0xb76ae000, write_cb=(nil), data=0xb9285b20)
D [30/Nov/2009:13:35:40 +0100] cupsdSetBusyState: Not busy
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 12 POST /printers/FollowPrint-test HTTP/1.1
D [30/Nov/2009:13:35:40 +0100] cupsdSetBusyState: Active clients
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: uri = "/printers/FollowPrint-test"...
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location / Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: best = /
d [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: con->uri="/printers/FollowPrint-test", con->best=0xb924c0f0(/)
d [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: Authorization=""
D [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: No authentication data provided.
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: con->uri="/printers/FollowPrint-test", con->best=0xb924c0f0(/)
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_ANON, type=None, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=392, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=392, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=363, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=363, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=326, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=326, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=265, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=265, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=236, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=236, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=218, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=218, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=174, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=174, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=158, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=158, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=139, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=139, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=113, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=113, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=92, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=92, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=73, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=73, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=64, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=64, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=38, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=38, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=20, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=20, con->file=-1
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=1, con->http.state=6 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=1, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 12 1.1 Create-Job 1
d [30/Nov/2009:13:35:40 +0100] cupsdProcessIPPRequest(0xb9285b20[12]): operation_id = 0005
D [30/Nov/2009:13:35:40 +0100] Create-Job ipp://localhost:631/printers/FollowPrint-test
d [30/Nov/2009:13:35:40 +0100] create_job(0xb9285b20[12], ipp://localhost:631/printers/FollowPrint-test)
d [30/Nov/2009:13:35:40 +0100] add_job(0xb9285b20[12], 0xb924ee20(FollowPrint-test), (nil)(none/none))
d [30/Nov/2009:13:35:40 +0100] cupsdFindPolicyOp(p=0xb924c2d0, op=5(Create-Job))
d [30/Nov/2009:13:35:40 +0100] cupsdFindPolicyOp: Found exact match...
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: con->uri="/printers/FollowPrint-test", con->best=0xb924d6c8((null))
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: level=CUPSD_AUTH_USER, type=Negotiate, satisfy=CUPSD_AUTH_SATISFY_ALL, num_names=0
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: op=5(Create-Job)
d [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: auth=CUPSD_AUTH_ALLOW...
D [30/Nov/2009:13:35:40 +0100] cupsdIsAuthorized: username=""
D [30/Nov/2009:13:35:40 +0100] Returning HTTP Unauthorized for Create-Job (ipp://localhost:631/printers/FollowPrint-test) from localhost
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: uri = "/printers/FollowPrint-test"...
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location / Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: best = /
d [30/Nov/2009:13:35:40 +0100] cupsdFindPolicyOp(p=0xb924c2d0, op=5(Create-Job))
d [30/Nov/2009:13:35:40 +0100] cupsdFindPolicyOp: Found exact match...
d [30/Nov/2009:13:35:40 +0100] cupsdSendError(con=0xb9285b20(12), code=401, auth_type=4
D [30/Nov/2009:13:35:40 +0100] cupsdSendHeader: 12 WWW-Authenticate: Negotiate
d [30/Nov/2009:13:35:40 +0100] select_timeout(0): 6 seconds to send browse update
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 12 WAITING Closing on EOF
D [30/Nov/2009:13:35:40 +0100] cupsdCloseClient: 12
D [30/Nov/2009:13:35:40 +0100] cupsdSetBusyState: Not busy
d [30/Nov/2009:13:35:40 +0100] cupsdRemoveSelect(fd=12)
d [30/Nov/2009:13:35:40 +0100] cupsdAcceptClient(lis=0xb92475c0(8)) Clients=0
D [30/Nov/2009:13:35:40 +0100] cupsdAcceptClient: 12 from localhost (Domain)
d [30/Nov/2009:13:35:40 +0100] cupsdAddSelect(fd=12, read_cb=0xb76ae000, write_cb=(nil), data=0xb9285b20)
d [30/Nov/2009:13:35:40 +0100] cupsdAcceptClient(lis=0xb92475c0(8)) Clients=1
D [30/Nov/2009:13:35:40 +0100] cupsdAcceptClient: 14 from localhost (Domain)
d [30/Nov/2009:13:35:40 +0100] cupsdAddSelect(fd=14, read_cb=0xb76ae000, write_cb=(nil), data=0xb928c698)
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb9285b20(12)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 12 WAITING Closing on EOF
D [30/Nov/2009:13:35:40 +0100] cupsdCloseClient: 12
d [30/Nov/2009:13:35:40 +0100] cupsdRemoveSelect(fd=12)
d [30/Nov/2009:13:35:40 +0100] cupsdReadClient(con=0xb928c698(14)) con->http.error=0 con->http.used=0, con->http.state=0 con->data_encoding=HTTP_ENCODE_LENGTH, con->data_remaining=0, con->file=-1
D [30/Nov/2009:13:35:40 +0100] cupsdReadClient: 14 POST /printers/FollowPrint-test HTTP/1.1
D [30/Nov/2009:13:35:40 +0100] cupsdSetBusyState: Active clients
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: uri = "/printers/FollowPrint-test"...
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location CUPS_INTERNAL_BROWSE_ACL Limit 0
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin/conf Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location /admin Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: Location / Limit 7f
d [30/Nov/2009:13:35:40 +0100] cupsdFindBest: best = /
d [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: con->uri="/printers/FollowPrint-test", con->best=0xb924c0f0(/)
d [30/Nov/2009:13:35:40 +0100] cupsdAuthorize: Authorization="Negotiate YIIFMwYJKoZIhvcSAQICAQBuggUiMIIFHqADAgEFoQMCAQ6iBwMFACAAAACjggQ0YYIEMDCCBCygAwIBBaEMGwpVU0VSLlVVLlNFoiYwJKADAgEDoR0wGxsEaG9zdBsTZnVsaWd1bGEudXNlci51dS5zZaOCA+0wggPpoAMCARKhAwIBA6KCA9sEggPXtAlq/1t1psctHjg/bsxAOTmcGOh9EJrRzCaEQgAeqOj7JGyKs1kGgxvWLV6fajR1Ok6m9MRcN06mocEgkkVqoJdgSWTPJ1wDPFDDULctzpyZFzDGrg9nP+fjCLDa9PUuf22IrEtzWacMHoyo9lB8Q7Sy3pMBZS4AGXFJAfHbSQyGtnoakAErLDSZR1RygGeqsDs5IJxbumq/2V+YlVlz1dFHaVcvzqMyyEZTfoU0wCSdsR9V7DqQYPpeR2pCLuEip/LIL5oDw88N8yG2gYF/8leWAJtN2ebl+RGnozBR1jwHwGcItJRNG3S9bpVnB2pGXJS2YB/qUzVR98EWZWFJ/6kxrFo8gDGnZehesuasuXyGBR3QKPDwMO9b94lxjv4JI9JNsicbiVd3onC/ajQ3cCf2A+3bBh2KIiRUJ3qzVbQaN88ncE3fDehzDy2RHWIbVInkGf62q7jQsrL2D4fFuRx/+KsdO7Gvb69tC2tSczyhTTHpgISpMGEczF1smbb6OXKlA5T1pXODcaMezVo5AIBoa5qq7SRv/n37sOh+icVsMWRh9Vf6L/mSV32R82UDpiFaj5X25GYyjutS3OKi5/0tHCMwz0psaJ7eW/WtypRToqpu8O/3z/MT3wA7zWrA6PBBdjDlf/ruFxhb0XwWpcpwG826V74HdJn99JkWynQnJr0tlhWTu/T/zIFHIvUxsIMBSK3taFZM7KIVvp6aSJaJVehSO9R49BDrcEVj47vV34zLqiHgd36ZebPBoTOCsJFRuAB3srPX7lUT73uWZr8dm3Y0d5B79U/8AJw2lyIYEg4OOCGxI7plLmm/rnqmiaovg9PB7Eb/tc6Kb9yHipIorQEaOqHGHblEzj6TRS7b8tqUZGw3xxPhssetxX8QvmWzShkOhga7T0KKmpBkmkMiZT+LsDAsLguOpwJq4OsHz9H656DX4voJDdavStSZHU6wJg+3+Sd1IqrtcU/cbYFa2EHulhFCF7p0HuUucNnXo413aoScPUq/yz2GvW/t11Vj1LbJ/JDyGuxsf7BnUTS0xGc8COyOwfVWlmRi5Ob/ZWCW9xwxTRn5bbY6bNfK/3F86JE/bdjjd0PeRUwYNf4UHSniXr/xHElfW/bsA6HoRY+zxbq4iEEoI7s/X7PdIbBjNPONe6a27mrlNqhiwBQtq6oSRde4O96E9HUa+zcd2RDF42Qp3spts3LT9HKLbkjxOX3keqbVuZtQn9FoksqTxcElNUphhav+nu7iAmPPfS17PctE4sFnEchMC9KkkazExhaQ5YysUtdVwZiGpL+eOXX7o1akgdAwgc2gAwIBEqKBxQSBwlqPBXqbnt7TiFhNtMGvGfxsXG+9VOLyblEdLzTRmyWxAic9dGhFr35pDgjBI4qwR5dTwKLk+ewAd1DXYHpuM/S21Ra4qC+kV2xf4SviH+IjHWG1hyrKoV6XAcNRq8qRJeXLMoGCtUzFWCDbNdp31lRhwcaUjAV/Bvfk8wvS6mDFTFvaF4W2paYhFuEU3D3ft8WAkNe84eqcUL2+MykTNiBMkLVXvDjemhk6VOeR5uWeXMePaPpiTu5piwoEw6OLcNj+"