Public bug reported:
Since the upgrade to Ubuntu 16.10, building packages with sbuild takes
much more time than previously. sbuild creates a schroot session for
building Debian packages and calls sbuild --run-session several times.
Entering the sessions takes norally 10 ms, but entering the session from
sbuild takes several seconds now:
time schroot -d / -c $session --run-session -q -u root -p -- true
real 0m2.098s
user 0m0.008s
sys 0m0.000s
This causes a drastic build time increase for small packages. Example
package build time on my affected Ubuntu workstation:
Build-Time: 9 s
Install-Time: 115 s
Package-Time: 195 s (= 00:03:15)
compared to the build bot running Debian stable (having a slower
processor):
Build-Time: 9 s
Install-Time: 24 s
Package-Time: 41 s
/var/log/syslog shows many entries about starting and stopping D-Bus
services:
Nov 28 16:27:34 konstrukt systemd[1]: Created slice User Slice of root.
Nov 28 16:27:34 konstrukt systemd[1]: Starting User Manager for UID 0...
Nov 28 16:27:34 konstrukt systemd[1]: Started Session 2 of user root.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Timers.
Nov 28 16:27:34 konstrukt systemd[21965]: Starting D-Bus User Message Bus
Socket.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Paths.
Nov 28 16:27:34 konstrukt systemd[21965]: Listening on D-Bus User Message Bus
Socket.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Sockets.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Basic System.
Nov 28 16:27:34 konstrukt systemd[21965]: Starting Run Click user-level hooks...
Nov 28 16:27:34 konstrukt systemd[21965]: Started D-Bus User Message Bus.
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Error parsing manifest for
package 'com.ubuntu.gallery': com.ubuntu.gallery does not exist in any database
for user root
Nov 28 16:27:34 konstrukt /usr/lib/snapd/snapd[1086]: daemon.go:174: DEBUG:
uid=0;@ GET /v2/snaps/com.ubuntu.gallery 40.327µs 404
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Unable to get snap
information for 'com.ubuntu.gallery': Status code is: 404
Nov 28 16:27:34 konstrukt dbus-daemon[22004]: Activating service
name='ca.desrt.dconf'
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Error parsing manifest for
package 'com.ubuntu.gallery': com.ubuntu.gallery does not exist in any database
for user root
Nov 28 16:27:34 konstrukt /usr/lib/snapd/snapd[1086]: daemon.go:174: DEBUG:
uid=0;@ GET /v2/snaps/com.ubuntu.gallery 23.455µs 404
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Unable to get snap
information for 'com.ubuntu.gallery': Status code is: 404
Nov 28 16:27:34 konstrukt dbus-daemon[22004]: Successfully activated service
'ca.desrt.dconf'
Nov 28 16:27:35 konstrukt dbus-daemon[22004]: Activating via systemd: service
name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service'
Nov 28 16:27:35 konstrukt systemd[21965]: Starting Virtual filesystem service...
Nov 28 16:27:35 konstrukt dbus-daemon[22004]: Successfully activated service
'org.gtk.vfs.Daemon'
Nov 28 16:27:35 konstrukt systemd[21965]: Started Virtual filesystem service.
Nov 28 16:27:35 konstrukt click[21997]:
/usr/lib/ubuntu-push-client/click-hook:15: PyGIWarning: Click was imported
without specifying a version first. Use gi.require_version('Click', '0.4')
before import to ensure that the right version gets loaded.
Nov 28 16:27:35 konstrukt click[21997]: from gi.repository import Click
Nov 28 16:27:35 konstrukt click[21997]: hooks.vala:1216: User-level hook
push-helper failed: Hook command
'/usr/lib/ubuntu-push-client/click-hook-wrapper' failed: Child process exited
with code 1
Nov 28 16:27:35 konstrukt click[21997]: Some user-level hooks failed:
push-helper
Nov 28 16:27:35 konstrukt systemd[21965]: click-user-hooks.service: Main
process exited, code=exited, status=1/FAILURE
Nov 28 16:27:35 konstrukt systemd[21965]: Failed to start Run Click user-level
hooks.
Nov 28 16:27:35 konstrukt systemd[21965]: click-user-hooks.service: Unit
entered failed state.
Nov 28 16:27:35 konstrukt systemd[21965]: click-user-hooks.service: Failed with
result 'exit-code'.
Nov 28 16:27:35 konstrukt systemd[21965]: Reached target Default.
Nov 28 16:27:35 konstrukt systemd[21965]: Startup finished in 497ms.
Nov 28 16:27:35 konstrukt systemd[1]: Started User Manager for UID 0.
Nov 28 16:27:35 konstrukt schroot[22084]:
[pb-jessie-93c04c41-79af-4e32-addb-09a186998122 chroot] (bdrung->root) Running
command: "getent group sbuild"
Nov 28 16:27:35 konstrukt systemd[1]: Stopping User Manager for UID 0...
Nov 28 16:27:35 konstrukt systemd[21965]: Stopping D-Bus User Message Bus...
Nov 28 16:27:35 konstrukt systemd[21965]: Stopped target Default.
Nov 28 16:27:35 konstrukt systemd[21965]: Stopping Virtual filesystem service...
Nov 28 16:27:35 konstrukt systemd[21965]: Stopped D-Bus User Message Bus.
Nov 28 16:27:35 konstrukt systemd[1]: Started Session 2 of user root.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped Virtual filesystem service.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Basic System.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Sockets.
Nov 28 16:27:36 konstrukt systemd[21965]: Closed D-Bus User Message Bus Socket.
Nov 28 16:27:36 konstrukt systemd[21965]: Reached target Shutdown.
Nov 28 16:27:36 konstrukt systemd[21965]: Starting Exit the Session...
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Timers.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Paths.
Nov 28 16:27:36 konstrukt systemd[21965]: Received SIGRTMIN+24 from PID 22105
(kill).
Nov 28 16:27:36 konstrukt systemd[1]: Starting User Manager for UID 0...
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Paths.
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Timers.
Nov 28 16:27:36 konstrukt systemd[22108]: Starting D-Bus User Message Bus
Socket.
Nov 28 16:27:36 konstrukt systemd[22108]: Listening on D-Bus User Message Bus
Socket.
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Sockets.
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Basic System.
Nov 28 16:27:36 konstrukt systemd[22108]: Starting Run Click user-level hooks...
Nov 28 16:27:36 konstrukt systemd[22108]: Started D-Bus User Message Bus.
[...]
ProblemType: Bug
DistroRelease: Ubuntu 16.10
Package: sbuild 0.71.0-2ubuntu1
ProcVersionSignature: Ubuntu 4.8.0-27.29-generic 4.8.1
Uname: Linux 4.8.0-27-generic x86_64
ApportVersion: 2.20.3-0ubuntu8
Architecture: amd64
CurrentDesktop: Unity
Date: Mon Nov 28 16:28:44 2016
PackageArchitecture: all
SourcePackage: sbuild
UpgradeStatus: Upgraded to yakkety on 2016-11-15 (13 days ago)
** Affects: sbuild (Ubuntu)
Importance: Undecided
Status: New
** Affects: systemd (Ubuntu)
Importance: Undecided
Status: New
** Tags: amd64 apport-bug yakkety
** Also affects: systemd (Ubuntu)
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Ubuntu
Touch seeded packages, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1645363
Title:
slow sbuild Debian package builds (schroot calls are slow)
Status in sbuild package in Ubuntu:
New
Status in systemd package in Ubuntu:
New
Bug description:
Since the upgrade to Ubuntu 16.10, building packages with sbuild takes
much more time than previously. sbuild creates a schroot session for
building Debian packages and calls sbuild --run-session several times.
Entering the sessions takes norally 10 ms, but entering the session
from sbuild takes several seconds now:
time schroot -d / -c $session --run-session -q -u root -p -- true
real 0m2.098s
user 0m0.008s
sys 0m0.000s
This causes a drastic build time increase for small packages. Example
package build time on my affected Ubuntu workstation:
Build-Time: 9 s
Install-Time: 115 s
Package-Time: 195 s (= 00:03:15)
compared to the build bot running Debian stable (having a slower
processor):
Build-Time: 9 s
Install-Time: 24 s
Package-Time: 41 s
/var/log/syslog shows many entries about starting and stopping D-Bus
services:
Nov 28 16:27:34 konstrukt systemd[1]: Created slice User Slice of root.
Nov 28 16:27:34 konstrukt systemd[1]: Starting User Manager for UID 0...
Nov 28 16:27:34 konstrukt systemd[1]: Started Session 2 of user root.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Timers.
Nov 28 16:27:34 konstrukt systemd[21965]: Starting D-Bus User Message Bus
Socket.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Paths.
Nov 28 16:27:34 konstrukt systemd[21965]: Listening on D-Bus User Message Bus
Socket.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Sockets.
Nov 28 16:27:34 konstrukt systemd[21965]: Reached target Basic System.
Nov 28 16:27:34 konstrukt systemd[21965]: Starting Run Click user-level
hooks...
Nov 28 16:27:34 konstrukt systemd[21965]: Started D-Bus User Message Bus.
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Error parsing manifest for
package 'com.ubuntu.gallery': com.ubuntu.gallery does not exist in any database
for user root
Nov 28 16:27:34 konstrukt /usr/lib/snapd/snapd[1086]: daemon.go:174: DEBUG:
uid=0;@ GET /v2/snaps/com.ubuntu.gallery 40.327µs 404
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Unable to get snap
information for 'com.ubuntu.gallery': Status code is: 404
Nov 28 16:27:34 konstrukt dbus-daemon[22004]: Activating service
name='ca.desrt.dconf'
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Error parsing manifest for
package 'com.ubuntu.gallery': com.ubuntu.gallery does not exist in any database
for user root
Nov 28 16:27:34 konstrukt /usr/lib/snapd/snapd[1086]: daemon.go:174: DEBUG:
uid=0;@ GET /v2/snaps/com.ubuntu.gallery 23.455µs 404
Nov 28 16:27:34 konstrukt content-hub-pee[22023]: Unable to get snap
information for 'com.ubuntu.gallery': Status code is: 404
Nov 28 16:27:34 konstrukt dbus-daemon[22004]: Successfully activated service
'ca.desrt.dconf'
Nov 28 16:27:35 konstrukt dbus-daemon[22004]: Activating via systemd: service
name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service'
Nov 28 16:27:35 konstrukt systemd[21965]: Starting Virtual filesystem
service...
Nov 28 16:27:35 konstrukt dbus-daemon[22004]: Successfully activated service
'org.gtk.vfs.Daemon'
Nov 28 16:27:35 konstrukt systemd[21965]: Started Virtual filesystem service.
Nov 28 16:27:35 konstrukt click[21997]:
/usr/lib/ubuntu-push-client/click-hook:15: PyGIWarning: Click was imported
without specifying a version first. Use gi.require_version('Click', '0.4')
before import to ensure that the right version gets loaded.
Nov 28 16:27:35 konstrukt click[21997]: from gi.repository import Click
Nov 28 16:27:35 konstrukt click[21997]: hooks.vala:1216: User-level hook
push-helper failed: Hook command
'/usr/lib/ubuntu-push-client/click-hook-wrapper' failed: Child process exited
with code 1
Nov 28 16:27:35 konstrukt click[21997]: Some user-level hooks failed:
push-helper
Nov 28 16:27:35 konstrukt systemd[21965]: click-user-hooks.service: Main
process exited, code=exited, status=1/FAILURE
Nov 28 16:27:35 konstrukt systemd[21965]: Failed to start Run Click
user-level hooks.
Nov 28 16:27:35 konstrukt systemd[21965]: click-user-hooks.service: Unit
entered failed state.
Nov 28 16:27:35 konstrukt systemd[21965]: click-user-hooks.service: Failed
with result 'exit-code'.
Nov 28 16:27:35 konstrukt systemd[21965]: Reached target Default.
Nov 28 16:27:35 konstrukt systemd[21965]: Startup finished in 497ms.
Nov 28 16:27:35 konstrukt systemd[1]: Started User Manager for UID 0.
Nov 28 16:27:35 konstrukt schroot[22084]:
[pb-jessie-93c04c41-79af-4e32-addb-09a186998122 chroot] (bdrung->root) Running
command: "getent group sbuild"
Nov 28 16:27:35 konstrukt systemd[1]: Stopping User Manager for UID 0...
Nov 28 16:27:35 konstrukt systemd[21965]: Stopping D-Bus User Message Bus...
Nov 28 16:27:35 konstrukt systemd[21965]: Stopped target Default.
Nov 28 16:27:35 konstrukt systemd[21965]: Stopping Virtual filesystem
service...
Nov 28 16:27:35 konstrukt systemd[21965]: Stopped D-Bus User Message Bus.
Nov 28 16:27:35 konstrukt systemd[1]: Started Session 2 of user root.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped Virtual filesystem service.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Basic System.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Sockets.
Nov 28 16:27:36 konstrukt systemd[21965]: Closed D-Bus User Message Bus
Socket.
Nov 28 16:27:36 konstrukt systemd[21965]: Reached target Shutdown.
Nov 28 16:27:36 konstrukt systemd[21965]: Starting Exit the Session...
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Timers.
Nov 28 16:27:36 konstrukt systemd[21965]: Stopped target Paths.
Nov 28 16:27:36 konstrukt systemd[21965]: Received SIGRTMIN+24 from PID 22105
(kill).
Nov 28 16:27:36 konstrukt systemd[1]: Starting User Manager for UID 0...
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Paths.
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Timers.
Nov 28 16:27:36 konstrukt systemd[22108]: Starting D-Bus User Message Bus
Socket.
Nov 28 16:27:36 konstrukt systemd[22108]: Listening on D-Bus User Message Bus
Socket.
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Sockets.
Nov 28 16:27:36 konstrukt systemd[22108]: Reached target Basic System.
Nov 28 16:27:36 konstrukt systemd[22108]: Starting Run Click user-level
hooks...
Nov 28 16:27:36 konstrukt systemd[22108]: Started D-Bus User Message Bus.
[...]
ProblemType: Bug
DistroRelease: Ubuntu 16.10
Package: sbuild 0.71.0-2ubuntu1
ProcVersionSignature: Ubuntu 4.8.0-27.29-generic 4.8.1
Uname: Linux 4.8.0-27-generic x86_64
ApportVersion: 2.20.3-0ubuntu8
Architecture: amd64
CurrentDesktop: Unity
Date: Mon Nov 28 16:28:44 2016
PackageArchitecture: all
SourcePackage: sbuild
UpgradeStatus: Upgraded to yakkety on 2016-11-15 (13 days ago)
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/sbuild/+bug/1645363/+subscriptions
--
Mailing list: https://launchpad.net/~touch-packages
Post to : touch-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~touch-packages
More help : https://help.launchpad.net/ListHelp
