Hi, this is just a quick post to share a particularly helpful method for troubleshooting issues between a Java client application and the HCP S3 Gateway. Most Java based software will allow you to inject Java System Properties at launch time, either by editing a configuration file or a launch script. This post does not cover how to achieve that step, to answer that question use the product documentation, Google, or ask their support team.
If you will be adding Java system properties by configuration you want to add the followinq name value pair (choose the correct value for your system type):
| Name |
Value |
| log4j.configuration |
file:///home/user/log4j.properties
file://C:/users/user/log4j.properties |
If you will be adding the system property by modifying the JVM launch script you will want to add the following to the JVM launch:
-Dlog4j.configuration="file:///home/user/log4j.properties"
Finally you will want to create the file log4j.properties with the following contents. This will log to both a file and to stdout, you can remove either file or stdout from the log4j.rootLogger directive to eliminate one or the other. Make sure that you modify the log4j.appender.file.File directive to indicate the desired output file location.
# Root logger option
log4j.rootLogger=INFO, stdout, file
# Class Level Logging Directives
log4j.logger.com.amazonaws=DEBUG
log4j.logger.org.apache.http=DEBUG
# Direct log messages to stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
# Direct log messages to a log file
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=/home/user/log4j.out
log4j.appender.file.MaxFileSize=100MB
log4j.appender.file.MaxBackupIndex=1
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
The properties file above turns AWS and http logging up and will provide detailed output on all the data sent and recieved by the SDK as well as information about how the SDK is calculating the V2 or V4 signature. Here is an example of debug output for a S3 create bucket request. Keep in mind Jive may have changed a bit of content here and there.
2018-09-13 09:01:01,881 [main] DEBUG com.amazonaws.AmazonWebServiceClient - Internal logging successfully configured to commons logger: true
2018-09-13 09:01:01,931 [main] DEBUG com.amazonaws.metrics.AwsSdkMetrics - Admin mbean registered under com.amazonaws.management:type=AwsSdkMetrics
Creating bucket bc1
2018-09-13 09:01:02,120 [main] DEBUG com.amazonaws.request - Sending Request: PUT http://bc1.ten.cluster55w-1.lab.archivas.com / Headers: (User-Agent: aws-sdk-java/1.11.84 Linux/4.8.6-300.fc25.x86_64 OpenJDK_64-Bit_Server_VM/25.121-b14/1.8.0_121, amz-sdk-invocation-id: b6959e76-3a13-70c0-8406-6dd42df586b5, Content-Type: application/octet-stream, )
2018-09-13 09:01:02,149 [main] DEBUG com.amazonaws.services.s3.internal.S3Signer - Calculated string to sign:
"PUT
application/octet-stream
Thu, 13 Sep 2018 13:01:02 GMT
/bc1/"
2018-09-13 09:01:02,169 [main] DEBUG org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: default
2018-09-13 09:01:02,176 [main] DEBUG org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
2018-09-13 09:01:02,177 [main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager - Connection request: [route: {}->http://bc1.ten.cluster55w-1.lab.archivas.com:80][total kept alive: 0; route allocated: 0 of 200; total allocated: 0 of 200]
2018-09-13 09:01:02,189 [main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager - Connection leased: [id: 0][route: {}->http://bc1.ten.cluster55w-1.lab.archivas.com:80][total kept alive: 0; route allocated: 1 of 200; total allocated: 1 of 200]
2018-09-13 09:01:02,191 [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Opening connection {}->http://bc1.ten.cluster55w-1.lab.archivas.com:80
2018-09-13 09:01:02,198 [main] DEBUG org.apache.http.impl.conn.DefaultHttpClientConnectionOperator - Connecting to bc1.ten.cluster55w-1.lab.archivas.com/172.20.55.138:80
2018-09-13 09:01:02,201 [main] DEBUG org.apache.http.impl.conn.DefaultHttpClientConnectionOperator - Connection established 172.18.25.3:53034<->172.20.55.138:80
2018-09-13 09:01:02,201 [main] DEBUG org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-0: set socket timeout to 50000
2018-09-13 09:01:02,201 [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Executing request PUT / HTTP/1.1
2018-09-13 09:01:02,201 [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Proxy auth state: UNCHALLENGED
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> PUT / HTTP/1.1
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Host: bc1.ten.cluster55w-1.lab.archivas.com
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Authorization: AWS ZGV2:ma3WomzhOJfQ42bDxlQilmbxVxA=
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> User-Agent: aws-sdk-java/1.11.84 Linux/4.8.6-300.fc25.x86_64 OpenJDK_64-Bit_Server_VM/25.121-b14/1.8.0_121
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> amz-sdk-invocation-id: b6959e76-3a13-70c0-8406-6dd42df586b5
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> amz-sdk-retry: 0/0/500
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Date: Thu, 13 Sep 2018 13:01:02 GMT
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Content-Type: application/octet-stream
2018-09-13 09:01:02,203 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Content-Length: 0
2018-09-13 09:01:02,204 [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Connection: Keep-Alive
2018-09-13 09:01:02,204 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "PUT / HTTP/1.1[\r][\n]"
2018-09-13 09:01:02,204 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "Host: bc1.ten.cluster55w-1.lab.archivas.com[\r][\n]"
2018-09-13 09:01:02,204 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "Authorization: AWS ZGV2:ma3WomzhOJfQ42bDxlQilmbxVxA=[\r][\n]"
2018-09-13 09:01:02,205 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "User-Agent: aws-sdk-java/1.11.84 Linux/4.8.6-300.fc25.x86_64 OpenJDK_64-Bit_Server_VM/25.121-b14/1.8.0_121[\r][\n]"
2018-09-13 09:01:02,206 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "amz-sdk-invocation-id: b6959e76-3a13-70c0-8406-6dd42df586b5[\r][\n]"
2018-09-13 09:01:02,206 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "amz-sdk-retry: 0/0/500[\r][\n]"
2018-09-13 09:01:02,206 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "Date: Thu, 13 Sep 2018 13:01:02 GMT[\r][\n]"
2018-09-13 09:01:02,206 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Type: application/octet-stream[\r][\n]"
2018-09-13 09:01:02,207 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Length: 0[\r][\n]"
2018-09-13 09:01:02,207 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
2018-09-13 09:01:02,207 [main] DEBUG org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
2018-09-13 09:01:02,210 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
2018-09-13 09:01:02,210 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Date: Thu, 13 Sep 2018 13:01:03 GMT[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Pragma: no-cache[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Cache-Control: no-cache,no-store,must-revalidate[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "X-Content-Type-Options: nosniff[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "X-DNS-Prefetch-Control: off[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "X-Download-Options: noopen[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "X-Frame-Options: SAMEORIGIN[\r][\n]"
2018-09-13 09:01:02,211 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "X-XSS-Protection: 1; mode=block[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Content-Security-Policy: default-src 'self'; script-src 'self' 'unsafe-eval' 'unsafe-inline'; connect-src 'self'; img-src 'self'; style-src 'self' 'unsafe-inline'; object-src 'self'; frame-ancestors 'self';[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Strict-Transport-Security: max-age=31536000; includeSubDomains[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Expires: Thu, 01 Jan 1970 00:00:00 GMT[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Location: /bc1[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Content-Type: application/xml;charset=UTF-8[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "Transfer-Encoding: chunked[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "12E[\r][\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << " BucketAlreadyOwnedByYou[\n]"
2018-09-13 09:01:02,212 [main] DEBUG org.apache.http.wire - http-outgoing-0 << " Your previous request to create the named bucket succeeded and you already own it[\n]"
2018-09-13 09:01:02,213 [main] DEBUG org.apache.http.wire - http-outgoing-0 << " 1536843663173[\n]"
2018-09-13 09:01:02,213 [main] DEBUG org.apache.http.wire - http-outgoing-0 << " Y2x1c3RlcjU1dy0xLmxhYi5hcmNoaXZhcy5jb206MTM4[\n]"
2018-09-13 09:01:02,213 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\n]"
2018-09-13 09:01:02,213 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\n]"
2018-09-13 09:01:02,213 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << HTTP/1.1 200 OK
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Date: Thu, 13 Sep 2018 13:01:03 GMT
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Pragma: no-cache
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Cache-Control: no-cache,no-store,must-revalidate
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << X-Content-Type-Options: nosniff
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << X-DNS-Prefetch-Control: off
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << X-Download-Options: noopen
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << X-Frame-Options: SAMEORIGIN
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << X-XSS-Protection: 1; mode=block
2018-09-13 09:01:02,215 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Content-Security-Policy: default-src 'self'; script-src 'self' 'unsafe-eval' 'unsafe-inline'; connect-src 'self'; img-src 'self'; style-src 'self' 'unsafe-inline'; object-src 'self'; frame-ancestors 'self';
2018-09-13 09:01:02,216 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Strict-Transport-Security: max-age=31536000; includeSubDomains
2018-09-13 09:01:02,216 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Expires: Thu, 01 Jan 1970 00:00:00 GMT
2018-09-13 09:01:02,216 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Location: /bc1
2018-09-13 09:01:02,216 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Content-Type: application/xml;charset=UTF-8
2018-09-13 09:01:02,216 [main] DEBUG org.apache.http.headers - http-outgoing-0 << Transfer-Encoding: chunked
2018-09-13 09:01:02,221 [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Connection can be kept alive for 60000 MILLISECONDS
2018-09-13 09:01:02,224 [main] DEBUG com.amazonaws.request - Received successful response: 200, AWS Request ID: null
2018-09-13 09:01:02,225 [main] DEBUG com.amazonaws.requestId - x-amzn-RequestId: not available
2018-09-13 09:01:02,225 [main] DEBUG com.amazonaws.requestId - AWS Request ID: not available
2018-09-13 09:01:02,225 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "0[\r][\n]"
2018-09-13 09:01:02,225 [main] DEBUG org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
2018-09-13 09:01:02,225 [main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager - Connection [id: 0][route: {}->http://bc1.ten.cluster55w-1.lab.archivas.com:80] can be kept alive for 60.0 seconds
2018-09-13 09:01:02,226 [main] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager - Connection released: [id: 0][route: {}->http://bc1.ten.cluster55w-1.lab.archivas.com:80][total kept alive: 1; route allocated: 1 of 200; total allocated: 1 of 200]
Hope this helps you next time you can't figure out why you can't get your client talking to HCP or trying to figure out why a request is failing.