Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CCGX v2.20~48 stuck while shutting down #312

Closed
mpvader opened this issue Aug 17, 2018 · 5 comments
Closed

CCGX v2.20~48 stuck while shutting down #312

mpvader opened this issue Aug 17, 2018 · 5 comments
Assignees

Comments

@mpvader
Copy link
Contributor

mpvader commented Aug 17, 2018

https://vrm.victronenergy.com/installation/14404/advanced

My conclusion so far: it got stuck during the shutdown process after installing v2.20~50. The good news is that the issue doesn't seem to be in booting v2.20~50.

Analysis

The VRM database shows no data after 17/08/2018 02:20, next expected entry would have been 02:35. This matches the logs on the device itself: the reboot was initiated by swupdate at 2:23. Next entry in the VRM Database is at 05:46: it shows a booting 2.20~50. This gap means that the device hasn't been running that time with the display off and/or a not working network interface. As in such case the data would have been backlogged, and sent out once all restored.

/log/messages doesn't show a complete shutdown. You see the shutdown starting, but then it gets silent and there are some ntp messages. Then at 05:45:16 there is a flurry of networking messages: before giving the device a hard reset, the customer confirmed me to have unplugged and replugged the network cable. Whereafter at 05:45:32 there is a fresh boot, right at the time at which the customer confirms he has given the device a hard reset.

Herewith the excerpt, full log further down below:

Aug 17 02:32:09 ccgx cron.info CROND[22734]: (root) CMDOUT (do_swupdate completed OK. Rebooting)
Aug 17 02:32:09 ccgx user.notice shutdown[22769]: shutting down for system reboot
Aug 17 02:32:09 ccgx daemon.info init: Switching to runlevel: 6
Aug 17 03:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.093024 s
Aug 17 05:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.082232 s
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {RX} 2615697 packets 490054135 bytes
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {TX} 3833972 packets 7731968 bytes
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {update} flags 4099 <UP>
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 address 68:9E:19:7A:7A:4A mtu 1500
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 operstate 2 <DOWN>
Aug 17 05:45:16 ccgx user.info kernel: [1219235.927842] davinci_emac davinci_emac.0 eth0: Link is Down
Aug 17 05:45:16 ccgx daemon.err connmand[773]: Time request for server 192.168.13.254 failed (101/Network is unreachable)
Aug 17 05:45:16 ccgx daemon.err connmand[773]: Time request for server 192.168.13.254 failed (101/Network is unreachable)
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} address 192.168.13.193/24 label eth0
Aug 17 05:45:16 ccgx user.info kernel: [1219235.980901] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} route 192.168.13.0 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} route fe80:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} route ff00:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:16 ccgx daemon.info dnsmasq[744]: read /etc/hosts - 6 addresses
Aug 17 05:45:16 ccgx daemon.err dnsmasq[744]: failed to read /run/resolv.conf: No such file or directory
Aug 17 05:45:16 ccgx daemon.info dnsmasq[744]: using nameserver 192.168.13.254#53
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route ff00:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route fe80:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {RX} 2615697 packets 490054135 bytes
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {TX} 3833972 packets 7731968 bytes
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {update} flags 69699 <UP,RUNNING,LOWER_UP>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 address 68:9E:19:7A:7A:4A mtu 1500
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 operstate 6 <UP>
Aug 17 05:45:18 ccgx user.info kernel: [1219237.977991] davinci_emac davinci_emac.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Aug 17 05:45:18 ccgx user.info kernel: [1219237.978136] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Aug 17 05:45:18 ccgx daemon.warn connmand[773]: Skipping disconnect of carrier, network is connecting.
Aug 17 05:45:18 ccgx daemon.info connmand[773]: Setting hostname to ccgx
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} address 192.168.13.193/24 label eth0 family 2
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 192.168.13.0 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 192.168.13.254 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 0.0.0.0 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:18 ccgx daemon.info dnsmasq[744]: read /etc/hosts - 6 addresses
Aug 17 05:45:18 ccgx daemon.info dnsmasq[744]: using nameserver 192.168.13.254#53
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 212.227.81.55 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:19 ccgx daemon.info connmand[773]: eth0 {del} route 212.227.81.55 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:32 ccgx syslog.info syslogd started: BusyBox v1.24.1
Aug 17 05:45:32 ccgx user.notice kernel: klogd started: BusyBox v1.24.1 (2018-08-15 16:01:30 CEST)
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Booting Linux on physical CPU 0
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000] Linux version 3.7.1 (oe-user@oe-host) (gcc version 7.3.0 (GCC) ) #1 Wed Aug 15 16:02:10 CEST 2018

For comparison a normal reboot sequence:

Aug 16 02:28:58 ccgx cron.info CROND[13930]: (root) CMDOUT (do_swupdate completed OK. Rebooting)
Aug 16 02:28:58 ccgx user.notice shutdown[17431]: shutting down for system reboot
Aug 16 02:28:58 ccgx daemon.info init: Switching to runlevel: 6
Aug 16 02:28:59 ccgx daemon.err connmand[1128]: D-Bus disconnect
Aug 16 02:29:00 ccgx daemon.err connmand[1128]: Time request for server 10.220.1.1 failed (101/Network is unreachable)
Aug 16 02:29:00 ccgx daemon.err connmand[1128]: Time request for server 10.220.1.1 failed (101/Network is unreachable)
Aug 16 02:29:00 ccgx daemon.info connmand[1128]: Remove interface eth0 [ ethernet ]
Aug 16 02:29:00 ccgx daemon.info connmand[1128]: eth0 {remove} index 4
Aug 16 02:29:00 ccgx daemon.info connmand[1128]: Exit
Aug 16 02:29:00 ccgx daemon.info dnsmasq[1099]: exiting on receipt of SIGTERM
Aug 16 02:29:00 ccgx user.info connmand_watch: no longer restarting the connmand process
Aug 16 02:29:00 ccgx syslog.info syslogd exiting
Aug 16 02:29:25 ccgx syslog.info syslogd started: BusyBox v1.24.1
Aug 16 02:29:25 ccgx user.notice kernel: klogd started: BusyBox v1.24.1 (2018-08-15 16:01:30 CEST)
Aug 16 02:29:25 ccgx user.info kernel: [    0.000000] Booting Linux on physical CPU 0

And then there are some other files, /data/dmesg and /data/boot, which don't contain the boot one would expect after the restart initiated at 02:32.

ls
 1305 Aug 17 05:45 boot      <- has data timestamped Fri Aug  3 03:04:33 2018 (??)
 1302 Jul 31 05:00 boot~     <- has data timestamped Tue Jul 31 04:59:57 2018
14158 Aug 17 05:45 dmesg     <- shows booting 3.7.1, incl. rtc 2018-08-17 05:45:24 UTC 
17783 Aug  3 03:04 dmesg.old <- shows booting 4.9.113, incl. rtc 2018-08-03 03:04:25 UTC

vrmlogger shows what it always shows during a restart, except for the 2 hour and a few minutes gap ofcourse:

2018-08-17 02:32:09.939582500 MainThread-dbusmonitor: com.victronenergy.battery.socketcan_can0 disappeared from the dbus. Removing it from our lists
2018-08-17 05:45:34.562622500 *** CCGX booted (1) ***

gui log is empty around that time:

2018-08-16 06:27:58.866263500 QVNCServer disconnected from "127.0.0.1" 
2018-08-17 05:45:34.408355500 *** CCGX booted (1) ***

Customer email


Hello Matthijs,

One of my local customers who is kind enough to be guinea pig for me, and who is running on release candidates, had their CCGX hang today.

By ‘hang’ I mean the system dropped off of the network (e.g. VRM) while the customer was out of their house.

When the customer came home - about 3 hours after the system dropped off of VRM logging - he found the CCGX was unresponsive (screen dark, no response to keypresses).

The system is set to turn its display off when idle so the black screen is normal - but clearly the hard hang isn’t.

I dropped by his place (I happened to be nearby) and popped the unit off of the wall, observed it still had power (led’s let on the ethernet port), so I tried a forced restart (both round buttons pressed and released).

The system rebooted perfectly happily in response to that hard reset - and it is running again right now.

I guess it could be a hardware issue, but clearly because its running 2.20~50 I thought it best to report it to you as a potential release candidate bug. Its not had any history of such things until now - its always worked perfectly well, no history of just ‘stopping’ like this in the past.

This is the system:

https://vrm.victronenergy.com/installation/14404/diagnostics

2 x VEDirect MPPT, 2 x MultiGrid-I, grid interactive, ESS system

Kind Regards, Simon


Log files

