2017-08-01 7 views
0

私のAndroid Xamarinフォームアプリケーションは、ViewModel/Viewを作成して実行時にビューをモーダルスタックにプッシュするとき、ディープリンクによってトリガーされたときにビューをプッシュする準備ができていないときに、Xamarin Androidの説明できない遅れ

アプリケーションはディープリンクを正常に受信していますが、目的のビューを表示しようとするとかなりのパフォーマンスが低下します。

IOSで実行されている同じアプリケーションにこの遅延がありません。

ログとコードを見ると、MT2の後、MT3ログエントリの前に、「***」とマークされた行で遅延が発生します。

私はDevice.BeginInvokeOnMainThreadを使って問題を改善するか悪化させるかを試していますが、この問題には何の影響も見ませんでした。

perfのハングアップは何ですか? TCPOptimizerは問題の一部ですか? 関連性がある場合は、2つの異なるSamsung S8でコードを実行しています。

コード

protected override async void OnAppLinkRequestReceived(Uri uri) 
{ 
    //Aside: I would rather use System.Web.HttpUtility to parse this query string, but it seems I can't in an Xam PCL. 

    //Pattern: 
    //my.app.deeplink://<command>?<params> 
    //Examples:        
    // Deep Linking Web Navigation: 
    //  my.app.deeplink://webnav?url=/ns/products/product/?id=1234&param1=value1&param2=value2 
    // Deep Linking Native Navigation: 
    //  my.app.deeplink://view?name=SettingsPageView&param1=value1&param2=value2 

    try 
    { 
     m_oLogging.LogInfo("OnAppLinkRequestReceived: " + uri.ToString()); 

     NavigationManager.DeepLinkCommand oDeepCmd = NavigationManager.ParseDeepLink(uri); 

     switch (oDeepCmd) 
     { 
      case NavigationManager.DeepLinkCommand.invalid: 
       m_oLogging.LogInfo("Deep Link deemed invalid. Doing nothing."); 
       break; 

      case NavigationManager.DeepLinkCommand.webnav: 
       //Query expected to be like: ?url=/ns/products/product/?id=1234&param1=value1&param2=value2 

       string szUri = uri.Query; 
       Uri oParsedURI = WebNavigationManager.URLS.ParseDeepLinkUri(szUri); 
       string szURL = oParsedURI.ToString(); 

       m_oLogging.LogInfo(string.Format("Proceeding with webnav to [{0}].", szURL)); 
       App oApp = ((App)Application.Current); 

       WebNavigationManager.Instance.NavigateToURL(szURL); 

       break; 

      case NavigationManager.DeepLinkCommand.view: 
       //Query like: ?name=SettingsPageView&param1=value1&param2=value2 

       string szView = uri.Query.Split('=')[1].Split('&')[0]; 
       string szViewTypeName = string.Empty; 
       switch (szView) 
       { 
        case "SettingsPageView": 
         szViewTypeName = typeof(SettingsPageView).Name; 
         break; 
        default: 
         //Try to dynamically present the named view. 
         szViewTypeName = "my.app.namespace." + szView; 
         break; 
       } 

       if (ViewIsAlreadyLoaded(szViewTypeName)) 
       { 
        //I'm already at that page, so chill! 
        m_oLogging.LogInfo(string.Format("View [{0}] is already loaded in one of the stacks. No need to load it again or duplicate it.", szViewTypeName)); 
       } 
       else 
       { 
        m_oLogging.LogInfo(string.Format("Proceeding with presenting view [{0}].", szViewTypeName)); 
        switch (szView) 
        { 
         case "SettingsPageView": 

          //There is nothing modal right now, or there is, but the top of the stack isn't the settings page. 
          m_oLogging.LogInfo(string.Format("Pushing known view modally: '{0}'", szViewTypeName)); 
          Device.BeginInvokeOnMainThread(() => 
          { 
           m_oLogging.LogInfo(string.Format("Pushing known view modally (MT1): '{0}'", szViewTypeName)); 
           IViewModel oSPVM = new SettingsPageViewModel(); 
           m_oLogging.LogInfo(string.Format("Pushing known view modally (MT2): '{0}'", szViewTypeName)); 
***        BaseView oSPV = new SettingsPageView(oSPVM); 
           m_oLogging.LogInfo(string.Format("Pushing known view modally (MT3): '{0}'", szViewTypeName)); 
           MainPage.Navigation.PushModalAsync(oSPV, false); 
           m_oLogging.LogInfo(string.Format("Pushed known view modally (MT4): '{0}'", szViewTypeName)); 
          }); 
          m_oLogging.LogInfo(string.Format("Pushed known view modally: '{0}'", szViewTypeName)); 
          break; 

         default: 

          //Try to dynamically present the named view. 
          var vViewModel = Activator.CreateInstance(Type.GetType(szViewTypeName + "Model")); 
          if (vViewModel != null) 
          { 
           var vView = Activator.CreateInstance(Type.GetType(szViewTypeName), vViewModel); 
           if (vView != null) 
           { 
            m_oLogging.LogInfo(string.Format("Pushing dynamic view modally: '{0}'", szViewTypeName)); 
            Device.BeginInvokeOnMainThread(async() => await MainPage.Navigation.PushModalAsync(vView as Page, false)); 
            m_oLogging.LogInfo(string.Format("Pushed dynamic view modally: '{0}'", szViewTypeName)); 
           } 
          } 
          break; 
        } 
       } 
       break; 
     } 
    } 
    catch (Exception oExc) 
    { 
     m_oLogging.LogError(oExc.Message); 
    } 


    base.OnAppLinkRequestReceived(uri); 
} 

