trouble shooting

Tomcatのcatalina.outが「java.util.zip.ZipException: error in opening zip file」で溢れかえった原因はAppleDouble

投稿日:2019年8月10日

事象

ある日、共有development環境として使っているCentOSのディスク使用率がどんどん増えていってることに気づきました。

増加原因になっていたTomcat8.5.32のログファイルcatalina.outを見ると、warファイルをデプロイする度に「ZIPファイルが開けない」旨の例外が発生しています。

08-Aug-2019 14:41:43.557 情報 [localhost-startStop-8] org.apache.catalina.startup.HostConfig.deployWAR Webアプリケーショ
ンアーカイブ [/usr/local/apache-tomcat-8.5.32/webapps/xxxxxx.war] を配備します
08-Aug-2019 14:41:44.710 警告 [localhost-startStop-8] org.apache.tomcat.util.scan.StandardJarScanner.processURLs Failed
to scan [file:/usr/local/apache-tomcat-8.5.32/lib/._el-api.jar] from classloader hierarchy
 java.util.zip.ZipException: error in opening zip file
        at java.util.zip.ZipFile.open(Native Method)
        at java.util.zip.ZipFile.<init>(ZipFile.java:219)
        at java.util.zip.ZipFile.<init>(ZipFile.java:149)
        at java.util.jar.JarFile.<init>(JarFile.java:166)
        at java.util.jar.JarFile.<init>(JarFile.java:130)
        at org.apache.tomcat.util.compat.JreCompat.jarFileNewInstance(JreCompat.java:188)
        at org.apache.tomcat.util.scan.JarFileUrlJar.<init>(JarFileUrlJar.java:65)
        at org.apache.tomcat.util.scan.JarFactory.newInstance(JarFactory.java:49)
        at org.apache.tomcat.util.scan.StandardJarScanner.process(StandardJarScanner.java:374)
        at org.apache.tomcat.util.scan.StandardJarScanner.processURLs(StandardJarScanner.java:309)
        at org.apache.tomcat.util.scan.StandardJarScanner.doScanClassPath(StandardJarScanner.java:266)
        at org.apache.tomcat.util.scan.StandardJarScanner.scan(StandardJarScanner.java:229)
        at org.apache.catalina.startup.ContextConfig.processJarsForWebFragments(ContextConfig.java:1888)
        at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1116)
        at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:765)
        at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:299)
        at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:94)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5154)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:754)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:730)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:734)
        at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:985)
        at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1857)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

この例外はtomcat/lib配下のjarファイル25個に対して出ており、上記のログが一度に連続して25回出ています。

  1. GitLabへpush
  2. Jenkinsがビルド
  3. このTomcatへデプロイ

のフローを自動化している為、誰かがgit pushする度にどんどんファイルサイズが増加していました。

原因

例外対象のjarファイルをよく見ると先頭に「._」が付いています。
tomcat/libをls -aしてみると、通常のjarの他「._」が付いた隠しファイルが実際に居ました。

# ls -la
合計 7828
drwxr-xr-x 2 tomcat tomcat    4096  7月 25  2018 .
drwxr-xr-x 9 tomcat tomcat     336  6月 20  2018 ..
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._annotations-api.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._catalina-ant.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._catalina-ha.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._catalina-storeconfig.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._catalina-tribes.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._catalina.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._ecj-4.6.3.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._el-api.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._jasper-el.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._jasper.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._jaspic-api.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._jsp-api.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._servlet-api.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-api.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-coyote.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-dbcp.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-i18n-es.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-i18n-fr.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-i18n-ja.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-jdbc.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-jni.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-util-scan.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-util.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._tomcat-websocket.jar
-rw-r--r-- 1 tomcat tomcat     212  6月 20  2018 ._websocket-api.jar
-rw-r--r-- 1 tomcat tomcat   12371  6月 20  2018 annotations-api.jar
-rw-r--r-- 1 tomcat tomcat   54183  6月 20  2018 catalina-ant.jar
-rw-r--r-- 1 tomcat tomcat  118606  6月 20  2018 catalina-ha.jar
-rw-r--r-- 1 tomcat tomcat   75852  6月 20  2018 catalina-storeconfig.jar
-rw-r--r-- 1 tomcat tomcat  283697  6月 20  2018 catalina-tribes.jar
-rw-r--r-- 1 tomcat tomcat 1641155  6月 20  2018 catalina.jar
-rw-r--r-- 1 tomcat tomcat 2450404  6月 20  2018 ecj-4.6.3.jar
-rw-r--r-- 1 tomcat tomcat   82382  6月 20  2018 el-api.jar
-rw-r--r-- 1 tomcat tomcat  164666  6月 20  2018 jasper-el.jar
-rw-r--r-- 1 tomcat tomcat  591616  6月 20  2018 jasper.jar
-rw-r--r-- 1 tomcat tomcat   26912  6月 20  2018 jaspic-api.jar
-rw-r--r-- 1 tomcat tomcat   61652  6月 20  2018 jsp-api.jar
-rw-r--r-- 1 tomcat tomcat  244064  6月 20  2018 servlet-api.jar
-rw-r--r-- 1 tomcat tomcat   10664  6月 20  2018 tomcat-api.jar
-rw-r--r-- 1 tomcat tomcat  810072  6月 20  2018 tomcat-coyote.jar
-rw-r--r-- 1 tomcat tomcat  278730  6月 20  2018 tomcat-dbcp.jar
-rw-r--r-- 1 tomcat tomcat   66897  6月 20  2018 tomcat-i18n-es.jar
-rw-r--r-- 1 tomcat tomcat   40792  6月 20  2018 tomcat-i18n-fr.jar
-rw-r--r-- 1 tomcat tomcat   42087  6月 20  2018 tomcat-i18n-ja.jar
-rw-r--r-- 1 tomcat tomcat  148296  6月 20  2018 tomcat-jdbc.jar
-rw-r--r-- 1 tomcat tomcat   34562  6月 20  2018 tomcat-jni.jar
-rw-r--r-- 1 tomcat tomcat  208448  6月 20  2018 tomcat-util-scan.jar
-rw-r--r-- 1 tomcat tomcat  143092  6月 20  2018 tomcat-util.jar
-rw-r--r-- 1 tomcat tomcat  224850  6月 20  2018 tomcat-websocket.jar
-rw-r--r-- 1 tomcat tomcat   36905  6月 20  2018 websocket-api.jar

