Another CI splat: do_cache_base_repo: Failed

Another CI splat: do_cache_base_repo: Failed

[Jan Kiszka]

Hi,

Familiar (even if rare)?

NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Started
ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo: Function 
failed: do_cache_base_repo (log file is located at 
/builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127)
ERROR: Logfile of failure stored in: 
/builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127
Log data follows:
| DEBUG: Executing shell function do_cache_base_repo
| The lock file 
'/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfile' already 
exists. There might be another instance with the
| same database dir running. To avoid locking overhead, only one process
| can access the database at the same time. Do not delete the lock file unless
| you are sure no other version is still running!
| There have been errors!
| WARNING: exit code 239 from a shell command.
| ERROR: Function failed: do_cache_base_repo (log file is located at 
/builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127)
NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
ERROR: Task 
(multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/recipes-core/images/isar-image-base.bb:do_cache_base_repo) 
failed with exit code '1'


Cedric, you once sent a related patch ("dpkg: acquire lock when calling
reprepro") that seems like it was never merged. Was that related to a similar error?

Jan

-- 
Siemens AG, Corporate Technology, CT RDA IOT SES-DE
Corporate Competence Center Embedded Linux

Re: Another CI splat: do_cache_base_repo: Failed

[Jan Kiszka]

On 07.01.19 16:00, [ext] Jan Kiszka wrote:
> Hi,
> 
> Familiar (even if rare)?
> 
> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Started
> ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo: Function 
> failed: do_cache_base_repo (log file is located at 
> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127) 
> 
> ERROR: Logfile of failure stored in: 
> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127 
> 
> Log data follows:
> | DEBUG: Executing shell function do_cache_base_repo
> | The lock file 
> '/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfile' already 
> exists. There might be another instance with the
> | same database dir running. To avoid locking overhead, only one process
> | can access the database at the same time. Do not delete the lock file unless
> | you are sure no other version is still running!
> | There have been errors!
> | WARNING: exit code 239 from a shell command.
> | ERROR: Function failed: do_cache_base_repo (log file is located at 
> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127) 
> 
> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
> ERROR: Task 
> (multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/recipes-core/images/isar-image-base.bb:do_cache_base_repo) 
> failed with exit code '1'
> 
> 
> Cedric, you once sent a related patch ("dpkg: acquire lock when calling
> reprepro") that seems like it was never merged. Was that related to a similar 
> error?

Happened again yesterday, and even the retry failed now. Seems we have at least 
a better chance to reproduce this... Any comments on this bug?

Jan

-- 
Siemens AG, Corporate Technology, CT RDA IOT SES-DE
Corporate Competence Center Embedded Linux

Re: Another CI splat: do_cache_base_repo: Failed

[Hombourger, Cedric]

[-- Attachment #1: Type: text/plain, Size: 2188 bytes --]

Hi Jan,

Sorry - must have missed your earlier e-mail. Let me take a look at the latest code (we anyway need to rebase to the latest now that the feature merge window for our project has been reopened)

Thanks
Cedric
On Jan 16, 2019, 5:29 AM +0100, Jan Kiszka <jan.kiszka@siemens.com>, wrote:
On 07.01.19 16:00, [ext] Jan Kiszka wrote:
Hi,

Familiar (even if rare)?

NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Started
ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo: Function
failed: do_cache_base_repo (log file is located at
/builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127)

ERROR: Logfile of failure stored in:
/builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127

Log data follows:
| DEBUG: Executing shell function do_cache_base_repo
| The lock file
'/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfile' already
exists. There might be another instance with the
| same database dir running. To avoid locking overhead, only one process
| can access the database at the same time. Do not delete the lock file unless
| you are sure no other version is still running!
| There have been errors!
| WARNING: exit code 239 from a shell command.
| ERROR: Function failed: do_cache_base_repo (log file is located at
/builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127)

NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
ERROR: Task
(multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/recipes-core/images/isar-image-base.bb:do_cache_base_repo)
failed with exit code '1'


Cedric, you once sent a related patch ("dpkg: acquire lock when calling
reprepro") that seems like it was never merged. Was that related to a similar
error?

Happened again yesterday, and even the retry failed now. Seems we have at least
a better chance to reproduce this... Any comments on this bug?

Jan

--
Siemens AG, Corporate Technology, CT RDA IOT SES-DE
Corporate Competence Center Embedded Linux

[-- Attachment #2: Type: text/html, Size: 3224 bytes --]

Re: Another CI splat: do_cache_base_repo: Failed

[Maxim Yu. Osipov]

Hi Cedric,

Did you have a look at the code?

Looks like that the problem pop ups sometimes

See:
https://groups.google.com/forum/#!msg/isar-users/KO8NhgG2Nh8/a1QdEuFiGAAJ

Thanks,
Maxim.

On 1/16/19 6:46 AM, Hombourger, Cedric wrote:
> Hi Jan,
> 
> Sorry - must have missed your earlier e-mail. Let me take a look at the 
> latest code (we anyway need to rebase to the latest now that the feature 
> merge window for our project has been reopened)
> 
> Thanks
> Cedric
> On Jan 16, 2019, 5:29 AM +0100, Jan Kiszka <jan.kiszka@siemens.com>, wrote:
>> On 07.01.19 16:00, [ext] Jan Kiszka wrote:
>>> Hi,
>>>
>>> Familiar (even if rare)?
>>>
>>> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Started
>>> ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo: 
>>> Function
>>> failed: do_cache_base_repo (log file is located at
>>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127)
>>>
>>> ERROR: Logfile of failure stored in:
>>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127
>>>
>>> Log data follows:
>>> | DEBUG: Executing shell function do_cache_base_repo
>>> | The lock file
>>> '/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfile' already
>>> exists. There might be another instance with the
>>> | same database dir running. To avoid locking overhead, only one process
>>> | can access the database at the same time. Do not delete the lock 
>>> file unless
>>> | you are sure no other version is still running!
>>> | There have been errors!
>>> | WARNING: exit code 239 from a shell command.
>>> | ERROR: Function failed: do_cache_base_repo (log file is located at
>>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-image-base/temp/log.do_cache_base_repo.55127)
>>>
>>> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
>>> ERROR: Task
>>> (multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/recipes-core/images/isar-image-base.bb:do_cache_base_repo)
>>> failed with exit code '1'
>>>
>>>
>>> Cedric, you once sent a related patch ("dpkg: acquire lock when calling
>>> reprepro") that seems like it was never merged. Was that related to a 
>>> similar
>>> error?
>>
>> Happened again yesterday, and even the retry failed now. Seems we have 
>> at least
>> a better chance to reproduce this... Any comments on this bug?
>>
>> Jan
>>
>> --
>> Siemens AG, Corporate Technology, CT RDA IOT SES-DE
>> Corporate Competence Center Embedded Linux
> 
> -- 
> You received this message because you are subscribed to the Google 
> Groups "isar-users" group.
> To unsubscribe from this group and stop receiving emails from it, send 
> an email to isar-users+unsubscribe@googlegroups.com 
> <mailto:isar-users+unsubscribe@googlegroups.com>.
> To post to this group, send email to isar-users@googlegroups.com 
> <mailto:isar-users@googlegroups.com>.
> To view this discussion on the web visit 
> https://groups.google.com/d/msgid/isar-users/3893d116-3a06-48e6-b691-f17b7b444daa%40Spark 
> <https://groups.google.com/d/msgid/isar-users/3893d116-3a06-48e6-b691-f17b7b444daa%40Spark?utm_medium=email&utm_source=footer>.
> For more options, visit https://groups.google.com/d/optout.


-- 
Maxim Osipov
ilbers GmbH
Maria-Merian-Str. 8
85521 Ottobrunn
Germany
+49 (151) 6517 6917
mosipov@ilbers.de
http://ilbers.de/
Commercial register Munich, HRB 214197
General Manager: Baurzhan Ismagulov

RE: Another CI splat: do_cache_base_repo: Failed

[Hombourger, Cedric]

Hi Maxim,

I did and the only think I locally came up with to fix some random issues in our own project was:

diff --git a/meta/classes/dpkg.bbclass b/meta/classes/dpkg.bbclass
index 24b9fe3..f4e3d7a 100644
--- a/meta/classes/dpkg.bbclass
+++ b/meta/classes/dpkg.bbclass
@@ -19,5 +19,6 @@ do_install_builddeps[stamp-extra-info] = "${DISTRO}-${DISTRO_ARCH}"
 # Build package from sources using build script
 dpkg_runbuild() {
     E="${@ bb.utils.export_proxies(d)}"
+    flock -s "${REPO_ISAR_DIR}/isar.lock" \
     sudo -E chroot --userspec=$( id -u ):$( id -g ) ${BUILDCHROOT_DIR} /isar/build.sh ${PP}/${PPS} ${DISTRO_ARCH}
 }

Note: unless I am missing something, bitbake does not provide a mechanism to acquired a shared lock via task_name[lockfiles]

In our case, I noticed that Debian packages may access the package database during their build process while other packages/recipes may install dependencies
The idea was therefore to acquire a read (shared) lock while building (do_install_deps and friends acquire a write (exclusive) lock)

I have had this local change in our systems for several days now and errors like below have not been seen again

 | dpkg-query: error: failed to open package info file '/var/lib/dpkg/updates/0001' for reading: No such file or directory
 | dpkg-shlibdeps: error: dpkg-query --control-path libgcrypt20:amd64 symbols gave error exit status

I am however unsure if the CI build failures that we have here as yours
Can you have someone create an account on your CI infrastructure so I can check?

Thanks
Cedric 

-----Original Message-----
From: Maxim Yu. Osipov [mailto:mosipov@ilbers.de] 
Sent: Thursday, February 7, 2019 1:01 PM
To: Hombourger, Cedric <Cedric_Hombourger@mentor.com>; isar-users <isar-users@googlegroups.com>; Jan Kiszka <jan.kiszka@siemens.com>
Subject: Re: Another CI splat: do_cache_base_repo: Failed

Hi Cedric,

Did you have a look at the code?

Looks like that the problem pop ups sometimes

See:
https://groups.google.com/forum/#!msg/isar-users/KO8NhgG2Nh8/a1QdEuFiGAAJ

Thanks,
Maxim.

On 1/16/19 6:46 AM, Hombourger, Cedric wrote:
> Hi Jan,
> 
> Sorry - must have missed your earlier e-mail. Let me take a look at 
> the latest code (we anyway need to rebase to the latest now that the 
> feature merge window for our project has been reopened)
> 
> Thanks
> Cedric
> On Jan 16, 2019, 5:29 AM +0100, Jan Kiszka <jan.kiszka@siemens.com>, wrote:
>> On 07.01.19 16:00, [ext] Jan Kiszka wrote:
>>> Hi,
>>>
>>> Familiar (even if rare)?
>>>
>>> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: 
>>> Started
>>> ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo: 
>>> Function
>>> failed: do_cache_base_repo (log file is located at
>>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-im
>>> age-base/temp/log.do_cache_base_repo.55127)
>>>
>>> ERROR: Logfile of failure stored in:
>>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-im
>>> age-base/temp/log.do_cache_base_repo.55127
>>>
>>> Log data follows:
>>> | DEBUG: Executing shell function do_cache_base_repo The lock file
>>> '/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfil
>>> e' already exists. There might be another instance with the
>>> | same database dir running. To avoid locking overhead, only one 
>>> | process can access the database at the same time. Do not delete 
>>> | the lock
>>> file unless
>>> | you are sure no other version is still running!
>>> | There have been errors!
>>> | WARNING: exit code 239 from a shell command.
>>> | ERROR: Function failed: do_cache_base_repo (log file is located at
>>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-im
>>> age-base/temp/log.do_cache_base_repo.55127)
>>>
>>> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
>>> ERROR: Task
>>> (multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/reci
>>> pes-core/images/isar-image-base.bb:do_cache_base_repo)
>>> failed with exit code '1'
>>>
>>>
>>> Cedric, you once sent a related patch ("dpkg: acquire lock when 
>>> calling
>>> reprepro") that seems like it was never merged. Was that related to 
>>> a similar error?
>>
>> Happened again yesterday, and even the retry failed now. Seems we 
>> have at least a better chance to reproduce this... Any comments on 
>> this bug?
>>
>> Jan
>>
>> --
>> Siemens AG, Corporate Technology, CT RDA IOT SES-DE Corporate 
>> Competence Center Embedded Linux
> 
> --
> You received this message because you are subscribed to the Google 
> Groups "isar-users" group.
> To unsubscribe from this group and stop receiving emails from it, send 
> an email to isar-users+unsubscribe@googlegroups.com
> <mailto:isar-users+unsubscribe@googlegroups.com>.
> To post to this group, send email to isar-users@googlegroups.com 
> <mailto:isar-users@googlegroups.com>.
> To view this discussion on the web visit 
> https://groups.google.com/d/msgid/isar-users/3893d116-3a06-48e6-b691-f
> 17b7b444daa%40Spark 
> <https://groups.google.com/d/msgid/isar-users/3893d116-3a06-48e6-b691-f17b7b444daa%40Spark?utm_medium=email&utm_source=footer>.
> For more options, visit https://groups.google.com/d/optout.


--
Maxim Osipov
ilbers GmbH
Maria-Merian-Str. 8
85521 Ottobrunn
Germany
+49 (151) 6517 6917
mosipov@ilbers.de
http://ilbers.de/
Commercial register Munich, HRB 214197
General Manager: Baurzhan Ismagulov

RE: Another CI splat: do_cache_base_repo: Failed

[Hombourger, Cedric]

Don't we need to add:

do_cache_base_repo[lockfiles] = "${REPO_BASE_DIR}/isar.lock"

Your CI is building multiple images in parallel, this means that we will end-up having multiple processes populate the base apt cache concurrently
We'd therefore need to serialize accesses to the repo

I am happy to generate a patch if you believe my theory makes sense

Cedric

-----Original Message-----
From: Jan Kiszka [mailto:jan.kiszka@siemens.com] 
Sent: Wednesday, January 16, 2019 5:29 AM
To: isar-users <isar-users@googlegroups.com>; Hombourger, Cedric <Cedric_Hombourger@mentor.com>; Maksim Osipov <mosipov@ilbers.de>
Subject: Re: Another CI splat: do_cache_base_repo: Failed

On 07.01.19 16:00, [ext] Jan Kiszka wrote:
> Hi,
> 
> Familiar (even if rare)?
> 
> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Started
> ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo: 
> Function
> failed: do_cache_base_repo (log file is located at
> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-imag
> e-base/temp/log.do_cache_base_repo.55127)
> 
> ERROR: Logfile of failure stored in: 
> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-imag
> e-base/temp/log.do_cache_base_repo.55127
> 
> Log data follows:
> | DEBUG: Executing shell function do_cache_base_repo The lock file
> '/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfile' 
> already exists. There might be another instance with the
> | same database dir running. To avoid locking overhead, only one 
> | process can access the database at the same time. Do not delete the 
> | lock file unless you are sure no other version is still running!
> | There have been errors!
> | WARNING: exit code 239 from a shell command.
> | ERROR: Function failed: do_cache_base_repo (log file is located at
> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-imag
> e-base/temp/log.do_cache_base_repo.55127)
> 
> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
> ERROR: Task
> (multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/recipe
> s-core/images/isar-image-base.bb:do_cache_base_repo)
> failed with exit code '1'
> 
> 
> Cedric, you once sent a related patch ("dpkg: acquire lock when 
> calling
> reprepro") that seems like it was never merged. Was that related to a 
> similar error?

Happened again yesterday, and even the retry failed now. Seems we have at least a better chance to reproduce this... Any comments on this bug?

Jan

--
Siemens AG, Corporate Technology, CT RDA IOT SES-DE Corporate Competence Center Embedded Linux

Re: Another CI splat: do_cache_base_repo: Failed

[Maxim Yu. Osipov]

Hi Cedric,

Thank you for fast feedback.

I agree with you - race may happen in populate_base_repo.

Your patch is very welcome.

Thanks,
Maxim.

On 2/7/19 2:22 PM, Hombourger, Cedric wrote:
> 
> Don't we need to add:
> 
> do_cache_base_repo[lockfiles] = "${REPO_BASE_DIR}/isar.lock"
> 
> Your CI is building multiple images in parallel, this means that we will end-up having multiple processes populate the base apt cache concurrently
> We'd therefore need to serialize accesses to the repo
> 
> I am happy to generate a patch if you believe my theory makes sense
> 
> Cedric
> 
> -----Original Message-----
> From: Jan Kiszka [mailto:jan.kiszka@siemens.com]
> Sent: Wednesday, January 16, 2019 5:29 AM
> To: isar-users <isar-users@googlegroups.com>; Hombourger, Cedric <Cedric_Hombourger@mentor.com>; Maksim Osipov <mosipov@ilbers.de>
> Subject: Re: Another CI splat: do_cache_base_repo: Failed
> 
> On 07.01.19 16:00, [ext] Jan Kiszka wrote:
>> Hi,
>>
>> Familiar (even if rare)?
>>
>> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Started
>> ERROR: mc:qemuarm-stretch:isar-image-base-1.0-r0 do_cache_base_repo:
>> Function
>> failed: do_cache_base_repo (log file is located at
>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-imag
>> e-base/temp/log.do_cache_base_repo.55127)
>>
>> ERROR: Logfile of failure stored in:
>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-imag
>> e-base/temp/log.do_cache_base_repo.55127
>>
>> Log data follows:
>> | DEBUG: Executing shell function do_cache_base_repo The lock file
>> '/builds/ebsy/debian/isar/build/downloads/base-apt/db/debian/lockfile'
>> already exists. There might be another instance with the
>> | same database dir running. To avoid locking overhead, only one
>> | process can access the database at the same time. Do not delete the
>> | lock file unless you are sure no other version is still running!
>> | There have been errors!
>> | WARNING: exit code 239 from a shell command.
>> | ERROR: Function failed: do_cache_base_repo (log file is located at
>> /builds/ebsy/debian/isar/build/tmp/work/debian-stretch-armhf/isar-imag
>> e-base/temp/log.do_cache_base_repo.55127)
>>
>> NOTE: recipe isar-image-base-1.0-r0: task do_cache_base_repo: Failed
>> ERROR: Task
>> (multiconfig:qemuarm-stretch:/builds/ebsy/debian/isar/meta-isar/recipe
>> s-core/images/isar-image-base.bb:do_cache_base_repo)
>> failed with exit code '1'
>>
>>
>> Cedric, you once sent a related patch ("dpkg: acquire lock when
>> calling
>> reprepro") that seems like it was never merged. Was that related to a
>> similar error?
> 
> Happened again yesterday, and even the retry failed now. Seems we have at least a better chance to reproduce this... Any comments on this bug?
> 
> Jan
> 
> --
> Siemens AG, Corporate Technology, CT RDA IOT SES-DE Corporate Competence Center Embedded Linux
> 


-- 
Maxim Osipov
ilbers GmbH
Maria-Merian-Str. 8
85521 Ottobrunn
Germany
+49 (151) 6517 6917
mosipov@ilbers.de
http://ilbers.de/
Commercial register Munich, HRB 214197
General Manager: Baurzhan Ismagulov