Re: Still seeing hangs in xlog_grant_log_space

Mark Tinguely
2012-05-09T21:07:56Z

On 05/09/12 02:35, Dave Chinner wrote:

>
> Transaction Wait queues Grant head Write Head Log head Log tail
> -----------------------------------------------------------------------------------------
> INACTIVE empty empty 118 438024 118 438024 118 802 118 697
> INACTIVE empty empty 119 20240 119 20240 118 802 118 697
> REMOVE empty empty 118 438456 118 438456 118 802 118 697
> REMOVE empty empty 118 438772 118 438772 118 802 118 697
> CREATE empty empty 119 35872 119 35872 118 802 118 697
> FSYNC_TS active empty 119 205428 119 205428 118 802 118 697
> FSYNC_TS active empty 119 202944 119 202944 118 802 118 697
> FSYNC_TS active empty 119 200664 119 200664 118 802 118 697
> REMOVE empty empty 118 380316 118 380316 118 724 118 652
> INACTIVE empty empty 118 552532 118 552532 118 724 118 652
> FSYNC_TS empty empty 118 382140 118 382140 118 724 118 652
> INACTIVE empty empty 118 565968 118 565968 118 724 118 652
> REMOVE empty empty 119 25404 119 25404 118 802 118 697
> INACTIVE active empty 119 25580 119 25580 118 802 118 697

Just so you don't go down a blind alley, the timestamp on the log went
backwards there. If you resort on the time stamps this does not go
backwards.

Not sorted:
grep ungrant_exit trace* | awk '{print $3, $8, $20, $22, $24, $26, $28,
$30, $32, $34, $36, $38}' | less

3501.000611: FSYNC_TS active empty 119 205428 119 205428 118 802 118 697
3501.004513: FSYNC_TS active empty 119 202944 119 202944 118 802 118 697
3501.005210: FSYNC_TS active empty 119 200664 119 200664 118 802 118 697
3500.962328: REMOVE empty empty 118 380316 118 380316 118 724 118 652
3500.962458: INACTIVE empty empty 118 552532 118 552532 118 724 118 652
3500.962770: FSYNC_TS empty empty 118 382140 118 382140 118 724 118 652
3500.964781: INACTIVE empty empty 118 565968 118 565968 118 724 118 652
3500.971259: REMOVE empty empty 119 25404 119 25404 118 802 118 697
3500.971454: INACTIVE active empty 119 25580 119 25580 118 802 118 697

Sorted on the timestamps:
grep ungrant_exit trace* | awk '{print $3, $8, $20, $22, $24, $26, $28,
$30, $32, $34, $36, $38}' | sort | less

3500.962328: REMOVE empty empty 118 380316 118 380316 118 724 118 652
3500.962386: INACTIVE empty empty 118 555684 118 555684 118 724 118 652
3500.962402: CREATE empty empty 118 380492 118 380492 118 724 118 652
3500.962458: INACTIVE empty empty 118 552532 118 552532 118 724 118 652
3500.962466: FSYNC_TS empty empty 118 552532 118 552532 118 724 118 652
3500.962476: REMOVE empty empty 118 380936 118 380936 118 724 118 652
3500.962534: INACTIVE empty empty 118 556304 118 556304 118 724 118 652
...
3500.979002: INACTIVE empty empty 118 437672 118 437672 118 802 118 697
3500.979185: CREATE empty empty 118 437848 118 437848 118 802 118 697
3500.979269: CREATE empty empty 118 438024 118 438024 118 802 118 697
3500.979462: INACTIVE empty empty 118 438024 118 438024 118 802 118 697
3500.979627: INACTIVE empty empty 119 20240 119 20240 118 802 118 697
3500.979657: REMOVE empty empty 118 438456 118 438456 118 802 118 697
3500.979713: REMOVE empty empty 118 438772 118 438772 118 802 118 697
3500.979815: CREATE empty empty 119 35872 119 35872 118 802 118 697
3501.000611: FSYNC_TS active empty 119 205428 119 205428 118 802 118 697

Maybe I have a corrupted version of his first trace, it looks like there
are 2 series of log grant/write/head/tail sequences. These sequences are
not even close to each other:

188.116687: FSYNC_TS empty empty 1 847894476 1 847894476 1 1655998 1 1655971
188.116939: FSYNC_TS empty empty 1 847894476 1 847894476 1 1655998 1 1655971
188.117755: CREATE empty empty 4440 166388 4440 166388 4440 312 4440 310
188.117784: FSYNC_TS empty empty 1 847894476 1 847894476 1 1655998 1 1655971
188.117902: FSYNC_TS empty empty 1 847894476 1 847894476 1 1655998 1 1655971
188.118249: CREATE empty empty 4440 166844 4440 166844 4440 312 4440 310
188.118350: CREATE empty empty 4440 167300 4440 167300 4440 312 4440 310
188.118628: FSYNC_TS empty empty 4440 167300 4440 167300 4440 312 4440 310
188.118837: FSYNC_TS empty empty 1 847894476 1 847894476 1 1655998 1 1655971
188.118868: FSYNC_TS empty empty 1 847894476 1 847894476 1 1655998 1 1655971

--Mark Tinguely.