diff --git a/docs/test-scripts.md b/docs/test-scripts.md index 39cfce8..3ab092e 100644 --- a/docs/test-scripts.md +++ b/docs/test-scripts.md @@ -93,6 +93,34 @@ PoR-in-submit: 5. **Counters**: the run starts from the preset's stored counter and persists each accepted packet's next value; consecutive runs continue correctly. +### Reading the run log + +Every step writes a semantic line to the server log under its step number, +request before response: + +``` +TEST-RUN step 1: SCP80 C-APDU=80E2900000 +TEST-RUN step 1: SCP80 SECURED=0100…1A2B (N B) TAR=B00001 SPI1=16 SPI2=21 CNTR=0000000A +TEST-RUN step 1: SCP80 -> SW=9000 +TEST-RUN step 1: PoR[inline] status=por_ok TAR=B00001 CNTR=0000000A raw=0271…aabb +TEST-RUN step 1: R-APDU SW=9000 data=AABB +TEST-RUN step 2: STATUS 1/2 -> 9102 +TEST-RUN step 3: FETCH=8012000002 -> SW=9000 D03C8103012500… +TEST-RUN step 3: CMD 0x25 SET UP MENU qual=00 +TEST-RUN step 3: TR=81030125008202828183020000 -> SW=9000 +TEST-RUN step 4: MENU-SELECT ENVELOPE=80c2000009d30702020181900101 item=1 ('One') -> SW=9103 +``` + +- A PoR delivered as SEND SHORT MESSAGE is logged on the step that fetches it: + `PoR[sms-submit] …` followed by the same `R-APDU` line. +- Other actions log their send/response pair too (`APDU TX=… -> SW=…`, + `ENVELOPE(Event Download) … -> SW=…`, `READ MF/… -> SW=…`). +- The shared secured-packet sender logs each segment's answer + (`OTA SEND: ENVELOPE i/N -> `). +- `--apdu-trace` adds the raw transport view + (`APDU-TRACE(…): → SW: … RESP: …`) for every APDU, including the + file-manager reads and pySim's auto-handler traffic. + ## Document shape ```json diff --git a/frontend/help-ru.html b/frontend/help-ru.html index 99e6cc8..81e39f1 100644 --- a/frontend/help-ru.html +++ b/frontend/help-ru.html @@ -568,6 +568,7 @@
  • Уровни ошибок — несовпадение помечает шаг как Ошибка (скрипт останавливается) или Предупреждение (продолжает); каждая проверка показывается с ожидаемым и фактическим значением.
  • Шаблоны — Empty, Обзор меню STK, Апплет через SCP80; редактор шагов — формный (поля действия Event вводятся объектом JSON), отдельные скрипты экспортируются/импортируются как JSON.
    • +

    Каждый шаг пишет семантическую строку в журнал сервера под своим номером (TEST-RUN step N: …), запрос перед ответом: отправленный APDU/данные и полученный SW, для SCP80 — открытый C-APDU, собранный защищённый пакет и R-APDU из PoR, для ожидания — тройка FETCH / команда / TERMINAL RESPONSE, а для выбора пункта меню — полный ENVELOPE с определённым пунктом. Запустите сервер с --apdu-trace, чтобы добавить и журнал сырых транспортных APDU.

    8.10 BIP-терминал (обычный TCP)

    Пилюля BIP запускает терминальную сторону Bearer Independent Protocol для карт, использующих TCP без HTTP OTA (SCP81): апплет или пуш-триггер может открыть канал и обменяться сырыми данными. Одновременно работает только одна BIP-сессия — запуск здесь останавливает слушатель SCP81, а запуск слушателя SCP81 останавливает эту сессию (в обоих случаях сообщается, что было заменено).

    diff --git a/frontend/help.html b/frontend/help.html index 9e749aa..d4f17ad 100644 --- a/frontend/help.html +++ b/frontend/help.html @@ -567,6 +567,7 @@
  • Fail levels — a mismatch flags the step as Error (terminates the script) or Warning (continues); each check is reported with expected vs actual values.
  • Templates — Empty, STK menu browsing, Applet via SCP80; the step editor is form-based (the event action's fields are a JSON object) and individual scripts export/import as JSON.
    • +

    Every step logs a semantic line to the server log under its step number (TEST-RUN step N: …), request before response: the APDU/data sent and the SW received, for SCP80 the plaintext C-APDU, the built secured packet and the PoR's R-APDU, for an expectation the FETCH / command / TERMINAL RESPONSE trio, and for a menu selection the complete ENVELOPE with the resolved item. Start the server with --apdu-trace to add the raw transport APDU log as well.

    8.10 BIP terminal (generic TCP)

    The BIP pill runs the terminal side of the Bearer Independent Protocol for cards that use TCP without HTTP OTA (SCP81): an applet or a push trigger can open a channel and exchange raw data. Only one BIP session runs at a time — starting here stops a running SCP81 listener, and starting the SCP81 listener stops this session (both report what was replaced).

    diff --git a/frontend/index.html b/frontend/index.html index 4819531..035bb08 100644 --- a/frontend/index.html +++ b/frontend/index.html @@ -1877,7 +1877,7 @@ // ===== Version ===== // Single source of truth for the PWA version: shown in the header and used // by the server version check in pysimConnect(). -const SIMPLE_VERSION = '3.18.2'; +const SIMPLE_VERSION = '3.18.3'; document.getElementById('app-version').textContent = 'v' + SIMPLE_VERSION; // ===== Tab switching ===== diff --git a/frontend/sw.js b/frontend/sw.js index ea5e600..d19eff1 100644 --- a/frontend/sw.js +++ b/frontend/sw.js @@ -1,4 +1,4 @@ -const CACHE = 'simple-v384'; +const CACHE = 'simple-v385'; const URLS = [ 'index.html', 'help.html', diff --git a/pyproject.toml b/pyproject.toml index 7994af3..2e85344 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta" [project] name = "pysim-simple-server" -version = "3.18.2" +version = "3.18.3" description = "HTTP REST server wrapping pysim for the SIMple PWA" requires-python = ">=3.8" # pysim is a git-only dependency installed explicitly by setup.bat/setup.sh. diff --git a/pysim_simple_server/server.py b/pysim_simple_server/server.py index 5d9a294..96f0a27 100644 --- a/pysim_simple_server/server.py +++ b/pysim_simple_server/server.py @@ -34,7 +34,7 @@ from osmocom.tlv import BER_TLV_IE from osmocom.utils import rpad -VERSION = '3.18.2' +VERSION = '3.18.3' MAX_ENVELOPE_SEGMENTS = 5 # max SMS segments for outgoing C-APDU in ENVELOPE @@ -1370,6 +1370,7 @@ def _send_secured_packet(scc, sp_hex, oa_number, sm_sc=None, include_cpi=True, submit_handler=submit_handler, handle_proactive=handle_proactive, poll_status=(i == total - 1)) + sys.stderr.write('OTA SEND: ENVELOPE %d/%d -> %s\n' % (i + 1, total, sw)) if sw != '9000' and not sw.startswith('91'): # A warning (62xx/63xx, e.g. the live card's 6200 for a low # counter) may still hold the PoR: pass it on so the caller can @@ -5792,6 +5793,16 @@ def _test_action_checks(step, sw, data, por, kind): return checks +def _test_log(msg): + """One semantic run-log line, prefixed with the current step number: the + verification trail (the plaintext C-APDU, the built secured packet, the + PoR R-APDU, the FETCH/TR of an expectation, the menu selection's ENVELOPE). + The raw transport view stays with `--apdu-trace`.""" + step = _TEST_RUN.get('index') + n = (step + 1) if isinstance(step, int) else 0 + sys.stderr.write('TEST-RUN step %d: %s\n' % (n, msg)) + + def _test_run_status(scc, step): p = step['params'] data, sw = '', '' @@ -5799,6 +5810,7 @@ def _test_run_status(scc, step): for n in range(p['attempts']): data, sw = _send_status(scc) used = n + 1 + _test_log('STATUS %d/%d -> %s' % (used, p['attempts'], sw)) if testscript.match_value(step['check']['sw'], sw): break if n + 1 < p['attempts'] and p['interval_ms']: @@ -5885,20 +5897,44 @@ def _test_run_scp80(server, step, ctx): if p.get('sp'): sp_hex = p['sp'] source = 'sp' + _test_log('SCP80 SP=%s' % sp_hex) else: sp_hex, _ = _build_secured_packet(spi1, spi2, kic, kid, tar, counter, p['apdu'], kic_key, kid_key) source = 'apdu' + _test_log('SCP80 C-APDU=%s' % p['apdu']) + _test_log('SCP80 SECURED=%s (%d B) TAR=%s SPI1=%s SPI2=%s CNTR=%s' + % (sp_hex, len(sp_hex) // 2, tar or '-', spi1, spi2, counter)) result = _send_secured_packet(scc, sp_hex, server.sms_oa, sm_sc=server.sms_sc, handle_proactive=False) sw = result.get('sw') or '' data = result.get('response_data') or '' + segments = result.get('segments') or 0 + _test_log('SCP80 -> SW=%s%s' % (sw or '(none)', + ' (%d segment(s))' % segments if segments > 1 else '')) por = None if data: por = _decode_por(spi1, spi2, kic, kid, counter, kic_key, kid_key, data) - sent = 'SCP80 %s TAR=%s SPI1=%s SPI2=%s cntr=%s%s' % ( + if por: + dec = por.get('decoded') or {} + extra = '' + if por.get('bad_format'): + extra = ' bad_format=%s (%s)' % (por['bad_format'], + por.get('bad_format_name') or '') + _test_log('PoR[inline] status=%s TAR=%s CNTR=%s%s raw=%s' + % (por.get('response_status'), por.get('tar'), + por.get('cntr'), extra, por.get('raw') or data)) + _test_log('R-APDU SW=%s data=%s' + % (dec.get('last_status_word') or '(none)', + dec.get('last_response_data') or '(none)')) + elif data: + _test_log('PoR[inline] undecodable raw=%s' % data) + else: + _test_log('PoR[inline] none') + sent = 'SCP80 %s TAR=%s SPI1=%s SPI2=%s cntr=%s%s %s' % ( source, tar or '-', spi1, spi2, counter, - (' kvn=%d' % kvn) if kvn else '') + (' kvn=%d' % kvn) if kvn else '', + ('SP=%s' % sp_hex) if source == 'sp' else ('C-APDU=%s' % p['apdu'])) if sw and _counter_tracked(spi1): # The card answered and the packet asks for a counter check, so the # SCP80 counter was consumed: advance the working value of this key @@ -5955,6 +5991,9 @@ def _test_run_action(server, step, ctx): bytes.fromhex(p['data']) if p['data'] else None, drain=False, src=p.get('src')) sent = 'ENVELOPE(Event Download) type=0x%02X' % p['event'] + _test_log('%s src=%s data=%s -> SW=%s%s' + % (sent, p.get('src') or '82', p['data'] or '(none)', sw or '(none)', + (' RESP=%s' % data) if data else '')) elif kind == 'event': # The semantic event download: the builder owns the byte layout. data_hex = events.build(p['event'], p.get('fields') or {}) @@ -5962,6 +6001,9 @@ def _test_run_action(server, step, ctx): drain=False, src=p.get('src')) sent = 'ENVELOPE(Event Download) type=0x%02X (%s) data=%s' % ( p['event'], events.event_name(p['event']), data_hex) + _test_log('%s src=%s -> SW=%s%s' + % (sent, p.get('src') or '82', sw or '(none)', + (' RESP=%s' % data) if data else '')) elif kind == 'menu-select': item_id = p.get('item_id') if item_id is None: @@ -5972,13 +6014,20 @@ def _test_run_action(server, step, ctx): data, sw = scc._tp.send_apdu(sent) if not (sw or '').startswith('91'): server.menu_active = False + _test_log('MENU-SELECT ENVELOPE=%s item=%d%s -> SW=%s%s' + % (sent, item_id, (' (%r)' % p['text']) if 'text' in p else '', + sw or '(none)', (' RESP=%s' % data) if data else '')) elif kind == 'apdu': sent = p['apdu'] data, sw = scc._tp.send_apdu(sent) + _test_log('APDU TX=%s -> SW=%s%s' + % (sent, sw or '(none)', (' RESP=%s' % data) if data else '')) elif kind == 'status': data, sw, sent = _test_run_status(scc, step) elif kind in ('file-write', 'file-read'): data, sw, sent = _test_run_file(server, step) + _test_log('%s -> SW=%s%s' % (sent, sw or '(none)', + (' RESP=%dB' % (len(data) // 2)) if data else '')) elif kind == 'scp80': data, sw, sent, por, counter = _test_run_scp80(server, step, ctx) else: @@ -6092,17 +6141,34 @@ def _test_run_expect(server, step, pending, ctx=None): 'no proactive command pending - the previous step must end with SW 91XX ' '(or add a status action); the UICC announces pending commands in the ' 'response to a command (TS 102 221 7.4.2.1)') - fdata, fetch_sw = scc._tp.send_apdu('%s120000%02x' % (scc.cat_cla, pending)) + fetch_apdu = '%s120000%02x' % (scc.cat_cla, pending) + fdata, fetch_sw = scc._tp.send_apdu(fetch_apdu) if not fdata: + _test_log('FETCH=%s -> SW=%s (no data)' % (fetch_apdu, fetch_sw)) raise testscript.ScriptError('FETCH returned no data (SW %s)' % fetch_sw) raw = bytes.fromhex(fdata) + _test_log('FETCH=%s -> SW=%s %s' % (fetch_apdu, fetch_sw, raw.hex().upper())) cmd_num, cmd_type, dev_src, dev_dst, cmd_qual = _parse_proactive_header(raw) log_entry = _log_proactive(cmd_type, raw, cmd_qual, cmd_num) type_name = PROACTIVE_TYPE_NAMES.get(cmd_type, 'UNKNOWN') + _test_log('CMD 0x%02X %s qual=%s' % ( + cmd_type, type_name, ('%02X' % cmd_qual) if cmd_qual is not None else '-')) # A SEND SHORT MESSAGE carries the PoR when the packet asked for it in # submit mode (SPI2 bit 0x20): decode it with the triggering scp80 step's # context so the checks can assert the PoR contents. por = _test_expect_por(ctx, raw) if cmd_type == 0x13 else None + if cmd_type == 0x13: + if por is not None: + dec = por.get('decoded') or {} + _test_log('PoR[sms-submit] status=%s TAR=%s CNTR=%s raw=%s' + % (por.get('response_status'), por.get('tar'), + por.get('cntr'), por.get('raw') or '(none)')) + _test_log('R-APDU SW=%s data=%s' + % (dec.get('last_status_word') or '(none)', + dec.get('last_response_data') or '(none)')) + else: + _test_log('PoR[sms-submit] none (no decodable PDU or no scp80 ' + 'context)') if cmd_type == 0x25: # The card may re-send its menu (e.g. after an applet install); keep # the cache that text-based menu selection resolves against current. @@ -6185,6 +6251,7 @@ def _test_run_expect(server, step, pending, ctx=None): tr = testscript.build_tr(cmd_num, cmd_type, dev_dst, dev_src, step['respond']) tr_rv = scc._tp.send_apdu('%s140000%02x%s' % (scc.cat_cla, len(tr), tr.hex())) tr_sw = tr_rv[1] + _test_log('TR=%s -> SW=%s' % (tr.hex().upper(), tr_sw)) _record_tr(log_entry, tr, tr_sw) status = testscript.combine_levels([c['level'] if not c['ok'] else 'ok' for c in checks]) result = {'status': status, 'sw': tr_sw, 'data': raw.hex().upper(), @@ -7410,6 +7477,8 @@ class PysimHandler(BaseHTTPRequestHandler): menu_tlv = bytes([0xD3, 0x07, 0x02, 0x02, 0x01, 0x81, 0x90, 0x01, item_id]) env_hex = '%sc20000%02x%s' % (scc.cat_cla, len(menu_tlv), menu_tlv.hex()) data, sw = scc._tp.send_apdu(env_hex) + sys.stderr.write('MENU-SELECT: ENVELOPE %s item=%d -> %s\n' + % (env_hex, item_id, sw)) resp = {'type': 'done', 'sw': sw} on_fetch = _make_menu_fetch_handler(self.server, resp) if sw.startswith('91'): diff --git a/tests/test_testscript.py b/tests/test_testscript.py index 052f13b..30fd6be 100644 --- a/tests/test_testscript.py +++ b/tests/test_testscript.py @@ -729,12 +729,84 @@ class TestRunnerActions(RunnerTestCase): # 12 07 01 3F007F106F3A (one file: MF/7F10/6F3A). REFRESH_FCN_CMD = 'D0128103010100820283811207013F007F106F3A' + def test_the_run_log_carries_the_card_exchange_details(self): + # the semantic lines a verification needs: the plaintext C-APDU, the + # built secured packet, the FETCH/CMD/TR pair of an expectation and + # the menu selection's ENVELOPE with the resolved item + import contextlib + import io + scc = FakeScc() + scc.push('80F2', '', '9102') + scc.push('8012', self.SETUP_MENU_CMD, '9000') + scc.push('8014', '', '9000') + scc.push('80C2', '', '9000') + preset = {'kic': '15', 'kid': '15', 'kicKey': 'AA' * 16, 'kidKey': 'BB' * 16, + 'counter': '0000000A', 'tars': preset_tars()} + buf = io.StringIO() + with mock.patch.object(S, '_build_secured_packet', return_value=('CC' * 10, {})), \ + mock.patch.object(S, '_send_secured_packet', + return_value={'success': True, 'sw': '9000', + 'response_data': None}): + with contextlib.redirect_stderr(buf): + run = self.run_script(FakeServer(scc), [ + {'type': 'action', 'kind': 'scp80', + 'params': {'apdu': '80E2900000'}}, + {'type': 'action', 'kind': 'status', 'params': {'attempts': 2}, + 'check': {'sw': {'mode': 'mask', 'value': '91??'}}}, + {'type': 'expect', 'command': 'SET UP MENU', + 'respond': {'result': 'ok'}}, + {'type': 'action', 'kind': 'menu-select', + 'params': {'text': 'One'}}, + ], preset) + self.assertEqual(run['status'], 'ok', run['steps']) + log = buf.getvalue() + self.assertIn('TEST-RUN step 1: SCP80 C-APDU=80E2900000', log) + self.assertIn('TEST-RUN step 1: SCP80 SECURED=' + 'CC' * 10, log) + self.assertIn('TEST-RUN step 1: SCP80 -> SW=9000', log) + self.assertIn('TEST-RUN step 1: PoR[inline] none', log) + self.assertIn('TEST-RUN step 2: STATUS 1/2 -> 9102', log) + self.assertIn('TEST-RUN step 3: FETCH=', log) + self.assertIn('TEST-RUN step 3: CMD 0x25 SET UP MENU', log) + self.assertIn('TEST-RUN step 3: TR=', log) + self.assertIn('TEST-RUN step 4: MENU-SELECT ENVELOPE=', log) + self.assertIn("item=1 ('One')", log) + + def test_the_run_log_carries_the_inline_por(self): + # the decoded PoR and its R-APDU are logged with the raw packet + import contextlib + import io + scc = FakeScc() + preset = {'kic': '15', 'kid': '15', 'kicKey': 'AA' * 16, 'kidKey': 'BB' * 16, + 'counter': '0000000A', 'tars': preset_tars()} + decoded = {'response_status': 'por_ok', 'tar': '000000', 'cntr': '0000000A', + 'raw': '0271000021AABB', + 'decoded': {'last_status_word': '9000', 'last_response_data': 'AABB'}} + buf = io.StringIO() + with mock.patch.object(S, '_build_secured_packet', return_value=('AA' * 10, {})), \ + mock.patch.object(S, '_send_secured_packet', + return_value={'success': True, 'sw': '9000', + 'response_data': '0271000021AABB'}), \ + mock.patch.object(S, '_decode_por', return_value=decoded): + with contextlib.redirect_stderr(buf): + run = self.run_script(FakeServer(scc), [ + {'type': 'action', 'kind': 'scp80', + 'params': {'apdu': '80E2900000'}}, + ], preset) + self.assertEqual(run['status'], 'ok', run['steps']) + log = buf.getvalue() + self.assertIn('TEST-RUN step 1: PoR[inline] status=por_ok', log) + self.assertIn('raw=0271000021AABB', log) + self.assertIn('TEST-RUN step 1: R-APDU SW=9000 data=AABB', log) + def test_expect_decodes_the_submit_por(self): + import contextlib + import io scc = FakeScc() preset = {'kic': '15', 'kid': '15', 'kicKey': 'AA' * 16, 'kidKey': 'BB' * 16, 'counter': '0000000A', 'tars': preset_tars()} decoded = {'response_status': 'por_ok', 'tar': '000000', 'decoded': {'last_status_word': '9000', 'last_response_data': 'AABB'}} + buf = io.StringIO() with mock.patch.object(S, '_build_secured_packet', return_value=('AA' * 10, {})), \ mock.patch.object(S, '_send_secured_packet', return_value={'success': True, 'sw': '9102', @@ -742,14 +814,18 @@ class TestRunnerActions(RunnerTestCase): mock.patch.object(S, '_decode_por', return_value=decoded) as dec: scc.push('8012', self.SEND_SM_POR_CMD, '9000') scc.push('8014', '', '9000') - run = self.run_script(FakeServer(scc), [ - {'type': 'action', 'kind': 'scp80', 'params': {'apdu': '80E2900000'}, - 'check': {'sw': {'mode': 'mask', 'value': '91??'}, 'por': 'none'}}, - {'type': 'expect', 'command': 'SEND SHORT MESSAGE', - 'checks': [{'kind': 'por', 'status': 'por_ok', 'sw': '9000'}], - 'respond': {'result': 'ok'}}, - ], preset) + with contextlib.redirect_stderr(buf): + run = self.run_script(FakeServer(scc), [ + {'type': 'action', 'kind': 'scp80', 'params': {'apdu': '80E2900000'}, + 'check': {'sw': {'mode': 'mask', 'value': '91??'}, 'por': 'none'}}, + {'type': 'expect', 'command': 'SEND SHORT MESSAGE', + 'checks': [{'kind': 'por', 'status': 'por_ok', 'sw': '9000'}], + 'respond': {'result': 'ok'}}, + ], preset) self.assertEqual(run['status'], 'ok', run['steps']) + log = buf.getvalue() + self.assertIn('TEST-RUN step 2: PoR[sms-submit] status=por_ok', log) + self.assertIn('TEST-RUN step 2: R-APDU SW=9000 data=AABB', log) self.assertEqual(run['steps'][1]['por']['response_status'], 'por_ok') labels = {c['label']: c for c in run['steps'][1]['checks']} self.assertTrue(labels['PoR status']['ok'], labels)