'guix system vm-image' hangs

'guix system vm-image' hangs

[George myglc2 Clemmer]

'guix system vm-image' hangs on guix (GNU Guix) 0.14.0.4439-eb88e built
from source today. Please see log except below. It worked on guix (GNU
Guix) 0.14.0.4196-2c92a. built <2018-04-18 Wed>

TIA - George

Note: full log is avail.

g1@g1 ~/src/vm/vms/sysi20$ guix system vm-image --image-size=10G sysi19.scm
substitute: updating list of substitutes from 'https://mirror.hydra.gnu.org'... 100.0%
The following derivations will be built:
   /gnu/store/s6k5yvpv7ynbrrzmxndga7y6w7zd0hcd-qemu-image.drv
   /gnu/store/82gwqkkzdc7jwfs7v5442qz3mj3fw7bx-parameters.drv
   /gnu/store/yngnp5b7c9316bkc2h1jqcgmkqj2j72z-init.drv
[...]
[    0.558501] sr 1:0:0:0: Attached scsi generic sg0 type 5
[    0.562147] Freeing unused kernel memory: 1780K
[    0.562741] Write protecting the kernel read-only data: 18432k
[    0.563853] Freeing unused kernel memory: 2024K
[    0.565010] Freeing unused kernel memory: 216K
GC Warning: pthread_getattr_np or pthread_attr_getstack failed for main thread
GC Warning: Couldn't read /proc/stat
Welcome, this is GNU's early boot Guile.
Use '--repl' for an initrd REPL.

loading kernel modules...
[    0.627471] usbcore: registered new interface driver usb-storage
[    0.630380] usbcore: registered new interface driver uas
[    0.637058] hidraw: raw HID events driver (C) Jiri Kosina
[    0.638165] usbcore: registered new interface driver usbhid
[    0.638838] usbhid: USB HID core driver
[    0.646823] isci: Intel(R) C600 SAS Controller Driver - version 1.2.0
[    0.674476] PCI Interrupt Link [LNKC] enabled at IRQ 11
[    0.701700] PCI Interrupt Link [LNKD] enabled at IRQ 10
[    0.729258] PCI Interrupt Link [LNKA] enabled at IRQ 10
[    0.757009] PCI Interrupt Link [LNKB] enabled at IRQ 11
[    0.815977] virtio_blk virtio5: [vda] 20971520 512-byte logical blocks (10.7 GB/10.0 GiB)
[    0.827477] FS-Cache: Loaded
[    0.830625] 9pnet: Installing 9P2000 support
[    0.831776] 9p: Installing v9fs 9p2000 file system support
[    0.832546] FS-Cache: Netfs '9p' registered for caching
configuring QEMU networking...
[    0.846491] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
loading '/gnu/store/30bcjgk80467cgb8fjbpw3ldss5wmn2d-linux-vm-loader'...
[    0.880302] random: fast init done
environment variable `PATH' set to `/gnu/store/1n3cvnxrz1m6jqc09d9m1grbfbs91kmv-qemu-minimal-2.12.0/bin:/gnu/store/h8670f6j1rawhhaz8wvdy5gv79lny0am-parted-3.2/sbin:/gnu/store/nm305rpb2mvridkyj4l3636nc9ql4lf9-e2fsprogs-1.43.6/bin:/gnu/store/nm305rpb2mvridkyj4l3636nc9ql4lf9-e2fsprogs-1.43.6/sbin:/gnu/store/0sq2nflm42x0znkv44add0gk82khkcb6-dosfstools-4.1/sbin:/gnu/store/0hl513mnpkhszm2hjai2w9cxmpxs0vgq-sed-4.4/bin:/gnu/store/1h44pkgdd7n6s3i2vjh54awsvfmc219j-grep-3.1/bin:/gnu/store/kgzvfby2ggi1xawsh5vjh4s93qk2dp9k-coreutils-8.28/bin:/gnu/store/k7r2m2wgj8x8jjhccwjsiimp0dlzxb7i-findutils-4.6.0/bin:/gnu/store/ahxc89r6npzf2bbl8yg5vdjicskzzjf3-gawk-4.1.4/bin:/gnu/store/cwwvdxd9d778a2xp8vbb38vl62rx992g-guix-0.14.0-11.ab85cf7/bin:/gnu/store/cwwvdxd9d778a2xp8vbb38vl62rx992g-guix-0.14.0-11.ab85cf7/sbin
 '
