Bug 902028

Summary: [rhevm-dwh] - Table audit_log - No Logs in table for an exception (Blocks DNS using iptables)
Product: Red Hat Enterprise Virtualization Manager Reporter: David Botzer <dbotzer>
Component: ovirt-engine-dwhAssignee: Yaniv Lavi <ylavi>
Status: CLOSED ERRATA QA Contact: David Botzer <dbotzer>
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.2.0CC: acathrow, bazulay, dyasny, iheim, pstehlik, Rhev-m-bugs, sgrinber, ykaul, zdover
Target Milestone: ---   
Target Release: 3.2.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: infra
Fixed In Version: sf10 Doc Type: Bug Fix
Doc Text:
Previously, ovirt-engine.dwhd log wrote exceptions logs but showed no no events/logs in the audit_log reports table. The audit_log reports table now contains the information that is written to the exceptions logs.
 Story Points: ---
Clone Of: Environment:
Last Closed: 2013-06-10 21:57:20 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 915537, 922807    
Attachments:
Description Flags
dwh.log
none
engine-logs
none
all-logs
none
missingTable none

Description David Botzer 2013-01-20 14:21:03 UTC 
Created attachment 683561 [details]
dwh.log

Description of problem:
Table audit_log doesnt gets any logs on the following exceptions
ovirt-engine.dwhd log writes exceptions logs due to
blocked DNS connections using iptables.

Version-Release number of selected component (if applicable):
3.2/sf3

How reproducible:
always

Steps to Reproduce:
1.install rhevm+dwh+reports
2.create entities - hosts, SD, VMs
3.Imply the below iptables rules
4.examine ovirt-engine.dwhd log
  
Actual results:
ovirt-engine.dwhd log writes exceptions logs but no events/logs in audit_log table

Expected results:
audit_log table should have events on the exception written in the dwhd.log

Additional info:
iptables rules:
Add rules in iptables

-A INPUT -s DNS-IP/32 -d RHEVM-IP/32 -p udp -m udp --sport 53 --dport 1024:65535 -m state --state ESTABLISHED -j DROP
-A INPUT -s DNS-IP/32 -d RHEVM-IP/32 -p tcp -m tcp --sport 53 --dport 1024:65535 -m state --state ESTABLISHED -j DROP
-A OUTPUT -p udp -m udp --dport 53 -j DROP
-A OUTPUT -s RHEVM-IP/32 -d DNS-IP/32 -p tcp -m tcp --sport 1024:65535 --dport 53 -m state --state NEW,ESTABLISHED -j DROP
=======================================
ovirt-engine-dwh.log exception
--------------------------------
2013-01-17 17:03:00|Lj9gd5|S80i59|0o0sDj|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java Exception|tJava_1|java.net.UnknownHostException:dbotzer-ydary.qa.lab.tlv.redhat.com|1
Exception in component tJava_1
java.net.UnknownHostException: dbotzer-ydary.qa.lab.tlv.redhat.com
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:178)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
	at java.net.Socket.connect(Socket.java:579)
	at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:618)
	at sun.security.ssl.BaseSSLSocketImpl.connect(BaseSSLSocketImpl.java:160)
	at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
	at sun.net.www.http.HttpClient.openServer(HttpClient.java:378)
	at sun.net.www.http.HttpClient.openServer(HttpClient.java:473)
	at sun.net.www.protocol.https.HttpsClient.<init>(HttpsClient.java:270)
	at sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:327)
	at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(AbstractDelegateHttpsURLConnection.java:191)
	at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:931)
	at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:177)
	at sun.net.www.protocol.https.HttpsURLConnectionImpl.connect(HttpsURLConnectionImpl.java:153)
	at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJava_1Process(SampleTimeKeepingJob.java:1170)
	at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob$1.run(SampleTimeKeepingJob.java:4309)
2013-01-17 17:04:00|DNIL8R|S80i59|0o0sDj|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java Exception|tJava_1|java.net.UnknownHostException:dbotzer-ydary.qa.lab.tlv.redhat.com|1
Comment 1 David Botzer 2013-01-20 14:22:51 UTC 
Created attachment 683562 [details]
engine-logs
Comment 2 David Botzer 2013-01-20 14:25:01 UTC 
Created attachment 683563 [details]
all-logs
Comment 3 David Botzer 2013-01-21 09:03:37 UTC 
audit_log doesnt get logs even if a view is deleted
I deleted vm_configuration from ovirt_engine_history DB
And I cant get any logs in audit log - i waited more than 5 minutes,
---
2013-01-21 11:07:00|rvGQ5L|8slpb6|EbyCZc|OVIRT_ENGINE_DWH|SampleRunJobs|Default|6|Java Exception|tRunJob_1|java.lang.RuntimeException:Child job running failed|1
Exception in component tRunJob_1
java.lang.RuntimeException: Child job running failed
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tRunJob_1Process(SampleTimeKeepingJob.java:2479)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJDBCInput_2Process(SampleTimeKeepingJob.java:2322)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJDBCConnection_1Process(SampleTimeKeepingJob.java:1484)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJDBCConnection_2Process(SampleTimeKeepingJob.java:1386)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJava_3Process(SampleTimeKeepingJob.java:1294)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJava_1Process(SampleTimeKeepingJob.java:1199)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob$1.run(SampleTimeKeepingJob.java:4309)
2013-01-21 11:07:00|EbyCZc|8slpb6|RZ8cn0|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java Exception|tRunJob_1|java.lang.RuntimeException:Child job running failed|1
Comment 4 David Botzer 2013-01-21 09:04:09 UTC 
Created attachment 684122 [details]
missingTable
Comment 6 David Botzer 2013-02-14 08:29:08 UTC 
tested SF6,
Is that the output I should get in audit_log table :
------
"USER_VDC_LOGIN" - "User admin@internal logged in." - FALSE
----------------


And in dwh.log:
----------------
2013-02-14 10:18:04|5OWQs5|meBWew|8Bni46|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java Exception|tJava_1|java.net.UnknownHostException:dbotzer-vm-jrs7.qa.lab.tlv.redhat.com|1
Exception in component tJava_1
java.net.UnknownHostException: dbotzer-vm-jrs7.qa.lab.tlv.redhat.com
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:178)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
        at java.net.Socket.connect(Socket.java:579)
        at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:618)
        at sun.security.ssl.BaseSSLSocketImpl.connect(BaseSSLSocketImpl.java:160)
        at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
        at sun.net.www.http.HttpClient.openServer(HttpClient.java:378)
        at sun.net.www.http.HttpClient.openServer(HttpClient.java:473)
        at sun.net.www.protocol.https.HttpsClient.<init>(HttpsClient.java:270)
        at sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:327)
        at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(AbstractDelegateHttpsURLConnection.java:191)
        at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:931)
        at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:177)
        at sun.net.www.protocol.https.HttpsURLConnectionImpl.connect(HttpsURLConnectionImpl.java:153)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.tJava_1Process(SampleTimeKeepingJob.java:1170)
        at ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob$1.run(SampleTimeKeepingJob.java:4309)
2013-02-14 10:19:04|3KyRjP|meBWew|8Bni46|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java Exception|tJava_1|java.net.UnknownHostException:dbotzer-vm-jrs7.qa.lab.tlv.redhat.com|1
Comment 7 Yaniv Lavi 2013-02-14 10:22:02 UTC 
(In reply to comment #6)
> tested SF6,
> Is that the output I should get in audit_log table :
> ------
> "USER_VDC_LOGIN" - "User admin@internal logged in." - FALSE
> ----------------
> 
> 
> And in dwh.log:
> ----------------
> 2013-02-14
> 10:18:
> 04|5OWQs5|meBWew|8Bni46|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java
> Exception|tJava_1|java.net.UnknownHostException:dbotzer-vm-jrs7.qa.lab.tlv.
> redhat.com|1
> Exception in component tJava_1
> java.net.UnknownHostException: dbotzer-vm-jrs7.qa.lab.tlv.redhat.com
>         at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:178)
>         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
>         at java.net.Socket.connect(Socket.java:579)
>         at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:618)
>         at
> sun.security.ssl.BaseSSLSocketImpl.connect(BaseSSLSocketImpl.java:160)
>         at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
>         at sun.net.www.http.HttpClient.openServer(HttpClient.java:378)
>         at sun.net.www.http.HttpClient.openServer(HttpClient.java:473)
>         at
> sun.net.www.protocol.https.HttpsClient.<init>(HttpsClient.java:270)
>         at sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:327)
>         at
> sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.
> getNewHttpClient(AbstractDelegateHttpsURLConnection.java:191)
>         at
> sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.
> java:931)
>         at
> sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.
> connect(AbstractDelegateHttpsURLConnection.java:177)
>         at
> sun.net.www.protocol.https.HttpsURLConnectionImpl.
> connect(HttpsURLConnectionImpl.java:153)
>         at
> ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob.
> tJava_1Process(SampleTimeKeepingJob.java:1170)
>         at
> ovirt_engine_dwh.sampletimekeepingjob_3_2.SampleTimeKeepingJob$1.
> run(SampleTimeKeepingJob.java:4309)
> 2013-02-14
> 10:19:
> 04|3KyRjP|meBWew|8Bni46|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java
> Exception|tJava_1|java.net.UnknownHostException:dbotzer-vm-jrs7.qa.lab.tlv.
> redhat.com|1

It's fixed in SF7.
Look at release notes please.


Yaniv
Comment 8 David Botzer 2013-02-14 13:29:25 UTC 
Fixed, 3.2/SF7
Table audit_log contains correct log
"DWH_ERROR";9704;2;"ETL service sampling has encountered an error. Please consult the service log for more details."
Fixed, 3.2/SF7
Comment 9 Yaniv Lavi 2013-03-05 11:09:53 UTC 
Found error in fix.
Moving back to assigned.


Yaniv
Comment 10 David Botzer 2013-03-21 08:06:24 UTC 
Fixed 3.2/SF10
------
dwh properties is configured by default ->
timeBetweenErrorEvents=300000 (5min)
------
I get the below log every 5min - correctly,
Table audit_log contains correct log
"ETL service sampling has encountered an error. Please consult the service log for more details."
------
I have changed timeBetweenErrorEvents=60000 (1min) - keep getting errors every 1min
I left the errors to keep on coming for 1H
Fixed 3.2/SF10
------
also DWH contains log,
2013-03-21 09:53:17|T2q9Zm|h5Cx48|gaUbZm|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java Exception|tJava_1|java
.net.UnknownHostException:xxx.xxx.xxx.com|1
Exception in component tJava_1
java.net.UnknownHostException: xxx.xxx.xxx.com

Fixed 3.2/SF10
Comment 11 errata-xmlrpc 2013-06-10 21:57:20 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHEA-2013-0926.html