MemoryTracking metric strange values

[Yashin32]

Since v18.12.13 i receive negative values in MemoryTracking when querying system.metrics table.

select metric, value from system.metrics where metric = 'MemoryTracking' format Vertical
metric: MemoryTracking
value:  -6746321106

free -m
              total        used        free      shared  buff/cache   available
Mem:          15290        1531        8289         152        5469       13222
Swap:             0           0           0

[bocharov]

We were affected by this issue as well, when trying to upgrade from 1.1.54388 to 18.12.14.
The exceptions we saw in the logs are:

<Error> executeQuery: Code: 241, e.displayText() = DB::Exception: Memory limit (total) exceeded: would use 30.00 GiB (attempt to allocate chunk of 1048591 bytes), maximum: 30.00 GiB, e.what() = DB::Exception (from [2400:cb00:36:1020::a29e:4267]:57306) (in query: INSERT INTO ....

This was happening only on 1/3 of the cluster, which we upgraded first.
cc @vavrusa @bobrik

[sivasamyk]

We are running ClickHouse version 18.12.14 revision 54407. In our case MemoryTracking metrics is behaving like a counter (it keeps increasing). Currently it is reporting around 170GB.

select metric,value from system.metrics where metric='MemoryTracking';

SELECT
    metric,
    value
FROM system.metrics
WHERE metric = 'MemoryTracking'

┌─metric─────────┬────────value─┐
│ MemoryTracking │ 183160211569 │
└────────────────┴──────────────┘

1 rows in set. Elapsed: 0.002 sec.

$ free -h
              total        used        free      shared  buff/cache   available
Mem:           1.9G        757M        156M         22M        1.0G        968M
Swap:            0B          0B          0B

Will this commit vavrusa@0652302 fix this issue?

[alexey-milovidov]

Yes. It is fixed in 18.14.8 (this version will be released today).

[vavrusa]

It looks like there's still issues with memory tracker in 18.14.11-stable, I suspect the memory is allocated in queries but ends up being freed elsewhere, hence the discrepancy:

SELECT 
    metric, 
    formatReadableSize(value)
FROM system.metrics 
WHERE metric LIKE 'Memory%'

┌─metric───────────────────────────────────┬─formatReadableSize(value)─┐
│ MemoryTracking                           │ 24.27 GiB                 │
│ MemoryTrackingInBackgroundProcessingPool │ -14.52 GiB                │
│ MemoryTrackingInBackgroundSchedulePool   │ -2.84 GiB                 │
│ MemoryTrackingForMerges                  │ 30.53 MiB                 │
└──────────────────────────────────────────┴───────────────────────────┘

4 rows in set. Elapsed: 0.002 sec. 

But quotas are only looking at the query memory consumption, so it throws exceptions in queries even though the limit for all queries isn't really met.

[dqminh]

@alexey-milovidov should we reopen this ? The metrics are still incorrect for us.

[citrin]

I also see a negative value with ClickHouse 19.5.3.8

┌─metric───────────────────────────────────┬─formatReadableSize(value)─┐
│ MemoryTracking                           │ 18.63 KiB                 │
│ MemoryTrackingInBackgroundProcessingPool │ -3.58 MiB                 │
│ MemoryTrackingInBackgroundSchedulePool   │ 0.00 B                    │
│ MemoryTrackingForMerges                  │ 0.00 B                    │
└──────────────────────────────────────────┴───────────────────────────┘

[Nikolo]

SELECT 
    metric, 
    formatReadableSize(value)
FROM system.metrics 
WHERE metric LIKE 'Memory%'

┌─metric───────────────────────────────────┬─formatReadableSize(value)─┐
│ MemoryTracking                           │ 18.56 KiB                 │
│ MemoryTrackingInBackgroundProcessingPool │ -5.87 GiB                 │
│ MemoryTrackingInBackgroundSchedulePool   │ -53.49 GiB                │
│ MemoryTrackingForMerges                  │ 17.94 MiB                 │
└──────────────────────────────────────────┴───────────────────────────┘

SELECT 
    metric, 
    value
FROM system.metrics 
WHERE metric IN ('VersionInteger', 'Revision')

┌─metric─────────┬────value─┐
│ Revision       │    54420 │
│ VersionInteger │ 19008003 │
└────────────────┴──────────┘

[alexey-milovidov]

│ MemoryTrackingInBackgroundProcessingPool │ -5.87 GiB                 │
│ MemoryTrackingInBackgroundSchedulePool   │ -53.49 GiB                │

It's technically Ok, because BackgroundPool frees memory that was allocated outside.
Example:

• SELECT from MergeTree is loading index for data parts;
• "clean old parts" operation in BackgroundSchedulePool removes old parts, deallocating their indices.

From MemoryTracker standpoint, SELECT "leaks" memory and BackgroundSchedulePool frees more memory than was allocated inside it.

[holen]

SELECT
metric,
formatReadableSize(value)
FROM system.metrics
WHERE metric LIKE 'Memory%'

Query id: ea4969e7-34f3-4e79-8fa1-f949043135cc

┌─metric────────────────────┬─formatReadableSize(value)─┐

1. │ MemoryTracking │ 1.52 GiB │
2. │ MemoryTrackingUncorrected │ 12.08 MiB │
   └───────────────────────────┴───────────────────────────┘
   ClickHouse's memory usage keeps increasing.