Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

NS race condition during test case #2494

Closed
389-ds-bot opened this issue Sep 13, 2020 · 9 comments
Closed

NS race condition during test case #2494

389-ds-bot opened this issue Sep 13, 2020 · 9 comments
Labels
closed: fixed Migration flag - Issue
Milestone
1.3.7.0

Comments

@389-ds-bot
Copy link

Cloned from Pagure issue: https://pagure.io/389-ds-base/issue/49435

Issue Description

During the test case, a very very rare issue can be observed (maybe 1 in a million executions)

This appears to be a race between internal job rearm's state assertion, and the thread shutdown clearing the queues.

[ RUN      ] ns_set_data_test
Assertion failure: job->state == NS_JOB_NEEDS_ARM, at src/nunc-stans/ns/ns_thrpool.c:254
Assertion failure: job->state == NS_JOB_NEEDS_ARM, at src/nunc-stans/ns/ns_thrpool.c:254
ns_thrpool_new():  max threads, (4)
ns_thrpool_new():  max threads, (4)
stacksize (0), event q size (unbounded), work q size (unbounded)
stacksize (0), event q size (unbounded), work q size (unbounded)
new_ns_job 580 initial NS_JOB_WAITING
new_ns_job 580 initial NS_JOB_WAITING
setup_event_q_wakeup 580 state 7 moving NS_JOB_ARMED
setup_event_q_wakeup 580 state 7 moving NS_JOB_ARMED
new_ns_job 660 initial NS_JOB_WAITING
new_ns_job 660 initial NS_JOB_WAITING
ns_add_job 660 state 7 moving to NS_JOB_ARMED
ns_add_job 660 state 7 moving to NS_JOB_ARMED
internal_ns_rearm_job 660 state 4 moving to NS_JOB_ARMED
internal_ns_rearm_job 660 state 4 moving to NS_JOB_ARMED
work_q_notify 660 state 5
work_q_notify 660 state 5
work_job_execute 660 state 5 moving to NS_JOB_RUNNING
work_job_execute 660 state 5 moving to NS_JOB_RUNNING
work_job_execute 660 state 6 job func complete move to NS_JOB_WAITING
work_job_execute 660 state 6 job func complete move to NS_JOB_WAITING
ns_rearm_job 660 state 7 moving to NS_JOB_NEEDS_ARM
ns_rearm_job 660 state 7 moving to NS_JOB_NEEDS_ARM
internal_ns_rearm_job 660 state 4 moving to NS_JOB_ARMED
internal_ns_rearm_job 660 state 4 moving to NS_JOB_ARMED
work_q_notify 660 state 5
work_q_notify 660 state 5
work_job_execute 660 state 5 moving to NS_JOB_RUNNING
work_job_execute 660 state 5 moving to NS_JOB_RUNNING
work_job_execute 660 state 6 job func complete move to NS_JOB_WAITING
work_job_execute 660 state 6 job func complete move to NS_JOB_WAITING
ns_job_done 660 tp shutdown -> false state 7 setting NS_JOB_NEEDS_DELETE and queuing
ns_job_done 660 tp shutdown -> false state 7 setting NS_JOB_NEEDS_DELETE and queuing
event_q_notify enqueuing 660 with state 2
event_q_notify enqueuing 660 with state 2
event_q_wake attempting to wake event queue.
event_q_wake attempting to wake event queue.
event_q_wake result. 0
event_q_wake result. 0
ns_thrpool_shutdown initiated ...
ns_thrpool_shutdown initiated ...
new_ns_job 740 initial NS_JOB_WAITING
new_ns_job 740 initial NS_JOB_WAITING
internal_ns_rearm_job 740 state 4 moving to NS_JOB_ARMED
internal_ns_rearm_job 740 state 4 moving to NS_JOB_ARMED
work_q_notify 740 state 5
work_q_notify 740 state 5
event_cb 580 state 5 non-threaded, execute right meow
event_cb 580 state 5 non-threaded, execute right meow
work_job_execute 580 state 5 moving to NS_JOB_RUNNING
work_job_execute 580 state 5 moving to NS_JOB_RUNNING
wakeup_cb 580 state 6 wakeup_cb
wakeup_cb 580 state 6 wakeup_cb
new_ns_job 820 initial NS_JOB_WAITING
new_ns_job 820 initial NS_JOB_WAITING
internal_ns_rearm_job 820 state 4 moving to NS_JOB_ARMED
internal_ns_rearm_job 820 state 4 moving to NS_JOB_ARMED
work_q_notify 820 state 5
work_q_notify 820 state 5
new_ns_job 900 initial NS_JOB_WAITING
new_ns_job 900 initial NS_JOB_WAITING
internal_ns_rearm_job 900 state 4 moving to NS_JOB_ARMED
internal_ns_rearm_job 900 state 4 moving to NS_JOB_ARMED
work_q_notify 900 state 5
work_q_notify 900 state 5
worker_thread_func notified to shutdown!
worker_thread_func notified to shutdown!
internal_ns_job_done 740 state 5 moving to NS_JOB_DELETED
internal_ns_job_done 740 state 5 moving to NS_JOB_DELETED
worker_thread_func shutdown complete!
worker_thread_func shutdown complete!
get_new_event_requests Dequeuing 660 with state 2
get_new_event_requests Dequeuing 660 with state 2
update_event 660 state 2
update_event 660 state 2
internal_ns_job_done 660 state 2 moving to NS_JOB_DELETED
internal_ns_job_done 660 state 2 moving to NS_JOB_DELETED
work_job_execute PERSIST and RUNNING, remarking 580 as NS_JOB_NEEDS_ARM
work_job_execute PERSIST and RUNNING, remarking 580 as NS_JOB_NEEDS_ARM
work_job_execute 580 state 4 job func complete, sending to rearm...
work_job_execute 580 state 4 job func complete, sending to rearm...
worker_thread_func notified to shutdown!
worker_thread_func notified to shutdown!
new_ns_job 9e0 initial NS_JOB_WAITING
new_ns_job 9e0 initial NS_JOB_WAITING
worker_thread_func notified to shutdown!
worker_thread_func notified to shutdown!
internal_ns_job_done 900 state 5 moving to NS_JOB_DELETED
internal_ns_job_done 900 state 5 moving to NS_JOB_DELETED
internal_ns_rearm_job 9e0 state 4 moving to NS_JOB_ARMED
internal_ns_rearm_job 9e0 state 4 moving to NS_JOB_ARMED
work_q_notify 9e0 state 5
work_q_notify 9e0 state 5
worker_thread_func shutdown complete!
worker_thread_func shutdown complete!
ns_thrpool_wait has begun
ns_thrpool_wait has begun
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait joined thread, result 0
internal_ns_job_done 820 state 5 moving to NS_JOB_DELETED
internal_ns_job_done 820 state 5 moving to NS_JOB_DELETED
worker_thread_func shutdown complete!
worker_thread_func shutdown complete!
worker_thread_func notified to shutdown!
worker_thread_func notified to shutdown!
internal_ns_job_done 9e0 state 5 moving to NS_JOB_DELETED
internal_ns_job_done 9e0 state 5 moving to NS_JOB_DELETED
worker_thread_func shutdown complete!
worker_thread_func shutdown complete!
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait joined thread, result 0
ns_thrpool_wait complete, retval 0
ns_thrpool_wait complete, retval 0
ns_thrpool_destroy
ns_thrpool_destroy
ns_thrpool_destroy 580 state 4 moving to NS_JOB_NEEDS_DELETE
ns_thrpool_destroy 580 state 4 moving to NS_JOB_NEEDS_DELETE
event_q_notify enqueuing 580 with state 2
event_q_notify enqueuing 580 with state 2
event_q_wake attempting to wake event queue.
event_q_wake attempting to wake event queue.
event_q_wake result. 0
event_q_wake result. 0
FAIL test_nuncstans (exit status: 134)
FAIL test_nuncstans (exit status: 134)
RPM build errors:
RPM build errors:

