Go to Qiita Advent Calendar 2024 Top
LoginSignup
13
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

All About Group（株式会社オールアバウト）Advent Calendar 2019

Day 15
@k_mattunin株式会社オールアバウト

新卒1年目がCircleCIに振り回される話

Last updated at Posted at 2019-12-14

こんにちは！新卒エンジニア1年目の@k_mattunです。
この記事は、All About Group（株式会社オールアバウト） Advent Calendar 2019 15日目の記事となっております。

はじめに

つい先日入社したように感じますが、気づいたらクリスマスが迫っているんですね・・・。
社会人の方々が言っていた、あっという間に時間が経っている現象を身を以て体験して焦りを感じています。

この記事では、新卒エンジニアとして仕事を始めてハマった事を書いていこうかなーって思います。
※Advent Calendarに書く内容がなかったわけではありませんので、誤解なきようお願いします

基本的な開発環境

私が日頃仕事を行う上での基本的な開発環境としては、ざっくり以下の通りです。

使用言語

  • PHP5系 or PHP7系
  • JavaScript

使用フレームワーク

  • Laravel5系

インフラ周り・CIツール

  • GCP
  • k8s
  • Docker
  • CircleCI

ハマった事その1

まずこのエラーについて説明する前に、やっていた作業について簡単に説明します。

CIツールの変更について

みなさん改修作業など行なった際に改修内容をリリースしますよね？
そんな時大体の方がCIツールを利用されていると思います。
もちろん、うちの会社でもCIツールは使用していて。

私が入社したタイミングではJenkinsおじさんことJenkinsと、Werckerを利用していました。
※入社当初CIツール？Wercker？？って感じでした。自分が参考にしたサイトはこちらです。https://deeeet.com/writing/2014/10/16/wercker/

しかし、入社後CIツールをJenkins + WerckerからCircleCIに変更する事となりました。
Werckerを撤廃した後、あるアプリの改修を行なったのですが。
そのアプリはCircleCIでデプロイした事がなかったため、改修内容を反映させるためにもCircleCIでリリースを行えるように対応を行う事となりました。
※CircleCIについても無知だったので、自分が参考にした記事を載せておきます(大変助かりました、ありがとうございます)https://qiita.com/gold-kou/items/4c7e62434af455e977c2

ハマった事その1については、こちらのCircleCI移行中に起こった出来事になります。

起きたエラー

CircleCIってなんぞやって状況ながらも、社内のCircleCI移行に関するドキュメントであったりネット上の記事であったり。
手当たり次第探しては読み、探しては読みを繰り返しながらなんとかconfig.yamlを記述していきます。

ふんふん、大体ステージング用とプロダクション用にjobを作ってそれぞれどんなタイミングで実行させるかworkflowsで指定していくのね・・・って感じで順調に設定ファイルを書き上げていく。
wercker.ymlを参考にしたのもあって意外とすんなり書けたので、よっしゃ案外CircleCI移行も簡単か？って思っていました。

そして、いざ！CircleCIでデプロイできるかテストや！！ってやってみると。

php artisan clear-compiled

[ErrorException]
~ エラーメッセージ ~

出ました出ました、画面に表示される無慈悲な文言。
きっと今の自分ならこのエラーが出ると、あっ多分この辺りで怒られているんだなって察しがつきますが。
※きっとそうであると信じたい
業務を始めて1ヶ月ぐらいだった自分は頭の中が???でいっぱいでした笑

エラーの調査

何はともあれ調べないとわからないので、このエラーをコピーして調べまくりました。
どうやらphp artisan clear-compiledはLaravelのコマンドっぽいぞ?ってことがわかり。
エラーメッセージを読み解くと、なんか使おうとしてるけど該当のモジュール無いよ的な意味でした。

しかしWerckerと同じ設定にしているため、Werckerでは動いていてCircleCIで動かないって現象が理解できず。
何故うまく動作しないのか、考えました。

composer installするタイミングのそれぞれのイメージの違い

Wercker時代のビルドフローを全て見直してみて気づきました。
Werckerで行なっていた時はcomposer installするタイミングのイメージの状態がCircleCIの時と違ったのです。

Wercker時代は、Jenkinsでベースイメージを元にDockerfileでアプリ用のイメージを生成します。Wercker.ymlで扱うイメージはアプリ用に作成した色々モジュールがインストールされた状態のイメージを使用しています。
その為Werckerでcomposer installするタイミングでは該当のモジュールが入っており、正しく動作していたのだと思います。

