オウム返しLinbot(Python)で401が検出され、返答されない。

Question

#事象
オウム返しするLinebotをFlaskで作成し、herokuにデプロイ後、webhockのurl検証が成功したので、lineのトークからチャットを送ってみましたが、返答が返ってきません。herokuのログを確認するとhttpステータスが401が返答され、認証エラーになっております。チャネルトークン、チャネルシークレットが間違っていないことは確認しました。どうすれば解消するでしょうか。

#試したこと
以下のことを試しましたが、だめでした。
・チャネルトークン、チャネルシークレットの再発行
・チャネルの再作成
・herokuの再作成
・参考にしたwebサイトで利用していたpython,flask,line-bot-sdkのバージョンを合わし、再デプロイ
・line developer console でuse webhockのon,offを繰り返す

#herokuログ

2021-03-21T03:25:44.159413+00:00 app[web.1]: [2021-03-21 03:25:44,158] ERROR in app: Exception on /callback [POST]
2021-03-21T03:25:44.159431+00:00 app[web.1]: Traceback (most recent call last):
2021-03-21T03:25:44.159432+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/flask/app.py", line 2292, in wsgi_app
2021-03-21T03:25:44.159432+00:00 app[web.1]: response = self.full_dispatch_request()
2021-03-21T03:25:44.159436+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/flask/app.py", line 1815, in full_dispatch_request
2021-03-21T03:25:44.159436+00:00 app[web.1]: rv = self.handle_user_exception(e)
2021-03-21T03:25:44.159437+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/flask/app.py", line 1718, in handle_user_exception
2021-03-21T03:25:44.159437+00:00 app[web.1]: reraise(exc_type, exc_value, tb)
2021-03-21T03:25:44.159438+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/flask/_compat.py", line 35, in reraise
2021-03-21T03:25:44.159438+00:00 app[web.1]: raise value
2021-03-21T03:25:44.159439+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/flask/app.py", line 1813, in full_dispatch_request
2021-03-21T03:25:44.159439+00:00 app[web.1]: rv = self.dispatch_request()
2021-03-21T03:25:44.159440+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/flask/app.py", line 1799, in dispatch_request
2021-03-21T03:25:44.159440+00:00 app[web.1]: return self.view_functions[rule.endpoint](**req.view_args)
2021-03-21T03:25:44.159441+00:00 app[web.1]: File "main.py", line 42, in callback
2021-03-21T03:25:44.159441+00:00 app[web.1]: handler.handle(body, signature)
2021-03-21T03:25:44.159441+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/linebot/webhook.py", line 230, in handle
2021-03-21T03:25:44.159442+00:00 app[web.1]: func(event)
2021-03-21T03:25:44.159442+00:00 app[web.1]: File "main.py", line 67, in handle_message
2021-03-21T03:25:44.159442+00:00 app[web.1]: TextSendMessage(text=event.message.text)) #ここでオウム返しのメッセージを返します。
2021-03-21T03:25:44.159443+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/linebot/api.py", line 95, in reply_message
2021-03-21T03:25:44.159443+00:00 app[web.1]: '/v2/bot/message/reply', data=json.dumps(data), timeout=timeout
2021-03-21T03:25:44.159444+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/linebot/api.py", line 561, in _post
2021-03-21T03:25:44.159444+00:00 app[web.1]: self.__check_error(response)
2021-03-21T03:25:44.159444+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.7/site-packages/linebot/api.py", line 584, in __check_error
2021-03-21T03:25:44.159445+00:00 app[web.1]: raise LineBotApiError(response.status_code, error)
2021-03-21T03:25:44.159446+00:00 app[web.1]: linebot.exceptions.LineBotApiError: LineBotApiError: status_code=401, error_response={"details": [], "message": "Authentication failed due to the following reason: invalid token. Confirm that the access token in the authorization header is valid."}
2021-03-21T03:25:44.161260+00:00 app[web.1]: 10.95.209.15 - - [21/Mar/2021 03:25:44] "POST /callback HTTP/1.1" 500 -
2021-03-21T03:25:44.164662+00:00 heroku[router]: at=info method=POST path="/callback" host=line-bot-py-bitbank.herokuapp.com request_id=9e0eb807-19bd-40a4-967b-fe83e21e1e71 fwd="147.92.149.168" dyno=web.1 connect=0ms service=556ms status=500 bytes=464 protocol=https

#フォルダ構成

/
│- main.py
│- Procfile
│- requirements.txt
│- runtime.txt

#main.py

from flask import Flask, request, abort
from flask.logging import create_logger

