ふんわり R-tips

ぜんぜんわからない、俺たちは雰囲気でRをやっている

Shinyアプリケーションのデバッグテクニック

このエントリはShiny公式サイトのDebugging Shiny applicationsを抜粋・翻訳・追記したものです。

Shiny - Debugging Shiny applications

概要

Shinyアプリケーションはreactiveで、入力操作に応じて挙動が変わるので、単純なRスクリプトと比較するとデバッグは面倒です。代表的なデバッグテクニックを紹介します。

  • (RStudioの)ブレークポイントを使ったデバッグ

ブレークポイントと呼ばれる選んだところでプログラムの実行を止める機能を使って、以降の各行での実行状態を監視します。コードの特定の箇所周辺でエラーが起きていないかどうかを検証する目的で使います。

  • 実行したコードの追跡

ブレークポイントで、コード内の特定の行で実行停止して変数を見るだけでは、デバッグが難しい場合もあります。その場合には、どの順でコードが実行されてエラーが発生したのかを追跡します。この方法のデバッグで定番なのはログ出力です。

ログ出力では、プログラムを止めることなく走らせて、あとで解析するために情報を集めます。頻繁にプログラムが止まる、といったことがない場合に正常に動作しているかどうかを判断する目的で使います。

ローカルでブレークポイントを使ったデバッグを行ってから、デプロイしてログの解析や実行されたコードを追跡してデバッグ、という手順でWebアプリケーションのバグを修正する手順が一般的です。

ブレークポイントを使ったデバッグ

RStudioにおけるブレークポイントの設定方法

RStudio上では、コードの左側をクリックしてブレークポイントを置くことができます。R言語だけでなく、一般的な統合開発環境では、このブレークポイントによるデバッグ方法の理解がもっとも重要です。

f:id:phmpk:20170119201909p:plain

ブレークポイントを置くと、Shinyアプリケーションを実行中に、Rがブレークポイントで停止して、そこからステップ実行を始めることができます。

f:id:phmpk:20170119201950p:plain

現在、Shinyアプリケーション内にブレークポイントを設定するのは、RStudio環境でのみ可能です。Rでブレークポイントを設定するsetBreakpoint()などの関数はShinyでは動作しません。

ブレークポイントの制限

