Question / Help "Possible slow server"

twirlyd

New Member
I have tried every EU server, ran the logs through the analyzer and every one of them came back as 300+ ms. The JTVPing app says my ping is fine on all of them.

Why is this happening and what will it affect, if anything?
 

Gol D. Ace

Member
Are you talking about this?
for example
16:07:35: Completed handshake with rtmp://live-fra.justin.tv/app in 429 ms.

This isn't your ping.


This would be your average ping to the server. (Hopefully I'm not talking bs right now.)
16:11:16: Average send payload: 4568 bytes, average send interval: 22 ms
 

twirlyd

New Member
I'm talking about this:
OBS Log Analyzer said:
Possible slow server
The server you are streaming to (rtmp://live-arn.justin.tv/app) took 511 ms to connect. This may mean your connection or the server is slow, or the server is far away from you. If you are using twitch.tv, you may want to try using JTVPing to find an optimal server.
 

R1CH

Forum Admin
Developer
Connecting can take a little longer than a ping, since it has to complete an RTMP handshake. Generally this should happen very quickly, within 200ms with a decent server as it only has to exchange 1kb of data or so. 511ms is suspiciously high, try changing around to other servers and see what happens.

Gol D. Ace said:
Are you talking about this?
This would be your average ping to the server. (Hopefully I'm not talking bs right now.)
16:11:16: Average send payload: 4568 bytes, average send interval: 22 ms
This isn't the ping, this measures the delay between data sends. A low number means a smooth data rate which is good.
 

twirlyd

New Member
R1CH said:
Connecting can take a little longer than a ping, since it has to complete an RTMP handshake. Generally this should happen very quickly, within 200ms with a decent server as it only has to exchange 1kb of data or so. 511ms is suspiciously high, try changing around to other servers and see what happens.

Gol D. Ace said:
Are you talking about this?
This would be your average ping to the server. (Hopefully I'm not talking bs right now.)
16:11:16: Average send payload: 4568 bytes, average send interval: 22 ms
This isn't the ping, this measures the delay between data sends. A low number means a smooth data rate which is good.
As I said, I've tried all the EU ones and they were all 300+.
 

twirlyd

New Member
R1CH said:
If you aren't experiencing any frame drops I wouldn't worry about it.
Well it's probably unrelated to this but this previous issue is still unresolved. Any ideas?

I streamed at 60fps about an hour ago and near the end of the game my FPS once again dropped down from ~150 to about 20-40, the same way I outlined in that earlier thread. I stopped the stream shortly after. Here's the log:

Code:
20:09:56: Open Broadcaster Software v0.571b - 64bit ( ^ω^)
20:09:56: -------------------------------
20:09:56: CPU Name: Intel(R) Core(TM) i7 CPU         860  @ 2.80GHz
20:09:56: CPU Speed: 2809MHz
20:09:56: Physical Memory:  4087MB Total, 778MB Free
20:09:56: stepping id: 5, model 14, family 6, type 0, extmodel 0, extfamily 0, HTT 1, logical cores 8, total cores 4
20:09:56: monitor 1: pos={0, 0}, size={1920, 1080}
20:09:56: Windows Version: 6.1 Build 7601 S
20:09:56: Aero is Enabled
20:09:56: -------------------------------
20:09:56: OBS Modules:
20:09:56: Base Address     Module
20:09:56: 000000003FB00000 OBS.exe
20:09:56: 00000000EF020000 OBSApi.dll
20:09:56: 00000000F8820000 DShowPlugin.dll
20:09:56: 00000000F8960000 GraphicsCapture.dll
20:09:56: 00000000F8940000 NoiseGate.dll
20:09:56: 00000000F7C40000 PSVPlugin.dll
20:09:56: ------------------------------------------
20:09:56: Adapter 1
20:09:56:   Video Adapter: NVIDIA GeForce GTX 660 Ti
20:09:56:   Video Adapter Dedicated Video Memory: 2086993920
20:09:56:   Video Adapter Shared System Memory: 1874358272
20:09:56: =====Stream Start: 2013-10-08, 20:09:56===============================================
20:09:56:   Multithreaded optimizations: On
20:09:56:   Base resolution: 1920x1080
20:09:56:   Output resolution: 1280x720
20:09:56: ------------------------------------------
20:09:56: Loading up D3D10 on NVIDIA GeForce GTX 660 Ti...
20:09:57: ------------------------------------------
20:09:57: Audio Format: 48000hz
20:09:57: Playback device {0.0.0.00000000}.{2aa6d56f-8292-466b-8045-762e58135486}
20:09:57: ------------------------------------------
20:09:57: Using desktop audio input: Headset (2- ASUS Xonar D2X Audio Device)
20:09:57: ------------------------------------------
20:09:57: Using auxilary audio input: Microphone (2- ASUS Xonar D2X Audio Device)
20:09:57: ------------------------------------------
20:09:57: Audio Encoding: AAC
20:09:57:     bitrate: 128
20:09:57: Using graphics capture
20:09:57: ------------------------------------------
20:09:57: Video Encoding: x264
20:09:57:     fps: 60
20:09:57:     width: 1280, height: 720
20:09:57:     preset: veryfast
20:09:57:     profile: high
20:09:57:     keyint: 120
20:09:57:     CBR: yes
20:09:57:     CFR: yes
20:09:57:     max bitrate: 3500
20:09:57:     buffer size: 3500
20:09:57: ------------------------------------------
20:09:57: MMDeviceAudioSource: Frequency for device 'Headset (2- ASUS Xonar D2X Audio Device)' is 352800, samples per sec is 44100
20:09:57: MMDeviceAudioSource: Frequency for device 'Microphone (2- ASUS Xonar D2X Audio Device)' is 352800, samples per sec is 44100
20:09:59: Using RTMP service: Twitch / Justin.tv
20:09:59:   Server selection: rtmp://live-arn.justin.tv/app
20:09:59:   Interface: Realtek RTL8168D/8111D Family PCI-E Gigabit Ethernet NIC (NDIS 6.20) (ethernet, 100 mbps)
20:09:59: Completed handshake with rtmp://live-arn.justin.tv/app in 536 ms.
20:10:01: SO_SNDBUF was at 8192
20:10:01: SO_SNDBUF is now 65536
20:10:02: RTMPPublisher::Socketloop: Increasing send buffer to ISB 131072 (buffer: 0 / 463872)
20:10:05: SharedTexCapture hooked
20:10:07: RTMPPublisher::Socketloop: Increasing send buffer to ISB 262144 (buffer: 3947 / 463872)
20:46:08: Capture window 0x000C069E invalid or changing, terminating capture
20:46:37: Total frames encoded: 131953, total frames duplicated: 233 (0.18%)
20:46:37: Number of frames skipped due to encoder lag: 113 (0.09%)
20:46:37: Total frames rendered: 131806, number of late frames: 25 (0.02%) (it's okay for some frames to be late)
20:46:37: RTMPPublisher::SocketLoop: Graceful loop exit
20:46:37: Average send payload: 6504 bytes, average send interval: 14 ms
20:46:37: Number of times waited to send: 0, Waited for a total of 0 bytes
20:46:37: Number of b-frames dropped: 0 (0%), Number of p-frames dropped: 0 (0%), Total 0 (0%)
20:46:37: Number of bytes sent: 998026848
20:46:37: 
20:46:37: Profiler time results:
20:46:37: 
20:46:37: ==============================================================
20:46:37: video thread frame - [100%] [avg time: 0.069 ms] [children: 1.45%] [unaccounted: 98.6%]
20:46:37: | scene->Preprocess - [1.45%] [avg time: 0.001 ms]
20:46:37: GPU download and conversion - [100%] [avg time: 0.34 ms] [children: 81.5%] [unaccounted: 18.5%]
20:46:37: | flush - [61.2%] [avg time: 0.208 ms]
20:46:37: | CopyResource - [19.4%] [avg time: 0.066 ms]
20:46:37: | conversion to 4:2:0 - [0.882%] [avg time: 0.003 ms]
20:46:37: Convert444Threads - [100%] [avg time: 0.676 ms] [children: 99.4%] [unaccounted: 0.592%]
20:46:37: | Convert444toNV12 - [99.4%] [avg time: 0.672 ms]
20:46:37: encoder thread frame - [100%] [avg time: 1.232 ms]
20:46:37: ==============================================================
20:46:37: 
20:46:37: 
20:46:37: Profiler CPU results:
20:46:37: 
20:46:37: ==============================================================
20:46:37: video thread frame - [cpu time: avg 0.002 ms, total 312.002 ms] [avg calls per frame: 1]
20:46:37: | scene->Preprocess - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
20:46:37: GPU download and conversion - [cpu time: avg 0.007 ms, total 998.405 ms] [avg calls per frame: 1]
20:46:37: | flush - [cpu time: avg 0.004 ms, total 592.803 ms] [avg calls per frame: 1]
20:46:37: | CopyResource - [cpu time: avg 0.001 ms, total 202.801 ms] [avg calls per frame: 1]
20:46:37: | conversion to 4:2:0 - [cpu time: avg 0 ms, total 15.6 ms] [avg calls per frame: 1]
20:46:37: Convert444Threads - [cpu time: avg 0.241 ms, total 63617.2 ms] [avg calls per frame: 2]
20:46:37: | Convert444toNV12 - [cpu time: avg 0.237 ms, total 62681.2 ms] [avg calls per frame: 2]
20:46:37: encoder thread frame - [cpu time: avg 0.848 ms, total 111978 ms] [avg calls per frame: 1]
20:46:37: ==============================================================
20:46:37: 
20:46:37: =====Stream End: 2013-10-08, 20:46:37=================================================


Last game capture log:
2013-10-08, 18:13:57: we're booting up: 
18:13:57: D3D9 Present
18:13:58: NV Capture available
18:13:58: FBO available
18:13:58: GL Present
18:13:58: (half life scientist) everything..  seems to be in order
18:32:47: D3D9EndScene called
18:32:47: D3DPRESENT_PARAMETERS {
18:32:47: 	BackBufferWidth: 1920
18:32:47: 	BackBufferHeight: 1080
18:32:47: 	BackBufferFormat: D3DFMT_A8R8G8B8
18:32:47: 	BackBufferCount: 1
18:32:47: 	MultiSampleType: D3DMULTISAMPLE_8_SAMPLES
18:32:47: 	MultiSampleQuality: 0
18:32:47: 	SwapEffect: D3DSWAPEFFECT_DISCARD
18:32:47: 	hDeviceWindow: 788126
18:32:47: 	Windowed: false
18:32:47: 	EnableAutoDepthStencil: true
18:32:47: 	AutoDepthStencilFormat: D3DFMT_D24S8
18:32:47: 	Flags: None
18:32:47: 	FullScreen_RefreshRateInHz: 120
18:32:47: 	PresentationInterval: 2147483648
18:32:47: };
18:32:47: successfully set up d3d9 hooks
18:32:47: D3D9Present called
18:32:47: ---------------------- Cleared D3D9 Capture ----------------------
18:32:47: received restart event, capturing
18:32:48: DoD3D9GPUHook: success
18:32:48: D3D9EndScene called
18:32:48: D3D9Present called
18:32:48: D3DSURFACE_DESC {
18:32:48: 	Format: D3DFMT_A8R8G8B8
18:32:48: 	Type: D3DRTYPE_SURFACE
18:32:48: 	Usage: D3DUSAGE_RENDERTARGET 
18:32:48: 	Pool: D3DPOOL_DEFAULT
18:32:48: 	MultiSampleType: D3DMULTISAMPLE_8_SAMPLES
18:32:48: 	MultiSampleQuality: 0
18:32:48: 	Width: 1920
18:32:48: 	Height: 1080
18:32:48: };
18:32:48: successfully capturing d3d9 frames via GPU
20:09:59: ---------------------- Cleared D3D9 Capture ----------------------
20:09:59: received restart event, capturing
20:09:59: DoD3D9GPUHook: shareDevice->CreateTexture2D failed, result = 2147942487
20:09:59: ---------------------- Cleared D3D9 Capture ----------------------
20:09:59: D3D9Reset called
20:09:59: ---------------------- Cleared D3D9 Capture ----------------------
20:10:00: D3DPRESENT_PARAMETERS {
20:10:00: 	BackBufferWidth: 1920
20:10:00: 	BackBufferHeight: 1080
20:10:00: 	BackBufferFormat: D3DFMT_A8R8G8B8
20:10:00: 	BackBufferCount: 1
20:10:00: 	MultiSampleType: D3DMULTISAMPLE_8_SAMPLES
20:10:00: 	MultiSampleQuality: 0
20:10:00: 	SwapEffect: D3DSWAPEFFECT_DISCARD
20:10:00: 	hDeviceWindow: 788126
20:10:00: 	Windowed: false
20:10:00: 	EnableAutoDepthStencil: true
20:10:00: 	AutoDepthStencilFormat: D3DFMT_D24S8
20:10:00: 	Flags: None
20:10:00: 	FullScreen_RefreshRateInHz: 120
20:10:00: 	PresentationInterval: 2147483648
20:10:00: };
20:10:00: successfully set up d3d9 hooks
20:10:05: D3D9EndScene called
20:10:05: D3D9Present called
20:10:05: DoD3D9GPUHook: success
20:10:06: D3DSURFACE_DESC {
20:10:06: 	Format: D3DFMT_A8R8G8B8
20:10:06: 	Type: D3DRTYPE_SURFACE
20:10:06: 	Usage: D3DUSAGE_RENDERTARGET 
20:10:06: 	Pool: D3DPOOL_DEFAULT
20:10:06: 	MultiSampleType: D3DMULTISAMPLE_8_SAMPLES
20:10:06: 	MultiSampleQuality: 0
20:10:06: 	Width: 1920
20:10:06: 	Height: 1080
20:10:06: };
20:10:06: successfully capturing d3d9 frames via GPU
EDIT: Decided to bump my old thread instead of posting an unrelated issue in this one. Please see here and help if possible!
 
Top