Tern exits with 'killed' when Dockerfile RUN statement is complex

[rnjudge]

Describe the bug
Running Tern on a Dockerfile with a complex RUN statement causes it to crash.

To Reproduce
Steps to reproduce the behavior:

1. Using the following Dockerfile, run tern report -d Dockerfile

FROM debian:buster

# Install fuse-overlayfs and Tern dependencies
RUN apt-get update && apt-get -y install wget gnupg2 tar findutils attr util-linux python3 python3-pip python3-setuptools git && pip3 install --upgrade pip && pip3 install tern && echo 'deb http://download.opensuse.org/repositories/devel:/kubic:/libcontainers:/stable/Debian_10/ /' > /etc/apt/sources.list.d/devel:kubic:libcontainers:stable.list && wget -nv https://download.opensuse.org/repositories/devel:kubic:libcontainers:stable/Debian_10/Release.key -O Release.key && apt-key add - < Release.key && apt-get update -qq && apt-get -qq -y install buildah fuse-overlayfs && rm -rf /var/cache /var/log/dnf* /var/log/yum.*

# Adjust storage.conf to enable Fuse storage.
RUN sed -i -e 's|^#mount_program|mount_program|g' -e '/additionalimage.*/a "/var/lib/shared",' /etc/containers/storage.conf

ENTRYPOINT ["tern"]
CMD ["-h"]

Tern builds the image correctly but fails during the analysis. I noticed it lists "No listing statement" for all the non-snippet install commands that come right after each && (echo, wget, apt-key, rm) and then gets killed.

Error in terminal

(ternenv) rjudge:tern$ tern report -d Dockerfile
2020-07-17 13:47:34,335 - DEBUG - __main__ - Starting...
2020-07-17 13:47:34,340 - DEBUG - run - Setting up...
2020-07-17 13:47:34,342 - DEBUG - run - Building Docker image...
2020-07-17 13:47:34,342 - DEBUG - container - Checking if image "ternimage_69132:terntag_69132" is available on disk...
2020-07-17 13:49:14,330 - DEBUG - helpers - Successfully built image
2020-07-17 13:49:14,331 - DEBUG - container - Checking if image "ternimage_69132:terntag_69132" is available on disk...
2020-07-17 13:49:14,333 - DEBUG - container - Image "ternimage_69132:terntag_69132" found
2020-07-17 13:49:21,743 - DEBUG - rootfs - Running command: tar -tf /home/rjudge/.tern/temp.tar
2020-07-17 13:49:21,750 - DEBUG - rootfs - Running command: tar -x --exclude=.wh.* -f /home/rjudge/.tern/temp.tar -C /home/rjudge/.tern/temp
2020-07-17 13:49:22,726 - DEBUG - rootfs - Running command: tar -tf /home/rjudge/.tern/temp/259e5907d1da030b95c58597756a8b0d7fa4a98168b6358c83c07c863cb8fb46/layer.tar
2020-07-17 13:49:22,794 - DEBUG - rootfs - Running command: tar -x --exclude=.wh.* -f /home/rjudge/.tern/temp/259e5907d1da030b95c58597756a8b0d7fa4a98168b6358c83c07c863cb8fb46/layer.tar -C /home/rjudge/.tern/temp/259e5907d1da030b95c58597756a8b0d7fa4a98168b6358c83c07c863cb8fb46/contents
2020-07-17 13:49:23,152 - DEBUG - rootfs - Running command: sudo /home/rjudge/ternenv/tern/tern/tools/fs_hash.sh /home/rjudge/.tern/temp/259e5907d1da030b95c58597756a8b0d7fa4a98168b6358c83c07c863cb8fb46/contents
[sudo] password for rjudge: 
2020-07-17 13:49:35,708 - DEBUG - rootfs - Running command: tar -tf /home/rjudge/.tern/temp/e7ddaa2d89bff0cabdedd17c1d918b758c4549327c41efae43e51eadbd1254b2/layer.tar
2020-07-17 13:49:35,862 - DEBUG - rootfs - Running command: tar -x --exclude=.wh.* -f /home/rjudge/.tern/temp/e7ddaa2d89bff0cabdedd17c1d918b758c4549327c41efae43e51eadbd1254b2/layer.tar -C /home/rjudge/.tern/temp/e7ddaa2d89bff0cabdedd17c1d918b758c4549327c41efae43e51eadbd1254b2/contents
2020-07-17 13:49:36,979 - DEBUG - rootfs - Running command: sudo /home/rjudge/ternenv/tern/tern/tools/fs_hash.sh /home/rjudge/.tern/temp/e7ddaa2d89bff0cabdedd17c1d918b758c4549327c41efae43e51eadbd1254b2/contents
2020-07-17 13:49:54,838 - DEBUG - rootfs - Running command: tar -tf /home/rjudge/.tern/temp/1dd586cad03bff2f97b2f914d76ababe8a8c589c52298edcdac6890de1ce4b18/layer.tar
2020-07-17 13:49:54,842 - DEBUG - rootfs - Running command: tar -x --exclude=.wh.* -f /home/rjudge/.tern/temp/1dd586cad03bff2f97b2f914d76ababe8a8c589c52298edcdac6890de1ce4b18/layer.tar -C /home/rjudge/.tern/temp/1dd586cad03bff2f97b2f914d76ababe8a8c589c52298edcdac6890de1ce4b18/contents
2020-07-17 13:49:54,846 - DEBUG - rootfs - Running command: sudo /home/rjudge/ternenv/tern/tern/tools/fs_hash.sh /home/rjudge/.tern/temp/1dd586cad03bff2f97b2f914d76ababe8a8c589c52298edcdac6890de1ce4b18/contents
2020-07-17 13:49:54,862 - DEBUG - common - Reading files in filesystem...
2020-07-17 13:49:57,086 - DEBUG - rootfs - Running command: sudo mount -o bind /home/rjudge/.tern/temp/259e5907d1da030b95c58597756a8b0d7fa4a98168b6358c83c07c863cb8fb46/contents /home/rjudge/.tern/temp/mergedir
2020-07-17 13:49:57,121 - DEBUG - rootfs - Running command: sudo mount -t proc /proc /home/rjudge/.tern/temp/mergedir/proc
2020-07-17 13:49:57,169 - DEBUG - rootfs - Running command: sudo mount -o bind /sys /home/rjudge/.tern/temp/mergedir/sys
2020-07-17 13:49:57,217 - DEBUG - rootfs - Running command: sudo mount -o bind /dev /home/rjudge/.tern/temp/mergedir/dev
2020-07-17 13:49:57,271 - DEBUG - rootfs - Running command: sudo cp /etc/resolv.conf /home/rjudge/.tern/temp/mergedir/etc/resolv.conf
2020-07-17 13:49:57,296 - DEBUG - rootfs - Running command: sudo unshare -pf --mount-proc=/home/rjudge/.tern/temp/mergedir/proc chroot /home/rjudge/.tern/temp/mergedir /bin/sh -c pkgs=`dpkg --get-selections | cut -f1 -d':' | awk '{print $1}'` && for p in $pkgs; do dpkg -l $p | awk 'NR>5 {print $3}'; done
2020-07-17 13:49:57,747 - DEBUG - rootfs - Running command: sudo unshare -pf --mount-proc=/home/rjudge/.tern/temp/mergedir/proc chroot /home/rjudge/.tern/temp/mergedir /bin/sh -c pkgs=`dpkg --get-selections | cut -f1 -d':' | awk '{print $1}'` && for p in $pkgs; do /bin/cat /usr/share/doc/$p/copyright; echo LICF; done
2020-07-17 13:49:57,825 - DEBUG - rootfs - Running command: sudo unshare -pf --mount-proc=/home/rjudge/.tern/temp/mergedir/proc chroot /home/rjudge/.tern/temp/mergedir /bin/sh -c dpkg --get-selections | cut -f1 -d':' | awk '{print $1}'
2020-07-17 13:49:57,969 - WARNING - common - Inconsistent lengths for key: proj_urls
2020-07-17 13:49:57,973 - DEBUG - rootfs - Running command: sudo umount /home/rjudge/.tern/temp/mergedir/proc
2020-07-17 13:49:58,005 - DEBUG - rootfs - Running command: sudo umount /home/rjudge/.tern/temp/mergedir/sys
2020-07-17 13:49:58,045 - DEBUG - rootfs - Running command: sudo umount /home/rjudge/.tern/temp/mergedir/dev
2020-07-17 13:49:58,078 - DEBUG - rootfs - Running command: sudo umount -rl /home/rjudge/.tern/temp/mergedir
2020-07-17 13:49:58,130 - DEBUG - common - Reading files in filesystem...
1
2020-07-17 13:50:16,013 - WARNING - command_lib - No listing method for 'echo'. Additional analysis may be required.

2020-07-17 13:50:16,013 - WARNING - command_lib - No listing method for 'wget'. Additional analysis may be required.

2020-07-17 13:50:16,013 - WARNING - command_lib - No listing method for 'apt-key'. Additional analysis may be required.

1
2020-07-17 13:50:16,013 - WARNING - command_lib - No listing method for 'rm'. Additional analysis may be required.

Killed

Expected behavior
Tern should generate a report for the Dockerfile.

Environment you are running Tern on
Enter all that apply

• Tern @ tip of master.

[nishakm]

The issue is in filter_install_commands(shell_command_line). For some reason the above shell command messes with stdout.

>>> from tern.analyze.common import filter_install_commands
>>> commands, report = filter_install_commands("apt-get update && apt-get -y install wget gnupg2 tar findutils a
ttr util-linux python3 python3-pip python3-setuptools git && pip3 install --upgrade pip && pip3 install tern &&
echo 'deb http://download.opensuse.org/repositories/devel:/kubic:/libcontainers:/stable/Debian_10/ /' > /etc/apt
/sources.list.d/devel:kubic:libcontainers:stable.list && wget -nv https://download.opensuse.org/repositories/dev
el:kubic:libcontainers:stable/Debian_10/Release.key -O Release.key && apt-key add - < Release.key && apt-get upd
ate -qq && apt-get -qq -y install buildah fuse-overlayfs && rm -rf /var/cache /var/log/dnf* /var/log/yum.*")
1
No listing method for 'echo'. Additional analysis may be required.

No listing method for 'wget'. Additional analysis may be required.

No listing method for 'apt-key'. Additional analysis may be required.

1
No listing method for 'rm'. Additional analysis may be required.

^CTraceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/home/nisha/terndev/tern/tern/analyze/common.py", line 500, in filter_install_commands
    return consolidate_commands(filter2), report
  File "/home/nisha/terndev/tern/tern/analyze/common.py", line 475, in consolidate_commands
    if not first.merge(second):
  File "/home/nisha/terndev/tern/tern/classes/command.py", line 132, in merge
    self.__words.append(word)
KeyboardInterrupt

@ForgetMe17 Do you want to take a look?

[nishakm]

From what I can tell, get_shell_commands parser that @ForgetMe17 implemented is not the issue - it splits each of the commands correctly. Something happens while filtering out the "install" command.

[ForgetMe17]

There are some problem with consolidate_commands():
Here are the logic:

while command_list: # This while loop try to match each command(the first one in the list) with its following commands.
        first = command_list.pop(0)
        for _ in range(0, len(command_list)):
            second = command_list.pop(0)
            if first.is_remove() and second.is_install():
                # if remove then install, ignore the remove command
                new_list.append(second)
            else:
                if not first.merge(second):
                    command_list.append(first)
                new_list.append(first)

We can assume two cases to point out the problems here:
Case 1

A = apt-get install
B = pip3 install
C = pip3 install
D = apt-get install
command_list = [A B C D]
for the while loop where first = A, second = B, C
first.is_remove() and second.is_install() will be False and first.merge(second) will be False
So A will be added to command_list for two times. This is deadly since in the following while loop, there must be a case where first = A, second = A.

while we are calling A.merge(A),  in function Command.merge():
for word in other.words:
                        self.__words.append(word)
While we are traversing the words list, we are adding elements to its tail, this will cause a dead loop, so there will be a memory out of idex error which will kill the program.

Case 2

A = apt-get install
Bn = apt-get remove
command_list = [A B1 B2 B3 B4 B5 B6]
in the above code, the first loop of while:
first = A
second = B1
since first.is_remove() and second.is_install() will be FALSE, so the new_list.append(first).
A will be added to the output_list.
for second = B2, B3, B4...., first.is_remove() and second.is_install() will always be FALSE, so A will be added to the output_list for many times which is dulipcate.

Case 1 is the cause of this issue. Case 2 only has affects on our output, not causing this issue.

In general, this bug is caused by dead loop when we call A.merge(A), A is a Command object.
Furthemore, while we are dealing with different types of intall commands like apt-get pip3, we will get FALSE where (apt-get_command).merge(pip3_command), and then appending apt-get_command to the command_list, if this action repeats more than twice(like we have two pip3_command after a apt-get_command), there will be two same Command objects in the command_list. In the following progress, There must be a time when we call A.merge(A).

[ForgetMe17]

I have fixed this by adjusting the logic in the consolidate_commands to fit the situations where there are more than one type of install commands.

[ForgetMe17]

@rnjudge Thanks for finding out this bug!

[rnjudge]

@rnjudge Thanks for finding out this bug!

Thanks for taking a look and finding the fix so quickly!