From mboxrd@z Thu Jan 1 00:00:00 1970 From: francois_arsenau@hotmail.com (francois arsenault) Date: Mon, 9 Mar 2009 17:26:19 +0000 Subject: [ltt-dev] ltt - no traces logged using lttctl Message-ID: Message-ID: <20090309172619.2tb7YypBS87a6xIs6EUbBipAEqByzWUO0reYQbDWYds@z> Hello to all, We are trying to use the ltt for debugging a problem on our hardware and no data is logged in the trace. Our Hardware: - ppc405gpr - linux 2.6 (Linux version 2.6.26.8-00004) - from Denx We have done the following steps for the ltt installation: - Download "patch-2.6.26-rc8-0.10-pre56" from http://ltt.polymtl.ca - installed the patch (one error on the "kernel/printk.c" file) - In the kernel menuconfig, select all related ltt options (see the .config file attached) - make / make modules_install - Cross compile for the ppc405 the "ltt-control" (wget http://ltt.polymtl.ca/files/lttng/ltt-control-0.48-27022008.tar.gz) We are using the following commands on the target to start the traces: mkdir /mnt/debugfs echo "debugfs /mnt/debugfs debugfs rw 0 0" >> /etc/fstab mount /mnt/debugfs #Start Trace lttctl -n trace -b lttd -c /mnt/debugfs/ltt/trace -t /mnt/tmpfs/traceout1 -d #Stop Trace lttctl -n trace -R Question: we are executing the "lttctl -n trace -b" command, the "/mnt/debugfs/ltt" content is always zero i.e.: # ls -alR /mnt/debugfs/ltt /mnt/debugfs/ltt: drwxr-xr-x 3 0 0 0 Jan 1 00:00 . drwxr-xr-x 6 0 0 0 Jan 1 00:00 .. drwxr-xr-x 3 0 0 0 Jan 1 00:17 trace /mnt/debugfs/ltt/trace: drwxr-xr-x 3 0 0 0 Jan 1 00:17 . drwxr-xr-x 3 0 0 0 Jan 1 00:00 .. -r-------- 1 0 0 0 Jan 1 00:17 compact_0 drwxr-xr-x 2 0 0 0 Jan 1 00:17 control -r-------- 1 0 0 0 Jan 1 00:17 cpu_0 /mnt/debugfs/ltt/trace/control: drwxr-xr-x 2 0 0 0 Jan 1 00:17 . drwxr-xr-x 3 0 0 0 Jan 1 00:17 .. -r-------- 1 0 0 0 Jan 1 00:17 facilities_0 -r-------- 1 0 0 0 Jan 1 00:17 interrupts_0 -r-------- 1 0 0 0 Jan 1 00:17 modules_0 -r-------- 1 0 0 0 Jan 1 00:17 network_0 -r-------- 1 0 0 0 Jan 1 00:17 processes_0 It seems that the kernel doesn't send the "trace_mark" to the application. How can I fix this or debug it? Thanks, Francois. Attached, - kernel .config -The following are dmesg and cat /proc/ltt dump: =========== dmesg ================= Using SMUS4000 machine description Linux version 2.6.26.8-00004-gbb42807-dirty (franky at franky-desktop) (gcc version 4.2.2) #13 Mon Mar 9 11:20:47 EDT 2009 Found initrd at 0xc3c91000:0xc3ebc0a7 Found legacy serial port 0 for /plb/opb/serial at ef600300 mem=ef600300, taddr=ef600300, irq=0, clk=11250112, speed=115200 Found legacy serial port 1 for /plb/opb/serial at ef600400 mem=ef600400, taddr=ef600400, irq=0, clk=11250112, speed=115200 console [udbg0] enabled Entering add_active_range(0, 0, 16384) 0 entries of 256 used Top of RAM: 0x4000000, Total RAM: 0x4000000 Memory hole size: 0MB Zone PFN ranges: DMA 0 -> 16384 Normal 16384 -> 16384 Movable zone start PFN for each node early_node_map[1] active PFN ranges 0: 0 -> 16384 On node 0 totalpages: 16384 DMA zone: 128 pages used for memmap DMA zone: 0 pages reserved DMA zone: 16256 pages, LIFO batch:3 Normal zone: 0 pages used for memmap Movable zone: 0 pages used for memmap Built 1 zonelists in Zone order, mobility grouping on. Total pages: 16256 Kernel command line: console=ttyS1,115200 root=/dev/ram rw ip=10.0.102.247:10.0.102.71:10.0.102.71:255.255.255.0:ep405:eth0 init=./linuxrc UIC0 (32 IRQ sources) at DCR 0xc0 PID hash table entries: 256 (order: 8, 1024 bytes) time_init: decrementer frequency = 360.003600 MHz time_init: processor frequency = 360.003600 MHz clocksource: timebase mult[b1c6a8] shift[22] registered clockevent: decrementer mult[5c29] shift[16] cpu[0] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes) Inode-cache hash table entries: 4096 (order: 2, 16384 bytes) Memory: 59552k/65536k available (2860k kernel code, 5924k reserved, 108k data, 125k bss, 140k init) SLUB: Genslabs=10, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 Calibrating delay loop... 718.84 BogoMIPS (lpj=1437696) Mount-cache hash table entries: 512 net_namespace: 192 bytes NET: Registered protocol family 16 PCI: Probing PCI hardware NET: Registered protocol family 2 IP route cache hash table entries: 1024 (order: 0, 4096 bytes) TCP established hash table entries: 2048 (order: 2, 16384 bytes) TCP bind hash table entries: 2048 (order: 1, 8192 bytes) TCP: Hash tables configured (established 2048 bind 2048) TCP reno registered NET: Registered protocol family 1 checking if image is initramfs...it isn't (no cpio magic); looks like an initrd Freeing initrd memory: 2220k freed JFFS2 version 2.2. (NAND) ?? 2001-2006 Red Hat, Inc. msgmni has been set to 120 io scheduler noop registered io scheduler anticipatory registered (default) io scheduler deadline registered io scheduler cfq registered Synthetic TSC timer will fire each 741 jiffies. LTT : ltt-heartbeat init LTT : ltt-heartbeat init Requested number of bits 11 Available number of bits 14 Heartbeat timer will fire each 88 jiffies. Compact TSC init : truncate 8 lsb, cutoff 3 msb. LTT : ltt-relay init ltt-control init LTT : State dump init Data shifted from 24 bits 3 bits used for event IDs, 8 available for data. Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled serial8250.0: ttyS0 at MMIO 0xef600300 (irq = 16) is a 16550A serial8250.0: ttyS1 at MMIO 0xef600400 (irq = 17) is a 16550A console handover: boot [udbg0] -> real [ttyS1] ef600300.serial: ttyS0 at MMIO 0xef600300 (irq = 16) is a 16550A ef600400.serial: ttyS1 at MMIO 0xef600400 (irq = 17) is a 16550A brd: module loaded PPC 4xx OCP EMAC driver, version 3.54 MAL v1 /plb/mcmal, 1 TX channels, 1 RX channels eth0: EMAC-0 /plb/opb/ethernet at ef600800, MAC 00:40:fd:01:ef:8e eth0: found Generic MII PHY (0x18) init_smu_mtd: chip probing count 0 SMU-0: Found 2 x16 devices at 0x0 in 32-bit bank Amd/Fujitsu Extended Query Table at 0x0040 SMU-0: CFI does not contain boot bank location. Assuming top. number of CFI chips: 1 cfi_cmdset_0002: Disabling erase-suspend-program due to code brokenness. init_smu_mtd: bank 1, name: SMU-0, size: 33554432 bytes init_smu_mtd: 0 command line partitions on bank 0 SMU flash bank 0: Using static image bank1 partition definition Creating 5 MTD partitions on "ppc4xx-nor": 0x00000000-0x01dc0000 : "flash file System" 0x01dc0000-0x01f80000 : "buf" 0x01f80000-0x01fa0000 : "env2" mtd: partition "env2" doesn't end on an erase block -- force read-only 0x01fa0000-0x01fc0000 : "env1" mtd: partition "env1" doesn't start on an erase block boundary -- force read-only 0x01fc0000-0x02000000 : "u-boot" TCP cubic registered NET: Registered protocol family 17 RPC: Registered udp transport module. RPC: Registered tcp transport module. eth0: link is down IP-Config: Complete: device=eth0, addr=10.0.102.247, mask=255.255.255.0, gw=10.0.102.71, host=ep405, domain=, nis-domain=(none), bootserver=10.0.102.71, rootserver=10.0.102.71, rootpath= RAMDISK: Compressed image found at block 0 VFS: Mounted root (ext2 filesystem). Freeing unused kernel memory: 140k init eth0: link is up, 100 FDX, pause enabled vxworksStubs_class_init.77: Module loaded sat_mod: module license 'unspecified' taints kernel. sat_init_module for sat0 net driver sat_init_module.618: Symb: semBCreate, value: 0xc7083d94 SMUS4000 fpga0 FOUND!!! sat_dev_interrupt_map.419: fpga0_sign_virt_irq_nbr: 0x19 sat_dev_interrupt_map.420: fpga1_sof_virt_irq_nbr: 0x1a sat_dev_interrupt_map.432: i2c FOUND sat_dev_interrupt_map.434: i2c_virt_irq_nbr: 0x1b SMUF_init_module: Calling SMUF_getVirtualAddress SATevfm_Init.363: init module SATevfm_Init.375: init module OK FLINK_init_module: Registering FLINK device<4>Loading SMU FPGA Programming driver version 1.0 Mar 9 2009 11:21:15 fpga_prog: got major number 254, minor 0 ltt-control ltt_control_input ltt_control : trace trace Creating trace trace ltt-control ltt_control_input ltt_control : trace trace Start tracing trace Data shifted from 24 bits 3 bits used for event IDs, 8 available for data. LTT : ltt-heartbeat trigger LTT : ltt-heartbeat start LTT state dump begin LTT state dump thread start LTT state dump end ltt-control ltt_control_input ltt_control : trace trace Stop tracing trace LTT : ltt-heartbeat trigger LTT : ltt-heartbeat stop ltt-control ltt_control_input ltt_control : trace trace Destroying trace trace =========== cat /proc/ltt ================= cat /proc/ltt marker: kernel_arch_syscall_entry format: "syscall_id %d ip #p%ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_syscall_exit format: "ret %ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_ipc_call format: "call %u first %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_kthread_create format: "pid %ld fn %p" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_entry format: "trap_id %ld ip #p%ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_exit format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_entry format: "trap_id %ld ip #p%ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_exit format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_entry format: "trap_id %ld ip #p%ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_exit format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_entry format: "trap_id %ld ip #p%ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_arch_trap_exit format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_sched_try_wakeup format: "pid %d state %ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: internal_kernel_sched_schedule format: "prev %p next %p" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_sched_wakeup_new_task format: "pid %d state %ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_process_fork format: "parent_pid %d child_pid %d child_tgid %d" state: 0 call: 0xc0055bf0 probe multi : 0x000 00000 marker: kernel_printk format: "ip %p" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_process_free format: "pid %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_process_wait format: "pid %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_process_exit format: "pid %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_timer_itimer_set format: "which %d interval_sec %ld interval_usec %ld value_sec %ld value_usec %ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_timer_itimer_expired format: "pid %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_softirq_raise format: "softirq_id %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: statedump_softirq_vec format: "id %d address %p symbol %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_tasklet_high_entry format: "func %p data %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_tasklet_high_exit format: "func %p data %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_tasklet_low_entry format: "func %p data %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_tasklet_low_exit format: "func %p data %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_softirq_entry format: "softirq_id %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_softirq_exit format: "softirq_id %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_timer_set format: "expires %lu function %p data %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_timer_timeout format: "pid %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_timer_update_time format: "jiffies #8u%llu xtime_sec %ld xtime_nsec %ld walltomonotonic_sec %ld walltomonoton ic_nsec %ld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_send_signal format: "pid %d signal %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_kthread_stop format: "pid %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_kthread_stop_ret format: "ret %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_module_free format: "name %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_module_load format: "name %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: list_module format: "name %s state %d refcount %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_irq_entry format: "irq_id %u kernel_mode %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_irq_exit format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_format format: "name %s format %s" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_format format: "name %s format %s" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_filemap_wait_start format: "pfn %lu bit_nr %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_filemap_wait_end format: "pfn %lu bit_nr %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_page_free format: "order %u pfn %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_page_free format: "order %u pfn %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_page_alloc format: "order %u pfn %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_handle_fault_entry format: "address %lu ip #p%ld write_access %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000 000 marker: mm_swap_in format: "pfn %lu filp %p offset %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_handle_fault_exit format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_swap_out format: "pfn %lu filp %p offset %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: statedump_swap_files format: "filp %p vfsmount %p dname %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_swap_file_close format: "filp %p" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: mm_swap_file_open format: "filp %p filename %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_close format: "fd %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_open format: "fd %d filename %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_writev format: "fd %lu vlen %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_lseek format: "fd %u offset %ld origin %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_llseek format: "fd %u offset %llu origin %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_read format: "fd %u count %zu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_write format: "fd %u count %zu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_pread64 format: "fd %u count %zu pos %llu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_pwrite64 format: "fd %u count %zu pos %llu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_readv format: "fd %lu vlen %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_exec format: "filename %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_ioctl format: "fd %u cmd %u arg %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_pollfd format: "fd %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_select format: "fd %d timeout #8d%lld" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_buffer_wait_start format: "bh %p" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: fs_buffer_wait_end format: "bh %p" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: ipc_msg_create format: "id %ld flags %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: ipc_sem_create format: "id %ld flags %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: ipc_shm_create format: "id %ld flags %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_heartbeat_32 format: " " state: 1 call: 0xc0054b40 probe multi : 0x00000000 marker: core_heartbeat_64 format: "timestamp #8u%llu" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: list_process_state format: "pid %d parent_pid %d name %s type %d mode %d submode %d status %d tgid %d" state: 0 call : 0xc0055bf0 probe multi : 0x00000000 marker: list_file_descriptor format: "filename %s pid %d fd %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: list_vm_map format: "pid %d start %lu end %lu flags %lu pgoff %lu inode %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: list_interrupt format: "name %s action %s irq_id %u" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: list_network_ipv4_interface format: "name %s address #4u%lu up %d" state: 0 call: 0xc0055bf0 probe multi : 0x0000000 0 marker: list_network_ip_interface format: "name %s address #4u%lu up %d" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: list_statedump_end format: " " state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_id format: "name %s id %hu int #1u%zu long #1u%zu pointer #1u%zu size_t #1u%zu alignment #1u%u" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_format format: "name %s format %s" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_id format: "name %s id %hu int #1u%zu long #1u%zu pointer #1u%zu size_t #1u%zu alignment #1u%u" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_id format: "name %s id %hu int #1u%zu long #1u%zu pointer #1u%zu size_t #1u%zu alignment #1u%u" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: core_marker_id format: "name %s id %hu int #1u%zu long #1u%zu pointer #1u%zu size_t #1u%zu alignment #1u%u" state: 1 call: 0xc0055bf0 probe multi : 0x00000000 marker: kernel_sched_schedule format: "prev_pid %d next_pid %d prev_state %ld" state: 0 call: 0xc0055bf0 probe multi : 0x000 00000 marker: net_socket_recvmsg format: "sock %p family %d type %d protocol %d size %zu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: net_socket_sendmsg format: "sock %p family %d type %d protocol %d size %zu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: net_socket_create format: "sock %p family %d type %d protocol %d fd %d" state: 0 call: 0xc0055bf0 probe multi : 0x00 000000 marker: net_socket_call format: "call %d a0 %lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: net_dev_receive format: "skb %p protocol #2u%hu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: net_dev_xmit format: "skb %p protocol #2u%hu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: net_insert_ifa_ipv4 format: "label %s address #4u%lu" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 marker: net_del_ifa_ipv4 format: "label %s" state: 0 call: 0xc0055bf0 probe multi : 0x00000000 Thanks. _________________________________________________________________ R?inventez comment vous restez en contact avec le nouveau Windows Live Messenger. http://go.microsoft.com/?linkid=9650737 -------------- next part -------------- An HTML attachment was scrubbed... URL: -------------- next part -------------- A non-text attachment was scrubbed... Name: config_9Mars2009 Type: application/octet-stream Size: 22478 bytes Desc: not available URL: