Hi Murali and others:
Since my last report I tried a 2-node cluster config without our head
node as metadata server worked!! I am going to configure a 12-server
node pvfs2, using node1 as the metadata server and let you know how it
works.
At this point I feel I got past my hurdles to try out pvfs2.
Aesthetically the current solution is inferior as it breaks the symmetry
of our server nodes but for our small cluster size this may not matter.
To summarize, different kernel versions on head node and server nodes do
not seem to get along. I noticed that the clock on head and server
nodes are out of sync. I don't see how this could come into play but
thought to let you know.
Attached are pvfs2-fs.conf and log file. The machines in question are:
Metadata server:
# uname -a
Linux cree 2.6.12-12mdksmp #1 SMP Fri Sep 9 17:20:34 CEST 2005 x86_64
AMD Opteron(tm) Processor 248 unknown GNU/Linux
12 identical data servers node[1-12] :
[EMAIL PROTECTED] ~]# uname -a
Linux node1 2.6.11-1.1369_FC4smp #1 SMP Thu Jun 2 23:16:33 EDT 2005
x86_64 AMD Opteron(tm) Processor 248 unknown GNU/Linux
(Metadata and data nodes are running Mandriva 2006.0. The Mandriva
kernel does not support our hardware (Marvell sata) on the data server
nodes which forces us to use the Fedora kernel & binary-only module for
the Marvell chip than came with the machines)
... Matt
Murali Vilayannur wrote:
>Hi Matt,
>I will try to recreate this on some machines here over the weekend.
>I may be a little busy over the next couple of days, so I may not be able
>to get back to you soon. But, I will definitely get back to you by early
>next week if noone on the list is able to determine what the
>problem is..
>Could you send another mail to the user list with your fs.conf details of
>platform etc?
>Thanks,
>Murali
>
>On Thu, 25 May 2006, Matt wrote:
>
>
>
>>Hi Murali,
>>
>>I installed the cvs version. Still no luck.
>>I tested single host installations on both the head (metadata)
>>and server nodes. Both worked fine.
>>
>>Attached you find the fs-conf and log files from the metadata and one
>>server node. Let me know if there are other things I should try.
>>
>>... Matt
>>
>>Murali Vilayannur wrote:
>>
>>
>>
>>>Hi matt,
>>>Could you send me your fs.conf file?
>>>Thanks,
>>>Murali
>>>
>>>On Wed, 24 May 2006, langelino wrote:
>>>
>>>
>>>
>>>
>>>
>>>>Hi Murali:
>>>>
>>>>I applied the patch, recompiled and restarted the server on all nodes
>>>>but still get the
>>>>same error on pvfs2-cp. Tomorrow I may try the CVS version and report.
>>>>
>>>>In the meantime, here is the log of one of the I/O servers, node1 for
>>>>the patched pvfs2-server:
>>>>
>>>>------------8<----------------
>>>>
>>>>[D 22:24:28.872666] BMI_tcp_initialize: Initializing TCP/IP module.
>>>>[D 22:24:28.872796] BMI_tcp_initialize: TCP/IP module successfully
>>>>initialized.
>>>>[D 22:24:28.874065] dbpf_thread_initialize: initialized
>>>>[D 22:24:28.874354] collection lookup: version is 0.0.1
>>>>[D 22:24:28.874460] - set handle re-use timeout to 360 seconds (ret=0)
>>>>[D 22:24:28.874594] dbpf_thread_function started
>>>>[D 22:25:02.750384] handle_new_connection: Assigning socket 9 to new
>>>>method addr.
>>>>[D 22:25:02.750484] tcp_do_work_recv: Reading header for new op.
>>>>[D 22:25:02.750503] tcp_do_work_recv: Received new message; mode: 2.
>>>>[D 22:25:02.750514] tcp_do_work_recv: tag: 14
>>>>[D 22:25:02.750610] [1 extents] -- new_handle is 0 (cur_extent is
>>>>1321528400 - 1651910498)
>>>>[E 22:25:02.750629] Error: handle allocator returned a zero handle.
>>>>[D 22:25:02.750674] BMI_post_send_list: addr: 119, count: 1, total_size: 24
>>>>[D 22:25:02.750688] element 0: offset: 0x618f20, size: 24
>>>>[D 22:25:02.750714] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
>>>>[D 22:29:45.602335] handle_new_connection: Assigning socket 9 to new
>>>>method addr.
>>>>[D 22:29:45.602466] tcp_do_work_recv: Reading header for new op.
>>>>[D 22:29:45.602484] tcp_do_work_recv: Received new message; mode: 2.
>>>>[D 22:29:45.602495] tcp_do_work_recv: tag: 6
>>>>[D 22:29:45.602542] BMI_post_send_list: addr: 680, count: 1, total_size: 16
>>>>[D 22:29:45.602557] element 0: offset: 0x618970, size: 16
>>>>[D 22:29:45.602578] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
>>>>[D 22:29:45.608972] tcp_do_work_recv: Reading header for new op.
>>>>[D 22:29:45.609039] tcp_do_work_recv: Received new message; mode: 2.
>>>>[D 22:29:45.609052] tcp_do_work_recv: tag: 19
>>>>[D 22:29:45.609195] BMI_post_send_list: addr: 680, count: 1, total_size: 24
>>>>[D 22:29:45.609275] element 0: offset: 0x6189a0, size: 24
>>>>[D 22:29:45.609334] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
>>>>[D 22:29:45.609612] tcp_do_work_recv: Reading header for new op.
>>>>[D 22:29:45.609634] tcp_do_work_recv: Received new message; mode: 2.
>>>>[D 22:29:45.609654] tcp_do_work_recv: tag: 32
>>>>[D 22:29:45.609769] BMI_post_send_list: addr: 680, count: 1, total_size: 24
>>>>[D 22:29:45.609790] element 0: offset: 0x618970, size: 24
>>>>[D 22:29:45.609813] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
>>>>[D 22:30:18.316997] handle_new_connection: Assigning socket 9 to new
>>>>method addr.
>>>>[D 22:30:18.317099] tcp_do_work_recv: Reading header for new op.
>>>>[D 22:30:18.317116] tcp_do_work_recv: Received new message; mode: 2.
>>>>[D 22:30:18.317127] tcp_do_work_recv: tag: 14
>>>>[D 22:30:18.317206] [1 extents] -- new_handle is 0 (cur_extent is
>>>>1321528400 - 1651910498)
>>>>[E 22:30:18.317273] Error: handle allocator returned a zero handle.
>>>>[D 22:30:18.317316] BMI_post_send_list: addr: 761, count: 1, total_size: 24
>>>>[D 22:30:18.317336] element 0: offset: 0x5e23e0, size: 24
>>>>[D 22:30:18.317373] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
>>>>--------------->8-----------
>>>>
>>>>... Matt
>>>>
>>>>Murali Vilayannur wrote:
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>>Hi Matt,
>>>>>It is indeed a 64 bit bug that was fixed in the patch/url I mentioned.
>>>>>The server logs with the relevant aio messages would be more interesting..
>>>>>The snippet below does not seem to have the aio messages.
>>>>>Please let us know if that patch addresses your problems. Alternatively,
>>>>>do try cvs if possible..
>>>>>Thanks,
>>>>>Murali
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>
>>>>
>>>
>>>
>>>
>>>
>
>
>
>
<Defaults>
UnexpectedRequests 50
LogFile /var/log/pvfs2-server.log
EventLogging storage,network,server
EventLogging none
LogStamp usec
BMIModules bmi_tcp
FlowModules flowproto_multiqueue
PerfUpdateInterval 1000
ServerJobBMITimeoutSecs 30
ServerJobFlowTimeoutSecs 30
ClientJobBMITimeoutSecs 300
ClientJobFlowTimeoutSecs 300
ClientRetryLimit 5
ClientRetryDelayMilliSecs 2000
</Defaults>
<Aliases>
Alias cree tcp://cree:3334
Alias node1 tcp://node10:3334
Alias node10 tcp://node11:3334
Alias node11 tcp://node12:3334
Alias node12 tcp://node1:3334
Alias node2 tcp://node2:3334
Alias node3 tcp://node3:3334
Alias node4 tcp://node4:3334
Alias node5 tcp://node5:3334
Alias node6 tcp://node6:3334
Alias node7 tcp://node7:3334
Alias node8 tcp://node8:3334
Alias node9 tcp://node9:3334
</Aliases>
<Filesystem>
Name pvfs2-fs
ID 1559991218
RootHandle 1048576
<MetaHandleRanges>
Range cree 4-330382102
</MetaHandleRanges>
<DataHandleRanges>
Range node1 330382103-660764201
Range node10 660764202-991146300
Range node11 991146301-1321528399
Range node12 1321528400-1651910498
Range node2 1651910499-1982292597
Range node3 1982292598-2312674696
Range node4 2312674697-2643056795
Range node5 2643056796-2973438894
Range node6 2973438895-3303820993
Range node7 3303820994-3634203092
Range node8 3634203093-3964585191
Range node9 3964585192-4294967290
</DataHandleRanges>
<StorageHints>
TroveSyncMeta yes
TroveSyncData no
AttrCacheKeywords datafile_handles,metafile_dist
AttrCacheKeywords dir_ent, symlink_target
AttrCacheSize 4093
AttrCacheMaxNumElems 32768
</StorageHints>
</Filesystem>
[E 21:15:19.821914] Error: handle allocator returned a zero handle.
[E 21:15:19.825030] tried to remove non-existant dataspace
[E 21:20:05.754149] Error: handle allocator returned a zero handle.
[E 21:25:21.309261] Error: handle allocator returned a zero handle.
[E 09:14:21.277492]
PVFS2 server got signal 15 (server_status_flag: 262143)
[D 09:14:23.350158] PVFS2 Server version 1.4.1pre1-2006-05-25-172859 starting.
[E 09:14:23.357587] src/server/pvfs2-server.c line 1006: Error initializing
filesystem pvfs2-fs
[E 09:14:23.379473] [bt] /usr/local/sbin/pvfs2-server [0x40d453]
[E 09:14:23.379649] [bt] /usr/local/sbin/pvfs2-server(main+0xbe8) [0x40e5e8]
[E 09:14:23.379676] [bt] /lib64/tls/libc.so.6(__libc_start_main+0xda)
[0x2aaaaaffc4fa]
[E 09:14:23.379688] [bt] /usr/local/sbin/pvfs2-server [0x40c30a]
[E 09:14:23.379700] Error: Could not initialize server interfaces; aborting.
[E 09:14:23.379711] Error: Could not initialize server; aborting.
[D 10:27:09.438409] PVFS2 Server version 1.4.1pre1-2006-05-25-172859 starting.
[E 10:27:09.442240] src/server/pvfs2-server.c line 1006: Error initializing
filesystem pvfs2-fs
[E 10:27:09.442808] [bt] /usr/local/sbin/pvfs2-server [0x40d453]
[E 10:27:09.442857] [bt] /usr/local/sbin/pvfs2-server(main+0xbe8) [0x40e5e8]
[E 10:27:09.442869] [bt] /lib64/tls/libc.so.6(__libc_start_main+0xda)
[0x2aaaaaffc4fa]
[E 10:27:09.442880] [bt] /usr/local/sbin/pvfs2-server [0x40c30a]
[E 10:27:09.442906] Error: Could not initialize server interfaces; aborting.
[E 10:27:09.442917] Error: Could not initialize server; aborting.
[D 10:48:59.498893] PVFS2 Server version 1.4.1pre1-2006-05-25-172859 starting.
[E 10:51:47.787894] Error: handle allocator returned a zero handle.
[E 12:12:00.311530]
PVFS2 server got signal 15 (server_status_flag: 262143)
[D 12:13:19.951885] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[E 12:13:19.957389] src/server/pvfs2-server.c line 1006: Error initializing
filesystem pvfs2-fs
[E 12:13:19.957781] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40d453]
[E 12:13:19.957796] [bt]
/usr/local/pvfs2_nodes/sbin/pvfs2-server(main+0xbe8) [0x40e5e8]
[E 12:13:19.957807] [bt] /lib64/tls/libc.so.6(__libc_start_main+0xda)
[0x2aaaaaffc4fa]
[E 12:13:19.957817] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40c30a]
[E 12:13:19.957828] Error: Could not initialize server interfaces; aborting.
[E 12:13:19.957839] Error: Could not initialize server; aborting.
[D 12:13:25.766237] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[E 12:13:25.772995] src/server/pvfs2-server.c line 1006: Error initializing
filesystem pvfs2-fs
[E 12:13:25.773371] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40d453]
[E 12:13:25.773387] [bt]
/usr/local/pvfs2_nodes/sbin/pvfs2-server(main+0xbe8) [0x40e5e8]
[E 12:13:25.773398] [bt] /lib64/tls/libc.so.6(__libc_start_main+0xda)
[0x2aaaaaffc4fa]
[E 12:13:25.773408] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40c30a]
[E 12:13:25.773419] Error: Could not initialize server interfaces; aborting.
[E 12:13:25.773431] Error: Could not initialize server; aborting.
[D 12:13:41.461844] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[E 12:13:41.466391] src/server/pvfs2-server.c line 1006: Error initializing
filesystem pvfs2-fs
[E 12:13:41.466779] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40d453]
[E 12:13:41.466794] [bt]
/usr/local/pvfs2_nodes/sbin/pvfs2-server(main+0xbe8) [0x40e5e8]
[E 12:13:41.466805] [bt] /lib64/tls/libc.so.6(__libc_start_main+0xda)
[0x2aaaaaffc4fa]
[E 12:13:41.466815] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40c30a]
[E 12:13:41.466826] Error: Could not initialize server interfaces; aborting.
[E 12:13:41.466839] Error: Could not initialize server; aborting.
[D 12:14:59.455914] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[D 12:14:59.456912] BMI_tcp_initialize: Initializing TCP/IP module.
[D 12:14:59.457007] BMI_tcp_initialize: TCP/IP module successfully initialized.
[D 12:14:59.458395] dbpf_thread_initialize: initialized
[E 12:14:59.460359] src/server/pvfs2-server.c line 1006: Error initializing
filesystem pvfs2-fs
[E 12:14:59.460741] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40d453]
[E 12:14:59.460757] [bt]
/usr/local/pvfs2_nodes/sbin/pvfs2-server(main+0xbe8) [0x40e5e8]
[E 12:14:59.460767] [bt] /lib64/tls/libc.so.6(__libc_start_main+0xda)
[0x2aaaaaffc4fa]
[E 12:14:59.460778] [bt] /usr/local/pvfs2_nodes/sbin/pvfs2-server [0x40c30a]
[E 12:14:59.460789] Error: Could not initialize server interfaces; aborting.
[E 12:14:59.460799] Error: Could not initialize server; aborting.
[D 12:14:59.460837] dbpf_thread_function started
[D 12:14:59.471459] BMI_tcp_finalize: TCP/IP module finalized.
[D 12:14:59.482380] dbpf_thread_function ending
[D 12:14:59.482503] dbpf_thread_finalize: finalized
[D 12:16:31.238213] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[D 12:16:31.238967] BMI_tcp_initialize: Initializing TCP/IP module.
[D 12:16:31.239066] BMI_tcp_initialize: TCP/IP module successfully initialized.
[D 12:16:31.240520] dbpf_thread_initialize: initialized
[D 12:16:31.242277] collection lookup: version is 0.1.2
[D 12:16:31.242443] - set handle re-use timeout to 360 seconds (ret=0)
[D 12:16:31.242618] dbpf_thread_function started
[E 12:16:53.700266]
PVFS2 server got signal 15 (server_status_flag: 262143)
[D 12:16:53.801305] BMI_tcp_finalize: TCP/IP module finalized.
[D 12:16:53.803284] dbpf_thread_function ending
[D 12:16:53.803321] dbpf_thread_finalize: finalized
[D 12:16:58.673431] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[D 12:16:58.674250] BMI_tcp_initialize: Initializing TCP/IP module.
[D 12:16:58.674346] BMI_tcp_initialize: TCP/IP module successfully initialized.
[D 12:16:58.676053] dbpf_thread_function started
[D 12:16:58.676110] dbpf_thread_initialize: initialized
[D 12:16:58.677469] collection lookup: version is 0.1.2
[D 12:16:58.677635] - set handle re-use timeout to 360 seconds (ret=0)
[E 12:17:01.766466]
PVFS2 server got signal 15 (server_status_flag: 262143)
[D 12:17:01.852093] BMI_tcp_finalize: TCP/IP module finalized.
[D 12:17:01.860037] dbpf_thread_function ending
[D 12:17:01.860136] dbpf_thread_finalize: finalized
[D 12:17:03.804485] PVFS2 Server version 1.4.1pre1-2006-05-25-174324 starting.
[D 12:17:03.805582] BMI_tcp_initialize: Initializing TCP/IP module.
[D 12:17:03.805684] BMI_tcp_initialize: TCP/IP module successfully initialized.
[D 12:17:03.807236] dbpf_thread_initialize: initialized
[D 12:17:03.807373] dbpf_thread_function started
[D 12:17:03.811085] collection lookup: version is 0.1.2
[D 12:17:03.812792] - set handle re-use timeout to 360 seconds (ret=0)
[D 12:18:09.666537] handle_new_connection: Assigning socket 12 to new method
addr.
[D 12:18:09.666671] tcp_do_work_recv: Reading header for new op.
[D 12:18:09.666691] tcp_do_work_recv: Received new message; mode: 2.
[D 12:18:09.666703] tcp_do_work_recv: tag: 5
[D 12:18:09.666804] BMI_post_send_list: addr: 181, count: 1, total_size: 16
[D 12:18:09.666892] element 0: offset: 0x61b870, size: 16
[D 12:18:09.666928] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
[D 12:19:11.619230] handle_new_connection: Assigning socket 12 to new method
addr.
[D 12:19:11.619308] tcp_do_work_recv: Reading header for new op.
[D 12:19:11.619326] tcp_do_work_recv: Received new message; mode: 2.
[D 12:19:11.619337] tcp_do_work_recv: tag: 5
[D 12:19:11.619405] BMI_post_send_list: addr: 309, count: 1, total_size: 16
[D 12:19:11.619462] element 0: offset: 0x61b870, size: 16
[D 12:19:11.619499] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
[D 12:19:11.623886] tcp_do_work_recv: Reading header for new op.
[D 12:19:11.623905] tcp_do_work_recv: Received new message; mode: 2.
[D 12:19:11.623916] tcp_do_work_recv: tag: 18
[D 12:19:11.624005] BMI_post_send_list: addr: 309, count: 1, total_size: 24
[D 12:19:11.624023] element 0: offset: 0x5e56b0, size: 24
[D 12:19:11.624043] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 12:19:11.624381] tcp_do_work_recv: Reading header for new op.
[D 12:19:11.624399] tcp_do_work_recv: Received new message; mode: 2.
[D 12:19:11.624410] tcp_do_work_recv: tag: 31
[D 12:19:11.624520] BMI_post_send_list: addr: 309, count: 1, total_size: 24
[D 12:19:11.624559] element 0: offset: 0x5e57d0, size: 24
[D 12:19:11.624587] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 12:20:04.244167] handle_new_connection: Assigning socket 12 to new method
addr.
[D 12:20:04.244222] tcp_do_work_recv: Reading header for new op.
[D 12:20:04.244237] tcp_do_work_recv: Received new message; mode: 2.
[D 12:20:04.244248] tcp_do_work_recv: tag: 14
[D 12:20:04.244303] [1 extents] -- new_handle is 0 (cur_extent is 991146301 -
1321528399)
[E 12:20:04.244317] Error: handle allocator returned a zero handle.
[D 12:20:04.244351] BMI_post_send_list: addr: 428, count: 1, total_size: 24
[D 12:20:04.244363] element 0: offset: 0x5e5a40, size: 24
[D 12:20:04.244382] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 13:10:22.948994] PVFS2 Server version 1.4.1pre1-2006-05-25-172859 starting.
[D 13:10:22.949717] Passing tcp://cree:3334 as BMI listen address.
[D 13:10:22.949775] BMI_tcp_initialize: Initializing TCP/IP module.
[D 13:10:22.949849] BMI_tcp_initialize: TCP/IP module successfully initialized.
[D 13:10:22.951286] dbpf_thread_initialize: initialized
[D 13:10:22.951510] dbpf_thread_function started
[D 13:10:22.952606] collection lookup: version is 0.1.2
[D 13:10:22.952773] - set handle re-use timeout to 360 seconds (ret=0)
[D 13:10:22.976651] File system pvfs2-fs using handles:
4-330382102
[D 13:10:22.976663] Sync on metadata update for pvfs2-fs: yes
[D 13:10:22.976672] Sync on I/O data update for pvfs2-fs: no
[D 13:10:22.976701] Storage Init Complete (aio-threaded)
[D 13:10:22.976711] 1 filesystem(s) initialized
[D 13:10:22.977268] Initialization completed successfully.
[D 13:10:33.376598] handle_new_connection: Assigning socket 12 to new method
addr.
[D 13:10:33.376682] tcp_do_work_recv: Reading header for new op.
[D 13:10:33.376697] tcp_do_work_recv: Received new message; mode: 2.
[D 13:10:33.376708] tcp_do_work_recv: tag: 1
[D 13:10:33.376777] (0x5e1ea0) getconfig (prelude sm) state: req_sched
[D 13:10:33.376839] (0x5e1ea0) getconfig (prelude sm) state: getattr_if_needed
[D 13:10:33.376851] (0x5e1ea0) getconfig (prelude sm) state: perm_check (status
= 0)
[D 13:10:33.376863] (0x5e1ea0) getconfig state: init
[D 13:10:33.376876] (0x5e1ea0) getconfig (FR sm) state: release: (error_code =
0)
[D 13:10:33.376890] (0x5e1ea0) getconfig (FR sm) state: send_resp (status = 0)
[D 13:10:33.376918] BMI_post_send_list: addr: 73, count: 1, total_size: 1720
[D 13:10:33.376929] element 0: offset: 0x61ba30, size: 1720
[D 13:10:33.376977] BMI_tcp_post_send_generic: Sent: 1720 bytes of data.
[D 13:10:33.376990] (0x5e1ea0) getconfig (FR sm) state: cleanup
[D 13:10:33.377020] (0x5e1ea0) getconfig state: cleanup
[D 13:10:33.387230] tcp_do_work_recv: Reading header for new op.
[D 13:10:33.387253] tcp_do_work_recv: Received new message; mode: 2.
[D 13:10:33.387264] tcp_do_work_recv: tag: 2
[D 13:10:33.387306] (0x5e34e0) mgmt_noop (prelude sm) state: req_sched
[D 13:10:33.387327] (0x5e34e0) mgmt_noop (prelude sm) state: getattr_if_needed
[D 13:10:33.387337] (0x5e34e0) mgmt_noop (prelude sm) state: perm_check (status
= 0)
[D 13:10:33.387346] (0x5e34e0) mgmt_noop (FR sm) state: release: (error_code =
0)
[D 13:10:33.387358] (0x5e34e0) mgmt_noop (FR sm) state: send_resp (status = 0)
[D 13:10:33.387370] BMI_post_send_list: addr: 73, count: 1, total_size: 16
[D 13:10:33.387379] element 0: offset: 0x61b8a0, size: 16
[D 13:10:33.387409] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
[D 13:10:33.387420] (0x5e34e0) mgmt_noop (FR sm) state: cleanup
[D 13:10:33.387432] (0x5e34e0) mgmt_noop state: cleanup
[D 13:10:33.393697] tcp_do_work_recv: Reading header for new op.
[D 13:10:33.393727] tcp_do_work_recv: Received new message; mode: 2.
[D 13:10:33.393737] tcp_do_work_recv: tag: 15
[D 13:10:33.393768] (0x5e4680) mgmt_setparam (prelude sm) state: req_sched
[D 13:10:33.393785] (0x5e4680) mgmt_setparam (prelude sm) state:
getattr_if_needed
[D 13:10:33.393794] (0x5e4680) mgmt_setparam (prelude sm) state: perm_check
(status = 0)
[D 13:10:33.393806] (0x5e4680) mgmt_setparam state: work
[D 13:10:33.393878] looking for fs_id: 1559991218, found 1559991218.
[D 13:10:33.393889] (0x5e4680) mgmt_setparam (FR sm) state: release:
(error_code = 0)
[D 13:10:33.393901] (0x5e4680) mgmt_setparam (FR sm) state: send_resp (status =
0)
[D 13:10:33.393911] BMI_post_send_list: addr: 73, count: 1, total_size: 24
[D 13:10:33.393921] element 0: offset: 0x5e56e0, size: 24
[D 13:10:33.393950] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 13:10:33.393961] (0x5e4680) mgmt_setparam (FR sm) state: cleanup
[D 13:10:33.393972] (0x5e4680) mgmt_setparam state: cleanup
[D 13:10:33.393982] - setparam returning 0
[D 13:10:33.394393] tcp_do_work_recv: Reading header for new op.
[D 13:10:33.394418] tcp_do_work_recv: Received new message; mode: 2.
[D 13:10:33.394428] tcp_do_work_recv: tag: 28
[D 13:10:33.394485] (0x5e5820) mgmt_setparam (prelude sm) state: req_sched
[D 13:10:33.394504] (0x5e5820) mgmt_setparam (prelude sm) state:
getattr_if_needed
[D 13:10:33.394513] (0x5e5820) mgmt_setparam (prelude sm) state: perm_check
(status = 0)
[D 13:10:33.394522] (0x5e5820) mgmt_setparam state: work
[D 13:10:33.394531] - ROOT_CHECK looking for handle 1048576, on fs_id
1559991218
[D 13:10:33.394599] (0x5e5820) mgmt_setparam (FR sm) state: release:
(error_code = 0)
[D 13:10:33.394612] (0x5e5820) mgmt_setparam (FR sm) state: send_resp (status =
0)
[D 13:10:33.394623] BMI_post_send_list: addr: 73, count: 1, total_size: 24
[D 13:10:33.394633] element 0: offset: 0x5e5800, size: 24
[D 13:10:33.394661] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 13:10:33.394673] (0x5e5820) mgmt_setparam (FR sm) state: cleanup
[D 13:10:33.394684] (0x5e5820) mgmt_setparam state: cleanup
[D 13:10:33.394693] - setparam returning 0
[D 13:35:16.847414] handle_new_connection: Assigning socket 12 to new method
addr.
[D 13:35:16.847493] tcp_do_work_recv: Reading header for new op.
[D 13:35:16.847507] tcp_do_work_recv: Received new message; mode: 2.
[D 13:35:16.847516] tcp_do_work_recv: tag: 1
[D 13:35:16.847554] (0x5e69c0) getconfig (prelude sm) state: req_sched
[D 13:35:16.847572] (0x5e69c0) getconfig (prelude sm) state: getattr_if_needed
[D 13:35:16.847583] (0x5e69c0) getconfig (prelude sm) state: perm_check (status
= 0)
[D 13:35:16.847593] (0x5e69c0) getconfig state: init
[D 13:35:16.847604] (0x5e69c0) getconfig (FR sm) state: release: (error_code =
0)
[D 13:35:16.847617] (0x5e69c0) getconfig (FR sm) state: send_resp (status = 0)
[D 13:35:16.847645] BMI_post_send_list: addr: 3003, count: 1, total_size: 1720
[D 13:35:16.847656] element 0: offset: 0x61d1f0, size: 1720
[D 13:35:16.847745] BMI_tcp_post_send_generic: Sent: 1720 bytes of data.
[D 13:35:16.847759] (0x5e69c0) getconfig (FR sm) state: cleanup
[D 13:35:16.847789] (0x5e69c0) getconfig state: cleanup
[D 13:35:16.848667] tcp_do_work_recv: Reading header for new op.
[D 13:35:16.848681] tcp_do_work_recv: Received new message; mode: 2.
[D 13:35:16.848691] tcp_do_work_recv: tag: 2
[D 13:35:16.848715] (0x5e7b60) mgmt_noop (prelude sm) state: req_sched
[D 13:35:16.848727] (0x5e7b60) mgmt_noop (prelude sm) state: getattr_if_needed
[D 13:35:16.848737] (0x5e7b60) mgmt_noop (prelude sm) state: perm_check (status
= 0)
[D 13:35:16.848747] (0x5e7b60) mgmt_noop (FR sm) state: release: (error_code =
0)
[D 13:35:16.848757] (0x5e7b60) mgmt_noop (FR sm) state: send_resp (status = 0)
[D 13:35:16.848776] BMI_post_send_list: addr: 3003, count: 1, total_size: 16
[D 13:35:16.848785] element 0: offset: 0x5e5710, size: 16
[D 13:35:16.848815] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
[D 13:35:16.848827] (0x5e7b60) mgmt_noop (FR sm) state: cleanup
[D 13:35:16.848838] (0x5e7b60) mgmt_noop state: cleanup
[D 13:36:18.806935] handle_new_connection: Assigning socket 12 to new method
addr.
[D 13:36:18.807024] tcp_do_work_recv: Reading header for new op.
[D 13:36:18.807038] tcp_do_work_recv: Received new message; mode: 2.
[D 13:36:18.807048] tcp_do_work_recv: tag: 1
[D 13:36:18.807082] (0x5e8d00) getconfig (prelude sm) state: req_sched
[D 13:36:18.807099] (0x5e8d00) getconfig (prelude sm) state: getattr_if_needed
[D 13:36:18.807109] (0x5e8d00) getconfig (prelude sm) state: perm_check (status
= 0)
[D 13:36:18.807120] (0x5e8d00) getconfig state: init
[D 13:36:18.807130] (0x5e8d00) getconfig (FR sm) state: release: (error_code =
0)
[D 13:36:18.807142] (0x5e8d00) getconfig (FR sm) state: send_resp (status = 0)
[D 13:36:18.807161] BMI_post_send_list: addr: 3136, count: 1, total_size: 1720
[D 13:36:18.807172] element 0: offset: 0x61d1f0, size: 1720
[D 13:36:18.807227] BMI_tcp_post_send_generic: Sent: 1720 bytes of data.
[D 13:36:18.807241] (0x5e8d00) getconfig (FR sm) state: cleanup
[D 13:36:18.807261] (0x5e8d00) getconfig state: cleanup
[D 13:36:18.809210] tcp_do_work_recv: Reading header for new op.
[D 13:36:18.809224] tcp_do_work_recv: Received new message; mode: 2.
[D 13:36:18.809233] tcp_do_work_recv: tag: 2
[D 13:36:18.809293] (0x5e9ea0) mgmt_noop (prelude sm) state: req_sched
[D 13:36:18.809306] (0x5e9ea0) mgmt_noop (prelude sm) state: getattr_if_needed
[D 13:36:18.809316] (0x5e9ea0) mgmt_noop (prelude sm) state: perm_check (status
= 0)
[D 13:36:18.809325] (0x5e9ea0) mgmt_noop (FR sm) state: release: (error_code =
0)
[D 13:36:18.809336] (0x5e9ea0) mgmt_noop (FR sm) state: send_resp (status = 0)
[D 13:36:18.809359] BMI_post_send_list: addr: 3136, count: 1, total_size: 16
[D 13:36:18.809368] element 0: offset: 0x5e5710, size: 16
[D 13:36:18.809398] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
[D 13:36:18.809410] (0x5e9ea0) mgmt_noop (FR sm) state: cleanup
[D 13:36:18.809420] (0x5e9ea0) mgmt_noop state: cleanup
[D 13:36:18.815363] tcp_do_work_recv: Reading header for new op.
[D 13:36:18.815377] tcp_do_work_recv: Received new message; mode: 2.
[D 13:36:18.815386] tcp_do_work_recv: tag: 15
[D 13:36:18.815411] (0x5eb040) mgmt_setparam (prelude sm) state: req_sched
[D 13:36:18.815422] (0x5eb040) mgmt_setparam (prelude sm) state:
getattr_if_needed
[D 13:36:18.815432] (0x5eb040) mgmt_setparam (prelude sm) state: perm_check
(status = 0)
[D 13:36:18.815442] (0x5eb040) mgmt_setparam state: work
[D 13:36:18.815501] looking for fs_id: 1559991218, found 1559991218.
[D 13:36:18.815512] (0x5eb040) mgmt_setparam (FR sm) state: release:
(error_code = 0)
[D 13:36:18.815523] (0x5eb040) mgmt_setparam (FR sm) state: send_resp (status =
0)
[D 13:36:18.815534] BMI_post_send_list: addr: 3136, count: 1, total_size: 24
[D 13:36:18.815543] element 0: offset: 0x5e5710, size: 24
[D 13:36:18.815571] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 13:36:18.815582] (0x5eb040) mgmt_setparam (FR sm) state: cleanup
[D 13:36:18.815593] (0x5eb040) mgmt_setparam state: cleanup
[D 13:36:18.815602] - setparam returning 0
[D 13:36:18.815854] tcp_do_work_recv: Reading header for new op.
[D 13:36:18.815865] tcp_do_work_recv: Received new message; mode: 2.
[D 13:36:18.815874] tcp_do_work_recv: tag: 28
[D 13:36:18.815898] (0x5ec1e0) mgmt_setparam (prelude sm) state: req_sched
[D 13:36:18.815909] (0x5ec1e0) mgmt_setparam (prelude sm) state:
getattr_if_needed
[D 13:36:18.815919] (0x5ec1e0) mgmt_setparam (prelude sm) state: perm_check
(status = 0)
[D 13:36:18.815928] (0x5ec1e0) mgmt_setparam state: work
[D 13:36:18.815937] - ROOT_CHECK looking for handle 1048576, on fs_id
1559991218
[D 13:36:18.815997] (0x5ec1e0) mgmt_setparam (FR sm) state: release:
(error_code = 0)
[D 13:36:18.816009] (0x5ec1e0) mgmt_setparam (FR sm) state: send_resp (status =
0)
[D 13:36:18.816020] BMI_post_send_list: addr: 3136, count: 1, total_size: 24
[D 13:36:18.816030] element 0: offset: 0x5e5710, size: 24
[D 13:36:18.816057] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 13:36:18.816068] (0x5ec1e0) mgmt_setparam (FR sm) state: cleanup
[D 13:36:18.816079] (0x5ec1e0) mgmt_setparam state: cleanup
[D 13:36:18.816088] - setparam returning 0
[D 13:37:11.429254] handle_new_connection: Assigning socket 12 to new method
addr.
[D 13:37:11.429419] tcp_do_work_recv: Reading header for new op.
[D 13:37:11.429435] tcp_do_work_recv: Received new message; mode: 2.
[D 13:37:11.429445] tcp_do_work_recv: tag: 1
[D 13:37:11.429484] (0x5ed380) getconfig (prelude sm) state: req_sched
[D 13:37:11.429503] (0x5ed380) getconfig (prelude sm) state: getattr_if_needed
[D 13:37:11.429514] (0x5ed380) getconfig (prelude sm) state: perm_check (status
= 0)
[D 13:37:11.429524] (0x5ed380) getconfig state: init
[D 13:37:11.429535] (0x5ed380) getconfig (FR sm) state: release: (error_code =
0)
[D 13:37:11.429548] (0x5ed380) getconfig (FR sm) state: send_resp (status = 0)
[D 13:37:11.429572] BMI_post_send_list: addr: 3260, count: 1, total_size: 1720
[D 13:37:11.429583] element 0: offset: 0x61e250, size: 1720
[D 13:37:11.429608] BMI_tcp_post_send_generic: Sent: 1720 bytes of data.
[D 13:37:11.429622] (0x5ed380) getconfig (FR sm) state: cleanup
[D 13:37:11.429641] (0x5ed380) getconfig state: cleanup
[D 13:37:11.430475] tcp_do_work_recv: Reading header for new op.
[D 13:37:11.430493] tcp_do_work_recv: Received new message; mode: 2.
[D 13:37:11.430522] tcp_do_work_recv: tag: 2
[D 13:37:11.430553] (0x5ee520) lookup_path (prelude sm) state: req_sched
[D 13:37:11.430566] (0x5ee520) lookup_path (prelude sm) state: getattr_if_needed
[D 13:37:11.430576] About to retrieve attributes for handle 1048576
[D 13:37:11.430726] ATTRIB: retrieved attributes from DISK for key 1048576
uid = 0, mode = 511, type = 4, dfile_count = 0, dist_size = 0
b_size = 0, k_size = 4
[D 13:37:11.430805] (0x5ee520) lookup_path (prelude sm) state: perm_check
(status = 0)
[D 13:37:11.430824] (0x5ee520) lookup_path state: init
[D 13:37:11.430835] (0x5ee520) lookup_path state: read_object_metadata
[D 13:37:11.430848] (0x5ee520) lookup_path state: verify_object_metadata
[D 13:37:11.430858] attrs = (owner = 0, group = 0, perms = 777, type = 4)
[D 13:37:11.430869] object is a directory; will be looking for handle for
segment "testf2" in a bit
[D 13:37:11.430879] (0x5ee520) lookup_path state: read_directory_entry_handle
[D 13:37:11.430888] reading dirent handle value from handle 1048576
[D 13:37:11.430968] (0x5ee520) lookup_path state: read_directory_entry
[D 13:37:11.430979] reading from dirent handle = 4, segment = testf2 (len=6)
[D 13:37:11.431017] (0x5ee520) lookup_path state: setup_resp
[D 13:37:11.431028] sending 'error' response with 0 handle(s) and 0 attr(s)
[D 13:37:11.431038] (0x5ee520) lookup_path (FR sm) state: release: (error_code
= -1073742082)
[D 13:37:11.431050] (0x5ee520) lookup_path (FR sm) state: send_resp (status =
-1073741826)
[D 13:37:11.431066] BMI_post_send_list: addr: 3260, count: 1, total_size: 32
[D 13:37:11.431076] element 0: offset: 0x61e250, size: 32
[D 13:37:11.431101] BMI_tcp_post_send_generic: Sent: 32 bytes of data.
[D 13:37:11.431113] (0x5ee520) lookup_path (FR sm) state: cleanup
[D 13:37:11.431125] (0x5ee520) lookup_path state: cleanup
[D 13:37:11.431238] tcp_do_work_recv: Reading header for new op.
[D 13:37:11.431255] tcp_do_work_recv: Received new message; mode: 2.
[D 13:37:11.431264] tcp_do_work_recv: tag: 3
[D 13:37:11.431290] (0x5ef6c0) getattr (prelude sm) state: req_sched
[D 13:37:11.431303] (0x5ef6c0) getattr (prelude sm) state: getattr_if_needed
[D 13:37:11.431312] About to retrieve attributes for handle 1048576
[D 13:37:11.431323] (0x5ef6c0) getattr (prelude sm) state: perm_check (status =
0)
[D 13:37:11.431337] (0x5ef6c0) getattr state: verify_attribs
[D 13:37:11.431356] (0x5ef6c0) getattr state: setup_resp
[D 13:37:11.431366] (0x5ef6c0) getattr (FR sm) state: release: (error_code = 0)
[D 13:37:11.431376] (0x5ef6c0) getattr (FR sm) state: send_resp (status = 0)
[D 13:37:11.431388] BMI_post_send_list: addr: 3260, count: 1, total_size: 64
[D 13:37:11.431398] element 0: offset: 0x61e250, size: 64
[D 13:37:11.431419] BMI_tcp_post_send_generic: Sent: 64 bytes of data.
[D 13:37:11.431430] (0x5ef6c0) getattr (FR sm) state: cleanup
[D 13:37:11.431442] (0x5ef6c0) getattr state: getattr_cleanup
[D 13:37:11.431533] tcp_do_work_recv: Reading header for new op.
[D 13:37:11.431549] tcp_do_work_recv: Received new message; mode: 2.
[D 13:37:11.431559] tcp_do_work_recv: tag: 4
[D 13:37:11.431584] (0x5f0860) create (prelude sm) state: req_sched
[D 13:37:11.431596] (0x5f0860) create (prelude sm) state: getattr_if_needed
[D 13:37:11.431606] (0x5f0860) create (prelude sm) state: perm_check (status =
0)
[D 13:37:11.431616] (0x5f0860) create state: create
[D 13:37:11.431645] [1 extents] -- new_handle is 330382101 (cur_extent is 4 -
330382102)
[D 13:37:11.440762] db SYNC called servicing op type DSPACE_CREATE
[D 13:37:11.440807] (0x5f0860) create state: setup_resp
[D 13:37:11.440825] Handle created: 330382101
[D 13:37:11.440835] (0x5f0860) create (FR sm) state: release: (error_code = 0)
[D 13:37:11.440846] (0x5f0860) create (FR sm) state: send_resp (status = 0)
[D 13:37:11.440856] BMI_post_send_list: addr: 3260, count: 1, total_size: 24
[D 13:37:11.440865] element 0: offset: 0x5eecc0, size: 24
[D 13:37:11.440888] BMI_tcp_post_send_generic: Sent: 24 bytes of data.
[D 13:37:11.440899] (0x5f0860) create (FR sm) state: cleanup
[D 13:37:11.440928] (0x5f0860) create state: cleanup
[D 13:37:11.449844] tcp_do_work_recv: Reading header for new op.
[D 13:37:11.449866] tcp_do_work_recv: Received new message; mode: 2.
[D 13:37:11.449876] tcp_do_work_recv: tag: 25
[D 13:37:11.449905] (0x5f1a00) remove (prelude sm) state: req_sched
[D 13:37:11.449919] (0x5f1a00) remove (prelude sm) state: getattr_if_needed
[D 13:37:11.449928] About to retrieve attributes for handle 330382101
[D 13:37:11.449940] (0x5f1a00) remove (prelude sm) state: perm_check (status =
0)
[D 13:37:11.449950] (0x5f1a00) remove state: setup_work
[D 13:37:11.449960] (0x5f1a00) remove state: check_object_type
[D 13:37:11.449972] (0x5f1a00) remove state: verify_object_metadata
[D 13:37:11.449982] attrs read from keyval = (owner = 0, group = 0, perms =
0, type = 1)
[D 13:37:11.449992] (0x5f1a00) remove state: remove_dspace
[D 13:37:11.450001] (0x5f1a00) remove: removing dspace object
330382101,1559991218
[D 13:37:11.450070] removed dataspace with handle 330382101
[D 13:37:11.450398] db SYNC called servicing op type DSPACE_REMOVE
[D 13:37:11.450431] db SYNC called servicing op type DSPACE_REMOVE
[D 13:37:11.450467] (0x5f1a00) remove (FR sm) state: release: (error_code = 0)
[D 13:37:11.450488] (0x5f1a00) remove (FR sm) state: send_resp (status = 0)
[D 13:37:11.450499] BMI_post_send_list: addr: 3260, count: 1, total_size: 16
[D 13:37:11.450508] element 0: offset: 0x5ec710, size: 16
[D 13:37:11.450533] BMI_tcp_post_send_generic: Sent: 16 bytes of data.
[D 13:37:11.450544] (0x5f1a00) remove (FR sm) state: cleanup
[D 13:37:11.450556] (0x5f1a00) remove state: cleanup
_______________________________________________
Pvfs2-users mailing list
[email protected]
http://www.beowulf-underground.org/mailman/listinfo/pvfs2-users
