Scanning openwrt image, S115 won't finish #487

at40493 · 2023-02-22T08:56:58Z

Describe the bug

I've successfully run the scan twice with non-openwrt image.
But when trying to run a scan with the openwrt image,
I'm stuck on the S115 for over 9 hours with alternating screens showing "cve-search - testing" and "cve-search - ok".

To Reproduce
Steps to reproduce the behavior:

EMBA installation : default mode
Use the firmware available here: https://downloads.openwrt.org/releases/19.07.9/targets/ipq40xx/generic/openwrt-19.07.9-ipq40xx-generic-linksys_ea8300-squashfs-sysupgrade.bin
Start EMBA with the following parameters: sudo ./emba -l ./log -f ~/Downloads/openwrt-19.07.9-ipq40xx-generic-linksys_ea8300-squashfs-sysupgrade.bin -p ./scan-profiles/default-scan.emba
EMBA scan never finish

Expected behavior
The scan to finish.

Screenshots

Desktop (please complete the following information):

OS : Ubuntu:jammy (22.04 LTS)
RAM: DDR4-2400 32GB
Processors: i7-7820X (8 cores)
Hard disk : 1.2TB PCIe SSD ( 2500/1200 MB/s)
EMBA version: current master branch

Additional context
Here is emba.log
It seems that both S116 and S20 are waiting for S115 to be completed.

Here is console log for debugging (console_log.txt )

m-1-k-3 · 2023-02-22T09:38:42Z

hmmm ...

[*] Wed Feb 22 10:31:58 CET 2023 - S20_shell_check starting <==
[*] Wed Feb 22 10:35:14 CET 2023 - S115_usermode_emulator finished <==
[*] Wed Feb 22 10:35:15 CET 2023 - S21_python_check starting
[*] Wed Feb 22 10:35:18 CET 2023 - S21_python_check finished
[*] Wed Feb 22 10:35:19 CET 2023 - S22_php_check starting
[*] Wed Feb 22 10:35:24 CET 2023 - S22_php_check finished
[*] Wed Feb 22 10:35:25 CET 2023 - S24_kernel_bin_identifier starting
[*] Wed Feb 22 10:35:58 CET 2023 - S20_shell_check finished <==
[*] Wed Feb 22 10:36:00 CET 2023 - S25_kernel_check starting

Could you start your test with the additional -S parameter and check for a emba_error.log file in your log directory.

at40493 · 2023-02-22T11:10:17Z

Start EMBA with the following parameters: sudo ./emba -l ./log -f ~/Downloads/openwrt-19.07.9-ipq40xx-generic-linksys_ea8300-squashfs-sysupgrade.bin -S -p ./scan-profiles/default-scan.emba

Several S36_lighttpd errors detected in emba_error.log

Error detected - status code 1
Command:  echo -e "Command:  $ORANGE$BASH_COMMAND$NC"
Location:  ./modules/S36_lighttpd.sh, line 111
Stack Trace:
    [1] lighttpd_binary_analysis(): ./modules/S36_lighttpd.sh, line 111 -> lighttpd_binary_analysis ------------------------------------------------------------------------------------------------ $'Error detected - status code \E[0;33m1\E[0m' $'Command:  \E[0;33mecho -e "Command:  $ORANGE$BASH_COMMAND$NC"\E[0m' $'Location:  \E[0;33m./modules/S36_...[2] S36_lighttpd(): ./modules/S36_lighttpd.sh, line 38 -> S36_lighttpd
    [3] run_modules(): ./emba, line 180 -> run_modules S 1 1
    [4] main(): ./emba, line 979 -> main
    [5] main(): ./emba, line 1077 -> main

Important: Consider filling out a bug report at https://github.com/e-m-b-a/emba/issues

m-1-k-3 · 2023-02-22T11:22:59Z

The s36 issues are addressed in #485. In the mean time you could put the s36 module to the blacklist:

cat config/module_blacklist.txt
S36_lighttpd

at40493 · 2023-02-22T15:12:23Z

I put the s36 module to the blacklist.
There is no emba_error.log file in the log directory.

But the EMBA still stuck for more than 3 hours after S99_grepit finished.
The S115 seems not finish yet. (stuck in wait_for_pid?!)

(s115_usermode_emulator.txt)

m-1-k-3 · 2023-02-22T15:17:15Z

Very interesting. I will do another test later today.

m-1-k-3 · 2023-02-22T18:29:28Z

