richclient_info.log-20180125-error-Failed_to_transmit_control_command_to_the_terminal_REINER_SCT_cyberJack_RFID_standard.txt - Open eCard - Open eCard Development Center

RE: Authentication error when using eID » richclient_info.log-20180125-error-Failed_to_transmit_control_command_to_the_terminal_REINER_SCT_cyberJack_RFID_standard.txt

debug log file - Alexander Kamm, 01/25/2018 10:13 AM

 -01-25 09:53:03,626 [main] INFO  o.o.richclient.LogbackConfig:81 - Configured Logback with config file from: /home/alexander/.openecard/richclient_logback.xml
 -01-25 09:53:03,653 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource ifd for lang C.
 -01-25 09:53:03,653 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource ifd for lang de.
 -01-25 09:53:03,654 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource ifd for lang de_DE.
 -01-25 09:53:03,657 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource sal for lang C.
 -01-25 09:53:03,657 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource sal for lang de.
 -01-25 09:53:03,657 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource sal for lang de_DE.
 -01-25 09:53:03,659 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource richclient for lang de_DE.
 -01-25 09:53:03,664 [main] INFO  org.openecard.richclient.RichClient:122 - Starting Open eCard App org.openecard.common.SemanticVersion@e580929 ...
 -01-25 09:53:04,966 [main] DEBUG o.o.m.sal.config.MiddlewareConfig:107 - Loading middleware config.
 -01-25 09:53:04,967 [main] DEBUG o.o.m.sal.config.MiddlewareConfig:144 - Reading middleware config from XML file.
 -01-25 09:53:05,037 [main] DEBUG o.o.m.sal.config.MiddlewareConfig:158 - CardImageName: rub-card.png
 -01-25 09:53:05,039 [main] DEBUG o.o.m.sal.config.MiddlewareConfig:158 - CardImageName: luxtrust-v3.jpg
 -01-25 09:53:05,041 [main] DEBUG o.o.m.sal.config.MiddlewareConfig:158 - CardImageName: Lux-eID.jpg
 -01-25 09:53:05,042 [main] DEBUG o.o.m.sal.config.MiddlewareConfig:158 - CardImageName: ihk-card.jpg
 -01-25 09:53:05,050 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource recognition for lang de_DE.
 -01-25 09:53:05,136 [Init-File-Addons] DEBUG org.openecard.addon.FileRegistry:144 - Starting addon filesystem monitor on path: /home/alexander/.openecard/addons
 -01-25 09:53:05,139 [main] WARN  org.openecard.common.I18n:152 - Failed to load resource http for lang de_DE.
 -01-25 09:53:05,152 [main] DEBUG o.o.c.binding.http.HttpService:77 - Starting HTTPBinding on port 24727
 -01-25 09:53:05,173 [main] DEBUG o.o.c.binding.http.HttpService:88 - Add handler [org.openecard.control.binding.http.handler.HttpAppPluginActionHandler] for ID [*]
 -01-25 09:53:05,477 [Init-Classpath-Addons] INFO  o.openecard.addon.ClasspathRegistry:94 - Loaded internal TR-03112 add-on.
 -01-25 09:53:05,498 [Init-Classpath-Addons] INFO  o.openecard.addon.ClasspathRegistry:94 - Loaded internal ChipGateway add-on.
 -01-25 09:53:05,512 [Init-Classpath-Addons] INFO  o.openecard.addon.ClasspathRegistry:94 - Loaded internal PIN-Management add-on.
 -01-25 09:53:05,516 [Init-Classpath-Addons] INFO  o.openecard.addon.ClasspathRegistry:94 - Loaded internal GenericCrypto add-on.
 -01-25 09:53:05,522 [Init-Classpath-Addons] INFO  o.openecard.addon.ClasspathRegistry:94 - Loaded internal Status add-on.
 -01-25 09:53:05,523 [Init-Classpath-Addons] WARN  o.openecard.addon.ClasspathRegistry:89 - Skipped loading internal add-on PKCS#11, because it is not available.
 -01-25 09:53:05,977 [main] DEBUG o.o.ifd.event.IfdEventRunner:91 - Requesting terminal names.
 -01-25 09:53:06,001 [main] DEBUG org.openecard.scio.PCSCTerminals:99 - No reader available exception.
 -01-25 09:53:06,002 [main] DEBUG o.o.ifd.event.IfdEventRunner:97 - Requesting status for all terminals found.
 -01-25 09:53:06,017 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:220 - No reader available exception.
 -01-25 09:53:06,021 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:07,522 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:09,023 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:10,525 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:12,026 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:13,528 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:15,030 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:16,531 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:18,032 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:19,534 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:20,442 [AWT-EventQueue-1] DEBUG o.openecard.richclient.gui.Status$2:179 - About button pressed.
 -01-25 09:53:20,453 [AWT-EventQueue-1] WARN  org.openecard.common.I18n:152 - Failed to load resource about for lang de_DE.
 -01-25 09:53:21,035 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:22,536 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:24,038 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:25,540 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:27,042 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:28,543 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:30,045 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:31,547 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:33,048 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:34,549 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:36,051 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:37,552 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:39,054 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:40,555 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:42,056 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:43,557 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:45,059 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:46,560 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:48,061 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:49,563 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:51,064 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:52,566 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:54,067 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:55,569 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:57,070 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:53:58,572 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:00,073 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:01,574 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:03,076 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:04,577 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:06,078 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:07,579 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:09,081 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:10,582 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:12,084 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:13,585 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:15,086 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:16,588 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:18,089 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:19,591 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:21,092 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:22,594 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:24,095 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:25,596 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:27,098 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:28,599 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:30,101 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:31,602 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:33,103 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:34,605 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:36,106 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:37,608 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:39,109 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:40,611 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:42,112 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:43,614 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:45,115 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:46,616 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:48,118 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:49,619 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:51,121 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:52,622 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:54,123 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:55,624 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:57,126 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:54:58,627 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:00,128 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:01,629 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:03,130 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:04,632 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:06,132 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:07,633 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:09,135 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:10,636 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:12,138 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:13,639 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:15,140 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:16,642 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:18,143 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:19,644 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:21,145 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:22,647 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:24,149 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:25,650 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:27,151 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:28,652 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:30,154 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:31,655 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:33,156 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:34,658 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:36,159 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:37,661 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:39,162 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:40,664 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:42,165 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:43,667 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:45,168 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:46,670 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:48,171 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:49,673 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:51,174 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:52,675 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:54,177 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:55,678 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:57,180 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:55:58,681 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:412 - Waiting for PCSC system to become available again.
 -01-25 09:56:00,194 [IFD Watcher 0] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type GetIFDCapabilities.
 -01-25 09:56:00,203 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:00,203 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:00,204 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.GetIFDCapabilities
 -01-25 09:56:00,219 [IFD Watcher 0] DEBUG org.openecard.ifd.scio.IFD:350 - Failed to request status from terminal.
       org.openecard.common.ifd.scio.SCIOException: Reader refused to connect card with any protocol.
       	at org.openecard.ifd.scio.wrapper.SingleThreadChannel.connectCard(SingleThreadChannel.java:139)
       	at org.openecard.ifd.scio.wrapper.SingleThreadChannel.<init>(SingleThreadChannel.java:80)
       	at org.openecard.ifd.scio.wrapper.ChannelManager.openMasterChannel(ChannelManager.java:90)
       	at org.openecard.ifd.scio.IFD.getIFDCapabilities(IFD.java:285)
       	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
       	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
       	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
       	at java.lang.reflect.Method.invoke(Method.java:498)
       	at org.openecard.transport.dispatcher.Service.invoke(Service.java:192)
       	at org.openecard.transport.dispatcher.MessageDispatcher.deliver(MessageDispatcher.java:116)
       	at org.openecard.transport.dispatcher.MessageDispatcher.safeDeliver(MessageDispatcher.java:135)
       	at org.openecard.ifd.event.IfdEventRunner.getCapabilities(IfdEventRunner.java:279)
       	at org.openecard.ifd.event.IfdEventRunner.fireEvents(IfdEventRunner.java:189)
       	at org.openecard.ifd.event.IfdEventRunner.run(IfdEventRunner.java:128)
       	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
       	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
       	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
       	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
       	at java.lang.Thread.run(Thread.java:748)
 -01-25 09:56:00,228 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:00,229 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:00,229 [IFD Watcher 0] DEBUG o.o.ifd.event.IfdEventRunner:201 - Found a terminal added event (REINER SCT cyberJack RFID standard (0810057893) 00 00).
 -01-25 09:56:00,231 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:361 - Event: TERMINAL_ADDED
 -01-25 09:56:00,232 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:369 - ConnectionHandle: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType@57fec3f8
 -01-25 09:56:00,232 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:371 - RecognitionInfo: null
 -01-25 09:56:00,232 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:373 - IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00
 -01-25 09:56:00,234 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event TERMINAL_ADDED into event queue.
 -01-25 09:56:00,236 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:201 - Detecting initial terminal status.
 -01-25 09:56:00,237 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:205 - Terminal='REINER SCT cyberJack RFID standard (0810057893) 00 00' cardPresent=false
 -01-25 09:56:28,837 [SCIO Watcher 0] INFO  o.o.i.s.wrapper.SingleThreadChannel:144 - Card connected with protocol T=1.
 -01-25 09:56:28,839 [IFD Watcher 0] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type GetIFDCapabilities.
 -01-25 09:56:28,843 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:28,844 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:28,844 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.GetIFDCapabilities
 -01-25 09:56:28,845 [IFD Watcher 0] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 09:56:28,869 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:28,871 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:28,871 [IFD Watcher 0] DEBUG o.o.ifd.event.IfdEventRunner:223 - Found a card insert event (REINER SCT cyberJack RFID standard (0810057893) 00 00).
 -01-25 09:56:28,873 [IFD Watcher 0] INFO  o.o.ifd.event.IfdEventRunner:224 - Card with ATR=3B8780018031B8738401E019 inserted.
 -01-25 09:56:28,875 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:361 - Event: CARD_INSERTED
 -01-25 09:56:28,875 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:369 - ConnectionHandle: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType@25826842
 -01-25 09:56:28,875 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event CARD_INSERTED into event queue.
 -01-25 09:56:28,875 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:371 - RecognitionInfo: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType$RecognitionInfo@62fe62f0
 -01-25 09:56:28,875 [IFD Watcher 0] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 09:56:28,876 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:373 - IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00
 -01-25 09:56:28,887 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type Connect.
 -01-25 09:56:28,888 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:201 - Detecting initial terminal status.
 -01-25 09:56:28,888 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:205 - Terminal='REINER SCT cyberJack RFID standard (0810057893) 00 00' cardPresent=true
 -01-25 09:56:28,895 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:28,901 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:28,902 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Connect
 -01-25 09:56:28,902 [IFD Watcher 1] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 09:56:28,913 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:28,914 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:28,915 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type BeginTransaction.
 -01-25 09:56:28,919 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:28,921 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:28,921 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.BeginTransaction
 -01-25 09:56:28,931 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:28,933 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:28,934 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:28,941 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:28,942 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:28,942 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:28,945 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 09:56:28,983 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:28,991 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:28,991 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:28,992 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:28,996 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:28,997 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:28,997 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:28,998 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x00 0x03
 -01-25 09:56:29,003 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6A 0x82
 -01-25 09:56:29,012 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,013 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,014 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,018 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,019 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,019 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,020 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 09:56:29,027 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:29,037 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,037 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,038 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,041 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,042 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,042 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,043 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x2F 0x00
 -01-25 09:56:29,050 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:29,057 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,058 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,059 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,063 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,064 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,064 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,065 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xB2 0x04 0x04 0xFF
 -01-25 09:56:29,068 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6D 0x00
 -01-25 09:56:29,075 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,076 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,077 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,080 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,080 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,081 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,082 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 09:56:29,087 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:29,095 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,095 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,096 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,100 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,101 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,101 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,102 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x2F 0x00
 -01-25 09:56:29,109 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:29,115 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,117 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,118 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,123 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,124 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,124 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,125 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xB2 0x03 0x04 0xFF
 -01-25 09:56:29,128 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6D 0x00
 -01-25 09:56:29,137 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,138 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,138 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,141 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,142 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,143 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,144 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x04 0x0C 0x0F 0xF0 0x45 0x73 0x74 0x45 0x49 0x44 0x20 0x76 0x65 0x72 0x20 0x31 0x2E 0x30
 -01-25 09:56:29,153 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6A 0x82
 -01-25 09:56:29,160 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,161 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,161 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,164 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,165 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,165 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,167 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x04 0x0C 0x0F 0xD2 0x33 0x00 0x00 0x00 0x45 0x73 0x74 0x45 0x49 0x44 0x20 0x76 0x33 0x35
 -01-25 09:56:29,175 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6A 0x82
 -01-25 09:56:29,183 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,184 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,185 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,188 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,189 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,190 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,191 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 09:56:29,199 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:29,205 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,206 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,206 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,209 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,210 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,210 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,211 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x2F 0x00
 -01-25 09:56:29,217 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 09:56:29,224 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,225 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,225 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 09:56:29,228 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,229 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,229 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 09:56:29,230 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xB0 0x00 0x00 0xFF
 -01-25 09:56:29,245 [IFD Watcher 1] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x61 0x32 0x4F 0x0F 0xE8 0x28 0xBD 0x08 0x0F 0xA0 0x00 0x00 0x01 0x67 0x45 0x53 0x49 0x47 0x4E 0x50 0x0F 0x43 0x49 0x41 0x20 0x7A 0x75 0x20 0x44 0x46 0x2E 0x65 0x53 0x69 0x67 0x6E 0x51 0x00 0x73 0x0C 0x4F 0x0A 0xA0 0x00 0x00 0x01 0x67 0x45 0x53 0x49 0x47 0x4E 0x61 0x09 0x4F 0x07 0xA0 0x00 0x00 0x02 0x47 0x10 0x01 0x61 0x0B 0x4F 0x09 0xE8 0x07 0x04 0x00 0x7F 0x00 0x07 0x03 0x02 0x61 0x0C 0x4F 0x0A 0xA0 0x00 0x00 0x01 0x67 0x45 0x53 0x49 0x47 0x4E 0x62 0x82
 -01-25 09:56:29,253 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,254 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,255 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type EndTransaction.
 -01-25 09:56:29,257 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,258 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,258 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.EndTransaction
 -01-25 09:56:29,274 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,275 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,276 [IFD Watcher 1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Disconnect.
 -01-25 09:56:29,279 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:29,280 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:29,280 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Disconnect
 -01-25 09:56:29,288 [IFD Watcher 1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:29,288 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:29,289 [IFD Watcher 1] DEBUG org.openecard.ifd.event.Recognizer:60 - Found a recognized card event (REINER SCT cyberJack RFID standard (0810057893) 00 00).
 -01-25 09:56:29,290 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:361 - Event: CARD_RECOGNIZED
 -01-25 09:56:29,292 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:369 - ConnectionHandle: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType@65603115
 -01-25 09:56:29,297 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:371 - RecognitionInfo: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType$RecognitionInfo@164aaa65
 -01-25 09:56:29,297 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:373 - IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00
 -01-25 09:56:29,291 [Dispatcher Event 1] INFO  o.o.c.sal.state.SALStateCallback:63 - Add ConnectionHandle to SAL:
       ConnectionHandle:
         Session: H1NctFpkvY7sCUUpPBSegA
         ContextHandle: 0C4CFAEE07B92B3DB449BBD1F144DC09
         IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00  SlotIndex: 0
         CardType: http://bsi.bund.de/cif/npa.xml
 -01-25 09:56:29,313 [IFD Watcher 1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event CARD_RECOGNIZED into event queue.
 -01-25 09:56:51,463 [IFD Watcher 0] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type GetIFDCapabilities.
 -01-25 09:56:51,468 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 09:56:51,468 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 09:56:51,469 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.GetIFDCapabilities
 -01-25 09:56:51,472 [IFD Watcher 0] DEBUG org.openecard.ifd.scio.IFD:350 - Failed to request status from terminal.
       org.openecard.common.ifd.scio.SCIOException: Reader refused to connect card with any protocol.
       	at org.openecard.ifd.scio.wrapper.SingleThreadChannel.connectCard(SingleThreadChannel.java:139)
       	at org.openecard.ifd.scio.wrapper.SingleThreadChannel.<init>(SingleThreadChannel.java:80)
       	at org.openecard.ifd.scio.wrapper.ChannelManager.openMasterChannel(ChannelManager.java:90)
       	at org.openecard.ifd.scio.IFD.getIFDCapabilities(IFD.java:285)
       	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
       	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
       	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
       	at java.lang.reflect.Method.invoke(Method.java:498)
       	at org.openecard.transport.dispatcher.Service.invoke(Service.java:192)
       	at org.openecard.transport.dispatcher.MessageDispatcher.deliver(MessageDispatcher.java:116)
       	at org.openecard.transport.dispatcher.MessageDispatcher.safeDeliver(MessageDispatcher.java:135)
       	at org.openecard.ifd.event.IfdEventRunner.getCapabilities(IfdEventRunner.java:279)
       	at org.openecard.ifd.event.IfdEventRunner.fireEvents(IfdEventRunner.java:189)
       	at org.openecard.ifd.event.IfdEventRunner.run(IfdEventRunner.java:128)
       	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
       	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
       	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
       	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
       	at java.lang.Thread.run(Thread.java:748)
 -01-25 09:56:51,481 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 09:56:51,482 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 09:56:51,482 [IFD Watcher 0] DEBUG o.o.ifd.event.IfdEventRunner:250 - Found a card removed event (REINER SCT cyberJack RFID standard (0810057893) 00 00).
 -01-25 09:56:51,483 [Dispatcher Event 2] INFO  o.o.c.sal.state.SALStateCallback:73 - Remove ConnectionHandle from SAL.
       ConnectionHandle:
         Session: H1NctFpkvY7sCUUpPBSegA
         ContextHandle: 0C4CFAEE07B92B3DB449BBD1F144DC09
         IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00  SlotIndex: 0
 -01-25 09:56:51,484 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:361 - Event: CARD_REMOVED
 -01-25 09:56:51,484 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:369 - ConnectionHandle: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType@2f84bb76
 -01-25 09:56:51,484 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:371 - RecognitionInfo: null
 -01-25 09:56:51,485 [Dispatcher Event 3] DEBUG org.openecard.richclient.gui.Status:373 - IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00
 -01-25 09:56:51,486 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event CARD_REMOVED into event queue.
 -01-25 09:56:51,488 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:201 - Detecting initial terminal status.
 -01-25 09:56:51,489 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:205 - Terminal='REINER SCT cyberJack RFID standard (0810057893) 00 00' cardPresent=false
 -01-25 09:59:54,847 [Thread-8] DEBUG o.o.c.b.h.h.HttpAppPluginActionHandler:88 - HTTP request: GET /eID-Client?tcTokenURL=https%3A%2F%2Fwww.elster.de%2Feportal%2Fregistrierung-auswahl%2Feid-fwd%2FJA0?ElsterRequestKeys.NPA_REG_ID=f9601f51-99bd-4b25-9f76-ff98768ece05 [Host: 127.0.0.1:24727, Connection: keep-alive, Upgrade-Insecure-Requests: 1, User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/63.0.3239.84 Chrome/63.0.3239.84 Safari/537.36, Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8, Accept-Encoding: gzip, deflate, br, Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7]
 -01-25 09:59:54,863 [Thread-8] WARN  org.openecard.common.I18n:152 - Failed to load resource tr03112 for lang de_DE.
 -01-25 09:59:54,874 [Thread-8] WARN  org.openecard.common.I18n:152 - Failed to load resource tctoken for lang de_DE.
 -01-25 09:59:54,877 [Thread-8] WARN  org.openecard.common.I18n:152 - Failed to load resource pinplugin for lang de_DE.
 -01-25 09:59:54,879 [Thread-8] WARN  org.openecard.common.I18n:152 - Failed to load resource pace for lang de_DE.
 -01-25 09:59:54,996 [Thread-8] WARN  org.openecard.common.I18n:152 - Failed to load resource gui for lang de_DE.
 -01-25 09:59:55,153 [Thread-8] DEBUG org.openecard.gui.swing.StepBar:97 - Selecting index 0, previous was -1.
 -01-25 09:59:55,400 [Instant-Return-Thread-1] DEBUG o.o.gui.swing.SwingNavigator:244 - Received event: Button.next
 -01-25 09:59:55,405 [Instant-Return-Thread-1] DEBUG org.openecard.gui.swing.StepFrame:257 - Trying to kill background task if it exists.
 -01-25 09:59:55,408 [Instant-Return-Thread-1] DEBUG org.openecard.gui.swing.StepFrame:222 - Exchange result for step 'Karte bereitstellen'.
 -01-25 10:00:07,015 [SCIO Watcher 0] INFO  o.o.i.s.wrapper.SingleThreadChannel:144 - Card connected with protocol T=1.
 -01-25 10:00:07,016 [IFD Watcher 0] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type GetIFDCapabilities.
 -01-25 10:00:07,021 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,022 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,023 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.GetIFDCapabilities
 -01-25 10:00:07,023 [IFD Watcher 0] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 10:00:07,038 [IFD Watcher 0] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,040 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,040 [IFD Watcher 0] DEBUG o.o.ifd.event.IfdEventRunner:223 - Found a card insert event (REINER SCT cyberJack RFID standard (0810057893) 00 00).
 -01-25 10:00:07,041 [IFD Watcher 0] INFO  o.o.ifd.event.IfdEventRunner:224 - Card with ATR=3B8780018031B8738401E019 inserted.
 -01-25 10:00:07,041 [IFD Watcher 0] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event CARD_INSERTED into event queue.
 -01-25 10:00:07,041 [IFD Watcher 0] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 10:00:07,042 [Dispatcher Event 6] DEBUG org.openecard.richclient.gui.Status:361 - Event: CARD_INSERTED
 -01-25 10:00:07,043 [Dispatcher Event 6] DEBUG org.openecard.richclient.gui.Status:369 - ConnectionHandle: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType@62c7408d
 -01-25 10:00:07,043 [Dispatcher Event 6] DEBUG org.openecard.richclient.gui.Status:371 - RecognitionInfo: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType$RecognitionInfo@6c00a2a5
 -01-25 10:00:07,043 [Dispatcher Event 6] DEBUG org.openecard.richclient.gui.Status:373 - IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00
 -01-25 10:00:07,046 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type Connect.
 -01-25 10:00:07,053 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,054 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,055 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Connect
 -01-25 10:00:07,055 [IFD Watcher 2] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 10:00:07,057 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:201 - Detecting initial terminal status.
 -01-25 10:00:07,057 [IFD Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:205 - Terminal='REINER SCT cyberJack RFID standard (0810057893) 00 00' cardPresent=true
 -01-25 10:00:07,094 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,101 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,102 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type BeginTransaction.
 -01-25 10:00:07,105 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,108 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,109 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.BeginTransaction
 -01-25 10:00:07,125 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,127 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,127 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,132 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,133 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,133 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,136 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 10:00:07,172 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,179 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,180 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,180 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,183 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,183 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,184 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,184 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x00 0x03
 -01-25 10:00:07,196 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6A 0x82
 -01-25 10:00:07,208 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,214 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,215 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,220 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,221 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,221 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,227 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 10:00:07,235 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,246 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,247 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,247 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,252 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,254 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,254 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,255 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x2F 0x00
 -01-25 10:00:07,262 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,278 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,279 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,279 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,284 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,284 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,284 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,286 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xB2 0x04 0x04 0xFF
 -01-25 10:00:07,289 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6D 0x00
 -01-25 10:00:07,294 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,295 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,295 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,299 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,299 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,300 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,301 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 10:00:07,308 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,314 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,315 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,315 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,318 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,320 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,320 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,321 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x2F 0x00
 -01-25 10:00:07,328 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,334 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,337 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,338 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,341 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,342 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,343 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,343 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xB2 0x03 0x04 0xFF
 -01-25 10:00:07,347 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6D 0x00
 -01-25 10:00:07,353 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,354 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,354 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,357 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,358 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,359 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,360 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x04 0x0C 0x0F 0xF0 0x45 0x73 0x74 0x45 0x49 0x44 0x20 0x76 0x65 0x72 0x20 0x31 0x2E 0x30
 -01-25 10:00:07,370 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6A 0x82
 -01-25 10:00:07,378 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,380 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,380 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,384 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,384 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,384 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,385 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x04 0x0C 0x0F 0xD2 0x33 0x00 0x00 0x00 0x45 0x73 0x74 0x45 0x49 0x44 0x20 0x76 0x33 0x35
 -01-25 10:00:07,396 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x6A 0x82
 -01-25 10:00:07,409 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,410 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,414 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,418 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,418 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,419 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,420 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 10:00:07,428 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,435 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,436 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,437 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,440 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,441 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,441 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,442 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x02 0x0C 0x02 0x2F 0x00
 -01-25 10:00:07,449 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:07,458 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,459 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,459 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:07,463 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,464 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,464 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:07,465 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xB0 0x00 0x00 0xFF
 -01-25 10:00:07,474 [IFD Watcher 2] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x61 0x32 0x4F 0x0F 0xE8 0x28 0xBD 0x08 0x0F 0xA0 0x00 0x00 0x01 0x67 0x45 0x53 0x49 0x47 0x4E 0x50 0x0F 0x43 0x49 0x41 0x20 0x7A 0x75 0x20 0x44 0x46 0x2E 0x65 0x53 0x69 0x67 0x6E 0x51 0x00 0x73 0x0C 0x4F 0x0A 0xA0 0x00 0x00 0x01 0x67 0x45 0x53 0x49 0x47 0x4E 0x61 0x09 0x4F 0x07 0xA0 0x00 0x00 0x02 0x47 0x10 0x01 0x61 0x0B 0x4F 0x09 0xE8 0x07 0x04 0x00 0x7F 0x00 0x07 0x03 0x02 0x61 0x0C 0x4F 0x0A 0xA0 0x00 0x00 0x01 0x67 0x45 0x53 0x49 0x47 0x4E 0x62 0x82
 -01-25 10:00:07,483 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,483 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,484 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type EndTransaction.
 -01-25 10:00:07,486 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,487 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,487 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.EndTransaction
 -01-25 10:00:07,500 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,500 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,500 [IFD Watcher 2] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Disconnect.
 -01-25 10:00:07,504 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:07,505 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:07,505 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Disconnect
 -01-25 10:00:07,512 [IFD Watcher 2] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:07,513 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:07,513 [IFD Watcher 2] DEBUG org.openecard.ifd.event.Recognizer:60 - Found a recognized card event (REINER SCT cyberJack RFID standard (0810057893) 00 00).
 -01-25 10:00:07,514 [Dispatcher Event 5] DEBUG org.openecard.richclient.gui.Status:361 - Event: CARD_RECOGNIZED
 -01-25 10:00:07,515 [Dispatcher Event 5] DEBUG org.openecard.richclient.gui.Status:369 - ConnectionHandle: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType@64d9bede
 -01-25 10:00:07,517 [IFD Watcher 2] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event CARD_RECOGNIZED into event queue.
 -01-25 10:00:07,515 [Dispatcher Event 8] INFO  o.o.c.sal.state.SALStateCallback:63 - Add ConnectionHandle to SAL:
       ConnectionHandle:
         Session: H1NctFpkvY7sCUUpPBSegA
         ContextHandle: 0C4CFAEE07B92B3DB449BBD1F144DC09
         IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00  SlotIndex: 0
         CardType: http://bsi.bund.de/cif/npa.xml
 -01-25 10:00:07,516 [Dispatcher Event 5] DEBUG org.openecard.richclient.gui.Status:371 - RecognitionInfo: iso.std.iso_iec._24727.tech.schema.ConnectionHandleType$RecognitionInfo@6a1e5c35
 -01-25 10:00:07,523 [Dispatcher Event 5] DEBUG org.openecard.richclient.gui.Status:373 - IFDName: REINER SCT cyberJack RFID standard (0810057893) 00 00
 -01-25 10:00:07,591 [Thread-8] INFO  o.o.binding.tctoken.ResourceContext:207 - Trying to load resource from: https://www.elster.de/eportal/registrierung-auswahl/eid-fwd/JA0?ElsterRequestKeys.NPA_REG_ID=f9601f51-99bd-4b25-9f76-ff98768ece05
 -01-25 10:00:07,695 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for java. Trying next one.
 -01-25 10:00:07,732 [Thread-8] DEBUG o.o.c.t.proxy.ProxySettingsLoader$1:80 - Firefox settings folder is {0}
 -01-25 10:00:07,745 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,745 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,746 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for firefox. Trying next one.
 -01-25 10:00:07,746 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,747 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,747 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for desktop. Trying next one.
 -01-25 10:00:07,749 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for env. Trying next one.
 -01-25 10:00:07,754 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for java. Trying next one.
 -01-25 10:00:07,762 [Thread-8] DEBUG o.o.c.t.proxy.ProxySettingsLoader$1:80 - Firefox settings folder is {0}
 -01-25 10:00:07,764 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,765 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,765 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for firefox. Trying next one.
 -01-25 10:00:07,781 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,783 [Thread-8] WARN  o.o.c.t.proxy.ProxySettingsLoader$1:86 - Gnome settings: {0} not found.
 -01-25 10:00:07,784 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for desktop. Trying next one.
 -01-25 10:00:07,785 [Thread-8] INFO  o.o.c.t.proxy.ProxySettingsLoader$1:83 - No proxy found for env. Trying next one.
 -01-25 10:00:07,789 [Thread-8] DEBUG o.o.crypto.tls.proxy.ProxySettings:133 - Selecting proxy: DIRECT
 -01-25 10:00:07,877 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:244 - Performing TLS handshake.
 -01-25 10:00:08,161 [Thread-8] DEBUG o.o.c.tls.verify.HostnameVerifier:126 - Comparing connection hostname against certificate hostname: [www.elster.de] [www.elster.de]
 -01-25 10:00:08,478 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:246 - TLS handshake performed.
 -01-25 10:00:08,487 [Thread-8] DEBUG o.o.transport.httpcore.HttpUtils:81 - HTTP Request:
         GET /eportal/registrierung-auswahl/eid-fwd/JA0?ElsterRequestKeys.NPA_REG_ID=f9601f51-99bd-4b25-9f76-ff98768ece05 HTTP/1.1
         Connection: keep-alive
         User-Agent: Open eCard App/org.openecard.common.SemanticVersion@e580929
         Host: www.elster.de
         Accept: text/xml, */*;q=0.8
         Accept-Charset: utf-8, *;q=0.8
 -01-25 10:00:08,487 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:267 - Sending HTTP request.
 -01-25 10:00:08,694 [Thread-8] DEBUG o.o.t.h.cookies.CookieManager:130 - Setting cookie JSESSIONID=0DAA40230D806D42BD4DF62E4BC216EB for domain www.elster.de.
 -01-25 10:00:08,694 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:270 - HTTP response received.
 -01-25 10:00:08,695 [Thread-8] DEBUG o.o.transport.httpcore.HttpUtils:112 - HTTP Response:
         HTTP/1.1 303 See Other
         X-Content-Type-Options: nosniff
         X-XSS-Protection: 1; mode=block
         Cache-Control: no-cache, no-store, max-age=0, must-revalidate
         Pragma: no-cache
         Expires: 0
         Strict-Transport-Security: max-age=31536000
         X-Frame-Options: SAMEORIGIN
         Content-Security-Policy: default-src 'self' ; style-src 'self' ; media-src 'self' https://www.elster.de ; img-src 'self' https://www.elster.de ; form-action 'self' ; object-src 'self' blob: ; frame-src 'self'
         X-Content-Security-Policy: default-src 'self' ; style-src 'self' ; media-src 'self' https://www.elster.de ; img-src 'self' https://www.elster.de ; form-action 'self' ; object-src 'self' blob: ; frame-src 'self'
         X-WebKit-CSP: default-src 'self' ; style-src 'self' ; media-src 'self' https://www.elster.de ; img-src 'self' https://www.elster.de ; form-action 'self' ; object-src 'self' blob: ; frame-src 'self'
         X-UA-Compatible: IE=edge
         Location: https://eid.elsteronline.de/gov_autent/async?SAMLRequest=rVVhb9owEP0rkb8nDmnpmEWo0qZMTN2GKJ2mfZlMcgVrxs5sB9p%2Fv3OS0mwam8b2CeTj3t29d%2FcYXz5uZbADY4VWKRlEMQlAFboUap2S%2B%2BU0HJHLydjyrUwqltVuoxbwrQbrAkxUlrWRlNRGMc2tsEzxLVjmCnaXvbtlSRSzyminCy1JkFkLxmGpa61svQVzB2YnCrhf3KZk41xlGaX7%2FT4CaR2YqAQKlTaOS2pgLawzAkyt1iGv7Z5vJPWfICyvqtCAwybo2wxHyLFBobiv9IILouxwtZJCgUdf690XXjtQjnL7pAoSzPKU5DE7j1l2zq4zNjxjgxs2vGLTKUsGLBmy61dslLCzKZvesAsMZZhkbQ0zZR1XLiVJPBiF8SBMhsv4NYtjFo%2Bi4cX5ZxLMjd6JEsx75Cgl7ZAhzBHh47MESBjpCGcNrOkz%2FXui%2BTO9ZPKCPaaNRh3YQcubR5zaq24nY2TmB20Psa40xlsaUZ2VFdGqVmWjzSyn5JT2upxHKw64XvX9WaTNmiZxPKCf3t3eFRvY8lA0vBbQJwkp8k13uwhl5nA1VigkTtOOe3gJWrJz7uDDw5UwboMr3uUK00tNiTM1EHoMYYFLZUThoJzlJ0K8ETtQvh97IkCuCzwb5ZZPFfJx0hhTvhXy6V%2BamEteIJfIB%2B5yI8wfGqFHtWoifVs5rN5knJWl8BfM5Zwb5AxvxbaL017BSttwZQDpaK3GtMaEq3H4feDNKCVoD1IUjR0sDVeWF%2F7rTD1oEjhu1oBHW0iBvJJgx2Xt1%2BUvLQC35ueqR0uhB6Lj%2Fs9Sxwf0Oh8dctH3VPtVK2e0lHu0aH8F9FcC4HP3Z9A3kOe3vpKT7w%3D%3D&RelayState=1516870808568&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%2Frsa-sha256&Signature=KLCBYBPXI8YO7%2Fn9s5Rjc2a7X8Jy9PT6tIKK1AKFAOowh8OhAjxcJuSez2O7G1E2ZYvan2bExJZ4%0ArjAbDbtJx98ANSK9VB93O4K5gqNE5Hlaiy00QoQrE4zUTlLDq5c2r0I23AkhqwQ%2FQEnV2WOuF5oG%0A%2FGVDlOtlw7IwcvIDGx5EAFKv9H3xyu%2B%2B2IvgiyHq0Jl7OAbfRIL578cbP9chyF7Js0nhWhlSfzrj%0ACgqNcTz4u87ptirHkjIuoy2ftL%2BhRolvcJ%2FmZkvMonCJnWRATZF2h5ptj63IYJHn47XGYbNJLQhp%0Aeoct2VmyycJKYf3QcoYJZI3mAeM3ISS9gA4ppQ%3D%3D
         Content-Length: 0
         Date: Thu, 25 Jan 2018 09:00:08 GMT
         Set-Cookie: JSESSIONID=0DAA40230D806D42BD4DF62E4BC216EB; Path=/eportal/; Secure; HttpOnly
 -01-25 10:00:08,697 [Thread-8] INFO  o.o.c.t.ClientCertDefaultTlsClient:321 - TLS warning sent.
 -01-25 10:00:08,697 [Thread-8] INFO  o.o.c.t.ClientCertDefaultTlsClient:323 - TLS(WARN): Close [close_notify=0] --> Connection closed
 -01-25 10:00:08,698 [Thread-8] INFO  o.o.binding.tctoken.ResourceContext:207 - Trying to load resource from: https://eid.elsteronline.de/gov_autent/async?SAMLRequest=rVVhb9owEP0rkb8nDmnpmEWo0qZMTN2GKJ2mfZlMcgVrxs5sB9p%2Fv3OS0mwam8b2CeTj3t29d%2FcYXz5uZbADY4VWKRlEMQlAFboUap2S%2B%2BU0HJHLydjyrUwqltVuoxbwrQbrAkxUlrWRlNRGMc2tsEzxLVjmCnaXvbtlSRSzyminCy1JkFkLxmGpa61svQVzB2YnCrhf3KZk41xlGaX7%2FT4CaR2YqAQKlTaOS2pgLawzAkyt1iGv7Z5vJPWfICyvqtCAwybo2wxHyLFBobiv9IILouxwtZJCgUdf690XXjtQjnL7pAoSzPKU5DE7j1l2zq4zNjxjgxs2vGLTKUsGLBmy61dslLCzKZvesAsMZZhkbQ0zZR1XLiVJPBiF8SBMhsv4NYtjFo%2Bi4cX5ZxLMjd6JEsx75Cgl7ZAhzBHh47MESBjpCGcNrOkz%2FXui%2BTO9ZPKCPaaNRh3YQcubR5zaq24nY2TmB20Psa40xlsaUZ2VFdGqVmWjzSyn5JT2upxHKw64XvX9WaTNmiZxPKCf3t3eFRvY8lA0vBbQJwkp8k13uwhl5nA1VigkTtOOe3gJWrJz7uDDw5UwboMr3uUK00tNiTM1EHoMYYFLZUThoJzlJ0K8ETtQvh97IkCuCzwb5ZZPFfJx0hhTvhXy6V%2BamEteIJfIB%2B5yI8wfGqFHtWoifVs5rN5knJWl8BfM5Zwb5AxvxbaL017BSttwZQDpaK3GtMaEq3H4feDNKCVoD1IUjR0sDVeWF%2F7rTD1oEjhu1oBHW0iBvJJgx2Xt1%2BUvLQC35ueqR0uhB6Lj%2Fs9Sxwf0Oh8dctH3VPtVK2e0lHu0aH8F9FcC4HP3Z9A3kOe3vpKT7w%3D%3D&RelayState=1516870808568&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%2Frsa-sha256&Signature=KLCBYBPXI8YO7%2Fn9s5Rjc2a7X8Jy9PT6tIKK1AKFAOowh8OhAjxcJuSez2O7G1E2ZYvan2bExJZ4%0ArjAbDbtJx98ANSK9VB93O4K5gqNE5Hlaiy00QoQrE4zUTlLDq5c2r0I23AkhqwQ%2FQEnV2WOuF5oG%0A%2FGVDlOtlw7IwcvIDGx5EAFKv9H3xyu%2B%2B2IvgiyHq0Jl7OAbfRIL578cbP9chyF7Js0nhWhlSfzrj%0ACgqNcTz4u87ptirHkjIuoy2ftL%2BhRolvcJ%2FmZkvMonCJnWRATZF2h5ptj63IYJHn47XGYbNJLQhp%0Aeoct2VmyycJKYf3QcoYJZI3mAeM3ISS9gA4ppQ%3D%3D
 -01-25 10:00:08,699 [Thread-8] DEBUG o.o.crypto.tls.proxy.ProxySettings:133 - Selecting proxy: DIRECT
 -01-25 10:00:08,776 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:244 - Performing TLS handshake.
 -01-25 10:00:08,919 [Thread-8] DEBUG o.o.c.tls.verify.HostnameVerifier:126 - Comparing connection hostname against certificate hostname: [eid.elsteronline.de] [eid.elsteronline.de]
 -01-25 10:00:09,005 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:246 - TLS handshake performed.
 -01-25 10:00:09,005 [Thread-8] DEBUG o.o.transport.httpcore.HttpUtils:81 - HTTP Request:
         GET /gov_autent/async?SAMLRequest=rVVhb9owEP0rkb8nDmnpmEWo0qZMTN2GKJ2mfZlMcgVrxs5sB9p%2Fv3OS0mwam8b2CeTj3t29d%2FcYXz5uZbADY4VWKRlEMQlAFboUap2S%2B%2BU0HJHLydjyrUwqltVuoxbwrQbrAkxUlrWRlNRGMc2tsEzxLVjmCnaXvbtlSRSzyminCy1JkFkLxmGpa61svQVzB2YnCrhf3KZk41xlGaX7%2FT4CaR2YqAQKlTaOS2pgLawzAkyt1iGv7Z5vJPWfICyvqtCAwybo2wxHyLFBobiv9IILouxwtZJCgUdf690XXjtQjnL7pAoSzPKU5DE7j1l2zq4zNjxjgxs2vGLTKUsGLBmy61dslLCzKZvesAsMZZhkbQ0zZR1XLiVJPBiF8SBMhsv4NYtjFo%2Bi4cX5ZxLMjd6JEsx75Cgl7ZAhzBHh47MESBjpCGcNrOkz%2FXui%2BTO9ZPKCPaaNRh3YQcubR5zaq24nY2TmB20Psa40xlsaUZ2VFdGqVmWjzSyn5JT2upxHKw64XvX9WaTNmiZxPKCf3t3eFRvY8lA0vBbQJwkp8k13uwhl5nA1VigkTtOOe3gJWrJz7uDDw5UwboMr3uUK00tNiTM1EHoMYYFLZUThoJzlJ0K8ETtQvh97IkCuCzwb5ZZPFfJx0hhTvhXy6V%2BamEteIJfIB%2B5yI8wfGqFHtWoifVs5rN5knJWl8BfM5Zwb5AxvxbaL017BSttwZQDpaK3GtMaEq3H4feDNKCVoD1IUjR0sDVeWF%2F7rTD1oEjhu1oBHW0iBvJJgx2Xt1%2BUvLQC35ueqR0uhB6Lj%2Fs9Sxwf0Oh8dctH3VPtVK2e0lHu0aH8F9FcC4HP3Z9A3kOe3vpKT7w%3D%3D&RelayState=1516870808568&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%2Frsa-sha256&Signature=KLCBYBPXI8YO7%2Fn9s5Rjc2a7X8Jy9PT6tIKK1AKFAOowh8OhAjxcJuSez2O7G1E2ZYvan2bExJZ4%0ArjAbDbtJx98ANSK9VB93O4K5gqNE5Hlaiy00QoQrE4zUTlLDq5c2r0I23AkhqwQ%2FQEnV2WOuF5oG%0A%2FGVDlOtlw7IwcvIDGx5EAFKv9H3xyu%2B%2B2IvgiyHq0Jl7OAbfRIL578cbP9chyF7Js0nhWhlSfzrj%0ACgqNcTz4u87ptirHkjIuoy2ftL%2BhRolvcJ%2FmZkvMonCJnWRATZF2h5ptj63IYJHn47XGYbNJLQhp%0Aeoct2VmyycJKYf3QcoYJZI3mAeM3ISS9gA4ppQ%3D%3D HTTP/1.1
         Connection: keep-alive
         User-Agent: Open eCard App/org.openecard.common.SemanticVersion@e580929
         Host: eid.elsteronline.de
         Accept: text/xml, */*;q=0.8
         Accept-Charset: utf-8, *;q=0.8
 -01-25 10:00:09,006 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:267 - Sending HTTP request.
 -01-25 10:00:09,115 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:270 - HTTP response received.
 -01-25 10:00:09,116 [Thread-8] DEBUG o.o.transport.httpcore.HttpUtils:112 - HTTP Response:
         HTTP/1.1 302 Moved Temporarily
         Server: Apache-Coyote/1.1
         Content-Security-Policy: default-src 'self'
         Cache-Control: no-cache, no-store
         Pragma: no-cache
         Location: https://eid.elsteronline.de/ecardpaos/startauthentication?DateOfBirth=true&applicationTransactionInfo=D0%3A40%3AA4%3ACA%3A53%3A1E%3A5B%3AFF%3A21%3A25%3AC7%3A82%3A3F%3AFE%3A6E%3A5A&RestrictedID=true&DocumentType=true&FamilyNames=true&applicationTransactionInfoName=Registrierungskontrollwert&receiverUrl=https%3A%2F%2Feidpaos.elsteronline.de%2Fecardpaos%2Fpaosreceiver&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%23rsa-sha256&requestID=d9904910-9752-4365-8ad0-0140eea2b460&GivenNames=true&Signature=gPJow0msFjVB%2FiXRbglYh5BgsID5zjmQT7Iu%2BzsbZGChrwU3InZh8%2BelgVoqtzshcum5PPVgfnvU5hWTbNYUG%2F7lbpgh64jjihBYedmT5puwn3hppcbMKorNe4pFcJxU8LHs%2FgPF1w07o%2B2PoD1%2B33i6M3TYwavJ0ZchkdTC5Ux5a6iTRGQL3IKWU8UXn9qUWltmSGYge8fEUr2z%2B4NjKzCfWhvr567UV7rBtbEf5f80CGTIKfsZ2j86dHY9uUC%2FMvDjZ4cjjHvhjUTj%2BMmfxCrsL%2FagNNLBz9HENReI%2BgcAhGFF2L0dmY6R39seU75s0KpQ1vOPuTCxrR7wrIM%2BLw%3D%3D&PlaceOfResidence=true&idProviderUrl=https%3A%2F%2Feid.elsteronline.de%2Fgov_autent%2Fasync%3FrefID%3D_5c41d2ba455507270ee7ef6fb1f128a05e4592fe
         Content-Length: 0
         Date: Thu, 25 Jan 2018 09:00:09 GMT
 -01-25 10:00:09,116 [Thread-8] INFO  o.o.c.t.ClientCertDefaultTlsClient:321 - TLS warning sent.
 -01-25 10:00:09,117 [Thread-8] INFO  o.o.c.t.ClientCertDefaultTlsClient:323 - TLS(WARN): Close [close_notify=0] --> Connection closed
 -01-25 10:00:09,118 [Thread-8] INFO  o.o.binding.tctoken.ResourceContext:207 - Trying to load resource from: https://eid.elsteronline.de/ecardpaos/startauthentication?DateOfBirth=true&applicationTransactionInfo=D0%3A40%3AA4%3ACA%3A53%3A1E%3A5B%3AFF%3A21%3A25%3AC7%3A82%3A3F%3AFE%3A6E%3A5A&RestrictedID=true&DocumentType=true&FamilyNames=true&applicationTransactionInfoName=Registrierungskontrollwert&receiverUrl=https%3A%2F%2Feidpaos.elsteronline.de%2Fecardpaos%2Fpaosreceiver&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%23rsa-sha256&requestID=d9904910-9752-4365-8ad0-0140eea2b460&GivenNames=true&Signature=gPJow0msFjVB%2FiXRbglYh5BgsID5zjmQT7Iu%2BzsbZGChrwU3InZh8%2BelgVoqtzshcum5PPVgfnvU5hWTbNYUG%2F7lbpgh64jjihBYedmT5puwn3hppcbMKorNe4pFcJxU8LHs%2FgPF1w07o%2B2PoD1%2B33i6M3TYwavJ0ZchkdTC5Ux5a6iTRGQL3IKWU8UXn9qUWltmSGYge8fEUr2z%2B4NjKzCfWhvr567UV7rBtbEf5f80CGTIKfsZ2j86dHY9uUC%2FMvDjZ4cjjHvhjUTj%2BMmfxCrsL%2FagNNLBz9HENReI%2BgcAhGFF2L0dmY6R39seU75s0KpQ1vOPuTCxrR7wrIM%2BLw%3D%3D&PlaceOfResidence=true&idProviderUrl=https%3A%2F%2Feid.elsteronline.de%2Fgov_autent%2Fasync%3FrefID%3D_5c41d2ba455507270ee7ef6fb1f128a05e4592fe
 -01-25 10:00:09,118 [Thread-8] DEBUG o.o.crypto.tls.proxy.ProxySettings:133 - Selecting proxy: DIRECT
 -01-25 10:00:09,152 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:244 - Performing TLS handshake.
 -01-25 10:00:09,289 [Thread-8] DEBUG o.o.c.tls.verify.HostnameVerifier:126 - Comparing connection hostname against certificate hostname: [eid.elsteronline.de] [eid.elsteronline.de]
 -01-25 10:00:09,370 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:246 - TLS handshake performed.
 -01-25 10:00:09,371 [Thread-8] DEBUG o.o.transport.httpcore.HttpUtils:81 - HTTP Request:
         GET /ecardpaos/startauthentication?DateOfBirth=true&applicationTransactionInfo=D0%3A40%3AA4%3ACA%3A53%3A1E%3A5B%3AFF%3A21%3A25%3AC7%3A82%3A3F%3AFE%3A6E%3A5A&RestrictedID=true&DocumentType=true&FamilyNames=true&applicationTransactionInfoName=Registrierungskontrollwert&receiverUrl=https%3A%2F%2Feidpaos.elsteronline.de%2Fecardpaos%2Fpaosreceiver&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%23rsa-sha256&requestID=d9904910-9752-4365-8ad0-0140eea2b460&GivenNames=true&Signature=gPJow0msFjVB%2FiXRbglYh5BgsID5zjmQT7Iu%2BzsbZGChrwU3InZh8%2BelgVoqtzshcum5PPVgfnvU5hWTbNYUG%2F7lbpgh64jjihBYedmT5puwn3hppcbMKorNe4pFcJxU8LHs%2FgPF1w07o%2B2PoD1%2B33i6M3TYwavJ0ZchkdTC5Ux5a6iTRGQL3IKWU8UXn9qUWltmSGYge8fEUr2z%2B4NjKzCfWhvr567UV7rBtbEf5f80CGTIKfsZ2j86dHY9uUC%2FMvDjZ4cjjHvhjUTj%2BMmfxCrsL%2FagNNLBz9HENReI%2BgcAhGFF2L0dmY6R39seU75s0KpQ1vOPuTCxrR7wrIM%2BLw%3D%3D&PlaceOfResidence=true&idProviderUrl=https%3A%2F%2Feid.elsteronline.de%2Fgov_autent%2Fasync%3FrefID%3D_5c41d2ba455507270ee7ef6fb1f128a05e4592fe HTTP/1.1
         Connection: keep-alive
         User-Agent: Open eCard App/org.openecard.common.SemanticVersion@e580929
         Host: eid.elsteronline.de
         Accept: text/xml, */*;q=0.8
         Accept-Charset: utf-8, *;q=0.8
 -01-25 10:00:09,372 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:267 - Sending HTTP request.
 -01-25 10:00:09,449 [Thread-8] DEBUG o.o.binding.tctoken.ResourceContext:270 - HTTP response received.
 -01-25 10:00:09,451 [Thread-8] DEBUG o.o.transport.httpcore.HttpUtils:112 - HTTP Response:
         HTTP/1.1 200 OK
         Server: Apache-Coyote/1.1
         Content-Security-Policy: default-src 'self'
         Content-Type: text/xml;charset=utf-8
         Content-Length: 648
         Date: Thu, 25 Jan 2018 09:00:09 GMT
 -01-25 10:00:09,454 [Thread-8] DEBUG o.o.binding.tctoken.TCTokenContext:91 - Cleaned up TCToken:
       <TCTokenType>
       <ServerAddress>https://eidpaos.elsteronline.de/ecardpaos/paosreceiver</ServerAddress>
       <SessionIdentifier>d9904910-9752-4365-8ad0-0140eea2b460</SessionIdentifier>
       <RefreshAddress>https://eid.elsteronline.de/gov_autent/async?refID=_5c41d2ba455507270ee7ef6fb1f128a05e4592fe</RefreshAddress>
       <CommunicationErrorAddress/>
       <Binding>urn:liberty:paos:2006-08</Binding>
       <PathSecurity-Protocol>urn:ietf:rfc:4279</PathSecurity-Protocol>
       <PathSecurity-Parameters>
       <PSK>1e3e2bb51a097a8667072d6d795b62d7484b26f837ff5a53d17a0e0fee97cbcdf3b24b044d045209a86c8073e1889f4a8f187c5a6531e32190c5d4fd2979d6e4</PSK>
       </PathSecurity-Parameters>
       </TCTokenType>
 -01-25 10:00:09,485 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:09,486 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:09,487 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.CardApplicationPath
 -01-25 10:00:09,498 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:09,499 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:09,502 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:09,503 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:09,504 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.CardApplicationConnect
 -01-25 10:00:09,505 [Thread-8] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type Connect.
 -01-25 10:00:09,509 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:09,518 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:09,518 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Connect
 -01-25 10:00:09,519 [Thread-8] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 10:00:09,534 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:09,535 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:09,539 [Thread-8] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:09,551 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:09,553 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:09,553 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:09,554 [Thread-8] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0xA4 0x00 0x0C 0x02 0x3F 0x00
 -01-25 10:00:09,564 [Thread-8] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:09,571 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:09,573 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:09,582 [Thread-8] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:09,585 [Thread-8] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:09,599 [PAOS] INFO  o.o.c.t.ClientCertDefaultTlsClient:321 - TLS warning sent.
 -01-25 10:00:09,599 [PAOS] INFO  o.o.c.t.ClientCertDefaultTlsClient:323 - TLS(WARN): Close [close_notify=0] --> Connection closed
 -01-25 10:00:09,648 [PAOS] DEBUG org.openecard.transport.paos.PAOS:399 - Opening connection to PAOS server.
 -01-25 10:00:09,650 [PAOS] DEBUG o.o.crypto.tls.proxy.ProxySettings:133 - Selecting proxy: DIRECT
 -01-25 10:00:09,785 [PAOS] DEBUG o.o.c.tls.verify.HostnameVerifier:126 - Comparing connection hostname against certificate hostname: [eidpaos.elsteronline.de] [eidpaos.elsteronline.de]
 -01-25 10:00:09,924 [PAOS] DEBUG org.openecard.transport.paos.PAOS:402 - Connection to PAOS server established.
 -01-25 10:00:09,929 [PAOS] DEBUG o.o.transport.httpcore.HttpUtils:81 - HTTP Request (before adding content):
         POST /ecardpaos/paosreceiver HTTP/1.1
         Connection: keep-alive
         User-Agent: Open eCard App/org.openecard.common.SemanticVersion@e580929
         Host: eidpaos.elsteronline.de
         PAOS: ver="urn:liberty:paos:2006-08" ;"urn:iso:std:iso-iec:24727:tech:schema:Transmit";"http://www.bsi.bund.de/ecard/api/1.0#InitializeFramework";"urn:iso:std:iso-iec:24727:tech:schema:StartSession";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationEndSession";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationList";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationServiceList";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationServiceDescribe";"urn:iso:std:iso-iec:24727:tech:schema:DataSetList";"urn:iso:std:iso-iec:24727:tech:schema:DataSetSelect";"urn:iso:std:iso-iec:24727:tech:schema:DSIList";"urn:iso:std:iso-iec:24727:tech:schema:DSIWrite";"urn:iso:std:iso-iec:24727:tech:schema:DSIRead";"urn:iso:std:iso-iec:24727:tech:schema:Encipher";"urn:iso:std:iso-iec:24727:tech:schema:Decipher";"urn:iso:std:iso-iec:24727:tech:schema:GetRandom";"urn:iso:std:iso-iec:24727:tech:schema:Sign";"urn:iso:std:iso-iec:24727:tech:schema:VerifySignature";"urn:iso:std:iso-iec:24727:tech:schema:VerifyCertificate";"urn:iso:std:iso-iec:24727:tech:schema:DIDList";"urn:iso:std:iso-iec:24727:tech:schema:DIDGet";"urn:iso:std:iso-iec:24727:tech:schema:DIDAuthenticate";"urn:iso:std:iso-iec:24727:tech:schema:ACLList";"urn:iso:std:iso-iec:24727:tech:schema:Hash"
         Accept: text/xml, application/xml, application/vnd.paos+xml
 -01-25 10:00:10,006 [PAOS] DEBUG org.openecard.transport.paos.PAOS:234 - Message sent:
       <?xml version="1.0" encoding="UTF-8" standalone="no"?>
       <Envelope xmlns="http://schemas.xmlsoap.org/soap/envelope/">
         <Header>
           <PAOS xmlns:ns0="http://schemas.xmlsoap.org/soap/envelope/" ns0:actor="http://schemas.xmlsoap.org/soap/actor/next" xmlns:ns1="http://schemas.xmlsoap.org/soap/envelope/" ns1:mustUnderstand="1" xmlns="urn:liberty:paos:2006-08">
             <Version>urn:liberty:paos:2006-08</Version>
             <EndpointReference>
               <Address>http://www.projectliberty.org/2006/01/role/paos</Address>
               <MetaData>
                 <ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</ServiceType>
               </MetaData>
             </EndpointReference>
           </PAOS>
           <ReplyTo xmlns="http://www.w3.org/2005/03/addressing">
             <Address>http://www.projectliberty.org/2006/02/role/paos</Address>
           </ReplyTo>
           <MessageID xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:bf7a0269-c9b4-4da8-8fc5-816b9624669a</MessageID>
         </Header>
         <Body>
           <iso:StartPAOS xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:ns10="urn:oasis:names:tc:SAML:1.0:assertion" xmlns:ns11="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns12="http://www.w3.org/2001/04/xmlenc#" xmlns:ns13="http://ws.openecard.org/schema" xmlns:ns14="http://www.w3.org/2001/04/xmldsig-more#" xmlns:ns15="http://www.w3.org/2007/05/xmldsig-more#" xmlns:ns2="urn:oasis:names:tc:dss:1.0:core:schema" xmlns:ns3="http://www.w3.org/2000/09/xmldsig#" xmlns:ns4="http://www.bsi.bund.de/ecard/api/1.1" xmlns:ns5="http://uri.etsi.org/02231/v3.1.2#" xmlns:ns6="http://www.w3.org/2009/xmlenc11#" xmlns:ns7="http://www.setcce.org/schemas/ers" xmlns:ns8="urn:oasis:names:tc:dss-x:1.0:profiles:verificationreport:schema#" xmlns:ns9="http://uri.etsi.org/01903/v1.3.2#" Profile="http://www.bsi.bund.de/ecard/api/1.1">
             <iso:SessionIdentifier>d9904910-9752-4365-8ad0-0140eea2b460</iso:SessionIdentifier>
             <iso:ConnectionHandle>
               <iso:ChannelHandle>
                 <iso:SessionIdentifier>H1NctFpkvY7sCUUpPBSegA</iso:SessionIdentifier>
               </iso:ChannelHandle>
               <iso:ContextHandle>0C4CFAEE07B92B3DB449BBD1F144DC09</iso:ContextHandle>
               <iso:IFDName>REINER SCT cyberJack RFID standard (0810057893) 00 00</iso:IFDName>
               <iso:SlotIndex>0</iso:SlotIndex>
               <iso:CardApplication>3F00</iso:CardApplication>
               <iso:SlotHandle>874B4EF35DD1A3A87611A06D91439BA8E983AE516CDE2ABE</iso:SlotHandle>
               <iso:RecognitionInfo>
                 <iso:CardType>http://bsi.bund.de/cif/npa.xml</iso:CardType>
               </iso:RecognitionInfo>
             </iso:ConnectionHandle>
             <iso:UserAgent>
               <iso:Name>Open eCard App</iso:Name>
               <iso:VersionMajor>1</iso:VersionMajor>
               <iso:VersionMinor>3</iso:VersionMinor>
               <iso:VersionSubminor>0</iso:VersionSubminor>
             </iso:UserAgent>
             <iso:SupportedAPIVersions>
               <iso:Major>1</iso:Major>
               <iso:Minor>1</iso:Minor>
               <iso:Subminor>4</iso:Subminor>
             </iso:SupportedAPIVersions>
             <iso:SupportedDIDProtocols>urn:oid:1.3.162.15480.3.0.14</iso:SupportedDIDProtocols>
             <iso:SupportedDIDProtocols>urn:oid:1.3.162.15480.3.0.14.2</iso:SupportedDIDProtocols>
             <iso:SupportedDIDProtocols>urn:oid:1.3.162.15480.3.0.25</iso:SupportedDIDProtocols>
             <iso:SupportedDIDProtocols>urn:oid:1.3.162.15480.3.0.9</iso:SupportedDIDProtocols>
           </iso:StartPAOS>
         </Body>
       </Envelope>
 -01-25 10:00:10,007 [PAOS] DEBUG org.openecard.transport.paos.PAOS:318 - Sending HTTP request.
 -01-25 10:00:10,325 [PAOS] DEBUG org.openecard.transport.paos.PAOS:320 - HTTP response received.
 -01-25 10:00:10,325 [PAOS] WARN  org.openecard.transport.paos.PAOS:424 - The PAOS endpoint sent the http status code 200 which does not conform to the PAOS specification. (See section 9.4 Processing Rules of the PAOS Specification)
 -01-25 10:00:10,326 [PAOS] DEBUG o.o.transport.httpcore.HttpUtils:112 - HTTP Response:
         HTTP/1.1 200 OK
         Server: Apache-Coyote/1.1
         Content-Security-Policy: default-src 'self'
         Content-Type: application/vnd.paos+xml
         Content-Length: 7189
         Date: Thu, 25 Jan 2018 09:00:10 GMT
       <?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
          <soap:Header>
             <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id33899" refToMessageID="d9904910-9752-4365-8ad0-0140eea2b460"/>
             <RelatesTo xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:bf7a0269-c9b4-4da8-8fc5-816b9624669a</RelatesTo>
             <MessageID xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:24072141-9029-4b8b-b89f-a5ef9da7c393</MessageID>
          </soap:Header>
          <soap:Body>
          <ns4:DIDAuthenticate xmlns:ns4="urn:iso:std:iso-iec:24727:tech:schema" xmlns:ns2="urn:oasis:names:tc:dss:1.0:core:schema" xmlns:ns3="http://www.w3.org/2000/09/xmldsig#">
             <ns4:ConnectionHandle>
               <ns4:ChannelHandle>
                 <ns4:SessionIdentifier>H1NctFpkvY7sCUUpPBSegA</ns4:SessionIdentifier>
               </ns4:ChannelHandle>
               <ns4:ContextHandle>0C4CFAEE07B92B3DB449BBD1F144DC09</ns4:ContextHandle>
               <ns4:IFDName>REINER SCT cyberJack RFID standard (0810057893) 00 00</ns4:IFDName>
               <ns4:SlotIndex>0</ns4:SlotIndex>
               <ns4:CardApplication>3F00</ns4:CardApplication>
               <ns4:SlotHandle>874B4EF35DD1A3A87611A06D91439BA8E983AE516CDE2ABE</ns4:SlotHandle>
               <ns4:RecognitionInfo>
                 <ns4:CardType>http://bsi.bund.de/cif/npa.xml</ns4:CardType>
               </ns4:RecognitionInfo>
             </ns4:ConnectionHandle>
             <ns4:DIDName>PIN</ns4:DIDName>
             <ns4:AuthenticationProtocolData xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" Protocol="urn:oid:1.3.162.15480.3.0.14.2" xsi:type="ns4:EAC1InputType">
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f218201487f4e8201005f2901004210444544566549444454523130313433317f494f060a04007f000702020202038641048650ffb363aca465ceddff921455e7d8b40b46668f44ef3f6129d1e654e99a2c6caba42ea553b9bcc3143794b8b5be76535d1493ffe93f8d69b0824eaa44b94c5f200e44453030303035313030303035337f4c12060904007f0007030102025305000101db045f25060108000102055f2406010800010206655e732d060904007f00070301030280202f7f530240110ee0adfcaba5bce97e9a44bab167b5677e42b002192a9d238945732d060904007f0007030103018020cde462c123ef567854d77ed12df1183bbcecae8279b4abd5020016b4fe22fa535f374053a0b7cbec3bcc4a95565963137d4e188588d27b81bcb063ffbf8532b600066c97f92d8db68d6cbed4a6091533fc7a54d796c0876405bec2d88bc21fa430289b</ns4:Certificate>
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f218201b67f4e82016e5f290100420e44454356434165494430303130327f4982011d060a04007f000702020202038120a9fb57dba1eea9bc3e660a909d838d726e3bf623d52620282013481d1f6e537782207d5a0975fc2c3057eef67530417affe7fb8055c126dc5c6ce94a4b44f330b5d9832026dc5c6ce94a4b44f330b5d9bbd77cbf958416295cf7e1ce6bccdc18ff8c07b68441048bd2aeb9cb7e57cb2c4b482ffc81b7afb9de27e1e3bd23c23a4453bd9ace3262547ef835c3dac4fd97f8461a14611dc9c27745132ded8e545c1d54c72f0469978520a9fb57dba1eea9bc3e660a909d838d718c397aa3b561a6f7901e0e82974856a78641048925419fc7f194922cfc6b8dd25ae6a19c1b59216e6cf06270e5d75cfd64205f55cf867bbfefeefd6e680e1fd197f18ab684484901362568efc9adb5c6018d728701015f200e44454356434165494430303130337f4c12060904007f0007030102025305fc0f13ffff5f25060102010200035f24060105010200035f37404d6f08a86a4f18409f6685387dd3c6a7ff5d68ea4f7714a861bbb3bb721d05d3014adf1763c9292f715d8e94ee9b3e1b73ab1382414ebf39dfb3b0fb6c09dbeb</ns4:Certificate>
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f218201b67f4e82016e5f290100420e44454356434165494430303130337f4982011d060a04007f000702020202038120a9fb57dba1eea9bc3e660a909d838d726e3bf623d52620282013481d1f6e537782207d5a0975fc2c3057eef67530417affe7fb8055c126dc5c6ce94a4b44f330b5d9832026dc5c6ce94a4b44f330b5d9bbd77cbf958416295cf7e1ce6bccdc18ff8c07b68441048bd2aeb9cb7e57cb2c4b482ffc81b7afb9de27e1e3bd23c23a4453bd9ace3262547ef835c3dac4fd97f8461a14611dc9c27745132ded8e545c1d54c72f0469978520a9fb57dba1eea9bc3e660a909d838d718c397aa3b561a6f7901e0e82974856a7864104241d8627338b64f20077ffd558909a096c635ddb222852038eaae642e869a40173d588f817d95db2a6a0f077ea5ee63596a20f85bc3cb176d2f98d88d90219aa8701015f200e44454356434165494430303130347f4c12060904007f0007030102025305fc0f13ffff5f25060105000901045f24060108000901045f3740313a81ed8734e7a8c45f16b55fb603e63027b7f44c2de3a8e782552d35949db221ca33bd41a01da6a1288c7885714fc3a03fa45683b75d3884930ec6738af8a0</ns4:Certificate>
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f2181e77f4e81a05f290100420e44454356434165494430303130347f494f060a04007f000702020202038641048b9fbbfa2e30567e97c28f2fcfbfd0b02a129fa27654252a17af90f06d5a1edd6cd9b027145c4154148509d5bae005268d2082f8f6a1e358bdd4be98ea08439a5f2010444544566549444454523130313433317f4c12060904007f0007030102025305400513ff875f25060107010200085f24060108000300085f37403a8a1f9c4ba64edd5093953ab7a1b6a0180a689debdf22f3bad64e776b4647675bc34251fa9ff848cdb3e3ff51da73b7ded2bc70e3ef1f7520c1d41000255fd6</ns4:Certificate>
               <ns4:CertificateDescription xmlns="urn:iso:std:iso-iec:24727:tech:schema">308202fa060a04007f00070301030101a10e0c0c442d547275737420476d6248a2181316687474703a2f2f7777772e642d74727573742e6e6574a3470c45454c53544552202d204672656973746161742042617965726e2c2076657274722e2064757263682042617953744d462c2076657274722e206475726368204261794c665374a417131568747470733a2f2f7777772e656c737465722e6465a58201f40c8201f04e616d652c20416e7363687269667420756e6420452d4d61696c2d4164726573736520646573200d0a4469656e737465616e626965746572733a0d0a454c53544552202d204672656973746161742042617965726e2c0d0a76657274722e2064757263682042617953744d462c0d0a76657274722e206475726368204261794c6653740d0a4b6174686172696e612d766f6e2d426f72612d53747261c39f6520360d0a3830333333204dc3bc6e6368656e0d0a686f746c696e6540656c737465722e64650d0a0d0a4765736368c3a46674737a7765636b3a0d0a0d0a48696e7765697320617566206469652066c3bc722064656e204469656e737465616e626965746572200d0a7a757374c3a46e646967656e205374656c6c656e2c20646965206469652045696e68616c74756e67200d0a64657220566f7273636872696674656e207a756d20446174656e73636875747a200d0a6b6f6e74726f6c6c696572656e3a0d0a4465722042617965726973636865204c616e64657362656175667472616774652066c3bc722064656e20446174656e73636875747a0d0a5761676dc3bc6c6c657273747261c39f652031380d0a3830353338204dc3bc6e6368656e0d0a303839203231323637322d300d0a706f73747374656c6c6540646174656e73636875747a2d62617965726e2e6465a76831660420375b6e3cc271940553c199386e13a6eab00c086ae3bce1a67e8a1e83118733c004209c7575d778fb0dba0687864a93f85b1bee48d20a72e4b8ab8d19610aab34a1500420fb9a1575bd0ce4e986f7f42a2234ce40617757135ccef19c62519a764790cfea</ns4:CertificateDescription>
               <ns4:RequiredCHAT xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f4c12060904007f00070301020253050001009904</ns4:RequiredCHAT>
               <ns4:OptionalCHAT xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f4c12060904007f00070301020253050000000000</ns4:OptionalCHAT>
               <ns4:AuthenticatedAuxiliaryData xmlns="urn:iso:std:iso-iec:24727:tech:schema">67177315060904007f00070301040253083230313830313235</ns4:AuthenticatedAuxiliaryData>
               <ns4:TransactionInfo xmlns="urn:iso:std:iso-iec:24727:tech:schema">D0:40:A4:CA:53:1E:5B:FF:21:25:C7:82:3F:FE:6E:5A</ns4:TransactionInfo>
             </ns4:AuthenticationProtocolData>
           </ns4:DIDAuthenticate>
         </soap:Body>
       </soap:Envelope>
 -01-25 10:00:10,331 [PAOS] DEBUG org.openecard.transport.paos.PAOS:209 - Message received:
       <?xml version="1.0" encoding="UTF-8" standalone="no"?>
       <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
         <soap:Header>
           <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id33899" refToMessageID="d9904910-9752-4365-8ad0-0140eea2b460"/>
           <RelatesTo xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:bf7a0269-c9b4-4da8-8fc5-816b9624669a</RelatesTo>
           <MessageID xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:24072141-9029-4b8b-b89f-a5ef9da7c393</MessageID>
         </soap:Header>
         <soap:Body>
           <ns4:DIDAuthenticate xmlns:ns2="urn:oasis:names:tc:dss:1.0:core:schema" xmlns:ns3="http://www.w3.org/2000/09/xmldsig#" xmlns:ns4="urn:iso:std:iso-iec:24727:tech:schema">
             <ns4:ConnectionHandle>
               <ns4:ChannelHandle>
                 <ns4:SessionIdentifier>H1NctFpkvY7sCUUpPBSegA</ns4:SessionIdentifier>
               </ns4:ChannelHandle>
               <ns4:ContextHandle>0C4CFAEE07B92B3DB449BBD1F144DC09</ns4:ContextHandle>
               <ns4:IFDName>REINER SCT cyberJack RFID standard (0810057893) 00 00</ns4:IFDName>
               <ns4:SlotIndex>0</ns4:SlotIndex>
               <ns4:CardApplication>3F00</ns4:CardApplication>
               <ns4:SlotHandle>874B4EF35DD1A3A87611A06D91439BA8E983AE516CDE2ABE</ns4:SlotHandle>
               <ns4:RecognitionInfo>
                 <ns4:CardType>http://bsi.bund.de/cif/npa.xml</ns4:CardType>
               </ns4:RecognitionInfo>
             </ns4:ConnectionHandle>
             <ns4:DIDName>PIN</ns4:DIDName>
             <ns4:AuthenticationProtocolData xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" Protocol="urn:oid:1.3.162.15480.3.0.14.2" xsi:type="ns4:EAC1InputType">
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f218201487f4e8201005f2901004210444544566549444454523130313433317f494f060a04007f000702020202038641048650ffb363aca465ceddff921455e7d8b40b46668f44ef3f6129d1e654e99a2c6caba42ea553b9bcc3143794b8b5be76535d1493ffe93f8d69b0824eaa44b94c5f200e44453030303035313030303035337f4c12060904007f0007030102025305000101db045f25060108000102055f2406010800010206655e732d060904007f00070301030280202f7f530240110ee0adfcaba5bce97e9a44bab167b5677e42b002192a9d238945732d060904007f0007030103018020cde462c123ef567854d77ed12df1183bbcecae8279b4abd5020016b4fe22fa535f374053a0b7cbec3bcc4a95565963137d4e188588d27b81bcb063ffbf8532b600066c97f92d8db68d6cbed4a6091533fc7a54d796c0876405bec2d88bc21fa430289b</ns4:Certificate>
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f218201b67f4e82016e5f290100420e44454356434165494430303130327f4982011d060a04007f000702020202038120a9fb57dba1eea9bc3e660a909d838d726e3bf623d52620282013481d1f6e537782207d5a0975fc2c3057eef67530417affe7fb8055c126dc5c6ce94a4b44f330b5d9832026dc5c6ce94a4b44f330b5d9bbd77cbf958416295cf7e1ce6bccdc18ff8c07b68441048bd2aeb9cb7e57cb2c4b482ffc81b7afb9de27e1e3bd23c23a4453bd9ace3262547ef835c3dac4fd97f8461a14611dc9c27745132ded8e545c1d54c72f0469978520a9fb57dba1eea9bc3e660a909d838d718c397aa3b561a6f7901e0e82974856a78641048925419fc7f194922cfc6b8dd25ae6a19c1b59216e6cf06270e5d75cfd64205f55cf867bbfefeefd6e680e1fd197f18ab684484901362568efc9adb5c6018d728701015f200e44454356434165494430303130337f4c12060904007f0007030102025305fc0f13ffff5f25060102010200035f24060105010200035f37404d6f08a86a4f18409f6685387dd3c6a7ff5d68ea4f7714a861bbb3bb721d05d3014adf1763c9292f715d8e94ee9b3e1b73ab1382414ebf39dfb3b0fb6c09dbeb</ns4:Certificate>
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f218201b67f4e82016e5f290100420e44454356434165494430303130337f4982011d060a04007f000702020202038120a9fb57dba1eea9bc3e660a909d838d726e3bf623d52620282013481d1f6e537782207d5a0975fc2c3057eef67530417affe7fb8055c126dc5c6ce94a4b44f330b5d9832026dc5c6ce94a4b44f330b5d9bbd77cbf958416295cf7e1ce6bccdc18ff8c07b68441048bd2aeb9cb7e57cb2c4b482ffc81b7afb9de27e1e3bd23c23a4453bd9ace3262547ef835c3dac4fd97f8461a14611dc9c27745132ded8e545c1d54c72f0469978520a9fb57dba1eea9bc3e660a909d838d718c397aa3b561a6f7901e0e82974856a7864104241d8627338b64f20077ffd558909a096c635ddb222852038eaae642e869a40173d588f817d95db2a6a0f077ea5ee63596a20f85bc3cb176d2f98d88d90219aa8701015f200e44454356434165494430303130347f4c12060904007f0007030102025305fc0f13ffff5f25060105000901045f24060108000901045f3740313a81ed8734e7a8c45f16b55fb603e63027b7f44c2de3a8e782552d35949db221ca33bd41a01da6a1288c7885714fc3a03fa45683b75d3884930ec6738af8a0</ns4:Certificate>
               <ns4:Certificate xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f2181e77f4e81a05f290100420e44454356434165494430303130347f494f060a04007f000702020202038641048b9fbbfa2e30567e97c28f2fcfbfd0b02a129fa27654252a17af90f06d5a1edd6cd9b027145c4154148509d5bae005268d2082f8f6a1e358bdd4be98ea08439a5f2010444544566549444454523130313433317f4c12060904007f0007030102025305400513ff875f25060107010200085f24060108000300085f37403a8a1f9c4ba64edd5093953ab7a1b6a0180a689debdf22f3bad64e776b4647675bc34251fa9ff848cdb3e3ff51da73b7ded2bc70e3ef1f7520c1d41000255fd6</ns4:Certificate>
               <ns4:CertificateDescription xmlns="urn:iso:std:iso-iec:24727:tech:schema">308202fa060a04007f00070301030101a10e0c0c442d547275737420476d6248a2181316687474703a2f2f7777772e642d74727573742e6e6574a3470c45454c53544552202d204672656973746161742042617965726e2c2076657274722e2064757263682042617953744d462c2076657274722e206475726368204261794c665374a417131568747470733a2f2f7777772e656c737465722e6465a58201f40c8201f04e616d652c20416e7363687269667420756e6420452d4d61696c2d4164726573736520646573200d0a4469656e737465616e626965746572733a0d0a454c53544552202d204672656973746161742042617965726e2c0d0a76657274722e2064757263682042617953744d462c0d0a76657274722e206475726368204261794c6653740d0a4b6174686172696e612d766f6e2d426f72612d53747261c39f6520360d0a3830333333204dc3bc6e6368656e0d0a686f746c696e6540656c737465722e64650d0a0d0a4765736368c3a46674737a7765636b3a0d0a0d0a48696e7765697320617566206469652066c3bc722064656e204469656e737465616e626965746572200d0a7a757374c3a46e646967656e205374656c6c656e2c20646965206469652045696e68616c74756e67200d0a64657220566f7273636872696674656e207a756d20446174656e73636875747a200d0a6b6f6e74726f6c6c696572656e3a0d0a4465722042617965726973636865204c616e64657362656175667472616774652066c3bc722064656e20446174656e73636875747a0d0a5761676dc3bc6c6c657273747261c39f652031380d0a3830353338204dc3bc6e6368656e0d0a303839203231323637322d300d0a706f73747374656c6c6540646174656e73636875747a2d62617965726e2e6465a76831660420375b6e3cc271940553c199386e13a6eab00c086ae3bce1a67e8a1e83118733c004209c7575d778fb0dba0687864a93f85b1bee48d20a72e4b8ab8d19610aab34a1500420fb9a1575bd0ce4e986f7f42a2234ce40617757135ccef19c62519a764790cfea</ns4:CertificateDescription>
               <ns4:RequiredCHAT xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f4c12060904007f00070301020253050001009904</ns4:RequiredCHAT>
               <ns4:OptionalCHAT xmlns="urn:iso:std:iso-iec:24727:tech:schema">7f4c12060904007f00070301020253050000000000</ns4:OptionalCHAT>
               <ns4:AuthenticatedAuxiliaryData xmlns="urn:iso:std:iso-iec:24727:tech:schema">67177315060904007f00070301040253083230313830313235</ns4:AuthenticatedAuxiliaryData>
               <ns4:TransactionInfo xmlns="urn:iso:std:iso-iec:24727:tech:schema">D0:40:A4:CA:53:1E:5B:FF:21:25:C7:82:3F:FE:6E:5A</ns4:TransactionInfo>
             </ns4:AuthenticationProtocolData>
           </ns4:DIDAuthenticate>
         </soap:Body>
       </soap:Envelope>
 -01-25 10:00:10,340 [PAOS] DEBUG o.o.common.util.HandlerUtils:124 - Found ConnectionHandle in object of type DIDAuthenticate.
 -01-25 10:00:10,363 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:10,364 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:10,364 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:10,364 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.DIDAuthenticate
 -01-25 10:00:10,388 [PAOS] WARN  org.openecard.common.I18n:152 - Failed to load resource eac for lang de_DE.
 -01-25 10:00:10,432 [PAOS] DEBUG o.o.common.util.HandlerUtils:131 - Found ContextHandle in object of type GetIFDCapabilities.
 -01-25 10:00:10,436 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:10,436 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:10,437 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:10,438 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.GetIFDCapabilities
 -01-25 10:00:10,439 [PAOS] WARN  o.o.ifd.scio.wrapper.ChannelManager:86 - Terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00' is already connected.
 -01-25 10:00:10,457 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:10,458 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:10,459 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:10,463 [PAOS] WARN  o.o.c.c.a.c.CardVerifiableCertificateChain:60 - Verification of the certificate chain is disabled.
 -01-25 10:00:10,475 [PAOS] DEBUG o.o.common.util.TR03112Utils:104 - Hash of the retrieved server certificate: FB9A1575BD0CE4E986F7F42A2234CE40617757135CCEF19C62519A764790CFEA
 -01-25 10:00:10,476 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 375B6E3CC271940553C199386E13A6EAB00C086AE3BCE1A67E8A1E83118733C0
 -01-25 10:00:10,478 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 9C7575D778FB0DBA0687864A93F85B1BEE48D20A72E4B8AB8D19610AAB34A150
 -01-25 10:00:10,479 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: FB9A1575BD0CE4E986F7F42A2234CE40617757135CCEF19C62519A764790CFEA
 -01-25 10:00:10,484 [PAOS] DEBUG o.o.common.util.TR03112Utils:104 - Hash of the retrieved server certificate: 375B6E3CC271940553C199386E13A6EAB00C086AE3BCE1A67E8A1E83118733C0
 -01-25 10:00:10,485 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 375B6E3CC271940553C199386E13A6EAB00C086AE3BCE1A67E8A1E83118733C0
 -01-25 10:00:10,490 [PAOS] DEBUG o.o.common.util.TR03112Utils:104 - Hash of the retrieved server certificate: 9C7575D778FB0DBA0687864A93F85B1BEE48D20A72E4B8AB8D19610AAB34A150
 -01-25 10:00:10,491 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 375B6E3CC271940553C199386E13A6EAB00C086AE3BCE1A67E8A1E83118733C0
 -01-25 10:00:10,494 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 9C7575D778FB0DBA0687864A93F85B1BEE48D20A72E4B8AB8D19610AAB34A150
 -01-25 10:00:10,497 [PAOS] DEBUG o.o.common.util.TR03112Utils:104 - Hash of the retrieved server certificate: 9C7575D778FB0DBA0687864A93F85B1BEE48D20A72E4B8AB8D19610AAB34A150
 -01-25 10:00:10,498 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 375B6E3CC271940553C199386E13A6EAB00C086AE3BCE1A67E8A1E83118733C0
 -01-25 10:00:10,499 [PAOS] DEBUG o.o.common.util.TR03112Utils:109 - CommCertificate: 9C7575D778FB0DBA0687864A93F85B1BEE48D20A72E4B8AB8D19610AAB34A150
 -01-25 10:00:10,505 [PAOS] DEBUG o.o.common.util.TR03112Utils:54 - Checking SOP for https://www.elster.de/eportal/registrierung-auswahl/eid-fwd/JA0?ElsterRequestKeys.NPA_REG_ID=f9601f51-99bd-4b25-9f76-ff98768ece05 and https://www.elster.de.
 -01-25 10:00:10,526 [PAOS] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Transmit.
 -01-25 10:00:10,540 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:10,541 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:10,542 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:10,542 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Transmit
 -01-25 10:00:10,545 [PAOS] DEBUG o.o.i.s.wrapper.SingleThreadChannel:260 - Send APDU: 0x00 0x22 0xC1 0xA4 0x0F 0x80 0x0A 0x04 0x00 0x7F 0x00 0x07 0x02 0x02 0x04 0x02 0x02 0x83 0x01 0x03
 -01-25 10:00:10,604 [PAOS] DEBUG o.o.i.s.wrapper.SingleThreadChannel:263 - Receive APDU: 0x90 0x00
 -01-25 10:00:10,615 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:10,615 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:10,615 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:10,764 [EAC-GUI] DEBUG org.openecard.gui.swing.StepBar:97 - Selecting index 0, previous was -1.
 -01-25 10:00:10,841 [EAC-GUI] WARN  org.openecard.common.I18n:152 - Failed to load resource swing for lang de_DE.
 -01-25 10:00:11,026 [Swing-GUI-BG-Task] DEBUG o.o.s.protocol.eac.gui.CardMonitor:65 - Waiting for card to be removed.
 -01-25 10:00:16,076 [AWT-EventQueue-1] DEBUG o.o.gui.swing.SwingNavigator:244 - Received event: Button.next
 -01-25 10:00:16,082 [AWT-EventQueue-1] DEBUG org.openecard.gui.swing.StepFrame:257 - Trying to kill background task if it exists.
 -01-25 10:00:16,083 [AWT-EventQueue-1] DEBUG org.openecard.gui.swing.StepFrame:260 - Killing background task.
 -01-25 10:00:16,083 [Swing-GUI-BG-Task] DEBUG o.o.s.protocol.eac.gui.CardMonitor:76 - Card has not been removed.
 -01-25 10:00:16,083 [AWT-EventQueue-1] DEBUG org.openecard.gui.swing.StepFrame:222 - Exchange result for step 'Anbieter'.
 -01-25 10:00:16,084 [Swing-GUI-BG-Task] DEBUG org.openecard.gui.swing.StepFrame$1:276 - Background task has been terminated from the Swing GUI.
       java.lang.InterruptedException: null
       	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039)
       	at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
       	at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
       	at org.openecard.common.util.Promise.deref(Promise.java:145)
       	at org.openecard.common.util.Promise.deref(Promise.java:125)
       	at org.openecard.sal.protocol.eac.gui.CardMonitor.call(CardMonitor.java:66)
       	at org.openecard.sal.protocol.eac.gui.CardMonitor.call(CardMonitor.java:47)
       	at org.openecard.gui.swing.StepFrame$1.run(StepFrame.java:272)
       	at java.lang.Thread.run(Thread.java:748)
 -01-25 10:00:16,099 [EAC-GUI] DEBUG org.openecard.gui.swing.StepBar:97 - Selecting index 1, previous was 0.
 -01-25 10:00:16,181 [Swing-GUI-BG-Task] DEBUG o.o.s.protocol.eac.gui.CardMonitor:65 - Waiting for card to be removed.
 -01-25 10:00:18,997 [AWT-EventQueue-1] DEBUG o.o.gui.swing.SwingNavigator:244 - Received event: Button.next
 -01-25 10:00:19,001 [AWT-EventQueue-1] DEBUG org.openecard.gui.swing.StepFrame:257 - Trying to kill background task if it exists.
 -01-25 10:00:19,001 [AWT-EventQueue-1] DEBUG org.openecard.gui.swing.StepFrame:260 - Killing background task.
 -01-25 10:00:19,002 [Swing-GUI-BG-Task] DEBUG o.o.s.protocol.eac.gui.CardMonitor:76 - Card has not been removed.
 -01-25 10:00:19,003 [Swing-GUI-BG-Task] DEBUG org.openecard.gui.swing.StepFrame$1:276 - Background task has been terminated from the Swing GUI.
       java.lang.InterruptedException: null
       	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039)
       	at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
       	at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
       	at org.openecard.common.util.Promise.deref(Promise.java:145)
       	at org.openecard.common.util.Promise.deref(Promise.java:125)
       	at org.openecard.sal.protocol.eac.gui.CardMonitor.call(CardMonitor.java:66)
       	at org.openecard.sal.protocol.eac.gui.CardMonitor.call(CardMonitor.java:47)
       	at org.openecard.gui.swing.StepFrame$1.run(StepFrame.java:272)
       	at java.lang.Thread.run(Thread.java:748)
 -01-25 10:00:19,003 [AWT-EventQueue-1] DEBUG org.openecard.gui.swing.StepFrame:222 - Exchange result for step 'Angefragte Daten'.
 -01-25 10:00:19,023 [EAC-GUI] DEBUG org.openecard.gui.swing.StepBar:97 - Selecting index 2, previous was 1.
 -01-25 10:00:19,079 [Swing-GUI-BG-Task] DEBUG o.o.s.protocol.eac.gui.CardMonitor:65 - Waiting for card to be removed.
 -01-25 10:00:19,096 [Instant-Return-Thread-2] DEBUG o.o.gui.swing.SwingNavigator:244 - Received event: Button.next
 -01-25 10:00:19,097 [Instant-Return-Thread-2] DEBUG org.openecard.gui.swing.StepFrame:257 - Trying to kill background task if it exists.
 -01-25 10:00:19,098 [Instant-Return-Thread-2] DEBUG org.openecard.gui.swing.StepFrame:260 - Killing background task.
 -01-25 10:00:19,098 [Swing-GUI-BG-Task] DEBUG o.o.s.protocol.eac.gui.CardMonitor:76 - Card has not been removed.
 -01-25 10:00:19,098 [Swing-GUI-BG-Task] DEBUG org.openecard.gui.swing.StepFrame$1:276 - Background task has been terminated from the Swing GUI.
       java.lang.InterruptedException: null
       	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039)
       	at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
       	at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
       	at org.openecard.common.util.Promise.deref(Promise.java:145)
       	at org.openecard.common.util.Promise.deref(Promise.java:125)
       	at org.openecard.sal.protocol.eac.gui.CardMonitor.call(CardMonitor.java:66)
       	at org.openecard.sal.protocol.eac.gui.CardMonitor.call(CardMonitor.java:47)
       	at org.openecard.gui.swing.StepFrame$1.run(StepFrame.java:272)
       	at java.lang.Thread.run(Thread.java:748)
 -01-25 10:00:19,101 [Instant-Return-Thread-2] DEBUG org.openecard.gui.swing.StepFrame:222 - Exchange result for step 'PIN-Eingabe'.
 -01-25 10:00:19,132 [pool-6-thread-1] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type EstablishChannel.
 -01-25 10:00:19,164 [pool-6-thread-1] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:19,171 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:19,172 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:19,173 [pool-6-thread-1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:19,173 [pool-6-thread-1] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.EstablishChannel
 -01-25 10:00:19,203 [pool-6-thread-1] DEBUG org.openecard.ifd.scio.IFD:1067 - executeCtrlCode request: 02180303157F4C12060904007F0007030102025305000100990400FE02308202FA060A04007F00070301030101A10E0C0C442D547275737420476D6248A2181316687474703A2F2F7777772E642D74727573742E6E6574A3470C45454C53544552202D204672656973746161742042617965726E2C2076657274722E2064757263682042617953744D462C2076657274722E206475726368204261794C665374A417131568747470733A2F2F7777772E656C737465722E6465A58201F40C8201F04E616D652C20416E7363687269667420756E6420452D4D61696C2D4164726573736520646573200D0A4469656E737465616E626965746572733A0D0A454C53544552202D204672656973746161742042617965726E2C0D0A76657274722E2064757263682042617953744D462C0D0A76657274722E206475726368204261794C6653740D0A4B6174686172696E612D766F6E2D426F72612D53747261C39F6520360D0A3830333333204DC3BC6E6368656E0D0A686F746C696E6540656C737465722E64650D0A0D0A4765736368C3A46674737A7765636B3A0D0A0D0A48696E7765697320617566206469652066C3BC722064656E204469656E737465616E626965746572200D0A7A757374C3A46E646967656E205374656C6C656E2C20646965206469652045696E68616C74756E67200D0A64657220566F7273636872696674656E207A756D20446174656E73636875747A200D0A6B6F6E74726F6C6C696572656E3A0D0A4465722042617965726973636865204C616E64657362656175667472616774652066C3BC722064656E20446174656E73636875747A0D0A5761676DC3BC6C6C657273747261C39F652031380D0A3830353338204DC3BC6E6368656E0D0A303839203231323637322D300D0A706F73747374656C6C6540646174656E73636875747A2D62617965726E2E6465A76831660420375B6E3CC271940553C199386E13A6EAB00C086AE3BCE1A67E8A1E83118733C004209C7575D778FB0DBA0687864A93F85B1BEE48D20A72E4B8AB8D19610AAB34A1500420FB9A1575BD0CE4E986F7F42A2234CE40617757135CCEF19C62519A764790CFEA
 -01-25 10:00:39,167 [SCIO Watcher 0] DEBUG o.o.scio.PCSCTerminals$PCSCWatcher:404 - No service available exception, reloading PCSC.
 -01-25 10:00:39,186 [pool-6-thread-1] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:39,187 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:39,187 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:39,187 [pool-6-thread-1] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:39,190 [pool-6-thread-1] ERROR o.o.s.p.eac.gui.PINStepAction:223 - An unknown error occured while trying to verify the PIN.
 -01-25 10:00:39,211 [EAC-GUI] DEBUG org.openecard.gui.swing.StepBar:97 - Selecting index 2, previous was 2.
 -01-25 10:00:39,217 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:122 - Sending API_CALL_FINISHED event.
 -01-25 10:00:39,218 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_FINISHED into event queue.
 -01-25 10:00:39,219 [PAOS] DEBUG o.o.transport.httpcore.HttpUtils:81 - HTTP Request (before adding content):
         POST /ecardpaos/paosreceiver HTTP/1.1
         Connection: keep-alive
         User-Agent: Open eCard App/org.openecard.common.SemanticVersion@e580929
         Host: eidpaos.elsteronline.de
         PAOS: ver="urn:liberty:paos:2006-08" ;"urn:iso:std:iso-iec:24727:tech:schema:Transmit";"http://www.bsi.bund.de/ecard/api/1.0#InitializeFramework";"urn:iso:std:iso-iec:24727:tech:schema:StartSession";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationEndSession";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationList";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationServiceList";"urn:iso:std:iso-iec:24727:tech:schema:CardApplicationServiceDescribe";"urn:iso:std:iso-iec:24727:tech:schema:DataSetList";"urn:iso:std:iso-iec:24727:tech:schema:DataSetSelect";"urn:iso:std:iso-iec:24727:tech:schema:DSIList";"urn:iso:std:iso-iec:24727:tech:schema:DSIWrite";"urn:iso:std:iso-iec:24727:tech:schema:DSIRead";"urn:iso:std:iso-iec:24727:tech:schema:Encipher";"urn:iso:std:iso-iec:24727:tech:schema:Decipher";"urn:iso:std:iso-iec:24727:tech:schema:GetRandom";"urn:iso:std:iso-iec:24727:tech:schema:Sign";"urn:iso:std:iso-iec:24727:tech:schema:VerifySignature";"urn:iso:std:iso-iec:24727:tech:schema:VerifyCertificate";"urn:iso:std:iso-iec:24727:tech:schema:DIDList";"urn:iso:std:iso-iec:24727:tech:schema:DIDGet";"urn:iso:std:iso-iec:24727:tech:schema:DIDAuthenticate";"urn:iso:std:iso-iec:24727:tech:schema:ACLList";"urn:iso:std:iso-iec:24727:tech:schema:Hash"
         Accept: text/xml, application/xml, application/vnd.paos+xml
 -01-25 10:00:39,221 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:39,223 [Dispatcher Event 0] DEBUG o.o.s.p.eac.gui.CardRemovedFilter:54 - Received event.
 -01-25 10:00:39,224 [PAOS] DEBUG org.openecard.transport.paos.PAOS:234 - Message sent:
       <?xml version="1.0" encoding="UTF-8" standalone="no"?>
       <Envelope xmlns="http://schemas.xmlsoap.org/soap/envelope/">
         <Header>
           <PAOS xmlns:ns0="http://schemas.xmlsoap.org/soap/envelope/" ns0:actor="http://schemas.xmlsoap.org/soap/actor/next" xmlns:ns1="http://schemas.xmlsoap.org/soap/envelope/" ns1:mustUnderstand="1" xmlns="urn:liberty:paos:2006-08">
             <Version>urn:liberty:paos:2006-08</Version>
             <EndpointReference>
               <Address>http://www.projectliberty.org/2006/01/role/paos</Address>
               <MetaData>
                 <ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</ServiceType>
               </MetaData>
             </EndpointReference>
           </PAOS>
           <ReplyTo xmlns="http://www.w3.org/2005/03/addressing">
             <Address>http://www.projectliberty.org/2006/02/role/paos</Address>
           </ReplyTo>
           <RelatesTo xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:24072141-9029-4b8b-b89f-a5ef9da7c393</RelatesTo>
           <MessageID xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:00634a2e-d24e-4d49-9fdb-dc80972f7b13</MessageID>
         </Header>
         <Body>
           <iso:DIDAuthenticateResponse xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:ns10="urn:oasis:names:tc:SAML:1.0:assertion" xmlns:ns11="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns12="http://www.w3.org/2001/04/xmlenc#" xmlns:ns13="http://ws.openecard.org/schema" xmlns:ns14="http://www.w3.org/2001/04/xmldsig-more#" xmlns:ns15="http://www.w3.org/2007/05/xmldsig-more#" xmlns:ns2="urn:oasis:names:tc:dss:1.0:core:schema" xmlns:ns3="http://www.w3.org/2000/09/xmldsig#" xmlns:ns4="http://www.bsi.bund.de/ecard/api/1.1" xmlns:ns5="http://uri.etsi.org/02231/v3.1.2#" xmlns:ns6="http://www.w3.org/2009/xmlenc11#" xmlns:ns7="http://www.setcce.org/schemas/ers" xmlns:ns8="urn:oasis:names:tc:dss-x:1.0:profiles:verificationreport:schema#" xmlns:ns9="http://uri.etsi.org/01903/v1.3.2#">
             <ns2:Result>
               <ns2:ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#error</ns2:ResultMajor>
               <ns2:ResultMinor>http://www.bsi.bund.de/ecard/api/1.1/resultminor/al/common#unknownError</ns2:ResultMinor>
               <ns2:ResultMessage xml:lang="en">Failed to transmit control command to the terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00'.</ns2:ResultMessage>
             </ns2:Result>
           </iso:DIDAuthenticateResponse>
         </Body>
       </Envelope>
 -01-25 10:00:39,224 [PAOS] DEBUG org.openecard.transport.paos.PAOS:318 - Sending HTTP request.
 -01-25 10:00:39,258 [Instant-Return-Thread-3] DEBUG o.o.gui.swing.SwingNavigator:244 - Received event: Button.next
 -01-25 10:00:39,262 [Instant-Return-Thread-3] DEBUG org.openecard.gui.swing.StepFrame:257 - Trying to kill background task if it exists.
 -01-25 10:00:39,263 [Instant-Return-Thread-3] DEBUG org.openecard.gui.swing.StepFrame:222 - Exchange result for step 'Fehler'.
 -01-25 10:00:39,280 [EAC-GUI] INFO  o.o.gui.executor.ExecutionEngine:180 - StepAction was canceled.
 -01-25 10:00:39,471 [PAOS] DEBUG org.openecard.transport.paos.PAOS:320 - HTTP response received.
 -01-25 10:00:39,471 [PAOS] WARN  org.openecard.transport.paos.PAOS:424 - The PAOS endpoint sent the http status code 200 which does not conform to the PAOS specification. (See section 9.4 Processing Rules of the PAOS Specification)
 -01-25 10:00:39,472 [PAOS] DEBUG o.o.transport.httpcore.HttpUtils:112 - HTTP Response:
         HTTP/1.1 200 OK
         Server: Apache-Coyote/1.1
         Content-Security-Policy: default-src 'self'
         Content-Type: application/vnd.paos+xml
         Content-Length: 1195
         Date: Thu, 25 Jan 2018 09:00:39 GMT
       <?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
          <soap:Header>
             <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id33900" refToMessageID="d9904910-9752-4365-8ad0-0140eea2b460"/>
             <RelatesTo xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:00634a2e-d24e-4d49-9fdb-dc80972f7b13</RelatesTo>
             <MessageID xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:169b6161-e39d-458c-9182-65d81363adf1</MessageID>
          </soap:Header>
          <soap:Body>
          <ns4:StartPAOSResponse xmlns:ns4="urn:iso:std:iso-iec:24727:tech:schema" xmlns:ns2="urn:oasis:names:tc:dss:1.0:core:schema" xmlns:ns3="http://www.w3.org/2000/09/xmldsig#">
             <ns2:Result>
               <ns2:ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#error</ns2:ResultMajor>
               <ns2:ResultMinor>http://www.bsi.bund.de/ecard/api/1.1/resultminor/al/common#unknownError</ns2:ResultMinor>
               <ns2:ResultMessage xml:lang="en">Failed to transmit control command to the terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00'.</ns2:ResultMessage>
             </ns2:Result>
           </ns4:StartPAOSResponse>
         </soap:Body>
       </soap:Envelope>
 -01-25 10:00:39,475 [PAOS] DEBUG org.openecard.transport.paos.PAOS:209 - Message received:
       <?xml version="1.0" encoding="UTF-8" standalone="no"?>
       <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
         <soap:Header>
           <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id33900" refToMessageID="d9904910-9752-4365-8ad0-0140eea2b460"/>
           <RelatesTo xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:00634a2e-d24e-4d49-9fdb-dc80972f7b13</RelatesTo>
           <MessageID xmlns="http://www.w3.org/2005/03/addressing">urn:uuid:169b6161-e39d-458c-9182-65d81363adf1</MessageID>
         </soap:Header>
         <soap:Body>
           <ns4:StartPAOSResponse xmlns:ns2="urn:oasis:names:tc:dss:1.0:core:schema" xmlns:ns3="http://www.w3.org/2000/09/xmldsig#" xmlns:ns4="urn:iso:std:iso-iec:24727:tech:schema">
             <ns2:Result>
               <ns2:ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#error</ns2:ResultMajor>
               <ns2:ResultMinor>http://www.bsi.bund.de/ecard/api/1.1/resultminor/al/common#unknownError</ns2:ResultMinor>
               <ns2:ResultMessage xml:lang="en">Failed to transmit control command to the terminal 'REINER SCT cyberJack RFID standard (0810057893) 00 00'.</ns2:ResultMessage>
             </ns2:Result>
           </ns4:StartPAOSResponse>
         </soap:Body>
       </soap:Envelope>
 -01-25 10:00:39,478 [PAOS] INFO  o.o.c.tls.ClientCertPSKTlsClient:262 - TLS warning sent.
 -01-25 10:00:39,479 [PAOS] INFO  o.o.c.tls.ClientCertPSKTlsClient:264 - TLS(WARN): Close [close_notify=0] --> Connection closed
 -01-25 10:00:39,480 [PAOS] DEBUG o.o.common.util.HandlerUtils:124 - Found ConnectionHandle in object of type CardApplicationDisconnect.
 -01-25 10:00:39,483 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:39,483 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:39,483 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.CardApplicationDisconnect
 -01-25 10:00:39,484 [PAOS] DEBUG o.o.common.util.HandlerUtils:144 - Found SlotHandle in object of type Disconnect.
 -01-25 10:00:39,487 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:105 - Sending API_CALL_STARTED event.
 -01-25 10:00:39,488 [PAOS] DEBUG o.o.c.event.EventDispatcherImpl:124 - Added event API_CALL_STARTED into event queue.
 -01-25 10:00:39,488 [PAOS] DEBUG o.o.t.dispatcher.MessageDispatcher:114 - Delivering message of type: iso.std.iso_iec._24727.tech.schema.Disconnect
 -01-25 10:02:50,216 [AWT-EventQueue-1] DEBUG o.openecard.richclient.gui.Status$1:165 - Shutdown button pressed.

(1-1/1)

Project

General

Profile

Open eCard

RE: Authentication error when using eID » richclient_info.log-20180125-error-Failed_to_transmit_control_command_to_the_terminal_REINER_SCT_cyberJack_RFID_standard.txt