I agree that the bug title is not very creative, but here it is :) srvcn[66062]: segfault at 0 ip 00000000004514f2 sp 00007f30575f4a10 error 6 in slurmctld[400000+df000] # addr2line -e /usr/sbin/slurmctld 00000000004514f2 /root/rpmbuild/BUILD/slurm-17.11.8/src/slurmctld/job_mgr.c:18048 (gdb) bt #0 0x00000000004514f2 in build_job_info_resp (job_ptr=0x3077380) at job_mgr.c:18048 #1 0x000000000048e3ae in _slurm_rpc_job_pack_alloc_info (msg=0x7f30575f4e50) at proc_req.c:3223 #2 slurmctld_req (msg=msg@entry=0x7f30575f4e50, arg=arg@entry=0x7f30bc042350) at proc_req.c:414 #3 0x0000000000424df8 in _service_connection (arg=0x7f30bc042350) at controller.c:1125 #4 0x00007f30dceb9e25 in start_thread () from /lib64/libpthread.so.0 #5 0x00007f30dcbe3bad in clone () from /lib64/libc.so.6 (gdb) p *job_ptr $1 = {account = 0x3077730 "jamesz", admin_comment = 0x0, alias_list = 0x0, alloc_node = 0x3077030 "sh-ln05", alloc_resp_port = 0, alloc_sid = 22850, array_job_id = 0, array_task_id = 4294967294, array_recs = 0x0, assoc_id = 12176, assoc_ptr = 0x221bd10, batch_flag = 1, batch_host = 0x7f30d4124e50 "sh-01-22", billable_tres = 1, bit_flags = 0, burst_buffer = 0x0, burst_buffer_state = 0x0, check_job = 0x0, ckpt_interval = 0, ckpt_time = 0, clusters = 0x0, comment = 0x0, cpu_cnt = 0, cr_enabled = 1, db_index = 421232919, deadline = 0, delay_boot = 0, derived_ec = 15, details = 0x30770b0, direct_set_prio = 0, end_time = 1532660183, end_time_exp = 1532660183, epilog_running = false, exit_code = 0, fed_details = 0x0, front_end_ptr = 0x0, gids = 0x0, gres = 0x0, gres_list = 0x0, gres_alloc = 0x3077750 "", gres_detail_cnt = 0, gres_detail_str = 0x0, gres_req = 0x3077770 "", gres_used = 0x0, group_id = 303878, job_id = 22590777, job_next = 0x2f6e480, job_array_next_j = 0x0, job_array_next_t = 0x0, job_resrcs = 0x7f30d44e6970, job_state = 1, kill_on_node_fail = 1, last_sched_eval = 1532588178, licenses = 0x0, license_list = 0x0, limit_set = {qos = 0, time = 0, tres = 0x3076a20}, mail_type = 0, mail_user = 0x0, magic = 4038539564, mcs_label = 0x0, name = 0x3077000 "tmpr0_m6k7k", network = 0x0, next_step_id = 7, ngids = 0, nodes = 0x7f30d42351c0 "sh-01-22", node_addr = 0x7f30d42c7b70, node_bitmap = 0x7f30d489b0c0, node_bitmap_cg = 0x0, node_cnt = 0, node_cnt_wag = 1, nodes_completing = 0x0, origin_cluster = 0x0, other_port = 0, pack_job_id = 0, pack_job_id_set = 0x0, pack_job_offset = 0, pack_job_list = 0x0, partition = 0x3076e50 "owners", part_ptr_list = 0x0, part_nodes_missing = false, part_ptr = 0x7f3078764ee0, power_flags = 0 '\000', pre_sus_time = 0, preempt_time = 0, preempt_in_progress = false, priority = 471, priority_array = 0x0, prio_factors = 0x3077260, profile = 0, qos_id = 3, qos_ptr = 0x209c5f0, qos_blocking_ptr = 0x0, reboot = 0 '\000', restart_cnt = 7, resize_time = 0, resv_id = 0, resv_name = 0x0, resv_ptr = 0x0, requid = 4294967295, resp_host = 0x0, sched_nodes = 0x0, select_jobinfo = 0x30777c0, spank_job_env = 0x0, spank_job_env_size = 0, start_protocol_ver = 8192, start_time = 1532588178, state_desc = 0x0, state_reason = 0, state_reason_prev = 35, step_list = 0x3059bc0, suspend_time = 0, time_last_active = 1532588178, time_limit = 1200, time_min = 0, tot_sus_time = 5, total_cpus = 1, total_nodes = 1, tres_req_cnt = 0x3077dd0, tres_req_str = 0x3077bd0 "1=1,2=4000,4=1", tres_fmt_req_str = 0x3077c00 "cpu=1,mem=4000M,node=1", tres_alloc_cnt = 0x7f30d44c23f0, tres_alloc_str = 0x7f30d4091120 "1=1,2=4000,3=18446744073709551614,4=1,5=1", tres_fmt_alloc_str = 0x7f30d408da00 "cpu=1,mem=4000M,node=1,billing=1", user_id = 279308, user_name = 0x30772f0 "bryanhe", wait_all_nodes = 0, warn_flags = 0, warn_signal = 0, warn_time = 0, wckey = 0x0, req_switch = 0, wait4switch = 0, best_switch = true, wait4switch_start = 0} (gdb) thread apply all bt full -> output attached Cheers, -- Kilian
Created attachment 7422 [details] GDB output "thread apply all bt full"
Thanks, I'll study the backtrace. How often did this happen? Just once?
Can you run slurmctld with gdb with that core again and do the following: thread 1 frame 0 info locals p *job_ptr p *job_info_resp_msg Thanks. It looks like it might be another job_resrcs==NULL one, which can hopefully be fixed the same way as the others.
Sorry, I just realized you already printed *job_ptr. The other info would be helpful, though.
(In reply to Marshall Garey from comment #2) > Thanks, I'll study the backtrace. How often did this happen? Just once? 6 times in the last week, according to the kernel logs. (In reply to Marshall Garey from comment #3) > Can you run slurmctld with gdb with that core again and do the following: > > thread 1 > frame 0 > info locals > p *job_ptr > p *job_info_resp_msg Sure! Here it is: (gdb) thread 1 [Switching to thread 1 (Thread 0x7f30575f5700 (LWP 66062))] #0 0x00000000004514f2 in build_job_info_resp (job_ptr=0x3077380) at job_mgr.c:18048 18048 in job_mgr.c (gdb) frame 0 #0 0x00000000004514f2 in build_job_info_resp (job_ptr=0x3077380) at job_mgr.c:18048 18048 in job_mgr.c (gdb) info locals job_info_resp_msg = 0x7f305c38d0c0 i = 0 j = 0 __func__ = "build_job_info_resp" (gdb) p *job_ptr $1 = {account = 0x3077730 "jamesz", admin_comment = 0x0, alias_list = 0x0, alloc_node = 0x3077030 "sh-ln05", alloc_resp_port = 0, alloc_sid = 22850, array_job_id = 0, array_task_id = 4294967294, array_recs = 0x0, assoc_id = 12176, assoc_ptr = 0x221bd10, batch_flag = 1, batch_host = 0x7f30d4124e50 "sh-01-22", billable_tres = 1, bit_flags = 0, burst_buffer = 0x0, burst_buffer_state = 0x0, check_job = 0x0, ckpt_interval = 0, ckpt_time = 0, clusters = 0x0, comment = 0x0, cpu_cnt = 0, cr_enabled = 1, db_index = 421232919, deadline = 0, delay_boot = 0, derived_ec = 15, details = 0x30770b0, direct_set_prio = 0, end_time = 1532660183, end_time_exp = 1532660183, epilog_running = false, exit_code = 0, fed_details = 0x0, front_end_ptr = 0x0, gids = 0x0, gres = 0x0, gres_list = 0x0, gres_alloc = 0x3077750 "", gres_detail_cnt = 0, gres_detail_str = 0x0, gres_req = 0x3077770 "", gres_used = 0x0, group_id = 303878, job_id = 22590777, job_next = 0x2f6e480, job_array_next_j = 0x0, job_array_next_t = 0x0, job_resrcs = 0x7f30d44e6970, job_state = 1, kill_on_node_fail = 1, last_sched_eval = 1532588178, licenses = 0x0, license_list = 0x0, limit_set = {qos = 0, time = 0, tres = 0x3076a20}, mail_type = 0, mail_user = 0x0, magic = 4038539564, mcs_label = 0x0, name = 0x3077000 "tmpr0_m6k7k", network = 0x0, next_step_id = 7, ngids = 0, nodes = 0x7f30d42351c0 "sh-01-22", node_addr = 0x7f30d42c7b70, node_bitmap = 0x7f30d489b0c0, node_bitmap_cg = 0x0, node_cnt = 0, node_cnt_wag = 1, nodes_completing = 0x0, origin_cluster = 0x0, other_port = 0, pack_job_id = 0, pack_job_id_set = 0x0, pack_job_offset = 0, pack_job_list = 0x0, partition = 0x3076e50 "owners", part_ptr_list = 0x0, part_nodes_missing = false, part_ptr = 0x7f3078764ee0, power_flags = 0 '\000', pre_sus_time = 0, preempt_time = 0, preempt_in_progress = false, priority = 471, priority_array = 0x0, prio_factors = 0x3077260, profile = 0, qos_id = 3, qos_ptr = 0x209c5f0, qos_blocking_ptr = 0x0, reboot = 0 '\000', restart_cnt = 7, resize_time = 0, resv_id = 0, resv_name = 0x0, resv_ptr = 0x0, requid = 4294967295, resp_host = 0x0, sched_nodes = 0x0, select_jobinfo = 0x30777c0, spank_job_env = 0x0, spank_job_env_size = 0, start_protocol_ver = 8192, start_time = 1532588178, state_desc = 0x0, state_reason = 0, state_reason_prev = 35, step_list = 0x3059bc0, suspend_time = 0, time_last_active = 1532588178, time_limit = 1200, time_min = 0, tot_sus_time = 5, total_cpus = 1, total_nodes = 1, tres_req_cnt = 0x3077dd0, tres_req_str = 0x3077bd0 "1=1,2=4000,4=1", tres_fmt_req_str = 0x3077c00 "cpu=1,mem=4000M,node=1", tres_alloc_cnt = 0x7f30d44c23f0, tres_alloc_str = 0x7f30d4091120 "1=1,2=4000,3=18446744073709551614,4=1,5=1", tres_fmt_alloc_str = 0x7f30d408da00 "cpu=1,mem=4000M,node=1,billing=1", user_id = 279308, user_name = 0x30772f0 "bryanhe", wait_all_nodes = 0, warn_flags = 0, warn_signal = 0, warn_time = 0, wckey = 0x0, req_switch = 0, wait4switch = 0, best_switch = true, wait4switch_start = 0} (gdb) p *job_info_resp_msg $2 = {account = 0x0, job_id = 0, alias_list = 0x0, cpu_freq_min = 0, cpu_freq_max = 0, cpu_freq_gov = 0, cpus_per_node = 0x0, cpu_count_reps = 0x0, env_size = 0, environment = 0x0, error_code = 0, job_submit_user_msg = 0x0, node_addr = 0x0, node_cnt = 0, node_list = 0x0, ntasks_per_board = 0, ntasks_per_core = 0, ntasks_per_socket = 0, num_cpu_groups = 0, partition = 0x0, pn_min_memory = 0, qos = 0x0, resv_name = 0x0, select_jobinfo = 0x0, working_cluster_rec = 0x0}
Thanks. Clearly the job_ptr got corrupted somehow, since job_ptr->node_cnt == 0 and job_ptr->cpu_cnt == 0, which meant that job_info_resp_msg got malloced to a size of 0 and caused the segfault here. Can you also get this from gdb? p job_ptr->job_resrcs p bit_set_count(job_ptr->node_bitmap) p bit_set_count(job_ptr->job_resrcs->node_bitmap) Can you make sure to save the slurmctld binary and core dump? I know this is a different symptom than the other segfault, but I suspect it's either the same or very similar cause.
(In reply to Marshall Garey from comment #6) > Thanks. Clearly the job_ptr got corrupted somehow, since job_ptr->node_cnt > == 0 and job_ptr->cpu_cnt == 0, which meant that job_info_resp_msg got > malloced to a size of 0 and caused the segfault here. To put that back into context, we're restarting slurmctld pretty often these days, because of https://bugs.schedmd.com/show_bug.cgi?id=5443 > Can you also get this from gdb? > > p job_ptr->job_resrcs > p bit_set_count(job_ptr->node_bitmap) > p bit_set_count(job_ptr->job_resrcs->node_bitmap) Just the first one, gdb doesn't like the last two: (gdb) p job_ptr->job_resrcs $7 = (job_resources_t *) 0x7f30d44e6970 (gdb) p bit_set_count(job_ptr->node_bitmap) You can't do that without a process to debug. (gdb) p bit_set_count(job_ptr->job_resrcs->node_bitmap) You can't do that without a process to debug. > > Can you make sure to save the slurmctld binary and core dump? > > I know this is a different symptom than the other segfault, but I suspect > it's either the same or very similar cause. Sure, will save the binary and dump. Do you want them? Cheers, -- Kilian
(In reply to Kilian Cavalotti from comment #7) > (gdb) p job_ptr->job_resrcs > $7 = (job_resources_t *) 0x7f30d44e6970 Sorry, typo on my part. I meant to dereference that. Can you get that again, with the dereference? p *job_ptr->job_resrcs > (gdb) p bit_set_count(job_ptr->node_bitmap) > You can't do that without a process to debug. > (gdb) p bit_set_count(job_ptr->job_resrcs->node_bitmap) > You can't do that without a process to debug. Right, my mistake, that makes sense. > > > > Can you make sure to save the slurmctld binary and core dump? > > > > I know this is a different symptom than the other segfault, but I suspect > > it's either the same or very similar cause. > > Sure, will save the binary and dump. Do you want them? No, they aren't useful for us without the same libraries/OS/etc. Thanks - Marshall
(In reply to Marshall Garey from comment #8) > (In reply to Kilian Cavalotti from comment #7) > > (gdb) p job_ptr->job_resrcs > > $7 = (job_resources_t *) 0x7f30d44e6970 > > Sorry, typo on my part. I meant to dereference that. Can you get that again, > with the dereference? > > p *job_ptr->job_resrcs (gdb) p *job_ptr->job_resrcs $8 = {core_bitmap = 0x7f30d422fe10, core_bitmap_used = 0x7f30d499d1b0, cpu_array_cnt = 1, cpu_array_value = 0x7f30d4073100, cpu_array_reps = 0x7f30d4275ee0, cpus = 0x7f30d4072c80, cpus_used = 0x7f30d406d000, cores_per_socket = 0x7f30d46a2f40, memory_allocated = 0x7f30d407f8a0, memory_used = 0x7f30d41dbed0, nhosts = 1, node_bitmap = 0x7f30d4899580, node_req = 1, nodes = 0x7f30d4d0a2e0 "sh-01-22", ncpus = 1, sock_core_rep_count = 0x7f30d47a6c00, sockets_per_node = 0x7f30d4094fe0, whole_node = 0 '\000'} Thanks! -- Kilian
Created attachment 7446 [details] log error before segfault That's interesting, thanks. I know you're testing the job_resrcs patch (bug 5438) right now. I'd like to know if that fixes this problem, too. So I've attached a patch which just prints an error message right before it would segfault. It still lets the slurmctld segfault rather than bailing or trying to fix the job_ptr, since I'm not sure what the effects of that would be yet, restarting your slurmctld seems to make it fine, and I want to know if it segfaults anymore. Can you apply this patch locally report if you see any of this error message while you're also testing the patch from bug 5438? The reason I think 5438 might have something to do with it is that bug causes node_cnt==0 when it shouldn't, which is the problem in this bug.
Hi Marshall, (In reply to Marshall Garey from comment #10) > I know you're testing the job_resrcs patch (bug 5438) right now. I'd like to > know if that fixes this problem, too. So I've attached a patch which just > prints an error message right before it would segfault. It still lets the > slurmctld segfault rather than bailing or trying to fix the job_ptr, since > I'm not sure what the effects of that would be yet, restarting your > slurmctld seems to make it fine, and I want to know if it segfaults anymore. > Can you apply this patch locally report if you see any of this error message > while you're also testing the patch from bug 5438? Sure. Patch applied, I'll check the logs and report back. Thanks! -- Kilian
(In reply to Kilian Cavalotti from comment #11) > Sure. Patch applied, I'll check the logs and report back. It just crashed after a restart, trying to recover from with the following message logged: Jul 29 16:10:59 sh-sl01 slurmctld[126964]: _job_complete: JobID=22902449_383(22905080) State=0x8003 NodeCnt=1 done Jul 29 16:10:59 sh-sl01 slurmctld[126964]: prolog_running_decr: Configuration for JobID=22903014_276(22905501) is complete Jul 29 16:10:59 sh-sl01 slurmctld[126964]: error: WARNING: job_ptr node_cnt == 0, cpu_cnt == 0, these should never be zero here! slurmctld is about to segfault. Jul 29 16:10:59 sh-sl01 kernel: srvcn[79751]: segfault at 0 ip 0000000000451726 sp 00007f4f528e7a10 error 6 in slurmctld[400000+df000] I have the core dump saved, same bt: (gdb) bt #0 0x0000000000451726 in build_job_info_resp (job_ptr=0x55007c0) at job_mgr.c:18053 #1 0x000000000048e5de in _slurm_rpc_job_pack_alloc_info (msg=0x7f4f528e7e50) at proc_req.c:3223 #2 slurmctld_req (msg=msg@entry=0x7f4f528e7e50, arg=arg@entry=0x7f4eac010760) at proc_req.c:414 #3 0x0000000000424fe8 in _service_connection (arg=0x7f4eac010760) at controller.c:1125 #4 0x00007f4f668cae25 in start_thread () from /lib64/libpthread.so.0 #5 0x00007f4f665f4bad in clone () from /lib64/libc.so.6
(In reply to Kilian Cavalotti from comment #12) > It just crashed after a restart, trying to recover from > with the following message logged: > > Jul 29 16:10:59 sh-sl01 slurmctld[126964]: _job_complete: > JobID=22902449_383(22905080) State=0x8003 NodeCnt=1 done > Jul 29 16:10:59 sh-sl01 slurmctld[126964]: prolog_running_decr: > Configuration for JobID=22903014_276(22905501) is complete > Jul 29 16:10:59 sh-sl01 slurmctld[126964]: error: WARNING: job_ptr node_cnt > == 0, cpu_cnt == 0, these should never be zero here! slurmctld is about to > segfault. > Jul 29 16:10:59 sh-sl01 kernel: srvcn[79751]: segfault at 0 ip > 0000000000451726 sp 00007f4f528e7a10 error 6 in slurmctld[400000+df000] Thank you for that. It's interesting that it crashed *after* a restart. Can you upload a complete slurmctld log file for the day leading up to the crash? I think that will help me understand a more complete context of what's going on. Since you've already uploaded a complete log to bug 5443 that almost reaches the crash, can you get the remainder of the log up to the crash and upload it here? (I've CC'd myself on 5443 since I wouldn't be surprised if that's related.) Thanks. - Marshall
(In reply to Marshall Garey from comment #13) > (In reply to Kilian Cavalotti from comment #12) > > It just crashed after a restart, trying to recover from Paste didn't work, I meant recover from https://bugs.schedmd.com/show_bug.cgi?id=5443 > > with the following message logged: > > > > Jul 29 16:10:59 sh-sl01 slurmctld[126964]: _job_complete: > > JobID=22902449_383(22905080) State=0x8003 NodeCnt=1 done > > Jul 29 16:10:59 sh-sl01 slurmctld[126964]: prolog_running_decr: > > Configuration for JobID=22903014_276(22905501) is complete > > Jul 29 16:10:59 sh-sl01 slurmctld[126964]: error: WARNING: job_ptr node_cnt > > == 0, cpu_cnt == 0, these should never be zero here! slurmctld is about to > > segfault. > > Jul 29 16:10:59 sh-sl01 kernel: srvcn[79751]: segfault at 0 ip > > 0000000000451726 sp 00007f4f528e7a10 error 6 in slurmctld[400000+df000] > > Thank you for that. It's interesting that it crashed *after* a restart. Yes, it's weird to me too, unless the job structure gets truncated during the restart (which is a clean one, via a "service systemctl restart" command). But if it's corrupted during the accumulation of CG jobs, one could think it would segfault right away, indeed. > Can > you upload a complete slurmctld log file for the day leading up to the > crash? I think that will help me understand a more complete context of > what's going on. > Since you've already uploaded a complete log to bug 5443 that almost reaches > the crash, can you get the remainder of the log up to the crash and upload > it here? (I've CC'd myself on 5443 since I wouldn't be surprised if that's > related.) Sure, coming up. Full slurmctld log from the primary controller, starting at around 3:30am. Restart happens at 15:48 and the segfault at 16:10. Thanks! -- Kilian
Created attachment 7456 [details] slurmctld log
If you still have the slurmctld binary saved from the dump in comment 12, can you run gdb with the core file and print the job ptr? p *job_ptr I'm mainly interested in the job id, though the additional information would be nice too. I forgot to print out the job id in the error message I added in. I'd like to use the job id so I can look for references to it in the slurmctld log file. Thanks - Marshall
Hi Marshall, (In reply to Marshall Garey from comment #19) > If you still have the slurmctld binary saved from the dump in comment 12, > can you run gdb with the core file and print the job ptr? Sure, here it is: (gdb) p *job_ptr $1 = {account = 0x3077730 "jamesz", admin_comment = 0x0, alias_list = 0x0, alloc_node = 0x3077030 "sh-ln05", alloc_resp_port = 0, alloc_sid = 22850, array_job_id = 0, array_task_id = 4294967294, array_recs = 0x0, assoc_id = 12176, assoc_ptr = 0x221bd10, batch_flag = 1, batch_host = 0x7f30d4124e50 "sh-01-22", billable_tres = 1, bit_flags = 0, burst_buffer = 0x0, burst_buffer_state = 0x0, check_job = 0x0, ckpt_interval = 0, ckpt_time = 0, clusters = 0x0, comment = 0x0, cpu_cnt = 0, cr_enabled = 1, db_index = 421232919, deadline = 0, delay_boot = 0, derived_ec = 15, details = 0x30770b0, direct_set_prio = 0, end_time = 1532660183, end_time_exp = 1532660183, epilog_running = false, exit_code = 0, fed_details = 0x0, front_end_ptr = 0x0, gids = 0x0, gres = 0x0, gres_list = 0x0, gres_alloc = 0x3077750 "", gres_detail_cnt = 0, gres_detail_str = 0x0, gres_req = 0x3077770 "", gres_used = 0x0, group_id = 303878, job_id = 22590777, job_next = 0x2f6e480, job_array_next_j = 0x0, job_array_next_t = 0x0, job_resrcs = 0x7f30d44e6970, job_state = 1, kill_on_node_fail = 1, last_sched_eval = 1532588178, licenses = 0x0, license_list = 0x0, limit_set = {qos = 0, time = 0, tres = 0x3076a20}, mail_type = 0, mail_user = 0x0, magic = 4038539564, mcs_label = 0x0, name = 0x3077000 "tmpr0_m6k7k", network = 0x0, next_step_id = 7, ngids = 0, nodes = 0x7f30d42351c0 "sh-01-22", node_addr = 0x7f30d42c7b70, node_bitmap = 0x7f30d489b0c0, node_bitmap_cg = 0x0, node_cnt = 0, node_cnt_wag = 1, nodes_completing = 0x0, origin_cluster = 0x0, other_port = 0, pack_job_id = 0, pack_job_id_set = 0x0, pack_job_offset = 0, pack_job_list = 0x0, partition = 0x3076e50 "owners", part_ptr_list = 0x0, part_nodes_missing = false, part_ptr = 0x7f3078764ee0, power_flags = 0 '\000', pre_sus_time = 0, preempt_time = 0, preempt_in_progress = false, priority = 471, priority_array = 0x0, prio_factors = 0x3077260, profile = 0, qos_id = 3, qos_ptr = 0x209c5f0, qos_blocking_ptr = 0x0, reboot = 0 '\000', restart_cnt = 7, resize_time = 0, resv_id = 0, resv_name = 0x0, resv_ptr = 0x0, requid = 4294967295, resp_host = 0x0, sched_nodes = 0x0, select_jobinfo = 0x30777c0, spank_job_env = 0x0, spank_job_env_size = 0, start_protocol_ver = 8192, start_time = 1532588178, state_desc = 0x0, state_reason = 0, state_reason_prev = 35, step_list = 0x3059bc0, suspend_time = 0, time_last_active = 1532588178, time_limit = 1200, time_min = 0, tot_sus_time = 5, total_cpus = 1, total_nodes = 1, tres_req_cnt = 0x3077dd0, tres_req_str = 0x3077bd0 "1=1,2=4000,4=1", tres_fmt_req_str = 0x3077c00 "cpu=1,mem=4000M,node=1", tres_alloc_cnt = 0x7f30d44c23f0, tres_alloc_str = 0x7f30d4091120 "1=1,2=4000,3=18446744073709551614,4=1,5=1", tres_fmt_alloc_str = 0x7f30d408da00 "cpu=1,mem=4000M,node=1,billing=1", user_id = 279308, user_name = 0x30772f0 "bryanhe", wait_all_nodes = 0, warn_flags = 0, warn_signal = 0, warn_time = 0, wckey = 0x0, req_switch = 0, wait4switch = 0, best_switch = true, wait4switch_start = 0} Let me know if you need anything else. Cheers, -- Kilian
Thanks. Actually - that job id (22590777) isn't in this log. The start time was July 26. Can you grep for the job id in the slurmctld logs with a couple lines before and after (-a2 -b2 flags for grep), and upload that here in a file? Thanks. - Marshall
Created attachment 7473 [details] slurmctld logs around job 22590777 Here it is.
I'm interested to see what the database has to say about this job. Can you upload the output of this command? sacct -D -j 22590777 --format=jobid,partition,account,state,exitcode,alloctres%40,start,end,ncpus,alloccpus,nnodes,allocnodes,nodelist I understand that several of those fields seem like duplicates - I'm interested to see if there are any discrepancies. Something I found interesting about the job is that it appears to have completed (for the last time) on July 28, but the job caused the slurmctld to segfault a whole day later on July 29. It's also interesting that the job's nodes field (nodes = 0x7f30d42351c0 "sh-01-22",) is not the last node that it ran on, nor is it the first. Also that the job state is running from the gdb output, but slurmctld clearly shows that it completed and was in a completed state (0x8003 == COMPLETE|COMPLETING) Thanks. - Marshall
(In reply to Marshall Garey from comment #28) > I'm interested to see what the database has to say about this job. Can you > upload the output of this command? > > sacct -D -j 22590777 > --format=jobid,partition,account,state,exitcode,alloctres%40,start,end,ncpus, > alloccpus,nnodes,allocnodes,nodelist Sure! JobID Partition Account State ExitCode AllocTRES Start End NCPUS AllocCPUS NNodes AllocNodes NodeList ------------ ---------- ---------- ---------- -------- ---------------------------------------- ------------------- ------------------- ---------- ---------- -------- ---------- --------------- 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-23T16:01:21 2018-07-24T10:25:35 1 1 1 1 sh-07-20 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-23T16:01:21 2018-07-24T10:33:06 1 1 1 1 sh-07-20 22590777.0 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-23T16:01:38 2018-07-24T10:33:06 1 1 1 1 sh-07-20 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-24T10:38:56 2018-07-24T21:25:00 1 1 1 1 sh-26-11 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-24T10:38:56 2018-07-24T21:25:11 1 1 1 1 sh-26-11 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-24T10:38:56 2018-07-24T21:25:11 1 1 1 1 sh-26-11 22590777.1 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-24T10:48:20 2018-07-24T21:25:11 1 1 1 1 sh-26-11 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-24T21:30:31 2018-07-24T21:52:26 1 1 1 1 sh-107-25 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-24T21:30:31 2018-07-24T21:52:30 1 1 1 1 sh-107-25 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-24T21:30:31 2018-07-24T21:52:29 1 1 1 1 sh-107-25 22590777.2 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-24T21:30:35 2018-07-24T21:52:30 1 1 1 1 sh-107-25 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-24T21:56:30 2018-07-25T08:42:30 1 1 1 1 sh-01-03 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-24T21:56:30 2018-07-25T08:42:38 1 1 1 1 sh-01-03 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-24T21:56:30 2018-07-25T08:42:36 1 1 1 1 sh-01-03 22590777.3 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-24T21:56:49 2018-07-25T08:42:38 1 1 1 1 sh-01-03 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T08:47:19 2018-07-25T10:14:21 1 1 1 1 sh-18-23 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-25T08:47:19 2018-07-25T10:14:28 1 1 1 1 sh-18-23 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T08:47:19 2018-07-25T10:14:26 1 1 1 1 sh-18-23 22590777.4 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-25T08:47:22 2018-07-25T10:14:26 1 1 1 1 sh-18-23 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T10:20:48 2018-07-25T15:44:16 1 1 1 1 sh-31-04 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-25T10:20:48 2018-07-25T15:44:21 1 1 1 1 sh-31-04 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T10:20:48 2018-07-25T15:44:19 1 1 1 1 sh-31-04 22590777.5 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-25T10:20:53 2018-07-25T15:44:21 1 1 1 1 sh-31-04 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T17:42:41 2018-07-25T23:40:49 1 1 1 1 sh-01-22 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T17:42:41 2018-07-25T23:52:32 1 1 1 1 sh-01-22 22590777.6 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-25T17:43:12 2018-07-25T23:52:32 1 1 1 1 sh-01-22 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T23:56:18 2018-07-26T07:27:41 1 1 1 1 sh-01-22 22590777.ex+ jamesz CANCELLED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T23:56:18 2018-07-25T23:56:53 1 1 1 1 sh-01-22 22590777 owners jamesz NODE_FAIL 1:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T09:11:49 2018-07-26T09:13:26 1 1 1 1 sh-27-19 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T09:11:49 2018-07-26T09:17:09 1 1 1 1 sh-27-19 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T09:22:41 2018-07-26T09:44:17 1 1 1 1 sh-08-29 22590777.ex+ jamesz CANCELLED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T09:22:41 2018-07-26T09:52:25 1 1 1 1 sh-08-29 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T09:57:30 2018-07-26T11:06:27 1 1 1 1 sh-30-12 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-26T09:57:30 2018-07-26T11:06:32 1 1 1 1 sh-30-12 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T09:57:30 2018-07-26T11:06:32 1 1 1 1 sh-30-12 22590777.7 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-26T09:57:52 2018-07-26T11:06:32 1 1 1 1 sh-30-12 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T12:33:01 2018-07-26T18:57:59 1 1 1 1 sh-27-10 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-26T12:33:01 2018-07-26T18:58:23 1 1 1 1 sh-27-10 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T12:33:01 2018-07-26T18:58:20 1 1 1 1 sh-27-10 22590777.8 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-26T12:33:12 2018-07-26T18:58:23 1 1 1 1 sh-27-10 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T20:02:12 2018-07-26T22:07:09 1 1 1 1 sh-27-23 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-26T20:02:12 2018-07-26T22:07:12 1 1 1 1 sh-27-23 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-26T20:02:12 2018-07-26T22:07:10 1 1 1 1 sh-27-23 22590777.9 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-26T20:02:19 2018-07-26T22:07:12 1 1 1 1 sh-27-23 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T04:56:11 2018-07-27T08:31:49 1 1 1 1 sh-27-08 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T04:56:11 2018-07-27T08:31:57 1 1 1 1 sh-27-08 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T04:56:11 2018-07-27T08:31:57 1 1 1 1 sh-27-08 22590777.10 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T04:56:31 2018-07-27T08:31:57 1 1 1 1 sh-27-08 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T12:15:14 2018-07-27T12:15:18 1 1 1 1 sh-18-22 22590777.ex+ jamesz CANCELLED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T12:15:14 2018-07-27T12:16:02 1 1 1 1 sh-18-22 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T12:27:15 2018-07-27T12:44:04 1 1 1 1 sh-30-25 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T12:27:15 2018-07-27T12:44:18 1 1 1 1 sh-30-25 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T12:27:15 2018-07-27T12:44:16 1 1 1 1 sh-30-25 22590777.11 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T12:27:48 2018-07-27T12:44:18 1 1 1 1 sh-30-25 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T13:21:51 2018-07-27T18:33:18 1 1 1 1 sh-30-25 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T13:21:51 2018-07-27T18:33:28 1 1 1 1 sh-30-25 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T13:21:51 2018-07-27T18:33:27 1 1 1 1 sh-30-25 22590777.12 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T13:22:10 2018-07-27T18:33:27 1 1 1 1 sh-30-25 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T19:58:35 2018-07-27T22:06:21 1 1 1 1 sh-30-36 22590777.ba+ jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T19:58:35 2018-07-27T22:06:28 1 1 1 1 sh-30-36 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T19:58:35 2018-07-27T22:06:27 1 1 1 1 sh-30-36 22590777.13 jamesz CANCELLED 0:15 cpu=1,mem=4000M,node=1 2018-07-27T19:58:58 2018-07-27T22:06:27 1 1 1 1 sh-30-36 22590777 owners jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T22:22:05 2018-07-28T14:55:52 1 1 1 1 sh-20-10 22590777.ba+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1 2018-07-27T22:22:05 2018-07-28T14:55:52 1 1 1 1 sh-20-10 22590777.ex+ jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-27T22:22:05 2018-07-28T14:55:59 1 1 1 1 sh-20-10 22590777.14 jamesz COMPLETED 0:0 cpu=1,mem=4000M,node=1 2018-07-27T22:22:17 2018-07-28T14:55:52 1 1 1 1 sh-20-10 Cheers, -- Kilian
Thanks, that's really helpful. It appears that the job that caused the segfault wasn't the last instance of this job. I believe it was this instance of the job: 22590777 owners jamesz PREEMPTED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T23:56:18 2018-07-26T07:27:41 1 1 1 1 sh-01-22 22590777.ex+ jamesz CANCELLED 0:0 cpu=1,mem=4000M,node=1,billing=1 2018-07-25T23:56:18 2018-07-25T23:56:53 1 1 1 1 sh-01-22 The start time and node match the gdb output. Can you grep for 22590777 (with a couple lines before and after) in the slurmd log for node sh-01-22 and attach that as a file? It would be interesting to know what happened to the job on the node.
(In reply to Marshall Garey from comment #30) > Thanks, that's really helpful. It appears that the job that caused the > segfault wasn't the last instance of this job. I believe it was this > instance of the job: > > 22590777 owners jamesz PREEMPTED 0:0 > cpu=1,mem=4000M,node=1,billing=1 2018-07-25T23:56:18 2018-07-26T07:27:41 > 1 1 1 1 sh-01-22 > 22590777.ex+ jamesz CANCELLED 0:0 > cpu=1,mem=4000M,node=1,billing=1 2018-07-25T23:56:18 2018-07-25T23:56:53 > 1 1 1 1 sh-01-22 > > > The start time and node match the gdb output. > > Can you grep for 22590777 (with a couple lines before and after) in the > slurmd log for node sh-01-22 and attach that as a file? It would be > interesting to know what happened to the job on the node. Sure, that's what I got: /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 10:35:51 sh-01-22 slurmstepd[18224]: task/cgroup: /slurm/uid_254620/job_22680775/step_extern: alloc=10000MB mem.limit=10000MB memsw.limit=10000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 10:35:51 sh-01-22 slurmd[19067]: Launching batch job 22680775 for UID 254620 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 10:35:51 sh-01-22 slurmstepd[18260]: task/cgroup: /slurm/uid_254620/job_22680775: alloc=10000MB mem.limit=10000MB memsw.limit=10000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 10:35:51 sh-01-22 slurmstepd[18260]: task/cgroup: /slurm/uid_254620/job_22680775/step_batch: alloc=10000MB mem.limit=10000MB memsw.limit=10000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 16:52:30 sh-01-22 slurmd[19067]: Message aggregation enabled: WindowMsgs=50, WindowTime=300 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 16:52:30 sh-01-22 slurmd[19067]: error: _find_node_record(751): lookup failure for sh-115-05 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 16:52:30 sh-01-22 slurmd[19067]: error: _find_node_record(763): lookup failure for sh-115-05 alias sh-115-05 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 16:52:30 sh-01-22 slurmd[19067]: error: WARNING: Invalid hostnames in switch configuration: sh-115-05 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 16:52:30 sh-01-22 slurmd[19067]: TOPOLOGY: warning -- no switch can reach all nodes through its descendants.Do not use route/topology /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmd[19067]: _run_prolog: run job script took usec=38608 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmd[19067]: _run_prolog: prolog with lock for job 22590777 ran for 0 seconds /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmstepd[45008]: task/cgroup: /slurm/uid_279308/job_22590777: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmstepd[45008]: task/cgroup: /slurm/uid_279308/job_22590777/step_extern: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmd[19067]: Launching batch job 22590777 for UID 279308 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmstepd[45023]: task/cgroup: /slurm/uid_279308/job_22590777: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmstepd[45023]: task/cgroup: /slurm/uid_279308/job_22590777/step_batch: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmd[19067]: launch task 22590777.6 request from 279308.303878@10.10.1.22 (port 61148) /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmstepd[45097]: task/cgroup: /slurm/uid_279308/job_22590777: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 17:43:12 sh-01-22 slurmstepd[45097]: task/cgroup: /slurm/uid_279308/job_22590777/step_6: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:30 sh-01-22 slurmstepd[45023]: error: *** JOB 22590777 ON sh-01-22 CANCELLED AT 2018-07-25T23:52:30 DUE TO PREEMPTION *** /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:30 sh-01-22 slurmstepd[45097]: error: *** STEP 22590777.6 ON sh-01-22 CANCELLED AT 2018-07-25T23:52:30 DUE TO PREEMPTION *** /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:30 sh-01-22 slurmstepd[45008]: _oom_event_monitor: oom-kill event count: 1 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:30 sh-01-22 slurmstepd[45097]: error: Failed to send MESSAGE_TASK_EXIT: Connection refused /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:31 sh-01-22 slurmstepd[45023]: sending REQUEST_COMPLETE_BATCH_SCRIPT, error:0 status 15 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:31 sh-01-22 slurmstepd[45023]: done with job /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:32 sh-01-22 slurmstepd[45008]: done with job /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 25 23:52:32 sh-01-22 slurmstepd[45097]: done with job /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 00:01:56 sh-01-22 slurmd[19067]: reissued job credential for job 22590777 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 00:01:56 sh-01-22 slurmd[19067]: Launching batch job 22590777 for UID 279308 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 00:01:56 sh-01-22 slurmstepd[14455]: task/cgroup: /slurm/uid_279308/job_22590777: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 00:01:56 sh-01-22 slurmstepd[14455]: task/cgroup: /slurm/uid_279308/job_22590777/step_batch: alloc=4000MB mem.limit=4000MB memsw.limit=4000MB /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 00:02:11 sh-01-22 slurmstepd[14455]: sending REQUEST_COMPLETE_BATCH_SCRIPT, error:0 status 256 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 00:02:11 sh-01-22 slurmstepd[14455]: done with job /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:46 sh-01-22 slurmstepd[17646]: error: *** JOB 22680774 ON sh-01-22 CANCELLED AT 2018-07-26T09:09:46 DUE TO JOB REQUEUE *** /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:46 sh-01-22 slurmstepd[17618]: _oom_event_monitor: oom-kill event count: 1 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:47 sh-01-22 slurmstepd[18260]: error: *** JOB 22680775 ON sh-01-22 CANCELLED AT 2018-07-26T09:09:47 DUE TO JOB REQUEUE *** /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:47 sh-01-22 slurmstepd[18224]: _oom_event_monitor: oom-kill event count: 1 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:48 sh-01-22 slurmstepd[17646]: sending REQUEST_COMPLETE_BATCH_SCRIPT, error:0 status 15 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:48 sh-01-22 slurmstepd[17646]: done with job /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:48 sh-01-22 slurmstepd[18260]: sending REQUEST_COMPLETE_BATCH_SCRIPT, error:0 status 15 /var/log/slurm/d/archives/sh-01-22.log-20180729.gz:Jul 26 09:09:48 sh-01-22 slurmstepd[18260]: done with job
Kilian, I just wanted to give you an update. I haven't yet been able to identify why/how the job got corrupted and thus caused a segfault, but I have at least worked on something to prevent it from segfaulting. I've added Tim to CC so we can talk about it internally and see if we can come up with a patch that we're comfortable giving you to put in a production build, whether or not we decide to push it to github. Do you know if you've hit this particular segfault again? I understand you've been bogged down by a lot of other things (in particular 5443).
Hi Marshall, (In reply to Marshall Garey from comment #37) > Kilian, I just wanted to give you an update. I haven't yet been able to > identify why/how the job got corrupted and thus caused a segfault, but I > have at least worked on something to prevent it from segfaulting. I've added > Tim to CC so we can talk about it internally and see if we can come up with > a patch that we're comfortable giving you to put in a production build, > whether or not we decide to push it to github. I appreciate the update, thank you! > Do you know if you've hit this particular segfault again? I understand > you've been bogged down by a lot of other things (in particular 5443). It doesn't look like this particular segfault occurred recently again. The last occurrence appears to have been on July 30th. I'll definitely let you know if it hits again. Cheers, -- Kilian
Hi Kilian, I've continued doing more research on this, and I have still failed to reproduce it or find out why it happened in the first place. Because it happened at the same time as several other problems which were fixed (such as that job_resrcs segfault), I'm not actually sure if one of those patches fixed this bug or not. I did implement something that would sidestep this segfault and just throw an error message instead. Tim and I talked about it. Tim is of the opinion that even though segfaults are really bad, dumping a core and getting a backtrace is usually the only chance we have to fix the problem, though he acknowledged that you disagree. I'm on the fence. Because you haven't seen it for the past two months, I'm inclined to close this as "cannotreproduce" (yes, we made a new close reason). What do you think? If you decide it's fine to close this out, if you do hit this segfault again, definitely re-open the bug. (By the way - work has been done for 5443 to try to optimize the agent queue, though nothing has been committed yet.) Regards, - Marshall
Hi Marshall, (In reply to Marshall Garey from comment #45) > I've continued doing more research on this, and I have still failed to > reproduce it or find out why it happened in the first place. Because it > happened at the same time as several other problems which were fixed (such > as that job_resrcs segfault), I'm not actually sure if one of those patches > fixed this bug or not. Yes, I agree, there were several tings going on at once, so probably not easy to isolate each one. > I did implement something that would sidestep this segfault and just throw > an error message instead. Tim and I talked about it. Tim is of the opinion > that even though segfaults are really bad, dumping a core and getting a > backtrace is usually the only chance we have to fix the problem, though he > acknowledged that you disagree. I'm on the fence. That's the developer's standpoint vs the end-user one. I understand both. :) > Because you haven't seen it for the past two months, I'm inclined to close > this as "cannotreproduce" (yes, we made a new close reason). What do you > think? > > If you decide it's fine to close this out, if you do hit this segfault > again, definitely re-open the bug. That sounds reasonable, yes. No reason to keep this around as we haven't encountered this error again. > (By the way - work has been done for 5443 to try to optimize the agent > queue, though nothing has been committed yet.) Nice to hear, thanks! Cheers, -- Kilian
Sounds good. Closing as cannotreproduce.
