Curl - slow response

Question

I got an address and port number from someone. I'm sending something called a "tagstream", and receive a response back, a zpl label.

I'm supposed to trigger the "Uni-Box" by sending this tagstream over a socket connection. I've tried doing this with curl. It works, but it takes about 10 seconds before I get a response back.

    $ch = curl_init();
        curl_setopt($ch, CURLOPT_URL, '87.213.39.202');
        curl_setopt($ch, CURLOPT_PORT, 3032);

        curl_setopt($ch, CURLOPT_RETURNTRANSFER, 1);

        curl_setopt($ch, CURLOPT_POST, 0);
        curl_setopt($ch, CURLOPT_POSTFIELDS, $message);

    $zpl = curl_exec($ch);

    curl_close($ch);

This is what I get back from curl_getinfo() :

array:26 [▼
  "url" => "HTTP://87.213.39.202/"
  "content_type" => null
  "http_code" => 0
  "header_size" => 0
  "request_size" => 538
  "filetime" => -1
  "ssl_verify_result" => 0
  "redirect_count" => 0
  "total_time" => 10.327
  "namelookup_time" => 0.0
  "connect_time" => 0.031
  "pretransfer_time" => 0.031
  "size_upload" => 410.0
  "size_download" => 8598.0
  "speed_download" => 832.0
  "speed_upload" => 39.0
  "download_content_length" => -1.0
  "upload_content_length" => 410.0
  "starttransfer_time" => 0.062
  "redirect_time" => 0.0
  "redirect_url" => ""
  "primary_ip" => "87.213.39.202"
  "certinfo" => []
  "primary_port" => 3032
  "local_ip" => "192.168.1.136"
  "local_port" => 49948
]

I also tested the connection via this program: http://sockettest.sourceforge.net/

When I use this I get a response back instantly.

I did a trace with xdebug:

TRACE START [2015-11-24 10:43:47]
    0.0010     130056   -> {main}() C:\Users\phpmachine\test.php:0
    0.0010     130696     -> curl_init() C:\Users\phpmachine\test.php:4
    0.0010     131600     -> curl_setopt() C:\Users\phpmachine\test.php:5
    0.0010     131576     -> curl_setopt() C:\Users\phpmachine\test.php:6
    0.0010     131576     -> curl_setopt() C:\Users\phpmachine\test.php:7
    0.0010     131576     -> curl_setopt() C:\Users\phpmachine\test.php:9
    0.0010     131576     -> curl_setopt() C:\Users\phpmachine\test.php:11
    0.0010     131544     -> curl_setopt() C:\Users\phpmachine\test.php:12
    0.0010     131512     -> curl_exec() C:\Users\phpmachine\test.php:14
   10.3476     153384     -> curl_getinfo() C:\Users\phpmachine\test.php:15
   10.3476     156232     -> var_dump() C:\Users\phpmachine\test.php:17
   10.3516       8416
TRACE END   [2015-11-24 10:43:58]

I got this from process monitor:

12:23:34,0427525    php.exe 6052    TCP Accept  phpmachine-PC:8001 -> phpmachine-PC:52116   SUCCESS Length: 0, mss: 1440, sackopt: 1, tsopt: 0, wsopt: 1, rcvwin: 8192, rcvwinscale: 8, sndwinscale: 8, seqnum: 0, connid: 0
12:23:34,0430792    php.exe 6052    TCP Accept  phpmachine-PC:8001 -> phpmachine-PC:52117   SUCCESS Length: 0, mss: 1440, sackopt: 1, tsopt: 0, wsopt: 1, rcvwin: 8192, rcvwinscale: 8, sndwinscale: 8, seqnum: 0, connid: 0
12:23:34,0481570    php.exe 6052    TCP TCPCopy phpmachine-PC:8001 -> phpmachine-PC:52116   SUCCESS Length: 1052, seqnum: 0, connid: 0
12:23:34,0481705    php.exe 6052    TCP Receive phpmachine-PC:8001 -> phpmachine-PC:52116   SUCCESS Length: 1052, seqnum: 0, connid: 0
12:23:34,0485330    php.exe 6052    CreateFile  C:\Users\phpmachine SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:23:34,0485752    php.exe 6052    QueryDirectory  C:\Users\phpmachine\test.php    SUCCESS Filter: test.php, 1: test.php
12:23:34,0486250    php.exe 6052    CloseFile   C:\Users\phpmachine SUCCESS 
12:23:34,0490208    php.exe 6052    CreateFile  C:\Users\phpmachine SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:23:34,0490670    php.exe 6052    QueryNetworkOpenInformationFile C:\Users\phpmachine SUCCESS CreationTime: 5-11-2014 20:57:57, LastAccessTime: 24-11-2015 11:04:43, LastWriteTime: 24-11-2015 11:04:43, ChangeTime: 24-11-2015 11:04:43, AllocationSize: 1-1-1601 1:00:00, EndOfFile: 1-1-1601 1:00:00, FileAttributes: D
12:23:34,0490802    php.exe 6052    CloseFile   C:\Users\phpmachine SUCCESS 
12:23:34,0491815    php.exe 6052    CreateFile  C:\Users\phpmachine\test.php    SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened
12:23:34,0492591    php.exe 6052    QueryInformationVolume  C:\Users\phpmachine\test.php    BUFFER OVERFLOW VolumeCreationTime: 31-10-2014 0:44:17, VolumeSerialNumber: 1C6C-4C1A, SupportsObjects: True, VolumeLabel: Win
12:23:34,0492742    php.exe 6052    QueryAllInformationFile C:\Users\phpmachine\test.php    BUFFER OVERFLOW CreationTime: 24-11-2015 10:44:39, LastAccessTime: 24-11-2015 10:44:39, LastWriteTime: 24-11-2015 11:41:30, ChangeTime: 24-11-2015 11:41:30, FileAttributes: A, AllocationSize: 4.096, EndOfFile: 911, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0xb000000023920, EaSize: 0, Access: Generic Read, Position: 0, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word
12:23:34,0492939    php.exe 6052    CreateFileMapping   C:\Users\phpmachine\test.php    FILE LOCKED WITH ONLY READERS   SyncType: SyncTypeCreateSection, PageProtection: 
12:23:34,0493072    php.exe 6052    QueryStandardInformationFile    C:\Users\phpmachine\test.php    SUCCESS AllocationSize: 4.096, EndOfFile: 911, NumberOfLinks: 1, DeletePending: False, Directory: False
12:23:34,0493284    php.exe 6052    CreateFileMapping   C:\Users\phpmachine\test.php    SUCCESS SyncType: SyncTypeOther
12:23:34,0493580    php.exe 6052    QueryStandardInformationFile    C:\Users\phpmachine\test.php    SUCCESS AllocationSize: 4.096, EndOfFile: 911, NumberOfLinks: 1, DeletePending: False, Directory: False
12:23:34,0494642    php.exe 6052    CloseFile   C:\Users\phpmachine\test.php    SUCCESS 
12:23:34,0764135    php.exe 6052    TCP Connect phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 0, mss: 1460, sackopt: 1, tsopt: 0, wsopt: 1, rcvwin: 65700, rcvwinscale: 8, sndwinscale: 0, seqnum: 0, connid: 0
12:23:34,1108071    php.exe 6052    TCP Send    phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 626, startime: 112255, endtime: 112256, seqnum: 0, connid: 0
12:23:34,1115333    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 128, seqnum: 0, connid: 0
12:23:34,1115718    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 128, seqnum: 0, connid: 0
12:23:34,3219629    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3220048    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3392041    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3392469    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3400457    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3400661    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3689893    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3690216    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3696465    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1256, seqnum: 0, connid: 0
12:23:34,3696662    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1256, seqnum: 0, connid: 0
12:23:34,3766311    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,3766508    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 1460, seqnum: 0, connid: 0
12:23:34,4040472    php.exe 6052    TCP TCPCopy phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 150, seqnum: 0, connid: 0
12:23:34,4040780    php.exe 6052    TCP Receive phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 150, seqnum: 0, connid: 0
12:23:44,3904869    php.exe 6052    CreateFile  C:\Users    SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:23:44,3905414    php.exe 6052    QueryDirectory  C:\Users\phpmachine SUCCESS Filter: phpmachine, 1: phpmachine
12:23:44,3906037    php.exe 6052    CloseFile   C:\Users    SUCCESS 
12:23:44,3906877    php.exe 6052    CreateFile  C:\ SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:23:44,3907428    php.exe 6052    QueryDirectory  C:\Users    SUCCESS Filter: Users, 1: Users
12:23:44,3908402    php.exe 6052    CloseFile   C:\ SUCCESS 
12:23:44,3910462    php.exe 6052    CreateFile  C:\Users\phpmachine SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:23:44,3911072    php.exe 6052    QueryNetworkOpenInformationFile C:\Users\phpmachine SUCCESS CreationTime: 5-11-2014 20:57:57, LastAccessTime: 24-11-2015 11:04:43, LastWriteTime: 24-11-2015 11:04:43, ChangeTime: 24-11-2015 11:04:43, AllocationSize: 1-1-1601 1:00:00, EndOfFile: 1-1-1601 1:00:00, FileAttributes: D
12:23:44,3911278    php.exe 6052    CloseFile   C:\Users\phpmachine SUCCESS 
12:23:44,3917083    php.exe 6052    TCP Send    phpmachine-PC:8001 -> phpmachine-PC:52116   SUCCESS Length: 125, startime: 112358, endtime: 112358, seqnum: 0, connid: 0
12:23:44,3918207    php.exe 6052    TCP Send    phpmachine-PC:8001 -> phpmachine-PC:52116   SUCCESS Length: 723, startime: 112358, endtime: 112358, seqnum: 0, connid: 0
12:23:44,3925080    php.exe 6052    TCP Disconnect  phpmachine-PC:8001 -> phpmachine-PC:52117   SUCCESS Length: 0, seqnum: 0, connid: 0
12:23:44,3935677    php.exe 6052    TCP Disconnect  phpmachine-PC:8001 -> phpmachine-PC:52116   SUCCESS Length: 0, seqnum: 0, connid: 0
12:23:44,4195232    php.exe 6052    TCP Disconnect  phpmachine-PC:52118 -> gateway.gls-netherlands.com:3032 SUCCESS Length: 0, seqnum: 0, connid: 0
12:23:48,4995571    php.exe 6052    Thread Exit     SUCCESS Thread ID: 5964, User Time: 0.0000000, Kernel Time: 0.0000000
12:23:48,4996301    php.exe 6052    Thread Exit     SUCCESS Thread ID: 5708, User Time: 0.0000000, Kernel Time: 0.0000000