Note, this will not affect production releases, on our test builds.
@389-ds-bot 389-ds-bot added the closed: fixed Migration flag - Issue label Sep 13, 2020
@389-ds-bot 389-ds-bot added this to the 1.3.7.0 milestone Sep 13, 2020
@389-ds-bot
Copy link
Author

Comment from firstyear (@Firstyear) at 2017-11-01 06:43:23

Metadata Update from @Firstyear:

  • Issue assigned to Firstyear

@389-ds-bot
Copy link
Author

Comment from mreynolds (@mreynolds389) at 2017-11-02 16:40:05

Metadata Update from @mreynolds389:

  • Custom field component adjusted to None
  • Custom field origin adjusted to None
  • Custom field reviewstatus adjusted to None
  • Custom field type adjusted to None
  • Custom field version adjusted to None
  • Issue set to the milestone: 1.4 backlog

@389-ds-bot
Copy link
Author

Comment from firstyear (@Firstyear) at 2017-11-06 00:33:55

0001-Ticket-49435-Fix-NS-race-condition-on-loaded-test-sy.patch

@389-ds-bot
Copy link
Author

Comment from firstyear (@Firstyear) at 2017-11-06 00:33:56

Metadata Update from @Firstyear:

  • Custom field reviewstatus adjusted to review (was: None)

@389-ds-bot
Copy link
Author

Comment from mreynolds (@mreynolds389) at 2017-11-06 12:58:03

Metadata Update from @mreynolds389:

  • Custom field reviewstatus adjusted to ack (was: review)

@389-ds-bot
Copy link
Author

Comment from firstyear (@Firstyear) at 2017-11-06 23:14:40

commit 11974a0
To ssh://git@pagure.io/389-ds-base.git
e622d95..11974a0 master -> master

@389-ds-bot
Copy link
Author

Comment from firstyear (@Firstyear) at 2017-11-06 23:14:41

Metadata Update from @Firstyear:

  • Issue close_status updated to: fixed
  • Issue status updated to: Closed (was: Open)

@389-ds-bot
Copy link
Author

Comment from mreynolds (@mreynolds389) at 2017-11-16 19:34:43

60f66df..d67e8ae 389-ds-base-1.3.7 -> 389-ds-base-1.3.7

@389-ds-bot
Copy link
Author

Comment from mreynolds (@mreynolds389) at 2017-11-16 19:34:44

Metadata Update from @mreynolds389:

  • Issue set to the milestone: 1.3.7.0 (was: 1.4 backlog)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
closed: fixed Migration flag - Issue
Projects
None yet
Milestone
1.3.7.0
Development

No branches or pull requests
1 participant
@389-ds-bot