Create a Post
cancel
Showing results for 
Search instead for 
Did you mean: 
chico
Contributor

MTA - mail delayed

Hello,

We use the MTA on our checkpoint R80.20 Cluster and sometime we have some mails send with a veriable delay to the host. Per exemple a host complain me that he had reveied a mail 25 minutes later and his collegue 20 minutes later (for the same mail and the same sender).

Effectily I seen on the smart dashboard the mail with some logs, 

mta_.png

1- 9h58 - an MTA log that describe "An email from info@magnenat.com is being processed"

2 - 10h08 - a log from the system monitor "Warning: Email is delayed for 10 minutes in the MTA queue. Consider adjusting the scanning policy in order to reduce the load." and after nothing.

So my questions are:

1- What does mean "An email from info@magnenat.com is being processed" ? the mail is send to the cloud sanblast for scan ?  even if the mail doesn't have attachment ?

2- Why the mail is delayed ?

3- The mail is delayed OK but how can I know how many times and when the mail as passed the scan and send to the client ? I don't have any log about it.


In the mail agent advanced settings, I can see some settings.

What does meens the "Maximum delay time" ? if the scan is not finish after 25 minutes the mail is deleted ?

The other option "Troubleshooting" it's log only the mails delayed after 10 minutes in the logs ? 

if someone can enlighten me it would be nice

Regards,

advanced_see_mta.png



0 Kudos
9 Replies
Blason_R
Advisor

You can investigate the logs /var/log/maillog and look for timings pls look at /opt/CPsuite-R80.20/fw1/log/mta.elg logs and lastly /opt/CPsuite-R80.20/fw1/log/ted.elg files

0 Kudos
chico
Contributor

Hello, 

 

I find this log on the /opt/CPsuite-R80.20/fw1/log/mta.elg with the "email queue ID" but I dont' understand what is mean ?

 

email_links_parser_search_url(): email_links_parser_remove_callbacks(sm) failed rc=-50
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:03] [EMAIL_AP (NOTICE)] handle() - 49lkF96XfTz8lJg :AP policy off
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:03] [EMAIL_MTA (NOTICE)] editContent() - 49lkF96XfTz8lJg :[mta_policy_context_id=2057908648] End connection.
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] emaild_new_connection(): [fw_conn_id=82, emaild_context_id=338146807] New connection.
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] pre(): sender='info@magnenat.com'
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] pre() - :recipient='XXXXXXXXX@fve.ch'
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] pre(): Message-ID=' <c0ccf675-ee18-8513-1483-277e34d53019@magnenat.com>'
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] parseEmlFile() - 49lkGH05qnz8lJg :[emailContextId=3913194064] MIME Parsing result: 0(Success)
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] email_links_xml_parser_finalize_url_inside_xml_attribute_value(): no base url in this xml part
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] email_links_xml_parser_finalize_url_inside_xml_attribute_value(): no base url in this xml part
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_AP (NOTICE)] handle() - 49lkGH05qnz8lJg :AP policy off
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_MTA (NOTICE)] emaild_new_connection(): [fw_conn_id=86, emaild_context_id=1845345666] New connection.
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_AV (ERROR)] OnListenerCallback(): RepCloudService: Consumer ended with error
[mtad 17609 4042984352]@feto1n065[15 Jun 9:57:59] [EMAIL_AV (ERROR)] OnListenerCallback(): RepCloudService: Consumer ended with error

0 Kudos
Blason_R
Advisor

Email ID is the SMTP ID assigned by postfix. You will find the same ID in /var/log/maillog

0 Kudos
chico
Contributor

Hello thank you for your reply,

I did a test, I send me an email with a pdf attachment file. 

- sender : sender

-recipient : recipient

here the mta.elg log so If i resume the process

  • at 9:42:02 - new connection from sender to recipient
  • at 9:42:03 the attachment file is send to the checkpoint cloud for analysis ? and/or to the threat prevention blade ?
  • at 9:42:03 the scan is finish with a verdict 0, 0=no threats detected ?
  • So the scan started at 9:42:02 and finished at 9:42:03 ?
#######################################################################################################################################
•	/opt/CPsuite-R80.20/fw1/log/mta.elg
#######################################################################################################################################
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:02]  [EMAIL_MTA (NOTICE)] emaild_new_connection(): [fw_conn_id=155, emaild_context_id=966213017] New connection.
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:02]  [EMAIL_MTA (NOTICE)] pre(): sender='sender'
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:02]  [EMAIL_MTA (NOTICE)] pre() -  :recipient='recipient'
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:02]  [EMAIL_MTA (NOTICE)] pre(): Message-ID=' <CAG7jjqEM41_YvzoCY-4JOOBurkPj-7bWONhZn_9NFWYpZX6qXQ@mail.gmail.com>'
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:02]  [EMAIL_MTA (NOTICE)] parseEmlFile() - 49nYmV54dQzGJqn :[emailContextId=717262164] MIME Parsing result: 0(Success)
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:02]  [EMAIL_AP (NOTICE)] handle() - 49nYmV54dQzGJqn :AP policy off
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:03]  [EMAIL_TE (NOTICE)] sendAttachmentRequest() - 49nYmV54dQzGJqn :Send to TE: Attachment name is 'debug_vpnAlwaysON_Jabber.pdf', size=132742, teContext.m_teHandle = dfda0d50
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:04]  [EMAIL_TE (NOTICE)] scanFinishedCb() - 49nYmV54dQzGJqn :TE email scan finished, verdict=0
[mtad 17542 4043160480]@feto1n064[18 Jun  9:42:04]  [EMAIL_MTA (NOTICE)] editContent() – 
49nYmV54dQzGJqn :[mta_policy_context_id=717262164] End connection
#######################################################################################################################################

 

Now if I look the ted.elg log (ted.elg = threat emulation logs right ?) I want to try to correclate the logs with the mta.log

  • at 9:42:03, the mta sent the attachment to the threat emulation blade ? with the file debug_vpnAlwaysON_Jabber.pdf
  • What doean mean the logs [TE_TRACE]
  • What doeans mean this logs below ? (adding image)

adding image '5e5de275-a103-4f67-b55b-47532918fa59' for emulation
adding image 'e50e99f3-5963-4573-af9e-e3f4750b55e2' for emulation

Are they the emulated environnments used for the scan on the checkpoint cloud ?

What does mean the last logs with the :event_id ("{5F743C7A-418D-0E46-8099-C5634F8EA7EA}") ?

The postfix logs start at 9:42:04 for this email ?does it means that the mail is sent after the scan on the cloud or threat emulation blade is finish ?

Thank you 

#######################################################################################################################################
•	/opt/CPsuite-R80.20/fw1/log/ted.elg
#######################################################################################################################################
[14547 4117154720][18 Jun  9:42:03]  [TE_IS_TRACE (TD::All)] te_is::SocketApiServer::HandleDataEvent: got on conn_id: 2 data:
(
	:connection (
		:src_ip (clearswift)
		:src_port (0)
		:dst_ip (checkpoint)
		:dst_port (25)
		:protocol (6)
	)
	:meta_data (
		:file_orig_name (debug_vpnAlwaysON_Jabber.pdf)
		:file_path ("/opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/OXUUPVFDA102314XF1UFYPWA3HBQZP46Q07I3MMPLMPR")
		:file_type (pdf)
		:file_len (132742)
		:protocol (smtp)
		:rule_id (30)
		:free_text ()
		:should_track ()
		:malware_rule_id ("{C66F190E-F469-4386-94DF-181D234F1CCF}")
		:scope_ip (checkpoint)
		:conn_id ()
		:session_id ()
		:instance_id ()
		:investigation_path (PATH_TE)
		:cdir (2)
	)
	:http_data (
		:url ()
	)
	:smtp_data (
		:to (recipient)
		:from (sender)
		:subject (" test email")
		:body_path ("/opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFile")
	)
)

[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Handling new file "debug_vpnAlwaysON_Jabber.pdf", Path: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/OXUUPVFDA102314XF1UFYPWA3HBQZP46Q07I3MMPLMPR, rule_number = 30, rule name = MTA traffic to Gateway portail , investigation_path = PATH_TE
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Local Partial response is enabled
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Remote Partial response is enabled
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Cloud Partial response is enabled
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'system state' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'system state' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {system state} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'url prepare handler' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'url prepare handler' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {url prepare handler} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'classifier' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'classifier' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {classifier} total duration time in milliseconds is: 2, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'policy' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} adding image '5e5de275-a103-4f67-b55b-47532918fa59' for emulation
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} adding image 'e50e99f3-5963-4573-af9e-e3f4750b55e2' for emulation
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'policy' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {policy} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'file' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Hashes: md5=ba0bf9749eb218cc4d13e15fc6dbde3d, sha1=862fc1316f9896f9d410ae64f9d0ffbb34dc700d
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'file' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {file} total duration time in milliseconds is: 2, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'prepare persistency' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'prepare persistency' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {prepare persistency} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'contract' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'contract' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {contract} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'cache inquirer' (phase: 'prepare')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'cache inquirer' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {cache inquirer} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} path in ep: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFilein response data: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFile
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Reporting back action: unknown; Confidence: 0; InvestigationPath: PATH_TE
[14547 4117154720][18 Jun  9:42:03]  [TE_IS_TRACE (TD::All)] te_is::SocketApiServer::Transmit: transmit on conn_id: 2 data:
(
	:event_id ("{5F743C7A-418D-0E46-8099-C5634F8EA7EA}")
	:action (unknown)
	:confidence (none)
	:done (0)
	:file_path ("/opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/OXUUPVFDA102314XF1UFYPWA3HBQZP46Q07I3MMPLMPR")
	:md5_string (ba0bf9749eb218cc4d13e15fc6dbde3d)
	:investigation_path (PATH_TE)
	:additional_data ()
	:body_path ("/opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFile")
)

[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'duplicate' (phase: 'processing')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'duplicate' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {duplicate} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'url handler' (phase: 'processing')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'url handler' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {url handler} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'trusted source' (phase: 'processing')
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} url is empty, don't check in white domains
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'trusted source' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {trusted source} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][18 Jun  9:42:03] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'advisory' (phase: 'processing')
[14547 4117154720][18 Jun  9:42:03]  [TE_IS_TRACE (TD::All)] te_is::SocketApiClient::SendObject: sending data:
{
   "api_name" : "BDRpcScanFile",
   "file_path" : "/opt/CPsuite-R80.20/fw1/tmp/te/te_tmp_files/{624FA0D7-D9B0-154D-8065-917FB017F5D3}",
   "referance_uid" : "{5F743C7A-418D-0E46-8099-C5634F8EA7EA}"
}

[14547 4117154720][18 Jun  9:42:03]  [TE_IS_TRACE (TD::All)] te_is::SocketApiClient::OnListenerCallback: got data:
{"api_name":"BDRpcScanFile","file_path":"/opt/CPsuite-R80.20/fw1/tmp/te/te_tmp_files/{624FA0D7-D9B0-154D-8065-917FB017F5D3}","last_update":"18.06.2020 07:50:16","referance_uid":"{5F743C7A-418D-0E46-8099-C5634F8EA7EA}","status":1,"status_text":"CLEAN"}