ランタイムデバッグコンテンツ

08-01 15:14:59.023 I/MyApp (29249): OnAppLinkRequestReceived: my.package.name://view/?name=SettingsPageView&ampAction=Clicked 
08-01 15:14:59.030 I/MyApp (29249): Proceeding with presenting view [SettingsPageView]. 
08-01 15:14:59.031 I/MyApp (29249): Pushing known view modally: 'SettingsPageView' 
08-01 15:14:59.031 I/MyApp (29249): Pushed known view modally: 'SettingsPageView' 
Thread started: #17 
08-01 15:14:59.079 D/Mono (29249): [0xb7190920] worker starting 
08-01 15:14:59.153 D/[email protected]: Relayout returned: oldFrame=[0,0][1080,2220] newFrame=[0,0][1080,2220] result=0x7 surface={isValid=true -1281830912} surfaceGenerationChanged=true 
08-01 15:14:59.153 D/[email protected]: mHardwareRenderer.initialize() mSurface={isValid=true -1281830912} hwInitialized=true 
08-01 15:14:59.162 I/MyApp (29249): Pushing known view modally (MT1): 'SettingsPageView' 
Resolved pending breakpoint at 'SettingsPageViewModel.cs:25,1' to bool app.namespace.name.SettingsPageViewModel.get_PreferencePushService() [0x00001]. 
Resolved pending breakpoint at 'SettingsPageViewModel.cs:38,1' to bool app.namespace.name.SettingsPageViewModel.get_PreferencePushDelivery() [0x00001]. 
Resolved pending breakpoint at 'SettingsPageViewModel.cs:51,1' to bool app.namespace.name.SettingsPageViewModel.get_PreferencePushPromotion() [0x00001]. 
08-01 15:14:59.340 I/MyApp (29249): Pushing known view modally (MT2): 'SettingsPageView' 
08-01 15:14:59.488 D/Mono (29249): DllImport searching in: '__Internal' ('(null)'). 
08-01 15:14:59.488 D/Mono (29249): Searching for 'java_interop_jnienv_call_static_object_method'. 
08-01 15:14:59.488 D/Mono (29249): Probing 'java_interop_jnienv_call_static_object_method'. 
08-01 15:14:59.488 D/Mono (29249): Found as 'java_interop_jnienv_call_static_object_method'.

#############################[ 3 seconds of lag ]

08-01 15:15:02.826 D/TcpOptimizer(29249): [my.package.name] Full closed: sid=125, tcpi_state=8

#############################[ 1 second of lag ]

08-01 15:15:03.830 D/TcpOptimizer(29249): [my.package.name] Full closed: sid=130, tcpi_state=8 Thread finished: #15 The thread 'Unknown' (0xf) has exited with code 0 (0x0).

#############################[ 26 seconds of lag ]

