Bug 6085

Summary: useradd_base.bbclass: sleep more seconds when fail
Product: [Build System, Metadata & Runtime] OE-Core Reporter: Robert Yang <liezhi.yang>
Component: coreAssignee: Robert Yang <liezhi.yang>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: Medium CC: jessica.zhang, meta.mr.watcher, meta.watcher, richard.purdie, sgw
Version: 1.6   
Target Milestone: 1.6 M5   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)

Description Robert Yang 2014-04-01 03:29:02 UTC
Currently, it would sleep 1 second when fail to add the user, this maybe not enough when we use the sstate cache, as my test shows below, nearly all the useradd actions are doing in the same minute when mirror from ssate cache, and it would fail when the load is high, I got these time by adding strace before the useradd for debugging:

diff --git a/meta/classes/useradd_base.bbclass b/meta/classes/useradd_base.bbclass
index 7aafe29..3105899 100644
--- a/meta/classes/useradd_base.bbclass
+++ b/meta/classes/useradd_base.bbclass
@@ -48,7 +48,7 @@ perform_useradd () {
        if test "x$user_exists" = "x"; then
               local count=0
               while true; do
-                      eval $PSEUDO useradd $opts || true
+                      eval $PSEUDO strace -o /tmp/log/${PN}.${count}.c useradd $opts || true
                       user_exists="`grep "^$username:" $rootdir/etc/passwd || true`"
                       if test "x$user_exists" = "x"; then
                               bbwarn "useradd command did not succeed. Retrying..."


2014-03-31 14:48:22.978079781 +0800 /tmp/log/pulseaudio.4.c
2014-03-31 14:48:22.028079813 +0800 /tmp/log/pulseaudio.1.c
2014-03-31 14:48:21.949079816 +0800 /tmp/log/pulseaudio.3.c
2014-03-31 14:48:20.903079852 +0800 /tmp/log/pulseaudio.2.c
2014-03-31 14:48:20.006079883 +0800 /tmp/log/nfs-utils.9.c
2014-03-31 14:48:18.876079923 +0800 /tmp/log/xuser-account.9.c
2014-03-31 14:48:18.824079924 +0800 /tmp/log/pulseaudio.0.c
2014-03-31 14:48:17.826079959 +0800 /tmp/log/xuser-account.8.c
2014-03-31 14:48:17.766079961 +0800 /tmp/log/nfs-utils.8.c
2014-03-31 14:48:16.794079995 +0800 /tmp/log/xuser-account.7.c
2014-03-31 14:48:16.735079997 +0800 /tmp/log/nfs-utils.7.c
2014-03-31 14:48:14.719080066 +0800 /tmp/log/xuser-account.5.c
2014-03-31 14:48:14.677080068 +0800 /tmp/log/nfs-utils.5.c
2014-03-31 14:48:12.621080139 +0800 /tmp/log/nfs-utils.3.c
2014-03-31 14:48:11.589080175 +0800 /tmp/log/nfs-utils.2.c
2014-03-31 14:48:10.242080221 +0800 /tmp/log/builder.0.c
2014-03-31 14:48:09.523080246 +0800 /tmp/log/nfs-utils.0.c
2014-03-31 14:48:09.488080248 +0800 /tmp/log/openssh.0.c
2014-03-31 14:48:09.485080248 +0800 /tmp/log/rpcbind.1.c
2014-03-31 14:48:07.590080313 +0800 /tmp/log/rpcbind.0.c
2014-03-31 14:28:15.437121590 +0800 /tmp/log/avahi.0.c
2014-03-31 14:18:19.067142238 +0800 /tmp/log/dbus.0.c

The nfs-utils and xuser-account are failed to add the user.

This is only from the useradd, we also have groupadd and groupmems, it would be more crowding if we also print their time.

The useradd command needs two locks, passwd.lock and group.lock, it may get one, but can't get another if we look into these .c files, sleep 1 minute is really  not enough, I think that we need sleep more seconds, for example, 3 seconds, the reason is that, if succeed, it doesn't have any effect, if failed, we need wait for more seconds rather than make it more crowding.

The similar to other two commands.
Comment 1 Robert Yang 2014-04-01 08:22:00 UTC
3 seconds seems still not enough, didn't get any failures now, but the "builder" recipe re-tries 9 times which is in danger, maybe we need 5 seconds.

014-04-01 15:05:38.435052479 +0800 /tmp/log/dbus.0.c
2014-04-01 15:05:01.320053764 +0800 /tmp/log/builder.8.c
2014-04-01 15:04:58.477053863 +0800 /tmp/log/pulseaudio.0.c
2014-04-01 15:04:56.655053926 +0800 /tmp/log/builder.7.c
2014-04-01 15:04:53.606054032 +0800 /tmp/log/avahi-ui.0.c
2014-04-01 15:04:53.468054036 +0800 /tmp/log/builder.6.c
2014-04-01 15:04:51.801054094 +0800 /tmp/log/avahi-ui.5.c
2014-04-01 15:04:50.409054142 +0800 /tmp/log/builder.5.c
2014-04-01 15:04:49.137054186 +0800 /tmp/log/nfs-utils.5.c
2014-04-01 15:04:48.337054214 +0800 /tmp/log/nfs-utils.4.c
2014-04-01 15:04:46.133054290 +0800 /tmp/log/avahi-ui.4.c
2014-04-01 15:04:46.087054292 +0800 /tmp/log/builder.4.c
2014-04-01 15:04:44.995054330 +0800 /tmp/log/xuser-account.3.c
2014-04-01 15:04:43.075054396 +0800 /tmp/log/nfs-utils.3.c
2014-04-01 15:04:43.064054397 +0800 /tmp/log/rpcbind.3.c
2014-04-01 15:04:43.057054397 +0800 /tmp/log/avahi-ui.3.c
2014-04-01 15:04:43.036054397 +0800 /tmp/log/builder.3.c
2014-04-01 15:04:41.787054441 +0800 /tmp/log/xuser-account.2.c
2014-04-01 15:04:41.428054453 +0800 /tmp/log/rpcbind.2.c
2014-04-01 15:04:40.024054502 +0800 /tmp/log/nfs-utils.2.c
2014-04-01 15:04:40.013054502 +0800 /tmp/log/avahi-ui.2.c
2014-04-01 15:04:40.002054503 +0800 /tmp/log/builder.2.c
2014-04-01 15:04:40.002054503 +0800 /tmp/log/distcc.1.c
2014-04-01 15:04:38.754054546 +0800 /tmp/log/xuser-account.1.c
2014-04-01 15:04:37.599054586 +0800 /tmp/log/openssh.1.c
2014-04-01 15:04:36.636054619 +0800 /tmp/log/rpcbind.1.c
2014-04-01 15:04:36.632054619 +0800 /tmp/log/nfs-utils.1.c
2014-04-01 15:04:36.617054620 +0800 /tmp/log/avahi-ui.1.c
2014-04-01 15:04:36.601054620 +0800 /tmp/log/builder.1.c
2014-04-01 15:04:35.727054651 +0800 /tmp/log/xuser-account.0.c
2014-04-01 15:04:35.605054655 +0800 /tmp/log/distcc.0.c
2014-04-01 15:04:33.579054725 +0800 /tmp/log/nfs-utils.0.c
2014-04-01 15:04:33.579054725 +0800 /tmp/log/rpcbind.0.c
2014-04-01 15:04:33.566054725 +0800 /tmp/log/builder.0.c
2014-04-01 15:04:33.532054727 +0800 /tmp/log/ppp-dialin.0.c
2014-04-01 15:04:29.811054855 +0800 /tmp/log/openssh.0.c
2014-04-01 13:15:15.934281772 +0800 /tmp/log/avahi.0.c