[Pvfs2-users] Some verbose logging from pvfs2-cp failure
Phil Carns
carns at mcs.anl.gov
Fri Oct 2 09:43:16 EDT 2009
Hi Ben,
I actually don't see any problems in the log file that you posted. The
"CANNOT cache" messages are normal with verbose logging turned on.
Those happen whenever PVFS encounters a metadata key that it isn't
configured to cache by default.
Looking through the log for just error codes returned to the client,
this is all that shows up:
grep error_code pvfs2-cp-fail.txt
[D 12/31 19:38] (s_op 0x1011cab8) getconfig (FR sm) state: release:
(error_code = 0)
[D 12/31 19:38] (s_op 0x1011dc58) lookup_path (FR sm) state: release:
(error_code = -1073742082)
[D 12/31 19:38] (s_op 0x1011edf8) getattr (FR sm) state: release:
(error_code = 0)
[D 12/31 19:38] (s_op 0x1011ff98) create (FR sm) state: release:
(error_code = 0)
This shows that pvfs2-cp did the following steps:
- got configuration info from the server
(success)
- checked to see if the target file already existed
1073742082 = "no such file or directory"
- retrieved attributes on the parent directory
(success)
- created the target file
(success)
All of that is normal from the server's perspective. Is there anything
else in the log after that?
You can also turn on logging for the pvfs2-cp executable itself by
setting the PVFS2_DEBUGMASK environment variable (export
PVFS2_DEBUGMASK=verbose) before running it.
-Phil
Huang, Bin wrote:
> Hi, list,
>
> I ran into a pvfs2-cp failure several months ago and
> received lots of helps from the list. But I had
> to leave my pvfs2 problem unsolved since I was
> assigned to a new project at that time.
>
> Now I have some time to attack this problem again.
> (hate to see a project fail especially when there is
> a clear start guide). Here is my verbose logging
> from the following attempt:
>
> "/usr/local/bin/pvfs2-cp -t /usr/lib/libc.a /mnt/pvfs2/testfile"
>
> The logging is gonna be long but the crucial message
> I think is " CANNOT cache data retrieved (key is de)"
> Maybe my Berkely DB is not working correctly.
>
> BTW, my pvfs2-touch also fails and I can show
> verbose message if needed.
>
> I appreciate any thought and help from you.
>
> Ben
>
>
> --------------------------------------------------------------
> [D 12/31 19:27] PVFS2 Server version 2.8.1 starting.
> [D 12/31 19:38] handle_new_connection: Assigning socket 11 to new method
> addr.
> [D 12/31 19:38] tcp_do_work_recv: Reading header for new op.
> [D 12/31 19:38] tcp_do_work_recv: Received new message; mode: 2.
> [D 12/31 19:38] tcp_do_work_recv: tag: 1
> [D 12/31 19:38] server_post_unexpected_recv
> [D 12/31 19:38] server_op_state_get_machine 999
> [D 12/31 19:38] server_state_machine_start 0x1011ca18
> [D 12/31 19:38] decoding 0 hints from request
> [D 12/31 19:38] server_op_state_get_machine 13
> [D 12/31 19:38] client:0, reqid:0, rank:0
> [D 12/31 19:38] (0x1011cab8) getconfig (prelude sm) state: req_sched
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011cab8: getconfig:
> request
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011cab8: getconfig:
> start
> [D 12/31 19:38] (0x1011cab8) getconfig (prelude sm) state: getattr_if_needed
> [D 12/31 19:38] PVFS operation "getconfig" got attr mask 127
> (attr_uid_valid? yes, attr_owner = 0, credentials_uid = 0)
> (attr_gid_valid? yes, attr_group = 0, credentials.gid = 0)
> [D 12/31 19:38] Final permission check for "getconfig" set error code to 0
> [D 12/31 19:38] (0x1011cab8) getconfig (prelude sm) state: perm_check
> (status = 0)
> [D 12/31 19:38] (s_op 0x1011cab8) getconfig (FR sm) state: release:
> (error_code = 0)
> [D 12/31 19:38] (s_op 0x1011cab8) getconfig (FR sm) state: send_resp
> (status = 0)
> [D 12/31 19:38] BMI_post_send_list: addr: 1372, count: 1, total_size:
> 904, tag: 1
> [D 12/31 19:38] element 0: offset: 0x1013d000, size: 904
> [D 12/31 19:38] tcp_post_send_generic: Sent: 904 bytes of data.
> [D 12/31 19:38] (s_op 0x1011cab8) getconfig (FR sm) state: cleanup
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011cab8: getconfig:
> finish (Success)
> [D 12/31 19:38] server_state_machine_complete 0x1011ca18
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: set_info: 1372 option: 6
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: searching for ref 1372
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: decremented ref 1372 to: 0
> [D 12/31 19:38] server_state_machine_terminate 0x1011ca18
> [D 12/31 19:38] tcp_do_work_recv: Reading header for new op.
> [D 12/31 19:38] tcp_do_work_recv: Received new message; mode: 2.
> [D 12/31 19:38] tcp_do_work_recv: tag: 2
> [D 12/31 19:38] server_post_unexpected_recv
> [D 12/31 19:38] server_op_state_get_machine 999
> [D 12/31 19:38] server_state_machine_start 0x1011dbb8
> [D 12/31 19:38] decoding 1 hints from request
> [D 12/31 19:38] server_op_state_get_machine 6
> [D 12/31 19:38] client:0, reqid:0, rank:0
> [D 12/31 19:38] (0x1011dc58) lookup_path (prelude sm) state: req_sched
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011dc58:
> lookup_path: request
> [D 12/31 19:38] REQ SCHED POSTING, handle: 1048576, queue_element:
> 0x1011cc30
> [D 12/31 19:38] REQ SCHED SCHEDULING, handle: 1048576, queue_element:
> 0x1011cc30
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011dc58:
> lookup_path: start
> [D 12/31 19:38] (0x1011dc58) lookup_path (prelude sm) state:
> getattr_if_needed
> [D 12/31 19:38] About to retrieve attributes for handle 1048576
> [D 12/31 19:38] dspace_getattr fast path attr cache hit on 1048576
> [D 12/31 19:38] PVFS operation "lookup_path" got attr mask 127
> (attr_uid_valid? yes, attr_owner = 0, credentials_uid = 0)
> (attr_gid_valid? yes, attr_group = 0, credentials.gid = 0)
> [D 12/31 19:38] Final permission check for "lookup_path" set error code to 0
> [D 12/31 19:38] (0x1011dc58) lookup_path (prelude sm) state: perm_check
> (status = 0)
> [D 12/31 19:38] STARTING LOOKUP REQUEST
> (path:testfile)(fs_id:1729469593)(handle:1048576)(attrmask:127)(# of
> segments:1)
> [D 12/31 19:38] dspace_getattr fast path attr cache hit on 1048576
> [D 12/31 19:38] attrs = (owner = 0, group = 0, perms = 777, type = 4)
> [D 12/31 19:38] - check_mode called --- (uid=0,gid=0,access_type=1)
> [D 12/31 19:38] - object attributes --- (uid=0,gid=0,mode=511)
> [D 12/31 19:38] - checking if uid (0) is root ...
> [D 12/31 19:38] - yes
> [D 12/31 19:38] object is a directory; will be looking for handle for
> segment "testfile" in a bit
> [D 12/31 19:38] reading dirent handle value from handle 1048576
> [D 12/31 19:38] *** Trove KeyVal Read of de
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048576
> returned (num_elems=2)
> [D 12/31 19:38] op_queue add: 0x1011cd98
> [D 12/31 19:38] [DBPF THREAD]: [KEYVAL -1]: -23
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE (KEYVAL_READ)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048576
> returned (num_elems=2)
> [D 12/31 19:38] ** CANNOT cache data retrieved (key is de)
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (KEYVAL_READ) (ret: 1)
> [D 12/31 19:38] op_queue add: 0x1011cd98
> [D 12/31 19:38] reading from dirent handle = 3, segment = testfile (len=8)
> [D 12/31 19:38] *** Trove KeyVal Read of testfile
> [D 12/31 19:38] op_queue add: 0x1011cd98
> [D 12/31 19:38] [DBPF THREAD]: [KEYVAL -1]: -24
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE (KEYVAL_READ)
> [D 12/31 19:38] warning: keyval read error on handle 3 and key= testfile
> (DB_NOTFOUND: No matching key/data pair found)
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (KEYVAL_READ) (ret: -1073742082)
> [D 12/31 19:38] op_queue add: 0x1011cd98
> [D 12/31 19:38] lookup error in previous step
> [D 12/31 19:38] sending 'error' response with 0 handle(s) and 0 attr(s)
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011dc58:
> lookup_path: path: testfile, lookup failed
> [D 12/31 19:38] (s_op 0x1011dc58) lookup_path (FR sm) state: release:
> (error_code = -1073742082)
> [D 12/31 19:38] REQ SCHED RELEASING, handle: 1048576, queue_element:
> 0x1011cc30
> [D 12/31 19:38] (s_op 0x1011dc58) lookup_path (FR sm) state: send_resp
> (status = -1073741826)
> [D 12/31 19:38] BMI_post_send_list: addr: 1372, count: 1, total_size:
> 16, tag: 2
> [D 12/31 19:38] element 0: offset: 0x1013e000, size: 16
> [D 12/31 19:38] tcp_post_send_generic: Sent: 16 bytes of data.
> [D 12/31 19:38] (s_op 0x1011dc58) lookup_path (FR sm) state: cleanup
> [D 12/31 19:38] tcp_do_work_recv: Reading header for new op.
> [D 12/31 19:38] tcp_do_work_recv: Received new message; mode: 2.
> [D 12/31 19:38] tcp_do_work_recv: tag: 3
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011dc58:
> lookup_path: finish (No such file or directory)
> [D 12/31 19:38] server_state_machine_complete 0x1011dbb8
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: set_info: 1372 option: 6
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: searching for ref 1372
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: decremented ref 1372 to: 1
> [D 12/31 19:38] server_state_machine_terminate 0x1011dbb8
> [D 12/31 19:38] server_post_unexpected_recv
> [D 12/31 19:38] server_op_state_get_machine 999
> [D 12/31 19:38] server_state_machine_start 0x1011ed58
> [D 12/31 19:38] decoding 1 hints from request
> [D 12/31 19:38] server_op_state_get_machine 4
> [D 12/31 19:38] client:0, reqid:0, rank:0
> [D 12/31 19:38] (0x1011edf8) getattr (prelude sm) state: req_sched
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011edf8:
> getattr: request
> [D 12/31 19:38] REQ SCHED POSTING, handle: 1048576, queue_element:
> 0x1011fea0
> [D 12/31 19:38] REQ SCHED SCHEDULING, handle: 1048576, queue_element:
> 0x1011fea0
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011edf8:
> getattr: start
> [D 12/31 19:38] (0x1011edf8) getattr (prelude sm) state: getattr_if_needed
> [D 12/31 19:38] About to retrieve attributes for handle 1048576
> [D 12/31 19:38] dspace_getattr fast path attr cache hit on 1048576
> [D 12/31 19:38] PVFS operation "getattr" got attr mask 127
> (attr_uid_valid? yes, attr_owner = 0, credentials_uid = 0)
> (attr_gid_valid? yes, attr_group = 0, credentials.gid = 0)
> [D 12/31 19:38] Final permission check for "getattr" set error code to 0
> [D 12/31 19:38] (0x1011edf8) getattr (prelude sm) state: perm_check
> (status = 0)
> [D 12/31 19:38] No version found! Using mtime 1748
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011edf8:
> getattr: type: directory
> [D 12/31 19:38] getattr: dirent_count not needed.
> [D 12/31 19:38] getattr: dfile_count needed.
> [D 12/31 19:38] *** Trove KeyVal Read of de
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048576
> returned (num_elems=2)
> [D 12/31 19:38] op_queue add: 0x1011dcb0
> [D 12/31 19:38] [DBPF THREAD]: [KEYVAL -1]: -25
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE (KEYVAL_READ)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048576
> returned (num_elems=2)
> [D 12/31 19:38] ** CANNOT cache data retrieved (key is de)
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (KEYVAL_READ) (ret: 1)
> [D 12/31 19:38] op_queue add: 0x1011dcb0
> [D 12/31 19:38] trying to getxattr of
> user.pvfs2.dist_name,user.pvfs2.dist_params,user.pvfs2.num_dfiles of dir
> handle (coll_id = 1729469593, handle = 1048576
> [D 12/31 19:38] op_queue add: 0x1011e0b8
> [D 12/31 19:38] [DBPF THREAD]: [KEYVAL -1]: -26
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE
> (KEYVAL_READ_LIST)
> [D 12/31 19:38] keyval get user.pvfs2.dist_name failed with error
> DB_NOTFOUND: No matching key/data pair found
> [D 12/31 19:38] keyval get user.pvfs2.dist_params failed with error
> DB_NOTFOUND: No matching key/data pair found
> [D 12/31 19:38] keyval get user.pvfs2.num_dfiles failed with error
> DB_NOTFOUND: No matching key/data pair found
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (KEYVAL_READ_LIST) (ret: -1073742082)
> [D 12/31 19:38] op_queue add: 0x1011e0b8
> [D 12/31 19:38] getattr: job status code = -1073742082
> [D 12/31 19:38] getattr: dir hint dfile_count: 0
> [D 12/31 19:38] - RETURNING retrieved attrs: [owner = 0, group = 0
> perms = 777, type = 4, atime = 1748, mtime = 1748
> ctime = 1748, dist_size = 0]
> [D 12/31 19:38] server returning dirent_count = 0 dfile_count = 0
> dist_name_len = 0 dist_params_len = 0
> [D 12/31 19:38] @ End DIRECTORY attributes: sending status 0 (error = 0)
> [D 12/31 19:38] (s_op 0x1011edf8) getattr (FR sm) state: release:
> (error_code = 0)
> [D 12/31 19:38] REQ SCHED RELEASING, handle: 1048576, queue_element:
> 0x1011fea0
> [D 12/31 19:38] (s_op 0x1011edf8) getattr (FR sm) state: send_resp
> (status = 0)
> [D 12/31 19:38] BMI_post_send_list: addr: 1372, count: 1, total_size:
> 108, tag: 3
> [D 12/31 19:38] element 0: offset: 0x1013e000, size: 108
> [D 12/31 19:38] tcp_post_send_generic: Sent: 108 bytes of data.
> [D 12/31 19:38] (s_op 0x1011edf8) getattr (FR sm) state: cleanup
> [D 12/31 19:38] tcp_do_work_recv: Reading header for new op.
> [D 12/31 19:38] tcp_do_work_recv: Received new message; mode: 2.
> [D 12/31 19:38] tcp_do_work_recv: tag: 4
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=1048576 S=0x1011edf8:
> getattr: finish (Success)
> [D 12/31 19:38] server_state_machine_complete 0x1011ed58
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: set_info: 1372 option: 6
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: searching for ref 1372
> [D 12/31 19:38] [BMI CONTROL]: BMI_set_info: decremented ref 1372 to: 1
> [D 12/31 19:38] server_state_machine_terminate 0x1011ed58
> [D 12/31 19:38] server_post_unexpected_recv
> [D 12/31 19:38] server_op_state_get_machine 999
> [D 12/31 19:38] server_state_machine_start 0x1011fef8
> [D 12/31 19:38] decoding 1 hints from request
> [D 12/31 19:38] server_op_state_get_machine 1
> [D 12/31 19:38] client:0, reqid:0, rank:0
> [D 12/31 19:38] (0x1011ff98) create (prelude sm) state: req_sched
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011ff98: create: request
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011ff98: create: start
> [D 12/31 19:38] (0x1011ff98) create (prelude sm) state: getattr_if_needed
> [D 12/31 19:38] PVFS operation "create" got attr mask 127
> (attr_uid_valid? yes, attr_owner = 0, credentials_uid = 0)
> (attr_gid_valid? yes, attr_group = 0, credentials.gid = 0)
> [D 12/31 19:38] Final permission check for "create" set error code to 0
> [D 12/31 19:38] (0x1011ff98) create (prelude sm) state: perm_check
> (status = 0)
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue called
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue 1 counter sync:0 non_sync:1
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue called
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue 1 counter sync:0 non_sync:0
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE
> (DSPACE_CREATE)
> [D 12/31 19:38] [1 extents] -- new_handle is 1048583 (cur_extent is 3 -
> 4611686018427387904)
> [D 12/31 19:38] dbpf_attr_cache_insert: inserting 1048583 (b_size is 0)
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (DSPACE_CREATE) (ret: 1)
> [D 12/31 19:38] [SYNC_COALESCE]: sync_coalesce called, handle: 0, cid: 0
> [D 12/31 19:38] [SYNC_COALESCE]: sync not needed, moving to completion
> queue: 0
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] Metafile handle created: 1048583
> [D 12/31 19:38] creating 1 local data files
> [D 12/31 19:38] creating 0 remote data files
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue called
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue 1 counter sync:0 non_sync:1
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue called
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue 1 counter sync:0 non_sync:0
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE
> (DSPACE_CREATE)
> [D 12/31 19:38] dbpf_attr_cache_insert: inserting 9223372036854775802
> (b_size is 0)
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (DSPACE_CREATE) (ret: 1)
> [D 12/31 19:38] [SYNC_COALESCE]: sync_coalesce called, handle: 0, cid: 0
> [D 12/31 19:38] [SYNC_COALESCE]: sync not needed, moving to completion
> queue: 0
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] create storing layout of size: 16
> [D 12/31 19:38] create storing NUM_DFILES_REQ_KEY value of 1
> [D 12/31 19:38] job_trove_keyval_write_list() posting
> trove_keyval_write_list()
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue called
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue 0 counter sync:1 non_sync:0
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue called
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue 0 counter sync:0 non_sync:0
> [D 12/31 19:38] [DBPF THREAD]: [KEYVAL -1]: -27
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE
> (KEYVAL_WRITE_LIST)
> [D 12/31 19:38] keyval_db->put(handle= 1048583, key= dh (3)) size=11
> [D 12/31 19:38] *** Trove KeyVal Write of dh
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] Setting data 0x100fec68 based on key 1048583 and key_str
> dh (data_sz=8)
> [D 12/31 19:38] *** cached keyval data written (key is dh)
> [D 12/31 19:38] keyval_db->put(handle= 1048583, key= md (3)) size=11
> [D 12/31 19:38] *** Trove KeyVal Write of md
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] ** CANNOT cache data written (key is md)
> [D 12/31 19:38] keyval_db->put(handle= 1048583, key= ml (3)) size=11
> [D 12/31 19:38] *** Trove KeyVal Write of ml
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] ** CANNOT cache data written (key is ml)
> [D 12/31 19:38] keyval_db->put(handle= 1048583, key= nd (3)) size=11
> [D 12/31 19:38] *** Trove KeyVal Write of nd
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] ** CANNOT cache data written (key is nd)
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (KEYVAL_WRITE_LIST) (ret: 1)
> [D 12/31 19:38] [SYNC_COALESCE]: sync_coalesce called, handle: 1048583,
> cid: 0
> [D 12/31 19:38] [SYNC_COALESCE]: sync_context: 0x100c7edc
> [D 12/31 19:38] [SYNC_COALESCE]: sync context type is KEYVAL
> [D 12/31 19:38] [SYNC_COALESCE]: high or low watermark reached:
> coalesced: 0
> queued: 0
> [D 12/31 19:38] [SYNC_COALESCE]: syncing now!
> [D 12/31 19:38] [SYNC_COALESCE]: coalesce 0 sync start in
> coalesce_queue:0 pending:0
> [D 12/31 19:38] [SYNC_COALESCE]: coalesce 0 sync stop
> [D 12/31 19:38] [SYNC_COALESCE]: moving op: 0x1011dbb8, handle: 1048583
> , type: 71 to completion queue
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] [STUFFED CREATE]: WRITING attrs: [owner = 0, group = 0
> perms = 644, type = 1, atime = 2284, mtime = 0
> ctime = 2284 | dfile_count = 1 | dist_size = 48]
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue called
> [D 12/31 19:38] [SYNC_COALESCE]: enqueue 1 counter sync:1 non_sync:0
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue called
> [D 12/31 19:38] [SYNC_COALESCE]: dequeue 1 counter sync:0 non_sync:0
> [D 12/31 19:38] [DBPF THREAD]: STARTING TROVE SERVICE ROUTINE
> (DSPACE_SETATTR)
> [D 12/31 19:38] dbpf_cache_elem_lookup: cache elem matching 1048583
> returned (num_elems=4)
> [D 12/31 19:38] Updating cached attributes for key 1048583
> [D 12/31 19:38] [DBPF THREAD]: FINISHED TROVE SERVICE ROUTINE
> (DSPACE_SETATTR) (ret: 1)
> [D 12/31 19:38] [SYNC_COALESCE]: sync_coalesce called, handle: 1048583,
> cid: 0
> [D 12/31 19:38] [SYNC_COALESCE]: sync_context: 0x100c815c
> [D 12/31 19:38] [SYNC_COALESCE]: sync context type is DSPACE
> [D 12/31 19:38] [SYNC_COALESCE]: high or low watermark reached:
> coalesced: 0
> queued: 0
> [D 12/31 19:38] [SYNC_COALESCE]: syncing now!
> [D 12/31 19:38] [SYNC_COALESCE]: coalesce 1 sync start in
> coalesce_queue:0 pending:0
> [D 12/31 19:38] [SYNC_COALESCE]: coalesce 1 sync stop
> [D 12/31 19:38] [SYNC_COALESCE]: moving op: 0x1011dbb8, handle: 1048583
> , type: 133 to completion queue
> [D 12/31 19:38] op_queue add: 0x1011dbb8
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011ff98: create:
> create: new metadata handle: 1048583.
> [D 12/31 19:38] (s_op 0x1011ff98) create (FR sm) state: release:
> (error_code = 0)
> [D 12/31 19:38] (s_op 0x1011ff98) create (FR sm) state: send_resp
> (status = 0)
> [D 12/31 19:38] BMI_post_send_list: addr: 1372, count: 1, total_size:
> 40, tag: 4
> [D 12/31 19:38] element 0: offset: 0x1013f000, size: 40
> [D 12/31 19:38] tcp_post_send_generic: Sent: 40 bytes of data.
> [D 12/31 19:38] (s_op 0x1011ff98) create (FR sm) state: cleanup
> [A 12/31 19:38] root.root at n06.rcs.uncc.edu H=0 S=0x1011ff98: create:
> finish (Success)
> [D 12/31 19:38] server_state_machine_complete 0x1011fef8
> [D 12/31 19:38] tcp_do_work_recv: Reading header for new op.
> [D 12/31 19:38] tcp_do_work_recv: Received new message; mode: 2.
> [d 12/31 19:38] tcp_do_work_recv: tag: 5
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Pvfs2-users mailing list
> Pvfs2-users at beowulf-underground.org
> http://www.beowulf-underground.org/mailman/listinfo/pvfs2-users
More information about the Pvfs2-users
mailing list