maemo-optify-boottime.log growing every boot
 

Since the last week I have found that the log file /var/log/maemo-optify-boottime.log is growing with a new record on every boot. The records are like this:
2012-10-31 18:05:25 :: not enough free space in /home (need at least 200 MB free), quitting.
1+0 records in
1+0 records out
512 bytes (512B) copied, 1.222565 seconds, 418B/s

The script which is generating the log is /usr/sbin/maemo-optify-auto-opt.sh, which calls the function dfree inside /usr/sbin/maemo-optify-lib.sh. dfree function is as follows

If you execute the command you get two integers, not only one, and the last one is 0 (the first one is 512 in my phone). Indeed, I have made an script to see the value of the returned $space variable, and it is 0!!! Obviously I have plenty of space in /home directory. I cannot understand why it happens only since the last week. Any idea?

On the other hand, I do not know where the /usr/sbin/maemo-optify-auto-opt.sh is called from on every boot of the phone. The file checks if everything is optified, and it is not required now.

Thanks in advance.

Re: maemo-optify-boottime.log growing every boot
 

@ikerrg,

(I just answered this on the other thread "Random reboot..")

Very interesting analysis. I don't have /usr/sbin/maemo-optify-auto.sh (but I may have removed many Nokia packages). Could you please do "dpkg -S /usr/sbin/maemo-optify-auto.sh" to see from which package this thing is coming?

Furthermore, that way of checking space using stat seems quite broken.

$5 is the block size, but
$9 is the total number of inodes

so the dfree() function is mixing apples with bananas

It should either use df[*] or replace $9 with $8, which is the number "available blocks" ($9 is the number of "free blocks", don't know what the difference may be).

Plus I don't know why awk returns two values when multiplying. Seems that busybox is way beyond broken (I tested with latest busybox-power).[*]
Good luck.

PS: I do have (in my most "normal" N900) a /var/log/maemo-optify-boottime.log, last modified about 8 months ago. Nothing in the boot process seems to be touching it, so it must have come from some package that I have uninstalled.

Re: maemo-optify-boottime.log growing every boot
 

@reinob

The file /var/log/maemo-optify-boottime.log is coming from the package maemo-optify-runonce. Why you don't have it installed? It is odd, I have not changed any official package in my device and it is reflashed one month ago with the latest rootfs and eMMC images.
In addition, I do not understand why since the last week a process is executing this file on boot. How can I find where it is called on booting?

Re: maemo-optify-boottime.log growing every boot
 

Well, I guess the "runonce" made me decide to uninstall it. If it was (pre-)installed and did its thing already ("once"), then why should it continue to be installed polluting my dpkg database :)

AFAIK in /etc/event.d/rcS-late (where /home is mounted) and (where one of the possibilities for *generating a reboot loop* is present -- "if fail to mount /home and system already optified")

When /home is mounted OK and not in ACT_DEAD mode /usr/sbin/maemo-optify-firstboot.sh is called.

Then /opt is mounted, and then /usr/sbin/maemo-optify-auto-opt.sh is called (if it exists).

So I guess the script (if it exists) runs at *every* boot, makes a messy calculation of a bogus number and logs it in a file taking space in rootfs (not much, but hey..)

I'd suggest you just uninstall every package containing the string "optify" *except* pymaemo-optify. That's a whole different beast, and I still have to find a nice way of having optified-python without all that bind-mounting party.

Re: maemo-optify-boottime.log growing every boot
 

Thanks again! I will try to play with the booting process to learn a bit more :) And also I will consider removing optify packages, though maemo-optify-runonce is considered that it is used for when you update your rootfs, to be sure that everything is optified.

Anyway, you said that in your most "normal" N900 you also have the file /usr/sbin/maemo-optify-auto-opt.sh . If it is being executed on every boot like in my N900, why in your device it is not logging anything into /var/log/maemo-optify-boottime.log? I think the calculation of the bogus number should be the same in your device as in my device.
Something should have changed in my phone in the last week because the logfile had no records from before, and now it is growing.

Re: maemo-optify-boottime.log growing every boot
 

Well, I don't (still) know what exactly those packages "optify", i.e. how they decide which file/folder to move away and symlink. It might be useful, but most probably not :)

Nope. I said I have the log in /var/log but not the script in /usr/sbin. In fact, thanks for reminding me to delete that log :)

