Bug 1259

I can confirm the file:// does not work where http:// works ok. The comment above the SSTATE_MIRRORS variable in conf/local.conf seems to indicate the same thing.

I just ran some tests on this locally. Specifically, I had:

SSTATE_MIRRORS ?= "\
file://.* file:///media/build3/work/b2/sstate/"

in my local.conf, I then ran "bitbake bash" and it quickly jumped to compiling bash running many setscene tasks as expected using the cache. I've tried various things like changing DL_DIR in the second build, using a different build directory for the second build and so on but I cannot reproduce this :(.

Is it possible the ?= in the SSTATE_MIRRORS assignment is causing issues with some other value you have set? Can you double check the steps to show the bug and see if there any details you can add to aid reproduction of the issue please? A copy of the local.conf you're using (not just the diff) might give me some ideas although I'm puzzled by this...

In response to Matthew's comments, I have updated local.conf.sample to improve the comment to be more accurate (file:// urls are supported).

Created attachment 192 [details]
Config file with SSTATE_MIRRORS set

Derived from local.conf.sample with these changes:
  * DL_DIR
  * MACHINE
  * SSTATE_MIRRORS

In my test case, "/local" is really a symbolic link to "/raid/local"
Could this have any effect on this issue?  I did try to set the full
path in SSTATE_MIRRORS, but that didn't seem to change anything.

I've tried a symlink here and it still worked as expected.

This might sound crazy but can you see if adding some blank lines at the end of local.conf helps? I think I can reproduce a problem if there SSTATE_MIRRORS is the last line in local.conf with no empty lines.

Initially I didn't spot this as I needed to clean out SSTATE_DIR as it will setup symlinks in there to local file:// urls mirrors.

Sorry, no difference with extra lines at the end of local.conf

Is there more data I can gather that might show:
  * If the cache is even being checked?
  * Why the cached data is being rejected?

Created attachment 193 [details]
Debugging Patch

I've added a patch which makes the sstate code more verbose, see if that helps shed any light on where its going wrong.

What I have noticed locally is I can end up seeing:

NOTE: Testing sstate mirror: "file://.* file:///media/build3/work/b2/sstate/

and the stray " in there is a problem. That looks like a bitbake parsing bug which I'm looking into.

Created attachment 194 [details]
Bitbake Parsing Fix

Gary, could you give this patch a try and see if it fixes the problem you were seeing. It fixes an issue in bitbake for multiline variable parsing in .conf files. The result would have been visible by printing out the value of SSTATE_MIRRORS as it would have had a stray " character in it previously.

Created attachment 195 [details]
Build output

I'm a bit confused by these lines:

NOTE: Testing sstate mirror: file://.* file://raid/work/test/qemu_build1/sstate-cache/
NOTE: file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-c0564fb6291f2c5db771de16eb273f47_populate-sysroot.tgz

Is this path unexpanded?

Later, the build checks this

Checking for /raid/work/test/qemuarm_build3/sstate-cache/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-c0564fb6291f2c5db771de16eb273f47_populate-sysroot.tgz

This file doesn't exist (virgin build), but it does exist in qemuarm_build1/...
with the same checksum, etc.

