troglobit/uftpd

still able to trigger 100% CPU usage

oz123 opened this issue ยท 12 comments

oz123 commented

Hi,

The new release is awesome. VLC can now play files over FTP using uftpd.
The CPU usage is nothing if the directory has some media files.

However, when I started VLC FTP client in a directory full of non playable media uftp ran crazy
and started 100% cpu usage.

For example I browsed to ~/Downloads/zoom/audio
and tried playing libqtaudio_alsa.so, obvisiouly this should not work on VLC. But even after killing VLC on android uftpd keeps my CPU busy.
I could not kill it with CTRL+C. Only pkill -9 uftpd stopped it.

(You can download zoom video client from https://www.zoom.us/).

I know this is a weird test to do ... Never the less, I thought I should share the results of my experiment here.

Wow, thanks for trying it out! So happy I managed to fix all the issues you reported previously :-)

OK, I'll look in to it, thanks for reporting!

Weird, cannot reproduce the issue ... could you perhaps give me some more details on what you did?

I tried:

  • Download the zoom tarball and unpack it in ~/Downloads
  • Ran the uftpd configure script with no arguments
  • Started uftpd from the src/ sub-directory: sudo ./src/uftpd -n /home/jocke/Downloads
  • Used the VLC app to list the directory and navigate to zoom
  • The zoom directory has an empy doc/ directory, nothing ...
  • Tapped on libqtaudio_alsa.so in the audio/ directory, nothing ...
oz123 commented

I can definitely reproduce this is issue on two gentoo laptops.
Both have libuev in the latest version (v2.1.2).

Here is an example output:

$ sudo uftpd -l info -n .
Password: 
Starting FTP server on port 21 ...
Starting TFTP server on port 69 ...
Serving files from . ...
Client connection from 192.168.1.100
Guest logged in from 192.168.1.100
Data server port estabished.  Waiting for client connnect ...
Client connection from 192.168.1.100
Guest logged in from 192.168.1.100
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
User anonymous from 192.168.1.100 downloaded video_2016-10-23_10-44-36.mov
Data server port estabished.  Waiting for client connnect ...
User anonymous from 192.168.1.100 downloaded video_2016-10-23_10-44-36.mov
Client connection from 192.168.1.100
Guest logged in from 192.168.1.100
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
User anonymous from 192.168.1.100 downloaded becomingfunctional.epub
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
User anonymous from 192.168.1.100 downloaded becomingfunctional.epub
Client connection from 192.168.1.100
Guest logged in from 192.168.1.100
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
User anonymous from 192.168.1.100 downloaded becomingfunctional.epub
Data server port estabished.  Waiting for client connnect ...
Client connection from 192.168.1.100
Guest logged in from 192.168.1.100
Data server port estabished.  Waiting for client connnect ...
Data server port estabished.  Waiting for client connnect ...
User anonymous from 192.168.1.100 downloaded becomingfunctional.epub
Data server port estabished.  Waiting for client connnect ...
Client disconnected.
^CRecieved signal 2, exiting ...
Killed

As you can see, I can play a video. The video stops, and CPU usage is still OK.
If I try to play an epub file, VLC closes the connection. Immidietly after that CPU usage spikes to 100%
and I can't kill uftp with CTRL+C. using pkill -9 uftpd on another tty killed it.

I hope this helps your investigations.

Thank you @oz123, I'll see what I can find! Very kind of you to provide such detailed feedback :)

Update: still cannot reproduce this issue. May have to try out Gentoo ... sorry

oz123 commented

You don't have to try Gentoo ... I can reproduce this on Ubuntu ... here is an account of how to.

  1. First start uftpd in a directory where you have files to serve
  2. start uftpd with:
# uname -a
Linux oznt-IdeaPad-U330p 4.4.0-128-generic #154-Ubuntu SMP Fri May 25 14:15:18 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
root@oznt-IdeaPad-U330p:/home/oznt/Desktop/uftpd-test# LD_LIBRARY_PATH=/usr/local/lib/ uftpd -l debug -n .
4080> Initializing ...

