Problem downloading Threat Feed

[Mfryksten]

Hi

we are running RA 2.5, ePO 4.5.4 hf1. A while ago the server task "MRA: Threat Download and Analysis" stopped working, The server task logs simply reports "Error occured, check system log for error detail". Downloading the threat feeds manually also fails (cannot check in the updates)

We enabled the debug logging of orion and has the following output. One can see the access denied when the threat feed is due to start downloadning. HTTP access is fine, both from webbrowser and according to the logs.

Any ideas where to start troubleshoot??

################################3

2011-09-08 12:05:26,491 INFO  [mfs:pool-1-thread-6] connector.MTISServiceHandler  - Initializing the threat feed download.

2011-09-08 12:05:26,491 DEBUG [mfs:pool-1-thread-6] shared.Licensing  - >>>>>>>> returned from native CheckLicense call tmp= 1

2011-09-08 12:05:26,491 DEBUG [mfs:pool-1-thread-6] shared.Licensing  - >>>>>>>> license Status= LICENSE_LICENSED

2011-09-08 12:05:26,491 DEBUG [mfs:pool-1-thread-6] shared.Licensing  - >>>>>>>> Days To Expiry= 0

2011-09-08 12:05:26,507 DEBUG [mfs:pool-1-thread-6] shared.SharedUtils  - LICENSE LICENSED, do nothing

2011-09-08 12:05:26,507 DEBUG [listThreatDownloadBeginEvent] sp.StoredProcedure  - calling stored procedure: {? = call MTIS_Threat.listThreatDownloadReconEvents(?,?,?,?)}

2011-09-08 12:05:26,507 DEBUG [listThreatDownloadBeginEvent] sp.StoredProcedure  - Param type: 12

Param value: mra_event_threat_download_begin

Set as Null: false

2011-09-08 12:05:26,507 DEBUG [listThreatDownloadBeginEvent] sp.StoredProcedure  - Param type: 12

Param value: Starting Threat Download

Set as Null: false

2011-09-08 12:05:26,507 DEBUG [listThreatDownloadBeginEvent] sp.StoredProcedure  - Param type: 16

Param value: false

Set as Null: false

2011-09-08 12:05:26,507 DEBUG [listThreatDownloadBeginEvent] sp.StoredProcedure  - Param type: 12

Param value: <Param><ThreatDownloadCount>0</ThreatDownloadCount><Status>1</Status></Param>

Set as Null: false

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultResponsiveStoredProcedure  - Publish events is set to : true

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  - NEW EVENT 1001

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     1001 1001 GOT PROPERTY Description

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     1001 1001 GOT PROPERTY EventType

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  - attempting to set variable: description of class com.mcafee.carma.core.shared.ThreatDownloadReconEvent

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     SETTING java.lang.String description, [Starting Threat Download]

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -  as simple property.

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     1001 1001 GOT PROPERTY Status

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  - attempting to set variable: eventType of class com.mcafee.carma.core.shared.ThreatDownloadReconEvent

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     SETTING java.lang.String eventType, [mra_event_threat_download_begin]

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -  as simple property.

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     1001 1001 GOT PROPERTY TaskDate

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  - attempting to set variable: status of class com.mcafee.carma.core.shared.ThreatDownloadReconEvent

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     SETTING boolean status, [1]

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -  as simple property.

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     1001 1001 GOT PROPERTY ThreatsDownloaded

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  - attempting to set variable: taskDate of class com.mcafee.carma.core.shared.ThreatDownloadReconEvent

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     SETTING java.sql.Timestamp taskDate, [2011-09-08 10:05:26]

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -  as simple property.

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  - attempting to set variable: threatsDownloaded of class com.mcafee.carma.core.shared.ThreatDownloadReconEvent

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -     SETTING int threatsDownloaded, [0]

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DefaultEventParser  -  as simple property.

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.DispatchingEventPublisher  - publishing the following to the ARS system: com.mcafee.carma.core.shared.ThreatDownloadReconEvent Details: com.mcafee.carma.core.shared.ThreatDownloadReconEvent@f7db5c

2011-09-08 12:05:26,523 DEBUG [listThreatDownloadBeginEvent] response.EventStoredProcInvokerThread  - Event is dispacthed successfully

2011-09-08 12:05:26,523 INFO  [mfs:pool-1-thread-6] connector.MTISServiceHandler  - Starting threat data download.

2011-09-08 12:05:26,679 DEBUG [mfs:pool-1-thread-6] wire.header      - >> "GET /ctp/data/status.evt HTTP/1.1[\r][\n]"

2011-09-08 12:05:26,679 DEBUG [mfs:pool-1-thread-6] wire.header      - >> "User-Agent: Jakarta Commons-HttpClient/3.0.1[\r][\n]"

