hv-fcopy-daemon.service system failed start

[Scott Moser]

I booted a yakkety system on azure, and saw

$ systemctl status hv-fcopy-daemon.service --no-pager --full
● hv-fcopy-daemon.service - Hyper-V File Copy Protocol Daemon
   Loaded: loaded (/lib/systemd/system/hv-fcopy-daemon.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Thu 2016-08-18 16:01:51 UTC; 32min ago
 Main PID: 2291 (code=exited, status=1/FAILURE)

Aug 18 16:01:51 ubuntu systemd[1]: Started Hyper-V File Copy Protocol Daemon.
Aug 18 16:01:51 ubuntu systemd[1]: hv-fcopy-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 18 16:01:51 ubuntu systemd[1]: hv-fcopy-daemon.service: Unit entered failed state.
Aug 18 16:01:51 ubuntu systemd[1]: hv-fcopy-daemon.service: Failed with result 'exit-code'.

Also, random information but surprising none the less:
$ systemd-analyze
Startup finished in 5min 14.289s (kernel) + 1min 43.164s (userspace) = 6min 57.454s

$ systemd-analyze critical-chain
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @1min 43.124s
└─multi-user.target @1min 43.124s
  └─ephemeral-disk-warning.service @1min 42.888s +235ms
    └─cloud-final.service @1min 39.480s +3.407s
      └─cloud-config.service @1min 2.517s +36.961s
        └─network-online.target @1min 2.464s
          └─cloud-init.service @35.453s +26.967s
            └─networking.service @32.799s +2.622s
              └─network-pre.target @32.766s
                └─cloud-init-local.service @12.044s +20.690s
                  └─local-fs.target @12.030s
                    └─mnt.mount @1min 29.655s
                      └─dev-sdb1.device @1min 8.310s

ProblemType: Bug
DistroRelease: Ubuntu 16.10
Package: linux-cloud-tools-common 4.4.0-34.53
ProcVersionSignature: User Name 4.4.0-34.53-generic 4.4.15
Uname: Linux 4.4.0-34-generic x86_64
AlsaDevices:
 total 0
 crw-rw---- 1 root audio 116, 1 Aug 18 16:01 seq
 crw-rw---- 1 root audio 116, 33 Aug 18 16:01 timer
AplayDevices: Error: [Errno 2] No such file or directory: 'aplay'
ApportVersion: 2.20.3-0ubuntu7
Architecture: amd64
ArecordDevices: Error: [Errno 2] No such file or directory: 'arecord'
AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1:
Date: Thu Aug 18 16:31:54 2016
IwConfig: Error: [Errno 2] No such file or directory: 'iwconfig'
Lsusb: Error: command ['lsusb'] failed with exit code 1:
MachineType: Microsoft Corporation Virtual Machine
PackageArchitecture: all
PciMultimedia:

ProcEnviron:
 TERM=xterm-256color
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcFB: 0 hyperv_fb
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.4.0-34-generic root=UUID=314ea127-227e-4b64-b5b4-d70ab0fb7eb7 ro console=tty1 console=ttyS0 earlyprintk=ttyS0 rootdelay=300
RelatedPackageVersions:
 linux-restricted-modules-4.4.0-34-generic N/A
 linux-backports-modules-4.4.0-34-generic N/A
 linux-firmware 1.160
RfKill: Error: [Errno 2] No such file or directory: 'rfkill'
SourcePackage: linux
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 05/23/2012
dmi.bios.vendor: American Megatrends Inc.
dmi.bios.version: 090006
dmi.board.name: Virtual Machine
dmi.board.vendor: Microsoft Corporation
dmi.board.version: 7.0
dmi.chassis.asset.tag: 7783-7084-3265-9085-8269-3286-77
dmi.chassis.type: 3
dmi.chassis.vendor: Microsoft Corporation
dmi.chassis.version: 7.0
dmi.modalias: dmi:bvnAmericanMegatrendsInc.:bvr090006:bd05/23/2012:svnMicrosoftCorporation:pnVirtualMachine:pvr7.0:rvnMicrosoftCorporation:rnVirtualMachine:rvr7.0:cvnMicrosoftCorporation:ct3:cvr7.0:
dmi.product.name: Virtual Machine
dmi.product.version: 7.0
dmi.sys.vendor: Microsoft Corporation

[Brad Figg (brad-figg)]

This change was made by a bot.

[Joseph Salisbury (jsalisbury)]

Is it possible for you to test other kernels with that instance? It would be good to confirm this is in fact a regression and bisect it down.

[Shaun Hughes (shaun-hughes)]

I am seeing this as well in a Hyper-V 2012R2 environment, but with more reasonable boot times.

$ systemd-analyze
Startup finished in 14.479s (kernel) + 3.101s (userspace) = 17.580s

$ cat /proc/version
Linux version 4.4.0-36-generic (buildd@lcy01-01) (gcc version 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.2) ) #55-Ubuntu SMP Thu Aug 11 18:01:55 UTC 2016