Now on vlc start a connection, this will list the files in that directory:

4080> Serving files as PID 4080 ...
4080> Starting services ...
4080> Opened socket for port 21
4080> Starting FTP server on port 21 ...
4080> Opened socket for port 69
4080> Starting TFTP server on port 69 ...
4080> Serving files from . ...
4080> Created new client session as PID 4085
4085> Client connection from 192.168.1.100
4085> Sent: 220 uftpd (2.5) ready.

4085> Recv: FEAT 
4085> Sent: 
211-Features:
 EPSV
 PASV
 SIZE
 UTF8
 REST STREAM
 MLST modify*;perm*;size*;type*;
211 End

4085> Recv: USER anonymous
4085> Guest logged in from 192.168.1.100
4085> Sent: 230 Guest login OK, access restrictions apply.

4085> Recv: EPSV ALL
4085> Sent: 200 Command OK

4085> Recv: TYPE I
4085> Sent: 200 Type set to I.

4085> Recv: EPSV 
4085> Data server port estabished.  Waiting for client connnect ...
4085> Sent: 229 Entering Extended Passive Mode (|||37827|)

4085> Recv: TYPE I
4085> Sent: 200 Type set to I.

4085> Event on data_listen_sd ...
4085> Client PASV data connection from 192.168.1.100:39758
4085> No pending command, waiting ...
4085> Recv: MLSD 
4085> Compose path from cwd: /, arg: 
4085> Reading directory / ... 4 number of entries
4085> Sent: 125 Data connection already open; transfer starting.

4085> Sending LIST entry 0 of 4 to 192.168.1.100 ...
4085> Found directory entry .
4085> Found directory entry ..
4085> Found directory entry Birdman.2014.720p.BluRay.x264.YIFY.mp4
4085> Compose path from cwd: /, arg: /Birdman.2014.720p.BluRay.x264.YIFY.mp4
4085> Found directory entry Building Web Applications with Flask.pdf
4085> Compose path from cwd: /, arg: /Building Web Applications with Flask.pdf
4085> Found directory entry .
4085> Compose path from cwd: /, arg: /.
4085> Found directory entry ..
4085> Compose path from cwd: /, arg: /..
4085> Found directory entry Birdman.2014.720p.BluRay.x264.YIFY.mp4
4085> Compose path from cwd: /, arg: /Birdman.2014.720p.BluRay.x264.YIFY.mp4
4085> LIST modify=20180626203801;perm=rw;size=908665147;type=file; Birdman.2014.720p.BluRay.x264.YIFY.mp4

4085> Found directory entry Building Web Applications with Flask.pdf
4085> Compose path from cwd: /, arg: /Building Web Applications with Flask.pdf
4085> LIST modify=20180626203748;perm=rw;size=5643465;type=file; Building Web Applications with Flask.pdf

4085> Closing data connection ...
4085> Sent: 226 Transfer complete.
4085> Recv: ABOR 
4085> Aborting any current transfer ...
4085> Closing data connection ...
4085> Sent: 226 Closing data connection.
4085> Recv: QUIT 
4085> Sent: 221 Goodbye.
4085> FTP Client session ended.

Now start playing that film VLC and abort playing after a few seconds:

4080> Created new client session as PID 4086
4086> Client connection from 192.168.1.100
4086> Sent: 220 uftpd (2.5) ready.

4086> Recv: FEAT 
4086> Sent: 
211-Features:
 EPSV
 PASV
 SIZE
 UTF8
 REST STREAM
 MLST modify*;perm*;size*;type*;
211 End

4086> Recv: USER anonymous
4086> Guest logged in from 192.168.1.100
4086> Sent: 230 Guest login OK, access restrictions apply.

