Gentoo,
app-benchmarks/bootchart2 v0.14.8-r1
python 3.9

> pybootchartgui
Traceback (most recent call last):
  File "/usr/bin/pybootchartgui", line 20, in <module>
    from pybootchartgui.main import main
  File "/usr/lib/python3.9/site-packages/pybootchartgui/main.py", line 25, in <module>
    from . import parsing
  File "/usr/lib/python3.9/site-packages/pybootchartgui/parsing.py", line 26, in <module>
    from time import clock
ImportError: cannot import name 'clock' from 'time' (unknown location)

From Thomas De Schampheleire:

I'm trying out bootchart2 on an embedded Linux system, using an
initramfs as main rootfs (no harddisk or other permanent storage).
I am having a number of problems with this, as described below. Your
feedback is most welcome.

The standard boot process (without bootchart2) on this system is as follows:

kernel starts /init
/init mounts /dev (devtmpfs)
/init starts /sbin/init
/sbin/init (busybox) reads inittab
inittab has rules to run the init scripts in /etc/init.d
inittab has a rule to start a getty (login prompt)

I have added getty as EXIT_PROC.

When I boot the kernel with rdinit=/sbin/bootchartd
bootchart_init=/init, bootchartd detects it is in the init process,
and also detects it's in an 'initrd'. In this case, the start() method
is called, but wait_boot() is not.
This is my first question: why is wait_boot() not called (and thus:
why is initrd treated differently as a normal system), and how is the
bootchartd stop() method supposed to be called if wait_boot() is not
doing it?
I have currently patched bootchartd such that the initrd exception is
removed, and thus both start() and wait_boot() are called.

Another problem I have with bootchartd is that it spawns a message:
/sbin/bootchartd: line 229: can't open '/dev/null'

where line 229 has just 'fi' (the end of the 'if init process' block).
There is no explicit reference to /dev/null in that script though, and
I have not been able to find out which command is causing that.
The fact that /dev/null is not present is because it is normally
created with devtmpfs, and this is only mounted on /dev through /init,
which has the following commands on my system:

#!/bin/sh
# devtmpfs does not get automounted for initramfs
/bin/mount -t devtmpfs devtmpfs /dev
exec 0</dev/console
exec 1>/dev/console
exec 2>/dev/console
exec /sbin/init $*

So, the order
bootchartd --> /init --> /sbin/init
is not really right. It should rather be
/init --> bootchartd --> /sbin/init

I can get this order by changing the last line of /init so that it
calls bootchartd, and passing bootchart_init=/sbin/init on the kernel
command-line. This fixes the /dev/null problem.

How is this working on other systems using initramfs or initrd?
Any comments on my approach above are welcome.

Now, with the above fix, when bootchart-collector is started,
am_in_initrd() returns true, and the initrd sanity check is called.
This one however, does not find (rd)init=/sbin/bootchartd on the
kernel command line and bails out. Manually patching
bootchart-collector can also fix that problem.

To conclude, to get bootchart2 to output statistics properly, I need to:

• change the boot order so that /init runs first and starts
  bootchartd, which then starts /sbin/init
• patch bootchartd to remove the initrd exception
• patch bootchart-collector to remove the initrd specific code

I would like to hear from you what you think of the above, and how we
can fix bootchart2 to cover this type of embedded system. Note that I
am not doing anything exotic: this is a standard busybox-based
embedded system, built with buildroot (www.buildroot.org) and standard
initramfs-based rootfs.

If we can find a good solution for these problems, I will add support
for building bootchart2 in buildroot, so that other developers of such
embedded systems can benefit from it.

While trying to render a chart I get something like this:

[~] pybootchartgui -i
No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
parsing 'cmdline2.log'
parsing 'proc_diskstats.log'
parsing 'proc_stat.log'
parsing 'taskstats.log'

Traceback (most recent call last):
File "/usr/bin/pybootchartgui", line 23, in
sys.exit(main())
File "/usr/lib/python2.6/site-packages/pybootchartgui/main.py", line 114, in main
options.crop_after, options.annotate)
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 537, in parse
state = parse_paths(writer, ParserState(), paths)
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 457, in parse_paths
state = _do_parse(writer, state, name, tf.extractfile(name))
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 414, in _do_parse
state.ps_stats = _parse_taskstats_log(writer, file)
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 184, in _parse_taskstats_log
avgSampleLength = (ltime - startTime)/(len(timed_blocks)-1)
ZeroDivisionError: integer division or modulo by zero ``

I've tested on 2 kernels (one with initrd, one without), always the same. Running Arch Linux and Python 2.6.5.

With 0.12.2 on armel qemu debian sid image,
bootchart.png and bootchart.log available here http://annarchy.freedesktop.org/~rm/bootchart2/

