Unsolved
7 Posts
0
5323
Object content being dumped to logs
Let me start with apologizing for the lengthy post. Just want to make sure all the details are provided in one go...
We use com.emc.atmos.api.jersey.AtmosApiClient class to call getObjectMetadata and readObjectStream methods to retrieve the objects from the storage. Functionality is working absolutely fine and we don't have any issue with that. However, on the catalina.out log file we see below log debug information for getObjectMetadata:
DEBUG: Connection request: [route: {}->http:// : ][total kept alive: 0; route allocated: 0 of 200; total allocated: 0 of 200]
DEBUG: Connection leased: [id: 1][route: {}->http:// : ][total kept alive: 0; route allocated: 1 of 200; total allocated: 1 of 200]
DEBUG: Connecting to :
DEBUG: CookieSpec selected: best-match
DEBUG: Target auth state: UNCHALLENGED
DEBUG: Proxy auth state: UNCHALLENGED
DEBUG: Attempt 1 to execute request
DEBUG: Sending request: HEAD /rest/objects/ HTTP/1.1
DEBUG: >> "HEAD /rest/objects/ HTTP/1.1[\r][\n]"
DEBUG: >> "x-emc-utf8: true[\r][\n]"
DEBUG: >> "Date: Mon, 9 Jul 2018 21:10:25 UTC[\r][\n]"
DEBUG: >> "x-emc-date: Mon, 9 Jul 2018 21:10:25 UTC[\r][\n]"
DEBUG: >> "x-emc-uid: [\r][\n]"
DEBUG: >> "x-emc-signature: [\r][\n]"
DEBUG: >> "Host: : [\r][\n]"
DEBUG: >> "Connection: Keep-Alive[\r][\n]"
DEBUG: >> "User-Agent: Apache-HttpClient/4.2.6 (java 1.5)[\r][\n]"
DEBUG: >> "[\r][\n]"
DEBUG: >> HEAD /rest/objects/ HTTP/1.1
DEBUG: >> x-emc-utf8: true
DEBUG: >> Date: Mon, 9 Jul 2018 21:10:25 UTC
DEBUG: >> x-emc-date: Mon, 9 Jul 2018 21:10:25 UTC
DEBUG: >> x-emc-uid:
DEBUG: >> x-emc-signature:
DEBUG: >> Host: :
DEBUG: >> Connection: Keep-Alive
DEBUG: >> User-Agent: Apache-HttpClient/4.2.6 (java 1.5)
DEBUG: << "HTTP/1.1 200 OK[\r][\n]"
DEBUG: << "Date: Mon, 09 Jul 2018 21:10:19 GMT[\r][\n]"
DEBUG: << "x-emc-mtime: 1531164643814[\r][\n]"
DEBUG: << "x-emc-meta: [\r][\n]"
DEBUG: << "x-emc-listable-meta: filename=Test%20New%20Download%20Cloud%20Storage.xlsx[\r][\n]"
DEBUG: << "x-emc-useracl: =FULL_CONTROL[\r][\n]"
DEBUG: << "x-emc-groupacl: other=READ[\r][\n]"
DEBUG: << "x-emc-policy: default[\r][\n]"
DEBUG: << "x-emc-utf8: true[\r][\n]"
DEBUG: << "x-emc-request-id: [\r][\n]"
DEBUG: << "Content-Type: application/octet-stream[\r][\n]"
DEBUG: << "Content-Length: 1219856[\r][\n]"
DEBUG: << "[\r][\n]"
DEBUG: Receiving response: HTTP/1.1 200 OK
DEBUG: << HTTP/1.1 200 OK
DEBUG: << Date: Mon, 09 Jul 2018 21:10:19 GMT
DEBUG: << x-emc-mtime: 1531164643814
DEBUG: << x-emc-meta:
DEBUG: << x-emc-listable-meta: filename=Test%20New%20Download%20Cloud%20Storage.xlsx
DEBUG: << x-emc-useracl: =FULL_CONTROL
DEBUG: << x-emc-groupacl: other=READ
DEBUG: << x-emc-policy: default
DEBUG: << x-emc-utf8: true
DEBUG: << x-emc-request-id:
DEBUG: << Content-Type: application/octet-stream
DEBUG: << Content-Length: 1219856
DEBUG: Connection can be kept alive indefinitely
DEBUG: Connection [id: 1][route: {}->http:// : ] can be kept alive indefinitely
DEBUG: Connection released: [id: 1][route: {}->http:// : ][total kept alive: 1; route allocated: 1 of 200; total allocated: 1 of 200]
And for readObjectStream:
All of the above debug logs plus -
DEBUG: << Content-Type: application/octet-stream
DEBUG: << Content-Length: 1219856
DEBUG: Connection can be kept alive indefinitely
DEBUG: << "PK[0x3][0x4][0x14][0x0][0x8][0x8][0x8][0x0][0xd4]s[0xe9]L[0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x11][0x0][0x0][0x0]docProps/core.xml[0xad][0x91]MK[0xc4]0[0x10][0x86][0xef][0xfd][0x15]![0xf7]v[0xd2][0xad][0xe8][0x1a][0xda].[0xa2],[0x8][0x8a][0xb][0xae]([0xde]B:[0xb6][0xc5][0xe6][0x83]$[0xda][0xf5][0xdf][0x9b][0xed][0xae][0x15][0xc5][0xa3][0xc7][0xc9][0xfb][0xbc][0xf][0xc3][0xa4]\[0xed][0xd4]@[0xde][0xd1][0xf9][0xde][0xe8][0x8a][0xe6][0x19][0xa3][0x4][0xb5]4M[0xaf][0xdb][0x8a]>l[0xd7][0xe9][0x92][0xae][0xea]$)[0xa5]q[0xb8]q[0xc6][0xa2][0xb]=z[0x12][[0xda]W[0xb4][0xb][0xc1]r[0x0]/;T[0xc2]g1[0xd6]1y1N[0x89][0x10]G[0xd7][0x82][0x15][0xf2]U[0xb4][0x8][0xb][0xc6]NAa[0x10][0x8d][0x8][0x2][0xf6][0xb6][0xd4][0xce]:z[0xf0]qi[0xff]][0xd9][0xc8]Yi[0xdf][0xdc]0[0x9][0x1a][0x9]8[0xa0]B[0x1d]<[0xe4]Y[0xe][0xdf]l@[0xa7][0xfc][0x9f][0x85])[0x99][0xc9][0x9d][0xef]gj[0x1c][0xc7]l,&.n[0x94][0xc3][0xd3][0xed][0xcd][0xfd][0xb4]|[0xda]k[0x1f][0x84][0x96]H[0xeb][0x84][0x90][0xf2]h[0xe7][0xd2][0xa1][0x8][0xd8][0x90][0xe8][0xe0][0xe1][0xc3]bE[0xbf][0x92][0xc7][0xe2][0xf2]j[0xbb][0xa6][0xf5][0x82][0xe5][0xcb][0x94][0x9d][0xa5][0xec]|[0x9b][0x9f][0xf0][0x82]qV<[0x97][0xf0][0xab]t[0x1e]F[0xe3][0xea][0x8b]x[0x96][0xe][0xc9][0xe6][0xee]z[0x8f][0xce][0xcf]I[0x9]?[0xbf][0xae]N>[0x1]PK[0x7][0x8][0x9d][0xf0][0x7][0x1e][0x5][0x1][0x0][0x0][0xf4][0x1][0x0][0x0]PK[0x3][0x4][0x14][0x0][0x8][0x8][0x8][0x0][0xd4]s[0xe9]L[0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0xb][0x0][0x0][0x0]_rels/.rels[0xad][0x92][0xc1]N[0xc3]0[0xc][0x86][0xef]}[0x8a]([0xf7][0xd5][0xdd][0x90][0x10]BMwAH[0xbb]Mh<@H[0xdc]6j[0x13]G[0x89][0x7][0xe5][0xed][0x9][0x7][0x4]C[0xc]v[0xe0][0x18][0xe7][0xf7][0xe7]O[0xb2][0xdb][0xed][0xe2]g[0xf1][0x8c]);[\n]"
DEBUG: << "J[0xae][0xeb]F[\n]"
DEBUG: << "[0xc][0x86][0xac][0xb][0x83][0x92][0x8f][0x87][0xfb][0xd5][0x8d][0xdc]vU[0xd5]>[0xe0][0xac][0xb9]d[0xf2][0xe8]b[0x16][0xa5])d%G[0xe6]x[0xb][0x90][0xcd][0x88]^[0xe7][0x9a]"[0x86][0xf2][0xd3]S[0xf2][0x9a][0xcb]3[\r][0x10][0xb5][0x99][0xf4][0x80][0xb0]i[0x9a]kH_[0x19][0xb2][0xab][0x84]8[0xc1][0x8a][0x9d]U2[0xed][0xec]Z[0x8a][0xc3]k[0xc4]K[0xf0][0xd4][0xf7][0xce][0xe0][0x1d][0x99][0xa3][0xc7][0xc0]?L[0xf9][0x96](d[0x9d][0x6]d%[0x97][0x19]^(MODS][0xa0][0x12][0xce][0xea]l[0xfe]S[0x7][0x17][0xc6]`[0xd1][0xae]b*[0xfd][0x89][0x1d][0xe6]O'Kf_[0xca][0x19]t[0x8c]H]].u~[0x5][0xe0][0x91][0xb5][0xd5][0xac][0xc1]P[0xc2][0xdf][0x95][0xde][0x13][0x1f]N-[0x9c]\CW[0xbd][0x1]PK[0x7][0x8]W(^#[0xe3][0x0][0x0][0x0]F[0x2][0x0][0x0]PK[0x3][0x4][0x14][0x0][0x8][0x8][0x8][0x0][0xd4]s[0xe9]L[0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x13][0x0][0x0][0x0][Content_Types].xml[0xad][0x93][0xcb]N[0xc3]0[0x10]E[0xf7][0xf9][\n]"
So basically the API is dumping even the binary content of the file to logs. This debug log is what we want to avoid being written to logs.
In order to fix this we created a log4j.properties file with entries shown below, made sure that the file is getting read properly by removing the entry log4j.appender.A1.layout from the file and we got a warning indicating this entry is missing. When I debug just before calling readObjectStream method the Atmos Client object created was (com.emc.atmos.api.jersey.AtmosApiClient) - So we tried to set the logger level to ERROR for this package - but still we can see all the binary content being dumped to catalina.out!! Any hints to solve this is greatly appreciated!! Thanks in advance.
# Set root logger level to DEBUG and its only appender to A1.
log4j.rootLogger=ERROR, A1
# A1 is set to be a ConsoleAppender.
log4j.appender.A1=org.apache.log4j.ConsoleAppender
# A1 uses PatternLayout.
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n
# Print only messages of level INFO or above in the package com.emc.
log4j.logger.com.emc=ERROR
log4j.logger.com.emc.atmos.api.AtmosApi=ERROR
log4j.logger.com.emc.atmos.api.jersey=ERROR
Jars being used: atmos-client-3.0.1.jar, commons-httpclient-3.0.1.jar, jersey-apache-httpclient4-1.18-CUSTOM.jar
, jersey-client-1.19.jar, jersey-core-1.18.jar
chris_arnett
110 Posts
0
July 10th, 2018 12:00
Those log statements don't match the pattern you've set. It seems you may have some other log configuration active (the Apache httpclient supports a few). Read this, and see if perhaps you have some other log configuration that is setting the root logger to DEBUG level:
https://hc.apache.org/httpcomponents-client-ga/logging.html
SNShiva
7 Posts
0
July 11th, 2018 12:00
Stu Arnett,
I think you are right that there is another log configuration active. We have a custom logging framework which is built on top of log4j which might be causing this. I tried to limit the logging level to ERROR in that configuration as well - which didn't help.
Is there a way we can force Atmos API to use a specific logging configuration? perhaps set some System properties or make sure a specific servlet is loaded first which sets the right logging configurations?
Thanks for taking time to go through this question.
chris_arnett
110 Posts
0
July 12th, 2018 07:00
The above logs are coming from the Apache httpclient library, which we use under the covers for our REST calls. The link above is probably the most relevant to describe the options for configuring its log settings.
You might be able to differentiate the format used by your application log statements and the above statements to find which log framework is being initialized and where it is configured. Maybe it's getting pulled in by a transitive dependency? Maybe there is an environment variable triggering something in the app? Unfortunately, these types of issues are not easy to track down.