diff --git a/application/single_app/config.py b/application/single_app/config.py index b1a5c8102..79c40687b 100644 --- a/application/single_app/config.py +++ b/application/single_app/config.py @@ -101,7 +101,7 @@ EXECUTOR_TYPE = 'thread' EXECUTOR_MAX_WORKERS = 30 SESSION_TYPE = 'filesystem' -VERSION = "0.261.329" +VERSION = "0.261.331" IS_DEVELOPMENT = is_development_env_enabled() # Opt-out for deployments where App Service Easy Auth is active but the platform diff --git a/application/single_app/functions_appinsights.py b/application/single_app/functions_appinsights.py index a301a8795..9c87e48bf 100644 --- a/application/single_app/functions_appinsights.py +++ b/application/single_app/functions_appinsights.py @@ -11,6 +11,7 @@ from azure.monitor.opentelemetry import configure_azure_monitor import app_settings_cache +from functions_assist_diagnostics import ASSIST_DIAGNOSTIC_TEXT, safe_assist_diagnostics # Singleton for the logger and Azure Monitor configuration _appinsights_logger = None @@ -274,6 +275,9 @@ def _build_logger_extra( if diagnostic_key in LOGGER_WORKFLOW_HASH_KEYS: if re.fullmatch(r"[0-9a-f]{64}", value): logger_extra[normalized_key] = value + elif key in ASSIST_DIAGNOSTIC_TEXT: + if value in ASSIST_DIAGNOSTIC_TEXT[key]: + logger_extra[normalized_key] = value elif diagnostic_key in LOGGER_WORKFLOW_CODE_KEYS: if re.fullmatch(r"[a-z][a-z0-9_]{0,79}", value): logger_extra[normalized_key] = value @@ -383,6 +387,19 @@ def is_debug_enabled() -> bool: return bool(settings.get('enable_debug_logging', False)) +def log_assist_debug(properties): + """Send content-free Ask AI diagnostics to both sinks only while debug logging is enabled.""" + if not is_debug_enabled(): + return + safe = safe_assist_diagnostics(properties) + if 'assist_surface' not in safe or 'assist_event' not in safe: + return + if safe['assist_surface'] == 'workflow': + log_event('[WORKFLOW_ASSIST] Ask AI diagnostic', extra=safe) + else: + log_event('[EDITOR_ASSIST] Ask AI diagnostic', extra=safe) + + def _get_appinsights_debug_logger() -> Optional[logging.Logger]: """Return a logger that can emit DEBUG traces without widening parent logger levels.""" base_logger = get_appinsights_logger() diff --git a/application/single_app/functions_assist_diagnostics.py b/application/single_app/functions_assist_diagnostics.py new file mode 100644 index 000000000..98eac7a9f --- /dev/null +++ b/application/single_app/functions_assist_diagnostics.py @@ -0,0 +1,147 @@ +# functions_assist_diagnostics.py +"""Content-free diagnostics shared by the editor and workflow Ask AI cores.""" + +import hashlib +import math +import time + + +ASSIST_DIAGNOSTIC_LIMIT = 12 +ASSIST_DIAGNOSTIC_TEXT = { + 'assist_surface': frozenset({'agent', 'action', 'workflow'}), + 'assist_scope': frozenset({'personal', 'group', 'global'}), + 'assist_event': frozenset({ + 'model_started', 'model_finished', 'provider_finished', 'provider_failed', 'json_mode_fallback', + 'validation_rejected', 'correction_started', 'request_finished', + }), + 'assist_stage': frozenset({ + 'request', 'limit', 'base', 'projection', 'references', 'options', 'handles', 'excerpts', + 'envelope', 'model', 'evaluate', 'warnings', 'response', 'parse', 'shape', 'length', + 'operations', 'schema', 'apply', 'violation', 'validation', + }), + 'assist_outcome': frozenset({'changed', 'explained', 'question', 'failed'}), + 'assist_code': frozenset({ + 'invalid_request', 'instruction_invalid', 'conversation_invalid', 'draft_invalid', 'focus_invalid', + 'time_zone_invalid', 'tags_unsupported', 'reference_limit', 'reference_unavailable', + 'group_workflow_unsupported', 'workflow_read_only', 'assistant_input_too_large', 'request_too_large', + 'workflow_not_found', 'workflow_definition_conflict', 'workflow_deleted', 'assistant_busy', + 'assistant_rate_limited', 'assistant_output_invalid', 'assistant_refused', 'assistant_unavailable', + 'assistant_timeout', 'assistant_limit_unavailable', 'reference_check_failed', 'assistant_failed', + 'agent_assistant_disabled', 'action_assistant_disabled', 'scope_forbidden', 'scope_not_found', + }), + 'assist_finish_reason': frozenset({'stop', 'length', 'content_filter', 'tool_calls', 'function_call', 'missing', 'other'}), + 'assist_validation_code': frozenset({ + 'invalid_workflow', 'invalid_workflow_definition', 'invalid_workflow_settings', 'invalid_workflow_alerts', + 'blueprint_invalid', 'unsupported_field', 'too_many_tasks', 'trigger_invalid', 'cadence_below_minimum', + 'quota_exceeded', 'agent_unavailable', 'reference_unknown', 'reference_unauthorized', + 'file_sync_source_unavailable', 'workflow_conflict', 'workflows_unavailable', 'scope_unavailable', + 'merge_unavailable', 'merge_inputs_required', 'merge_trigger_required', 'merge_runner_invalid', + 'merge_options_invalid', 'merge_format_invalid', + }), + 'assist_field_kind': frozenset({'text', 'textarea', 'number', 'boolean', 'select', 'choices', 'lines', 'web_sources'}), + 'assist_rule': frozenset({ + 'empty_reply', 'invalid_json', 'invalid_json_value', 'reply_not_object', + 'unexpected_reply_field', 'reply_required', 'operations_not_array', 'too_many_operations', + 'operation_shape', 'output_truncated', 'create_unavailable', 'create_shape', + 'new_handle_invalid', 'too_many_new_items', 'new_type_invalid', 'new_values_not_object', + 'new_field_unknown', 'new_required_field', 'field_unknown', 'field_read_only', + 'field_repeated', 'text_invalid', 'text_multiline', 'text_too_long', 'required_value', + 'number_invalid', 'number_below_minimum', 'number_above_maximum', 'boolean_invalid', + 'select_invalid', 'choices_not_array', 'choice_handle_invalid', 'too_many_items', + 'lines_not_array', 'line_invalid', 'line_too_long', 'web_sources_not_array', + 'web_source_shape', 'web_source_url', 'web_source_mode', 'field_kind_invalid', + 'created_item_unassigned', 'operation_invalid', 'handle_invalid', 'schedule_invalid', + 'protected_workflow', 'projection_invalid', 'save_validation', 'candidate_invalid', + 'task_limit', 'task_required', 'task_self_reference', 'new_task_key_repeated', + 'document_scope_unknown', 'reference_not_bound', 'alert_scope_invalid', + 'schema_required', 'schema_additional_properties', 'schema_not', 'schema_enum', + 'schema_const', 'schema_type', 'schema_pattern', 'schema_min_length', 'schema_max_length', + 'schema_min_items', 'schema_max_items', 'schema_unique_items', 'schema_minimum', + 'schema_maximum', 'schema_one_of', 'schema_invalid', + }), + 'assist_operation': frozenset({ + 'set', 'create_item', 'set_name', 'set_description', 'set_trigger_manual', + 'set_schedule_interval', 'set_schedule_calendar', 'set_alert_mode', 'add_alert_rule', + 'update_alert_rule', 'remove_alert_rule', 'set_workflow_runner', 'set_task_runner', + 'add_task', 'remove_task', 'move_task', 'set_task_name', 'set_task_instructions', + 'set_task_inputs', 'bind_reference', 'set_task_references', 'unbind_reference', + 'set_task_document_target', 'clear_task_document_target', + }), + 'assist_field': frozenset({ + '/display_name', '/displayName', '/description', '/instructions', '/actions', '/model', + '/type', '/agent_type', '/reasoning_effort', '/max_completion_tokens', + '/endpoint', '/deployment', '/api_version', '/auth/type', + '/knowledge/enabled', '/knowledge/sources', '/knowledge/documents', '/knowledge/tags', + '/knowledge/web_sources', '/additionalFields/database_type', '/additionalFields/server', + '/additionalFields/database', '/additionalFields/port', '/additionalFields/driver', + '/additionalFields/read_only', '/additionalFields/max_rows', '/additionalFields/timeout', + }), +} +ASSIST_DIAGNOSTIC_NUMBERS = frozenset({ + 'attempt', 'provider_attempt', 'operation_index', 'reason_index', 'reason_count', 'elapsed_ms', 'remaining_ms', + 'provider_duration_ms', 'provider_status', 'output_length', 'operation_count', 'model_calls', + 'correction_count', 'status', 'change_count', 'new_item_count', +}) +ASSIST_DIAGNOSTIC_FLAGS = frozenset({'output_present', 'json_mode', 'field_known'}) + + +def safe_assist_diagnostics(properties): + """Keep only closed categories, finite measurements, flags, and a submission hash.""" + safe = {} + for key, value in properties.items(): + if key in ASSIST_DIAGNOSTIC_TEXT: + if isinstance(value, str) and value in ASSIST_DIAGNOSTIC_TEXT[key]: + safe[key] = value + elif key in ASSIST_DIAGNOSTIC_NUMBERS: + if isinstance(value, (int, float)) and not isinstance(value, bool) and ( + isinstance(value, int) or math.isfinite(value) + ): + safe[key] = max(0, min(value, 1_000_000_000)) + elif key in ASSIST_DIAGNOSTIC_FLAGS: + if isinstance(value, bool): + safe[key] = value + elif key == 'turn_id_hash': + if isinstance(value, str) and len(value) == 64 and all(char in '0123456789abcdef' for char in value): + safe[key] = value + return safe + + +class AssistDiagnostics: + """An injected, best-effort observer; no settings, Azure, or request content dependencies.""" + + def __init__(self, emit=None): + self._emit = emit + self._context = {} + self._clock = time.monotonic + self._started = self._clock() + self.attempt = 0 + + def bind(self, surface, scope, submission_id=None, *, clock=time.monotonic): + self._clock = clock + self._started = clock() + self.attempt = 0 + self._context = safe_assist_diagnostics({'assist_surface': surface, 'assist_scope': scope}) + if isinstance(submission_id, str) and submission_id: + self._context['turn_id_hash'] = hashlib.sha256(submission_id.encode('utf-8')).hexdigest() + + def emit(self, event, **properties): + if self._emit is None or 'assist_surface' not in self._context: + return + safe = safe_assist_diagnostics({ + **properties, **self._context, 'assist_event': event, 'attempt': self.attempt, + 'elapsed_ms': int((self._clock() - self._started) * 1000), + }) + try: + self._emit(safe) + except Exception: + # An observer must not replace the proposal, rejection, or limiter cleanup. + pass + + +def assist_finish_reason(value): + """A provider finish reason is diagnostic data, not an arbitrary log string.""" + if value is None: + return 'missing' + if isinstance(value, str) and value in ASSIST_DIAGNOSTIC_TEXT['assist_finish_reason']: + return value + return 'other' diff --git a/application/single_app/functions_editor_assist.py b/application/single_app/functions_editor_assist.py index 4b6615371..5fcc531a7 100644 --- a/application/single_app/functions_editor_assist.py +++ b/application/single_app/functions_editor_assist.py @@ -43,6 +43,7 @@ from urllib.parse import urlsplit from functions_assist_submissions import SubmissionIdError, normalize_submission_id +from functions_assist_diagnostics import ASSIST_DIAGNOSTIC_LIMIT, AssistDiagnostics, assist_finish_reason from functions_rate_limit import build_rate_limit_error_payload @@ -704,7 +705,7 @@ def offered(self, path): - {"op": "set", "path": "", "value": } replaces one field's whole value. __CREATE_OPERATION__ Rules: -- Use only paths listed in draft.fields (or, after you change "__VARIANT_PATH__", the fields listed for the new value in draft.variant_fields). Never set a field marked "read_only". +- For set operations, use only paths listed in draft.fields (or, after you change "__VARIANT_PATH__", the fields listed for the new value in draft.variant_fields). Never set a field marked "read_only". - Match each field's "kind": "text" is one line; "textarea" may have line breaks; "number" is a JSON number within "min" and "max" ("integer" means a whole number); "boolean" is true or false; "select" is one of the field's option "value"s; "choices" is a JSON array of option "handle"s from that field (a full replacement list -- include the ones to keep); "lines" is a JSON array of short strings; "web_sources" is a JSON array of {"url": "https://...", "mode": "url_review" or "deep_research"}. - Respect "max_length" and "max_items". Never invent handles, option values, IDs or URLs the person did not give you. - Never ask for, guess, write or repeat secrets, keys, passwords, tokens or connection strings. Those fields are hidden from you; tell the person to fill them in themselves when they are needed. @@ -726,7 +727,9 @@ def offered(self, path): - Endpoints, server names and IDs come only from the person. Leave them unchanged if you were not told them, and tell the person to fill in required ones. - Prefer safe defaults, such as read-only access and modest row or result limits, unless the person asks otherwise.""" -_CREATE_OPERATION = """- {"op": "create_item", "handle": "N1", "type": "", "values": {"": , ...}} drafts a new __NOUN__ that will be saved with this __SUBJECT__ and assigns it through "__TARGET__". Use handles N1, N2, ... (at most __MAX__). "values" may set the paths in new_items.common_fields and the fields listed for that type in new_items.type_fields; set every required common field. To assign it, the new handle is added to "__TARGET__" for you. Create one only when no existing option fits.""" +_CREATE_OPERATION = """- {"op": "create_item", "handle": "N1", "type": "", "values": {"": , ...}} drafts a new __NOUN__ that will be saved with this __SUBJECT__ and assigns it through "__TARGET__". Use handles N1, N2, ... (at most __MAX__). To assign it, the new handle is added to "__TARGET__" for you. Create one only when no existing option fits. + For create_item, use only the paths in new_items.common_fields and new_items.type_fields for the selected type, not the parent draft's fields. "values" is a flat object: its keys must be the exact "path" strings, including the leading "/" and the exact capitalization. For example, a listed "/displayName" field is written as "values": {"/displayName": "Lookup"}, never "values": {"displayName": "Lookup"}. + Respect each new field's kind, limits and options, and set every required common field. Do not copy every type-specific field or send blank placeholders. If a type-specific field needs a server, database, endpoint or other detail the person has not provided, omit that field from "values" and tell the person to finish it before saving, or ask a short question with no operations. Never invent connection details or enter credentials.""" def system_prompt(request): @@ -893,7 +896,7 @@ def message_size(messages): class _Correctable(Exception): """The reply cannot be used; ``messages`` are server-authored and go to the correction round.""" - def __init__(self, messages, stage): + def __init__(self, messages, stage, *, diagnostics=(), operation_count=None): cleaned = [] for message in list(messages)[:_MAX_CORRECTION_MESSAGES]: text = ' '.join(str(message).split()) @@ -902,13 +905,16 @@ def __init__(self, messages, stage): cleaned.append(text) self.messages = cleaned or ['The reply could not be used.'] self.stage = stage + self.diagnostics = list(diagnostics)[:ASSIST_DIAGNOSTIC_LIMIT] + self.operation_count = operation_count super().__init__(stage) def parse_model_output(content): """The model's reply as a JSON object, or raise ``_Correctable``. One Markdown fence is tolerated.""" if not isinstance(content, str) or not content.strip(): - raise _Correctable(['The reply was empty. Reply with exactly one JSON object.'], 'parse') + raise _Correctable(['The reply was empty. Reply with exactly one JSON object.'], 'parse', + diagnostics=[{'assist_rule': 'empty_reply'}]) text = content.strip() fenced = _JSON_FENCE.match(text) if fenced: @@ -916,11 +922,14 @@ def parse_model_output(content): try: output = _strict_json(text) except (ValueError, RecursionError): - raise _Correctable(['The reply was not valid JSON. Reply with exactly one JSON object and nothing else.'], 'parse') from None + raise _Correctable(['The reply was not valid JSON. Reply with exactly one JSON object and nothing else.'], 'parse', + diagnostics=[{'assist_rule': 'invalid_json'}]) from None if not isinstance(output, dict): - raise _Correctable(['The reply must be one JSON object.'], 'parse') + raise _Correctable(['The reply must be one JSON object.'], 'parse', + diagnostics=[{'assist_rule': 'reply_not_object'}]) if _json_problem(output) is not None: - raise _Correctable(['The reply contains text that is not valid Unicode or is nested too deeply.'], 'parse') + raise _Correctable(['The reply contains text that is not valid Unicode or is nested too deeply.'], 'parse', + diagnostics=[{'assist_rule': 'invalid_json_value'}]) return output @@ -956,7 +965,9 @@ def _safe_url(value): class _ValueError(Exception): - pass + def __init__(self, message, rule): + super().__init__(message) + self.rule = rule def coerce_value(descriptor, value, handles, extra_handles=()): @@ -967,39 +978,39 @@ def coerce_value(descriptor, value, handles, extra_handles=()): if value is None and not descriptor.required: return '' if not isinstance(value, str) or _CONTROL_CHARACTERS.search(value): - raise _ValueError(f'{path} must be a string without control characters.') + raise _ValueError(f'{path} must be a string without control characters.', 'text_invalid') if kind == 'text' and _LINE_BREAKS.search(value): - raise _ValueError(f'{path} must be one line.') + raise _ValueError(f'{path} must be one line.', 'text_multiline') text = _js_trim(value) if kind == 'text' else value.strip('\r\n') if len(text) > descriptor.max_length: - raise _ValueError(f'{path} must be at most {descriptor.max_length} characters.') + raise _ValueError(f'{path} must be at most {descriptor.max_length} characters.', 'text_too_long') if descriptor.required and not _js_trim(text): - raise _ValueError(f'{path} is required and cannot be blank.') + raise _ValueError(f'{path} is required and cannot be blank.', 'required_value') return text if kind == 'number': if value is None and not descriptor.required: return None number = _number(value, integer=descriptor.integer) if number is None: - raise _ValueError(f'{path} must be a {"whole " if descriptor.integer else ""}number.') + raise _ValueError(f'{path} must be a {"whole " if descriptor.integer else ""}number.', 'number_invalid') if descriptor.minimum is not None and number < descriptor.minimum: - raise _ValueError(f'{path} must be at least {descriptor.minimum}.') + raise _ValueError(f'{path} must be at least {descriptor.minimum}.', 'number_below_minimum') if descriptor.maximum is not None and number > descriptor.maximum: - raise _ValueError(f'{path} must be at most {descriptor.maximum}.') + raise _ValueError(f'{path} must be at most {descriptor.maximum}.', 'number_above_maximum') return int(number) if descriptor.integer else number if kind == 'boolean': if not isinstance(value, bool): - raise _ValueError(f'{path} must be true or false.') + raise _ValueError(f'{path} must be true or false.', 'boolean_invalid') return value if kind == 'select': if value is None and not descriptor.required: return None if value not in descriptor.option_values(): - raise _ValueError(f'{path} must be one of its option values.') + raise _ValueError(f'{path} must be one of its option values.', 'select_invalid') return value if kind == 'choices': if not isinstance(value, list): - raise _ValueError(f'{path} must be a JSON array of option handles.') + raise _ValueError(f'{path} must be a JSON array of option handles.', 'choices_not_array') result = [] for handle in value: if isinstance(handle, str) and handle in extra_handles: @@ -1007,51 +1018,51 @@ def coerce_value(descriptor, value, handles, extra_handles=()): else: resolved = handles.value(path, handle) if isinstance(handle, str) else None if resolved is None: - raise _ValueError(f'{path} lists a handle that is not one of its options.') + raise _ValueError(f'{path} lists a handle that is not one of its options.', 'choice_handle_invalid') if resolved not in result: result.append(resolved) if len(result) > descriptor.max_items: - raise _ValueError(f'{path} can list at most {descriptor.max_items} items.') + raise _ValueError(f'{path} can list at most {descriptor.max_items} items.', 'too_many_items') return result if kind == 'lines': if not isinstance(value, list): - raise _ValueError(f'{path} must be a JSON array of strings.') + raise _ValueError(f'{path} must be a JSON array of strings.', 'lines_not_array') result = [] for item in value: if not isinstance(item, str) or _CONTROL_CHARACTERS.search(item) or _LINE_BREAKS.search(item): - raise _ValueError(f'{path} items must be one-line strings.') + raise _ValueError(f'{path} items must be one-line strings.', 'line_invalid') text = _js_trim(item) if not text: continue if len(text) > descriptor.max_length: - raise _ValueError(f'{path} items must be at most {descriptor.max_length} characters.') + raise _ValueError(f'{path} items must be at most {descriptor.max_length} characters.', 'line_too_long') if text not in result: result.append(text) if len(result) > descriptor.max_items: - raise _ValueError(f'{path} can list at most {descriptor.max_items} items.') + raise _ValueError(f'{path} can list at most {descriptor.max_items} items.', 'too_many_items') return result if kind == 'web_sources': if not isinstance(value, list): - raise _ValueError(f'{path} must be a JSON array of {{"url", "mode"}} objects.') + raise _ValueError(f'{path} must be a JSON array of {{"url", "mode"}} objects.', 'web_sources_not_array') result = [] seen = set() for item in value: if not isinstance(item, dict) or not set(item) <= {'url', 'mode'} or 'url' not in item: - raise _ValueError(f'{path} items must be {{"url", "mode"}} objects.') + raise _ValueError(f'{path} items must be {{"url", "mode"}} objects.', 'web_source_shape') url = _safe_url(item['url']) if url is None: - raise _ValueError(f'{path} URLs must be http or https addresses without credentials.') + raise _ValueError(f'{path} URLs must be http or https addresses without credentials.', 'web_source_url') mode = item.get('mode', 'url_review') if mode not in WEB_SOURCE_MODES: - raise _ValueError(f'{path} mode must be "url_review" or "deep_research".') + raise _ValueError(f'{path} mode must be "url_review" or "deep_research".', 'web_source_mode') if url in seen: continue seen.add(url) result.append({'url': url, 'mode': mode}) if len(result) > descriptor.max_items: - raise _ValueError(f'{path} can list at most {descriptor.max_items} items.') + raise _ValueError(f'{path} can list at most {descriptor.max_items} items.', 'too_many_items') return result - raise _ValueError(f'{path} cannot be changed.') + raise _ValueError(f'{path} cannot be changed.', 'field_kind_invalid') class _Attempt: @@ -1068,28 +1079,43 @@ def __init__(self, *, outcome, reply, candidate, changes, new_items, warnings, o _NO_CHANGE_REPLY = 'The draft already works this way, so nothing was changed.' +class _OperationErrors: + def __init__(self): + self.messages = [] + self.diagnostics = [] + + def reject(self, message, rule, *, index=0, operation='create_item', path=None, descriptor=None): + self.messages.append(message) + if len(self.diagnostics) < ASSIST_DIAGNOSTIC_LIMIT: + self.diagnostics.append({ + 'assist_rule': rule, 'operation_index': index, 'assist_operation': operation, + 'assist_field': path, 'field_known': descriptor is not None, + 'assist_field_kind': descriptor.kind if descriptor is not None else None, + }) + + def _apply_create(request, handles, operation, index, created, errors): spec = request.new_items if spec is None or spec.max_items <= 0: - errors.append(f'Operation {index}: create_item is not available in this editor.') + errors.reject(f'Operation {index}: create_item is not available in this editor.', 'create_unavailable', index=index) return if not set(operation) <= {'op', 'handle', 'type', 'values'}: - errors.append(f'Operation {index}: create_item accepts only handle, type and values.') + errors.reject(f'Operation {index}: create_item accepts only handle, type and values.', 'create_shape', index=index) return handle = operation.get('handle') if not isinstance(handle, str) or not _NEW_HANDLE.match(handle) or handle in created: - errors.append(f'Operation {index}: handle must be a new, unique N1, N2, ... handle.') + errors.reject(f'Operation {index}: handle must be a new, unique N1, N2, ... handle.', 'new_handle_invalid', index=index) return if len(created) >= spec.max_items: - errors.append(f'Operation {index}: at most {spec.max_items} new items can be created.') + errors.reject(f'Operation {index}: at most {spec.max_items} new items can be created.', 'too_many_new_items', index=index) return item_type = operation.get('type') if item_type not in {option['value'] for option in spec.type_options}: - errors.append(f'Operation {index}: type must be one of new_items.types.') + errors.reject(f'Operation {index}: type must be one of new_items.types.', 'new_type_invalid', index=index) return raw_values = operation.get('values', {}) if not isinstance(raw_values, dict): - errors.append(f'Operation {index}: values must be an object.') + errors.reject(f'Operation {index}: values must be an object.', 'new_values_not_object', index=index) return allowed = dict(spec.common) allowed.update(spec.variants.get(item_type, {})) @@ -1098,17 +1124,20 @@ def _apply_create(request, handles, operation, index, created, errors): for path, value in raw_values.items(): descriptor = allowed.get(path) if descriptor is None or descriptor.read_only: - errors.append(f'Operation {index}: {str(path)[:80]} is not a field a new item can set.') + errors.reject(f'Operation {index}: {str(path)[:80]} is not a field a new item can set.', + 'field_read_only' if descriptor is not None else 'new_field_unknown', + index=index, path=path, descriptor=descriptor) failed = True continue try: values[path] = coerce_value(descriptor, value, handles) except _ValueError as exc: - errors.append(f'Operation {index}: {exc}') + errors.reject(f'Operation {index}: {exc}', exc.rule, index=index, path=path, descriptor=descriptor) failed = True for path, descriptor in spec.common.items(): if descriptor.required and _is_blank(values.get(path)): - errors.append(f'Operation {index}: {path} is required for a new item.') + errors.reject(f'Operation {index}: {path} is required for a new item.', 'new_required_field', + index=index, path=path, descriptor=descriptor) failed = True if not failed: created[handle] = {'handle': NEW_ITEM_PREFIX + handle, 'type': item_type, 'values': values} @@ -1116,27 +1145,32 @@ def _apply_create(request, handles, operation, index, created, errors): def _checked_operations(output): if not set(output) <= {'reply', 'operations'}: - raise _Correctable(['The reply object may contain only "reply" and "operations".'], 'shape') + raise _Correctable(['The reply object may contain only "reply" and "operations".'], 'shape', + diagnostics=[{'assist_rule': 'unexpected_reply_field'}]) reply = clean_reply(output.get('reply')) if reply is None: - raise _Correctable(['"reply" must be a non-empty string.'], 'shape') + raise _Correctable(['"reply" must be a non-empty string.'], 'shape', + diagnostics=[{'assist_rule': 'reply_required'}]) operations = output.get('operations', []) if operations is None: operations = [] if not isinstance(operations, list): - raise _Correctable(['"operations" must be a JSON array.'], 'shape') + raise _Correctable(['"operations" must be a JSON array.'], 'shape', + diagnostics=[{'assist_rule': 'operations_not_array'}]) if len(operations) > EDITOR_ASSIST_MAX_OPERATIONS: - raise _Correctable([f'Send at most {EDITOR_ASSIST_MAX_OPERATIONS} operations.'], 'shape') + raise _Correctable([f'Send at most {EDITOR_ASSIST_MAX_OPERATIONS} operations.'], 'shape', + diagnostics=[{'assist_rule': 'too_many_operations'}]) for index, operation in enumerate(operations, start=1): if not isinstance(operation, dict) or operation.get('op') not in ('set', 'create_item'): - raise _Correctable([f'Operation {index} must be an object whose "op" is "set" or "create_item".'], 'shape') + raise _Correctable([f'Operation {index} must be an object whose "op" is "set" or "create_item".'], 'shape', + diagnostics=[{'assist_rule': 'operation_shape', 'operation_index': index}]) return reply, operations def evaluate_output(request, handles, output): """Apply the model's operations to a copy of the view and return an ``_Attempt``, or raise ``_Correctable``.""" reply, operations = _checked_operations(output) - errors = [] + errors = _OperationErrors() created = {} for index, operation in enumerate(operations, start=1): if operation['op'] == 'create_item': @@ -1151,26 +1185,31 @@ def evaluate_output(request, handles, output): variant_changed = False for index, operation in sets: if not set(operation) <= {'op', 'path', 'value'} or 'value' not in operation: - errors.append(f'Operation {index}: a set operation has exactly "op", "path" and "value".') + errors.reject(f'Operation {index}: a set operation has exactly "op", "path" and "value".', + 'operation_shape', index=index, operation='set') continue path = operation.get('path') active = request.active_fields(candidate) descriptor = active.get(path) if isinstance(path, str) else None if descriptor is None: - errors.append(f'Operation {index}: the path is not a field in this draft.') + errors.reject(f'Operation {index}: the path is not a field in this draft.', 'field_unknown', + index=index, operation='set', path=path) continue if descriptor.read_only: - errors.append(f'Operation {index}: {path} is read-only.') + errors.reject(f'Operation {index}: {path} is read-only.', 'field_read_only', + index=index, operation='set', path=path, descriptor=descriptor) continue if path in seen_paths: - errors.append(f'Operation {index}: {path} is set more than once.') + errors.reject(f'Operation {index}: {path} is set more than once.', 'field_repeated', + index=index, operation='set', path=path, descriptor=descriptor) continue seen_paths.add(path) extra = tuple(created) if request.new_items is not None and path == request.new_items.target else () try: value = coerce_value(descriptor, operation['value'], handles, extra) except _ValueError as exc: - errors.append(f'Operation {index}: {exc}') + errors.reject(f'Operation {index}: {exc}', exc.rule, index=index, operation='set', + path=path, descriptor=descriptor) continue if path == variant_path and value != candidate.get(path): variant_changed = True @@ -1186,15 +1225,17 @@ def evaluate_output(request, handles, output): assigned.append(item['handle']) target_descriptor = request.fields[target] if len(assigned) > target_descriptor.max_items: - errors.append(f'{target} can list at most {target_descriptor.max_items} items, including new ones.') + errors.reject(f'{target} can list at most {target_descriptor.max_items} items, including new ones.', + 'too_many_items', path=target, descriptor=target_descriptor) candidate[target] = assigned new_handles = {item['handle'] for item in created.values()} orphan = [handle for handle in new_handles if handle not in assigned] if orphan: - errors.append(f'Every created item must stay assigned in {target}.') + errors.reject(f'Every created item must stay assigned in {target}.', 'created_item_unassigned', + path=target, descriptor=target_descriptor) - if errors: - raise _Correctable(errors, 'operations') + if errors.messages: + raise _Correctable(errors.messages, 'operations', diagnostics=errors.diagnostics, operation_count=len(operations)) changes = compute_changes(request, candidate, variant_changed) warnings = [] @@ -1254,11 +1295,12 @@ class EditorAssistServices: Each may raise ``EditorAssistError`` or the shared ``WorkflowAssistError``, which is converted. """ - def __init__(self, *, limiter, call_model, log=None, clock=time.monotonic): + def __init__(self, *, limiter, call_model, log=None, clock=time.monotonic, diagnostics=None): self.limiter = limiter self.call_model = call_model self.log = log or (lambda _message, _extra, _level: None) self.clock = clock + self.diagnostics = diagnostics or AssistDiagnostics() def _as_editor_error(exc): @@ -1276,6 +1318,8 @@ def __init__(self, services, user_id, kind, scope): self.started = services.clock() self.deadline = self.started + ASSIST_DEADLINE_SECONDS self.model_called = False + self.diagnostics = services.diagnostics + self.diagnostics.bind(kind, scope, clock=services.clock) self.metrics = { 'user_id': user_id, 'editor': kind, 'scope': scope, 'submission_id': None, 'status': None, 'outcome': None, 'code': None, 'stage': 'request', 'error_type': None, 'invalid_stage': None, @@ -1291,6 +1335,8 @@ def stage(self, name): self.metrics['stage'] = name def execute(self, request): + self.diagnostics.bind(self.metrics['editor'], self.metrics['scope'], request.submission_id, + clock=self.services.clock) self.metrics.update({ 'submission_id': request.submission_id, 'turns_received': len(request.conversation), 'field_count': len(request.fields), @@ -1341,6 +1387,7 @@ def _execute(self, request): def _model_turns(self, request, handles, envelope): previous_errors = None for attempt_number in range(1, ASSIST_MODEL_ATTEMPTS + 1): + self.diagnostics.attempt = attempt_number remaining = self.remaining() if remaining < ASSIST_MIN_MODEL_SECONDS: raise EditorAssistError('assistant_timeout') @@ -1348,23 +1395,41 @@ def _model_turns(self, request, handles, envelope): messages = envelope.messages(previous_errors) self.model_called = True self.metrics['model_calls'] += 1 + self.diagnostics.emit('model_started', assist_stage='model', remaining_ms=int(remaining * 1000)) content, finish_reason = self.services.call_model(messages, remaining - ASSIST_POST_MODEL_SECONDS) + self.diagnostics.emit( + 'model_finished', assist_stage='evaluate', + assist_finish_reason=assist_finish_reason(finish_reason), + output_present=isinstance(content, str) and bool(content.strip()), + output_length=len(content) if isinstance(content, str) else 0, + ) self.stage('evaluate') try: if finish_reason == 'content_filter': raise EditorAssistError('assistant_refused') if finish_reason == 'length': - raise _Correctable(['The reply was cut off. Reply with fewer operations or shorter text.'], 'length') + raise _Correctable(['The reply was cut off. Reply with fewer operations or shorter text.'], 'length', + diagnostics=[{'assist_rule': 'output_truncated'}]) return evaluate_output(request, handles, parse_model_output(content)) except _Correctable as exc: self.metrics['invalid_stage'] = exc.stage + for reason_index, diagnostic in enumerate(exc.diagnostics, start=1): + self.diagnostics.emit('validation_rejected', **diagnostic, assist_stage=exc.stage, + reason_index=reason_index, reason_count=len(exc.diagnostics), + operation_count=exc.operation_count) if attempt_number >= ASSIST_MODEL_ATTEMPTS: break self.metrics['correction_count'] += 1 + self.diagnostics.emit('correction_started', assist_stage=exc.stage) previous_errors = exc.messages raise EditorAssistError('assistant_output_invalid') def log(self, status, *, outcome=None, code=None): + self.diagnostics.emit('request_finished', assist_stage=self.metrics['stage'], + assist_outcome=outcome or 'failed', assist_code=code, status=status, + model_calls=self.metrics['model_calls'], correction_count=self.metrics['correction_count'], + operation_count=self.metrics['operation_count'], change_count=self.metrics['change_count'], + new_item_count=self.metrics['new_item_count']) self.metrics.update({ 'status': status, 'outcome': outcome, 'code': code, 'duration_ms': max(0, int((self.services.clock() - self.started) * 1000)), diff --git a/application/single_app/functions_editor_assist_runtime.py b/application/single_app/functions_editor_assist_runtime.py index 71fc022e2..a3c1bfc6e 100644 --- a/application/single_app/functions_editor_assist_runtime.py +++ b/application/single_app/functions_editor_assist_runtime.py @@ -20,7 +20,8 @@ from flask import current_app, request from werkzeug.exceptions import BadRequest, RequestEntityTooLarge -from functions_appinsights import log_event +from functions_appinsights import log_assist_debug, log_event +from functions_assist_diagnostics import AssistDiagnostics from functions_editor_assist import ( EDITOR_ASSIST_MAX_BODY_BYTES, EditorAssistError, @@ -82,10 +83,12 @@ def build_editor_assist_services(*, client_factory, limiter=None): def log(message, extra, level): log_event(message, extra=extra, level=level) + diagnostics = AssistDiagnostics(log_assist_debug) return EditorAssistServices( limiter=_ConvertingLimiter(limiter), - call_model=_ConvertingModel(WorkflowAssistModel(client_factory)), + call_model=_ConvertingModel(WorkflowAssistModel(client_factory, diagnostics=diagnostics)), log=log, + diagnostics=diagnostics, ) diff --git a/application/single_app/functions_workflow_assist.py b/application/single_app/functions_workflow_assist.py index b89a13672..2075d6d7d 100644 --- a/application/single_app/functions_workflow_assist.py +++ b/application/single_app/functions_workflow_assist.py @@ -38,6 +38,7 @@ import traceback from functions_assist_references import ReferenceRequestError, canonical_request_references +from functions_assist_diagnostics import ASSIST_DIAGNOSTIC_LIMIT, AssistDiagnostics, assist_finish_reason from functions_assist_submissions import SubmissionIdError, normalize_submission_id from functions_m365_workflow_binding import workflow_execution_fingerprint from functions_rate_limit import build_rate_limit_error_payload @@ -592,7 +593,7 @@ def message_size(messages): class _Correctable(Exception): """The model's reply cannot be used; ``messages`` are server-authored and go to the correction round.""" - def __init__(self, messages, stage): + def __init__(self, messages, stage, *, diagnostics=()): cleaned = [] for message in messages[:_MAX_CORRECTION_MESSAGES]: text = ' '.join(str(message).split()) @@ -601,13 +602,15 @@ def __init__(self, messages, stage): cleaned.append(text) self.messages = cleaned or ['The reply could not be used.'] self.stage = stage + self.diagnostics = list(diagnostics)[:ASSIST_DIAGNOSTIC_LIMIT] super().__init__(stage) def parse_model_output(content): """The model's reply as a JSON object, or raise ``_Correctable``. One Markdown fence is tolerated.""" if not isinstance(content, str) or not content.strip(): - raise _Correctable(['The reply was empty. Reply with exactly one JSON object.'], 'parse') + raise _Correctable(['The reply was empty. Reply with exactly one JSON object.'], 'parse', + diagnostics=[{'assist_rule': 'empty_reply'}]) text = content.strip() fenced = _JSON_FENCE.match(text) if fenced: @@ -617,11 +620,14 @@ def parse_model_output(content): except (ValueError, RecursionError): raise _Correctable( ['The reply was not valid JSON. Reply with exactly one JSON object and nothing else.'], 'parse', + diagnostics=[{'assist_rule': 'invalid_json'}], ) from None if not isinstance(output, dict): - raise _Correctable(['The reply must be one JSON object.'], 'parse') + raise _Correctable(['The reply must be one JSON object.'], 'parse', + diagnostics=[{'assist_rule': 'reply_not_object'}]) if _json_problem(output) is not None: - raise _Correctable(['The reply contains text that is not valid Unicode or is nested too deeply.'], 'parse') + raise _Correctable(['The reply contains text that is not valid Unicode or is nested too deeply.'], 'parse', + diagnostics=[{'assist_rule': 'invalid_json_value'}]) return output @@ -681,7 +687,7 @@ class WorkflowAssistServices: """ def __init__(self, *, limiter, read_base, resolve_references, load_options, load_excerpt, call_model, dry_run, - agent_email_capable=None, m365_connected=None, log=None, clock=time.monotonic): + agent_email_capable=None, m365_connected=None, log=None, clock=time.monotonic, diagnostics=None): self.limiter = limiter self.read_base = read_base self.resolve_references = resolve_references @@ -693,6 +699,7 @@ def __init__(self, *, limiter, read_base, resolve_references, load_options, load self.m365_connected = m365_connected or (lambda _user_id: None) self.log = log or (lambda _message, _extra, _level: None) self.clock = clock + self.diagnostics = diagnostics or AssistDiagnostics() # --------------------------------------------------------------------------- @@ -781,14 +788,17 @@ def evaluate(self, content, finish_reason): if finish_reason == 'length': raise _Correctable( ['The reply was cut off before it ended. Reply with fewer operations or a shorter reply.'], 'length', + diagnostics=[{'assist_rule': 'output_truncated'}], ) output = parse_model_output(content) - messages = validate_assist_output(output) + diagnostics = [] + messages = validate_assist_output(output, diagnostics=diagnostics) if messages: - raise _Correctable(messages, 'schema') + raise _Correctable(messages, 'schema', diagnostics=diagnostics) reply = clean_reply(output['reply']) if not reply: - raise _Correctable(['reply must be plain text that is not blank.'], 'schema') + raise _Correctable(['reply must be plain text that is not blank.'], 'schema', + diagnostics=[{'assist_rule': 'reply_required'}]) operation_count = len(output.get('operations') or []) if output['outcome'] != 'changed': return _Attempt(output['outcome'], reply) @@ -797,17 +807,19 @@ def evaluate(self, content, finish_reason): try: candidate, info = apply_assist_operations(draft, output, self.handles, self.context) except AssistApplyError as exc: - raise _Correctable(exc.messages, 'apply') from None + raise _Correctable(exc.messages, 'apply', + diagnostics=exc.diagnostics or [{'assist_rule': 'operation_invalid'}]) from None violation = workflow_assist_violation(draft, candidate) if violation: - raise _Correctable([violation], 'violation') + raise _Correctable([violation], 'violation', diagnostics=[{'assist_rule': 'protected_workflow'}]) changes = workflow_changes(draft, candidate) if not changes: return _Attempt('explained', _NO_CHANGE_REPLY, operation_count=operation_count) try: projection = workflow_for_save(_json_copy(candidate), self.original) except WorkflowEditorProjectionError: - raise _Correctable(['The workflow editor could not save the changed workflow.'], 'projection') from None + raise _Correctable(['The workflow editor could not save the changed workflow.'], 'projection', + diagnostics=[{'assist_rule': 'projection_invalid'}]) from None result = self.run.services.dry_run(self.run.user_id, validation_copy(projection)) tolerated = False if not (result or {}).get('ok'): @@ -817,7 +829,10 @@ def evaluate(self, content, finish_reason): if code in codes: raise WorkflowAssistError(code) if _error_signature(errors) != _error_signature(self.baseline_errors()): - raise _Correctable(self._validation_messages(errors, candidate), 'validation') + raise _Correctable(self._validation_messages(errors, candidate), 'validation', + diagnostics=[{ + 'assist_rule': 'save_validation', 'assist_validation_code': error.get('code'), + } for error in errors[:ASSIST_DIAGNOSTIC_LIMIT]] or [{'assist_rule': 'save_validation'}]) tolerated = True return _Attempt( 'changed', reply, candidate=candidate, info=info, changes=changes, projection=projection, @@ -981,6 +996,8 @@ def __init__(self, services, user_id): self.started = services.clock() self.deadline = self.started + ASSIST_DEADLINE_SECONDS self.model_called = False + self.diagnostics = services.diagnostics + self.diagnostics.bind('workflow', 'personal', clock=services.clock) self.metrics = { 'user_id': user_id, 'submission_id': None, 'status': None, 'outcome': None, 'code': None, 'stage': 'request', 'error_type': None, 'invalid_stage': None, 'operation_count': 0, @@ -996,6 +1013,7 @@ def stage(self, name): self.metrics['stage'] = name def execute(self, request): + self.diagnostics.bind('workflow', 'personal', request.submission_id, clock=self.services.clock) services = self.services user_id = self.user_id self.metrics.update({ @@ -1099,6 +1117,7 @@ def _model_turns(self, envelope, evaluator): """At most two model calls: the reply, then one correction round with server-authored errors.""" previous_errors = None for attempt_number in range(1, ASSIST_MODEL_ATTEMPTS + 1): + self.diagnostics.attempt = attempt_number remaining = self.remaining() if remaining < ASSIST_MIN_MODEL_SECONDS: raise WorkflowAssistError('assistant_timeout') @@ -1106,19 +1125,33 @@ def _model_turns(self, envelope, evaluator): messages = envelope.messages(previous_errors) self.model_called = True self.metrics['model_calls'] += 1 + self.diagnostics.emit('model_started', assist_stage='model', remaining_ms=int(remaining * 1000)) content, finish_reason = self.services.call_model(messages, remaining - ASSIST_POST_MODEL_SECONDS) + self.diagnostics.emit( + 'model_finished', assist_stage='evaluate', assist_finish_reason=assist_finish_reason(finish_reason), + output_present=isinstance(content, str) and bool(content.strip()), + output_length=len(content) if isinstance(content, str) else 0, + ) self.stage('evaluate') try: return evaluator.evaluate(content, finish_reason) except _Correctable as exc: self.metrics['invalid_stage'] = exc.stage + for reason_index, diagnostic in enumerate(exc.diagnostics, start=1): + self.diagnostics.emit('validation_rejected', **diagnostic, assist_stage=exc.stage, + reason_index=reason_index, reason_count=len(exc.diagnostics)) if attempt_number >= ASSIST_MODEL_ATTEMPTS: break self.metrics['correction_count'] += 1 + self.diagnostics.emit('correction_started', assist_stage=exc.stage) previous_errors = exc.messages raise WorkflowAssistError('assistant_output_invalid') def log(self, status, *, outcome=None, code=None): + self.diagnostics.emit('request_finished', assist_stage=self.metrics['stage'], assist_code=code, + assist_outcome=outcome or 'failed', status=status, + model_calls=self.metrics['model_calls'], correction_count=self.metrics['correction_count'], + operation_count=self.metrics['operation_count']) self.metrics.update({ 'status': status, 'outcome': outcome, 'code': code, 'duration_ms': max(0, int((self.services.clock() - self.started) * 1000)), diff --git a/application/single_app/functions_workflow_assist_operations.py b/application/single_app/functions_workflow_assist_operations.py index 3597e9a4f..b176b9e27 100644 --- a/application/single_app/functions_workflow_assist_operations.py +++ b/application/single_app/functions_workflow_assist_operations.py @@ -27,6 +27,7 @@ import uuid from jsonschema import Draft202012Validator +from functions_assist_diagnostics import ASSIST_DIAGNOSTIC_LIMIT from functions_workflow_alert_authoring import alert_rule_properties from functions_workflow_alerts import normalize_alert_rule, normalize_alert_flag @@ -118,15 +119,17 @@ class AssistApplyError(Exception): """The model's operations cannot be applied. ``messages`` are server-authored and content-free.""" - def __init__(self, messages): + def __init__(self, messages, *, diagnostics=()): self.messages = [str(message) for message in messages] + self.diagnostics = list(diagnostics)[:ASSIST_DIAGNOSTIC_LIMIT] super().__init__('; '.join(self.messages)) class _OperationError(Exception): - def __init__(self, message): + def __init__(self, message, rule='operation_invalid'): super().__init__(message) self.message = message + self.rule = rule # --------------------------------------------------------------------------- @@ -144,16 +147,16 @@ def _string(value): def model_text(value, label, max_length, *, multiline=False, required=True): """Check one piece of model-written text and return it trimmed, or raise ``_OperationError``.""" if not isinstance(value, str): - raise _OperationError(f'{label} must be text.') + raise _OperationError(f'{label} must be text.', 'text_invalid') text = js_trim(value) if required and not text: - raise _OperationError(f'{label} must not be blank.') + raise _OperationError(f'{label} must not be blank.', 'required_value') if len(text) > max_length: - raise _OperationError(f'{label} must be {max_length} characters or fewer.') + raise _OperationError(f'{label} must be {max_length} characters or fewer.', 'text_too_long') if _CONTROL_CHARACTERS.search(text): - raise _OperationError(f'{label} must not contain control characters.') + raise _OperationError(f'{label} must not contain control characters.', 'text_invalid') if not multiline and _LINE_BREAKS.search(text): - raise _OperationError(f'{label} must be a single line.') + raise _OperationError(f'{label} must be a single line.', 'text_multiline') return text @@ -1123,21 +1126,21 @@ def _task_id(self, handle): if handle.startswith('new_'): task_id = self.new_tasks.get(handle) if task_id is None: - raise _OperationError('It names a new task that no earlier add_task created.') + raise _OperationError('It names a new task that no earlier add_task created.', 'handle_invalid') else: target = self.handles.resolve(handle) if target is None or target[0] != 'task': - raise _OperationError('It names a task that is not in the draft.') + raise _OperationError('It names a task that is not in the draft.', 'handle_invalid') task_id = target[1] if task_id in self.removed_tasks: - raise _OperationError('It names a task that an earlier operation removed.') + raise _OperationError('It names a task that an earlier operation removed.', 'handle_invalid') return task_id def _task(self, handle): task_id = self._task_id(handle) index = self._task_index(task_id) if index < 0: - raise _OperationError('It names a task that is not in the draft.') + raise _OperationError('It names a task that is not in the draft.', 'handle_invalid') return index, self._tasks()[index] def _renumber(self): @@ -1149,17 +1152,17 @@ def _renumber(self): def _agent(self, handle): target = self.handles.resolve(handle) if target is None or target[0] != 'agent': - raise _OperationError('It names an agent that is not one of the choices.') + raise _OperationError('It names an agent that is not one of the choices.', 'handle_invalid') return target[1] def _model(self, handle): target = self.handles.resolve(handle) if handle == 'default_model': if target is None: - raise _OperationError('The default model is not available here. Choose one of the models.') + raise _OperationError('The default model is not available here. Choose one of the models.', 'handle_invalid') return None if target is None or target[0] != 'model': - raise _OperationError('It names a model that is not one of the choices.') + raise _OperationError('It names a model that is not one of the choices.', 'handle_invalid') return target[1] def _references(self): @@ -1183,11 +1186,11 @@ def _document(self, handle): """``(identity, reference or None, label)`` for a document handle the model sent.""" target = self.handles.resolve(handle) if target is None or target[0] not in ('reference', 'document'): - raise _OperationError('It names a document that is not in the draft or the request.') + raise _OperationError('It names a document that is not in the draft or the request.', 'handle_invalid') if target[0] == 'reference': reference = self._reference_by_id(target[1]) if reference is None: - raise _OperationError('It names a shared reference that an earlier operation removed.') + raise _OperationError('It names a shared reference that an earlier operation removed.', 'handle_invalid') return reference_identity(reference, self.user_id), reference, '' entry = self.handles.documents.get(self.handles.identity_handles.get(target[1])) or {} return target[1], self._reference_for_identity(target[1]), entry.get('file_label') or '' @@ -1197,7 +1200,7 @@ def _known_scope(identity): if identity[0] == UNKNOWN_SCOPE: raise _OperationError( 'The workspace of that document is not known, so the assistant cannot place it. ' - 'Ask the user to add it with the document picker.' + 'Ask the user to add it with the document picker.', 'document_scope_unknown', ) return identity @@ -1224,9 +1227,11 @@ def op_set_description(self, op): def _check_trigger_editable(self, *, schedule=True): trigger_type = self.candidate.get('trigger_type') if trigger_type == 'file_sync': - raise _OperationError('This workflow runs on File Sync changes, which the assistant cannot change yet.') + raise _OperationError('This workflow runs on File Sync changes, which the assistant cannot change yet.', + 'protected_workflow') if schedule and trigger_type == 'interval' and workflow_schedule_for_editor(self.candidate.get('schedule')) is None: - raise _OperationError('The current schedule uses options the editor cannot show, so the assistant cannot change it.') + raise _OperationError('The current schedule uses options the editor cannot show, so the assistant cannot change it.', + 'protected_workflow') def _current_calendar_timezone(self): schedule = workflow_schedule_for_editor(self.candidate.get('schedule')) @@ -1241,7 +1246,7 @@ def _set_schedule(self, schedule): enforce_workflow_schedule_minimum(normalized, self.min_interval_seconds) except WorkflowPublicValidationError as exc: # Schedule messages name only fixed limits and choices, never the value sent. - raise _OperationError(str(exc)) from None + raise _OperationError(str(exc), 'schedule_invalid') from None self._set(self.candidate, 'trigger_type', 'interval') self._set(self.candidate, 'schedule', schedule) @@ -1263,12 +1268,12 @@ def op_set_schedule_calendar(self, op): if 'timezone' in op: timezone = model_text(op['timezone'], 'The time zone', ASSIST_TIMEZONE_MAX_LENGTH) if timezone not in workflow_schedule_timezones(): - raise _OperationError('The time zone must be an IANA time zone name, such as America/New_York.') + raise _OperationError('The time zone must be an IANA time zone name, such as America/New_York.', 'schedule_invalid') else: # changeRepeats keeps a calendar schedule's time zone, else uses the browser's. timezone = self._current_calendar_timezone() or self.context.time_zone if not timezone: - raise _OperationError('No time zone is known for this schedule. Ask the user which time zone to use.') + raise _OperationError('No time zone is known for this schedule. Ask the user which time zone to use.', 'schedule_invalid') frequency = op['frequency'] days = op.get('days_of_week') or [] self._set_schedule({ @@ -1336,7 +1341,8 @@ def op_add_alert_rule(self, op): condition = self._alert_condition(op['condition']) scope = op.get('scope') or {'type': 'final'} if condition['type'] in ASSIST_SCOPELESS_CONDITIONS and scope['type'] != 'final': - raise _OperationError('Run status, File Sync and agent signal rules watch the whole run, so their scope must be final.') + raise _OperationError('Run status, File Sync and agent signal rules watch the whole run, so their scope must be final.', + 'alert_scope_invalid') task_id = self._task_id(scope['task']) if scope['type'] == 'task' else '' # newWorkflowAlertRule's shape, with the model's choices. self.alert_rules.append((None, { @@ -1355,10 +1361,10 @@ def op_update_alert_rule(self, op): self._alerts() target = self.handles.resolve(op['rule']) if target is None or target[0] != 'alert': - raise _OperationError('It names an alert rule that is not in the draft.') + raise _OperationError('It names an alert rule that is not in the draft.', 'handle_invalid') rule = next((rule for index, rule in self.alert_rules if index == target[1]), None) if rule is None: - raise _OperationError('It names an alert rule that an earlier operation removed.') + raise _OperationError('It names an alert rule that an earlier operation removed.', 'handle_invalid') for key in ('name', 'enabled', 'severity', 'delivery', 'require_acknowledgment', 'sound', 'size'): if key in op: rule[key] = ( @@ -1371,18 +1377,19 @@ def op_update_alert_rule(self, op): scope = op['scope'] rule['scope'] = {'type': scope['type'], 'task_id': self._task_id(scope['task']) if scope['type'] == 'task' else ''} if rule['condition']['type'] in ASSIST_SCOPELESS_CONDITIONS and rule['scope']['type'] != 'final': - raise _OperationError('Run status, File Sync and agent signal rules watch the whole run, so their scope must be final.') + raise _OperationError('Run status, File Sync and agent signal rules watch the whole run, so their scope must be final.', + 'alert_scope_invalid') def op_remove_alert_rule(self, op): self._alerts() target = self.handles.resolve(op['rule']) if target is None or target[0] != 'alert': - raise _OperationError('It names an alert rule that is not in the draft.') + raise _OperationError('It names an alert rule that is not in the draft.', 'handle_invalid') for position, (index, _rule) in enumerate(self.alert_rules): if index == target[1]: del self.alert_rules[position] return - raise _OperationError('It names an alert rule that an earlier operation removed.') + raise _OperationError('It names an alert rule that an earlier operation removed.', 'handle_invalid') # -- runners ----------------------------------------------------------- @@ -1403,7 +1410,7 @@ def op_set_workflow_runner(self, op): def op_set_task_runner(self, op): _index, task = self._task(op['task']) if js_truthy(task.get('publication')): - raise _OperationError('A publication task has no runner to change.') + raise _OperationError('A publication task has no runner to change.', 'protected_workflow') current = task.get('runner') if isinstance(task.get('runner'), dict) else {} runner_type = op['runner'] # TaskRunnerFields writes a fresh runner of the chosen type. @@ -1431,7 +1438,8 @@ def op_set_task_runner(self, op): def _refuse_structured(self): if self.structured: raise _OperationError( - 'This workflow is a flow. Only the flow editor adds, removes, moves or connects its tasks.' + 'This workflow is a flow. Only the flow editor adds, removes, moves or connects its tasks.', + 'protected_workflow', ) def _position_after(self, handle, moving_id=None): @@ -1439,20 +1447,20 @@ def _position_after(self, handle, moving_id=None): return 0 task_id = self._task_id(handle) if task_id == moving_id: - raise _OperationError('A task cannot be placed after itself.') + raise _OperationError('A task cannot be placed after itself.', 'task_self_reference') index = self._task_index(task_id) if index < 0: - raise _OperationError('It names a task that is not in the draft.') + raise _OperationError('It names a task that is not in the draft.', 'handle_invalid') return index + 1 def op_add_task(self, op): self._refuse_structured() key = op['key'] if key in self.new_tasks: - raise _OperationError('Each add_task needs its own key.') + raise _OperationError('Each add_task needs its own key.', 'new_task_key_repeated') tasks = self._tasks() if len(tasks) >= self.max_tasks: - raise _OperationError(f'A workflow can have at most {self.max_tasks} tasks.') + raise _OperationError(f'A workflow can have at most {self.max_tasks} tasks.', 'task_limit') position = self._position_after(op['after']) if 'after' in op else len(tasks) task = create_workflow_task(len(tasks)) task['id'] = _new_uuid() @@ -1471,9 +1479,9 @@ def op_remove_task(self, op): index, task = self._task(op['task']) tasks = self._tasks() if len(tasks) <= 1: - raise _OperationError('A workflow needs at least one task.') + raise _OperationError('A workflow needs at least one task.', 'task_required') if task.get('approval') is not None: - raise _OperationError('The task has an approval step, which only the user can remove.') + raise _OperationError('The task has an approval step, which only the user can remove.', 'protected_workflow') del tasks[index] self._renumber() self.removed_tasks.add(task['id']) @@ -1523,7 +1531,7 @@ def op_set_task_inputs(self, op): for handle in op['from']: producer_id = self._task_id(handle) if producer_id == task['id']: - raise _OperationError('A task cannot take input from itself.') + raise _OperationError('A task cannot take input from itself.', 'task_self_reference') if producer_id not in producers: producers.append(producer_id) existing = [item for item in inputs if _is_legacy_binding(item)] if isinstance(inputs, list) else [] @@ -1606,7 +1614,8 @@ def op_set_task_references(self, op): for handle in op['references']: identity, reference, _label = self._document(handle) if reference is None: - raise _OperationError('It names a document that is not a shared reference. Use bind_reference first.') + raise _OperationError('It names a document that is not a shared reference. Use bind_reference first.', + 'reference_not_bound') if reference['id'] not in selected: selected.append(reference['id']) self.placed.add(identity) @@ -1616,7 +1625,7 @@ def op_set_task_references(self, op): def op_unbind_reference(self, op): _identity, reference, _label = self._document(op['reference']) if reference is None: - raise _OperationError('It names a document that is not a shared reference.') + raise _OperationError('It names a document that is not a shared reference.', 'reference_not_bound') references = self._references() for position, item in enumerate(references): if item is reference: @@ -1630,12 +1639,14 @@ def op_unbind_reference(self, op): def _check_document_target(self, task): if js_truthy(task.get('publication')): - raise _OperationError('A publication task has no document action.') + raise _OperationError('A publication task has no document action.', 'protected_workflow') mode = document_action_mode(task.get('document_action')) if mode == 'current_item': - raise _OperationError('The task analyzes the current loop document, which only the flow editor changes.') + raise _OperationError('The task analyzes the current loop document, which only the flow editor changes.', + 'protected_workflow') if mode == 'preserve': - raise _OperationError('The task has an advanced document action that the assistant cannot change.') + raise _OperationError('The task has an advanced document action that the assistant cannot change.', + 'protected_workflow') def _target_identity(self, handle): identity, _reference, _label = self._document(handle) @@ -1766,37 +1777,61 @@ def apply_assist_operations(draft, output, handles, context): """ applier = _Applier(draft, handles, context) messages = [] + diagnostics = [] for position, operation in enumerate(output.get('operations') or [], start=1): name = operation['op'] try: getattr(applier, f'op_{name}')(operation) except _OperationError as exc: messages.append(f'Operation {position} ({name}): {exc.message}') + diagnostics.append({'assist_rule': exc.rule, 'operation_index': position, 'assist_operation': name}) if len(messages) >= _MAX_SCHEMA_ERRORS: break if not messages: messages = applier.finish(output) + if messages: + diagnostics.append({'assist_rule': 'candidate_invalid'}) if messages: - raise AssistApplyError(messages) + raise AssistApplyError(messages, diagnostics=diagnostics) return applier.candidate, applier.info() -def _schema_errors(validator, instance, prefix): +_SCHEMA_DIAGNOSTIC_RULES = { + 'required': 'schema_required', 'additionalProperties': 'schema_additional_properties', + 'not': 'schema_not', 'enum': 'schema_enum', 'const': 'schema_const', 'type': 'schema_type', + 'pattern': 'schema_pattern', 'minLength': 'schema_min_length', 'maxLength': 'schema_max_length', + 'minItems': 'schema_min_items', 'maxItems': 'schema_max_items', 'uniqueItems': 'schema_unique_items', + 'minimum': 'schema_minimum', 'maximum': 'schema_maximum', 'oneOf': 'schema_one_of', +} + + +def _schema_errors(validator, instance, prefix, diagnostics=None, *, position=0, operation=None): errors = sorted(validator.iter_errors(instance), key=lambda item: (list(map(str, item.absolute_path)), item.validator)) + if diagnostics is not None: + for error in errors[:_MAX_SCHEMA_ERRORS]: + if len(diagnostics) >= ASSIST_DIAGNOSTIC_LIMIT: + break + diagnostics.append({ + 'assist_rule': _SCHEMA_DIAGNOSTIC_RULES.get(error.validator, 'schema_invalid'), + 'operation_index': position, 'assist_operation': operation, + }) return [f'{prefix}{_schema_error_message(error)}' for error in errors[:_MAX_SCHEMA_ERRORS]] -def validate_assist_output(output): +def validate_assist_output(output, *, diagnostics=None): """Schema errors in the model's parsed reply, as server-authored messages; empty when it is valid.""" if not isinstance(output, dict): + if diagnostics is not None: + diagnostics.append({'assist_rule': 'reply_not_object'}) return ['The reply must be a JSON object.'] - messages = _schema_errors(_ENVELOPE_VALIDATOR, output, '') + messages = _schema_errors(_ENVELOPE_VALIDATOR, output, '', diagnostics) if messages: return messages for position, operation in enumerate(output.get('operations') or [], start=1): name = operation['op'] prefix = f'Operation {position} ({name}): ' - messages.extend(_schema_errors(_OPERATION_VALIDATORS[name], operation, prefix)) + messages.extend(_schema_errors(_OPERATION_VALIDATORS[name], operation, prefix, diagnostics, + position=position, operation=name)) if len(messages) >= _MAX_SCHEMA_ERRORS: break return messages[:_MAX_SCHEMA_ERRORS] diff --git a/application/single_app/functions_workflow_assist_runtime.py b/application/single_app/functions_workflow_assist_runtime.py index 9bbb0ede4..de887b2df 100644 --- a/application/single_app/functions_workflow_assist_runtime.py +++ b/application/single_app/functions_workflow_assist_runtime.py @@ -29,7 +29,8 @@ from azure.core.exceptions import AzureError from openai import APITimeoutError, BadRequestError, RateLimitError -from functions_appinsights import log_event +from functions_appinsights import log_assist_debug, log_event +from functions_assist_diagnostics import AssistDiagnostics from functions_workflow_alert_safety import sanitize_workflow_alert_record from functions_workflow_assist import ASSIST_MAX_REQUEST_REFERENCES, WorkflowAssistError, WorkflowAssistServices from functions_workflow_assist_limits import CosmosAssistLimitStore, WorkflowAssistLimiter @@ -148,18 +149,21 @@ class WorkflowAssistModel: asked for, and dropped for the rest of the request when the deployment refuses it. """ - def __init__(self, client_factory, *, clock=time.monotonic): + def __init__(self, client_factory, *, clock=time.monotonic, diagnostics=None): self._client_factory = client_factory self._clock = clock self._client = None self._model_name = None self._json_mode = True + self._diagnostics = diagnostics or AssistDiagnostics() + self._provider_calls = 0 def _ready_client(self): if self._client is None: try: client, model_name = self._client_factory() except Exception as exc: + self._diagnostics.emit('provider_failed', assist_stage='model', assist_code='assistant_unavailable') raise WorkflowAssistError('assistant_unavailable') from exc self._client, self._model_name = client, model_name return self._client @@ -172,13 +176,26 @@ def __call__(self, messages, timeout): if remaining < ASSIST_MIN_CALL_SECONDS: raise WorkflowAssistError('assistant_timeout') parameters = assist_model_parameters(self._model_name, messages, json_mode=self._json_mode) + started = self._clock() + self._provider_calls += 1 try: response = client.with_options(timeout=remaining, max_retries=0).chat.completions.create(**parameters) except Exception as exc: if self._json_mode and is_json_mode_rejection(exc): + self._diagnostics.emit('json_mode_fallback', assist_stage='model', json_mode=True, + provider_status=getattr(exc, 'status_code', None), + provider_attempt=self._provider_calls) self._json_mode = False continue - raise provider_error(exc) from exc + error = provider_error(exc) + self._diagnostics.emit('provider_failed', assist_stage='model', assist_code=error.code, + provider_status=getattr(exc, 'status_code', None), json_mode=self._json_mode, + provider_attempt=self._provider_calls, + provider_duration_ms=int((self._clock() - started) * 1000)) + raise error from exc + self._diagnostics.emit('provider_finished', assist_stage='model', json_mode=self._json_mode, + provider_attempt=self._provider_calls, + provider_duration_ms=int((self._clock() - started) * 1000)) return model_reply(response) @@ -290,15 +307,17 @@ def m365_connected(user_id): def log(message, extra, level): log_event(message, extra=extra, level=level) + diagnostics = AssistDiagnostics(log_assist_debug) return WorkflowAssistServices( limiter=WorkflowAssistLimiter(CosmosAssistLimitStore(cosmos_settings_container)), read_base=read_base, resolve_references=resolve_references, load_options=load_options, load_excerpt=load_excerpt, - call_model=WorkflowAssistModel(client_factory), + call_model=WorkflowAssistModel(client_factory, diagnostics=diagnostics), dry_run=dry_run, agent_email_capable=agent_email_capable, m365_connected=m365_connected, log=log, + diagnostics=diagnostics, ) diff --git a/docs/explanation/features/AGENT_ACTION_AI_ASSISTANT.md b/docs/explanation/features/AGENT_ACTION_AI_ASSISTANT.md index 9f5ae4d6f..773b5b554 100644 --- a/docs/explanation/features/AGENT_ACTION_AI_ASSISTANT.md +++ b/docs/explanation/features/AGENT_ACTION_AI_ASSISTANT.md @@ -1,4 +1,4 @@ -# Ask AI in the Agent and Action Editors (v0.261.288) +# Ask AI in the Agent and Action Editors (v0.261.329) ## Overview @@ -16,6 +16,12 @@ Implemented in version: **0.261.288**, tracked in `application/single_app/config built in phases (shared backend, agent editor, action editor, drafted actions, then tests, documentation and the drafted-action hand-off fix) and ships as one release. +Debug-gated operation diagnostics implemented in version: **0.261.329**, tracked in +`application/single_app/config.py`. + +The same version clarifies the creation prompt's exact field paths and treatment of missing +connection details, fixing a SQL-agent request reproduced against the configured live model. + Dependencies: - **Enable Agents** (`enable_semantic_kernel`) must be on. @@ -95,6 +101,35 @@ before saving**. Call agent actions are never drafted. - **Remove** drops a drafted action. Undoing the turn that drafted it does the same, and undoing a later turn that removed it brings it back. +The assistant must use the new action's exact field paths, not the parent agent's paths or +unprefixed field names. When connection details have not been supplied, it can omit those +type-specific values and explain what needs finishing, or ask a clarifying question without +changing the draft. It must not invent connection details or send blank placeholders for +required fields. An unfinished SQL action still needs its server and database before saving. + +### Diagnosing a failed turn + +When **Enable Debug Logging** (`enable_debug_logging`) is enabled, agent and action turns emit +`[EDITOR_ASSIST] Ask AI diagnostic` records to the configured Application Insights logger and +the application's debug console mirror. With it disabled, none of these new detailed records +are emitted; the existing request summaries remain unchanged. + +Each record identifies the assistant surface, scope category, attempt and stage, with a hash of +the validated submission ID for correlation. Validation records include a closed rule code, +operation index and operation category. Safe, explicitly allowlisted fields and field kinds help +distinguish an unknown path from a blank required value or a bad choice handle. Up to 12 reasons +are recorded per rejected attempt. Provider records distinguish a failed call from a JSON-mode +fallback; successful calls record their duration. A final record reports the outcome, status and +correction count. + +These records never include instructions, draft values, replies, credentials, raw identity IDs, +provider exception messages or unknown field names. A SQL request without connection details can +produce an unfinished action draft that needs attention before saving; diagnostics do not +authorize connecting to a database or saving that draft. + +See [Ask AI operation diagnostics](../fixes/ASK_AI_OPERATION_DIAGNOSTICS_FIX.md) for bounded queries +and the distinction between diagnosing a rejection and fixing its underlying cause. + ## Usage Instructions 1. Open an agent or action in the V2 editor, for a personal, group or global agent or action. @@ -109,12 +144,18 @@ The guides [Create an agent](../../guides/create-an-agent.md) and ## Testing and Validation - `functional_tests/test_editor_assist_core.py`: request validation, prompt building and answer checking. +- `functional_tests/test_editor_assist_create_item_prompt.py`: exact new-action path guidance, + the live-observed malformed-operation pattern and a valid unfinished SQL draft. +- `functional_tests/test_ask_ai_debug_diagnostics.py`: real logging serialization, both debug + states, per-attempt rules, provider failures and fallback, privacy and best-effort observers. - `functional_tests/route_tests/test_editor_assist_policy.py`: scope authorization, feature toggles and route policy. - `functional_tests/test_v2_agent_editor_assist_logic.mjs`, `test_v2_action_editor_assist_logic.mjs` and `test_v2_agent_drafted_actions_logic.mjs`: the adapters' describe and apply logic. - `ui_tests/test_v2_agent_action_ask_ai.py`: an agent turn applied and undone, a drafted action finished in the action editor and saved with the agent, an action turn that never sends the - stored key, and the panels hidden while the toggles are off. + stored key, and the panels hidden while the toggles are off. SQL new-agent cases use the actual + browser-generated descriptors to check unfinished drafts, successful correction, terminal + rejection and undo without persistence. - `ui_tests/test_v2_group_action_drafts.ts` (run by `test_v2_group_actions.py`): the drafted-action hand-off never crosses a workspace boundary. diff --git a/docs/explanation/features/WORKFLOW_AI_ASSISTANT.md b/docs/explanation/features/WORKFLOW_AI_ASSISTANT.md index 05402692e..e090d2a1b 100644 --- a/docs/explanation/features/WORKFLOW_AI_ASSISTANT.md +++ b/docs/explanation/features/WORKFLOW_AI_ASSISTANT.md @@ -1,4 +1,4 @@ -# Workflow AI Assistant (v0.261.315) +# Workflow AI Assistant (v0.261.329) ## Overview @@ -23,6 +23,9 @@ Implemented in version: **0.261.208** (the endpoint) and **0.261.213** (the **As Phases 3b and 3c of the [chat orchestration workflows roadmap](CHAT_ORCHESTRATION_WORKFLOWS_ROADMAP.md) (#1548, part of #1543). +Debug-gated operation diagnostics implemented in version: **0.261.329**, tracked in +`application/single_app/config.py`. + The assistant ships in three layers: | Layer | What it adds | Status | @@ -499,6 +502,22 @@ only these fields: `user_id`, `submission_id`, `status`, `outcome`, `code`, `sta `warning_codes`, `fault_location` (file and line, on a 500 only) and `duration_ms`. A body that can't be read logs `[WorkflowAssist] Assist request refused` with its code, status and stage. +With **Enable Debug Logging** (`enable_debug_logging`) enabled, the core also emits +`[WORKFLOW_ASSIST] Ask AI diagnostic` records for model attempts, validation rejection, correction +and the terminal outcome. The shared provider adapter records call duration, safe failure status +and JSON-mode fallback. These new records reach the configured Application Insights logger and +the application's debug console mirror only while debug logging is enabled. + +The records retain closed rule codes, operation categories and indexes, attempt counters, +finish-reason categories and a hash of the validated submission ID. Workflow schema failures +identify the schema keyword; apply failures identify the operation and rule; save-check failures +retain only explicitly allowlisted validation codes. At most 12 reasons are recorded per rejected +attempt. Private content, raw identity IDs, arbitrary paths and exception messages are excluded. +Existing summaries and the single correction retry are unchanged. + +The [Ask AI operation diagnostics reference](../fixes/ASK_AI_OPERATION_DIAGNOSTICS_FIX.md) +includes bounded queries and explains remaining diagnostic limitations. + ### The Ask AI tab **Ask AI** is the second tab in the editor's side panel, after **Changes**. It runs on Track A1's @@ -800,6 +819,7 @@ All tests use a scripted model. None calls a live model. | `test_workflow_assist_scenarios.py` | The roadmap's "Done when" cases, placement, the un-normalized candidate, the correction round and 502, warnings, deadlines and content-free telemetry | | `test_workflow_assist_dry_run_parity.py` | The Python `workflowForSave` projection against Phase 2's dry run, including a whole `expected_count` given as `"12"` or `12.0`, which is checked and saved as an `int` | | `test_workflow_assist_limits_runtime.py` | The limiter (in flight, window, `Retry-After`, refunds, fail closed), the model parameters and provider errors, the runtime adapters, and a whole request against stores that fail on any write other than the caller's rate-limit document | +| `test_ask_ai_debug_diagnostics.py` | Debug-on/off behavior in both logging sinks, per-attempt schema/apply/save rejection rules, provider failures and fallback, finish reasons, content privacy and observer failure isolation | | `test_workflow_assist_field_parity.py` | The Python field lists, violation messages and editor vocabularies against the V2 TypeScript, read as text | | `test_workflow_assist_candidate_parity.py` | 24 Python candidates replayed through the real V2 editor code under Node, and the type-strict corpus of numbers, whitespace, JSON literals and File Sync saves. Tables of known JavaScript answers also run without Node. | | `route_tests/test_workflow_assist_policy.py` | The decorator order, the gates and their status codes, `is_workflow_assistant_enabled_for_user` and the V2 bootstrap flag built from it, and strict response serialization | diff --git a/docs/explanation/fixes/ASK_AI_OPERATION_DIAGNOSTICS_FIX.md b/docs/explanation/fixes/ASK_AI_OPERATION_DIAGNOSTICS_FIX.md new file mode 100644 index 000000000..430536f6b --- /dev/null +++ b/docs/explanation/fixes/ASK_AI_OPERATION_DIAGNOSTICS_FIX.md @@ -0,0 +1,247 @@ +# Ask AI Creation Contract and Operation Diagnostics Fix (v0.261.331) + +## Issue and root cause + +Agent creation through Ask AI returned HTTP 502 with `assistant_output_invalid` after both +model attempts. The final response passed parsing and response-shape validation but failed +operation validation. Existing summaries retained the last stage, not the particular operation +or validation rule. Application Insights also reduced most string dimensions to their lengths. +Consequently, the rejected operation and the first attempt's reason could not be recovered. + +The same SQL instruction was then reproduced locally against the application's configured +Azure model using a real browser-generated 12-field new-agent request and synthetic workspace +choices. Two runs returned the same terminal 502. The model used `displayName` and `description` +instead of the required `/displayName` and `/description` paths; it initially also supplied +empty SQL server and database fields. The correction removed the empty connection fields but +still used the wrong name paths, so the required action name remained absent. + +The prompt's general path rule referred to the parent draft even for new-item values, and its +creation instructions did not clearly require leading slashes or explain how to represent +unknown connection details. This change clarifies those contracts and fixes the live-reproduced +failure without accepting malformed operations. It also fixes the diagnostic gap. The original +historical response was not retained, so the evidence comes from a fresh live-model reproduction, +not recovery of that request's exact response. + +Fixed/Implemented in version: **0.261.329**. The application version is recorded in +`application/single_app/config.py`. + +## Technical details + +`functions_editor_assist.py` now scopes the parent-draft path rule to `set` operations. Its +`create_item` instructions require exact, case-sensitive paths including the leading `/`, +distinguish new-action fields from the parent agent's fields and give the `/displayName` +example explicitly. Unknown type-specific connection details must be omitted rather than +filled with blank placeholders or invented values; the assistant can instead ask a short +question with no operations. Every required common field still must be supplied. + +The validator remains strict: unprefixed field names are rejected, not silently repaired. +Missing required connection details still block saving in the action editor. No SQL connection +or editor persistence occurs during Ask AI. + +`functions_assist_diagnostics.py` supplies a bootstrap-free, injected observer and a closed +property allowlist. The editor and workflow cores attach typed diagnostic metadata at the +validation decision, not by parsing human-readable correction messages. Runtime adapters inject +the same observer into the core and its model adapter. + +`functions_appinsights.py` gates `log_assist_debug()` on the existing `enable_debug_logging` +setting before emitting an event. Enabled events use ordinary `log_event()` so the configured +Application Insights logger and debug console mirror both receive them. Using +`log_event(debug_only=True)` would reach only the console. The serializer preserves only the +explicitly allowlisted categorical strings; unrelated string properties remain protected. + +Affected endpoints are `POST /api/agents/assist`, `POST /api/actions/assist` and +`POST /api/user/workflows/assist`. There are no new routes, settings, retries or browser assets. +Feature gates, authorization, response bodies, atomic proposal validation and deadlines remain +unchanged. Logging failures cannot replace the proposal, rejection or limiter cleanup. + +### Events and dimensions + +| Event | Useful dimensions | +| --- | --- | +| `model_started` | Core attempt number and remaining deadline | +| `provider_finished` | Provider-call number, duration and whether JSON mode was used | +| `provider_failed` | Safe assistant error code, provider status when available and call duration | +| `json_mode_fallback` | The refused provider-call number and status; no exception text | +| `model_finished` | Output presence and length, normalized finish reason | +| `validation_rejected` | Stage, closed rule, operation index/category, reason index/count and approved field metadata | +| `correction_started` | The rejected attempt and stage that prompted the one correction round | +| `request_finished` | Status, outcome, safe error code, model/correction counts and successful operation counts | + +All records carry `assist_surface`, `assist_scope`, `attempt` and elapsed milliseconds. +Once the request is validated, `turn_id_hash` correlates its events without logging the raw +submission ID. Application Insights stores the values with the `sc_` prefix in `Properties`. +The normal request trace supplies `OperationId` when tracing is configured. `provider_attempt` +counts provider calls across the request; a JSON-mode fallback can add a provider call without +adding a core correction attempt. + +Rejections record at most 12 reasons per attempt. `reason_count` is the count retained, not an +unbounded total. Editor field identifiers are preserved only for a small explicit allowlist; +other fields retain a kind and whether the descriptor was known. Workflow save failures include +`assist_validation_code` only for approved server codes. Some workflow candidate-finalization +and apply failures remain grouped as `candidate_invalid` or `operation_invalid`. + +### Privacy boundary + +No new record contains prompts, conversation text, draft values, model replies, document titles, +credentials, endpoints, raw user/workspace IDs, unknown field names or provider exception text. +Provider finish reasons and validation codes outside the allowlist are categorized or omitted. +Measurements are finite and bounded. Debug logging is not permission to log private content. + +## Diagnosing a reproduced failure + +For diagnosis through the app, deploy the instrumented build to an approved environment, enable +**Enable Debug Logging** and send one Ask AI request without saving the resulting draft. +Any deployment, restart or production settings change requires its own approval. A local +reproduction can instead use the configured model with a synthetic browser-generated request +and local debug logging, as this investigation did; neither app deployment nor stored settings +needs to change. + +Find the request in `AppRequests`, then inspect its operation's diagnostic events. Both rejected +attempts matter: the correction can fail for a different reason. A `required_value` on the SQL +server field differs from `new_required_field` on a missing action name, `new_type_invalid`, +`choice_handle_invalid` or an unknown path. Only an observed rejection supports choosing the +corresponding behavioral fix. + +### Application Insights through Log Analytics + +Run these against the Log Analytics workspace linked to the application's diagnostic settings. +Keep the time window narrow and replace the operation placeholder with the observed request's +ID. These queries are deliberately single-line: when invoking the Azure CLI from PowerShell, +passing multiline KQL can result in only the first line being applied. + +```kusto +AppRequests | where TimeGenerated > ago(30m) | where Url contains "/api/agents/assist" or Url contains "/api/actions/assist" or Url contains "/api/user/workflows/assist" | project TimeGenerated, OperationId, ResultCode, DurationMs | order by TimeGenerated desc | take 50 +``` + +```kusto +AppTraces | where TimeGenerated > ago(30m) | where OperationId == "PASTE_REQUEST_OPERATION_ID" | where tostring(Properties.sc_message) in ("[EDITOR_ASSIST] Ask AI diagnostic", "[WORKFLOW_ASSIST] Ask AI diagnostic") | project TimeGenerated, OperationId, Surface=tostring(Properties.sc_assist_surface), Event=tostring(Properties.sc_assist_event), Attempt=toint(Properties.sc_attempt), Stage=tostring(Properties.sc_assist_stage), Rule=tostring(Properties.sc_assist_rule), Operation=tostring(Properties.sc_assist_operation), Index=toint(Properties.sc_operation_index), Field=tostring(Properties.sc_assist_field), ValidationCode=tostring(Properties.sc_assist_validation_code), Code=tostring(Properties.sc_assist_code), TurnHash=tostring(Properties.sc_turn_id_hash) | order by TimeGenerated asc | take 100 +``` + +### App Service console + +If trace correlation is unavailable, use the same window and the submission hash from the +structured records to narrow these console results further. + +```kusto +AppServiceConsoleLogs | where TimeGenerated > ago(30m) | where ResultDescription contains "[EDITOR_ASSIST] Ask AI diagnostic" or ResultDescription contains "[WORKFLOW_ASSIST] Ask AI diagnostic" | project TimeGenerated, ResultDescription | order by TimeGenerated asc | take 100 +``` + +## Validation and impact + +`functional_tests/test_ask_ai_debug_diagnostics.py` exercises the real serializer and captures +both logging sinks. It covers all three surfaces, debug on/off, per-attempt rejection and +correction, finish reasons, provider failure/fallback, bounded reasons, unknown/private data +and observer failure isolation. + +`functional_tests/test_editor_assist_create_item_prompt.py` checks the clarified prompt and +replays the observed malformed-operation pattern with synthetic values. The prompt regression +failed before the fix and passes afterward; strict rejection and a valid unfinished SQL draft +are covered separately. + +`ui_tests/test_v2_agent_action_ask_ai.py` runs the shipped V2 bundle with the real action catalog, +browser-generated new-agent descriptors and the backend core. SQL scenarios verify an unfinished +read-only draft, assigning an existing SQL action, a clarification without mutation, a corrected +blank-server proposal, correction of unprefixed common fields, a terminal missing-name rejection +and undo. +The fixture refuses unexpected service requests and asserts no editor persistence before save. +No test connects to SQL or calls a live model. + +The new diagnostic suite passes all 44 cases, the creation-contract suite passes all 3 cases, +and the real-bundle editor suite passes all 11 cases. Combined core/runtime/operation/route +coverage reports 407 passed with the known pre-existing bootstrap source assertion deselected: +that assertion does not recognize the existing `measure()` wrapper. Additional workflow +request/save/client parity coverage passes. Documentation coverage +and quality checks pass, and the patch has no whitespace errors. The repository-wide logging-tag +test still reports pre-existing mixed-case tags outside the new diagnostics; the new tags use +the normalized format. + +Before this change, a terminal operations-stage failure could not identify its rejected rule. +After this change, a reproduced failure on the instrumented build yields content-free +per-attempt rule and operation metadata while debug logging is enabled. With debug disabled, +the new detailed records are absent. + +Manual live-model verification returned 502 in both pre-fix reproductions. Six post-fix +reproductions returned successful outcomes: four unfinished SQL-action drafts and two useful +clarifications about the missing database details. The final two runs also explicitly checked +that drafts contained no invented server/database/endpoint, credential field or read-write SQL +setting. Neither validation rules nor retry counts were relaxed. Automated tests remain offline +and do not depend on Azure access. + +The corrected build still needs the normal approved deployment before the live App Service +benefits from the fix. This investigation did not deploy, restart the app or change stored +settings. + +Related feature references: [Agent and action Ask AI](../features/AGENT_ACTION_AI_ASSISTANT.md) +and [Workflow Ask AI](../features/WORKFLOW_AI_ASSISTANT.md). + +## Cosmos contract review follow-up (v0.261.330) + +Fixed in version: **0.261.330**, recorded in `application/single_app/config.py`. +PR [#1760](https://github.com/microsoft/simplechat/pull/1760) changed the workflow +runtime module when adding diagnostics, invalidating the Cosmos inventory's +closed source-only review for `read_workflow_base`. Its function implementation +did not change; the module fingerprint did. The PR base still matched the +original review, so this was a PR-caused review gap, not a service outage. + +`functional_tests/test_workflow_assist_cosmos_response_contract.py` now runs the +real reader against the installed Cosmos SDK through the existing offline HTTP +transport fixture. It checks wrapped point responses, plain editor projections, +authored revisions, metadata removal, alert diagnostic sanitization, read-only +behavior, personal partition isolation, real SDK 404 responses and rejected +identifiers. The inventory replaces the stale source-only exemption with +owner-runtime evidence that the Cosmos contract job executes automatically. +No runtime behavior, validator, CI workflow or contract guard is weakened. + +The full contract run also exposed an import failure in the existing M365 action +card harness: its isolated `functions_appinsights` module supplied `log_event` +but not the PR's new `log_assist_debug` adapter. The harness now supplies both +logger methods so the real pending-action routes can import the editor assistant +runtime. Authorization, delivery and route assertions remain unchanged. + +### Follow-up validation + +Validation uses Python 3.12 and the application's pinned `azure-cosmos==4.9.0`. +The review gate reports **1,051 owners, 394 doubles and zero review gaps**. +With the application and functional-test directories on `PYTHONPATH`, this +network-blocked targeted command passes **85 tests**: + +```powershell +python -m pytest -p test_support.cosmos_network_guard .\functional_tests\test_m365_action_card_api.py .\functional_tests\test_m365_pending_authorization.py .\functional_tests\test_workflow_assist_cosmos_response_contract.py .\functional_tests\test_ask_ai_debug_diagnostics.py .\functional_tests\test_editor_assist_create_item_prompt.py -q --disable-warnings --tb=short +``` + +`python .\functional_tests\test_docs_app_surface_coverage.py` passes all seven +checks, and `python .\functional_tests\test_docs_site_quality.py` passes all six. +The full CI contract command, +`python .\scripts\check_cosmos_response_boundaries.py --run-contracts`, passes +**704 tests and 231 subtests** locally with external network access blocked. +It automatically selects the new owner-runtime evidence with its existing suites. + +## Operation error container review follow-up (v0.261.331) + +Fixed in version: **0.261.331**, recorded in `application/single_app/config.py`. +The CodeQL review on PR [#1760](https://github.com/microsoft/simplechat/pull/1760) +flagged `py/missing-equals`: `_OperationErrors` inherited list equality while +adding separate diagnostic metadata that those comparisons ignored. + +The accumulator is now a plain object with explicit `messages` and `diagnostics` +lists, rather than a list subclass. Validation checks `messages` and supplies +that ordinary list to the correction exception. This removes the inherited +collection equality contract without adding unnecessary equality operators or +changing correction text, diagnostic limits, proposal atomicity or response bodies. +No CodeQL rule, CI check or domain validation is weakened. + +`functional_tests/test_ask_ai_debug_diagnostics.py` adds regression cases for empty +accumulators, multiple messages, and a rejection count above the diagnostic limit. +They verify that messages remain an ordinary, ordered list while diagnostic +records are retained separately and capped. Existing core and creation-contract +tests exercise successful proposals, corrected rejections and terminal failures. + +The three new cases fail against the original list subclass and pass after the +change. The targeted validation command passes **76 tests**: + +```powershell +python -m pytest .\functional_tests\test_ask_ai_debug_diagnostics.py .\functional_tests\test_editor_assist_core.py .\functional_tests\test_editor_assist_create_item_prompt.py -q --tb=short +``` + +`python .\functional_tests\test_docs_app_surface_coverage.py` passes all seven +checks, and `python .\functional_tests\test_docs_site_quality.py` passes all six. diff --git a/docs/reference/logging-tags.md b/docs/reference/logging-tags.md index 1b425f200..7308f671d 100644 --- a/docs/reference/logging-tags.md +++ b/docs/reference/logging-tags.md @@ -10,6 +10,8 @@ Last inventoried: 2026-08-10 ## Current tag inventory +- `[EDITOR_ASSIST]` +- `[WORKFLOW_ASSIST]` - `[PUBLIC_CHAT_SCOPE]` - `[ACTION_TEST]` @@ -312,6 +314,24 @@ Last inventoried: 2026-08-10 - `[WORKSPACE_IDENTITY]` - `[WORKSPACE_ROUTE]` +## Ask AI operation diagnostics + +Implemented in version: **0.261.329**, recorded in `application/single_app/config.py`. + +`[EDITOR_ASSIST] Ask AI diagnostic` covers agent and action editor turns; +`[WORKFLOW_ASSIST] Ask AI diagnostic` covers personal workflow turns. The shared provider +adapter uses the same surface-specific tag. **Enable Debug Logging** must be enabled for any of +these new detailed records to reach the configured Application Insights logger or debug console. +Existing assistant request summaries retain their previous behavior. + +The records use explicitly enumerated `assist_*` categories, bounded numeric measurements, +boolean flags and `turn_id_hash`. The serializer preserves these safe categories instead of +replacing them with string lengths. It does not allow arbitrary diagnostic text. No instruction, +draft, response, credentials, raw identity IDs or provider exception message is recorded. + +See [Ask AI operation diagnostics](../explanation/fixes/ASK_AI_OPERATION_DIAGNOSTICS_FIX.md) +for the event and dimension reference, bounded queries and reproduction procedure. + ## Orchestration failure diagnostics Implemented in version **0.261.140**, recorded in diff --git a/functional_tests/cosmos_response_boundaries.json b/functional_tests/cosmos_response_boundaries.json index 250feec13..a43300fbd 100644 --- a/functional_tests/cosmos_response_boundaries.json +++ b/functional_tests/cosmos_response_boundaries.json @@ -837,7 +837,6 @@ "application/single_app/functions_thoughts.py::get_pending_thoughts": "f85d5447504e2a31b52688be081be28bfa7d3f43c7c8d5e836be3c2dc1637858", "application/single_app/functions_thoughts.py::get_thoughts_for_conversation": "17fdb138dd59ebe66492745f2d0f111655ee6e10714504ea137824a21d374288", "application/single_app/functions_workflow_assist_limits.py::CosmosAssistLimitStore.read": "e38f530dd1bef4ba82fdc57f68096ad8426e4c7f992a80cf5b99eb75b8762b11", - "application/single_app/functions_workflow_assist_runtime.py::read_workflow_base": "1be9f68968bc2828a5b0088b7e9afab4610f95d6d2c9c880cc1e972f09b45151", "application/single_app/functions_workflow_definition_store.py::save_workflow_definition_record": "78c26fbe4d26cdfa86bad30dcc59829d8d883a52749179906824d129451e9fa4", "application/single_app/functions_workflow_definition_store.py::create_workflow_definition_record_if_absent": "52d7e92b83453a9caf96bbb108673810fd48caa03ab729dd1ad1fff085cd1339", "application/single_app/functions_workflow_definition_store.py::update_workflow_runtime_record": "f41b5161ec9f6f56e4990f3cc55d457d966ee9f2d08a8deae6dd88013acc2e57", @@ -17065,13 +17064,13 @@ ], "queries": [], "batches": [], - "module_sha256": "e4db2e747cbc4026e96e90af13cf117ab83c5f6d3a8fe3ed2c193364752188cb" + "module_sha256": "585d2a5ef9566cfb23b0f763b3b9ed9f0e152d2135f20429b1344f254c2d1aaf" }, "classification": "sdk-compatible", - "contract": "read_workflow_base: point documents use Mapping field reads/JSON encoding/metadata projections; batch status/body lists are separate, never top-level-normalized as documents. Strict domain sinks remain with their storage owners.", - "evidence_scope": "sdk-api-and-source-review", + "contract": "read_workflow_base reads a real SDK CosmosDict in the caller's personal partition, projects a plain editor dictionary without Cosmos metadata, sanitizes alert diagnostics, and recomputes the authored revision without writes. Foreign or missing items remain unavailable, and invalid IDs never reach the SDK.", + "evidence_scope": "owner-runtime", "tests": [ - "functional_tests/test_m365_cosmos_sdk_contract.py::test_real_sdk_point_documents_are_wrapped_but_nested_json_and_query_rows_are_plain" + "functional_tests/test_workflow_assist_cosmos_response_contract.py" ] }, "application/single_app/functions_workflow_chat_delivery_status.py::_RequestReads._read_workflow": { diff --git a/functional_tests/test_ask_ai_debug_diagnostics.py b/functional_tests/test_ask_ai_debug_diagnostics.py new file mode 100644 index 000000000..e6c77b95d --- /dev/null +++ b/functional_tests/test_ask_ai_debug_diagnostics.py @@ -0,0 +1,439 @@ +# test_ask_ai_debug_diagnostics.py +""" +Functional regressions for debug-gated Ask AI diagnostics. +Version: 0.261.331 +Implemented in: 0.261.329 +Operation error container fix: 0.261.331 + +Exercises real editor/workflow cores, model adapter, and log_event serialization +with offline providers. Synthetic replies prove rule visibility and privacy, +not the unknown historical SQL-agent response. +""" + +import copy +import hashlib +import json +import logging +import sys +from pathlib import Path +from types import SimpleNamespace + +import httpx +import openai +import pytest + +ROOT = Path(__file__).resolve().parents[1] +sys.path.insert(0, str(ROOT / 'application' / 'single_app')) +sys.path.insert(0, str(ROOT / 'functional_tests')) + +import functions_appinsights as telemetry # noqa: E402 +import functions_editor_assist as editor # noqa: E402 +import functions_editor_assist_runtime as editor_runtime # noqa: E402 +import functions_workflow_assist as workflow # noqa: E402 +import functions_workflow_assist_runtime as runtime # noqa: E402 +from functions_assist_diagnostics import ( # noqa: E402 + ASSIST_DIAGNOSTIC_LIMIT, AssistDiagnostics, safe_assist_diagnostics, +) +from test_editor_assist_core import FakeLimiter, ScriptedModel, agent_body, SUBMISSION_ID # noqa: E402 +from test_support import workflow_assist as wa # noqa: E402 +from test_support.versioning import assert_app_version_at_least # noqa: E402 + + +PRIVATE = 'PRIVATE_PROMPT_PASSWORD_DRAFT_RESPONSE' +UNKNOWN_PATH = '/additionalFields/private_field' +REQUEST = httpx.Request('POST', 'https://model.example.invalid/chat/completions') + + +@pytest.fixture +def diagnostic_logger(monkeypatch): + logger = logging.getLogger('test.ask_ai.diagnostics') + monkeypatch.setattr(telemetry, 'get_appinsights_logger', lambda: logger) + settings = {'enable_debug_logging': True} + monkeypatch.setattr(telemetry, '_load_logging_settings', lambda: settings) + return settings, logger + + +def records(caplog): + return [ + record for record in caplog.records + if getattr(record, 'sc_message', '') in { + '[EDITOR_ASSIST] Ask AI diagnostic', '[WORKFLOW_ASSIST] Ask AI diagnostic', + } + ] + + +def emitted_text(caplog, capsys): + properties = [ + {key: value for key, value in record.__dict__.items() if key.startswith('sc_')} + for record in records(caplog) + ] + console = capsys.readouterr() + return json.dumps(properties) + console.out + console.err + + +def run_editor(model, *, kind='agent', body=None, diagnostics=None, limiter=None): + services = editor.EditorAssistServices( + limiter=limiter or FakeLimiter(), call_model=model, + diagnostics=diagnostics or AssistDiagnostics(telemetry.log_assist_debug), + ) + return editor.run_editor_assist( + body if body is not None else agent_body(instruction=PRIVATE), + kind=kind, scope='personal', user_id=PRIVATE, services=services, + ) + + +def changed(path='/display_name'): + return {'reply': PRIVATE, 'operations': [{'op': 'set', 'path': path, 'value': PRIVATE}]} + + +@pytest.mark.parametrize('debug', [False, True]) +@pytest.mark.parametrize('surface', ['agent', 'action', 'workflow']) +def test_debug_gate_covers_both_sinks_and_every_surface(diagnostic_logger, caplog, capsys, debug, surface): + settings, logger = diagnostic_logger + settings['enable_debug_logging'] = debug + with caplog.at_level(logging.INFO, logger=logger.name): + if surface == 'workflow': + bundle = wa.services(wa.ScriptedModel(wa.reply('explained', PRIVATE))) + bundle.diagnostics = AssistDiagnostics(telemetry.log_assist_debug) + result = wa.run(wa.request_body(instruction=PRIVATE), bundle) + else: + body = agent_body(instruction=PRIVATE) + if surface == 'action': + body = { + 'submission_id': SUBMISSION_ID, 'instruction': PRIVATE, + 'fields': [{'path': '/displayName', 'label': PRIVATE, 'kind': 'text'}], + 'values': {'/displayName': PRIVATE}, + } + result = run_editor(ScriptedModel({'reply': PRIVATE, 'operations': []}), kind=surface, body=body) + assert result['outcome'] == 'explained' + events = records(caplog) + assert bool(events) is debug + if debug: + assert {record.sc_assist_surface for record in events} == {surface} + assert {record.sc_assist_event for record in events} == {'model_started', 'model_finished', 'request_finished'} + expected_id = 'submission-0001' if surface == 'workflow' else SUBMISSION_ID + assert all(record.sc_turn_id_hash == hashlib.sha256(expected_id.encode()).hexdigest() for record in events) + output = emitted_text(caplog, capsys) + assert PRIVATE not in output + assert SUBMISSION_ID not in output + assert ('Ask AI diagnostic' in output) is debug + + +@pytest.mark.parametrize('reply,rule', [ + ('', 'empty_reply'), ('not JSON', 'invalid_json'), ('[]', 'reply_not_object'), + ({'reply': PRIVATE, 'extra': PRIVATE}, 'unexpected_reply_field'), + ({'reply': ''}, 'reply_required'), + ({'reply': PRIVATE, 'operations': PRIVATE}, 'operations_not_array'), + ({'reply': PRIVATE, 'operations': [{'op': PRIVATE}]}, 'operation_shape'), + ({'reply': PRIVATE, 'operations': [{'op': 'set', 'path': PRIVATE, 'value': PRIVATE}]}, 'field_unknown'), + ({'reply': PRIVATE, 'operations': [{'op': 'set', 'path': '/max_completion_tokens', 'value': 99999}]}, 'number_above_maximum'), + ({'reply': PRIVATE, 'operations': [{'op': 'set', 'path': '/actions', 'value': [PRIVATE]}]}, 'choice_handle_invalid'), +]) +def test_terminal_rejections_retain_each_attempts_rule_without_content(diagnostic_logger, caplog, capsys, reply, rule): + _settings, logger = diagnostic_logger + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(editor.EditorAssistError) as caught: + run_editor(ScriptedModel(reply, reply)) + assert caught.value.code == 'assistant_output_invalid' + rejected = [record for record in records(caplog) if record.sc_assist_event == 'validation_rejected'] + assert [record.sc_attempt for record in rejected] == [1, 2] + assert all(record.sc_assist_rule == rule for record in rejected) + terminal = records(caplog)[-1] + assert terminal.sc_assist_code == 'assistant_output_invalid' + assert terminal.sc_model_calls == 2 and terminal.sc_correction_count == 1 + assert PRIVATE not in emitted_text(caplog, capsys) + + +def test_new_sql_action_failure_is_specific_and_successful_correction_is_atomic(diagnostic_logger, caplog, capsys): + _settings, logger = diagnostic_logger + body = agent_body(instruction='i want to connect to a sql database', new_items={ + 'target': '/actions', 'types': [{'value': 'sql_query', 'label': PRIVATE}], + 'common': [{'path': '/displayName', 'label': PRIVATE, 'kind': 'text', 'required': True}], + 'variants': {'sql_query': [ + {'path': '/additionalFields/server', 'label': PRIVATE, 'kind': 'text', 'required': True}, + ]}, + }) + invalid = {'reply': PRIVATE, 'operations': [{ + 'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', + 'values': {'/displayName': 'SQL lookup', '/additionalFields/server': ''}, + }]} + corrected = copy.deepcopy(invalid) + del corrected['operations'][0]['values']['/additionalFields/server'] + before = copy.deepcopy(body) + with caplog.at_level(logging.INFO, logger=logger.name): + result = run_editor(ScriptedModel(invalid, corrected), body=body) + assert result['outcome'] == 'changed' + assert result['candidate']['new_items'][0]['values'] == {'/displayName': 'SQL lookup'} + assert body == before + rejected = next(record for record in records(caplog) if record.sc_assist_event == 'validation_rejected') + assert rejected.sc_assist_rule == 'required_value' + assert rejected.sc_assist_field == '/additionalFields/server' + assert rejected.sc_assist_operation == 'create_item' and rejected.sc_operation_index == 1 + assert records(caplog)[-1].sc_assist_outcome == 'changed' + assert PRIVATE not in emitted_text(caplog, capsys) + + +@pytest.mark.parametrize('operation,rule', [ + ({'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', 'values': {}}, 'new_required_field'), + ({'op': 'create_item', 'handle': 'N1', 'type': PRIVATE, 'values': {}}, 'new_type_invalid'), + ({'op': 'create_item', 'handle': PRIVATE, 'type': 'sql_query', 'values': {}}, 'new_handle_invalid'), + ({'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', 'values': {PRIVATE: PRIVATE}}, 'new_field_unknown'), +]) +def test_new_action_contract_rejection_codes(diagnostic_logger, caplog, capsys, operation, rule): + _settings, logger = diagnostic_logger + body = agent_body(new_items={ + 'target': '/actions', 'types': [{'value': 'sql_query'}], + 'common': [{'path': '/displayName', 'kind': 'text', 'required': True}], 'variants': {}, + }) + reply = {'reply': PRIVATE, 'operations': [operation]} + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(editor.EditorAssistError): + run_editor(ScriptedModel(reply, reply), body=body) + assert rule in [getattr(record, 'sc_assist_rule', None) for record in records(caplog)] + assert PRIVATE not in emitted_text(caplog, capsys) + + +def test_repeated_and_read_only_fields_and_bounded_reasons(diagnostic_logger, caplog, capsys): + _settings, logger = diagnostic_logger + body = agent_body() + body['fields'][0]['read_only'] = True + reply = {'reply': PRIVATE, 'operations': [ + {'op': 'set', 'path': '/display_name', 'value': PRIVATE} for _ in range(40) + ]} + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(editor.EditorAssistError): + run_editor(ScriptedModel(reply, reply), body=body) + rejected = [record for record in records(caplog) if record.sc_assist_event == 'validation_rejected'] + assert len(rejected) == 2 * ASSIST_DIAGNOSTIC_LIMIT + assert all(record.sc_assist_rule == 'field_read_only' for record in rejected) + assert PRIVATE not in emitted_text(caplog, capsys) + + +@pytest.mark.parametrize('message_count', [0, 2, ASSIST_DIAGNOSTIC_LIMIT + 1]) +def test_operation_error_container_separates_messages_and_bounded_diagnostics(message_count): + errors = editor._OperationErrors() + expected_messages = [] + expected_diagnostics = [] + for index in range(1, message_count + 1): + message = f'Operation {index}: the path is not a field in this draft.' + expected_messages.append(message) + errors.reject(message, 'field_unknown', index=index, operation='set') + if index <= ASSIST_DIAGNOSTIC_LIMIT: + expected_diagnostics.append({ + 'assist_rule': 'field_unknown', 'operation_index': index, + 'assist_operation': 'set', 'assist_field': None, + 'field_known': False, 'assist_field_kind': None, + }) + assert type(errors.messages) is list + assert errors.messages == expected_messages + assert errors.diagnostics == expected_diagnostics + + +def test_duplicate_fields_and_private_paths_have_separate_safe_reasons(diagnostic_logger, caplog, capsys): + _settings, logger = diagnostic_logger + reply = {'reply': PRIVATE, 'operations': [ + {'op': 'set', 'path': '/display_name', 'value': 'SQL helper'}, + {'op': 'set', 'path': '/display_name', 'value': PRIVATE}, + {'op': 'set', 'path': UNKNOWN_PATH, 'value': PRIVATE}, + {'op': 'set', 'path': '/instructions', 'value': PRIVATE + '\r\n\x00FORGED_LOG'}, + ]} + body = agent_body() + before = copy.deepcopy(body) + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(editor.EditorAssistError): + run_editor(ScriptedModel(reply, reply), body=body) + rejected = [record for record in records(caplog) if record.sc_assist_event == 'validation_rejected'] + assert [record.sc_assist_rule for record in rejected] == [ + 'field_repeated', 'field_unknown', 'text_invalid', + ] * 2 + assert body == before + unknown = [record for record in rejected if record.sc_assist_rule == 'field_unknown'] + assert all(not hasattr(record, 'sc_assist_field') and record.sc_field_known is False for record in unknown) + output = emitted_text(caplog, capsys) + assert PRIVATE not in output and UNKNOWN_PATH not in output and 'FORGED_LOG' not in output + + +@pytest.mark.parametrize('surface', ['agent', 'workflow']) +@pytest.mark.parametrize('finish,code,calls', [ + ('length', 'assistant_output_invalid', 2), + ('content_filter', 'assistant_refused', 1), + (PRIVATE, None, 1), +]) +def test_finish_reason_categories_and_terminal_outcomes(diagnostic_logger, caplog, capsys, surface, finish, code, calls): + _settings, logger = diagnostic_logger + model = ( + ScriptedModel({'reply': PRIVATE}, {'reply': PRIVATE}, finish=finish) + if surface == 'agent' else + wa.ScriptedModel((wa.reply('question', PRIVATE), finish), (wa.reply('question', PRIVATE), finish)) + ) + bundle = wa.services(model) if surface == 'workflow' else None + if bundle is not None: + bundle.diagnostics = AssistDiagnostics(telemetry.log_assist_debug) + with caplog.at_level(logging.INFO, logger=logger.name): + if code: + with pytest.raises((editor.EditorAssistError, workflow.WorkflowAssistError)) as caught: + if bundle is None: + run_editor(model) + else: + wa.run(wa.request_body(), bundle) + assert caught.value.code == code + else: + result = run_editor(model) if bundle is None else wa.run(wa.request_body(), bundle) + assert result['outcome'] == ('explained' if surface == 'agent' else 'question') + terminal = records(caplog)[-1] + assert terminal.sc_model_calls == calls + finished = [record for record in records(caplog) if record.sc_assist_event == 'model_finished'] + assert all(record.sc_assist_finish_reason == ('other' if finish == PRIVATE else finish) for record in finished) + if finish == 'length': + rejected = [record for record in records(caplog) if record.sc_assist_event == 'validation_rejected'] + assert [record.sc_assist_rule for record in rejected] == ['output_truncated', 'output_truncated'] + assert PRIVATE not in emitted_text(caplog, capsys) + + +@pytest.mark.parametrize('operations,rule,stage', [ + ([{'op': 'set_name'}], 'schema_required', 'schema'), + ([{'op': 'set_task_runner', 'task': 'task_99', 'runner': 'inherit'}], 'handle_invalid', 'apply'), +]) +def test_workflow_rejections_are_typed_and_correlated(diagnostic_logger, caplog, capsys, operations, rule, stage): + _settings, logger = diagnostic_logger + reply = wa.reply(operations=operations) + bundle = wa.services(wa.ScriptedModel(reply, reply)) + bundle.diagnostics = AssistDiagnostics(telemetry.log_assist_debug) + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(workflow.WorkflowAssistError) as caught: + wa.run(wa.request_body(instruction=PRIVATE), bundle) + assert caught.value.code == 'assistant_output_invalid' + rejected = [record for record in records(caplog) if record.sc_assist_event == 'validation_rejected'] + assert len(rejected) == 2 + assert all(record.sc_assist_rule == rule and record.sc_assist_stage == stage for record in rejected) + assert PRIVATE not in emitted_text(caplog, capsys) + + +@pytest.mark.parametrize('validation_code', ['invalid_workflow', PRIVATE]) +def test_workflow_save_validation_drops_private_codes_and_messages(diagnostic_logger, caplog, capsys, validation_code): + _settings, logger = diagnostic_logger + def dry_run(_user_id, payload): + if payload['name'] == 'Rejected SQL workflow': + return {'ok': False, 'errors': [{'code': validation_code, 'message': PRIVATE, 'path': UNKNOWN_PATH}]} + return {'ok': True, 'errors': []} + reply = wa.reply(operations=[{'op': 'set_name', 'name': 'Rejected SQL workflow'}]) + bundle = wa.services(wa.ScriptedModel(reply, reply), dry_run=dry_run) + bundle.diagnostics = AssistDiagnostics(telemetry.log_assist_debug) + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(workflow.WorkflowAssistError): + wa.run(wa.request_body(), bundle) + rejected = [record for record in records(caplog) if record.sc_assist_event == 'validation_rejected'] + assert [record.sc_assist_rule for record in rejected] == ['save_validation', 'save_validation'] + assert all(getattr(record, 'sc_assist_validation_code', None) == + ('invalid_workflow' if validation_code != PRIVATE else None) for record in rejected) + output = emitted_text(caplog, capsys) + assert PRIVATE not in output and UNKNOWN_PATH not in output + + +def test_diagnostic_logger_failures_do_not_change_results_or_cleanup(): + def failed_log(_properties): + raise RuntimeError(PRIVATE) + limiter = FakeLimiter() + result = run_editor(ScriptedModel(changed()), limiter=limiter, diagnostics=AssistDiagnostics(failed_log)) + assert result['outcome'] == 'changed' + assert limiter.events[-1] == ('release', False) + + +def test_allowlist_rejects_unknown_fields_categories_and_non_finite_measurements(): + safe = safe_assist_diagnostics({ + 'assist_rule': 'private_prompt', 'assist_field': UNKNOWN_PATH, + 'assist_finish_reason': PRIVATE, 'prompt': PRIVATE, 'password': PRIVATE, + 'elapsed_ms': float('nan'), 'provider_status': float('inf'), 'attempt': True, + 'output_length': 10 ** 1000, 'turn_id_hash': PRIVATE, 'assist_stage': 'operations', + }) + assert safe == {'output_length': 1_000_000_000, 'assist_stage': 'operations'} + + +class Client: + def __init__(self, *answers): + self.answers = iter(answers) + self.calls = [] + + def with_options(self, **options): + def create(**parameters): + self.calls.append((options, parameters)) + answer = next(self.answers) + if isinstance(answer, Exception): + raise answer + return answer + return SimpleNamespace(chat=SimpleNamespace(completions=SimpleNamespace(create=create))) + + +def completion(finish='stop'): + return SimpleNamespace(choices=[SimpleNamespace( + message=SimpleNamespace(content=json.dumps(changed()), refusal=None), finish_reason=finish, + )]) + + +@pytest.mark.parametrize('debug', [False, True]) +@pytest.mark.parametrize('failure,code', [ + (openai.APITimeoutError(request=REQUEST), 'assistant_timeout'), + (openai.AuthenticationError(PRIVATE, response=httpx.Response(401, request=REQUEST), body=None), 'assistant_unavailable'), + (openai.RateLimitError(PRIVATE, response=httpx.Response(429, request=REQUEST), body=None), 'assistant_unavailable'), +]) +def test_provider_failures_keep_only_safe_status_and_code(diagnostic_logger, caplog, capsys, failure, code, debug): + settings, logger = diagnostic_logger + settings['enable_debug_logging'] = debug + diagnostics = AssistDiagnostics(telemetry.log_assist_debug) + client = Client(failure) + services = editor_runtime.build_editor_assist_services( + client_factory=lambda: (client, 'gpt-4o'), limiter=FakeLimiter(), + ) + services.diagnostics = diagnostics + services.call_model = editor_runtime._ConvertingModel(runtime.WorkflowAssistModel( + lambda: (client, 'gpt-4o'), diagnostics=diagnostics, + )) + with caplog.at_level(logging.INFO, logger=logger.name): + with pytest.raises(editor.EditorAssistError) as caught: + editor.run_editor_assist(agent_body(instruction=PRIVATE), kind='agent', scope='personal', + user_id='user', services=services) + assert caught.value.code == code + if debug: + failed = next(record for record in records(caplog) if record.sc_assist_event == 'provider_failed') + assert failed.sc_assist_code == code and failed.sc_provider_attempt == 1 + assert getattr(failed, 'sc_provider_status', None) == getattr(failure, 'status_code', None) + else: + assert records(caplog) == [] + assert len(client.calls) == 1 + assert PRIVATE not in emitted_text(caplog, capsys) + + +@pytest.mark.parametrize('debug', [False, True]) +def test_json_mode_fallback_is_debug_visible_without_provider_message(diagnostic_logger, caplog, capsys, debug): + settings, logger = diagnostic_logger + settings['enable_debug_logging'] = debug + failure = openai.BadRequestError( + PRIVATE, response=httpx.Response(400, request=REQUEST), + body={'code': 'unsupported_parameter', 'param': 'response_format', + 'message': 'response_format is not supported with this model.'}, + ) + client = Client(failure, completion()) + services = editor_runtime.build_editor_assist_services( + client_factory=lambda: (client, 'gpt-4o'), limiter=FakeLimiter(), + ) + with caplog.at_level(logging.INFO, logger=logger.name): + result = editor.run_editor_assist(agent_body(), kind='agent', scope='personal', user_id='user', + services=services) + assert result['outcome'] == 'changed' + if debug: + fallback = next(record for record in records(caplog) if record.sc_assist_event == 'json_mode_fallback') + assert fallback.sc_provider_status == 400 and fallback.sc_json_mode is True and fallback.sc_provider_attempt == 1 + finished = next(record for record in records(caplog) if record.sc_assist_event == 'provider_finished') + assert finished.sc_provider_attempt == 2 and finished.sc_json_mode is False and finished.sc_provider_duration_ms >= 0 + else: + assert records(caplog) == [] + assert 'response_format' in client.calls[0][1] and 'response_format' not in client.calls[1][1] + assert PRIVATE not in emitted_text(caplog, capsys) + + +def test_implementation_version(): + assert_app_version_at_least('0.261.329') + + +if __name__ == '__main__': + sys.exit(pytest.main([__file__, '-q'])) diff --git a/functional_tests/test_editor_assist_create_item_prompt.py b/functional_tests/test_editor_assist_create_item_prompt.py new file mode 100644 index 000000000..d5ec3c730 --- /dev/null +++ b/functional_tests/test_editor_assist_create_item_prompt.py @@ -0,0 +1,92 @@ +# test_editor_assist_create_item_prompt.py +""" +Regression coverage for the live-reproduced SQL-agent creation contract failure. +Version: 0.261.329 +Implemented in: 0.261.329 + +The configured Azure model used unprefixed action names and blank connection +details on a real browser-generated request. Offline cases preserve strict +validation and verify the prompt distinguishes set paths from new-item paths. +""" + +import copy +import sys +from pathlib import Path + +import pytest + +ROOT = Path(__file__).resolve().parents[1] +sys.path.insert(0, str(ROOT / 'application' / 'single_app')) +sys.path.insert(0, str(ROOT / 'functional_tests')) + +import functions_editor_assist as core # noqa: E402 +from functions_assist_diagnostics import AssistDiagnostics # noqa: E402 +from test_editor_assist_core import FakeLimiter, ScriptedModel, agent_body # noqa: E402 + + +def sql_body(): + return agent_body(instruction='i want to connect to a sql database', new_items={ + 'target': '/actions', 'types': [{'value': 'sql_query', 'label': 'SQL query'}], + 'common': [ + {'path': '/displayName', 'kind': 'text', 'required': True}, + {'path': '/description', 'kind': 'textarea'}, + ], + 'variants': {'sql_query': [ + {'path': '/additionalFields/server', 'kind': 'text', 'required': True}, + {'path': '/additionalFields/database', 'kind': 'text', 'required': True}, + ]}, + }) + + +def test_prompt_separates_set_paths_from_new_action_paths_and_missing_details(): + request = core.parse_editor_assist_request(sql_body(), kind='agent', scope='personal') + prompt = core.system_prompt(request) + assert 'For set operations, use only paths listed in draft.fields' in prompt + assert 'including the leading "/"' in prompt + assert '"/displayName"' in prompt and '"displayName"' in prompt + assert 'omit that field from "values"' in prompt + assert 'blank placeholders' in prompt + + +def test_live_observed_unprefixed_fields_remain_rejected_instead_of_silently_repaired(): + bad = {'reply': 'Drafted.', 'operations': [{ + 'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', 'values': { + 'displayName': 'SQL lookup', 'description': 'Read rows.', + '/additionalFields/server': '', '/additionalFields/database': '', + }, + }]} + corrected_but_still_invalid = copy.deepcopy(bad) + del corrected_but_still_invalid['operations'][0]['values']['/additionalFields/server'] + del corrected_but_still_invalid['operations'][0]['values']['/additionalFields/database'] + events = [] + services = core.EditorAssistServices( + limiter=FakeLimiter(), call_model=ScriptedModel(bad, corrected_but_still_invalid), + diagnostics=AssistDiagnostics(events.append), + ) + body = sql_body() + before = copy.deepcopy(body) + with pytest.raises(core.EditorAssistError) as caught: + core.run_editor_assist(body, kind='agent', scope='personal', user_id='test-user', services=services) + assert caught.value.code == 'assistant_output_invalid' + assert body == before + rejected = [event for event in events if event['assist_event'] == 'validation_rejected'] + assert [event['assist_rule'] for event in rejected] == [ + 'new_field_unknown', 'new_field_unknown', 'required_value', 'required_value', 'new_required_field', + 'new_field_unknown', 'new_field_unknown', 'new_required_field', + ] + + +def test_exact_action_paths_and_omitted_unknown_connection_details_make_a_valid_draft(): + reply = {'reply': 'Enter the connection details before saving.', 'operations': [{ + 'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', + 'values': {'/displayName': 'SQL lookup', '/description': 'Read rows.'}, + }]} + services = core.EditorAssistServices(limiter=FakeLimiter(), call_model=ScriptedModel(reply)) + result = core.run_editor_assist(sql_body(), kind='agent', scope='personal', user_id='test-user', services=services) + assert result['outcome'] == 'changed' + assert result['candidate']['new_items'][0]['values'] == reply['operations'][0]['values'] + assert 'new:N1' in result['candidate']['values']['/actions'] + + +if __name__ == '__main__': + sys.exit(pytest.main([__file__, '-q'])) diff --git a/functional_tests/test_m365_action_card_api.py b/functional_tests/test_m365_action_card_api.py index 422cecd66..19be41d45 100644 --- a/functional_tests/test_m365_action_card_api.py +++ b/functional_tests/test_m365_action_card_api.py @@ -1,8 +1,9 @@ # test_m365_action_card_api.py """ Behavioral tests for authoritative M365 action cards and confirmation APIs. -Version: 0.261.038 +Version: 0.261.330 Implemented in: 0.261.038 +Ask AI diagnostic logger adapter updated in: 0.261.330 Real records, projections, route bodies, tenant/CSRF checks and delivery claims run with scoped external storage/Graph seams. No live messages are sent. @@ -82,7 +83,7 @@ def cards(monkeypatch): monkeypatch.setattr(connections, "_service", connection_service) seams = { "config": module_stub("config", cosmos_msgraph_pending_actions_container=container), - "functions_appinsights": module_stub("functions_appinsights", log_event=log), + "functions_appinsights": module_stub("functions_appinsights", log_event=log, log_assist_debug=Mock()), "functions_debug": module_stub("functions_debug", debug_print=lambda *args: None), "functions_authentication": module_stub( "functions_authentication", login_required=login_guard, user_required=user_guard, diff --git a/functional_tests/test_workflow_assist_cosmos_response_contract.py b/functional_tests/test_workflow_assist_cosmos_response_contract.py new file mode 100644 index 000000000..9e6c00554 --- /dev/null +++ b/functional_tests/test_workflow_assist_cosmos_response_contract.py @@ -0,0 +1,102 @@ +# test_workflow_assist_cosmos_response_contract.py +""" +Functional regressions for the Ask AI workflow base reader's Cosmos response contract. +Version: 0.261.330 +Implemented in: 0.261.330 + +The real installed SDK reads through the shared offline HTTP transport fixture. +These tests cover editor projection, metadata removal, partition isolation and +invalid identifiers without contacting Azure or replacing the storage owner. +""" + +from copy import deepcopy +from pathlib import Path +import sys + +from azure.cosmos._cosmos_responses import CosmosDict +import pytest + + +ROOT = Path(__file__).resolve().parents[1] +sys.path.insert(0, str(ROOT / "application" / "single_app")) +sys.path.insert(0, str(ROOT / "functional_tests")) + +# Standalone execution establishes repository paths before importing real modules. +import functions_workflow_assist_runtime as runtime # noqa: E402 +from functions_workflow_alert_safety import WORKFLOW_ALERT_EVALUATION_ERROR_MESSAGE # noqa: E402 +from functions_workflow_definitions import workflow_definition_revision # noqa: E402 +from test_m365_cosmos_sdk_contract import cosmos_factory # noqa: E402, F401 + + +@pytest.mark.parametrize("definition_version", [1, 2, 3]) +def test_workflow_base_projects_real_sdk_point_response(cosmos_factory, definition_version): + http, container = cosmos_factory("user_id") + diagnostic = "Alert condition could not be evaluated: SENTINEL provider detail" + stored = http.seed({ + "id": "workflow", "user_id": "owner", "name": "Document review", + "definition_version": definition_version, "definition_revision": "stale", + "tasks": [{"id": "review", "name": "Review", "prompt": "Review documents."}], + "schedule": {"kind": "calendar", "frequency": "weekdays", "time_of_day": "07:00"}, + "alert_decision": { + "matched_rules": [{"condition_type": "model_evaluation", "reason": diagnostic}], + "message": diagnostic, + }, + }) + point = container.read_item(item="workflow", partition_key="owner") + before = deepcopy(http.records) + + loaded = runtime.read_workflow_base(container, "owner", "workflow") + + assert isinstance(point, CosmosDict) + assert type(point) is not dict + assert type(loaded) is dict + assert loaded["id"] == "workflow" + assert loaded["user_id"] == "owner" + assert loaded["definition_version"] == definition_version + assert loaded["tasks"] == stored["tasks"] + assert type(loaded["tasks"][0]) is dict + assert loaded["schedule"] == stored["schedule"] + assert not any(key.startswith("_") for key in loaded) + expected_revision = workflow_definition_revision(stored) + assert loaded["definition_revision"] == expected_revision + assert loaded["definition_revision"] != "stale" + assert loaded["alert_decision"]["message"] == WORKFLOW_ALERT_EVALUATION_ERROR_MESSAGE + assert loaded["alert_decision"]["matched_rules"][0]["reason"] == WORKFLOW_ALERT_EVALUATION_ERROR_MESSAGE + assert http.records == before + assert point["alert_decision"]["message"] == diagnostic + assert all(method == "GET" for method, _path, _headers in http.calls) + item_reads = [headers for method, path, headers in http.calls if path.endswith("/docs/workflow")] + assert len(item_reads) == 2 + assert all(headers["x-ms-documentdb-partitionkey"] == '["owner"]' for headers in item_reads) + + +@pytest.mark.parametrize("user_id, workflow_id", [("someone-else", "workflow"), ("owner", "missing")]) +def test_workflow_base_missing_or_foreign_item_uses_real_sdk_404(cosmos_factory, user_id, workflow_id): + http, container = cosmos_factory("user_id") + http.seed({"id": "workflow", "user_id": "owner", "name": "Private workflow"}) + before = deepcopy(http.records) + + loaded = runtime.read_workflow_base(container, user_id, workflow_id) + + assert loaded is None + assert http.records == before + item_reads = [(path, headers) for method, path, headers in http.calls if "/docs/" in path] + assert len(item_reads) == 1 + path, headers = item_reads[0] + assert path.endswith(f"/docs/{workflow_id}") + assert headers["x-ms-documentdb-partitionkey"] == f'["{user_id}"]' + + +@pytest.mark.parametrize("character", ["/", "\\", "?", "#"]) +def test_workflow_base_invalid_id_never_calls_sdk(cosmos_factory, character): + http, container = cosmos_factory("user_id") + before = list(http.calls) + + loaded = runtime.read_workflow_base(container, "owner", f"workflow{character}other") + + assert loaded is None + assert http.calls == before + + +if __name__ == "__main__": + raise SystemExit(pytest.main([str(Path(__file__).resolve())])) diff --git a/ui_tests/test_v2_agent_action_ask_ai.py b/ui_tests/test_v2_agent_action_ask_ai.py index b6b442071..e4e1b6adf 100644 --- a/ui_tests/test_v2_agent_action_ask_ai.py +++ b/ui_tests/test_v2_agent_action_ask_ai.py @@ -1,8 +1,9 @@ # test_v2_agent_action_ask_ai.py """ Offline real-bundle browser regressions for Ask AI in the agent and action editors. -Version: 0.261.288 +Version: 0.261.329 Implemented in: 0.261.288 +SQL draft and debug-diagnostic coverage extended in: 0.261.329 Covers the agent editor applying a proposal to the unsaved draft with Undo, an agent turn that drafts a new action that blocks saving until the person finishes it in the action editor and is @@ -35,6 +36,7 @@ parse_editor_assist_request, run_editor_assist, ) +from functions_assist_diagnostics import AssistDiagnostics # noqa: E402 from ui_tests.fixtures.workspace_authoring import ( # noqa: E402 ACTION_ID, AGENT_ID, @@ -68,6 +70,7 @@ def __init__(self, page): self.agent_assist_enabled = True self.action_assist_enabled = True self.assist_requests = [] + self.assist_diagnostics = [] self.script = None def _bootstrap(self): @@ -91,7 +94,8 @@ def call_model(_messages, _timeout): request = parse_editor_assist_request(copy.deepcopy(body), kind=kind, scope=scope) return json.dumps(script(request, ChoiceHandles(request))), "stop" - services = EditorAssistServices(limiter=_Limiter(), call_model=call_model) + services = EditorAssistServices(limiter=_Limiter(), call_model=call_model, + diagnostics=AssistDiagnostics(self.assist_diagnostics.append)) try: result = run_editor_assist(body, kind=kind, scope=scope, user_id=OWNER_ID, services=services) except EditorAssistError as error: @@ -220,6 +224,118 @@ def test_action_ask_ai_never_sends_stored_credentials(ask_ai_ui): assert '"/auth/key"' not in serialized +@pytest.mark.parametrize('first_defect', [None, 'blank_connection', 'unprefixed_common_fields']) +def test_new_sql_agent_drafts_an_action_without_inventing_connection_details(ask_ai_ui, first_defect): + ui, page = ask_ai_ui, ask_ai_ui.page + attempts = [] + + def script(request, _handles): + attempts.append(True) + assert request.new_items is not None + assert 'sql_query' in request.new_items.variants + fields = request.new_items.variants['sql_query'] + assert '/additionalFields/server' in fields + assert not any('password' in path or 'connection_string' in path for path in fields) + values = {'/displayName': 'SQL lookup', '/additionalFields/read_only': True} + if first_defect == 'blank_connection' and len(attempts) == 1: + values['/additionalFields/server'] = '' + elif first_defect == 'unprefixed_common_fields' and len(attempts) == 1: + values['displayName'] = values.pop('/displayName') + values['description'] = 'Read SQL rows.' + return { + 'reply': 'I drafted a read-only SQL action. Enter the database details before saving.', + 'operations': [{'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', 'values': values}], + } + + ui.script = script + ui.open('/workspace/agents/new') + panel = ask(page, 'i want to connect to a sql database') + pending = page.get_by_role('list', name='New actions from Ask AI', exact=True) + expect(pending).to_contain_text('SQL lookup') + expect(pending.get_by_text(re.compile('Needs attention before saving'))).to_be_visible() + assert not ui.editor_writes + assert len(attempts) == (2 if first_defect else 1) + rejected = [event for event in ui.assist_diagnostics if event['assist_event'] == 'validation_rejected'] + if first_defect == 'blank_connection': + assert len(rejected) == 1 + assert rejected[0]['assist_rule'] == 'required_value' + assert rejected[0]['assist_field'] == '/additionalFields/server' + elif first_defect == 'unprefixed_common_fields': + assert [event['assist_rule'] for event in rejected] == [ + 'new_field_unknown', 'new_field_unknown', 'new_required_field', + ] + else: + assert rejected == [] + panel.get_by_role('button', name=re.compile(r'^Undo this change')).click() + expect(page.get_by_role('list', name='New actions from Ask AI', exact=True)).to_have_count(0) + assert not ui.editor_writes + + +def test_failed_new_sql_agent_turn_keeps_the_draft_and_records_the_rule(ask_ai_ui): + ui, page = ask_ai_ui, ask_ai_ui.page + ui.script = lambda _request, _handles: { + 'reply': 'I configured SQL.', + 'operations': [{'op': 'create_item', 'handle': 'N1', 'type': 'sql_query', 'values': {}}], + } + ui.open('/workspace/agents/new') + original = page.get_by_label('Display name', exact=True).input_value() + page.get_by_role('button', name='Ask AI', exact=True).click() + panel = page.get_by_role('complementary', name='Ask AI', exact=True) + panel.get_by_role('textbox', name='Message Ask AI', exact=True).fill('i want to connect to a sql database') + panel.get_by_role('button', name='Send to Ask AI', exact=True).click() + expect(panel.get_by_text(re.compile("couldn't produce a valid change"))).to_be_visible() + expect(page.get_by_label('Display name', exact=True)).to_have_value(original) + expect(page.get_by_role('list', name='New actions from Ask AI', exact=True)).to_have_count(0) + assert not ui.editor_writes + rejected = [event for event in ui.assist_diagnostics if event['assist_event'] == 'validation_rejected'] + assert [event['attempt'] for event in rejected] == [1, 2] + assert all(event['assist_rule'] == 'new_required_field' for event in rejected) + + +def test_new_sql_agent_can_assign_an_existing_action_without_running_it(ask_ai_ui): + ui, page = ask_ai_ui, ask_ai_ui.page + ui.actions[ACTION_ID].update({ + "displayName": "SQL lookup", "type": "sql_query", + "additionalFields": {"server": "sql.example.test", "database": "fixture", "read_only": True}, + }) + + def script(request, handles): + assert any(option["value"] == ACTION_ID for option in request.fields["/actions"].options) + handle = handles.handle("/actions", ACTION_ID) + assert handle is not None + return { + "reply": "I assigned the existing SQL lookup action.", + "operations": [{"op": "set", "path": "/actions", "value": [handle]}], + } + + ui.script = script + ui.open("/workspace/agents/new") + panel = ask(page, "i want to connect to a sql database") + expect(page.get_by_role("checkbox", name=re.compile("SQL lookup")).first).to_be_checked() + assert not ui.editor_writes + expect(page.get_by_role("list", name="New actions from Ask AI", exact=True)).to_have_count(0) + panel.get_by_role("button", name=re.compile(r"^Undo this change")).click() + expect(page.get_by_role("checkbox", name=re.compile("SQL lookup")).first).not_to_be_checked() + assert not ui.editor_writes + + +def test_new_sql_agent_can_ask_for_connection_details_without_mutation(ask_ai_ui): + ui, page = ask_ai_ui, ask_ai_ui.page + question = "Which SQL database engine will you use? Enter its connection details in the action editor." + ui.script = lambda _request, _handles: {"reply": question, "operations": []} + ui.open("/workspace/agents/new") + original = page.get_by_label("Display name", exact=True).input_value() + page.get_by_role("button", name="Ask AI", exact=True).click() + panel = page.get_by_role("complementary", name="Ask AI", exact=True) + panel.get_by_role("textbox", name="Message Ask AI", exact=True).fill("i want to connect to a sql database") + panel.get_by_role("button", name="Send to Ask AI", exact=True).click() + expect(panel.get_by_text(question, exact=True)).to_be_visible() + expect(page.get_by_label("Display name", exact=True)).to_have_value(original) + expect(page.get_by_role("list", name="New actions from Ask AI", exact=True)).to_have_count(0) + assert not ui.editor_writes + assert ui.assist_diagnostics[-1]["assist_outcome"] == "explained" + + @pytest.mark.parametrize("path", [f"/workspace/agents/{AGENT_ID}", f"/workspace/actions/{ACTION_ID}"]) def test_ask_ai_is_hidden_when_the_admin_turns_it_off(ask_ai_ui, path): ui, page = ask_ai_ui, ask_ai_ui.page