2018-08-17 02:05:01.488455500 *** Checking for updates ***
2018-08-17 02:05:01.494811500 arguments: -auto -delay
2018-08-17 02:05:01.583617500 Sleeping for 1458 seconds
2018-08-17 02:29:19.737858500 Retrieving latest version (feed=candidate)...
2018-08-17 02:29:23.191965500 installed: 20180802165149 v2.20~48
2018-08-17 02:29:23.195594500 available: 20180815135911 v2.20~50
2018-08-17 02:29:23.255765500 Starting swupdate to install version 20180815135911 v2.20~50 ...
2018-08-17 02:29:23.376800500 software set: stable mode: copy1
2018-08-17 02:29:24.390061500 Swupdate v2016.10.0
2018-08-17 02:29:24.390078500 
2018-08-17 02:29:24.390082500 Licensed under GPLv2. See source distribution for detailed copyright notices.
2018-08-17 02:29:24.390089500 
2018-08-17 02:29:24.390093500 Searching for custom LUA handlers :[string "require ("swupdate_handlers")"]:1: module 'swupdate_handlers' not found:
2018-08-17 02:29:24.390102500 	no field package.preload['swupdate_handlers']
2018-08-17 02:29:24.390107500 	no file '/usr/share/lua/5.3/swupdate_handlers.lua'
2018-08-17 02:29:24.390113500 	no file '/usr/share/lua/5.3/swupdate_handlers/init.lua'
2018-08-17 02:29:24.391284500 	no file '/usr/lib/lua/5.3/swupdate_handlers.lua'
2018-08-17 02:29:24.391294500 	no file '/usr/lib/lua/5.3/swupdate_handlers/init.lua'
2018-08-17 02:29:24.391300500 	no file './swupdate_handlers.lua'
2018-08-17 02:29:24.391305500 	no file './swupdate_handlers/init.lua'
2018-08-17 02:29:24.391310500 	no file '/usr/lib/lua/5.3/swupdate_handlers.so'
2018-08-17 02:29:24.391316500 	no file '/usr/lib/lua/5.3/loadall.so'
2018-08-17 02:29:24.391321500 	no file './swupdate_handlers.so'
2018-08-17 02:29:24.392174500 Custom handlers not found, no error, skipping...
2018-08-17 02:29:24.392181500 
2018-08-17 02:29:24.392184500 Registered handlers:
2018-08-17 02:29:24.392189500 	archive
2018-08-17 02:29:24.392193500 	tar
2018-08-17 02:29:24.443211500 	flash
2018-08-17 02:29:24.447853500 	flash-hamming1
2018-08-17 02:29:24.447861500 	raw
2018-08-17 02:29:24.447864500 	rawfile
2018-08-17 02:29:24.447868500 	ubivol
2018-08-17 02:29:24.447872500 	ubipartition
2018-08-17 02:29:24.447876500 	lua
2018-08-17 02:29:24.447880500 	shellscript
2018-08-17 02:29:24.447884500 	preinstall
2018-08-17 02:29:24.447888500 	postinstall
2018-08-17 02:29:24.447892500 	uboot
2018-08-17 02:29:24.447896500 Main loop Daemon
2018-08-17 02:29:24.447900500 [NOTIFY] : SWUPDATE running :  [network_thread] : Incoming network request: processing...
2018-08-17 02:29:24.448757500 [NOTIFY] : SWUPDATE started :  Software Update started !
2018-08-17 02:29:24.448764500 [NOTIFY] : SWUPDATE downloading :  
2018-08-17 02:29:24.448769500 [NOTIFY] : SWUPDATE running :  [download_from_url] : Image download started : https://updates.victronenergy.com/feeds/venus/candidate/images/ccgx/venus-swu-ccgx-20180815135911-v2.20~50.swu
2018-08-17 02:29:24.488203500 scan_for_ubi_devices
2018-08-17 02:29:24.488217500 [NOTIFY] : SWUPDATE running :  [scan_ubi_volumes] : mtd12:	Volume found : 	rootfs1
2018-08-17 02:29:24.495898500 [NOTIFY] : SWUPDATE running :  [scan_ubi_volumes] : mtd12:	Volume found : 	rootfs2
2018-08-17 02:29:24.514222500 [NOTIFY] : SWUPDATE running :  [scan_ubi_volumes] : mtd12:	Volume found : 	data
2018-08-17 02:29:25.719651500 [NOTIFY] : SWUPDATE running :  [download_info] : Received : 0 / 0
2018-08-17 02:29:27.013072500 [NOTIFY] : SWUPDATE running :  [download_info] : Received : 0 / 0
2018-08-17 02:29:27.769987500 [NOTIFY] : SWUPDATE running :  [extract_file_to_tmp] : Found file:
2018-08-17 02:29:27.770004500 	filename sw-description
2018-08-17 02:29:27.770009500 	size 2223
2018-08-17 02:29:27.782928500 Version 0.1.0
2018-08-17 02:29:27.782941500 [NOTIFY] : SWUPDATE running :  [parse_images] : Found Image  : venus-image-ccgx.ubifs in volume : rootfs1 for handler ubivol (installed from stream) 
2018-08-17 02:29:27.782953500 
2018-08-17 02:29:27.794961500 [NOTIFY] : SWUPDATE running :  [parse_images] : Found Image  : uImage in device : /dev/mtd10 for handler flash 
2018-08-17 02:29:27.794980500 
2018-08-17 02:29:27.806858500 [NOTIFY] : SWUPDATE running :  [parse_uboot] : U-Boot var: nandboot = mii write 0 0 8000; nand read ${loadaddr} ${kernel} && bootm ${loadaddr}
2018-08-17 02:29:30.054617500 
2018-08-17 02:29:30.054630500 [NOTIFY] : SWUPDATE running :  [parse_uboot] : U-Boot var: miscargs = omapdss.def_disp=lcd omapfb.vram=0:2M@0x8fe00000 fbskip
2018-08-17 02:29:30.054641500 
2018-08-17 02:29:30.054644500 [NOTIFY] : SWUPDATE running :  [parse_uboot] : U-Boot var: version = 1
2018-08-17 02:29:30.054651500 
2018-08-17 02:29:30.054655500 [NOTIFY] : SWUPDATE running :  [extract_files] : Found file:
2018-08-17 02:29:30.054662500 	filename venus-image-ccgx.ubifs
2018-08-17 02:29:30.054667500 	size 102961152 required
2018-08-17 02:29:30.059394500 [NOTIFY] : SWUPDATE running :  [extract_files] : Installing STREAM venus-image-ccgx.ubifs, 102961152 bytes
2018-08-17 02:29:30.059408500 
2018-08-17 02:29:30.059412500 [NOTIFY] : SWUPDATE running :  [install_single_image] : Found installer for stream venus-image-ccgx.ubifs ubivol
2018-08-17 02:29:30.059421500 [NOTIFY] : SWUPDATE running :  [download_info] : Received : 32497 / 106672808
2018-08-17 02:29:30.079884500 [NOTIFY] : SWUPDATE running :  Installing image venus-image-ccgx.ubifs into volume /dev/ubi0_0(rootfs1)
2018-08-17 02:29:30.079902500 [NOTIFY] : SWUPDATE running :  [update_volume] : Updating UBI : venus-image-ccgx.ubifs 102961152
2018-08-17 02:29:30.079911500 
2018-08-17 02:29:30.079914500 [NOTIFY] : SWUPDATE running :  [download_info] : Received : 179953 / 106672808
.....
2018-08-17 02:32:05.947419500 [NOTIFY] : SWUPDATE running :  [download_info] : Received : 105594609 / 106672808
2018-08-17 02:32:05.978374500 [NOTIFY] : SWUPDATE running :  [extract_files] : Found file:
2018-08-17 02:32:05.978392500 	filename u-boot.img
2018-08-17 02:32:05.978397500 	size 465456 Not required: skipping
2018-08-17 02:32:06.413547500 [NOTIFY] : SWUPDATE running :  [extract_files] : Found file:
2018-08-17 02:32:06.413565500 	filename MLO
2018-08-17 02:32:06.413570500 	size 41616 Not required: skipping
2018-08-17 02:32:06.451943500 [NOTIFY] : SWUPDATE running :  [extract_files] : Found file:
2018-08-17 02:32:06.451962500 	filename splash.bgra
2018-08-17 02:32:06.451967500 	size 522240 Not required: skipping
2018-08-17 02:32:06.879210500 [NOTIFY] : SWUPDATE running :  [network_initializer] : Valid image found: copying to FLASH
2018-08-17 02:32:07.026354500 [NOTIFY] : SWUPDATE running :  [download_from_url] : Success : 106672808 bytes
2018-08-17 02:32:07.183192500 [NOTIFY] : SWUPDATE running :  Installation in progress
2018-08-17 02:32:07.194810500 [NOTIFY] : SWUPDATE running :  [install_single_image] : Found installer for stream uImage flash
2018-08-17 02:32:07.422741500 [NOTIFY] : SWUPDATE running :  [install_flash_image] : Copying uImage into /dev/mtd10
2018-08-17 02:32:08.308898500 [NOTIFY] : SWUPDATE running :  [update_uboot_env] : Updating U-boot environment
2018-08-17 02:32:08.447105500 [NOTIFY] : SWUPDATE successful ! SWUPDATE successful !
2018-08-17 02:32:08.452059500 [NOTIFY] : SWUPDATE running :  [network_initializer] : Main thread sleep again !
2018-08-17 02:32:08.454655500 [NOTIFY] : No SWUPDATE running :  Waiting for requests...
2018-08-17 02:32:09.290407500 Main loop Daemon
2018-08-17 02:32:09.309242500 do_swupdate completed OK. Rebooting
... note the time gap here ...
2018-08-17 05:45:34.519653500 *** CCGX booted (1) ***
2018-08-17 05:50:54.050812500 *** Checking for updates ***
2018-08-17 05:50:54.050812500 arguments: -auto
2018-08-17 05:50:54.211579500 Retrieving latest version (feed=candidate)...
2018-08-17 05:50:57.428406500 installed: 20180815135911 v2.20~50
2018-08-17 05:50:57.431153500 available: 20180815135911 v2.20~50
2018-08-17 05:50:57.431153500 No newer version available, exit.
root@ccgx:~# cat /log/messages
Aug 14 23:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.085385 s
Aug 15 01:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.103678 s
Aug 15 02:05:01 ccgx cron.info CROND[31360]: (root) CMD (/opt/victronenergy/swupdate-scripts/check-updates.sh -auto -delay)
Aug 15 02:05:01 ccgx cron.info CROND[31359]: (root) CMDOUT (*** Checking for updates ***)
Aug 15 02:05:01 ccgx cron.info CROND[31359]: (root) CMDOUT (arguments: -auto -delay)
Aug 15 02:05:02 ccgx cron.info CROND[31359]: (root) CMDOUT (Sleeping for 3248 seconds)
Aug 15 02:59:10 ccgx cron.info CROND[31359]: (root) CMDOUT (Retrieving latest version (feed=candidate)...)
Aug 15 02:59:13 ccgx cron.info CROND[31359]: (root) CMDOUT (installed: 20180802165149 v2.20~48)
Aug 15 02:59:13 ccgx cron.info CROND[31359]: (root) CMDOUT (available: 20180802165149 v2.20~48)
Aug 15 02:59:13 ccgx cron.info CROND[31359]: (root) CMDOUT (No newer version available, exit.)
Aug 15 03:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.092989 s
Aug 15 05:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.079134 s
Aug 15 07:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.116561 s
Aug 15 09:05:08 ccgx daemon.info connmand[773]: ntp: time slew +0.093282 s
Aug 15 11:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.084733 s
Aug 15 13:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.099176 s
Aug 15 15:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.105400 s
Aug 15 17:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.080356 s
Aug 15 19:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.085681 s
Aug 15 21:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.121796 s
Aug 15 23:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.080338 s
Aug 16 01:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.093033 s
Aug 16 02:05:01 ccgx cron.info CROND[28985]: (root) CMD (/opt/victronenergy/swupdate-scripts/check-updates.sh -auto -delay)
Aug 16 02:05:01 ccgx cron.info CROND[28984]: (root) CMDOUT (*** Checking for updates ***)
Aug 16 02:05:01 ccgx cron.info CROND[28984]: (root) CMDOUT (arguments: -auto -delay)
Aug 16 02:05:02 ccgx cron.info CROND[28984]: (root) CMDOUT (Sleeping for 1296 seconds)
Aug 16 02:26:38 ccgx cron.info CROND[28984]: (root) CMDOUT (Retrieving latest version (feed=candidate)...)
Aug 16 02:26:41 ccgx cron.info CROND[28984]: (root) CMDOUT (installed: 20180802165149 v2.20~48)
Aug 16 02:26:41 ccgx cron.info CROND[28984]: (root) CMDOUT (available: 20180802165149 v2.20~48)
Aug 16 02:26:41 ccgx cron.info CROND[28984]: (root) CMDOUT (No newer version available, exit.)
Aug 16 03:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.098687 s
Aug 16 05:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.094799 s
Aug 16 07:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.089612 s
Aug 16 09:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.084704 s
Aug 16 11:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.109883 s
Aug 16 13:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.075174 s
Aug 16 15:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.114757 s
Aug 16 17:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.088253 s
Aug 16 19:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.084790 s
Aug 16 21:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.106849 s
Aug 16 23:05:08 ccgx daemon.info connmand[773]: ntp: time slew +0.094142 s
Aug 17 01:05:10 ccgx daemon.info connmand[773]: ntp: time slew +0.095013 s
Aug 17 02:05:01 ccgx cron.info CROND[22735]: (root) CMD (/opt/victronenergy/swupdate-scripts/check-updates.sh -auto -delay)
Aug 17 02:05:01 ccgx cron.info CROND[22734]: (root) CMDOUT (*** Checking for updates ***)
Aug 17 02:05:01 ccgx cron.info CROND[22734]: (root) CMDOUT (arguments: -auto -delay)
Aug 17 02:05:01 ccgx cron.info CROND[22734]: (root) CMDOUT (Sleeping for 1458 seconds)
Aug 17 02:29:19 ccgx cron.info CROND[22734]: (root) CMDOUT (Retrieving latest version (feed=candidate)...)
Aug 17 02:29:23 ccgx cron.info CROND[22734]: (root) CMDOUT (installed: 20180802165149 v2.20~48)
Aug 17 02:29:23 ccgx cron.info CROND[22734]: (root) CMDOUT (available: 20180815135911 v2.20~50)
Aug 17 02:29:23 ccgx cron.info CROND[22734]: (root) CMDOUT (Starting swupdate to install version 20180815135911 v2.20~50 ...)
Aug 17 02:29:23 ccgx cron.info CROND[22734]: (root) CMDOUT (software set: stable mode: copy1)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (Swupdate v2016.10.0)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (Licensed under GPLv2. See source distribution for detailed copyright notices.)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (Searching for custom LUA handlers :[string "require ("swupdate_handlers")"]:1: module 'swupdate_handlers' not found:)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no field package.preload['swupdate_handlers'])
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file '/usr/share/lua/5.3/swupdate_handlers.lua')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file '/usr/share/lua/5.3/swupdate_handlers/init.lua')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file '/usr/lib/lua/5.3/swupdate_handlers.lua')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file '/usr/lib/lua/5.3/swupdate_handlers/init.lua')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file './swupdate_handlers.lua')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file './swupdate_handlers/init.lua')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file '/usr/lib/lua/5.3/swupdate_handlers.so')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file '/usr/lib/lua/5.3/loadall.so')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	no file './swupdate_handlers.so')
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (Custom handlers not found, no error, skipping...)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (Registered handlers:)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	archive)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	tar)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	flash)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	flash-hamming1)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	raw)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	rawfile)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	ubivol)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	ubipartition)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	lua)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	shellscript)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	preinstall)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	postinstall)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (	uboot)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (Main loop Daemon)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [network_thread] : Incoming network request: processing...)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE started :  Software Update started !)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE downloading :  )
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_from_url] : Image download started : https://updates.victronenergy.com/feeds/venus/candidate/images/ccgx/venus-swu-ccgx-20180815135911-v2.20~50.swu)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT (scan_for_ubi_devices)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [scan_ubi_volumes] : mtd12:	Volume found : 	rootfs1)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [scan_ubi_volumes] : mtd12:	Volume found : 	rootfs2)
Aug 17 02:29:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [scan_ubi_volumes] : mtd12:	Volume found : 	data)
Aug 17 02:29:25 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 0 / 0)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 0 / 0)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_file_to_tmp] : Found file:)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT (	filename sw-description)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT (	size 2223)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT (Version 0.1.0)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [parse_images] : Found Image  : venus-image-ccgx.ubifs in volume : rootfs1 for handler ubivol (installed from stream) )
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [parse_images] : Found Image  : uImage in device : /dev/mtd10 for handler flash )
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [parse_uboot] : U-Boot var: nandboot = mii write 0 0 8000; nand read ${loadaddr} ${kernel} && bootm ${loadaddr})
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [parse_uboot] : U-Boot var: miscargs = omapdss.def_disp=lcd omapfb.vram=0:2M@0x8fe00000 fbskip)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [parse_uboot] : U-Boot var: version = 1)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : Found file:)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT (	filename venus-image-ccgx.ubifs)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT (	size 102961152 required)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : Installing STREAM venus-image-ccgx.ubifs, 102961152 bytes)
Aug 17 02:29:27 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:28 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [install_single_image] : Found installer for stream venus-image-ccgx.ubifs ubivol)
Aug 17 02:29:28 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 32497 / 106672808)
Aug 17 02:29:30 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  Installing image venus-image-ccgx.ubifs into volume /dev/ubi0_0(rootfs1))
Aug 17 02:29:30 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [update_volume] : Updating UBI : venus-image-ccgx.ubifs 102961152)
Aug 17 02:29:30 ccgx cron.info CROND[22734]: (root) CMDOUT ()
Aug 17 02:29:30 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 179953 / 106672808)
Aug 17 02:29:31 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 589553 / 106672808)
Aug 17 02:29:32 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 868081 / 106672808)
Aug 17 02:29:33 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 1031921 / 106672808)
Aug 17 02:29:34 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 1228529 / 106672808)
Aug 17 02:29:35 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 1474289 / 106672808)
Aug 17 02:29:36 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 1720049 / 106672808)
Aug 17 02:29:37 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 1965809 / 106672808)
Aug 17 02:29:38 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 2260721 / 106672808)
Aug 17 02:29:39 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 2604785 / 106672808)
Aug 17 02:29:40 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 3047153 / 106672808)
Aug 17 02:29:41 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 3636977 / 106672808)
Aug 17 02:29:42 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 4226801 / 106672808)
Aug 17 02:29:43 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 5111537 / 106672808)
Aug 17 02:29:44 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 5914353 / 106672808)
Aug 17 02:29:45 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 6225649 / 106672808)
Aug 17 02:29:46 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 6569713 / 106672808)
Aug 17 02:29:47 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 7274225 / 106672808)
Aug 17 02:29:48 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 7749361 / 106672808)
Aug 17 02:29:49 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 8224497 / 106672808)
Aug 17 02:29:50 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 8716017 / 106672808)
Aug 17 02:29:51 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 9191153 / 106672808)
Aug 17 02:29:52 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 9666289 / 106672808)
Aug 17 02:29:53 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 10190577 / 106672808)
Aug 17 02:29:54 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 10747633 / 106672808)
Aug 17 02:29:55 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 11304689 / 106672808)
Aug 17 02:29:56 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 11796209 / 106672808)
Aug 17 02:29:57 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 12287729 / 106672808)
Aug 17 02:29:58 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 12828401 / 106672808)
Aug 17 02:29:59 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 13549297 / 106672808)
Aug 17 02:30:00 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 14171889 / 106672808)
Aug 17 02:30:01 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 14794481 / 106672808)
Aug 17 02:30:02 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 15449841 / 106672808)
Aug 17 02:30:03 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 16154353 / 106672808)
Aug 17 02:30:04 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 16809713 / 106672808)
Aug 17 02:30:05 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 17546993 / 106672808)
Aug 17 02:30:06 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 18005745 / 106672808)
Aug 17 02:30:07 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 18661105 / 106672808)
Aug 17 02:30:08 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 19496689 / 106672808)
Aug 17 02:30:09 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 20250353 / 106672808)
Aug 17 02:30:10 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 20971249 / 106672808)
Aug 17 02:30:11 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 21888753 / 106672808)
Aug 17 02:30:12 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 22707953 / 106672808)
Aug 17 02:30:13 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 23379697 / 106672808)
Aug 17 02:30:14 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 24379121 / 106672808)
Aug 17 02:30:15 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 25247473 / 106672808)
Aug 17 02:30:16 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 25853681 / 106672808)
Aug 17 02:30:17 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 27098865 / 106672808)
Aug 17 02:30:18 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 27901681 / 106672808)
Aug 17 02:30:19 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 28704497 / 106672808)
Aug 17 02:30:20 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 29720305 / 106672808)
Aug 17 02:30:21 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 30605041 / 106672808)
Aug 17 02:30:22 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 31424241 / 106672808)
Aug 17 02:30:23 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 32603889 / 106672808)
Aug 17 02:30:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 33488625 / 106672808)
Aug 17 02:30:25 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 34193137 / 106672808)
Aug 17 02:30:26 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 35192561 / 106672808)
Aug 17 02:30:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 36011761 / 106672808)
Aug 17 02:30:28 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 36929265 / 106672808)
Aug 17 02:30:29 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 37797617 / 106672808)
Aug 17 02:30:30 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 38731505 / 106672808)
Aug 17 02:30:31 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 39354097 / 106672808)
Aug 17 02:30:32 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 40517361 / 106672808)
Aug 17 02:30:33 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 41139953 / 106672808)
Aug 17 02:30:34 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 41893617 / 106672808)
Aug 17 02:30:35 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 42319601 / 106672808)
Aug 17 02:30:36 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 42942193 / 106672808)
Aug 17 02:30:37 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 43400945 / 106672808)
Aug 17 02:30:38 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 43908849 / 106672808)
Aug 17 02:30:39 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 44433137 / 106672808)
Aug 17 02:30:40 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 44924657 / 106672808)
Aug 17 02:30:41 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 45465329 / 106672808)
Aug 17 02:30:42 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 46022385 / 106672808)
Aug 17 02:30:43 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 46546673 / 106672808)
Aug 17 02:30:44 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 47103729 / 106672808)
Aug 17 02:30:45 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 47742705 / 106672808)
Aug 17 02:30:46 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 48365297 / 106672808)
Aug 17 02:30:47 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 49151729 / 106672808)
Aug 17 02:30:48 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 49659633 / 106672808)
Aug 17 02:30:49 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 50216689 / 106672808)
Aug 17 02:30:50 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 50790129 / 106672808)
Aug 17 02:30:51 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 51379953 / 106672808)
Aug 17 02:30:52 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 51953393 / 106672808)
Aug 17 02:30:53 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 52461297 / 106672808)
Aug 17 02:30:54 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 53018353 / 106672808)
Aug 17 02:30:55 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 53690097 / 106672808)
Aug 17 02:30:56 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 54361841 / 106672808)
Aug 17 02:30:57 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 55230193 / 106672808)
Aug 17 02:30:58 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 55770865 / 106672808)
Aug 17 02:30:59 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 56753905 / 106672808)
Aug 17 02:31:00 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 57474801 / 106672808)
Aug 17 02:31:01 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 58228465 / 106672808)
Aug 17 02:31:03 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 59227889 / 106672808)
Aug 17 02:31:04 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 60276465 / 106672808)
Aug 17 02:31:05 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 61226737 / 106672808)
Aug 17 02:31:06 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 62340849 / 106672808)
Aug 17 02:31:07 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 62897905 / 106672808)
Aug 17 02:31:08 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 63717105 / 106672808)
Aug 17 02:31:09 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 64896753 / 106672808)
Aug 17 02:31:10 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 65404657 / 106672808)
Aug 17 02:31:11 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 66060017 / 106672808)
Aug 17 02:31:12 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 66813681 / 106672808)
Aug 17 02:31:13 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 67354353 / 106672808)
Aug 17 02:31:14 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 68026097 / 106672808)
Aug 17 02:31:15 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 68566769 / 106672808)
Aug 17 02:31:16 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 69091057 / 106672808)
Aug 17 02:31:17 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 69680881 / 106672808)
Aug 17 02:31:18 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 70352625 / 106672808)
Aug 17 02:31:19 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 70958833 / 106672808)
Aug 17 02:31:20 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 71712497 / 106672808)
Aug 17 02:31:21 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 72154865 / 106672808)
Aug 17 02:31:22 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 72793841 / 106672808)
Aug 17 02:31:23 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 73416433 / 106672808)
Aug 17 02:31:24 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 74186481 / 106672808)
Aug 17 02:31:25 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 74579697 / 106672808)
Aug 17 02:31:26 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 75513585 / 106672808)
Aug 17 02:31:27 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 76185329 / 106672808)
Aug 17 02:31:28 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 76791537 / 106672808)
Aug 17 02:31:29 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 77414129 / 106672808)
Aug 17 02:31:30 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 77971185 / 106672808)
Aug 17 02:31:31 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 78561009 / 106672808)
Aug 17 02:31:32 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 79118065 / 106672808)
Aug 17 02:31:33 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 79691505 / 106672808)
Aug 17 02:31:34 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 80379633 / 106672808)
Aug 17 02:31:35 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 81051377 / 106672808)
Aug 17 02:31:36 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 81755889 / 106672808)
Aug 17 02:31:37 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 82296561 / 106672808)
Aug 17 02:31:38 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 83197681 / 106672808)
Aug 17 02:31:39 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 84033265 / 106672808)
Aug 17 02:31:40 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 84737777 / 106672808)
Aug 17 02:31:41 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 85982961 / 106672808)
Aug 17 02:31:42 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 86966001 / 106672808)
Aug 17 02:31:43 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 87654129 / 106672808)
Aug 17 02:31:44 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 89177841 / 106672808)
Aug 17 02:31:45 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 90078961 / 106672808)
Aug 17 02:31:46 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 91143921 / 106672808)
Aug 17 02:31:47 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 92290801 / 106672808)
Aug 17 02:31:48 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 93241073 / 106672808)
Aug 17 02:31:49 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 94240497 / 106672808)
Aug 17 02:31:50 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 95108849 / 106672808)
Aug 17 02:31:51 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 96091889 / 106672808)
Aug 17 02:31:52 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 96960241 / 106672808)
Aug 17 02:31:53 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 97402609 / 106672808)
Aug 17 02:31:54 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 98156273 / 106672808)
Aug 17 02:31:55 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 98729713 / 106672808)
Aug 17 02:31:56 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 99335921 / 106672808)
Aug 17 02:31:57 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 99958513 / 106672808)
Aug 17 02:31:58 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 100564721 / 106672808)
Aug 17 02:31:59 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 101138161 / 106672808)
Aug 17 02:32:00 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 101793521 / 106672808)
Aug 17 02:32:01 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 102366961 / 106672808)
Aug 17 02:32:02 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : END INSTALLING STREAMING)
Aug 17 02:32:02 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : Found file:)
Aug 17 02:32:02 ccgx cron.info CROND[22734]: (root) CMDOUT (	filename uImage)
Aug 17 02:32:02 ccgx cron.info CROND[22734]: (root) CMDOUT (	size 2679248 required)
Aug 17 02:32:02 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 103038705 / 106672808)
Aug 17 02:32:03 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 103808753 / 106672808)
Aug 17 02:32:04 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 104595185 / 106672808)
Aug 17 02:32:05 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_info] : Received : 105594609 / 106672808)
Aug 17 02:32:05 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : Found file:)
Aug 17 02:32:05 ccgx cron.info CROND[22734]: (root) CMDOUT (	filename u-boot.img)
Aug 17 02:32:05 ccgx cron.info CROND[22734]: (root) CMDOUT (	size 465456 Not required: skipping)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : Found file:)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT (	filename MLO)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT (	size 41616 Not required: skipping)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [extract_files] : Found file:)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT (	filename splash.bgra)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT (	size 522240 Not required: skipping)
Aug 17 02:32:06 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [network_initializer] : Valid image found: copying to FLASH)
Aug 17 02:32:07 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [download_from_url] : Success : 106672808 bytes)
Aug 17 02:32:07 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  Installation in progress)
Aug 17 02:32:07 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [install_single_image] : Found installer for stream uImage flash)
Aug 17 02:32:07 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [install_flash_image] : Copying uImage into /dev/mtd10)
Aug 17 02:32:08 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [update_uboot_env] : Updating U-boot environment)
Aug 17 02:32:08 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE successful ! SWUPDATE successful !)
Aug 17 02:32:08 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : SWUPDATE running :  [network_initializer] : Main thread sleep again !)
Aug 17 02:32:08 ccgx cron.info CROND[22734]: (root) CMDOUT ([NOTIFY] : No SWUPDATE running :  Waiting for requests...)
Aug 17 02:32:09 ccgx cron.info CROND[22734]: (root) CMDOUT (Main loop Daemon)
Aug 17 02:32:09 ccgx cron.info CROND[22734]: (root) CMDOUT (do_swupdate completed OK. Rebooting)
Aug 17 02:32:09 ccgx user.notice shutdown[22769]: shutting down for system reboot
Aug 17 02:32:09 ccgx daemon.info init: Switching to runlevel: 6
Aug 17 03:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.093024 s
Aug 17 05:05:09 ccgx daemon.info connmand[773]: ntp: time slew +0.082232 s
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {RX} 2615697 packets 490054135 bytes
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {TX} 3833972 packets 7731968 bytes
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {update} flags 4099 <UP>
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 address 68:9E:19:7A:7A:4A mtu 1500
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 operstate 2 <DOWN>
Aug 17 05:45:16 ccgx user.info kernel: [1219235.927842] davinci_emac davinci_emac.0 eth0: Link is Down
Aug 17 05:45:16 ccgx daemon.err connmand[773]: Time request for server 192.168.13.254 failed (101/Network is unreachable)
Aug 17 05:45:16 ccgx daemon.err connmand[773]: Time request for server 192.168.13.254 failed (101/Network is unreachable)
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} address 192.168.13.193/24 label eth0
Aug 17 05:45:16 ccgx user.info kernel: [1219235.980901] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} route 192.168.13.0 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} route fe80:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:16 ccgx daemon.info connmand[773]: eth0 {del} route ff00:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:16 ccgx daemon.info dnsmasq[744]: read /etc/hosts - 6 addresses
Aug 17 05:45:16 ccgx daemon.err dnsmasq[744]: failed to read /run/resolv.conf: No such file or directory
Aug 17 05:45:16 ccgx daemon.info dnsmasq[744]: using nameserver 192.168.13.254#53
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route ff00:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route fe80:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {RX} 2615697 packets 490054135 bytes
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {TX} 3833972 packets 7731968 bytes
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {update} flags 69699 <UP,RUNNING,LOWER_UP>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 address 68:9E:19:7A:7A:4A mtu 1500
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {newlink} index 3 operstate 6 <UP>
Aug 17 05:45:18 ccgx user.info kernel: [1219237.977991] davinci_emac davinci_emac.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Aug 17 05:45:18 ccgx user.info kernel: [1219237.978136] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Aug 17 05:45:18 ccgx daemon.warn connmand[773]: Skipping disconnect of carrier, network is connecting.
Aug 17 05:45:18 ccgx daemon.info connmand[773]: Setting hostname to ccgx
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} address 192.168.13.193/24 label eth0 family 2
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 192.168.13.0 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 192.168.13.254 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 0.0.0.0 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:18 ccgx daemon.info dnsmasq[744]: read /etc/hosts - 6 addresses
Aug 17 05:45:18 ccgx daemon.info dnsmasq[744]: using nameserver 192.168.13.254#53
Aug 17 05:45:18 ccgx daemon.info connmand[773]: eth0 {add} route 212.227.81.55 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:19 ccgx daemon.info connmand[773]: eth0 {del} route 212.227.81.55 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:32 ccgx syslog.info syslogd started: BusyBox v1.24.1
Aug 17 05:45:32 ccgx user.notice kernel: klogd started: BusyBox v1.24.1 (2018-08-15 16:01:30 CEST)
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Booting Linux on physical CPU 0
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000] Linux version 3.7.1 (oe-user@oe-host) (gcc version 7.3.0 (GCC) ) #1 Wed Aug 15 16:02:10 CEST 2018
Aug 17 05:45:32 ccgx user.warn kernel: [    0.000000] CPU: ARMv7 Processor [411fc087] revision 7 (ARMv7), cr=10c53c7d
Aug 17 05:45:32 ccgx user.warn kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
Aug 17 05:45:32 ccgx user.warn kernel: [    0.000000] Machine: Victron BPP3
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Reserving 2097152 bytes SDRAM for VRAM
Aug 17 05:45:32 ccgx user.warn kernel: [    0.000000] Memory policy: ECC disabled, Data cache writeback
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000] On node 0 totalpages: 64768
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000] free_area_init_node: node 0, pgdat c050e5e0, node_mem_map c0535000
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000]   Normal zone: 512 pages used for memmap
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000]   Normal zone: 64256 pages, LIFO batch:15
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] AM3517 ES1.1 (l2cache sgx neon )
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/332/600 MHz
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Aug 17 05:45:32 ccgx user.debug kernel: [    0.000000] pcpu-alloc: [0] 0 
Aug 17 05:45:32 ccgx user.warn kernel: [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 64256
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000] Kernel command line: root=ubi0:rootfs1 rootfstype=ubifs ubi.mtd=12 omapdss.def_disp=lcd omapfb.vram=0:2M@0x8fe00000 fbskip mtdparts=omap2-nand.0:128k(spl1),128k(spl2),128k(spl3),128k(spl4),1m(u-boot),256k(env1),2
Aug 17 05:45:32 ccgx daemon.info dnsmasq[1290]: started, version 2.78 cachesize 150
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
Aug 17 05:45:32 ccgx daemon.warn dnsmasq[1290]: overflow: 4 log entries lost
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
Aug 17 05:45:32 ccgx daemon.err dnsmasq[1290]: failed to read /run/resolv.conf: No such file or directory
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Memory: 253MB = 253MB total
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000] Memory: 251444k/251444k available, 10700k reserved, 0K highmem
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000] Virtual kernel memory layout:
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]     vmalloc : 0xd0800000 - 0xff000000   ( 744 MB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]     lowmem  : 0xc0000000 - 0xd0000000   ( 256 MB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]       .text : 0xc0008000 - 0xc04a95e4   (4742 kB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]       .init : 0xc04aa000 - 0xc04d5cc0   ( 176 kB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]       .data : 0xc04d6000 - 0xc050f900   ( 231 kB)
Aug 17 05:45:32 ccgx user.notice kernel: [    0.000000]        .bss : 0xc050f924 - 0xc0534b5c   ( 149 kB)
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] NR_IRQS:16 nr_irqs:16 16
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 4.0) with 96 interrupts
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Total of 96 interrupts on 1 active controller
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] OMAP clockevent source: GPTIMER1 at 32768 Hz
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 131071999ms
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] Console: colour dummy device 80x30
Aug 17 05:45:32 ccgx user.info kernel: [    0.000000] console [tty0] enabled
Aug 17 05:45:32 ccgx user.info kernel: [    0.000701] Calibrating delay loop... 399.14 BogoMIPS (lpj=1560576)
Aug 17 05:45:32 ccgx user.info kernel: [    0.054718] pid_max: default: 32768 minimum: 301
Aug 17 05:45:32 ccgx user.info kernel: [    0.054870] Mount-cache hash table entries: 512
Aug 17 05:45:32 ccgx user.info kernel: [    0.055541] CPU: Testing write buffer coherency: ok
Aug 17 05:45:32 ccgx user.info kernel: [    0.055908] Setting up static identity map for 0x8036d328 - 0x8036d380
Aug 17 05:45:32 ccgx user.info kernel: [    0.056854] devtmpfs: initialized
Aug 17 05:45:32 ccgx user.info kernel: [    0.134277] pinctrl core: initialized pinctrl subsystem
Aug 17 05:45:32 ccgx user.info kernel: [    0.135498] regulator-dummy: no parameters
Aug 17 05:45:32 ccgx user.info kernel: [    0.135925] NET: Registered protocol family 16
Aug 17 05:45:32 ccgx user.info kernel: [    0.137237] DMA: preallocated 256 KiB pool for atomic coherent allocations
Aug 17 05:45:32 ccgx user.info kernel: [    0.137969] omap-gpmc omap-gpmc: GPMC revision 5.0
Aug 17 05:45:32 ccgx user.debug kernel: [    0.141174] gpiochip_add: registered GPIOs 0 to 31 on device: gpio
Aug 17 05:45:32 ccgx user.info kernel: [    0.141235] OMAP GPIO hardware version 2.5
Aug 17 05:45:32 ccgx user.debug kernel: [    0.141906] gpiochip_add: registered GPIOs 32 to 63 on device: gpio
Aug 17 05:45:32 ccgx user.debug kernel: [    0.142547] gpiochip_add: registered GPIOs 64 to 95 on device: gpio
Aug 17 05:45:32 ccgx user.debug kernel: [    0.143157] gpiochip_add: registered GPIOs 96 to 127 on device: gpio
Aug 17 05:45:32 ccgx user.debug kernel: [    0.143829] gpiochip_add: registered GPIOs 128 to 159 on device: gpio
Aug 17 05:45:32 ccgx user.debug kernel: [    0.144470] gpiochip_add: registered GPIOs 160 to 191 on device: gpio
Aug 17 05:45:32 ccgx user.info kernel: [    0.146270] omap_mux_init: Add partition: #1: core, flags: 0
Aug 17 05:45:32 ccgx user.info kernel: [    0.159576] Found NAND on CS0
Aug 17 05:45:32 ccgx user.info kernel: [    0.159637] Registering NAND on CS0
Aug 17 05:45:32 ccgx user.info kernel: [    0.160430] _omap_mux_init_gpio: Multiple gpio paths (3) for gpio126
Aug 17 05:45:32 ccgx user.info kernel: [    0.161743] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio94
Aug 17 05:45:32 ccgx user.info kernel: [    0.161804] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio96
Aug 17 05:45:32 ccgx user.info kernel: [    0.161834] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio98
Aug 17 05:45:32 ccgx user.info kernel: [    0.161865] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio99
Aug 17 05:45:32 ccgx user.info kernel: [    0.161895] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio104
Aug 17 05:45:32 ccgx user.info kernel: [    0.161987] hw-breakpoint: debug architecture 0x4 unsupported.
Aug 17 05:45:32 ccgx user.info kernel: [    0.165771] OMAP DMA hardware revision 4.0
Aug 17 05:45:32 ccgx user.warn kernel: [    0.167510]  arm-pmu: alias fck already exists
Aug 17 05:45:32 ccgx user.info kernel: [    0.182708] bio: create slab <bio-0> at 0
Aug 17 05:45:32 ccgx user.info kernel: [    0.212341] omap-dma-engine omap-dma-engine: OMAP DMA engine driver
Aug 17 05:45:32 ccgx user.info kernel: [    0.212799] display: 1800 mV normal 
Aug 17 05:45:32 ccgx user.notice kernel: [    0.214324] SCSI subsystem initialized
Aug 17 05:45:32 ccgx user.info kernel: [    0.215240] usbcore: registered new interface driver usbfs
Aug 17 05:45:32 ccgx user.info kernel: [    0.215454] usbcore: registered new interface driver hub
Aug 17 05:45:32 ccgx user.info kernel: [    0.215728] usbcore: registered new device driver usb
Aug 17 05:45:32 ccgx user.info kernel: [    0.218048] VDCDC1: 1200 mV normal 
Aug 17 05:45:32 ccgx user.info kernel: [    0.218780] VDCDC2: 3300 mV normal 
Aug 17 05:45:32 ccgx user.info kernel: [    0.219207] VDCDC3: 1800 mV normal 
Aug 17 05:45:32 ccgx user.info kernel: [    0.219512] LDO1: 1800 mV normal 
Aug 17 05:45:32 ccgx user.info kernel: [    0.219940] LDO2: 3300 mV normal 
Aug 17 05:45:32 ccgx user.info kernel: [    0.220611] omap_i2c omap_i2c.1: bus 1 rev1.3.12 at 400 kHz
Aug 17 05:45:32 ccgx user.info kernel: [    0.221496] omap_i2c omap_i2c.3: bus 3 rev1.3.12 at 400 kHz
Aug 17 05:45:32 ccgx user.info kernel: [    0.224121] Switching to clocksource 32k_counter
Aug 17 05:45:32 ccgx user.info kernel: [    0.245330] NET: Registered protocol family 2
Aug 17 05:45:32 ccgx user.info kernel: [    0.246063] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
Aug 17 05:45:32 ccgx user.info kernel: [    0.246276] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
Aug 17 05:45:32 ccgx user.info kernel: [    0.246398] TCP: Hash tables configured (established 8192 bind 8192)
Aug 17 05:45:32 ccgx user.info kernel: [    0.246520] TCP: reno registered
Aug 17 05:45:32 ccgx user.info kernel: [    0.246551] UDP hash table entries: 256 (order: 0, 4096 bytes)
Aug 17 05:45:32 ccgx user.info kernel: [    0.246582] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Aug 17 05:45:32 ccgx user.info kernel: [    0.246826] NET: Registered protocol family 1
Aug 17 05:45:32 ccgx user.err kernel: [    0.247131] usbhs_omap usbhs_omap: xclk60mhsp1_ck set parentfailed error:-22
Aug 17 05:45:32 ccgx user.info kernel: [    0.248748] CPU PMU: probing PMU on CPU 0
Aug 17 05:45:32 ccgx user.info kernel: [    0.248809] hw perfevents: enabled with ARMv7 Cortex-A8 PMU driver, 5 counters available
Aug 17 05:45:32 ccgx user.info kernel: [    0.253021] msgmni has been set to 491
Aug 17 05:45:32 ccgx user.info kernel: [    0.254211] io scheduler noop registered
Aug 17 05:45:32 ccgx user.info kernel: [    0.254241] io scheduler deadline registered
Aug 17 05:45:32 ccgx user.info kernel: [    0.254272] io scheduler cfq registered (default)
Aug 17 05:45:32 ccgx user.info kernel: [    0.255645] OMAP DSS rev 2.0
Aug 17 05:45:32 ccgx user.info kernel: [    0.259674] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
Aug 17 05:45:32 ccgx user.info kernel: [    0.261657] omap_uart.0: ttyO0 at MMIO 0x4806a000 (irq = 88) is a OMAP UART0
Aug 17 05:45:32 ccgx user.info kernel: [    0.262237] omap_uart.1: ttyO1 at MMIO 0x4806c000 (irq = 89) is a OMAP UART1
Aug 17 05:45:32 ccgx user.info kernel: [    0.262786] omap_uart.2: ttyO2 at MMIO 0x49020000 (irq = 90) is a OMAP UART2
Aug 17 05:45:32 ccgx user.info kernel: [    0.264373] brd: module loaded
Aug 17 05:45:32 ccgx user.info kernel: [    0.269866] loop: module loaded
Aug 17 05:45:32 ccgx user.info kernel: [    0.269989] at24 1-0050: 256 byte 24c02 EEPROM, writable, 1 bytes/write
Aug 17 05:45:32 ccgx user.err kernel: [    0.271453] mtdoops: mtd device (mtddev=name/number) must be supplied
Aug 17 05:45:32 ccgx user.warn kernel: [    0.271484] Generic platform RAM MTD, (c) 2004 Simtec Electronics
Aug 17 05:45:32 ccgx user.info kernel: [    0.272125] NAND device: Manufacturer ID: 0x2c, Chip ID: 0xbc (Micron NAND 512MiB 1,8V 16-bit), page size: 2048, OOB size: 64
Aug 17 05:45:32 ccgx user.notice kernel: [    0.272247] 13 cmdlinepart partitions found on MTD device omap2-nand.0
Aug 17 05:45:32 ccgx user.notice kernel: [    0.272247] Creating 13 MTD partitions on "omap2-nand.0":
Aug 17 05:45:32 ccgx user.notice kernel: [    0.272277] 0x000000000000-0x000000020000 : "spl1"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.273986] 0x000000020000-0x000000040000 : "spl2"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.275543] 0x000000040000-0x000000060000 : "spl3"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.277038] 0x000000060000-0x000000080000 : "spl4"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.278564] 0x000000080000-0x000000180000 : "u-boot"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.281005] 0x000000180000-0x0000001c0000 : "env1"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.282684] 0x0000001c0000-0x000000200000 : "env2"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.284271] 0x000000200000-0x000000300000 : "u-boot2"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.286499] 0x000000300000-0x000000340000 : "bootparms"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.288177] 0x000000340000-0x000000400000 : "splash"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.290191] 0x000000400000-0x000000a00000 : "kernel1"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.296569] 0x000000a00000-0x000001000000 : "kernel2"
Aug 17 05:45:32 ccgx user.notice kernel: [    0.303009] 0x000001000000-0x000020000000 : "ubisystem"
Aug 17 05:45:32 ccgx user.info kernel: [    0.712310] OneNAND driver initializing
Aug 17 05:45:32 ccgx user.info kernel: [    0.712615] tun: Universal TUN/TAP device driver, 1.6
Aug 17 05:45:32 ccgx user.info kernel: [    0.712646] tun: (C) 1999-2004 Max Krasnyansky <[email protected]>
Aug 17 05:45:32 ccgx user.info kernel: [    0.713012] CAN device driver interface
Aug 17 05:45:32 ccgx user.info kernel: [    0.714202] ti_hecc ti_hecc: device registered (reg_base=d0810000, irq=40)
Aug 17 05:45:32 ccgx user.info kernel: [    0.755706] davinci_mdio davinci_mdio.0: davinci mdio revision 1.5
Aug 17 05:45:32 ccgx user.info kernel: [    0.755737] davinci_mdio davinci_mdio.0: detected phy mask fffffffe
Aug 17 05:45:32 ccgx user.info kernel: [    0.756347] libphy: davinci_mdio.0: probed
Aug 17 05:45:32 ccgx user.info kernel: [    0.756378] davinci_mdio davinci_mdio.0: phy[0]: device davinci_mdio-0:00, driver unknown
Aug 17 05:45:32 ccgx user.info kernel: [    0.757080] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Aug 17 05:45:32 ccgx user.warn kernel: [    0.757232] ehci-omap.0 supply hsusb0 not found, using dummy regulator
Aug 17 05:45:32 ccgx user.info kernel: [    0.757385] ehci-omap ehci-omap.0: OMAP-EHCI Host Controller
Aug 17 05:45:32 ccgx user.info kernel: [    0.757812] ehci-omap ehci-omap.0: new USB bus registered, assigned bus number 1
Aug 17 05:45:32 ccgx user.info kernel: [    1.794708] ehci-omap ehci-omap.0: irq 93, io mem 0x48064800
Aug 17 05:45:32 ccgx user.info kernel: [    1.810272] ehci-omap ehci-omap.0: USB 2.0 started, EHCI 1.00
Aug 17 05:45:32 ccgx user.info kernel: [    1.810394] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Aug 17 05:45:32 ccgx user.info kernel: [    1.810455] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Aug 17 05:45:32 ccgx user.info kernel: [    1.810485] usb usb1: Product: OMAP-EHCI Host Controller
Aug 17 05:45:32 ccgx user.info kernel: [    1.810485] usb usb1: Manufacturer: Linux 3.7.1 ehci_hcd
Aug 17 05:45:32 ccgx user.info kernel: [    1.810516] usb usb1: SerialNumber: ehci-omap.0
Aug 17 05:45:32 ccgx user.info kernel: [    1.811492] hub 1-0:1.0: USB hub found
Aug 17 05:45:32 ccgx user.info kernel: [    1.811553] hub 1-0:1.0: 3 ports detected
Aug 17 05:45:32 ccgx user.info kernel: [    1.812408] usbcore: registered new interface driver usbtmc
Aug 17 05:45:32 ccgx user.info kernel: [    1.812438] Initializing USB Mass Storage driver...
Aug 17 05:45:32 ccgx user.info kernel: [    1.812713] usbcore: registered new interface driver usb-storage
Aug 17 05:45:32 ccgx user.info kernel: [    1.812713] USB Mass Storage support registered.
Aug 17 05:45:32 ccgx user.info kernel: [    1.812988] musb-hdrc: version 6.0, ?dma?, otg (peripheral+host)
Aug 17 05:45:32 ccgx user.info kernel: [    1.815185] rtc-ds1307 3-0068: rtc core: registered ds1307 as rtc0
Aug 17 05:45:32 ccgx user.info kernel: [    1.815246] rtc-ds1307 3-0068: 56 bytes nvram
Aug 17 05:45:32 ccgx user.info kernel: [    1.815460] i2c /dev entries driver
Aug 17 05:45:32 ccgx user.info kernel: [    1.816955] omap_wdt: OMAP Watchdog Timer Rev 0x31: initial timeout 60 sec
Aug 17 05:45:32 ccgx user.warn kernel: [    1.817230] cpu0 supply vcc not found, using dummy regulator
Aug 17 05:45:32 ccgx user.warn kernel: [    1.817291] omap_cpufreq_init: physical regulator not present for MPU
Aug 17 05:45:32 ccgx user.info kernel: [    1.817474] cpuidle: using governor ladder
Aug 17 05:45:32 ccgx user.info kernel: [    1.817504] cpuidle: using governor menu
Aug 17 05:45:32 ccgx user.warn kernel: [    1.818206] omap_hsmmc omap_hsmmc.0: Failed to get debounce clk
Aug 17 05:45:32 ccgx user.info kernel: [    1.818328] omap-dma-engine omap-dma-engine: allocating channel for 62
Aug 17 05:45:32 ccgx user.info kernel: [    1.818359] omap-dma-engine omap-dma-engine: allocating channel for 61
Aug 17 05:45:32 ccgx user.info kernel: [    1.867279] usbcore: registered new interface driver usbhid
Aug 17 05:45:32 ccgx user.info kernel: [    1.867340] usbhid: USB HID core driver
Aug 17 05:45:32 ccgx user.info kernel: [    1.867675] TCP: cubic registered
Aug 17 05:45:32 ccgx user.info kernel: [    1.867706] Initializing XFRM netlink socket
Aug 17 05:45:32 ccgx user.info kernel: [    1.867797] NET: Registered protocol family 10
Aug 17 05:45:32 ccgx user.info kernel: [    1.868652] sit: IPv6 over IPv4 tunneling driver
Aug 17 05:45:32 ccgx user.info kernel: [    1.869812] NET: Registered protocol family 17
Aug 17 05:45:32 ccgx user.info kernel: [    1.869873] NET: Registered protocol family 15
Aug 17 05:45:32 ccgx user.info kernel: [    1.869903] can: controller area network core (rev 20120528 abi 9)
Aug 17 05:45:32 ccgx user.info kernel: [    1.869995] NET: Registered protocol family 29
Aug 17 05:45:32 ccgx user.info kernel: [    1.870056] can: raw protocol (rev 20120528)
Aug 17 05:45:32 ccgx user.info kernel: [    1.870086] lib80211: common routines for IEEE802.11 drivers
Aug 17 05:45:32 ccgx user.debug kernel: [    1.870117] lib80211_crypt: registered algorithm 'NULL'
Aug 17 05:45:32 ccgx user.notice kernel: [    1.870513] Key type dns_resolver registered
Aug 17 05:45:32 ccgx user.info kernel: [    1.870635] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 1
Aug 17 05:45:32 ccgx user.err kernel: [    1.872283] voltdm_scale: No voltage scale API registered for vdd_mpu_iva
Aug 17 05:45:32 ccgx user.err kernel: [    1.872344] voltdm_scale: No voltage scale API registered for vdd_core
Aug 17 05:45:32 ccgx user.warn kernel: [    1.878723] LDO2: incomplete constraints, leaving on
Aug 17 05:45:32 ccgx user.warn kernel: [    1.879272] LDO1: incomplete constraints, leaving on
Aug 17 05:45:32 ccgx user.notice kernel: [    1.880065] UBI: attaching mtd12 to ubi0
Aug 17 05:45:32 ccgx user.info kernel: [    2.138610] usb 1-1: new high-speed USB device number 2 using ehci-omap
Aug 17 05:45:32 ccgx user.info kernel: [    2.295776] usb 1-1: New USB device found, idVendor=0424, idProduct=2412
Aug 17 05:45:32 ccgx user.info kernel: [    2.295837] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Aug 17 05:45:32 ccgx user.info kernel: [    2.310516] hub 1-1:1.0: USB hub found
Aug 17 05:45:32 ccgx user.info kernel: [    2.310943] hub 1-1:1.0: 2 ports detected
Aug 17 05:45:32 ccgx user.notice kernel: [    3.036041] UBI: scanning is finished
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052185] UBI: attached mtd12 (name "ubisystem", size 496 MiB) to ubi0
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052246] UBI: PEB size: 131072 bytes (128 KiB), LEB size: 129024 bytes
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052276] UBI: min./max. I/O unit sizes: 2048/2048, sub-page size 512
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052307] UBI: VID header offset: 512 (aligned 512), data offset: 2048
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052307] UBI: good PEBs: 3968, bad PEBs: 0, corrupted PEBs: 0
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052337] UBI: user volume: 3, internal volumes: 1, max. volumes count: 128
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052368] UBI: max/mean erase counter: 396/192, WL threshold: 4096, image sequence number: 696274219
Aug 17 05:45:32 ccgx user.notice kernel: [    3.052398] UBI: available PEBs: 371, total reserved PEBs: 3597, PEBs reserved for bad PEB handling: 80
Aug 17 05:45:32 ccgx user.notice kernel: [    3.053527] UBI: background thread "ubi_bgt0d" started, PID 652
Aug 17 05:45:32 ccgx user.info kernel: [    3.055450] input: gpio-keys as /devices/platform/gpio-keys/input/input0
Aug 17 05:45:32 ccgx user.info kernel: [    3.056732] rtc-ds1307 3-0068: setting system clock to 2018-08-17 05:45:24 UTC (1534484724)
Aug 17 05:45:32 ccgx user.notice kernel: [    3.077423] UBIFS: background thread "ubifs_bgt0_0" started, PID 660
Aug 17 05:45:32 ccgx user.notice kernel: [    3.113128] UBIFS: mounted UBI device 0, volume 0, name "rootfs1"(null)
Aug 17 05:45:32 ccgx user.notice kernel: [    3.113189] UBIFS: LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
Aug 17 05:45:32 ccgx user.notice kernel: [    3.113220] UBIFS: FS size: 208373760 bytes (198 MiB, 1615 LEBs), journal size 9033728 bytes (8 MiB, 71 LEBs)
Aug 17 05:45:32 ccgx user.notice kernel: [    3.113250] UBIFS: reserved for root: 0 bytes (0 KiB)
Aug 17 05:45:32 ccgx user.notice kernel: [    3.113281] UBIFS: media format: w4/r0 (latest is w4/r0), UUID 0969B30B-459B-4FB6-8DF2-6C15C67ECA54, small LPT model
Aug 17 05:45:32 ccgx user.info kernel: [    3.114196] VFS: Mounted root (ubifs filesystem) on device 0:11.
Aug 17 05:45:32 ccgx user.info kernel: [    3.114685] Freeing init memory: 172K
Aug 17 05:45:32 ccgx user.notice kernel: [    4.201293] UBIFS: background thread "ubifs_bgt0_2" started, PID 683
Aug 17 05:45:32 ccgx user.notice kernel: [    4.218292] UBIFS: recovery needed
Aug 17 05:45:32 ccgx user.notice kernel: [    4.385986] UBIFS: recovery completed
Aug 17 05:45:32 ccgx user.notice kernel: [    4.386047] UBIFS: mounted UBI device 0, volume 2, name "data"(null)
Aug 17 05:45:32 ccgx user.notice kernel: [    4.386077] UBIFS: LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
Aug 17 05:45:33 ccgx user.notice kernel: [    4.386108] UBIFS: FS size: 32385024 bytes (30 MiB, 251 LEBs), journal size 1677312 bytes (1 MiB, 13 LEBs)
Aug 17 05:45:33 ccgx user.notice kernel: [    4.386138] UBIFS: reserved for root: 1529624 bytes (1493 KiB)
Aug 17 05:45:33 ccgx user.notice kernel: [    4.386169] UBIFS: media format: w4/r0 (latest is w4/r0), UUID 68C57D19-4EB4-4709-88C3-16B53D15FD5D, small LPT model
Aug 17 05:45:33 ccgx daemon.info kernel: [    4.541809] udevd[694]: starting version 3.2.2
Aug 17 05:45:33 ccgx daemon.info kernel: [    4.617523] udevd[695]: starting eudev-3.2.2
Aug 17 05:45:33 ccgx user.crit kernel: [   10.124237] omap_wdt: Unexpected close, not stopping!
Aug 17 05:45:33 ccgx user.warn kernel: [   10.563537] davinci_mdio davinci_mdio.0: resetting idled controller
Aug 17 05:45:33 ccgx user.info kernel: [   10.564117] net eth0: attached PHY driver [Generic PHY] (mii_bus:phy_addr=davinci_mdio-0:00, id=7c0f1)
Aug 17 05:45:33 ccgx user.info kernel: [   10.564270] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: Connection Manager version 1.33
Aug 17 05:45:33 ccgx cron.info crond[1352]: (CRON) STARTUP (1.5.1)
Aug 17 05:45:33 ccgx cron.info crond[1352]: (CRON) INFO (Syslog will be used instead of sendmail.)
Aug 17 05:45:33 ccgx cron.info crond[1352]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 77% if used.)
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: Checking loopback interface settings
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: System hostname is ccgx
Aug 17 05:45:33 ccgx daemon.notice dbus[1283]: [system] Activating service name='fi.w1.wpa_supplicant1' (using servicehelper)
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: lo {newlink} index 1 address 00:00:00:00:00:00 mtu 65536
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: lo {newlink} index 1 operstate 0 <UNKNOWN>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: can0 {newlink} index 2 address 00:00:00:00:00:00 mtu 16
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: can0 {newlink} index 2 operstate 2 <DOWN>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: sit0 {newlink} index 3 address 00:00:00:00:08:00 mtu 1480
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: sit0 {newlink} index 3 operstate 2 <DOWN>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {create} index 4 type 1 <ETHER>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {update} flags 4099 <UP>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {newlink} index 4 address 68:9E:19:7A:7A:4A mtu 1500
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {newlink} index 4 operstate 2 <DOWN>
Aug 17 05:45:33 ccgx user.info kernel: [   12.560546] libphy: davinci_mdio-0:00 - Link is Up - 100/Full
Aug 17 05:45:33 ccgx user.info kernel: [   12.560638] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: Adding interface eth0 [ ethernet ]
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route ff00:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route fe80:: gw :: scope 0 <UNIVERSE>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {update} flags 69699 <UP,RUNNING,LOWER_UP>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {newlink} index 4 address 68:9E:19:7A:7A:4A mtu 1500
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {newlink} index 4 operstate 6 <UP>
Aug 17 05:45:33 ccgx daemon.warn connmand[1319]: Skipping disconnect of carrier, network is connecting.
Aug 17 05:45:33 ccgx user.notice kernel: [   12.694152] UBIFS: recovery needed
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: Setting hostname to ccgx
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} address 192.168.13.193/24 label eth0 family 2
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route 192.168.13.0 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route 192.168.13.254 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route 0.0.0.0 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route 0.0.0.0 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route 192.168.13.0 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:33 ccgx daemon.info connmand[1319]: eth0 {add} route 192.168.13.254 gw 0.0.0.0 scope 253 <LINK>
Aug 17 05:45:34 ccgx daemon.info dnsmasq[1290]: read /etc/hosts - 6 addresses
Aug 17 05:45:34 ccgx daemon.info dnsmasq[1290]: using nameserver 192.168.13.254#53
Aug 17 05:45:34 ccgx daemon.info connmand[1319]: eth0 {add} route 212.227.81.55 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:34 ccgx user.notice kernel: [   13.046295] UBIFS: recovery deferred
Aug 17 05:45:34 ccgx user.notice kernel: [   13.046356] UBIFS: mounted UBI device 0, volume 1, name "rootfs2", R/O mode
Aug 17 05:45:34 ccgx user.notice kernel: [   13.046386] UBIFS: LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
Aug 17 05:45:34 ccgx user.notice kernel: [   13.046417] UBIFS: FS size: 208373760 bytes (198 MiB, 1615 LEBs), journal size 9033728 bytes (8 MiB, 71 LEBs)
Aug 17 05:45:34 ccgx user.notice kernel: [   13.046447] UBIFS: reserved for root: 0 bytes (0 KiB)
Aug 17 05:45:34 ccgx user.notice kernel: [   13.046478] UBIFS: media format: w4/r0 (latest is w4/r0), UUID DF2D4B80-91CB-4813-A696-6D3C108494F4, small LPT model
Aug 17 05:45:34 ccgx user.notice kernel: [   13.104431] UBIFS: un-mount UBI device 0, volume 1
Aug 17 05:45:34 ccgx daemon.notice dbus[1283]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
Aug 17 05:45:34 ccgx daemon.info init: no more processes left in this runlevel
Aug 17 05:45:34 ccgx daemon.info connmand[1319]: eth0 {del} route 212.227.81.55 gw 192.168.13.254 scope 0 <UNIVERSE>
Aug 17 05:45:51 ccgx daemon.info connmand[1319]: can0 {newlink} index 2 address 00:00:00:00:00:00 mtu 16
Aug 17 05:45:51 ccgx daemon.info connmand[1319]: can0 {newlink} index 2 operstate 0 <UNKNOWN>
Aug 17 05:45:51 ccgx user.warn kernel: [   30.022460] turning CAN driver on
Aug 17 05:45:51 ccgx user.info kernel: [   30.022552] ti_hecc ti_hecc can0: setting CANBTC=0x10049
Aug 17 05:46:05 ccgx daemon.info connmand[1319]: ntp: time slew +19.291017 s
root@ccgx:~# 
root@ccgx:/data/log# ls -al
drwxr-xr-x   28 root     root          2736 Aug 17 05:45 .
drwxr-xr-x   12 root     root           808 Jul 30 06:55 ..
-rw-r--r--    1 root     root          1305 Aug 17 05:45 boot
-rw-r--r--    1 root     root          1302 Jul 31 05:00 boot~
drwx------    2 root     root           968 Mar 19 04:23 can-bus-bms.can0
drwx------    2 root     root           968 Mar 19 04:23 dbus-fronius
drwx------    2 root     root           968 Mar 19 04:23 dbus-modbustcp
drwx------    2 root     root           968 Aug 17 06:41 dbus-qwacs
drwx------    2 root     root           968 Dec 13  2017 dbus-systemcalc-py
drwx------    2 root     root           968 Mar 19 04:23 dbus-systemcalc-py-bol
drwx------    2 root     root           968 Mar 19 04:23 dbus-vebus-to-pvinverter
-rw-r--r--    1 root     root         14158 Aug 17 05:45 dmesg
-rw-r--r--    1 root     root         17783 Aug  3 03:04 dmesg.old
drwx------    2 root     root           968 Aug  3 03:04 gui
drwxr-xr-x    2 root     root           160 Aug 15 13:48 hiawatha
drwx------    2 root     root           968 Dec 13  2017 hub4control
drwx------    2 root     root           968 Mar 19 04:23 hub4control-bol
-rw-r--r--    1 root     root           292 Aug 17 06:39 lastlog
drwx------    2 root     root           968 Mar 19 04:23 localsettings
-rw-r--r--    1 root     root         68915 Aug 17 05:46 messages
-rw-r--r--    1 root     root        102458 Aug 14 21:05 messages.0
-rw-r--r--    1 root     root        102401 Aug  5 17:36 messages.1
-rw-r--r--    1 root     root        102405 Jul 31 05:40 messages.2
drwx------    2 root     root           968 Mar 19 04:23 mk2_dbus.ttyO1
drwx------    2 root     root           352 Jul 31 05:00 mqtt-rpc
drwx------    2 root     root           968 Mar 19 04:23 serial-starter
drwx------    2 root     root           352 Jul 31 05:00 simple-upnpd
drwx------    2 root     root           968 Mar 19 04:23 ssh-tunnel
drwx------    2 root     root           968 Mar 19 04:23 sshd
drwx------    2 root     root           968 Jul 31 04:58 swupdate
drwx------    2 root     root           880 Sep 19  2017 vecan-dbus.can0
drwx------    2 root     root           968 Aug 17 06:44 vedirect.ttyO0
drwx------    2 root     root           968 Aug 17 02:31 vedirect.ttyO2
drwx------    2 root     root           968 Mar 19 04:23 vrmlogger
drwx------    2 root     root           352 Jul 30 06:53 vrmpubnub
drwxr-x---    2 root     root           160 Nov 13  2017 watchdog
drwx------    2 root     root           968 Aug 15 02:33 websockify-c
-rw-rw-r--    1 root     root        120192 Aug 17 06:39 wtmp
root@ccgx:/data/log# cat /log/boot
Fri Aug  3 03:04:33 2018: Starting watchdog
Fri Aug  3 03:04:33 2018: INIT: Entering runlevel: 5
Fri Aug  3 03:04:33 2018: Configuring network interfaces... done.
Fri Aug  3 03:04:34 2018: Starting system message bus: Setting up watches.
Fri Aug  3 03:04:34 2018: Watches established.
Fri Aug  3 03:04:34 2018: /var/run/dbus/ CREATE system_bus_socket
Fri Aug  3 03:04:34 2018: starting DNS forwarder and DHCP server: dnsmasq... done.
Fri Aug  3 03:04:34 2018: starting resolv.conf manager: resolv-watch... done.
Fri Aug  3 03:04:34 2018: Starting syslogd/klogd: done
Fri Aug  3 03:04:34 2018: Starting php-fpm  done
Fri Aug  3 03:04:34 2018: Starting Connection Manager
Fri Aug  3 03:04:34 2018: Starting Hiawatha Web Server: hiawatha.
Fri Aug  3 03:04:35 2018: Starting crond: OK
Fri Aug  3 03:04:35 2018: Checking available software versions...
Fri Aug  3 03:04:35 2018: dbus[737]: [system] Activating service name='fi.w1.wpa_supplicant1' (using servicehelper)
Fri Aug  3 03:04:35 2018: Active rootfs: 2
Fri Aug  3 03:04:35 2018: Active version: 20180802165149 v2.20~48
Fri Aug  3 03:04:35 2018: Backup version: 20180723205115 v2.20~44
Fri Aug  3 03:04:35 2018: dbus[737]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
Fri Aug  3 03:04:35 2018: Successfully initialized wpa_supplicant
root@ccgx:/data/log# cat /log/boot~ 
Tue Jul 31 04:59:57 2018: Starting watchdog
Tue Jul 31 04:59:57 2018: INIT: Entering runlevel: 5
Tue Jul 31 04:59:57 2018: Configuring network interfaces... done.
Tue Jul 31 04:59:58 2018: Starting system message bus: Setting up watches.
Tue Jul 31 04:59:58 2018: Watches established.
Tue Jul 31 04:59:58 2018: /var/run/dbus/ CREATE system_bus_socket
Tue Jul 31 04:59:58 2018: starting DNS forwarder and DHCP server: dnsmasq... done.
Tue Jul 31 04:59:58 2018: starting resolv.conf manager: resolv-watch... done.
Tue Jul 31 04:59:58 2018: Starting syslogd/klogd: done
Tue Jul 31 04:59:58 2018: Starting php-fpm  done
Tue Jul 31 04:59:59 2018: Starting Connection Manager
Tue Jul 31 04:59:59 2018: Starting Hiawatha Web Server: hiawatha.
Tue Jul 31 04:59:59 2018: Starting crond: OK
Tue Jul 31 04:59:59 2018: Checking available software versions...
Tue Jul 31 04:59:59 2018: dbus[737]: [system] Activating service name='fi.w1.wpa_supplicant1' (using servicehelper)
Tue Jul 31 04:59:59 2018: Active rootfs: 1
Tue Jul 31 04:59:59 2018: Active version: 20180723205115 v2.20~44
Tue Jul 31 04:59:59 2018: Backup version: 20180625152458 v2.16
Tue Jul 31 04:59:59 2018: dbus[737]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
Tue Jul 31 05:00:00 2018: Successfully initialized wpa_supplicant
root@ccgx:/data/log# 
root@ccgx:/data/log# cat /log/dmesg
[    0.000000] Booting Linux on physical CPU 0
[    0.000000] Linux version 3.7.1 (oe-user@oe-host) (gcc version 7.3.0 (GCC) ) #1 Wed Aug 15 16:02:10 CEST 2018
[    0.000000] CPU: ARMv7 Processor [411fc087] revision 7 (ARMv7), cr=10c53c7d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[    0.000000] Machine: Victron BPP3
[    0.000000] Reserving 2097152 bytes SDRAM for VRAM
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] On node 0 totalpages: 64768
[    0.000000] free_area_init_node: node 0, pgdat c050e5e0, node_mem_map c0535000
[    0.000000]   Normal zone: 512 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 64256 pages, LIFO batch:15
[    0.000000] AM3517 ES1.1 (l2cache sgx neon )
[    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/332/600 MHz
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 64256
[    0.000000] Kernel command line: root=ubi0:rootfs1 rootfstype=ubifs ubi.mtd=12 omapdss.def_disp=lcd omapfb.vram=0:2M@0x8fe00000 fbskip mtdparts=omap2-nand.0:128k(spl1),128k(spl2),128k(spl3),128k(spl4),1m(u-boot),256k(env1),256k(env2),1m(u-boot2),256k(bootparms),768k(splash),6m(kernel1),6m(kernel2),496m(ubisystem) 5
[    0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
[    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Memory: 253MB = 253MB total
[    0.000000] Memory: 251444k/251444k available, 10700k reserved, 0K highmem
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
[    0.000000]     vmalloc : 0xd0800000 - 0xff000000   ( 744 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xd0000000   ( 256 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc04a95e4   (4742 kB)
[    0.000000]       .init : 0xc04aa000 - 0xc04d5cc0   ( 176 kB)
[    0.000000]       .data : 0xc04d6000 - 0xc050f900   ( 231 kB)
[    0.000000]        .bss : 0xc050f924 - 0xc0534b5c   ( 149 kB)
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 4.0) with 96 interrupts
[    0.000000] Total of 96 interrupts on 1 active controller
[    0.000000] OMAP clockevent source: GPTIMER1 at 32768 Hz
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 131071999ms
[    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000000] Console: colour dummy device 80x30
[    0.000000] console [tty0] enabled
[    0.000701] Calibrating delay loop... 399.14 BogoMIPS (lpj=1560576)
[    0.054718] pid_max: default: 32768 minimum: 301
[    0.054870] Mount-cache hash table entries: 512
[    0.055541] CPU: Testing write buffer coherency: ok
[    0.055908] Setting up static identity map for 0x8036d328 - 0x8036d380
[    0.056854] devtmpfs: initialized
[    0.134277] pinctrl core: initialized pinctrl subsystem
[    0.135498] regulator-dummy: no parameters
[    0.135925] NET: Registered protocol family 16
[    0.137237] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.137969] omap-gpmc omap-gpmc: GPMC revision 5.0
[    0.141174] gpiochip_add: registered GPIOs 0 to 31 on device: gpio
[    0.141235] OMAP GPIO hardware version 2.5
[    0.141906] gpiochip_add: registered GPIOs 32 to 63 on device: gpio
[    0.142547] gpiochip_add: registered GPIOs 64 to 95 on device: gpio
[    0.143157] gpiochip_add: registered GPIOs 96 to 127 on device: gpio
[    0.143829] gpiochip_add: registered GPIOs 128 to 159 on device: gpio
[    0.144470] gpiochip_add: registered GPIOs 160 to 191 on device: gpio
[    0.146270] omap_mux_init: Add partition: #1: core, flags: 0
[    0.159576] Found NAND on CS0
[    0.159637] Registering NAND on CS0
[    0.160430] _omap_mux_init_gpio: Multiple gpio paths (3) for gpio126
[    0.161743] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio94
[    0.161804] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio96
[    0.161834] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio98
[    0.161865] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio99
[    0.161895] _omap_mux_init_gpio: Multiple gpio paths (2) for gpio104
[    0.161987] hw-breakpoint: debug architecture 0x4 unsupported.
[    0.165771] OMAP DMA hardware revision 4.0
[    0.167510]  arm-pmu: alias fck already exists
[    0.182708] bio: create slab <bio-0> at 0
[    0.212341] omap-dma-engine omap-dma-engine: OMAP DMA engine driver
[    0.212799] display: 1800 mV normal 
[    0.214324] SCSI subsystem initialized
[    0.215240] usbcore: registered new interface driver usbfs
[    0.215454] usbcore: registered new interface driver hub
[    0.215728] usbcore: registered new device driver usb
[    0.218048] VDCDC1: 1200 mV normal 
[    0.218780] VDCDC2: 3300 mV normal 
[    0.219207] VDCDC3: 1800 mV normal 
[    0.219512] LDO1: 1800 mV normal 
[    0.219940] LDO2: 3300 mV normal 
[    0.220611] omap_i2c omap_i2c.1: bus 1 rev1.3.12 at 400 kHz
[    0.221496] omap_i2c omap_i2c.3: bus 3 rev1.3.12 at 400 kHz
[    0.224121] Switching to clocksource 32k_counter
[    0.245330] NET: Registered protocol family 2
[    0.246063] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
[    0.246276] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
[    0.246398] TCP: Hash tables configured (established 8192 bind 8192)
[    0.246520] TCP: reno registered
[    0.246551] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.246582] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.246826] NET: Registered protocol family 1
[    0.247131] usbhs_omap usbhs_omap: xclk60mhsp1_ck set parentfailed error:-22
[    0.248748] CPU PMU: probing PMU on CPU 0
[    0.248809] hw perfevents: enabled with ARMv7 Cortex-A8 PMU driver, 5 counters available
[    0.253021] msgmni has been set to 491
[    0.254211] io scheduler noop registered
[    0.254241] io scheduler deadline registered
[    0.254272] io scheduler cfq registered (default)
[    0.255645] OMAP DSS rev 2.0
[    0.259674] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.261657] omap_uart.0: ttyO0 at MMIO 0x4806a000 (irq = 88) is a OMAP UART0
[    0.262237] omap_uart.1: ttyO1 at MMIO 0x4806c000 (irq = 89) is a OMAP UART1
[    0.262786] omap_uart.2: ttyO2 at MMIO 0x49020000 (irq = 90) is a OMAP UART2
[    0.264373] brd: module loaded
[    0.269866] loop: module loaded
[    0.269989] at24 1-0050: 256 byte 24c02 EEPROM, writable, 1 bytes/write
[    0.271453] mtdoops: mtd device (mtddev=name/number) must be supplied
[    0.271484] Generic platform RAM MTD, (c) 2004 Simtec Electronics
[    0.272125] NAND device: Manufacturer ID: 0x2c, Chip ID: 0xbc (Micron NAND 512MiB 1,8V 16-bit), page size: 2048, OOB size: 64
[    0.272247] 13 cmdlinepart partitions found on MTD device omap2-nand.0
[    0.272247] Creating 13 MTD partitions on "omap2-nand.0":
[    0.272277] 0x000000000000-0x000000020000 : "spl1"
[    0.273986] 0x000000020000-0x000000040000 : "spl2"
[    0.275543] 0x000000040000-0x000000060000 : "spl3"
[    0.277038] 0x000000060000-0x000000080000 : "spl4"
[    0.278564] 0x000000080000-0x000000180000 : "u-boot"
[    0.281005] 0x000000180000-0x0000001c0000 : "env1"
[    0.282684] 0x0000001c0000-0x000000200000 : "env2"
[    0.284271] 0x000000200000-0x000000300000 : "u-boot2"
[    0.286499] 0x000000300000-0x000000340000 : "bootparms"
[    0.288177] 0x000000340000-0x000000400000 : "splash"
[    0.290191] 0x000000400000-0x000000a00000 : "kernel1"
[    0.296569] 0x000000a00000-0x000001000000 : "kernel2"
[    0.303009] 0x000001000000-0x000020000000 : "ubisystem"
[    0.712310] OneNAND driver initializing
[    0.712615] tun: Universal TUN/TAP device driver, 1.6
[    0.712646] tun: (C) 1999-2004 Max Krasnyansky <[email protected]>
[    0.713012] CAN device driver interface
[    0.714202] ti_hecc ti_hecc: device registered (reg_base=d0810000, irq=40)
[    0.755706] davinci_mdio davinci_mdio.0: davinci mdio revision 1.5
[    0.755737] davinci_mdio davinci_mdio.0: detected phy mask fffffffe
[    0.756347] libphy: davinci_mdio.0: probed
[    0.756378] davinci_mdio davinci_mdio.0: phy[0]: device davinci_mdio-0:00, driver unknown
[    0.757080] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.757232] ehci-omap.0 supply hsusb0 not found, using dummy regulator
[    0.757385] ehci-omap ehci-omap.0: OMAP-EHCI Host Controller
[    0.757812] ehci-omap ehci-omap.0: new USB bus registered, assigned bus number 1
[    1.794708] ehci-omap ehci-omap.0: irq 93, io mem 0x48064800
[    1.810272] ehci-omap ehci-omap.0: USB 2.0 started, EHCI 1.00
[    1.810394] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    1.810455] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.810485] usb usb1: Product: OMAP-EHCI Host Controller
[    1.810485] usb usb1: Manufacturer: Linux 3.7.1 ehci_hcd
[    1.810516] usb usb1: SerialNumber: ehci-omap.0
[    1.811492] hub 1-0:1.0: USB hub found
[    1.811553] hub 1-0:1.0: 3 ports detected
[    1.812408] usbcore: registered new interface driver usbtmc
[    1.812438] Initializing USB Mass Storage driver...
[    1.812713] usbcore: registered new interface driver usb-storage
[    1.812713] USB Mass Storage support registered.
[    1.812988] musb-hdrc: version 6.0, ?dma?, otg (peripheral+host)
[    1.815185] rtc-ds1307 3-0068: rtc core: registered ds1307 as rtc0
[    1.815246] rtc-ds1307 3-0068: 56 bytes nvram
[    1.815460] i2c /dev entries driver
[    1.816955] omap_wdt: OMAP Watchdog Timer Rev 0x31: initial timeout 60 sec
[    1.817230] cpu0 supply vcc not found, using dummy regulator
[    1.817291] omap_cpufreq_init: physical regulator not present for MPU
[    1.817474] cpuidle: using governor ladder
[    1.817504] cpuidle: using governor menu
[    1.818206] omap_hsmmc omap_hsmmc.0: Failed to get debounce clk
[    1.818328] omap-dma-engine omap-dma-engine: allocating channel for 62
[    1.818359] omap-dma-engine omap-dma-engine: allocating channel for 61
[    1.867279] usbcore: registered new interface driver usbhid
[    1.867340] usbhid: USB HID core driver
[    1.867675] TCP: cubic registered
[    1.867706] Initializing XFRM netlink socket
[    1.867797] NET: Registered protocol family 10
[    1.868652] sit: IPv6 over IPv4 tunneling driver
[    1.869812] NET: Registered protocol family 17
[    1.869873] NET: Registered protocol family 15
[    1.869903] can: controller area network core (rev 20120528 abi 9)
[    1.869995] NET: Registered protocol family 29
[    1.870056] can: raw protocol (rev 20120528)
[    1.870086] lib80211: common routines for IEEE802.11 drivers
[    1.870117] lib80211_crypt: registered algorithm 'NULL'
[    1.870513] Key type dns_resolver registered
[    1.870635] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 1
[    1.872283] voltdm_scale: No voltage scale API registered for vdd_mpu_iva
[    1.872344] voltdm_scale: No voltage scale API registered for vdd_core
[    1.878723] LDO2: incomplete constraints, leaving on
[    1.879272] LDO1: incomplete constraints, leaving on
[    1.880065] UBI: attaching mtd12 to ubi0
[    2.138610] usb 1-1: new high-speed USB device number 2 using ehci-omap
[    2.295776] usb 1-1: New USB device found, idVendor=0424, idProduct=2412
[    2.295837] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.310516] hub 1-1:1.0: USB hub found
[    2.310943] hub 1-1:1.0: 2 ports detected
[    3.036041] UBI: scanning is finished
[    3.052185] UBI: attached mtd12 (name "ubisystem", size 496 MiB) to ubi0
[    3.052246] UBI: PEB size: 131072 bytes (128 KiB), LEB size: 129024 bytes
[    3.052276] UBI: min./max. I/O unit sizes: 2048/2048, sub-page size 512
[    3.052307] UBI: VID header offset: 512 (aligned 512), data offset: 2048
[    3.052307] UBI: good PEBs: 3968, bad PEBs: 0, corrupted PEBs: 0
[    3.052337] UBI: user volume: 3, internal volumes: 1, max. volumes count: 128
[    3.052368] UBI: max/mean erase counter: 396/192, WL threshold: 4096, image sequence number: 696274219
[    3.052398] UBI: available PEBs: 371, total reserved PEBs: 3597, PEBs reserved for bad PEB handling: 80
[    3.053527] UBI: background thread "ubi_bgt0d" started, PID 652
[    3.055450] input: gpio-keys as /devices/platform/gpio-keys/input/input0
[    3.056732] rtc-ds1307 3-0068: setting system clock to 2018-08-17 05:45:24 UTC (1534484724)
[    3.077423] UBIFS: background thread "ubifs_bgt0_0" started, PID 660
[    3.113128] UBIFS: mounted UBI device 0, volume 0, name "rootfs1"(null)
[    3.113189] UBIFS: LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    3.113220] UBIFS: FS size: 208373760 bytes (198 MiB, 1615 LEBs), journal size 9033728 bytes (8 MiB, 71 LEBs)
[    3.113250] UBIFS: reserved for root: 0 bytes (0 KiB)
[    3.113281] UBIFS: media format: w4/r0 (latest is w4/r0), UUID 0969B30B-459B-4FB6-8DF2-6C15C67ECA54, small LPT model
[    3.114196] VFS: Mounted root (ubifs filesystem) on device 0:11.
[    3.114685] Freeing init memory: 172K
[    4.201293] UBIFS: background thread "ubifs_bgt0_2" started, PID 683
[    4.218292] UBIFS: recovery needed
[    4.385986] UBIFS: recovery completed
[    4.386047] UBIFS: mounted UBI device 0, volume 2, name "data"(null)
[    4.386077] UBIFS: LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    4.386108] UBIFS: FS size: 32385024 bytes (30 MiB, 251 LEBs), journal size 1677312 bytes (1 MiB, 13 LEBs)
[    4.386138] UBIFS: reserved for root: 1529624 bytes (1493 KiB)
[    4.386169] UBIFS: media format: w4/r0 (latest is w4/r0), UUID 68C57D19-4EB4-4709-88C3-16B53D15FD5D, small LPT model
[    4.541809] udevd[694]: starting version 3.2.2
[    4.617523] udevd[695]: starting eudev-3.2.2
root@ccgx:/data/log# cat ./dmesg.old 
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.9.113 (oe-user@oe-host) (gcc version 7.3.0 (GCC) ) #1 Thu Aug 2 18:53:25 CEST 2018
[    0.000000] CPU: ARMv7 Processor [411fc087] revision 7 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[    0.000000] OF: fdt:Machine model: Color Control GX
[    0.000000] cma: Reserved 16 MiB at 0x8e800000
[    0.000000] Memory policy: Data cache writeback
[    0.000000] On node 0 totalpages: 64768
[    0.000000] free_area_init_node: node 0, pgdat c095ac04, node_mem_map cfab1000
[    0.000000]   Normal zone: 570 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 64768 pages, LIFO batch:15
[    0.000000] CPU: All CPU(s) started in SVC mode.
[    0.000000] AM3517 ES1.1 (l2cache sgx neon)
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 64198
[    0.000000] Kernel command line: mem=254M root=ubi0:rootfs2 rootfstype=ubifs ubi.mtd=12 omapdss.def_disp=lcd omapfb.vram=0:2M@0x8fe00000 fbskip mtdparts=omap2-nand.0:128k(spl1),128k(spl2),128k(spl3),128k(spl4),1m(u-boot),256k(env1),256k(env2),1m(u-boot2),256k(bootparms),768k(splash),6m(kernel1),6m(kernel2),496m(ubisystem) 5
[    0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
[    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Memory: 230984K/259072K available (5120K kernel code, 381K rwdata, 1680K rodata, 1024K init, 239K bss, 11704K reserved, 16384K cma-reserved, 0K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xd0000000 - 0xff800000   ( 760 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xcfd00000   ( 253 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0600000   (6112 kB)
[    0.000000]       .init : 0xc0800000 - 0xc0900000   (1024 kB)
[    0.000000]       .data : 0xc0900000 - 0xc095f610   ( 382 kB)
[    0.000000]        .bss : 0xc0961000 - 0xc099cef8   ( 240 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 4.0) with 96 interrupts
[    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/332/600 MHz
[    0.000000] OMAP clockevent source: timer2 at 13000000 Hz
[    0.000025] sched_clock: 32 bits at 13MHz, resolution 76ns, wraps every 165191050201ns
[    0.000058] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 147020034397 ns
[    0.000073] OMAP clocksource: timer1 at 13000000 Hz
[    0.000785] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
[    0.000798] OMAP clocksource: 32k_counter at 32768 Hz
[    0.001330] Console: colour dummy device 80x30
[    0.002149] console [tty0] enabled
[    0.002199] Calibrating delay loop... 597.60 BogoMIPS (lpj=2988032)
[    0.057781] pid_max: default: 32768 minimum: 301
[    0.057988] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.058032] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.059151] CPU: Testing write buffer coherency: ok
[    0.059720] Setting up static identity map for 0x80100000 - 0x80100058
[    0.062767] devtmpfs: initialized
[    0.094037] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 1
[    0.094524] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.094608] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.096321] pinctrl core: initialized pinctrl subsystem
[    0.096964] regulator-dummy: no parameters
[    0.098117] NET: Registered protocol family 16
[    0.101192] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.113747] omap_hwmod: mcbsp2_sidetone using broken dt data from mcbsp
[    0.114193] omap_hwmod: mcbsp3_sidetone using broken dt data from mcbsp
[    0.188973] cpuidle: using governor menu
[    0.189600] Reprogramming SDRC clock to 332000000 Hz
[    0.192803] platform 480c5000.aes: Cannot lookup hwmod 'aes'
[    0.198070] OMAP GPIO hardware version 2.5
[    0.216078] irq: no irq domain found for /ocp@68000000/l4@48000000/scm@2000/pinmux@30 !
[    0.216607] irq: no irq domain found for /ocp@68000000/l4@48000000/scm@2000/pinmux@30 !
[    0.219828] platform 480c3000.sham: Cannot lookup hwmod 'sham'
[    0.220237] platform 480cb000.smartreflex: Cannot lookup hwmod 'smartreflex_core'
[    0.224798] omap-gpmc 6e000000.gpmc: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/gpmc_pins, deferring probe
[    0.225259] platform 480ab000.usb_otg_hs: Cannot lookup hwmod 'usb_otg_hs'
[    0.230564] hw-breakpoint: debug architecture 0x4 unsupported.
[    0.231784] OMAP DMA hardware revision 4.0
[    0.254990] omap-dma-engine 48056000.dma-controller: OMAP DMA engine driver
[    0.255981] vmmc: 3300 mV 
[    0.256276] reg-fixed-voltage vmmc: vmmc supplying 3300000uV
[    0.256381] hsusb1_vbus: 3300 mV 
[    0.256628] reg-fixed-voltage hsusb1_power_reg: hsusb1_vbus supplying 3300000uV
[    0.256684] reg-fixed-voltage vdd_can_regulator: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/vdd_can_pins, deferring probe
[    0.256796] reg-fixed-voltage vdd_mk2_regulator: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/vdd_mk2_pins, deferring probe
[    0.259084] SCSI subsystem initialized
[    0.259598] usbcore: registered new interface driver usbfs
[    0.259734] usbcore: registered new interface driver hub
[    0.259873] usbcore: registered new device driver usb
[    0.260213] usb_phy_generic hsusb1_phy: could not find pctldev for node /ocp@68000000/pinmux@480025d8/hsusb1_phy_pins, deferring probe
[    0.260618] omap_i2c 48070000.i2c: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/i2c1_pins, deferring probe
[    0.261634] omap_i2c 48072000.i2c: bus 1 rev3.3 at 100 kHz
[    0.261772] omap_i2c 48060000.i2c: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/i2c3_pins, deferring probe
[    0.262096] pps_core: LinuxPPS API ver. 1 registered
[    0.262137] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]>
[    0.262237] PTP clock support registered
[    0.263830] clocksource: Switched to clocksource timer1
[    0.304445] NET: Registered protocol family 2
[    0.305358] TCP established hash table entries: 2048 (order: 1, 8192 bytes)
[    0.305447] TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
[    0.305512] TCP: Hash tables configured (established 2048 bind 2048)
[    0.305672] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.305724] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.305955] NET: Registered protocol family 1
[    0.308754] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available
[    0.311788] audit: initializing netlink subsys (disabled)
[    0.311949] audit: type=2000 audit(0.300:1): initialized
[    0.313314] workingset: timestamp_bits=14 max_order=16 bucket_order=2
[    0.331900] io scheduler noop registered
[    0.331972] io scheduler deadline registered
[    0.332068] io scheduler cfq registered (default)
[    0.334290] pinctrl-single 48002030.pinmux: 284 pins at pa fa002030 size 568
[    0.334643] pinctrl-single 48002a00.pinmux: 46 pins at pa fa002a00 size 92
[    0.335121] pinctrl-single 480025d8.pinmux: 18 pins at pa fa0025d8 size 36
[    0.337416] omapdss_dss 48050000.dss: Looking up vdda_video-supply from device tree
[    0.337438] omapdss_dss 48050000.dss: Looking up vdda_video-supply property in node /ocp@68000000/dss@48050000 failed
[    0.337457] 48050000.dss supply vdda_video not found, using dummy regulator
[    0.337693] OMAP DSS rev 2.0
[    0.337990] omapdss_dss 48050000.dss: bound 48050400.dispc (ops dispc_component_ops)
[    0.343462] omapfb omapfb: using display 'lcd' mode 480x272
[    0.344609] pbias_mmc_omap2430: 1800 <--> 3000 mV at 3000 mV 
[    0.346149] omap_uart 4806a000.serial: no wakeirq for uart0
[    0.346325] 4806a000.serial: ttyO0 at MMIO 0x4806a000 (irq = 88, base_baud = 3000000) is a OMAP UART0
[    0.347040] irq: no irq domain found for /ocp@68000000/l4@48000000/scm@2000/pinmux@30 !
[    0.347140] omap_uart 4806c000.serial: no wakeirq for uart1
[    0.347250] 4806c000.serial: ttyO1 at MMIO 0x4806c000 (irq = 89, base_baud = 3000000) is a OMAP UART1
[    0.347850] irq: no irq domain found for /ocp@68000000/l4@48000000/scm@2000/pinmux@30 !
[    0.347937] omap_uart 49020000.serial: no wakeirq for uart2
[    0.348038] 49020000.serial: ttyO2 at MMIO 0x49020000 (irq = 90, base_baud = 3000000) is a OMAP UART2
[    0.367908] brd: module loaded
[    0.369021] mtdoops: mtd device (mtddev=name/number) must be supplied
[    0.370857] libphy: Fixed MDIO Bus: probed
[    0.371221] CAN device driver interface
[    0.371551] ti_hecc 5c050000.can: Looking up xceiver-supply from device tree
[    0.423953] davinci_mdio davinci_mdio.0: davinci mdio revision 1.5
[    0.424019] libphy: davinci_mdio.0: probed
[    0.424968] davinci_mdio davinci_mdio.0: phy[0]: device davinci_mdio.0:00, driver SMSC LAN8710/LAN8720
[    0.425991] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.426043] ehci-omap: OMAP-EHCI Host Controller driver
[    0.426725] ehci-omap 48064800.ehci: Can't get PHY device for port 0: -517
[    0.427009] i2c /dev entries driver
[    0.428495] omap_wdt: OMAP Watchdog Timer Rev 0x31: initial timeout 60 sec
[    0.429283] cpu cpu0: Looking up cpu0-supply from device tree
[    0.430537] omap_hsmmc 4809c000.mmc: Got CD GPIO
[    0.431192] omap_hsmmc 4809c000.mmc: Looking up vmmc-supply from device tree
[    0.431394] omap_hsmmc 4809c000.mmc: Looking up vmmc_aux-supply from device tree
[    0.431410] omap_hsmmc 4809c000.mmc: Looking up vmmc_aux-supply property in node /ocp@68000000/mmc@4809c000 failed
[    0.431430] omap_hsmmc 4809c000.mmc: Looking up pbias-supply from device tree
[    0.486270] NET: Registered protocol family 10
[    0.488069] NET: Registered protocol family 17
[    0.488144] can: controller area network core (rev 20120528 abi 9)
[    0.488295] NET: Registered protocol family 29
[    0.488334] can: raw protocol (rev 20120528)
[    0.488369] can: broadcast manager protocol (rev 20161123 t)
[    0.488413] can: netlink gateway (rev 20130117) max_hops=1
[    0.488651] omap2_set_init_voltage: unable to find boot up OPP for vdd_mpu_iva
[    0.488709] omap2_set_init_voltage: unable to set vdd_mpu_iva
[    0.488758] omap2_set_init_voltage: unable to find boot up OPP for vdd_core
[    0.488794] omap2_set_init_voltage: unable to set vdd_core
[    0.489085] PM: no software I/O chain control; some wakeups may be lost
[    0.489144] pm: Failed to request pm_wkup irq
[    0.489231] ThumbEE CPU extension supported.
[    0.489278] Registering SWP/SWPB emulation handler
[    0.489313] SmartReflex Class3 initialized
[    0.506103] omap-gpmc 6e000000.gpmc: GPMC revision 5.0
[    0.506196] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000
[    0.508170] nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xbc
[    0.508231] nand: Micron MT29F4G16ABBDAH4
[    0.508269] nand: 512 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    0.508344] nand: WARNING: omap2-nand.0: the ECC used on your system is too weak compared to the one required by the NAND chip
[    0.508454] 13 cmdlinepart partitions found on MTD device omap2-nand.0
[    0.508492] Creating 13 MTD partitions on "omap2-nand.0":
[    0.508537] 0x000000000000-0x000000020000 : "spl1"
[    0.510818] 0x000000020000-0x000000040000 : "spl2"
[    0.512766] 0x000000040000-0x000000060000 : "spl3"
[    0.515759] 0x000000060000-0x000000080000 : "spl4"
[    0.517537] 0x000000080000-0x000000180000 : "u-boot"
[    0.520045] 0x000000180000-0x0000001c0000 : "env1"
[    0.521968] 0x0000001c0000-0x000000200000 : "env2"
[    0.524004] 0x000000200000-0x000000300000 : "u-boot2"
[    0.526587] 0x000000300000-0x000000340000 : "bootparms"
[    0.528468] 0x000000340000-0x000000400000 : "splash"
[    0.530710] 0x000000400000-0x000000a00000 : "kernel1"
[    0.537393] 0x000000a00000-0x000001000000 : "kernel2"
[    0.544046] 0x000001000000-0x000020000000 : "ubisystem"
[    0.952002] vdd_can: 5000 mV 
[    0.952323] reg-fixed-voltage vdd_can_regulator: vdd_can supplying 5000000uV
[    0.952611] vdd_mk2: 5000 mV 
[    0.952908] reg-fixed-voltage vdd_mk2_regulator: vdd_mk2 supplying 5000000uV
[    0.953376] usb_phy_generic hsusb1_phy: Looking up vcc-supply from device tree
[    0.955654] vdd_mpu: 1200 mV 
[    0.956373] vdd_core: 3300 mV 
[    0.956897] vdd_io: 1800 mV 
[    0.957554] vdd_usb18: 1800 mV 
[    0.958377] vdd_usb33: 3300 mV 
[    0.959669] at24 0-0050: 256 byte 24c02 EEPROM, writable, 8 bytes/write
[    0.959765] omap_i2c 48070000.i2c: bus 0 rev3.3 at 400 kHz
[    0.962719] rtc-ds1307 2-0068: rtc core: registered ds1307 as rtc0
[    0.962805] rtc-ds1307 2-0068: 56 bytes nvram
[    0.962866] omap_i2c 48060000.i2c: bus 2 rev3.3 at 400 kHz
[    0.963295] ti_hecc 5c050000.can: Looking up xceiver-supply from device tree
[    0.964868] ti_hecc 5c050000.can: device registered (reg_base=d00dd000, irq=40)
[    0.985943] ehci-omap 48064800.ehci: EHCI Host Controller
[    0.986057] ehci-omap 48064800.ehci: new USB bus registered, assigned bus number 1
[    0.986527] ehci-omap 48064800.ehci: irq 93, io mem 0x48064800
[    1.013917] ehci-omap 48064800.ehci: USB 2.0 started, EHCI 1.00
[    1.014288] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    1.014336] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.014392] usb usb1: Product: EHCI Host Controller
[    1.014429] usb usb1: Manufacturer: Linux 4.9.113 ehci_hcd
[    1.014465] usb usb1: SerialNumber: 48064800.ehci
[    1.015494] hub 1-0:1.0: USB hub found
[    1.015604] hub 1-0:1.0: 3 ports detected
[    1.016735] cpu cpu0: Looking up cpu0-supply from device tree
[    1.017553] cpu cpu0: Looking up cpu0-supply from device tree
[    1.019257] vdd_mpu: ramp_delay not set
[    1.019835] ubi0: attaching mtd12
[    1.374083] usb 1-1: new high-speed USB device number 2 using ehci-omap
[    1.565034] usb 1-1: New USB device found, idVendor=0424, idProduct=2412
[    1.565096] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.566410] hub 1-1:1.0: USB hub found
[    1.566813] hub 1-1:1.0: 2 ports detected
[    1.585148] random: fast init done
[    1.981613] ubi0: scanning is finished
[    1.994964] ubi0: attached mtd12 (name "ubisystem", size 496 MiB)
[    1.995047] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 129024 bytes
[    1.995087] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 512
[    1.995124] ubi0: VID header offset: 512 (aligned 512), data offset: 2048
[    1.995161] ubi0: good PEBs: 3968, bad PEBs: 0, corrupted PEBs: 0
[    1.995197] ubi0: user volume: 3, internal volumes: 1, max. volumes count: 128
[    1.995254] ubi0: max/mean erase counter: 251/105, WL threshold: 4096, image sequence number: 696274219
[    1.995311] ubi0: available PEBs: 371, total reserved PEBs: 3597, PEBs reserved for bad PEB handling: 80
[    1.999156] input: gpio-keys as /devices/platform/gpio-keys/input/input0
[    1.999727] ubi0: background thread "ubi_bgt0d" started, PID 65
[    2.000406] rtc-ds1307 2-0068: setting system clock to 2018-08-03 03:04:25 UTC (1533265465)
[    2.000477] sr_init: No PMIC hook to init smartreflex
[    2.000730] sr_init: platform driver register failed for SR
[    2.001708] vdd_can: disabling
[    2.034727] UBIFS (ubi0:1): UBIFS: mounted UBI device 0, volume 1, name "rootfs2", R/O mode
[    2.034828] UBIFS (ubi0:1): LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    2.034894] UBIFS (ubi0:1): FS size: 208373760 bytes (198 MiB, 1615 LEBs), journal size 9033728 bytes (8 MiB, 71 LEBs)
[    2.034952] UBIFS (ubi0:1): reserved for root: 0 bytes (0 KiB)
[    2.034993] UBIFS (ubi0:1): media format: w4/r0 (latest is w4/r0), UUID DF2D4B80-91CB-4813-A696-6D3C108494F4, small LPT model
[    2.035933] VFS: Mounted root (ubifs filesystem) readonly on device 0:14.
[    2.036456] devtmpfs: mounted
[    2.039076] Freeing unused kernel memory: 1024K
[    2.469190] UBIFS (ubi0:2): background thread "ubifs_bgt0_2" started, PID 88
[    2.510489] UBIFS (ubi0:2): UBIFS: mounted UBI device 0, volume 2, name "data"
[    2.510587] UBIFS (ubi0:2): LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    2.510652] UBIFS (ubi0:2): FS size: 32385024 bytes (30 MiB, 251 LEBs), journal size 1677312 bytes (1 MiB, 13 LEBs)
[    2.510711] UBIFS (ubi0:2): reserved for root: 1529624 bytes (1493 KiB)
[    2.510753] UBIFS (ubi0:2): media format: w4/r0 (latest is w4/r0), UUID 68C57D19-4EB4-4709-88C3-16B53D15FD5D, small LPT model
[    2.664840] udevd[97]: starting version 3.2.2
[    2.677379] random: udevd: uninitialized urandom read (16 bytes read)
[    2.680134] random: udevd: uninitialized urandom read (16 bytes read)
[    2.682672] random: udevd: uninitialized urandom read (16 bytes read)
[    2.736399] udevd[98]: starting eudev-3.2.2
[    6.357031] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" started, PID 317
root@ccgx:/data/log# 
@mpvader mpvader changed the title CCGX stuck while booting CCGX v2.20~48 stuck while shutting down Aug 17, 2018
@mpvader
Copy link
Contributor Author