[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} verdict 'Benign' set for image: '5e5de275-a103-4f67-b55b-47532918fa59' (Win7,Office 2013,Adobe 11) by: 4, reason: Skipping emulation
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} verdict 'Benign' set for image: 'e50e99f3-5963-4573-af9e-e3f4750b55e2' (WinXP,Office 2003/7,Adobe 9) by: 4, reason: Skipping emulation
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'advisory' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {advisory} total duration time in milliseconds is: 905, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'file analyzer' (phase: 'processing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'file analyzer' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {file analyzer} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'domain threshold' not mandatory, will jump to next in phase
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'Web Emulation phase1' not mandatory, will jump to next in phase
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'Web Emulation phase2' not mandatory, will jump to next in phase
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'emulator' not mandatory, will jump to next in phase
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'cloud emulation' not mandatory, will jump to next in phase
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'remote emulation' not mandatory, will jump to next in phase
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'false positives' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'false positives' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {false positives} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'ip reputation' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'ip reputation' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {ip reputation} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'decode' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'decode' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {decode} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'embedded files' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'embedded files' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {embedded files} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'dropped files' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'dropped files' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {dropped files} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'archive' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'archive' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {archive} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'classifier_holder' (phase: 'finalizing')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'classifier_holder' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {classifier_holder} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'cloud data enricher' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'cloud data enricher' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {cloud data enricher} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'forensics' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'forensics' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {forensics} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'additional emulation data' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'additional emulation data' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {additional emulation data} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'cache updater' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'cache updater' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {cache updater} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'threat cloud sharing' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'threat cloud sharing' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {threat cloud sharing} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'threat cloud statistics' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'threat cloud statistics' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {threat cloud statistics} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'logger' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'logger' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {logger} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'finalize persistency' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'finalize persistency' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {finalize persistency} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'file saver' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'file saver' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {file saver} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'measurements' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'measurements' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {measurements} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'verdicts collector' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'verdicts collector' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {verdicts collector} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} calling investigator 'local filter counter' (phase: 'reporting')
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} investigator 'local filter counter' reporting back (status: done)
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} {local filter counter} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} path in ep: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFilein response data: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFile
[14547 4117154720][18 Jun  9:42:04] [TE_TRACE]: {5F743C7A-418D-0E46-8099-C5634F8EA7EA} Done with file; Reporting back action: accept; Confidence: 0; InvestigationPath: PATH_TE
[14547 4117154720][18 Jun  9:42:04]  [TE_IS_TRACE (TD::All)] te_is::SocketApiServer::Transmit: transmit on conn_id: 2 data:
(
	:event_id ("{5F743C7A-418D-0E46-8099-C5634F8EA7EA}")
	:action (accept)
	:confidence (none)
	:done (1)
	:file_path ("/opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/OXUUPVFDA102314XF1UFYPWA3HBQZP46Q07I3MMPLMPR")
	:md5_string (ba0bf9749eb218cc4d13e15fc6dbde3d)
	:investigation_path (PATH_TE)
	:additional_data ()
	:body_path ("/opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592466122-3224643445-811477696_D/MailBodyFile")
)

 

0 Kudos
Blason_R
Advisor

Correct the debug files are pretty descriptive and if you correlated with /var/log/maillog it will show who connected what is the original SMTP ID.

Trace is the debug messages while Images are the Windows images AFAIK. Since there are multiple images with different environments.

 

0 Kudos
chico
Contributor

okay thank you a lot, my last question, I increased the size of maillog and the numbers of maillog rotate. I would like to increase the size of ted.elg log too. but I find nothing about to how to do that, Do you know it ?

 

Regards,

0 Kudos
Blason_R
Advisor

May be sk39013 and sk36798 - Would help

0 Kudos
chico
Contributor

hi,

I had a case where the email was delayed for 15 minutes and I don't know where the scan was spend more times.

In the mailog, I can find that the mail arrived at 14:53:11 and sent at 15:08:04

Jun 19 14:53:11 2020 feto1n064 postfix/smtpd[32252]: 49pJd36jkGzGJr7: client=unknown[mail]
Jun 19 14:53:11 2020 feto1n064 postfix/cleanup[32255]: 49pJd36jkGzGJr7: message-id=<CAK8YdH97ND43S0LdqQYdk7xD-oPSFAWZSUxi_B1MNNXDfLyFsw@mail.gmail.com>
Jun 19 14:53:11 2020 feto1n064 postfix/qmgr[4565]: 49pJd36jkGzGJr7: from=<SRS0=DbzY=AA=plr-vd.ch=c.danselme@srs.addressix.com>, size=83166, nrcpt=1 (queue active)
Jun 19 14:53:11 2020 feto1n064 postfix/smtpd[32257]: 49pJd36sxCzGJrB: client=localhost[127.0.0.1], orig_queue_id=49pJd36jkGzGJr7, orig_client=unknown[mail]
Jun 19 15:08:04 2020 feto1n064 postfix/smtp[32256]: 49pJd36jkGzGJr7: to=<recipient>, relay=127.0.0.1[127.0.0.1]:10025, delay=893, delays=0.02/0/0/892, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 49pJd36sxCzGJrB)
Jun 19 15:08:04 2020 feto1n064 postfix/qmgr[4565]: 49pJd36jkGzGJr7: removed

 

