[ 
https://issues.apache.org/jira/browse/IGNITE-17456?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Pavel Pereslegin updated IGNITE-17456:
--------------------------------------
    Description: 
If you enable compression of WAL segments and at the same time set the WAL 
archive size too small, then compression will not actually occur, but after 
each node restart, "fake" notifications about segment compression are 
sequentially written to the log from the beginning (see log example below).

{noformat}
[2022-08-02T14:46:33,757][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Resolved write ahead log work directory: 
/home/xtern/src/java/ignite/work/db/wal/node00-63fb6fa2-fcea-42aa-a3c8-b36cd330ba7c
[2022-08-02T14:46:33,757][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Resolved write ahead log archive directory: 
/home/xtern/src/java/ignite/work/db/wal/archive/node00-63fb6fa2-fcea-42aa-a3c8-b36cd330ba7c
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=0]
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=1]
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=2]
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=3]
...
[2022-08-02T14:46:33,761][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=49]
[2022-08-02T14:46:33,761][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileHandleManagerImpl] 
Initialized write-ahead log manager [mode=LOG_ONLY]
...
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-1-#133%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=0]
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=1]
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=2]
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=3]
...
[2022-08-02T14:46:34,092][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=49]
[2022-08-02T14:46:34,093][INFO 
][exchange-worker-#127%wal.WalCompactionAfterRestartTest0%][GridCacheProcessor] 
Finished recovery for cache [cache=ignite-sys-cache, grp=ignite-sys-cache, 
startVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]]
{noformat}

Reproducer:

{code:java}
    private final ListeningTestLogger logger = new ListeningTestLogger(log);

    /** {@inheritDoc} */
    @Override protected IgniteConfiguration getConfiguration(String name) 
throws Exception {
        return super.getConfiguration(name)
            .setGridLogger(logger)
            .setDataStorageConfiguration(new DataStorageConfiguration()
                .setDefaultDataRegionConfiguration(new DataRegionConfiguration()
                    .setPersistenceEnabled(true))
                .setWalSegmentSize(512 * 1024)
                .setMaxWalArchiveSize(512 * 1024)
                .setWalCompactionEnabled(true)
            );
    }

    @Test
    public void testCompactionDuplicationNotificationsOnRestart() throws 
Exception {
        String msg = "Segment compressed notification [idx=0]";
        LogListener exactOnceMsg = LogListener.matches(msg).times(1).build();
        LogListener duplicationMsgCheck = 
LogListener.matches(msg).times(0).build();

        logger.registerListener(exactOnceMsg);

        IgniteEx ignite = startGrid(0);

        ignite.cluster().state(ClusterState.ACTIVE);

        for (int i = 0; i < 1_000; i++)
            ignite.getOrCreateCache(DEFAULT_CACHE_NAME).put(i, i);

        
assertTrue(ignite.context().cache().context().wal().lastCompactedSegment() > 0);
        assertTrue(exactOnceMsg.check());

        // Restart grid.
        stopGrid(0);

        logger.registerListener(duplicationMsgCheck);

        ignite = startGrid(0);

        ignite.cluster().state(ClusterState.ACTIVE);

        assertTrue("Duplicate notification present after restart.", 
duplicationMsgCheck.check());
    }
{code}

  was:
If you enable compression of WAL segments and at the same time set the WAL 
archive size too small, then compression will not actually occur, but after 
each node restart, "fake" notifications about segment compression are 
sequentially written to the log from the beginning (see log example below).

