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