From 21f36711d9982978da9d7c64a1aaec7f81d16010 Mon Sep 17 00:00:00 2001 From: msweet Date: Thu, 30 May 2013 00:41:43 +0000 Subject: [PATCH] Go back to non-blocking ippWrite. Add some more debug logging. Normalize some of the logging to consistently have a [Client NNN] prefix. git-svn-id: svn+ssh://src.apple.com/svn/cups/cups.org/trunk@10998 a1ca3aef-8c08-0410-bb20-df032aa958be --- cups/ipp.c | 5 +++-- scheduler/client.c | 26 ++++++++++++++++++-------- scheduler/ipp.c | 19 +++++++++++-------- 3 files changed, 32 insertions(+), 18 deletions(-) diff --git a/cups/ipp.c b/cups/ipp.c index fd6f45f40..335020d3d 100644 --- a/cups/ipp.c +++ b/cups/ipp.c @@ -6348,10 +6348,11 @@ ippWriteIO(void *dst, /* I - Destination */ } /* - * If blocking is disabled, stop here... + * If blocking is disabled and we aren't at the end of the attribute + * list, stop here... */ - if (!blocking) + if (!blocking && ipp->current) break; } diff --git a/scheduler/client.c b/scheduler/client.c index b5cf43319..55bff4236 100644 --- a/scheduler/client.c +++ b/scheduler/client.c @@ -2882,9 +2882,7 @@ cupsdWriteClient(cupsd_client_t *con) /* I - Client connection */ * Write a single attribute or the IPP message header... */ -// ipp_state = ippWrite(HTTP(con), con->response); - ipp_state = ippWriteIO(HTTP(con), (ipp_iocb_t)httpWrite2, 1, NULL, - con->response); + ipp_state = ippWrite(HTTP(con), con->response); /* * If the write buffer has been flushed, stop buffering up attributes... @@ -2896,15 +2894,25 @@ cupsdWriteClient(cupsd_client_t *con) /* I - Client connection */ while (ipp_state != IPP_STATE_DATA && ipp_state != IPP_STATE_ERROR); cupsdLogMessage(CUPSD_LOG_DEBUG, - "[Client %d] Writing IPP response, ipp_state=%d, old " - "wused=%d, new wused=%d", con->http.fd, ipp_state, wused, - con->http.wused); + "[Client %d] Writing IPP response, ipp_state=%s, old " + "wused=%d, new wused=%d", con->http.fd, + ipp_state == IPP_STATE_ERROR ? "ERROR" : + ipp_state == IPP_STATE_IDLE ? "IDLE" : + ipp_state == IPP_STATE_HEADER ? "HEADER" : + ipp_state == IPP_STATE_ATTRIBUTE ? "ATTRIBUTE" : "DATA", + wused, con->http.wused); if (con->http.wused > 0) httpFlushWrite(HTTP(con)); bytes = ipp_state != IPP_STATE_ERROR && (con->file >= 0 || ipp_state != IPP_STATE_DATA); + + cupsdLogMessage(CUPSD_LOG_DEBUG, + "[Client %d] bytes=%d, http_state=%d, " + "data_remaining=" CUPS_LLFMT, + con->http.fd, (int)bytes, con->http.state, + CUPS_LLCAST con->http.data_remaining); } else if ((bytes = read(con->file, con->header + con->header_used, sizeof(con->header) - con->header_used)) > 0) @@ -3049,7 +3057,8 @@ cupsdWriteClient(cupsd_client_t *con) /* I - Client connection */ } if (bytes <= 0 || - (con->http.state != HTTP_STATE_GET_SEND && con->http.state != HTTP_STATE_POST_SEND)) + (con->http.state != HTTP_STATE_GET_SEND && + con->http.state != HTTP_STATE_POST_SEND)) { if (!con->sent_header && con->pipe_pid) cupsdSendError(con, HTTP_SERVER_ERROR, CUPSD_AUTH_NONE); @@ -3059,7 +3068,8 @@ cupsdWriteClient(cupsd_client_t *con) /* I - Client connection */ httpFlushWrite(HTTP(con)); - if (con->http.data_encoding == HTTP_ENCODING_CHUNKED && con->sent_header == 1) + if (con->http.data_encoding == HTTP_ENCODING_CHUNKED && + con->sent_header == 1) { if (httpWrite2(HTTP(con), "", 0) < 0) { diff --git a/scheduler/ipp.c b/scheduler/ipp.c index 83041d64b..906f6922e 100644 --- a/scheduler/ipp.c +++ b/scheduler/ipp.c @@ -707,17 +707,13 @@ cupsdProcessIPPRequest( >= IPP_BAD_REQUEST && con->response->request.status.status_code != IPP_NOT_FOUND ? CUPSD_LOG_ERROR : CUPSD_LOG_DEBUG, - "Returning IPP %s for %s (%s) from %s", + "[Client %d] Returning IPP %s for %s (%s) from %s", + con->http.fd, ippErrorString(con->response->request.status.status_code), ippOpString(con->request->request.op.operation_id), uri ? uri->values[0].string.text : "no URI", con->http.hostname); - if (LogLevel == CUPSD_LOG_DEBUG2) - cupsdLogMessage(CUPSD_LOG_DEBUG2, - "cupsdProcessIPPRequest: ippLength(response)=%ld", - (long)ippLength(con->response)); - if (cupsdSendHeader(con, HTTP_OK, "application/ipp", CUPSD_AUTH_NONE)) { #ifdef CUPSD_USE_CHUNKING @@ -731,6 +727,10 @@ cupsdProcessIPPRequest( if (con->http.version == HTTP_1_1) { + cupsdLogMessage(CUPSD_LOG_DEBUG, + "[Client %d] Transfer-Encoding: chunked", + con->http.fd); + if (httpPrintf(HTTP(con), "Transfer-Encoding: chunked\r\n\r\n") < 0) return (0); @@ -755,6 +755,9 @@ cupsdProcessIPPRequest( length += fileinfo.st_size; } + cupsdLogMessage(CUPSD_LOG_DEBUG, + "[Client %d] Content-Length: " CUPS_LLFMT, + con->http.fd, CUPS_LLCAST length); if (httpPrintf(HTTP(con), "Content-Length: " CUPS_LLFMT "\r\n\r\n", CUPS_LLCAST length) < 0) return (0); @@ -9582,8 +9585,8 @@ send_http_error( uri = ippFindAttribute(con->request, "job-uri", IPP_TAG_URI); cupsdLogMessage(status == HTTP_FORBIDDEN ? CUPSD_LOG_ERROR : CUPSD_LOG_DEBUG, - "Returning HTTP %s for %s (%s) from %s", - httpStatus(status), + "[Client %d] Returning HTTP %s for %s (%s) from %s", + con->http.fd, httpStatus(status), con->request ? ippOpString(con->request->request.op.operation_id) : "no operation-id", -- 2.39.2