08-01 15:15:29.177 I/System.out(29249): (HTTPLog)-Static: isSBSettingEnabled false 08-01 15:15:29.177 I/System.out(29249): (HTTPLog)-Static: isSBSettingEnabled false 08-01 15:15:29.179 I/MyApp (29249): CustomerID: (known) e3ecf5c1-3920-4cc9-ad08-0c1b2145db2b (<-- this code runs while data is being read from the viewmodel for the view) 08-01 15:15:29.186 I/System.out(29249): (HTTPLog)-Static: isSBSettingEnabled false 08-01 15:15:29.187 I/System.out(29249): (HTTPLog)-Static: isSBSettingEnabled false 08-01 15:15:29.188 I/System.out(29249): (HTTPLog)-Static: isSBSettingEnabled false 08-01 15:15:29.188 I/System.out(29249): (HTTPLog)-Static: isSBSettingEnabled false Thread started: #18 08-01 15:15:29.285 D/Mono (29249): Assembly Loader probing location: '/Users/builder/data/lanes/4009/3a62f1ea/source/monodroid/builds/install/mono-armv7/lib/app.namespace.name.resources.dll'. 08-01 15:15:29.285 D/Mono (29249): Assembly Loader probing location: '/Users/builder/data/lanes/4009/3a62f1ea/source/monodroid/builds/install/mono-armv7/lib/app.namespace.name.resources.exe'. 08-01 15:15:29.291 D/Mono (29249): Assembly Loader probing location: '/storage/emulated/0/Android/data/my.package.name/files/.override/en-US/app.namespace.name.resources.dll'. 08-01 15:15:29.364 I/MyApp (29249): Pushing known view modally (MT3): 'SettingsPageView' 08-01 15:15:29.428 W/art (29249): JNI RegisterNativeMethods: attempt to register 0 native methods for md5b60ffeb829f638581ab2bb9b1a7f4f3f.LabelRenderer 08-01 15:15:29.646 W/art (29249): JNI RegisterNativeMethods: attempt to register 0 native methods for md5b6ed58bdd2dc5ff75bde29ef5e42d6e8.ExtendedSwitchRenderer 08-01 15:15:30.001 I/MyApp (29249): Pushed known view modally (MT4): 'SettingsPageView' 08-01 15:15:30.002 I/Choreographer(29249): Skipped 1851 frames! The application may be doing too much work on its main thread. 08-01 15:15:30.111 D/ScrollView(29249): onsize change changed 08-01 15:15:30.189 D/[email protected]: MSG_WINDOW_FOCUS_CHANGED 1 08-01 15:15:30.189 D/[email protected]: mHardwareRenderer.initializeIfNeeded()#2 mSurface={isValid=true -1281830912} 08-01 15:15:30.229 V/InputMethodManager(29249): Starting input: [email protected] nm : my.package.name ic=null 08-01 15:15:30.230 I/InputMethodManager(29249): [IMM] startInputInner - mService.startInputOrWindowGainedFocus 08-01 15:15:30.231 D/InputTransport(29249): Input channel constructed: fd=160 08-01 15:15:30.233 D/InputMethodManager(29249): HSI from window - flag : 0 Pid : 29249 08-01 15:15:30.252 W/IInputConnectionWrapper(29249): reportFullscreenMode on inexistent InputConnection 08-01 15:15:38.190 D/Mono (29249): [0xb7190920] worker finishing Thread finished: #17 The thread 'Unknown' (0x11) has exited with code 0 (0x0). 08-01 15:15:41.995 D/TcpOptimizer(29249): [my.package.name] Full closed: sid=171, tcpi_state=8 08-01 15:15:49.902 D/[email protected]: MSG_RESIZED_REPORT: frame=Rect(0, 0 - 1080, 2220) ci=Rect(0, 72 - 0, 144) vi=Rect(0, 72 - 0, 144) or=1 08-01 15:15:49.972 D/[email protected]: Relayout returned: oldFrame=[0,0][1080,2220] newFrame=[0,0][1080,2220] result=0x1 surface={isValid=true -1281830912} surfaceGenerationChanged=false 08-01 15:15:51.378 D/[email protected]: MSG_WINDOW_FOCUS_CHANGED 0 08-01 15:15:54.111 D/[email protected]: MSG_WINDOW_FOCUS_CHANGED 1 08-01 15:15:54.111 D/[email protected]: mHardwareRenderer.initializeIfNeeded()#2 mSurface={isValid=true -1281830912} 08-01 15:16:09.240 D/Mono (29249): [0xbf27c920] worker finishing Thread finished: #10 The thread 'Unknown' (0xa) has exited with code 0 (0x0).

