The tftpd-hpa doesn't start after update

Question

I have tftpd-hpa installed(Ubuntu 16.04 LTS). Recently, maybe after getting some updates (or uninstalling some application with vaste dependencies) the tftpd-hpa doesn't start anymore. The tftpd-hpa settings are:

TFTP_USERNAME="tftp"
TFTP_DIRECTORY="/var/lib/tftpboot"
TFTP_ADDRESS=":69"
TFTP_OPTIONS="--secure --create"

The default root directory is /var/lib/tftpboot. Output of systemctl status tftpd-hpa.service and journalctl -xe commands:

testlab@Amtek:~$ systemctl status tftpd-hpa.service
● tftpd-hpa.service - LSB: HPA's tftp server
   Loaded: loaded (/etc/init.d/tftpd-hpa; bad; vendor preset: enabled)
   Active: failed (Result: exit-code) since Tue 2017-04-18 01:47:32 EEST; 2min 8
     Docs: man:systemd-sysv-generator(8)
  Process: 4764 ExecStart=/etc/init.d/tftpd-hpa start (code=exited, status=71)

Apr 18 01:47:32 Amtek systemd[1]: Stopped LSB: HPA's tftp server.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Addre
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, 
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed stat
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit
lines 1-14/14 (END)

---

testlab@Amtek:~$ journalctl -xe
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Addre
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, 
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed stat
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authenticat
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atom
lines 1276-1298/1298 (END)
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Addres
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, c
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed state
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit-
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authenticati
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atomi
lines 1276-1298/1298 (END)
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Address already in use
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, code=exited status=71
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed state.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit-code'.
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authentication Agent for unix-process:4752:17293
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=58
lines 1276-1298/1298 (END)
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Address already in use
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, code=exited status=71
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed state.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit-code'.
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authentication Agent for unix-process:4752:172933
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=585
lines 1276-1298/1298 (END)
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Address already in use
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, code=exited status=71
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed state.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit-code'.
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authentication Agent for unix-process:4752:1729339 (system
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=585206 end=5
lines 1276-1298/1298 (END)
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Address already in use
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, code=exited status=71
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed state.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit-code'.
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authentication Agent for unix-process:4752:1729339 (system 
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=585206 end=58
lines 1276-1298/1298 (END)
-- 
-- Unit tftpd-hpa.service has finished shutting down.
Apr 18 01:47:32 Amtek systemd[1]: Starting LSB: HPA's tftp server...
-- Subject: Unit tftpd-hpa.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has begun starting up.
Apr 18 01:47:32 Amtek tftpd-hpa[4764]:  * Starting HPA's tftpd in.tftpd
Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Address already in use
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Control process exited, code=exited status=71
Apr 18 01:47:32 Amtek systemd[1]: Failed to start LSB: HPA's tftp server.
-- Subject: Unit tftpd-hpa.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit tftpd-hpa.service has failed.
-- 
-- The result is failed.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Unit entered failed state.
Apr 18 01:47:32 Amtek systemd[1]: tftpd-hpa.service: Failed with result 'exit-code'.
Apr 18 01:47:32 Amtek polkitd(authority=local)[885]: Unregistered Authentication Agent for unix-process:4752:1729339 (system bus name :1.
Apr 18 01:48:46 Amtek kernel: [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=585206 end=585207) time 9
lines 1276-1298/1298 (END)

EDIT: below is sudo netstat -lnp | grep 69 output

udp        0      0 0.0.0.0:69              0.0.0.0:*                           851/inetd       
unix  2      [ ACC ]     STREAM     LISTENING     20940    1069/Xorg           @/tmp/.X11-unix/X0
unix  2      [ ACC ]     STREAM     LISTENING     20941    1069/Xorg           /tmp/.X11-unix/X0

Solution

Combining the two parts of information:

Recently, after some updates received

And the following error:

Apr 18 01:47:32 Amtek in.tftpd[4777]: cannot bind to local IPv4 socket: Address already in use

It seems like the problem is that the tftp port (69) is already in use, when you start the tftp server. This might be due to a new program which was installed/updated recently.

Running the following command will help you figure out which process is using tftp port (69) on your machine:

netstat -lnp | grep 69

netstat man

-l, --listening Show only listening sockets. (These are omitted by default.)

--numeric , -n Show numerical addresses instead of trying to determine symbolic host, port or user names.

-p, --program Show the PID and name of the program to which each socket belongs.

Note: The | grep 69 filter the result and will show only the lines which holds 69 in them

Edit:

As you added to your question the result of netstat -lnp shows that now inetd is running on udp/port 69, it is possible that it execute tftp client as part of inetd, hence you can't run tftpd-hpa on this port.

Note: Please check if tftpd is running, and if it is good enough you can avoid using tftpd-hpa

You have two options:

• Move tftp server to use different port This can be done by changing the following line which set tftp on port 69:

  TFTP_ADDRESS=":69"

  To use other port, e.g. 6900:

  TFTP_ADDRESS=":6900"

Note: Using this solution will require that tftp-client will use the new port number

• Stop inetd from using udp/69 You can check if tftp configuration file exists in inetd folder, search for a file in a name like:

  /etc/xinetd.d/tftp

or

 /etc/inetd.d/tftp

Comments

[Rui F Ribeiro]

Do you have automatic recovery, like monit in place?

[sonex]

Not sure, seems no.

[sonex]

I edited details, added netstat -lnp | grep 69 output.

[Yaron]

@sonex - I've edit my answer to reflect the result of the output.

[sonex]

I would prefer not to change the default tftp port number 69. As to second option, I have no xinetd installed, also have no inetd folder. The inetd files is here.

[sonex]

Here is a few more logs.

[Yaron]

@sonex - did you confirm that no tftpd is running on your machine? for example, what happen when you try to connect using tftp to your machine?

[sonex]

I tested tftp on local PC, created test file.txt in root dir /var/lib/tftpboot and able to download it. However, the status of tftpd-hpa is strange. What is correct ownership and chmod permissions for the TFTP directory?

[Yaron]

@sonex - please try to stop tftpd-hpa from running on boot and try again to confirm that another tftpd is running (e.g. by inetd)

[sonex]

I tried to stop tftpd-hpa use command echo manual | sudo tee /etc/init/tftpd-hpa.override, then checked status with service tftpd-hpa status, it still show same output as I posted in previous log.

[Yaron]

@sonex - please change the tftpd-hpa port to be 6969, boot the machine, and check if you can download a file using tftp-client using the default port of 69 (i.e. without changing the default port your tftp-client is using)

[sonex]

Changed to 6969, tested tftp on localhost machine: I can download (get) file, but upload (put) file into /tftpboot dir only possible if I first create empty file with file name I going to upload. tftpd-hpa status is ok (green). The output of ps -ef | grep tftpd: root 2566 1 0 23:05 ? 00:00:00 /usr/sbin/in.tftpd --listen --user tftp --address 0.0.0.0:6969 --secure --create /var/lib/tftpboot testlab+ 2860 2848 0 23:17 pts/2 00:00:00 grep --color=auto tftpd

[Yaron]

@sonox - great! this prove that you have two tftp servers. one (tftp-hpa) is running on port 6969, and one is running on port 69. I guess that you'll want to leave only one of them. You'll need to identify what is executing the 2nd tftp server. I'd suggest checking inted / xinetd configuration as the tftp server seems to be executed by inted

[sonex]

I have no xinetd installed. Inetd configuration inetd.conf

[Yaron]

@sonox - tftp is enabled in your inetd.conf. adding # before the tftp line and restart the system will stop inetd tftpd server.

[Yaron]

@sonox - you have TWO tftp servers running on your system, tftp server from inetd and another tftp server (tftpd-hpa server). The original problem happened as both servers tried to use the same port - hence tftp-hpa failed running. We found the problem. You should choose ONE TFTP server and remove the other one. This will solve your problem. The Debian Bug report doesn't seems to be related.

[sonex]

I commented tftp line in /etc/inetd.conf, and changed port back to 69 in tftpd-hpa configuration file. When I checked status with sudo service tftpd-hpa status, it show failed status again, all the same. I can download files, though (tested on localhost).

[Yaron]

@sonex - did you restart your system after you made the changes?

[sonex]

It works now, a full system restart was needed to apply changes, as restart tftpd-hpa service from terminal not worked. Thank you!