Commit 6075da4a authored by alexyu@google.com's avatar alexyu@google.com

Standardize log message style for cloudprint service and display printer id

and job id wherever possible


BUG=138602
TEST=

Review URL: https://chromiumcodereview.appspot.com/10808086

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@147987 0039d316-1c4b-4281-b951-d872f2087c98
parent 65fd16aa
...@@ -36,7 +36,8 @@ CloudPrintConnector::CloudPrintConnector( ...@@ -36,7 +36,8 @@ CloudPrintConnector::CloudPrintConnector(
bool CloudPrintConnector::Start() { bool CloudPrintConnector::Start() {
DCHECK(!print_system_.get()); DCHECK(!print_system_.get());
VLOG(1) << "CP_CONNECTOR: Starting connector, id: " << proxy_id_; VLOG(1) << "CP_CONNECTOR: Starting connector"
<< ", proxy id: " << proxy_id_;
pending_tasks_.clear(); pending_tasks_.clear();
...@@ -64,7 +65,8 @@ bool CloudPrintConnector::Start() { ...@@ -64,7 +65,8 @@ bool CloudPrintConnector::Start() {
} }
void CloudPrintConnector::Stop() { void CloudPrintConnector::Stop() {
VLOG(1) << "CP_CONNECTOR: Stopping connector, id: " << proxy_id_; VLOG(1) << "CP_CONNECTOR: Stopping connector"
<< ", proxy id: " << proxy_id_;
DCHECK(print_system_.get()); DCHECK(print_system_.get());
if (print_system_.get()) { if (print_system_.get()) {
// Do uninitialization here. // Do uninitialization here.
...@@ -236,8 +238,9 @@ CloudPrintConnector::HandlePrinterDeleteResponse( ...@@ -236,8 +238,9 @@ CloudPrintConnector::HandlePrinterDeleteResponse(
const GURL& url, const GURL& url,
DictionaryValue* json_data, DictionaryValue* json_data,
bool succeeded) { bool succeeded) {
VLOG(1) << "CP_CONNECTOR: Handler printer delete response, succeeded:" VLOG(1) << "CP_CONNECTOR: Handler printer delete response"
<< succeeded << " url: " << url; << ", succeeded: " << succeeded
<< ", url: " << url;
ContinuePendingTaskProcessing(); // Continue processing background tasks. ContinuePendingTaskProcessing(); // Continue processing background tasks.
return CloudPrintURLFetcher::STOP_PROCESSING; return CloudPrintURLFetcher::STOP_PROCESSING;
} }
...@@ -248,8 +251,9 @@ CloudPrintConnector::HandleRegisterPrinterResponse( ...@@ -248,8 +251,9 @@ CloudPrintConnector::HandleRegisterPrinterResponse(
const GURL& url, const GURL& url,
DictionaryValue* json_data, DictionaryValue* json_data,
bool succeeded) { bool succeeded) {
VLOG(1) << "CP_CONNECTOR: Handler printer register response, succeeded:" VLOG(1) << "CP_CONNECTOR: Handler printer register response"
<< succeeded << " url: " << url; << ", succeeded: " << succeeded
<< ", url: " << url;
if (succeeded) { if (succeeded) {
ListValue* printer_list = NULL; ListValue* printer_list = NULL;
// There should be a "printers" value in the JSON // There should be a "printers" value in the JSON
...@@ -322,8 +326,8 @@ void CloudPrintConnector::InitJobHandlerForPrinter( ...@@ -322,8 +326,8 @@ void CloudPrintConnector::InitJobHandlerForPrinter(
PrinterJobHandler::PrinterInfoFromCloud printer_info_cloud; PrinterJobHandler::PrinterInfoFromCloud printer_info_cloud;
printer_data->GetString(kIdValue, &printer_info_cloud.printer_id); printer_data->GetString(kIdValue, &printer_info_cloud.printer_id);
DCHECK(!printer_info_cloud.printer_id.empty()); DCHECK(!printer_info_cloud.printer_id.empty());
VLOG(1) << "CP_CONNECTOR: Init job handler for printer id: " VLOG(1) << "CP_CONNECTOR: Init job handler"
<< printer_info_cloud.printer_id; << ", printer id: " << printer_info_cloud.printer_id;
JobHandlerMap::iterator index = job_handler_map_.find( JobHandlerMap::iterator index = job_handler_map_.find(
printer_info_cloud.printer_id); printer_info_cloud.printer_id);
if (index != job_handler_map_.end()) if (index != job_handler_map_.end())
...@@ -487,8 +491,8 @@ void CloudPrintConnector::OnReceivePrinterCaps( ...@@ -487,8 +491,8 @@ void CloudPrintConnector::OnReceivePrinterCaps(
pending_tasks_.front().type == PENDING_PRINTER_REGISTER); pending_tasks_.front().type == PENDING_PRINTER_REGISTER);
if (!succeeded) { if (!succeeded) {
LOG(ERROR) << "CP_CONNECTOR: Failed to get printer info for: " << LOG(ERROR) << "CP_CONNECTOR: Failed to get printer info"
printer_name; << ", printer name: " << printer_name;
// This printer failed to register, notify the server of this failure. // This printer failed to register, notify the server of this failure.
string16 printer_name_utf16 = UTF8ToUTF16(printer_name); string16 printer_name_utf16 = UTF8ToUTF16(printer_name);
std::string status_message = l10n_util::GetStringFUTF8( std::string status_message = l10n_util::GetStringFUTF8(
......
...@@ -304,17 +304,20 @@ class PrinterWatcherCUPS ...@@ -304,17 +304,20 @@ class PrinterWatcherCUPS
void PrinterUpdate() { void PrinterUpdate() {
if (delegate_ == NULL) if (delegate_ == NULL)
return; // Orphan call. We have been stopped already. return; // Orphan call. We have been stopped already.
VLOG(1) << "CP_CUPS: Checking for printer updates: " << printer_name_; VLOG(1) << "CP_CUPS: Checking for updates"
<< ", printer name: " << printer_name_;
if (print_system_->NotifyDelete() && if (print_system_->NotifyDelete() &&
!print_system_->IsValidPrinter(printer_name_)) { !print_system_->IsValidPrinter(printer_name_)) {
delegate_->OnPrinterDeleted(); delegate_->OnPrinterDeleted();
VLOG(1) << "CP_CUPS: Printer deleted: " << printer_name_; VLOG(1) << "CP_CUPS: Printer deleted"
<< ", printer name: " << printer_name_;
} else { } else {
std::string new_hash = GetSettingsHash(); std::string new_hash = GetSettingsHash();
if (settings_hash_ != new_hash) { if (settings_hash_ != new_hash) {
settings_hash_ = new_hash; settings_hash_ = new_hash;
delegate_->OnPrinterChanged(); delegate_->OnPrinterChanged();
VLOG(1) << "CP_CUPS: Printer update detected for: " << printer_name_; VLOG(1) << "CP_CUPS: Printer configuration changed"
<< ", printer name: " << printer_name_;
} }
} }
MessageLoop::current()->PostDelayedTask( MessageLoop::current()->PostDelayedTask(
...@@ -487,8 +490,9 @@ void PrintSystemCUPS::UpdatePrinters() { ...@@ -487,8 +490,9 @@ void PrintSystemCUPS::UpdatePrinters() {
printer_it->printer_name = MakeFullPrinterName(it->url, printer_it->printer_name = MakeFullPrinterName(it->url,
printer_it->printer_name); printer_it->printer_name);
} }
VLOG(1) << "CUPS: Updated printer list for url: " << it->url VLOG(1) << "CP_CUPS: Updated printers list"
<< " Number of printers: " << it->printers.size(); << ", server: " << it->url
<< ", # of printers: " << it->printers.size();
} }
// Schedule next update. // Schedule next update.
...@@ -506,7 +510,7 @@ PrintSystem::PrintSystemResult PrintSystemCUPS::EnumeratePrinters( ...@@ -506,7 +510,7 @@ PrintSystem::PrintSystemResult PrintSystemCUPS::EnumeratePrinters(
printer_list->insert(printer_list->end(), printer_list->insert(printer_list->end(),
it->printers.begin(), it->printers.end()); it->printers.begin(), it->printers.end());
} }
VLOG(1) << "CUPS: Total " << printer_list->size() << " printers enumerated."; VLOG(1) << "CP_CUPS: Total printers enumerated: " << printer_list->size();
// TODO(sanjeevr): Maybe some day we want to report the actual server names // TODO(sanjeevr): Maybe some day we want to report the actual server names
// for which the enumeration failed. // for which the enumeration failed.
return PrintSystemResult(printer_enum_succeeded_, std::string()); return PrintSystemResult(printer_enum_succeeded_, std::string());
...@@ -606,10 +610,9 @@ bool PrintSystemCUPS::GetJobDetails(const std::string& printer_name, ...@@ -606,10 +610,9 @@ bool PrintSystemCUPS::GetJobDetails(const std::string& printer_name,
short_printer_name.c_str(), 1, -1); short_printer_name.c_str(), 1, -1);
bool error = (num_jobs == 0) && (cupsLastError() > IPP_OK_EVENTS_COMPLETE); bool error = (num_jobs == 0) && (cupsLastError() > IPP_OK_EVENTS_COMPLETE);
if (error) { if (error) {
VLOG(1) << "CP_CUPS: Error getting jobs from CUPS server. Printer:" VLOG(1) << "CP_CUPS: Error getting jobs from CUPS server"
<< printer_name << ", printer name:" << printer_name
<< " Error: " << ", error: " << static_cast<int>(cupsLastError());
<< static_cast<int>(cupsLastError());
return false; return false;
} }
...@@ -618,7 +621,8 @@ bool PrintSystemCUPS::GetJobDetails(const std::string& printer_name, ...@@ -618,7 +621,8 @@ bool PrintSystemCUPS::GetJobDetails(const std::string& printer_name,
// accessible through CUPS. // accessible through CUPS.
if (job_id == kDryRunJobId) { if (job_id == kDryRunJobId) {
job_details->status = PRINT_JOB_STATUS_COMPLETED; job_details->status = PRINT_JOB_STATUS_COMPLETED;
VLOG(1) << "CP_CUPS: Dry run job succeeded for: " << printer_name; VLOG(1) << "CP_CUPS: Dry run job succeeded"
<< ", printer name: " << printer_name;
return true; return true;
} }
...@@ -651,11 +655,14 @@ bool PrintSystemCUPS::GetJobDetails(const std::string& printer_name, ...@@ -651,11 +655,14 @@ bool PrintSystemCUPS::GetJobDetails(const std::string& printer_name,
} }
if (found) if (found)
VLOG(1) << "CP_CUPS: Job details for: " << printer_name VLOG(1) << "CP_CUPS: Job found"
<< " job_id: " << job_id << " job status: " << job_details->status; << ", printer name: " << printer_name
<< ", cups job id: " << job_id
<< ", cups job status: " << job_details->status;
else else
LOG(WARNING) << "CP_CUPS: Job not found for: " << printer_name LOG(WARNING) << "CP_CUPS: Job not found"
<< " job_id: " << job_id; << ", printer name: " << printer_name
<< ", cups job id: " << job_id;
cupsFreeJobs(num_jobs, jobs); cupsFreeJobs(num_jobs, jobs);
return found; return found;
...@@ -665,7 +672,8 @@ bool PrintSystemCUPS::GetPrinterInfo(const std::string& printer_name, ...@@ -665,7 +672,8 @@ bool PrintSystemCUPS::GetPrinterInfo(const std::string& printer_name,
printing::PrinterBasicInfo* info) { printing::PrinterBasicInfo* info) {
DCHECK(initialized_); DCHECK(initialized_);
if (info) if (info)
VLOG(1) << "CP_CUPS: Getting printer info for: " << printer_name; VLOG(1) << "CP_CUPS: Getting printer info"
<< ", printer name: " << printer_name;
std::string short_printer_name; std::string short_printer_name;
PrintServerInfoCUPS* server_info = PrintServerInfoCUPS* server_info =
...@@ -760,7 +768,7 @@ PlatformJobId PrintSystemCUPS::SpoolPrintJob( ...@@ -760,7 +768,7 @@ PlatformJobId PrintSystemCUPS::SpoolPrintJob(
const std::vector<std::string>& tags, const std::vector<std::string>& tags,
bool* dry_run) { bool* dry_run) {
DCHECK(initialized_); DCHECK(initialized_);
VLOG(1) << "CP_CUPS: Spooling print job for: " << printer_name; VLOG(1) << "CP_CUPS: Spooling print job, printer name: " << printer_name;
std::string short_printer_name; std::string short_printer_name;
PrintServerInfoCUPS* server_info = PrintServerInfoCUPS* server_info =
...@@ -781,7 +789,7 @@ PlatformJobId PrintSystemCUPS::SpoolPrintJob( ...@@ -781,7 +789,7 @@ PlatformJobId PrintSystemCUPS::SpoolPrintJob(
// Check if this is a dry run (test) job. // Check if this is a dry run (test) job.
*dry_run = CloudPrintHelpers::IsDryRunJob(tags); *dry_run = CloudPrintHelpers::IsDryRunJob(tags);
if (*dry_run) { if (*dry_run) {
VLOG(1) << "CP_CUPS: Dry run job spooled."; VLOG(1) << "CP_CUPS: Dry run job spooled";
return kDryRunJobId; return kDryRunJobId;
} }
...@@ -803,7 +811,10 @@ PlatformJobId PrintSystemCUPS::SpoolPrintJob( ...@@ -803,7 +811,10 @@ PlatformJobId PrintSystemCUPS::SpoolPrintJob(
cups_options.size(), cups_options.size(),
&(cups_options[0])); &(cups_options[0]));
VLOG(1) << "CP_CUPS: Job spooled, id: " << job_id; // TODO(alexyu): Output printer id.
VLOG(1) << "CP_CUPS: Job spooled"
<< ", printer name: " << printer_name
<< ", cups job id: " << job_id;
return job_id; return job_id;
} }
...@@ -827,7 +838,8 @@ PrintServerInfoCUPS* PrintSystemCUPS::FindServerByFullName( ...@@ -827,7 +838,8 @@ PrintServerInfoCUPS* PrintSystemCUPS::FindServerByFullName(
size_t front = full_printer_name.find("\\\\"); size_t front = full_printer_name.find("\\\\");
size_t separator = full_printer_name.find("\\", 2); size_t separator = full_printer_name.find("\\", 2);
if (front == std::string::npos || separator == std::string::npos) { if (front == std::string::npos || separator == std::string::npos) {
LOG(WARNING) << "Invalid UNC printer name: " << full_printer_name; LOG(WARNING) << "CP_CUPS: Invalid UNC"
<< ", printer name: " << full_printer_name;
return NULL; return NULL;
} }
std::string server = full_printer_name.substr(2, separator - 2); std::string server = full_printer_name.substr(2, separator - 2);
...@@ -846,7 +858,8 @@ PrintServerInfoCUPS* PrintSystemCUPS::FindServerByFullName( ...@@ -846,7 +858,8 @@ PrintServerInfoCUPS* PrintSystemCUPS::FindServerByFullName(
} }
} }
LOG(WARNING) << "Server not found for printer: " << full_printer_name; LOG(WARNING) << "CP_CUPS: Server not found"
<< ", printer name: " << full_printer_name;
return NULL; return NULL;
} }
......
...@@ -74,8 +74,8 @@ std::string PrinterJobHandler::GetPrinterName() const { ...@@ -74,8 +74,8 @@ std::string PrinterJobHandler::GetPrinterName() const {
} }
void PrinterJobHandler::CheckForJobs(const std::string& reason) { void PrinterJobHandler::CheckForJobs(const std::string& reason) {
VLOG(1) << "CP_CONNECTOR: CheckForJobs, id: " VLOG(1) << "CP_CONNECTOR: Checking for jobs"
<< printer_info_cloud_.printer_id << ", printer id: " << printer_info_cloud_.printer_id
<< ", reason: " << reason << ", reason: " << reason
<< ", task in progress: " << task_in_progress_; << ", task in progress: " << task_in_progress_;
job_fetch_reason_ = reason; job_fetch_reason_ = reason;
...@@ -87,8 +87,8 @@ void PrinterJobHandler::CheckForJobs(const std::string& reason) { ...@@ -87,8 +87,8 @@ void PrinterJobHandler::CheckForJobs(const std::string& reason) {
} }
void PrinterJobHandler::Shutdown() { void PrinterJobHandler::Shutdown() {
VLOG(1) << "CP_CONNECTOR: Printer job handler shutdown, id: " VLOG(1) << "CP_CONNECTOR: Shutting down printer job handler"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
Reset(); Reset();
shutting_down_ = true; shutting_down_ = true;
while (!job_status_updater_list_.empty()) { while (!job_status_updater_list_.empty()) {
...@@ -110,7 +110,7 @@ CloudPrintURLFetcher::ResponseAction PrinterJobHandler::HandleRawResponse( ...@@ -110,7 +110,7 @@ CloudPrintURLFetcher::ResponseAction PrinterJobHandler::HandleRawResponse(
// means data conversion error. Stop fetching process and mark job as error. // means data conversion error. Stop fetching process and mark job as error.
if (next_data_handler_ == (&PrinterJobHandler::HandlePrintDataResponse) && if (next_data_handler_ == (&PrinterJobHandler::HandlePrintDataResponse) &&
response_code == net::HTTP_UNSUPPORTED_MEDIA_TYPE) { response_code == net::HTTP_UNSUPPORTED_MEDIA_TYPE) {
VLOG(1) << "CP_CONNECTOR: Job failed. Unsupported media type."; VLOG(1) << "CP_CONNECTOR: Job failed (unsupported media type)";
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, FROM_HERE,
base::Bind(&PrinterJobHandler::JobFailed, this, JOB_DOWNLOAD_FAILED)); base::Bind(&PrinterJobHandler::JobFailed, this, JOB_DOWNLOAD_FAILED));
...@@ -142,7 +142,7 @@ void PrinterJobHandler::OnRequestGiveUp() { ...@@ -142,7 +142,7 @@ void PrinterJobHandler::OnRequestGiveUp() {
// specified number of retries, is when we are trying to fetch print job // specified number of retries, is when we are trying to fetch print job
// data. So, this function will be reached only if we failed to get job data. // data. So, this function will be reached only if we failed to get job data.
// In that case, we should make job as error and should not try it later. // In that case, we should make job as error and should not try it later.
VLOG(1) << "CP_CONNECTOR: Job failed. Giving up."; VLOG(1) << "CP_CONNECTOR: Job failed (giving up)";
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, FROM_HERE,
base::Bind(&PrinterJobHandler::JobFailed, this, JOB_DOWNLOAD_FAILED)); base::Bind(&PrinterJobHandler::JobFailed, this, JOB_DOWNLOAD_FAILED));
...@@ -214,7 +214,7 @@ void PrinterJobHandler::OnJobSpoolSucceeded( ...@@ -214,7 +214,7 @@ void PrinterJobHandler::OnJobSpoolSucceeded(
void PrinterJobHandler::OnJobSpoolFailed() { void PrinterJobHandler::OnJobSpoolFailed() {
DCHECK(MessageLoop::current() == print_thread_.message_loop()); DCHECK(MessageLoop::current() == print_thread_.message_loop());
job_spooler_ = NULL; job_spooler_ = NULL;
VLOG(1) << "CP_CONNECTOR: Job failed. Job Spool Failed."; VLOG(1) << "CP_CONNECTOR: Job failed (spool failed)";
job_handler_message_loop_proxy_->PostTask( job_handler_message_loop_proxy_->PostTask(
FROM_HERE, base::Bind(&PrinterJobHandler::JobFailed, this, PRINT_FAILED)); FROM_HERE, base::Bind(&PrinterJobHandler::JobFailed, this, PRINT_FAILED));
} }
...@@ -231,10 +231,11 @@ PrinterJobHandler::HandlePrinterUpdateResponse( ...@@ -231,10 +231,11 @@ PrinterJobHandler::HandlePrinterUpdateResponse(
const GURL& url, const GURL& url,
DictionaryValue* json_data, DictionaryValue* json_data,
bool succeeded) { bool succeeded) {
VLOG(1) << "CP_CONNECTOR: Handle printer update response, id: " VLOG(1) << "CP_CONNECTOR: Handling printer update response"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
// We are done here. Go to the Stop state // We are done here. Go to the Stop state
VLOG(1) << "CP_CONNECTOR: Stopping PrinterJobHandler"; VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
<< ", printer id: " << printer_info_cloud_.printer_id;
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
return CloudPrintURLFetcher::STOP_PROCESSING; return CloudPrintURLFetcher::STOP_PROCESSING;
...@@ -246,8 +247,8 @@ PrinterJobHandler::HandleJobMetadataResponse( ...@@ -246,8 +247,8 @@ PrinterJobHandler::HandleJobMetadataResponse(
const GURL& url, const GURL& url,
DictionaryValue* json_data, DictionaryValue* json_data,
bool succeeded) { bool succeeded) {
VLOG(1) << "CP_CONNECTOR: Handle job metadata response, id: " VLOG(1) << "CP_CONNECTOR: Handling job metadata response"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
bool job_available = false; bool job_available = false;
if (succeeded) { if (succeeded) {
ListValue* job_list = NULL; ListValue* job_list = NULL;
...@@ -284,7 +285,8 @@ PrinterJobHandler::HandleJobMetadataResponse( ...@@ -284,7 +285,8 @@ PrinterJobHandler::HandleJobMetadataResponse(
} }
// If no jobs are available, go to the Stop state. // If no jobs are available, go to the Stop state.
if (!job_available) { if (!job_available) {
VLOG(1) << "CP_CONNECTOR: Stopping PrinterJobHandler"; VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
<< ", printer id: " << printer_info_cloud_.printer_id;
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
} }
...@@ -295,8 +297,8 @@ CloudPrintURLFetcher::ResponseAction ...@@ -295,8 +297,8 @@ CloudPrintURLFetcher::ResponseAction
PrinterJobHandler::HandlePrintTicketResponse(const net::URLFetcher* source, PrinterJobHandler::HandlePrintTicketResponse(const net::URLFetcher* source,
const GURL& url, const GURL& url,
const std::string& data) { const std::string& data) {
VLOG(1) << "CP_CONNECTOR: Handle print ticket response, id: " VLOG(1) << "CP_CONNECTOR: Handling print ticket response"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
if (print_system_->ValidatePrintTicket(printer_info_.printer_name, data)) { if (print_system_->ValidatePrintTicket(printer_info_.printer_name, data)) {
job_details_.print_ticket_ = data; job_details_.print_ticket_ = data;
SetNextDataHandler(&PrinterJobHandler::HandlePrintDataResponse); SetNextDataHandler(&PrinterJobHandler::HandlePrintDataResponse);
...@@ -318,8 +320,8 @@ CloudPrintURLFetcher::ResponseAction ...@@ -318,8 +320,8 @@ CloudPrintURLFetcher::ResponseAction
PrinterJobHandler::HandlePrintDataResponse(const net::URLFetcher* source, PrinterJobHandler::HandlePrintDataResponse(const net::URLFetcher* source,
const GURL& url, const GURL& url,
const std::string& data) { const std::string& data) {
VLOG(1) << "CP_CONNECTOR: Handle print data response, id: " VLOG(1) << "CP_CONNECTOR: Handling print data response"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
base::Closure next_task; base::Closure next_task;
if (file_util::CreateTemporaryFile(&job_details_.print_data_file_path_)) { if (file_util::CreateTemporaryFile(&job_details_.print_data_file_path_)) {
int ret = file_util::WriteFile(job_details_.print_data_file_path_, int ret = file_util::WriteFile(job_details_.print_data_file_path_,
...@@ -335,7 +337,8 @@ PrinterJobHandler::HandlePrintDataResponse(const net::URLFetcher* source, ...@@ -335,7 +337,8 @@ PrinterJobHandler::HandlePrintDataResponse(const net::URLFetcher* source,
// If there was no task allocated above, then there was an error in // If there was no task allocated above, then there was an error in
// saving the print data, bail out here. // saving the print data, bail out here.
if (next_task.is_null()) { if (next_task.is_null()) {
VLOG(1) << "CP_CONNECTOR: Job failed. Error saving print data."; VLOG(1) << "CP_CONNECTOR: Error saving print data"
<< ", printer id: " << printer_info_cloud_.printer_id;
next_task = base::Bind(&PrinterJobHandler::JobFailed, this, next_task = base::Bind(&PrinterJobHandler::JobFailed, this,
JOB_DOWNLOAD_FAILED); JOB_DOWNLOAD_FAILED);
} }
...@@ -349,8 +352,8 @@ PrinterJobHandler::HandleSuccessStatusUpdateResponse( ...@@ -349,8 +352,8 @@ PrinterJobHandler::HandleSuccessStatusUpdateResponse(
const GURL& url, const GURL& url,
DictionaryValue* json_data, DictionaryValue* json_data,
bool succeeded) { bool succeeded) {
VLOG(1) << "CP_CONNECTOR: Handle success status update response, id: " VLOG(1) << "CP_CONNECTOR: Handling success status update response"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
// The print job has been spooled locally. We now need to create an object // The print job has been spooled locally. We now need to create an object
// that monitors the status of the job and updates the server. // that monitors the status of the job and updates the server.
scoped_refptr<JobStatusUpdater> job_status_updater( scoped_refptr<JobStatusUpdater> job_status_updater(
...@@ -365,7 +368,8 @@ PrinterJobHandler::HandleSuccessStatusUpdateResponse( ...@@ -365,7 +368,8 @@ PrinterJobHandler::HandleSuccessStatusUpdateResponse(
// Since we just printed successfully, we want to look for more jobs. // Since we just printed successfully, we want to look for more jobs.
CheckForJobs(kJobFetchReasonQueryMore); CheckForJobs(kJobFetchReasonQueryMore);
} }
VLOG(1) << "CP_CONNECTOR: Stopping PrinterJobHandler"; VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
<< ", printer id: " << printer_info_cloud_.printer_id;
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
return CloudPrintURLFetcher::STOP_PROCESSING; return CloudPrintURLFetcher::STOP_PROCESSING;
...@@ -377,16 +381,16 @@ PrinterJobHandler::HandleFailureStatusUpdateResponse( ...@@ -377,16 +381,16 @@ PrinterJobHandler::HandleFailureStatusUpdateResponse(
const GURL& url, const GURL& url,
DictionaryValue* json_data, DictionaryValue* json_data,
bool succeeded) { bool succeeded) {
VLOG(1) << "CP_CONNECTOR: Handle failure status update response, id: " VLOG(1) << "CP_CONNECTOR: Handling failure status update response"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
return CloudPrintURLFetcher::STOP_PROCESSING; return CloudPrintURLFetcher::STOP_PROCESSING;
} }
void PrinterJobHandler::Start() { void PrinterJobHandler::Start() {
VLOG(1) << "CP_CONNECTOR: Start printer job handler, id: " VLOG(1) << "CP_CONNECTOR: Starting printer job handler"
<< printer_info_cloud_.printer_id << ", printer id: " << printer_info_cloud_.printer_id
<< ", task in progress: " << task_in_progress_; << ", task in progress: " << task_in_progress_;
if (task_in_progress_) { if (task_in_progress_) {
// Multiple Starts can get posted because of multiple notifications // Multiple Starts can get posted because of multiple notifications
...@@ -400,13 +404,15 @@ void PrinterJobHandler::Start() { ...@@ -400,13 +404,15 @@ void PrinterJobHandler::Start() {
if (!task_in_progress_ && printer_update_pending_) { if (!task_in_progress_ && printer_update_pending_) {
printer_update_pending_ = false; printer_update_pending_ = false;
task_in_progress_ = UpdatePrinterInfo(); task_in_progress_ = UpdatePrinterInfo();
VLOG(1) << "CP_CONNECTOR: Changed task in progress to: " << VLOG(1) << "CP_CONNECTOR: Changed task in progress"
task_in_progress_; << ", printer id: " << printer_info_cloud_.printer_id
<< ", task in progress: " << task_in_progress_;
} }
if (!task_in_progress_ && job_check_pending_) { if (!task_in_progress_ && job_check_pending_) {
task_in_progress_ = true; task_in_progress_ = true;
VLOG(1) << "CP_CONNECTOR: Changed task in progress to: " << VLOG(1) << "CP_CONNECTOR: Changed task in progress"
task_in_progress_; ", printer id: " << printer_info_cloud_.printer_id
<< ", task in progress: " << task_in_progress_;
job_check_pending_ = false; job_check_pending_ = false;
// We need to fetch any pending jobs for this printer // We need to fetch any pending jobs for this printer
SetNextJSONHandler(&PrinterJobHandler::HandleJobMetadataResponse); SetNextJSONHandler(&PrinterJobHandler::HandleJobMetadataResponse);
...@@ -419,9 +425,9 @@ void PrinterJobHandler::Start() { ...@@ -419,9 +425,9 @@ void PrinterJobHandler::Start() {
kCloudPrintAPIMaxRetryCount, kCloudPrintAPIMaxRetryCount,
std::string()); std::string());
last_job_fetch_time_ = base::TimeTicks::Now(); last_job_fetch_time_ = base::TimeTicks::Now();
VLOG(1) << "Last job fetch time for printer " VLOG(1) << "CP_CONNECTOR: Last job fetch time"
<< printer_info_.printer_name.c_str() << " is " << ", printer name: " << printer_info_.printer_name.c_str()
<< last_job_fetch_time_.ToInternalValue(); << ", timestamp: " << last_job_fetch_time_.ToInternalValue();
job_fetch_reason_.clear(); job_fetch_reason_.clear();
} }
} }
...@@ -429,11 +435,12 @@ void PrinterJobHandler::Start() { ...@@ -429,11 +435,12 @@ void PrinterJobHandler::Start() {
} }
void PrinterJobHandler::Stop() { void PrinterJobHandler::Stop() {
VLOG(1) << "CP_CONNECTOR: Stop printer job handler, id: " VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
task_in_progress_ = false; task_in_progress_ = false;
VLOG(1) << "CP_CONNECTOR: Changed task in progress to: " << VLOG(1) << "CP_CONNECTOR: Changed task in progress"
task_in_progress_; << ", printer id: " << printer_info_cloud_.printer_id
<< ", task in progress: " << task_in_progress_;
Reset(); Reset();
if (HavePendingTasks()) { if (HavePendingTasks()) {
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
...@@ -442,13 +449,14 @@ void PrinterJobHandler::Stop() { ...@@ -442,13 +449,14 @@ void PrinterJobHandler::Stop() {
} }
void PrinterJobHandler::StartPrinting() { void PrinterJobHandler::StartPrinting() {
VLOG(1) << "CP_CONNECTOR: Start printing, id: " VLOG(1) << "CP_CONNECTOR: Starting printing"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
// We are done with the request object for now. // We are done with the request object for now.
request_ = NULL; request_ = NULL;
if (!shutting_down_) { if (!shutting_down_) {
if (!print_thread_.Start()) { if (!print_thread_.Start()) {
VLOG(1) << "CP_CONNECTOR: Failed to start print thread."; VLOG(1) << "CP_CONNECTOR: Failed to start print thread"
<< ", printer id: " << printer_info_cloud_.printer_id;
JobFailed(PRINT_FAILED); JobFailed(PRINT_FAILED);
} else { } else {
print_thread_.message_loop()->PostTask( print_thread_.message_loop()->PostTask(
...@@ -467,19 +475,22 @@ void PrinterJobHandler::Reset() { ...@@ -467,19 +475,22 @@ void PrinterJobHandler::Reset() {
void PrinterJobHandler::UpdateJobStatus(cloud_print::PrintJobStatus status, void PrinterJobHandler::UpdateJobStatus(cloud_print::PrintJobStatus status,
PrintJobError error) { PrintJobError error) {
VLOG(1) << "CP_CONNECTOR: Update job status, id: " VLOG(1) << "CP_CONNECTOR: Updating job status"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id
<< ", job id: " << job_details_.job_id_
<< ", job status: " << status;
if (shutting_down_) { if (shutting_down_) {
VLOG(1) << "CP_CONNECTOR: Update job status aborted. Shutting down."; VLOG(1) << "CP_CONNECTOR: Job status update aborted (shutting down)"
<< ", printer id: " << printer_info_cloud_.printer_id
<< ", job id: " << job_details_.job_id_;
return; return;
} }
if (job_details_.job_id_.empty()) { if (job_details_.job_id_.empty()) {
VLOG(1) << "CP_CONNECTOR: Update job status aborted. Emtpy job id."; VLOG(1) << "CP_CONNECTOR: Job status update aborted (empty job id)"
<< ", printer id: " << printer_info_cloud_.printer_id;
return; return;
} }
VLOG(1) << "CP_CONNECTOR: Updating status, job id: "
<< job_details_.job_id_ << ", status: " << status;
if (error == SUCCESS) { if (error == SUCCESS) {
SetNextJSONHandler( SetNextJSONHandler(
&PrinterJobHandler::HandleSuccessStatusUpdateResponse); &PrinterJobHandler::HandleSuccessStatusUpdateResponse);
...@@ -508,9 +519,10 @@ void PrinterJobHandler::SetNextDataHandler(DataHandler handler) { ...@@ -508,9 +519,10 @@ void PrinterJobHandler::SetNextDataHandler(DataHandler handler) {
} }
void PrinterJobHandler::JobFailed(PrintJobError error) { void PrinterJobHandler::JobFailed(PrintJobError error) {
VLOG(1) << "CP_CONNECTOR: Job failed, printer id: " << VLOG(1) << "CP_CONNECTOR: Job failed"
printer_info_cloud_.printer_id << " job id: " << job_details_.job_id_ << << ", printer id: " << printer_info_cloud_.printer_id
" error: " << error; << ", job id: " << job_details_.job_id_
<< ", error: " << error;
if (!shutting_down_) { if (!shutting_down_) {
UpdateJobStatus(cloud_print::PRINT_JOB_STATUS_ERROR, error); UpdateJobStatus(cloud_print::PRINT_JOB_STATUS_ERROR, error);
// This job failed, but others may be pending. Schedule a check. // This job failed, but others may be pending. Schedule a check.
...@@ -519,8 +531,9 @@ void PrinterJobHandler::JobFailed(PrintJobError error) { ...@@ -519,8 +531,9 @@ void PrinterJobHandler::JobFailed(PrintJobError error) {
} }
void PrinterJobHandler::JobSpooled(cloud_print::PlatformJobId local_job_id) { void PrinterJobHandler::JobSpooled(cloud_print::PlatformJobId local_job_id) {
VLOG(1) << "CP_CONNECTOR: Job spooled, printer id: " VLOG(1) << "CP_CONNECTOR: Job spooled"
<< printer_info_cloud_.printer_id << ", job id: " << local_job_id; << ", printer id: " << printer_info_cloud_.printer_id
<< ", job id: " << local_job_id;
if (!shutting_down_) { if (!shutting_down_) {
local_job_id_ = local_job_id; local_job_id_ = local_job_id;
UpdateJobStatus(cloud_print::PRINT_JOB_STATUS_IN_PROGRESS, SUCCESS); UpdateJobStatus(cloud_print::PRINT_JOB_STATUS_IN_PROGRESS, SUCCESS);
...@@ -531,13 +544,13 @@ void PrinterJobHandler::JobSpooled(cloud_print::PlatformJobId local_job_id) { ...@@ -531,13 +544,13 @@ void PrinterJobHandler::JobSpooled(cloud_print::PlatformJobId local_job_id) {
bool PrinterJobHandler::UpdatePrinterInfo() { bool PrinterJobHandler::UpdatePrinterInfo() {
if (!printer_watcher_) { if (!printer_watcher_) {
LOG(ERROR) << "CP_CONNECTOR: Printer watcher is missing." LOG(ERROR) << "CP_CONNECTOR: Printer watcher is missing."
<< "Check printer server url for printer id: " << " Check printer server url for printer id: "
<< printer_info_cloud_.printer_id; << printer_info_cloud_.printer_id;
return false; return false;
} }
VLOG(1) << "CP_CONNECTOR: Update printer info, id: " VLOG(1) << "CP_CONNECTOR: Updating printer info"
<< printer_info_cloud_.printer_id; << ", printer id: " << printer_info_cloud_.printer_id;
// We need to update the parts of the printer info that have changed // We need to update the parts of the printer info that have changed
// (could be printer name, description, status or capabilities). // (could be printer name, description, status or capabilities).
// First asynchronously fetch the capabilities. // First asynchronously fetch the capabilities.
...@@ -562,8 +575,9 @@ bool PrinterJobHandler::HavePendingTasks() { ...@@ -562,8 +575,9 @@ bool PrinterJobHandler::HavePendingTasks() {
void PrinterJobHandler::FailedFetchingJobData() { void PrinterJobHandler::FailedFetchingJobData() {
if (!shutting_down_) { if (!shutting_down_) {
LOG(ERROR) << "CP_CONNECTOR: Failed fetching job data for printer: " << LOG(ERROR) << "CP_CONNECTOR: Failed fetching job data"
printer_info_.printer_name << ", job id: " << job_details_.job_id_; << ", printer name: " << printer_info_.printer_name
<< ", job id: " << job_details_.job_id_;
JobFailed(INVALID_JOB_DATA); JobFailed(INVALID_JOB_DATA);
} }
} }
...@@ -597,8 +611,8 @@ void PrinterJobHandler::OnReceivePrinterCaps( ...@@ -597,8 +611,8 @@ void PrinterJobHandler::OnReceivePrinterCaps(
caps_hash, mime_boundary, std::string(), &post_data); caps_hash, mime_boundary, std::string(), &post_data);
} }
} else { } else {
LOG(ERROR) << "Failed to get printer caps and defaults for printer: " LOG(ERROR) << "Failed to get printer caps and defaults"
<< printer_name; << ", printer name: " << printer_name;
} }
std::string tags_hash = std::string tags_hash =
...@@ -646,7 +660,8 @@ void PrinterJobHandler::OnReceivePrinterCaps( ...@@ -646,7 +660,8 @@ void PrinterJobHandler::OnReceivePrinterCaps(
std::string()); std::string());
} else { } else {
// We are done here. Go to the Stop state // We are done here. Go to the Stop state
VLOG(1) << "CP_CONNECTOR: Stopping PrinterJobHandler"; VLOG(1) << "CP_CONNECTOR: Stopping printer job handler"
<< ", printer name: " << printer_name;
MessageLoop::current()->PostTask( MessageLoop::current()->PostTask(
FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this)); FROM_HERE, base::Bind(&PrinterJobHandler::Stop, this));
} }
......
...@@ -146,10 +146,9 @@ bool PrintBackendCUPS::EnumeratePrinters(PrinterList* printer_list) { ...@@ -146,10 +146,9 @@ bool PrintBackendCUPS::EnumeratePrinters(PrinterList* printer_list) {
cups_dest_t* destinations = NULL; cups_dest_t* destinations = NULL;
int num_dests = GetDests(&destinations); int num_dests = GetDests(&destinations);
if ((num_dests == 0) && (cupsLastError() > IPP_OK_EVENTS_COMPLETE)) { if ((num_dests == 0) && (cupsLastError() > IPP_OK_EVENTS_COMPLETE)) {
VLOG(1) << "CP_CUPS: Error getting printers from CUPS server. Server: " VLOG(1) << "CUPS: Error getting printers from CUPS server"
<< print_server_url_ << ", server: " << print_server_url_
<< " Error: " << ", error: " << static_cast<int>(cupsLastError());
<< static_cast<int>(cupsLastError());
return false; return false;
} }
...@@ -197,7 +196,9 @@ bool PrintBackendCUPS::EnumeratePrinters(PrinterList* printer_list) { ...@@ -197,7 +196,9 @@ bool PrintBackendCUPS::EnumeratePrinters(PrinterList* printer_list) {
cupsFreeDests(num_dests, destinations); cupsFreeDests(num_dests, destinations);
VLOG(1) << "CUPS: Enumerated " << printer_list->size() << " printers."; VLOG(1) << "CUPS: Enumerated printers"
<< ", server: " << print_server_url_
<< ", # of printers: " << printer_list->size();
return true; return true;
} }
...@@ -214,12 +215,14 @@ bool PrintBackendCUPS::GetPrinterCapsAndDefaults( ...@@ -214,12 +215,14 @@ bool PrintBackendCUPS::GetPrinterCapsAndDefaults(
PrinterCapsAndDefaults* printer_info) { PrinterCapsAndDefaults* printer_info) {
DCHECK(printer_info); DCHECK(printer_info);
VLOG(1) << "CUPS: Getting Caps and Defaults for: " << printer_name; VLOG(1) << "CUPS: Getting caps and defaults"
<< ", printer name: " << printer_name;
FilePath ppd_path(GetPPD(printer_name.c_str())); FilePath ppd_path(GetPPD(printer_name.c_str()));
// In some cases CUPS failed to get ppd file. // In some cases CUPS failed to get ppd file.
if (ppd_path.empty()) { if (ppd_path.empty()) {
LOG(ERROR) << "CUPS: Failed to get PPD for: " << printer_name; LOG(ERROR) << "CUPS: Failed to get PPD"
<< ", printer name: " << printer_name;
return false; return false;
} }
...@@ -344,7 +347,8 @@ FilePath PrintBackendCUPS::GetPPD(const char* name) { ...@@ -344,7 +347,8 @@ FilePath PrintBackendCUPS::GetPPD(const char* name) {
ipp_status_t error_code = cupsLastError(); ipp_status_t error_code = cupsLastError();
int http_error = httpError(http.http()); int http_error = httpError(http.http());
if (error_code > IPP_OK_EVENTS_COMPLETE || http_error != 0) { if (error_code > IPP_OK_EVENTS_COMPLETE || http_error != 0) {
LOG(ERROR) << "Error downloading PPD file for: " << name LOG(ERROR) << "Error downloading PPD file"
<< ", name: " << name
<< ", CUPS error: " << static_cast<int>(error_code) << ", CUPS error: " << static_cast<int>(error_code)
<< ", HTTP error: " << http_error; << ", HTTP error: " << http_error;
file_util::Delete(ppd_path, false); file_util::Delete(ppd_path, false);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment