Skip to content
This repository has been archived by the owner on Apr 12, 2023. It is now read-only.

COCOA 突如として初期化される問題（UserDataが壊れている） #16

Closed
moonmile opened this issue Jan 14, 2021 · 16 comments
Closed

COCOA 突如として初期化される問題（UserDataが壊れている） #16

moonmile opened this issue Jan 14, 2021 · 16 comments

Comments

@moonmile
Copy link
Contributor

moonmile commented Jan 14, 2021 •
edited
Loading

1月4日の突如として COCOA の継続日数が初期化されました。

image

初期化された後、再び同意をして使用を継続しているのですが、ログを見ていくと、初期化される前に常に
"existsUserData: False" な状態になっています。

"2020/12/26 00:02:18","Info","existsUserData: False","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"

この状態が、1/4 まで続きます。

"2021/01/04 23:39:48","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:48","Info","existsUserData: False","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:48","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","77","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:48","Info","No user data exists","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","80","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:48","Info","Transition to TutorialPage1","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","81","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:48","Info","End","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","99","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","Start","Init","/Users/runner/work/1/s/Covid19Radar/Covid19Radar.iOS/Services/Logs/LogPeriodicDeleteServiceIos.cs","40","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","Start","ScheduleAppRefresh","/Users/runner/work/1/s/Covid19Radar/Covid19Radar.iOS/Services/Logs/LogPeriodicDeleteServiceIos.cs","92","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","request.EarliestBeginDate: 2021-01-05 14:39:49 +0000","ScheduleAppRefresh","/Users/runner/work/1/s/Covid19Radar/Covid19Radar.iOS/Services/Logs/LogPeriodicDeleteServiceIos.cs","98","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","End","ScheduleAppRefresh","/Users/runner/work/1/s/Covid19Radar/Covid19Radar.iOS/Services/Logs/LogPeriodicDeleteServiceIos.cs","107","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","End","Init","/Users/runner/work/1/s/Covid19Radar/Covid19Radar.iOS/Services/Logs/LogPeriodicDeleteServiceIos.cs","49","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","Start","Rotate","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/Logs/LogFileService.cs","128","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:49","Info","End","Rotate","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/Logs/LogFileService.cs","147","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:52","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:52","Info","existsUserData: False","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:52","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","77","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","OnClickAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/Tutorial/TutorialPage3ViewModel.cs","35","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","No user data exists","OnClickAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/Tutorial/TutorialPage3ViewModel.cs","40","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","RegisterUserAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","44","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","PostRegisterUserAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/HttpDataService.cs","62","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","PostRegisterUserAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/HttpDataService.cs","81","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","userData is not null","RegisterUserAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","52","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","currentdata don't equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","93","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","100","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","RegisterUserAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","61","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","userData is not null","OnClickAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/Tutorial/TutorialPage3ViewModel.cs","50","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","currentdata don't equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","93","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","100","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","IsOptined set to True","OnClickAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/Tutorial/TutorialPage3ViewModel.cs","59","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","SaveLastUpdateDateAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","106","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","SaveLastUpdateDateAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","111","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:57","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:39:58","Info","End","OnClickAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/Tutorial/TutorialPage3ViewModel.cs","63","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:40:49","Info","Start","Rotate","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/Logs/LogFileService.cs","128","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:40:49","Info","End","Rotate","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/Logs/LogFileService.cs","147","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:40:50","Info","Start","OnClickAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/Tutorial/PrivacyPolicyPageViewModel.cs","41","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:40:50","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/04 23:40:50","Info","currentdata don't equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","93","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"

同意をすると、再び "existsUserData: True" な状態になります。

この動作は想定されているものでしょうか？
@moonmile
Copy link
Contributor Author

COCOA のログの出力は、

  1. COCOA で「アプリに関するお問い合わせ」を選択
  2. 「動作情報を送信」
  3. 「動作情報を確認する」のリンクをクリック

で、保存された内容を確認しています。

@moonmile moonmile changed the title COCOA ga COCOA 突如として初期化される問題（UserDataが壊れている） Jan 14, 2021
@moonmile
Copy link
Contributor Author

2021/01/21 付けの報道ステーションで取り上げられたので、ログ取得の手順をあげておきます。

  1. COCOA のメニューから、「アプリに関するお問い合わせ」を選択
  2. 文章をスクロールして「動作情報を確認する」をクリック
  3. ファイルにログが保存されます。

image

保存された情報は、iPhone であれば「ファイル」アプリを起動して、接触確認アプリのフォルダーで見れます。
*.zip ファイルをクリックすると、iPhone 内でファイルが解凍され、内容が CSV 形式で書かれていることがわかります。

image

このデータを iTunes などを使って取り出せばよいでしょう。

なお、実際に、厚生労働省に送信するときは、あらかじめメールアプリの設定が必要です。

という案内が公式にあったほうが良いと思います。

@tmurakami
Copy link

厚労省サポートさんへ動作情報(ログ)を送信する手順をここに追記しておきます。
(PDFです)

https://www.mhlw.go.jp/content/10906000/000701383.pdf

@moonmile
Copy link
Contributor Author

ログの解析を追記

COCOA の UserData が壊れている件の補足 ・ openCACAO/cocoa-documentation Wiki

@ypresto ypresto mentioned this issue Feb 3, 2021
Closed
@Ryo-9399
Copy link

Ryo-9399 commented Feb 3, 2021

横から失礼します🙇‍♂️

ExposureNotificationHandler.DownloadBatchAsync で例外が発生している原因について、少し調べてみました。結論からすると ExposureNotificationHandler のフィールド userData が null であるためだと思います。

"2021/01/03 02:47:52","Info","End","GetTemporaryExposureKeyList","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/HttpDataService.cs","111","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/03 02:47:53","Error","Fail to download files, Exception: System.NullReferenceException: Object reference not set to an instance of an object  at Covid19Radar.Services.ExposureNotificationHandler.DownloadBatchAsync (System.String region, System.Threading.CancellationToken cancellationToken) <0x101eac430 + 0x00558> in <1abf079d7ff14e698144d8eed233764d#3d51fe5363cc0218d8b88183cd5fca9c>:0   at Covid19Radar.Services.ExposureNotificationHandler.FetchExposureKeyBatchFilesFromServerAsync (System.Func`2[T,TResult] submitBatches, System.Threading.CancellationToken cancellationToken) <0x101eab960 + 0x0039b> in <1abf079d7ff14e698144d8eed233764d#3d51fe5363cc0218d8b88183cd5fca9c>:0 ","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","197","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"
"2021/01/03 02:47:53","Info","End","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","199","iOS","14.2","iPhone11,8","Physical","1.2.1","1607653212"

注目したのはこのログです。

「"End","GetTemporaryExposureKeyList"」のログの直後すぐに NullReferenceException をキャッチした旨のログがあり、「tekItem.Created: ...」というログが無いので、ソースの以下の範囲内で NullReferenceException が発生し、ExposureNotificationHandler.DownloadBatchAsync が例外終了したように見えます。

cocoa/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs

Lines 226 to 248 in 36b1a07

List<TemporaryExposureKeyExportFileModel> tekList = await httpDataService.GetTemporaryExposureKeyList(region, cancellationToken);
if (tekList.Count == 0)
{
loggerService.EndMethod();
return (batchNumber, downloadedFiles);
}
Debug.WriteLine("C19R Fetch Exposure Key");
Dictionary<string, long> lastTekTimestamp = userData.LastProcessTekTimestamp;
foreach (var tekItem in tekList)
{
long lastCreated = 0;
if (lastTekTimestamp.ContainsKey(region))
{
lastCreated = lastTekTimestamp[region];
}
else
{
lastTekTimestamp.Add(region, 0);
}
loggerService.Info($"tekItem.Created: {tekItem.Created}");

ログには「"End","GetTemporaryExposureKeyList"」とあるので、行 226 の HttpDataService.GetTemporaryExposureKeyList の呼び出しは成功し、また NullReferenceException は発生しません。その後、NullReferenceException が発生する可能性がある行は以下の通りです。

  • 行 227: tekList.Count
  • 行 234: userData.LastProcessTekTimestamp
  • 行 248: tekItem.Created

このうち最も可能性が高いのは 2 個目の userData.LastProcessTekTimestamp です。理由は userData の値が、ログを確認する限り、UserData が壊れている場合は常に null であるためです。代入箇所は同クラスのコンストラクタ内のみ、代入する値は UserDataService.Get の戻り値です。ここで、ログの他の部分には「existsUserData: False」とあり、このログが出るということは、以下のソースの行 78 に到達するため戻り値は確実に null です。

cocoa/Covid19Radar/Covid19Radar/Services/UserDataService.cs

Lines 65 to 79 in 36b1a07

public UserDataModel Get()
{
loggerService.StartMethod();
var existsUserData = Application.Current.Properties.ContainsKey("UserData");
loggerService.Info($"existsUserData: {existsUserData}");
if (existsUserData)
{
loggerService.EndMethod();
return Utils.DeserializeFromJson<UserDataModel>(Application.Current.Properties["UserData"].ToString());
}
loggerService.EndMethod();
return null;
}

注目したログの時点で userData が null であることが原因というのはあくまで推測で、上に挙げた残り 2 つの可能性、 @moonmile さんが Wiki で挙げられている「JSON 形式がおかしい場合」も否めません。しかし、もしログに「userData is null.」があるならば、これは ExposureNotificationHandler のコンストラクタ内で userData に null が代入されたという証拠となります。

@ypresto
Copy link

ypresto commented Feb 4, 2021 •
edited
Loading

アプリがリセットされた皆さま、可能であればexistsUserData: Falseが記録される「前」のログを共有していただけないでしょうか。
わたしの場合は下記のとおりでした。

"2021/02/01 00:11:44","Info","tekItem.Created: 1612018808311","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","tekItem.Created: 1612018808553","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","tekItem.Created: 1612018808914","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","tekItem.Created: 1612018809017","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","tekItem.Created: 1612018809133","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","GetTermsUpdateInfo","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","53","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Batch number: 0, Downloaded files: 0","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","275","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","IsReAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","69","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","IsReAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","88","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","IsReAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","69","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","privacyType: PrivacyPolicy, lastUpdateDate: 2021/01/12 16:55:59, info.UpdateDateTime: 2020/12/15 13:00:00","IsReAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","98","iOS","14.3","iPhone13,2","Physical","1.2.1","160765321
2"
"2021/02/01 00:11:44","Info","End","IsReAgree","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/TermsUpdateService.cs","99","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","47","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","currentdata equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","89","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","90","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","region: 440, userData.LastProcessTekTimestamp[440]: 1612018809133","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","278","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","280","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End to download files","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","165","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Batch number: 0, Downloaded files: 0","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","166","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","199","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","Initialize","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/HomePage/HomePageViewModel.cs","54","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","CheckVersion","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Common/AppUtils.cs","46","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Start","StartExposureNotification","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","118","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","Initialize","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/HomePage/SplashPageViewModel.cs","48","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Success to download configuration","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","56","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","CheckVersion","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Common/AppUtils.cs","79","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:45","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:45","Info","currentdata equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","89","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","Start","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","42","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","existsUserData: False","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"

下記のように、SetAsyncのEndが呼ばれる前にアプリがterminateされた次の起動で消えているようなので、SetAsync内の保存操作が完了する前にterminateされるとデータが消えるのではないかと疑っています。

"2021/02/01 00:11:45","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:45","Info","currentdata equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","89","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","Start","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","42","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","existsUserData: False","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"

具体的にはXamarin.FormsのSavePropertiesAsyncの実装が

  1. tmpファイルへ書き込み
  2. 設定ファイルの削除
  3. tmpファイルを設定ファイルの位置に移動

という三段階になっており、2と3の間でiOSがバックグラウンド動作時間超過などでアプリをterminateすると消える可能性がゼロではないように見えます。

https://github.com/xamarin/Xamarin.Forms/blob/25b2aa49a2abd9c523636598575585e3173907a8/Xamarin.Forms.Platform.iOS/Deserializer.cs#L85-L86

@ypresto
Copy link

ypresto commented Feb 4, 2021 •
edited
Loading

あ、すみませんSetAsyncの部分だけ違いますね・・上記のログでは currentdata equals newdata になって保存操作はスキップされており、SetAsyncからのSavePropertiesAsyncで消えているわけじゃなさそうです。

よく見るとGetExposureNotificationConfigもEndになっておらず↓

"2021/02/01 00:11:44","Info","Start","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","47","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"

...（省略）...

"2021/02/01 00:11:44","Info","Start","StartExposureNotification","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","118","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","Initialize","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/HomePage/SplashPageViewModel.cs","48","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","Success to download configuration","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","56","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:44","Info","End","CheckVersion","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Common/AppUtils.cs","79","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:45","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 00:11:45","Info","currentdata equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","89","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"
"2021/02/01 04:13:01","Info","Start","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","42","iOS","14.3","iPhone13,2","Physical","1.2.1","1607653212"

GetExposureNotificationConfigの中でSavePropertiesAsyncを呼び出していました。

            if (result.StatusCode == System.Net.HttpStatusCode.OK)
            {
                loggerService.Info("Success to download configuration");
                Application.Current.Properties["ExposureNotificationConfigration"] = await result.Content.ReadAsStringAsync();
                await Application.Current.SavePropertiesAsync();
            }
            else
            {
                loggerService.Error("Fail to download configuration");
            }

            loggerService.EndMethod();

このEndMethodが呼ばれる前にterminateされているので、SavePropertiesAsyncの途中でプロセスが落ちてしまった→tmpファイルを残してProperties全体が消えてしまった可能性がありそうです。

@yozjp
Copy link

yozjp commented Feb 5, 2021

ちょうど一昨日手元の iPhone で初期化を確認したのでログを取得できました。
cocoa_log_20210203.csv の先頭で existsUserData: False になっています。

"output_date","log_level","message","method","file_path","line_number","platform","platform_version","model","device_type","app_version","build_number"
"2021/02/03 01:56:43","Info","Start","OnInitialized","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/App.xaml.cs","42","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/03 01:56:43","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/03 01:56:43","Info","existsUserData: False","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/03 01:56:43","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","77","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"

前日のログ cocoa_log_20210202.csv の終端を見てみると……

"2021/02/02 21:56:39","Info","Start","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","47","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","tekItem.Created: 1612018805254","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
（略）
"2021/02/02 21:56:39","Info","tekItem.Created: 1612018809133","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","tekItem.Created: 1612105205617","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","tekItem.Created: 1612105208041","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","tekItem.Created: 1612105208563","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
（略）
"2021/02/02 21:56:39","Info","tekItem.Created: 1612191635879","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Start","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","existsUserData: True","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","End","Get","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","73","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","tekItem.Created: 1612191636725","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
（略）
"2021/02/02 21:56:39","Info","tekItem.Created: 1612191637771","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","248","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Batch number: 0, Downloaded files: 0","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","275","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Start","Initialize","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/HomePage/HomePageViewModel.cs","54","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Start","CheckVersion","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Common/AppUtils.cs","46","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Start","StartExposureNotification","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","118","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","currentdata equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","89","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","End","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","90","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","region: 440, userData.LastProcessTekTimestamp[440]: 1612191637771","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","278","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","End","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","280","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","End to download files","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","165","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","Batch number: 0, Downloaded files: 0","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","166","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:39","Info","End","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","199","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","End","Initialize","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/ViewModels/HomePage/SplashPageViewModel.cs","48","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","Success to download configuration","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","56","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","End","CheckVersion","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Common/AppUtils.cs","79","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","Start","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","83","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","currentdata equals newdata","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","89","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","End","SetAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/UserDataService.cs","90","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","End","StartExposureNotification","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","128","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","Start","FetchExposureKeyAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","79","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","Start","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","153","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","Start download files","FetchExposureKeyBatchFilesFromServerAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","163","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"
"2021/02/02 21:56:40","Info","Start","DownloadBatchAsync","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationHandler.cs","204","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"

と、ここで唐突に終わっています。中途半端なところで terminate された感はありますね。
このログをサポートに送信したところ、2月中旬に改修予定との返信をいただきましたので、メンテナの方も原因を把握しているのかもしれません。issue へのレスポンス無いのでわかりませんが。

@ypresto
Copy link

ypresto commented Feb 5, 2021

@yozjp ありがとうございます！

DownloadBatchAsyncで止まってるようにも見えますが、ログを1行ずつ突き合わせると

"2021/02/02 21:56:39","Info","Start","GetExposureNotificationConfig","/Users/runner/work/1/s/Covid19Radar/Covid19Radar/Services/ExposureNotificationService.cs","47","iOS","14.4","iPhone12,1","Physical","1.2.1","1607653212"

の後にGetExposureNotificationConfigの中で

loggerService.Info("Success to download configuration");

が呼ばれてますが、その直後のSavePropertiesAsyncの後に呼ばれるはずの

loggerService.EndMethod();

に該当するログがないようですね。わたしのパターンと同じのように見受けられます。

@ypresto
Copy link

ypresto commented Feb 5, 2021 •
edited
Loading

image

実際にXamarin.Formsのコードのこの位置にbreakpointを差し込んでやってみて、この位置でアプリが落ちるとデータが消えてしまうことが確認できました。

COCOA自体をデバッグ用に準備する手順は下記のとおりです。（すでにデバッグ実行できる場合は、デバッグソースファイルを追加するだけでOKです）

  1. COCOAとXamarin.Formsをgit cloneする。
  2. Visual Studio for Macをインストールして、Covid19Radar.slnを開く。
  3. ユーザー設定からApple IDでログインしましたが、シミュレーターで実行するだけなら不要かもしれないです。
  4. Androidのセットアップが面倒だったので、Covid19Radar.Androidを右クリックしてアンロードしました。
    合わせて Covid19Radar/Xamarin.ExposureNotification/Xamarin.ExposureNotification.csproj からmonoandroidをコメントアウトします。
    <TargetFrameworks>netstandard2.0;xamarin.ios10<!--;monoandroid10.0--></TargetFrameworks>
  5. ソリューションペイン（左側）で一番上のCovid19Radarを右クリック→オプションから、デバッグソースファイルを開いてcloneしたXamarin.Formsのディレクトリを追加します。
  6. ツールバー左上から Covid19Radar.iOS › Debug_Mock | iPhoneSimulator › (任意のシミュレーター） の構成を選択します
  7. GetExposureNotificationConfig()の中の httpClient.GetAsync(url) を httpClient.GetAsync("https://covid19radar-jpn-prod.azureedge.net/c19r/Configration.json") に書き換える

ここまでセットアップしたら、下記の手順で再現させます。

  1. 実行ボタンでアプリを起動して、COCOAの初期設定を済ませる
  2. 一度停止ボタンを押して再実行して、データが消えていないことを確認する
  3. GetExposureNotificationConfig()のSavePropertiesAsync()の行にブレークポイントを設定する
  4. 再度実行ボタンで起動したら、SavePropertiesAsync()の行で止まる
  5. ステップインを押すと、SavePropertiesAsync()を通り過ぎてAsyncTaskMethodBuilderの中に入ってしまいますが、辛抱強くステップインを連打するとSavePropertiesAsync()の最初に到達する
  6. Commandキー+クリックでSetPropertiesAsync()の中に入り、await DependencyService.Get<IDeserializer>().SerializePropertiesAsync(Properties) の行にブレークポイントをつけて再開
  7. 止まったらステップ・インすると、DependencyService周りのコードに入るのでステップアウトで抜ける（SetPropertiesAsyncに戻ってくる）
  8. 再度ステップインするとDictionaryの中に入るのでステップアウトで抜けると、SerializePropertiesAsync()の先頭に到達する
  9. store.MoveFile()の行にブレークポイントをつけて再開し、止まったらそのままアプリをVisual Studioの停止ボタンで終了する
  10. 再度起動すると、初期設定画面に遷移することが確認できる

再度起動した際のログは下記の通りで、existsUserData: Falseとなっていることが確認できました。

"2021/02/06 00:47:19","Info","Start","OnInitialized","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/App.xaml.cs","42","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"
"2021/02/06 00:47:19","Info","Start","Get","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/Services/UserDataService.cs","67","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"
"2021/02/06 00:47:19","Info","existsUserData: False","Get","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/Services/UserDataService.cs","70","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"
"2021/02/06 00:47:19","Info","End","Get","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/Services/UserDataService.cs","77","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"
"2021/02/06 00:47:19","Info","No user data exists","OnInitialized","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/App.xaml.cs","80","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"
"2021/02/06 00:47:19","Info","Transition to TutorialPage1","OnInitialized","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/App.xaml.cs","81","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"
"2021/02/06 00:47:19","Info","End","OnInitialized","/Users/ypresto/github/cocoa/Covid19Radar/Covid19Radar/App.xaml.cs","99","iOS","14.4","x86_64","Virtual","APP_VERSION","1.1"

This was referenced Feb 5, 2021
Open
Closed
@ypresto
Copy link

ypresto commented Feb 13, 2021 •
edited
Loading

（質問をいただいたので追記）該当箇所はAndroidもiOSも影響を受けていそうですが、iOSだけ報告が多い理由は、通知などからのバックグラウンド実行（してるかは未確認）に厳しい時間制限（強制終了）があったはずで、おそらくそのタイミングと運悪く重なっているのではと推測しています。Androidはスリープはされてもメモリ不足にならない限りkillされない記憶です。
（追記：Xcodeでクラッシュログも見てみましたがcocoaのものはなかったので、例外で落ちてるわけではないと判断しています）

@tmurakami
Copy link

Android版はバックグラウンド実行がまともに動いていないからではないでしょうか。
MainActivityが起動している状態でないとWorker経由でのExposureNotificationHandlerの実行に失敗するのではないかと思います。
バックグラウンド実行させるためには、Appへの依存を取り除く必要があるのではないかと。
(サポートさんには報告済みです)

@amay077
Copy link
Contributor

amay077 commented Feb 13, 2021 •
edited
Loading

xamarin/Xamarin.Forms#13676 で報告されている SerializePropertiesAsync() はスレッドセーフかなあ、と心配しています。

#16 (comment) のログは、

  1. Start - GetExposureNotificationConfig
  2. Start - SetAsync

どちらも End はなし。

#16 (comment) のログは、

  1. Start - GetExposureNotificationConfig
  2. Start - DownloadBatchAsync

どちらも End はなし。

となっており、SerializePropertiesAsync() が同じタイミングで実行される可能性はあって、その時 SerializePropertiesAsync() （というか IsolatedStorageFile の実装）は大丈夫かな？と思っています（未確認）。※

あるいは GetExposureNotificationConfig は、 ExposureNotificationService のコンストラクタで呼び出されて、await されてない?ようなので、これが適切に await されると何か変わるのかも知れません。

※追記

あ、 Xamarin.iOS や Xamarin.Android の IsolatedStorageFile の実装がスレッドセーフであっても、Xamarin.Forms.Platform.{iOS,Android,Tizen}/Deserializer.cs - SerializePropertiesAsync() や、COCOA 側で SerializePropertiesAsync() を呼び出している各所がスレッドセーフであるとは限らないので、非同期処理が並列に実行される現状は望ましくなさそうだと思います。

@zaruudon
Copy link

となっており、SerializePropertiesAsync() が同じタイミングで実行される可能性はあって、その時 SerializePropertiesAsync() （というか IsolatedStorageFile の実装）は大丈夫かな？と思っています（未確認）。※

同時に書き込むと例外が発生する、という問題が以前にあって今はセマフォで排他制御をしているようです。
xamarin/Xamarin.Forms@afa0fb7

@amay077
Copy link
Contributor

amay077 commented Feb 14, 2021

なるほど、GetExposureNotificationConfig と SetAsync、または GetExposureNotificationConfig と DownloadBatchAsync が並列に実行されて大丈夫かなあ？という不安はあるものの(突然 terminate する事とは関係無さそうです)、Xamarin.Forms の Application.SavePropertiesAsync はスレッドセーフと言えそうですね、ありがとうございます。

@heykuro
Copy link
Collaborator

heykuro commented Feb 26, 2021

@moonmile さんはじめ皆さま、Issueコメント、さまざまな原因調査・検証のご協力ありがとうございます。
頂いた情報を元に厚労省および開発チームにて検討しまして、この度対応を実施しました。

@ypresto さんご指摘の通り、厚生労働省でもXamarin.Formsの該当箇所でアプリが落ちた場合にデータ消失が発生することを確認しており、今回以下の通り対策を講じました。また、iOSにおいて発生している問題でしたが、今回iOS/Android双方で同様に処理を変更しています。

具体的には、データ保存について、Xamarin.FormsではなくiOS/AndroidのNative APIを使用するよう変更し、データ保存は同期処理として、かつ保存処理時に排他制御をかけています。

この上で同様の不具合が継続して発生する場合は、更なる検証、対応を進めます。
今後もお気づきの点がありましたらぜひIssueにてご指摘ください。

@moonmile moonmile mentioned this issue Feb 26, 2021
Open
@C-Juku C-Juku mentioned this issue May 5, 2021
Closed
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
9 participants
@ypresto @amay077 @moonmile @tmurakami @yozjp @heykuro @Ryo-9399 @cocoa-dev @zaruudon