TGary,(In reply to comment #11)
> Created attachment 195 [details]
> Build output

Gary, could you check the attachement please as I don't think its what you meant to add.
 
> I'm a bit confused by these lines:
> 
> NOTE: Testing sstate mirror: file://.*
> file://raid/work/test/qemu_build1/sstate-cache/

What jumps out at me here is file://, not file:///

> NOTE:
> file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-c0564fb6291f2c5db771de16eb273f47_populate-sysroot.tgz
> 
> Is this path unexpanded?

No, this is correct. That code tries to find a file called "sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-c0564fb6291f2c5db771de16eb273f47_populate-sysroot.tgz" and to do so it will check SSTATE_DIR along with any PREMIRRORS that are setup and match that url. The debug output is not clearly worded, the intent was just to dump info about which code paths it was hitting.

> Later, the build checks this
> 
> Checking for
> /raid/work/test/qemuarm_build3/sstate-cache/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-c0564fb6291f2c5db771de16eb273f47_populate-sysroot.tgz
>
> This file doesn't exist (virgin build), but it does exist in qemuarm_build1/...
> with the same checksum, etc.

Right, its not searching the mirror, likely due to the file:// vs. file:/// issue. At least the checksums matching rules out a certain class of problems! :)

Created attachment 196 [details]
Actual build output

Sorry about the attachment mixup :-(  Fixed

It looks like we might have had two problems here:
  * The parsing bug which you fixed
  * A typo I introduced during the testing - file:/// became file://
    when I checked symbolic link vs real path.  In my example /local == /raid/work/test

Sadly, fixing this pattern with file:/// didn't help.  The same lines as
before are now:

NOTE: Testing sstate mirror: file://.* file:///raid/work/test/qemu_build1/sstate-cache/
NOTE: file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-f4ab282746c2b313ca8354803bd0f1f9_populate-lic.tgz

I just tried it with http:// pattern and I see this:

NOTE: Testing sstate mirror: file://.* http://192.168.1.125/sstate/ \n file://.* file:///local/p60_latest/sstate-cache/
NOTE: file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
NOTE: fetch http://192.168.1.125/sstate/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz

However, my HTTP log does not show any access to any of these files.

Created attachment 197 [details]
Updated debugging patch

Hi Gary,

I've attached an updated debugging patch. This one instruments the fetcher component that does url replacement so locally I see output like:

NOTE: uri_replace: replacing file://.* with file:///media/build3/work/b2/sstate/sstate-gmp-native-x86_64-linux-5.0.2-r0-x86_64-2-3460410f454e82b991f0bf5ffae61c44_populate-lic.tgz

so we should further be able to pinpoint what's happening.

Can you confirm that my parsing fix is applied (its also in the debug patch I've just realised).

(In reply to comment #15)
> Created attachment 197 [details]
> Updated debugging patch
> 
> Hi Gary,
> 
> I've attached an updated debugging patch. This one instruments the fetcher
> component that does url replacement so locally I see output like:
> 
> NOTE: uri_replace: replacing file://.* with
> file:///media/build3/work/b2/sstate/sstate-gmp-native-x86_64-linux-5.0.2-r0-x86_64-2-3460410f454e82b991f0bf5ffae61c44_populate-lic.tgz
> 
> so we should further be able to pinpoint what's happening.
> 
> Can you confirm that my parsing fix is applied (its also in the debug patch
> I've just realised).

With this patch, I'm seeing output like this:

NOTE: Testing sstate mirror: file://.* http://192.168.1.125/sstate/ \n file://.* file:///local/p60_latest/sstate-cache/
NOTE: file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
NOTE: Attempting fetch for file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
NOTE: uri_replace: replacing file://.* with http://192.168.1.125/sstate/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
NOTE: fetch http://192.168.1.125/sstate/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
NOTE: Exception when attempting fetch for file://sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz

I'm not sure why the exception, I just tried it directly with no error (cut & paste the path from the message):

$ wget http://192.168.1.125/sstate/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
--2011-07-20 09:31:47--  http://192.168.1.125/sstate/sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz
Connecting to 192.168.1.125:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: 1324610 (1.3M) [application/x-tgz]
Saving to: “sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz”

100%[===============================================================================>] 1,324,610   --.-K/s   in 0.02s   

2011-07-20 09:31:47 (80.9 MB/s) - “sstate-pseudo-native-i686-linux-1.1.1-r1-i686-2-1d9a8078bb541781ff99c66771467f84_populate-sysroot.tgz” saved [1324610/1324610]

I've tried this a number of times and now I see what the problem was.
Note this from the original comment:
  % diff -u qemuarm_build?/conf/local.conf
  --- qemuarm_build1/conf/local.conf      2011-07-19 13:15:38.000000000 +0100
  +++ qemuarm_build2/conf/local.conf      2011-07-19 15:40:51.000000000 +0100
  @@ -216,3 +216,7 @@
   # The network based PR service host and port
   #PRSERV_HOST = "localhost"
   #PRSERV_PORT = "8585"
  +
  +# Reusable state information
  +SSTATE_MIRRORS ?= "\
  +file://.* file:///local/qemu_build1/sstate-cache/"

That last line should have read
  +file://.* file:///local/qemuarm_build1/sstate-cache/"

Subtle, but oh so frustrating.  Duh :-(

With this fixed, it seems to be working.  I tried it without the parser change and this doesn't seem to affect the result (still works).  Everything was just the result of my typo.  I wonder if a warning could be issued if during the early phases (where it seems that every sstate cache file which might be needed is being enumerated) if none of the desired cache files exist or can be accessed?  This might give a clue that the setup is incorrect.  Just a thought.

Sorry for the [extreme] noise!

(In reply to comment #17)
> I wonder if a warning could be issued if during the
> early phases (where it seems that every sstate cache file which might be needed
> is being enumerated) if none of the desired cache files exist or can be
> accessed?  

It would be very nice to see when we have a cache hit or miss and possibly a summary.

-M

We could do with improving the debug messages to make this kind of issue easier to debug which is what needs to be done to close out this bug.

Debug messages have now been added to builds in http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=6ede10595349dcba0cac6f421f5af90403420f0e