[MCOL-5597]  NULL & non-zero length string | assertion 'mStr || mLength == 0' failed Created: 2023-10-25  Updated: 2024-02-01

Status: In Progress
Project: MariaDB ColumnStore
Component/s: None
Affects Version/s: 23.02.4, 23.10.0
Fix Version/s: 23.02, 23.10.1

Type: Bug Priority: Critical
Reporter: Allen Herrera Assignee: Sergey Zefirov
Resolution: Unresolved Votes: 1
Labels: triage
Environment:

Validated on: Single node localstorage - EC2 - Rocky 8 - 4x16
Source: Single node localstorage - Rocky 8.8 16x256

Attachments: JPEG File Untitled.jpg     JPEG File error2.jpg    
Issue Links:
Issue split
split to MCOL-5626 Disk join step race with parallel joi... In Testing
Relates
relates to MCOL-5627 Memory oversubscription issues in 23.10. In Progress
Sprint: 2023-11, 2023-12
Assigned for Review: Roman Roman
Assigned for Testing: Kirill Perov Kirill Perov

 Description   

The query worked on 23.02.3 but now on 23.10.0 & 23.02.4 returns
ERROR 1815 (HY000): Internal error: InetStreamSocket::readToMagic: Remote is closed
or
ERROR 1815 (HY000): Internal error: DiskJoinStep::largeReader() MCS-2035: An internal error occurred. Check the error log file & contact support.

See developer notes for reproduction tar file
Reproduction:

# Works:  bash cs_package_manager.sh install enterprise 10.6.14-9 --token xxxxxxxxxxx
 
# Broken: bash cs_package_manager.sh install enterprise 10.6.15-10 --token xxxxxxxxxxx
 
 
 
mcsSetConfig HashJoin AllowDiskBasedJoin Y
 
mcsSetConfig RowAggregation AllowDiskBasedAggregation Y
 
mcs cluster stop
 
mcs cluster start
 
 
 
mariadb < mcs_table_ddls.sql
 
 
 
bash mock.bash edf_colstore vinci_cs_tracking_t 1600000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
bash mock.bash edf_colstore pl_cs_contact_t 400000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
bash mock.bash edf_colstore pl_cs_question_t 400000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
bash mock.bash edf_colstore pl_cs_org_unit_t 400000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
bash mock.bash edf_colstore pl_cs_question_repository_t 400000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
bash mock.bash edf_colstore pl_cs_answer_repository_t 400000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
bash mock.bash edf_colstore pl_cs_tracking_status_t 400000 > tmp.sql; mariadb edf_colstore < tmp.sql;
 
 
 
mariadb edf_colstore < large_query.sql
 
 
 
tdebug
 
# Oct 25 14:39:08 ip-172-31-24-202 Calpont[39728]: 08.345180 |0|0|0| E 00 CAL0000: /mdb/verylongdirnameforverystrangecpackbehavior/storage/columnstore/columnstore/utils/common/conststring.h@36: assertion 'mStr || mLength == 0' failed         %%10%%



 Comments   
Comment by Kirill Perov [ 2023-12-02 ]

allen.herrera I'm not able to download edf-reproduction.tar using guide above

kirill_perov@kirillperov-testvm:~/5597$ aws s3 cp --profile jira s3://columnstore-jira-mcols/MCOL-5597/edf-reproduction.tar .
download failed: s3://columnstore-jira-mcols/MCOL-5597/edf-reproduction.tar to ./edf-reproduction.tar [Errno 13] Permission denied: '/home/kirill_perov/5597/edf-reproduction.tar.caDcDFbD'

Comment by Kirill Perov [ 2023-12-05 ]

1. Bug confirmed for version 23.02.4 only with millions of rows. With hundred thousands of rows bug is not reproducible for 23.02.4.
2. Latest develop (05.12.2023) returns result for hundred thousands of rows. And VM stucks when query is running for millions of rows after about 20 minutes (tried 2 times).

after reload VM has 140GB of disk space free (same as before query run)