from linebot import (
    LineBotApi, WebhookHandler
)
from linebot.exceptions import (
    InvalidSignatureError
)
from linebot.models import (
    MessageEvent, TextMessage, TextSendMessage,
)
import os

app = Flask(__name__)
log = create_logger(app)
 
#環境変数取得
# LINE Developersで設定されているアクセストークンとChannel Secretをを取得し、設定します。
YOUR_CHANNEL_ACCESS_TOKEN = os.environ["YOUR_CHANNEL_ACCESS_TOKEN"]
YOUR_CHANNEL_SECRET = os.environ["YOUR_CHANNEL_SECRET"]

# LINE Developersで設定されているアクセストークンとChannel Secretを設定します。 
line_bot_api = LineBotApi(YOUR_CHANNEL_ACCESS_TOKEN)
handler = WebhookHandler(YOUR_CHANNEL_SECRET)
 
## 1 ##
#Webhookからのリクエストをチェックします。
@app.route("/callback", methods=['POST'])
def callback():
    # リクエストヘッダーから署名検証のための値を取得します。
    signature = request.headers['X-Line-Signature']
 
    # リクエストボディを取得します。
    body = request.get_data(as_text=True)
    #app.logger.info("Request body: " + body)
    log.info("Request body: " + body)
 
    # handle webhook body
    # 署名を検証し、問題なければhandleに定義されている関数を呼び出す。
    try:
        handler.handle(body, signature)
    # 署名検証で失敗した場合、例外を出す。
    except InvalidSignatureError:
        print("Invalid signature. Please check your channel access token/channel secret.")
        abort(400)
    # handleの処理を終えればOK
    return 'OK'
 
## 2 ##
###############################################
#LINEのメッセージの取得と返信内容の設定(オウム返し)
###############################################
 
#LINEでMessageEvent（普通のメッセージを送信された場合）が起こった場合に、
#def以下の関数を実行します。
#reply_messageの第一引数のevent.reply_tokenは、イベントの応答に用いるトークンです。 
#第二引数には、linebot.modelsに定義されている返信用のTextSendMessageオブジェクトを渡しています。
 
@handler.add(MessageEvent, message=TextMessage)
def handle_message(event):
    line_bot_api.reply_message(
        event.reply_token,
        TextSendMessage(text=event.message.text)) #ここでオウム返しのメッセージを返します。
 
# ポート番号の設定
if __name__ == "__main__":
    # app.run()
    port = int(os.getenv("PORT", 5000))
    app.run(host="0.0.0.0", port=port)

#requirements.txt

Flask==1.0.2
line-bot-sdk==1.8.0

#runtime.txt

python-3.7.10

#Procfile

web: python main.py

##参考にしたサイト
・https://datacoach.me/data/tips/python-linebot/

Answer 1

log.info("Request body: " + body)でログ出力していたのがエラーの原因でした。
app.logger.info("Request body: " + body)でログ出力するようにすると正常に動作しました。
ただapp.logger.info("Request body: " + body)だと構文エラーが出ていたので、log.info("Request body: " + body)に修正したのですが、僕の環境が悪いのでしょうか・・・

Answer 2

質問の中で「httpステータスが401が返答され、認証エラー」と認識されているとおり、LineBotApiでAPIを呼び出すところで認証に失敗しているように見えます。

提示されているherokuのログで以下のメッセージにある通り、適切でないトークン（invalid token）が原因のようです（おそらくトークンがHTTPリクエストのヘッダーへ適切に設定できてない）。

linebot.exceptions.LineBotApiError: LineBotApiError: status_code=401, error_response={"details": [], "message": "Authentication failed due to the following reason: invalid token. Confirm that the access token in the authorization header is valid."}

LineBotApiは使ったことがないので具体的な修正方法はわかりませんが、Flask連携を試す前に、LineBotApi単体でメッセージを送信する方法を、ローカルのpythonインタプリタ上などで確認してみたらどうでしょうか。

---

以下、質問されている点とは直接関係ないです

Flaskでログ出力したいときは、質問にあるコードの場合ではapp.loggerが使えると思います。例えばinfoレベルのメッセージを出力したい場合は、create_loggerでloggerオブジェクトを取得しなくても、「app.logger.info("Request body: " + body)」で出力できると思います。

Comments

[montai21]

ご提示いただいた通り、「app.logger.info("Request body: " + body)」でログを取得するようにした途端、エラーが出ずに、オウム返しができました。
log = create_logger(app)で生成したloggerオブジェクトでのログ出力が不具合の原因でした。なぜ、このような現象が起きたかまではわかりませんが、とりあえず解決しました。