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
PrinterInfoFromCloud()56 PrinterJobHandler::PrinterInfoFromCloud::PrinterInfoFromCloud()
57 : current_xmpp_timeout(0), pending_xmpp_timeout(0) {
58 }
59
PrinterJobHandler(const printing::PrinterBasicInfo & printer_info,const PrinterInfoFromCloud & printer_info_cloud,const GURL & cloud_print_server_url,PrintSystem * print_system,Delegate * delegate)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
Initialize()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
GetPrinterName() const96 std::string PrinterJobHandler::GetPrinterName() const {
97 return printer_info_.printer_name;
98 }
99
CheckForJobs(const std::string & reason)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
Shutdown()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.
HandleRawResponse(const net::URLFetcher * source,const GURL & url,const net::URLRequestStatus & status,int response_code,const net::ResponseCookies & cookies,const std::string & data)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
HandleRawData(const net::URLFetcher * source,const GURL & url,const std::string & data)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
HandleJSONData(const net::URLFetcher * source,const GURL & url,base::DictionaryValue * json_data,bool succeeded)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
OnRequestGiveUp()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
OnRequestAuthError()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
GetAuthHeader()191 std::string PrinterJobHandler::GetAuthHeader() {
192 return GetCloudPrintAuthHeaderFromStore();
193 }
194
195 // JobStatusUpdater::Delegate implementation
OnJobCompleted(JobStatusUpdater * updater)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
OnAuthError()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
OnPrinterDeleted()223 void PrinterJobHandler::OnPrinterDeleted() {
224 if (delegate_)
225 delegate_->OnPrinterDeleted(printer_info_cloud_.printer_id);
226 }
227
OnPrinterChanged()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
OnJobChanged()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
OnJobSpoolSucceeded(const PlatformJobId & job_id)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
OnJobSpoolFailed()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
ReportsStats()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
~PrinterJobHandler()275 PrinterJobHandler::~PrinterJobHandler() {
276 if (printer_watcher_.get())
277 printer_watcher_->StopWatching();
278 }
279
280 // Begin Response handlers
281 CloudPrintURLFetcher::ResponseAction
HandlePrinterUpdateResponse(const net::URLFetcher * source,const GURL & url,base::DictionaryValue * json_data,bool succeeded)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
HandleJobMetadataResponse(const net::URLFetcher * source,const GURL & url,base::DictionaryValue * json_data,bool succeeded)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
HandlePrintTicketResponse(const net::URLFetcher * source,const GURL & url,const std::string & data)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
HandlePrintDataResponse(const net::URLFetcher * source,const GURL & url,const std::string & data)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
HandleInProgressStatusUpdateResponse(const net::URLFetcher * source,const GURL & url,base::DictionaryValue * json_data,bool succeeded)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
HandleFailureStatusUpdateResponse(const net::URLFetcher * source,const GURL & url,base::DictionaryValue * json_data,bool succeeded)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
Start()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
Stop()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
StartPrinting()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
Reset()531 void PrinterJobHandler::Reset() {
532 job_details_.Clear();
533 request_ = NULL;
534 print_thread_.Stop();
535 }
536
UpdateJobStatus(PrintJobStatus status,PrintJobError error)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
RunScheduledJobCheck()575 void PrinterJobHandler::RunScheduledJobCheck() {
576 CheckForJobs(kJobFetchReasonRetry);
577 }
578
SetNextJSONHandler(JSONDataHandler handler)579 void PrinterJobHandler::SetNextJSONHandler(JSONDataHandler handler) {
580 next_json_data_handler_ = handler;
581 next_data_handler_ = NULL;
582 }
583
SetNextDataHandler(DataHandler handler)584 void PrinterJobHandler::SetNextDataHandler(DataHandler handler) {
585 next_data_handler_ = handler;
586 next_json_data_handler_ = NULL;
587 }
588
JobFailed(PrintJobError error)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
JobSpooled(PlatformJobId local_job_id)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
UpdatePrinterInfo()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
HavePendingTasks()663 bool PrinterJobHandler::HavePendingTasks() {
664 return (job_check_pending_ || printer_update_pending_);
665 }
666
ValidatePrintTicketFailed()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
OnReceivePrinterCaps(bool succeeded,const std::string & printer_name,const printing::PrinterCapsAndDefaults & caps_and_defaults)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_|.
DoPrint(const JobDetails & job_details,const std::string & printer_name)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