Hi Reinier,

> I will try the tracing machanism to test the USB driver. Is there public
> the trace monitor version used to bring up the Rpi USB driver on base_hw?

I just went through my old branches and un-buried the attached patch.

Note that it is just a hack I developed for debugging a specific problem
(the interaction of the kernel's scheduling with IRQ latencies of the
USB driver). Even though it won't be immediately useful for your problem
(I even doubt that the patch applies to the current version of Genode),
it may still be useful for pointing you to the right places.

Cheers
Norman

-- 
Dr.-Ing. Norman Feske
Genode Labs

http://www.genode-labs.com · http://genode.org

Genode Labs GmbH · Amtsgericht Dresden · HRB 28424 · Sitz Dresden
Geschäftsführer: Dr.-Ing. Norman Feske, Christian Helmuth
commit 970760c16193811d1b07992446998a1e849536a0
Author: Norman Feske <norman.fe...@genode-labs.com>
Date:   Sun Sep 15 17:50:51 2013 +0200

    Tracing of USB HID interrupts on Raspberry Pi

diff --git a/base-hw/src/core/irq_session_component.cc b/base-hw/src/core/irq_session_component.cc
index ebb9bb4..66e93d0 100644
--- a/base-hw/src/core/irq_session_component.cc
+++ b/base-hw/src/core/irq_session_component.cc
@@ -13,6 +13,8 @@
 
 /* Genode includes */
 #include <kernel/syscalls.h>
+#include <trace/timestamp.h>
+#include <util/mmio.h>
 
 /* core includes */
 #include <irq_root.h>
@@ -20,12 +22,40 @@
 using namespace Genode;
 
 
+struct Dwc_otg : Genode::Mmio
+{
+	struct Core_interrupt : Register<0x14, 32> { };
+
+	enum { DWC_BASE = 0x20980000 };
+
+	Dwc_otg() : Genode::Mmio(DWC_BASE) { }
+
+	void dump()
+	{
+		PINF("Core_interrupt=0x%08x", read<Core_interrupt>());
+	}
+};
+
+
+static Dwc_otg *dwc_otg()
+{
+	static Dwc_otg inst;
+	return &inst;
+}
+
+
 bool
 Irq_session_component::Irq_control_component::associate_to_irq(unsigned irq)
 { return Kernel::allocate_irq(irq); }
 
 
-void Irq_session_component::wait_for_irq() { Kernel::await_irq(); }
+Irq_session::Irq_info Irq_session_component::wait_for_irq()
+{
+	Kernel::await_irq();
+
+	return Irq_session::Irq_info(Trace::timestamp(),
+	                             dwc_otg()->read<Dwc_otg::Core_interrupt>());
+}
 
 
 Irq_session_component::~Irq_session_component()
diff --git a/base/include/irq_session/client.h b/base/include/irq_session/client.h
index 9a1c9d1..f2d38fa 100644
--- a/base/include/irq_session/client.h
+++ b/base/include/irq_session/client.h
@@ -24,7 +24,7 @@ namespace Genode {
 		explicit Irq_session_client(Irq_session_capability session)
 		: Rpc_client<Irq_session>(session) { }
 
-		void wait_for_irq() { call<Rpc_wait_for_irq>(); }
+		Irq_info wait_for_irq() { return call<Rpc_wait_for_irq>(); }
 	};
 }
 
diff --git a/base/include/irq_session/irq_session.h b/base/include/irq_session/irq_session.h
index d42a88f..f2ee12c 100644
--- a/base/include/irq_session/irq_session.h
+++ b/base/include/irq_session/irq_session.h
@@ -43,14 +43,25 @@ namespace Genode {
 
 		virtual ~Irq_session() { }
 
-		virtual void wait_for_irq() = 0;
+		struct Irq_info
+		{
+			unsigned long timestamp;
+			unsigned long status;
+
+			Irq_info() : timestamp(0), status(0) { }
+
+			Irq_info(unsigned long timestamp, unsigned long status)
+			: timestamp(timestamp), status(status) { }
+		};
+
+		virtual Irq_info wait_for_irq() = 0;
 
 
 		/*********************
 		 ** RPC declaration **
 		 *********************/
 
-		GENODE_RPC(Rpc_wait_for_irq, void, wait_for_irq);
+		GENODE_RPC(Rpc_wait_for_irq, Irq_info, wait_for_irq);
 		GENODE_RPC_INTERFACE(Rpc_wait_for_irq);
 	};
 }
diff --git a/base/src/core/include/irq_session_component.h b/base/src/core/include/irq_session_component.h
index 723ad40..bf40c52 100644
--- a/base/src/core/include/irq_session_component.h
+++ b/base/src/core/include/irq_session_component.h
@@ -133,7 +133,7 @@ namespace Genode {
 			 ** Irq session interface **
 			 ***************************/
 
-			void wait_for_irq();
+			Irq_info wait_for_irq();
 	};
 }
 