逆にCircleCIの場合該当のモジュールが入っていないイメージのタイミングでcomposer installを行い、その後デプロイするタイミングでDockerのビルドを行ないアプリ用のイメージを作成していました。
その為、Laravelの環境が立ち上がるタイミングで先ほどのエラーが発生していました。

config.ymlで該当モジュールをinstallしてみる

composer installするタイミングでモジュールが入ってればいいのなら、config.yamlで入れたらこのエラー解決するんじゃね？って考え、実行してみることに。

command: |
    ~ 他のいろんな処理 ~
    install ~ 該当モジュール ~
    ~ 他のいろんな処理 ~

これで問題なく次のステップに進める！って思っていましたが、またしても画面に表示される無慈悲な文言。

php artisan clear-compiled

[ErrorException]
~ また別のエラーメッセージ ~

・・・何やねん！！って心境ですね。

再びエラー調査

今度はphp artisan clear-compiledについて集中的に調べることに。
ここで触れておきますが、私は入社して始めてまともにフレームワークを触りました。
Laravelについては無知です。

一生懸命ネットの海を渡りながら調べた結果、どうやらcomposer.jsonに記述されているscriptの
php artisan clear-compiledが動作。
それによってvendor配下にあるHogeServiceProvider.php(composerでautoloadしている)のメソッドが動作し、該当のエラーが発生していることがわかった。

エラーの原因

エラーの事象として、CircleCIでデプロイの最適化を行うscript(php artisan clear-compiledやphp artisan optimize)が走った際に、該当のエラーが発生することがわかりました。

これは最適化のタイミングでLaravelのServiceProviderが動作し、とあるメソッドが動作していました。

メソッドの中の処理として他のサーバと通信を行う処理が書いてあったのですが、この際に通信できていないのが実際の原因。

というのも、今回このエラーが発生するタイミングは
環境を構築している段階(ステージングのビルド時)でCircleCI上のコンテナで動いています。
コンテナはまだGKEにデプロイされていない状態です。

ビルドが実行されているCircleCI上コンテナはIPアドレスもポートも毎回異なります。
セキュリティの観点から接続できるIPアドレスは絞っており、該当のサーバへ通信が通らなかった為上記エラーが発生していました。

対処方法

envの環境変数に登録してあるIPに通信を行うので、envが無い場合はその通信が発生しません。
なのでconfig.yamlのコマンドの順番を変更しました。

steps:
    - envを配置する処理
    - composer_installする処理

この処理の流れから

steps:
    - composer_installする処理
    - envを配置する処理

こう変更した。

この事によりcomposer install実行して該当のscriptが走っても、サーバに通信する事もなく、ビルドしてしまった後にenvを配置するのでデプロイしても無事に動作するようになりました。

実はWerckerでのデプロイも同様の処理フローでした。
(あんなに見比べていたのに一体何をみていたんだ？？)

このおかげで、無事CircleCIでのデプロイができるようになり、本来の改修内容もリリースすることが可能となりました。

ハマった事その2

はい、今回のハマった事ですがまたもやCircleCI移行でハマりました。
CircleCI移行って、言ってしまえばデプロイに関する設定を行うので、ちょっとした間違いで直ぐエラーが起こります。
今回も結論としてはしょうもないところでした。

CircleCI移行を済ませ、ステージング環境をデプロイ。
今度は念入りに動作の確認を行って、問題ないことを確認しました。
よっし、これでプロダクションリリースできる！！
そう、こんな時にいつもあの無慈悲な文言が現れるんです・・・

バグの内容

内容としてはCircleCIでデプロイして、ステージング環境プロダクション環境共にリリースできたがプロダクション環境だけアクセスするとステータスコードの500が帰って来るといった問題です。
※社内ツールだった為、今回もビジネス影響はなく九死に一生を得ました

500が帰ってきた際GCPにあるStackdriverのLoggingで該当アプリのログを確認したのですが、アクセスログしか吐かれておらずエラーログがわからない状態でした。

エラーの調査のためにバグの再現

500で繋がらなくなってからすぐにKubernetesで切り戻しを行なったので調べようにも、バグが発生する環境がない状態でした。なぜかステージングは正常に動作しているため調査には使えず。

そこでCircleCIがイメージのビルド時にGCPのContainer Registryにpushしているのを思い出したので、そのイメージを手元に落としてきてDockerでコンテナを建てて再現することにしました。
簡単に設定などをローカル用に合わせて、無事立ち上げることができ環境も現象も再現することができました。

