(unpack_constraints)    trace: Processing constraint rsc_order constraint2
(get_flags)     trace: Upgrade constraint2: implies right
(get_flags)     trace: Upgrade constraint2: runnable
(custom_action_order)   trace: Creating[1] rsc2 rsc2_start_0 NA - promotable1 promotable1_promote_0 NA
(unpack_simple_rsc_order)       trace: order-1 (constraint2): rsc2_start before promotable1_promote flags=0x000121
	-> optional implies_then runnable_left
(get_flags)     trace: Upgrade constraint2: implies left
(custom_action_order)   trace: Creating[2] promotable1 promotable1_demote_0 NA - rsc2 rsc2_stop_0 NA
(unpack_simple_rsc_order)       trace: order-2 (constraint2): promotable1_demote before rsc2_stop flags=0x000011
	-> optional implies_first (correct -- runnable_right doesn't exist b/c it's implied by optional)
...
(custom_action)         trace: Creating optional action 16: promotable1_demote_0 for promotable1 (demote) on no node
(crm_set_bit)   trace: Bit 0x00000002 for promotable1_demote_0 set by custom_action:553
	-> runnable
(crm_set_bit)   trace: Bit 0x00000004 for promotable1_demote_0 set by custom_action:555
	-> optional
...
(custom_action)         trace: Unset runnable on promotable1_demote_0
(crm_clear_bit)         trace: Bit 0x00000002 for promotable1_demote_0 cleared by custom_action:611
	-> runnable cleared (but set again below)
(crm_set_bit)   trace: Bit 0x00000001 for promotable1_demote_0 set by create_pseudo_resource_op:460
	-> pseudo
(update_action_flags)   trace: promotable1_demote_0 on [none]: set flags 0x000001 (was 0x000004, now 0x000005, 14, create_pseudo_resource_op)
(crm_set_bit)   trace: Bit 0x00000002 for promotable1_demote_0 set by create_pseudo_resource_op:461
	-> runnable again
(update_action_flags)   trace: promotable1_demote_0 on [none]: set flags 0x000002 (was 0x000005, now 0x000007, 15, create_pseudo_resource_op)
...
(order_actions)         trace: Ordering Action promotable1_demote_0 before rsc2_stop_0
	-> maybe optional never gets cleared?
...
(LogActions)    info: Leave   rsc1:1    (Master node1)
	-> no specific logging for a demote/promote cycle (fixed)
...
(stage7)        trace: Updating 19 actions
...
(update_action)         trace: Processing rsc2_stop_0 (optional runnable node1)
	-> stop is optional when compared against demote
...
(update_action)         trace: Processing rsc2_start_0 (required runnable node1)
(update_action)         trace: Checking rsc2_start_0 (required runnable node1) against rsc2_stop_0 (optional runnable node1) filter=0x000006 type=0x001021
...
(crm_clear_bit)         trace: Bit 0x00000004 for rsc2_stop_0 cleared by handle_restart_ordering:2073
	-> stop becomes required when processing rsc2_start_0
...
(update_action)         trace: Updated rsc2_stop_0 (first required runnable node1), processing dependents 
...
(update_action)         trace: Checking rsc2_stop_0 (required runnable node1) against promotable1_demoted_0 (optional runnable pseudo) filter=0x000007 type=0x000011
	-> promotable1_demoted_0 has been made the "then" of the constraint,
	   but it's not made required here
(crm_clear_bit)         trace: Bit 0x00000001 cleared by graph_update_action:203
	-> why would we clear the pseudo bit of demoted?
...
(graph_update_action)   trace: implies left: promotable1_demoted_0 (1) then rsc2_stop_0 (0)
	-> why doesn't implies_first take effect here?
...
(native_update_actions)         trace: Testing rsc2_start_0 on node1 (0x000002) with promotable1_promote_0 0x000007
(native_update_actions)         trace: Unset optional on promotable1_promote_0 because of rsc2_start_0
(crm_clear_bit)         trace: Bit 0x00000004 for promotable1_promote_0 cleared by native_update_actions:2218
(pe_action_set_reason)  trace: Set promotable1_promote_0 reason to 'required rsc2 start'
(native_update_actions)         trace: Then: Flags for promotable1_promote_0 on [none] are now  0x000003 (was 0x000007) because of rsc2_start_0 0x000002
(native_update_actions)         trace: Testing rsc2_start_0 on node1 (0x000002) with rsc1:1_promote_0 0x000006
(native_update_actions)         trace: Unset optional on rsc1:1_promote_0 because of rsc2_start_0
(crm_clear_bit)         trace: Bit 0x00000004 for rsc1:1_promote_0 cleared by native_update_actions:2218
(pe_action_set_reason)  trace: Set rsc1:1_promote_0 reason to 'required rsc2 start'
(native_update_actions)         trace: Then: Flags for rsc1:1_promote_0 on node1 are now  0x000002 (was 0x000006) because of rsc2_start_0 0x000002
	-> promote is made required
...
(native_update_actions)         trace: Testing rsc1:1_demote_0 on node1 (0x000006) with rsc1:1_promote_0 0x000002
(graph_update_action)   trace: optional: rsc1:1_demote_0 then rsc1:1_promote_0
(update_action)         trace: Checking rsc1:1_promote_0 (required runnable node1) against rsc1:1_start_0 (optional runnable node1) filter=0x000006 type=0x000100

We never see "Testing rsc1:1_demote_0 on node1 ... with rsc2_stop_0"