Huge MBL Operating System File - Could It Be Preventing Sleep?

WD “pounding the logs” Tony,
The large file that I originally observed on 16 Oct 2011 (two days after initial power up) was /var/log/user.log. By 28 Nov 2011 (but possibly earlier than this) the bulk of the contents of user.log had been transferred (not by me but presumably by the OS) to daemon.log.1. It was the deletion of daemon.log.1 that after a reboot finally allowed my MBL to Sleep for a period greater than 61 seconds and for the hard drive to totally spin down for the first time. Perhaps it was your pruning operation that transferred the bulk of the contents of user.log to daemon.log.1
WilliamH

I thinking pruning happens at 6:25am?  (… or is that pm?)

Myron,
I think you are correct about 6:25 AM - if not pruning, then at least something seems to happen pretty regularly at 06:25. Once the 625 MB file (daemon.log.1) got manually deleted and my MBL was finally able to Sleep/Standby, it never slept more than 85,793 seconds (approx 23 hours 50 min (with Sleep set to start after 10 minutes)) and seemed to wake up, more often than not, at 06:25 AM:

Nov 29 06:25:11 localhost logger: exit standby after 7547
Nov 29 06:35:19 localhost logger: Enter standby
Nov 30 04:28:41 localhost logger: exit standby after 78802
Nov 30 04:38:48 localhost logger: Enter standby
Nov 30 06:25:11 localhost logger: exit standby after 6383
Nov 30 06:35:18 localhost logger: Enter standby
Dec  1 06:25:11 localhost logger: exit standby after 85793
Dec  1 06:35:19 localhost logger: Enter standby
Dec  1 06:52:11 localhost logger: exit standby after 1012
Dec  1 07:02:19 localhost logger: Enter standby
Dec  2 01:07:19 localhost logger: exit standby after 65100
Dec  2 01:17:27 localhost logger: Enter standby
Dec  2 06:25:12 localhost logger: exit standby after 18465
Dec  2 06:35:19 localhost logger: Enter standby
Dec  3 06:25:12 localhost logger: exit standby after 85793
Dec  3 06:35:19 localhost logger: Enter standby
Dec  4 00:57:11 localhost logger: exit standby after 66112
Dec  4 01:07:18 localhost logger: Enter standby
Dec  4 06:25:11 localhost logger: exit standby after 19073
Dec  4 06:35:19 localhost logger: Enter standby
Dec  4 06:47:11 localhost logger: exit standby after 712
Dec  4 06:57:18 localhost logger: Enter standby
Dec  5 06:25:11 localhost logger: exit standby after 84473

However I must note, as WDTony has observed, that WDs pruning algorithm did not catch the huge file size that was causing the Sleep problem. Although “user.log” got pruned, the bulk of its huge contents (the 7,093,007 ‘cnid_metad’ lines that got generated within the first 34 minutes of initial power-up) actually got transferred over intact to “daemon.log.1”
WilliamH

Yep . . .

NAS:/etc# cat crontab
# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# m h dom mon dow user command
17 * * * * root cd / && run-parts --report /etc/cron.hourly
25 6 * * * root test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6 * * 7 root test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6 1 * * root test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )
#


NAS:/etc# l /etc/cron.daily
total 60
-rw-r--r-- 1 root root 102 Mar 4 2010 .placeholder
-rw-r--r-- 1 root root 2863 Aug 26 03:18 20-checkRAID
-rwxr-xr-x 1 root root 633 Mar 4 2010 apache2
-rwxr-xr-x 1 root root 7482 Mar 4 2010 apt
-rwxr-xr-x 1 root root 314 Mar 4 2010 aptitude
-rwxr-xr-x 1 root root 502 Mar 4 2010 bsdmainutils
-rwxr-xr-x 1 root root 384 Mar 4 2010 cracklib-runtime
-rwxr-xr-x 1 root root 4073 Mar 4 2010 exim4-base
-rwxr-xr-x 1 root root 73 Jun 30 03:03 fw_check
-rwxr-xr-x 1 root root 1154 Mar 4 2010 ntp
-rwxr-xr-x 1 root root 75 May 26 2010 ramlog
-rwxr-xr-x 1 root root 383 Mar 4 2010 samba
-rwxr-xr-x 1 root root 3349 Mar 4 2010 standard
-rwxr-xr-x 1 root root 469 Mar 24 2010 sysstat
NAS:/etc# l /etc/cron.weekly
total 4
-rw-r--r-- 1 root root 102 Mar 4 2010 .placeholder
NAS:/etc# l /etc/cron.monthly
total 8
-rw-r--r-- 1 root root 102 Mar 4 2010 .placeholder
-rwxr-xr-x 1 root root 129 Mar 4 2010 standard
NAS:/etc#

