Error on emulating HTTP/HTTPS links on local R81 T...

Anna_Habert · ‎2021-08-10

Hi,

running R81.00 T36 on virtual Lab, fresh install, no fancy stuff. 1x SMS, 2x GWs as ClusterXL, 1x local MAIL/SMTP Threat emulation. Everything is updated/latest like IPS/image downloads/TE engine version

When I send an e-mail with a link inside, for example: https://secure.eicar.org/eicar_com.zip the SMTP Threat Emulation skips the mail with the error "error during preparion phase." Sending the malicous file "directly" the emulation works as designed and the mail gets blocked due to malicous attachement.

I reinstalled the whole Lab with R81.00 no Update and R81.00 T23, same thing. With R80.40 T118 it works. Installation process is
always the same.

Things I did:
- different Emulating OS (XP,7,10)
- with/without HTTPS inspection
- links to malicious and non-malicous files
- links to http and https
- checking connection with ping/wget/curl/dig/..

From the logs (see below) it does not look like a configuration misbehavoir (filesize error). I cannot remember if i have ever seen it working on R81 since i always send the files directly.

I could not find any SK or googling info. So, is anyone out there successfully running R81.00 with local emulation? Any ideas? Something that I miss?

Thanks in advance for your input.

Anna

mail-header (nothing special):

To: xx@yy.zz
From: zz@yy.xx
Subject: TEST aa
Message-ID: <48a9beb4-2530-9b2f-b0eb-94adf6d63351@yy.zz>
Date: Tue, 10 Aug 2021 09:41:36 +0200
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101
 Thunderbird/78.12.0
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit
Content-Language: en-US

Test

https://secure.eicar.org/eicar_com.zip

ted.elg

(
        :connection (
                :src_ip (10.4.30.4)
                :src_port (0)
                :dst_ip (10.4.20.4)
                :dst_port (25)
                :protocol (6)
        )
        :meta_data (
                :file_orig_name (file0QEFlf.cp_lnk)
                :file_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/file0QEFlf.cp_lnk")
                :file_type (cp_lnk)
                :file_len (38)
                :protocol (smtp)
                :rule_id (1)
                :free_text ()
                :should_track ()
                :malware_rule_id ("{F38A5084-E80D-4130-9152-3733F0D216E3}")
                :scope_ip (10.4.20.4)
                :conn_id ()
                :session_id ()
                :instance_id ()
                :investigation_path (PATH_TE)
                :av_deep_scan ()
                :av_ifi ()
                :cdir (2)
        )
        :http_data (
                :url ()
        )
        :smtp_data (
                :to (xx@yy.zz)
                :from (zz@yy.xx)
                :subject (" TEST TEST aa")
                :body_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFile")
        )
)

[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} Handling new file "file0QEFlf.cp_lnk", Path: /opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/file0QEFlf.cp_lnk, rule_number = 1, rule name = MTA traffic to Gateway sb , investigation_path = PATH_TE
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} Local Partial response is enabled
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} Remote Partial response is enabled
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} Cloud Partial response is enabled
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'system state' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'system state' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {system state} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'url prepare handler' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'url prepare handler' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {url prepare handler} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'classifier' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'classifier' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {classifier} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'policy' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'policy' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {policy} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'file' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'file' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {file} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'prepare persistency' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'prepare persistency' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {prepare persistency} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'contract' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'contract' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {contract} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'cache inquirer' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} URL from mail
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} no images found in event profile..do nothing..
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'cache inquirer' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {cache inquirer} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} path in ep: /opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFilein response data: /opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFile
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} Reporting back action: unknown; Confidence: 0; InvestigationPath: PATH_TE
[8386 4103927744][6 Aug 15:55:30]  [TE_IS_TRACE (TD::All)] te_is::SocketApiServer::Transmit: transmit on conn_id: 2 data:
(
        :event_id ("{7348D08E-1103-0046-A24A-34B39CDC0E8C}")
        :action (unknown)
        :confidence (none)
        :done (0)
        :file_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/file0QEFlf.cp_lnk")
        :md5_string ()
        :investigation_path (PATH_TE)
        :additional_data ()
        :body_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFile")
)