I found something that works, but not sure if it's the best way.

Not using curl this time. If I use socket_read when there's nothing left to read, it takes 10 seconds again to get the result. But I know the characters the received message should end with, so I'm using that to determine when to stop.

It works, and it takes way less time now!

$socket = socket_create(AF_INET, SOCK_STREAM, SOL_TCP);
$result = socket_connect($socket, '87.213.39.202', 3032);
socket_write($socket, $message, strlen($message));

$result = '';
$zpl = '';

for($i = 0; $i < 10; $i++) {
    $read = socket_read($socket, 2048);
    $zpl = $zpl . $read;
    if(substr($read, -13) == '/////GLS/////') {
        break;
    }
}

socket_close($socket);

Try to explicitly set the protocol in your URL (`http://87.213.39.202`) -- `http` is the default, but maybe the guessing leads to the delay; `strace` the php process, this almost always leads to the culprit. If the delay is constant, eliminiate commen causes like DNS queries. — Tom Regner, Nov 24 '15 at 09:15
@TomRegner I tried setting the protocol with `curl_setopt($ch, CURLOPT_PROTOCOLS, CURLPROTO_HTTP);` but it didn't help. — Clearasil, Nov 24 '15 at 10:57
Ah well, 't was but a guess :( - try the strace approach to close in on the culprit — Tom Regner, Nov 24 '15 at 10:59
I did a trace with xdebug, I can't use strace since I'm on windows. Edited my post with the result. — Clearasil, Nov 24 '15 at 11:01
tracing php won't help as the interesting part will happen on the c level - maybe there's an strace like tool for win? — Tom Regner, Nov 24 '15 at 11:04
I added a trace from process monitor. So I guess the last TCP receive is the culprit? I'm not sure what I can do with this info though. — Clearasil, Nov 24 '15 at 11:30
It tells us that it isn't the initial connection, but something at the end - I don't develop under windows (don't use it at all) so I can't help you further along - maybe you can craft a search string with this knowledge that leads you to the solution . Curl is so widely used, I doubt this is the first time this happens. — Tom Regner, Nov 24 '15 at 11:54
I will try to test first in the console: C:\curl http://87.213.39.202 , maybe it's not because of php, maybe the target computer has a firewall, which makes the request slower. — Don Globian, Oct 11 '22 at 09:52
Check this out https://stackoverflow.com/questions/19467449/how-to-speed-up-curl-in-php — Urvin, Mar 02 '23 at 13:57

score 0 · Answer 1 · answered Nov 24 '15 at 13:11

0

HTTP is not the same as http
"http_code" => 0 - this means an error occured during the request and it wasn't even completed.

answered Nov 24 '15 at 13:11

Flash Thunder

11,672
8
47
91

Curl - slow response

1 Answers1