$ python /usr/lib/python2.6/site-packages/pybootchartgui/main.py
No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
corrupted init call for net_ns_init+0x0/0x17c
corrupted init call for ptrace_break_init+0x0/0x2c
corrupted init call for consistent_init+0x0/0xc8
corrupted init call for sysctl_init+0x0/0x44
corrupted init call for ksysfs_init+0x0/0xcc
corrupted init call for init_jiffies_clocksource+0x0/0x1c
corrupted init call for filelock_init+0x0/0x4c
corrupted init call for init_script_binfmt+0x0/0x1c
corrupted init call for init_elf_binfmt+0x0/0x1c
corrupted init call for debugfs_init+0x0/0x64
corrupted init call for securityfs_init+0x0/0x64
corrupted init call for random32_init+0x0/0xac
corrupted init call for sock_init+0x0/0x84
corrupted init call for netpoll_init+0x0/0x28
corrupted init call for netlink_proto_init+0x0/0x164
corrupted init call for bdi_class_init+0x0/0x5c
corrupted init call for kobject_uevent_init+0x0/0x68
corrupted init call for pcibus_class_init+0x0/0x1c
corrupted init call for pci_driver_init+0x0/0x1c
corrupted init call for amba_init+0x0/0x1c
corrupted init call for tty_class_init+0x0/0x3c
corrupted init call for vtconsole_class_init+0x0/0xe0
corrupted init call for customize_machine+0x0/0x2c
corrupted init call for init_atags_procfs+0x0/0xe4
corrupted init call for clk_init+0x0/0x38
corrupted init call for topology_init+0x0/0x30
corrupted init call for versatile_pci_init+0x0/0x20
corrupted init call for param_sysfs_init+0x0/0x1cc
corrupted init call for readahead_init+0x0/0x40
corrupted init call for init_bio+0x0/0xec
corrupted init call for blk_settings_init+0x0/0x4c
corrupted init call for blk_ioc_init+0x0/0x48
corrupted init call for genhd_device_init+0x0/0x50
corrupted init call for fbmem_init+0x0/0xa8
corrupted init call for misc_init+0x0/0xb0
corrupted init call for serio_init+0x0/0x9c
corrupted init call for input_init+0x0/0x118
corrupted init call for rtc_init+0x0/0x74
corrupted init call for hwmon_init+0x0/0x54
corrupted init call for proto_init+0x0/0x3c
corrupted init call for net_dev_init+0x0/0x140
corrupted init call for neigh_init+0x0/0x8c
corrupted init call for fib_rules_init+0x0/0xb8
corrupted init call for pktsched_init+0x0/0xe4
corrupted init call for tc_filter_init+0x0/0x60
corrupted init call for tc_action_init+0x0/0x60
corrupted init call for genl_init+0x0/0xf8
corrupted init call for wireless_nlevent_init+0x0/0x28
corrupted init call for sysctl_init+0x0/0x38
corrupted init call for alignment_init+0x0/0x94
corrupted init call for clocksource_done_booting+0x0/0x24
corrupted init call for init_pipe_fs+0x0/0x58
corrupted init call for init_mnt_writers+0x0/0x20
corrupted init call for eventpoll_init+0x0/0x9c
corrupted init call for anon_inode_init+0x0/0x118
corrupted init call for chr_dev_init+0x0/0xa8
corrupted init call for loopback_init+0x0/0x1c
corrupted init call for inet_init+0x0/0x31c
corrupted init call for af_unix_init+0x0/0x60
corrupted init call for populate_rootfs+0x0/0xf0
corrupted init call for timer_init_sysfs+0x0/0x44
corrupted init call for fpe_init+0x0/0x84
corrupted init call for init_sched_debug_procfs+0x0/0x48
corrupted init call for create_proc_profile+0x0/0x78
corrupted init call for ioresources_init+0x0/0x60
corrupted init call for uid_cache_init+0x0/0x90
corrupted init call for init_posix_timers+0x0/0xc0
corrupted init call for init_posix_cpu_timers+0x0/0xe8
corrupted init call for nsproxy_cache_init+0x0/0x48
corrupted init call for timekeeping_init_device+0x0/0x38
corrupted init call for init_clocksource_sysfs+0x0/0x68
corrupted init call for init_timer_list_procfs+0x0/0x48
corrupted init call for init_tstats_procfs+0x0/0x48
corrupted init call for futex_init+0x0/0x6c
corrupted init call for kallsyms_init+0x0/0x40
corrupted init call for crash_save_vmcoreinfo_init+0x0/0x394
corrupted init call for crash_notes_memory_init+0x0/0x58
corrupted init call for pid_namespaces_init+0x0/0x48
corrupted init call for audit_init+0x0/0x140
corrupted init call for relay_init+0x0/0x14
corrupted init call for utsname_sysctl_init+0x0/0x20
corrupted init call for init_per_zone_pages_min+0x0/0x50
corrupted init call for pdflush_init+0x0/0x2c
corrupted init call for kswapd_init+0x0/0x20
corrupted init call for procswaps_init+0x0/0x40
corrupted init call for init_tmpfs+0x0/0xe8
corrupted init call for cpucache_init+0x0/0x1c
corrupted init call for fasync_init+0x0/0x48
corrupted init call for aio_setup+0x0/0x98
corrupted init call for inotify_setup+0x0/0x20
corrupted init call for inotify_user_setup+0x0/0xec
corrupted init call for dquot_init+0x0/0x13c
corrupted init call for dnotify_init+0x0/0x48
corrupted init call for init_devpts_fs+0x0/0x4c
corrupted init call for init_ramfs_fs+0x0/0x1c
corrupted init call for ipc_init+0x0/0x2c
corrupted init call for ipc_sysctl_init+0x0/0x20
corrupted init call for init_mqueue_fs+0x0/0xe4
corrupted init call for key_proc_init+0x0/0x54
corrupted init call for selinux_nf_ip_init+0x0/0xac
corrupted init call for init_sel_fs+0x0/0x7c
corrupted init call for selnl_init+0x0/0x6c
corrupted init call for sel_netif_init+0x0/0x9c
corrupted init call for sel_netnode_init+0x0/0x9c
corrupted init call for sel_netport_init+0x0/0x9c
corrupted init call for aurule_init+0x0/0x50
corrupted init call for crypto_algapi_init+0x0/0x18
corrupted init call for cryptomgr_init+0x0/0x1c
corrupted init call for hmac_module_init+0x0/0x1c
corrupted init call for md5_mod_init+0x0/0x1c
corrupted init call for bsg_init+0x0/0x148
corrupted init call for noop_init+0x0/0x20
corrupted init call for as_init+0x0/0x20
corrupted init call for deadline_init+0x0/0x20
corrupted init call for cfq_init+0x0/0xd0
corrupted init call for audit_classes_init+0x0/0x64
corrupted init call for pci_init+0x0/0x40
corrupted init call for pci_proc_init+0x0/0x8c
corrupted init call for fb_console_init+0x0/0x178
corrupted init call for amba_clcdfb_init+0x0/0x40
corrupted init call for rand_initialize+0x0/0x38
corrupted init call for tty_init+0x0/0x1d4
corrupted init call for pty_init+0x0/0x228
corrupted init call for pl011_init+0x0/0x54
corrupted init call for brd_init+0x0/0x1b8
corrupted init call for net_olddevs_init+0x0/0xcc
corrupted init call for serport_init+0x0/0x3c
corrupted init call for amba_kmi_init+0x0/0x1c
corrupted init call for mousedev_init+0x0/0xa0
corrupted init call for atkbd_init+0x0/0x28
corrupted init call for pl031_init+0x0/0x1c
corrupted init call for sysctl_core_init+0x0/0x1c
corrupted init call for flow_cache_init+0x0/0x158
corrupted init call for llc_init+0x0/0x2c
corrupted init call for llc2_init+0x0/0xd4
corrupted init call for snap_init+0x0/0x48
corrupted init call for rif_init+0x0/0xb4
corrupted init call for blackhole_module_init+0x0/0x1c
corrupted init call for sysctl_ipv4_init+0x0/0x5c
corrupted init call for init_syncookies+0x0/0x24
corrupted init call for ipv4_netfilter_init+0x0/0x1c
corrupted init call for cubictcp_register+0x0/0x88
corrupted init call for packet_init+0x0/0x54
corrupted init call for vfp_init+0x0/0x104
corrupted init call for sched_init_debug+0x0/0x40
corrupted init call for init_oops_id+0x0/0x34
corrupted init call for disable_boot_consoles+0x0/0x5c
corrupted init call for pm_qos_power_init+0x0/0x70
corrupted init call for taskstats_init+0x0/0x94
corrupted init call for random32_reseed+0x0/0x68
corrupted init call for pci_sysfs_init+0x0/0x60
corrupted init call for seqgen_init+0x0/0x1c
corrupted init call for rtc_hctosys+0x0/0x144
corrupted init call for tcp_congestion_default+0x0/0x1c
parsing 'cmdline2.log'
parsing 'paternity.log'
parsing 'proc_diskstats.log'
parsing 'proc_stat.log'
parsing 'taskstats.log'
merged 0 logger processes
pruned 11 process, 0 exploders, 0 threads, and 0 runs
bootchart written to 'bootchart.png'