どのような援助が歓迎です!

答えて

0

さらに調査した結果、私が作成していたビューには、ビューモデルのプロパティにバインドされたラベルがあり、それがサードパーティ製SDKの値を返していたことがわかりました。 SDKは、この単純なプロパティに応答するのが遅かったため、いくつかのシナリオではうまくいきませんでした。修正プログラムは、非同期を使用してこの値を読み取るために、このパターンを使用していた

が待っています:私が役に立ったと評価してい

private string m_szCustomerID = null; 
public string CustomerID 
{ 
    get 
    { 
     if (m_szCustomerID == null) 
     { 
      m_oLogging.LogInfo("Fetching CustomerID Async"); 
      FetchCustomerID(); 
     } 
     m_oLogging.LogInfo("Returning: " + (m_szCustomerID == null ? "NULL": m_szCustomerID)); 
     return m_szCustomerID; 
    } 
    set 
    { 
     if (value != m_szCustomerID) 
     { 
      m_szCustomerID = value; 
      m_oLogging.LogInfo("CustomerID new value: " + (m_szCustomerID == null ? "NULL" : m_szCustomerID)); 
      NotifyPropertyChanged(); 
     } 
    } 
} 

private async void FetchCustomerID() 
{ 
    string szVal = null; 
    szVal = await m_oSDK.AsyncCustomerID; 

    if (szVal == null) 
    { 
     szVal = "(unknown) " + await m_oSDK.AsyncInstallID; 
    } 
    else 
    { 
     szVal = "(known) " + szVal; 
    } 
    CustomerID = szVal; 
} 

1つのリンクがあった。 共有の精神でHow to call an async method from a getter or setter?

、私は共有しますパフォーマンス問題を分離するのに便利です:

LoggedSection Tool - タイミングの問題を見つけるのに役立つようにコード化されたシンプルなクラスは、次のとおりです。

//IDisposable is a Try/Finally if you look at it using Ildasm.exe. 
//Using it here provides some convenient info gathered without a lot of overhead while the code being logged is executing. 
public class LoggedSection : IDisposable 
{ 
    private ILogging m_iLogger = null; 
    private string m_szSpanDescription; 
    private string m_szCallerMemberName; 
    private string m_szFilePath; 
    private DateTime m_dtStart; 
    private Guid m_oGuid; 
    private List<MileStone> m_oMileStones = null; 

    private class MileStone 
    { 
     private string m_szMileStone; 
     private DateTime m_dtWhen; 

     public MileStone(string szWhat) 
     { 
      m_szMileStone = szWhat; 
      m_dtWhen = DateTime.Now; 
     } 

     public string What 
     { 
      get 
      { 
       return m_szMileStone; 
      } 
     } 

     public DateTime When 
     { 
      get 
      { 
       return m_dtWhen; 
      } 
     } 
    } 

    public LoggedSection(ILogging iLogger, string szSpanDescription = "", [CallerMemberName] string szCallerMemberName = "", [CallerFilePath] string szFilePath = null) 
    { 
     m_oGuid = Guid.NewGuid(); 
     m_dtStart = DateTime.Now; 
     m_iLogger = iLogger; 
     m_szSpanDescription = szSpanDescription; 
     m_szCallerMemberName = szCallerMemberName; 
     m_szFilePath = szFilePath; 
     m_iLogger.LogInfo(string.Format("At: {3} Span ID '{2}' Name '{0}' Started in [{1}].", 
      m_szSpanDescription, m_szCallerMemberName, m_oGuid.ToString(), m_dtStart.ToString(TIME_FORMAT)), 
      m_szCallerMemberName, m_szFilePath); 
    } 

    public void AddMileStone(string szMileStone) 
    { 
     if (m_oMileStones == null) m_oMileStones = new List<MileStone>(); 
     m_oMileStones.Add(new MileStone(szMileStone)); 
    } 

    private const string TIME_FORMAT = "hh:mm:ss.fff";  

    public void Dispose() 
    { 
     DateTime dtNow = DateTime.Now; 
     try 
     { 
      if (m_oMileStones != null) 
      { 
       DateTime dtLastStone = m_dtStart; 
       int iStone = 1; 
       foreach (MileStone oStone in m_oMileStones) 
       { 
        m_iLogger.LogInfo(string.Format("At: {8} Span ID '{4}' Name '{0}' MileStone #{7} '{5}' in [{1}].{2} TIME ELAPSED: {3} MS INTO SPAN {6} MS since last Milestone", 
         m_szSpanDescription, m_szCallerMemberName, System.Environment.NewLine, (oStone.When - m_dtStart).TotalMilliseconds, m_oGuid.ToString(), oStone.What, (oStone.When - dtLastStone).TotalMilliseconds, iStone, oStone.When.ToString(TIME_FORMAT)), 
         m_szCallerMemberName, m_szFilePath); 
        dtLastStone = oStone.When; 
        iStone++; 
       } 
      } 

      m_iLogger.LogInfo(string.Format("At: {5} Span ID '{4}' Name '{0}' Finished in [{1}].{2} TIME ELAPSED: {3} MS", 
       m_szSpanDescription, m_szCallerMemberName, System.Environment.NewLine, (dtNow - m_dtStart).TotalMilliseconds, m_oGuid.ToString(), dtNow.ToString(TIME_FORMAT)), 
       m_szCallerMemberName, m_szFilePath); 
     } 
     catch(Exception oExc) 
     { 
      try 
      { 
       m_iLogger.LogError("An exception occurred in LoggedSection: " + oExc.Message, m_szCallerMemberName, m_szFilePath); 
      } 
      catch { } 
     } 
    } 
} 

Loggerクラスコード別名ILoggerです

public void LogError(string szError, [CallerMemberName] string szMember = null, [CallerFilePath] string szFilePath = null) 
{ 
    Log.Error(APP, FormatLog(szError, szMember, szFilePath)); 
} 

public void LogInfo(string szInfo, [CallerMemberName] string szMember = null, [CallerFilePath] string szFilePath = null) 
{ 
    Log.Info(APP, FormatLog(szInfo, szMember, szFilePath)); 
} 

public void LogWarning(string szWarning, [CallerMemberName] string szMember = null, [CallerFilePath] string szFilePath = null) 
{ 
    Log.Warn(APP, FormatLog(szWarning, szMember, szFilePath)); 
} 

private string FormatLog(string szInfo, string szMember, string szFilePath) 
{ 
    return string.Format("{4}{3}{0}{3}{1}{3}{2}{3}{4}{3}", 
     (szFilePath == null ? string.Empty : "File [" + szFilePath + "]"), 
     (szMember == null ? string.Empty : "Member [" + szMember + "]"), 
            szInfo, 
            System.Environment.NewLine, 
            "-----------------------------------------"); 
} 

記録されたセクションクラス使用例

using (LoggedSection oLogSec = new LoggedSection(m_oLogging, string.Format("Pushing known view modally: '{0}'", szViewTypeName))) 
{ 
    oLogSec.AddMileStone("Creating ViewModel SettingsPageViewModel"); 
    IViewModel oSPVM = new SettingsPageViewModel(); 
    oLogSec.AddMileStone(string.Format("Creating View {0}", szViewTypeName)); 
    BaseView oSPV = new SettingsPageView(oSPVM); 
    oLogSec.AddMileStone(string.Format("Pushing View {0}", szViewTypeName)); 
    MainPage.Navigation.PushModalAsync(oSPV, false); 
    oLogSec.AddMileStone(string.Format("Pushed View {0}", szViewTypeName)); 
} 

上記実行時に出力ウィンドウに見られる結果は、各として、有用ですマイルストーンは、Guid値でFindを使用するだけで、ログに記録されたセクションとの相関があります。最後のマイルストーン以来のタイミングだけでなく、セクションにタイミングを入れます。

この問題では、コードにLoggedSectionsが追加されているため、パフォーマンスの問題がかなり早く解決されました。

関連する問題