4086> Recv: EPSV ALL
4086> Sent: 200 Command OK

4086> Recv: TYPE I
4086> Sent: 200 Type set to I.

4086> Recv: SIZE Birdman.2014.720p.BluRay.x264.YIFY.mp4
4086> Compose path from cwd: /, arg: Birdman.2014.720p.BluRay.x264.YIFY.mp4
4086> SIZE /Birdman.2014.720p.BluRay.x264.YIFY.mp4
4086> Sent: 213 908665147

4086> Recv: EPSV 
4086> Data server port estabished.  Waiting for client connnect ...
4086> Sent: 229 Entering Extended Passive Mode (|||60984|)

4086> Recv: TYPE I
4086> Sent: 200 Type set to I.

4086> Event on data_listen_sd ...
4086> Client PASV data connection from 192.168.1.100:42986
4086> No pending command, waiting ...
4086> Recv: RETR Birdman.2014.720p.BluRay.x264.YIFY.mp4
4086> Compose path from cwd: /, arg: Birdman.2014.720p.BluRay.x264.YIFY.mp4
4086> Sent: 125 Data connection already open; transfer starting.

4086> Sending 8192 bytes of Birdman.2014.720p.BluRay.x264.YIFY.mp4 to 192.168.1.100 ...
4086> Sending 8192 bytes of Birdman.2014.720p.BluRay.x264.YIFY.mp4 to 192.168.1.100 ...
4086> Recv: ABOR 
4086> Aborting any current transfer ...
4086> Closing data connection ...
4086> Sent: 426 Connection closed; transfer aborted.

4086> Sent: 226 Closing data connection.

4086> Recv: EPSV 
4086> Data server port estabished.  Waiting for client connnect ...
4086> Sent: 229 Entering Extended Passive Mode (|||37902|)

Now in top you will see uftpd consuming 100% on one core.

100 ...
4086> Sending 8192 bytes of Birdman.2014.720p.BluRay.x264.YIFY.mp4 to 192.168.1.100 ...
4086> Connection reset by client.
4086> Closing data connection ...
4086> Sent: 426 TCP connection was established but then broken!

4086> Client disconnected.
4086> FTP Client session ended.

Now try and play a PDF:

4080> Created new client session as PID 4119
4119> Client connection from 192.168.1.100
4119> Sent: 220 uftpd (2.5) ready.

4119> Recv: FEAT 
4119> Sent: 
211-Features:
 EPSV
 PASV
 SIZE
 UTF8
 REST STREAM
 MLST modify*;perm*;size*;type*;
211 End

4119> Recv: USER anonymous
4119> Guest logged in from 192.168.1.100
4119> Sent: 230 Guest login OK, access restrictions apply.

4119> Recv: EPSV ALL
4119> Sent: 200 Command OK

4119> Recv: TYPE I
4119> Sent: 200 Type set to I.

4119> Recv: SIZE Building Web Applications with Flask.pdf
4119> Compose path from cwd: /, arg: Building Web Applications with Flask.pdf
4119> SIZE /Building Web Applications with Flask.pdf
4119> Sent: 213 5643465

4119> Recv: EPSV 
4119> Data server port estabished.  Waiting for client connnect ...
4119> Sent: 229 Entering Extended Passive Mode (|||45324|)

4119> Recv: TYPE I
4119> Sent: 200 Type set to I.

4119> Event on data_listen_sd ...
4119> Client PASV data connection from 192.168.1.100:43161
4119> No pending command, waiting ...
4119> Recv: RETR Building Web Applications with Flask.pdf
4119> Compose path from cwd: /, arg: Building Web Applications with Flask.pdf
4119> Sent: 125 Data connection already open; transfer starting.

