Re: [Pvfs2-users] Some verbose logging from pvfs2-cp failure

Fri, 02 Oct 2009 06:44:00 -0700 

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] [email protected] H=0 S=0x1011cab8: getconfig: 
request
[A 12/31 19:38] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] 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] [email protected] H=0 S=0x1011ff98: create: request
[A 12/31 19:38] [email protected] 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] [email protected] 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] [email protected] 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
[email protected]
http://www.beowulf-underground.org/mailman/listinfo/pvfs2-users


_______________________________________________
Pvfs2-users mailing list
[email protected]
http://www.beowulf-underground.org/mailman/listinfo/pvfs2-users






















					Reply via email to