creating partition table with 2 partitions (10190.0 MiB, 40.0 MiB)...
[    1.344115] tsc: Refined TSC clocksource calibration: 3392.348 MHz
[    1.344865] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x30e6121e742, max_idle_ns: 440795321217 ns
[    1.856062] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
  C-c C-c
g1@g1 ~/src/vm/vms/sysi20$ guix --version
guix (GNU Guix) 0.14.0.4439-eb88e

Re: 'guix system vm-image' hangs

[Eric Bavier]

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

Hi George,

I've seen the same lately with 'guix system vm':

On Wed, 25 Apr 2018 21:39:30 -0400
George myglc2 Clemmer <myglc2@gmail.com> wrote:

> 'guix system vm-image' hangs on guix (GNU Guix) 0.14.0.4439-eb88e built
> from source today. Please see log except below. It worked on guix (GNU
> Guix) 0.14.0.4196-2c92a. built <2018-04-18 Wed>
> 
> TIA - George
> 
[...]
> environment variable `PATH' set to `/gnu/store/1n3cvnxrz1m6jqc09d9m1grbfbs91kmv-qemu-minimal-2.12.0/bin:/gnu/store/h8670f6j1rawhhaz8wvdy5gv79lny0am-parted-3.2/sbin:/gnu/store/nm305rpb2mvridkyj4l3636nc9ql4lf9-e2fsprogs-1.43.6/bin:/gnu/store/nm305rpb2mvridkyj4l3636nc9ql4lf9-e2fsprogs-1.43.6/sbin:/gnu/store/0sq2nflm42x0znkv44add0gk82khkcb6-dosfstools-4.1/sbin:/gnu/store/0hl513mnpkhszm2hjai2w9cxmpxs0vgq-sed-4.4/bin:/gnu/store/1h44pkgdd7n6s3i2vjh54awsvfmc219j-grep-3.1/bin:/gnu/store/kgzvfby2ggi1xawsh5vjh4s93qk2dp9k-coreutils-8.28/bin:/gnu/store/k7r2m2wgj8x8jjhccwjsiimp0dlzxb7i-findutils-4.6.0/bin:/gnu/store/ahxc89r6npzf2bbl8yg5vdjicskzzjf3-gawk-4.1.4/bin:/gnu/store/cwwvdxd9d778a2xp8vbb38vl62rx992g-guix-0.14.0-11.ab85cf7/bin:/gnu/store/cwwvdxd9d778a2xp8vbb38vl62rx992g-guix-0.14.0-11.ab85cf7/sbin'
> creating partition table with 2 partitions (10190.0 MiB, 40.0 MiB)...
> [    1.344115] tsc: Refined TSC clocksource calibration: 3392.348 MHz
> [    1.344865] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x30e6121e742, max_idle_ns: 440795321217 ns
> [    1.856062] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
>   C-c C-c

Same log output on my end.

> g1@g1 ~/src/vm/vms/sysi20$ guix --version
> guix (GNU Guix) 0.14.0.4439-eb88e
> 

I bisected the git repo to commit:

```
commit ba39d3280759fb20a4ff0092a5afac721a5fa769
Author: Mark H Weaver <mhw@netris.org>
Date:   Tue Apr 24 16:51:45 2018 -0400

    gnu: linux-libre: Update to 4.16.4.

    * gnu/packages/linux.scm (%linux-libre-version): Update to 4.16.4.
    (%linux-libre-hash): Update hash.

```

Perhaps we should open a bug.