mpvader commented Aug 17, 2018

Why didn't the watchdog intervene?

A device hanging itself up during reboot is stupid. So, as a precaution it would be best to as a first thing stop the watchdog, to only thereafter stop all services and do whatever else needs doing.

Right now the watchdog is only stopped after various other things are stopped (remeber, init first Kills, then Starts:

root@beaglebone:/etc/rc6.d# ls -al
drwxr-xr-x    2 root     root          1024 Aug 15 13:57 .
drwxr-xr-x   43 root     root          4096 Aug 17 02:06 ..
lrwxrwxrwx    1 root     root            23 Aug 15 13:57 K15svscanboot.sh -> ../init.d/svscanboot.sh
lrwxrwxrwx    1 root     root            16 Aug 15 13:57 K20dbus-1 -> ../init.d/dbus-1
lrwxrwxrwx    1 root     root            17 Aug 15 13:57 K20dnsmasq -> ../init.d/dnsmasq
lrwxrwxrwx    1 root     root            20 Aug 15 13:34 K20dnsmasq.ap -> ../init.d/dnsmasq.ap
lrwxrwxrwx    1 root     root            20 Aug 15 13:57 K20hwclock.sh -> ../init.d/hwclock.sh
lrwxrwxrwx    1 root     root            22 Aug 15 13:34 K20resolv-watch -> ../init.d/resolv-watch
lrwxrwxrwx    1 root     root            16 Aug 15 13:57 K20syslog -> ../init.d/syslog
lrwxrwxrwx    1 root     root            18 Aug 15 13:57 K20watchdog -> ../init.d/watchdog
lrwxrwxrwx    1 root     root            17 Aug 15 13:57 K22connman -> ../init.d/connman
lrwxrwxrwx    1 root     root            15 Aug 15 13:57 K60crond -> ../init.d/crond
lrwxrwxrwx    1 root     root            17 Aug 15 13:57 K60php-fpm -> ../init.d/php-fpm
lrwxrwxrwx    1 root     root            18 Aug 15 13:57 K70hiawatha -> ../init.d/hiawatha
lrwxrwxrwx    1 root     root            18 Aug 15 13:57 K70swupdate -> ../init.d/swupdate
lrwxrwxrwx    1 root     root            20 Aug 15 13:57 K80networking -> ../init.d/networking
lrwxrwxrwx    1 root     root            18 Aug 15 13:23 S20sendsigs -> ../init.d/sendsigs
lrwxrwxrwx    1 root     root            21 Aug 15 13:23 S25save-rtc.sh -> ../init.d/save-rtc.sh
lrwxrwxrwx    1 root     root            22 Aug 15 13:23 S31umountnfs.sh -> ../init.d/umountnfs.sh
lrwxrwxrwx    1 root     root            17 Aug 15 13:23 S38urandom -> ../init.d/urandom
lrwxrwxrwx    1 root     root            18 Aug 15 13:23 S40umountfs -> ../init.d/umountfs
lrwxrwxrwx    1 root     root            16 Aug 15 13:23 S90reboot -> ../init.d/reboot

Wouldn't stopping the watchdog risk also tripping systems that are still rebooting?

No: the kernel driver expects a write to the watchdog device every minute. The userland watchdog process updates the kernel every 10 seconds: stopping it therefore leaves at least 50 seconds for the device to reboot.

Proposed change

Change the watchdog to K00watchdog, so when entering runlevel 6, the first thing done is stopping the watchdog.

mpvader added a commit to victronenergy/meta-victronenergy that referenced this issue Aug 17, 2018
A device hanging itself up during shutdown as part of a reboot is stupid.
Therefore, the first to do when initiating a reboot is to stop the watchdog.

Wouldn't this risk interrupting a reboot that was otherwise OK?

No the kernel driver expects a write to the watchdog device every minute.
The userland watchdog process updates the kernel every 10 seconds: stopping
it therefore leaves at least 50 seconds for the device to reboot.

Also add a message to the syslog, to make the log file clear:
Aug 17 11:07:07 ccgx user.notice shutdown[2127]: shutting down for system reboot
Aug 17 11:07:07 ccgx daemon.info init: Switching to runlevel: 6
Aug 17 11:07:07 ccgx user.notice root: Stopping watchdog (keeping hw watchdog alive)
Aug 17 11:07:07 ccgx user.crit kernel: [  236.577026] omap_wdt: Unexpected close, not stopping!

victronenergy/venus#312
mpvader added a commit to victronenergy/meta-victronenergy that referenced this issue Sep 7, 2018
A device hanging itself up during shutdown as part of a reboot is stupid.
Therefore, the first to do when initiating a reboot is to stop the watchdog.

The processes stopped before the watchdog where:
K15svscanboot.sh -> ../init.d/svscanboot.sh
K20dbus-1 -> ../init.d/dbus-1
K20dnsmasq -> ../init.d/dnsmasq
K20hwclock.sh -> ../init.d/hwclock.sh
K20resolv-watch -> ../init.d/resolv-watch
K20syslog -> ../init.d/syslog
K20watchdog -> ../init.d/watchdog

With this commit its the first thing.

Wouldn't this risk interrupting a reboot that was otherwise OK?

No the kernel driver expects a write to the watchdog device every minute.
The userland watchdog process updates the kernel every 10 seconds: stopping
it therefore leaves at least 50 seconds for the device to reboot.

Also add a message to the syslog, to make the log file clear:
Aug 17 11:07:07 ccgx user.notice shutdown[2127]: shutting down for system reboot
Aug 17 11:07:07 ccgx daemon.info init: Switching to runlevel: 6
Aug 17 11:07:07 ccgx user.notice root: Stopping watchdog (keeping hw watchdog alive)
Aug 17 11:07:07 ccgx user.crit kernel: [  236.577026] omap_wdt: Unexpected close, not stopping!

closes victronenergy/venus#312
@jhofstee
Copy link
Contributor

Another one getting stuck on reboot, idSite 12032. Note, this is with the watchdog "fix"

ls  /etc/rc6.d/*watchdog
/etc/rc6.d/K00watchdog

cat /opt/victronenergy/version          
v2.20~57
Victron Energy
20180827204811

2018-08-31 02:48:55.346865500 Retrieving latest version (feed=candidate)...
2018-08-31 02:48:56.250569500 installed: 20180827204811 v2.20~57
2018-08-31 02:48:56.257577500 available: 20180829161619 v2.20~58
2018-08-31 02:48:56.429238500 Starting swupdate to install version 20180829161619 v2.20~58 ...
2018-08-31 02:48:56.614771500 software set: stable mode: copy1
2018-08-31 02:48:57.639766500 Swupdate v2016.10.0
....
2018-08-31 02:51:35.269618500 [NOTIFY] : SWUPDATE running :  [update_uboot_env] : Updating U-boot environment
2018-08-31 02:51:35.399716500 [NOTIFY] : SWUPDATE successful ! SWUPDATE successful !
2018-08-31 02:51:35.415100500 [NOTIFY] : SWUPDATE running :  [network_initializer] : Main thread sleep again !
2018-08-31 02:51:35.445492500 [NOTIFY] : No SWUPDATE running :  Waiting for requests...
2018-08-31 02:51:36.243029500 Main loop Daemon
2018-08-31 02:51:36.262464500 do_swupdate completed OK. Rebooting

uname -a                       
Linux ccgx 4.14.67 #1 Mon Aug 27 22:50:14 CEST 2018 armv7l GNU/Linux

Logs are completely filled with:
Sep 10 09:32:17 ccgx user.err kernel: [1148389.178867] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148389.298615] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148389.418479] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148389.538655] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148389.658471] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148389.778568] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148389.898624] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:17 ccgx user.err kernel: [1148390.018517] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:18 ccgx user.err kernel: [1148390.138475] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:18 ccgx user.err kernel: [1148390.258534] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0
Sep 10 09:32:18 ccgx user.err kernel: [1148390.378452] usb-storage: Error in queuecommand_lck: us->srb = ce7ea2d0

CPU:   9% usr   7% sys   0% nic   0% idle  82% io   0% irq   0% sirq

   86 root         0 DW   [udevd]
   90 root         0 DW   [usb-storage]
23934 root      1944 D    shutdown -r 0 w


root@ccgx:~# date
Mon Sep 10 09:34:42 UTC 2018
root@ccgx:~# uptime
 09:34:43 up 13 days,  7:02,  load average: 3.44, 3.39, 3.44

@jhofstee
Copy link
Contributor

Closing this as it is the broken USB pendrive causing this. The pendrive is mounted again after a wd reset. Just use a better pendrive for now. We can always make an issue for this itself if we get many complaints about it.

@jhofstee
Copy link
Contributor

reopening this since hub2 got stuck during usb pendrive update test on hub2 groningen:

Sep 20 19:28:01 ccgx daemon.info connmand[786]: eth0 {del} route 212.227.81.55 gw 192.168.4.1 scope 0 <UNIVERSE>
Sep 20 19:28:31 ccgx daemon.info connmand[786]: ntp: time slew -0.004862 s
Sep 20 19:28:45 ccgx user.notice shutdown[1585]: shutting down for system reboot
Sep 20 19:28:45 ccgx daemon.info init: Switching to runlevel: 6
Sep 20 19:28:45 ccgx daemon.info connmand[786]: Terminating
Sep 20 19:28:46 ccgx daemon.err connmand[786]: Time request for server 192.168.4.1 failed (101/Network is unreachable)
Sep 20 19:28:46 ccgx daemon.err connmand[786]: Time request for server 192.168.4.1 failed (101/Network is unreachable)
Sep 21 08:22:49 ccgx syslog.info syslogd started: BusyBox v1.24.1

@jhofstee jhofstee reopened this Sep 21, 2018
@jhofstee
Copy link
Contributor

closing again, since the watchdog is simply not included in the test image...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants