Changeset a1732929 in mainline for uspace/drv/bus/usb/ohci

Timestamp:

2018-01-15T17:04:34Z (8 years ago)

Author:

Ondřej Hlavatý <aearsis@…>

Branches:

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

Children:

9ff99e8

Parents:

c1a966e

git-author:

Ondřej Hlavatý <aearsis@…> (2018-01-15 17:04:32)

git-committer:

Ondřej Hlavatý <aearsis@…> (2018-01-15 17:04:34)

Message:

usb: unified logging

Use logger instead of printf. Logger adds newlines automatically.

Location:

uspace/drv/bus/usb/ohci

Files:

• endpoint_list.c (modified) (5 diffs)
• hc.c (modified) (26 diffs)
• ohci_batch.c (modified) (11 diffs)
• ohci_rh.c (modified) (6 diffs)

uspace/drv/bus/usb/ohci/endpoint_list.c

@@ -57 +57 @@
         instance->list_head = malloc32(sizeof(ed_t));
         if (!instance->list_head) {
-                usb_log_error("Failed to allocate list head.\n");
+                usb_log_error("Failed to allocate list head.");
                 return ENOMEM;
         }
         instance->list_head_pa = addr_to_phys(instance->list_head);
-        usb_log_debug2("Transfer list %s setup with ED: %p(0x%0" PRIx32 ")).\n",
+        usb_log_debug2("Transfer list %s setup with ED: %p(0x%0" PRIx32 ")).",
             name, instance->list_head, instance->list_head_pa);
 
@@ -96 +96 @@
         assert(instance);
         assert(ep);
-        usb_log_debug2("Queue %s: Adding endpoint(%p).\n", instance->name, ep);
+        usb_log_debug2("Queue %s: Adding endpoint(%p).", instance->name, ep);
 
         fibril_mutex_lock(&instance->guard);
@@ -126 +126 @@
         ohci_endpoint_t *first = list_get_instance(
             list_first(&instance->endpoint_list), ohci_endpoint_t, link);
-        usb_log_debug("HCD EP(%p) added to list %s, first is %p(%p).\n",
+        usb_log_debug("HCD EP(%p) added to list %s, first is %p(%p).",
                 ep, instance->name, first, first->ed);
         if (last_ed == instance->list_head) {
-                usb_log_debug2("%s head ED(%p-0x%0" PRIx32 "): %x:%x:%x:%x.\n",
+                usb_log_debug2("%s head ED(%p-0x%0" PRIx32 "): %x:%x:%x:%x.",
                     instance->name, last_ed, instance->list_head_pa,
                     last_ed->status, last_ed->td_tail, last_ed->td_head,
@@ -151 +151 @@
         fibril_mutex_lock(&instance->guard);
 
-        usb_log_debug2("Queue %s: removing endpoint(%p).\n", instance->name, ep);
+        usb_log_debug2("Queue %s: removing endpoint(%p).", instance->name, ep);
 
         const char *qpos = NULL;
@@ -171 +171 @@
         write_barrier();
 
-        usb_log_debug("HCD EP(%p) removed (%s) from %s, next %x.\n",
+        usb_log_debug("HCD EP(%p) removed (%s) from %s, next %x.",
             ep, qpos, instance->name, ep->ed->next);
 

uspace/drv/bus/usb/ohci/hc.c

@@ -136 +136 @@
         OHCI_WR(code->cmds[1].value, OHCI_USED_INTERRUPTS);
 
-        usb_log_debug("Memory mapped regs at %p (size %zu), IRQ %d.\n",
+        usb_log_debug("Memory mapped regs at %p (size %zu), IRQ %d.",
             RNGABSPTR(regs), RNGSZ(regs), hw_res->irqs.irqs[0]);
 
@@ -160 +160 @@
             (void **) &instance->registers);
         if (ret != EOK) {
-                usb_log_error("Failed to gain access to registers: %s.\n",
+                usb_log_error("Failed to gain access to registers: %s.",
                     str_error(ret));
                 return ret;
         }
-        usb_log_debug("Device registers at %" PRIx64 " (%zuB) accessible.\n",
+        usb_log_debug("Device registers at %" PRIx64 " (%zuB) accessible.",
             hw_res->mem_ranges.ranges[0].address.absolute,
             hw_res->mem_ranges.ranges[0].size);
@@ -173 +173 @@
         ret = hc_init_memory(instance);
         if (ret != EOK) {
-                usb_log_error("Failed to create OHCI memory structures: %s.\n",
+                usb_log_error("Failed to create OHCI memory structures: %s.",
                     str_error(ret));
                 // TODO: We should disable pio access here
@@ -293 +293 @@
         /* Check for root hub communication */
         if (batch->target.address == ohci_rh_get_address(&hc->rh)) {
-                usb_log_debug("OHCI root hub request.\n");
+                usb_log_debug("OHCI root hub request.");
                 return ohci_rh_schedule(&hc->rh, batch);
         }
@@ -341 +341 @@
         if ((status & ~I_SF) == 0) /* ignore sof status */
                 return;
-        usb_log_debug2("OHCI(%p) interrupt: %x.\n", hc, status);
+        usb_log_debug2("OHCI(%p) interrupt: %x.", hc, status);
         if (status & I_RHSC)
                 ohci_rh_interrupt(&hc->rh);
@@ -347 +347 @@
         if (status & I_WDH) {
                 fibril_mutex_lock(&hc->guard);
-                usb_log_debug2("HCCA: %p-%#" PRIx32 " (%p).\n", hc->hcca,
+                usb_log_debug2("HCCA: %p-%#" PRIx32 " (%p).", hc->hcca,
                     OHCI_RD(hc->registers->hcca),
                     (void *) addr_to_phys(hc->hcca));
-                usb_log_debug2("Periodic current: %#" PRIx32 ".\n",
+                usb_log_debug2("Periodic current: %#" PRIx32 ".",
                     OHCI_RD(hc->registers->periodic_current));
 
@@ -370 +370 @@
 
         if (status & I_UE) {
-                usb_log_fatal("Error like no other!\n");
+                usb_log_fatal("Error like no other!");
                 hc_start(&hc->base);
         }
@@ -387 +387 @@
         hc_t *instance = hcd_to_hc(hcd);
 
-        usb_log_debug("Requesting OHCI control.\n");
+        usb_log_debug("Requesting OHCI control.");
         if (OHCI_RD(instance->registers->revision) & R_LEGACY_FLAG) {
                 /* Turn off legacy emulation, it should be enough to zero
@@ -396 +396 @@
                 volatile uint32_t *ohci_emulation_reg =
                 (uint32_t*)((char*)instance->registers + LEGACY_REGS_OFFSET);
-                usb_log_debug("OHCI legacy register %p: %x.\n",
+                usb_log_debug("OHCI legacy register %p: %x.",
                     ohci_emulation_reg, OHCI_RD(*ohci_emulation_reg));
                 /* Zero everything but A20State */
@@ -402 +402 @@
                 OHCI_CLR(*ohci_emulation_reg, ~0x100);
                 usb_log_debug(
-                    "OHCI legacy register (should be 0 or 0x100) %p: %x.\n",
+                    "OHCI legacy register (should be 0 or 0x100) %p: %x.",
                     ohci_emulation_reg, OHCI_RD(*ohci_emulation_reg));
         }
@@ -408 +408 @@
         /* Interrupt routing enabled => smm driver is active */
         if (OHCI_RD(instance->registers->control) & C_IR) {
-                usb_log_debug("SMM driver: request ownership change.\n");
+                usb_log_debug("SMM driver: request ownership change.");
                 // TODO: should we ack interrupts before doing this?
                 OHCI_SET(instance->registers->command_status, CS_OCR);
@@ -415 +415 @@
                         async_usleep(1000);
                 }
-                usb_log_info("SMM driver: Ownership taken.\n");
+                usb_log_info("SMM driver: Ownership taken.");
                 C_HCFS_SET(instance->registers->control, C_HCFS_RESET);
                 async_usleep(50000);
@@ -424 +424 @@
         /* Interrupt routing disabled && status != USB_RESET => BIOS active */
         if (hc_status != C_HCFS_RESET) {
-                usb_log_debug("BIOS driver found.\n");
+                usb_log_debug("BIOS driver found.");
                 if (hc_status == C_HCFS_OPERATIONAL) {
-                        usb_log_info("BIOS driver: HC operational.\n");
+                        usb_log_info("BIOS driver: HC operational.");
                         return EOK;
                 }
@@ -432 +432 @@
                 C_HCFS_SET(instance->registers->control, C_HCFS_RESUME);
                 async_usleep(20000);
-                usb_log_info("BIOS driver: HC resumed.\n");
+                usb_log_info("BIOS driver: HC resumed.");
                 return EOK;
         }
@@ -438 +438 @@
         /* HC is in reset (hw startup) => no other driver
          * maintain reset for at least the time specified in USB spec (50 ms)*/
-        usb_log_debug("Host controller found in reset state.\n");
+        usb_log_debug("Host controller found in reset state.");
         async_usleep(50000);
         return EOK;
@@ -454 +454 @@
         /* OHCI guide page 42 */
         assert(instance);
-        usb_log_debug2("Started hc initialization routine.\n");
+        usb_log_debug2("Started hc initialization routine.");
 
         /* Save contents of fm_interval register */
         const uint32_t fm_interval = OHCI_RD(instance->registers->fm_interval);
-        usb_log_debug2("Old value of HcFmInterval: %x.\n", fm_interval);
+        usb_log_debug2("Old value of HcFmInterval: %x.", fm_interval);
 
         /* Reset hc */
-        usb_log_debug2("HC reset.\n");
+        usb_log_debug2("HC reset.");
         size_t time = 0;
         OHCI_WR(instance->registers->command_status, CS_HCR);
@@ -468 +468 @@
                 time += 10;
         }
-        usb_log_debug2("HC reset complete in %zu us.\n", time);
+        usb_log_debug2("HC reset complete in %zu us.", time);
 
         /* Restore fm_interval */
@@ -475 +475 @@
 
         /* hc is now in suspend state */
-        usb_log_debug2("HC should be in suspend state(%x).\n",
+        usb_log_debug2("HC should be in suspend state(%x).",
             OHCI_RD(instance->registers->control));
 
@@ -484 +484 @@
         OHCI_WR(instance->registers->bulk_head,
             instance->lists[USB_TRANSFER_BULK].list_head_pa);
-        usb_log_debug2("Bulk HEAD set to: %p (%#" PRIx32 ").\n",
+        usb_log_debug2("Bulk HEAD set to: %p (%#" PRIx32 ").",
             instance->lists[USB_TRANSFER_BULK].list_head,
             instance->lists[USB_TRANSFER_BULK].list_head_pa);
@@ -490 +490 @@
         OHCI_WR(instance->registers->control_head,
             instance->lists[USB_TRANSFER_CONTROL].list_head_pa);
-        usb_log_debug2("Control HEAD set to: %p (%#" PRIx32 ").\n",
+        usb_log_debug2("Control HEAD set to: %p (%#" PRIx32 ").",
             instance->lists[USB_TRANSFER_CONTROL].list_head,
             instance->lists[USB_TRANSFER_CONTROL].list_head_pa);
@@ -496 +496 @@
         /* Enable queues */
         OHCI_SET(instance->registers->control, (C_PLE | C_IE | C_CLE | C_BLE));
-        usb_log_debug("Queues enabled(%x).\n",
+        usb_log_debug("Queues enabled(%x).",
             OHCI_RD(instance->registers->control));
 
@@ -503 +503 @@
                 OHCI_WR(instance->registers->interrupt_enable,
                     OHCI_USED_INTERRUPTS);
-                usb_log_debug("Enabled interrupts: %x.\n",
+                usb_log_debug("Enabled interrupts: %x.",
                     OHCI_RD(instance->registers->interrupt_enable));
                 OHCI_WR(instance->registers->interrupt_enable, I_MI);
@@ -513 +513 @@
         OHCI_WR(instance->registers->periodic_start,
             ((frame_length / 10) * 9) & PS_MASK << PS_SHIFT);
-        usb_log_debug2("All periodic start set to: %x(%u - 90%% of %d).\n",
+        usb_log_debug2("All periodic start set to: %x(%u - 90%% of %d).",
             OHCI_RD(instance->registers->periodic_start),
             OHCI_RD(instance->registers->periodic_start), frame_length);
         C_HCFS_SET(instance->registers->control, C_HCFS_OPERATIONAL);
-        usb_log_debug("OHCI HC up and running (ctl_reg=0x%x).\n",
+        usb_log_debug("OHCI HC up and running (ctl_reg=0x%x).",
             OHCI_RD(instance->registers->control));
 
@@ -536 +536 @@
         const int ret = endpoint_list_init(&instance->lists[type], name); \
         if (ret != EOK) { \
-                usb_log_error("Failed to setup %s endpoint list: %s.\n", \
+                usb_log_error("Failed to setup %s endpoint list: %s.", \
                     name, str_error(ret)); \
                 endpoint_list_fini(&instance->lists[USB_TRANSFER_ISOCHRONOUS]);\
@@ -577 +577 @@
         if (instance->hcca == NULL)
                 return ENOMEM;
-        usb_log_debug2("OHCI HCCA initialized at %p.\n", instance->hcca);
+        usb_log_debug2("OHCI HCCA initialized at %p.", instance->hcca);
 
         for (unsigned i = 0; i < HCCA_INT_EP_COUNT; ++i) {
@@ -583 +583 @@
                     instance->lists[USB_TRANSFER_INTERRUPT].list_head_pa);
         }
-        usb_log_debug2("Interrupt HEADs set to: %p (%#" PRIx32 ").\n",
+        usb_log_debug2("Interrupt HEADs set to: %p (%#" PRIx32 ").",
             instance->lists[USB_TRANSFER_INTERRUPT].list_head,
             instance->lists[USB_TRANSFER_INTERRUPT].list_head_pa);

uspace/drv/bus/usb/ohci/ohci_batch.c

@@ -175 +175 @@
         assert(ohci_batch);
 
-        usb_log_debug("Batch %p checking %zu td(s) for completion.\n",
+        usb_log_debug("Batch %p checking %zu td(s) for completion.",
             &ohci_batch->base, ohci_batch->td_count);
-        usb_log_debug2("ED: %08x:%08x:%08x:%08x.\n",
+        usb_log_debug2("ED: %08x:%08x:%08x:%08x.",
             ohci_batch->ed->status, ohci_batch->ed->td_head,
             ohci_batch->ed->td_tail, ohci_batch->ed->next);
@@ -196 +196 @@
         for (size_t i = 0; i < ohci_batch->td_count; ++i) {
                 assert(ohci_batch->tds[i] != NULL);
-                usb_log_debug("TD %zu: %08x:%08x:%08x:%08x.\n", i,
+                usb_log_debug("TD %zu: %08x:%08x:%08x:%08x.", i,
                     ohci_batch->tds[i]->status, ohci_batch->tds[i]->cbp,
                     ohci_batch->tds[i]->next, ohci_batch->tds[i]->be);
@@ -217 +217 @@
                             -= td_remain_size(ohci_batch->tds[i]);
                 } else {
-                        usb_log_debug("Batch %p found error TD(%zu):%08x.\n",
+                        usb_log_debug("Batch %p found error TD(%zu):%08x.",
                             &ohci_batch->base, i,
                             ohci_batch->tds[i]->status);
@@ -295 +295 @@
         assert(dir == USB_DIRECTION_IN || dir == USB_DIRECTION_OUT);
 
-        usb_log_debug("Using ED(%p): %08x:%08x:%08x:%08x.\n", ohci_batch->ed,
+        usb_log_debug("Using ED(%p): %08x:%08x:%08x:%08x.", ohci_batch->ed,
             ohci_batch->ed->status, ohci_batch->ed->td_tail,
             ohci_batch->ed->td_head, ohci_batch->ed->next);
@@ -312 +312 @@
             ohci_batch->tds[0], ohci_batch->tds[1], USB_DIRECTION_BOTH,
             buffer, USB_SETUP_PACKET_SIZE, toggle);
-        usb_log_debug("Created CONTROL SETUP TD: %08x:%08x:%08x:%08x.\n",
+        usb_log_debug("Created CONTROL SETUP TD: %08x:%08x:%08x:%08x.",
             ohci_batch->tds[0]->status, ohci_batch->tds[0]->cbp,
             ohci_batch->tds[0]->next, ohci_batch->tds[0]->be);
@@ -328 +328 @@
                     ohci_batch->tds[td_current + 1],
                     data_dir, buffer, transfer_size, toggle);
-                usb_log_debug("Created CONTROL DATA TD: %08x:%08x:%08x:%08x.\n",
+                usb_log_debug("Created CONTROL DATA TD: %08x:%08x:%08x:%08x.",
                     ohci_batch->tds[td_current]->status,
                     ohci_batch->tds[td_current]->cbp,
@@ -344 +344 @@
         td_init(ohci_batch->tds[td_current], ohci_batch->tds[td_current + 1],
             status_dir, NULL, 0, 1);
-        usb_log_debug("Created CONTROL STATUS TD: %08x:%08x:%08x:%08x.\n",
+        usb_log_debug("Created CONTROL STATUS TD: %08x:%08x:%08x:%08x.",
             ohci_batch->tds[td_current]->status,
             ohci_batch->tds[td_current]->cbp,
@@ -350 +350 @@
             ohci_batch->tds[td_current]->be);
         usb_log_debug2(
-            "Batch %p %s %s " USB_TRANSFER_BATCH_FMT " initialized.\n", \
+            "Batch %p %s %s " USB_TRANSFER_BATCH_FMT " initialized.", \
             &ohci_batch->base,
             usb_str_transfer_type(ohci_batch->base.ep->transfer_type),
@@ -371 +371 @@
         usb_direction_t dir = ohci_batch->base.dir;
         assert(dir == USB_DIRECTION_IN || dir == USB_DIRECTION_OUT);
-        usb_log_debug("Using ED(%p): %08x:%08x:%08x:%08x.\n", ohci_batch->ed,
+        usb_log_debug("Using ED(%p): %08x:%08x:%08x:%08x.", ohci_batch->ed,
             ohci_batch->ed->status, ohci_batch->ed->td_tail,
             ohci_batch->ed->td_head, ohci_batch->ed->next);
@@ -386 +386 @@
                     dir, buffer, transfer_size, -1);
 
-                usb_log_debug("Created DATA TD: %08x:%08x:%08x:%08x.\n",
+                usb_log_debug("Created DATA TD: %08x:%08x:%08x:%08x.",
                     ohci_batch->tds[td_current]->status,
                     ohci_batch->tds[td_current]->cbp,
@@ -398 +398 @@
         }
         usb_log_debug2(
-            "Batch %p %s %s " USB_TRANSFER_BATCH_FMT " initialized.\n", \
+            "Batch %p %s %s " USB_TRANSFER_BATCH_FMT " initialized.", \
             &ohci_batch->base,
             usb_str_transfer_type(ohci_batch->base.ep->transfer_type),

uspace/drv/bus/usb/ohci/ohci_rh.c

@@ -114 +114 @@
         instance->registers = regs;
         instance->port_count = OHCI_RD(regs->rh_desc_a) & RHDA_NDS_MASK;
-        usb_log_debug2("rh_desc_a: %x.\n", OHCI_RD(regs->rh_desc_a));
+        usb_log_debug2("rh_desc_a: %x.", OHCI_RD(regs->rh_desc_a));
         if (instance->port_count > OHCI_MAX_PORTS) {
                 usb_log_warning("OHCI specification does not allow %d ports. "
-                    "Max %d ports will be used.\n", instance->port_count,
+                    "Max %d ports will be used.", instance->port_count,
                     OHCI_MAX_PORTS);
                 instance->port_count = OHCI_MAX_PORTS;
         }
-        usb_log_info("%s: Found %u ports.\n", name, instance->port_count);
+        usb_log_info("%s: Found %u ports.", name, instance->port_count);
 
 #if defined OHCI_POWER_SWITCH_no
-        usb_log_info("%s: Set power mode to no power switching.\n", name);
+        usb_log_info("%s: Set power mode to no power switching.", name);
         /* Set port power mode to no power-switching. (always on) */
         OHCI_SET(regs->rh_desc_a, RHDA_NPS_FLAG);
@@ -132 +132 @@
 
 #elif defined OHCI_POWER_SWITCH_ganged
-        usb_log_info("%s: Set power mode to ganged power switching.\n", name);
+        usb_log_info("%s: Set power mode to ganged power switching.", name);
         /* Set port power mode to ganged power-switching. */
         OHCI_CLR(regs->rh_desc_a, RHDA_NPS_FLAG);
@@ -144 +144 @@
         OHCI_CLR(regs->rh_desc_a, RHDA_OCPM_FLAG);
 #else
-        usb_log_info("%s: Set power mode to per-port power switching.\n", name);
+        usb_log_info("%s: Set power mode to per-port power switching.", name);
         /* Set port power mode to per port power-switching. */
         OHCI_CLR(regs->rh_desc_a, RHDA_NPS_FLAG);
@@ -356 +356 @@
         case USB_HUB_FEATURE_C_PORT_RESET:        /*20*/
                 usb_log_debug2("Clearing port C_CONNECTION, C_ENABLE, "
-                    "C_SUSPEND, C_OC or C_RESET on port %u.\n", port);
+                    "C_SUSPEND, C_OC or C_RESET on port %u.", port);
                 /* Bit offsets correspond to the feature number */
                 OHCI_WR(hub->registers->rh_port_status[port],
@@ -405 +405 @@
         case USB_HUB_FEATURE_PORT_RESET:   /*4*/
                 usb_log_debug2("Setting port POWER, ENABLE, SUSPEND or RESET "
-                    "on port %u.\n", port);
+                    "on port %u.", port);
                 /* Bit offsets correspond to the feature number */
                 OHCI_WR(hub->registers->rh_port_status[port], 1 << feature);
@@ -451 +451 @@
         }
 
-        usb_log_debug2("OHCI root hub interrupt mask: %hx.\n", mask);
+        usb_log_debug2("OHCI root hub interrupt mask: %hx.", mask);
 
         if (mask == 0)