`~Eric

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: 'guix system vm-image' hangs

[George myglc2 Clemmer]

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

On 04/26/2018 at 03:37 Eric Bavier writes:

> Hi George,
>
> I've seen the same lately with 'guix system vm':
>
> On Wed, 25 Apr 2018 21:39:30 -0400
> George myglc2 Clemmer <myglc2@gmail.com> wrote:
>
>> 'guix system vm-image' hangs on guix (GNU Guix) 0.14.0.4439-eb88e built
>> from source today. Please see log except below. It worked on guix (GNU
>> Guix) 0.14.0.4196-2c92a. built <2018-04-18 Wed>
>>
>> TIA - George
>>
> [...]
>> environment variable `PATH' set to `/gnu/store/1n3cvnxrz1m6jqc09d9m1grbfbs91kmv-qemu-minimal-2.12.0/bin:/gnu/store/h8670f6j1rawhhaz8wvdy5gv79lny0am-parted-3.2/sbin:/gnu/store/nm305rpb2mvridkyj4l3636nc9ql4lf9-e2fsprogs-1.43.6/bin:/gnu/store/nm305rpb2mvridkyj4l3636nc9ql4lf9-e2fsprogs-1.43.6/sbin:/gnu/store/0sq2nflm42x0znkv44add0gk82khkcb6-dosfstools-4.1/sbin:/gnu/store/0hl513mnpkhszm2hjai2w9cxmpxs0vgq-sed-4.4/bin:/gnu/store/1h44pkgdd7n6s3i2vjh54awsvfmc219j-grep-3.1/bin:/gnu/store/kgzvfby2ggi1xawsh5vjh4s93qk2dp9k-coreutils-8.28/bin:/gnu/store/k7r2m2wgj8x8jjhccwjsiimp0dlzxb7i-findutils-4.6.0/bin:/gnu/store/ahxc89r6npzf2bbl8yg5vdjicskzzjf3-gawk-4.1.4/bin:/gnu/store/cwwvdxd9d778a2xp8vbb38vl62rx992g-guix-0.14.0-11.ab85cf7/bin:/gnu/store/cwwvdxd9d778a2xp8vbb38vl62rx992g-guix-0.14.0-11.ab85cf7/s
 bin'
>> creating partition table with 2 partitions (10190.0 MiB, 40.0 MiB)...
>> [    1.344115] tsc: Refined TSC clocksource calibration: 3392.348 MHz
>> [    1.344865] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x30e6121e742, max_idle_ns: 440795321217 ns
>> [    1.856062] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
>>   C-c C-c
>
> Same log output on my end.
>
>> g1@g1 ~/src/vm/vms/sysi20$ guix --version
>> guix (GNU Guix) 0.14.0.4439-eb88e
>>
>
> I bisected the git repo to commit:
>
> ```
> commit ba39d3280759fb20a4ff0092a5afac721a5fa769
> Author: Mark H Weaver <mhw@netris.org>
> Date:   Tue Apr 24 16:51:45 2018 -0400
>
>     gnu: linux-libre: Update to 4.16.4.
>
>     * gnu/packages/linux.scm (%linux-libre-version): Update to 4.16.4.
>     (%linux-libre-hash): Update hash.
>
> ```
>
> Perhaps we should open a bug.
>
> `~Eric

Thank you Eric! Actually I meant to send it to bug-guix@gnu.org
before. Here is something that fails here.

guix system vm-image --image-size=10G sysi19.scm


[-- Attachment #2: sysi19.scm --]
[-- Type: application/octet-stream, Size: 1501 bytes --]

;; -*-Scheme-*-
;;; minimal 'guix system vm-image' config ~ sys.scm
(define sys-packages
  '(
    "cups"
    "git"
    "glibc-utf8-locales"
    "nss-certs"
    "openssh"
    "screen"
    ))
(use-modules (gnu))
(use-modules (gnu packages))
(use-modules (gnu system nss))
(use-service-modules
 avahi
 networking ; dhcp-client-service
 ssh ; openssh-service-type
 )
(operating-system
  (host-name "sysi19")
  (timezone "America/New_York")
  (locale "en_US.utf8")
  (bootloader (grub-configuration (target "/dev/sda")))
  (file-systems (cons (file-system
			(device "g1sd")
			(title 'label)
			(mount-point "/")
			(type "ext4"))
		      %base-file-systems))
  (users (cons*
	  (user-account
	   (name "g1")
	   (group "users")
	   (supplementary-groups '("wheel"))
	   (home-directory "/home/g1"))
	  (user-account
	   (name "al")
	   (group "users")
	   (supplementary-groups '("wheel"))
	   (home-directory "/home/al"))
	  %base-user-accounts))
  (packages (append (map specification->package sys-packages)
		    %base-packages))
  (services (cons*
	     (dhcp-client-service)
	     (service openssh-service-type
		      (openssh-configuration
		       (x11-forwarding? #t)
		       (permit-root-login #t)
		       (allow-empty-passwords? #t)
		       (authorized-keys
			`(
			  ("g1" ,(local-file "glc.pub"))
			  ("al" ,(local-file "glc.pub"))
			  ("root" ,(local-file "glc.pub"))))))
	     (avahi-service)
	     (ntp-service)
	     %base-services))
  (name-service-switch %mdns-host-lookup-nss))