4119> Sending 8192 bytes of Building Web Applications with Flask.pdf to 192.168.1.100 ...
4119> Sending 8192 bytes of Building Web Applications with Flask.pdf to 192.168.1.100 ...
4119> Sending 8192 bytes of Building Web Applications with Flask.pdf to 192.168.1.100 ...
4119> Recv: ABOR 
4119> Aborting any current transfer ...
4119> Closing data connection ...
4119> Sent: 426 Connection closed; transfer aborted.

4119> Sent: 226 Closing data connection.

4119> Recv: EPSV 
4119> Data server port estabished.  Waiting for client connnect ...
4119> Sent: 229 Entering Extended Passive Mode (|||48996|)

4119> Recv: TYPE I
4119> Sent: 200 Type set to I.

4119> Recv: REST 5443465
4119> Sent: 350 Restarting at 5443465.  Send STOR or RETR to continue transfer.

4119> Event on data_listen_sd ...
4119> Client PASV data connection from 192.168.1.100:41423
4119> No pending command, waiting ...
4119> Recv: RETR Building Web Applications with Flask.pdf
4119> Compose path from cwd: /, arg: Building Web Applications with Flask.pdf
4119> Previous REST 5443465 of file size 5643465
4119> Sent: 125 Data connection already open; transfer starting.

4119> User anonymous from 192.168.1.100 downloaded Building Web Applications with Flask.pdf
4119> Closing data connection ...
4119> Sent: 226 Transfer complete.

4119> Recv: ABOR 
4119> Aborting any current transfer ...
4119> Closing data connection ...
4119> Sent: 226 Closing data connection.

4119> Recv: EPSV 
4119> Data server port estabished.  Waiting for client connnect ...
4119> Sent: 229 Entering Extended Passive Mode (|||57325|)

4119> Recv: TYPE I
4119> Sent: 200 Type set to I.

4119> Recv: REST 4686523
4119> Sent: 350 Restarting at 4686523.  Send STOR or RETR to continue transfer.

4119> Event on data_listen_sd ...
4119> Client PASV data connection from 192.168.1.100:48551
4119> No pending command, waiting ...
4119> Recv: RETR Building Web Applications with Flask.pdf
4119> Compose path from cwd: /, arg: Building Web Applications with Flask.pdf
4119> Previous REST 4686523 of file size 5643465
4119> Sent: 125 Data connection already open; transfer starting.

4119> User anonymous from 192.168.1.100 downloaded Building Web Applications with Flask.pdf
4119> Closing data connection ...
4119> Sent: 226 Transfer complete.

4119> Recv: ABOR 
4119> Aborting any current transfer ...
4119> Closing data connection ...
4119> Sent: 226 Closing data connection.

4119> Recv: QUIT 
4119> Sent: 221 Goodbye.

4119> FTP Client session ended.

Now with top you will see uftpd consuming 2 cores 100%:

Tasks: 211 total,   3 running, 208 sleeping,   0 stopped,   0 zombie
%Cpu(s): 50,2 us,  0,2 sy,  0,0 ni, 49,5 id,  0,2 wa,  0,0 hi,  0,0 si,  0,0 st
KiB Mem :  8089156 total,  2748696 free,  1045384 used,  4295076 buff/cache
KiB Swap:  3327996 total,  3327996 free,        0 used.  6501468 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND     
 4086 root      20   0    8552    100      0 R 100,0  0,0   1:16.47 uftpd       
 4119 root      20   0    8552    100      0 R 100,0  0,0   0:20.45 uftpd       
  978 root      20   0  369936  59020  48352 S   1,0  0,7   0:10.68 Xorg        
 1960 oznt      20   0 1163856  99500  57636 S   0,7  1,2   0:16.77 compiz      
 2169 oznt      20   0  664164  36920  28264 S   0,3  0,5   0:03.48 gnome-term+ 
 3754 root      20   0       0      0      0 S   0,3  0,0   0:00.06 kworker/0:1 
    1 root      20   0  119996   6092   3960 S   0,0  0,1   0:01.81 systemd     
    2 root      20   0       0      0      0 S   0,0  0,0   0:00.00 kthreadd    
    3 root      20   0       0      0      0 S   0,0  0,0   0:00.02 ksoftirqd/0 
    5 root       0 -20       0      0      0 S   0,0  0,0   0:00.00 kworker/0:+ 
    7 root      20   0       0      0      0 S   0,0  0,0   0:00.33 rcu_sched   
    8 root      20   0       0      0      0 S   0,0  0,0   0:00.00 rcu_bh      
    9 root      rt   0       0      0      0 S   0,0  0,0   0:00.01 migration/0 
   10 root      rt   0       0      0      0 S   0,0  0,0   0:00.00 watchdog/0  
   11 root      rt   0       0      0      0 S   0,0  0,0   0:00.00 watchdog/1  
   12 root      rt   0       0      0      0 S   0,0  0,0   0:00.01 migration/1 
   13 root      20   0       0      0      0 S   0,0  0,0   0:00.01 ksoftirqd/1 

