Skip to content

Commit dd4cde3

Browse files
nebhalenebhale
committed
Add buildpack debugging documentation
Previously there was no documentation around debugging the buildpack. This lead to having to provide that information on mailing lists and in issues. This change adds documentation about debug logging and running the buildpack locally. [#69986486][resolves #50]
1 parent eb57f60 commit dd4cde3

File tree

3 files changed

+131
-1
lines changed

3 files changed

+131
-1
lines changed

‎README.md

+1
Original file line numberDiff line numberDiff line change
@@ -63,6 +63,7 @@ To learn how to configure various properties of the buildpack, follow the "Confi
6363
* [Logging](docs/extending-logging.md) ([Configuration](docs/extending-logging.md#configuration))
6464
* [Repositories](docs/extending-repositories.md) ([Configuration](docs/extending-repositories.md#configuration))
6565
* [Utiltities](docs/extending-utiltities.md)
66+
* [Debugging the Buildpack](docs/debugging-the-buildpack.md)
6667
* Related Projects
6768
* [Java Buildpack Dependency Builder](https://github.com/cloudfoundry/java-buildpack-dependency-builder)
6869
* [Java Test Applications](https://github.com/cloudfoundry/java-test-applications)

‎docs/debugging-the-buildpack.md

+129
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,129 @@
1+
# Debugging the Buildpack
2+
The buildpack is designed to be easy to configure and extend, but it is still possible that something will go wrong. A configuration property might have an invalid value, or a new component may conflict with an existing one. When these problems happen, the buildpack can tell you quite a bit about what went wrong.
3+
4+
## Debug Logging
5+
By default the buildpack is very quiet, only informing you about big things going right. Behind the scenes however, it logs an incredible amount of information about each attempt at staging. If your application has staged and is running, but not the way you expected it to, you can get the contents of the debug log by running the following command
6+
7+
```bash
8+
cf files <APP> app/.java-buildpack.log
9+
```
10+
11+
If staging fails completely there is no instance that you can query for that file. In that case, you need to cause the [debug logging][d] to print to the console and capture it there. To configure this, run the following command and then push your application again.
12+
13+
```bash
14+
cf set-env <APP> JBP_LOG_LEVEL DEBUG
15+
```
16+
17+
In either case, the output will look like the following:
18+
19+
```text
20+
# Logfile created on 2014-04-25 08:06:06 +0000 by logger.rb/31641
21+
2014-04-25T08:06:06.01+0000 [ConfigurationUtils] DEBUG No configuration file /tmp/buildpacks/java-buildpack/config/version.yml found
22+
2014-04-25T08:06:06.04+0000 [BuildpackVersion] DEBUG 9d0293b | https://github.com/cloudfoundry/java-buildpack#9d0293b
23+
2014-04-25T08:06:06.04+0000 [Buildpack] DEBUG Environment Variables: {"USER"=>"vcap", "VCAP_APPLICATION"=>"{...}", "STAGING_TIMEOUT"=>"900.0", "PATH"=>"/bin:/usr/bin", "PWD"=>"/home/vcap", "VCAP_SERVICES"=>"{...}", "SHLVL"=>"1", "HOME"=>"/home/vcap", "BUILDPACK_CACHE"=>"/var/vcap/packages/buildpack_cache", "DATABASE_URL"=>"", "MEMORY_LIMIT"=>"512m", "_"=>"/usr/bin/ruby"}
24+
2014-04-25T08:06:06.04+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/components.yml: {"containers"=>["JavaBuildpack::Container::DistZip", "JavaBuildpack::Container::Groovy", "JavaBuildpack::Container::JavaMain", "JavaBuildpack::Container::PlayFramework", "JavaBuildpack::Container::Ratpack", "JavaBuildpack::Container::SpringBoot", "JavaBuildpack::Container::SpringBootCLI", "JavaBuildpack::Container::Tomcat"], "jres"=>["JavaBuildpack::Jre::OpenJdkJRE"], "frameworks"=>["JavaBuildpack::Framework::AppDynamicsAgent", "JavaBuildpack::Framework::JavaOpts", "JavaBuildpack::Framework::MariaDbJDBC", "JavaBuildpack::Framework::NewRelicAgent", "JavaBuildpack::Framework::PlayFrameworkAutoReconfiguration", "JavaBuildpack::Framework::PlayFrameworkJPAPlugin", "JavaBuildpack::Framework::PostgresqlJDBC", "JavaBuildpack::Framework::SpringAutoReconfiguration", "JavaBuildpack::Framework::SpringInsight"]}
25+
2014-04-25T08:06:06.04+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Jre::OpenJdkJRE
26+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Jre::OpenJdkJRE
27+
2014-04-25T08:06:06.10+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/open_jdk_jre.yml: {"repository_root"=>"{default.repository.root}/openjdk/{platform}/{architecture}", "version"=>"1.7.0_+", "memory_sizes"=>{"permgen"=>"64m.."}, "memory_heuristics"=>{"heap"=>75, "permgen"=>10, "stack"=>5, "native"=>10}}
28+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::AppDynamicsAgent
29+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::AppDynamicsAgent
30+
2014-04-25T08:06:06.10+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/app_dynamics_agent.yml: {"version"=>"3.7.+", "repository_root"=>"{default.repository.root}/app-dynamics", "tier_name"=>"Cloud Foundry"}
31+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::JavaOpts
32+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::JavaOpts
33+
2014-04-25T08:06:06.10+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/java_opts.yml: {"from_environment"=>true}
34+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::MariaDbJDBC
35+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::MariaDbJDBC
36+
2014-04-25T08:06:06.10+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/maria_db_jdbc.yml: {"version"=>"1.1.+", "repository_root"=>"{default.repository.root}/mariadb-jdbc"}
37+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::NewRelicAgent
38+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::NewRelicAgent
39+
2014-04-25T08:06:06.10+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/new_relic_agent.yml: {"version"=>"3.6.+", "repository_root"=>"{default.repository.root}/new-relic"}
40+
2014-04-25T08:06:06.10+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::PlayFrameworkAutoReconfiguration
41+
2014-04-25T08:06:06.11+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::PlayFrameworkAutoReconfiguration
42+
2014-04-25T08:06:06.11+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/play_framework_auto_reconfiguration.yml: {"version"=>"0.+", "repository_root"=>"{default.repository.root}/auto-reconfiguration"}
43+
2014-04-25T08:06:06.11+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::PlayFrameworkJPAPlugin
44+
2014-04-25T08:06:06.11+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::PlayFrameworkJPAPlugin
45+
2014-04-25T08:06:06.11+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/play_framework_jpa_plugin.yml: {"version"=>"0.+", "repository_root"=>"{default.repository.root}/play-jpa-plugin"}
46+
2014-04-25T08:06:06.12+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::PostgresqlJDBC
47+
2014-04-25T08:06:06.12+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::PostgresqlJDBC
48+
2014-04-25T08:06:06.12+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/postgresql_jdbc.yml: {"version"=>"9.3.+", "repository_root"=>"{default.repository.root}/postgresql-jdbc"}
49+
2014-04-25T08:06:06.12+0000 [Buildpack] DEBUG Instantiating JavaBuildpack::Framework::SpringAutoReconfiguration
50+
2014-04-25T08:06:06.15+0000 [Buildpack] DEBUG Successfully required JavaBuildpack::Framework::SpringAutoReconfiguration
51+
2014-04-25T08:06:06.15+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/spring_auto_reconfiguration.yml: {"version"=>"0.+", "repository_root"=>"{default.repository.root}/auto-reconfiguration"}
52+
2014-04-25T08:06:06.15+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/repository.yml: {"default_repository_root"=>"http://download.run.pivotal.io"}
53+
2014-04-25T08:06:06.21+0000 [RepositoryIndex] DEBUG {default.repository.root}/auto-reconfiguration expanded to http://download.run.pivotal.io/auto-reconfiguration
54+
2014-04-25T08:06:06.21+0000 [ConfigurationUtils] DEBUG Configuration from /tmp/buildpacks/java-buildpack/config/cache.yml: {"remote_downloads"=>"enabled"}
55+
2014-04-25T08:06:06.22+0000 [DownloadCache] DEBUG Proxy: , , ,
56+
2014-04-25T08:06:06.24+0000 [DownloadCache] DEBUG HTTP: download.run.pivotal.io, 80, {:read_timeout=>10, :connect_timeout=>10, :open_timeout=>10, :use_ssl=>false}
57+
2014-04-25T08:06:06.24+0000 [DownloadCache] DEBUG Request: /auto-reconfiguration/index.yml, {"accept"=>["*/*"], "user-agent"=>["Ruby"]}
58+
2014-04-25T08:06:06.24+0000 [DownloadCache] DEBUG Status: 200
59+
2014-04-25T08:06:06.24+0000 [DownloadCache] DEBUG Persisting etag: "d093ebc9c94d3050c28898585611701c"
60+
2014-04-25T08:06:06.25+0000 [DownloadCache] DEBUG Persisting last-modified: Thu, 24 Apr 2014 10:47:19 GMT
61+
2014-04-25T08:06:06.25+0000 [DownloadCache] DEBUG Persisting content to /tmp/http:%2F%2Fdownload.run.pivotal.io%2Fauto-reconfiguration%2Findex.yml.cached
62+
2014-04-25T08:06:06.25+0000 [DownloadCache] DEBUG Validated content size 1174 is 1174
63+
2014-04-25T08:06:06.25+0000 [RepositoryIndex] DEBUG {"0.6.8"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.6.8.jar", "0.7.0"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.7.0.jar", "0.7.1"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.7.1.jar", "0.7.2"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.7.2.jar", "0.8.0"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.0.jar", "0.8.1"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.1.jar", "0.8.2"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.2.jar", "0.8.3"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.3.jar", "0.8.4"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.4.jar", "0.8.5"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.5.jar", "0.8.6"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.6.jar", "0.8.7"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.7.jar", "0.8.8"=>"http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.8.jar"}
64+
65+
...
66+
67+
2014-04-25T08:06:08.83+0000 [MemoryBucket] DEBUG #<JavaBuildpack::Jre::MemoryBucket:0x000000020e57c0 @name="heap", @weighting=75, @range=0..>
68+
2014-04-25T08:06:08.83+0000 [MemoryBucket] DEBUG #<JavaBuildpack::Jre::MemoryBucket:0x000000020ed510 @name="permgen", @weighting=10, @range=64M..>
69+
2014-04-25T08:06:08.83+0000 [MemoryBucket] DEBUG #<JavaBuildpack::Jre::StackMemoryBucket:0x000000020ec9a8 @name="stack", @weighting=5, @range=0..>
70+
2014-04-25T08:06:08.84+0000 [MemoryBucket] DEBUG #<JavaBuildpack::Jre::MemoryBucket:0x000000020ebf30 @name="native", @weighting=10, @range=0..>
71+
2014-04-25T08:06:08.84+0000 [MemoryBucket] DEBUG #<JavaBuildpack::Jre::MemoryBucket:0x000000020ea568 @name="normalised stack", @weighting=5, @range=0..>
72+
2014-04-25T08:06:08.84+0000 [Buildpack] DEBUG Release Payload
73+
---
74+
addons: []
75+
config_vars: {}
76+
default_process_types:
77+
web: JAVA_HOME=$PWD/.java-buildpack/open_jdk_jre JAVA_OPTS="-Djava.io.tmpdir=$TMPDIR
78+
-XX:OnOutOfMemoryError=$PWD/.java-buildpack/open_jdk_jre/bin/killjava.sh -Xmx382293K
79+
-Xms382293K -XX:MaxPermSize=64M -XX:PermSize=64M -Xss995K -Dalpha=bravo -Dhttp.port=$PORT"
80+
$PWD/.java-buildpack/tomcat/bin/catalina.sh run
81+
```
82+
83+
The example content here has been trimmed so that it's not overwhelming, but nearly every component in the buildpack will output something useful as it works.
84+
85+
## Running the Buildpack Locally
86+
Sometimes logging just isn't going to cut it for debugging. There are times when using a debugger or a local filesystem is the only way to diagnose problems. A simple and surprisingly effective way of troubleshooting buildpacks is actually to skip all of Cloud Foundry and run the buildpack locally. The buildpack API consists of three bash scripts. This means that if you've got a filesystem that looks like what Cloud Foundry will be presented plus a local copy of your buildpack, you can run the bash scripts locally. You might see something like this:
87+
88+
```bash
89+
$ mkdir -p target/exploded
90+
$ cd target/exploded
91+
$ jar xf ../web-application-1.0.0-BUILD-SNAPSHOT.war
92+
93+
$ <BUILDPACK-CLONE>/bin/detect .
94+
java-buildpack=ded1e56-https://github.com/cloudfoundry/java-buildpack#ded1e56 open-jdk-jre=1.7.0_51 spring-auto-reconfiguration=0.8.7 tomcat-instance=7.0.53 tomcat-lifecycle-support=2.1.0_RELEASE tomcat-logging-support=2.1.0_RELEASE
95+
96+
$ <BUILDPACK-CLONE>/bin/compile . $TMPDIR
97+
-----> Java Buildpack Version: ded1e56 | https://github.com/cloudfoundry/java-buildpack#ded1e56
98+
-----> Downloading Open Jdk JRE 1.7.0_51 from http://download.run.pivotal.io/openjdk/mountainlion/x86_64/openjdk-1.7.0_51.tar.gz (5.0s)
99+
Expanding Open Jdk JRE to .java-buildpack/open_jdk_jre (0.4s)
100+
-----> Downloading Spring Auto Reconfiguration 0.8.7 from http://download.run.pivotal.io/auto-reconfiguration/auto-reconfiguration-0.8.7.jar (0.3s)
101+
Modifying /WEB-INF/web.xml for Auto Reconfiguration
102+
-----> Downloading Tomcat Instance 7.0.53 from http://download.run.pivotal.io/tomcat/tomcat-7.0.53.tar.gz (1.1s)
103+
Expanding Tomcat to .java-buildpack/tomcat (0.0s)
104+
-----> Downloading Tomcat Lifecycle Support 2.1.0_RELEASE from http://download.run.pivotal.io/tomcat-lifecycle-support/tomcat-lifecycle-support-2.1.0_RELEASE.jar (0.2s)
105+
-----> Downloading Tomcat Logging Support 2.1.0_RELEASE from http://download.run.pivotal.io/tomcat-logging-support/tomcat-logging-support-2.1.0_RELEASE.jar (0.1s)
106+
107+
$ <BUILDPACK-CLONE>/bin/release .
108+
---
109+
addons: []
110+
config_vars: {}
111+
default_process_types:
112+
web: JAVA_HOME=$PWD/.java-buildpack/open_jdk_jre JAVA_OPTS="-Djava.io.tmpdir=$TMPDIR
113+
-XX:OnOutOfMemoryError=$PWD/.java-buildpack/open_jdk_jre/bin/killjava.sh -XX:MaxPermSize=64M
114+
-XX:PermSize=64M -Dhttp.port=$PORT" $PWD/.java-buildpack/tomcat/bin/catalina.sh
115+
run
116+
117+
$ JAVA_HOME=$PWD/.java-buildpack/open_jdk_jre JAVA_OPTS="-Djava.io.tmpdir=$TMPDIR -XX:OnOutOfMemoryError=$PWD/.java-buildpack/open_jdk_jre/bin/killjava.sh -XX:MaxPermSize=64M -XX:PermSize=64M -Dhttp.port=$PORT" $PWD/.java-buildpack/tomcat/bin/catalina.sh run
118+
...
119+
```
120+
121+
You must be careful that path you run from is the same as the path Cloud Foundry will be presented with. In the case of an exploded filesystem, nothing is different. However, when pushing an archive (e.g. `JAR`, `WAR`, `ZIP`) Cloud Foundry presents the buildpack with an exploded copy of that archive and you must do the same. As described in the **Debug Logging** section above, both file and console debug output are available. To get console output you run the commands as follows:
122+
123+
```bash
124+
JBP_LOG_LEVEL=DEBUG <BUILDPACK-CLONE>/bin/detect .
125+
JBP_LOG_LEVEL=DEBUG <BUILDPACK-CLONE>/bin/compile . $TMPDIR
126+
JBP_LOG_LEVEL=DEBUG <BUILDPACK-CLONE>/bin/release .
127+
```
128+
129+
[d]: extending-logging.md#configuration

‎lib/java_buildpack/buildpack.rb

+1-1
Original file line numberDiff line numberDiff line change
@@ -82,7 +82,7 @@ def release
8282
'default_process_types' => { 'web' => command }
8383
}.to_yaml
8484

85-
@logger.debug { "Release Payload #{payload}" }
85+
@logger.debug { "Release Payload\n#{payload}" }
8686

8787
payload
8888
end

0 commit comments

Comments
 (0)