Race condition in packaged staging?

Race condition in packaged staging?

[Denys Dmytriyenko]

Hi,

I've been seeing some strange breaks in my builds from time to time since the 
introduction of new style staging. It doesn't happen often, but when it does, 
I usually see a message from "tar" complaining about the archive being changed 
on the fly, which comes from the kernel during it's do_package_stage task, 
staging_packager function. The simplest workaround was to disable parallel 
build and parallel bitbake execution (PARALLEL_MAKE and BB_NUMBER_THREADS).
I usually never had time to investigate further.

Today I received a slightly different message, which gave me some pointers 
towards a possible race condition in packaged staging, when multiple bitbake 
threads are trying to execute relative tasks and have a conflict:

NOTE: Running task 1372 of 1377 (ID: 980, /OE/arago/recipes/ti/ti-dmai_svn.bb, do_package_write)
NOTE: Running task 1373 of 1377 (ID: 18, /OE/arago/recipes/images/arago-dvsdk-image.bb, do_package_update_index_ipk)
NOTE: Running task 1374 of 1377 (ID: 982, /OE/arago/recipes/ti/ti-dmai_svn.bb, do_package_stage)
ERROR: function staging_packager failed
ERROR: log data follows (/OE/arago-tmp/work/omap3evm-none-linux-gnueabi/ti-dmai-1_1.0+svnr423-r51e/temp/log.staging_packager.13580)
| mkdir: cannot create directory `/OE/arago-deploy/pstage/angstromglibc/IPKG_BUILD.13587': File exists
NOTE: Task failed: /OE/arago-tmp/work/omap3evm-none-linux-gnueabi/ti-dmai-1_1.0+svnr423-r51e/temp/log.staging_packager.13580
ERROR: TaskFailed event exception, aborting
ERROR: Build of /OE/arago/recipes/ti/ti-dmai_svn.bb do_package_stage failed
ERROR: Task 982 (/OE/arago/recipes/ti/ti-dmai_svn.bb, do_package_stage) failed
NOTE: Waiting for 1 active tasks to finish
NOTE: 1: /OE/arago/recipes/images/arago-dvsdk-image.bb, do_package_update_index_ipk (13566)
NOTE: Tasks Summary: Attempted 1372 tasks of which 549 didn't need to be rerun and 1 failed.
ERROR: '/OE/arago/recipes/ti/ti-dmai_svn.bb' failed

Hopefully this helps somebody more familiar with the subject (don't want to 
bother RP, but it's his creation :)) easily identify the culprit and fix it, 
either by adding a lock or something similar... :) I hate to not use the full 
power of my 4 cores and run everything in one thread. Thanks.

-- 
Denys

Re: Race condition in packaged staging?

[Eric Bénard]

Hi,

Le 11/02/2010 10:45, Denys Dmytriyenko a écrit :
> I've been seeing some strange breaks in my builds from time to time since the
> introduction of new style staging. It doesn't happen often, but when it does,
> I usually see a message from "tar" complaining about the archive being changed
> on the fly, which comes from the kernel during it's do_package_stage task,
> staging_packager function. The simplest workaround was to disable parallel
> build and parallel bitbake execution (PARALLEL_MAKE and BB_NUMBER_THREADS).
> I usually never had time to investigate further.
>
> Today I received a slightly different message, which gave me some pointers
> towards a possible race condition in packaged staging, when multiple bitbake
> threads are trying to execute relative tasks and have a conflict:
>
> NOTE: Running task 1372 of 1377 (ID: 980, /OE/arago/recipes/ti/ti-dmai_svn.bb, do_package_write)
> NOTE: Running task 1373 of 1377 (ID: 18, /OE/arago/recipes/images/arago-dvsdk-image.bb, do_package_update_index_ipk)
> NOTE: Running task 1374 of 1377 (ID: 982, /OE/arago/recipes/ti/ti-dmai_svn.bb, do_package_stage)
> ERROR: function staging_packager failed
> ERROR: log data follows (/OE/arago-tmp/work/omap3evm-none-linux-gnueabi/ti-dmai-1_1.0+svnr423-r51e/temp/log.staging_packager.13580)
> | mkdir: cannot create directory `/OE/arago-deploy/pstage/angstromglibc/IPKG_BUILD.13587': File exists
> NOTE: Task failed: /OE/arago-tmp/work/omap3evm-none-linux-gnueabi/ti-dmai-1_1.0+svnr423-r51e/temp/log.staging_packager.13580
> ERROR: TaskFailed event exception, aborting
> ERROR: Build of /OE/arago/recipes/ti/ti-dmai_svn.bb do_package_stage failed
> ERROR: Task 982 (/OE/arago/recipes/ti/ti-dmai_svn.bb, do_package_stage) failed
> NOTE: Waiting for 1 active tasks to finish
> NOTE: 1: /OE/arago/recipes/images/arago-dvsdk-image.bb, do_package_update_index_ipk (13566)
> NOTE: Tasks Summary: Attempted 1372 tasks of which 549 didn't need to be rerun and 1 failed.
> ERROR: '/OE/arago/recipes/ti/ti-dmai_svn.bb' failed
>
> Hopefully this helps somebody more familiar with the subject (don't want to
> bother RP, but it's his creation :)) easily identify the culprit and fix it,
> either by adding a lock or something similar... :) I hate to not use the full
> power of my 4 cores and run everything in one thread. Thanks.
>
I had a problem which seems to be very close to this problem :
while buidling a project from scratch, it failed at linux's 
staging_packager with the following log :

