[Pvfs2-developers] Unexpected flow protocol error using unequally
distribution of data with MPI
Julian Martin Kunkel
Julian.Kunkel at web.de
Mon Mar 12 11:14:10 EST 2007
Hi,
here comes the output, I guess it could be a problem with an overflow of int
values.. I just send the interesting (last) parts of the output, because the
two files have a total of 50 MByte :-)
Best regards,
Julian
-------------- next part --------------
A non-text attachment was scrubbed...
Name: node1
Type: text/x-diff
Size: 72613 bytes
Desc: not available
Url : http://www.beowulf-underground.org/pipermail/pvfs2-developers/attachments/20070312/8308279c/node1-0001.bin
-------------- next part --------------
[D 17:02:13.511175] calling distribute
[D 17:02:13.511190] PINT_distribute
[D 17:02:13.511205] of 2142502912 sz 131072 ix 2 sm 64 by 131072 bm 262144 fsz 1071185920 exfl 1
[D 17:02:13.511225] begin iteration loff: 2142502912
[D 17:02:13.511242] frag extends beyond strip
[D 17:02:13.511258] file being extended
[D 17:02:13.511273] process a segment
[D 17:02:13.511288] of 1071251456 sz 65536
[D 17:02:13.511305] add a segment 2
[D 17:02:13.511321] end iteration
[D 17:02:13.511336] of 2142568448 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.511355] next loff: 2142633984 next poff: 1071316992
[D 17:02:13.511372] (return value) 131072
[D 17:02:13.511388] finished
[D 17:02:13.511404] retval = 131072
[D 17:02:13.511420] return from level 0
[D 17:02:13.511436] going to next block
[D 17:02:13.511451] going to next item in sequence chain
[D 17:02:13.511466] Do seq of 2142699520 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 4128768 co 0
[D 17:02:13.511486] lvl 0 el 0 blk 0 by 0
[D 17:02:13.511503] to 2162688 ta 0 fi 6291456
[D 17:02:13.511520] subtype is contiguous
[D 17:02:13.511536] Request disp
[D 17:02:13.511551] contig_offset = 2142699520 contig_size = 65536 lvl_flag = 0
[D 17:02:13.511569] calling distribute
[D 17:02:13.511585] PINT_distribute
[D 17:02:13.511600] of 2142699520 sz 65536 ix 3 sm 64 by 196608 bm 262144 fsz 1071316992 exfl 1
[D 17:02:13.511620] of 2142699520 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.511639] next loff: 2142765056 next poff: 1071382528
[D 17:02:13.511656] (return value) 65536
[D 17:02:13.511673] finished
[D 17:02:13.511688] retval = 65536
[D 17:02:13.511704] return from level 0
[D 17:02:13.511720] going to next block
[D 17:02:13.511735] going to next item in sequence chain
[D 17:02:13.511751] Do seq of 2142765056 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 4063232 co 0
[D 17:02:13.511770] lvl 0 el 0 blk 0 by 0
[D 17:02:13.511787] to 2228224 ta 0 fi 6291456
[D 17:02:13.511805] subtype is contiguous
[D 17:02:13.511821] Request disp
[D 17:02:13.511836] contig_offset = 2142765056 contig_size = 131072 lvl_flag = 0
[D 17:02:13.511854] calling distribute
[D 17:02:13.511869] PINT_distribute
[D 17:02:13.511884] of 2142765056 sz 131072 ix 3 sm 64 by 196608 bm 262144 fsz 1071316992 exfl 1
[D 17:02:13.511904] begin iteration loff: 2142765056
[D 17:02:13.511952] frag extends beyond strip
[D 17:02:13.511969] file being extended
[D 17:02:13.511984] process a segment
[D 17:02:13.512000] of 1071382528 sz 65536
[D 17:02:13.512016] add a segment 3
[D 17:02:13.512032] end iteration
[D 17:02:13.512047] done with segments or bytes
[D 17:02:13.512063] of 2142830592 sz 65536 sg 4 sm 64 by 262144 bm 262144
[D 17:02:13.512082] next loff: 2142896128 next poff: 1071448064
[D 17:02:13.512099] (return value) 131072
[D 17:02:13.512116] finished
[D 17:02:13.512131] retval = 131072
[D 17:02:13.512147] return from level 0
[D 17:02:13.512163] going to next block
[D 17:02:13.512178] going to next item in sequence chain
[D 17:02:13.512194] ran out of segments or bytes
[D 17:02:13.512209] done sg 4 sm 64 by 262144 bm 262144 ta 0 to 2359296 fo 6291456 eof 0
[D 17:02:13.512228] =========================================================
[D 17:02:13.512246] BMI_post_recv: addr: 73, offset: 0xa4b30008, size: 262144, tag: 536
[D 17:02:13.512290] flowproto-multiqueue trove_write_callback_fn, error_code: 0, flow: 0x813e298.
[D 17:02:13.512318] tcp_do_work_recv: Reading header for new op.
[D 17:02:13.512349] tcp_do_work_recv: Received new message; mode: 8.
[D 17:02:13.512366] tcp_do_work_recv: tag: 536
[D 17:02:13.512912] actual_size=262144, amt_complete=135640, old_amt_complete=130424
[D 17:02:13.514162] actual_size=262144, amt_complete=139984, old_amt_complete=135640
[D 17:02:13.514458] actual_size=262144, amt_complete=161704, old_amt_complete=139984
[D 17:02:13.514690] actual_size=262144, amt_complete=187768, old_amt_complete=161704
[D 17:02:13.514826] actual_size=262144, amt_complete=199928, old_amt_complete=187768
[D 17:02:13.514967] actual_size=262144, amt_complete=215856, old_amt_complete=199928
[D 17:02:13.515202] actual_size=262144, amt_complete=246264, old_amt_complete=215856
[D 17:02:13.515316] actual_size=262144, amt_complete=262144, old_amt_complete=246264
[D 17:02:13.515342] BMI_testcontext completing: 4251
[D 17:02:13.515370] flowproto-multiqueue bmi_recv_callback_fn, error code: 0, flow: 0x813e298.
[D 17:02:13.515391] get_data_sync_mode returning 0
[D 17:02:13.515416] dbpf_bstream_rw_list: mem_count: 1, stream_count: 4
[D 17:02:13.515435] dbpf_bstream_rw_list: mem_offset: 0xa4b30008, mem_size: 262144
[D 17:02:13.515453] dbpf_bstream_rw_list: stream_offset: 1070989312, stream_size: 65536
[D 17:02:13.515470] dbpf_bstream_rw_list: stream_offset: 1071120384, stream_size: 65536
[D 17:02:13.515494] dbpf_bstream_rw_list: stream_offset: 1071251456, stream_size: 65536
[D 17:02:13.515512] dbpf_bstream_rw_list: stream_offset: 1071382528, stream_size: 65536
[D 17:02:13.515530] dbpf_open_cache_get: called
[D 17:02:13.515547] dbpf_open_cache_get: found bstream entry in unused list.
[D 17:02:13.515564] dbpf_open_cache_get: moving to (or reordering in) used list.
[D 17:02:13.515600] DBPF I/O ops in progress: 1
[D 17:02:13.515617] lio_listio called with the following aiocbs:
[D 17:02:13.515634] aiocb_ptr_array[0]: fd: 19, off: 1070989312, bytes: 65536, buf: 0xa4b30008, type: 1
[D 17:02:13.515653] aiocb_ptr_array[1]: fd: 19, off: 1071120384, bytes: 65536, buf: 0xa4b40008, type: 1
[D 17:02:13.515671] aiocb_ptr_array[2]: fd: 19, off: 1071251456, bytes: 65536, buf: 0xa4b50008, type: 1
[D 17:02:13.515690] aiocb_ptr_array[3]: fd: 19, off: 1071382528, bytes: 65536, buf: 0xa4b60008, type: 1
[D 17:02:13.515725] issue_or_delay_io_operation: lio_listio posted 0xa4201e18 (handle 2863311532, ret 0)
[D 17:02:13.515778] =========================================================
[D 17:02:13.515799] PINT_process_request
[D 17:02:13.515819] tiling 2 copies
[D 17:02:13.515838] Do seq of 2142961664 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 3932160 co 0
[D 17:02:13.515861] lvl 0 el 0 blk 0 by 0
[D 17:02:13.515882] to 2359296 ta 0 fi 6291456
[D 17:02:13.515902] subtype is contiguous
[D 17:02:13.515921] Request disp
[D 17:02:13.515938] contig_offset = 2142961664 contig_size = 65536 lvl_flag = 0
[D 17:02:13.515961] calling distribute
[D 17:02:13.516026] PINT_distribute
[D 17:02:13.516046] of 2142961664 sz 65536 ix 0 sm 64 by 0 bm 262144 fsz 1071448064 exfl 1
[D 17:02:13.516071] of 2142961664 sz 65536 sg 0 sm 64 by 0 bm 262144
[D 17:02:13.516092] next loff: 2143027200 next poff: 1071513600
[D 17:02:13.516112] (return value) 65536
[D 17:02:13.516131] finished
[D 17:02:13.516150] retval = 65536
[D 17:02:13.516167] return from level 0
[D 17:02:13.516185] going to next block
[D 17:02:13.516203] going to next item in sequence chain
[D 17:02:13.516222] Do seq of 2143027200 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 3866624 co 0
[D 17:02:13.516273] lvl 0 el 0 blk 0 by 0
[D 17:02:13.516293] to 2424832 ta 0 fi 6291456
[D 17:02:13.516310] subtype is contiguous
[D 17:02:13.516328] Request disp
[D 17:02:13.516345] contig_offset = 2143027200 contig_size = 131072 lvl_flag = 0
[D 17:02:13.516365] calling distribute
[D 17:02:13.516383] PINT_distribute
[D 17:02:13.516401] of 2143027200 sz 131072 ix 0 sm 64 by 0 bm 262144 fsz 1071448064 exfl 1
[D 17:02:13.516424] begin iteration loff: 2143027200
[D 17:02:13.516443] frag extends beyond strip
[D 17:02:13.516461] file being extended
[D 17:02:13.516555] process a segment
[D 17:02:13.516574] of 1071513600 sz 65536
[D 17:02:13.516593] add a segment 0
[D 17:02:13.516658] end iteration
[D 17:02:13.516677] of 2143092736 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.516698] next loff: 2143158272 next poff: 1071579136
[D 17:02:13.516720] (return value) 131072
[D 17:02:13.516806] finished
[D 17:02:13.516824] retval = 131072
[D 17:02:13.516843] return from level 0
[D 17:02:13.516911] going to next block
[D 17:02:13.516930] going to next item in sequence chain
[D 17:02:13.516948] Do seq of 2143223808 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 3735552 co 0
[D 17:02:13.516972] lvl 0 el 0 blk 0 by 0
[D 17:02:13.517051] to 2555904 ta 0 fi 6291456
[D 17:02:13.517071] subtype is contiguous
[D 17:02:13.517089] Request disp
[D 17:02:13.517167] contig_offset = 2143223808 contig_size = 65536 lvl_flag = 0
[D 17:02:13.517189] calling distribute
[D 17:02:13.517208] PINT_distribute
[D 17:02:13.517225] of 2143223808 sz 65536 ix 1 sm 64 by 65536 bm 262144 fsz 1071579136 exfl 1
[D 17:02:13.517301] of 2143223808 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.517323] next loff: 2143289344 next poff: 1071644672
[D 17:02:13.517345] (return value) 65536
[D 17:02:13.517412] finished
[D 17:02:13.517429] retval = 65536
[D 17:02:13.517448] return from level 0
[D 17:02:13.517465] going to next block
[D 17:02:13.517489] going to next item in sequence chain
[D 17:02:13.517508] Do seq of 2143289344 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 3670016 co 0
[D 17:02:13.517531] lvl 0 el 0 blk 0 by 0
[D 17:02:13.517549] to 2621440 ta 0 fi 6291456
[D 17:02:13.517567] subtype is contiguous
[D 17:02:13.517583] Request disp
[D 17:02:13.517599] contig_offset = 2143289344 contig_size = 131072 lvl_flag = 0
[D 17:02:13.517597] --- aio_progress_notification called with handle 2863311532 (0xa4201e18)
[D 17:02:13.517634] calling distribute
[D 17:02:13.517661] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.517680] PINT_distribute
[D 17:02:13.517700] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.517718] of 2143289344 sz 131072 ix 1 sm 64 by 65536 bm 262144 fsz 1071579136 exfl 1
[D 17:02:13.517738] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.517757] begin iteration loff: 2143289344
[D 17:02:13.517775] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.517794] frag extends beyond strip
[D 17:02:13.517821] dbpf_open_cache_put: cached entry.
[D 17:02:13.517844] dbpf_open_cache_put: move to unused list.
[D 17:02:13.517849] file being extended
[D 17:02:13.517866] *** starting delayed ops if any (state is LIST_PROC_ALLPOSTED)
[D 17:02:13.517883] process a segment
[D 17:02:13.517902] op_queue add: 0xa4201e18
[D 17:02:13.517949] of 1071644672 sz 65536
[D 17:02:13.517987] add a segment 1
[D 17:02:13.518001] DBPF I/O ops in progress: 0
[D 17:02:13.518003] end iteration
[D 17:02:13.518045] of 2143354880 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.518064] next loff: 2143420416 next poff: 1071710208
[D 17:02:13.518081] (return value) 131072
[D 17:02:13.518098] finished
[D 17:02:13.518113] retval = 131072
[D 17:02:13.518129] return from level 0
[D 17:02:13.518145] going to next block
[D 17:02:13.518161] going to next item in sequence chain
[D 17:02:13.518176] Do seq of 2143485952 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 3538944 co 0
[D 17:02:13.518196] lvl 0 el 0 blk 0 by 0
[D 17:02:13.518213] to 2752512 ta 0 fi 6291456
[D 17:02:13.518231] subtype is contiguous
[D 17:02:13.519610] Request disp
[D 17:02:13.519629] contig_offset = 2143485952 contig_size = 65536 lvl_flag = 0
[D 17:02:13.519648] calling distribute
[D 17:02:13.519664] PINT_distribute
[D 17:02:13.519680] of 2143485952 sz 65536 ix 2 sm 64 by 131072 bm 262144 fsz 1071710208 exfl 1
[D 17:02:13.519702] of 2143485952 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.519722] next loff: 2143551488 next poff: 1071775744
[D 17:02:13.519740] (return value) 65536
[D 17:02:13.519757] finished
[D 17:02:13.519772] retval = 65536
[D 17:02:13.519789] return from level 0
[D 17:02:13.519805] going to next block
[D 17:02:13.519820] going to next item in sequence chain
[D 17:02:13.519836] Do seq of 2143551488 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 3473408 co 0
[D 17:02:13.519857] lvl 0 el 0 blk 0 by 0
[D 17:02:13.519874] to 2818048 ta 0 fi 6291456
[D 17:02:13.519892] subtype is contiguous
[D 17:02:13.519908] Request disp
[D 17:02:13.519923] contig_offset = 2143551488 contig_size = 131072 lvl_flag = 0
[D 17:02:13.519941] calling distribute
[D 17:02:13.519957] PINT_distribute
[D 17:02:13.519972] of 2143551488 sz 131072 ix 2 sm 64 by 131072 bm 262144 fsz 1071710208 exfl 1
[D 17:02:13.519992] begin iteration loff: 2143551488
[D 17:02:13.520009] frag extends beyond strip
[D 17:02:13.520025] file being extended
[D 17:02:13.520040] process a segment
[D 17:02:13.520056] of 1071775744 sz 65536
[D 17:02:13.520073] add a segment 2
[D 17:02:13.520089] end iteration
[D 17:02:13.520104] of 2143617024 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.520123] next loff: 2143682560 next poff: 1071841280
[D 17:02:13.520140] (return value) 131072
[D 17:02:13.520157] finished
[D 17:02:13.520172] retval = 131072
[D 17:02:13.520188] return from level 0
[D 17:02:13.520204] going to next block
[D 17:02:13.520219] going to next item in sequence chain
[D 17:02:13.520235] Do seq of 2143748096 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 3342336 co 0
[D 17:02:13.520255] lvl 0 el 0 blk 0 by 0
[D 17:02:13.520272] to 2949120 ta 0 fi 6291456
[D 17:02:13.520289] subtype is contiguous
[D 17:02:13.520305] Request disp
[D 17:02:13.520320] contig_offset = 2143748096 contig_size = 65536 lvl_flag = 0
[D 17:02:13.520338] calling distribute
[D 17:02:13.520353] PINT_distribute
[D 17:02:13.520369] of 2143748096 sz 65536 ix 3 sm 64 by 196608 bm 262144 fsz 1071841280 exfl 1
[D 17:02:13.520389] of 2143748096 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.520408] next loff: 2143813632 next poff: 1071906816
[D 17:02:13.520425] (return value) 65536
[D 17:02:13.520442] finished
[D 17:02:13.520457] retval = 65536
[D 17:02:13.520473] return from level 0
[D 17:02:13.520489] going to next block
[D 17:02:13.520505] going to next item in sequence chain
[D 17:02:13.520520] Do seq of 2143813632 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 3276800 co 0
[D 17:02:13.520540] lvl 0 el 0 blk 0 by 0
[D 17:02:13.520557] to 3014656 ta 0 fi 6291456
[D 17:02:13.520575] subtype is contiguous
[D 17:02:13.520590] Request disp
[D 17:02:13.520606] contig_offset = 2143813632 contig_size = 131072 lvl_flag = 0
[D 17:02:13.520624] calling distribute
[D 17:02:13.520678] PINT_distribute
[D 17:02:13.520695] of 2143813632 sz 131072 ix 3 sm 64 by 196608 bm 262144 fsz 1071841280 exfl 1
[D 17:02:13.520715] begin iteration loff: 2143813632
[D 17:02:13.520732] frag extends beyond strip
[D 17:02:13.520747] file being extended
[D 17:02:13.520763] process a segment
[D 17:02:13.520779] of 1071906816 sz 65536
[D 17:02:13.520795] add a segment 3
[D 17:02:13.520811] end iteration
[D 17:02:13.520827] done with segments or bytes
[D 17:02:13.520842] of 2143879168 sz 65536 sg 4 sm 64 by 262144 bm 262144
[D 17:02:13.520861] next loff: 2143944704 next poff: 1071972352
[D 17:02:13.520878] (return value) 131072
[D 17:02:13.520895] finished
[D 17:02:13.520910] retval = 131072
[D 17:02:13.520926] return from level 0
[D 17:02:13.520942] going to next block
[D 17:02:13.520958] going to next item in sequence chain
[D 17:02:13.520974] ran out of segments or bytes
[D 17:02:13.520989] done sg 4 sm 64 by 262144 bm 262144 ta 0 to 3145728 fo 6291456 eof 0
[D 17:02:13.521008] =========================================================
[D 17:02:13.521027] BMI_post_recv: addr: 73, offset: 0xa41bf008, size: 262144, tag: 536
[D 17:02:13.521076] flowproto-multiqueue trove_write_callback_fn, error_code: 0, flow: 0x813e298.
[D 17:02:13.521117] tcp_do_work_recv: Reading header for new op.
[D 17:02:13.521149] tcp_do_work_recv: Received new message; mode: 8.
[D 17:02:13.521166] tcp_do_work_recv: tag: 536
[D 17:02:13.521714] actual_size=262144, amt_complete=133240, old_amt_complete=129392
[D 17:02:13.522048] actual_size=262144, amt_complete=154960, old_amt_complete=133240
[D 17:02:13.522179] actual_size=262144, amt_complete=165096, old_amt_complete=154960
[D 17:02:13.522338] actual_size=262144, amt_complete=181024, old_amt_complete=165096
[D 17:02:13.522569] actual_size=262144, amt_complete=210480, old_amt_complete=181024
[D 17:02:13.522811] actual_size=262144, amt_complete=240888, old_amt_complete=210480
[D 17:02:13.522949] actual_size=262144, amt_complete=252472, old_amt_complete=240888
[D 17:02:13.523072] actual_size=262144, amt_complete=262144, old_amt_complete=252472
[D 17:02:13.523098] BMI_testcontext completing: 4252
[D 17:02:13.523176] flowproto-multiqueue bmi_recv_callback_fn, error code: 0, flow: 0x813e298.
[D 17:02:13.523198] get_data_sync_mode returning 0
[D 17:02:13.523266] dbpf_bstream_rw_list: mem_count: 1, stream_count: 4
[D 17:02:13.523286] dbpf_bstream_rw_list: mem_offset: 0xa41bf008, mem_size: 262144
[D 17:02:13.523304] dbpf_bstream_rw_list: stream_offset: 1071513600, stream_size: 65536
[D 17:02:13.523322] dbpf_bstream_rw_list: stream_offset: 1071644672, stream_size: 65536
[D 17:02:13.523340] dbpf_bstream_rw_list: stream_offset: 1071775744, stream_size: 65536
[D 17:02:13.523405] dbpf_bstream_rw_list: stream_offset: 1071906816, stream_size: 65536
[D 17:02:13.523424] dbpf_open_cache_get: called
[D 17:02:13.523442] dbpf_open_cache_get: found bstream entry in unused list.
[D 17:02:13.523460] dbpf_open_cache_get: moving to (or reordering in) used list.
[D 17:02:13.523549] DBPF I/O ops in progress: 1
[D 17:02:13.523567] lio_listio called with the following aiocbs:
[D 17:02:13.523584] aiocb_ptr_array[0]: fd: 19, off: 1071513600, bytes: 65536, buf: 0xa41bf008, type: 1
[D 17:02:13.523662] aiocb_ptr_array[1]: fd: 19, off: 1071644672, bytes: 65536, buf: 0xa41cf008, type: 1
[D 17:02:13.523683] aiocb_ptr_array[2]: fd: 19, off: 1071775744, bytes: 65536, buf: 0xa41df008, type: 1
[D 17:02:13.523702] aiocb_ptr_array[3]: fd: 19, off: 1071906816, bytes: 65536, buf: 0xa41ef008, type: 1
[D 17:02:13.523785] issue_or_delay_io_operation: lio_listio posted 0xa4201e18 (handle 2863311532, ret 0)
[D 17:02:13.523844] =========================================================
[D 17:02:13.523887] PINT_process_request
[D 17:02:13.523908] tiling 2 copies
[D 17:02:13.523925] Do seq of 2144010240 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 3145728 co 0
[D 17:02:13.523947] lvl 0 el 0 blk 0 by 0
[D 17:02:13.523964] to 3145728 ta 0 fi 6291456
[D 17:02:13.523985] subtype is contiguous
[D 17:02:13.524059] Request disp
[D 17:02:13.524079] contig_offset = 2144010240 contig_size = 65536 lvl_flag = 0
[D 17:02:13.524100] calling distribute
[D 17:02:13.524118] PINT_distribute
[D 17:02:13.524138] of 2144010240 sz 65536 ix 0 sm 64 by 0 bm 262144 fsz 1071972352 exfl 1
[D 17:02:13.524164] of 2144010240 sz 65536 sg 0 sm 64 by 0 bm 262144
[D 17:02:13.524187] next loff: 2144075776 next poff: 1072037888
[D 17:02:13.524207] (return value) 65536
[D 17:02:13.524226] finished
[D 17:02:13.524244] retval = 65536
[D 17:02:13.524263] return from level 0
[D 17:02:13.524280] going to next block
[D 17:02:13.524298] going to next item in sequence chain
[D 17:02:13.524317] Do seq of 2144075776 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 3080192 co 0
[D 17:02:13.524339] lvl 0 el 0 blk 0 by 0
[D 17:02:13.524358] to 3211264 ta 0 fi 6291456
[D 17:02:13.524379] subtype is contiguous
[D 17:02:13.524396] Request disp
[D 17:02:13.524415] contig_offset = 2144075776 contig_size = 131072 lvl_flag = 0
[D 17:02:13.524437] calling distribute
[D 17:02:13.524454] PINT_distribute
[D 17:02:13.524471] of 2144075776 sz 131072 ix 0 sm 64 by 0 bm 262144 fsz 1071972352 exfl 1
[D 17:02:13.524493] begin iteration loff: 2144075776
[D 17:02:13.524513] frag extends beyond strip
[D 17:02:13.524531] file being extended
[D 17:02:13.524549] process a segment
[D 17:02:13.524566] of 1072037888 sz 65536
[D 17:02:13.524586] add a segment 0
[D 17:02:13.524604] end iteration
[D 17:02:13.524621] of 2144141312 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.524642] next loff: 2144206848 next poff: 1072103424
[D 17:02:13.524661] (return value) 131072
[D 17:02:13.524680] finished
[D 17:02:13.524698] retval = 131072
[D 17:02:13.524717] return from level 0
[D 17:02:13.524736] going to next block
[D 17:02:13.524754] going to next item in sequence chain
[D 17:02:13.524770] Do seq of 2144272384 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 2949120 co 0
[D 17:02:13.524791] lvl 0 el 0 blk 0 by 0
[D 17:02:13.524810] to 3342336 ta 0 fi 6291456
[D 17:02:13.524830] subtype is contiguous
[D 17:02:13.524848] Request disp
[D 17:02:13.524864] contig_offset = 2144272384 contig_size = 65536 lvl_flag = 0
[D 17:02:13.524885] calling distribute
[D 17:02:13.524902] PINT_distribute
[D 17:02:13.524919] of 2144272384 sz 65536 ix 1 sm 64 by 65536 bm 262144 fsz 1072103424 exfl 1
[D 17:02:13.524941] of 2144272384 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.524963] next loff: 2144337920 next poff: 1072168960
[D 17:02:13.525056] (return value) 65536
[D 17:02:13.525075] finished
[D 17:02:13.525093] retval = 65536
[D 17:02:13.525129] return from level 0
[D 17:02:13.525149] going to next block
[D 17:02:13.525166] going to next item in sequence chain
[D 17:02:13.525184] Do seq of 2144337920 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 2883584 co 0
[D 17:02:13.525205] lvl 0 el 0 blk 0 by 0
[D 17:02:13.525223] to 3407872 ta 0 fi 6291456
[D 17:02:13.525242] subtype is contiguous
[D 17:02:13.525259] Request disp
[D 17:02:13.525276] contig_offset = 2144337920 contig_size = 131072 lvl_flag = 0
[D 17:02:13.525296] calling distribute
[D 17:02:13.525313] PINT_distribute
[D 17:02:13.525331] of 2144337920 sz 131072 ix 1 sm 64 by 65536 bm 262144 fsz 1072103424 exfl 1
[D 17:02:13.525353] begin iteration loff: 2144337920
[D 17:02:13.525371] frag extends beyond strip
[D 17:02:13.525388] file being extended
[D 17:02:13.525406] process a segment
[D 17:02:13.525424] of 1072168960 sz 65536
[D 17:02:13.525445] add a segment 1
[D 17:02:13.525463] end iteration
[D 17:02:13.525481] of 2144403456 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.525504] next loff: 2144468992 next poff: 1072234496
[D 17:02:13.525523] (return value) 131072
[D 17:02:13.525542] finished
[D 17:02:13.525560] retval = 131072
[D 17:02:13.525577] return from level 0
[D 17:02:13.525595] going to next block
[D 17:02:13.525615] going to next item in sequence chain
[D 17:02:13.525662] Do seq of 2144534528 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 2752512 co 0
[D 17:02:13.525679] --- aio_progress_notification called with handle 2863311532 (0xa4201e18)
[D 17:02:13.525683] lvl 0 el 0 blk 0 by 0
[D 17:02:13.525723] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.525743] to 3538944 ta 0 fi 6291456
[D 17:02:13.525763] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.525781] subtype is contiguous
[D 17:02:13.525800] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.525818] Request disp
[D 17:02:13.525837] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.525855] contig_offset = 2144534528 contig_size = 65536 lvl_flag = 0
[D 17:02:13.525882] dbpf_open_cache_put: cached entry.
[D 17:02:13.525893] calling distribute
[D 17:02:13.525908] dbpf_open_cache_put: move to unused list.
[D 17:02:13.525926] PINT_distribute
[D 17:02:13.525944] *** starting delayed ops if any (state is LIST_PROC_ALLPOSTED)
[D 17:02:13.525962] of 2144534528 sz 65536 ix 2 sm 64 by 131072 bm 262144 fsz 1072234496 exfl 1
[D 17:02:13.525981] op_queue add: 0xa4201e18
[D 17:02:13.526000] of 2144534528 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.526036] next loff: 2144600064 next poff: 1072300032
[D 17:02:13.526048] DBPF I/O ops in progress: 0
[D 17:02:13.526054] (return value) 65536
[D 17:02:13.526090] finished
[D 17:02:13.526106] retval = 65536
[D 17:02:13.526122] return from level 0
[D 17:02:13.526137] going to next block
[D 17:02:13.526153] going to next item in sequence chain
[D 17:02:13.526169] Do seq of 2144600064 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 2686976 co 0
[D 17:02:13.526188] lvl 0 el 0 blk 0 by 0
[D 17:02:13.526205] to 3604480 ta 0 fi 6291456
[D 17:02:13.526223] subtype is contiguous
[D 17:02:13.526290] Request disp
[D 17:02:13.526307] contig_offset = 2144600064 contig_size = 131072 lvl_flag = 0
[D 17:02:13.526325] calling distribute
[D 17:02:13.526341] PINT_distribute
[D 17:02:13.526356] of 2144600064 sz 131072 ix 2 sm 64 by 131072 bm 262144 fsz 1072234496 exfl 1
[D 17:02:13.526376] begin iteration loff: 2144600064
[D 17:02:13.526393] frag extends beyond strip
[D 17:02:13.526409] file being extended
[D 17:02:13.526424] process a segment
[D 17:02:13.526440] of 1072300032 sz 65536
[D 17:02:13.526457] add a segment 2
[D 17:02:13.526473] end iteration
[D 17:02:13.526488] of 2144665600 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.526507] next loff: 2144731136 next poff: 1072365568
[D 17:02:13.526524] (return value) 131072
[D 17:02:13.526541] finished
[D 17:02:13.526556] retval = 131072
[D 17:02:13.526572] return from level 0
[D 17:02:13.526597] going to next block
[D 17:02:13.526612] going to next item in sequence chain
[D 17:02:13.526628] Do seq of 2144796672 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 2555904 co 0
[D 17:02:13.526648] lvl 0 el 0 blk 0 by 0
[D 17:02:13.526665] to 3735552 ta 0 fi 6291456
[D 17:02:13.526682] subtype is contiguous
[D 17:02:13.526698] Request disp
[D 17:02:13.526713] contig_offset = 2144796672 contig_size = 65536 lvl_flag = 0
[D 17:02:13.526731] calling distribute
[D 17:02:13.526746] PINT_distribute
[D 17:02:13.526762] of 2144796672 sz 65536 ix 3 sm 64 by 196608 bm 262144 fsz 1072365568 exfl 1
[D 17:02:13.526782] of 2144796672 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.526801] next loff: 2144862208 next poff: 1072431104
[D 17:02:13.526818] (return value) 65536
[D 17:02:13.526834] finished
[D 17:02:13.526850] retval = 65536
[D 17:02:13.526866] return from level 0
[D 17:02:13.526882] going to next block
[D 17:02:13.526897] going to next item in sequence chain
[D 17:02:13.526912] Do seq of 2144862208 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 2490368 co 0
[D 17:02:13.526932] lvl 0 el 0 blk 0 by 0
[D 17:02:13.526949] to 3801088 ta 0 fi 6291456
[D 17:02:13.526993] subtype is contiguous
[D 17:02:13.527009] Request disp
[D 17:02:13.527025] contig_offset = 2144862208 contig_size = 131072 lvl_flag = 0
[D 17:02:13.527043] calling distribute
[D 17:02:13.527058] PINT_distribute
[D 17:02:13.527074] of 2144862208 sz 131072 ix 3 sm 64 by 196608 bm 262144 fsz 1072365568 exfl 1
[D 17:02:13.527093] begin iteration loff: 2144862208
[D 17:02:13.527110] frag extends beyond strip
[D 17:02:13.527126] file being extended
[D 17:02:13.527142] process a segment
[D 17:02:13.527157] of 1072431104 sz 65536
[D 17:02:13.527174] add a segment 3
[D 17:02:13.527190] end iteration
[D 17:02:13.527205] done with segments or bytes
[D 17:02:13.527220] of 2144927744 sz 65536 sg 4 sm 64 by 262144 bm 262144
[D 17:02:13.527239] next loff: 2144993280 next poff: 1072496640
[D 17:02:13.527256] (return value) 131072
[D 17:02:13.527273] finished
[D 17:02:13.527288] retval = 131072
[D 17:02:13.527304] return from level 0
[D 17:02:13.527320] going to next block
[D 17:02:13.527335] going to next item in sequence chain
[D 17:02:13.527351] ran out of segments or bytes
[D 17:02:13.527366] done sg 4 sm 64 by 262144 bm 262144 ta 0 to 3932160 fo 6291456 eof 0
[D 17:02:13.527385] =========================================================
[D 17:02:13.527403] BMI_post_recv: addr: 73, offset: 0xa397e008, size: 262144, tag: 536
[D 17:02:13.527446] flowproto-multiqueue trove_write_callback_fn, error_code: 0, flow: 0x813e298.
[D 17:02:13.527472] tcp_do_work_recv: Reading header for new op.
[D 17:02:13.527503] tcp_do_work_recv: Received new message; mode: 8.
[D 17:02:13.527521] tcp_do_work_recv: tag: 536
[D 17:02:13.528041] actual_size=262144, amt_complete=134384, old_amt_complete=130848
[D 17:02:13.528399] actual_size=262144, amt_complete=150312, old_amt_complete=134384
[D 17:02:13.528527] actual_size=262144, amt_complete=161896, old_amt_complete=150312
[D 17:02:13.528667] actual_size=262144, amt_complete=176376, old_amt_complete=161896
[D 17:02:13.528797] actual_size=262144, amt_complete=191576, old_amt_complete=176376
[D 17:02:13.528942] actual_size=262144, amt_complete=206056, old_amt_complete=191576
[D 17:02:13.529075] actual_size=262144, amt_complete=221984, old_amt_complete=206056
[D 17:02:13.529302] actual_size=262144, amt_complete=250944, old_amt_complete=221984
[D 17:02:13.529424] actual_size=262144, amt_complete=262144, old_amt_complete=250944
[D 17:02:13.529451] BMI_testcontext completing: 4253
[D 17:02:13.529485] flowproto-multiqueue bmi_recv_callback_fn, error code: 0, flow: 0x813e298.
[D 17:02:13.529506] get_data_sync_mode returning 0
[D 17:02:13.529533] dbpf_bstream_rw_list: mem_count: 1, stream_count: 4
[D 17:02:13.529552] dbpf_bstream_rw_list: mem_offset: 0xa397e008, mem_size: 262144
[D 17:02:13.529570] dbpf_bstream_rw_list: stream_offset: 1072037888, stream_size: 65536
[D 17:02:13.529587] dbpf_bstream_rw_list: stream_offset: 1072168960, stream_size: 65536
[D 17:02:13.529611] dbpf_bstream_rw_list: stream_offset: 1072300032, stream_size: 65536
[D 17:02:13.529630] dbpf_bstream_rw_list: stream_offset: 1072431104, stream_size: 65536
[D 17:02:13.529647] dbpf_open_cache_get: called
[D 17:02:13.529664] dbpf_open_cache_get: found bstream entry in unused list.
[D 17:02:13.529682] dbpf_open_cache_get: moving to (or reordering in) used list.
[D 17:02:13.529720] DBPF I/O ops in progress: 1
[D 17:02:13.529737] lio_listio called with the following aiocbs:
[D 17:02:13.529754] aiocb_ptr_array[0]: fd: 19, off: 1072037888, bytes: 65536, buf: 0xa397e008, type: 1
[D 17:02:13.529773] aiocb_ptr_array[1]: fd: 19, off: 1072168960, bytes: 65536, buf: 0xa398e008, type: 1
[D 17:02:13.529791] aiocb_ptr_array[2]: fd: 19, off: 1072300032, bytes: 65536, buf: 0xa399e008, type: 1
[D 17:02:13.529809] aiocb_ptr_array[3]: fd: 19, off: 1072431104, bytes: 65536, buf: 0xa39ae008, type: 1
[D 17:02:13.529846] issue_or_delay_io_operation: lio_listio posted 0xa4201e18 (handle 2863311532, ret 0)
[D 17:02:13.529891] =========================================================
[D 17:02:13.529912] PINT_process_request
[D 17:02:13.529983] tiling 2 copies
[D 17:02:13.530003] Do seq of 2145058816 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 2359296 co 0
[D 17:02:13.530027] lvl 0 el 0 blk 0 by 0
[D 17:02:13.530047] to 3932160 ta 0 fi 6291456
[D 17:02:13.530068] subtype is contiguous
[D 17:02:13.530087] Request disp
[D 17:02:13.530105] contig_offset = 2145058816 contig_size = 65536 lvl_flag = 0
[D 17:02:13.530127] calling distribute
[D 17:02:13.530145] PINT_distribute
[D 17:02:13.530163] of 2145058816 sz 65536 ix 0 sm 64 by 0 bm 262144 fsz 1072496640 exfl 1
[D 17:02:13.530187] of 2145058816 sz 65536 sg 0 sm 64 by 0 bm 262144
[D 17:02:13.530211] next loff: 2145124352 next poff: 1072562176
[D 17:02:13.530230] (return value) 65536
[D 17:02:13.530286] finished
[D 17:02:13.530304] retval = 65536
[D 17:02:13.530321] return from level 0
[D 17:02:13.530339] going to next block
[D 17:02:13.530356] going to next item in sequence chain
[D 17:02:13.530376] Do seq of 2145124352 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 2293760 co 0
[D 17:02:13.530399] lvl 0 el 0 blk 0 by 0
[D 17:02:13.530417] to 3997696 ta 0 fi 6291456
[D 17:02:13.530437] subtype is contiguous
[D 17:02:13.530456] Request disp
[D 17:02:13.530472] contig_offset = 2145124352 contig_size = 131072 lvl_flag = 0
[D 17:02:13.530492] calling distribute
[D 17:02:13.530509] PINT_distribute
[D 17:02:13.530526] of 2145124352 sz 131072 ix 0 sm 64 by 0 bm 262144 fsz 1072496640 exfl 1
[D 17:02:13.530549] begin iteration loff: 2145124352
[D 17:02:13.530568] frag extends beyond strip
[D 17:02:13.530672] file being extended
[D 17:02:13.530693] process a segment
[D 17:02:13.530710] of 1072562176 sz 65536
[D 17:02:13.530769] add a segment 0
[D 17:02:13.530787] end iteration
[D 17:02:13.530807] of 2145189888 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.530828] next loff: 2145255424 next poff: 1072627712
[D 17:02:13.530917] (return value) 131072
[D 17:02:13.530937] finished
[D 17:02:13.530956] retval = 131072
[D 17:02:13.531022] return from level 0
[D 17:02:13.531040] going to next block
[D 17:02:13.531058] going to next item in sequence chain
[D 17:02:13.531075] Do seq of 2145320960 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 2162688 co 0
[D 17:02:13.531148] lvl 0 el 0 blk 0 by 0
[D 17:02:13.531169] to 4128768 ta 0 fi 6291456
[D 17:02:13.531189] subtype is contiguous
[D 17:02:13.531207] Request disp
[D 17:02:13.531278] contig_offset = 2145320960 contig_size = 65536 lvl_flag = 0
[D 17:02:13.531300] calling distribute
[D 17:02:13.531319] PINT_distribute
[D 17:02:13.531336] of 2145320960 sz 65536 ix 1 sm 64 by 65536 bm 262144 fsz 1072627712 exfl 1
[D 17:02:13.531418] of 2145320960 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.531439] next loff: 2145386496 next poff: 1072693248
[D 17:02:13.531461] (return value) 65536
[D 17:02:13.531514] finished
[D 17:02:13.531532] retval = 65536
[D 17:02:13.531550] return from level 0
[D 17:02:13.531567] going to next block
[D 17:02:13.531585] going to next item in sequence chain
[D 17:02:13.531602] Do seq of 2145386496 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 2097152 co 0
[D 17:02:13.531625] lvl 0 el 0 blk 0 by 0
[D 17:02:13.531643] to 4194304 ta 0 fi 6291456
[D 17:02:13.531661] subtype is contiguous
[D 17:02:13.531677] Request disp
[D 17:02:13.531689] --- aio_progress_notification called with handle 2863311532 (0xa4201e18)
[D 17:02:13.531692] contig_offset = 2145386496 contig_size = 131072 lvl_flag = 0
[D 17:02:13.531733] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.531753] calling distribute
[D 17:02:13.531774] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.531791] PINT_distribute
[D 17:02:13.531811] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.531828] of 2145386496 sz 131072 ix 1 sm 64 by 65536 bm 262144 fsz 1072627712 exfl 1
[D 17:02:13.531847] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.531866] begin iteration loff: 2145386496
[D 17:02:13.531921] dbpf_open_cache_put: cached entry.
[D 17:02:13.531947] dbpf_open_cache_put: move to unused list.
[D 17:02:13.531953] frag extends beyond strip
[D 17:02:13.531968] *** starting delayed ops if any (state is LIST_PROC_ALLPOSTED)
[D 17:02:13.531986] file being extended
[D 17:02:13.532005] op_queue add: 0xa4201e18
[D 17:02:13.532023] process a segment
[D 17:02:13.532057] of 1072693248 sz 65536
[D 17:02:13.532072] DBPF I/O ops in progress: 0
[D 17:02:13.532074] add a segment 1
[D 17:02:13.532115] end iteration
[D 17:02:13.532131] of 2145452032 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.532151] next loff: 2145517568 next poff: 1072758784
[D 17:02:13.532168] (return value) 131072
[D 17:02:13.532185] finished
[D 17:02:13.532200] retval = 131072
[D 17:02:13.532216] return from level 0
[D 17:02:13.532232] going to next block
[D 17:02:13.532247] going to next item in sequence chain
[D 17:02:13.532263] Do seq of 2145583104 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 1966080 co 0
[D 17:02:13.532282] lvl 0 el 0 blk 0 by 0
[D 17:02:13.532299] to 4325376 ta 0 fi 6291456
[D 17:02:13.532317] subtype is contiguous
[D 17:02:13.532332] Request disp
[D 17:02:13.532348] contig_offset = 2145583104 contig_size = 65536 lvl_flag = 0
[D 17:02:13.532366] calling distribute
[D 17:02:13.532381] PINT_distribute
[D 17:02:13.532396] of 2145583104 sz 65536 ix 2 sm 64 by 131072 bm 262144 fsz 1072758784 exfl 1
[D 17:02:13.532416] of 2145583104 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.532436] next loff: 2145648640 next poff: 1072824320
[D 17:02:13.532453] (return value) 65536
[D 17:02:13.532469] finished
[D 17:02:13.532485] retval = 65536
[D 17:02:13.532501] return from level 0
[D 17:02:13.532517] going to next block
[D 17:02:13.532532] going to next item in sequence chain
[D 17:02:13.532547] Do seq of 2145648640 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 1900544 co 0
[D 17:02:13.532567] lvl 0 el 0 blk 0 by 0
[D 17:02:13.532584] to 4390912 ta 0 fi 6291456
[D 17:02:13.532601] subtype is contiguous
[D 17:02:13.532617] Request disp
[D 17:02:13.532632] contig_offset = 2145648640 contig_size = 131072 lvl_flag = 0
[D 17:02:13.532650] calling distribute
[D 17:02:13.532665] PINT_distribute
[D 17:02:13.532680] of 2145648640 sz 131072 ix 2 sm 64 by 131072 bm 262144 fsz 1072758784 exfl 1
[D 17:02:13.532700] begin iteration loff: 2145648640
[D 17:02:13.532717] frag extends beyond strip
[D 17:02:13.532733] file being extended
[D 17:02:13.532748] process a segment
[D 17:02:13.532763] of 1072824320 sz 65536
[D 17:02:13.532780] add a segment 2
[D 17:02:13.532796] end iteration
[D 17:02:13.532811] of 2145714176 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.532830] next loff: 2145779712 next poff: 1072889856
[D 17:02:13.532847] (return value) 131072
[D 17:02:13.532863] finished
[D 17:02:13.532879] retval = 131072
[D 17:02:13.532894] return from level 0
[D 17:02:13.532910] going to next block
[D 17:02:13.532925] going to next item in sequence chain
[D 17:02:13.532941] Do seq of 2145845248 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 1769472 co 0
[D 17:02:13.532960] lvl 0 el 0 blk 0 by 0
[D 17:02:13.532977] to 4521984 ta 0 fi 6291456
[D 17:02:13.532995] subtype is contiguous
[D 17:02:13.533010] Request disp
[D 17:02:13.533026] contig_offset = 2145845248 contig_size = 65536 lvl_flag = 0
[D 17:02:13.533043] calling distribute
[D 17:02:13.533059] PINT_distribute
[D 17:02:13.533074] of 2145845248 sz 65536 ix 3 sm 64 by 196608 bm 262144 fsz 1072889856 exfl 1
[D 17:02:13.533094] of 2145845248 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.533113] next loff: 2145910784 next poff: 1072955392
[D 17:02:13.533130] (return value) 65536
[D 17:02:13.533146] finished
[D 17:02:13.533162] retval = 65536
[D 17:02:13.533178] return from level 0
[D 17:02:13.533194] going to next block
[D 17:02:13.533241] going to next item in sequence chain
[D 17:02:13.533257] Do seq of 2145910784 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 1703936 co 0
[D 17:02:13.533277] lvl 0 el 0 blk 0 by 0
[D 17:02:13.533294] to 4587520 ta 0 fi 6291456
[D 17:02:13.533311] subtype is contiguous
[D 17:02:13.533327] Request disp
[D 17:02:13.533343] contig_offset = 2145910784 contig_size = 131072 lvl_flag = 0
[D 17:02:13.533361] calling distribute
[D 17:02:13.533377] PINT_distribute
[D 17:02:13.533392] of 2145910784 sz 131072 ix 3 sm 64 by 196608 bm 262144 fsz 1072889856 exfl 1
[D 17:02:13.533412] begin iteration loff: 2145910784
[D 17:02:13.533429] frag extends beyond strip
[D 17:02:13.533445] file being extended
[D 17:02:13.533460] process a segment
[D 17:02:13.533475] of 1072955392 sz 65536
[D 17:02:13.533492] add a segment 3
[D 17:02:13.533508] end iteration
[D 17:02:13.533523] done with segments or bytes
[D 17:02:13.533539] of 2145976320 sz 65536 sg 4 sm 64 by 262144 bm 262144
[D 17:02:13.533558] next loff: 2146041856 next poff: 1073020928
[D 17:02:13.533575] (return value) 131072
[D 17:02:13.533591] finished
[D 17:02:13.533607] retval = 131072
[D 17:02:13.533623] return from level 0
[D 17:02:13.533639] going to next block
[D 17:02:13.533654] going to next item in sequence chain
[D 17:02:13.533670] ran out of segments or bytes
[D 17:02:13.533685] done sg 4 sm 64 by 262144 bm 262144 ta 0 to 4718592 fo 6291456 eof 0
[D 17:02:13.533705] =========================================================
[D 17:02:13.533723] BMI_post_recv: addr: 73, offset: 0xa393d008, size: 262144, tag: 536
[D 17:02:13.533766] flowproto-multiqueue trove_write_callback_fn, error_code: 0, flow: 0x813e298.
[D 17:02:13.533790] tcp_do_work_recv: Reading header for new op.
[D 17:02:13.533823] tcp_do_work_recv: Received new message; mode: 8.
[D 17:02:13.533840] tcp_do_work_recv: tag: 536
[D 17:02:13.535295] actual_size=262144, amt_complete=149200, old_amt_complete=129504
[D 17:02:13.535559] actual_size=262144, amt_complete=176712, old_amt_complete=149200
[D 17:02:13.535788] actual_size=262144, amt_complete=205672, old_amt_complete=176712
[D 17:02:13.535920] actual_size=262144, amt_complete=218704, old_amt_complete=205672
[D 17:02:13.536051] actual_size=262144, amt_complete=233184, old_amt_complete=218704
[D 17:02:13.536175] actual_size=262144, amt_complete=249112, old_amt_complete=233184
[D 17:02:13.536254] actual_size=262144, amt_complete=259824, old_amt_complete=249112
[D 17:02:13.536437] actual_size=262144, amt_complete=262144, old_amt_complete=259824
[D 17:02:13.536463] BMI_testcontext completing: 4254
[D 17:02:13.536529] flowproto-multiqueue bmi_recv_callback_fn, error code: 0, flow: 0x813e298.
[D 17:02:13.536549] get_data_sync_mode returning 0
[D 17:02:13.536576] dbpf_bstream_rw_list: mem_count: 1, stream_count: 4
[D 17:02:13.536595] dbpf_bstream_rw_list: mem_offset: 0xa393d008, mem_size: 262144
[D 17:02:13.536671] dbpf_bstream_rw_list: stream_offset: 1072562176, stream_size: 65536
[D 17:02:13.536689] dbpf_bstream_rw_list: stream_offset: 1072693248, stream_size: 65536
[D 17:02:13.536707] dbpf_bstream_rw_list: stream_offset: 1072824320, stream_size: 65536
[D 17:02:13.536731] dbpf_bstream_rw_list: stream_offset: 1072955392, stream_size: 65536
[D 17:02:13.536750] dbpf_open_cache_get: called
[D 17:02:13.536767] dbpf_open_cache_get: found bstream entry in unused list.
[D 17:02:13.536784] dbpf_open_cache_get: moving to (or reordering in) used list.
[D 17:02:13.536821] DBPF I/O ops in progress: 1
[D 17:02:13.536838] lio_listio called with the following aiocbs:
[D 17:02:13.536855] aiocb_ptr_array[0]: fd: 19, off: 1072562176, bytes: 65536, buf: 0xa393d008, type: 1
[D 17:02:13.536874] aiocb_ptr_array[1]: fd: 19, off: 1072693248, bytes: 65536, buf: 0xa394d008, type: 1
[D 17:02:13.536893] aiocb_ptr_array[2]: fd: 19, off: 1072824320, bytes: 65536, buf: 0xa395d008, type: 1
[D 17:02:13.536911] aiocb_ptr_array[3]: fd: 19, off: 1072955392, bytes: 65536, buf: 0xa396d008, type: 1
[D 17:02:13.536946] issue_or_delay_io_operation: lio_listio posted 0xa4201e18 (handle 2863311532, ret 0)
[D 17:02:13.537050] =========================================================
[D 17:02:13.537072] PINT_process_request
[D 17:02:13.537090] tiling 2 copies
[D 17:02:13.537111] Do seq of 2146107392 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 1572864 co 0
[D 17:02:13.537134] lvl 0 el 0 blk 0 by 0
[D 17:02:13.537153] to 4718592 ta 0 fi 6291456
[D 17:02:13.537173] subtype is contiguous
[D 17:02:13.537192] Request disp
[D 17:02:13.537210] contig_offset = 2146107392 contig_size = 65536 lvl_flag = 0
[D 17:02:13.537231] calling distribute
[D 17:02:13.537250] PINT_distribute
[D 17:02:13.537268] of 2146107392 sz 65536 ix 0 sm 64 by 0 bm 262144 fsz 1073020928 exfl 1
[D 17:02:13.537296] of 2146107392 sz 65536 sg 0 sm 64 by 0 bm 262144
[D 17:02:13.537316] next loff: 2146172928 next poff: 1073086464
[D 17:02:13.537337] (return value) 65536
[D 17:02:13.537355] finished
[D 17:02:13.537374] retval = 65536
[D 17:02:13.537393] return from level 0
[D 17:02:13.537411] going to next block
[D 17:02:13.537427] going to next item in sequence chain
[D 17:02:13.537446] Do seq of 2146172928 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 1507328 co 0
[D 17:02:13.537467] lvl 0 el 0 blk 0 by 0
[D 17:02:13.537486] to 4784128 ta 0 fi 6291456
[D 17:02:13.537506] subtype is contiguous
[D 17:02:13.537524] Request disp
[D 17:02:13.537543] contig_offset = 2146172928 contig_size = 131072 lvl_flag = 0
[D 17:02:13.537564] calling distribute
[D 17:02:13.537581] PINT_distribute
[D 17:02:13.537623] of 2146172928 sz 131072 ix 0 sm 64 by 0 bm 262144 fsz 1073020928 exfl 1
[D 17:02:13.537649] begin iteration loff: 2146172928
[D 17:02:13.537667] frag extends beyond strip
[D 17:02:13.537685] file being extended
[D 17:02:13.537704] process a segment
[D 17:02:13.537796] of 1073086464 sz 65536
[D 17:02:13.537818] add a segment 0
[D 17:02:13.537838] end iteration
[D 17:02:13.537904] of 2146238464 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.537926] next loff: 2146304000 next poff: 1073152000
[D 17:02:13.537947] (return value) 131072
[D 17:02:13.538032] finished
[D 17:02:13.538052] retval = 131072
[D 17:02:13.538069] return from level 0
[D 17:02:13.538087] going to next block
[D 17:02:13.538155] going to next item in sequence chain
[D 17:02:13.538174] Do seq of 2146369536 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 1376256 co 0
[D 17:02:13.538196] lvl 0 el 0 blk 0 by 0
[D 17:02:13.538216] to 4915200 ta 0 fi 6291456
[D 17:02:13.538330] subtype is contiguous
[D 17:02:13.538367] Request disp
[D 17:02:13.538387] contig_offset = 2146369536 contig_size = 65536 lvl_flag = 0
[D 17:02:13.538406] calling distribute
[D 17:02:13.538424] PINT_distribute
[D 17:02:13.538441] of 2146369536 sz 65536 ix 1 sm 64 by 65536 bm 262144 fsz 1073152000 exfl 1
[D 17:02:13.538463] of 2146369536 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.538484] next loff: 2146435072 next poff: 1073217536
[D 17:02:13.538505] (return value) 65536
[D 17:02:13.538523] finished
[D 17:02:13.538541] retval = 65536
[D 17:02:13.538559] return from level 0
[D 17:02:13.538591] going to next block
[D 17:02:13.538608] going to next item in sequence chain
[D 17:02:13.538626] Do seq of 2146435072 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 1310720 co 0
[D 17:02:13.538648] lvl 0 el 0 blk 0 by 0
[D 17:02:13.538669] to 4980736 ta 0 fi 6291456
[D 17:02:13.538690] subtype is contiguous
[D 17:02:13.538707] Request disp
[D 17:02:13.538725] contig_offset = 2146435072 contig_size = 131072 lvl_flag = 0
[D 17:02:13.538745] calling distribute
[D 17:02:13.538762] PINT_distribute
[D 17:02:13.538779] of 2146435072 sz 131072 ix 1 sm 64 by 65536 bm 262144 fsz 1073152000 exfl 1
[D 17:02:13.538800] begin iteration loff: 2146435072
[D 17:02:13.538819] frag extends beyond strip
[D 17:02:13.538837] file being extended
[D 17:02:13.538855] process a segment
[D 17:02:13.538871] of 1073217536 sz 65536
[D 17:02:13.538889] add a segment 1
[D 17:02:13.538942] end iteration
[D 17:02:13.538958] of 2146500608 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.538978] next loff: 2146566144 next poff: 1073283072
[D 17:02:13.538995] (return value) 131072
[D 17:02:13.539012] finished
[D 17:02:13.539027] retval = 131072
[D 17:02:13.539043] return from level 0
[D 17:02:13.539059] going to next block
[D 17:02:13.539075] going to next item in sequence chain
[D 17:02:13.539090] Do seq of 2146631680 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 1179648 co 0
[D 17:02:13.539110] lvl 0 el 0 blk 0 by 0
[D 17:02:13.539127] to 5111808 ta 0 fi 6291456
[D 17:02:13.539145] subtype is contiguous
[D 17:02:13.539160] Request disp
[D 17:02:13.539176] contig_offset = 2146631680 contig_size = 65536 lvl_flag = 0
[D 17:02:13.539194] calling distribute
[D 17:02:13.539209] PINT_distribute
[D 17:02:13.539224] of 2146631680 sz 65536 ix 2 sm 64 by 131072 bm 262144 fsz 1073283072 exfl 1
[D 17:02:13.539245] of 2146631680 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.539264] next loff: 2146697216 next poff: 1073348608
[D 17:02:13.539282] (return value) 65536
[D 17:02:13.539298] finished
[D 17:02:13.539314] retval = 65536
[D 17:02:13.539329] return from level 0
[D 17:02:13.539345] going to next block
[D 17:02:13.539361] going to next item in sequence chain
[D 17:02:13.539376] Do seq of 2146697216 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 1114112 co 0
[D 17:02:13.539396] lvl 0 el 0 blk 0 by 0
[D 17:02:13.539413] to 5177344 ta 0 fi 6291456
[D 17:02:13.539430] subtype is contiguous
[D 17:02:13.539446] Request disp
[D 17:02:13.539461] contig_offset = 2146697216 contig_size = 131072 lvl_flag = 0
[D 17:02:13.539479] calling distribute
[D 17:02:13.539495] PINT_distribute
[D 17:02:13.539510] of 2146697216 sz 131072 ix 2 sm 64 by 131072 bm 262144 fsz 1073283072 exfl 1
[D 17:02:13.539530] begin iteration loff: 2146697216
[D 17:02:13.539547] frag extends beyond strip
[D 17:02:13.539563] file being extended
[D 17:02:13.539579] process a segment
[D 17:02:13.539594] of 1073348608 sz 65536
[D 17:02:13.539611] add a segment 2
[D 17:02:13.539626] end iteration
[D 17:02:13.539642] of 2146762752 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.539661] next loff: 2146828288 next poff: 1073414144
[D 17:02:13.539679] (return value) 131072
[D 17:02:13.539696] finished
[D 17:02:13.539711] retval = 131072
[D 17:02:13.539727] return from level 0
[D 17:02:13.539743] going to next block
[D 17:02:13.539758] going to next item in sequence chain
[D 17:02:13.539774] Do seq of 2146893824 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 983040 co 0
[D 17:02:13.539793] lvl 0 el 0 blk 0 by 0
[D 17:02:13.539810] to 5308416 ta 0 fi 6291456
[D 17:02:13.539828] subtype is contiguous
[D 17:02:13.538900] --- aio_progress_notification called with handle 2863311532 (0xa4201e18)
[D 17:02:13.539887] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.539890] Request disp
[D 17:02:13.539921] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.539940] contig_offset = 2146893824 contig_size = 65536 lvl_flag = 0
[D 17:02:13.539961] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.539980] calling distribute
[D 17:02:13.539999] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.540017] PINT_distribute
[D 17:02:13.540047] dbpf_open_cache_put: cached entry.
[D 17:02:13.540070] dbpf_open_cache_put: move to unused list.
[D 17:02:13.540075] of 2146893824 sz 65536 ix 3 sm 64 by 196608 bm 262144 fsz 1073414144 exfl 1
[D 17:02:13.540104] of 2146893824 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.540109] *** starting delayed ops if any (state is LIST_PROC_ALLPOSTED)
[D 17:02:13.540127] next loff: 2146959360 next poff: 1073479680
[D 17:02:13.540147] op_queue add: 0xa4201e18
[D 17:02:13.540164] (return value) 65536
[D 17:02:13.540219] DBPF I/O ops in progress: 0
[D 17:02:13.540226] finished
[D 17:02:13.540264] retval = 65536
[D 17:02:13.540281] return from level 0
[D 17:02:13.540297] going to next block
[D 17:02:13.540312] going to next item in sequence chain
[D 17:02:13.540328] Do seq of 2146959360 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 917504 co 0
[D 17:02:13.540347] lvl 0 el 0 blk 0 by 0
[D 17:02:13.540364] to 5373952 ta 0 fi 6291456
[D 17:02:13.540382] subtype is contiguous
[D 17:02:13.540397] Request disp
[D 17:02:13.540413] contig_offset = 2146959360 contig_size = 131072 lvl_flag = 0
[D 17:02:13.540431] calling distribute
[D 17:02:13.540446] PINT_distribute
[D 17:02:13.540461] of 2146959360 sz 131072 ix 3 sm 64 by 196608 bm 262144 fsz 1073414144 exfl 1
[D 17:02:13.540481] begin iteration loff: 2146959360
[D 17:02:13.540498] frag extends beyond strip
[D 17:02:13.540514] file being extended
[D 17:02:13.540529] process a segment
[D 17:02:13.540544] of 1073479680 sz 65536
[D 17:02:13.540561] add a segment 3
[D 17:02:13.540577] end iteration
[D 17:02:13.540592] done with segments or bytes
[D 17:02:13.540608] of 2147024896 sz 65536 sg 4 sm 64 by 262144 bm 262144
[D 17:02:13.540627] next loff: 2147090432 next poff: 1073545216
[D 17:02:13.540644] (return value) 131072
[D 17:02:13.540660] finished
[D 17:02:13.540676] retval = 131072
[D 17:02:13.540692] return from level 0
[D 17:02:13.540708] going to next block
[D 17:02:13.540723] going to next item in sequence chain
[D 17:02:13.540739] ran out of segments or bytes
[D 17:02:13.540754] done sg 4 sm 64 by 262144 bm 262144 ta 0 to 5505024 fo 6291456 eof 0
[D 17:02:13.540773] =========================================================
[D 17:02:13.540791] BMI_post_recv: addr: 73, offset: 0xa38fc008, size: 262144, tag: 536
[D 17:02:13.540837] flowproto-multiqueue trove_write_callback_fn, error_code: 0, flow: 0x813e298.
[D 17:02:13.540862] tcp_do_work_recv: Reading header for new op.
[D 17:02:13.540894] tcp_do_work_recv: Received new message; mode: 8.
[D 17:02:13.540912] tcp_do_work_recv: tag: 536
[D 17:02:13.541436] actual_size=262144, amt_complete=135776, old_amt_complete=130560
[D 17:02:13.541763] actual_size=262144, amt_complete=153152, old_amt_complete=135776
[D 17:02:13.541838] actual_size=262144, amt_complete=164736, old_amt_complete=153152
[D 17:02:13.542024] actual_size=262144, amt_complete=180664, old_amt_complete=164736
[D 17:02:13.542154] actual_size=262144, amt_complete=193136, old_amt_complete=180664
[D 17:02:13.542403] actual_size=262144, amt_complete=209064, old_amt_complete=193136
[D 17:02:13.542655] actual_size=262144, amt_complete=238024, old_amt_complete=209064
[D 17:02:13.542829] actual_size=262144, amt_complete=262144, old_amt_complete=238024
[D 17:02:13.542907] BMI_testcontext completing: 4255
[D 17:02:13.542928] flowproto-multiqueue bmi_recv_callback_fn, error code: 0, flow: 0x813e298.
[D 17:02:13.542949] get_data_sync_mode returning 0
[D 17:02:13.543026] dbpf_bstream_rw_list: mem_count: 1, stream_count: 4
[D 17:02:13.543046] dbpf_bstream_rw_list: mem_offset: 0xa38fc008, mem_size: 262144
[D 17:02:13.543064] dbpf_bstream_rw_list: stream_offset: 1073086464, stream_size: 65536
[D 17:02:13.543082] dbpf_bstream_rw_list: stream_offset: 1073217536, stream_size: 65536
[D 17:02:13.543152] dbpf_bstream_rw_list: stream_offset: 1073348608, stream_size: 65536
[D 17:02:13.543170] dbpf_bstream_rw_list: stream_offset: 1073479680, stream_size: 65536
[D 17:02:13.543189] dbpf_open_cache_get: called
[D 17:02:13.543206] dbpf_open_cache_get: found bstream entry in unused list.
[D 17:02:13.543275] dbpf_open_cache_get: moving to (or reordering in) used list.
[D 17:02:13.543313] DBPF I/O ops in progress: 1
[D 17:02:13.543330] lio_listio called with the following aiocbs:
[D 17:02:13.543397] aiocb_ptr_array[0]: fd: 19, off: 1073086464, bytes: 65536, buf: 0xa38fc008, type: 1
[D 17:02:13.543417] aiocb_ptr_array[1]: fd: 19, off: 1073217536, bytes: 65536, buf: 0xa390c008, type: 1
[D 17:02:13.543436] aiocb_ptr_array[2]: fd: 19, off: 1073348608, bytes: 65536, buf: 0xa391c008, type: 1
[D 17:02:13.543539] aiocb_ptr_array[3]: fd: 19, off: 1073479680, bytes: 65536, buf: 0xa392c008, type: 1
[D 17:02:13.543577] issue_or_delay_io_operation: lio_listio posted 0xa4201e18 (handle 2863311532, ret 0)
[D 17:02:13.543682] =========================================================
[D 17:02:13.543703] PINT_process_request
[D 17:02:13.543767] tiling 2 copies
[D 17:02:13.543786] Do seq of 2147155968 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 786432 co 0
[D 17:02:13.543808] lvl 0 el 0 blk 0 by 0
[D 17:02:13.543828] to 5505024 ta 0 fi 6291456
[D 17:02:13.543849] subtype is contiguous
[D 17:02:13.543868] Request disp
[D 17:02:13.543888] contig_offset = 2147155968 contig_size = 65536 lvl_flag = 0
[D 17:02:13.543911] calling distribute
[D 17:02:13.543929] PINT_distribute
[D 17:02:13.543946] of 2147155968 sz 65536 ix 0 sm 64 by 0 bm 262144 fsz 1073545216 exfl 1
[D 17:02:13.543970] of 2147155968 sz 65536 sg 0 sm 64 by 0 bm 262144
[D 17:02:13.543993] next loff: 2147221504 next poff: 1073610752
[D 17:02:13.544013] (return value) 65536
[D 17:02:13.544031] finished
[D 17:02:13.544050] retval = 65536
[D 17:02:13.544068] return from level 0
[D 17:02:13.544087] going to next block
[D 17:02:13.544104] going to next item in sequence chain
[D 17:02:13.544122] Do seq of 2147221504 ne 131072 st 0 nb 1 ub 2147483648 lb -2147483648 as 720896 co 0
[D 17:02:13.544143] lvl 0 el 0 blk 0 by 0
[D 17:02:13.544164] to 5570560 ta 0 fi 6291456
[D 17:02:13.544183] subtype is contiguous
[D 17:02:13.544200] Request disp
[D 17:02:13.544219] contig_offset = 2147221504 contig_size = 131072 lvl_flag = 0
[D 17:02:13.544240] calling distribute
[D 17:02:13.544257] PINT_distribute
[D 17:02:13.544275] of 2147221504 sz 131072 ix 0 sm 64 by 0 bm 262144 fsz 1073545216 exfl 1
[D 17:02:13.544299] begin iteration loff: 2147221504
[D 17:02:13.544318] frag extends beyond strip
[D 17:02:13.544335] file being extended
[D 17:02:13.544355] process a segment
[D 17:02:13.544372] of 1073610752 sz 65536
[D 17:02:13.544391] add a segment 0
[D 17:02:13.544409] end iteration
[D 17:02:13.544426] of 2147287040 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.544448] next loff: 2147352576 next poff: 1073676288
[D 17:02:13.544468] (return value) 131072
[D 17:02:13.544485] finished
[D 17:02:13.544502] retval = 131072
[D 17:02:13.544521] return from level 0
[D 17:02:13.544540] going to next block
[D 17:02:13.544556] going to next item in sequence chain
[D 17:02:13.544575] Do seq of 2147418112 ne 65536 st 0 nb 1 ub 2147483648 lb -2147483648 as 589824 co 0
[D 17:02:13.544596] lvl 0 el 0 blk 0 by 0
[D 17:02:13.544615] to 5701632 ta 0 fi 6291456
[D 17:02:13.544635] subtype is contiguous
[D 17:02:13.544653] Request disp
[D 17:02:13.544671] contig_offset = 2147418112 contig_size = 65536 lvl_flag = 0
[D 17:02:13.544691] calling distribute
[D 17:02:13.544709] PINT_distribute
[D 17:02:13.544727] of 2147418112 sz 65536 ix 1 sm 64 by 65536 bm 262144 fsz 1073676288 exfl 1
[D 17:02:13.544748] of 2147418112 sz 65536 sg 1 sm 64 by 65536 bm 262144
[D 17:02:13.544769] next loff: 2147483648 next poff: 1073741824
[D 17:02:13.544790] (return value) 65536
[D 17:02:13.544810] finished
[D 17:02:13.544826] retval = 65536
[D 17:02:13.544845] return from level 0
[D 17:02:13.544863] going to next block
[D 17:02:13.544880] going to next item in sequence chain
[D 17:02:13.544896] Do seq of -2147483648 ne 131072 st 0 nb 1 ub -2146828288 lb -2147483648 as 524288 co 0
[D 17:02:13.544918] lvl 0 el 0 blk 0 by 0
[D 17:02:13.544936] to 5767168 ta 0 fi 6291456
[D 17:02:13.544954] subtype is contiguous
[D 17:02:13.544971] Request disp
[D 17:02:13.544989] contig_offset = -2147483648 contig_size = 131072 lvl_flag = 0
[D 17:02:13.545009] calling distribute
[D 17:02:13.545027] PINT_distribute
[D 17:02:13.545046] of -2147483648 sz 131072 ix 1 sm 64 by 65536 bm 262144 fsz 1073676288 exfl 1
[D 17:02:13.545069] begin iteration loff: -2147483648
[D 17:02:13.545087] frag extends beyond strip
[D 17:02:13.545140] process a segment
[D 17:02:13.545160] of -1073741824 sz 65536
[D 17:02:13.545179] add a segment 1
[D 17:02:13.545196] end iteration
[D 17:02:13.545214] of -2147418112 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.545234] next loff: 0 next poff: 0
[D 17:02:13.545253] (return value) 131072
[D 17:02:13.545273] finished
[D 17:02:13.545290] retval = 131072
[D 17:02:13.545308] return from level 0
[D 17:02:13.545326] going to next block
[D 17:02:13.545345] going to next item in sequence chain
[D 17:02:13.545364] Do seq of -2147287040 ne 65536 st 0 nb 1 ub -2146828288 lb -2147287040 as 393216 co 0
[D 17:02:13.545385] lvl 0 el 0 blk 0 by 0
[D 17:02:13.545404] to 5898240 ta 0 fi 6291456
[D 17:02:13.545421] subtype is contiguous
[D 17:02:13.545437] Request disp
[D 17:02:13.545431] --- aio_progress_notification called with handle 2863311532 (0xa4201e18)
[D 17:02:13.545463] contig_offset = -2147287040 contig_size = 65536 lvl_flag = 0
[D 17:02:13.545492] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.545511] calling distribute
[D 17:02:13.545532] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.545549] PINT_distribute
[D 17:02:13.545568] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.545587] of -2147287040 sz 65536 ix 2 sm 64 by 131072 bm 262144 fsz 1073676288 exfl 1
[D 17:02:13.545606] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.545624] of -2147287040 sz 65536 sg 2 sm 64 by 131072 bm 262144
[D 17:02:13.545652] dbpf_open_cache_put: cached entry.
[D 17:02:13.545666] next loff: 0 next poff: 0
[D 17:02:13.545680] dbpf_open_cache_put: move to unused list.
[D 17:02:13.545698] (return value) 65536
[D 17:02:13.545716] *** starting delayed ops if any (state is LIST_PROC_ALLPOSTED)
[D 17:02:13.545734] finished
[D 17:02:13.545753] op_queue add: 0xa4201e18
[D 17:02:13.545770] retval = 65536
[D 17:02:13.545804] return from level 0
[D 17:02:13.545819] DBPF I/O ops in progress: 0
[D 17:02:13.545821] going to next block
[D 17:02:13.545863] going to next item in sequence chain
[D 17:02:13.545880] Do seq of -2147221504 ne 131072 st 0 nb 1 ub -2146828288 lb -2147221504 as 327680 co 0
[D 17:02:13.545899] lvl 0 el 0 blk 0 by 0
[D 17:02:13.545916] to 5963776 ta 0 fi 6291456
[D 17:02:13.545934] subtype is contiguous
[D 17:02:13.545950] Request disp
[D 17:02:13.545965] contig_offset = -2147221504 contig_size = 131072 lvl_flag = 0
[D 17:02:13.545983] calling distribute
[D 17:02:13.545998] PINT_distribute
[D 17:02:13.546013] of -2147221504 sz 131072 ix 2 sm 64 by 131072 bm 262144 fsz 1073676288 exfl 1
[D 17:02:13.546034] begin iteration loff: -2147221504
[D 17:02:13.546051] frag extends beyond strip
[D 17:02:13.546066] process a segment
[D 17:02:13.546082] of -1073610752 sz 65536
[D 17:02:13.546098] add a segment 2
[D 17:02:13.546114] end iteration
[D 17:02:13.546129] of -2147155968 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.546148] next loff: 0 next poff: 0
[D 17:02:13.546165] (return value) 131072
[D 17:02:13.546181] finished
[D 17:02:13.546196] retval = 131072
[D 17:02:13.546212] return from level 0
[D 17:02:13.546228] going to next block
[D 17:02:13.546300] going to next item in sequence chain
[D 17:02:13.546317] Do seq of -2147024896 ne 65536 st 0 nb 1 ub -2146828288 lb -2147024896 as 196608 co 0
[D 17:02:13.546336] lvl 0 el 0 blk 0 by 0
[D 17:02:13.546353] to 6094848 ta 0 fi 6291456
[D 17:02:13.546370] subtype is contiguous
[D 17:02:13.546386] Request disp
[D 17:02:13.546402] contig_offset = -2147024896 contig_size = 65536 lvl_flag = 0
[D 17:02:13.546420] calling distribute
[D 17:02:13.546435] PINT_distribute
[D 17:02:13.546450] of -2147024896 sz 65536 ix 3 sm 64 by 196608 bm 262144 fsz 1073676288 exfl 1
[D 17:02:13.546471] of -2147024896 sz 65536 sg 3 sm 64 by 196608 bm 262144
[D 17:02:13.546516] next loff: 0 next poff: 0
[D 17:02:13.546533] (return value) 65536
[D 17:02:13.546550] finished
[D 17:02:13.546565] retval = 65536
[D 17:02:13.546590] return from level 0
[D 17:02:13.546606] going to next block
[D 17:02:13.546621] going to next item in sequence chain
[D 17:02:13.546637] Do seq of -2146959360 ne 131072 st 0 nb 1 ub -2146828288 lb -2146959360 as 131072 co 0
[D 17:02:13.546656] lvl 0 el 0 blk 0 by 0
[D 17:02:13.546673] to 6160384 ta 0 fi 6291456
[D 17:02:13.546691] subtype is contiguous
[D 17:02:13.546706] Request disp
[D 17:02:13.546722] contig_offset = -2146959360 contig_size = 131072 lvl_flag = 0
[D 17:02:13.546740] calling distribute
[D 17:02:13.546755] PINT_distribute
[D 17:02:13.546771] of -2146959360 sz 131072 ix 3 sm 64 by 196608 bm 262144 fsz 1073676288 exfl 1
[D 17:02:13.546791] begin iteration loff: -2146959360
[D 17:02:13.546809] frag extends beyond strip
[D 17:02:13.546824] process a segment
[D 17:02:13.546840] of -1073479680 sz 65536
[D 17:02:13.546856] add a segment 3
[D 17:02:13.546873] end iteration
[D 17:02:13.546888] done with segments or bytes
[D 17:02:13.546903] of -2146893824 sz 65536 sg 4 sm 64 by 262144 bm 262144
[D 17:02:13.546922] next loff: 0 next poff: 0
[D 17:02:13.546939] (return value) 131072
[D 17:02:13.546956] finished
[D 17:02:13.546971] retval = 131072
[D 17:02:13.546987] return from level 0
[D 17:02:13.547003] going to next block
[D 17:02:13.547018] going to next item in sequence chain
[D 17:02:13.547034] going to next element in block of level above
[D 17:02:13.547050] ran out of segments or bytes
[D 17:02:13.547066] done sg 4 sm 64 by 262144 bm 262144 ta 0 to 6291456 fo 6291456 eof 0
[D 17:02:13.547084] =========================================================
[D 17:02:13.547103] BMI_post_recv: addr: 73, offset: 0xa38bb008, size: 262144, tag: 536
[D 17:02:13.547145] flowproto-multiqueue trove_write_callback_fn, error_code: 0, flow: 0x813e298.
[D 17:02:13.547173] tcp_do_work_recv: Reading header for new op.
[D 17:02:13.547205] tcp_do_work_recv: Received new message; mode: 8.
[D 17:02:13.547222] tcp_do_work_recv: tag: 536
[D 17:02:13.547744] actual_size=262144, amt_complete=134824, old_amt_complete=129608
[D 17:02:13.548147] actual_size=262144, amt_complete=153648, old_amt_complete=134824
[D 17:02:13.548277] actual_size=262144, amt_complete=165232, old_amt_complete=153648
[D 17:02:13.548410] actual_size=262144, amt_complete=181160, old_amt_complete=165232
[D 17:02:13.548538] actual_size=262144, amt_complete=194192, old_amt_complete=181160
[D 17:02:13.548678] actual_size=262144, amt_complete=210120, old_amt_complete=194192
[D 17:02:13.548813] actual_size=262144, amt_complete=224600, old_amt_complete=210120
[D 17:02:13.549033] actual_size=262144, amt_complete=255008, old_amt_complete=224600
[D 17:02:13.549096] actual_size=262144, amt_complete=262144, old_amt_complete=255008
[D 17:02:13.549121] BMI_testcontext completing: 4256
[D 17:02:13.549141] flowproto-multiqueue bmi_recv_callback_fn, error code: 0, flow: 0x813e298.
[D 17:02:13.549162] get_data_sync_mode returning 0
[D 17:02:13.549187] dbpf_bstream_rw_list: mem_count: 1, stream_count: 4
[D 17:02:13.549206] dbpf_bstream_rw_list: mem_offset: 0xa38bb008, mem_size: 262144
[D 17:02:13.549235] dbpf_bstream_rw_list: stream_offset: 1073610752, stream_size: 65536
[D 17:02:13.549254] dbpf_bstream_rw_list: stream_offset: -1073741824, stream_size: 65536
[D 17:02:13.549271] dbpf_bstream_rw_list: stream_offset: -1073610752, stream_size: 65536
[D 17:02:13.549289] dbpf_bstream_rw_list: stream_offset: -1073479680, stream_size: 65536
[D 17:02:13.549307] dbpf_open_cache_get: called
[D 17:02:13.549324] dbpf_open_cache_get: found bstream entry in unused list.
[D 17:02:13.549342] dbpf_open_cache_get: moving to (or reordering in) used list.
[D 17:02:13.549380] DBPF I/O ops in progress: 1
[D 17:02:13.549396] lio_listio called with the following aiocbs:
[D 17:02:13.549413] aiocb_ptr_array[0]: fd: 19, off: 1073610752, bytes: 65536, buf: 0xa38bb008, type: 1
[D 17:02:13.549471] aiocb_ptr_array[1]: fd: 19, off: -1073741824, bytes: 65536, buf: 0xa38cb008, type: 1
[D 17:02:13.549490] aiocb_ptr_array[2]: fd: 19, off: -1073610752, bytes: 65536, buf: 0xa38db008, type: 1
[D 17:02:13.549509] aiocb_ptr_array[3]: fd: 19, off: -1073479680, bytes: 65536, buf: 0xa38eb008, type: 1
[D 17:02:13.549545] issue_or_delay_io_operation: lio_listio posted 0xa4201e18 (handle 2863311532, ret 0)
[D 17:02:13.550037] --- aio_progress_notification called with handle 2863311532 (0xa4201e18)
[D 17:02:13.550064] aio_progress_notification: BSTREAM_WRITE_LIST complete: aio_return() says 65536 [fd = 19]
[D 17:02:13.550097] error 22 (Invalid argument) from aio_error/aio_return on block 1; skipping
[D 17:02:13.550118] dbpf_open_cache_put: cached entry.
[D 17:02:13.550134] dbpf_open_cache_put: move to unused list.
[D 17:02:13.550150] *** starting delayed ops if any (state is LIST_PROC_ALLPOSTED)
[D 17:02:13.550167] op_queue add: 0xa4201e18
[D 17:02:13.550208] flowproto-multiqueue trove_write_callback_fn, error_code: -1073742095, flow: 0x813e298.
[D 17:02:13.550245] flowproto-multiqueue handle_io_error() called for flow 0x813e298.
[E 17:02:13.550262] handle_io_error: flow proto error cleanup started on 0x813e298, error_code: -1073742095
[D 17:02:13.550282] flowproto-multiqueue canceled 0 bmi-trove BMI ops.
[D 17:02:13.550299] flowproto-multiqueue canceled 0 bmi-trove Trove ops.
[E 17:02:13.550315] handle_io_error: flow proto 0x813e298 canceled 0 operations, will clean up.
[D 17:02:13.550333] flowproto-multiqueue handle_io_error() pending count: 0
[E 17:02:13.550349] handle_io_error: flow proto 0x813e298 error cleanup finished, error_code: -1073742095
[D 17:02:13.550368] flowproto completing 0x813e298
[D 17:02:13.550808] Job flows in progress (callback time): 0
[D 17:02:13.550843] DBPF I/O ops in progress: 0
[D 17:02:13.550854] [SM Entering]: (0x8138368) io_sm:release (status: 0)
[D 17:02:13.550890] REQ SCHED RELEASING, handle: 2863311532, queue_element: 0x8132240
[D 17:02:13.550912] [SM Exiting]: (0x8138368) io_sm:release (error code: 0)
[D 17:02:13.550931] [SM Entering]: (0x8138368) io_sm:cleanup (status: 0)
[A 17:02:13.551181] jkunkel2.users at node0.cluster H=2863311532 S=0x8138368: io: finish (Success)
[D 17:02:13.551205] PINT_encode_release
[D 17:02:13.551222] lebf_encode_rel
[D 17:02:13.551242] PINT_decode_release
[D 17:02:13.551258] lebf_decode_rel
[D 17:02:13.551278] [SM Exiting]: (0x8138368) io_sm:cleanup (error code: 0)
[D 17:02:14.390280] [SM Entering]: (0x8162f98) job_timer_sm:do_work (status: 0)
[D 17:02:14.814316] [SM Exiting]: (0x8162f98) job_timer_sm:do_work (error code: 0)
[D 17:02:15.854087] [SM Entering]: (0x8162f98) job_timer_sm:do_work (status: 0)
[D 17:02:15.854120] [SM Exiting]: (0x8162f98) job_timer_sm:do_work (error code: 0)
More information about the Pvfs2-developers
mailing list