Comment by Kirill Perov [ 2023-12-06 ]

bug is reproduced for latest develop on a smaller amount of data:

reproduced on: 40% (1600000/400000), and 20%
work fine on 10%

same time old version working fine even with 40% of data and fail only from 45%

Comment by Kirill Perov [ 2023-12-11 ]

denis0x0D, can the request in the description succeed now?

Comment by Kirill Perov [ 2023-12-12 ]

denis0x0D move branch to main repo https://github.com/mariadb-corporation/mariadb-columnstore-engine

Comment by Kirill Perov [ 2023-12-12 ]

denis0x0D, problem is still reproduced

root@kirillperov-ub22:/home/kirill_perov/5597# bash mock.bash edf_colstore vinci_cs_tracking_t 2000000 > tmp.sql; mariadb edf_colstore < tmp.sql;
bash mock.bash edf_colstore pl_cs_contact_t 500000 > tmp.sql; mariadb edf_colstore < tmp.sql;
bash mock.bash edf_colstore pl_cs_question_t 500000 > tmp.sql; mariadb edf_colstore < tmp.sql;
bash mock.bash edf_colstore pl_cs_org_unit_t 500000 > tmp.sql; mariadb edf_colstore < tmp.sql;
bash mock.bash edf_colstore pl_cs_question_repository_t 500000 > tmp.sql; mariadb edf_colstore < tmp.sql;
bash mock.bash edf_colstore pl_cs_answer_repository_t 500000 > tmp.sql; mariadb edf_colstore < tmp.sql;
bash mock.bash edf_colstore pl_cs_tracking_status_t 500000 > tmp.sql; mariadb edf_colstore < tmp.sql;

root@kirillperov-ub22:/home/kirill_perov/5597#
root@kirillperov-ub22:/home/kirill_perov/5597#
root@kirillperov-ub22:/home/kirill_perov/5597# mariadb edf_colstore < large_query.sql
ERROR 1815 (HY000) at line 1: Internal error: InetStreamSocket::readToMagic: Remote is closed
root@kirillperov-ub22:/home/kirill_perov/5597#

tested with 50% of data

tested on packages taken from
https://cspkg.s3.amazonaws.com/index.html?prefix=develop/pull_request/9289/10.6-enterprise/amd64/ubuntu22.04/
(PR https://github.com/mariadb-corporation/mariadb-columnstore-engine/pull/3061)

Comment by Kirill Perov [ 2023-12-12 ]

problem still reproduced

Comment by Kirill Perov [ 2023-12-13 ]

kirill_perov@kirillperov-ub22:~$ sudo journalctl -f
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:13:03 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), next retry is Wed Dec 13 11:13:33 2023, retry nbr 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:13:15 kirillperov-ub22 sudo[13810]: kirill_perov : TTY=pts/3 ; PWD=/home/kirill_perov ; USER=root ; COMMAND=/usr/bin/journalctl -f
Dec 13 11:13:15 kirillperov-ub22 sudo[13810]: pam_unix(sudo:session): session opened for user root(uid=0) by kirill_perov(uid=66210096)
Dec 13 11:13:26 kirillperov-ub22 systemd[1]: Starting GCE Workload Certificate refresh...
Dec 13 11:13:26 kirillperov-ub22 gce_workload_cert_refresh[13814]: 2023/12/13 11:13:26: Error getting config status, workload certificates may not be configured: HTTP 404
Dec 13 11:13:26 kirillperov-ub22 gce_workload_cert_refresh[13814]: 2023/12/13 11:13:26: Done
Dec 13 11:13:26 kirillperov-ub22 systemd[1]: gce-workload-cert-refresh.service: Deactivated successfully.
Dec 13 11:13:26 kirillperov-ub22 systemd[1]: Finished GCE Workload Certificate refresh.
Dec 13 11:17:02 kirillperov-ub22 kernel: cron invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0
Dec 13 11:17:02 kirillperov-ub22 kernel: CPU: 1 PID: 13824 Comm: cron Not tainted 6.2.0-1019-gcp #21~22.04.1-Ubuntu
Dec 13 11:17:02 kirillperov-ub22 kernel: Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/10/2023
Dec 13 11:17:02 kirillperov-ub22 kernel: Call Trace:
Dec 13 11:17:02 kirillperov-ub22 kernel: <TASK>
Dec 13 11:17:02 kirillperov-ub22 kernel: dump_stack_lvl+0x48/0x70
Dec 13 11:17:02 kirillperov-ub22 kernel: dump_stack+0x10/0x20
Dec 13 11:17:02 kirillperov-ub22 kernel: dump_header+0x50/0x270
Dec 13 11:17:02 kirillperov-ub22 kernel: oom_kill_process+0x10d/0x1c0
Dec 13 11:17:02 kirillperov-ub22 kernel: out_of_memory+0x101/0x370
Dec 13 11:17:02 kirillperov-ub22 kernel: __alloc_pages_may_oom+0x112/0x1e0
Dec 13 11:17:02 kirillperov-ub22 kernel: __alloc_pages_slowpath.constprop.0+0x4c7/0xa00
Dec 13 11:17:02 kirillperov-ub22 kernel: __alloc_pages+0x304/0x330
Dec 13 11:17:02 kirillperov-ub22 kernel: alloc_pages+0x90/0x1a0
Dec 13 11:17:02 kirillperov-ub22 kernel: folio_alloc+0x1d/0x60
Dec 13 11:17:02 kirillperov-ub22 kernel: filemap_alloc_folio+0x31/0x40
Dec 13 11:17:02 kirillperov-ub22 kernel: __filemap_get_folio+0x14f/0x3c0
Dec 13 11:17:02 kirillperov-ub22 kernel: filemap_fault+0x352/0x6e0
Dec 13 11:17:02 kirillperov-ub22 kernel: __do_fault+0x36/0x150
Dec 13 11:17:02 kirillperov-ub22 kernel: do_read_fault+0xef/0x170
Dec 13 11:17:02 kirillperov-ub22 kernel: do_fault+0xa0/0x2f0
Dec 13 11:17:02 kirillperov-ub22 kernel: handle_pte_fault+0x118/0x240
Dec 13 11:17:02 kirillperov-ub22 kernel: __handle_mm_fault+0x661/0x720
Dec 13 11:17:02 kirillperov-ub22 kernel: handle_mm_fault+0x10f/0x320
Dec 13 11:17:02 kirillperov-ub22 kernel: ? lock_mm_and_find_vma+0x43/0x230
Dec 13 11:17:02 kirillperov-ub22 kernel: do_user_addr_fault+0x17f/0x610
Dec 13 11:17:02 kirillperov-ub22 kernel: exc_page_fault+0x80/0x190
Dec 13 11:17:02 kirillperov-ub22 kernel: asm_exc_page_fault+0x27/0x30
Dec 13 11:17:02 kirillperov-ub22 kernel: RIP: 0033:0x7f91bff784e1
Dec 13 11:17:02 kirillperov-ub22 kernel: Code: 8b 4b 68 48 03 41 08 48 89 04 24 48 8b 83 00 03 00 00 48 85 c0 0f 84 ce 00 00 00 48 8b 7c 24 08 8b 4c 24 18 23 8b f8 02 00 00 <48> 8b 04 c8 8b 8b fc 02 00 00 48 89 fe 48 d3 ee 48 89 f1 48 89 c6
Dec 13 11:17:02 kirillperov-ub22 kernel: RSP: 002b:00007fff999a2100 EFLAGS: 00010202
Dec 13 11:17:02 kirillperov-ub22 kernel: RAX: 00007f91bfb27300 RBX: 00005642e19278a0 RCX: 0000000000000016
Dec 13 11:17:02 kirillperov-ub22 kernel: RDX: 0000000000000107 RSI: 0000000000000000 RDI: 00000000102cc5bd
Dec 13 11:17:02 kirillperov-ub22 kernel: RBP: 0000000000000005 R08: 0000000000000001 R09: 00005642e191e3e0
Dec 13 11:17:02 kirillperov-ub22 kernel: R10: 00007f91bfb27c90 R11: 0000000000000000 R12: 0000000000000012
Dec 13 11:17:02 kirillperov-ub22 kernel: R13: 00007f91bff544d0 R14: 00005642e192a258 R15: 0000000000000000
Dec 13 11:17:02 kirillperov-ub22 kernel: </TASK>
Dec 13 11:17:02 kirillperov-ub22 kernel: Mem-Info:
Dec 13 11:17:02 kirillperov-ub22 kernel: active_anon:326 inactive_anon:3933913 isolated_anon:0
active_file:137 inactive_file:0 isolated_file:0
unevictable:6905 dirty:0 writeback:0
slab_reclaimable:15259 slab_unreclaimable:19879
mapped:5374 shmem:15622 pagetables:17144
sec_pagetables:0 bounce:0
kernel_misc_reclaimable:0
free:33084 free_pcp:0 free_cma:0
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 active_anon:1304kB inactive_anon:15735652kB active_file:548kB inactive_file:0kB unevictable:27620kB isolated(anon):0kB isolated(file):0kB mapped:21496kB dirty:0kB writeback:0kB shmem:62488kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB kernel_stack:8256kB pagetables:68576kB sec_pagetables:0kB all_unreclaimable? yes
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 DMA free:13312kB boost:0kB min:60kB low:72kB high:84kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15920kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
Dec 13 11:17:02 kirillperov-ub22 kernel: lowmem_reserve[]: 0 2988 15955 15955 15955
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 DMA32 free:64504kB boost:0kB min:12644kB low:15804kB high:18964kB reserved_highatomic:0KB active_anon:0kB inactive_anon:2985304kB active_file:176kB inactive_file:160kB unevictable:0kB writepending:0kB present:3126072kB managed:3060500kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
Dec 13 11:17:02 kirillperov-ub22 kernel: lowmem_reserve[]: 0 0 12966 12966 12966
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 Normal free:54520kB boost:0kB min:54872kB low:68588kB high:82304kB reserved_highatomic:0KB active_anon:1304kB inactive_anon:12750348kB active_file:96kB inactive_file:104kB unevictable:27620kB writepending:0kB present:13631488kB managed:13286548kB mlocked:27620kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
Dec 13 11:17:02 kirillperov-ub22 kernel: lowmem_reserve[]: 0 0 0 0 0
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 1*1024kB (U) 2*2048kB (UM) 2*4096kB (M) = 13312kB
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 DMA32: 14*4kB (UME) 16*8kB (UME) 80*16kB (UME) 72*32kB (UME) 64*64kB (UME) 50*128kB (UE) 33*256kB (UE) 32*512kB (UE) 15*1024kB (UE) 5*2048kB (UME) 0*4096kB = 64696kB
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 Normal: 262*4kB (UME) 324*8kB (UME) 606*16kB (UME) 555*32kB (UME) 232*64kB (UME) 49*128kB (UME) 9*256kB (ME) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 54520kB
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Dec 13 11:17:02 kirillperov-ub22 kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Dec 13 11:17:02 kirillperov-ub22 kernel: 18102 total pagecache pages
Dec 13 11:17:02 kirillperov-ub22 kernel: 0 pages in swap cache
Dec 13 11:17:02 kirillperov-ub22 kernel: Free swap = 0kB
Dec 13 11:17:02 kirillperov-ub22 kernel: Total swap = 0kB
Dec 13 11:17:02 kirillperov-ub22 kernel: 4193370 pages RAM
Dec 13 11:17:02 kirillperov-ub22 kernel: 0 pages HighMem/MovableOnly
Dec 13 11:17:02 kirillperov-ub22 kernel: 102768 pages reserved
Dec 13 11:17:02 kirillperov-ub22 kernel: 0 pages hwpoisoned
Dec 13 11:17:02 kirillperov-ub22 kernel: Tasks state (memory values in pages):
Dec 13 11:17:02 kirillperov-ub22 kernel: [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 620] 102 620 7298 768 98304 0 -900 dbus-daemon
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 660] 0 660 8270 2460 106496 0 0 networkd-dispat
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 818] 0 818 27524 2336 118784 0 0 unattended-upgr
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 839] 0 839 1543 32 45056 0 0 agetty
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3471] 0 3471 72328 6848 114688 0 -1000 multipathd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3590] 0 3590 456477 2055 258048 0 -999 google_guest_ag
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3596] 0 3596 550454 2262 311296 0 0 google_osconfig
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3618] 0 3618 73995 1600 167936 0 0 packagekitd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3620] 0 3620 1554 512 45056 0 0 agetty
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3623] 0 3623 533116 3339 348160 0 -900 snapd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3641] 0 3641 63665 1421 131072 0 0 polkitd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3651] 0 3651 11973 864 98304 0 -250 systemd-journal
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3662] 113 3662 4729 743 57344 0 0 chronyd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3664] 113 3664 2647 400 57344 0 0 chronyd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3793] 0 3793 2773 1013 65536 0 -1000 systemd-udevd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3848] 100 3848 4061 928 69632 0 0 systemd-network
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3908] 101 3908 6383 1881 90112 0 0 systemd-resolve
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3926] 0 3926 3856 1248 65536 0 -1000 sshd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3957] 0 3957 7685 1248 102400 0 0 systemd-logind
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 3963] 0 3963 1821 640 49152 0 0 cron
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 6326] 104 6326 60457 1440 122880 0 0 rsyslogd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 8342] 114 8342 377878 19221 487424 0 0 mariadbd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 8435] 114 8435 57517 3035 180224 0 0 workernode
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 8444] 114 8444 414073 1173 290816 0 0 controllernode
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 8545] 114 8545 155788 4978 835584 0 0 WriteEngineServ
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 8552] 114 8552 61683 2415 188416 0 0 DMLProc
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 8572] 114 8572 312288 4533 520192 0 0 DDLProc
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 12175] 114 12175 11615825 3863967 63983616 0 0 PrimProc
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13243] 0 13243 8297 1536 102400 0 0 sshd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13248] 66210096 13248 4266 1120 69632 0 0 systemd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13250] 66210096 13250 46230 1663 122880 0 0 (sd-pam)
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13331] 66210096 13331 8341 1361 102400 0 0 sshd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13332] 66210096 13332 7469 1408 98304 0 0 bash
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13470] 66210096 13470 7863 1280 98304 0 0 sudo
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13471] 66210096 13471 7863 792 86016 0 0 sudo
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13472] 0 13472 8719 1430 106496 0 0 mc
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13474] 0 13474 2006 672 53248 0 0 bash
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13663] 0 13663 4983 960 81920 0 0 mariadb
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13713] 0 13713 8296 1568 106496 0 0 sshd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13792] 66210096 13792 8340 1328 106496 0 0 sshd
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13793] 66210096 13793 7469 1440 102400 0 0 bash
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13810] 66210096 13810 7863 1216 102400 0 0 sudo
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13811] 66210096 13811 7863 793 90112 0 0 sudo
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13812] 0 13812 8627 832 90112 0 0 journalctl
Dec 13 11:17:02 kirillperov-ub22 kernel: [ 13824] 0 13824 2366 451 49152 0 0 cron
Dec 13 11:17:02 kirillperov-ub22 kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=cron.service,mems_allowed=0,global_oom,task_memcg=/system.slice/mcs-primproc.service,task=PrimProc,pid=12175,uid=114
Dec 13 11:17:02 kirillperov-ub22 kernel: Out of memory: Killed process 12175 (PrimProc) total-vm:46463300kB, anon-rss:15453692kB, file-rss:2048kB, shmem-rss:128kB, UID:114 pgtables:62484kB oom_score_adj:0
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 systemd[1]: mcs-primproc.service: A process of this unit has been killed by the OOM killer.
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' resumed (module 'builtin:omfile') [v8.2112.0 try https://www.rsyslog.com/e/2359 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 rsyslogd[6326]: action 'action-13-builtin:omfile' suspended (module 'builtin:omfile'), next retry is Wed Dec 13 11:17:32 2023, retry nbr 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Dec 13 11:17:02 kirillperov-ub22 CRON[13824]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Dec 13 11:17:02 kirillperov-ub22 CRON[13825]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Dec 13 11:17:02 kirillperov-ub22 CRON[13824]: pam_unix(cron:session): session closed for user root
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: mcs-primproc.service: Main process exited, code=killed, status=9/KILL
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: mcs-primproc.service: Failed with result 'oom-kill'.
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: mcs-primproc.service: Consumed 6min 17.090s CPU time.
Dec 13 11:17:03 kirillperov-ub22 messagequeue[8342]: 03.219950 |0|0|0| W 31 CAL0000: Client read close socket for InetStreamSocket::readToMagic: Remote is closed %%10%%
Dec 13 11:17:03 kirillperov-ub22 mariadbd[8342]: ClientRotator caught exception: InetStreamSocket::connect: connect() error: Connection refused to: InetStreamSocket: sd: 113 inet: 127.0.0.1 port: 8601
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: mcs-primproc.service: Scheduled restart job, restart counter is at 2.
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: Stopped mcs-primproc.
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: mcs-primproc.service: Consumed 6min 17.090s CPU time.
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: Starting mcs-primproc...
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemory cGroupDefined (from getConfig) 0
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemoryFromProc reading /proc/meminfo
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemory Total mem available (bytes) 16755105792 (GIB) 15
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemory cGroupDefined (from getConfig) 0
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemoryFromProc reading /proc/meminfo
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemory Total mem available (bytes) 16755105792 (GIB) 15
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getFreeMemory : returned from getFreeMemoryFromProc 15831068672 (GIB) 14
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemory cGroupDefined (from getConfig) 0
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemoryFromProc reading /proc/meminfo
Dec 13 11:17:03 kirillperov-ub22 env[13841]: getTotalMemory Total mem available (bytes) 16755105792 (GIB) 15
Dec 13 11:17:03 kirillperov-ub22 env[13841]: Starting PrimitiveServer: st = 1, sq = 10, pw = 128, pq = 10240, nb = 1022650, nt = 32, nc = 1, ra = 512, db = 128, mb = 512, rd = 0, tr = 0, ss = 67108864, bp = 32
Dec 13 11:17:03 kirillperov-ub22 env[13831]: PrimProc main process has started
Dec 13 11:17:03 kirillperov-ub22 systemd[1]: Started mcs-primproc.
Dec 13 11:17:04 kirillperov-ub22 env[13841]: FairThreadPool started 32 thread/-s.
Dec 13 11:17:04 kirillperov-ub22 env[13841]: getTotalMemory cGroupDefined (from getConfig) 0
Dec 13 11:17:04 kirillperov-ub22 env[13841]: getTotalMemoryFromProc reading /proc/meminfo
Dec 13 11:17:04 kirillperov-ub22 env[13841]: getTotalMemory Total mem available (bytes) 16755105792 (GIB) 15
Dec 13 11:17:04 kirillperov-ub22 env[13841]: Starting ExeMgr: st = 50, qs = 20, mx = 95, cf = /etc/columnstore/Columnstore.xml

Comment by Kirill Perov [ 2023-12-14 ]

need more details here:
1) target system parameters
2) accept criteria (amount of data, speed?)
3) where to take sources (develop, packages folder, ?)

Comment by Kirill Perov [ 2023-12-14 ]

need more details here:
1) target system parameters
2) accept criteria (amount of data, speed?)
3) where to take sources (develop, packages folder, ?)

+allen.herrera

Comment by Kirill Perov [ 2023-12-14 ]

query was succeeded on 40% of original data - 1600000/400000
on packages from PR 3061, ubuntu22 16x16
elapsed time about 20 minutes

Generated at Thu Feb 08 11:21:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.