@@ -3100,10 +3100,20 @@ perform_final_merge(Oid relid_src, Oid *indexes_src, int nindexes,
31003100 struct timeval t_start ;
31013101
31023102 gettimeofday (& t_start , NULL );
3103+ /* Add the whole seconds. */
3104+ t_end .tv_sec = t_start .tv_sec + squeeze_max_xlock_time / 1000 ;
3105+ /* Add the rest, expressed in microseconds. */
31033106 usec = t_start .tv_usec + 1000 * (squeeze_max_xlock_time % 1000 );
3104- t_end .tv_sec = t_start .tv_sec + usec / USECS_PER_SEC ;
3107+ /* The number of microseconds could have overflown. */
3108+ t_end .tv_sec += usec / USECS_PER_SEC ;
31053109 t_end .tv_usec = usec % USECS_PER_SEC ;
31063110 t_end_ptr = & t_end ;
3111+
3112+ elog (DEBUG1 ,
3113+ "pg_squeeze: completion required by %lu.%lu, current time is %lu.%lu." ,
3114+ t_end_ptr -> tv_sec , t_end_ptr -> tv_usec , t_start .tv_sec ,
3115+ t_start .tv_usec );
3116+
31073117 }
31083118
31093119 /*
@@ -3153,6 +3163,16 @@ perform_final_merge(Oid relid_src, Oid *indexes_src, int nindexes,
31533163 cat_state , rel_dst , ident_key ,
31543164 ident_key_nentries , iistate ,
31553165 AccessExclusiveLock , t_end_ptr );
3166+ if (t_end_ptr )
3167+ {
3168+ struct timeval t_now ;
3169+
3170+ gettimeofday (& t_now , NULL );
3171+ elog (DEBUG1 ,
3172+ "pg_squeeze: concurrent changes processed at %lu.%lu, result: %u" ,
3173+ t_now .tv_sec , t_now .tv_usec , success );
3174+ }
3175+
31563176 if (!success )
31573177 {
31583178 /* Unlock the relations and indexes. */
0 commit comments