In the mtad.elg I find that the file was send at 14:53:11 and finish at 15:08:04...so 16 minutes to scan the file

[mtad 17542 4043160480]@feto1n064[19 Jun 14:53:11]  [EMAIL_MTA (NOTICE)] parseEmlFile() - 49pJd36jkGzGJr7 :[emailContextId=2775134773] MIME Parsing result: 0(Success)
[mtad 17542 4043160480]@feto1n064[19 Jun 14:53:11]  [EMAIL_AP (NOTICE)] handle() - 49pJd36jkGzGJr7 :AP policy off
[mtad 17542 4043160480]@feto1n064[19 Jun 14:53:11]  [EMAIL_TE (NOTICE)] sendAttachmentRequest() - 49pJd36jkGzGJr7 :Send to TE: Attachment name is 'attachment.doc', size=56320, teContext.m_teHandle = e1b183f8
[mtad 17542 4043160480]@feto1n064[19 Jun 15:08:04]  [EMAIL_TE (NOTICE)] scanFinishedCb() - 49pJd36jkGzGJr7 :TE email scan finished, verdict=0
[mtad 17542 4043160480]@feto1n064[19 Jun 15:08:04]  [EMAIL_MTA (NOTICE)] editContent() - 49pJd36jkGzGJr7 :[mta_policy_context_id=2775134773] End connection.

 

In the ted.el log it isn't very clear where the scan spent more times... I see only a gap in the logs between 14:53:11 and 15:05:50.. Do you have any ideas why the scan is so long ?

[Expert@feto1n064:0]# cat ted.elg | grep {46572C86-5B06-004B-AB39-D6EDE074211A}
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Handling new file "Simple question Catherine Labouchère.doc", Path: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/RDFQA2G01104469WTRWJ0TLCS0F05BGE3ZBYGTFF63ID, rule_number = 30, rule name = MTA traffic to Gateway portail , investigation_path = PATH_TE
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Local Partial response is enabled
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Remote Partial response is enabled
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Cloud Partial response is enabled
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'system state' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'system state' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {system state} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'url prepare handler' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'url prepare handler' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {url prepare handler} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'classifier' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'classifier' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {classifier} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'policy' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} adding image '5e5de275-a103-4f67-b55b-47532918fa59' for emulation
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} adding image 'e50e99f3-5963-4573-af9e-e3f4750b55e2' for emulation
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'policy' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {policy} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'file' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Hashes: md5=36b8cef565d9b56910b1f35f0cc72709, sha1=ca226bfa49686beaca3db26a43944603d73bd7af
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'file' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {file} total duration time in milliseconds is: 2, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'prepare persistency' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'prepare persistency' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {prepare persistency} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'contract' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'contract' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {contract} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'cache inquirer' (phase: 'prepare')
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'cache inquirer' reporting back (status: done)
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {cache inquirer} total duration time in milliseconds is: 1, current combined verdict is: Inert
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} path in ep: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/MailBodyFilein response data: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/MailBodyFile
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Reporting back action: unknown; Confidence: 0; InvestigationPath: PATH_TE
        :event_id ("{46572C86-5B06-004B-AB39-D6EDE074211A}")
