search

BelaPlatform / bela-image-builder

Scripts to build a Bela image from scratch
MIT License
35 stars 16 forks source link

Network not working after sudden shutdown: the fall and rise of a corrupted modules/ folder #74

Closed giuliomoro closed 6 years ago

giuliomoro commented 6 years ago

This happened after compiling a kernel module which hang the system and so yanked the power cable and restarted. The host was showing "this composite device is not for us" (i.e.: HoRNDIS did not recognize the USB device as something it could do something about) and no network or BELABOOT was coming up.

Serial log:

�
U-Boot SPL 2017.03-dirty (Nov 08 2017 - 18:25:49)
Trying to boot from MMC2
reading u-boot.img
reading u-boot.img

U-Boot 2017.03-dirty (Nov 08 2017 - 18:25:49 +0000)

CPU  : AM335X-GP rev 2.1
I2C:   ready
DRAM:  512 MiB
Reset Source: Power-on reset has occurred.
MMC:   OMAP SD/MMC: 0, OMAP SD/MMC: 1
Using default environment

<ethaddr> not set. Validating first E-fuse MAC
BeagleBone Black:
BeagleBone: cape eeprom: i2c_probe: 0x54:
BeagleBone: cape eeprom: i2c_probe: 0x55:
BeagleBone: cape eeprom: i2c_probe: 0x56:
BeagleBone: cape eeprom: i2c_probe: 0x57:
Net:   eth0: MII MODE
cpsw
Hit any key to stop autoboot:  0
reading uEnv.txt
487 bytes read in 4 ms (118.2 KiB/s)
booting from SD card
## Error: "initrd_file" not defined
reading am335x-bone-bela.dtb
55183 bytes read in 9 ms (5.8 MiB/s)
8393712 bytes read in 545 ms (14.7 MiB/s)
## Flattened Device Tree blob at 88000000
   Booting using the fdt blob at 0x88000000
   Loading Device Tree to 8ffef000, end 8ffff78e ... OK

Starting kernel ...

[    0.000885] clocksource_probe: no matching clocksources found
[    0.740557] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[    0.926795] omap_voltage_late_init: Voltage driver support not added
[    0.934465] PM: Cannot get wkup_m3_ipc handle
[    3.215712] systemd[1]: Failed to start Load Kernel Modules.
[FAILED] Failed to start Load Kernel Modules.
See 'systemctl status systemd-modules-load.service' for details.
[  OK  ] Started File System Check on Root Device.
[  OK  ] Started Create Static Device Nodes in /dev.
[  OK  ] Started File System Check Daemon to report status.
         Starting udev Kernel Device Manager...
         Starting Remount Root and Kernel File Systems...
         Mounting Configuration File System...
         Starting Apply Kernel Variables...
         Mounting FUSE Control File System...
[  OK  ] Mounted Configuration File System.
[  OK  ] Started Journal Service.
[  OK  ] Mounted FUSE Control File System.
[  OK  ] Started udev Kernel Device Manager.
[  OK  ] Started Remount Root and Kernel File Systems.
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Reached target Local File Systems (Pre).
         Starting Load/Save Random Seed...
         Starting udev Coldplug all Devices...
         Starting Flush Journal to Persistent Storage...
[  OK  ] Started Load/Save Random Seed.
[  OK  ] Started Flush Journal to Persistent Storage.
[  OK  ] Started udev Coldplug all Devices.
[  OK  ] Found device /dev/ttyS0.
[  OK  ] Found device /dev/mmcblk0p1.
         Starting File System Check on /dev/mmcblk0p1...
[  OK  ] Started File System Check on /dev/mmcblk0p1.
         Mounting /mnt/boot...
[  OK  ] Mounted /mnt/boot.
[  OK  ] Reached target Local File Systems.
         Starting Create Volatile Files and Directories...
[  OK  ] Started Create Volatile Files and Directories.
         Starting Update UTMP about System Boot/Shutdown...
         Starting Network Time Synchronization...
