vasilito/RedBear-OS
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Replace all calls to [e]println with log macros.

Browse Source
This commit is contained in:
4lDO2
2020-04-05 00:17:55 +02:00
parent 80d3affa1c
commit 74c77412bf
4 changed files with 72 additions and 98 deletions
Download Patch File Download Diff File Expand all files Collapse all files
xhcid/src/xhci/context.rs
+2 -1
View File
@@ -1,5 +1,6 @@
use std::collections::BTreeMap;
use log::debug;
use syscall::error::Result;
use syscall::io::{Dma, Io, Mmio};
@@ -59,7 +60,7 @@ pub struct InputContext {
}
impl InputContext {
pub fn dump_control(&self) {
println!(
debug!(
"INPUT CONTEXT: {} {} [{} {} {} {} {}] {}",
self.drop_context.read(),
self.add_context.read(),
xhcid/src/xhci/irq_reactor.rs
+17 -16
View File
@@ -10,6 +10,7 @@ use std::{io, mem, task, thread};
use std::os::unix::io::AsRawFd;
use crossbeam_channel::{Sender, Receiver};
use log::{debug, error, info, warn, trace};
use futures::Stream;
use syscall::Io;
@@ -106,7 +107,7 @@ impl IrqReactor {
std::thread::yield_now();
}
fn run_polling(mut self) {
println!("Running IRQ reactor in polling mode.");
debug!("Running IRQ reactor in polling mode.");
let hci_clone = Arc::clone(&self.hci);
'event_loop: loop {
@@ -133,7 +134,7 @@ impl IrqReactor {
}
}
fn run_with_irq_file(mut self) {
println!("Running IRQ reactor with IRQ file and event queue");
debug!("Running IRQ reactor with IRQ file and event queue");
let hci_clone = Arc::clone(&self.hci);
let mut event_queue = EventQueue::<()>::new().expect("xhcid irq_reactor: failed to create IRQ event queue");
@@ -142,18 +143,18 @@ impl IrqReactor {
let mut event_trb_index = { hci_clone.primary_event_ring.lock().unwrap().ring.next_index() };
event_queue.add(irq_fd, move |_| -> io::Result<Option<()>> {
println!("IRQ event queue notified");
trace!("IRQ event queue notified");
let mut buffer = [0u8; 8];
let _ = self.irq_file.as_mut().unwrap().read(&mut buffer).expect("Failed to read from irq scheme");
if !self.hci.received_irq() {
// continue only when an IRQ to this device was received
println!("no interrupt pending");
trace!("no interrupt pending");
return Ok(None);
}
println!("IRQ reactor received an IRQ");
trace!("IRQ reactor received an IRQ");
let _ = self.irq_file.as_mut().unwrap().write(&buffer);
@@ -167,15 +168,15 @@ impl IrqReactor {
let event_trb = &mut event_ring.ring.trbs[event_trb_index];
if event_trb.completion_code() == TrbCompletionCode::Invalid as u8 {
if count == 0 { println!("xhci: Received interrupt, but no event was found in the event ring. Ignoring interrupt.") }
if count == 0 { warn!("xhci: Received interrupt, but no event was found in the event ring. Ignoring interrupt.") }
// no more events were found, continue the loop
return Ok(None);
} else { count += 1 }
println!("Found event TRB: {:?}", event_trb);
trace!("Found event TRB: {:?}", event_trb);
if self.check_event_ring_full(event_trb.clone()) {
println!("Had to resize event TRB, retrying...");
info!("Had to resize event TRB, retrying...");
hci_clone.event_handler_finished();
return Ok(None);
}
@@ -197,12 +198,12 @@ impl IrqReactor {
let dequeue_pointer = dequeue_pointer_and_dcs & 0xFFFF_FFFF_FFFF_FFFE;
assert_eq!(dequeue_pointer & 0xFFFF_FFFF_FFFF_FFF0, dequeue_pointer, "unaligned ERDP received from primary event ring");
println!("Updated ERDP to {:#0x}", dequeue_pointer);
debug!("Updated ERDP to {:#0x}", dequeue_pointer);
self.hci.run.lock().unwrap().ints[0].erdp.write(dequeue_pointer);
}
fn handle_requests(&mut self) {
self.states.extend(self.receiver.try_iter().inspect(|req| println!("Received request: {:?}", req)));
self.states.extend(self.receiver.try_iter().inspect(|req| trace!("Received request: {:?}", req)));
}
fn acknowledge(&mut self, trb: Trb) {
let mut index = 0;
@@ -212,7 +213,7 @@ impl IrqReactor {
match self.states[index].kind {
StateKind::CommandCompletion { phys_ptr } if dbg!(trb.trb_type()) == TrbType::CommandCompletion as u8 => if dbg!(trb.completion_trb_pointer()) == Some(phys_ptr) {
println!("Found matching command completion future");
trace!("Found matching command completion future");
let state = self.states.remove(index);
// Before waking, it's crucial that the command TRB that generated this event
@@ -224,7 +225,7 @@ impl IrqReactor {
t
},
None => {
println!("The xHC supplied a pointer to a command TRB that was outside the known command ring bounds. Ignoring event TRB {:?}.", trb);
warn!("The xHC supplied a pointer to a command TRB that was outside the known command ring bounds. Ignoring event TRB {:?}.", trb);
continue;
}
};
@@ -235,12 +236,12 @@ impl IrqReactor {
event_trb: trb.clone(),
});
println!("Waking up future with waker: {:?}", state.waker);
trace!("Waking up future with waker: {:?}", state.waker);
state.waker.wake();
return;
} else if trb.completion_trb_pointer().is_none() {
println!("Command TRB somehow resulted in an error that only can be caused by transfer TRBs. Ignoring event TRB: {:?}.", trb);
warn!("Command TRB somehow resulted in an error that only can be caused by transfer TRBs. Ignoring event TRB: {:?}.", trb);
continue;
} else {
// The event TRB simply didn't match the current future
@@ -290,7 +291,7 @@ impl IrqReactor {
}
}
}
println!("Lost event TRB: {:?}", trb);
warn!("Lost event TRB: {:?}", trb);
}
fn acknowledge_failed_transfer_trbs(&mut self, trb: Trb) {
let mut index = 0;
@@ -325,7 +326,7 @@ impl IrqReactor {
/// Grows the event ring
fn grow_event_ring(&mut self) {
// TODO
println!("TODO: grow event ring");
error!("TODO: grow event ring");
}
pub fn run(mut self) {
xhcid/src/xhci/mod.rs
+47 -64
View File
@@ -11,6 +11,7 @@ use std::{mem, process, slice, sync::atomic, task, thread};
use chashmap::CHashMap;
use crossbeam_channel::{Receiver, Sender};
use log::{debug, error, info, trace, warn};
use serde::Deserialize;
use syscall::error::{Error, Result, EBADF, EBADMSG, ENOENT, EIO};
use syscall::flag::O_RDONLY;
@@ -94,14 +95,11 @@ impl MsixInfo {
impl Xhci {
/// Gets descriptors, before the port state is initiated.
async fn get_desc_raw<T>(&self, port: usize, slot: u8, kind: usb::DescriptorKind, index: u8, desc: &mut Dma<T>) -> Result<()> {
println!("A");
let len = mem::size_of::<T>();
let future = {
println!("B");
let mut port_state = self.port_states.get_mut(&port).ok_or(Error::new(ENOENT))?;
let ring = port_state.endpoint_states.get_mut(&0).ok_or(Error::new(EIO))?.ring().expect("no ring for the default control pipe");
println!("C");
let (cmd, cycle) = ring.next();
cmd.setup(
@@ -117,24 +115,18 @@ impl Xhci {
let (cmd, cycle) = (&mut ring.trbs[last_index], ring.cycle);
cmd.status(0, true, true, false, false, cycle);
println!("D");
self.next_transfer_event_trb(RingId::default_control_pipe(port as u8), &ring, &ring.trbs[last_index])
};
println!("E");
self.dbs.lock().unwrap()[usize::from(slot)].write(Self::def_control_endp_doorbell());
println!("F");
let trbs = future.await;
let event_trb = trbs.event_trb;
let status_trb = trbs.src_trb.unwrap();
println!("G");
self::scheme::handle_transfer_event_trb("GET_DESC", &event_trb, &status_trb)?;
println!("H");
self.event_handler_finished();
println!("I");
Ok(())
}
@@ -242,7 +234,7 @@ impl EndpointState {
impl Xhci {
pub fn new(scheme_name: String, address: usize, interrupt_method: InterruptMethod, pcid_handle: PcidServerHandle) -> Result<Xhci> {
let cap = unsafe { &mut *(address as *mut CapabilityRegs) };
println!(" - CAP {:X}", address);
debug!("CAP REGS BASE {:X}", address);
let page_size = {
let memory_fd = syscall::open("memory:", O_RDONLY)?;
@@ -253,52 +245,52 @@ impl Xhci {
let op_base = address + cap.len.read() as usize;
let op = unsafe { &mut *(op_base as *mut OperationalRegs) };
println!(" - OP {:X}", op_base);
debug!("OP REGS BASE {:X}", op_base);
let (max_slots, max_ports) = {
println!(" - Wait for ready");
debug!("Waiting for xHC becoming ready.");
// Wait until controller is ready
while op.usb_sts.readf(1 << 11) {
println!(" - Waiting for XHCI ready");
trace!("Waiting for the xHC to be ready.");
}
println!(" - Stop");
debug!("Stopping the xHC");
// Set run/stop to 0
op.usb_cmd.writef(1, false);
println!(" - Wait for not running");
debug!("Waiting for the xHC to stop.");
// Wait until controller not running
while !op.usb_sts.readf(1) {
println!(" - Waiting for XHCI stopped");
trace!("Waiting for the xHC to stop.");
}
println!(" - Reset");
debug!("Resetting the xHC.");
op.usb_cmd.writef(1 << 1, true);
while op.usb_sts.readf(1 << 1) {
println!(" - Waiting for XHCI reset");
trace!("Waiting for the xHC to reset.");
}
println!(" - Read max slots");
debug!("Reading max slots.");
let max_slots = cap.max_slots();
let max_ports = cap.max_ports();
println!(" - Max Slots: {}, Max Ports {}", max_slots, max_ports);
info!("xHC max slots: {}, max ports: {}", max_slots, max_ports);
(max_slots, max_ports)
};
let port_base = op_base + 0x400;
let ports =
unsafe { slice::from_raw_parts_mut(port_base as *mut Port, max_ports as usize) };
println!(" - PORT {:X}", port_base);
debug!("PORT BASE {:X}", port_base);
let db_base = address + cap.db_offset.read() as usize;
let dbs = unsafe { slice::from_raw_parts_mut(db_base as *mut Doorbell, 256) };
println!(" - DOORBELL {:X}", db_base);
debug!("DOORBELL REGS BASE {:X}", db_base);
let run_base = address + cap.rts_offset.read() as usize;
let run = unsafe { &mut *(run_base as *mut RuntimeRegs) };
println!(" - RUNTIME {:X}", run_base);
debug!("RUNTIME REGS BASE {:X}", run_base);
// Create the command ring with 4096 / 16 (TRB size) entries, so that it uses all of the
// DMA allocation (which is at least a 4k page).
@@ -345,42 +337,42 @@ impl Xhci {
pub fn init(&mut self, max_slots: u8) -> Result<()> {
// Set enabled slots
println!(" - Set enabled slots to {}", max_slots);
debug!("Setting enabled slots to {}.", max_slots);
self.op.get_mut().unwrap().config.write(max_slots as u32);
println!(" - Enabled Slots: {}", self.op.get_mut().unwrap().config.read() & 0xFF);
debug!("Enabled Slots: {}", self.op.get_mut().unwrap().config.read() & 0xFF);
// Set device context address array pointer
let dcbaap = self.dev_ctx.dcbaap();
println!(" - Write DCBAAP: {:X}", dcbaap);
debug!("Writing DCBAAP: {:X}", dcbaap);
self.op.get_mut().unwrap().dcbaap.write(dcbaap as u64);
// Set command ring control register
let crcr = self.cmd.get_mut().unwrap().register();
assert_eq!(crcr & 0xFFFF_FFFF_FFFF_FFC1, crcr, "unaligned CRCR");
println!(" - Write CRCR: {:X}", crcr);
debug!("Writing CRCR: {:X}", crcr);
self.op.get_mut().unwrap().crcr.write(crcr as u64);
// Set event ring segment table registers
println!(" - Interrupter 0: {:X}", self.run.get_mut().unwrap().ints.as_ptr() as usize);
debug!("Interrupter 0: {:p}", self.run.get_mut().unwrap().ints.as_ptr());
{
let int = &mut self.run.get_mut().unwrap().ints[0];
let erstz = 1;
println!(" - Write ERSTZ: {}", erstz);
debug!("Writing ERSTZ: {}", erstz);
int.erstsz.write(erstz);
let erdp = self.primary_event_ring.get_mut().unwrap().erdp();
println!(" - Write ERDP: {:X}", erdp);
debug!("Writing ERDP: {:X}", erdp);
int.erdp.write(erdp as u64 | (1 << 3));
let erstba = self.primary_event_ring.get_mut().unwrap().erstba();
println!(" - Write ERSTBA: {:X}", erstba);
debug!("Writing ERSTBA: {:X}", erstba);
int.erstba.write(erstba as u64);
println!(" - Write IMODC and IMODI: {} and {}", 0, 0);
debug!("Writing IMODC and IMODI: {} and {}", 0, 0);
int.imod.write(0);
println!(" - Enable interrupts");
debug!("Enabling Primary Interrupter.");
int.iman.writef(1 << 1 | 1, true);
}
@@ -390,22 +382,20 @@ impl Xhci {
self.setup_scratchpads()?;
// Set run/stop to 1
println!(" - Start");
info!("Starting xHC.");
self.op.get_mut().unwrap().usb_cmd.writef(1, true);
// Wait until controller is running
println!(" - Wait for running");
debug!("Waiting for start request to complete.");
while self.op.get_mut().unwrap().usb_sts.readf(1) {
println!(" - Waiting for XHCI running");
trace!("Waiting for XHCI to report running status.");
}
println!("IP={}", self.run.get_mut().unwrap().ints[0].iman.readf(1));
// Ring command doorbell
println!(" - Ring doorbell");
debug!("Ringing command doorbell.");
self.dbs.get_mut().unwrap()[0].write(0);
println!(" - XHCI initialized");
info!("XHCI initialized.");
if self.cap.cic() {
self.op.get_mut().unwrap().set_cie(true);
@@ -422,6 +412,7 @@ impl Xhci {
}
let scratchpad_buf_arr = ScratchpadBufferArray::new(self.page_size,buf_count)?;
self.dev_ctx.dcbaa[0] = scratchpad_buf_arr.register() as u64;
debug!("Setting up {} scratchpads, at {:#0x}", buf_count, scratchpad_buf_arr.register());
self.scratchpad_buf_arr = Some(scratchpad_buf_arr);
Ok(())
@@ -452,7 +443,7 @@ impl Xhci {
}
pub async fn probe(&self) -> Result<()> {
println!("XHCI capabilities: {:?}", self.capabilities_iter().collect::<Vec<_>>());
info!("XHCI capabilities: {:?}", self.capabilities_iter().collect::<Vec<_>>());
let port_count = { self.ports.lock().unwrap().len() };
@@ -461,29 +452,26 @@ impl Xhci {
let port = &self.ports.lock().unwrap()[i];
(port.read(), port.state(), port.speed(), port.flags())
};
println!(
" + XHCI Port {}: {:X}, State {}, Speed {}, Flags {:?}",
info!(
"XHCI Port {}: {:X}, State {}, Speed {}, Flags {:?}",
i, data, state, speed, flags
);
if flags.contains(port::PortFlags::PORT_CCS) {
//TODO: Link TRB when running to the end of the ring buffer
println!(" - Enable slot");
let slot_ty = self
.supported_protocol(i as u8)
.expect("Failed to find supported protocol information for port")
.proto_slot_ty();
println!("Got slot type: {}", slot_ty);
debug!("Slot type: {}", slot_ty);
debug!("Enabling slot.");
let slot = self.enable_port_slot(slot_ty).await?;
println!(" - Slot {}", slot);
info!("Enabled port {}, which the xHC mapped to {}", i, slot);
let mut input = Dma::<InputContext>::zeroed()?;
let mut ring = self.address_device(&mut input, i, slot_ty, slot, speed).await?;
println!("Addressed device");
info!("Addressed device");
// TODO: Should the descriptors be cached in PortState, or refetched?
@@ -504,9 +492,7 @@ impl Xhci {
};
self.port_states.insert(i, port_state);
println!("pre get desc");
let dev_desc = self.get_desc(i, slot).await?;
println!("post get desc");
self.port_states.get_mut(&i).unwrap().dev_desc = Some(dev_desc);
{
@@ -520,7 +506,7 @@ impl Xhci {
/*match self.spawn_drivers(i, &mut port_state) {
Ok(()) => (),
Err(err) => println!("Failed to spawn driver for port {}: `{}`", i, err),
Err(err) => error!("Failed to spawn driver for port {}: `{}`", i, err),
}*/
}
@@ -648,14 +634,14 @@ impl Xhci {
let input_context_physical = input_context.physical();
println!("pre_address_device");
let (event_trb, _) = self.execute_command(|trb, cycle| {
trb.address_device(slot, input_context_physical, false, cycle)
}).await;
println!("post_address_device");
if event_trb.completion_code() != TrbCompletionCode::Success as u8 {
println!("Failed to address device at slot {} (port {})", slot, i);
error!("Failed to address device at slot {} (port {})", slot, i);
self.event_handler_finished();
return Err(Error::new(EIO));
}
self.event_handler_finished();
@@ -690,13 +676,10 @@ impl Xhci {
if self.uses_msi() || self.uses_msix() {
// Since using MSI and MSI-X implies having no IRQ sharing whatsoever, the IP bit
// doesn't have to be touched.
println!("Successfully received MSI/MSI-X interrupt, IP={}, EHB={}", runtime_regs.ints[0].iman.readf(1), runtime_regs.ints[0].erdp.readf(3));
println!("MSI-X PB={}", self.msix_info_mut().unwrap().pba(0));
let mut msix = self.msix_info_mut().unwrap();
let entry = msix.table_entry_pointer(0);
println!("MSI-X entry (addr_lo, addr_hi, msg_data, vec_ctl: {:#0x} {:#0x} {:#0x} {:#0x}", entry.addr_lo.read(), entry.addr_hi.read(), entry.msg_data.read(), entry.vec_ctl.read());
trace!("Successfully received MSI/MSI-X interrupt, IP={}, EHB={}", runtime_regs.ints[0].iman.readf(1), runtime_regs.ints[0].erdp.readf(3));
true
} else if runtime_regs.ints[0].iman.readf(1) {
trace!("Successfully received INTx# interrupt, IP={}, EHB={}", runtime_regs.ints[0].iman.readf(1), runtime_regs.ints[0].erdp.readf(3));
// If MSI and/or MSI-X are not used, the interrupt might have to be shared, and thus there is
// a special register to specify whether the IRQ actually came from the xHC.
runtime_regs.ints[0].iman.writef(1, true);
@@ -734,7 +717,7 @@ impl Xhci {
.map(|subclass| subclass == ifdesc.sub_class)
.unwrap_or(true)
}) {
println!("Loading driver \"{}\"", driver.name);
info!("Loading subdriver\"{}\"", driver.name);
let (command, args) = driver.command.split_first().ok_or(Error::new(EBADMSG))?;
let if_proto = ifdesc.protocol;
@@ -865,10 +848,10 @@ pub fn start_irq_reactor(hci: &Arc<Xhci>, irq_file: Option<File>) {
let receiver = hci.irq_reactor_receiver.clone();
let hci_clone = Arc::clone(&hci);
println!("About to start IRQ reactor");
debug!("About to start IRQ reactor");
*hci.irq_reactor.lock().unwrap() = Some(thread::spawn(move || {
println!("Started IRQ reactor thread");
info!("Started IRQ reactor thread");
IrqReactor::new(hci_clone, receiver, irq_file).run()
}));
}
xhcid/src/xhci/scheme.rs
+6 -17
View File
@@ -4,6 +4,7 @@ use std::sync::atomic;
use std::{cmp, io, mem, path, str};
use futures::executor::block_on;
use log::{debug, error, info, warn, trace};
use serde::{Deserialize, Serialize};
use smallvec::{smallvec, SmallVec};
@@ -235,9 +236,7 @@ impl Xhci {
self.next_command_completion_event_trb(&*command_ring, command_trb)
};
println!("Ringing doorbell");
self.dbs.lock().unwrap()[0].write(0);
println!("Doorbell rung");
let trbs = next_event.await;
let event_trb = trbs.event_trb;
@@ -381,14 +380,14 @@ impl Xhci {
if event_trb.completion_code() != TrbCompletionCode::ShortPacket as u8
&& event_trb.transfer_length() != 0
{
println!(
error!(
"Event trb didn't yield a short packet, but some bytes were not transferred"
);
return Err(Error::new(EIO));
}
// TODO: Handle event data
println!("EVENT DATA: {:?}", event_trb.event_data());
debug!("EVENT DATA: {:?}", event_trb.event_data());
Ok(event_trb)
}
@@ -925,41 +924,33 @@ impl Xhci {
port_id: usize,
slot: u8,
) -> Result<DevDesc> {
println!("Checkpoint 1");
let ports = self.ports.lock().unwrap();
let port = ports.get(port_id).ok_or(Error::new(ENOENT))?;
if !port.flags().contains(port::PortFlags::PORT_CCS) {
return Err(Error::new(ENOENT));
}
println!("Checkpoint 2");
let raw_dd = self.fetch_dev_desc(port_id, slot).await?;
println!("Checkpoint 3");
let (manufacturer_str, product_str, serial_str) = (
if raw_dd.manufacturer_str > 0 {
println!("Checkpoint 4a");
Some(self.fetch_string_desc(port_id, slot, raw_dd.manufacturer_str).await?)
} else {
None
},
if raw_dd.product_str > 0 {
println!("Checkpoint 4b");
Some(self.fetch_string_desc(port_id, slot, raw_dd.product_str).await?)
} else {
None
},
if raw_dd.serial_str > 0 {
println!("Checkpoint 4c");
Some(self.fetch_string_desc(port_id, slot, raw_dd.serial_str).await?)
} else {
None
},
);
println!("Checkpoint 5");
let (bos_desc, bos_data) = self.fetch_bos_desc(port_id, slot).await?;
println!("Checkpoint 6");
let supports_superspeed =
usb::bos_capability_descs(bos_desc, &bos_data).any(|desc| desc.is_superspeed());
@@ -969,9 +960,7 @@ impl Xhci {
let mut config_descs = SmallVec::new();
for index in 0..raw_dd.configurations {
println!("Checkpoint 7: {}", index);
let (desc, data) = self.fetch_config_desc(port_id, slot, index).await?;
println!("Checkpoint 8: {}", index);
let extra_length = desc.total_length as usize - mem::size_of_val(&desc);
let data = &data[..extra_length];
@@ -2001,7 +1990,7 @@ impl Xhci {
/// # Locking
/// This function locks `Xhci::run`.
pub fn event_handler_finished(&self) {
println!("Event handler finished");
trace!("Event handler finished");
// write 1 to EHB to clear it
self.run.lock().unwrap().ints[0].erdp.writef(1 << 3, true);
}
@@ -2010,7 +1999,7 @@ pub fn handle_event_trb(name: &str, event_trb: &Trb, command_trb: &Trb) -> Resul
if event_trb.completion_code() == TrbCompletionCode::Success as u8 {
Ok(())
} else {
println!("{} command (TRB {:?}) failed with event trb {:?}", name, command_trb, event_trb);
error!("{} command (TRB {:?}) failed with event trb {:?}", name, command_trb, event_trb);
Err(Error::new(EIO))
}
}
@@ -2018,7 +2007,7 @@ pub fn handle_transfer_event_trb(name: &str, event_trb: &Trb, transfer_trb: &Trb
if event_trb.completion_code() == TrbCompletionCode::Success as u8 || event_trb.completion_code() == TrbCompletionCode::ShortPacket as u8 {
Ok(())
} else {
println!("{} transfer (TRB {:?}) failed with event trb {:?}", name, transfer_trb, event_trb);
error!("{} transfer (TRB {:?}) failed with event trb {:?}", name, transfer_trb, event_trb);
Err(Error::new(EIO))
}
}