$ systemctl status hv-fcopy-daemon.service --no-pager --full
● hv-fcopy-daemon.service - Hyper-V File Copy Protocol Daemon
   Loaded: loaded (/lib/systemd/system/hv-fcopy-daemon.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Tue 2016-08-30 15:51:41 PDT; 32min ago
  Process: 3105 ExecStart=/usr/sbin/hv_fcopy_daemon -n (code=exited, status=1/FAILURE)
 Main PID: 3105 (code=exited, status=1/FAILURE)

Aug 30 15:51:41 xenial01 systemd[1]: Started Hyper-V File Copy Protocol Daemon.
Aug 30 15:51:41 xenial01 systemd[1]: hv-fcopy-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 15:51:41 xenial01 systemd[1]: hv-fcopy-daemon.service: Unit entered failed state.
Aug 30 15:51:41 xenial01 systemd[1]: hv-fcopy-daemon.service: Failed with result 'exit-code'.

$ sudo grep -E -i "hv.fcopy" /var/log/syslog
Aug 30 15:51:41 xenial01 HV_FCOPY: starting; pid is:3105
Aug 30 15:51:41 xenial01 HV_FCOPY: open /dev/vmbus/hv_fcopy failed; error: 2 No such file or directory
Aug 30 15:51:41 xenial01 systemd[1]: hv-fcopy-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 30 15:51:41 xenial01 systemd[1]: hv-fcopy-daemon.service: Unit entered failed state.
Aug 30 15:51:41 xenial01 systemd[1]: hv-fcopy-daemon.service: Failed with result 'exit-code'.

[John Lose (johnlose)]

cat /proc/version
Linux version 4.4.0-36-generic (buildd@lcy01-01) (gcc version 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.2) ) #55-Ubuntu SMP Thu Aug 11 18:01:55 UTC 2016
joe@cloud:~$ systemctl status hv-vss-daemon.service

● hv-vss-daemon.service - Hyper-V VSS Protocol Daemon
   Loaded: loaded (/lib/systemd/system/hv-vss-daemon.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Di 2016-09-13 09:15:19 CEST; 19min ago
  Process: 2157 ExecStart=/usr/sbin/hv_vss_daemon -n (code=exited, status=1/FAILURE)
 Main PID: 2157 (code=exited, status=1/FAILURE)

Sep 13 09:15:18 cloud systemd[1]: Started Hyper-V VSS Protocol Daemon.
Sep 13 09:15:19 cloud systemd[1]: hv-vss-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 13 09:15:19 cloud systemd[1]: hv-vss-daemon.service: Unit entered failed state.
Sep 13 09:15:19 cloud systemd[1]: hv-vss-daemon.service: Failed with result 'exit-code'.

Seems like the whole VSS thing is broken. I face this also in GEN1 HyperV 2008R2.

[Ian Abbott (ian-abbott)]

The /dev/vmbus/hv_fcopy device won't be created unless the 'Guest Service Interface' integration service is enabled in the VM. It isn't enabled by default. This can be checked with the following PowerShell command on the Hyper-V server:

  Get-VMIntegrationService 'Guest Service Interface' -VMName FOO

where 'FOO' is the name of the virtual machine. Look for the 'Enabled' column in the output. If it says 'False', it can be enabled using the following PowerShell command:

  Enable-VMIntegrationService 'Guest Service Interface' -VMName FOO