これらの正体は「AppleDouble」というファイルです。

# file ./._annotations-api.jar
./._annotations-api.jar: AppleDouble encoded Macintosh file

# cat ._annotations-api.jar
Mac OS X                2「ヤATTRヤ<<com.apple.quarantineq/0083;5b5674fe;Safari;6DFD0406-1C16-4C92-A6EB-F563DC5411CC

Macのファイルシステム管理を補佐する為の情報が入っていて、HFS+ではOS内部でこの情報を持つ為、Macを使っている分にはFinderではお目に掛からないファイルです。

Mac(HFS+)からWindows(FAT32)やLinux(ext4)へファイル共有した時にこれらの情報が抜け落ちないようにわざわざファイルを作ってくれるんですね。Macユーザ以外に嫌われがちな「.DS_store」と同じ目的です。

拡張子はjarですが、中身はjarではないので、Tomcatがこれらのファイルにzipを期待してアクセスする度「zipじゃない」と警告をログに残します。

これらのファイルがインストールに使ったと思われるapache-tomcat-8.5.32.zipに混入したのが原因でした。

対処

暫定対処としてtomcat/libから._ファイルを削除。
取りあえず例外は出なくなります。

# cd ${TOMCAT_HOME}/lib
# rm ./._*

こちらの場合、ミドルはansibleでインストールしていてチーム内リポジトリからインストール資源を持ってくるので、社内リポジトリのapache-tomcat-8.5.32.zipをまともなものに置換しました。

まとめ

寧ろどうやってzipの中にAppleDoubleファイルを入れたのか、の疑問が残りました。

このTomcatのアップデート作業を行ったのは2か月前に退社した人で連絡も取れず真相は迷宮入りです。

落としてきたtomcatのzipをリポジトリディレクトリに放り込んで、ansible playbookのyamlをちょちょいとコピーするだけだったんですが・・・。

  • Macでapache-tomcat-8.5.32.zipをダウンロード、解凍
  • Windowsにディレクトリを転送して再zip

とかしたんでしょうかね・・・謎は深まるばかりです。

-trouble shooting
-, , ,

執筆者:

関連記事

java.security.InvalidKeyException: IOException : DerInputStream.getLength(): lengthTag=111, too big.

目次1 事象2 原因3 対処4 得た教訓 事象 OpenSSLで作成した秘密鍵をJava(Eclipse + Maven環境)で読み込み、公開鍵で暗号化されたデータを復号しようとした際に例外が発生しま …

Angularのテンプレート評価式にビット演算を使うとTemplate parse errorが発生する

AngularのテンプレートHTMLでビット演算をすることは禁じられているので代替手段を考えます。 目次1 事象2 原因3 対処 事象 CSSクラスをビット演算で切り替えるテンプレートを書きました。c …

スタンドアロンモードのPgAdmin4が開くデフォルトブラウザを変更

PostgreSQL公式GUIクライアントツールの「PgAdmin4」。 PostGISのgeometry型をWeb地図上に表示出来たり、サーバモードで起動すればチーム内で共通的に使えるPostgre …

Metabaseの登録データベース削除時に入力を求められて消せない

分析対象として登録したデータベースを一覧から削除する際に入力値を求められ、何を入れていいか分からずプチはまりました。 結論から述べると入力する文字は「delete」でした。 事象 Metabase(v …

ローカルネットワーク内のHTTP通信が2回に1回交互にタイムアウトするようになった原因

目次1 事象2 調査3 解決4 その後 事象 ある日突然、オフィスのローカル開発環境でHTTP通信が異常なほど遅くなり、タイムアウトするようになりました。 その後F5でリロードすると普通にレスポンスが …

 

shingo.nakanishi
 

東京在勤、1977年生まれ、IT職歴2n年、生涯技術者として楽しく生きることを目指しています。デスマに負けず健康第一。