{noformat}
[2022-08-02T14:46:33,757][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Resolved write ahead log work directory: 
/home/xtern/src/java/ignite/work/db/wal/node00-63fb6fa2-fcea-42aa-a3c8-b36cd330ba7c
[2022-08-02T14:46:33,757][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Resolved write ahead log archive directory: 
/home/xtern/src/java/ignite/work/db/wal/archive/node00-63fb6fa2-fcea-42aa-a3c8-b36cd330ba7c
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=0]
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=1]
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=2]
[2022-08-02T14:46:33,759][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=3]
...
[2022-08-02T14:46:33,761][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager] 
Enqueuing segment for compression [idx=49]
[2022-08-02T14:46:33,761][INFO 
][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileHandleManagerImpl] 
Initialized write-ahead log manager [mode=LOG_ONLY]
...
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-1-#133%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=0]
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=1]
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=2]
[2022-08-02T14:46:34,084][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=3]
...
[2022-08-02T14:46:34,092][INFO 
][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
 Segment compressed notification [idx=49]
[2022-08-02T14:46:34,093][INFO 
][exchange-worker-#127%wal.WalCompactionAfterRestartTest0%][GridCacheProcessor] 
Finished recovery for cache [cache=ignite-sys-cache, grp=ignite-sys-cache, 
startVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]]
{noformat}

Reproducer:

{code:java}
    private final ListeningTestLogger logger = new ListeningTestLogger(log);

    /** {@inheritDoc} */
    @Override protected IgniteConfiguration getConfiguration(String name) 
throws Exception {
        IgniteConfiguration cfg = super.getConfiguration(name);

        cfg.setGridLogger(logger)
            .setDataStorageConfiguration(new DataStorageConfiguration()
                .setDefaultDataRegionConfiguration(new DataRegionConfiguration()
                    .setPersistenceEnabled(true))
                .setWalSegmentSize(512 * 1024)
                .setMaxWalArchiveSize(512 * 1024)
                .setWalCompactionEnabled(true)
            );

        return cfg;
    }

    @Test
    public void testCompactionDuplicationNotificationsOnRestart() throws 
Exception {
        String msg = "Segment compressed notification [idx=0]";
        LogListener exactOnceMsg = LogListener.matches(msg).times(1).build();
        LogListener duplicationMsgCheck = 
LogListener.matches(msg).times(0).build();

        logger.registerListener(exactOnceMsg);

        IgniteEx ignite = startGrid(0);

        ignite.cluster().state(ClusterState.ACTIVE);

        for (int i = 0; i < 1_000; i++)
            ignite.getOrCreateCache(DEFAULT_CACHE_NAME).put(i, i);

        
assertTrue(ignite.context().cache().context().wal().lastCompactedSegment() > 0);
        assertTrue(exactOnceMsg.check());

        // Restart grid.
        stopGrid(0);

        logger.registerListener(duplicationMsgCheck);

        ignite = startGrid(0);

        ignite.cluster().state(ClusterState.ACTIVE);

        assertTrue("Duplicate notification present after restart.", 
duplicationMsgCheck.check());
    }
{code}


> After node restart, there are duplicate messages about WAL segment 
> compression.
> -------------------------------------------------------------------------------
>
>                 Key: IGNITE-17456
>                 URL: https://issues.apache.org/jira/browse/IGNITE-17456
>             Project: Ignite
>          Issue Type: Bug
>            Reporter: Pavel Pereslegin
>            Assignee: Pavel Pereslegin
>            Priority: Minor
>              Labels: ise
>
> If you enable compression of WAL segments and at the same time set the WAL 
> archive size too small, then compression will not actually occur, but after 
> each node restart, "fake" notifications about segment compression are 
> sequentially written to the log from the beginning (see log example below).
> {noformat}
> [2022-08-02T14:46:33,757][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Resolved write ahead log work directory: 
> /home/xtern/src/java/ignite/work/db/wal/node00-63fb6fa2-fcea-42aa-a3c8-b36cd330ba7c
> [2022-08-02T14:46:33,757][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Resolved write ahead log archive directory: 
> /home/xtern/src/java/ignite/work/db/wal/archive/node00-63fb6fa2-fcea-42aa-a3c8-b36cd330ba7c
> [2022-08-02T14:46:33,759][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Enqueuing segment for compression [idx=0]
> [2022-08-02T14:46:33,759][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Enqueuing segment for compression [idx=1]
> [2022-08-02T14:46:33,759][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Enqueuing segment for compression [idx=2]
> [2022-08-02T14:46:33,759][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Enqueuing segment for compression [idx=3]
> ...
> [2022-08-02T14:46:33,761][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileWriteAheadLogManager]
>  Enqueuing segment for compression [idx=49]
> [2022-08-02T14:46:33,761][INFO 
> ][test-runner-#1%wal.WalCompactionAfterRestartTest%][FileHandleManagerImpl] 
> Initialized write-ahead log manager [mode=LOG_ONLY]
> ...
> [2022-08-02T14:46:34,084][INFO 
> ][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-1-#133%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
>  Segment compressed notification [idx=0]
> [2022-08-02T14:46:34,084][INFO 
> ][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
>  Segment compressed notification [idx=1]
> [2022-08-02T14:46:34,084][INFO 
> ][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
>  Segment compressed notification [idx=2]
> [2022-08-02T14:46:34,084][INFO 
> ][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
>  Segment compressed notification [idx=3]
> ...
> [2022-08-02T14:46:34,092][INFO 
> ][wal-file-compressor-%wal.WalCompactionAfterRestartTest0%-0-#131%wal.WalCompactionAfterRestartTest0%][FileWriteAheadLogManager]
>  Segment compressed notification [idx=49]
> [2022-08-02T14:46:34,093][INFO 
> ][exchange-worker-#127%wal.WalCompactionAfterRestartTest0%][GridCacheProcessor]
>  Finished recovery for cache [cache=ignite-sys-cache, grp=ignite-sys-cache, 
> startVer=AffinityTopologyVersion [topVer=1, minorTopVer=1]]
> {noformat}
> Reproducer:
> {code:java}
>     private final ListeningTestLogger logger = new ListeningTestLogger(log);
>     /** {@inheritDoc} */
>     @Override protected IgniteConfiguration getConfiguration(String name) 
> throws Exception {
>         return super.getConfiguration(name)
>             .setGridLogger(logger)
>             .setDataStorageConfiguration(new DataStorageConfiguration()
>                 .setDefaultDataRegionConfiguration(new 
> DataRegionConfiguration()
>                     .setPersistenceEnabled(true))
>                 .setWalSegmentSize(512 * 1024)
>                 .setMaxWalArchiveSize(512 * 1024)
>                 .setWalCompactionEnabled(true)
>             );
>     }
>     @Test
>     public void testCompactionDuplicationNotificationsOnRestart() throws 
> Exception {
>         String msg = "Segment compressed notification [idx=0]";
>         LogListener exactOnceMsg = LogListener.matches(msg).times(1).build();
>         LogListener duplicationMsgCheck = 
> LogListener.matches(msg).times(0).build();
>         logger.registerListener(exactOnceMsg);
>         IgniteEx ignite = startGrid(0);
>         ignite.cluster().state(ClusterState.ACTIVE);
>         for (int i = 0; i < 1_000; i++)
>             ignite.getOrCreateCache(DEFAULT_CACHE_NAME).put(i, i);
>         
> assertTrue(ignite.context().cache().context().wal().lastCompactedSegment() > 
> 0);
>         assertTrue(exactOnceMsg.check());
>         // Restart grid.
>         stopGrid(0);
>         logger.registerListener(duplicationMsgCheck);
>         ignite = startGrid(0);
>         ignite.cluster().state(ClusterState.ACTIVE);
>         assertTrue("Duplicate notification present after restart.", 
> duplicationMsgCheck.check());
>     }
> {code}



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

Reply via email to