diff --git a/dde_linux/run/usb_hid.run b/dde_linux/run/usb_hid.run
index 3b48e2d..0fce1c1 100644
--- a/dde_linux/run/usb_hid.run
+++ b/dde_linux/run/usb_hid.run
@@ -7,6 +7,8 @@ set build_components {
 	drivers/timer
 	drivers/usb
 	test/input
+	trace/usb_drv lib/trace/policy/manual
+	test/affinity
 }
 
 lappend_if [have_spec acpi]             build_components drivers/acpi
@@ -36,6 +38,7 @@ append config {
 		<service name="CPU"/>
 		<service name="LOG"/>
 		<service name="SIGNAL" />
+		<service name="TRACE" />
 	</parent-provides>
 	<default-route>
 		<any-service> <parent/> <any-child/> </any-service>
@@ -82,6 +85,12 @@ append config {
 	<start name="test-input">
 		<resource name="RAM" quantum="1M"/>
 	</start>
+	<start name="trace-usb_drv">
+		<resource name="RAM" quantum="35M"/>
+	</start>
+	<start name="test-affinity">
+		<resource name="RAM" quantum="35M"/>
+	</start>
 </config>}
 
 install_config $config
@@ -92,7 +101,7 @@ install_config $config
 
 # generic modules
 set boot_modules {
-	core init timer usb_drv test-input
+	core init timer usb_drv test-input trace-usb_drv manual test-affinity
 }
 
 lappend_if [have_spec acpi]             boot_modules acpi_drv
diff --git a/dde_linux/src/lib/usb/include/lx_emul.h b/dde_linux/src/lib/usb/include/lx_emul.h
index f4c2e48..3d1216e 100644
--- a/dde_linux/src/lib/usb/include/lx_emul.h
+++ b/dde_linux/src/lib/usb/include/lx_emul.h
@@ -57,6 +57,11 @@ static inline void bt()
 }
 
 
+void trace_emi();
+void trace_hcd_irq(unsigned long status);
+void trace_end_sof(unsigned long status);
+
+
 /*******************
  ** linux/sizes.h **
  *******************/
diff --git a/dde_linux/src/lib/usb/lx_emul.cc b/dde_linux/src/lib/usb/lx_emul.cc
index d71c342..75a17d5 100644
--- a/dde_linux/src/lib/usb/lx_emul.cc
+++ b/dde_linux/src/lib/usb/lx_emul.cc
@@ -18,6 +18,8 @@
 #include <rm_session/connection.h>
 #include <timer_session/connection.h>
 #include <util/string.h>
+#include <base/thread.h>
+#include <trace/timestamp.h>
 
 /* Local includes */
 #include "routine.h"
@@ -1222,3 +1224,32 @@ u8 mii_resolve_flowctrl_fdx(u16 lcladv, u16 rmtadv)
 }
 
 