2011-09-08 12:05:26,679 DEBUG [mfs:pool-1-thread-6] wire.header      - >> "Host: threatfeed.mtis.mcafee.com[\r][\n]"

2011-09-08 12:05:26,679 DEBUG [mfs:pool-1-thread-6] wire.header      - >> "[\r][\n]"

2011-09-08 12:05:26,679 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Starting new doGet request: /scheduler/showTaskLog.do

2011-09-08 12:05:26,710 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Validating action: showTaskLog.do

2011-09-08 12:05:26,710 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Executing action: showTaskLog.do

2011-09-08 12:05:26,710 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Starting new doGet request: /scheduler/tasklog/list.jsp

2011-09-08 12:05:26,726 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Validating action: orionNavigationBar.do

2011-09-08 12:05:26,726 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Executing action: orionNavigationBar.do

2011-09-08 12:05:26,741 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Starting new doGet request: /scheduler/tasklog/list.jsp

2011-09-08 12:05:26,757 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Validating action: table.do

2011-09-08 12:05:26,757 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Executing action: table.do

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "HTTP/1.1 200 OK[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "Content-Type: application/octet-stream[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "Last-Modified: Thu, 08 Sep 2011 09:44:09 GMT[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "Accept-Ranges: bytes[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "ETag: "6a94c5dbb6ecc1:0"[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "Server: Microsoft-IIS/7.0[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "X-Powered-By: ASP.NET[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "Date: Thu, 08 Sep 2011 10:05:27 GMT[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.header      - << "Content-Length: 8[\r][\n]"

2011-09-08 12:05:27,491 DEBUG [mfs:pool-1-thread-6] wire.content     - << "144914[\r][\n]"

2011-09-08 12:05:27,741 DEBUG [http-8443-Processor16] servlet.ControllerServlet  - Starting new doGet request: /core/loadTableData.do

2011-09-08 12:05:27,757 DEBUG [http-8443-Processor16] servlet.ControllerServlet  - Validating action: loadTableData.do

2011-09-08 12:05:27,757 DEBUG [http-8443-Processor16] servlet.ControllerServlet  - Executing action: loadTableData.do

2011-09-08 12:05:27,804 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Starting new doPost request.

2011-09-08 12:05:27,819 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Validating action: getNavBar.do

2011-09-08 12:05:27,819 DEBUG [http-8443-Processor17] servlet.ControllerServlet  - Executing action: getNavBar.do

2011-09-08 12:05:28,507 DEBUG [pool-7-thread-1] engine.RuleEngineImpl  - checking if rules are ready to be triggered

2011-09-08 12:05:29,226 ERROR [mfs:pool-1-thread-6] connector.MTISServiceHandler  - Unable to download threat data.

com.mcafee.carma.mtis.connector.ConnectorException: Access Denied

at com.mcafee.carma.mtis.connector.MTISThreatFeed.query(Unknown Source)

at com.mcafee.carma.mtis.connector.MTISThreatFeed.getThreats(Unknown Source)

at com.mcafee.carma.mtis.connector.MTISServiceHandler.start(Unknown Source)

at com.mcafee.carma.mtis.connector.MTISServiceHandler.service(Unknown Source)

at com.mcafee.carma.mtis.connector.ConnectorCommandBase.invoke(Unknown Source)

at com.mcafee.carma.mtis.connector.MTISThreatFeedCommand.invoke(Unknown Source)

at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:825)

at com.mcafee.orion.core.cmd.CommandInvoker.invokeCommand(CommandInvoker.java:607)

at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:596)

at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:575)

at com.mcafee.orion.scheduler.chainable.Chain.invokeChain(Chain.java:278)

at com.mcafee.orion.scheduler.chainable.Chain.invokeChain(Chain.java:300)

at com.mcafee.orion.scheduler.chainable.Chain.invokeChain(Chain.java:219)

at com.mcafee.orion.scheduler.chainable.Chain.invoke(Chain.java:41)

at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:825)

at com.mcafee.orion.core.cmd.CommandInvoker$AsyncCommandRunner.call(CommandInvoker.java:743)

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

at java.util.concurrent.FutureTask.run(FutureTask.java:138)

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

at java.lang.Thread.run(Thread.java:619)

Caused by: Access Denied

at org.apache.axis.message.SOAPFaultBuilder.createFault(SOAPFaultBuilder.java:221)

at org.apache.axis.message.SOAPFaultBuilder.endElement(SOAPFaultBuilder.java:128)

at org.apache.axis.encoding.DeserializationContext.endElement(DeserializationContext.java:1083)

at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:601)

at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1782)