Re: bug#31268: 'guix system vm-image' hangs

[Mark H Weaver]

George myglc2 Clemmer <myglc2@gmail.com> writes:

> On 04/26/2018 at 03:37 Eric Bavier writes:
>
>> Hi George,
>>
>> I've seen the same lately with 'guix system vm':
>>
>> On Wed, 25 Apr 2018 21:39:30 -0400
>> George myglc2 Clemmer <myglc2@gmail.com> wrote:
>>
>>> 'guix system vm-image' hangs on guix (GNU Guix) 0.14.0.4439-eb88e built
>>> from source today. Please see log except below. It worked on guix (GNU
>>> Guix) 0.14.0.4196-2c92a. built <2018-04-18 Wed>

[...]

>> I bisected the git repo to commit:
>>
>> ```
>> commit ba39d3280759fb20a4ff0092a5afac721a5fa769
>> Author: Mark H Weaver <mhw@netris.org>
>> Date:   Tue Apr 24 16:51:45 2018 -0400
>>
>>     gnu: linux-libre: Update to 4.16.4.
>>
>>     * gnu/packages/linux.scm (%linux-libre-version): Update to 4.16.4.
>>     (%linux-libre-hash): Update hash.

FYI, I just pushed commit 8c21c64e59d3f4d223d8aeef91f06fdde7de1ab7 which
updates linux-libre to 4.16.6.  Would you like to see if the problem
still persists?

       Mark

bug#31268: 'guix system vm-image' hangs

[Ludovic Courtès]

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

Hello Mark,

Mark H Weaver <mhw@netris.org> skribis:

> FYI, I just pushed commit 8c21c64e59d3f4d223d8aeef91f06fdde7de1ab7 which
> updates linux-libre to 4.16.6.  Would you like to see if the problem
> still persists?

It does.

I instrumented the code to see what happens.  Opening /dev/vda works
fine, invoking “parted --version” works, so it’s really just ‘parted’
that hangs when asked to do the real thing (with 0% CPU consumption.)

However, if we strace it as with the patch below, it succeeds.  It
doesn’t seem to be a simple timing issue because adding (sleep 2) before
the parted invocation doesn’t make a difference.

To be continued…

Ludo’.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 1526 bytes --]

diff --git a/gnu/build/vm.scm b/gnu/build/vm.scm
index 527b4c495..b73c8f912 100644
--- a/gnu/build/vm.scm
+++ b/gnu/build/vm.scm
@@ -242,9 +242,21 @@ actual /dev name based on DEVICE."
                                      partition-size)
                             partitions)
                        ", "))
-  (apply invoke "parted" "--script"
+  (pk 'parted (which "parted"))
+  (pk 'parted2 (stat (which "parted")))
+  (pk 'opts device partitions offset)
+  (pk 'actual-options "parted" "--script"
          device "mklabel" label-type
          (options partitions offset))
+  (pk 'stat device (stat device))
+  (invoke "parted" "--version")
+  ;; (pk 'open-device device (open-fdes device O_WRONLY))
+  (pk 'parted)
+  (apply invoke "strace" "-s" "123"
+         "parted" "--script"
+         device "mklabel" label-type
+         (options partitions offset))
+  (pk 'parted-done)
 
   ;; Set the 'device' field of each partition.
   (reverse
diff --git a/gnu/system/vm.scm b/gnu/system/vm.scm
index 09a11af86..ba54a71dd 100644
--- a/gnu/system/vm.scm
+++ b/gnu/system/vm.scm
@@ -304,7 +304,7 @@ the image."
                       (ice-9 binary-ports))
 
          (let ((inputs
-                '#$(append (list qemu parted e2fsprogs dosfstools)
+                '#$(append (list strace qemu parted e2fsprogs dosfstools)
                            (map canonical-package
                                 (list sed grep coreutils findutils gawk))
                            (if register-closures? (list guix) '())))