I think the issue is that VLC is closing the connection inappropriately, and that uftpd tries somehow to handle it ...

I hope this helps a bit more.

Still no luck, unfortunately. It's rock solid for me ... ๐Ÿ˜ž

Is there anything special you do to "abort playing after a few seconds"? I just press the Back button on screen, but I've also tried to background VLC by switching back to the main screen in Android. Nothing.

Maybe you could build uftpd with debug flags and attach gdb to the 100% CPU process when it gets into this state? If that works just do a bt, or bt full, at the GDB prompt and submit the log here.

To build with debug flags, run configure like this:

./configure CFLAGS="-g -O0" [any other configure options you usually have]

Run make V=1 clean all to verify that the default -O2 is not used anymore.

oz123 commented

Hi, thanks for staying on this.

OK, here is what I did on the uftpd session (I followed all your instructions, then I tried playing a JSON file VLC). This again triggers a high cpu usage.

[29] oznt@yeni2:~/Software/uftpd/uftpd  [master]  $ sudo make V=1 clean all
Making clean in src
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd/src'
test -z "uftpd" || rm -f uftpd
rm -f *.o
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd/src'
Making clean in man
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd/man'
make[1]: Nothing to be done for 'clean'.
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd/man'
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd'
make[1]: Nothing to be done for 'clean-am'.
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd'
make  all-recursive
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd'
Making all in src
make[2]: Entering directory '/home/oznt/Software/uftpd/uftpd/src'
gcc -DHAVE_CONFIG_H -I. -I..  -D_GNU_SOURCE -D_BSD_SOURCE -D_DEFAULT_SOURCE  -W -Wall -Wextra -Wno-unused-parameter -std=gnu99   -g -O0 -MT uftpd-uftpd.o -MD -MP -MF .deps/uftpd-uftpd.Tpo -c -o uftpd-uftpd.o `test -f 'uftpd.c' || echo './'`uftpd.c
mv -f .deps/uftpd-uftpd.Tpo .deps/uftpd-uftpd.Po
gcc -DHAVE_CONFIG_H -I. -I..  -D_GNU_SOURCE -D_BSD_SOURCE -D_DEFAULT_SOURCE  -W -Wall -Wextra -Wno-unused-parameter -std=gnu99   -g -O0 -MT uftpd-common.o -MD -MP -MF .deps/uftpd-common.Tpo -c -o uftpd-common.o `test -f 'common.c' || echo './'`common.c
mv -f .deps/uftpd-common.Tpo .deps/uftpd-common.Po
gcc -DHAVE_CONFIG_H -I. -I..  -D_GNU_SOURCE -D_BSD_SOURCE -D_DEFAULT_SOURCE  -W -Wall -Wextra -Wno-unused-parameter -std=gnu99   -g -O0 -MT uftpd-ftpcmd.o -MD -MP -MF .deps/uftpd-ftpcmd.Tpo -c -o uftpd-ftpcmd.o `test -f 'ftpcmd.c' || echo './'`ftpcmd.c
mv -f .deps/uftpd-ftpcmd.Tpo .deps/uftpd-ftpcmd.Po
gcc -DHAVE_CONFIG_H -I. -I..  -D_GNU_SOURCE -D_BSD_SOURCE -D_DEFAULT_SOURCE  -W -Wall -Wextra -Wno-unused-parameter -std=gnu99   -g -O0 -MT uftpd-tftpcmd.o -MD -MP -MF .deps/uftpd-tftpcmd.Tpo -c -o uftpd-tftpcmd.o `test -f 'tftpcmd.c' || echo './'`tftpcmd.c
mv -f .deps/uftpd-tftpcmd.Tpo .deps/uftpd-tftpcmd.Po
gcc -DHAVE_CONFIG_H -I. -I..  -D_GNU_SOURCE -D_BSD_SOURCE -D_DEFAULT_SOURCE  -W -Wall -Wextra -Wno-unused-parameter -std=gnu99   -g -O0 -MT uftpd-log.o -MD -MP -MF .deps/uftpd-log.Tpo -c -o uftpd-log.o `test -f 'log.c' || echo './'`log.c
mv -f .deps/uftpd-log.Tpo .deps/uftpd-log.Po
gcc -W -Wall -Wextra -Wno-unused-parameter -std=gnu99   -g -O0   -o uftpd uftpd-uftpd.o uftpd-common.o uftpd-ftpcmd.o uftpd-tftpcmd.o uftpd-log.o -luev   -lite 
make[2]: Leaving directory '/home/oznt/Software/uftpd/uftpd/src'
Making all in man
make[2]: Entering directory '/home/oznt/Software/uftpd/uftpd/man'
make[2]: Nothing to be done for 'all'.
make[2]: Leaving directory '/home/oznt/Software/uftpd/uftpd/man'
make[2]: Entering directory '/home/oznt/Software/uftpd/uftpd'
make[2]: Leaving directory '/home/oznt/Software/uftpd/uftpd'
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd'
[30] oznt@yeni2:~/Software/uftpd/uftpd  [master]  $ ./configure CFLAGS="-g -O0" 
checking for a BSD-compatible install... /usr/bin/install -c
checking whether build environment is sane... yes
checking for a thread-safe mkdir -p... /bin/mkdir -p
checking for gawk... gawk
checking whether make sets $(MAKE)... yes
checking whether make supports nested variables... yes
checking whether make supports nested variables... (cached) yes
checking for gcc... gcc
checking whether the C compiler works... yes
checking for C compiler default output file name... a.out
checking for suffix of executables... 
checking whether we are cross compiling... no
checking for suffix of object files... o
checking whether we are using the GNU C compiler... yes
checking whether gcc accepts -g... yes
checking for gcc option to accept ISO C89... none needed
checking whether gcc understands -c and -o together... yes
checking for style of include used by make... GNU
checking dependency style of gcc... gcc3
checking whether ln -s works... yes
checking how to run the C preprocessor... gcc -E
checking for grep that handles long lines and -e... /bin/grep
checking for egrep... /bin/grep -E
checking for ANSI C header files... yes
checking for strstr... yes
checking for getopt... yes
checking for getsubopt... yes
checking for sys/types.h... yes
checking for sys/stat.h... yes
checking for stdlib.h... yes
checking for string.h... yes
checking for memory.h... yes
checking for strings.h... yes
checking for inttypes.h... yes
checking for stdint.h... yes
checking for unistd.h... yes
checking for uint8_t... yes
checking for uint16_t... yes
checking for uint32_t... yes
checking for pkg-config... /usr/bin/pkg-config
checking pkg-config is at least version 0.9.0... yes
checking for libuev >= 2.1.0... yes
checking for libite >= 1.5.0... yes
checking that generated files are newer than configure... done
configure: creating ./config.status
config.status: creating Makefile
config.status: creating src/Makefile
config.status: creating man/Makefile
config.status: creating config.h
config.status: config.h is unchanged
config.status: executing depfiles commands
[31] oznt@yeni2:~/Software/uftpd/uftpd  [master]  $ sudo make install
Making install in src
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd/src'
make[2]: Entering directory '/home/oznt/Software/uftpd/uftpd/src'
 /bin/mkdir -p '/usr/local/sbin'
  /usr/bin/install -c uftpd '/usr/local/sbin'