+void trace_emi()
+{
+	char buf[64];
+
+	Genode::snprintf(buf, sizeof(buf), "%u emi", Genode::Trace::timestamp());
+
+	Genode::Thread_base::trace(buf);
+}
+
+
+void trace_hcd_irq(unsigned long status)
+{
+	char buf[64];
+
+	Genode::snprintf(buf, sizeof(buf), "%u dwc_irq (0x%08lx)",
+	                 Genode::Trace::timestamp(), status);
+
+	Genode::Thread_base::trace(buf);
+}
+
+void trace_end_sof(unsigned long status)
+{
+	char buf[64];
+
+	Genode::snprintf(buf, sizeof(buf), "%u end_sof (0x%08lx)",
+	                 Genode::Trace::timestamp(), status);
+
+	Genode::Thread_base::trace(buf);
+}
diff --git a/dde_linux/src/trace/usb_drv/main.cc b/dde_linux/src/trace/usb_drv/main.cc
new file mode 100644
index 0000000..ed91408
--- /dev/null
+++ b/dde_linux/src/trace/usb_drv/main.cc
@@ -0,0 +1,98 @@
+/*
+ * \brief  Trace monitor for tracing the USB driver
+ * \author Norman Feske
+ * \date   2013-09-12
+ */
+
+/*
+ * Copyright (C) 2013 Genode Labs GmbH
+ *
+ * This file is part of the Genode OS framework, which is distributed
+ * under the terms of the GNU General Public License version 2.
+ */
+
+#include <trace/timestamp.h>
+#include <trace_session/connection.h>
+#include <base/printf.h>
+#include <timer_session/connection.h>
+#include <os/attached_rom_dataspace.h>
+#include <base/sleep.h>
+
+
+static Genode::Trace::Policy_id import_policy(Genode::Trace::Session &trace, char const *policy_name)
+{
+	using namespace Genode;
+	using namespace Trace;
+
+	Attached_rom_dataspace policy(policy_name);
+	Policy_id const policy_id = trace.alloc_policy(policy.size());
+	void *policy_local_addr = env()->rm_session()->attach(trace.policy(policy_id));
+	memcpy(policy_local_addr, policy.local_addr<void>(), policy.size());
+	env()->rm_session()->detach(policy_local_addr);
+	return policy_id;
+}
+
+
+int main(int argc, char **argv)
+{
+	using namespace Genode;
+	using namespace Trace;
+
+	printf("--- trace-usb_drv started ---\n");
+	static Trace::Connection trace(32*1024*1024, 4096, 0);
+	static Timer::Connection timer;
+
+	timer.msleep(3000);
+
+	Policy_id const policy_id = import_policy(trace, "manual");
+
+	enum { MAX_SUBJECTS = 64 };
+	static Subject_id subject_ids[MAX_SUBJECTS];
+
+	size_t const num_subjects = trace.subjects(subject_ids, MAX_SUBJECTS);
+
+	for (unsigned i = 0; i < num_subjects; i++) {
+
+		Subject_info info = trace.subject_info(subject_ids[i]);
+
+		if (strcmp(info.session_label().string(), "init -> usb_drv") != 0)
+			continue;
+
+		printf("install policy to thread: %s\n", info.thread_name().string());
+
+		trace.trace(subject_ids[i], policy_id, 6*1024*1024);
+	}
+
+	timer.msleep(3000);
+
+	for (unsigned i = 0; i < num_subjects; i++)
+		trace.pause(subject_ids[i]);
+
+	for (unsigned i = 0; i < num_subjects; i++) {
+
+		Subject_info info = trace.subject_info(subject_ids[i]);
+
+		if (strcmp(info.session_label().string(), "init -> usb_drv") != 0)
+			continue;
+
+		Dataspace_capability ds = trace.buffer(subject_ids[i]);
+		Buffer const &buffer = *(Buffer const *)env()->rm_session()->attach(ds);
+
+		printf("-- buffer of %s --\n", info.thread_name().string());
+
+		enum { MAX_EVENTS_TO_DUMP = 250 };
+		unsigned cnt = 0;
+		for (Buffer::Entry e = buffer.first(); !e.is_last(); e = buffer.next(e)) {
+
+			if (cnt++ == MAX_EVENTS_TO_DUMP)
+				break;
+
+			char buf[64];
+			strncpy(buf, e.data(), min(sizeof(buf), e.length() + 1));
+			printf("%s\n", buf);
+		}
+	}
+
+	printf("sleep forever\n");
+	sleep_forever();
+}
diff --git a/dde_linux/src/trace/usb_drv/target.mk b/dde_linux/src/trace/usb_drv/target.mk
new file mode 100644
index 0000000..244c362
--- /dev/null
+++ b/dde_linux/src/trace/usb_drv/target.mk
@@ -0,0 +1,3 @@
+TARGET = trace-usb_drv
+SRC_CC = main.cc
+LIBS   = base
diff --git a/os/src/lib/dde_kit/interrupt.cc b/os/src/lib/dde_kit/interrupt.cc
index a9339e0..93bd21f 100644
--- a/os/src/lib/dde_kit/interrupt.cc
+++ b/os/src/lib/dde_kit/interrupt.cc
@@ -25,6 +25,7 @@
 #include <base/printf.h>
 #include <base/thread.h>
 #include <base/snprintf.h>
+#include <trace/timestamp.h>
 #include <util/avl_tree.h>
 
 #include <irq_session/connection.h>
@@ -102,7 +103,24 @@ class Irq_handler : Dde_kit::Thread, public Avl_node<Irq_handler>
 			_lock.unlock();
 
 			while (1) {
-				_irq.wait_for_irq();
+				char buf[64];
+
+				{
+					snprintf(buf, sizeof(buf), "%lu wait_for_irq",
+					         (long)Trace::timestamp());
+					Thread_base::trace(buf);
+				}
+
+				Irq_session::Irq_info info = _irq.wait_for_irq();
+
+				if (info.status & (1 << 3)) {
+					snprintf(buf, sizeof(buf), "%lu stuck irq", info.timestamp);
+					Thread_base::trace(buf);
+				} else {
+					snprintf(buf, sizeof(buf), "%lu irq", info.timestamp);
+					Thread_base::trace(buf);
+				}
+
 
 				/* only call registered handler function, if IRQ is not disabled */
 				_lock.lock();
------------------------------------------------------------------------------
One dashboard for servers and applications across Physical-Virtual-Cloud 
Widest out-of-the-box monitoring support with 50+ applications
Performance metrics, stats and reports that give you Actionable Insights
Deep dive visibility with transaction tracing using APM Insight.
http://ad.doubleclick.net/ddm/clk/290420510;117567292;y
_______________________________________________
genode-main mailing list
genode-main@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/genode-main

Reply via email to