[14547 4117154720][19 Jun 14:53:11] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'duplicate' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'duplicate' reporting back (status: rewind)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {duplicate} total duration time in milliseconds is: 758928, current combined verdict is: Inert
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'system state' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'system state' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'url prepare handler' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'url prepare handler' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'classifier' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'classifier' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'policy' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} adding image '5e5de275-a103-4f67-b55b-47532918fa59' for emulation
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} adding image 'e50e99f3-5963-4573-af9e-e3f4750b55e2' for emulation
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'policy' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'file' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Hashes: md5=36b8cef565d9b56910b1f35f0cc72709, sha1=ca226bfa49686beaca3db26a43944603d73bd7af
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'file' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'prepare persistency' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'prepare persistency' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'contract' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'contract' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'cache inquirer' (phase: 'prepare')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} verdict 'Benign' set for image: '5e5de275-a103-4f67-b55b-47532918fa59' (Win7,Office 2013,Adobe 11) by: 0, reason:
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'cache inquirer' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} path in ep: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/MailBodyFilein response data: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/MailBodyFile
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Reporting back action: accept; Confidence: 0; InvestigationPath: PATH_TE
        :event_id ("{46572C86-5B06-004B-AB39-D6EDE074211A}")
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'duplicate' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'duplicate' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {duplicate} total duration time in milliseconds is: 758928, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'url handler' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'url handler' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {url handler} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'trusted source' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} url is empty, don't check in white domains
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'trusted source' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {trusted source} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:50] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'advisory' (phase: 'processing')
   "referance_uid" : "{46572C86-5B06-004B-AB39-D6EDE074211A}"
{"api_name":"BDRpcScanFile","file_path":"/opt/CPsuite-R80.20/fw1/tmp/te/te_tmp_files/{4AFEA341-D3E4-F648-8661-5A16C43756E8}","last_update":"19.06.2020 09:38:43","referance_uid":"{46572C86-5B06-004B-AB39-D6EDE074211A}","status":1,"status_text":"CLEAN"}
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'advisory' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {advisory} total duration time in milliseconds is: 803, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'file analyzer' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'file analyzer' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {file analyzer} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'domain threshold' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'domain threshold' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {domain threshold} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'Web Emulation phase1' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'Web Emulation phase1' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {Web Emulation phase1} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'Web Emulation phase2' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'Web Emulation phase2' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {Web Emulation phase2} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'emulator' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'emulator' reporting back (status: done)
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {emulator} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:05:51] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'cloud emulation' (phase: 'processing')
[14547 4117154720][19 Jun 15:05:52] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} uploaded to 217.68.13.87. (cloud emulation)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} verdict 'Benign' set for image: 'e50e99f3-5963-4573-af9e-e3f4750b55e2' (WinXP,Office 2003/7,Adobe 9) by: 16, reason:
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'cloud emulation' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {cloud emulation} total duration time in milliseconds is: 132991, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'remote emulation' not mandatory, will jump to next in phase
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'false positives' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'false positives' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {false positives} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'ip reputation' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'ip reputation' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {ip reputation} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'decode' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'decode' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {decode} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'embedded files' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'embedded files' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {embedded files} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'dropped files' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'dropped files' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {dropped files} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'archive' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'archive' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {archive} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'classifier_holder' (phase: 'finalizing')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'classifier_holder' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {classifier_holder} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'cloud data enricher' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'cloud data enricher' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {cloud data enricher} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'forensics' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'forensics' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {forensics} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'additional emulation data' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'additional emulation data' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {additional emulation data} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'cache updater' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'cache updater' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {cache updater} total duration time in milliseconds is: 2, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'threat cloud sharing' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'threat cloud sharing' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {threat cloud sharing} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'threat cloud statistics' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'threat cloud statistics' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {threat cloud statistics} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'logger' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'logger' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {logger} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'finalize persistency' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'finalize persistency' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {finalize persistency} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'file saver' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'file saver' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {file saver} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'measurements' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'measurements' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {measurements} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'verdicts collector' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'verdicts collector' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {verdicts collector} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} calling investigator 'local filter counter' (phase: 'reporting')
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} investigator 'local filter counter' reporting back (status: done)
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} {local filter counter} total duration time in milliseconds is: 1, current combined verdict is: Benign
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} path in ep: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/MailBodyFilein response data: /opt/CPsuite-R80.20/fw1/tmp/email_tmp/emailtemp-1592571190-3449878024-3136697231_D/MailBodyFile
[14547 4117154720][19 Jun 15:08:04] [TE_TRACE]: {46572C86-5B06-004B-AB39-D6EDE074211A} Done with file; Reporting back action: accept; Confidence: 0; InvestigationPath: PATH_TE
        :event_id ("{46572C86-5B06-004B-AB39-D6EDE074211A}")

Regards,

 

0 Kudos
Pierre-Aymeric_
Participant

Hi there,

Did you raised a case to CHKP support ? was there any improvement ?

 

I'm having the exact same issue, and it appeared 2 month ago. Only temporary solution was to restart the service since I did not had time to work on it.

If I'm progressing on the issue, I'll update here.

0 Kudos