[  OK  ] Started Update UTMP about System Boot/Shutdown.
[  OK  ] Started Network Time Synchronization.
[  OK  ] Reached target System Initialization.
[  OK  ] Started Daily Cleanup of Temporary Directories.
[  OK  ] Listening on D-Bus System Message Bus Socket.
[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Basic System.
[  OK  ] Started Regular background program processing daemon.
[  OK  ] Started Monitor the Bela cape button.
         Starting Login Service...
         Starting System Logging Service...
[  OK  ] Started D-Bus System Message Bus.
         Starting Configure Bela as a composite USB device...
[  OK  ] Started Bela IDE Launcher.
         Starting Avahi mDNS/DNS-SD Stack...
[  OK  ] Reached target System Time Synchronized.
[  OK  ] Started Daily apt download activities.
[  OK  ] Started Daily apt upgrade and clean activities.
[  OK  ] Reached target Timers.
[  OK  ] Started System Logging Service.
[FAILED] Failed to start Configure Bela as a composite USB device.
See 'systemctl status bela_gadget.service' for details.
[  OK  ] Started Avahi mDNS/DNS-SD Stack.
[  OK  ] Started Login Service.
[  OK  ] Reached target Network (Pre).
         Starting Raise network interfaces...
[FAILED] Failed to start Raise network interfaces.
See 'systemctl status networking.service' for details.
[  OK  ] Reached target Network.
         Starting OpenBSD Secure Shell server...
         Starting Kill Bela programme at shutdown if running...
         Starting Kill dhclient to prevent ifup eth0 blocking shutdown...
         Starting Kill ssh sessions before network...
         Starting Permit User Sessions...
[  OK  ] Reached target Network is Online.
         Starting LSB: Advanced IEEE 802.11 management daemon...
         Starting LSB: simple distributed compiler server...
         Starting LSB: DHCP server...
[  OK  ] Started Kill Bela programme at shutdown if running.
[  OK  ] Started Kill dhclient to prevent ifup eth0 blocking shutdown.
[  OK  ] Started Kill ssh sessions before network.
[  OK  ] Started Permit User Sessions.
[  OK  ] Started LSB: Advanced IEEE 802.11 management daemon.
[  OK  ] Started OpenBSD Secure Shell server.
[  OK  ] Started Getty on tty1.
[  OK  ] Started Serial Getty on ttyS0.
[  OK  ] Started LSB: simple distributed compiler server.
[FAILED] Failed to start LSB: DHCP server.
See 'systemctl status isc-dhcp-server.service' for details.

Debian GNU/Linux 9 bela ttyS0

bela login:
Debian GNU/Linux 9 bela ttyS0

This is journalctl:

root@bela:~# cat log
-- Logs begin at Thu 2016-11-03 17:16:43 UTC, end at Thu 2016-11-03 17:18:13 UTC. --
Nov 03 17:16:43 bela kernel: Booting Linux on physical CPU 0x0
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys cpuset
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys cpu
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys cpuacct
Nov 03 17:16:43 bela kernel: Linux version 4.4.113-ti-xenomai-r148 (root@giulio-VirtualBox) (gcc version 5.5.0 (Linaro GCC 5.5-2017.10) ) #1 PREEMPT Mon Mar 26 11:20:37 BST 2018
Nov 03 17:16:43 bela kernel: CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d
Nov 03 17:16:43 bela kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Nov 03 17:16:43 bela kernel: Machine model: TI AM335x BeagleBone Green
Nov 03 17:16:43 bela kernel: Memory policy: Data cache writeback
Nov 03 17:16:43 bela kernel: On node 0 totalpages: 131072
Nov 03 17:16:43 bela kernel: free_area_init_node: node 0, pgdat c100b204, node_mem_map dfb79000
Nov 03 17:16:43 bela kernel:   Normal zone: 1152 pages used for memmap
Nov 03 17:16:43 bela kernel:   Normal zone: 0 pages reserved
Nov 03 17:16:43 bela kernel:   Normal zone: 131072 pages, LIFO batch:31
Nov 03 17:16:43 bela kernel: CPU: All CPU(s) started in SVC mode.
Nov 03 17:16:43 bela kernel: AM335X ES2.1 (sgx neon )
Nov 03 17:16:43 bela kernel: pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Nov 03 17:16:43 bela kernel: pcpu-alloc: [0] 0
Nov 03 17:16:43 bela kernel: Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 129920
Nov 03 17:16:43 bela kernel: Kernel command line: console=ttyS0,115200n8 root=/dev/mmcblk0p2 ro rootfstype=ext4 rootwait coherent_pool=1M net.ifnames=0 quiet
Nov 03 17:16:43 bela kernel: PID hash table entries: 2048 (order: 1, 8192 bytes)
Nov 03 17:16:43 bela kernel: Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
Nov 03 17:16:43 bela kernel: Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
Nov 03 17:16:43 bela kernel: Memory: 501524K/524288K available (11518K kernel code, 869K rwdata, 3656K rodata, 456K init, 967K bss, 22764K reserved, 0K cma-reserved, 0K highmem)
Nov 03 17:16:43 bela kernel: Virtual kernel memory layout:
                                 vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                                 fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                                 vmalloc : 0xe0800000 - 0xff800000   ( 496 MB)
                                 lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
                                 pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
                                 modules : 0xbf000000 - 0xbfe00000   (  14 MB)
                                   .text : 0xc0008000 - 0xc0ed9b2c   (15175 kB)
                                   .init : 0xc0eda000 - 0xc0f4c000   ( 456 kB)
                                   .data : 0xc0f4c000 - 0xc10257bc   ( 870 kB)
                                    .bss : 0xc1028000 - 0xc1119c04   ( 968 kB)
Nov 03 17:16:43 bela kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Nov 03 17:16:43 bela kernel: Preemptible hierarchical RCU implementation.
Nov 03 17:16:43 bela kernel:         Build-time adjustment of leaf fanout to 32.
Nov 03 17:16:43 bela kernel: NR_IRQS:16 nr_irqs:16 16
Nov 03 17:16:43 bela kernel: IRQ: Found an INTC at 0xfa200000 (revision 5.0) with 128 interrupts
Nov 03 17:16:43 bela kernel: OMAP clockevent source: timer2 at 24000000 Hz
Nov 03 17:16:43 bela kernel: sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns
Nov 03 17:16:43 bela kernel: I-pipe, 24.000 MHz clocksource, wrap in 178956 ms
Nov 03 17:16:43 bela kernel: clocksource: ipipe_tsc: mask: 0xffffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns
Nov 03 17:16:43 bela kernel: clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
Nov 03 17:16:43 bela kernel: OMAP clocksource: timer1 at 24000000 Hz
Nov 03 17:16:43 bela kernel: clocksource_probe: no matching clocksources found
Nov 03 17:16:43 bela kernel: Interrupt pipeline (release #9)
Nov 03 17:16:43 bela kernel: Console: colour dummy device 80x30
Nov 03 17:16:43 bela kernel: Calibrating delay loop... 995.32 BogoMIPS (lpj=1990656)
Nov 03 17:16:43 bela kernel: pid_max: default: 32768 minimum: 301
Nov 03 17:16:43 bela kernel: Security Framework initialized
Nov 03 17:16:43 bela kernel: Yama: becoming mindful.
Nov 03 17:16:43 bela kernel: AppArmor: AppArmor disabled by boot time parameter
Nov 03 17:16:43 bela kernel: Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
Nov 03 17:16:43 bela kernel: Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys io
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys memory
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys devices
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys freezer
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys net_cls
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys perf_event
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys net_prio
Nov 03 17:16:43 bela kernel: Initializing cgroup subsys pids
Nov 03 17:16:43 bela kernel: CPU: Testing write buffer coherency: ok
Nov 03 17:16:43 bela kernel: Setting up static identity map for 0x80008200 - 0x80008260
Nov 03 17:16:43 bela kernel: devtmpfs: initialized
Nov 03 17:16:43 bela kernel: VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3
Nov 03 17:16:43 bela kernel: omap_hwmod: debugss: _wait_target_disable failed
Nov 03 17:16:43 bela kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Nov 03 17:16:43 bela kernel: futex hash table entries: 256 (order: -1, 3072 bytes)
Nov 03 17:16:43 bela kernel: xor: measuring software checksum speed
Nov 03 17:16:43 bela kernel:    arm4regs  :  1148.000 MB/sec
Nov 03 17:16:43 bela kernel:    8regs     :   912.000 MB/sec
Nov 03 17:16:43 bela kernel:    32regs    :  1032.000 MB/sec
Nov 03 17:16:43 bela kernel:    neon      :  1365.000 MB/sec
Nov 03 17:16:43 bela kernel: xor: using function: neon (1365.000 MB/sec)
Nov 03 17:16:43 bela kernel: pinctrl core: initialized pinctrl subsystem
Nov 03 17:16:43 bela kernel: NET: Registered protocol family 16
Nov 03 17:16:43 bela kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations
Nov 03 17:16:43 bela kernel: OMAP GPIO hardware version 0.1
Nov 03 17:16:43 bela kernel: No ATAGs?
Nov 03 17:16:43 bela kernel: hw-breakpoint: debug architecture 0x4 unsupported.
Nov 03 17:16:43 bela kernel: raid6: neonx2   gen()  1850 MB/s
Nov 03 17:16:43 bela kernel: raid6: neonx2   xor()  1138 MB/s
Nov 03 17:16:43 bela kernel: raid6: using algorithm neonx2 gen() 1850 MB/s
Nov 03 17:16:43 bela kernel: raid6: .... xor() 1138 MB/s, rmw enabled
Nov 03 17:16:43 bela kernel: raid6: using intx1 recovery algorithm
Nov 03 17:16:43 bela kernel: edma 49000000.edma: TI EDMA DMA engine driver
Nov 03 17:16:43 bela kernel: SCSI subsystem initialized
Nov 03 17:16:43 bela kernel: libata version 3.00 loaded.
Nov 03 17:16:43 bela kernel: usbcore: registered new interface driver usbfs
Nov 03 17:16:43 bela kernel: usbcore: registered new interface driver hub
Nov 03 17:16:43 bela kernel: usbcore: registered new device driver usb
Nov 03 17:16:43 bela kernel: omap_i2c 44e0b000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c0_pins, deferring probe
Nov 03 17:16:43 bela kernel: omap_i2c 4802a000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c1_pins, deferring probe
Nov 03 17:16:43 bela kernel: omap_i2c 4819c000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c2_pins, deferring probe
Nov 03 17:16:43 bela kernel: media: Linux media interface: v0.10
Nov 03 17:16:43 bela kernel: Linux video capture interface: v2.00
Nov 03 17:16:43 bela kernel: pps_core: LinuxPPS API ver. 1 registered
Nov 03 17:16:43 bela kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
Nov 03 17:16:43 bela kernel: PTP clock support registered
Nov 03 17:16:43 bela kernel: omap-mailbox 480c8000.mailbox: omap mailbox rev 0x400
Nov 03 17:16:43 bela kernel: NetLabel: Initializing
Nov 03 17:16:43 bela kernel: NetLabel:  domain hash size = 128
Nov 03 17:16:43 bela kernel: NetLabel:  protocols = UNLABELED CIPSOv4
Nov 03 17:16:43 bela kernel: NetLabel:  unlabeled traffic allowed by default
Nov 03 17:16:43 bela kernel: clocksource: Switched to clocksource ipipe_tsc
Nov 03 17:16:43 bela kernel: NET: Registered protocol family 2
Nov 03 17:16:43 bela kernel: TCP established hash table entries: 4096 (order: 2, 16384 bytes)
Nov 03 17:16:43 bela kernel: TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
Nov 03 17:16:43 bela kernel: TCP: Hash tables configured (established 4096 bind 4096)
Nov 03 17:16:43 bela kernel: UDP hash table entries: 256 (order: 0, 4096 bytes)
Nov 03 17:16:43 bela kernel: UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Nov 03 17:16:43 bela kernel: NET: Registered protocol family 1
Nov 03 17:16:43 bela kernel: RPC: Registered named UNIX socket transport module.
Nov 03 17:16:43 bela kernel: RPC: Registered udp transport module.
Nov 03 17:16:43 bela kernel: RPC: Registered tcp transport module.
Nov 03 17:16:43 bela kernel: RPC: Registered tcp NFSv4.1 backchannel transport module.
Nov 03 17:16:43 bela kernel: hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available
Nov 03 17:16:43 bela kernel: audit: initializing netlink subsys (disabled)
Nov 03 17:16:43 bela kernel: audit: type=2000 audit(0.696:1): initialized
Nov 03 17:16:43 bela kernel: [Xenomai] scheduling class idle registered.
Nov 03 17:16:43 bela kernel: [Xenomai] scheduling class rt registered.
Nov 03 17:16:43 bela kernel: I-pipe: head domain Xenomai registered.
Nov 03 17:16:43 bela kernel: [Xenomai] Cobalt v3.0.6 (Stellar Parallax) [DEBUG]
Nov 03 17:16:43 bela kernel: zbud: loaded
Nov 03 17:16:43 bela kernel: VFS: Disk quotas dquot_6.6.0
Nov 03 17:16:43 bela kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Nov 03 17:16:43 bela kernel: NFS: Registering the id_resolver key type
Nov 03 17:16:43 bela kernel: Key type id_resolver registered
Nov 03 17:16:43 bela kernel: Key type id_legacy registered
Nov 03 17:16:43 bela kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering...
Nov 03 17:16:43 bela kernel: fuse init (API version 7.23)
Nov 03 17:16:43 bela kernel: SGI XFS with ACLs, security attributes, realtime, no debug enabled
Nov 03 17:16:43 bela kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
Nov 03 17:16:43 bela kernel: io scheduler noop registered
Nov 03 17:16:43 bela kernel: io scheduler deadline registered
Nov 03 17:16:43 bela kernel: io scheduler cfq registered (default)
Nov 03 17:16:43 bela kernel: pinctrl-single 44e10800.pinmux: 142 pins at pa f9e10800 size 568
Nov 03 17:16:43 bela kernel: wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
Nov 03 17:16:43 bela kernel: Serial: 8250/16550 driver, 6 ports, IRQ sharing disabled
Nov 03 17:16:43 bela kernel: console [ttyS0] disabled
Nov 03 17:16:43 bela kernel: 44e09000.serial: ttyS0 at MMIO 0x44e09000 (irq = 158, base_baud = 3000000) is a 8250
Nov 03 17:16:43 bela kernel: console [ttyS0] enabled
Nov 03 17:16:43 bela kernel: [drm] Initialized drm 1.1.0 20060810
Nov 03 17:16:43 bela kernel: davinci_mdio 4a101000.mdio: davinci mdio revision 1.6
Nov 03 17:16:43 bela kernel: davinci_mdio 4a101000.mdio: detected phy mask fffffffe
Nov 03 17:16:43 bela kernel: davinci_mdio: dt: updated phy_id[0] from phy_mask[fffffffe]
Nov 03 17:16:43 bela kernel: libphy: 4a101000.mdio: probed
Nov 03 17:16:43 bela kernel: davinci_mdio 4a101000.mdio: phy[0]: device 4a101000.mdio:00, driver SMSC LAN8710/LAN8720
Nov 03 17:16:43 bela kernel: cpsw 4a100000.ethernet: Detected MACID = e8:eb:11:88:57:f7
Nov 03 17:16:43 bela kernel: cpsw 4a100000.ethernet: cpts: overflow check period 2125
Nov 03 17:16:43 bela kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Nov 03 17:16:43 bela kernel: ehci-platform: EHCI generic platform driver
Nov 03 17:16:43 bela kernel: ehci-omap: OMAP-EHCI Host Controller driver
Nov 03 17:16:43 bela kernel: usbcore: registered new interface driver usb-storage
Nov 03 17:16:43 bela kernel: 47401300.usb-phy supply vcc not found, using dummy regulator
Nov 03 17:16:43 bela kernel: musb-hdrc: ConfigData=0xde (UTMI-8, dyn FIFOs, bulk combine, bulk split, HB-ISO Rx, HB-ISO Tx, SoftConn)
Nov 03 17:16:43 bela kernel: musb-hdrc: MHDRC RTL version 2.0
Nov 03 17:16:43 bela kernel: musb-hdrc: setup fifo_mode 4
Nov 03 17:16:43 bela kernel: musb-hdrc: 28/31 max ep, 16384/16384 memory
Nov 03 17:16:43 bela kernel: 47401b00.usb-phy supply vcc not found, using dummy regulator
Nov 03 17:16:43 bela kernel: musb-hdrc: ConfigData=0xde (UTMI-8, dyn FIFOs, bulk combine, bulk split, HB-ISO Rx, HB-ISO Tx, SoftConn)
Nov 03 17:16:43 bela kernel: musb-hdrc: MHDRC RTL version 2.0
Nov 03 17:16:43 bela kernel: musb-hdrc: setup fifo_mode 4
Nov 03 17:16:43 bela kernel: musb-hdrc: 28/31 max ep, 16384/16384 memory
Nov 03 17:16:43 bela kernel: musb-hdrc musb-hdrc.1.auto: MUSB HDRC host driver
Nov 03 17:16:43 bela kernel: musb-hdrc musb-hdrc.1.auto: new USB bus registered, assigned bus number 1
Nov 03 17:16:43 bela kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Nov 03 17:16:43 bela kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Nov 03 17:16:43 bela kernel: usb usb1: Product: MUSB HDRC host driver
Nov 03 17:16:43 bela kernel: usb usb1: Manufacturer: Linux 4.4.113-ti-xenomai-r148 musb-hcd
Nov 03 17:16:43 bela kernel: usb usb1: SerialNumber: musb-hdrc.1.auto
Nov 03 17:16:43 bela kernel: hub 1-0:1.0: USB hub found
Nov 03 17:16:43 bela kernel: hub 1-0:1.0: 1 port detected
Nov 03 17:16:43 bela kernel: mousedev: PS/2 mouse device common for all mice
Nov 03 17:16:43 bela kernel: omap_rtc 44e3e000.rtc: rtc core: registered 44e3e000.rtc as rtc0
Nov 03 17:16:43 bela kernel: i2c /dev entries driver
Nov 03 17:16:43 bela kernel: omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec
Nov 03 17:16:43 bela kernel: omap_hsmmc 48060000.mmc: Got CD GPIO
Nov 03 17:16:43 bela kernel: hidraw: raw HID events driver (C) Jiri Kosina
Nov 03 17:16:43 bela kernel: usbcore: registered new interface driver usbhid
Nov 03 17:16:43 bela kernel: usbhid: USB HID core driver
Nov 03 17:16:43 bela kernel: ashmem: initialized
Nov 03 17:16:43 bela kernel:  remoteproc0: wkup_m3 is available
Nov 03 17:16:43 bela kernel:  remoteproc0: Note: remoteproc is still under development and considered experimental.
Nov 03 17:16:43 bela kernel:  remoteproc0: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
Nov 03 17:16:43 bela kernel: NET: Registered protocol family 10
Nov 03 17:16:43 bela kernel: mip6: Mobile IPv6
Nov 03 17:16:43 bela kernel: NET: Registered protocol family 17
Nov 03 17:16:43 bela kernel: Key type dns_resolver registered
Nov 03 17:16:43 bela kernel: mpls_gso: MPLS GSO support
Nov 03 17:16:43 bela kernel: omap_voltage_late_init: Voltage driver support not added
Nov 03 17:16:43 bela kernel: PM: Cannot get wkup_m3_ipc handle
Nov 03 17:16:43 bela kernel: ThumbEE CPU extension supported.
Nov 03 17:16:43 bela kernel: registered taskstats version 1
Nov 03 17:16:43 bela kernel: zswap: loaded using pool lzo/zbud
Nov 03 17:16:43 bela kernel: Btrfs loaded
Nov 03 17:16:43 bela kernel: Key type encrypted registered
Nov 03 17:16:43 bela kernel: mmc0: host does not support reading read-only switch, assuming write-enable
Nov 03 17:16:43 bela kernel: input: tps65217_pwr_but as /devices/platform/ocp/44e0b000.i2c/i2c-0/0-0024/input/input0
Nov 03 17:16:43 bela kernel: mmc0: new high speed SDHC card at address aaaa
Nov 03 17:16:43 bela kernel: mmcblk0: mmc0:aaaa SL16G 14.8 GiB
Nov 03 17:16:43 bela kernel:  mmcblk0: p1 p2
Nov 03 17:16:43 bela kernel: tps65217 0-0024: TPS65217 ID 0xe version 1.2
Nov 03 17:16:43 bela kernel: at24 0-0050: 32768 byte 24c256 EEPROM, writable, 1 bytes/write
Nov 03 17:16:43 bela kernel: omap_i2c 44e0b000.i2c: bus 0 rev0.11 at 400 kHz
Nov 03 17:16:43 bela kernel: omap_i2c 4802a000.i2c: bus 1 rev0.11 at 100 kHz
Nov 03 17:16:43 bela kernel: at24 2-0054: 32768 byte 24c256 EEPROM, writable, 1 bytes/write
Nov 03 17:16:43 bela kernel: at24 2-0055: 32768 byte 24c256 EEPROM, writable, 1 bytes/write
Nov 03 17:16:43 bela kernel: at24 2-0056: 32768 byte 24c256 EEPROM, writable, 1 bytes/write
Nov 03 17:16:43 bela kernel: at24 2-0057: 32768 byte 24c256 EEPROM, writable, 1 bytes/write
Nov 03 17:16:43 bela kernel: omap_i2c 4819c000.i2c: bus 2 rev0.11 at 100 kHz
Nov 03 17:16:43 bela kernel:  remoteproc0: powering up wkup_m3
Nov 03 17:16:43 bela kernel:  remoteproc0: Booting fw image am335x-pm-firmware.elf, size 217148
Nov 03 17:16:43 bela kernel:  remoteproc0: remote processor wkup_m3 is now up
Nov 03 17:16:43 bela kernel: wkup_m3_ipc 44e11324.wkup_m3_ipc: CM3 Firmware Version = 0x192
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: Baseboard: 'A335BNLT,00C0,2917BBBK32FB'
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: compatible-baseboard=ti,beaglebone-black - #slots=4
Nov 03 17:16:43 bela kernel: mmc1: MAN_BKOPS_EN bit is not set
Nov 03 17:16:43 bela kernel: mmc1: new high speed MMC card at address 0001
Nov 03 17:16:43 bela kernel: mmcblk1: mmc1:0001 M62704 3.56 GiB
Nov 03 17:16:43 bela kernel: mmcblk1boot0: mmc1:0001 M62704 partition 1 2.00 MiB
Nov 03 17:16:43 bela kernel: mmcblk1boot1: mmc1:0001 M62704 partition 2 2.00 MiB
Nov 03 17:16:43 bela kernel:  mmcblk1: p1 p2
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: slot #0: No cape found
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: slot #1: No cape found
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: slot #2: No cape found
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: slot #3: No cape found
Nov 03 17:16:43 bela kernel: bone_capemgr bone_capemgr: initialized OK.
Nov 03 17:16:43 bela kernel: PM: bootloader does not support rtc-only!
Nov 03 17:16:43 bela kernel: omap_rtc 44e3e000.rtc: setting system clock to 2000-01-01 00:00:00 UTC (946684800)
Nov 03 17:16:43 bela kernel: of_cfs_init
Nov 03 17:16:43 bela kernel: of_cfs_init: OK
Nov 03 17:16:43 bela kernel: PM: Hibernation image not present or could not be loaded.
Nov 03 17:16:43 bela kernel: EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
Nov 03 17:16:43 bela kernel: EXT4-fs (mmcblk0p2): write access will be enabled during recovery
Nov 03 17:16:43 bela kernel: EXT4-fs (mmcblk0p2): recovery complete
Nov 03 17:16:43 bela kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Nov 03 17:16:43 bela kernel: VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Nov 03 17:16:43 bela kernel: devtmpfs: mounted
Nov 03 17:16:43 bela kernel: Freeing unused kernel memory: 456K
Nov 03 17:16:43 bela systemd[1]: System time before build time, advancing clock.
Nov 03 17:16:43 bela kernel: random: systemd: uninitialized urandom read (16 bytes read, 28 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd: uninitialized urandom read (16 bytes read, 28 bits of entropy available)
Nov 03 17:16:43 bela systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
Nov 03 17:16:43 bela systemd[1]: Detected architecture arm.
Nov 03 17:16:43 bela systemd[1]: Set hostname to <bela>.
Nov 03 17:16:43 bela kernel: random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 30 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd-cryptse: uninitialized urandom read (16 bytes read, 30 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 32 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 32 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd: uninitialized urandom read (16 bytes read, 37 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd: uninitialized urandom read (16 bytes read, 37 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd: uninitialized urandom read (16 bytes read, 37 bits of entropy available)
Nov 03 17:16:43 bela kernel: random: systemd: uninitialized urandom read (16 bytes read, 37 bits of entropy available)
Nov 03 17:16:43 bela systemd[1]: Listening on Syslog Socket.
Nov 03 17:16:43 bela systemd[1]: Created slice System Slice.
Nov 03 17:16:43 bela systemd[1]: Reached target Swap.
Nov 03 17:16:43 bela systemd[1]: Listening on udev Control Socket.
Nov 03 17:16:43 bela systemd[1]: Listening on udev Kernel Socket.
Nov 03 17:16:43 bela systemd[1]: Listening on fsck to fsckd communication Socket.
Nov 03 17:16:43 bela systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
Nov 03 17:16:43 bela systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
Nov 03 17:16:43 bela systemd[1]: Started Forward Password Requests to Wall Directory Watch.
Nov 03 17:16:43 bela systemd[1]: Reached target Paths.
Nov 03 17:16:43 bela systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
Nov 03 17:16:43 bela systemd[1]: Created slice system-systemd\x2dfsck.slice.
Nov 03 17:16:43 bela systemd[1]: Listening on Journal Socket.
Nov 03 17:16:43 bela systemd[1]: Starting Load Kernel Modules...
Nov 03 17:16:43 bela systemd[1]: Created slice User and Session Slice.
Nov 03 17:16:43 bela systemd[1]: Reached target Slices.
Nov 03 17:16:43 bela systemd[1]: Created slice system-getty.slice.
Nov 03 17:16:43 bela systemd[1]: Listening on Journal Audit Socket.
Nov 03 17:16:43 bela systemd[1]: Reached target Remote File Systems.
Nov 03 17:16:43 bela systemd[1]: Starting File System Check on Root Device...
Nov 03 17:16:43 bela systemd[1]: Listening on Journal Socket (/dev/log).
Nov 03 17:16:43 bela systemd[1]: Starting Create Static Device Nodes in /dev...
Nov 03 17:16:43 bela systemd[1]: Reached target Encrypted Volumes.
Nov 03 17:16:43 bela systemd[1]: Mounting Debug File System...
Nov 03 17:16:43 bela systemd[1]: Starting Journal Service...
Nov 03 17:16:43 bela systemd[1]: Mounting POSIX Message Queue File System...
Nov 03 17:16:43 bela systemd[1]: Created slice system-serial\x2dgetty.slice.
Nov 03 17:16:43 bela systemd[1]: Mounted Debug File System.
Nov 03 17:16:43 bela systemd[1]: Mounted POSIX Message Queue File System.
Nov 03 17:16:43 bela systemd[1]: systemd-modules-load.service: Main process exited, code=exited, status=1/FAILURE
Nov 03 17:16:43 bela systemd[1]: Failed to start Load Kernel Modules.
Nov 03 17:16:43 bela systemd[1]: systemd-modules-load.service: Unit entered failed state.
Nov 03 17:16:43 bela systemd[1]: systemd-modules-load.service: Failed with result 'exit-code'.
Nov 03 17:16:43 bela systemd[1]: Started File System Check on Root Device.
Nov 03 17:16:43 bela systemd[1]: Started Create Static Device Nodes in /dev.
Nov 03 17:16:43 bela systemd[1]: Started File System Check Daemon to report status.
Nov 03 17:16:43 bela systemd[1]: Starting udev Kernel Device Manager...
Nov 03 17:16:43 bela systemd[1]: Starting Remount Root and Kernel File Systems...
Nov 03 17:16:43 bela systemd[1]: Mounting Configuration File System...
Nov 03 17:16:43 bela systemd-journald[110]: Journal started
Nov 03 17:16:43 bela systemd-journald[110]: Runtime journal (/run/log/journal/b58703565c7d4fc39cbb9f10667f2b9a) is 3.0M, max 24.5M, 21.4M free.
Nov 03 17:16:43 bela systemd-modules-load[97]: could not open moddep file '/lib/modules/4.4.113-ti-xenomai-r148/modules.dep.bin'
Nov 03 17:16:43 bela systemd-modules-load[97]: Failed to lookup alias 'libcomposite': Function not implemented
Nov 03 17:16:43 bela systemd-modules-load[97]: could not open moddep file '/lib/modules/4.4.113-ti-xenomai-r148/modules.dep.bin'
Nov 03 17:16:44 bela systemd-fsck[101]: BELAROOTFS: clean, 92166/229376 files, 713568/916224 blocks
Nov 03 17:16:44 bela systemd[1]: Starting Apply Kernel Variables...
Nov 03 17:16:44 bela systemd-modules-load[97]: Failed to lookup alias 'rtdm_pruss_irq': Function not implemented
Nov 03 17:16:43 bela systemd-udevd[130]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Nov 03 17:16:44 bela kernel: EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Nov 03 17:16:44 bela systemd[1]: Mounting FUSE Control File System...
Nov 03 17:16:44 bela systemd-udevd[130]: specified group 'xenomai' unknown
Nov 03 17:16:44 bela systemd[1]: Mounted Configuration File System.
Nov 03 17:16:44 bela systemd[1]: Started Journal Service.
Nov 03 17:16:44 bela systemd[1]: Mounted FUSE Control File System.
Nov 03 17:16:44 bela systemd[1]: Started udev Kernel Device Manager.
Nov 03 17:16:44 bela systemd[1]: Started Remount Root and Kernel File Systems.
Nov 03 17:16:44 bela systemd[1]: Started Apply Kernel Variables.
Nov 03 17:16:44 bela systemd[1]: Reached target Local File Systems (Pre).
Nov 03 17:16:44 bela systemd[1]: Starting Load/Save Random Seed...
Nov 03 17:16:44 bela systemd[1]: Starting udev Coldplug all Devices...
Nov 03 17:16:44 bela systemd[1]: Starting Flush Journal to Persistent Storage...
Nov 03 17:16:44 bela systemd[1]: Started Load/Save Random Seed.
Nov 03 17:16:44 bela systemd-journald[110]: Runtime journal (/run/log/journal/b58703565c7d4fc39cbb9f10667f2b9a) is 3.0M, max 24.5M, 21.4M free.
Nov 03 17:16:44 bela systemd[1]: Started Flush Journal to Persistent Storage.
Nov 03 17:16:45 bela systemd[1]: Started udev Coldplug all Devices.
Nov 03 17:16:46 bela systemd[1]: Found device /dev/ttyS0.
Nov 03 17:16:47 bela systemd[1]: Found device /dev/mmcblk0p1.
Nov 03 17:16:47 bela systemd[1]: Starting File System Check on /dev/mmcblk0p1...
Nov 03 17:16:47 bela systemd-fsck[186]: fsck.fat 4.1 (2017-01-24)
Nov 03 17:16:47 bela systemd-fsck[186]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt.
Nov 03 17:16:47 bela systemd-fsck[186]:  Automatically removing dirty bit.
Nov 03 17:16:47 bela systemd-fsck[186]: Performing changes.
Nov 03 17:16:47 bela systemd-fsck[186]: /dev/mmcblk0p1: 124 files, 2646/34412 clusters
Nov 03 17:16:47 bela systemd[1]: Started File System Check on /dev/mmcblk0p1.
Nov 03 17:16:47 bela systemd[1]: Mounting /mnt/boot...
Nov 03 17:16:47 bela systemd[1]: Mounted /mnt/boot.
Nov 03 17:16:47 bela systemd[1]: Reached target Local File Systems.
Nov 03 17:16:47 bela systemd[1]: Starting Create Volatile Files and Directories...
Nov 03 17:16:47 bela systemd[1]: Started Create Volatile Files and Directories.
Nov 03 17:16:47 bela systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Nov 03 17:16:48 bela systemd[1]: Starting Network Time Synchronization...
Nov 03 17:16:48 bela systemd[1]: Started Update UTMP about System Boot/Shutdown.
Nov 03 17:16:48 bela systemd[1]: Started Network Time Synchronization.
Nov 03 17:16:48 bela systemd[1]: Reached target System Initialization.
Nov 03 17:16:48 bela systemd[1]: Started Daily Cleanup of Temporary Directories.
Nov 03 17:16:48 bela systemd[1]: Listening on D-Bus System Message Bus Socket.
Nov 03 17:16:48 bela systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Nov 03 17:16:48 bela systemd[1]: Reached target Sockets.
Nov 03 17:16:48 bela systemd[1]: Reached target Basic System.
Nov 03 17:16:48 bela systemd[1]: Started Regular background program processing daemon.
Nov 03 17:16:48 bela systemd[1]: Started Monitor the Bela cape button.
Nov 03 17:16:48 bela cron[209]: (CRON) INFO (pidfile fd = 3)
Nov 03 17:16:48 bela cron[209]: (CRON) INFO (Running @reboot jobs)
Nov 03 17:16:48 bela stdbuf[212]: Sleeping 20 seconds before polling
Nov 03 17:16:48 bela systemd[1]: Starting Login Service...
Nov 03 17:16:48 bela systemd[1]: Starting System Logging Service...
Nov 03 17:16:49 bela systemd[1]: Started D-Bus System Message Bus.
Nov 03 17:16:49 bela liblogging-stdlog[218]:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="218" x-info="http://www.rsyslog.com"] start
Nov 03 17:16:49 bela systemd[1]: Starting Configure Bela as a composite USB device...
Nov 03 17:16:49 bela systemd[1]: Started Bela IDE Launcher.
Nov 03 17:16:49 bela systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Nov 03 17:16:49 bela systemd[1]: Reached target System Time Synchronized.
Nov 03 17:16:49 bela systemd[1]: apt-daily.timer: Adding 5h 17min 15.140088s random time.
Nov 03 17:16:49 bela systemd[1]: Started Daily apt download activities.
Nov 03 17:16:49 bela systemd[1]: apt-daily-upgrade.timer: Adding 55.725220s random time.
Nov 03 17:16:49 bela systemd[1]: Started Daily apt upgrade and clean activities.
Nov 03 17:16:49 bela bash[230]: /opt/Bela/bela_gadget.sh: line 5: cd: /sys/kernel/config/usb_gadget/: No such file or directory
Nov 03 17:16:49 bela systemd[1]: Reached target Timers.
Nov 03 17:16:49 bela systemd[1]: Started System Logging Service.
Nov 03 17:16:49 bela systemd[1]: bela_gadget.service: Main process exited, code=exited, status=1/FAILURE
Nov 03 17:16:49 bela systemd[1]: Failed to start Configure Bela as a composite USB device.
Nov 03 17:16:49 bela systemd[1]: bela_gadget.service: Unit entered failed state.
Nov 03 17:16:49 bela systemd[1]: bela_gadget.service: Failed with result 'exit-code'.
Nov 03 17:16:49 bela avahi-daemon[237]: Found user 'avahi' (UID 107) and group 'avahi' (GID 112).
Nov 03 17:16:49 bela avahi-daemon[237]: Successfully dropped root privileges.
Nov 03 17:16:49 bela avahi-daemon[237]: avahi-daemon 0.6.32 starting up.
Nov 03 17:16:49 bela avahi-daemon[237]: Successfully called chroot().
Nov 03 17:16:49 bela avahi-daemon[237]: Successfully dropped remaining capabilities.
Nov 03 17:16:49 bela avahi-daemon[237]: No service file found in /etc/avahi/services.
Nov 03 17:16:49 bela avahi-daemon[237]: Network interface enumeration completed.
Nov 03 17:16:49 bela avahi-daemon[237]: Server startup complete. Host name is bela.local. Local service cookie is 4002834133.
Nov 03 17:16:49 bela systemd-logind[215]: New seat seat0.
Nov 03 17:16:49 bela systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Nov 03 17:16:50 bela systemd[1]: Started Login Service.
Nov 03 17:16:50 bela systemd[1]: Reached target Network (Pre).
Nov 03 17:16:50 bela systemd[1]: Starting Raise network interfaces...
Nov 03 17:16:50 bela kernel: random: nonblocking pool is initialized
Nov 03 17:16:51 bela ifup[255]: Cannot find device "usb0"
Nov 03 17:16:51 bela ifup[255]: ifup: failed to bring up usb0
Nov 03 17:16:51 bela kernel: net eth0: initializing cpsw version 1.12 (0)
Nov 03 17:16:51 bela kernel: net eth0: initialized cpsw ale version 1.4
Nov 03 17:16:51 bela kernel: net eth0: ALE Table size 1024
Nov 03 17:16:51 bela kernel: net eth0: phy found : id is : 0x7c0f1
Nov 03 17:16:51 bela avahi-daemon[237]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.30.100.
Nov 03 17:16:52 bela kernel: IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Nov 03 17:16:52 bela avahi-daemon[237]: New relevant interface eth0.IPv4 for mDNS.
Nov 03 17:16:52 bela avahi-daemon[237]: Registering new address record for 192.168.30.100 on eth0.IPv4.
Nov 03 17:16:52 bela systemd[1]: networking.service: Main process exited, code=exited, status=1/FAILURE
Nov 03 17:16:52 bela systemd[1]: Failed to start Raise network interfaces.
Nov 03 17:16:52 bela systemd[1]: networking.service: Unit entered failed state.
Nov 03 17:16:52 bela systemd[1]: networking.service: Failed with result 'exit-code'.
Nov 03 17:16:52 bela systemd[1]: Reached target Network.
Nov 03 17:16:52 bela systemd[1]: Starting OpenBSD Secure Shell server...
Nov 03 17:16:52 bela systemd[1]: Starting Kill Bela programme at shutdown if running...
Nov 03 17:16:52 bela systemd[1]: Starting Kill dhclient to prevent ifup eth0 blocking shutdown...
Nov 03 17:16:53 bela systemd[1]: Starting Kill ssh sessions before network...
Nov 03 17:16:53 bela systemd[1]: Starting Permit User Sessions...
Nov 03 17:16:53 bela systemd[1]: Reached target Network is Online.
Nov 03 17:16:53 bela systemd[1]: Starting LSB: Advanced IEEE 802.11 management daemon...
Nov 03 17:16:53 bela systemd[1]: Starting LSB: simple distributed compiler server...
Nov 03 17:16:53 bela systemd[1]: Starting LSB: DHCP server...
Nov 03 17:16:53 bela systemd[1]: Started Kill Bela programme at shutdown if running.
Nov 03 17:16:53 bela systemd[1]: Started Kill dhclient to prevent ifup eth0 blocking shutdown.
Nov 03 17:16:53 bela systemd[1]: Started Kill ssh sessions before network.
Nov 03 17:16:53 bela systemd[1]: Started Permit User Sessions.
Nov 03 17:16:53 bela systemd[1]: Started LSB: Advanced IEEE 802.11 management daemon.
Nov 03 17:16:54 bela sshd[386]: Server listening on 0.0.0.0 port 22.
Nov 03 17:16:54 bela sshd[386]: Server listening on :: port 22.
Nov 03 17:16:54 bela systemd[1]: Started OpenBSD Secure Shell server.
Nov 03 17:16:54 bela distcc[372]: STARTDISTCC is set to false in /etc/default/distcc ... (warning).
Nov 03 17:16:54 bela distcc[372]: /usr/bin/distccd not starting ... (warning).
Nov 03 17:16:54 bela systemd[1]: Started Getty on tty1.
Nov 03 17:16:54 bela systemd[1]: Started Serial Getty on ttyS0.
Nov 03 17:16:54 bela isc-dhcp-server[377]: Launching IPv4 server only.
Nov 03 17:16:54 bela systemd[1]: Started LSB: simple distributed compiler server.
Nov 03 17:16:54 bela dhcpd[402]: Wrote 0 leases to leases file.
Nov 03 17:16:54 bela dhcpd[402]:
Nov 03 17:16:54 bela dhcpd[402]: No subnet declaration for usb0 (no IPv4 addresses).
Nov 03 17:16:54 bela dhcpd[402]: ** Ignoring requests on usb0.  If this is not what
Nov 03 17:16:54 bela dhcpd[402]:    you want, please write a subnet declaration
Nov 03 17:16:54 bela dhcpd[402]:    in your dhcpd.conf file for the network segment
Nov 03 17:16:54 bela dhcpd[402]:    to which interface usb0 is attached. **
Nov 03 17:16:54 bela dhcpd[402]:
Nov 03 17:16:54 bela dhcpd[402]:
Nov 03 17:16:54 bela dhcpd[402]: Not configured to listen on any interfaces!
Nov 03 17:16:54 bela dhcpd[402]:
Nov 03 17:16:54 bela dhcpd[402]: If you think you have received this message due to a bug rather
Nov 03 17:16:54 bela dhcpd[402]: than a configuration issue please read the section on submitting
Nov 03 17:16:54 bela dhcpd[402]: bugs on either our web page at www.isc.org or in the README file
Nov 03 17:16:54 bela dhcpd[402]: before submitting a bug.  These pages explain the proper
Nov 03 17:16:54 bela dhcpd[402]: process and the information we find helpful for debugging..
Nov 03 17:16:54 bela dhcpd[402]:
Nov 03 17:16:54 bela dhcpd[402]: exiting.
Nov 03 17:16:56 bela isc-dhcp-server[377]: Starting ISC DHCPv4 server: dhcpdcheck syslog for diagnostics. ... failed!
Nov 03 17:16:57 bela isc-dhcp-server[377]:  failed!
Nov 03 17:16:57 bela systemd[1]: isc-dhcp-server.service: Control process exited, code=exited status=1
Nov 03 17:16:57 bela systemd[1]: Failed to start LSB: DHCP server.
Nov 03 17:16:57 bela systemd[1]: isc-dhcp-server.service: Unit entered failed state.
Nov 03 17:16:57 bela systemd[1]: isc-dhcp-server.service: Failed with result 'exit-code'.
Nov 03 17:17:01 bela CRON[413]: pam_unix(cron:account): account root has password changed in future
Nov 03 17:17:01 bela CRON[413]: pam_unix(cron:session): session opened for user root by (uid=0)
Nov 03 17:17:01 bela CRON[414]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Nov 03 17:17:01 bela CRON[413]: pam_unix(cron:session): session closed for user root
Nov 03 17:17:02 bela node[234]: starting IDE
Nov 03 17:17:03 bela node[234]: setting pwd timeout
Nov 03 17:17:03 bela node[234]: listening on port 80
Nov 03 17:17:08 bela stdbuf[212]: Monitoring pin `115`, will execute `(nothing)` on click and `/opt/Bela/bela_button_hold.sh` on hold. Button is pressed when pin is LOW...
Nov 03 17:18:10 bela login[396]: pam_unix(login:account): account root has password changed in future
Nov 03 17:18:10 bela login[396]: pam_unix(login:session): session opened for user root by LOGIN(uid=0)
Nov 03 17:18:10 bela login[427]: ROOT LOGIN  on '/dev/ttyS0'
Nov 03 17:18:12 bela systemd[1]: dev-ttyGS0.device: Job dev-ttyGS0.device/start timed out.
Nov 03 17:18:12 bela systemd[1]: Timed out waiting for device dev-ttyGS0.device.
Nov 03 17:18:12 bela systemd[1]: Dependency failed for Serial Getty on ttyGS0.
Nov 03 17:18:12 bela systemd[1]: serial-getty@ttyGS0.service: Job serial-getty@ttyGS0.service/start failed with result 'dependency'.
Nov 03 17:18:12 bela systemd[1]: dev-ttyGS0.device: Job dev-ttyGS0.device/start failed with result 'timeout'.
Nov 03 17:18:12 bela systemd[1]: Reached target Login Prompts.
Nov 03 17:18:12 bela systemd[1]: Reached target Multi-User System.
Nov 03 17:18:12 bela systemd[1]: Reached target Graphical Interface.
Nov 03 17:18:12 bela systemd[1]: Starting Update UTMP about System Runlevel Changes...
Nov 03 17:18:13 bela systemd[1]: Started Update UTMP about System Runlevel Changes.
Nov 03 17:18:13 bela systemd[1]: Startup finished in 1.637s (kernel) + 1min 31.104s (userspace) = 1min 32.742s.

first error in the serial log is [FAILED] Failed to start Load Kernel Modules.. I think the corresponding one in journalctl is

Nov 03 17:16:43 bela systemd[1]: Mounted POSIX Message Queue File System.
Nov 03 17:16:43 bela systemd[1]: systemd-modules-load.service: Main process exited, code=exited, status=1/FAILURE
Nov 03 17:16:43 bela systemd[1]: Failed to start Load Kernel Modules.
Nov 03 17:16:43 bela systemd[1]: systemd-modules-load.service: Unit entered failed state.
Nov 03 17:16:43 bela systemd[1]: systemd-modules-load.service: Failed with result 'exit-code'.

Then after that fails, the usb_gadget cannot be created and usb0 does not exist and cannot be brought up.

systemctl status systemd-modules-load.service gives:

● systemd-modules-load.service - Load Kernel Modules
   Loaded: loaded (/lib/systemd/system/systemd-modules-load.service; static; vendor preset: enabled)
   Active: failed (Result: exit-code) since Thu 2016-11-03 17:16:43 UTC; 53s ago
     Docs: man:systemd-modules-load.service(8)
           man:modules-load.d(5)
  Process: 101 ExecStart=/lib/systemd/systemd-modules-load (code=exited, status=1/FAILURE)
 Main PID: 101 (code=exited, status=1/FAILURE)

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.

I assumed it was my newly compiled rtdm_pruss_irq.ko module that was causing problems, so I removed it from /etc/modules but still no luck.

Turns out that the sudden shutdown just after the build had left multiple empty files in /lib/modules/$(uname -r), so it was failing in loading modules.dep.bin. Solution was to recompile and install a module, so that it fixed all those empty files.

Also, this outlined that if there is no /sys/kernel/config/usb_gadget/, that is if libcomposite has failed loading, then the folder structure for usb_gadget was created in / (fixed in https://github.com/BelaPlatform/bela-image-builder/commit/d3c527cf4188ff987d7e1e91b477f28b61ea4d2f).

However, this creates the interesting problem that one may end up with soft-bricked board (if they have no UART at hand, that is) if there are corrupted files in /lib/modules/$(uname -r). It would be interesting investigating if there is a way of cleaning those from /opt/Bela/bela_gadget.sh and unbrick the board. Or maybe try to force load libcomposite with insmod and warn the user of the failure?

giuliomoro commented 6 years ago

while the above got me to be able to load the libcomposite module, rtdm_pruss_irq would still fail loading with "invalid parameter" or "not found".

I tried resetting the whole content of /lib/modules/ as it was on the original SD card and that allowed me to load the module.

Then when I went back to /opt/rtdm_pruss_irq and ran make I would get some error saying to redo make oldconfig && make prepare in the kernel source, which failed

I then reverted the whole /usr/src/linux-headers-4.4.113-ti-xenomai-r148 to what it was from a fresh image and that finally worked.

LBDonovan commented 6 years ago

I think the key error is

Nov 03 17:16:43 bela systemd-modules-load[97]: could not open moddep file '/lib/modules/4.4.113-ti-xenomai-r148/modules.dep.bin'

I think if you have corrupted your kernel module dependencies you're pretty screwed really, and lucky the thing booted at all.

I guess we could try compiling those modules directly into the kernel? Seems like a rare kind of error though, and likely not worth the hassle (especially for rtdm_pruss_irq)

giuliomoro commented 6 years ago

I'd rather not have rtdm_pruss_irq into the kernel, because we may want to leave a way for us to update it. Though it may just be easier to reship the full kernel .deb file? We should also have one of those hooks that recompile the modules after updating the kernel. I remember seeing it somewhere.