Completed scan leaves no results file

[ghost]

Hi!

Just installed scantron with one master and one agent.
In the master UI I have added a scan command, a scan, a site, and I've added a schedules scan.
The agent finds it:
2020-02-26 09:07:59,492 [MainThread ] [INFO] No scan jobs found...checking back in 60 seconds.
2020-02-26 09:08:59,525 [MainThread ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans
2020-02-26 09:08:59,554 [MainThread ] [INFO] Executing scan job ID: 2
2020-02-26 09:08:59,606 [Thread-1 ] [INFO] Starting scan for site 'svea' with command: nmap -Pn -A -iL ./target_files/.targets -oG ./scan_results/pending/.gnmap -oN ./scan_results/pending/.nmap -oX ./scan_results/pending/.xml --script-args http.useragent='user-agent'
2020-02-26 09:09:04,558 [MainThread ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/2
2020-02-26 09:09:04,660 [MainThread ] [INFO] Successfully updated scan information for scan ID 2 with data {'scan_status': 'started'}
2020-02-26 09:09:04,660 [MainThread ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans
2020-02-26 09:09:04,733 [MainThread ] [INFO] No scan jobs found...checking back in 60 seconds.
2020-02-26 09:09:13,280 [Thread-1 ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/2
2020-02-26 09:09:13,386 [Thread-1 ] [INFO] Successfully updated scan information for scan ID 2 with data {'completed_time': '2020-02-26 09:09:13', 'scan_status': 'completed', 'result_file_base_name': ''}
2020-02-26 09:10:04,757 [MainThread ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans

As you can see result_file_base_name is empty, so perhaps that is why no results files are created. The actual scan itself should surely prompt results. Running it as a standalone command does. I set up both master and agent using ansible playbooks with zero errors. The GUI and everything else seems to work just fine.

Any idea what could be wrong?

[derpadoo]

Hi @jboger - thanks for posting an issue. What version of Scantron are you using? You can find it here: master/django_scantron/__init__.py

[derpadoo]

I should probably dump the entire scan_job to logs...for now.

1. Stop the agent

2. Add this line after https://github.com/rackerlabs/scantron/blob/master/agent/agent.py#L94

modules.logger.ROOT_LOGGER.info(f"scan_job: {scan_job}")

so it looks like this:

modules.logger.ROOT_LOGGER.info(f"Executing scan job ID: {scan_job['id']}")
modules.logger.ROOT_LOGGER.info(f"scan_job: {scan_job}")

# Create new dictionary that will contain scan_job and config_data information.

3. Browse to:

https://<SCANTRON_MASTER>/scantron-admin/django_scantron/scheduledscan/2/change/

and mark the "Scan status" to pending

4. Start up the agent again and let me know what the output is:

cd /root/agent
source .venv/bin/activate
python agent.py

[ghost]

Hi,

I have implemented the changes to the logging, that you suggested. The result is as follows:
2020-02-27 01:40:59,001 [MainThread ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans
2020-02-27 01:40:59,028 [MainThread ] [INFO] Executing scan job ID: 3
2020-02-27 01:40:59,028 [MainThread ] [INFO] scan_job: {'id': 3, 'site_name': 'svea', 'scan_agent': 'agent1', 'start_datetime': '2020-02-27T01:40:25-06:00', 'scan_binary': 'nmap', 'scan_command': '-Pn -A', 'targets': '', 'excluded_targets': '', 'scan_status': 'pending', 'completed_time': None, 'result_file_base_name': ''}
2020-02-27 01:40:59,092 [Thread-1 ] [INFO] Previous scan file found './scan_results/pending/.gnmap'. Resuming the scan.
2020-02-27 01:40:59,094 [Thread-1 ] [INFO] Starting scan for site 'svea' with command: nmap --resume ./scan_results/pending/.gnmap
Could not mmap() ./scan_results/pending/.gnmap read/write
QUITTING!
2020-02-27 01:41:04,035 [MainThread ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/3
2020-02-27 01:41:04,201 [MainThread ] [INFO] Successfully updated scan information for scan ID 3 with data {'scan_status': 'started'}

Mind you, the resumed scan is one of a much larger network that I scanned yesterday, to try and see if it was an issue with scanning a single IP (it was not). That is not the reason for my current issue. It appears to me that the .dotfiles are created in pending, but that once the scan is complete, these are never converted to the file formats that are linked from the main scanatron page (IE '.nmap' and '.xml). Both of those links result in a 404.

[ghost]

It appears the dotfiles are now appearing. I get '.nmap' '.gnmap' and '.xml' in ~/agent/scan_results/complete. However, the links from the GUI start page do not work.

[ghost]

Actually, just noticed this line:
gnmap_file = os.path.join(pending_files_dir, f"{result_file_base_name}.gnmap")
Since the file is named '.gnmap', it would appear that result_file_base_name has no value. Will set a static value and see if that solves it (will use {timestamp} for testing as that is already a part of the name, but should always return -something-.

My version is: version = "1.21"

[derpadoo]

Thanks for the debug line...looks like result_file_base_name field is empty, which is why the scan result files are just .nmap, .xml, etc. It should be {result_file_base_name}.nmap, but it has no value like you noticed.

The result_file_base_name string is built here:

https://github.com/rackerlabs/scantron/blob/master/master/scan_scheduler.py#L115

result_file_base_name = f"{clean_text(site_name)}__{clean_text(scan_agent)}__{timestamp}"

It should at least populate with the timestamp variable. I'll also need to dig into why result_file_base_name is allowed to be empty in the first place:

https://github.com/rackerlabs/scantron/blob/master/master/django_scantron/models.py#L261

Let's try this:

1. Delete any files in the /home/scantron/master/scan_results/pending directory

2. Ensure you have the agent1 API key (and not the admin one) in the agent's /root/agent/agent_config.json file.

3. As root on Master, open up crontab (crontab -e) and place a # in front of /home/scantron/master/scan_scheduler.sh so it looks like:

#Ansible: Schedule any new scans every minute.
#* * * * * /home/scantron/master/scan_scheduler.sh

4. Start the agent from the command line on the agent box:

cd /root/agent
source .venv/bin/activate
python agent.py

5. Review the Workflow of how to setup a scan, starting at "2. Create scan command" and make sure everything looks good: https://github.com/rackerlabs/scantron#workflow

6. Once you are done adding a scan command, site, and scan, run the scan scheduler Python script on Master:

cd /home/scantron/master

source /home/scantron/master/.venv/bin/activate
python scan_scheduler.py

7. Copy/pasta the output so I can see what it shows. The results are also saved here: /home/scantron/master/scan_scheduler.log

That should successfully schedule the scan which will be picked up by the agent. Let me know of any issues or errors that come up. If everything looks good, as root on Master, open up crontab (crontab -e) and remove the # in front of /home/scantron/master/scan_scheduler.sh so it looks like:

#Ansible: Schedule any new scans every minute.
* * * * * /home/scantron/master/scan_scheduler.sh

[ghost]

Hi,

I followed your steps, and this is the output of the agent.log:
2020-02-28 10:36:51,143 [MainThread ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/9 2020-02-28 10:36:51,222 [MainThread ] [INFO] Successfully updated scan information for scan ID 9 with data {'scan_status': 'started'} 2020-02-28 10:36:51,223 [MainThread ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans 2020-02-28 10:36:51,290 [MainThread ] [INFO] No scan jobs found...checking back in 60 seconds.
and after the scan output:

Running parser..... 2020-02-28 10:39:08,708 [Thread-1 ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/9 2020-02-28 10:39:08,785 [Thread-1 ] [INFO] Successfully updated scan information for scan ID 9 with data {'completed_time': '2020-02-28 10:39:08', 'scan_status': 'completed', 'result_file_base_name': ''}

scan_scheduler.log shows nothing in particular. Just like before I only get a.gnmap file in "complete".

[derpadoo]

There may be some weird cruft with all the data. Can you delete all scan commands, sites, scans, and scheduled scans through the Django admin? Then repopulate and try one more time? If that still doesn't work, maybe a server rebuild for both agent/master may be in order if you have the time.

[JonLMyers]

I started having the exact same issue so I followed the steps @derpadoo suggested. Unfortunatly after rebuilding the server, agent, and VMs they lived on I am still having this issue.

[derpadoo]

Thanks for the additional data point @JonLMyers . I just pulled down v1.22 (master branch) and was able to deploy and scan without issues on Ubuntu 18.04. Before answer the questions below, go ahead and reboot both the agent and Master boxes.

1. Is the agent running as root?
2. Are the Master and agent on different boxes / VMs?
3. Are the SSH tunnels up and running? https://github.com/rackerlabs/scantron#agent-troubleshooting
4. From the agent, can you read / write to the NFS share hosted on Master?

cd /root/agent
ls -la target_files
echo test > scan_results/pending/test.txt
cat scan_results/pending/test.txt

then on Master, checking

cat /home/scantron/master/scan_results/pending/test.txt

[derpadoo]

Just pushed v1.23 to add some protection mechanisms to prevent scheduling a scan if values are empty. Not a root cause solution for this, just an FYI.

[ghost]

Hi derpadoo,

1. Yes, the agent is running as root.
2. Yes, the master and agent are on different VMs.
3. Yes, the SSH tunnels are up and running.
4. Yes, the NFS directory (scan_results and target_files) are readible and writable from both servers.

(server rebuilt and rebooted)

[derpadoo]

@jboger Check your twitter DMs...I sent you a message.

[ghost]

@derpadoo: Hey, I don’t have any new twitter DMs. Did you send them to the right person (@johanboger)?

[derpadoo]

Just sent another message...it might be in the Message requests if you're not following me.

[nachobytes]

Hi Derpadoo,

I seem to be having this issue as well. I get the error below in agent.log. Any advice?

I took the following steps as described.

• __version__ = "1.27"
• The agent is running as root.
• The master and agent are on different VMs.
• The SSH tunnels are up and running.
• The NFS directory (scan_results and target_files) are readible and writable from both servers.
• All servers are rebuilt and rebooted(Ubuntu 18.04.4 Ansible Server, Master, and Agent1 )

Ansible Server = 10.0.50.92
Master = 10.0.50.90
Agent1 = 10.0.50.91

2020-05-02 21:03:02,525 [MainThread  ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans
2020-05-02 21:03:02,571 [MainThread  ] [INFO] scan_job: {'id': 1, 'site_name': 'Ansible', 'scan_agent': 'agent1', 'start_datetime': '2020-05-02T16:02:04-05:00', 'scan_binary': 'nmap', 'scan_command': '--top-ports 100', 'targets': '10.0.50.92', 'excluded_targets': '', 'scan_status': 'pending', 'completed_time': None, 'result_file_base_name': ''}
2020-05-02 21:03:02,632 [Thread-1    ] [INFO] Starting scan for site 'Ansible' with command: nmap --top-ports 100 -iL ./target_files/.targets -oG ./scan_results/pending/.gnmap -oN ./scan_results/pending/.nmap -oX ./scan_results/pending/.xml --script-args http.useragent='user-agent'
2020-05-02 21:03:04,554 [Thread-1    ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/1
2020-05-02 21:03:04,648 [Thread-1    ] [ERROR] Could not access https://127.0.0.1:4430/api/scheduled_scans/1 or failed to update scan ID 1. HTTP status code: 400
2020-05-02 21:03:04,648 [Thread-1    ] [ERROR] Error with scan ID 1.  Exception: '"result_file_base_name"'
Traceback (most recent call last):
  File "/root/agent/modules/scanner.py", line 176, in scan_site
    api.update_scan_information(config_data, scan_job, update_info)
  File "/root/agent/modules/api.py", line 89, in update_scan_information
    logger.ROOT_LOGGER.error(f"Response content: {response.content}".format())
KeyError: '"result_file_base_name"'
2020-05-02 21:03:04,649 [Thread-1    ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/1
2020-05-02 21:03:04,775 [Thread-1    ] [INFO] Successfully updated scan information for scan ID 1 with data {'scan_status': 'error'}
2020-05-02 21:03:07,577 [MainThread  ] [INFO] update_scan_information URL: https://127.0.0.1:4430/api/scheduled_scans/1
2020-05-02 21:03:07,670 [MainThread  ] [INFO] Successfully updated scan information for scan ID 1 with data {'scan_status': 'started'}
2020-05-02 21:03:07,670 [MainThread  ] [INFO] check_for_scans URL: https://127.0.0.1:4430/api/scheduled_scans
2020-05-02 21:03:07,744 [MainThread  ] [INFO] No scan jobs found...checking back in 60 seconds.

[derpadoo]

Thanks for submitting that information @nachobytes - it will probably be a few days before I can take a good look at it. If possible, could you and @jboger let me know where the boxes are being hosted...like AWS, GCP, Digital Ocean, simple VMs, bare metal, etc.

[derpadoo]

@nachobytes Can you let me know what the scan_scheduler.log log file on master showed when it scheduled the scan? I want to ensure it is populating "result_file_base_name" on the master side correctly.

/home/scantron/master/scan_scheduler.log

Should look something like:

2020-05-11 11:42:02,763 [INFO] Adding to scheduled scans: {'site_name': 'Test', 'start_time': datetime.time(11, 42), 'scan_agent': 'agent1', 'start_datetime': datetime.datetime(2020, 5, 11, 11, 42, tzinfo=<DstTzInfo 'America/Chicago' CDT-1 day, 19:00:00 DST>), 'scan_binary': 'nmap', 'scan_command': '--top-ports 20 -sV -Pn -n', 'targets': '10.1.1.2', 'excluded_targets': '', 'result_file_base_name': 'test__agent1__20200511_1142', 'scan_status': 'pending'}

[derpadoo]

@jboger / @nachobytes - There have been quite a few updates since this ticket was opened. Try installing the latest and let me know if you still have this issue. Going to close this ticket for now.