So, currently I can't reproduce it. Nevertheless, we have the s20 module that does not finish and the s115 module. Could you please do some further tests. First of all, please check out the branch of PR #485. Just to ensure we have the same code base.

The next thing is to ensure we are really dealing with these two modules. So, please start EMBA to only test s20 and s115:

└─$ sudo ./emba -f ~/Downloads/openwrt-19.07.9-ipq40xx-generic-linksys_ea8300-squashfs-sysupgrade.bin -S -l ~/firmware-stuff/emba_logs_openwrt -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j

Always have a look at the error log.

m-1-k-3 · 2023-02-23T07:12:53Z

Another test run also finished as expected.

[!] Test ended on Wed Feb 22 23:40:36 CET 2023 and took about 01:15:04

at40493 · 2023-02-23T10:57:12Z

I have checked out the branch of PR #485 and reinstalled the emba.

command:

sudo ./emba -l ./log -f ~/Downloads/openwrt-19.07.9-ipq40xx-generic-linksys_ea8300-squashfs-sysupgrade.bin -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j

The emba.log:

[!] Testing phase started on Thu Feb 23 15:32:45 CST 2023
    Firmware path: /logs/firmware
[*] Thu Feb 23 15:32:45 CST 2023 - S20_shell_check starting
[*] Thu Feb 23 15:32:45 CST 2023 - S115_usermode_emulator starting
[-] Thu Feb 23 15:32:47 CST 2023 - S115_usermode_emulator not in module array - this will result in unexpected behavior
[*] Thu Feb 23 15:32:52 CST 2023 - S20_shell_check finished

There is no emba_error.log file in the log directory.
Only see some qemu segemtation fault message in console output.

[*] Initial strace run with jchroot on the command ./usr/lib/libip6tc.so.2.0.0 to identify missing areas

[*] Emulating binary name: libip6tc.so.2.0.0 in strace mode to identify missing areas (with jchroot)
[*] Emulator used: qemu-arm-static
[*] Chroot environment used: jchroot
[*] Using root directory: /logs/s115_usermode_emulator/firmware/patool_extraction/sysupgrade-linksys_ea8300/root_binwalk_extracted/_root.extracted/squashfs-root (1/1)
[*] Using CPU config: 

--- SIGSEGV {si_signo=SIGSEGV, si_code=1, si_addr=NULL} ---
qemu: uncaught target signal 11 (Segmentation fault) - core dumped

[*] Identification of missing filesytem areas.
[*] No missing areas found.

The S115 still not enter the Cleanup phase.

After aborting the scan, I tried to scan again without clean the log directory.
Then it can complete the scan!!

[!] Testing phase started on Thu Feb 23 18:45:25 CST 2023
    Firmware path: /logs/firmware
[*] Thu Feb 23 18:45:25 CST 2023 - S20_shell_check starting
[*] Thu Feb 23 18:45:25 CST 2023 - S115_usermode_emulator starting
[-] Thu Feb 23 18:45:28 CST 2023 - S115_usermode_emulator not in module array - this will result in unexpected behavior
[*] Thu Feb 23 18:45:32 CST 2023 - S20_shell_check finished
[*] Thu Feb 23 18:46:51 CST 2023 - S115_usermode_emulator finished
[!] Testing phase ended on Thu Feb 23 18:46:51 CST 2023 and took about 00:02:26 

[!] Reporting phase started on Thu Feb 23 18:46:51 CST 2023

[!] Test ended on Thu Feb 23 18:46:53 CST 2023 and took about 00:02:28

m-1-k-3 · 2023-02-23T11:50:10Z

ok, looks better.

The s20 finished now in a correct way.
The fault on s115 is something normal as it tries to execute unknown binaries and libraries
Finally it finished ... hooray

Could you delete the log dir in the EMBA dir (./log) and use something different. Let's say ~/emba_logs and try it again

btw the PR is landed and you can just use the master of the emba repo

at40493 · 2023-02-24T07:39:34Z

I changed the log directory from ./log to ~/emba_logs, but nothing changed.
I still have to abort once and rescan again to finished =(.

S115 seems to keep waiting for some pid to complete.

[[ "$THREADED" -eq 1 ]] && wait_for_pid "${WAIT_PIDS_S115[@]}"

s115_cleanup "$EMULATOR"

Even the scan finished, I got the error as below:

[!] Testing phase ended on Fri Feb 24 14:56:25 CST 2023 and took about 00:02:26 

[!] Reporting phase started on Fri Feb 24 14:56:25 CST 2023

./helpers/helpers_emba_status_bar.sh: line 311: LINES: unbound variable
ERROR: 1
[-] EMBA failed in docker mode!
[*] Final cleanup started.
[*] Stopping kernel downloader thread with PID 2600663
[*] Stopping EMBA process with PID 2600776

m-1-k-3 · 2023-02-24T08:31:40Z

argl ... What is your scan doing in the status_bar area? Have you used -B? Could you try the following change in helpers/helpers_emba_helpers.sh: Change from

if [[ -f "$LOG_DIR"/"$MAIN_LOG_FILE" ]] && [[ $(grep -i -c S115_ "$LOG_DIR"/"$MAIN_LOG_FILE") -eq 1 && -n "$QRUNTIME" ]]; then

to

if [[ -f "$LOG_DIR"/"$MAIN_LOG_FILE" ]] && [[ $(grep -i -c S115_ "$LOG_DIR"/"$MAIN_LOG_FILE") -gt 0 && -n "$QRUNTIME" ]]; then

Just to ensure EMBA will kill older qemu processes.

at40493 · 2023-02-24T10:22:21Z

No, I did't use -B.
Please ignore the status_bar error.
It's fine after reboot the PC.

It looks better after change the helpers_emba_helpers.sh.
The scan success rate is higher.
But there is still a chance of getting stuck on the S115.

m-1-k-3 · 2023-02-24T10:26:24Z

ok, then we know the root of this issue is in the stopping of the qemu processes.

m-1-k-3 · 2023-02-24T10:57:08Z

Next, please uncomment the debugging message (~ line 41):

      print_output "[*] wait pid protection - running pid: $PID"

With this we should see which PID is blocking EMBA. Please post some details on the process

at40493 · 2023-02-24T13:41:04Z

test_stuck.log (PID:12054 & 23990):

.[*] wait pid protection - running pid: 12054
.[*] wait pid protection - running pid: 23990
.[*] wait pid protection - running pid: 12054
.[*] wait pid protection - running pid: 23990
.[*] wait pid protection - running pid: 12054
.[*] wait pid protection - running pid: 23990
.[*] wait pid protection - running pid: 12054
                      ....

test_non_stuck.log (PID: 12024):

.[*] wait pid protection - running pid: 12024
.[*] wait pid protection - running pid: 12024
...................[*] wait pid protection - running pid: 12024
...........................................................................................................................................................[*] wait pid protection - running pid: 12024
.[*] Fri Feb 24 21:30:00 CST 2023 - S115_usermode_emulator finished
[*] wait pid protection - running pid: 12024
.
[!] Testing phase ended on Fri Feb 24 21:30:00 CST 2023 and took about 00:02:30

m-1-k-3 · 2023-02-24T15:01:45Z

Cool we have the blocking boys. What are these babies? Please check them while EMBA is waiting for example with ps -Fwwp 12054 23990 <- adopth these PIDs to your next run

We should then see if these are running qemu processes.

at40493 · 2023-02-24T15:36:16Z

While EMBA is waiting, I can't get any pid info directly from my PC.

~$ ps -Fwwp 11979 23145
UID          PID    PPID  C    SZ   RSS PSR STIME TTY      STAT   TIME CMD
rdd3@Rdd2-EMBA-Server:~$ cat ~/0224_log/emba.log

So I add ps command in helpers/helpers_emba_helpers.sh:

 
    while [[ -e /proc/"$PID" ]]; do
       print_output "[*] wait pid protection - running pid: $PID"
+      ps -Fwwp $PID || true
       print_dot

Then I got these:

.[*] wait pid protection - running pid: 11979
[*] wait pid protection - running pid: 23145
UID          PID    PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
root       11979       1 18  5275 19252   0 23:16 pts/2    00:00:57 /bin/bash -p ./emba -l /logs -f /firmware -i -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j
.UID          PID    PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
root       23145   11979  0  5275 18872  11 23:16 pts/2    00:00:00 /bin/bash -p ./emba -l /logs -f /firmware -i -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j
.[*] wait pid protection - running pid: 11979
[*] wait pid protection - running pid: 23145
UID          PID    PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
root       11979       1 18  5275 19252   0 23:16 pts/2    00:00:58 /bin/bash -p ./emba -l /logs -f /firmware -i -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j
.UID          PID    PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
root       23145   11979  0  5275 18872  11 23:16 pts/2    00:00:00 /bin/bash -p ./emba -l /logs -f /firmware -i -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j
.[*] wait pid protection - running pid: 11979
[*] wait pid protection - running pid: 23145
UID          PID    PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
root       11979       1 18  5275 19252   0 23:16 pts/2    00:00:58 /bin/bash -p ./emba -l /logs -f /firmware -i -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j
.UID          PID    PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
root       23145   11979  0  5275 18872  11 23:16 pts/2    00:00:00 /bin/bash -p ./emba -l /logs -f /firmware -i -S -p ./scan-profiles/default-scan.emba -m s20 -m s115 -m f199 -y -j

The TIME for PID 23145 always seems to be 00:00:00.

m-1-k-3 · 2023-02-24T15:37:43Z

damn ... I hoped to see some emulated processes.

m-1-k-3 · 2023-02-24T16:27:24Z

I have extended the PID logging for further debugging here: https://github.com/m-1-k-3/emba/tree/auto-commit-test

Please clone it:

git clone --branch auto-commit-test https://github.com/m-1-k-3/emba.git

You should be able to just link the external directory from your current installation into the new branch and it should work.

└─$ sudo ./emba -f ~/Downloads/openwrt-19.07.9-ipq40xx-generic-linksys_ea8300-squashfs-sysupgrade.bin -S -l ~/firmware-stuff/emba_logs_openwrt -p ./scan-profiles/default-scan.emba -m s115 -m f199 -y -j

during the test you get an additional log file in your log directory: pid_notes.log
This log includes further details on which function, including PID, was started. Hopefully we find the the hanging PID in here

at40493 · 2023-02-24T17:04:13Z

PID: 12036 , 20320

.[*] wait pid protection - running pid: 12036
.[*] wait pid protection - running pid: 20320

grep PID from pid_notes.log

$ grep 12036 pid_notes.log 
main module - S115_usermode_emulator - 12036
$ grep 20320 pid_notes.log 
main-emulate_binary - ./sbin/procd - 20320

m-1-k-3 · 2023-02-24T17:09:31Z

echo "procd" >> config/emulation_blacklist.cfg

And try again.

at40493 · 2023-02-24T17:37:24Z

It works !!!!
I tried eight times without getting stuck.

m-1-k-3 · 2023-02-24T17:40:28Z

Very great ... was a hard ride but now we got it :) Thank you again for reporting and improving EMBA. I will leave the improved PID logging in EMBA for future issues like this.

at40493 · 2023-02-24T17:50:37Z

I will do more different tests.
If there no problem, I will close this issue.
Thanks for your great help :)

m-1-k-3 added the bug Something isn't working label Feb 22, 2023

at40493 closed this as completed Feb 22, 2023

at40493 reopened this Feb 22, 2023

m-1-k-3 self-assigned this Feb 22, 2023

m-1-k-3 mentioned this issue Feb 22, 2023

disk space monitor, rpm package analysis #485

Merged

m-1-k-3 added the Core modules (Sxx) The core scanning modules (Sxx modules) label Feb 22, 2023

m-1-k-3 added the can't reproduce Further details needed as we are not able to reproduce this issue label Feb 23, 2023

m-1-k-3 mentioned this issue Feb 25, 2023

Refactor, PID log, Github actions, APKHunt #495

Merged

m-1-k-3 closed this as completed in #495 Feb 25, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Scanning openwrt image, S115 won't finish #487

Scanning openwrt image, S115 won't finish #487

at40493 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

at40493 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

at40493 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

m-1-k-3 commented Feb 23, 2023 •

edited

Loading

at40493 commented Feb 23, 2023

m-1-k-3 commented Feb 23, 2023 •

edited

Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023 •

edited

Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023 •

edited

Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023 •

edited

Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

at40493 commented Feb 24, 2023

Scanning openwrt image, S115 won't finish #487

Scanning openwrt image, S115 won't finish #487

Comments

at40493 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

at40493 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

at40493 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

m-1-k-3 commented Feb 22, 2023

m-1-k-3 commented Feb 23, 2023 • edited Loading

at40493 commented Feb 23, 2023

m-1-k-3 commented Feb 23, 2023 • edited Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023 • edited Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023 • edited Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023 • edited Loading

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 24, 2023

at40493 commented Feb 24, 2023

m-1-k-3 commented Feb 23, 2023 •

edited

Loading

m-1-k-3 commented Feb 23, 2023 •

edited

Loading

m-1-k-3 commented Feb 24, 2023 •

edited

Loading

m-1-k-3 commented Feb 24, 2023 •

edited

Loading

m-1-k-3 commented Feb 24, 2023 •

edited

Loading