I can confirm this problem as well. I raised a case about it…

cnid_metad error in accept Socket operation on non-socket [deleted]

This message as shown in the subject line is being spewed into /var/log/daemon.log at over three thousand entries per second. I’m watching the file grow. from 87MB byte to 88MB bytes in less than 20 seconds. This problem happened when I was on 2.3 firmware and is still happening on 2.10 firmware (latest at time of posting). You can stop this message by shutting down the AFP netatalk service (filesharing) with /etc/init.d/netatalk stop. When you start it again it starts spewing log messages again.

I have searched forums to no avail. Something is misconfigured.

[deleted for privacy]

I actually feel very sorry for W.D. first level technical support. I would be quite resistant to wanting to have a user access to the Linux shell and command line to do things when the user might not be able to follow instructions correctly.

It’s a bit of a difficult situation for Western Digital.

One needed “fix” or patch is to have the daemons for netatalk ("/etc/default/netalalk") not run when iTunes is disabled. But then Mac users probably will still have problems. After changing “yes” to “no” in the netatalk file, my daemon.log & ramlog files are only about 3k.

Need my mac to access it, thus just did link of file to /dev/null. Unit sleeps fine.

I’ve escalated this thread to our product people to look at. 

anotherpaul wrote:
One needed “fix” or patch is to have the daemons for netatalk ("/etc/default/netalalk") not run when iTunes is disabled. But then Mac users probably will still have problems. After changing “yes” to “no” in the netatalk file, my daemon.log & ramlog files are only about 3k.

However if you have a Mac on your network then you cannot do this. While it will stop the log spewing information its not a solution to just turn it off. I did solve my problem in the end…

After copying all my files off the MBL to another machine yesterday I did a full factory restore. Since I no longer had access to the UI because of an installation issue, I had to do this manually with /usr/local/sbin/factoryRestore.sh ; reboot (reboots immediately but takes a couple of hours before its ready). Now the MBL is behaving as expected and is no longer showing this issue. We are seeing the unit go into standby mode now  for the first time since we bought it. Even more surprising is Time Machine backup is also working for the first time with an i7 iMac running OSX Lion.

Additional Notes: I have turned off media sharing under Twonky and iTunes (Settings-> Media) because we dont use it. The overhead is significant and the UI runs quite a bit faster when they are off.

Hope this helps people out there.

Jarvil

My MBL’s log file also very large and it is wasteful. Is there any script to clean log files weekly? And can I use cron job to run this .php file to make it run weekly?

I read some posts on huge log files that disable MBL sleep feature.

I recently try to use uTorrent to write directly on MBL (while downloading and after download).

After this my MBL did not sleep again.

I saw that kern.log.1 file was about 16MB: it is full of

Apr 14 12:02:16 MyBookLive kernel: imklog 3.18.6, log source = /proc/kmsg started.
Apr 14 12:02:16 MyBookLive kernel: net/ipv4/tcp.c:tcp_splice_read:702
Apr 14 12:02:16 MyBookLive kernel: signal pending recd during tcp splice read … returning -512.
Apr 14 12:02:16 MyBookLive kernel: fs/splice.c:do_splice_2:2637

May this be the cause?

Yesterday I received my mybooklive 2TB with firmware 02.02.02-020 installed. After asking the group here I successfully updated the f/w first to 021009-124 then to 021012-129 by downloading the deb files and using the “update from file” button in the dashboard. All went OK and my drive seemed to respond faster.

As it was late I shut all devices off but this morning noticed the mybooklive had not gone to sleep, even though I hadn’t started to put any files on the drive, it was as it arrived plus the two f/w updates. The log file indicated it slept for between 60 and 62 seconds every 10 minutes throughout the night.

I discovered this thread about the size of the daemon.log.1 causing this. I checked on mine at it was 120Mb.

I deleted it and rebooted the device, during the last couple of hours its has been to sleep for a max of 1163 seconds so it definitely helped, I will see what happens overnight…

Barry

daemon.log.1 should not reach the size of 120Mb.  The RAMLOG service would have quit and all logs written to the disc directly so the MBL won’t sleep.  Storage space allocated to RAMLOG is 20Mb. What that is exceeded then everything is written to disc.  When the Linux OS partition fills up then everything else starts to fail.  usuallt the Web UI fails.

If you don’t already have SSH access turned on, turn it on now.  Remember NOT to forward port 22 to the Internet on the router before you enable SSH.