make  install-exec-hook
make[3]: Entering directory '/home/oznt/Software/uftpd/uftpd/src'
make[3]: Leaving directory '/home/oznt/Software/uftpd/uftpd/src'
make[2]: Nothing to be done for 'install-data-am'.
make[2]: Leaving directory '/home/oznt/Software/uftpd/uftpd/src'
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd/src'
Making install in man
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd/man'
make[2]: Entering directory '/home/oznt/Software/uftpd/uftpd/man'
make[2]: Nothing to be done for 'install-exec-am'.
 /bin/mkdir -p '/usr/local/share/man/man8'
 /usr/bin/install -c -m 644 uftpd.8 '/usr/local/share/man/man8'
make  install-data-hook
make[3]: Entering directory '/home/oznt/Software/uftpd/uftpd/man'
make[3]: Leaving directory '/home/oznt/Software/uftpd/uftpd/man'
make[2]: Leaving directory '/home/oznt/Software/uftpd/uftpd/man'
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd/man'
make[1]: Entering directory '/home/oznt/Software/uftpd/uftpd'
make[2]: Entering directory '/home/oznt/Software/uftpd/uftpd'
make[2]: Nothing to be done for 'install-exec-am'.
 /bin/mkdir -p '/usr/local/share/doc/uftpd'
 /usr/bin/install -c -m 644 README.md LICENSE '/usr/local/share/doc/uftpd'
make[2]: Leaving directory '/home/oznt/Software/uftpd/uftpd'
make[1]: Leaving directory '/home/oznt/Software/uftpd/uftpd'

$ sudo ./src/uftpd -l debug -n testuftpd/
7023> Initializing ...
7023> Serving files as PID 7023 ...
7023> Starting services ...
7023> Opened socket for port 21
7023> Starting FTP server on port 21 ...
7023> Opened socket for port 69
7023> Starting TFTP server on port 69 ...
7023> Serving files from testuftpd ...
7023> Created new client session as PID 7050
7050> Client connection from 192.168.1.100
7050> Sent: 220 uftpd (2.5) ready.

7050> Recv: FEAT 
7050> Sent: 
211-Features:
 EPSV
 PASV
 SIZE
 UTF8
 REST STREAM
 MLST modify*;perm*;size*;type*;
211 End

7050> Recv: USER anonymous
7050> Guest logged in from 192.168.1.100
7050> Sent: 230 Guest login OK, access restrictions apply.

7050> Recv: EPSV ALL
7050> Sent: 200 Command OK

7050> Recv: TYPE I
7050> Sent: 200 Type set to I.

7050> Recv: SIZE package.json
7050> Compose path from cwd: /, arg: package.json
7050> SIZE /package.json
7050> Sent: 213 3861

7050> Recv: EPSV 
7050> Data server port estabished.  Waiting for client connnect ...
7050> Sent: 229 Entering Extended Passive Mode (|||53755|)

7050> Recv: TYPE I
7050> Sent: 200 Type set to I.

7050> Event on data_listen_sd ...
7050> Client PASV data connection from 192.168.1.100:37846
7050> No pending command, waiting ...
7050> Recv: RETR package.json
7050> Compose path from cwd: /, arg: package.json
7050> Sent: 125 Data connection already open; transfer starting.