make works but not pybootchart, there is a python 3 incompatibility
i'm on archlinux

I'm using Gentoo and bootchart 14.4 (the log is generated using 14.2 since I just updated on a running computer), and when running pybootchartgui I get the following error. I got the same parsing the logs with 14.2:

peter@skare$ pybootchartgui 
No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
parsing 'cmdline2.log'
parsing 'paternity.log'
Odd paternity line ''
parsing 'proc_cpuinfo.log'
parsing 'proc_diskstats.log'
parsing 'proc_meminfo.log'
parsing 'proc_stat.log'
parsing 'taskstats.log'
Traceback (most recent call last):
  File "/usr/bin/pybootchartgui", line 23, in <module>
    sys.exit(main())
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/main.py", line 124, in main
    res = parsing.Trace(writer, args, options)
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 46, in __init__
    parse_paths (writer, self, paths)
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 679, in parse_paths
    state = _do_parse(writer, state, name, tf.extractfile(name))
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 630, in _do_parse
    state.ps_stats = _parse_taskstats_log(writer, file)
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 321, in _parse_taskstats_log
    cpu_ns, blkio_delay_ns, swapin_delay_ns = long(tokens[-3]), long(tokens[-2]), long(tokens[-1]),
ValueError: invalid literal for long() with base 10: 'bootchart-colle'

This is the second time it happens in four reboots.

Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] bootchart-collector started as pid 1201 with 2 args: '--dump' '/tmp/bootchart.478TaoxNxj'
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] Extracting profile data from pid 427
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] map 0xbe899000 -> 0xbe8ae000 size: 84k from 'be899000' 'be8ae000'
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] pread error 'No such process'
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] read 0 bytes of 86016
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] Couldn't find state structures on pid 427's stack
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] bootchart-collector unmounted proc / clean exit
Aug 28 16:34:44 om-gta02 kernel: [21474604.990000] umount /lib/bootchart/tmpfs: Device or resource busy

ps aux | grep bootchart
root 426 0.0 0.5 3008 640 ? S 16:33 0:00 /bin/bash /sbin/bootchartd
root 427 5.1 2.2 12600 2872 ? Tl 16:33 0:12 /lib/bootchart/bootchart-collector 50

ls bootchart.478TaoxNxj/
dmesg header proc_cpuinfo.log

Run make && make test at branch push.

So I have noticed a little message on my fedora rawhide machine and on my gentoo machie when trying to use bootchart:
[ 48.712853] bootchart-collector unmounted proc / clean exit
[ 48.712855] umount /lib/bootchart/tmpfs: Device or resource busy

And mount shows:
$ mount | grep bootc
none on /lib64/bootchart/tmpfs type tmpfs (rw,nosuid,noexec,relatime)
none on /lib64/bootchart/tmpfs/proc type proc (rw,nosuid,nodev,noexec,relatime)

However bootchart is not running anywhere.

This seems to be because of bootchart-collector always mounts and umounts /lib/boostchart/tmpfs{/,/*} no matter really what options is passed.
The problem with this seems to be here the following:

1. bootchart-collector starts by bootchartd ad mounts everything
2. "bootchart-collector --dump" mounts everything again, and then tries to umount it
3. something fails

This also got me thinking, does --dump really even need to mount this structure all over again? As long as the initial bootchart-collector it should dump data from is running, this env should already be there.

So maybe this is two issues, bootchart-collector fails to clean up after itself, and bootchart-collector should not mount everything all over again.

I have added the proper arguments to /boot/grub/menu.lst, but bootchart.tgz is still not created.

Here's the log:

$ dmesg | grep bootchart
Kernel command line: ro root=/dev/sda3 initcall_debug printk.time=y quiet init=/sbin/bootchartd vga=0x037b 3
[ 4.515213] bootchart-collector started as pid 824 with 1 args: '50'
[ 4.515216] bootchart-collector run outside initrd
[ 4.515217] bootchart collector already running as pid 823, exiting...
[ 4.764974] bootchart continuing boot
[ 32.704138] bootchart-collector started as pid 1940 with 2 args: '--dump' '/tmp/bootchart.TdLggrvdT6'
[ 32.704143] bootchart-collector unmounted proc / clean exit
[ 32.704145] umount /lib/bootchart/tmpfs: Device or resource busy

For some reaseon /lib/bootchart/tmpfs is busy?

If I do:
$ sudo umount /lib/bootchart/tmpfs
It succeeds.

How can I fix this?

/lib/bootchart/tmpfs

This not good place for tmpfs, REALLY :-)
Maybe /tmp folder will better than /lib ?

When I builded rpm package, tmpfs folder not exist.
I added this hand to spec file

%make_install

this fix bug with not installed folder

install -m 755 -d %{buildroot}/lib/bootchart/tmpfs

PS: debug option for bootchart will be great idea ;-)

• Testing of app-benchmarks/bootchart2-0.14.4 with CPython 3.1...
  make -j16 -l12 test
  for f in pybootchartgui/tests/*.py;
  do
  echo "Testing $f...";
  python "$f";
  done
  Testing pybootchartgui/tests/parser_test.py...
  .F...

  FAIL: testParseProcPsLog (main.TestBCParser)

  Traceback (most recent call last):
  File "pybootchartgui/tests/parser_test.py", line 55, in testParseProcPsLog
  self.assertEqual(tokens[0], str(process.pid / 1000))
  AssertionError: '1' != '1.0'

Ran 5 tests in 1.144s

FAILED (failures=1)
Testing pybootchartgui/tests/process_tree_test.py...

EEEEEE

ERROR: testBuild (main.TestProcessTree)

Traceback (most recent call last):
File "pybootchartgui/tests/process_tree_test.py", line 49, in testBuild
self.checkAgainstJavaExtract(self.mk_fname('extract.processtree.1.log'), process_tree)
File "pybootchartgui/tests/process_tree_test.py", line 42, in checkAgainstJavaExtract
self.assertEqual(long(tokens[2]), 10 * actual.start_time)
NameError: global name 'long' is not defined

ERROR: testMergeExploders (main.TestProcessTree)

Traceback (most recent call last):
File "pybootchartgui/tests/process_tree_test.py", line 67, in testMergeExploders
self.checkAgainstJavaExtract(self.mk_fname('extract.processtree.3c.log'), process_tree)
File "pybootchartgui/tests/process_tree_test.py", line 42, in checkAgainstJavaExtract
self.assertEqual(long(tokens[2]), 10 * actual.start_time)
NameError: global name 'long' is not defined

ERROR: testMergeLogger (main.TestProcessTree)

Traceback (most recent call last):
File "pybootchartgui/tests/process_tree_test.py", line 54, in testMergeLogger
self.checkAgainstJavaExtract(self.mk_fname('extract.processtree.2.log'), process_tree)
File "pybootchartgui/tests/process_tree_test.py", line 42, in checkAgainstJavaExtract
self.assertEqual(long(tokens[2]), 10 * actual.start_time)
NameError: global name 'long' is not defined

ERROR: testMergeRuns (main.TestProcessTree)

Traceback (most recent call last):
File "pybootchartgui/tests/process_tree_test.py", line 84, in testMergeRuns
self.checkAgainstJavaExtract(self.mk_fname('extract.processtree.3e.log'), process_tree)
File "pybootchartgui/tests/process_tree_test.py", line 42, in checkAgainstJavaExtract
self.assertEqual(long(tokens[2]), 10 * actual.start_time)
NameError: global name 'long' is not defined

ERROR: testMergeSiblings (main.TestProcessTree)

Traceback (most recent call last):
File "pybootchartgui/tests/process_tree_test.py", line 75, in testMergeSiblings
self.checkAgainstJavaExtract(self.mk_fname('extract.processtree.3d.log'), process_tree)
File "pybootchartgui/tests/process_tree_test.py", line 42, in checkAgainstJavaExtract
self.assertEqual(long(tokens[2]), 10 * actual.start_time)
NameError: global name 'long' is not defined

ERROR: testPrune (main.TestProcessTree)

Traceback (most recent call last):
File "pybootchartgui/tests/process_tree_test.py", line 60, in testPrune
self.checkAgainstJavaExtract(self.mk_fname('extract.processtree.3b.log'), process_tree)
File "pybootchartgui/tests/process_tree_test.py", line 42, in checkAgainstJavaExtract
self.assertEqual(long(tokens[2]), 10 * actual.start_time)
NameError: global name 'long' is not defined

Ran 6 tests in 2.266s

FAILED (errors=6)
make: *** [test] Error 1

when i try to run your script n 64bit kernel i have this error:

mkdir: cannot create directory /dev/.bootchart/lib/bootchart: Not a directory
cp: accessing /dev/.bootchart/lib/bootchart: Not a directory
chroot: failed to run command /lib/bootchart/bootchart-collector: No such file or a directory

The README claims that bootchart2 will work with CONFIG_TASKSTATS=n, just not as well. However, when I try to generate charts on systems with CONFIG_TASKSTATS=n, I get a variety of wrong behaviors, depending on the version of bootchart2.

This is relevant when trying to instrument embedded Linux images generated by Yocto. See Yocto bug 5893:
https://bugzilla.yoctoproject.org/show_bug.cgi?id=5893
Yocto can be configured to enable CONFIG_TASKSTATS, but it's off by default, so ideally we'd like bootchart2 to at least work partially without CONFIG_TASKSTATS.

The bug seems to go back a very long way. On versions starting with 0.14.2 all the way up through current master, the bootchart is completely blank. Example: (very tall image, just scroll past it to read the rest)

On versions from 0.12.3 up through 0.14.0, the bootchart shows only the first five seconds, which is not correct. Example: (very tall image, just scroll past it to read the rest)

In versions prior to 0.12.3, a very small (~20 KB) bootchart.tgz is created, and pybootchartgui complains that it does not contain a valid bootchart.

Meanwhile, in some versions, there are other bugs that seem to have come and gone but which stop me from getting proper test results.

For reference, a correct boot chart for the Yocto image I'm testing looks like this:

I am able to get correct boot charts for all versions tested if CONFIG_TASKSTATS is enabled.

Complete results:

So as you can see, I could not find a single version of bootchart2 which actually produced a correct bootchart with CONFIG_TASKSTATS=n, out of any of the ones I tested.

Fixing this bug could be as simple as rewriting the README to indicate that CONFIG_TASKSTATS is mandatory, if you do not intend to support kernels without it.

I can get you bootchart.tgz and bootchart.png files for all of these tests if you want them.

Hi,
I compiled and installed your bootchart and the graphics it produces are very neat :D One thing though! It fails to stop automatically. I checked the start script. There are several programs listed as "stopping condition" one of them is gnome-terminal I added gdm and I have other programs from that list started.
But bootchart stops only after issuing /sbin/bootchartd stop. What could be wrong? how does it scan for the processes?

best enaut

See https://pygobject.readthedocs.io/en/latest/guide/porting.html

If your code contains imports like import gtk, import gst, import glib or import gobject you are using the old bindings and you should upgrade.

pygtk supported GTK 2.0 and Python 2 only. PyGObject supports GTK >=3.0 and Python 2/3. If you port away from pygtk you also have to move to GTK 3.0 at the same time. pygtkcompat described below can help you with that transition.

I'm not an expert in python, but your code seems to need porting to PyGObject to work on Gtk3 and python3. Excuse me if I'm wrong.

I guess I ran bootchart2 correctly, but I get an error message when evaluating the collected data:

eike@donald:~/temp/chart$ pybootchartgui
No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
corrupted init call for cdrom_init+0x0/0x6a
Parse error: empty state: '/var/log/bootchart.tgz' does not contain a valid bootchart

The cdrom init call indeed looks different from others (like it's being called implicitely?):

...
[ 1.357220] sd 4:0:0:0: [sdc] Write cache: enabled, read cache: enabled, does
n't support DPO or FUA
[ 1.357239] sda:
[ 1.357419] sdb:
[ 1.357508] sdc:initcall init_sd+0x0/0x16b [sd_mod] returned 0 after 787 use
cs
[ 1.357760] sdc1 sdc2 <calling cdrom_init+0x0/0x6a [cdrom] @ 363
[ 1.357887] initcall cdrom_init+0x0/0x6a [cdrom] returned 0 after 31 usecs
[ 1.357901] sdc5 >
[ 1.358130] sd 4:0:0:0: [sdc] Attached SCSI disk
[ 1.367534] sdb1 sdb2 < sda2 < sdb5 >
[ 1.380143] sd 3:0:0:0: [sdb] Attached SCSI disk
[ 1.384234] sda5
...

I've got this line in my dmesg output, with a UTF-8-encoded ® symbol (file /sys/bus/usb/devices/3-2/product confirms it):

[    5.339102] usb 3-2: Product: Natural® Ergonomic Keyboard 4000

pybootchartgui doesn't seem to like it much...

No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
  0.0 seconds
parsing 'dmesg'
Traceback (most recent call last):
  File "/usr/bin/pybootchartgui", line 23, in <module>
    sys.exit(main())
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/main.py", line 124, in main
    res = parsing.Trace(writer, args, options)
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 46, in __init__
    parse_paths (writer, self, paths)
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 679, in parse_paths
    state = _do_parse(writer, state, name, tf.extractfile(name))
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 637, in _do_parse
    state.kernel = _parse_dmesg(writer, file)
  File "/usr/lib64/python2.7/site-packages/pybootchartgui/parsing.py", line 494, in _parse_dmesg
    for line in file.read().decode().split('\n'):
UnicodeDecodeError: 'ascii' codec can't decode byte 0xc2 in position 59783: ordinal not in range(128)

Now that cairo for python3 entered debian i can sort this out.

For some reason, UML kernel images are MMU-enabled, but never have stack entry in /proc//maps. Therefore, the collector's --dump fails at them as they fail to find [stack].

Any chance of adding some other way of dumping state? At a guess, just shared memory, mmap, or something would work with less of a hard dependency on /proc + luck in stuff not breaking.. ;)

(find_chunks in dump.c fails if [stack] occurs on 1kb block's border too, so not very fond of it.)

When running bootchartd from the command line, and then stopping bootchartd, tar fails to find the dmesg log because it is not being dumped when bootchartd is being run as a non-init process. The bootchart.tgz archive is not created in this case.

I have created a patch that seems to do the job:

From: Henry Yei [email protected]
Date: Tue, 15 Mar 2011 18:20:43 -0700
Subject: [PATCH] expect dmesg log only if bootchartd run as init

Source: MontaVista Software, LLC
MR: 43117
Type: Defect Fix
Disposition: Needs submitting to bootchart2

The bootchartd script attempts to archive the dmesg
log in all cases, however the dmesg log is only dumped
when bootchartd is being run as the init process. This
patch adds conditional logic to only expect the dmesg
log when it is supposed to be generated.

Signed-off-by: Henry Yei [email protected]

bootchartd.in | 7 ++++++-
1 files changed, 6 insertions(+), 1 deletions(-)

diff --git a/bootchartd.in b/bootchartd.in
index a16b07d..bf366d5 100755
--- a/bootchartd.in
+++ b/bootchartd.in
@@ -123,7 +123,12 @@ stop()
fi

    # Archive it all up into the bootchart output

•   tar -zcf "$BOOTLOG_DEST" header dmesg *.log
  

•   # only expect dmesg log if bootchartd was started as an init process
  

•   if [ -n "$INIT_PROCESS" ]; then
  

•           tar -zcf "$BOOTLOG_DEST" header dmesg *.log
  

•   else
  

•           tar -zcf "$BOOTLOG_DEST" header *.log
  

•   fi
  
  rm -Rf $tmpdir
  

It gives this error:

/sbin/bootchartd: line 170: /lib/bootchart/tmpfs/kmsg: Operation not permitted

Then /sbin/bootchartd stop gives "Can't extract boot chart from collector" (fails on the collector dump).

Micheal,
pybootchargui reported this:
Missing CONFIG_PROC_EVENTS: no parent for pid '1001' ('bootchartd') with ppid '0'
Missing CONFIG_PROC_EVENTS: no parent for pid '1002' ('init') with ppid '0'
Missing CONFIG_PROC_EVENTS: no parent for pid '2882001' ('redis-server') with ppid '0'

First the simple stuff:

• pid 1 and 2 should not be accounted
• the error message is misleading, i have CONFIG_PROC_EVENTS and it is working fine
  I can fix myself these issues but i'd like a second opinion :)

Then the very strange pid of redis-server. Any hint?

Some of the stuff you can find in the logs:

• pid 2882 is used two times, one by startpar the other by redis-server initd script, that's plausible but i think in cases like this we can reuse the parent pid of the first one and the name of the second?

Logs available here:
http://people.freedesktop.org/~rm/bootchart-redis-pid/

This is bootchart2 0.12.3

The data has been collected on armel, both armel machine and my x86 desktop gave the same error while running pybootchargui.

python /usr/lib/python2.6/site-packages/pybootchartgui/main.py ~/src/moko/bootchart.tgz
parsing '/home/rm/src/moko/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
parsing 'cmdline2.log'
parsing 'paternity.log'
parsing 'proc_cpuinfo.log'
parsing 'proc_diskstats.log'
parsing 'proc_stat.log'
parsing 'taskstats.log'
merged 0 logger processes
pruned 805 process, 0 exploders, 137 threads, and 6 runs
Traceback (most recent call last):
File "/usr/lib/python2.6/site-packages/pybootchartgui/main.py", line 161, in
sys.exit(main())
File "/usr/lib/python2.6/site-packages/pybootchartgui/main.py", line 152, in main
render()
File "/usr/lib/python2.6/site-packages/pybootchartgui/main.py", line 143, in render
batch.render(writer, res, options, filename)
File "/usr/lib/python2.6/site-packages/pybootchartgui/batch.py", line 39, in render
surface = make_surface (w, h)
File "/usr/lib/python2.6/site-packages/pybootchartgui/batch.py", line 21, in
"png": (lambda w, h: cairo.ImageSurface(cairo.FORMAT_ARGB32, w, h),
MemoryError

Here is the output -

Traceback (most recent call last):
  File "/usr/bin/pybootchartgui", line 20, in <module>
    from pybootchartgui.main import main
ImportError: No module named pybootchartgui.main

the command I ran was pybootchartgui -i.

In my first chart created, the timing part and the cumulative percentage part overlap.
See http://user.cs.tu-berlin.de/~eikes/debian/bootchart.png.

hi.

I don't know what's wrong.
so i booted, changed the line in grub by adding initcall_debug printk.time=y init=/sbin/bootchartd

then I got my screen full of 'bootchart-collector - internal buffer overflow !' and rapidly filling it
I let it boot anyway and that works.
but now bootchart-collector is still using 100% cpu on one core. I can't kill it.
there is no /var/log/bootchart.tgz and no image either.

and
$ pybootchartgui -i
No path given, trying /var/log/bootchart.tgz
warning: path '/var/log/bootchart.tgz' does not exist, ignoring.
Parse error: empty state: '/var/log/bootchart.tgz' does not contain a valid bootchart

using kernel-2.6.33.4 on archlinux

Both README and manpage examples illustrate editing /boot/grub/menu.lst this should be updated to document configuring grub2, i.e /etc/defaults/grub.cfg and then run grub2-mkconfig

Hello,

pybootchartgui fails with this:

Traceback (most recent call last):
File "/usr/lib/python2.6/site-packages/pybootchartgui/main.py", line 161, in
sys.exit(main())
File "/usr/lib/python2.6/site-packages/pybootchartgui/main.py", line 116, in main
options.crop_after, options.annotate)
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 592, in parse
state = parse_paths (writer, ParserState(), paths)
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 512, in parse_paths
state = _do_parse(writer, state, name, tf.extractfile(name))
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 463, in _do_parse
state.disk_stats = _parse_proc_disk_stat_log(file, get_num_cpus(state.headers))
File "/usr/lib/python2.6/site-packages/pybootchartgui/parsing.py", line 251, in _parse_proc_disk_stat_log
util = float( sums[2] ) / 10 / interval / numCpu
ZeroDivisionError: float division

i've checked that numCpu is zero because of this headers:

defaultdict(<type 'str'>, {'system.cpu.num': '0', 'system.kernel.options': 'root=/dev/sda1 initcall_debug printk.time=y quiet init=/sbin/bootchartd', 'title': 'Boot chart for debian-armel.(none) (Thu Jul 29 22:29:57 2010)', 'system.cpu': '0', 'version': '0.12.2', 'system.uname': 'Linux 2.6.26-1-versatile #1 Sun Mar 15 05:49:36 UTC 2009 armv5tejl', 'system.maxpid': '1929', 'system.release': ''})

any hint? maybe add a max(foo, 1) for every return of get_num_cpus() just to be sure?

this is 0.12.2.

I think that auto generation of image file should be less talkative, especially that there are options in pybootchartgui that allow suppressing of sending unimportant messages to a terminal.

Max-E reports:
I am seeing a lot of extra pidof and bootchart-collector processes in this chart, compared to the ones with CONFIG_TASKSTATS=y.

Indeed it looks like ProcessTree.merge_logger() is not working. After debugging a bit the issue is that we don't have childrens for any process, p.child_list is an empty list.

I've observed that bootchartd is unable to dump logs about 10% of the time because the bootchart-collector process isn't available. It looks like the process that is supposed to be there exits because there is a bootchart-collector process with the argument --usleep 5000 still running. This is from the wait_boot() function thats put in the background right before.

I've added -c to /sbin/bootchartd and a fprintf at the beginning of main() in collector.c to narrow down the issue.
[partial output]
Starting bootchart logging
bootchart: no initrd used; starting
bootchart-collector started as pid 415 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 414 with 2 args: '-c' '50'
bootchart console.debug [1]
bootchart-collector started as pid 413 with 3 args: '-c' '--usleep' '250000'
bootchart-collector started as pid 414 with 2 args: '-c' '50'
bootchart-collector run outside initrd
bootchart collector already running as pid 416, exiting...
bootchart-collector started as pid 416 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 417 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 418 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 419 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 420 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 421 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 422 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 423 with 3 args: '-c' '--usleep' '5000'
bootchart-collector started as pid 424 with 3 args: '-c' '--usleep' '5000'

.....

bootchart-collector started as pid 1207 with 3 args: '-c' '--dump' '/tmp/bootchart.XXXXN2niDZ'
bootchart-collector started as pid 1207 with 3 args: '-c' '--dump' '/tmp/bootchart.XXXXN2niDZ'
Failed to find the collector's pid
bootchart-collector pid: 1207 unmounted proc / clean exit
Can't extract boot chart from collector

subject says it all.

I was trying to run /sbin/e4rat-preload as init just after bootchartd
So I used the kernel command line option bootchart_init=/sbin/e4rat-preload along side the other init=/sbin/bootchartd (...)

But it seems the usual /sbin/init was running. I was no mention of e4rat-preload in /var/log/bootchart.png

Looking at /sbin/bootchartd line 176, bootchartd assume that the kernel command line option are passed as arguments to the init process. Well, I don't know if it's the case but not here.
So I fixed it with using
for i in $(cat /proc/cmdline); do

It worked and used e4rat-preload as 2nd init process. I don't know if it has any side effect regarding other option or behavior

Cause of problem

My dmesg contains escape characters, preventing pybootchartgui from processing bootchart logs on my machine.

Suggested fix

Replace

for line in file.read().decode('utf-8', 'ignore').split('\n'):

or another Python UnicodeDecodeError handling method.

Failing case

stripped dmesg output

[ 0.000000] ACPI: BGRT 0x000000007885BEC8 000038 (v00 \xfffffff3\xffffffee 01072009 AMI 00010013)

pybootchartgui stack trace

Traceback (most recent call last): File "/usr/lib/python-exec/python3.4/pybootchartgui", line 23, in <module> sys.exit(main()) File "/usr/lib64/python3.4/site-packages/pybootchartgui/main.py", line 124, in main trace = parsing.Trace(writer, args, options) File "/usr/lib64/python3.4/site-packages/pybootchartgui/parsing.py", line 52, in __init__ parse_paths (writer, self, paths) File "/usr/lib64/python3.4/site-packages/pybootchartgui/parsing.py", line 716, in parse_paths state = _do_parse(writer, state, name, tf.extractfile(name)) File "/usr/lib64/python3.4/site-packages/pybootchartgui/parsing.py", line 674, in _do_parse state.kernel = _parse_dmesg(writer, file) File "/usr/lib64/python3.4/site-packages/pybootchartgui/parsing.py", line 529, in _parse_dmesg for line in file.read().decode('utf-8').split('\n'): UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf3 in position 57: invalid continuation byte

stripped failing bootchart.tgz (base64 encoded, use base64 -d to decode)

H4sIANpz5FoAA+3RwQsBQRTH8Tn7K96Ri97sLLvcrCQHJbnJQWxyQO0i+aNd/ANmSVHKSaLvp1ev mXmHN/3mqzRfmM9Srx6GRbdRTR/7lQ2tsS6IrPpy1hQX1hnRD+91tcu300zETI+7LJ1ly1W+Wb+a e/f+o8biafUWxERa7UGvKUl3OBI93POJ4riWdNqxFAcXS3mvKueTPFGfXqDakFa/J8Wk9eUqpW9/ EAAAAAAAAAAAAAAAAAD+1AVFIhhQACgAAA==

Link to above files (as Github attachments are broken)

https://drive.google.com/drive/folders/12bXkurAEv3kntzk5ZPk55Jyibn3o3-Kr

The pybootchartgui unit tests all fail mostly because it hasn't been rewritten to remove calls to ParserState(), and use the Trace() instead.

Got this on irc today:

'int object is not iterable' and 'global times not defined' are what I get for crop/annotate respectively

No other info, need to reproduce. meh.

The parsing of the disk stats isn't working for new kernels due to is_relevant_line expecting 14 tokens. See kernel doc below.

https://www.kernel.org/doc/Documentation/ABI/testing/procfs-diskstats

I am attempting to run bootchartd for just a few seconds so I can see a snapshot of the processes on my system. It works OK with the 0.14.5 stable release, but not with the latest Git revision

Operating System: Linux Mint 16 with MATE, 64-bit, fully updated as of July 1 2014

Install process:

    make clean
    sudo PY_SITEDIR=/usr/lib/python2.7/dist-packages/ make install

Running bootchartd:

    sudo bootchartd start
    sleep 3
    sudo bootchartd stop

Expected results:
A chart is created in /var/log/bootchart.png.

Actual results:
When I run bootchartd stop, it exits with an error message similar to "Can't find bootchart output in /tmp/bootchart.fTQHTlD3rq - aborting", and the chart is not created.

Versions affected:
I am able to use git-bisect to prove that the first commit that exhibits this behavior is 36721eb. Although I have not tried them all, I think any commits newer than that are also affected, including current master. The previous commit, 89cee25, seems to work as expected. However, looking at the actual changes between these two commits, it appears that the commit just enabled some extra assertions, so there may be a deeper underlying problem that goes back further. On the other hand, 89cee25 was able to produce a usable and correct boot chart.

Other information:
It looks like the tmp directories are being left behind when bootchartd stop fails. If you believe the contents of those directories would be useful to you, I can upload them somewhere and get them to you.
Also, here is the script I used when bisecting:

    #! /bin/sh

    make clean
    sudo PY_SITEDIR=/usr/lib/python2.7/dist-packages/ make install
    sudo rm -f /var/log/bootchart.tgz /var/log/bootchart.png
    sudo bootchartd start
    sleep 3
    sudo bootchartd stop >/tmp/testwarning && success=1 || success=0 
    if [ "$success" = "0" ] ; then
            grep "Can't find bootchart output in " /tmp/testwarning >/dev/null && cmd=bad || cmd=skip
    else
            cmd=good
    fi
    cp /var/log/bootchart.png .
    echo git bisect $cmd
    git bisect $cmd

First of all thank you for coding this useful tool.
Does it support systemd init?

Latest git gives this.

$ pybootchartgui -i
Traceback (most recent call last):
  File "/usr/bin/pybootchartgui", line 20, in 
    from pybootchartgui.main import main
  File "/usr/lib/python3.2/site-packages/pybootchartgui/main.py", line 25, in 
    from . import parsing
  File "/usr/lib/python3.2/site-packages/pybootchartgui/parsing.py", line 384
    if not lines:
                ^
TabError: inconsistent use of tabs and spaces in indentation

130d775 introduced reading the value of bootchart_init from an environment variable. Since this is a lot cleaner that looping on arguments i think we should investigate if the old code may be safely removed.

This is an excerpt of his findings:

bootparam(7) says that all parameters interpreted by the kernel are
stripped. That means, init=blah never makes it to bootchartd. Unless
using an initrd (which I am not) somehow depends on it, I think the
entire for-loop can go without checking $init at all.

This is also what I observe (now on Linux 3.0-rc1 :-)). The exact
(perhaps not very exciting) details follow. My kernel command line is:

root=/dev/sda3 ro init=/sbin/bootchartd resume=/dev/sda2 initcall_debug printk.time=y bootchart_init=/bin/systemd

Bootchartd has the following environment variables set (by calling "env"
just before checking for $bootchart_init):

TERM=linux
PWD=/
bootchart_init=/bin/systemd
SHLVL=1
HOME=/
BOOT_IMAGE=/vmlinuz-3.0.0-rc1
_=/bin/env

And $@ is empty.

in python it returns float while in python2 it returns int, may break some assumption when dealing with pids multiplied by 1000.

rm@montag:~$ python
Python 2.7.3rc2 (default, Apr 22 2012, 22:35:38)
[GCC 4.6.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.

1000 / 1
1000
1000 / 1
KeyboardInterrupt

rm@montag:~$ python3.2
Python 3.2.3rc2 (default, Mar 21 2012, 06:59:51)
[GCC 4.6.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.
1000 / 1
1000.0

pybootchartgui --annotate=xfwm4 --annotate-file=myfile.txt fails with the error message:

Traceback (most recent call last):
File "/usr/bin/pybootchartgui", line 23, in
sys.exit(main())
File "/usr/lib64/python2.7/site-packages/pybootchartgui/main.py", line 142, in main
for time in res[4]:
AttributeError: Trace instance has no attribute 'getitem'

I have tried to take a look at the main.py source code and I found that:

res = parsing.Trace(writer, args, options)
...
for time in res[4]:
if time is not None:
# output as ms
print(time * 10, file=f)
else:
print(file=f)

People in #python said:
21:44 [A] seems you're using [#] on something you can't use [#] on
21:45 [B] definitely looks like a bug in pybootchartgui to me, Trace doesn't
even define a getitem method, you might have to prod the maintainer of it

My guess is that the line:
for time in res[4]:
if time is not None:
should looks like:
for time in res.times
if time is not None:

Steps to reproduce:

pybootchartgui --annotate=xfwm4 --annotate-file=myfile
No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
parsing 'cmdline2.log'
parsing 'paternity.log'
parsing 'proc_cpuinfo.log'
parsing 'proc_diskstats.log'
parsing 'proc_meminfo.log'
parsing 'proc_stat.log'
parsing 'taskstats.log'
merged 0 logger processes
pruned 485 process, 0 exploders, 36 threads, and 0 runs
merged 0 logger processes
Traceback (most recent call last):
File "/usr/bin/pybootchartgui", line 23, in
sys.exit(main())
File "/usr/lib64/python2.7/site-packages/pybootchartgui/main.py", line 142, in main
for time in res[4]:
AttributeError: Trace instance has no attribute 'getitem'

-- System Information:
Distro: Gentoo 4.7.1 p1.3, pie-0.5.3
Kernel: Linux 3.5.0 #2 SMP x86_64
Locale: LANG=en_US.UTF-8
Shell: /bin/bash
Python: 2.7.3

Bootchart was working upon initial installation, but started failing in this way after a few days.

pybootchartgui -t

No path given, trying /var/log/bootchart.tgz
parsing '/var/log/bootchart.tgz'
parsing 'header'
parsing 'dmesg'
parsing 'cmdline2.log'
parsing 'paternity.log'
parsing 'proc_cpuinfo.log'
parsing 'proc_diskstats.log'
parsing 'proc_meminfo.log'
Traceback (most recent call last):
File "/usr/bin/pybootchartgui", line 23, in
sys.exit(main())
File "main.py", line 124, in main
File "parsing.py", line 50, in init
File "parsing.py", line 684, in parse_paths
File "parsing.py", line 640, in _do_parse
File "parsing.py", line 467, in _parse_proc_meminfo_log
AttributeError: 'NoneType' object has no attribute 'groups'