Closed p-alik closed 7 years ago
I can confirm this happens with gearmand SSL. Have you seen it with non-SSL job servers?
Also, it only happens with the first task registered by a worker.
SSL is no matter, it's a general issue.
In releases before aforementioned v2.003_001 the only _on_connect was executed by register_function. _on_connect
sends can_do
. In releases >= v2.003_001 register_function
sends the second can_do
request.
I see. When you're fixing that code, you might want to fix the misspelling of "working" on line 479.
The changes look reasonable. I'll see if I can test them.
"make test" failed tests 2 and 4 in t/03-worker.t:
# Looks like you planned 0 tests but ran 1.
Can't locate object method "_on_connect" via package "Gearman::Worker" at t/03-worker.t line 174.
# Tests were run but no plan was declared and done_testing() was not seen.
# Looks like your test exited with 255 just after 8.
t/03-worker.t ................... Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 2/8 subtests
Also, a lot of the tests printed this:
Variable "$timeout" is not available at /path/to/github/perl-Gearman/blib/lib/Gearman/Worker.pm line 473.
Pardon me. 03-worker.t
and `$timeout' issues are done.
Well, "make test" works now, but my workers are only registering the first task. The other tasks aren't registering.
So I went from having 30 capable workers for task "A" and 15 capable workers for tasks "B" through "Z" to having 15 capable workers for task "A" and zero capable workers for tasks "B" through "Z". :-1:
Log of my 5 development workers starting up:
Gearman::Worker::VERSION = 2.004.007 <-- GitHub upstream branch, really
*** starting 5 SSL workers
*** connecting to job server(s): myjobserver:47301
** child started, pid: 98136
** child started, pid: 98137
** Worker (pid: 98136) registering task DIRECTORY_CONTENTS => CODE(0x2431810)
** child started, pid: 98138
** Worker (pid: 98137) registering task DIRECTORY_CONTENTS => CODE(0x2431810)
** child started, pid: 98139
** Worker (pid: 98138) registering task DIRECTORY_CONTENTS => CODE(0x2431810)
** child started, pid: 98140
** Worker (pid: 98139) registering task DIRECTORY_CONTENTS => CODE(0x2431810)
** Worker (pid: 98140) registering task DIRECTORY_CONTENTS => CODE(0x2431810)
DEBUG: .../IO/Socket/SSL.pm:2760: new ctx 38531680
DEBUG: .../IO/Socket/SSL.pm:2760: new ctx 38527600
DEBUG: .../IO/Socket/SSL.pm:2760: new ctx 38531728
DEBUG: .../IO/Socket/SSL.pm:2760: new ctx 38531760
DEBUG: .../IO/Socket/SSL.pm:625: socket not yet connected
DEBUG: .../IO/Socket/SSL.pm:625: socket not yet connected
DEBUG: .../IO/Socket/SSL.pm:627: socket connected
DEBUG: .../IO/Socket/SSL.pm:649: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:627: socket connected
DEBUG: .../IO/Socket/SSL.pm:649: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:2760: new ctx 38531792
DEBUG: .../IO/Socket/SSL.pm:682: using SNI with hostname myjobsever
DEBUG: .../IO/Socket/SSL.pm:739: set socket to non-blocking to enforce timeout=60
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:625: socket not yet connected
DEBUG: .../IO/Socket/SSL.pm:627: socket connected
DEBUG: .../IO/Socket/SSL.pm:649: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:682: using SNI with hostname myjobserver
DEBUG: .../IO/Socket/SSL.pm:739: set socket to non-blocking to enforce timeout=60
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:682: using SNI with hostname myjobserver
DEBUG: .../IO/Socket/SSL.pm:739: set socket to non-blocking to enforce timeout=60
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:625: socket not yet connected
DEBUG: .../IO/Socket/SSL.pm:627: socket connected
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:649: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:682: using SNI with hostname myjobserver
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> 1
DEBUG: .../IO/Socket/SSL.pm:809: ssl handshake done
DEBUG: .../IO/Socket/SSL.pm:739: set socket to non-blocking to enforce timeout=60
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
** Worker (pid: 98138) registering task DIRECTORY_CREATE => CODE(0x242a848)
DEBUG: .../IO/Socket/SSL.pm:625: socket not yet connected
DEBUG: .../IO/Socket/SSL.pm:627: socket connected
DEBUG: .../IO/Socket/SSL.pm:649: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:682: using SNI with hostname myjobserver
DEBUG: .../IO/Socket/SSL.pm:739: set socket to non-blocking to enforce timeout=60
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
** Worker (pid: 98138) registering task EXECUTE_TOOL => CODE(0x22f73d8)
** Worker (pid: 98138) registering task FILE_DELETE => CODE(0x2447698)
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
** Worker (pid: 98138) registering task FILE_DOWNLOAD => CODE(0x24576f8)
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
** Worker (pid: 98138) registering task FILE_RENAME => CODE(0x244ff78)
** Worker (pid: 98138) registering task FILE_UPLOAD => CODE(0x246aab8)
** Worker (pid: 98138) registering task LINK_DATA => CODE(0x245b2a8)
** Worker (pid: 98138) registering task PARAMETER_LIST => CODE(0x24109e0)
** Worker (pid: 98138) registering task PARAMETER_RESET => CODE(0x2424f30)
** Worker (pid: 98138) registering task PARAMETER_UPDATE => CODE(0x2425668)
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
** Worker (pid: 98138) registering task USER_CREATE => CODE(0x24a0c88)
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
** Worker (pid: 98138) registering task USER_SPACE => CODE(0x2427de8)
** Worker (pid: 98138) registering task ping => CODE(0x22f3b88)
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> 1
DEBUG: .../IO/Socket/SSL.pm:809: ssl handshake done
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
** Worker (pid: 98137) registering task DIRECTORY_CREATE => CODE(0x242a848)
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> 1
DEBUG: .../IO/Socket/SSL.pm:809: ssl handshake done
** Worker (pid: 98137) registering task EXECUTE_TOOL => CODE(0x22f73d8)
** Worker (pid: 98139) registering task DIRECTORY_CREATE => CODE(0x242a848)
** Worker (pid: 98139) registering task EXECUTE_TOOL => CODE(0x22f73d8)
** Worker (pid: 98137) registering task FILE_DELETE => CODE(0x2447698)
** Worker (pid: 98137) registering task FILE_DOWNLOAD => CODE(0x24576f8)
** Worker (pid: 98139) registering task FILE_DELETE => CODE(0x2447698)
** Worker (pid: 98137) registering task FILE_RENAME => CODE(0x244ff78)
** Worker (pid: 98139) registering task FILE_DOWNLOAD => CODE(0x24576f8)
** Worker (pid: 98137) registering task FILE_UPLOAD => CODE(0x246aab8)
** Worker (pid: 98139) registering task FILE_RENAME => CODE(0x244ff78)
** Worker (pid: 98137) registering task LINK_DATA => CODE(0x245b2a8)
** Worker (pid: 98139) registering task FILE_UPLOAD => CODE(0x246aab8)
** Worker (pid: 98137) registering task PARAMETER_LIST => CODE(0x24109e0)
** Worker (pid: 98139) registering task LINK_DATA => CODE(0x245b2a8)
** Worker (pid: 98137) registering task PARAMETER_RESET => CODE(0x2424f30)
** Worker (pid: 98139) registering task PARAMETER_LIST => CODE(0x24109e0)
** Worker (pid: 98137) registering task PARAMETER_UPDATE => CODE(0x2425668)
** Worker (pid: 98139) registering task PARAMETER_RESET => CODE(0x2424f30)
** Worker (pid: 98137) registering task USER_CREATE => CODE(0x24a0c88)
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
** Worker (pid: 98139) registering task PARAMETER_UPDATE => CODE(0x2425668)
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:764: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:774: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> 1
DEBUG: .../IO/Socket/SSL.pm:809: ssl handshake done
** Worker (pid: 98137) registering task USER_SPACE => CODE(0x2427de8)
** Worker (pid: 98136) registering task DIRECTORY_CREATE => CODE(0x242a848)
** Worker (pid: 98139) registering task USER_CREATE => CODE(0x24a0c88)
** Worker (pid: 98137) registering task ping => CODE(0x22f3b88)
** Worker (pid: 98139) registering task USER_SPACE => CODE(0x2427de8)
** Worker (pid: 98139) registering task ping => CODE(0x22f3b88)
DEBUG: .../IO/Socket/SSL.pm:794: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:751: call Net::SSLeay::connect
DEBUG: .../IO/Socket/SSL.pm:754: done Net::SSLeay::connect -> 1
DEBUG: .../IO/Socket/SSL.pm:809: ssl handshake done
** Worker (pid: 98140) registering task DIRECTORY_CREATE => CODE(0x242a848)
** Worker (pid: 98140) registering task EXECUTE_TOOL => CODE(0x22f73d8)
** Worker (pid: 98140) registering task FILE_DELETE => CODE(0x2447698)
** Worker (pid: 98140) registering task FILE_DOWNLOAD => CODE(0x24576f8)
** Worker (pid: 98140) registering task FILE_RENAME => CODE(0x244ff78)
** Worker (pid: 98140) registering task FILE_UPLOAD => CODE(0x246aab8)
** Worker (pid: 98140) registering task LINK_DATA => CODE(0x245b2a8)
** Worker (pid: 98140) registering task PARAMETER_LIST => CODE(0x24109e0)
** Worker (pid: 98140) registering task PARAMETER_RESET => CODE(0x2424f30)
** Worker (pid: 98140) registering task PARAMETER_UPDATE => CODE(0x2425668)
** Worker (pid: 98140) registering task USER_CREATE => CODE(0x24a0c88)
** Worker (pid: 98140) registering task USER_SPACE => CODE(0x2427de8)
** Worker (pid: 98140) registering task ping => CODE(0x22f3b88)
** Worker (pid: 98136) registering task EXECUTE_TOOL => CODE(0x22f73d8)
** Worker (pid: 98136) registering task FILE_DELETE => CODE(0x2447698)
** Worker (pid: 98136) registering task FILE_DOWNLOAD => CODE(0x24576f8)
** Worker (pid: 98136) registering task FILE_RENAME => CODE(0x244ff78)
** Worker (pid: 98136) registering task FILE_UPLOAD => CODE(0x246aab8)
** Worker (pid: 98136) registering task LINK_DATA => CODE(0x245b2a8)
** Worker (pid: 98136) registering task PARAMETER_LIST => CODE(0x24109e0)
** Worker (pid: 98136) registering task PARAMETER_RESET => CODE(0x2424f30)
** Worker (pid: 98136) registering task PARAMETER_UPDATE => CODE(0x2425668)
** Worker (pid: 98136) registering task USER_CREATE => CODE(0x24a0c88)
** Worker (pid: 98136) registering task USER_SPACE => CODE(0x2427de8)
** Worker (pid: 98136) registering task ping => CODE(0x22f3b88)
Output of gearmand "status" command:
FILE_DOWNLOAD => {
capable => 0,
running => 0,
queued => 0
},
FILE_DELETE => {
capable => 0,
running => 0,
queued => 0
},
USER_SPACE => {
capable => 0,
running => 0,
queued => 0
},
FILE_UPLOAD => {
capable => 0,
running => 0,
queued => 0
},
FILE_RENAME => {
capable => 0,
running => 0,
queued => 0
},
PARAMETER_LIST => {
capable => 0,
running => 0,
queued => 0
},
DIRECTORY_CREATE => {
capable => 0,
running => 0,
queued => 0
},
DIRECTORY_CONTENTS => {
capable => 5,
running => 0,
queued => 0
},
EXECUTE_TOOL => {
capable => 0,
running => 0,
queued => 0
},
LINK_DATA => {
capable => 0,
running => 0,
queued => 0
},
ping => {
capable => 0,
running => 0,
queued => 0
},
USER_CREATE => {
capable => 0,
running => 0,
queued => 0
},
PARAMETER_RESET => {
capable => 0,
running => 0,
queued => 0
},
PARAMETER_UPDATE => {
capable => 0,
running => 0,
queued => 0
}
Sorry for that. It's work fine now
bed172ff4161bf46ad6b7dfdf01fce247897330f is related to the issue: renew registration on reconnect
Looking good. I've got it running in my testing environment, and it seems to be working fine. :+1:
bug fixing is released in v2.004.008
The bug is in releases >= v2.003_001