at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2938)

at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:648)

at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:140)

at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:511)

at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)

at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)

at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)

at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1205)

at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)

at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)

at org.apache.axis.encoding.DeserializationContext.parse(DeserializationContext.java:226)

at org.apache.axis.SOAPPart.getAsSOAPEnvelope(SOAPPart.java:645)

at org.apache.axis.Message.getSOAPEnvelope(Message.java:424)

at org.apache.axis.handlers.soap.MustUnderstandChecker.invoke(MustUnderstandChecker.java:62)

at org.apache.axis.client.AxisClient.invoke(AxisClient.java:173)

at org.apache.axis.client.Call.invokeEngine(Call.java:2719)

at org.apache.axis.client.Call.invoke(Call.java:2702)

at org.apache.axis.client.Call.invoke(Call.java:2378)

at org.apache.axis.client.Call.invoke(Call.java:2301)

at org.apache.axis.client.Call.invoke(Call.java:1758)

at com.mcafee.carma.mtis.connector.wsclient.ServiceSoapStub.query(Unknown Source)

... 21 more

######################################################################################

Message was edited by: Mfryksten and this is what the debug orion log file looks like when doing a manual file import of the threat feeds:

2011-09-08 15:38:11,769 ERROR [mfs:pool-2-thread-13] scheduler.Engine  - task [MRA: Threat File Import and Analysis] failed with exception java.util.concurrent.ExecutionException: com.mcafee.orion.core.cmd.CommandException: I/O Error: Connection reset by peer: socket write error      at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)      at java.util.concurrent.FutureTask.get(FutureTask.java:83)      at com.mcafee.orion.scheduler.Engine.runTasks(Engine.java:346)      at com.mcafee.orion.scheduler.engine.EngineTask.run(EngineTask.java:57)      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)      at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)      at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)      at java.lang.Thread.run(Thread.java:619) Caused by: com.mcafee.orion.core.cmd.CommandException: I/O Error: Connection reset by peer: socket write error      at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:862)      at com.mcafee.orion.core.cmd.CommandInvoker.invokeCommand(CommandInvoker.java:607)      at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:596)      at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:575)      at com.mcafee.orion.scheduler.chainable.Chain.invokeChain(Chain.java:278)      at com.mcafee.orion.scheduler.chainable.Chain.invokeChain(Chain.java:219)      at com.mcafee.orion.scheduler.chainable.Chain.invoke(Chain.java:41)      at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:825)      at com.mcafee.orion.core.cmd.CommandInvoker$AsyncCommandRunner.call(CommandInvoker.java:743)      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)      at java.util.concurrent.FutureTask.run(FutureTask.java:138)      ... 3 more Caused by: java.sql.BatchUpdateException: I/O Error: Connection reset by peer: socket write error      at net.sourceforge.jtds.jdbc.JtdsStatement.executeBatch(JtdsStatement.java:966)      at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)      at com.mcafee.carma.core.command.ImportThreatsFromFileCommand.populateTempRawThreat(Unknown Source)      at com.mcafee.carma.core.command.ImportThreatsFromFileCommand.invoke(Unknown Source)      at com.mcafee.carma.core.command.ImportThreatsFromFileCommand.invoke(Unknown Source)      at com.mcafee.orion.core.cmd.CommandInvoker.invoke(CommandInvoker.java:825)      ... 13 more on 9/8/11 8:57:12 AM CDT

Message was edited by: Mfryksten on 9/8/11 8:58:18 AM CDT

[KishoreRP]

Can you please do the below

     1) Is there a proxy enabled that is causing threat feed download to break?

     2) For the manual uploading of threats,  is it possible to restart epo server and check again.

     3) please send across the output of all the attached queries

Hope this helps.

[Mfryksten]

Hi,

Thanks for the reply

1) there is no proxy specified and the files can be downloaded on the server itself (web browser)

2) we will try and return answer

3) will try the files, can you please acknowledge that you are a mcafee representative? (want to know that files are legitimate)

Regards,

/Mikael

[KishoreRP]

I acknowledge that i am a McAfee representative.

Thanks,

Kishore

[Mfryksten]

Ok thanks Kishore,

I also have a  case with mcafee support open, ref 3-1667164701. If you are involved this is the same case

Thanks!

/Mike

[KishoreRP]

The response to the case 3-1667164701 is same as we have mentioned here, can you please revert with the output from .sql file.

Thanks,

Kishore

[Mfryksten]

Hi,

I have the result from Query,but would prefer not posting it here. Can I send you it via mail or ftp?

It contains account named among other info that we dont want to make public 🙂

Thanks,

Mikael

[KishoreRP]

not a problem,

pls check your private message,

have sent across my email id.