Forum Discussion

🚨 This forum is archived and read-only. To submit a forum post, please visit our new Developer Forum. 🚨
LucaMefisto's avatar
LucaMefisto
Meta Employee
10 years ago

Odd spikes after updating

Hello!

I just updated my old old build from Unity 5.1.0 (SDK 0.6...) to 5.3.0f4 (latest tools) and I am getting a huge performance loss.

Unity v5.3.0f4, Oculus Utilities v0.1.3.0, OVRPlugin v0.1.4.0.

I know I know this is not that weird for what I have read, but look at this screenshot running the profiler directly from my Note 4(4.4.4):

http://i.imgur.com/kugl6et.png

I disabled all renderers and pretty much anything that could overhead the CPU and GPU (it's basically renderingh just a skybox) and still I get 14ms in CPU with regular 30ms spikes.

Maybe I did the upgrade very wrong? :S This was working before at 55fps (with everything enabled of course)

HALP!

Edit: oj just seen this viewtopic.php?f=37&t=27963#p310144 but he is at least rendering stuff. Should I downgrade again? what is the previous recommended version?

5 Replies

Replies have been turned off for this discussion
  • cybereality's avatar
    cybereality
    Grand Champion
    10 years ago
    Is you profile for the phone or for running in the Editor on the PC? Is your PC capable and have you installed the latest drivers? If the issue is on the phone, can you provide a logcat? You can also try Unity 5.2.3p3.
  • LucaMefisto's avatar
    LucaMefisto
    Meta Employee
    10 years ago
    Thanks for the reply cybereality!

    -The profiler is for the phone indeed (Galaxy note 4) running in the profiling mode.
    My computer is quite powerful (drivers updated 2 weeks ago maximum, GTX970 )
    I will extract a log cat and put it here when I get home (around 3-4 hours) and also try 5.2.3p3
  • LucaMefisto's avatar
    LucaMefisto
    Meta Employee
    10 years ago
    The logcat keeps spamming this:



    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)

    I/E:\tw\33a21edae6c0e9ad\Software\OculusSDK\Integrations\Unity\Releases\0(11727): OVR_TW_SetDebugMode(0,0)


    Could be the cause?

    Edit: I got rid of that log (positional tracking was enabled) but the spikes persist. This is my "cleaner" logcat




    D/NetworkStatsFactory(  918): UpdateStatsForKnox

    V/NetworkStats(  918): performPollLocked(flags=0x1)

    D/ConnectivityService(  918): getLinkProperties for 1000{LinkAddresses: []  Routes: [] DnsAddresses: [] Domains: nullMTU: 0}

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    V/NetworkStats(  918): performPollLocked() took 44ms

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=53,Prd=44ms,Tear=0,Early=1,Stale=10,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    E/LocSvc_api_v02( 9670): D/locClientQmiCtrlPointInit:1924]: Service not up. Starting delay timer

    W/TimeWarp(12307): V-sync 5397: Eye 0, CPU latency 0.001, GPU latency 0.008, Total latency = 0.009

    I/TimeWarp(12307): WarpSwap: usleep( 395 )

    I/TimeWarp(12307): WarpSwap: usleep( 374 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/TimeWarp(12307): WarpSwap: usleep( 400 )

    W/TimeWarp(12307): V-sync 5411: Eye 0, CPU latency 0.001, GPU latency 0.008, Total latency = 0.009

    D/BatteryService(  918): level:100, scale:100, status:5, health:2, present:true, voltage: 4257, temperature: 223, technology: Li-ion, AC powered:false, USB powered:true, Wireless powered:false, icon:17303785, invalid charger:0, online:4, current avg:-549, charge type:1, power sharing:false, high voltage charger:false, capacity:322000

    D/BatteryService(  918): Sending ACTION_BATTERY_CHANGED.

    D/KeyguardUpdateMonitor( 1179): received broadcast android.intent.action.BATTERY_CHANGED

    D/KeyguardUpdateMonitor( 1179): handleBatteryUpdate

    D/UiModeManager(  918): mCoverManager.getCoverState() : true

    D/STATUSBAR-PhoneStatusBar( 1200):  mBrightnessEnablebySettings = true mBrightnessEnablebyBattery = true mBrightnessEnablebyDisableFlag = true mPmsBrightnessEnablebySettings = true

    D/BatteryMeterView( 1200): ACTION_BATTERY_CHANGED : level:100 status:5 health:2

    I/TimeWarp(12307): WarpSwap: usleep( 635 )

    W/TimeWarp(12307): V-sync 5420: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.010

    I/TimeWarp(12307): WarpSwap: usleep( 196 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=54,Prd=44ms,Tear=1,Early=0,Stale=9,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    I/TimeWarp(12307): WarpSwap: usleep( 91 )

    V/AlarmManager(  918): waitForAlarm result :8

    V/AlarmManager(  918): ClockReceiver onReceive() ACTION_TIME_TICK

    D/KeyguardUpdateMonitor( 1179): received broadcast android.intent.action.TIME_TICK

    D/KeyguardUpdateMonitor( 1179): handleTimeUpdate

    D/accuweather( 2740): [KK AccuPhone]>>> WCS:142 [0:0] action : androidintentactionTIME_TICK

    D/accuweather( 2740): [KK AccuPhone]>>> UIM:119 [0:0] getInstance

    D/accuweather( 2740): [KK AccuPhone]>>> UIM:286 [0:0] direct update clock

    D/accuweather( 2740): [KK AccuPhone]>>> RU:74 [0:0] get ww = 339, wh = 160span x = 4, span y = 2

    D/accuweather( 2740): [KK AccuPhone]>>> UIM:1428 [0:0] mc sy = 2

    D/accuweather( 2740): [KK AccuPhone]>>> RU:74 [0:0] get ww = 339, wh = 160span x = 4, span y = 2

    D/accuweather( 2740): [KK AccuPhone]>>> UIM:189 [0:0] get widget 4x2 view!!! wid = 1

    E/accuweather( 2740): [KK AccuPhone]>>> UIM:1466 [0:0] bTM 20 20

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    E/Watchdog(  918): !@Sync 2971

    W/TimeWarp(12307): V-sync 5472: Eye 0, CPU latency 0.001, GPU latency 0.008, Total latency = 0.009

    I/TimeWarp(12307): WarpSwap: usleep( 66 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=55,Prd=44ms,Tear=3,Early=0,Stale=8,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    W/TimeWarp(12307): V-sync 5521: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.010

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    W/TimeWarp(12307): V-sync 5524: Eye 0, CPU latency 0.000, GPU latency 0.009, Total latency = 0.010

    I/TimeWarp(12307): preFinish - afterSleepTime = 5.9 ms

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    V/NetworkStats(  918): performPollLocked(flags=0x1)

    D/NetworkStatsFactory(  918): UpdateStatsForKnox

    D/ConnectivityService(  918): getLinkProperties for 1000{LinkAddresses: []  Routes: [] DnsAddresses: [] Domains: nullMTU: 0}

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    V/NetworkStats(  918): performPollLocked() took 53ms

    I/TimeWarp(12307): WarpSwap: usleep( 87 )

    W/TimeWarp(12307): V-sync 5541: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.009

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=57,Prd=44ms,Tear=1,Early=0,Stale=6,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    D/ConnectivityManager(30671): getActiveNetworkInfo : NetworkInfo: type: WIFI[], state: CONNECTED/CONNECTED, reason: (unspecified), extra: "NukeTheWhales", roaming: false, failover: false, isAvailable: true, isConnectedToProvisioningNetwork: false

    W/TimeWarp(12307): V-sync 5581: Eye 0, CPU latency 0.001, GPU latency 0.010, Total latency = 0.011

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/TimeWarp(12307): WarpSwap: usleep( 642 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=54,Prd=44ms,Tear=3,Early=1,Stale=9,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    E/LocSvc_api_v02( 9670): D/locClientQmiCtrlPointInit:1924]: Service not up. Starting delay timer

    W/TimeWarp(12307): V-sync 5631: Eye 0, CPU latency 0.001, GPU latency 0.010, Total latency = 0.010

    I/TimeWarp(12307): WarpSwap: usleep( 9 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/TimeWarp(12307): WarpSwap: usleep( 918 )

    W/TimeWarp(12307): V-sync 5649: Eye 0, CPU latency 0.001, GPU latency 0.010, Total latency = 0.011

    I/TimeWarp(12307): WarpSwap: usleep( 291 )

    W/TimeWarp(12307): V-sync 5657: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.009

    I/TimeWarp(12307): WarpSwap: usleep( 418 )

    W/TimeWarp(12307): V-sync 5659: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.009

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NetworkStatsFactory(  918): UpdateStatsForKnox

    V/NetworkStats(  918): performPollLocked(flags=0x1)

    D/ConnectivityService(  918): getLinkProperties for 1000{LinkAddresses: []  Routes: [] DnsAddresses: [] Domains: nullMTU: 0}

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=56,Prd=44ms,Tear=1,Early=0,Stale=6,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    I/TimeWarp(12307): WarpSwap: usleep( 425 )

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    V/NetworkStats(  918): performPollLocked() took 45ms

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    W/TimeWarp(12307): V-sync 5703: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.010

    I/TimeWarp(12307): WarpSwap: usleep( 195 )

    W/TimeWarp(12307): V-sync 5704: Eye 0, CPU latency 0.000, GPU latency 0.008, Total latency = 0.009

    I/TimeWarp(12307): WarpSwap: usleep( 23 )

    I/TimeWarp(12307): WarpSwap: usleep( 247 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=53,Prd=44ms,Tear=4,Early=1,Stale=13,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    I/TimeWarp(12307): preFinish - afterSleepTime = 5.0 ms

    W/TimeWarp(12307): V-sync 5757: Eye 0, CPU latency 0.005, GPU latency 0.007, Total latency = 0.012

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)

    I/VrApi   (12307): FPS=56,Prd=44ms,Tear=2,Early=0,Stale=8,VSnc=1,Lat=1,CPU0/GPU=2/2,1497/389MHz,TA=F/F/F/F,Free=995MB,PLS=0,Temp=22.3C

    W/TimeWarp(12307): V-sync 5809: Eye 0, CPU latency 0.001, GPU latency 0.010, Total latency = 0.011

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/TimeWarp(12307): WarpSwap: usleep( 469 )

    W/TimeWarp(12307): V-sync 5824: Eye 0, CPU latency 0.001, GPU latency 0.009, Total latency = 0.010

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NetworkStatsFactory(  918): UpdateStatsForKnox

    V/NetworkStats(  918): performPollLocked(flags=0x1)

    D/ConnectivityService(  918): getLinkProperties for 1000{LinkAddresses: []  Routes: [] DnsAddresses: [] Domains: nullMTU: 0}

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    D/NtpTrustedTime(  918): currentTimeMillis() cache hit

    V/NetworkStats(  918): performPollLocked() took 41ms

    I/TimeWarp(12307): WarpSwap: usleep( 297 )

    E/csd_client(  331): csd_service_init: Check modem power up with MDM reset !!!

    I/OVR     (12307): DeviceManagerThread - poll(fds,1,1000) = 0 (Tid=12426)


    It states 53 fps sometimes in there (which is very little for something rendering just a skybox...) I imagine on the peaks will be lower (searching...)

    Edit2: Downgrading to 5.2.3p3 did not seem to work. I will spend some time this weekend with this maybe recreating the same scene in a brand new project... :cry:
  • vrdaveb's avatar
    vrdaveb
    Oculus Staff
    10 years ago
    Do you get the same spikes when you run the OVR/Scenes/Room.unity scene?
  • LucaMefisto's avatar
    LucaMefisto
    Meta Employee
    10 years ago
    Updating to 5.3.1 seems to have them gone!

    I also noticed that my Oclusion Culling bake was maybe overcomplex, probably affecting this?