I am pleased to report that the inability to Sleep problem that has plagued my MBL 3TB since its initial power-up on 14 Oct 2011 has been resolved.
The Problem:
The problem has always been that my MBL has never gone to Sleep/Standby. The file /var/log/user.log typically reports that the drive enters Sleep/Standby for a maximum period of 61 seconds every 10 minutes or so (when not being accessed by a browser). In fact the problem was actually worse than that because even though the log indicated a 61 second Sleep/Standby period and the activity LED changed from Green to Blue for 61 seconds, the drive never actually totally spun down. By listening to the drive I determined that power was removed from the drive when the LED changed from Green to Blue. The drive would start to spin-down however within less than one second power would be re-applied and the drive would start to spin-up again (before it had had a chance to totally stop spinning). The log and LED indicate a 61 second Sleep/Standby period but the actual hard drive inside the MBL was not even doing that minimal shutdown.
Oct 26 00:29:00 localhost logger: Enter standby
Oct 26 00:30:01 localhost logger: exit standby after 61
Oct 26 00:38:28 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:38:28 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:38:40 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:40:40 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:40:40 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:41:35 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:41:35 localhost apache2: 192.168.0.11 WebUI::session_id=d93e21b83c94185858db5bc3641a913c
Oct 26 00:53:17 localhost logger: Enter standby
Oct 26 00:54:18 localhost logger: exit standby after 61
Oct 26 01:05:27 localhost logger: Enter standby
Oct 26 01:06:28 localhost logger: exit standby after 61
(and so on)
As suggested in my initial posting of Mon 28 Nov 2011 in this thread, the problem was subsequently determined to be the huge file (var/log/daemon.log.1 of 659,648,549 bytes in size) that had been generated during the first 34 minutes after the drives initial power-up. There were 7,093,007 lines of the form
āDec 31 19:00:57 MyBookLive cnid_metad[2214]: error in accept: Socket operation on non-socketā
that created the huge size of the file (originally in file āuser.logā but subsequently transferred by the OS (after a F/W upgrade?) to the file ādaemon.log.1ā
The Fix:
The fix was simple. I deleted the file ādaemon.log.1ā and although it did not immediately resove the problem, it did resolve the problem after a shut-down via the Dashboard and a subsequent power-up. During the reboot the OS must have detected the greatly reduced size of the files in the ā/var/logā directory and this subsequently allowed the drive to enter Sleep/Standby. An extract from the file /var/log/user.log showing the MBLs newly acquired ability to Sleep/Standby is attached below. As you can see from the log file, a couple of times in the past week the drive was actually in Sleep for 85,793 seconds - thatās approximately 23.83 hours. I confirmed, by listening to the drive, that when the Blue LED was on, the drive was not spinning but was in fact now totally powered-down. Wow, what a change. The log file with the new Sleep/Standby capability is attached below:
Nov 28 10:50:31 localhost logger: Starting orion services: miocrawlerd, mediacrawlerd, communicationmanagerd
Nov 28 10:50:33 localhost logger: WD NAS: Email alerts REST API failed to return Success
Nov 28 11:02:41 localhost logger: Enter standby
Nov 28 11:09:11 localhost logger: exit standby after 390
Nov 28 11:26:23 localhost logger: Enter standby
Nov 28 11:29:31 localhost logger: exit standby after 188
Nov 28 11:49:45 localhost logger: Enter standby
Nov 28 12:09:17 localhost logger: exit standby after 1172
Nov 28 12:28:31 localhost logger: Enter standby
Nov 28 23:26:58 localhost logger: exit standby after 39507
Nov 28 23:37:05 localhost logger: Enter standby
Nov 29 03:03:55 localhost logger: exit standby after 12410
Nov 29 03:05:13 localhost logger: WD NAS: Email alerts REST API failed to return Success
Nov 29 03:14:01 localhost logger: Enter standby
Nov 29 03:26:21 localhost logger: exit standby after 740
Nov 29 03:36:28 localhost logger: Enter standby
Nov 29 03:39:17 localhost logger: exit standby after 169
Nov 29 03:49:24 localhost logger: Enter standby
Nov 29 04:09:17 localhost logger: exit standby after 1193
Nov 29 04:19:24 localhost logger: Enter standby
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
Needless to say Iām now a happy camper with this new development and am looking forward to finally starting to use my MBL for the purposes for which it was originally designed.
Recommendations for WDC:
Assuming the code that generated the huge file in the first place is under WDCs control. I would suggest they look into the merit of the following recommendations to try and prevent a reoccurance of this (presumably unusual) situation in the future and remedy any drives that currently have the problem.
1.) Suggest that the code that canveses the socket connection; the code that generated the huge number of lines of the form:
āDec 31 19:00:57 MyBookLive cnid_metad[2214]: error in accept: Socket operation on non-socketā
be throttled back to not canvas the socket so often. It was generating over 200,000 lines per minute (over 3300 queries pe second) and these were all logged and contributed to the huge size of the log file. Suggest the canvas of the socket be reduced to perhaps once per second or once every 5 seconds. If the socket had not been canvased so often then the huge file that created the Sleep problem would not have occurred. If this is not possible then perhaps not logging all the socket operations could be considered.
2.) Suggest that during the next firmware update, that WDC incorporate code that looks at the size of the files in certain critical directories and if the files are too large and thus could be creating the Sleep problem, that they be reduced in size or deleted.
Trust that this posting is of some use to the WD MBL Community.
Regards, WilliamH