IBM Bluemix 環境に cf ツールでアプリケーションを push した後にログが表示されますが・・・
2015021601



このログを詳しく調べて、「コマンド実行後に何をやっているのか?」の説明をします。

なお、今回の説明内容の前提として、2015/02/16 時点の、Liberty Java アプリケーション(war ファイル)1インスタンスをデプロイしています。このアプリケーションでは MySQL をデータストアとしてバインドしています。その条件下でのログを紹介します:

まずログ全文はこんな感じです:
$ cf push dotnsf-20150212 -p GeoImgWeb.war
Updating app dotnsf-20150212 in org (ユーザー名) / space dev as (ユーザー名)...
OK

Uploading dotnsf-20150212...
Uploading app files from: GeoImgWeb.war
Uploading 2.4M, 258 files
Done uploading
OK

Stopping app dotnsf-20150212 in org (ユーザー名) / space dev as (ユーザー名)...
OK

Starting app dotnsf-20150212 in org (ユーザー名) / space dev as (ユーザー名)...
-----> Downloaded app buildpack cache (224K)
-----> Retrieving IBM 1.7.1_sr2fp1ifx-20141220 JRE (ibm-java-jre-7.1-2.1-pxa6470
_27sr2fp1ifx-20141220_02-sfj.tgz) ... (0.0s)
         Expanding JRE to .java ... (0.8s)
-----> Retrieving App Management Agent 2015.02.04_102631 (com.ibm.ws.cloudoe.app
-mgmt-proxy-agent.zip) ... (0.0s)
         Expanding App Management to .app-management (0.0s)
-----> Downloading and installing client jar(s) from https://download.run.pivota
l.io/mariadb-jdbc/mariadb-jdbc-1.1.8.jar (0.0s)
-----> Auto-configuration is creating config for service instance 'mysql-x3' of
type 'mysql'
-----> Liberty buildpack is done creating the droplet



-----> Uploading droplet (116M)

0 of 1 instances running, 1 starting
1 of 1 instances running

App started


OK

App dotnsf-20150212 was started using this command `.liberty/initial_startup.rb`


Showing health and status for app dotnsf-20150212 in org (ユーザー名) / spa
ce dev as (ユーザー名)...
OK

requested state: started
instances: 1/1
usage: 512M x 1 instances
urls: dotnsf-20150212.eu-gb.mybluemix.net
package uploaded: Mon Feb 16 01:15:44 +0000 2015

     state     since                    cpu    memory           disk
#0   running   2015-02-16 10:16:46 AM   2.8%   149.4M of 512M   182M of 1G

$ 

まず、push コマンド:
$ cf push dotnsf-20150212 -p GeoImgWeb.war

で「dotnsf-20150212 という Bluemix アプリケーションに、GeoImgWeb.war という Java アプリケーションをデプロイする」という命令をしています。この GeoImgWeb.war はカレントディレクトリに存在しているものとします。

その直後のログは以下のようになっています:
Updating app dotnsf-20150212 in org (ユーザー名) / space dev as (ユーザー名)...
OK

Uploading dotnsf-20150212...
Uploading app files from: GeoImgWeb.war
Uploading 2.4M, 258 files
Done uploading
OK

Stopping app dotnsf-20150212 in org (ユーザー名) / space dev as (ユーザー名)...
OK

デプロイ先のアプリケーションを更新するため、GeoImgWeb.war をアップロードして、そして dotnsf-20150212 を一旦停止しています。ここまではまあ一般的というか、Bluemix / Cloud Foundry 環境に特化した内容ではないのでわかりやすいと思います。

この後から少し特殊な処理になります:
Starting app dotnsf-20150212 in org (ユーザー名) / space dev as (ユーザー名)...
-----> Downloaded app buildpack cache (224K)
-----> Retrieving IBM 1.7.1_sr2fp1ifx-20141220 JRE (ibm-java-jre-7.1-2.1-pxa6470
_27sr2fp1ifx-20141220_02-sfj.tgz) ... (0.0s)
         Expanding JRE to .java ... (0.8s)
-----> Retrieving App Management Agent 2015.02.04_102631 (com.ibm.ws.cloudoe.app
-mgmt-proxy-agent.zip) ... (0.0s)
         Expanding App Management to .app-management (0.0s)
-----> Downloading and installing client jar(s) from https://download.run.pivota
l.io/mariadb-jdbc/mariadb-jdbc-1.1.8.jar (0.0s)
-----> Auto-configuration is creating config for service instance 'mysql-x3' of
type 'mysql'
-----> Liberty buildpack is done creating the droplet

dotnsf-20150212 を起動する処理の中身です。Java アプリケーションとしての基板となる Liberty Buildpack をダウンロードし、IBM Java 1.7.1 & App Management Agent & MariaDB JDBC 1.1.8 を続けてビルド(実際にはダウンロード)しています。これらはビルドパック内で定義されている処理です。これで droplet と呼ばれる実行可能なアプリケーションが作成されます。

その後、作成した droplet をアップロードしてアプリケーションインスタンスを起動します。ここでちょっと時間がかかります:
-----> Uploading droplet (116M)

0 of 1 instances running, 1 starting
1 of 1 instances running

App started

OK

実はここまでの段階でアプリケーションとしては利用可能になっています。最後にアプリケーションやサーバーリソースの状態を確認するためのコマンドが実行され、その結果が表示されています:
App dotnsf-20150212 was started using this command `.liberty/initial_startup.rb`


Showing health and status for app dotnsf-20150212 in org (ユーザー名) / spa
ce dev as (ユーザー名)...
OK

requested state: started
instances: 1/1
usage: 512M x 1 instances
urls: dotnsf-20150212.eu-gb.mybluemix.net
package uploaded: Mon Feb 16 01:15:44 +0000 2015

     state     since                    cpu    memory           disk
#0   running   2015-02-16 10:16:46 AM   2.8%   149.4M of 512M   182M of 1G

CPU やメモリ、ディスクリソースの状態と合わせてアプリケーションの状態が最後に表示されています。この例ではサーバーは1インスタンスなので1行だけで表示されていますが、複数インスタンスで起動している場合は複数行の結果になります。