find: invalid expression; I was expecting to find a ')' somewhere but 
did not see one.
tar: .: file changed as we read it

Simply relaunching bitbake was enough to finish the build.

In this case I had
BB_NUMBER_THREADS=2
PARALLEL_MAKE = "-j 2"

(I also had the same thing with 8 BB threads and - j 8 on an other build 
machine).

Eric

Re: Race condition in packaged staging?

[Denys Dmytriyenko]

On Wed, May 12, 2010 at 06:48:49PM +0200, Eric B?nard wrote:
> Hi,
>
> Le 11/02/2010 10:45, Denys Dmytriyenko a ?crit :
>> I've been seeing some strange breaks in my builds from time to time since 
>> the
>> introduction of new style staging. It doesn't happen often, but when it 
>> does,
>> I usually see a message from "tar" complaining about the archive being 
>> changed
>> on the fly, which comes from the kernel during it's do_package_stage task,
>> staging_packager function. The simplest workaround was to disable parallel
>> build and parallel bitbake execution (PARALLEL_MAKE and 
>> BB_NUMBER_THREADS).
>> I usually never had time to investigate further.
>>
>> Today I received a slightly different message, which gave me some pointers
>> towards a possible race condition in packaged staging, when multiple 
>> bitbake
>> threads are trying to execute relative tasks and have a conflict:
>>
>> ERROR: log data follows 
>> (/OE/arago-tmp/work/omap3evm-none-linux-gnueabi/ti-dmai-1_1.0+svnr423-r51e/temp/log.staging_packager.13580)
>> | mkdir: cannot create directory 
>> `/OE/arago-deploy/pstage/angstromglibc/IPKG_BUILD.13587': File exists
>> NOTE: Task failed: 
>> /OE/arago-tmp/work/omap3evm-none-linux-gnueabi/ti-dmai-1_1.0+svnr423-r51e/temp/log.staging_packager.13580
>>
>> Hopefully this helps somebody more familiar with the subject (don't want 
>> to
>> bother RP, but it's his creation :)) easily identify the culprit and fix 
>> it,
>> either by adding a lock or something similar... :) I hate to not use the 
>> full
>> power of my 4 cores and run everything in one thread. Thanks.
>>
> I had a problem which seems to be very close to this problem :
> while buidling a project from scratch, it failed at linux's 
> staging_packager with the following log :
>
> find: invalid expression; I was expecting to find a ')' somewhere but did 
> not see one.
> tar: .: file changed as we read it

Yeah, it was also common for me, as I mentioned here:

>> I usually see a message from "tar" complaining about the archive being 
>> changed
>> on the fly, which comes from the kernel during it's do_package_stage task,
>> staging_packager function. The simplest workaround was to disable parallel

> Simply relaunching bitbake was enough to finish the build.
>
> In this case I had
> BB_NUMBER_THREADS=2
> PARALLEL_MAKE = "-j 2"
>
> (I also had the same thing with 8 BB threads and - j 8 on an other build 
> machine).

Do you still see the issue after the patch from Enrico Scholz[1][2] applied?

[1] http://thread.gmane.org/gmane.comp.handhelds.openembedded/32860
[2] http://cgit.openembedded.org/cgit.cgi/openembedded/commit/?id=311bed0b40aaa6298029f727d97f50c1d740a3fa

I'm still testing, as I haven't been able to run any large builds from scratch 
yet... Please let me know your results. Thanks.

-- 
Denys