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

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",