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...
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: