chrome/service/cloud_print/printer_job_handler.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "chrome/service/cloud_print/printer_job_handler.h"
   6
   7 #include "base/bind.h"
   8 #include "base/bind_helpers.h"
   9 #include "base/file_util.h"
  10 #include "base/json/json_reader.h"
  11 #include "base/md5.h"
  12 #include "base/metrics/histogram.h"
  13 #include "base/strings/stringprintf.h"
  14 #include "base/strings/utf_string_conversions.h"
  15 #include "base/values.h"
  16 #include "chrome/common/cloud_print/cloud_print_constants.h"
  17 #include "chrome/common/cloud_print/cloud_print_helpers.h"
  18 #include "chrome/service/cloud_print/cloud_print_service_helpers.h"
  19 #include "chrome/service/cloud_print/job_status_updater.h"
  20 #include "grit/generated_resources.h"
  21 #include "net/base/mime_util.h"
  22 #include "net/http/http_response_headers.h"
  23 #include "net/http/http_status_code.h"
  24 #include "printing/printing_utils.h"
  25 #include "ui/base/l10n/l10n_util.h"
  26 #include "url/gurl.h"
  27
  28 namespace cloud_print {
  29
  30 namespace {
  31
  32 base::subtle::Atomic32 g_total_jobs_started = 0;
  33 base::subtle::Atomic32 g_total_jobs_done = 0;
  34
  35 enum PrinterJobHandlerEvent {
  36   JOB_HANDLER_CHECK_FOR_JOBS,
  37   JOB_HANDLER_START,
  38   JOB_HANDLER_PENDING_TASK,
  39   JOB_HANDLER_PRINTER_UPDATE,
  40   JOB_HANDLER_JOB_CHECK,
  41   JOB_HANDLER_JOB_STARTED,
  42   JOB_HANDLER_VALID_TICKET,
  43   JOB_HANDLER_DATA,
  44   JOB_HANDLER_SET_IN_PROGRESS,
  45   JOB_HANDLER_SET_START_PRINTING,
  46   JOB_HANDLER_START_SPOOLING,
  47   JOB_HANDLER_SPOOLED,
  48   JOB_HANDLER_JOB_COMPLETED,
  49   JOB_HANDLER_INVALID_TICKET,
  50   JOB_HANDLER_INVALID_DATA,
  51   JOB_HANDLER_MAX,
  52 };
  53
  54 }  // namespace
  55
  56 PrinterJobHandler::PrinterInfoFromCloud::PrinterInfoFromCloud()
  57     : current_xmpp_timeout(0), pending_xmpp_timeout(0) {
  58 }
  59
  60 PrinterJobHandler::PrinterJobHandler(
  61     const printing::PrinterBasicInfo& printer_info,
  62     const PrinterInfoFromCloud& printer_info_cloud,
  63     const GURL& cloud_print_server_url,
  64     PrintSystem* print_system,
  65     Delegate* delegate)
  66     : print_system_(print_system),
  67       printer_info_(printer_info),
  68       printer_info_cloud_(printer_info_cloud),
  69       cloud_print_server_url_(cloud_print_server_url),
  70       delegate_(delegate),
  71       local_job_id_(-1),
  72       next_json_data_handler_(NULL),
  73       next_data_handler_(NULL),
  74       server_error_count_(0),
  75       print_thread_("Chrome_CloudPrintJobPrintThread"),
  76       job_handler_message_loop_proxy_(
  77           base::MessageLoopProxy::current()),
  78       shutting_down_(false),
  79       job_check_pending_(false),
  80       printer_update_pending_(true),
  81       task_in_progress_(false),
  82       weak_ptr_factory_(this) {
  83 }
  84
  85 bool PrinterJobHandler::Initialize() {
  86   if (!print_system_->IsValidPrinter(printer_info_.printer_name))
  87     return false;
  88
  89   printer_watcher_ = print_system_->CreatePrinterWatcher(
  90       printer_info_.printer_name);
  91   printer_watcher_->StartWatching(this);
  92   CheckForJobs(kJobFetchReasonStartup);
  93   return true;
  94 }
  95
  96 std::string PrinterJobHandler::GetPrinterName() const {
  97   return printer_info_.printer_name;
  98 }
  99
 100 void PrinterJobHandler::CheckForJobs(const std::string& reason) {
 101   VLOG(1) << "CP_CONNECTOR: Checking for jobs"
 102           << ", printer id: " << printer_info_cloud_.printer_id
 103           << ", reason: " << reason
 104           << ", task in progress: " << task_in_progress_;
 105   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 106                             JOB_HANDLER_CHECK_FOR_JOBS, JOB_HANDLER_MAX);
 107   job_fetch_reason_ = reason;
 108   job_check_pending_ = true;
 109   if (!task_in_progress_) {
 110     base::MessageLoop::current()->PostTask(
 111         FROM_HERE, base::Bind(&PrinterJobHandler::Start, this));
 112   }
 113 }
 114
 115 void PrinterJobHandler::Shutdown() {
 116   VLOG(1) << "CP_CONNECTOR: Shutting down printer job handler"
 117           << ", printer id: " << printer_info_cloud_.printer_id;
 118   Reset();
 119   shutting_down_ = true;
 120   while (!job_status_updater_list_.empty()) {
 121     // Calling Stop() will cause the OnJobCompleted to be called which will
 122     // remove the updater object from the list.
 123     job_status_updater_list_.front()->Stop();
 124   }
 125 }
 126
 127 // CloudPrintURLFetcher::Delegate implementation.
 128 CloudPrintURLFetcher::ResponseAction PrinterJobHandler::HandleRawResponse(
 129     const net::URLFetcher* source,
 130     const GURL& url,
 131     const net::URLRequestStatus& status,
 132     int response_code,
 133     const net::ResponseCookies& cookies,
 134     const std::string& data) {
 135   // 415 (Unsupported media type) error while fetching data from the server
 136   // means data conversion error. Stop fetching process and mark job as error.
 137   if (next_data_handler_ == (&PrinterJobHandler::HandlePrintDataResponse) &&
 138       response_code == net::HTTP_UNSUPPORTED_MEDIA_TYPE) {
 139     VLOG(1) << "CP_CONNECTOR: Job failed (unsupported media type)";
 140     base::MessageLoop::current()->PostTask(
 141         FROM_HERE,
 142         base::Bind(&PrinterJobHandler::JobFailed, this, JOB_DOWNLOAD_FAILED));
 143     return CloudPrintURLFetcher::STOP_PROCESSING;
 144   }
 145   return CloudPrintURLFetcher::CONTINUE_PROCESSING;
 146 }
 147
 148 CloudPrintURLFetcher::ResponseAction PrinterJobHandler::HandleRawData(
 149     const net::URLFetcher* source,
 150     const GURL& url,
 151     const std::string& data) {
 152   if (!next_data_handler_)
 153     return CloudPrintURLFetcher::CONTINUE_PROCESSING;
 154   return (this->*next_data_handler_)(source, url, data);
 155 }
 156
 157 CloudPrintURLFetcher::ResponseAction PrinterJobHandler::HandleJSONData(
 158     const net::URLFetcher* source,
 159     const GURL& url,
 160     base::DictionaryValue* json_data,
 161     bool succeeded) {
 162   DCHECK(next_json_data_handler_);
 163   return (this->*next_json_data_handler_)(source, url, json_data, succeeded);
 164 }
 165
 166 // Mark the job fetch as failed and check if other jobs can be printed
 167 void PrinterJobHandler::OnRequestGiveUp() {
 168   if (job_queue_handler_.JobFetchFailed(job_details_.job_id_)) {
 169     VLOG(1) << "CP_CONNECTOR: Job failed to load (scheduling retry)";
 170     CheckForJobs(kJobFetchReasonFailure);
 171     base::MessageLoop::current()->PostTask(
 172         FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 173   } else {
 174     VLOG(1) << "CP_CONNECTOR: Job failed (giving up after " <<
 175         kNumRetriesBeforeAbandonJob << " retries)";
 176     base::MessageLoop::current()->PostTask(
 177         FROM_HERE,
 178         base::Bind(&PrinterJobHandler::JobFailed, this, JOB_DOWNLOAD_FAILED));
 179   }
 180 }
 181
 182 CloudPrintURLFetcher::ResponseAction PrinterJobHandler::OnRequestAuthError() {
 183   // We got an Auth error and have no idea how long it will take to refresh
 184   // auth information (may take forever). We'll drop current request and
 185   // propagate this error to the upper level. After auth issues will be
 186   // resolved, GCP connector will restart.
 187   OnAuthError();
 188   return CloudPrintURLFetcher::STOP_PROCESSING;
 189 }
 190
 191 std::string PrinterJobHandler::GetAuthHeader() {
 192   return GetCloudPrintAuthHeaderFromStore();
 193 }
 194
 195 // JobStatusUpdater::Delegate implementation
 196 bool PrinterJobHandler::OnJobCompleted(JobStatusUpdater* updater) {
 197   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 198                             JOB_HANDLER_JOB_COMPLETED, JOB_HANDLER_MAX);
 199   UMA_HISTOGRAM_LONG_TIMES("CloudPrint.PrintingTime",
 200                            base::Time::Now() - updater->start_time());
 201   bool ret = false;
 202   base::subtle::NoBarrier_AtomicIncrement(&g_total_jobs_done, 1);
 203   job_queue_handler_.JobDone(job_details_.job_id_);
 204
 205   for (JobStatusUpdaterList::iterator index = job_status_updater_list_.begin();
 206        index != job_status_updater_list_.end(); index++) {
 207     if (index->get() == updater) {
 208       job_status_updater_list_.erase(index);
 209       ret = true;
 210       break;
 211     }
 212   }
 213   return ret;
 214 }
 215
 216 void PrinterJobHandler::OnAuthError() {
 217   base::MessageLoop::current()->PostTask(
 218       FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 219   if (delegate_)
 220     delegate_->OnAuthError();
 221 }
 222
 223 void PrinterJobHandler::OnPrinterDeleted() {
 224   if (delegate_)
 225     delegate_->OnPrinterDeleted(printer_info_cloud_.printer_id);
 226 }
 227
 228 void PrinterJobHandler::OnPrinterChanged() {
 229   printer_update_pending_ = true;
 230   if (!task_in_progress_) {
 231     base::MessageLoop::current()->PostTask(
 232         FROM_HERE, base::Bind(&PrinterJobHandler::Start, this));
 233   }
 234 }
 235
 236 void PrinterJobHandler::OnJobChanged() {
 237   // Some job on the printer changed. Loop through all our JobStatusUpdaters
 238   // and have them check for updates.
 239   for (JobStatusUpdaterList::iterator index = job_status_updater_list_.begin();
 240        index != job_status_updater_list_.end(); index++) {
 241     base::MessageLoop::current()->PostTask(
 242         FROM_HERE, base::Bind(&JobStatusUpdater::UpdateStatus, index->get()));
 243   }
 244 }
 245
 246 void PrinterJobHandler::OnJobSpoolSucceeded(const PlatformJobId& job_id) {
 247   DCHECK(base::MessageLoop::current() == print_thread_.message_loop());
 248   job_spooler_->AddRef();
 249   print_thread_.message_loop()->ReleaseSoon(FROM_HERE, job_spooler_.get());
 250   job_spooler_ = NULL;
 251   job_handler_message_loop_proxy_->PostTask(
 252       FROM_HERE, base::Bind(&PrinterJobHandler::JobSpooled, this, job_id));
 253 }
 254
 255 void PrinterJobHandler::OnJobSpoolFailed() {
 256   DCHECK(base::MessageLoop::current() == print_thread_.message_loop());
 257   job_spooler_->AddRef();
 258   print_thread_.message_loop()->ReleaseSoon(FROM_HERE, job_spooler_.get());
 259   job_spooler_ = NULL;
 260   VLOG(1) << "CP_CONNECTOR: Job failed (spool failed)";
 261   job_handler_message_loop_proxy_->PostTask(
 262       FROM_HERE, base::Bind(&PrinterJobHandler::JobFailed, this, JOB_FAILED));
 263 }
 264
 265 // static
 266 void PrinterJobHandler::ReportsStats() {
 267   base::subtle::Atomic32 started =
 268       base::subtle::NoBarrier_AtomicExchange(&g_total_jobs_started, 0);
 269   base::subtle::Atomic32 done =
 270       base::subtle::NoBarrier_AtomicExchange(&g_total_jobs_done, 0);
 271   UMA_HISTOGRAM_COUNTS_100("CloudPrint.JobsStartedPerInterval", started);
 272   UMA_HISTOGRAM_COUNTS_100("CloudPrint.JobsDonePerInterval", done);
 273 }
 274
 275 PrinterJobHandler::~PrinterJobHandler() {
 276   if (printer_watcher_.get())
 277     printer_watcher_->StopWatching();
 278 }
 279
 280 // Begin Response handlers
 281 CloudPrintURLFetcher::ResponseAction
 282 PrinterJobHandler::HandlePrinterUpdateResponse(
 283     const net::URLFetcher* source,
 284     const GURL& url,
 285     base::DictionaryValue* json_data,
 286     bool succeeded) {
 287   VLOG(1) << "CP_CONNECTOR: Handling printer update response"
 288           << ", printer id: " << printer_info_cloud_.printer_id;
 289   // We are done here. Go to the Stop state
 290   VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
 291           << ", printer id: " << printer_info_cloud_.printer_id;
 292   base::MessageLoop::current()->PostTask(
 293       FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 294   return CloudPrintURLFetcher::STOP_PROCESSING;
 295 }
 296
 297 CloudPrintURLFetcher::ResponseAction
 298 PrinterJobHandler::HandleJobMetadataResponse(
 299     const net::URLFetcher* source,
 300     const GURL& url,
 301     base::DictionaryValue* json_data,
 302     bool succeeded) {
 303   VLOG(1) << "CP_CONNECTOR: Handling job metadata response"
 304           << ", printer id: " << printer_info_cloud_.printer_id;
 305   bool job_available = false;
 306   if (succeeded) {
 307     std::vector<JobDetails> jobs;
 308     job_queue_handler_.GetJobsFromQueue(json_data, &jobs);
 309     if (!jobs.empty()) {
 310       if (jobs[0].time_remaining_ == base::TimeDelta()) {
 311         job_available = true;
 312         job_details_ = jobs[0];
 313         job_start_time_ = base::Time::Now();
 314         base::subtle::NoBarrier_AtomicIncrement(&g_total_jobs_started, 1);
 315         UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 316                                   JOB_HANDLER_JOB_STARTED, JOB_HANDLER_MAX);
 317         SetNextDataHandler(&PrinterJobHandler::HandlePrintTicketResponse);
 318         request_ = CloudPrintURLFetcher::Create();
 319         request_->StartGetRequest(CloudPrintURLFetcher::REQUEST_TICKET,
 320             GURL(job_details_.print_ticket_url_), this, kJobDataMaxRetryCount,
 321             std::string());
 322       } else {
 323         job_available = false;
 324         base::MessageLoop::current()->PostDelayedTask(
 325             FROM_HERE,
 326             base::Bind(&PrinterJobHandler::RunScheduledJobCheck, this),
 327             jobs[0].time_remaining_);
 328       }
 329     }
 330   }
 331
 332   if (!job_available) {
 333     // If no jobs are available, go to the Stop state.
 334     VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
 335             << ", printer id: " << printer_info_cloud_.printer_id;
 336     base::MessageLoop::current()->PostTask(
 337         FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 338   }
 339   return CloudPrintURLFetcher::STOP_PROCESSING;
 340 }
 341
 342 CloudPrintURLFetcher::ResponseAction
 343 PrinterJobHandler::HandlePrintTicketResponse(const net::URLFetcher* source,
 344                                              const GURL& url,
 345                                              const std::string& data) {
 346   VLOG(1) << "CP_CONNECTOR: Handling print ticket response"
 347           << ", printer id: " << printer_info_cloud_.printer_id;
 348   if (print_system_->ValidatePrintTicket(printer_info_.printer_name, data)) {
 349     UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 350                               JOB_HANDLER_VALID_TICKET, JOB_HANDLER_MAX);
 351     job_details_.print_ticket_ = data;
 352     SetNextDataHandler(&PrinterJobHandler::HandlePrintDataResponse);
 353     request_ = CloudPrintURLFetcher::Create();
 354     std::string accept_headers = "Accept: ";
 355     accept_headers += print_system_->GetSupportedMimeTypes();
 356     request_->StartGetRequest(CloudPrintURLFetcher::REQUEST_DATA,
 357         GURL(job_details_.print_data_url_), this, kJobDataMaxRetryCount,
 358         accept_headers);
 359   } else {
 360     UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 361                               JOB_HANDLER_INVALID_TICKET, JOB_HANDLER_MAX);
 362     // The print ticket was not valid. We are done here.
 363     ValidatePrintTicketFailed();
 364   }
 365   return CloudPrintURLFetcher::STOP_PROCESSING;
 366 }
 367
 368 CloudPrintURLFetcher::ResponseAction
 369 PrinterJobHandler::HandlePrintDataResponse(const net::URLFetcher* source,
 370                                            const GURL& url,
 371                                            const std::string& data) {
 372   VLOG(1) << "CP_CONNECTOR: Handling print data response"
 373           << ", printer id: " << printer_info_cloud_.printer_id;
 374   if (base::CreateTemporaryFile(&job_details_.print_data_file_path_)) {
 375     UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", JOB_HANDLER_DATA,
 376                               JOB_HANDLER_MAX);
 377     int ret = file_util::WriteFile(job_details_.print_data_file_path_,
 378                                    data.c_str(), data.length());
 379     source->GetResponseHeaders()->GetMimeType(
 380         &job_details_.print_data_mime_type_);
 381     DCHECK(ret == static_cast<int>(data.length()));
 382     if (ret == static_cast<int>(data.length())) {
 383       UpdateJobStatus(PRINT_JOB_STATUS_IN_PROGRESS, JOB_SUCCESS);
 384       return CloudPrintURLFetcher::STOP_PROCESSING;
 385     }
 386   }
 387   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 388                             JOB_HANDLER_INVALID_DATA, JOB_HANDLER_MAX);
 389
 390   // If we are here, then there was an error in saving the print data, bail out
 391   // here.
 392   VLOG(1) << "CP_CONNECTOR: Error saving print data"
 393           << ", printer id: " << printer_info_cloud_.printer_id;
 394   base::MessageLoop::current()->PostTask(
 395       FROM_HERE, base::Bind(&PrinterJobHandler::JobFailed, this,
 396                             JOB_DOWNLOAD_FAILED));
 397   return CloudPrintURLFetcher::STOP_PROCESSING;
 398 }
 399
 400 CloudPrintURLFetcher::ResponseAction
 401 PrinterJobHandler::HandleInProgressStatusUpdateResponse(
 402     const net::URLFetcher* source,
 403     const GURL& url,
 404     base::DictionaryValue* json_data,
 405     bool succeeded) {
 406   VLOG(1) << "CP_CONNECTOR: Handling success status update response"
 407           << ", printer id: " << printer_info_cloud_.printer_id;
 408   base::MessageLoop::current()->PostTask(
 409       FROM_HERE, base::Bind(&PrinterJobHandler::StartPrinting, this));
 410   return CloudPrintURLFetcher::STOP_PROCESSING;
 411 }
 412
 413 CloudPrintURLFetcher::ResponseAction
 414 PrinterJobHandler::HandleFailureStatusUpdateResponse(
 415     const net::URLFetcher* source,
 416     const GURL& url,
 417     base::DictionaryValue* json_data,
 418     bool succeeded) {
 419   VLOG(1) << "CP_CONNECTOR: Handling failure status update response"
 420           << ", printer id: " << printer_info_cloud_.printer_id;
 421   base::MessageLoop::current()->PostTask(
 422       FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 423   return CloudPrintURLFetcher::STOP_PROCESSING;
 424 }
 425
 426 void PrinterJobHandler::Start() {
 427   VLOG(1) << "CP_CONNECTOR: Starting printer job handler"
 428           << ", printer id: " << printer_info_cloud_.printer_id
 429           << ", task in progress: " << task_in_progress_;
 430   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 431                             JOB_HANDLER_START, JOB_HANDLER_MAX);
 432   if (task_in_progress_) {
 433     // Multiple Starts can get posted because of multiple notifications
 434     // We want to ignore the other ones that happen when a task is in progress.
 435     return;
 436   }
 437   Reset();
 438   if (!shutting_down_) {
 439     // Check if we have work to do.
 440     if (HavePendingTasks()) {
 441       UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 442                                 JOB_HANDLER_PENDING_TASK, JOB_HANDLER_MAX);
 443       if (!task_in_progress_ && printer_update_pending_) {
 444         UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 445                                   JOB_HANDLER_PRINTER_UPDATE, JOB_HANDLER_MAX);
 446         printer_update_pending_ = false;
 447         task_in_progress_ = UpdatePrinterInfo();
 448         VLOG(1) << "CP_CONNECTOR: Changed task in progress"
 449                 << ", printer id: " << printer_info_cloud_.printer_id
 450                 << ", task in progress: " << task_in_progress_;
 451       }
 452       if (!task_in_progress_ && job_check_pending_) {
 453         UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 454                                   JOB_HANDLER_JOB_CHECK, JOB_HANDLER_MAX);
 455         task_in_progress_ = true;
 456         VLOG(1) << "CP_CONNECTOR: Changed task in progress"
 457                 ", printer id: " << printer_info_cloud_.printer_id
 458                 << ", task in progress: " << task_in_progress_;
 459         job_check_pending_ = false;
 460         // We need to fetch any pending jobs for this printer
 461         SetNextJSONHandler(&PrinterJobHandler::HandleJobMetadataResponse);
 462         request_ = CloudPrintURLFetcher::Create();
 463         request_->StartGetRequest(
 464             CloudPrintURLFetcher::REQUEST_JOB_FETCH,
 465             GetUrlForJobFetch(
 466                 cloud_print_server_url_, printer_info_cloud_.printer_id,
 467                 job_fetch_reason_),
 468             this,
 469             kCloudPrintAPIMaxRetryCount,
 470             std::string());
 471         last_job_fetch_time_ = base::TimeTicks::Now();
 472         VLOG(1) << "CP_CONNECTOR: Last job fetch time"
 473                 << ", printer name: " << printer_info_.printer_name.c_str()
 474                 << ", timestamp: " << last_job_fetch_time_.ToInternalValue();
 475         job_fetch_reason_.clear();
 476       }
 477     }
 478   }
 479 }
 480
 481 void PrinterJobHandler::Stop() {
 482   VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
 483           << ", printer id: " << printer_info_cloud_.printer_id;
 484   task_in_progress_ = false;
 485   VLOG(1) << "CP_CONNECTOR: Changed task in progress"
 486           << ", printer id: " << printer_info_cloud_.printer_id
 487           << ", task in progress: " << task_in_progress_;
 488   Reset();
 489   if (HavePendingTasks()) {
 490     base::MessageLoop::current()->PostTask(
 491         FROM_HERE, base::Bind(&PrinterJobHandler::Start, this));
 492   }
 493 }
 494
 495 void PrinterJobHandler::StartPrinting() {
 496   VLOG(1) << "CP_CONNECTOR: Starting printing"
 497           << ", printer id: " << printer_info_cloud_.printer_id;
 498   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 499                             JOB_HANDLER_SET_START_PRINTING, JOB_HANDLER_MAX);
 500   // We are done with the request object for now.
 501   request_ = NULL;
 502   if (!shutting_down_) {
 503 #if defined(OS_WIN)
 504     print_thread_.init_com_with_mta(true);
 505 #endif
 506     if (!print_thread_.Start()) {
 507       VLOG(1) << "CP_CONNECTOR: Failed to start print thread"
 508               << ", printer id: " << printer_info_cloud_.printer_id;
 509       JobFailed(JOB_FAILED);
 510     } else {
 511       print_thread_.message_loop()->PostTask(
 512           FROM_HERE, base::Bind(&PrinterJobHandler::DoPrint, this, job_details_,
 513                                 printer_info_.printer_name));
 514     }
 515   }
 516 }
 517
 518 void PrinterJobHandler::Reset() {
 519   job_details_.Clear();
 520   request_ = NULL;
 521   print_thread_.Stop();
 522 }
 523
 524 void PrinterJobHandler::UpdateJobStatus(PrintJobStatus status,
 525                                         PrintJobError error) {
 526   VLOG(1) << "CP_CONNECTOR: Updating job status"
 527           << ", printer id: " << printer_info_cloud_.printer_id
 528           << ", job id: " << job_details_.job_id_
 529           << ", job status: " << status;
 530   if (shutting_down_) {
 531     VLOG(1) << "CP_CONNECTOR: Job status update aborted (shutting down)"
 532             << ", printer id: " << printer_info_cloud_.printer_id
 533             << ", job id: " << job_details_.job_id_;
 534     return;
 535   }
 536   if (job_details_.job_id_.empty()) {
 537     VLOG(1) << "CP_CONNECTOR: Job status update aborted (empty job id)"
 538             << ", printer id: " << printer_info_cloud_.printer_id;
 539     return;
 540   }
 541
 542   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobStatus", error, JOB_MAX);
 543
 544   if (error == JOB_SUCCESS) {
 545     DCHECK_EQ(status, PRINT_JOB_STATUS_IN_PROGRESS);
 546     UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 547                               JOB_HANDLER_SET_IN_PROGRESS, JOB_HANDLER_MAX);
 548     SetNextJSONHandler(
 549         &PrinterJobHandler::HandleInProgressStatusUpdateResponse);
 550   } else {
 551     SetNextJSONHandler(
 552         &PrinterJobHandler::HandleFailureStatusUpdateResponse);
 553   }
 554   request_ = CloudPrintURLFetcher::Create();
 555   request_->StartGetRequest(
 556       CloudPrintURLFetcher::REQUEST_UPDATE_JOB,
 557       GetUrlForJobStatusUpdate(cloud_print_server_url_, job_details_.job_id_,
 558                                status, error),
 559       this, kCloudPrintAPIMaxRetryCount, std::string());
 560 }
 561
 562 void PrinterJobHandler::RunScheduledJobCheck() {
 563   CheckForJobs(kJobFetchReasonRetry);
 564 }
 565
 566 void PrinterJobHandler::SetNextJSONHandler(JSONDataHandler handler) {
 567   next_json_data_handler_ = handler;
 568   next_data_handler_ = NULL;
 569 }
 570
 571 void PrinterJobHandler::SetNextDataHandler(DataHandler handler) {
 572   next_data_handler_ = handler;
 573   next_json_data_handler_ = NULL;
 574 }
 575
 576 void PrinterJobHandler::JobFailed(PrintJobError error) {
 577   VLOG(1) << "CP_CONNECTOR: Job failed"
 578           << ", printer id: " << printer_info_cloud_.printer_id
 579           << ", job id: " << job_details_.job_id_
 580           << ", error: " << error;
 581   if (!shutting_down_) {
 582     UpdateJobStatus(PRINT_JOB_STATUS_ERROR, error);
 583     // This job failed, but others may be pending.  Schedule a check.
 584     job_check_pending_ = true;
 585     job_fetch_reason_ = kJobFetchReasonFailure;
 586   }
 587 }
 588
 589 void PrinterJobHandler::JobSpooled(PlatformJobId local_job_id) {
 590   VLOG(1) << "CP_CONNECTOR: Job spooled"
 591           << ", printer id: " << printer_info_cloud_.printer_id
 592           << ", job id: " << local_job_id;
 593   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", JOB_HANDLER_SPOOLED,
 594                             JOB_HANDLER_MAX);
 595   UMA_HISTOGRAM_LONG_TIMES("CloudPrint.SpoolingTime",
 596                            base::Time::Now() - spooling_start_time_);
 597   if (shutting_down_)
 598     return;
 599
 600   local_job_id_ = local_job_id;
 601   print_thread_.Stop();
 602
 603   // The print job has been spooled locally. We now need to create an object
 604   // that monitors the status of the job and updates the server.
 605   scoped_refptr<JobStatusUpdater> job_status_updater(
 606       new JobStatusUpdater(printer_info_.printer_name, job_details_.job_id_,
 607                             local_job_id_, cloud_print_server_url_,
 608                             print_system_.get(), this));
 609   job_status_updater_list_.push_back(job_status_updater);
 610   base::MessageLoop::current()->PostTask(
 611       FROM_HERE,
 612       base::Bind(&JobStatusUpdater::UpdateStatus, job_status_updater.get()));
 613
 614   CheckForJobs(kJobFetchReasonQueryMore);
 615
 616   VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
 617           << ", printer id: " << printer_info_cloud_.printer_id;
 618   base::MessageLoop::current()->PostTask(
 619       FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 620 }
 621
 622 bool PrinterJobHandler::UpdatePrinterInfo() {
 623   if (!printer_watcher_.get()) {
 624     LOG(ERROR) << "CP_CONNECTOR: Printer watcher is missing."
 625                << " Check printer server url for printer id: "
 626                << printer_info_cloud_.printer_id;
 627     return false;
 628   }
 629
 630   VLOG(1) << "CP_CONNECTOR: Updating printer info"
 631           << ", printer id: " << printer_info_cloud_.printer_id;
 632   // We need to update the parts of the printer info that have changed
 633   // (could be printer name, description, status or capabilities).
 634   // First asynchronously fetch the capabilities.
 635   printing::PrinterBasicInfo printer_info;
 636   printer_watcher_->GetCurrentPrinterInfo(&printer_info);
 637
 638   // Asynchronously fetch the printer caps and defaults. The story will
 639   // continue in OnReceivePrinterCaps.
 640   print_system_->GetPrinterCapsAndDefaults(
 641       printer_info.printer_name.c_str(),
 642       base::Bind(&PrinterJobHandler::OnReceivePrinterCaps,
 643                  weak_ptr_factory_.GetWeakPtr()));
 644
 645   // While we are waiting for the data, pretend we have work to do and return
 646   // true.
 647   return true;
 648 }
 649
 650 bool PrinterJobHandler::HavePendingTasks() {
 651   return (job_check_pending_ || printer_update_pending_);
 652 }
 653
 654 void PrinterJobHandler::ValidatePrintTicketFailed() {
 655   if (!shutting_down_) {
 656     LOG(ERROR) << "CP_CONNECTOR: Failed validating print ticket"
 657                << ", printer name: " << printer_info_.printer_name
 658                << ", job id: " << job_details_.job_id_;
 659     JobFailed(JOB_VALIDATE_TICKET_FAILED);
 660   }
 661 }
 662
 663 void PrinterJobHandler::OnReceivePrinterCaps(
 664     bool succeeded,
 665     const std::string& printer_name,
 666     const printing::PrinterCapsAndDefaults& caps_and_defaults) {
 667   printing::PrinterBasicInfo printer_info;
 668   if (printer_watcher_.get())
 669     printer_watcher_->GetCurrentPrinterInfo(&printer_info);
 670
 671   std::string post_data;
 672   std::string mime_boundary;
 673   CreateMimeBoundaryForUpload(&mime_boundary);
 674
 675   if (succeeded) {
 676     std::string caps_hash =
 677         base::MD5String(caps_and_defaults.printer_capabilities);
 678     if (caps_hash != printer_info_cloud_.caps_hash) {
 679       // Hashes don't match, we need to upload new capabilities (the defaults
 680       // go for free along with the capabilities)
 681       printer_info_cloud_.caps_hash = caps_hash;
 682       net::AddMultipartValueForUpload(kPrinterCapsValue,
 683           caps_and_defaults.printer_capabilities, mime_boundary,
 684           caps_and_defaults.caps_mime_type, &post_data);
 685       net::AddMultipartValueForUpload(kPrinterDefaultsValue,
 686           caps_and_defaults.printer_defaults, mime_boundary,
 687           caps_and_defaults.defaults_mime_type, &post_data);
 688       net::AddMultipartValueForUpload(kPrinterCapsHashValue,
 689           caps_hash, mime_boundary, std::string(), &post_data);
 690     }
 691   } else {
 692     LOG(ERROR) << "Failed to get printer caps and defaults"
 693                << ", printer name: " << printer_name;
 694   }
 695
 696   std::string tags_hash = GetHashOfPrinterInfo(printer_info);
 697   if (tags_hash != printer_info_cloud_.tags_hash) {
 698     printer_info_cloud_.tags_hash = tags_hash;
 699     post_data += GetPostDataForPrinterInfo(printer_info, mime_boundary);
 700     // Remove all the existing proxy tags.
 701     std::string cp_tag_wildcard(kCloudPrintServiceProxyTagPrefix);
 702     cp_tag_wildcard += ".*";
 703     net::AddMultipartValueForUpload(kPrinterRemoveTagValue,
 704         cp_tag_wildcard, mime_boundary, std::string(), &post_data);
 705
 706     if (!last_caps_update_time_.is_null()) {
 707       UMA_HISTOGRAM_CUSTOM_TIMES(
 708           "CloudPrint.CapsUpdateInterval",
 709           base::Time::Now() - last_caps_update_time_,
 710           base::TimeDelta::FromMilliseconds(1),
 711           base::TimeDelta::FromDays(7), 50);
 712     }
 713     last_caps_update_time_ = base::Time::Now();
 714   }
 715
 716   if (printer_info.printer_name != printer_info_.printer_name) {
 717     net::AddMultipartValueForUpload(kPrinterNameValue,
 718         printer_info.printer_name, mime_boundary, std::string(), &post_data);
 719   }
 720   if (printer_info.printer_description != printer_info_.printer_description) {
 721     net::AddMultipartValueForUpload(kPrinterDescValue,
 722       printer_info.printer_description, mime_boundary,
 723       std::string(), &post_data);
 724   }
 725   if (printer_info.printer_status != printer_info_.printer_status) {
 726     net::AddMultipartValueForUpload(kPrinterStatusValue,
 727         base::StringPrintf("%d", printer_info.printer_status), mime_boundary,
 728         std::string(), &post_data);
 729   }
 730
 731   // Add local_settings with a current XMPP ping interval.
 732   if (printer_info_cloud_.pending_xmpp_timeout != 0) {
 733     DCHECK(kMinXmppPingTimeoutSecs <= printer_info_cloud_.pending_xmpp_timeout);
 734     net::AddMultipartValueForUpload(kPrinterLocalSettingsValue,
 735         base::StringPrintf(kUpdateLocalSettingsXmppPingFormat,
 736             printer_info_cloud_.current_xmpp_timeout),
 737         mime_boundary, std::string(), &post_data);
 738   }
 739
 740   printer_info_ = printer_info;
 741   if (!post_data.empty()) {
 742     net::AddMultipartFinalDelimiterForUpload(mime_boundary, &post_data);
 743     std::string mime_type("multipart/form-data; boundary=");
 744     mime_type += mime_boundary;
 745     SetNextJSONHandler(&PrinterJobHandler::HandlePrinterUpdateResponse);
 746     request_ = CloudPrintURLFetcher::Create();
 747     request_->StartPostRequest(
 748         CloudPrintURLFetcher::REQUEST_UPDATE_PRINTER,
 749         GetUrlForPrinterUpdate(
 750             cloud_print_server_url_, printer_info_cloud_.printer_id),
 751         this,
 752         kCloudPrintAPIMaxRetryCount,
 753         mime_type,
 754         post_data,
 755         std::string());
 756   } else {
 757     // We are done here. Go to the Stop state
 758     VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
 759             << ", printer name: " << printer_name;
 760     base::MessageLoop::current()->PostTask(
 761         FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
 762   }
 763 }
 764
 765 // The following methods are called on |print_thread_|. It is not safe to
 766 // access any members other than |job_handler_message_loop_proxy_|,
 767 // |job_spooler_| and |print_system_|.
 768 void PrinterJobHandler::DoPrint(const JobDetails& job_details,
 769                                 const std::string& printer_name) {
 770   job_spooler_ = print_system_->CreateJobSpooler();
 771   UMA_HISTOGRAM_LONG_TIMES("CloudPrint.PrepareTime",
 772                            base::Time::Now() - job_start_time_);
 773   DCHECK(job_spooler_.get());
 774   if (!job_spooler_.get())
 775     return;
 776   base::string16 document_name = printing::SimplifyDocumentTitle(
 777       base::UTF8ToUTF16(job_details.job_title_));
 778   if (document_name.empty()) {
 779     document_name = printing::SimplifyDocumentTitle(
 780         l10n_util::GetStringUTF16(IDS_DEFAULT_PRINT_DOCUMENT_TITLE));
 781   }
 782   UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent",
 783                             JOB_HANDLER_START_SPOOLING, JOB_HANDLER_MAX);
 784   spooling_start_time_ = base::Time::Now();
 785   if (!job_spooler_->Spool(job_details.print_ticket_,
 786                            job_details.print_data_file_path_,
 787                            job_details.print_data_mime_type_,
 788                            printer_name,
 789                            base::UTF16ToUTF8(document_name),
 790                            job_details.tags_,
 791                            this)) {
 792     OnJobSpoolFailed();
 793   }
 794 }
 795
 796 }  // namespace cloud_print