7050> Sending 3861 bytes of package.json to 192.168.1.100 ...
7050> User anonymous from 192.168.1.100 downloaded package.json
7050> Closing data connection ...
7050> Sent: 226 Transfer complete.

7050> Recv: ABOR 
7050> Aborting any current transfer ...
7050> Closing data connection ...
7050> Sent: 226 Closing data connection.

7050> Client disconnected.
7050> FTP Client session ended.
^C7023> Recieved signal 2, exiting ...


Note, I didn't get a 100% CPU usage this time, because I have 4 cores. But 2 where definitely 100% used, for a long duration. Maybe you have a multi-core CPU and you just didn't notice it?
Any way ... here the stack trace from gdb. See also that if I do pgrep uftpd I get to PIDs ...

sudo gdb -p 7050
GNU gdb (Gentoo 8.1 p1) 8.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-pc-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://bugs.gentoo.org/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 7050
Reading symbols from /home/oznt/Software/uftpd/uftpd/src/uftpd...done.
Reading symbols from /usr/lib64/libuev.so.2...(no debugging symbols found)...done.
Reading symbols from /usr/lib64/libite.so.5...(no debugging symbols found)...done.
Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
0x00007f384c5e3631 in uev_exit () from /usr/lib64/libuev.so.2
(gdb) bt full
#0  0x00007f384c5e3631 in uev_exit () from /usr/lib64/libuev.so.2
No symbol table info available.
#1  0x000055bb48a0e8e3 in del_session (ctrl=0x55bb4a32e4d0, isftp=1) at common.c:314
        ctx = 0x55bb4a32e440
#2  0x000055bb48a146c1 in ftp_session (ctx=0x7ffc872e4840, sd=11) at ftpcmd.c:1604
        pid = 0
        ctrl = 0x55bb4a32e4d0
        len = 16
#3  0x000055bb48a0cb1b in ftp_cb (w=0x55bb48c1a8a0 <ftp_watcher>, arg=0x7ffc872e4840, events=1) at uftpd.c:200
        client = 11
#4  0x00007f384c5e3a33 in uev_run () from /usr/lib64/libuev.so.2
No symbol table info available.
#5  0x000055bb48a0cdcc in serve_files (ctx=0x7ffc872e4840) at uftpd.c:261
        ftp = 0
        tftp = 0
#6  0x000055bb48a0d508 in main (argc=5, argv=0x7ffc872e4988) at uftpd.c:425
        c = -1
        subopts = 0xc2 <error: Cannot access memory at address 0xc2>
        token = {0x55bb48a16061 "ftp", 0x55bb48a16069 "tftp", 0x55bb48a161f9 "writable", 0x0}
        ctx = {running = 1, fd = 3, watchers = {lh_first = 0x55bb48c1aae0 <sigquit_watcher>}, workaround = 0}
(gdb) quit
A debugging session is active.

	Inferior 1 [process 7050] will be detached.

Quit anyway? (y or n) y
Detaching from program: /home/oznt/Software/uftpd/uftpd/src/uftpd, process 7050

Thanks bunch! ๐Ÿ™‡โ€โ™‚๏ธ ๐Ÿ‘

I think I have an idea now what's going on. The backtrace clearly shows that the client process reaches del_session(), and even calls the end of the event loop uev_exit(). So there is definitely something wrong with the cleanup phase.

(Btw, on my system I never see any hangs at all, CPU load of all cores is at ~0%.)

@oz123 Just pushed a possible fix to this problem in f951c46, still not able to reproduce the issue though.

oz123 commented

@troglobit this did it! I can't play json files as expected, and VLC will end the connection without triggering 100% CPU usage.
I believe this ticket can be closed.
Oh, and I forgot to say: thank you very very much!

That is great news! ๐Ÿ˜ƒ

I'm the one who should be giving thanks. Thank you for sticking with it so long and helping out debugging, and reporting, this! โค๏ธ

I'll prepare a new release during the week.