Was working for months. Changed nothing, now won't boot

This forum is for Marvell Kirkwood devices such as the GoFlex Home/Net, PogoPlug v1/v2, SheevaPlug, and ZyXEL devices.

Was working for months. Changed nothing, now won't boot

Postby tjtv » Mon May 27, 2013 2:28 pm

I had my E02 working for months. Basically just using it as a samba server. Something was wrong with my samba share, so I pulled the power cord to reboot the E02. Now it won't come back up. I didn't change anything, so I have no idea why it won't boot anymore.

I've attached the netconsole output. Can anyone help with debug?

$this->bbcode_second_pass_code('', '
U-Boot 2011.12 (Feb 20 2012 - 21:21:59)
Pogoplug E02
GNU ld (Sourcery G++ Lite 2009q3-67) 2.19.51.20090709
Hit any key to stop autoboot: 0
(Re)start USB...
USB: Register 10011 NbrPorts 1
USB EHCI 1.00
scanning bus for devices... 3 USB Device(s) found
scanning bus for storage devices... 1 Storage Device(s) found
Loading file "/rescueme" from usb device 0:1 (usbda1)
** File not found /rescueme
reading /rescueme.txt

** Unable to read "/rescueme.txt" from usb 0:1 **
Creating 1 MTD partitions on "nand0":
0x000002500000-0x000008000000 : "mtd=3"
UBI: attaching mtd1 to ubi0
UBI: physical eraseblock size: 131072 bytes (128 KiB)
UBI: logical eraseblock size: 129024 bytes
UBI: smallest flash I/O unit: 2048
UBI: sub-page size: 512
UBI: VID header offset: 512 (aligned 512)
UBI: data offset: 2048
UBI: attached mtd1 to ubi0
UBI: MTD device name: "mtd=3"
UBI: MTD device size: 91 MiB
UBI: number of good PEBs: 728
UBI: number of bad PEBs: 0
UBI: max. allowed volumes: 128
UBI: wear-leveling threshold: 4096
UBI: number of internal volumes: 1
UBI: number of user volumes: 0
UBI: available PEBs: 717
UBI: total number of reserved PEBs: 11
UBI: number of PEBs reserved for bad PEB handling: 7
UBI: max/mean erase counter: 1/1
UBIFS error (pid 0): ubifs_get_sb: cannot open "ubi:rootfs", error -19
Error reading superblock on volume 'ubi:rootfs'!
Loading file "/boot/uImage" from usb device 0:1 (usbda1)
1 bytes read
Found bootable drive on usb 0:1
Loading file "/boot/uImage" from usb device 0:1 (usbda1)
2869736 bytes read
Loading file "/boot/uInitrd" from usb device 0:1 (usbda1)
** File not found /boot/uInitrd
## Booting kernel from Legacy Image at 00800000 ...
Image Name: Linux-3.1.10-16-ARCH
Image Type: ARM Linux Kernel Image (uncompressed)
Data Size: 2869672 Bytes = 2.7 MiB
Load Address: 00008000
Entry Point: 00008000
Verifying Checksum ... OK
Loading Kernel Image ... OK
OK

Starting kernel ...
')
tjtv
 
Posts: 8
Joined: Thu Feb 21, 2013 5:53 am

Re: Was working for months. Changed nothing, now won't boot

Postby moonman » Tue May 28, 2013 4:44 am

That's a U-Boot netconsole and it looks good. How about kernel log?

Also try to e2fsck the driver on a different linux box
Pogoplug V4 | GoFlex Home | Raspberry Pi 4 4GB | CuBox-i4 Pro | ClearFog | BeagleBone Black | Odroid U2 | Odroid C1 | Odroid XU4
-----------------------------------------------------------------------------------------------------------------------
[armv5] Updated U-Boot | [armv5] NAND Rescue System
moonman
Developer
 
Posts: 3388
Joined: Sat Jan 15, 2011 3:36 am

Re: Was working for months. Changed nothing, now won't boot

Postby tjtv » Tue May 28, 2013 5:10 pm

So, this is normal then?

$this->bbcode_second_pass_code('', 'UBIFS error (pid 0): ubifs_get_sb: cannot open "ubi:rootfs", error -19
Error reading superblock on volume 'ubi:rootfs'!')

I can't get to the kernel log becuase the system doesn't come up, and I can't ssh into it. I suppose I could pull the thumb drive and inspect it on another linux box. Can you tell me the location of the kernel log file I should be looking for?
tjtv
 
Posts: 8
Joined: Thu Feb 21, 2013 5:53 am

Re: Was working for months. Changed nothing, now won't boot

Postby moonman » Tue May 28, 2013 9:00 pm

Yeah, that's fine. The location of logs if /var/log
Pogoplug V4 | GoFlex Home | Raspberry Pi 4 4GB | CuBox-i4 Pro | ClearFog | BeagleBone Black | Odroid U2 | Odroid C1 | Odroid XU4
-----------------------------------------------------------------------------------------------------------------------
[armv5] Updated U-Boot | [armv5] NAND Rescue System
moonman
Developer
 
Posts: 3388
Joined: Sat Jan 15, 2011 3:36 am

Re: Was working for months. Changed nothing, now won't boot

Postby tjtv » Wed May 29, 2013 3:43 am

Ok, not sure which log is most important, so I'll post a bunch of them. Prior to this bootup attempt I mounted the usb stick on another linux box and moved var/log to var/log_old and created a new var/log directory so that I know all logs are from the new bootup attempt.

What's strange is that all log files have a timestamp of Dec 31, 1969. Also, in the errors.log there is a note about the RTC not ticking, not sure if that is normal or not.

syslog.log
$this->bbcode_second_pass_code('', 'Dec 31 19:00:17 alsmb syslog-ng[117]: syslog-ng starting up; version='3.4.1'')

kernel.log
$this->bbcode_second_pass_code('', 'Dec 31 19:00:17 alsmb kernel: [ 0.000000] Initializing cgroup subsys cpuset
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Initializing cgroup subsys cpu
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Linux version 3.1.10-16-ARCH (nobody@panda2) (gcc version 4.7.2 (GCC) ) #1 PREEMPT Tue Feb 12 01:17:10 UTC 2013
Dec 31 19:00:17 alsmb kernel: [ 0.000000] CPU: Feroceon 88FR131 [56251311] revision 1 (ARMv5TE), cr=00053977
Dec 31 19:00:17 alsmb kernel: [ 0.000000] CPU: VIVT data cache, VIVT instruction cache
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Machine: Marvell SheevaPlug Reference Board
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Memory policy: ECC disabled, Data cache writeback
Dec 31 19:00:17 alsmb kernel: [ 0.000000] On node 0 totalpages: 65536
Dec 31 19:00:17 alsmb kernel: [ 0.000000] free_area_init_node: node 0, pgdat c0590af8, node_mem_map c0661000
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Normal zone: 512 pages used for memmap
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Normal zone: 0 pages reserved
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Normal zone: 65024 pages, LIFO batch:15
Dec 31 19:00:17 alsmb kernel: [ 0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Dec 31 19:00:17 alsmb kernel: [ 0.000000] pcpu-alloc: [0] 0
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 65024
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Kernel command line: console=ttyS0,115200 root=/dev/sda1 rootdelay=10 rootfstype=ext2 mtdparts=orion_nand:1M(u-b
oot),4M(uImage),32M(rootfs),-(data)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] allocated 1048576 bytes of page_cgroup
Dec 31 19:00:17 alsmb kernel: [ 0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Memory: 256MB = 256MB total
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Memory: 252304k/252304k available, 9840k reserved, 0K highmem
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Virtual kernel memory layout:
Dec 31 19:00:17 alsmb kernel: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] DMA : 0xffc00000 - 0xffe00000 ( 2 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] vmalloc : 0xd0800000 - 0xfe800000 ( 736 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] lowmem : 0xc0000000 - 0xd0000000 ( 256 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .text : 0xc0008000 - 0xc052ede4 (5276 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .init : 0xc052f000 - 0xc055a000 ( 172 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .data : 0xc055a000 - 0xc05932f0 ( 229 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .bss : 0xc0593314 - 0xc0660e8c ( 823 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Preemptible hierarchical RCU implementation.
Dec 31 19:00:17 alsmb kernel: [ 0.000000] NR_IRQS:114
Dec 31 19:00:17 alsmb kernel: [ 0.000000] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 21474ms
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Console: colour dummy device 80x30
Dec 31 19:00:17 alsmb kernel: [ 14.712760] Calibrating delay loop... 1191.11 BogoMIPS (lpj=5955584)
Dec 31 19:00:17 alsmb kernel: [ 14.802690] pid_max: default: 32768 minimum: 301
Dec 31 19:00:17 alsmb kernel: [ 14.802815] Security Framework initialized
Dec 31 19:00:17 alsmb kernel: [ 14.802838] AppArmor: AppArmor disabled by boot time parameter
Dec 31 19:00:17 alsmb kernel: [ 14.802904] Mount-cache hash table entries: 512
Dec 31 19:00:17 alsmb kernel: [ 14.803291] Initializing cgroup subsys cpuacct
Dec 31 19:00:17 alsmb kernel: [ 14.803319] Initializing cgroup subsys memory
Dec 31 19:00:17 alsmb kernel: [ 14.803355] Initializing cgroup subsys devices
Dec 31 19:00:17 alsmb kernel: [ 14.803368] Initializing cgroup subsys freezer
Dec 31 19:00:17 alsmb kernel: [ 14.803377] Initializing cgroup subsys net_cls
Dec 31 19:00:17 alsmb kernel: [ 14.803386] Initializing cgroup subsys blkio
Dec 31 19:00:17 alsmb kernel: [ 14.803410] Initializing cgroup subsys perf_event
Dec 31 19:00:17 alsmb kernel: [ 14.803428] Initializing cgroup subsys bfqio
Dec 31 19:00:17 alsmb kernel: [ 14.803521] CPU: Testing write buffer coherency: ok
Dec 31 19:00:17 alsmb kernel: [ 14.804807] devtmpfs: initialized
Dec 31 19:00:17 alsmb kernel: [ 14.806616] NET: Registered protocol family 16
Dec 31 19:00:17 alsmb kernel: [ 14.807275] Kirkwood: MV88F6281-A0, TCLK=200000000.
Dec 31 19:00:17 alsmb kernel: [ 14.807290] Feroceon L2: Enabling L2
Dec 31 19:00:17 alsmb kernel: [ 14.807327] Feroceon L2: Cache support initialised.
Dec 31 19:00:17 alsmb kernel: [ 14.807848] initial MPP regs: 01111111 11113322 00001111 00100000 00000000 00000000 00000000
Dec 31 19:00:17 alsmb kernel: [ 14.807877] final MPP regs: 01111111 11113322 00001111 00000000 00000000 00000000 00000000
Dec 31 19:00:17 alsmb kernel: [ 14.812959] bio: create slab <bio-0> at 0
Dec 31 19:00:17 alsmb kernel: [ 14.813326] vgaarb: loaded
Dec 31 19:00:17 alsmb kernel: [ 14.813587] SCSI subsystem initialized
Dec 31 19:00:17 alsmb kernel: [ 14.813754] libata version 3.00 loaded.
Dec 31 19:00:17 alsmb kernel: [ 14.813968] usbcore: registered new interface driver usbfs
Dec 31 19:00:17 alsmb kernel: [ 14.814065] usbcore: registered new interface driver hub
Dec 31 19:00:17 alsmb kernel: [ 14.814168] usbcore: registered new device driver usb
Dec 31 19:00:17 alsmb kernel: [ 14.814728] Switching to clocksource orion_clocksource
Dec 31 19:00:17 alsmb kernel: [ 14.822690] Switched to NOHz mode on CPU #0
Dec 31 19:00:17 alsmb kernel: [ 14.823689] FS-Cache: Loaded
Dec 31 19:00:17 alsmb kernel: [ 14.833537] NET: Registered protocol family 2
Dec 31 19:00:17 alsmb kernel: [ 14.833781] IP route cache hash table entries: 2048 (order: 1, 8192 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834499] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834684] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834819] TCP: Hash tables configured (established 8192 bind 8192)
Dec 31 19:00:17 alsmb kernel: [ 14.834831] TCP reno registered
Dec 31 19:00:17 alsmb kernel: [ 14.834844] UDP hash table entries: 256 (order: 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834867] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.835106] NET: Registered protocol family 1
Dec 31 19:00:17 alsmb kernel: [ 14.835142] PCI: CLS 0 bytes, default 32
Dec 31 19:00:17 alsmb kernel: [ 14.835731] audit: initializing netlink socket (disabled)
Dec 31 19:00:17 alsmb kernel: [ 14.835765] type=2000 audit(0.120:1): initialized
Dec 31 19:00:17 alsmb kernel: [ 14.922769] VFS: Disk quotas dquot_6.5.2
Dec 31 19:00:17 alsmb kernel: [ 14.923038] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.925351] JFFS2 version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
Dec 31 19:00:17 alsmb kernel: [ 14.926664] aufs 3.1-20111107
Dec 31 19:00:17 alsmb kernel: [ 14.926686] msgmni has been set to 492
Dec 31 19:00:17 alsmb kernel: [ 14.928041] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
Dec 31 19:00:17 alsmb kernel: [ 14.928057] io scheduler noop registered
Dec 31 19:00:17 alsmb kernel: [ 14.928065] io scheduler deadline registered
Dec 31 19:00:17 alsmb kernel: [ 14.928146] io scheduler cfq registered
Dec 31 19:00:17 alsmb kernel: [ 14.928218] io scheduler bfq registered (default)
Dec 31 19:00:17 alsmb kernel: [ 14.928282] mv_xor_shared mv_xor_shared.0: Marvell shared XOR driver
Dec 31 19:00:17 alsmb kernel: [ 14.928315] mv_xor_shared mv_xor_shared.1: Marvell shared XOR driver
Dec 31 19:00:17 alsmb kernel: [ 14.964811] mv_xor mv_xor.0: Marvell XOR: ( xor cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.004810] mv_xor mv_xor.1: Marvell XOR: ( xor fill cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.044806] mv_xor mv_xor.2: Marvell XOR: ( xor cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.084805] mv_xor mv_xor.3: Marvell XOR: ( xor fill cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.089889] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
Dec 31 19:00:17 alsmb kernel: [ 15.110576] serial8250.0: ttyS0 at MMIO 0xf1012000 (irq = 33) is a 16550A
Dec 31 19:00:17 alsmb kernel: [ 15.110679] console [ttyS0] enabled
Dec 31 19:00:17 alsmb kernel: [ 15.116823] brd: module loaded
Dec 31 19:00:17 alsmb kernel: [ 15.119828] loop: module loaded
Dec 31 19:00:17 alsmb kernel: [ 15.120827] NAND device: Manufacturer ID: 0xec, Chip ID: 0xf1 (Samsung NAND 128MiB 3,3V 8-bit)
Dec 31 19:00:17 alsmb kernel: [ 15.120851] Scanning device for bad blocks
Dec 31 19:00:17 alsmb kernel: [ 15.134839] Bad eraseblock 187 at 0x000001760000
Dec 31 19:00:17 alsmb kernel: [ 15.197004] 4 cmdlinepart partitions found on MTD device orion_nand
Dec 31 19:00:17 alsmb kernel: [ 15.197016] Creating 4 MTD partitions on "orion_nand":
Dec 31 19:00:17 alsmb kernel: [ 15.197031] 0x000000000000-0x000000100000 : "u-boot"
Dec 31 19:00:17 alsmb kernel: [ 15.197394] 0x000000100000-0x000000500000 : "uImage"
Dec 31 19:00:17 alsmb kernel: [ 15.197707] 0x000000500000-0x000002500000 : "rootfs"
Dec 31 19:00:17 alsmb kernel: [ 15.198042] 0x000002500000-0x000008000000 : "data"
Dec 31 19:00:17 alsmb kernel: [ 15.199196] mv643xx_eth: MV-643xx 10/100/1000 ethernet driver version 1.4
Dec 31 19:00:17 alsmb kernel: [ 15.199297] mv643xx_eth smi: probed
Dec 31 19:00:17 alsmb kernel: [ 15.201487] mv643xx_eth_port mv643xx_eth_port.0: eth0: port 0 with MAC address 00:25:31:02:22:4b
Dec 31 19:00:17 alsmb kernel: [ 15.201617] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Dec 31 19:00:17 alsmb kernel: [ 15.201670] orion-ehci orion-ehci.0: Marvell Orion EHCI
Dec 31 19:00:17 alsmb kernel: [ 15.201756] orion-ehci orion-ehci.0: new USB bus registered, assigned bus number 1
Dec 31 19:00:17 alsmb kernel: [ 15.224782] orion-ehci orion-ehci.0: irq 19, io mem 0xf1050000
Dec 31 19:00:17 alsmb kernel: [ 15.244765] orion-ehci orion-ehci.0: USB 2.0 started, EHCI 1.00
Dec 31 19:00:17 alsmb kernel: [ 15.245383] hub 1-0:1.0: USB hub found
Dec 31 19:00:17 alsmb kernel: [ 15.244765] orion-ehci orion-ehci.0: USB 2.0 started, EHCI 1.00
Dec 31 19:00:17 alsmb kernel: [ 15.245383] hub 1-0:1.0: USB hub found
Dec 31 19:00:17 alsmb kernel: [ 15.245406] hub 1-0:1.0: 1 port detected
Dec 31 19:00:17 alsmb kernel: [ 15.245917] Initializing USB Mass Storage driver...
Dec 31 19:00:17 alsmb kernel: [ 15.246015] usbcore: registered new interface driver usb-storage
Dec 31 19:00:17 alsmb kernel: [ 15.246024] USB Mass Storage support registered.
Dec 31 19:00:17 alsmb kernel: [ 15.246107] usbcore: registered new interface driver libusual
Dec 31 19:00:17 alsmb kernel: [ 15.246419] mousedev: PS/2 mouse device common for all mice
Dec 31 19:00:17 alsmb kernel: [ 15.564778] usb 1-1: new high speed USB device number 2 using orion-ehci
Dec 31 19:00:17 alsmb kernel: [ 15.716915] hub 1-1:1.0: USB hub found
Dec 31 19:00:17 alsmb kernel: [ 15.717292] hub 1-1:1.0: 4 ports detected
Dec 31 19:00:17 alsmb kernel: [ 15.995040] usb 1-1.4: new high speed USB device number 3 using orion-ehci
Dec 31 19:00:17 alsmb kernel: [ 16.106355] scsi0 : usb-storage 1-1.4:1.0
Dec 31 19:00:17 alsmb kernel: [ 16.254767] rtc-mv rtc-mv: internal RTC not ticking
Dec 31 19:00:17 alsmb kernel: [ 16.259828] sdhci: Secure Digital Host Controller Interface driver
Dec 31 19:00:17 alsmb kernel: [ 16.259838] sdhci: Copyright(c) Pierre Ossman
Dec 31 19:00:17 alsmb kernel: [ 16.260051] mmc0: mvsdio driver initialized, lacking card detect (fall back to polling)
Dec 31 19:00:17 alsmb kernel: [ 16.260094] sdhci-pltfm: SDHCI platform and OF driver helper
Dec 31 19:00:17 alsmb kernel: [ 16.260240] Registered led device: plug:red:misc
Dec 31 19:00:17 alsmb kernel: [ 16.260336] Registered led device: status:green:health
Dec 31 19:00:17 alsmb kernel: [ 16.260435] Registered led device: status:blue:health
Dec 31 19:00:17 alsmb kernel: [ 16.260648] usbcore: registered new interface driver r8712u
Dec 31 19:00:17 alsmb kernel: [ 16.261535] GRE over IPv4 demultiplexor driver
Dec 31 19:00:17 alsmb kernel: [ 16.261675] TCP cubic registered
Dec 31 19:00:17 alsmb kernel: [ 16.261687] NET: Registered protocol family 17
Dec 31 19:00:17 alsmb kernel: [ 16.261772] lib80211: common routines for IEEE802.11 drivers
Dec 31 19:00:17 alsmb kernel: [ 16.261783] lib80211_crypt: registered algorithm 'NULL'
Dec 31 19:00:17 alsmb kernel: [ 16.261792] Registering the dns_resolver key type
Dec 31 19:00:17 alsmb kernel: [ 16.261825] Gating clock of unused units
Dec 31 19:00:17 alsmb kernel: [ 16.261834] before: 0x00dfc3fd
Dec 31 19:00:17 alsmb kernel: [ 16.261842] after: 0x00c701d9
Dec 31 19:00:17 alsmb kernel: [ 16.262363] registered taskstats version 1
Dec 31 19:00:17 alsmb kernel: [ 16.263023] console [netcon0] enabled
Dec 31 19:00:17 alsmb kernel: [ 16.263031] netconsole: network logging started
Dec 31 19:00:17 alsmb kernel: [ 16.263096] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
Dec 31 19:00:17 alsmb kernel: [ 16.269700] Waiting 10sec before mounting root device...
Dec 31 19:00:17 alsmb kernel: [ 17.105641] scsi 0:0:0:0: Direct-Access SanDisk Cruzer Blade 1.26 PQ: 0 ANSI: 5
Dec 31 19:00:17 alsmb kernel: [ 17.106370] sd 0:0:0:0: Attached scsi generic sg0 type 0
Dec 31 19:00:17 alsmb kernel: [ 17.107449] sd 0:0:0:0: [sda] 15633408 512-byte logical blocks: (8.00 GB/7.45 GiB)
Dec 31 19:00:17 alsmb kernel: [ 17.108938] sd 0:0:0:0: [sda] Write Protect is off
Dec 31 19:00:17 alsmb kernel: [ 17.108952] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00
Dec 31 19:00:17 alsmb kernel: [ 17.109689] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Dec 31 19:00:17 alsmb kernel: [ 17.114632] sda: sda1
Dec 31 19:00:17 alsmb kernel: [ 17.117439] sd 0:0:0:0: [sda] Attached SCSI removable disk
Dec 31 19:00:17 alsmb kernel: [ 26.276202] EXT4-fs (sda1): mounting ext2 file system using the ext4 subsystem
Dec 31 19:00:17 alsmb kernel: [ 26.280593] EXT4-fs (sda1): warning: mounting unchecked fs, running e2fsck is recommended
Dec 31 19:00:17 alsmb kernel: [ 26.287728] EXT4-fs (sda1): mounted filesystem without journal. Opts: (null)
Dec 31 19:00:17 alsmb kernel: [ 26.287771] VFS: Mounted root (ext2 filesystem) on device 8:1.
Dec 31 19:00:17 alsmb kernel: [ 26.292116] devtmpfs: mounted
Dec 31 19:00:17 alsmb kernel: [ 26.292776] Freeing init memory: 172K
Dec 31 19:00:17 alsmb kernel: [ 27.931124] RPC: Registered named UNIX socket transport module.
Dec 31 19:00:17 alsmb kernel: [ 27.931139] RPC: Registered udp transport module.
Dec 31 19:00:17 alsmb kernel: [ 27.931147] RPC: Registered tcp transport module.
Dec 31 19:00:17 alsmb kernel: [ 27.931155] RPC: Registered tcp NFSv4.1 backchannel transport module.
Dec 31 19:00:17 alsmb kernel: [ 28.432944] FS-Cache: Netfs 'nfs' registered for caching
Dec 31 19:00:17 alsmb kernel: [ 29.385651] Adding 524284k swap on /swapfile.img. Priority:-1 extents:14 across:581628k
Dec 31 19:00:17 alsmb kernel: [ 30.186198] NET: Registered protocol family 10
Dec 31 19:00:17 alsmb kernel: [ 32.246739] ADDRCONF(NETDEV_UP): eth0: link is not ready
Dec 31 19:00:20 alsmb kernel: [ 34.921931] mv643xx_eth_port mv643xx_eth_port.0: eth0: link up, 1000 Mb/s, full duplex, flow control disabled
Dec 31 19:00:20 alsmb kernel: [ 34.922101] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Dec 31 19:00:30 alsmb kernel: [ 45.564762] eth0: no IPv6 routers present
')

errors.log
$this->bbcode_second_pass_code('', 'Dec 31 19:00:17 alsmb kernel: [ 16.254767] rtc-mv rtc-mv: internal RTC not ticking
Dec 31 19:00:17 alsmb kernel: [ 16.263096] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
Dec 31 19:00:20 alsmb dhcpcd[232]: eth0: sendmsg: Cannot assign requested address
Dec 31 19:00:30 alsmb dhcpcd[232]: timed out
Dec 31 19:00:30 alsmb systemd[1]: Failed to start Netcfg multi-profile daemon.
Dec 31 19:00:31 alsmb smbd[305]: [1969/12/31 19:00:31.427422, 0] param/loadparm.c:7969(lp_do_parameter)
Dec 31 19:00:31 alsmb smbd[305]: Ignoring unknown parameter "disable spools"
')

messages.log
$this->bbcode_second_pass_code('', 'Dec 31 19:00:13 alsmb systemd[1]: Started Remount Root and Kernel File Systems.
Dec 31 19:00:13 alsmb systemd[1]: Starting Local File Systems.
Dec 31 19:00:13 alsmb systemd[1]: Reached target Local File Systems.
Dec 31 19:00:13 alsmb systemd[1]: Starting Recreate Volatile Files and Directories...
Dec 31 19:00:13 alsmb systemd-modules-load[70]: Inserted module 'nfs'
Dec 31 19:00:13 alsmb systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
Dec 31 19:00:13 alsmb systemd[1]: Starting Local File Systems (Pre).
Dec 31 19:00:13 alsmb systemd[1]: Reached target Local File Systems (Pre).
Dec 31 19:00:13 alsmb systemd[1]: Starting Load Random Seed...
Dec 31 19:00:13 alsmb systemd[1]: Activating swap /swapfile.img...
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Initializing cgroup subsys cpuset
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Initializing cgroup subsys cpu
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Linux version 3.1.10-16-ARCH (nobody@panda2) (gcc version 4.7.2 (GCC) ) #1 PREEMPT Tue Feb 12 01:17:10 UTC 2013
Dec 31 19:00:17 alsmb kernel: [ 0.000000] CPU: Feroceon 88FR131 [56251311] revision 1 (ARMv5TE), cr=00053977
Dec 31 19:00:17 alsmb kernel: [ 0.000000] CPU: VIVT data cache, VIVT instruction cache
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Machine: Marvell SheevaPlug Reference Board
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Memory policy: ECC disabled, Data cache writeback
Dec 31 19:00:14 alsmb systemd[1]: Started Load Kernel Modules.
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 65024
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Kernel command line: console=ttyS0,115200 root=/dev/sda1 rootdelay=10 rootfstype=ext2 mtdparts=orion_nand:1M(u-b
oot),4M(uImage),32M(rootfs),-(data)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] allocated 1048576 bytes of page_cgroup
Dec 31 19:00:17 alsmb kernel: [ 0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Memory: 256MB = 256MB total
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Memory: 252304k/252304k available, 9840k reserved, 0K highmem
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Virtual kernel memory layout:
Dec 31 19:00:17 alsmb kernel: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] DMA : 0xffc00000 - 0xffe00000 ( 2 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] vmalloc : 0xd0800000 - 0xfe800000 ( 736 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] lowmem : 0xc0000000 - 0xd0000000 ( 256 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .text : 0xc0008000 - 0xc052ede4 (5276 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .init : 0xc052f000 - 0xc055a000 ( 172 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .data : 0xc055a000 - 0xc05932f0 ( 229 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] .bss : 0xc0593314 - 0xc0660e8c ( 823 kB)
Dec 31 19:00:17 alsmb kernel: [ 0.000000] SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Preemptible hierarchical RCU implementation.
Dec 31 19:00:17 alsmb kernel: [ 0.000000] NR_IRQS:114
Dec 31 19:00:17 alsmb kernel: [ 0.000000] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 21474ms
Dec 31 19:00:17 alsmb kernel: [ 0.000000] Console: colour dummy device 80x30
Dec 31 19:00:17 alsmb kernel: [ 14.712760] Calibrating delay loop... 1191.11 BogoMIPS (lpj=5955584)
Dec 31 19:00:17 alsmb kernel: [ 14.802690] pid_max: default: 32768 minimum: 301
Dec 31 19:00:17 alsmb kernel: [ 14.802815] Security Framework initialized
Dec 31 19:00:17 alsmb kernel: [ 14.802838] AppArmor: AppArmor disabled by boot time parameter
Dec 31 19:00:17 alsmb kernel: [ 14.802904] Mount-cache hash table entries: 512
Dec 31 19:00:17 alsmb kernel: [ 14.803291] Initializing cgroup subsys cpuacct
Dec 31 19:00:17 alsmb kernel: [ 14.803319] Initializing cgroup subsys memory
Dec 31 19:00:17 alsmb kernel: [ 14.803355] Initializing cgroup subsys devices
Dec 31 19:00:17 alsmb kernel: [ 14.803368] Initializing cgroup subsys freezer
Dec 31 19:00:17 alsmb kernel: [ 14.803377] Initializing cgroup subsys net_cls
Dec 31 19:00:17 alsmb kernel: [ 14.803386] Initializing cgroup subsys blkio
Dec 31 19:00:17 alsmb kernel: [ 14.803410] Initializing cgroup subsys perf_event
Dec 31 19:00:17 alsmb kernel: [ 14.803428] Initializing cgroup subsys bfqio
Dec 31 19:00:17 alsmb kernel: [ 14.803521] CPU: Testing write buffer coherency: ok
Dec 31 19:00:17 alsmb kernel: [ 14.804807] devtmpfs: initialized
Dec 31 19:00:17 alsmb kernel: [ 14.806616] NET: Registered protocol family 16
Dec 31 19:00:17 alsmb kernel: [ 14.807275] Kirkwood: MV88F6281-A0, TCLK=200000000.
Dec 31 19:00:17 alsmb kernel: [ 14.807290] Feroceon L2: Enabling L2
Dec 31 19:00:17 alsmb kernel: [ 14.807327] Feroceon L2: Cache support initialised.
Dec 31 19:00:17 alsmb kernel: [ 14.812959] bio: create slab <bio-0> at 0
Dec 31 19:00:17 alsmb kernel: [ 14.813326] vgaarb: loaded
Dec 31 19:00:17 alsmb kernel: [ 14.813587] SCSI subsystem initialized
Dec 31 19:00:17 alsmb kernel: [ 14.813968] usbcore: registered new interface driver usbfs
Dec 31 19:00:17 alsmb kernel: [ 14.814065] usbcore: registered new interface driver hub
Dec 31 19:00:17 alsmb kernel: [ 14.814168] usbcore: registered new device driver usb
Dec 31 19:00:17 alsmb kernel: [ 14.814728] Switching to clocksource orion_clocksource
Dec 31 19:00:17 alsmb kernel: [ 14.822690] Switched to NOHz mode on CPU #0
Dec 31 19:00:17 alsmb kernel: [ 14.823689] FS-Cache: Loaded
Dec 31 19:00:17 alsmb kernel: [ 14.833537] NET: Registered protocol family 2
Dec 31 19:00:17 alsmb kernel: [ 14.833781] IP route cache hash table entries: 2048 (order: 1, 8192 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834499] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834684] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834819] TCP: Hash tables configured (established 8192 bind 8192)
Dec 31 19:00:17 alsmb kernel: [ 14.834831] TCP reno registered
Dec 31 19:00:17 alsmb kernel: [ 14.834844] UDP hash table entries: 256 (order: 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.834867] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.835106] NET: Registered protocol family 1
Dec 31 19:00:17 alsmb kernel: [ 14.835731] audit: initializing netlink socket (disabled)
Dec 31 19:00:17 alsmb kernel: [ 14.835765] type=2000 audit(0.120:1): initialized
Dec 31 19:00:17 alsmb kernel: [ 14.922769] VFS: Disk quotas dquot_6.5.2
Dec 31 19:00:17 alsmb kernel: [ 14.923038] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Dec 31 19:00:17 alsmb kernel: [ 14.925351] JFFS2 version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
Dec 31 19:00:17 alsmb kernel: [ 14.926664] aufs 3.1-20111107
Dec 31 19:00:17 alsmb kernel: [ 14.926686] msgmni has been set to 492
Dec 31 19:00:17 alsmb kernel: [ 14.928041] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
Dec 31 19:00:17 alsmb kernel: [ 14.928057] io scheduler noop registered
Dec 31 19:00:17 alsmb kernel: [ 14.928065] io scheduler deadline registered
Dec 31 19:00:17 alsmb kernel: [ 14.928146] io scheduler cfq registered
Dec 31 19:00:17 alsmb kernel: [ 14.928218] io scheduler bfq registered (default)
Dec 31 19:00:17 alsmb kernel: [ 14.928282] mv_xor_shared mv_xor_shared.0: Marvell shared XOR driver
Dec 31 19:00:17 alsmb kernel: [ 14.928315] mv_xor_shared mv_xor_shared.1: Marvell shared XOR driver
Dec 31 19:00:17 alsmb kernel: [ 14.964811] mv_xor mv_xor.0: Marvell XOR: ( xor cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.004810] mv_xor mv_xor.1: Marvell XOR: ( xor fill cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.044806] mv_xor mv_xor.2: Marvell XOR: ( xor cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.084805] mv_xor mv_xor.3: Marvell XOR: ( xor fill cpy )
Dec 31 19:00:17 alsmb kernel: [ 15.089889] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
Dec 31 19:00:17 alsmb kernel: [ 15.110576] serial8250.0: ttyS0 at MMIO 0xf1012000 (irq = 33) is a 16550A
Dec 31 19:00:17 alsmb kernel: [ 15.110679] console [ttyS0] enabled
Dec 31 19:00:17 alsmb kernel: [ 15.116823] brd: module loaded
Dec 31 19:00:17 alsmb kernel: [ 15.119828] loop: module loaded
Dec 31 19:00:17 alsmb kernel: [ 15.120827] NAND device: Manufacturer ID: 0xec, Chip ID: 0xf1 (Samsung NAND 128MiB 3,3V 8-bit)
Dec 31 19:00:17 alsmb kernel: [ 15.120851] Scanning device for bad blocks
Dec 31 19:00:17 alsmb kernel: [ 15.134839] Bad eraseblock 187 at 0x000001760000
Dec 31 19:00:17 alsmb kernel: [ 15.197004] 4 cmdlinepart partitions found on MTD device orion_nand
Dec 31 19:00:17 alsmb kernel: [ 15.197016] Creating 4 MTD partitions on "orion_nand":
Dec 31 19:00:17 alsmb kernel: [ 15.197031] 0x000000000000-0x000000100000 : "u-boot"
Dec 31 19:00:17 alsmb kernel: [ 15.197394] 0x000000100000-0x000000500000 : "uImage"
Dec 31 19:00:17 alsmb kernel: [ 15.197707] 0x000000500000-0x000002500000 : "rootfs"
Dec 31 19:00:17 alsmb kernel: [ 15.198042] 0x000002500000-0x000008000000 : "data"
Dec 31 19:00:17 alsmb kernel: [ 15.199196] mv643xx_eth: MV-643xx 10/100/1000 ethernet driver version 1.4
Dec 31 19:00:17 alsmb kernel: [ 15.199297] mv643xx_eth smi: probed
Dec 31 19:00:17 alsmb kernel: [ 15.201487] mv643xx_eth_port mv643xx_eth_port.0: eth0: port 0 with MAC address 00:25:31:02:22:4b
Dec 31 19:00:17 alsmb kernel: [ 15.201617] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Dec 31 19:00:17 alsmb kernel: [ 15.201670] orion-ehci orion-ehci.0: Marvell Orion EHCI
Dec 31 19:00:17 alsmb kernel: [ 15.201756] orion-ehci orion-ehci.0: new USB bus registered, assigned bus number 1
Dec 31 19:00:17 alsmb kernel: [ 15.224782] orion-ehci orion-ehci.0: irq 19, io mem 0xf1050000
Dec 31 19:00:17 alsmb kernel: [ 15.244765] orion-ehci orion-ehci.0: USB 2.0 started, EHCI 1.00
Dec 31 19:00:17 alsmb kernel: [ 15.245383] hub 1-0:1.0: USB hub found
Dec 31 19:00:17 alsmb kernel: [ 15.245406] hub 1-0:1.0: 1 port detected
Dec 31 19:00:17 alsmb kernel: [ 15.245917] Initializing USB Mass Storage driver...
Dec 31 19:00:17 alsmb kernel: [ 15.246015] usbcore: registered new interface driver usb-storage
Dec 31 19:00:17 alsmb kernel: [ 15.246024] USB Mass Storage support registered.
Dec 31 19:00:17 alsmb kernel: [ 15.246107] usbcore: registered new interface driver libusual
Dec 31 19:00:17 alsmb kernel: [ 15.246419] mousedev: PS/2 mouse device common for all mice
Dec 31 19:00:17 alsmb kernel: [ 15.564778] usb 1-1: new high speed USB device number 2 using orion-ehci
Dec 31 19:00:17 alsmb kernel: [ 15.716915] hub 1-1:1.0: USB hub found
Dec 31 19:00:17 alsmb kernel: [ 15.717292] hub 1-1:1.0: 4 ports detected
Dec 31 19:00:17 alsmb kernel: [ 15.995040] usb 1-1.4: new high speed USB device number 3 using orion-ehci
Dec 31 19:00:17 alsmb kernel: [ 16.106355] scsi0 : usb-storage 1-1.4:1.0
Dec 31 19:00:17 alsmb kernel: [ 16.259828] sdhci: Secure Digital Host Controller Interface driver
Dec 31 19:00:17 alsmb kernel: [ 16.259838] sdhci: Copyright(c) Pierre Ossman
Dec 31 19:00:17 alsmb kernel: [ 16.260051] mmc0: mvsdio driver initialized, lacking card detect (fall back to polling)
Dec 31 19:00:17 alsmb kernel: [ 16.260094] sdhci-pltfm: SDHCI platform and OF driver helper
Dec 31 19:00:17 alsmb kernel: [ 16.260648] usbcore: registered new interface driver r8712u
Dec 31 19:00:17 alsmb kernel: [ 16.261535] GRE over IPv4 demultiplexor driver
Dec 31 19:00:17 alsmb kernel: [ 16.261675] TCP cubic registered
Dec 31 19:00:17 alsmb kernel: [ 16.261687] NET: Registered protocol family 17
Dec 31 19:00:17 alsmb kernel: [ 16.261772] lib80211: common routines for IEEE802.11 drivers
Dec 31 19:00:17 alsmb kernel: [ 16.261792] Registering the dns_resolver key type
Dec 31 19:00:17 alsmb kernel: [ 16.262363] registered taskstats version 1
Dec 31 19:00:17 alsmb kernel: [ 16.263023] console [netcon0] enabled
Dec 31 19:00:17 alsmb kernel: [ 16.263031] netconsole: network logging started
Dec 31 19:00:17 alsmb kernel: [ 16.269700] Waiting 10sec before mounting root device...
Dec 31 19:00:17 alsmb kernel: [ 17.105641] scsi 0:0:0:0: Direct-Access SanDisk Cruzer Blade 1.26 PQ: 0 ANSI: 5
Dec 31 19:00:17 alsmb kernel: [ 17.106370] sd 0:0:0:0: Attached scsi generic sg0 type 0
Dec 31 19:00:17 alsmb kernel: [ 17.107449] sd 0:0:0:0: [sda] 15633408 512-byte logical blocks: (8.00 GB/7.45 GiB)
Dec 31 19:00:17 alsmb kernel: [ 17.108938] sd 0:0:0:0: [sda] Write Protect is off
Dec 31 19:00:17 alsmb kernel: [ 17.109689] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Dec 31 19:00:17 alsmb kernel: [ 17.114632] sda: sda1
Dec 31 19:00:17 alsmb kernel: [ 17.117439] sd 0:0:0:0: [sda] Attached SCSI removable disk
Dec 31 19:00:17 alsmb kernel: [ 26.276202] EXT4-fs (sda1): mounting ext2 file system using the ext4 subsystem
Dec 31 19:00:17 alsmb kernel: [ 26.280593] EXT4-fs (sda1): warning: mounting unchecked fs, running e2fsck is recommended
Dec 31 19:00:17 alsmb kernel: [ 26.287728] EXT4-fs (sda1): mounted filesystem without journal. Opts: (null)
Dec 31 19:00:17 alsmb kernel: [ 26.287771] VFS: Mounted root (ext2 filesystem) on device 8:1.
Dec 31 19:00:17 alsmb kernel: [ 26.292116] devtmpfs: mounted
Dec 31 19:00:17 alsmb kernel: [ 26.292776] Freeing init memory: 172K
Dec 31 19:00:17 alsmb [ 26.804938] systemd[1]: systemd 197 running in system mode. (+PAM -LIBWRAP -AUDIT -SELINUX -IMA -SYSVINIT +LIBCRYPTSETUP +GCRYPT +AC
L +XZ)
Dec 31 19:00:17 alsmb [ 26.871928] systemd[1]: Inserted module 'autofs4'
Dec 31 19:00:17 alsmb [ 26.881206] systemd[1]: Set hostname to <alsmb>.
Dec 31 19:00:17 alsmb [ 27.079125] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to
load: No such file or directory. See system logs and 'systemctl status display-manager.service' for details.
Dec 31 19:00:17 alsmb [ 27.079944] systemd[1]: Expecting device dev-ttyS0.device...
Dec 31 19:00:17 alsmb [ 27.094927] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
Dec 31 19:00:17 alsmb [ 27.095262] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
Dec 31 19:00:17 alsmb [ 27.095374] systemd[1]: Starting Remote File Systems.
Dec 31 19:00:17 alsmb [ 27.114890] systemd[1]: Reached target Remote File Systems.
Dec 31 19:00:17 alsmb [ 27.114979] systemd[1]: Starting Syslog Socket.
Dec 31 19:00:17 alsmb [ 27.134857] systemd[1]: Listening on Syslog Socket.
Dec 31 19:00:17 alsmb [ 27.134950] systemd[1]: Starting Device-mapper event daemon FIFOs.
Dec 31 19:00:17 alsmb [ 27.154854] systemd[1]: Listening on Device-mapper event daemon FIFOs.
Dec 31 19:00:17 alsmb [ 27.154938] systemd[1]: Starting Delayed Shutdown Socket.
Dec 31 19:00:17 alsmb [ 27.174852] systemd[1]: Listening on Delayed Shutdown Socket.
Dec 31 19:00:17 alsmb [ 27.174933] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
Dec 31 19:00:17 alsmb [ 27.194850] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
Dec 31 19:00:17 alsmb [ 27.194933] systemd[1]: Starting LVM2 metadata daemon socket.
Dec 31 19:00:17 alsmb [ 27.214851] systemd[1]: Listening on LVM2 metadata daemon socket.
Dec 31 19:00:17 alsmb [ 27.214937] systemd[1]: Starting Encrypted Volumes.
Dec 31 19:00:17 alsmb [ 27.234847] systemd[1]: Reached target Encrypted Volumes.
Dec 31 19:00:17 alsmb mysqld[111]: 691231 19:00:17 InnoDB: Completed initialization of buffer pool
Dec 31 19:00:17 alsmb [ 27.235262] systemd[1]: Starting udev Kernel Socket.
Dec 31 19:00:17 alsmb [ 27.254860] systemd[1]: Listening on udev Kernel Socket.
Dec 31 19:00:17 alsmb [ 27.255219] systemd[1]: Starting udev Control Socket.
Dec 31 19:00:17 alsmb [ 27.274861] systemd[1]: Listening on udev Control Socket.
Dec 31 19:00:17 alsmb [ 27.275070] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
Dec 31 19:00:17 alsmb [ 27.294874] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
Dec 31 19:00:17 alsmb [ 27.294995] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
Dec 31 19:00:17 alsmb [ 27.295244] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
Dec 31 19:00:17 alsmb [ 27.295349] systemd[1]: Starting Journal Socket.
Dec 31 19:00:17 alsmb [ 27.314862] systemd[1]: Listening on Journal Socket.
Dec 31 19:00:17 alsmb [ 27.314978] systemd[1]: Mounting Temporary Directory...
Dec 31 19:00:17 alsmb [ 27.386326] systemd[1]: Mounting POSIX Message Queue File System...
Dec 31 19:00:17 alsmb [ 27.445461] systemd[1]: Starting udev Kernel Device Manager...
Dec 31 19:00:17 alsmb [ 27.505616] systemd[1]: Mounting Debug File System...
Dec 31 19:00:17 alsmb [ 27.568326] systemd[1]: Started Set Up Additional Binary Formats.
Dec 31 19:00:17 alsmb [ 27.570510] systemd-udevd[45]: starting version 197
Dec 31 19:00:17 alsmb [ 27.571352] systemd[1]: Starting Apply Kernel Variables...
Dec 31 19:00:17 alsmb [ 27.635552] systemd[1]: Mounted Huge Pages File System.
Dec 31 19:00:17 alsmb [ 27.635915] systemd[1]: Starting udev Coldplug all Devices...
Dec 31 19:00:17 alsmb [ 27.767689] systemd[1]: Starting Load Kernel Modules...
Dec 31 19:00:17 alsmb [ 27.835538] systemd[1]: Starting Setup Virtual Console...
Dec 31 19:00:17 alsmb [ 27.915481] systemd[1]: Starting Journal Service...
Dec 31 19:00:17 alsmb kernel: [ 27.931124] RPC: Registered named UNIX socket transport module.
Dec 31 19:00:17 alsmb kernel: [ 27.931139] RPC: Registered udp transport module.
Dec 31 19:00:17 alsmb kernel: [ 27.931147] RPC: Registered tcp transport module.
Dec 31 19:00:17 alsmb kernel: [ 27.931155] RPC: Registered tcp NFSv4.1 backchannel transport module.
Dec 31 19:00:17 alsmb [ 27.984965] systemd[1]: Started Journal Service.
Dec 31 19:00:17 alsmb [ 27.985223] systemd[1]: Starting Syslog.
Dec 31 19:00:17 alsmb [ 28.004918] systemd[1]: Reached target Syslog.
Dec 31 19:00:17 alsmb [ 28.005105] systemd[1]: Started File System Check on Root Device.
Dec 31 19:00:17 alsmb [ 28.005241] systemd[1]: Starting Remount Root and Kernel File Systems...
Dec 31 19:00:17 alsmb [ 28.084989] systemd[1]: Started udev Kernel Device Manager.
Dec 31 19:00:17 alsmb [ 28.105005] systemd[1]: Mounted Temporary Directory.
Dec 31 19:00:17 alsmb [ 28.124981] systemd[1]: Mounted POSIX Message Queue File System.
Dec 31 19:00:17 alsmb [ 28.145005] systemd[1]: Mounted Debug File System.
Dec 31 19:00:17 alsmb [ 28.204938] systemd[1]: Started Apply Kernel Variables.
Dec 31 19:00:17 alsmb kernel: [ 28.432944] FS-Cache: Netfs 'nfs' registered for caching
Dec 31 19:00:17 alsmb [ 29.178416] systemd-journald[74]: Received SIGUSR1
Dec 31 19:00:17 alsmb kernel: [ 29.385651] Adding 524284k swap on /swapfile.img. Priority:-1 extents:14 across:581628k
Dec 31 19:00:17 alsmb kernel: [ 30.186198] NET: Registered protocol family 10
Dec 31 19:00:17 alsmb mysqld[111]: 691231 19:00:17 InnoDB: highest supported file format is Barracuda.
Dec 31 19:00:17 alsmb kernel: [ 32.246739] ADDRCONF(NETDEV_UP): eth0: link is not ready
Dec 31 19:00:18 alsmb mysqld[111]: 691231 19:00:18 InnoDB: Waiting for the background threads to start
Dec 31 19:00:19 alsmb mysqld[111]: 691231 19:00:19 InnoDB: 5.5.30 started; log sequence number 6036444
Dec 31 19:00:19 alsmb mysqld[111]: /usr/bin/mysqld: File './mysql-bin.000016' not found (Errcode: 2)
Dec 31 19:00:19 alsmb mysqld[111]: 691231 19:00:19 [ERROR] Failed to open log (file './mysql-bin.000016', errno 2)
Dec 31 19:00:19 alsmb mysqld[111]: 691231 19:00:19 [ERROR] Could not open log file
Dec 31 19:00:19 alsmb mysqld[111]: 691231 19:00:19 [ERROR] Can't init tc log
Dec 31 19:00:19 alsmb mysqld[111]: 691231 19:00:19 [ERROR] Aborting
Dec 31 19:00:19 alsmb mysqld[111]: 691231 19:00:19 InnoDB: Starting shutdown...
Dec 31 19:00:20 alsmb kernel: [ 34.921931] mv643xx_eth_port mv643xx_eth_port.0: eth0: link up, 1000 Mb/s, full duplex, flow control disabled
Dec 31 19:00:20 alsmb kernel: [ 34.922101] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Dec 31 19:00:20 alsmb mysqld[111]: 691231 19:00:20 InnoDB: Shutdown completed; log sequence number 6036444
Dec 31 19:00:20 alsmb mysqld[111]: 691231 19:00:20 [Note] /usr/bin/mysqld: Shutdown complete
Dec 31 19:00:20 alsmb dhcpcd[232]: version 5.6.4 starting
Dec 31 19:00:20 alsmb systemd[1]: mysqld.service: main process exited, code=exited, status=1/FAILURE
Dec 31 19:00:20 alsmb dhcpcd[232]: eth0: sending IPv6 Router Solicitation
Dec 31 19:00:20 alsmb dhcpcd[232]: eth0: rebinding lease of 192.168.1.7
Dec 31 19:00:24 alsmb dhcpcd[232]: eth0: sending IPv6 Router Solicitation
Dec 31 19:00:25 alsmb dhcpcd[232]: eth0: broadcasting for a lease
Dec 31 19:00:27 alsmb dhcpcd[232]: eth0: offered 192.168.1.3 from 192.168.1.1
Dec 31 19:00:27 alsmb dhcpcd[232]: eth0: acknowledged 192.168.1.3 from 192.168.1.1
Dec 31 19:00:27 alsmb dhcpcd[232]: eth0: checking for 192.168.1.3
Dec 31 19:00:28 alsmb dhcpcd[232]: eth0: sending IPv6 Router Solicitation
Dec 31 19:00:30 alsmb netcfg-daemon[110]: :: wired-eth0 up DHCP IP lease attempt failed.
Dec 31 19:00:30 alsmb netcfg-daemon[110]: [fail]
Dec 31 19:00:30 alsmb systemd[1]: netcfg.service: main process exited, code=exited, status=1/FAILURE
Dec 31 19:00:30 alsmb systemd[1]: Unit netcfg.service entered failed state
Dec 31 19:00:30 alsmb systemd[1]: Starting Network.
Dec 31 19:00:30 alsmb systemd[1]: Reached target Network.
Dec 31 19:00:30 alsmb systemd[1]: Starting OpenNTP Daemon...
Dec 31 19:00:30 alsmb systemd[1]: Starting Samba NetBIOS name server...
Dec 31 19:00:31 alsmb systemd[1]: PID file /var/run/samba/nmbd.pid not readable (yet?) after start.
Dec 31 19:00:31 alsmb systemd[1]: Started Samba NetBIOS name server.
Dec 31 19:00:31 alsmb systemd[1]: Starting Samba SMB/CIFS server...
Dec 31 19:00:31 alsmb systemd[1]: nmbd.service: main process exited, code=exited, status=1/FAILURE
Dec 31 19:00:31 alsmb systemd[1]: Unit nmbd.service entered failed state
Dec 31 19:00:31 alsmb systemd[1]: Started Samba SMB/CIFS server.
Dec 31 19:00:45 alsmb systemd[1]: Started OpenNTP Daemon.
')
tjtv
 
Posts: 8
Joined: Thu Feb 21, 2013 5:53 am

Re: Was working for months. Changed nothing, now won't boot

Postby hydro » Wed May 29, 2013 8:36 am

$this->bbcode_second_pass_code('', '
Dec 31 19:00:20 alsmb dhcpcd[232]: eth0: sending IPv6 Router Solicitation
Dec 31 19:00:20 alsmb dhcpcd[232]: eth0: rebinding lease of 192.168.1.7
Dec 31 19:00:24 alsmb dhcpcd[232]: eth0: sending IPv6 Router Solicitation
Dec 31 19:00:25 alsmb dhcpcd[232]: eth0: broadcasting for a lease
Dec 31 19:00:27 alsmb dhcpcd[232]: eth0: offered 192.168.1.3 from 192.168.1.1
Dec 31 19:00:27 alsmb dhcpcd[232]: eth0: acknowledged 192.168.1.3 from 192.168.1.1
Dec 31 19:00:27 alsmb dhcpcd[232]: eth0: checking for 192.168.1.3
Dec 31 19:00:28 alsmb dhcpcd[232]: eth0: sending IPv6 Router Solicitation
Dec 31 19:00:30 alsmb netcfg-daemon[110]: :: wired-eth0 up DHCP IP lease attempt failed.
')
I suggest you add DHCP_TIMEOUT=30 to /etc/network.d/wired-eth0, the default of 10 seconds is obviously reached. Your device does not have a rtc, so time is set to 1.1.1970 (and adjusted depending on /etc/localtime), that's why you need openntpd (which, however, fails to set the time because of the network issue). I'm not sure why sshd is not started at all.
VDR on DockStar / Pogoplug E02: http://linux.bplaced.net/
hydro
 
Posts: 210
Joined: Wed Jun 15, 2011 2:03 pm
Location: Germany

Re: Was working for months. Changed nothing, now won't boot

Postby tjtv » Thu May 30, 2013 2:00 am

Thanks for your help. Adding DHCP_TIMEOUT=30 did seem to work, but it always seemed to grab 192.168.1.3 instead of 192.168.1.7 like it did for the previous many months.

I worked around that by editing /etc/wired-eth0 to use a static ip 192.168.1.7

However, now mysql doesn't seem to start properly. I've pasted what I think is the relevant section of the daemon.log
$this->bbcode_second_pass_code('', 'May 29 21:56:23 alsmb mysqld[734]: ^G/usr/bin/mysqld: File './mysql-bin.000016' not found (Errcode: 2)
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 [ERROR] Failed to open log (file './mysql-bin.000016', errno 2)
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 [ERROR] Could not open log file
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 [ERROR] Can't init tc log
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 [ERROR] Aborting
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 InnoDB: Starting shutdown...
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 InnoDB: Shutdown completed; log sequence number 6036444
May 29 21:56:23 alsmb mysqld[734]: 130529 21:56:23 [Note] /usr/bin/mysqld: Shutdown complete
May 29 21:56:23 alsmb systemd[1]: mysqld.service: main process exited, code=exited, status=1/FAILURE
')

Any idea what may be causing this? It really baffles me that all these problems are now occurring to a system that previously was up for months and that I didn't make any changes to.
tjtv
 
Posts: 8
Joined: Thu Feb 21, 2013 5:53 am

Re: Was working for months. Changed nothing, now won't boot

Postby tjtv » Thu May 30, 2013 3:35 am

I found a workaround. I commented out the following lines in /etc/mysql/my.cnf

$this->bbcode_second_pass_code('', '# Replication Master Server (default)
# binary logging is required for replication
#log-bin=mysql-bin

# binary logging format - mixed recommended
#binlog_format=mixed
')

I still have no idea why I need to comment out these lines now, when the system worked perfectly fine for months with those lines uncomented.
tjtv
 
Posts: 8
Joined: Thu Feb 21, 2013 5:53 am


Return to Marvell Kirkwood

Who is online

Users browsing this forum: No registered users and 6 guests