Here's my latest. I believe I've sorted out my trouble with the xmlrpc
user account (cleared out foreign key references it all my tables, then
changed its user ID to 3), and I'm running with Aaron Coburn's suggested
changs to utils.pm.
I'm pasting the entire log from my latest block reseration attempt
below. I'm getting more information but I still don't see anything that
looks like a smoking gun to me.
2012-10-12 13:42:16|2375|utils.pm:check_blockrequest_time(1026)|block request
start time is within start window (32 minutes from now),
returning 'start'
2012-10-12 13:42:16|2375|DataStructure.pm:_automethod(834)|data structure
updated: $self->blockrequest_data->{8}{MODE}
|2375| blockrequest_mode = start
2012-10-12 13:42:16|2375|vcld:main(445)|block request 8 'michael blocks three
machines' processing set to 1
2012-10-12 13:42:16|2375|vcld:make_new_child(515)|loaded VCL::blockrequest
module
2012-10-12 13:42:16|2375|vcld:make_new_child(539)|current number of forked
kids: 1
2012-10-12 13:42:16|4763|vcld:make_new_child(555)|vcld environment variable set
to 0 for this process
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'numMachines' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'ownerid' key for
VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'expireTime' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'repeating' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'admingroupid' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'status' key for
VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'managementnodeid'
key for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'name' key for
VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'blockTimes' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'groupname' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'id' key for
VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'groupid' key for
VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'imageid' key for
VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'processing' key
for VCL::blockrequest object from arguments
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(172)|set 'MODE' key for
VCL::blockrequest object from arguments
2012-10-12
13:42:16|4763|blockrequest|Module.pm:create_mn_os_object(361)|VCL::Module::OS::Linux::ManagementNode
module loaded
2012-10-12
13:42:16|4763|blockrequest|Module.pm:new(196)|VCL::Module::OS::Linux::ManagementNode
object created for image <not set>, ad
dress: 23934e8
2012-10-12 13:42:16|4763|blockrequest|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{0}{
computer}{hostname}
|4763|blockrequest| computer_hostname = vlab-a.uchicago.edu
2012-10-12 13:42:16|4763|blockrequest|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{0}{
computer}{NODENAME}
|4763|blockrequest| computer_node_name = vlab-a
2012-10-12 13:42:16|4763|blockrequest|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{0}{
computer}{SHORTNAME}
|4763|blockrequest| computer_short_name = vlab-a
2012-10-12 13:42:16|4763|blockrequest|DataStructure.pm:_automethod(834)|data
structure updated: $self->request_data->{reservation}{0}{
computer}{IPaddress}
|4763|blockrequest| computer_ip_address = 10.50.114.20
2012-10-12
13:42:16|4763|blockrequest|Module.pm:create_mn_os_object(366)|VCL::Module::OS::Linux::ManagementNode
OS object created, address: 23934e8
2012-10-12 13:42:16|4763|blockrequest|Module.pm:new(192)|VCL::blockrequest
object created for state <not set>, address: 213c6c0
2012-10-12 13:42:16|4763|blockrequest|blockrequest.pm:initialize(84)|obtained a
database handle for this state process, stored as $ENV{dbh}
2012-10-12
13:42:16|4763|blockrequest|utils.pm:rename_vcld_process(7136)|renamed process
to 'vcld 8:11 'michael blocks three machines''
2012-10-12 13:42:16|4763|blockrequest|blockrequest.pm:initialize(94)|returning 1
2012-10-12
13:42:16|4763|blockrequest|vcld:make_new_child(565)|VCL::blockrequest object
created and initialized
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(158)|blockrequest
id: 8
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(159)|blockrequest
mode: start
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(160)|blockrequest
image id: 90
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(161)|blockrequest
number machines: 3
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(162)|blockrequest
expire: 2012-10-12 23:59:59
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(163)|blocktime
id: 11
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(164)|blocktime
processed: 0
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(165)|blocktime
start: 2012-10-12 14:15:00
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(166)|owner email:
[email protected]
Use of uninitialized value $owner_affiliation_helpaddress in concatenation (.)
or string at /usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line
167 (#2)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:17|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$owner_affiliation_helpaddress in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 167.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 167)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(167)|help address:
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(172)|updated
process flag on blocktime_id= 11
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(192)|processing
blocktime_id= 11 pass 1
2012-10-12
13:42:17|4763|blockrequest|utils.pm:xmlrpc_call(9105)|argument_string=
XMLRPCprocessBlockTime 11 1
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:17|4763|blockrequest|utils.pm:xmlrpc_call(9131)|fault occured:
|4763|blockrequest| Response class = RPC::XML::fault
|4763|blockrequest| Response type = fault
|4763|blockrequest| Response string =
<fault><value><struct><member><name>faultString</name><value><string>Access
denied</string></value></member><member><name>faultCode</name><value><int>3</int></value></member></struct></value></fault>
|4763|blockrequest| Response value = HASH(0x294e428)
|4763|blockrequest| ( 0) utils.pm, xmlrpc_call (line: 9131)
|4763|blockrequest| (-1) blockrequest.pm, process_block_time (line: 373)
|4763|blockrequest| (-2) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-3) vcld, make_new_child (line: 568)
|4763|blockrequest| (-4) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:17|4763|blockrequest|blockrequest.pm:process_block_time(389)|return
argument XMLRPCprocessBlockTime was not a STRUCT as expectedRPC::XML::fault
|4763|blockrequest| ( 0) blockrequest.pm, process_block_time (line: 389)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:17|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$warningmsg in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:17|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$unallocated in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
2012-10-12 13:42:17|4763|blockrequest|blockrequest.pm:process(212)|xmlrpc
warning: allocated= 0 unallocated=
2012-10-12 13:42:22|4763|blockrequest|blockrequest.pm:process(192)|processing
blocktime_id= 11 pass 2
2012-10-12
13:42:22|4763|blockrequest|utils.pm:xmlrpc_call(9105)|argument_string=
XMLRPCprocessBlockTime 11 1
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:22|4763|blockrequest|utils.pm:xmlrpc_call(9131)|fault occured:
|4763|blockrequest| Response class = RPC::XML::fault
|4763|blockrequest| Response type = fault
|4763|blockrequest| Response string =
<fault><value><struct><member><name>faultString</name><value><string>Access
denied</string></value></member><member><name>faultCode</name><value><int>3</int></value></member></struct></value></fault>
|4763|blockrequest| Response value = HASH(0x2a79cf8)
|4763|blockrequest| ( 0) utils.pm, xmlrpc_call (line: 9131)
|4763|blockrequest| (-1) blockrequest.pm, process_block_time (line: 373)
|4763|blockrequest| (-2) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-3) vcld, make_new_child (line: 568)
|4763|blockrequest| (-4) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:22|4763|blockrequest|blockrequest.pm:process_block_time(389)|return
argument XMLRPCprocessBlockTime was not a STRUCT as expectedRPC::XML::fault
|4763|blockrequest| ( 0) blockrequest.pm, process_block_time (line: 389)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:22|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$warningmsg in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:22|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$unallocated in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
2012-10-12 13:42:22|4763|blockrequest|blockrequest.pm:process(212)|xmlrpc
warning: allocated= 0 unallocated=
2012-10-12 13:42:27|4763|blockrequest|blockrequest.pm:process(192)|processing
blocktime_id= 11 pass 3
2012-10-12
13:42:27|4763|blockrequest|utils.pm:xmlrpc_call(9105)|argument_string=
XMLRPCprocessBlockTime 11 1
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:27|4763|blockrequest|utils.pm:xmlrpc_call(9131)|fault occured:
|4763|blockrequest| Response class = RPC::XML::fault
|4763|blockrequest| Response type = fault
|4763|blockrequest| Response string =
<fault><value><struct><member><name>faultString</name><value><string>Access
denied</string></value></member><member><name>faultCode</name><value><int>3</int></value></member></struct></value></fault>
|4763|blockrequest| Response value = HASH(0x294e7a0)
|4763|blockrequest| ( 0) utils.pm, xmlrpc_call (line: 9131)
|4763|blockrequest| (-1) blockrequest.pm, process_block_time (line: 373)
|4763|blockrequest| (-2) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-3) vcld, make_new_child (line: 568)
|4763|blockrequest| (-4) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:27|4763|blockrequest|blockrequest.pm:process_block_time(389)|return
argument XMLRPCprocessBlockTime was not a STRUCT as expectedRPC::XML::fault
|4763|blockrequest| ( 0) blockrequest.pm, process_block_time (line: 389)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:27|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$warningmsg in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:27|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$unallocated in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
2012-10-12 13:42:27|4763|blockrequest|blockrequest.pm:process(212)|xmlrpc
warning: allocated= 0 unallocated=
2012-10-12 13:42:32|4763|blockrequest|blockrequest.pm:process(192)|processing
blocktime_id= 11 pass 4
2012-10-12
13:42:32|4763|blockrequest|utils.pm:xmlrpc_call(9105)|argument_string=
XMLRPCprocessBlockTime 11 1
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:32|4763|blockrequest|utils.pm:xmlrpc_call(9131)|fault occured:
|4763|blockrequest| Response class = RPC::XML::fault
|4763|blockrequest| Response type = fault
|4763|blockrequest| Response string =
<fault><value><struct><member><name>faultString</name><value><string>Access
denied</string></value></member><member><name>faultCode</name><value><int>3</int></value></member></struct></value></fault>
|4763|blockrequest| Response value = HASH(0x294e6b0)
|4763|blockrequest| ( 0) utils.pm, xmlrpc_call (line: 9131)
|4763|blockrequest| (-1) blockrequest.pm, process_block_time (line: 373)
|4763|blockrequest| (-2) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-3) vcld, make_new_child (line: 568)
|4763|blockrequest| (-4) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:32|4763|blockrequest|blockrequest.pm:process_block_time(389)|return
argument XMLRPCprocessBlockTime was not a STRUCT as expectedRPC::XML::fault
|4763|blockrequest| ( 0) blockrequest.pm, process_block_time (line: 389)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:32|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$warningmsg in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:32|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$unallocated in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
2012-10-12 13:42:32|4763|blockrequest|blockrequest.pm:process(212)|xmlrpc
warning: allocated= 0 unallocated=
2012-10-12 13:42:37|4763|blockrequest|blockrequest.pm:process(192)|processing
blocktime_id= 11 pass 5
2012-10-12
13:42:37|4763|blockrequest|utils.pm:xmlrpc_call(9105)|argument_string=
XMLRPCprocessBlockTime 11 1
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:37|4763|blockrequest|utils.pm:xmlrpc_call(9131)|fault occured:
|4763|blockrequest| Response class = RPC::XML::fault
|4763|blockrequest| Response type = fault
|4763|blockrequest| Response string =
<fault><value><struct><member><name>faultString</name><value><string>Access
denied</string></value></member><member><name>faultCode</name><value><int>3</int></value></member></struct></value></fault>
|4763|blockrequest| Response value = HASH(0x28976f0)
|4763|blockrequest| ( 0) utils.pm, xmlrpc_call (line: 9131)
|4763|blockrequest| (-1) blockrequest.pm, process_block_time (line: 373)
|4763|blockrequest| (-2) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-3) vcld, make_new_child (line: 568)
|4763|blockrequest| (-4) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:37|4763|blockrequest|blockrequest.pm:process_block_time(389)|return
argument XMLRPCprocessBlockTime was not a STRUCT as expectedRPC::XML::fault
|4763|blockrequest| ( 0) blockrequest.pm, process_block_time (line: 389)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 193)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:37|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$warningmsg in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
|4763|blockrequest| ---- WARNING ----
|4763|blockrequest| 2012-10-12
13:42:37|4763|blockrequest|vcld:warning_handler(610)|Use of uninitialized value
$unallocated in concatenation (.) or string at
/usr/local/vcl-2.2.1/bin/../lib/VCL/blockrequest.pm line 212.
|4763|blockrequest| ( 0) vcld, warning_handler (line: 610)
|4763|blockrequest| (-1) blockrequest.pm, process (line: 212)
|4763|blockrequest| (-2) vcld, make_new_child (line: 568)
|4763|blockrequest| (-3) vcld, main (line: 448)
2012-10-12 13:42:37|4763|blockrequest|blockrequest.pm:process(212)|xmlrpc
warning: allocated= 0 unallocated=
