Changeset c4fb5ecd in mainline

Timestamp:

2011-06-18T19:18:41Z (13 years ago)

Author:

Vojtech Horky <vojtechhorky@…>

Branches:

lfn, master, serial, ticket/834-toolchain-update, topic/msim-upgrade, topic/simplify-dev-export

Children:

497b6f31

Parents:

84eb7432

Message:

Less logging in USB host controller drivers

Many of the debug messages were degraded to debug2 level or
completely removed. Also added formatting string for unified
dump of USB transfer batches.

Warnings in EHCI stub use debug level now.

Location:

uspace

Files:

• drv/ehci_hcd/hc_iface.c (modified) (1 diff)
• drv/ohci/hc.c (modified) (3 diffs)
• drv/ohci/root_hub.c (modified) (13 diffs)
• drv/uhci_hcd/batch.c (modified) (9 diffs)
• drv/uhci_hcd/hw_struct/transfer_descriptor.c (modified) (1 diff)
• drv/uhci_hcd/iface.c (modified) (3 diffs)
• drv/uhci_hcd/transfer_list.c (modified) (2 diffs)
• lib/usbhost/include/usb/host/batch.h (modified) (1 diff)
• lib/usbhost/src/batch.c (modified) (3 diffs)

uspace/drv/ehci_hcd/hc_iface.c

@@ -45 +45 @@
 
 #define UNSUPPORTED(methodname) \
-        usb_log_warning("Unsupported interface method `%s()' in %s:%d.\n", \
+        usb_log_debug("Client called unsupported interface method " \
+            "`%s()' in %s:%d.\n", \
             methodname, __FILE__, __LINE__)
 

uspace/drv/ohci/hc.c

@@ -65 +65 @@
             device_keeper_get_free_address(&instance->manager, USB_SPEED_FULL);
         if (hub_address <= 0) {
-                usb_log_error("Failed(%d) to get OHCI root hub address.\n",
-                    hub_address);
+                usb_log_error("Failed to get OHCI root hub address: %s\n",
+                    str_error(hub_address));
                 return hub_address;
         }
@@ -445 +445 @@
         /* HC is in reset (hw startup) => no other driver
          * maintain reset for at least the time specified in USB spec (50 ms)*/
-        usb_log_info("HC found in reset.\n");
+        usb_log_debug("Host controller found in reset state.\n");
         async_usleep(50000);
 }
@@ -516 +516 @@
 
         instance->registers->control &= (C_HCFS_OPERATIONAL << C_HCFS_SHIFT);
-        usb_log_info("OHCI HC up and running(%x).\n",
+        usb_log_debug("OHCI HC up and running (ctl_reg=0x%x).\n",
             instance->registers->control);
 }

uspace/drv/ohci/root_hub.c

@@ -232 +232 @@
                 return ENOMEM;
 
-        usb_log_info("OHCI root hub with %zu ports initialized.\n",
+        usb_log_info("Root hub (%zu ports) initialized.\n",
             instance->port_count);
 
@@ -521 +521 @@
                 case USB_DESCTYPE_HUB:
                 {
-                        usb_log_debug("USB_DESCTYPE_HUB\n");
+                        usb_log_debug2("USB_DESCTYPE_HUB\n");
                         result_descriptor = instance->hub_descriptor;
                         size = instance->descriptor_size;
@@ -528 +528 @@
                 case USB_DESCTYPE_DEVICE:
                 {
-                        usb_log_debug("USB_DESCTYPE_DEVICE\n");
+                        usb_log_debug2("USB_DESCTYPE_DEVICE\n");
                         result_descriptor = &ohci_rh_device_descriptor;
                         size = sizeof (ohci_rh_device_descriptor);
@@ -535 +535 @@
                 case USB_DESCTYPE_CONFIGURATION:
                 {
-                        usb_log_debug("USB_DESCTYPE_CONFIGURATION\n");
+                        usb_log_debug2("USB_DESCTYPE_CONFIGURATION\n");
                         result_descriptor = instance->descriptors.configuration;
                         size = instance->descriptors.configuration_size;
@@ -542 +542 @@
                 case USB_DESCTYPE_INTERFACE:
                 {
-                        usb_log_debug("USB_DESCTYPE_INTERFACE\n");
+                        usb_log_debug2("USB_DESCTYPE_INTERFACE\n");
                         result_descriptor = &ohci_rh_iface_descriptor;
                         size = sizeof (ohci_rh_iface_descriptor);
@@ -549 +549 @@
                 case USB_DESCTYPE_ENDPOINT:
                 {
-                        usb_log_debug("USB_DESCTYPE_ENDPOINT\n");
+                        usb_log_debug2("USB_DESCTYPE_ENDPOINT\n");
                         result_descriptor = &ohci_rh_ep_descriptor;
                         size = sizeof (ohci_rh_ep_descriptor);
@@ -556 +556 @@
                 default:
                 {
-                        usb_log_debug("USB_DESCTYPE_EINVAL %d \n",
+                        usb_log_debug2("USB_DESCTYPE_EINVAL %d \n",
                             setup_request->value);
-                        usb_log_debug("\ttype %d\n\trequest %d\n\tvalue "
+                        usb_log_debug2("\ttype %d\n\trequest %d\n\tvalue "
                             "%d\n\tindex %d\n\tlen %d\n ",
                             setup_request->request_type,
@@ -789 +789 @@
                 }
                 if (setup_request->request_type == USB_HUB_REQ_TYPE_SET_PORT_FEATURE) {
-                        usb_log_debug("USB_HUB_REQ_TYPE_SET_PORT_FEATURE\n");
+                        usb_log_debug2("USB_HUB_REQ_TYPE_SET_PORT_FEATURE\n");
                         return process_port_feature_clear_request(instance,
                             setup_request->value,
@@ -854 +854 @@
                 return EINVAL;
         }
-        usb_log_info("CTRL packet: %s.\n",
+        usb_log_debug("CTRL packet: %s.\n",
             usb_debug_str_buffer(
             (const uint8_t *) request->setup_buffer, 8, 8));
@@ -864 +864 @@
                 case USB_DEVREQ_GET_DESCRIPTOR:
                 case USB_DEVREQ_GET_CONFIGURATION:
-                        usb_log_debug("Processing request with output\n");
+                        usb_log_debug2("Processing request with output\n");
                         opResult = process_request_with_output(
                             instance, request);
@@ -871 +871 @@
                 case USB_DEVREQ_SET_FEATURE:
                 case USB_DEVREQ_SET_ADDRESS:
-                        usb_log_debug("Processing request without "
+                        usb_log_debug2("Processing request without "
                             "additional data\n");
                         opResult = process_request_without_data(
@@ -878 +878 @@
                 case USB_DEVREQ_SET_DESCRIPTOR:
                 case USB_DEVREQ_SET_CONFIGURATION:
-                        usb_log_debug("Processing request with "
-                            "input\n");
+                        usb_log_debug2("Processing request with input\n");
                         opResult = process_request_with_input(
                             instance, request);
@@ -885 +884 @@
                         break;
                 default:
-                        usb_log_warning("Received unsuported request: "
-                            "%d\n",
-                            setup_request->request
-                            );
+                        usb_log_warning("Received unsupported request: %d.\n",
+                            setup_request->request);
                         opResult = ENOTSUP;
         }

uspace/drv/uhci_hcd/batch.c

@@ -147 +147 @@
             + sizeof(qh_t);
         void *data_buffer = setup + setup_size;
-        usb_target_t target =
-            { .address = ep->address, .endpoint = ep->endpoint };
         usb_transfer_batch_init(instance, ep, buffer, data_buffer, buffer_size,
             setup, setup_size, func_in, func_out, arg, fun,
@@ -154 +152 @@
 
         memcpy(instance->setup_buffer, setup_buffer, setup_size);
-        usb_log_debug("Batch(%p) %d:%d memory structures ready.\n",
-            instance, target.address, target.endpoint);
+        usb_log_debug2("Batch %p " USB_TRANSFER_BATCH_FMT
+            " memory structures ready.\n", instance,
+            USB_TRANSFER_BATCH_ARGS(*instance));
         return instance;
 }
@@ -205 +204 @@
         return true;
 }
+
+#define LOG_BATCH_INITIALIZED(batch, name) \
+        usb_log_debug2("Batch %p %s " USB_TRANSFER_BATCH_FMT " initialized.\n", \
+            (batch), (name), USB_TRANSFER_BATCH_ARGS(*(batch)))
+
 /*----------------------------------------------------------------------------*/
 /** Prepares control write transfer.
@@ -219 +223 @@
         batch_control(instance, USB_PID_OUT, USB_PID_IN);
         instance->next_step = usb_transfer_batch_call_out_and_dispose;
-        usb_log_debug("Batch(%p) CONTROL WRITE initialized.\n", instance);
+        LOG_BATCH_INITIALIZED(instance, "control write");
 }
 /*----------------------------------------------------------------------------*/
@@ -233 +237 @@
         batch_control(instance, USB_PID_IN, USB_PID_OUT);
         instance->next_step = usb_transfer_batch_call_in_and_dispose;
-        usb_log_debug("Batch(%p) CONTROL READ initialized.\n", instance);
+        LOG_BATCH_INITIALIZED(instance, "control read");
 }
 /*----------------------------------------------------------------------------*/
@@ -247 +251 @@
         batch_data(instance, USB_PID_IN);
         instance->next_step = usb_transfer_batch_call_in_and_dispose;
-        usb_log_debug("Batch(%p) INTERRUPT IN initialized.\n", instance);
+        LOG_BATCH_INITIALIZED(instance, "interrupt in");
 }
 /*----------------------------------------------------------------------------*/
@@ -263 +267 @@
         batch_data(instance, USB_PID_OUT);
         instance->next_step = usb_transfer_batch_call_out_and_dispose;
-        usb_log_debug("Batch(%p) INTERRUPT OUT initialized.\n", instance);
+        LOG_BATCH_INITIALIZED(instance, "interrupt out");
 }
 /*----------------------------------------------------------------------------*/
@@ -277 +281 @@
         batch_data(instance, USB_PID_IN);
         instance->next_step = usb_transfer_batch_call_in_and_dispose;
-        usb_log_debug("Batch(%p) BULK IN initialized.\n", instance);
+        LOG_BATCH_INITIALIZED(instance, "bulk in");
 }
 /*----------------------------------------------------------------------------*/
@@ -293 +297 @@
         batch_data(instance, USB_PID_OUT);
         instance->next_step = usb_transfer_batch_call_out_and_dispose;
-        usb_log_debug("Batch(%p) BULK OUT initialized.\n", instance);
+        LOG_BATCH_INITIALIZED(instance, "bulk out");
 }
 /*----------------------------------------------------------------------------*/

uspace/drv/uhci_hcd/hw_struct/transfer_descriptor.c

@@ -103 +103 @@
         td_print_status(instance);
         if (pid == USB_PID_SETUP) {
-                usb_log_debug("SETUP BUFFER: %s\n",
+                usb_log_debug2("SETUP BUFFER: %s\n",
                     usb_debug_str_buffer(buffer, 8, 8));
         }

uspace/drv/uhci_hcd/iface.c

@@ -64 +64 @@
         }
 
-        usb_log_debug("%s %d:%d %zu(%zu).\n",
+        usb_log_debug2("%s %d:%d %zu(%zu).\n",
             name, target.address, target.endpoint, size, ep->max_packet_size);
 
@@ -172 +172 @@
                 speed = ep_speed;
         }
-        usb_log_debug("Register endpoint %d:%d %s %s(%d) %zu(%zu) %u.\n",
+        usb_log_debug("Register endpoint %d:%d %s-%s %s %zuB %ums.\n",
             address, endpoint, usb_str_transfer_type(transfer_type),
-            usb_str_speed(speed), direction, size, max_packet_size, interval);
+            usb_str_direction(direction), usb_str_speed(speed),
+            max_packet_size, interval);
 
         return usb_endpoint_manager_add_ep(&hc->ep_manager, address, endpoint,
@@ -187 +188 @@
         hc_t *hc = fun_to_hc(fun);
         assert(hc);
-        usb_log_debug("Unregister endpoint %d:%d %d.\n",
-            address, endpoint, direction);
+        usb_log_debug("Unregister endpoint %d:%d %s.\n",
+            address, endpoint, usb_str_direction(direction));
         return usb_endpoint_manager_unregister_ep(&hc->ep_manager, address,
             endpoint, direction);

uspace/drv/uhci_hcd/transfer_list.c

@@ -141 +141 @@
         list_append(&batch->link, &instance->batch_list);
 
-        usb_transfer_batch_t *first = list_get_instance(
-            instance->batch_list.next, usb_transfer_batch_t, link);
-        usb_log_debug("Batch(%p) added to queue %s, first is %p.\n",
-                batch, instance->name, first);
+        usb_log_debug("Batch %p " USB_TRANSFER_BATCH_FMT " scheduled in queue %s.\n",
+            batch, USB_TRANSFER_BATCH_ARGS(*batch), instance->name);
         fibril_mutex_unlock(&instance->guard);
 }
@@ -234 +232 @@
         /* Remove from the batch list */
         list_remove(&batch->link);
-        usb_log_debug("Batch(%p) removed (%s) from %s, next: %x.\n",
-            batch, qpos, instance->name, batch_qh(batch)->next);
+        usb_log_debug2("Batch %p " USB_TRANSFER_BATCH_FMT " removed (%s) "
+            "from %s, next: %x.\n",
+            batch, USB_TRANSFER_BATCH_ARGS(*batch),
+            qpos, instance->name, batch_qh(batch)->next);
 }
 /**

uspace/lib/usbhost/include/usb/host/batch.h

@@ -61 +61 @@
 };
 
+/** Printf formatting string for dumping usb_transfer_batch_t. */
+#define USB_TRANSFER_BATCH_FMT "[%d:%d %s %s-%s %zuB/%zu]"
+
+/** Printf arguments for dumping usb_transfer_batch_t.
+ * @param batch USB transfer batch to be dumped.
+ */
+#define USB_TRANSFER_BATCH_ARGS(batch) \
+        (batch).ep->address, (batch).ep->endpoint, \
+        usb_str_speed((batch).ep->speed), \
+        usb_str_transfer_type_short((batch).ep->transfer_type), \
+        usb_str_direction((batch).ep->direction), \
+        (batch).buffer_size, (batch).ep->max_packet_size
+
+
 void usb_transfer_batch_init(
     usb_transfer_batch_t *instance,

uspace/lib/usbhost/src/batch.c

@@ -128 +128 @@
         memcpy(instance->buffer, instance->data_buffer, instance->buffer_size);
 
-        usb_log_debug("Batch(%p) done (T%d.%d, %s %s in, %zuB): %s (%d).\n",
-            instance, instance->ep->address, instance->ep->endpoint,
-            usb_str_speed(instance->ep->speed),
-            usb_str_transfer_type_short(instance->ep->transfer_type),
-            instance->transfered_size, str_error(instance->error),
-            instance->error);
+        usb_log_debug("Batch %p " USB_TRANSFER_BATCH_FMT " completed (%zuB): %s.\n",
+            instance, USB_TRANSFER_BATCH_ARGS(*instance),
+            instance->transfered_size, str_error(instance->error));
 
         instance->callback_in(instance->fun, instance->error,
@@ -148 +145 @@
         assert(instance->callback_out);
 
-        usb_log_debug("Batch(%p) done (T%d.%d, %s %s out): %s (%d).\n",
-            instance, instance->ep->address, instance->ep->endpoint,
-            usb_str_speed(instance->ep->speed),
-            usb_str_transfer_type_short(instance->ep->transfer_type),
-            str_error(instance->error), instance->error);
+        usb_log_debug("Batch %p " USB_TRANSFER_BATCH_FMT " completed: %s.\n",
+            instance, USB_TRANSFER_BATCH_ARGS(*instance),
+            str_error(instance->error));
 
         instance->callback_out(instance->fun,
@@ -165 +160 @@
 {
         assert(instance);
-        usb_log_debug("Batch(%p) disposing.\n", instance);
+        usb_log_debug2("Batch %p " USB_TRANSFER_BATCH_FMT " disposing.\n",
+            instance, USB_TRANSFER_BATCH_ARGS(*instance));
         if (instance->private_data) {
                 assert(instance->private_data_dtor);