apacheのconfファイルを書き換えてaccess_log、error_log共にStackdriverではなく手元に吐くようにして、確認できなかったエラーログを確認しました。

エラーの原因

再現した環境で取得したaccess_logとerror_logです
※パスは架空です

access_log

hoge - - [03/Sep/2019:10:02:53 +0900] "GET / HTTP/1.1" 500 - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/76.0.3809.132 Safari/537.36"

error_log

[Tue Sep 03 10:10:24 2019] [error] [client hoge] PHP Fatal error:  Cannot declare class Illuminate\\Support\\Facades\\Facade, because the name is already in use in /home/hogehoge/bootstrap/cache/compiled.php on line 6005
[Tue Sep 03 10:10:24 2019] [error] [client hoge] PHP Stack trace:
[Tue Sep 03 10:10:24 2019] [error] [client hoge] PHP   1. {main}() /home/hogehoge/public/index.php:0
[Tue Sep 03 10:10:24 2019] [error] [client hoge] PHP   2. require() /home/hogehoge/public/index.php:21

アクセスログは現象の500が帰ってきています。
エラーログではIlluminate\Support\Facades\Facadeを宣言しようとしてるけど、すでに/bootstrap/cache/compiled.phpで使われてるよって怒られてます。

これが原因で処理が中断されステータス500が返されているようでした。

エラーが発生する原因として、composer installもしくはupdateが実行された際にcomposer.jsonで記述されているscript(php artisa optimize)が実行され、Laravelの最適化が走っていたのがエラーの発生箇所。(またお前たちか)

composer.json

"scripts": {
        "post-root-package-install": [
            "php -r \"copy('.env.example', '.env');\""
        ],
        "post-create-project-cmd": [
            "php artisan key:generate"
        ],
        "post-install-cmd": [
            "Illuminate\\Foundation\\ComposerScripts::postInstall",
            "php artisan optimize"
        ],
        "post-update-cmd": [
            "Illuminate\\Foundation\\ComposerScripts::postUpdate",
            "php artisan optimize"
        ]

php artisan optimizeについて

php artisan optimizeコマンドで、Laravelの最適化を行います。
フレームワークのコードを結合して１つのファイルに纏める
該当のクラスなどを利用する際はこのキャッシュファイルを参照するため読み込み速度が上がってパフォーマンスが向上する

実際に手元で動かしているpodからcompiled.phpを取得し、error_logで指摘されていたコードが記述されていることを確認できました。

対応

結論から言って、compiled.phpを生成しないことにしました。

compiled.phpの必要性について

あくまでLaravelの最適化(処理速度向上)のため必要なファイル
生成するコマンドphp artisan optimizeについて、Laravel5.5辺りから非推奨となり、公式からも削除されている(5.4まで存在)
https://github.com/laravel-shift/laravel-5.5/blob/master/composer.json#L40

非推奨の理由
77d2a776-371f-3bcd-4045-dec7ebd63007.png

該当のシステムで使用されているphpは7系。
かつ、OPcacheがインストールされいることも確認できパフォーマンスにも影響がないと判断しました。

実際に、この対応を行うと無事プロダクションも動作するようになりました。

ステージングとプロダクションの動作が違った件について

APP_DEBUG

STGとPROのenvに記述してあるAPP_DEBUGが原因
今までステージング環境をAPP_DEBUG=trueでデプロイしていたため今回の現象が発生しなかった。

※APP_DEBUG=trueの場合、optimizeコマンドを実行してもcompiled.phpは生成されない

教訓

開発中はデバッグモードで作業してもいいと思うが、ステージングやプロダクションではデバッグモードを解除してリリースするべき。今回の件のように今までなんとなく動いていた、なんて事になり兼ねないし本番とテスト環境が異なる状況も避けるべき。

終わりに

本当は他にも色々ハマった事あったんですけど、文量が多くなりそうなので、またいつかの機会にでも・・・。

わかった事としてLaravel全般的な知識、特にLaravelが建ち上がるまでの動きとか知らなすぎ問題。
あとはサーバーサイドの事知らなすぎ問題。
今まで全く触れてこなかったので、やっぱり勉強あるのみだなって感じです。
今回のこれらの失敗は様々な事を知るいい機会でした。

少しでも早く一端のエンジニアになれるよう精進あるのみです。

13
1
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
13
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?