[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'duplicate' (phase: 'processing')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'duplicate' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {duplicate} total duration time in milliseconds is: 1, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'url handler' (phase: 'processing')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} url: https://secure.eicar.org/eicar_com.zip, extension :zip, head rc = 200
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling download with file path = /opt/CPsuite-R81/fw1/tmp/te/te_tmp_files/fb0a3687a8a8aeb9
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'url handler' reporting back (status: full rewind and data reset)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {url handler} total duration time in milliseconds is: 383, current combined verdict is: Inert
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'system state' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'system state' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'url prepare handler' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'url prepare handler' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'classifier' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'classifier' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'policy' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} adding image 'e50e99f3-5963-4573-af9e-e3f4750b55e2' for emulation
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'policy' reporting back (status: done)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} calling investigator 'file' (phase: 'prepare')
[8386 4103927744][6 Aug 15:55:30]  [TE (TD::Surprise)] te::FileInvestigatorTE::CheckFileSize: {7348D08E-1103-0046-A24A-34B39CDC0E8C} file size (184) != file size from metadata (38): /opt/CPsuite-R81/fw1/tmp/te/te_tmp_files/{77554640-E7C2-3242-8017-C55F16D2FF89}
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} investigator 'file' reporting back (status: error)
[8386 4103927744][6 Aug 15:55:30]  [TE (TD::Surprise)] te::InvestigatorManager::ProcessReport: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {file} reported: error
[8386 4103927744][6 Aug 15:55:30]  [TE (TD::Surprise)] te::InvestigatorManager::ProcessReport: {7348D08E-1103-0046-A24A-34B39CDC0E8C} setting global verdict to error (prepare phase error)
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} verdict 'Error' set for image: 'e50e99f3-5963-4573-af9e-e3f4750b55e2' (WinXP,Office 2003/7,Adobe 9) by: 7, reason: error during prepare phase
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} {file} total duration time in milliseconds is: 1, current combined verdict is: Error
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} path in ep: /opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFilein response data: /opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFile
[8386 4103927744][6 Aug 15:55:30] [TE_TRACE]: {7348D08E-1103-0046-A24A-34B39CDC0E8C} Reporting back action: error; Confidence: 0; InvestigationPath: PATH_TE
[8386 4103927744][6 Aug 15:55:30]  [TE_IS_TRACE (TD::All)] te_is::SocketApiServer::Transmit: transmit on conn_id: 2 data:
(
        :event_id ("{7348D08E-1103-0046-A24A-34B39CDC0E8C}")
        :action (error)
        :confidence (none)
        :done (0)
        :file_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/file0QEFlf.cp_lnk")
        :md5_string ()
        :investigation_path (PATH_TE)
        :additional_data ("error reason: error during prepare phase")
        :body_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628258130-1819055117-1381680526_D/MailBodyFile")
)

_Val_ · ‎2021-08-10

It looks like there is an error with zip, the emulator cannot open it (the last log)

_Val_ · ‎2021-08-10

also, it would make sense to contact your SE who could assist you with the trial

Anna_Habert · ‎2021-08-10

Hi Val,

since i'm on private here, i cannot call SE or TAC. On business it is a litte bit more complicated ;). Anyway

The problem exist on any file. If I send this link for example: https://www.checkpoint.com/downloads/300TestReport.pdf the result is the same.

I tried to debug it a little bit before and compared the results of a working R80.40 with the R81.00. The moment things go wrong is when the "investigator" tries to calculate the hash of the file.

Interpreting the ted.elg i would say the "investigator" compares the size of mail body with the size of the file. The result is a size mismatch. For example the pdf above. It is stored correctly

[Expert@sb:0]# cd $FWDIR/tmp/te/te_tmp_files/
[Expert@sb:0]# ls -la e408*
-rw-rw---- 1 admin root 432800 Aug 10 13:33 e408c241d3047c82
[Expert@sb:0]# file e408c241d3047c82
b241d96de146cc31: PDF document, version 1.4

but comparising is between 432800 and 54 which is the size of the linkfile? itself

        :meta_data (
                :file_orig_name (filea2eLAc.cp_lnk)
                :file_path ("/opt/CPsuite-R81/fw1/tmp/email_tmp/emailtemp-1628595203-2202185836-2388607940_D/filea2eLAc.cp_lnk")
                :file_type (cp_lnk)
                :file_len (54)
                :protocol (smtp)
                :rule_id (1)

and the result is an error as you can see in the ted.elg

..
[31605 4104619968][10 Aug 13:33:23] [TE_TRACE]: {6EE0AAAC-8ABB-5B4D-A7A5-3D2ED28D0F6F} url: https://www.checkpoint.com/downloads/300TestReport.pdf, extension :pdf, head rc = 200
[31605 4104619968][10 Aug 13:33:23] [TE_TRACE]: {6EE0AAAC-8ABB-5B4D-A7A5-3D2ED28D0F6F} calling download with file path = /opt/CPsuite-R81/fw1/tmp/te/te_tmp_files/e408c241d3047c82
..
[31605 4104619968][10 Aug 13:33:23] [TE_TRACE]: {6EE0AAAC-8ABB-5B4D-A7A5-3D2ED28D0F6F} calling investigator 'file' (phase: 'prepare')
[31605 4104619968][10 Aug 13:33:23]  [TE (TD::Surprise)] te::FileInvestigatorTE::CheckFileSize: {6EE0AAAC-8ABB-5B4D-A7A5-3D2ED28D0F6F} file size (432800) != file size from metadata (54): /opt/CPsuite-R81/fw1/tmp/te/te_tmp_files/{64FB36B4-5E3A-F24A-BFC4-8BE4A62D1638}
[31605 4104619968][10 Aug 13:33:23] [TE_TRACE]: {6EE0AAAC-8ABB-5B4D-A7A5-3D2ED28D0F6F} investigator 'file' reporting back (status: error)

Since it is a lab, for me that's not a big deal, but i was wondering that nobody else had this kind of problem, as the error is really easy to reproduce and visible. Lke I said, on R80.40, same "installation routine" everything works fine.

_Val_ · ‎2021-08-10

That could be a bug, so any official channel, whether TAC or SE is the way to move forward.

Anna_Habert · ‎2021-08-19

TAC confirmed that this has been a bug for several months affecting R81.00. Fixed with the latest TE engine version 59.990000738, released on 17 August 2021. Thumbs up.

Check out SK95235 for more information & update.

https://supportcenter.checkpoint.com/supportcenter/portal?eventSubmit_doGoviewsolutiondetails=&solut...

_Val_ · ‎2021-08-19

Thanks for the update.

Are you a member of CheckMates?

Error on emulating HTTP/HTTPS links on local R81 Threat Emulation