RStudioのブレークポイントはshinyServer関数内(shinyバージョン0.10以降はshinyServer()関数なしで実行できるのでオブジェクトを返すfunction()内でのみ使用可能です。他の.Rファイル内では使えません。

[注記] shinyバージョン0.14.2、RStudioバージョン1.0.44ではうまく動作しないようです。server.R以外でもRStudioのブレークポイントを使えるように改良する予定ということもあり、この機能はまだまだ開発途中です。下記のbrowser()文によるブレークポイントを使ったほうが良いでしょう。

browser() 文によるブレークポイント

browser()文は、RStudioのブレークポイントとは別のよく似たデバッグツールです。ブレークポイントのように動作し、実行を停止してデバッガを起動します。Rのコード内に埋め込んで使用することができます。

f:id:phmpk:20170119202037p:plain

ブレークポイントと異なり、ShinyServer関数内だけでなくbrowser()はどこでも動作します。以下のように、条件分を指定してbrowser()を使うこともできます。

if (input$bins > 50)
  browser()

実行したコードの追跡

コード内の特定の行で実行停止して変数を見るだけでは、デバッグが難しい場合もあります。Shinyアプリケーションは、Rスクリプトを上から順に実行するだけでなく、入力操作に応じて様々な場所のコードを実行します。実行中にShinyアプリケーションの状態を追跡するテクニックについて述べます。

ShinyのShowcaseモード

Shiny Galleryを見ると、ShowcaseモードのShinyアプリケーションを見ることができます。Showcaseモードでは、アプリケーションの側にコードが表示され、実行中のコードが黄色で塗りつぶされます。例として、以下の図では、入力が変化したときにプロット出力を変更するコードが確認できます。

f:id:phmpk:20170119202254g:plain

Showcaseモードはコードのどの部分が実行されているのかを可視化するのに有用なツールです。デフォルトでは無効になっており、runAppを呼び出すときにdisplay.mode="showcase"を付けることで有効となります。

shiny::runApp(display.mode="showcase")

Showcaseモードでの実行をデフォルトにしたいときは、(ui.Rとserver.R、またはapp.Rのある)アプリケーションのフォルダに以下を記述したDESCRIPTIONというファイルを置きます

Title: XXX
Author: XXX
DisplayMode: Showcase
Type: Shiny

Reactiveログ

reactiveな実行を追跡するShowcaseモード以外の方法として、Shiny rectiveログがあります。Reactiveログでは、どのreactiveな変数が実行されているのかに加えて、reactiveになっているオブジェクトの依存関係も可視化します。

Reactiveログを見るときには、以下のコードをRで予め実行します。

options(shiny.reactlog=TRUE)

Shinyアプリケーションを実行して、アプリケーション動作中に「Ctrl+F3」を押すと、以下の図のようなReactiveログが立ち上がります。

f:id:phmpk:20170119203215p:plain

"printf"によるログ出力

タイトルのprintfは例えで、古典的なログ出力によるコード実行の追跡方法のことです。あまりおすすめできる方法ではありませんが、実行を止めることなく、変数の値を出力することができます。Shinyアプリケーションでprintfのように標準エラー出力(stderr())を行うときには、以下のコードのようにcatを使用します。

x    <- faithful[, 2] 
bins <- seq(min(x), max(x), length.out = input$bins + 1)
cat(file=stderr(), "drawing histogram with", input$bins, "bins\n")

catを追加してからShinyアプリケーションを実行すると、コードが実行されるたびにコンソール上で標準エラー出力を監視できます。

Listening on http://127.0.0.1:5757
drawing histogram with 30 bins
drawing histogram with 35 bins

stderr()を使うことなく、cat("my output")でも正しく動作しますが、capture.outputでrenderPrint内へリダイレクトされる場合は例外です。renderPrint内ではstderr()へ出力する必要があります。

Shinyapps.io上で実行追跡

ShinyアプリケーションをRStudioのShinyApps.ioにデプロイしている場合、リアルタイムでcat()関数を使ってログを出力することができます。手順は、

  1. アプリケーションにcat(file=stderr(), ...)を追加

  2. RStudio IDE、またはrsconnect::deployApp()関数を用いて、Shinyアプリケーションをデプロイ

  3. アプリケーションのあるディレクトリで、rsconnect::showLogs(streaming = TRUE)を実行

  4. ブラウザでShinyApps.ioにデプロイしたアプリケーションを開くと、Rのコンソール上にcat()で指定したログを出力

Shinyサーバ上で実行追跡

cat(file=stderr(), ...)はShinyサーバでも同様に動作します。以下の場所にあるログが出力されます。

/var/log/shiny-server/*.log
cat()を使う場合の注意点

cat()を使うときに注意することとして、reactiveな値を参照する場合も特別扱いされないということです。依存関係が生成され、cat()がない場合と異なる動作になる可能性があります。

サーバ / クライアント間の送受信データ追跡

Shinyアプリケーションはクライアント(ブラウザ)とサーバ(Rのプロセス)がデータを送受信して動作します。クライアントとサーバの2つはwebcocketで繋げられており、状態変化をデータとして送受信します。

以下のコードを予め実行すると、送受信されたwebsocketをJSON形式で見ることができます。

options(shiny.trace = TRUE)

このオプションを実行すると、アプリケーションが動作している間は大量の出力がコンソールに現れます。以下はその例です。

SEND {"config":{"workerId":"","sessionId":"04531d50d12554bd981b24b9d3983cc4"}}
RECV {"method":"init","data":{"bins":30,".clientdata_output_distPlot_width":610,".clientdata_output_distPlot_height":400,".clientdata_output_distPlot_hidden":false,".clientdata_pixelratio":1,".clientdata_url_protocol":"http:",".clientdata_url_hostname":"127.0.0.1",".clientdata_url_port":"5569",".clientdata_url_pathname":"/",".clientdata_url_search":"",".clientdata_url_hash_initial":"",".clientdata_singletons":"",".clientdata_allowDataUriScheme":true}}

ログはクライアント視点のものです。

  • SENDはブラウザからRのセッションに送られたデータ

  • RECVはRのセッションからブラウザに送られたデータ

session$clientDataオブジェクトを見れば、さらに掘り下げた情報を見ることができます。