[upki-fed:00517] IdPが起動しません（テストフェデレーション）

[Akazawa TS <xxxxxxxx@xxxxxxxxxxxxxx>]

UPKI-fed ML の皆様

　いつもお世話になっております。
　都医学研の赤沢です。

　テスト用にIdPサーバを立ち上げ、テストフェデレーションに
　参加させていただいたところです。ところが、（立ち上げたと
　申し上げましたが）IdPサーバが立ち上がらず苦戦しております。
　以下に状況説明をさせていただきますので、大変恐れ入りますが、
　「○○を調べてみよ」とか「○○はどうなっているんだ」という
　ようなアドバイスをいただけないでしょうか。

　よろしくお願い致します。

1. 当方環境

　サーバ CPU: CoreDuo T2500 (32bit)
　OS: CentOS 5.5
　Apache HTTP Server: 2.2.3
　OpenLDAP: 2.3.43（ダミーの職員データを登録してあります）
　JDK: jdk-6u37-linux-i586-rpm.bin をダウンロードしてインストール。
　tomcat: apache-tomcat-6.0.35.tar.gz 同上。
　shibboleth: shibboleth-identityprovider-2.3.8-bin.zip 同上。
　shibboleth-jce-1.1.0.jar: [upki-fed:00513]で教えていただいたサイト
　　　　　　　　　　　　　　より入手。
　サーバ証明書:　IdPサーバ自体をCAとし、自己署名のサーバ証明書を使用。

　クライアント側環境： Firefox 16.0.2 on MacOS X 10.7.5

　IdPサーバの構築は、学認公式サイトの「技術ガイド」→「貴学にて
　IdPをインストールする場合の構築手順」に準じて行いました。
　また、「設定・運用・カスタマイズ」のページにも従い、設定致しました。
　https://www.gakunin.jp/docs/fed/technical

　構築作業は、すべて root 権限で実施しました。

　サーバローカルから、また、リモートからも ldapsearchコマンドにて
　LDAP内のダミー職員データを検索できています。

　tomcat6に付属のサンプルプログラムはちゃんと動作しています。
　サンプルプログラムとは、Servelet の "Hello World" とか、
　JSP の "Basic Arithmetic" とかのことです。


2. 症状

　●発症に至る手順
　　1) Firefoxにて test-sp1 にアクセス
　　　　→　「接続テスト」ボタンをクリック

　　2) 所属機関として「東京都医学総合研究所」を選択
　　　　→「選択」ボタンをクック

　　　　※「□ブラウザ起動中は自動ログイン」と
　　　　　「□選択した所属機関を保存して今後IdPの選択画面を
　　　　　　スキップする」のチェックははずしてあります。

　　3) 当方の IdPサーバにリダイレクトされるが、以下のような
　　　404エラーの画面となる。
-----------------------------------------------------------------------
HTTP Status 404 -

type Status report

message

description The requested resource () is not available.
Apache Tomcat/6.0.35
-----------------------------------------------------------------------


3. IdPサーバのログ

　https://www.gakunin.jp/docs/fed/technical/idp/customize/test-connect
　↑の「1. httpdとTomcatの再起動」の時点で不審なログが残っていました。

　「service tomcat6 start」を実行した時点における、
　/usr/java/tomcat/logs/catalina.out の中身（エラー的なもの）を以下に
　示します。
-----------------------------------------------------------------------
Nov 1, 2012 3:39:13 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal
performance in production environments was not found on the
java.library.path:
/usr/java/jdk1.6.0_37/jre/lib/i386/server:/usr/java/jdk1.6.0_37/jre/lib/i386:/usr/java/jdk1.6.0_37/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
Nov 1, 2012 3:39:19 PM org.apache.catalina.core.StandardContext start
SEVERE: Error listenerStart
Nov 1, 2012 3:39:19 PM org.apache.catalina.core.StandardContext start
SEVERE: Context [/idp] startup failed due to previous errors
-----------------------------------------------------------------------
　※最後の行にあるように、idpが起動していません。その原因は
　　「SEVERE: Error listenerStart」によるものであることがわかります。

　Googleで「SEVERE: Error listenerStart」を検索してみますと、
　/usr/java/tomcat/webapps/idp/WEB-INF/classes/フォルダを作り、
　logging.propertiesファイルを作ように書いている人がいました。
　その中身は以下のとおりということなので、そのとおりにしてみました。
-----------------------------------------------------------------------
org.apache.catalina.core.ContainerBase.[Catalina].level = INFO
org.apache.catalina.core.ContainerBase.[Catalina].handlers =
java.util.logging.ConsoleHandler
-----------------------------------------------------------------------
　※自動で折り返されるかもしれませんが、実際には org. で始まる、２行
　　です。
　　http://stufftohelpyouout.blogspot.jp/2011/10/tomcat-6-severe-error-
listenerstart-how.html

　この状態で、再度tomcat6を起動するとより詳細なログが得られるとの
　ことなので、次の３個のコマンドを実行しました。
# service tomcat6 stop
# service httpd restart
# service tomcat6 start

　そして、「service tomcat6 start」時の、
　/usr/java/tomcat/logs/catalina.out の中身（エラー的なもの）は次の
　ようにより詳細なものとなりました。

-----------------------------------------------------------------------
Nov 1, 2012 3:59:04 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal
performance in production environments was not found on the
java.library.path:
/usr/java/jdk1.6.0_37/jre/lib/i386/server:/usr/java/jdk1.6.0_37/jre/lib/i386:/usr/java/jdk1.6.0_37/jre/../lib/i386:/usr/java/
Nov 1, 2012 3:59:09 PM org.apache.catalina.core.StandardContext
listenerStart
SEVERE: Exception sending context initialized event to listener instance
of class org.springframework.web.context.ContextLoaderListener
org.springframework.beans.factory.BeanCreationException: Error creating
bean with name 'shibboleth.AttributeResolver': Invocation of init method
failed; nested exception is
edu.internet2.middleware.shibboleth.common.service.ServiceException:
Configuration was not loaded for shibboleth.AttributeResolver service,
error creating components.
        at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1338)
        at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:473)
   ・・・・・・・・・・・・・・・・・・延々と "at" で始まるエラー
Nov 1, 2012 3:59:09 PM org.apache.catalina.core.StandardContext start
SEVERE: Error listenerStart
Nov 1, 2012 3:59:09 PM org.apache.catalina.core.StandardContext start
SEVERE: Context [/idp] startup failed due to previous errors
-----------------------------------------------------------------------
　これを見ますと、上から２個目の「Nov 1」で始まる行からのエラーの中に
　「Error creating bean with name 'shibboleth.AttributeResolver':
Invocation of init method failed」とあります。

　ここで私の原因追求は頓挫しております。。。


4. 技術ガイドと異なる設定

　当方の環境では次の点が技術ガイドと異なります。

　[attribute-resolver.xml]は次のように値をセットしました。
　　ldapURL="ldap://localhost"
　　baseDN="dc=igakuken,dc=or,dc=jp"
　　principal="cn=******,ou=******"
　　principalCredential="**********"

　　※*印は伏せ字です。
　　　LDAPには cn=******,ou=******,dc=igakuken,dc=or,dc=jp が
　　　接続します。ローカルやリモートから ldapsearch コマンドでは
　　　接続できています。

　　　技術ガイドでは baseDNの値の末尾が「c=JP」とありましたので
　　　baseDN="dc=igakuken,dc=or,c=JP" の場合も試しましたが、状況は
　　　以上で申し上げた内容と同一でした。

　[attribute-filter.xml]
　　技術ガイドでは test-sp1 だけを有効化していますが、
　　当方では test-sp1 に加え、test-sp2 も有効化しました。

　[サーバ証明書の取得とApacheの設定]
　　https://www.gakunin.jp/docs/fed/technical/idp/customize/certpj-metadata
　　自己署名証明書を使いました。
　　※UPKIオープンドメイン証明書自動発行検証プロジェクトには
　　　10月下旬に参加承認が降りましたが、まだ承認書が届いた段階で
　　　あり、その後の参加手順が進んでいない状況です。

　　/etc/httpd/conf.d/ssl.conf の
　　SSLCertificateChainFileは値を指定していません。

　[Back-Channelの設定]
　　当方では未設定です。

以上です。
どうかよろしくお願い致します。

--
公益財団法人東京都医学総合研究所 情報システム室
赤沢年一