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/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/grit/generated_resources.h" 19 #include "chrome/service/cloud_print/cloud_print_service_helpers.h" 20 #include "chrome/service/cloud_print/job_status_updater.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 if (print_system_->UseCddAndCjt()) { 320 request_->StartGetRequest( 321 CloudPrintURLFetcher::REQUEST_TICKET, 322 GetUrlForJobCjt(cloud_print_server_url_, job_details_.job_id_, 323 job_fetch_reason_), 324 this, kJobDataMaxRetryCount, std::string()); 325 } else { 326 request_->StartGetRequest( 327 CloudPrintURLFetcher::REQUEST_TICKET, 328 GURL(job_details_.print_ticket_url_), this, kJobDataMaxRetryCount, 329 std::string()); 330 } 331 } else { 332 job_available = false; 333 base::MessageLoop::current()->PostDelayedTask( 334 FROM_HERE, 335 base::Bind(&PrinterJobHandler::RunScheduledJobCheck, this), 336 jobs[0].time_remaining_); 337 } 338 } 339 } 340 341 if (!job_available) { 342 // If no jobs are available, go to the Stop state. 343 VLOG(1) << "CP_CONNECTOR: Stopping printer job handler" 344 << ", printer id: " << printer_info_cloud_.printer_id; 345 base::MessageLoop::current()->PostTask( 346 FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); 347 } 348 return CloudPrintURLFetcher::STOP_PROCESSING; 349 } 350 351 CloudPrintURLFetcher::ResponseAction 352 PrinterJobHandler::HandlePrintTicketResponse(const net::URLFetcher* source, 353 const GURL& url, 354 const std::string& data) { 355 VLOG(1) << "CP_CONNECTOR: Handling print ticket response" 356 << ", printer id: " << printer_info_cloud_.printer_id; 357 std::string mime_type; 358 source->GetResponseHeaders()->GetMimeType(&mime_type); 359 if (print_system_->ValidatePrintTicket(printer_info_.printer_name, data, 360 mime_type)) { 361 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 362 JOB_HANDLER_VALID_TICKET, JOB_HANDLER_MAX); 363 job_details_.print_ticket_ = data; 364 job_details_.print_ticket_mime_type_ = mime_type; 365 SetNextDataHandler(&PrinterJobHandler::HandlePrintDataResponse); 366 request_ = CloudPrintURLFetcher::Create(); 367 std::string accept_headers = "Accept: "; 368 accept_headers += print_system_->GetSupportedMimeTypes(); 369 request_->StartGetRequest(CloudPrintURLFetcher::REQUEST_DATA, 370 GURL(job_details_.print_data_url_), this, kJobDataMaxRetryCount, 371 accept_headers); 372 } else { 373 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 374 JOB_HANDLER_INVALID_TICKET, JOB_HANDLER_MAX); 375 // The print ticket was not valid. We are done here. 376 ValidatePrintTicketFailed(); 377 } 378 return CloudPrintURLFetcher::STOP_PROCESSING; 379 } 380 381 CloudPrintURLFetcher::ResponseAction 382 PrinterJobHandler::HandlePrintDataResponse(const net::URLFetcher* source, 383 const GURL& url, 384 const std::string& data) { 385 VLOG(1) << "CP_CONNECTOR: Handling print data response" 386 << ", printer id: " << printer_info_cloud_.printer_id; 387 if (base::CreateTemporaryFile(&job_details_.print_data_file_path_)) { 388 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", JOB_HANDLER_DATA, 389 JOB_HANDLER_MAX); 390 int ret = base::WriteFile(job_details_.print_data_file_path_, 391 data.c_str(), data.length()); 392 source->GetResponseHeaders()->GetMimeType( 393 &job_details_.print_data_mime_type_); 394 DCHECK(ret == static_cast<int>(data.length())); 395 if (ret == static_cast<int>(data.length())) { 396 UpdateJobStatus(PRINT_JOB_STATUS_IN_PROGRESS, JOB_SUCCESS); 397 return CloudPrintURLFetcher::STOP_PROCESSING; 398 } 399 } 400 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 401 JOB_HANDLER_INVALID_DATA, JOB_HANDLER_MAX); 402 403 // If we are here, then there was an error in saving the print data, bail out 404 // here. 405 VLOG(1) << "CP_CONNECTOR: Error saving print data" 406 << ", printer id: " << printer_info_cloud_.printer_id; 407 base::MessageLoop::current()->PostTask( 408 FROM_HERE, base::Bind(&PrinterJobHandler::JobFailed, this, 409 JOB_DOWNLOAD_FAILED)); 410 return CloudPrintURLFetcher::STOP_PROCESSING; 411 } 412 413 CloudPrintURLFetcher::ResponseAction 414 PrinterJobHandler::HandleInProgressStatusUpdateResponse( 415 const net::URLFetcher* source, 416 const GURL& url, 417 base::DictionaryValue* json_data, 418 bool succeeded) { 419 VLOG(1) << "CP_CONNECTOR: Handling success status update response" 420 << ", printer id: " << printer_info_cloud_.printer_id; 421 base::MessageLoop::current()->PostTask( 422 FROM_HERE, base::Bind(&PrinterJobHandler::StartPrinting, this)); 423 return CloudPrintURLFetcher::STOP_PROCESSING; 424 } 425 426 CloudPrintURLFetcher::ResponseAction 427 PrinterJobHandler::HandleFailureStatusUpdateResponse( 428 const net::URLFetcher* source, 429 const GURL& url, 430 base::DictionaryValue* json_data, 431 bool succeeded) { 432 VLOG(1) << "CP_CONNECTOR: Handling failure status update response" 433 << ", printer id: " << printer_info_cloud_.printer_id; 434 base::MessageLoop::current()->PostTask( 435 FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); 436 return CloudPrintURLFetcher::STOP_PROCESSING; 437 } 438 439 void PrinterJobHandler::Start() { 440 VLOG(1) << "CP_CONNECTOR: Starting printer job handler" 441 << ", printer id: " << printer_info_cloud_.printer_id 442 << ", task in progress: " << task_in_progress_; 443 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 444 JOB_HANDLER_START, JOB_HANDLER_MAX); 445 if (task_in_progress_) { 446 // Multiple Starts can get posted because of multiple notifications 447 // We want to ignore the other ones that happen when a task is in progress. 448 return; 449 } 450 Reset(); 451 if (!shutting_down_) { 452 // Check if we have work to do. 453 if (HavePendingTasks()) { 454 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 455 JOB_HANDLER_PENDING_TASK, JOB_HANDLER_MAX); 456 if (!task_in_progress_ && printer_update_pending_) { 457 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 458 JOB_HANDLER_PRINTER_UPDATE, JOB_HANDLER_MAX); 459 printer_update_pending_ = false; 460 task_in_progress_ = UpdatePrinterInfo(); 461 VLOG(1) << "CP_CONNECTOR: Changed task in progress" 462 << ", printer id: " << printer_info_cloud_.printer_id 463 << ", task in progress: " << task_in_progress_; 464 } 465 if (!task_in_progress_ && job_check_pending_) { 466 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 467 JOB_HANDLER_JOB_CHECK, JOB_HANDLER_MAX); 468 task_in_progress_ = true; 469 VLOG(1) << "CP_CONNECTOR: Changed task in progress" 470 ", printer id: " << printer_info_cloud_.printer_id 471 << ", task in progress: " << task_in_progress_; 472 job_check_pending_ = false; 473 // We need to fetch any pending jobs for this printer 474 SetNextJSONHandler(&PrinterJobHandler::HandleJobMetadataResponse); 475 request_ = CloudPrintURLFetcher::Create(); 476 request_->StartGetRequest( 477 CloudPrintURLFetcher::REQUEST_JOB_FETCH, 478 GetUrlForJobFetch( 479 cloud_print_server_url_, printer_info_cloud_.printer_id, 480 job_fetch_reason_), 481 this, 482 kCloudPrintAPIMaxRetryCount, 483 std::string()); 484 last_job_fetch_time_ = base::TimeTicks::Now(); 485 VLOG(1) << "CP_CONNECTOR: Last job fetch time" 486 << ", printer name: " << printer_info_.printer_name.c_str() 487 << ", timestamp: " << last_job_fetch_time_.ToInternalValue(); 488 job_fetch_reason_.clear(); 489 } 490 } 491 } 492 } 493 494 void PrinterJobHandler::Stop() { 495 VLOG(1) << "CP_CONNECTOR: Stopping printer job handler" 496 << ", printer id: " << printer_info_cloud_.printer_id; 497 task_in_progress_ = false; 498 VLOG(1) << "CP_CONNECTOR: Changed task in progress" 499 << ", printer id: " << printer_info_cloud_.printer_id 500 << ", task in progress: " << task_in_progress_; 501 Reset(); 502 if (HavePendingTasks()) { 503 base::MessageLoop::current()->PostTask( 504 FROM_HERE, base::Bind(&PrinterJobHandler::Start, this)); 505 } 506 } 507 508 void PrinterJobHandler::StartPrinting() { 509 VLOG(1) << "CP_CONNECTOR: Starting printing" 510 << ", printer id: " << printer_info_cloud_.printer_id; 511 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 512 JOB_HANDLER_SET_START_PRINTING, JOB_HANDLER_MAX); 513 // We are done with the request object for now. 514 request_ = NULL; 515 if (!shutting_down_) { 516 #if defined(OS_WIN) 517 print_thread_.init_com_with_mta(true); 518 #endif 519 if (!print_thread_.Start()) { 520 VLOG(1) << "CP_CONNECTOR: Failed to start print thread" 521 << ", printer id: " << printer_info_cloud_.printer_id; 522 JobFailed(JOB_FAILED); 523 } else { 524 print_thread_.message_loop()->PostTask( 525 FROM_HERE, base::Bind(&PrinterJobHandler::DoPrint, this, job_details_, 526 printer_info_.printer_name)); 527 } 528 } 529 } 530 531 void PrinterJobHandler::Reset() { 532 job_details_.Clear(); 533 request_ = NULL; 534 print_thread_.Stop(); 535 } 536 537 void PrinterJobHandler::UpdateJobStatus(PrintJobStatus status, 538 PrintJobError error) { 539 VLOG(1) << "CP_CONNECTOR: Updating job status" 540 << ", printer id: " << printer_info_cloud_.printer_id 541 << ", job id: " << job_details_.job_id_ 542 << ", job status: " << status; 543 if (shutting_down_) { 544 VLOG(1) << "CP_CONNECTOR: Job status update aborted (shutting down)" 545 << ", printer id: " << printer_info_cloud_.printer_id 546 << ", job id: " << job_details_.job_id_; 547 return; 548 } 549 if (job_details_.job_id_.empty()) { 550 VLOG(1) << "CP_CONNECTOR: Job status update aborted (empty job id)" 551 << ", printer id: " << printer_info_cloud_.printer_id; 552 return; 553 } 554 555 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobStatus", error, JOB_MAX); 556 557 if (error == JOB_SUCCESS) { 558 DCHECK_EQ(status, PRINT_JOB_STATUS_IN_PROGRESS); 559 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 560 JOB_HANDLER_SET_IN_PROGRESS, JOB_HANDLER_MAX); 561 SetNextJSONHandler( 562 &PrinterJobHandler::HandleInProgressStatusUpdateResponse); 563 } else { 564 SetNextJSONHandler( 565 &PrinterJobHandler::HandleFailureStatusUpdateResponse); 566 } 567 request_ = CloudPrintURLFetcher::Create(); 568 request_->StartGetRequest( 569 CloudPrintURLFetcher::REQUEST_UPDATE_JOB, 570 GetUrlForJobStatusUpdate(cloud_print_server_url_, job_details_.job_id_, 571 status, error), 572 this, kCloudPrintAPIMaxRetryCount, std::string()); 573 } 574 575 void PrinterJobHandler::RunScheduledJobCheck() { 576 CheckForJobs(kJobFetchReasonRetry); 577 } 578 579 void PrinterJobHandler::SetNextJSONHandler(JSONDataHandler handler) { 580 next_json_data_handler_ = handler; 581 next_data_handler_ = NULL; 582 } 583 584 void PrinterJobHandler::SetNextDataHandler(DataHandler handler) { 585 next_data_handler_ = handler; 586 next_json_data_handler_ = NULL; 587 } 588 589 void PrinterJobHandler::JobFailed(PrintJobError error) { 590 VLOG(1) << "CP_CONNECTOR: Job failed" 591 << ", printer id: " << printer_info_cloud_.printer_id 592 << ", job id: " << job_details_.job_id_ 593 << ", error: " << error; 594 if (!shutting_down_) { 595 UpdateJobStatus(PRINT_JOB_STATUS_ERROR, error); 596 // This job failed, but others may be pending. Schedule a check. 597 job_check_pending_ = true; 598 job_fetch_reason_ = kJobFetchReasonFailure; 599 } 600 } 601 602 void PrinterJobHandler::JobSpooled(PlatformJobId local_job_id) { 603 VLOG(1) << "CP_CONNECTOR: Job spooled" 604 << ", printer id: " << printer_info_cloud_.printer_id 605 << ", job id: " << local_job_id; 606 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", JOB_HANDLER_SPOOLED, 607 JOB_HANDLER_MAX); 608 UMA_HISTOGRAM_LONG_TIMES("CloudPrint.SpoolingTime", 609 base::Time::Now() - spooling_start_time_); 610 if (shutting_down_) 611 return; 612 613 local_job_id_ = local_job_id; 614 print_thread_.Stop(); 615 616 // The print job has been spooled locally. We now need to create an object 617 // that monitors the status of the job and updates the server. 618 scoped_refptr<JobStatusUpdater> job_status_updater( 619 new JobStatusUpdater(printer_info_.printer_name, job_details_.job_id_, 620 local_job_id_, cloud_print_server_url_, 621 print_system_.get(), this)); 622 job_status_updater_list_.push_back(job_status_updater); 623 base::MessageLoop::current()->PostTask( 624 FROM_HERE, 625 base::Bind(&JobStatusUpdater::UpdateStatus, job_status_updater.get())); 626 627 CheckForJobs(kJobFetchReasonQueryMore); 628 629 VLOG(1) << "CP_CONNECTOR: Stopping printer job handler" 630 << ", printer id: " << printer_info_cloud_.printer_id; 631 base::MessageLoop::current()->PostTask( 632 FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); 633 } 634 635 bool PrinterJobHandler::UpdatePrinterInfo() { 636 if (!printer_watcher_.get()) { 637 LOG(ERROR) << "CP_CONNECTOR: Printer watcher is missing." 638 << " Check printer server url for printer id: " 639 << printer_info_cloud_.printer_id; 640 return false; 641 } 642 643 VLOG(1) << "CP_CONNECTOR: Updating printer info" 644 << ", printer id: " << printer_info_cloud_.printer_id; 645 // We need to update the parts of the printer info that have changed 646 // (could be printer name, description, status or capabilities). 647 // First asynchronously fetch the capabilities. 648 printing::PrinterBasicInfo printer_info; 649 printer_watcher_->GetCurrentPrinterInfo(&printer_info); 650 651 // Asynchronously fetch the printer caps and defaults. The story will 652 // continue in OnReceivePrinterCaps. 653 print_system_->GetPrinterCapsAndDefaults( 654 printer_info.printer_name.c_str(), 655 base::Bind(&PrinterJobHandler::OnReceivePrinterCaps, 656 weak_ptr_factory_.GetWeakPtr())); 657 658 // While we are waiting for the data, pretend we have work to do and return 659 // true. 660 return true; 661 } 662 663 bool PrinterJobHandler::HavePendingTasks() { 664 return (job_check_pending_ || printer_update_pending_); 665 } 666 667 void PrinterJobHandler::ValidatePrintTicketFailed() { 668 if (!shutting_down_) { 669 LOG(ERROR) << "CP_CONNECTOR: Failed validating print ticket" 670 << ", printer name: " << printer_info_.printer_name 671 << ", job id: " << job_details_.job_id_; 672 JobFailed(JOB_VALIDATE_TICKET_FAILED); 673 } 674 } 675 676 void PrinterJobHandler::OnReceivePrinterCaps( 677 bool succeeded, 678 const std::string& printer_name, 679 const printing::PrinterCapsAndDefaults& caps_and_defaults) { 680 printing::PrinterBasicInfo printer_info; 681 if (printer_watcher_.get()) 682 printer_watcher_->GetCurrentPrinterInfo(&printer_info); 683 684 std::string post_data; 685 std::string mime_boundary; 686 CreateMimeBoundaryForUpload(&mime_boundary); 687 688 if (succeeded) { 689 std::string caps_hash = 690 base::MD5String(caps_and_defaults.printer_capabilities); 691 if (caps_hash != printer_info_cloud_.caps_hash) { 692 // Hashes don't match, we need to upload new capabilities (the defaults 693 // go for free along with the capabilities) 694 printer_info_cloud_.caps_hash = caps_hash; 695 if (caps_and_defaults.caps_mime_type == kContentTypeJSON) { 696 DCHECK(print_system_->UseCddAndCjt()); 697 net::AddMultipartValueForUpload(kUseCDD, "true", mime_boundary, 698 std::string(), &post_data); 699 } 700 net::AddMultipartValueForUpload(kPrinterCapsValue, 701 caps_and_defaults.printer_capabilities, mime_boundary, 702 caps_and_defaults.caps_mime_type, &post_data); 703 net::AddMultipartValueForUpload(kPrinterDefaultsValue, 704 caps_and_defaults.printer_defaults, mime_boundary, 705 caps_and_defaults.defaults_mime_type, &post_data); 706 net::AddMultipartValueForUpload(kPrinterCapsHashValue, 707 caps_hash, mime_boundary, std::string(), &post_data); 708 } 709 } else { 710 LOG(ERROR) << "Failed to get printer caps and defaults" 711 << ", printer name: " << printer_name; 712 } 713 714 std::string tags_hash = GetHashOfPrinterInfo(printer_info); 715 if (tags_hash != printer_info_cloud_.tags_hash) { 716 printer_info_cloud_.tags_hash = tags_hash; 717 post_data += GetPostDataForPrinterInfo(printer_info, mime_boundary); 718 // Remove all the existing proxy tags. 719 std::string cp_tag_wildcard(kCloudPrintServiceProxyTagPrefix); 720 cp_tag_wildcard += ".*"; 721 net::AddMultipartValueForUpload(kPrinterRemoveTagValue, 722 cp_tag_wildcard, mime_boundary, std::string(), &post_data); 723 724 if (!last_caps_update_time_.is_null()) { 725 UMA_HISTOGRAM_CUSTOM_TIMES( 726 "CloudPrint.CapsUpdateInterval", 727 base::Time::Now() - last_caps_update_time_, 728 base::TimeDelta::FromMilliseconds(1), 729 base::TimeDelta::FromDays(7), 50); 730 } 731 last_caps_update_time_ = base::Time::Now(); 732 } 733 734 if (printer_info.printer_name != printer_info_.printer_name) { 735 net::AddMultipartValueForUpload(kPrinterNameValue, 736 printer_info.printer_name, mime_boundary, std::string(), &post_data); 737 } 738 if (printer_info.printer_description != printer_info_.printer_description) { 739 net::AddMultipartValueForUpload(kPrinterDescValue, 740 printer_info.printer_description, mime_boundary, 741 std::string(), &post_data); 742 } 743 if (printer_info.printer_status != printer_info_.printer_status) { 744 net::AddMultipartValueForUpload(kPrinterStatusValue, 745 base::StringPrintf("%d", printer_info.printer_status), mime_boundary, 746 std::string(), &post_data); 747 } 748 749 // Add local_settings with a current XMPP ping interval. 750 if (printer_info_cloud_.pending_xmpp_timeout != 0) { 751 DCHECK(kMinXmppPingTimeoutSecs <= printer_info_cloud_.pending_xmpp_timeout); 752 net::AddMultipartValueForUpload(kPrinterLocalSettingsValue, 753 base::StringPrintf(kUpdateLocalSettingsXmppPingFormat, 754 printer_info_cloud_.current_xmpp_timeout), 755 mime_boundary, std::string(), &post_data); 756 } 757 758 printer_info_ = printer_info; 759 if (!post_data.empty()) { 760 net::AddMultipartFinalDelimiterForUpload(mime_boundary, &post_data); 761 std::string mime_type("multipart/form-data; boundary="); 762 mime_type += mime_boundary; 763 SetNextJSONHandler(&PrinterJobHandler::HandlePrinterUpdateResponse); 764 request_ = CloudPrintURLFetcher::Create(); 765 request_->StartPostRequest( 766 CloudPrintURLFetcher::REQUEST_UPDATE_PRINTER, 767 GetUrlForPrinterUpdate( 768 cloud_print_server_url_, printer_info_cloud_.printer_id), 769 this, 770 kCloudPrintAPIMaxRetryCount, 771 mime_type, 772 post_data, 773 std::string()); 774 } else { 775 // We are done here. Go to the Stop state 776 VLOG(1) << "CP_CONNECTOR: Stopping printer job handler" 777 << ", printer name: " << printer_name; 778 base::MessageLoop::current()->PostTask( 779 FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); 780 } 781 } 782 783 // The following methods are called on |print_thread_|. It is not safe to 784 // access any members other than |job_handler_message_loop_proxy_|, 785 // |job_spooler_| and |print_system_|. 786 void PrinterJobHandler::DoPrint(const JobDetails& job_details, 787 const std::string& printer_name) { 788 job_spooler_ = print_system_->CreateJobSpooler(); 789 UMA_HISTOGRAM_LONG_TIMES("CloudPrint.PrepareTime", 790 base::Time::Now() - job_start_time_); 791 DCHECK(job_spooler_.get()); 792 if (!job_spooler_.get()) 793 return; 794 base::string16 document_name = printing::SimplifyDocumentTitle( 795 base::UTF8ToUTF16(job_details.job_title_)); 796 if (document_name.empty()) { 797 document_name = printing::SimplifyDocumentTitle( 798 l10n_util::GetStringUTF16(IDS_DEFAULT_PRINT_DOCUMENT_TITLE)); 799 } 800 UMA_HISTOGRAM_ENUMERATION("CloudPrint.JobHandlerEvent", 801 JOB_HANDLER_START_SPOOLING, JOB_HANDLER_MAX); 802 spooling_start_time_ = base::Time::Now(); 803 if (!job_spooler_->Spool(job_details.print_ticket_, 804 job_details.print_ticket_mime_type_, 805 job_details.print_data_file_path_, 806 job_details.print_data_mime_type_, 807 printer_name, 808 base::UTF16ToUTF8(document_name), 809 job_details.tags_, 810 this)) { 811 OnJobSpoolFailed(); 812 } 813 } 814 815 } // namespace cloud_print 816