From what I've been able to read from the .deb the script will check if the log has reached a certain size, and if so, delete it and start again. Probably this is what happened to you, and you just happened to notice that log file after the first log/previous logs had already been deleted.

If you find anything interesting, let us (at least me :) know! :)

Re: maemo-optify-boottime.log growing every boot
 

You have more info about the set of scripts in http://maemo.gitorious.org/maemo-af/...e/trees/master
The file maemo-optify-auto-opt.conf shows what is checked for optification. Not very useful.

OK, I think you got it!!! This must be the reason. So it is a bogus code in the original maemo scripts!!

Only one thing about your code. The dfree function outputs the free size (at least it should) in MiB. So you should change your code to:
Very smart code, indeed!! I will change it in the original script and check what happens.

Regarding your optimizations in your N900, it would be very interesting if your write a guide about which packages, boot scripts and whatever can be removed/commented in order to make N900 faster. It seems very interesting for me!!

Re: maemo-optify-boottime.log growing every boot
 

@reinob

Although the updated code for dfree works in the commandline and shows the space available (25450 MiB for me), it shows a different value when executed from inside a script. I have made a test script trying to understand what the boot time script is really getting:

It uses the same codes as the original script to call the dfree function. For me, the result of this script is 144 MiB, lower than the required 200 MiB, and therefore the message is still being logged to the file on boot time. Any idea? I'm not expert on linux scripts.

Thanks.

Re: maemo-optify-boottime.log growing every boot
 

Well, this is becoming a challenge for me. I have changed the dfree function to include the path to search for space in. ($1)

Now it perfectly returns the value of the rootfs free space (dfree "/"), but it fails for /home space. When called from my test script, I get about 70 MiB for / free space, but only 167MiB for /home free space, even when a direct commandline call to
df -B 1048576 /home | tail -1 | awk '{ print int($4) }' shows 1447 MiB. What could be the problem? Is the problem in my test script (the echo $? command)?

Thanks.

P.D.
It seems that if I modify my test script echoing the dfree result as $space instead of $?, the value returned is correct.
However, the original maemo script (/usr/sbin/maemo-optify-auto-opt.sh) is using the method $?, and therefore it cannot get the correct value for the free space. Am I right? Why $? method works for rootfs free space (70) and not for /home free space (1447)?

Re: maemo-optify-boottime.log growing every boot
 

Weird. Just as a test, change the command to

df -m $1 | tail -1 | awk ' { print $4 } '

with -m you get the megabytes directly. I suspect int() may be doing something weird.

Re: maemo-optify-boottime.log growing every boot
 

No change. Still the same difference. $? is not geting the correct output value from the function for the /home free space when called from my test script. Indeed, the same happens if your try to get the space of /media/mmc1 (which in my case is 25745 MiB). The output number by echo $? is 145!!!

Edit: I have tested the same scripts in my computer's Ubuntu,and the output of the function is the same using echo $? than using echo $space (free space is 7418 MiB in my Ubuntu) . Maybe maemo is using a function output of byte type and numbers longer than 256 cannot be represented. However, Ubuntu works OK for long numbers. Any idea?

Re: maemo-optify-boottime.log growing every boot
 

Don't know about Ubuntu, but program exit codes should be 8-bit (0-255).
I cannot check that at the moment, but I think your explanation is spot-on.

If you echo $space then it works OK, because $space can hold any value. But $? can, by definition, only be between 0 and 255, so it would explain your observations.

Given that filing a bug report is next-to-useless and Nokia will anyway not fix this, I would suggest you contact the CSSU people and report the bug (an easy solution would be to remove the dfree() function and just "inline" it where it's needed, which is at most 2 or 3 places).

Well done!

Re: maemo-optify-boottime.log growing every boot
 

Well, the issue is not big, one can survive with it. Even the best option is uninstalling the full package as you said. However, I liked to learn why it was happening.

Indeed, the dfree() function seems to only be used inside maemo-optify-auto-opt.sh, so only changing the two $? in that script is enough to fix the problem.

Edit: Confirmed!! Changing the dfree funcion as indicated and the two $? inside the maemo-optify-auto-opt.sh script (by $space) make the log error dissapear. However, now there is not an error in the log, but an info message:
optification session started
optification session completed