Project

General

Profile

Bug #363 » bug-unknown-namespace-ausweisapp2.txt

Logfile mit AusweisApp2 erzeugt - Detlef Hühnlein, 11/21/2014 12:11 PM

 
1
2014.11.21 11:41:29.683 D EnumAction::Action](core/controller/AppController.cpp:402)                 : Start governikus::AuthController
2
2014.11.21 11:41:29.714 D StateMachine::start(core/StateMachine.cpp:45)                              : Start state machine
3
2014.11.21 11:41:29.714 D StateMachine::start(core/StateMachine.cpp:55)                              : State machine started
4
2014.11.21 11:41:29.714 D StateMachine::start(core/StateMachine.cpp:58)                              : Invoke StateMachine:  true
5
2014.11.21 11:41:29.714 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepEmpty" | StepResult: 0
6
2014.11.21 11:41:29.714 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepProcessing"
7
2014.11.21 11:41:29.714 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepProcessing" state 0x4024468
8
2014.11.21 11:41:29.714 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
9
2014.11.21 11:41:29.714 D StateMachine::initStepUi(core/StateMachine.cpp:216)                        : step declares UI "governikus::StepProcessingUi"  (previous:   ); creating new one
10
2014.11.21 11:41:29.714 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepProcessing"
11
2014.11.21 11:41:29.714 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepProcessing"
12
2014.11.21 11:41:29.714 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepProcessing"
13
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepProcessing"
14
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepProcessing"
15
2014.11.21 11:41:29.730 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepProcessing" | StepResult: 0
16
2014.11.21 11:41:29.730 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepParseTcTokenUrl"
17
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepParseTcTokenUrl" state 0x4024488
18
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
19
2014.11.21 11:41:29.730 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
20
2014.11.21 11:41:29.730 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepParseTcTokenUrl"
21
2014.11.21 11:41:29.730 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepParseTcTokenUrl"
22
2014.11.21 11:41:29.730 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepProcessing"
23
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepParseTcTokenUrl"
24
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepParseTcTokenUrl"
25
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepParseTcTokenUrl"
26
2014.11.21 11:41:29.730 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepParseTcTokenUrl" | StepResult: 0
27
2014.11.21 11:41:29.730 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepGetTcToken"
28
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepGetTcToken" state 0x4024808
29
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
30
2014.11.21 11:41:29.730 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
31
2014.11.21 11:41:29.730 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepGetTcToken"
32
2014.11.21 11:41:29.730 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepGetTcToken"
33
2014.11.21 11:41:29.730 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepParseTcTokenUrl"
34
2014.11.21 11:41:29.730 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepGetTcToken"
35
2014.11.21 11:41:29.730 D StepGetTcToken::run(core/step/StepGetTcToken.cpp:45)                       : Got TC Token URL:  QUrl( "https://www.sixform.com/ID-Safe/poll/login" ) 
36
2014.11.21 11:41:30.167 D StepGetTcToken::onNetworkReply(core/step/StepGetTcToken.cpp:99)            : Got TCToken reply QSslCipher(name= DHE-RSA-AES256-GCM-SHA384 , bits= 256 , proto= TLSv1.2 )
37
2014.11.21 11:41:30.167 D StepGetTcToken::onNetworkReply(core/step/StepGetTcToken.cpp:100)           : Status Code:  200  | RedirectUrl:   QUrl( "" ) 
38
2014.11.21 11:41:30.182 D AuthModel::addCertificateData(core/model/AuthModel.h:123)                  : Adding certificate CN= ("www.sixform.com") SN= "2e:7d:6e:67:26:d7:be:84"
39
2014.11.21 11:41:30.182 D TcToken::parse(core/TcToken.cpp:37)                                        : Parsing TcToken:
40
2014.11.21 11:41:30.182 D TcToken::parse(core/TcToken.cpp:38)                                        : "<TCTokenType><ServerAddress>https://prodpaos.governikus-eid.de:443/ecardpaos/paosreceiver</ServerAddress><SessionIdentifier>f8241bf1-7858-43f9-ab54-a94187522256</SessionIdentifier><RefreshAddress>https://www.sixform.com:443/ID-Safe/success/login?refID=17019c67-0479-41a8-87b0-2a77166fe2d6</RefreshAddress><Binding>urn:liberty:paos:2006-08</Binding><PathSecurity-Protocol>urn:ietf:rfc:4279</PathSecurity-Protocol><PathSecurity-Parameters><PSK>2135224FD60CE2106E71CCF15418850BFDD8865BC4F4FBD276CFE28D2B33DF7FC21CEE8E0286F4715FE372952F793A0EBFF9F769A43066A52FDA7630C2834E92</PSK></PathSecurity-Parameters></TCTokenType>"
41
2014.11.21 11:41:30.182 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepGetTcToken"
42
2014.11.21 11:41:30.182 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepGetTcToken"
43
2014.11.21 11:41:30.182 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepGetTcToken" | StepResult: 0
44
2014.11.21 11:41:30.182 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepChooseCard"
45
2014.11.21 11:41:30.182 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepChooseCard" state 0x4023268
46
2014.11.21 11:41:30.182 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
47
2014.11.21 11:41:30.182 D StateMachine::initStepUi(core/StateMachine.cpp:216)                        : step declares UI "governikus::StepChooseCardUi"  (previous:  governikus::StepProcessingGui ); creating new one
48
2014.11.21 11:41:30.182 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepChooseCard"
49
2014.11.21 11:41:30.182 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepChooseCard"
50
2014.11.21 11:41:30.182 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepGetTcToken"
51
2014.11.21 11:41:30.182 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepChooseCard"
52
2014.11.21 11:41:30.182 D StepChooseCardGui::onErrorMessage(gui/step/StepChooseCardGui.cpp:84)       : ""
53
2014.11.21 11:41:30.182 D StepChooseCardGui::onErrorMessage(gui/step/StepChooseCardGui.cpp:85)       : ""
54
2014.11.21 11:41:30.182 D StepChooseCardGui::onErrorMessage(gui/step/StepChooseCardGui.cpp:86)       : true
55
2014.11.21 11:41:30.198 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepChooseCard"
56
2014.11.21 11:41:30.198 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepChooseCard"
57
2014.11.21 11:41:30.198 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepChooseCard" | StepResult: 0
58
2014.11.21 11:41:30.198 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSetReader"
59
2014.11.21 11:41:30.198 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSetReader" state 0x4023258
60
2014.11.21 11:41:30.198 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
61
2014.11.21 11:41:30.198 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
62
2014.11.21 11:41:30.198 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSetReader"
63
2014.11.21 11:41:30.198 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSetReader"
64
2014.11.21 11:41:30.198 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepChooseCard"
65
2014.11.21 11:41:30.198 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSetReader"
66
2014.11.21 11:41:30.198 D Reader::createCardController(card/base/Reader.cpp:47)                      : Connect to card in reader  "REINER SCT cyberJack RFID basis 0"
67
2014.11.21 11:41:30.213 D PcscCard::connectCard(card/pcsc/PcscCard.cpp:123)                          : "SCardConnect(cd010003, R, 2, 3, 0, 0)"
68
2014.11.21 11:41:30.291 D PcscCard::connectCard(card/pcsc/PcscCard.cpp:131)                          : SCardConnect for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"  cardHandle:  3926261760  protocol: T 1
69
2014.11.21 11:41:30.291 D PcscCard::connectCard(card/pcsc/PcscCard.cpp:138)                          : SCardBeginTransaction for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
70
2014.11.21 11:41:30.291 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSetReader"
71
2014.11.21 11:41:30.291 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSetReader"
72
2014.11.21 11:41:30.291 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSetReader" | StepResult: 0
73
2014.11.21 11:41:30.291 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepGetRetryCounter"
74
2014.11.21 11:41:30.291 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepGetRetryCounter" state 0x4024708
75
2014.11.21 11:41:30.291 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
76
2014.11.21 11:41:30.291 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
77
2014.11.21 11:41:30.291 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepGetRetryCounter"
78
2014.11.21 11:41:30.291 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepGetRetryCounter"
79
2014.11.21 11:41:30.291 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSetReader"
80
2014.11.21 11:41:30.291 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepGetRetryCounter"
81
2014.11.21 11:41:30.291 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "00a4020c02011c"
82
2014.11.21 11:41:30.323 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
83
2014.11.21 11:41:30.323 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
84
2014.11.21 11:41:30.323 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0022c1a412800a04007f0007020204020283010384010d"
85
2014.11.21 11:41:30.369 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
86
2014.11.21 11:41:30.369 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
87
2014.11.21 11:41:30.369 D CardController::getRetryCounter(card/base/CardController.cpp:154)          : StatusCode:  "SUCCESS"
88
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepGetRetryCounter"
89
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepGetRetryCounter"
90
2014.11.21 11:41:30.369 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepGetRetryCounter" | StepResult: 0
91
2014.11.21 11:41:30.369 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepStartPaos"
92
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepStartPaos" state 0x4024218
93
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
94
2014.11.21 11:41:30.369 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
95
2014.11.21 11:41:30.369 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepStartPaos"
96
2014.11.21 11:41:30.369 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepStartPaos"
97
2014.11.21 11:41:30.369 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepGetRetryCounter"
98
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepStartPaos"
99
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepStartPaos"
100
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepStartPaos"
101
2014.11.21 11:41:30.369 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepStartPaos" | StepResult: 0
102
2014.11.21 11:41:30.369 D PcscReader::update(card/pcsc/PcscReader.cpp:271)                           : 
103
  old state:  "(0x90422) CHANGED PRESENT UNPOWERED" 
104
  new state:  "(0x90122) CHANGED PRESENT INUSE"
105
2014.11.21 11:41:30.369 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendStartPaos"
106
2014.11.21 11:41:30.369 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
107
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendStartPaos" state 0x40246a8
108
2014.11.21 11:41:30.369 D PcscReader::update(card/pcsc/PcscReader.cpp:338)                           : fireCardAccessRightsChanged
109
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
110
2014.11.21 11:41:30.369 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
111
2014.11.21 11:41:30.369 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendStartPaos"
112
2014.11.21 11:41:30.369 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendStartPaos"
113
2014.11.21 11:41:30.369 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepStartPaos"
114
2014.11.21 11:41:30.369 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendStartPaos"
115
2014.11.21 11:41:30.385 D GnuTls::initPskCredentials(core/network/GnuTls.cpp:494)                    : Init psk credentials
116
2014.11.21 11:41:30.385 D GnuTls::initCredentials(core/network/GnuTls.cpp:478)                       : Init certificate credentials
117
2014.11.21 11:41:30.385 D ...ricSendReceive::connectToHost(core/step/StepGenericSendReceive.cpp:131) : Connect to server
118
2014.11.21 11:41:30.385 D GnuTls::initSession(core/network/GnuTls.cpp:523)                           : Init session
119
2014.11.21 11:41:30.385 D GnuTls::initSession(core/network/GnuTls.cpp:534)                           : Set psk credential
120
2014.11.21 11:41:30.385 D GnuTls::initSession(core/network/GnuTls.cpp:548)                           : Set certificate credential
121
2014.11.21 11:41:30.385 D GnuTls::initSession(core/network/GnuTls.cpp:556)                           : Set cipher priority
122
2014.11.21 11:41:30.385 D GnuTls::connectToHost(core/network/GnuTls.cpp:612)                         : Connecting | Host: "prodpaos.governikus-eid.de"  | Port: 443
123
2014.11.21 11:41:30.385 D GnuTls::doStateChanged(core/network/GnuTls.cpp:790)                        : State: QAbstractSocket::HostLookupState
124
2014.11.21 11:41:30.385 D GnuTls::doStateChanged(core/network/GnuTls.cpp:790)                        : State: QAbstractSocket::ConnectingState
125
2014.11.21 11:41:30.432 D GnuTls::doStateChanged(core/network/GnuTls.cpp:790)                        : State: QAbstractSocket::ConnectedState
126
2014.11.21 11:41:30.432 D GnuTls::startTls(core/network/GnuTls.cpp:705)                              : Start Handshake
127
2014.11.21 11:41:30.619 D GnuTls::onHandshakeDone(core/network/GnuTls.cpp:989)                       : Handshake complete | "RSA-PSK / AES-256-CBC / SHA1 / NULL / X.509"
128
2014.11.21 11:41:30.619 D GnuTls::checkAndEnableHeartbeat(core/network/GnuTls.cpp:746)               : GNUTLS_HB_PEER_ALLOWED_TO_SEND: 0
129
2014.11.21 11:41:30.619 D GnuTls::checkAndEnableHeartbeat(core/network/GnuTls.cpp:747)               : GNUTLS_HB_LOCAL_ALLOWED_TO_SEND: 0
130
2014.11.21 11:41:30.619 D GnuTls::onHandshakeDone(core/network/GnuTls.cpp:997)                       : QSslCertificate( "3" , "50:34:6c:46:ac:eb:df:b1" , "EBIRnP3mSM6hbtckyiehcQ==" , ("T-Systems International GmbH") , ("bremen online services GmbH & Co. KG") , QMap((1, "prodpaos.governikus-eid.de")) , QDateTime("2014-02-07 09:48:16.000 UTC Qt::UTC") , QDateTime("2017-02-12 23:59:59.000 UTC Qt::UTC") )
131
2014.11.21 11:41:30.635 D GnuTls::onHandshakeDone(core/network/GnuTls.cpp:997)                       : QSslCertificate( "3" , "07:27:42:c2" , "5CeTDX4Aj9fJZGlbt60vkw==" , ("Baltimore") , ("T-Systems International GmbH") , QMap() , QDateTime("2010-11-30 16:24:37.000 UTC Qt::UTC") , QDateTime("2017-11-30 16:23:46.000 UTC Qt::UTC") )
132
2014.11.21 11:41:30.635 D GnuTls::onHandshakeDone(core/network/GnuTls.cpp:997)                       : QSslCertificate( "3" , "02:00:00:b9" , "rLaUpZwX4NeRUpuxlwam5A==" , ("Baltimore") , ("Baltimore") , QMap() , QDateTime("2000-05-12 18:46:00.000 UTC Qt::UTC") , QDateTime("2025-05-12 23:59:00.000 UTC Qt::UTC") )
133
2014.11.21 11:41:30.635 D AuthModel::addCertificateData(core/model/AuthModel.h:123)                  : Adding certificate CN= ("prodpaos.governikus-eid.de") SN= "50:34:6c:46:ac:eb:df:b1"
134
2014.11.21 11:41:30.635 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
135
 "POST /ecardpaos/paosreceiver HTTP/1.1
136
Host: prodpaos.governikus-eid.de
137
User-Agent: AusweisApp2/1.0.0
138
Connection: keep-alive
139
Accept: text/html; application/vnd.paos+xml
140
PAOS: ver="urn:liberty:paos:2006-08"
141
Content-Type: application/vnd.paos+xml; charset=UTF-8
142
Content-Length: 1953
143
requestid: f8241bf1-7858-43f9-ab54-a94187522256
144

    
145
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
146
 <soap:Header>
147
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
148
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
149
   <paos:EndpointReference>
150
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
151
    <paos:MetaData>
152
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
153
    </paos:MetaData>
154
   </paos:EndpointReference>
155
  </paos:PAOS>
156
  <wsa:ReplyTo>
157
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
158
  </wsa:ReplyTo>
159
  <wsa:MessageID>urn:uuid:1067f38a-1ce4-4a2b-aa14-6921f06849a1</wsa:MessageID>
160
 </soap:Header>
161
 <soap:Body>
162
  <StartPAOS xmlns="urn:iso:std:iso-iec:24727:tech:schema">
163
   <SessionIdentifier>f8241bf1-7858-43f9-ab54-a94187522256</SessionIdentifier>
164
   <ConnectionHandle xsi:type="ConnectionHandle" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
165
    <ContextHandle>cd010003</ContextHandle>
166
    <IFDName>REINER SCT cyberJack RFID basis 0</IFDName>
167
    <SlotIndex>0</SlotIndex>
168
    <CardApplication>e80704007f00070302</CardApplication>
169
    <SlotHandle>33393236323631373630</SlotHandle>
170
    <RecognitionInfo/>
171
   </ConnectionHandle>
172
   <UserAgent>
173
    <Name>AusweisApp2</Name>
174
    <VersionMajor>1</VersionMajor>
175
    <VersionMinor>0</VersionMinor>
176
    <VersionSubminor>0</VersionSubminor>
177
   </UserAgent>
178
   <SupportedAPIVersions>
179
    <Major>1</Major>
180
    <Minor>1</Minor>
181
    <Subminor>4</Subminor>
182
   </SupportedAPIVersions>
183
  </StartPAOS>
184
 </soap:Body>
185
</soap:Envelope>
186
"
187
2014.11.21 11:41:30.635 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
188
2014.11.21 11:41:30.635 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
189
2014.11.21 11:41:30.681 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
190
2014.11.21 11:41:30.681 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 620
191
2014.11.21 11:41:30.681 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
192
2014.11.21 11:41:30.681 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "625"  bytes)
193
2014.11.21 11:41:30.681 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
194
2014.11.21 11:41:30.681 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
195
2014.11.21 11:41:30.681 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
196
2014.11.21 11:41:30.681 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
197
2014.11.21 11:41:30.681 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
198
2014.11.21 11:41:30.681 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
199
2014.11.21 11:41:30.681 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
200
   <soap:Header>
201
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id3995" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
202
   </soap:Header>
203
   <soap:Body>
204
   <InitializeFramework xmlns="http://www.bsi.bund.de/ecard/api/1.1"/>
205
</soap:Body>
206
</soap:Envelope>
207
"
208
2014.11.21 11:41:30.681 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
209
2014.11.21 11:41:30.681 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "INITIALIZE_FRAMEWORK"
210
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendStartPaos"
211
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendStartPaos"
212
2014.11.21 11:41:30.681 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendStartPaos" | StepResult: 0
213
2014.11.21 11:41:30.681 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepInitializeFramework"
214
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepInitializeFramework" state 0x4023ff8
215
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
216
2014.11.21 11:41:30.681 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
217
2014.11.21 11:41:30.681 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepInitializeFramework"
218
2014.11.21 11:41:30.681 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepInitializeFramework"
219
2014.11.21 11:41:30.681 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendStartPaos"
220
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepInitializeFramework"
221
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepInitializeFramework"
222
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepInitializeFramework"
223
2014.11.21 11:41:30.681 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepInitializeFramework" | StepResult: 0
224
2014.11.21 11:41:30.681 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendInitializeFrameworkResponse"
225
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendInitializeFrameworkResponse" state 0x40242e8
226
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
227
2014.11.21 11:41:30.681 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
228
2014.11.21 11:41:30.681 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendInitializeFrameworkResponse"
229
2014.11.21 11:41:30.681 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendInitializeFrameworkResponse"
230
2014.11.21 11:41:30.681 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepInitializeFramework"
231
2014.11.21 11:41:30.681 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendInitializeFrameworkResponse"
232
2014.11.21 11:41:30.681 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
233
 "POST /ecardpaos/paosreceiver HTTP/1.1
234
Host: prodpaos.governikus-eid.de
235
User-Agent: AusweisApp2/1.0.0
236
Connection: keep-alive
237
Accept: text/html; application/vnd.paos+xml
238
PAOS: ver="urn:liberty:paos:2006-08"
239
Content-Type: application/vnd.paos+xml; charset=UTF-8
240
Content-Length: 1526
241
requestid: f8241bf1-7858-43f9-ab54-a94187522256
242

    
243
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
244
 <soap:Header>
245
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
246
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
247
   <paos:EndpointReference>
248
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
249
    <paos:MetaData>
250
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
251
    </paos:MetaData>
252
   </paos:EndpointReference>
253
  </paos:PAOS>
254
  <wsa:ReplyTo>
255
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
256
  </wsa:ReplyTo>
257
  <wsa:MessageID>urn:uuid:0170a1af-1d89-4f39-b102-6df6f239ad20</wsa:MessageID>
258
 </soap:Header>
259
 <soap:Body>
260
  <InitializeFrameworkResponse Profile="http://www.bsi.bund.de/ecard/api/1.1" xmlns="http://www.bsi.bund.de/ecard/api/1.1">
261
   <Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
262
    <ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
263
   </Result>
264
   <Version>
265
    <Major>1</Major>
266
    <Minor>1</Minor>
267
    <SubMinor>4</SubMinor>
268
   </Version>
269
  </InitializeFrameworkResponse>
270
 </soap:Body>
271
</soap:Envelope>
272
"
273
2014.11.21 11:41:30.681 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
274
2014.11.21 11:41:30.681 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
275
2014.11.21 11:41:30.728 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
276
2014.11.21 11:41:30.728 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 977
277
2014.11.21 11:41:30.728 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "977"  bytes)
278
2014.11.21 11:41:30.728 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
279
2014.11.21 11:41:30.728 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
280
2014.11.21 11:41:30.728 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
281
2014.11.21 11:41:30.728 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
282
2014.11.21 11:41:30.728 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
283
2014.11.21 11:41:30.728 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
284
2014.11.21 11:41:30.728 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
285
   <soap:Header>
286
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id3996" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
287
   </soap:Header>
288
   <soap:Body>
289
   <DIDList xmlns="urn:iso:std:iso-iec:24727:tech:schema">
290
<ConnectionHandle xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="ConnectionHandle">
291
<ContextHandle>CD010003</ContextHandle>
292
<IFDName>REINER SCT cyberJack RFID basis 0</IFDName>
293
<SlotIndex>0</SlotIndex>
294
<CardApplication>E80704007F00070302</CardApplication>
295
<SlotHandle>33393236323631373630</SlotHandle>
296
<RecognitionInfo/>
297
</ConnectionHandle>
298
</DIDList>
299
</soap:Body>
300
</soap:Envelope>
301
"
302
2014.11.21 11:41:30.728 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
303
2014.11.21 11:41:30.728 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
304
2014.11.21 11:41:30.728 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "5"  bytes)
305
2014.11.21 11:41:30.728 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
306
2014.11.21 11:41:30.728 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "DID_LIST"
307
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendInitializeFrameworkResponse"
308
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendInitializeFrameworkResponse"
309
2014.11.21 11:41:30.728 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendInitializeFrameworkResponse" | StepResult: 0
310
2014.11.21 11:41:30.728 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepDidList"
311
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepDidList" state 0x4024758
312
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
313
2014.11.21 11:41:30.728 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
314
2014.11.21 11:41:30.728 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepDidList"
315
2014.11.21 11:41:30.728 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepDidList"
316
2014.11.21 11:41:30.728 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendInitializeFrameworkResponse"
317
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepDidList"
318
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepDidList"
319
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepDidList"
320
2014.11.21 11:41:30.728 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepDidList" | StepResult: 0
321
2014.11.21 11:41:30.728 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendDIDListResponse"
322
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendDIDListResponse" state 0x4024788
323
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
324
2014.11.21 11:41:30.728 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
325
2014.11.21 11:41:30.728 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendDIDListResponse"
326
2014.11.21 11:41:30.728 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendDIDListResponse"
327
2014.11.21 11:41:30.728 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepDidList"
328
2014.11.21 11:41:30.728 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendDIDListResponse"
329
2014.11.21 11:41:30.728 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
330
 "POST /ecardpaos/paosreceiver HTTP/1.1
331
Host: prodpaos.governikus-eid.de
332
User-Agent: AusweisApp2/1.0.0
333
Connection: keep-alive
334
Accept: text/html; application/vnd.paos+xml
335
PAOS: ver="urn:liberty:paos:2006-08"
336
Content-Type: application/vnd.paos+xml; charset=UTF-8
337
Content-Length: 1473
338
requestid: f8241bf1-7858-43f9-ab54-a94187522256
339

    
340
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
341
 <soap:Header>
342
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
343
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
344
   <paos:EndpointReference>
345
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
346
    <paos:MetaData>
347
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
348
    </paos:MetaData>
349
   </paos:EndpointReference>
350
  </paos:PAOS>
351
  <wsa:ReplyTo>
352
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
353
  </wsa:ReplyTo>
354
  <wsa:MessageID>urn:uuid:4d7b7a37-9570-4663-ac7d-7fed6d5b914b</wsa:MessageID>
355
 </soap:Header>
356
 <soap:Body>
357
  <DIDListResponse xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" Profile="http://www.bsi.bund.de/ecard/api/1.1">
358
   <Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
359
    <ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
360
   </Result>
361
   <DIDNameList>
362
    <DIDName>PIN</DIDName>
363
   </DIDNameList>
364
  </DIDListResponse>
365
 </soap:Body>
366
</soap:Envelope>
367
"
368
2014.11.21 11:41:30.728 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
369
2014.11.21 11:41:30.728 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
370
2014.11.21 11:41:30.775 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
371
2014.11.21 11:41:30.775 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
372
2014.11.21 11:41:30.775 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
373
2014.11.21 11:41:30.775 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
374
2014.11.21 11:41:30.775 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5061
375
2014.11.21 11:41:30.775 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
376
2014.11.21 11:41:30.775 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "5066"  bytes)
377
2014.11.21 11:41:30.775 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
378
2014.11.21 11:41:30.775 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
379
2014.11.21 11:41:30.775 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
380
2014.11.21 11:41:30.775 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
381
2014.11.21 11:41:30.775 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
382
2014.11.21 11:41:30.775 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
383
2014.11.21 11:41:30.775 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
384
   <soap:Header>
385
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id3997" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
386
   </soap:Header>
387
   <soap:Body>
388
   <DIDAuthenticate xmlns="urn:iso:std:iso-iec:24727:tech:schema">
389
<ConnectionHandle xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="ConnectionHandle">
390
<ContextHandle>CD010003</ContextHandle>
391
<IFDName>REINER SCT cyberJack RFID basis 0</IFDName>
392
<SlotIndex>0</SlotIndex>
393
<CardApplication>E80704007F00070302</CardApplication>
394
<SlotHandle>33393236323631373630</SlotHandle>
395
<RecognitionInfo/>
396
</ConnectionHandle>
397
<DIDName>PIN</DIDName>
398
<AuthenticationProtocolData Protocol="urn:oid:1.3.162.15480.3.0.14.2" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="EAC1InputType">
399
<Certificate>7F218201487F4E8201005F2901004210444544566549444450535430303033337F494F060A04007F00070202020203864104912C1CC0222118E026B1C50F9C588CBC1ECC99D0BDD9DD6D06B5C9E542CAA3CD5EBC02264531927F04C907454A373F4DAADF2E2E7539D450794D3FEA64B83B535F200E4445534958464F524D30313138337F4C12060904007F00070301020253050001009B045F25060104010102015F2406010401010202655E732D060904007F0007030103018020C46B993867A8276453A27C26B76D132B469BB7022E97F3238B576CAADED678C7732D060904007F000703010302802092BBA4FB9EF41484F429760AD0464B1F61518C7E03C5E04FE91029AC0C9CDA6D5F37405D5BDF959CC81F4C4D1BB8154DF7C08F4F5E94BDFA809DC26000748DDC5FDF6B6603104A269EB508FAE5EDAB7422F7C2BADDD2718A3D2B0E44860DA8C1A99D74</Certificate>
400
<Certificate>7F2181E77F4E81A05F290100420E44454356434165494430303130337F494F060A04007F000702020202038641041F27AD823F8AD678DC9B5B5C11F8FFFAC5C6EFD4517A6A4DC394DE52547FC8BB31BF485816B3B3C157F7500AD60EB7E034A88E164DADB1EE7210284071A456425F2010444544566549444450535430303033337F4C12060904007F0007030102025305400513FF875F25060104010101075F24060105000201055F3740076661078637BBBD2DCDE9260598DFAC72D58D72743DEB2677A99193DE94C3B6907110CF4BFC4D1C5B5DD77B72116D9297C67C351FE78FCC8EE25C1F1C500B95</Certificate>
401
<Certificate>7F218201B67F4E82016E5F290100420E44454356434165494430303130327F4982011D060A04007F000702020202038120A9FB57DBA1EEA9BC3E660A909D838D726E3BF623D52620282013481D1F6E537782207D5A0975FC2C3057EEF67530417AFFE7FB8055C126DC5C6CE94A4B44F330B5D9832026DC5C6CE94A4B44F330B5D9BBD77CBF958416295CF7E1CE6BCCDC18FF8C07B68441048BD2AEB9CB7E57CB2C4B482FFC81B7AFB9DE27E1E3BD23C23A4453BD9ACE3262547EF835C3DAC4FD97F8461A14611DC9C27745132DED8E545C1D54C72F0469978520A9FB57DBA1EEA9BC3E660A909D838D718C397AA3B561A6F7901E0E82974856A78641048925419FC7F194922CFC6B8DD25AE6A19C1B59216E6CF06270E5D75CFD64205F55CF867BBFEFEEFD6E680E1FD197F18AB684484901362568EFC9ADB5C6018D728701015F200E44454356434165494430303130337F4C12060904007F0007030102025305FC0F13FFFF5F25060102010200035F24060105010200035F37404D6F08A86A4F18409F6685387DD3C6A7FF5D68EA4F7714A861BBB3BB721D05D3014ADF1763C9292F715D8E94EE9B3E1B73AB1382414EBF39DFB3B0FB6C09DBEB</Certificate>
402
<CertificateDescription>308202D4060A04007F00070301030101A1270C25446575747363686520506F7374205369676E747275737420756E6420444D444120476D6248A2191317687474703A2F2F7777772E7369676E74727573742E6465A3160C144C616E646B72656973204F7374616C6C67C3A475A419131768747470733A2F2F7777772E736978666F726D2E636F6DA582019D0C820199416E736368726966743A0D0A4C616E646B72656973204F7374616C6C67C3A4750D0A536368776162656E73747261C39F652031310D0A3837363136204D61726B746F626572646F72660D0A0D0A452D4D61696C2D416472657373653A0D0A706F73747374656C6C65406C72612D6F616C2E62617965726E2E64650D0A0D0A5A7765636B20646573204175736C657365766F7267616E67733A0D0A416E6C6567656E20756E64204E75747A756E672065696E65732049442D5361666573207A75722041627769636B6C756E6720766F6E204F6E6C696E652D53657276696365730D0A0D0A5A757374C3A46E6469676520446174656E73636875747A61756673696368743A0D0A526567696572756E6720766F6E204D697474656C6672616E6B656E0D0A506F737466616368203630360D0A393135313120416E73626163680D0A303938312F35332D313330310D0A646174656E73636875747A407265672D6D66722E62617965726E2E64650D0A687474703A2F2F7777772E726567696572756E672E6D697474656C6672616E6B656E2E62617965726E2E64652FA781AD3181AA042029F04459C39E4B68C70AA3961FA7B1B40E8A49238446CFE606C56FF8DC0989F4042063317224E931A55C91406A98A65FBF2D3DE9B3D1B6FED62E80A4049C841731F904209D8EB0BDF36B19C4AF3147E57401FD792845F0413102A7BD784DF9418098BEBE0420DB37C8E02D6D715EFBFB819D9620C0D411BB6D5F8000200148FFCFA3467F71580420EBD2A9610AA53AE1C159B2C7B238451E2C6AF06F7034723BD4B9743196E6A720</CertificateDescription>
403
<RequiredCHAT>7F4C12060904007F00070301020253050000000004</RequiredCHAT>
404
<OptionalCHAT>7F4C12060904007F00070301020253050000000000</OptionalCHAT>
405
<AuthenticatedAuxiliaryData>67177315060904007F00070301040253083230313431313231</AuthenticatedAuxiliaryData>
406
</AuthenticationProtocolData>
407
</DIDAuthenticate>
408
</soap:Body>
409
</soap:Envelope>
410
"
411
2014.11.21 11:41:30.775 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
412
2014.11.21 11:41:30.775 D ...rser::parseMessage(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:40) : "ConnectionHandle"
413
2014.11.21 11:41:30.775 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "ContextHandle"
414
2014.11.21 11:41:30.775 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "IFDName"
415
2014.11.21 11:41:30.775 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "SlotIndex"
416
2014.11.21 11:41:30.775 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "CardApplication"
417
2014.11.21 11:41:30.775 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "SlotHandle"
418
2014.11.21 11:41:30.775 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "RecognitionInfo"
419
2014.11.21 11:41:30.775 D ...rser::parseMessage(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:40) : "DIDName"
420
2014.11.21 11:41:30.775 D ...rser::parseMessage(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:40) : "AuthenticationProtocolData"
421
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "Certificate"
422
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "Certificate"
423
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "Certificate"
424
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "CertificateDescription"
425
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "RequiredCHAT"
426
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "OptionalCHAT"
427
2014.11.21 11:41:30.775 D ...parseEac1InputType(core/paos/retrieve/DidAuthenticateEac1Parser.cpp:83) : "AuthenticatedAuxiliaryData"
428
2014.11.21 11:41:30.775 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "DID_AUTHENTICATE_EAC1"
429
2014.11.21 11:41:30.775 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendDIDListResponse"
430
2014.11.21 11:41:30.775 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendDIDListResponse"
431
2014.11.21 11:41:30.775 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendDIDListResponse" | StepResult: 0
432
2014.11.21 11:41:30.775 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepPreVerification"
433
2014.11.21 11:41:30.791 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepPreVerification" state 0x40243b8
434
2014.11.21 11:41:30.791 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
435
2014.11.21 11:41:30.791 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
436
2014.11.21 11:41:30.791 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepPreVerification"
437
2014.11.21 11:41:30.791 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepPreVerification"
438
2014.11.21 11:41:30.791 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendDIDListResponse"
439
2014.11.21 11:41:30.791 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepPreVerification"
440
2014.11.21 11:41:30.791 D ...ertificateChainBuilder(card/base/asn1/CVCertificateChainBuilder.cpp:45) : Found Terminal CVC(CHR/CAR):  "DESIXFORM01183" / "DEDVeIDDPST00033"
441
2014.11.21 11:41:30.791 D ...ertificateChainBuilder(card/base/asn1/CVCertificateChainBuilder.cpp:57) : Added CVC(CHR/CAR):  "DEDVeIDDPST00033" / "DECVCAeID00103"
442
2014.11.21 11:41:30.791 D ...ertificateChainBuilder(card/base/asn1/CVCertificateChainBuilder.cpp:57) : Added CVC(CHR/CAR):  "DECVCAeID00103" / "DECVCAeID00102"
443
2014.11.21 11:41:30.791 D ...ertificateChainBuilder(card/base/asn1/CVCertificateChainBuilder.cpp:57) : Added CVC(CHR/CAR):  "DECVCAeID00102" / "DECVCAeID00102"
444
2014.11.21 11:41:30.791 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
445
2014.11.21 11:41:30.791 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
446
2014.11.21 11:41:30.806 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
447
2014.11.21 11:41:30.806 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
448
2014.11.21 11:41:30.806 D StepPreVerification::isValid(core/step/StepPreVerification.cpp:84)         : Check certificate chain validity on  "2014-11-21"
449
2014.11.21 11:41:30.806 D StepPreVerification::isValid(core/step/StepPreVerification.cpp:96)         : CVC  "DESIXFORM01183(AT)" valid from / to [ "2014-11-21" ,  "2014-11-22" ] 
450
2014.11.21 11:41:30.806 D StepPreVerification::isValid(core/step/StepPreVerification.cpp:96)         : CVC  "DEDVeIDDPST00033(DV_no_f)" valid from / to [ "2014-11-17" ,  "2015-02-15" ] 
451
2014.11.21 11:41:30.806 D StepPreVerification::isValid(core/step/StepPreVerification.cpp:96)         : CVC  "DECVCAeID00103(CVCA)" valid from / to [ "2012-12-03" ,  "2015-12-03" ] 
452
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepPreVerification"
453
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepPreVerification"
454
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepPreVerification" | StepResult: 0
455
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepCertificateDescriptionCheck"
456
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepCertificateDescriptionCheck" state 0x4024088
457
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
458
2014.11.21 11:41:30.822 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
459
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepCertificateDescriptionCheck"
460
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepCertificateDescriptionCheck"
461
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
462
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
463
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
464
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
465
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
466
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
467
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
468
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
469
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
470
2014.11.21 11:41:30.822 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
471
2014.11.21 11:41:30.822 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepPreVerification"
472
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepCertificateDescriptionCheck"
473
2014.11.21 11:41:30.822 D UrlUtil::isMatchingSameOriginPolicy(core/network/UrlUtil.cpp:133)          : SOP-Check( "https://www.sixform.com:443" , "https://www.sixform.com:443" )= true
474
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepCertificateDescriptionCheck"
475
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepCertificateDescriptionCheck"
476
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepCertificateDescriptionCheck" | StepResult: 0
477
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepCheckCertificates"
478
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepCheckCertificates" state 0x4024398
479
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
480
2014.11.21 11:41:30.822 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
481
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepCheckCertificates"
482
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepCheckCertificates"
483
2014.11.21 11:41:30.822 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepCertificateDescriptionCheck"
484
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepCheckCertificates"
485
2014.11.21 11:41:30.822 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:29)       : Check certificate CN= ("www.sixform.com") SN= "2e:7d:6e:67:26:d7:be:84"
486
2014.11.21 11:41:30.822 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:31)       : Certificate hash( "SHA256" ) "63317224e931a55c91406a98a65fbf2d3de9b3d1b6fed62e80a4049c841731f9"
487
2014.11.21 11:41:30.822 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:32)       : Accepted certificate hashes QSet("DB37C8E02D6D715EFBFB819D9620C0D411BB6D5F8000200148FFCFA3467F7158", "9D8EB0BDF36B19C4AF3147E57401FD792845F0413102A7BD784DF9418098BEBE", "63317224E931A55C91406A98A65FBF2D3DE9B3D1B6FED62E80A4049C841731F9", "EBD2A9610AA53AE1C159B2C7B238451E2C6AF06F7034723BD4B9743196E6A720", "29F04459C39E4B68C70AA3961FA7B1B40E8A49238446CFE606C56FF8DC0989F4")
488
2014.11.21 11:41:30.822 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:29)       : Check certificate CN= ("prodpaos.governikus-eid.de") SN= "50:34:6c:46:ac:eb:df:b1"
489
2014.11.21 11:41:30.822 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:31)       : Certificate hash( "SHA256" ) "9d8eb0bdf36b19c4af3147e57401fd792845f0413102a7bd784df9418098bebe"
490
2014.11.21 11:41:30.822 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:32)       : Accepted certificate hashes QSet("DB37C8E02D6D715EFBFB819D9620C0D411BB6D5F8000200148FFCFA3467F7158", "9D8EB0BDF36B19C4AF3147E57401FD792845F0413102A7BD784DF9418098BEBE", "63317224E931A55C91406A98A65FBF2D3DE9B3D1B6FED62E80A4049C841731F9", "EBD2A9610AA53AE1C159B2C7B238451E2C6AF06F7034723BD4B9743196E6A720", "29F04459C39E4B68C70AA3961FA7B1B40E8A49238446CFE606C56FF8DC0989F4")
491
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepCheckCertificates"
492
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepCheckCertificates"
493
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepCheckCertificates" | StepResult: 0
494
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepPrepareChat"
495
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepPrepareChat" state 0x40244a8
496
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
497
2014.11.21 11:41:30.822 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
498
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepPrepareChat"
499
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepPrepareChat"
500
2014.11.21 11:41:30.822 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepCheckCertificates"
501
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepPrepareChat"
502
2014.11.21 11:41:30.822 D StepPrepareChat::run(core/step/StepPrepareChat.cpp:122)                    : Initially set effective chat to: "7f4c12060904007f00070301020253050000000004"
503
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepPrepareChat"
504
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepPrepareChat"
505
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepPrepareChat" | StepResult: 0
506
2014.11.21 11:41:30.822 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepDidAuthenticateEac1"
507
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepDidAuthenticateEac1" state 0x4024778
508
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
509
2014.11.21 11:41:30.822 D StateMachine::initStepUi(core/StateMachine.cpp:216)                        : step declares UI "governikus::StepDidAuthenticateEac1Ui"  (previous:  governikus::StepChooseCardGui ); creating new one
510
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepDidAuthenticateEac1"
511
2014.11.21 11:41:30.822 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepDidAuthenticateEac1"
512
2014.11.21 11:41:30.822 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepPrepareChat"
513
2014.11.21 11:41:30.822 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepDidAuthenticateEac1"
514
2014.11.21 11:41:30.869 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
515
2014.11.21 11:41:31.383 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
516
2014.11.21 11:41:31.883 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
517
2014.11.21 11:41:32.397 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
518
2014.11.21 11:41:32.897 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
519
2014.11.21 11:41:33.411 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
520
2014.11.21 11:41:33.926 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
521
2014.11.21 11:41:34.441 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
522
2014.11.21 11:41:34.956 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
523
2014.11.21 11:41:35.473 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
524
2014.11.21 11:41:35.624 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "00a4020c02011c"
525
2014.11.21 11:41:35.631 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
526
2014.11.21 11:41:35.631 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
527
2014.11.21 11:41:35.631 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0022c1a412800a04007f0007020204020283010384010d"
528
2014.11.21 11:41:35.693 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
529
2014.11.21 11:41:35.693 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
530
2014.11.21 11:41:35.693 D CardController::getRetryCounter(card/base/CardController.cpp:154)          : StatusCode:  "SUCCESS"
531
2014.11.21 11:41:35.693 D PaceHandler::isSupportedProtocol(card/base/pace/PaceHandler.cpp:137)       : Use ECDH with standardized domain parameters:  "0.4.0.127.0.7.2.2.4.2.2"
532
2014.11.21 11:41:35.693 D createCurve(card/base/pace/ec/EllipticCurveFactory.cpp:44)                 : Create elliptic curve  brainpoolP256r1
533
2014.11.21 11:41:35.693 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "00a4020c02011c"
534
2014.11.21 11:41:35.709 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
535
2014.11.21 11:41:35.709 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
536
2014.11.21 11:41:35.709 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0022c1a427800a04007f0007020204020283010384010d7f4c12060904007f00070301020253050000000004"
537
2014.11.21 11:41:35.771 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
538
2014.11.21 11:41:35.771 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
539
2014.11.21 11:41:35.771 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "10860000027c0000"
540
2014.11.21 11:41:35.849 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
541
2014.11.21 11:41:35.849 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "7c128010a4ec715d370435b52c93558e1ea3e19b9000"
542
2014.11.21 11:41:35.849 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "10860000457c438141043943154263d4fcf3c7e86a67b0ebc5ffe060c479e11278f460e6b2ded229e7bd29dd1c75459e7901103c4bb8a7196b343f5e8807749190f26c27e2163d99088600"
543
2014.11.21 11:41:36.177 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
544
2014.11.21 11:41:36.177 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "7c4382410409103d7a9e37d629d7984efac5ec6c85ed3191babec7d9854b81fbf61e9843d695e7384b61916eceff7002c5c12385ac6bf934026ef0039ada30e43f2b72bbb49000"
545
2014.11.21 11:41:36.177 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:111)        : Clear and free point
546
2014.11.21 11:41:36.193 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:123)          : Clear and free big number
547
2014.11.21 11:41:36.193 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:123)          : Clear and free big number
548
2014.11.21 11:41:36.193 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:111)        : Clear and free point
549
2014.11.21 11:41:36.193 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:123)          : Clear and free big number
550
2014.11.21 11:41:36.193 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:111)        : Clear and free point
551
2014.11.21 11:41:36.193 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "10860000457c438341045f865e887c554c474b33abbeb19ffed98de848f9c7cd46dcecea01ebd45ee0a4985a43275a14a380afc609c524b25343b57768a98ece3680a957e0831280292000"
552
2014.11.21 11:41:36.411 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
553
2014.11.21 11:41:36.411 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "7c4384410495a67511e8caaaf55dc27b616f5e143a68c403b0bcb2b8cc1dd589bb0241bdef65020f5b82cb998459de7ec080041e27a93eeab9e79c5b661e002f090c9aec079000"
554
2014.11.21 11:41:36.427 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
555
2014.11.21 11:41:36.427 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:111)        : Clear and free point
556
2014.11.21 11:41:36.427 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "008600000c7c0a8508aa96862cc66c13ae00"
557
2014.11.21 11:41:36.614 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
558
2014.11.21 11:41:36.614 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "7c2a8608080abcfa9e2e48f4870e4445435643416549443030313033880e44454356434165494430303130329000"
559
2014.11.21 11:41:36.614 D ...reement::performMutualAuthenticate(card/base/pace/KeyAgreement.cpp:139) : Successfully authenticated
560
2014.11.21 11:41:36.614 D PaceHandler::establishPaceChannel(card/base/pace/PaceHandler.cpp:97)       : Pace channel established
561
2014.11.21 11:41:36.614 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:111)        : Clear and free point
562
2014.11.21 11:41:36.614 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:111)        : Clear and free point
563
2014.11.21 11:41:36.614 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
564
2014.11.21 11:41:36.614 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:87)         : Clear and free curve: brainpoolP256r1
565
2014.11.21 11:41:36.614 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c8400000d9701088e08179562ed8434e44e00"
566
2014.11.21 11:41:36.661 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
567
2014.11.21 11:41:36.661 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "871101d9dca596d993e6a2990e0e920c3ff5c2990290008e0872b2c6f031c7e98a9000"
568
2014.11.21 11:41:36.661 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
569
2014.11.21 11:41:36.661 D const(card/base/asn1/CVCertificateChainBuilder.cpp:118)                    : Build sub chain for CAR  "DECVCAeID00102" of size  3
570
2014.11.21 11:41:36.661 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepDidAuthenticateEac1"
571
2014.11.21 11:41:36.661 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepDidAuthenticateEac1"
572
2014.11.21 11:41:36.661 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepDidAuthenticateEac1" | StepResult: 0
573
2014.11.21 11:41:36.661 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendDIDAuthenticateResponseEAC1"
574
2014.11.21 11:41:36.661 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendDIDAuthenticateResponseEAC1" state 0x40240f8
575
2014.11.21 11:41:36.661 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
576
2014.11.21 11:41:36.661 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
577
2014.11.21 11:41:36.661 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendDIDAuthenticateResponseEAC1"
578
2014.11.21 11:41:36.661 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendDIDAuthenticateResponseEAC1"
579
2014.11.21 11:41:36.661 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepDidAuthenticateEac1"
580
2014.11.21 11:41:36.661 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendDIDAuthenticateResponseEAC1"
581
2014.11.21 11:41:36.676 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
582
 "POST /ecardpaos/paosreceiver HTTP/1.1
583
Host: prodpaos.governikus-eid.de
584
User-Agent: AusweisApp2/1.0.0
585
Connection: keep-alive
586
Accept: text/html; application/vnd.paos+xml
587
PAOS: ver="urn:liberty:paos:2006-08"
588
Content-Type: application/vnd.paos+xml; charset=UTF-8
589
Content-Length: 2216
590
requestid: f8241bf1-7858-43f9-ab54-a94187522256
591

    
592
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
593
 <soap:Header>
594
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
595
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
596
   <paos:EndpointReference>
597
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
598
    <paos:MetaData>
599
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
600
    </paos:MetaData>
601
   </paos:EndpointReference>
602
  </paos:PAOS>
603
  <wsa:ReplyTo>
604
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
605
  </wsa:ReplyTo>
606
  <wsa:MessageID>urn:uuid:7b8de274-e761-44cc-82ec-0a9877607dab</wsa:MessageID>
607
 </soap:Header>
608
 <soap:Body>
609
  <DIDAuthenticateResponse Profile="http://www.bsi.bund.de/ecard/api/1.1" xmlns="urn:iso:std:iso-iec:24727:tech:schema">
610
   <Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
611
    <ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
612
   </Result>
613
   <AuthenticationProtocolData Protocol="urn:oid:1.3.162.15480.3.0.14.2" xsi:type="iso:EAC1OutputType">
614
    <CertificateHolderAuthorizationTemplate>7f4c12060904007f00070301020253050000000004</CertificateHolderAuthorizationTemplate>
615
    <EFCardAccess>3181b3300d060804007f00070202020201023012060a04007f000702020302020201020201413012060a04007f000702020302020201020201453012060a04007f0007020204020202010202010d301c060904007f000702020302300c060704007f0007010202010d020141301c060904007f000702020302300c060704007f0007010202010d020145302a060804007f0007020206161e687474703a2f2f6273692e62756e642e64652f6369662f6e70612e786d6c</EFCardAccess>
616
    <IDPICC>95a67511e8caaaf55dc27b616f5e143a68c403b0bcb2b8cc1dd589bb0241bdef</IDPICC>
617
    <Challenge>c344f8e681f7a582</Challenge>
618
   </AuthenticationProtocolData>
619
  </DIDAuthenticateResponse>
620
 </soap:Body>
621
</soap:Envelope>
622
"
623
2014.11.21 11:41:36.676 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
624
2014.11.21 11:41:36.676 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
625
2014.11.21 11:41:36.743 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
626
2014.11.21 11:41:36.744 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 1561
627
2014.11.21 11:41:36.744 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
628
2014.11.21 11:41:36.744 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "1566"  bytes)
629
2014.11.21 11:41:36.744 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
630
2014.11.21 11:41:36.744 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
631
2014.11.21 11:41:36.745 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
632
2014.11.21 11:41:36.745 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
633
2014.11.21 11:41:36.745 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
634
2014.11.21 11:41:36.745 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
635
2014.11.21 11:41:36.745 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
636
   <soap:Header>
637
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id3998" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
638
   </soap:Header>
639
   <soap:Body>
640
   <DIDAuthenticate xmlns="urn:iso:std:iso-iec:24727:tech:schema">
641
<ConnectionHandle xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="ConnectionHandle">
642
<ContextHandle>CD010003</ContextHandle>
643
<IFDName>REINER SCT cyberJack RFID basis 0</IFDName>
644
<SlotIndex>0</SlotIndex>
645
<CardApplication>E80704007F00070302</CardApplication>
646
<SlotHandle>33393236323631373630</SlotHandle>
647
<RecognitionInfo/>
648
</ConnectionHandle>
649
<DIDName>PIN</DIDName>
650
<AuthenticationProtocolData Protocol="urn:oid:1.3.162.15480.3.0.14.2" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="EAC2InputType">
651
<Certificates xmlns="unknownNamespace"/>
652
<EphemeralPublicKey>040AE9999D8E1696E994FF8AD26C7FF97F0457E97D78616450C6010722704866D94D4DD1980342303F6919E718602C96FB14DE1BEFCD1E874B576D6BB361DB308B</EphemeralPublicKey>
653
<Signature>5EDD8864787936F29AAC9478DDACDDC8506F86BFEFB96F36DCE5F3D8481CB874730B6188FC74954555162398FB325A1B4A25D1DD7AA3EE11CA787D4EF6D6D100</Signature>
654
</AuthenticationProtocolData>
655
</DIDAuthenticate>
656
</soap:Body>
657
</soap:Envelope>
658
"
659
2014.11.21 11:41:36.745 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
660
2014.11.21 11:41:36.746 D ...rser::parseMessage(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:41) : "ConnectionHandle"
661
2014.11.21 11:41:36.746 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "ContextHandle"
662
2014.11.21 11:41:36.746 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "IFDName"
663
2014.11.21 11:41:36.746 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "SlotIndex"
664
2014.11.21 11:41:36.746 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "CardApplication"
665
2014.11.21 11:41:36.746 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "SlotHandle"
666
2014.11.21 11:41:36.746 D ...ionHandleParser::parse(core/paos/element/ConnectionHandleParser.cpp:37) : "RecognitionInfo"
667
2014.11.21 11:41:36.747 D ...rser::parseMessage(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:41) : "DIDName"
668
2014.11.21 11:41:36.747 D ...rser::parseMessage(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:41) : "AuthenticationProtocolData"
669
2014.11.21 11:41:36.747 D ...parseEac2InputType(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:84) : "Certificates"
670
2014.11.21 11:41:36.747 W ...arseEac2InputType(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:116) : Unknown element: "Certificates"
671
2014.11.21 11:41:36.747 D ...parseEac2InputType(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:84) : "EphemeralPublicKey"
672
2014.11.21 11:41:36.747 D ...parseEac2InputType(core/paos/retrieve/DidAuthenticateEac2Parser.cpp:84) : "Signature"
673
2014.11.21 11:41:36.747 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "DID_AUTHENTICATE_EAC2"
674
2014.11.21 11:41:36.747 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendDIDAuthenticateResponseEAC1"
675
2014.11.21 11:41:36.748 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendDIDAuthenticateResponseEAC1"
676
2014.11.21 11:41:36.748 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendDIDAuthenticateResponseEAC1" | StepResult: 0
677
2014.11.21 11:41:36.748 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepEACAdditionalInputType"
678
2014.11.21 11:41:36.748 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepEACAdditionalInputType" state 0x4024138
679
2014.11.21 11:41:36.748 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
680
2014.11.21 11:41:36.748 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
681
2014.11.21 11:41:36.748 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepEACAdditionalInputType"
682
2014.11.21 11:41:36.748 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepEACAdditionalInputType"
683
2014.11.21 11:41:36.748 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendDIDAuthenticateResponseEAC1"
684
2014.11.21 11:41:36.748 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepEACAdditionalInputType"
685
2014.11.21 11:41:36.749 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepEACAdditionalInputType"
686
2014.11.21 11:41:36.749 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepEACAdditionalInputType"
687
2014.11.21 11:41:36.749 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepEACAdditionalInputType" | StepResult: 0
688
2014.11.21 11:41:36.749 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepProcessCertificatesFromEac2"
689
2014.11.21 11:41:36.753 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepProcessCertificatesFromEac2" state 0x4024238
690
2014.11.21 11:41:36.753 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
691
2014.11.21 11:41:36.753 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
692
2014.11.21 11:41:36.753 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepProcessCertificatesFromEac2"
693
2014.11.21 11:41:36.753 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepProcessCertificatesFromEac2"
694
2014.11.21 11:41:36.753 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepEACAdditionalInputType"
695
2014.11.21 11:41:36.754 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepProcessCertificatesFromEac2"
696
2014.11.21 11:41:36.754 D const(card/base/asn1/CVCertificateChainBuilder.cpp:118)                    : Build sub chain for CAR  "DECVCAeID00102" of size  3
697
2014.11.21 11:41:36.754 D ...ificatesFromEac2::run(core/step/StepProcessCertificatesFromEac2.cpp:37) : CVC chain already determined, skip further processing
698
2014.11.21 11:41:36.754 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepProcessCertificatesFromEac2"
699
2014.11.21 11:41:36.754 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepProcessCertificatesFromEac2"
700
2014.11.21 11:41:36.754 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepProcessCertificatesFromEac2" | StepResult: 0
701
2014.11.21 11:41:36.754 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepDidAuthenticateEac2"
702
2014.11.21 11:41:36.755 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepDidAuthenticateEac2" state 0x4024128
703
2014.11.21 11:41:36.755 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
704
2014.11.21 11:41:36.755 D StateMachine::initStepUi(core/StateMachine.cpp:204)                        : step's UI type matches previous one; keeping previous one
705
2014.11.21 11:41:36.755 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepDidAuthenticateEac2"
706
2014.11.21 11:41:36.755 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepDidAuthenticateEac2"
707
2014.11.21 11:41:36.755 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
708
2014.11.21 11:41:36.755 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
709
2014.11.21 11:41:36.755 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
710
2014.11.21 11:41:36.755 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
711
2014.11.21 11:41:36.755 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
712
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
713
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
714
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
715
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
716
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
717
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
718
2014.11.21 11:41:36.756 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
719
2014.11.21 11:41:36.756 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepProcessCertificatesFromEac2"
720
2014.11.21 11:41:36.756 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepDidAuthenticateEac2"
721
2014.11.21 11:41:36.757 D const(card/base/asn1/CVCertificateChainBuilder.cpp:118)                    : Build sub chain for CAR  "DECVCAeID00102" of size  3
722
2014.11.21 11:41:36.757 D const(card/base/asn1/CVCertificateChainBuilder.cpp:118)                    : Build sub chain for CAR  "DECVCAeID00102" of size  3
723
2014.11.21 11:41:36.758 D CardController::putCertificateChain(card/base/CardController.cpp:489)      : Performing TA MSE:Set DST
724
2014.11.21 11:41:36.758 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2281b62d8721011450845e22fe54bb4c0b0985acd97e308c1096aae65c7c996596bad058c498168e08e3e75ae4610c58ca00"
725
2014.11.21 11:41:36.796 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
726
2014.11.21 11:41:36.796 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e087fde432b3e1ae6f09000"
727
2014.11.21 11:41:36.796 D CardController::putCertificateChain(card/base/CardController.cpp:507)      : Performing TA PSO:Verify Certificate
728
2014.11.21 11:41:36.797 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2a00be0001cf878201c1017e7e5c604c9d20e3eaa9dcb28f3f240ae8832ca1d6f6734af3289a2876dbbc72b858668475db279121d4b75d2c25e6bd226eea64014726ecfeeb01395a935058de593643b29319037bef4f29bbd36cc7dd0d9338bae90010c7ee8223f35f55c17b453992f07308d5287e2e597db24aa48438b1607e3b861636a8c88fd27ed97ba3b535187c5d501b2214d15f44d1f16445176a5913d5236565b773992b971cb3362bb2d82946ed5859a779d7c0fefca0af840dc0e2a18ef49042cc8c15de30dc511f50d3803a7d426ed1f048c2ef18116cf7a44f57d6a0e9f37bd60dcfaf7db6080a07fa81fbc3bf336d7bde5ffe891b168d9119e74d763ea3fa139a1b215552b00287bad09ed5676f22435835849e69f55e4b761474abc05b571b28cc3250761d4498d9c61754a19928b3071af7ada658612327de6a0482fbcbfa1543576eec3c956ccb12486e600e8e205ab1165eaa2a451e3e8120479e35de71c2b68331d7f0e52cf35c338d6ac4334a86350d25115ce61fafc729dc5797e0e04387c5ba82681c9dc8b898613501e7442f95290a981e4f8e2aa57036d59bddb640ba7a0b44531d8621bf560ee5c6dcba8cfb60bb59b383b91d8c60905f85187fda5fda834e8e08c3bfcd64a66c12da0000"
729
2014.11.21 11:41:37.246 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
730
2014.11.21 11:41:37.247 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e0894bea0a176022b079000"
731
2014.11.21 11:41:37.247 D CardController::putCertificateChain(card/base/CardController.cpp:489)      : Performing TA MSE:Set DST
732
2014.11.21 11:41:37.247 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2281b62d87210125d1eab555e0892bcfe1c62b41f33280ce049ab94d77fd7eef0bcafd2037f05c8e08409e858288c1903700"
733
2014.11.21 11:41:37.286 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
734
2014.11.21 11:41:37.286 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08d3f65059926ae5249000"
735
2014.11.21 11:41:37.286 D CardController::putCertificateChain(card/base/CardController.cpp:507)      : Performing TA PSO:Verify Certificate
736
2014.11.21 11:41:37.287 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2a00befe8781f101ad981541898c1ef330ff2b4fe50a1c17384dce4f69495307734a3f95580bd53df2768938d9edd5d0238ae81839ca3a0cf1d55af7d2956d3b6f79fe928b5b6bbfa5a369371201ce36ab2c114282291d285e2f8735c63c42371203de8a67748da0da623a7d912a6399d23b0766120ea98f8a18f6cd2500be9255e70a44cf7c4571ddf6b6158e29ab4b7c2a0ca41fb9e709303feee9ac71e5643ec6e3b3760578ea0483d95b67ebfe96fbd3d2a3598aa49c53e174a46a21ada98928892377c5bf86455481652f381457d794597f057b89ba969a08c632b2230891a236f7c6b05c94b4a352206433242c6f989090bf95295e8e0852d38b7c6ebfc1f800"
737
2014.11.21 11:41:37.626 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
738
2014.11.21 11:41:37.626 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08c247bde03715ee629000"
739
2014.11.21 11:41:37.626 D CardController::putCertificateChain(card/base/CardController.cpp:489)      : Performing TA MSE:Set DST
740
2014.11.21 11:41:37.626 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2281b62d872101542ec361e1e93db0c596a343758ebd34562c7db443df843964808398d466d2cd8e089464f9a4c1d8a13700"
741
2014.11.21 11:41:37.661 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
742
2014.11.21 11:41:37.661 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08ec3aa69bc57019de9000"
743
2014.11.21 11:41:37.661 D CardController::putCertificateChain(card/base/CardController.cpp:507)      : Performing TA PSO:Verify Certificate
744
2014.11.21 11:41:37.662 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2a00be00015f87820151018b585c8b1b6ae4a72abf2f1d97727091c677498073f97ef1c3bf5724b73d9aa08807de8945cb5d2fc3ad7b59cc91025f47f58e7876f5bb0a604ba07bfd69544f4b72d013e06f55a2c80077f55489581725b82f838ed624b145a05f80acd3cebee9326e9aa18a4151110c9c49989b9efa652871097beb5aaedee4e62c3440314710531c85543e755736c3e052eb8970df73af93abe01fe94403cba7b7ff3829f08dc23e41ad8f801fcd95b7cb6e17891f4fe74780ecdc9326161791b8a0fb35cf87caa97ae4fd0af499281119d40065b8be1350dd157cdef6024aafbc24bd12508473d7662ce35842537c5f04cdf13afc030be53667deb2ddb0ba34a72374efef2a80c35c5d8d282bd6a21b35b222b32b92791797cd613a36da207f762dff9d1a4415be05fc870a5fc5dbec34e39caeb9fe31c15af29635d0a9155be7b36f240bcc6c9e1d40fa2253eb9d5dbcb27368518e0843cf018f3c246abc0000"
745
2014.11.21 11:41:37.994 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
746
2014.11.21 11:41:37.994 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08f2eeb544ef12c3bb9000"
747
2014.11.21 11:41:37.994 D ...roller::performTerminalAuthentication(card/base/CardController.cpp:447) : Performing TA MSE:Set AT
748
2014.11.21 11:41:37.995 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2281a46d87610155d4fd5802a87446a8195d47e0d2de5c91ede69fbff07cffb57b7a61e71beb443434d4d62cd53df43d0310325f073e45a8ffa3d4b0736361ea6d6b68ad322d85b1a6127456fa0be8a881cd5a24ab6ba7f61553b56f01370dbf1be666c0ff34c68e0825ab54db7d62e56900"
749
2014.11.21 11:41:38.032 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
750
2014.11.21 11:41:38.032 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08c7f4c27ed9f648dc9000"
751
2014.11.21 11:41:38.032 D ...roller::performTerminalAuthentication(card/base/CardController.cpp:463) : Performing TA External Authenticate
752
2014.11.21 11:41:38.033 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c8200005d875101143658d6b06e8fe042834133439a855ef5131559a7bb70fe15df9e0ab6e94c580da4e2e0d0db14605a9d669677aaedaf867743c0ad3a2394135bea908a9d8be5939c1e225b6a1bfe84eaa3f32b370b2d8e08d5aae0140ce8baa100"
753
2014.11.21 11:41:38.249 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
754
2014.11.21 11:41:38.249 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e080a9d9f6c5dfd7cda9000"
755
2014.11.21 11:41:38.250 D CardController::didAuthenticateEAC2(card/base/CardController.cpp:253)      : Performing Read EF.CardSecurity
756
2014.11.21 11:41:38.250 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0ca4020c1d8711019d70abe238b0d9b2461b93101e2bea3f8e08b73c423ee44ae3f700"
757
2014.11.21 11:41:38.273 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
758
2014.11.21 11:41:38.273 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e081880a3352dd0ad349000"
759
2014.11.21 11:41:38.273 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0cb000000d9701ff8e082c40f54a6c1cab9400"
760
2014.11.21 11:41:38.304 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
761
2014.11.21 11:41:38.304 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "8782010101e66adfa3c0fa4bc14d32bd7918bd82682983bd39be04912698a59ad32108fa194e78ca08267e4bc5968957fd5bfcbb6ea81161793898d549e3db6b2736be8389e60bc0af171334d8a22a832f92aecdf6bc96d8004d5155ca0b3e8940bae713f91fab42ae0dd1056b6f6a6944469072a981ce165c324cced8195ceca5970781ab40e12a65068ba5cd1b1b748ba963ad2f29f0b0eb5a8733b72e7a6b08f49f1ab4a4670cbbffdbec5c037dc37f1516b70426f865aed70dd190073e7a5f0a3744850bde8da77e178bb77b290afbd4afbdd41398970163ca00e617e2dcc6c80e69a5c3833299386aa2d2fa5658ff1377f5299b8b15de91d3d165c3edd8173765d99d990290008e088f9cf3bd7b12b41f9000"
762
2014.11.21 11:41:38.305 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0cb000ff0d9701ff8e0806ecd4222465c66c00"
763
2014.11.21 11:41:38.335 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
764
2014.11.21 11:41:38.335 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "87820101015351e714242f80485513ad6109e66d14ff6237e44a7f652bdfe02b1813fa8ad5fa7d384203fded142def416e470a17a771e0cfccfa7a15544eb822b3c36c8aa7c795810b2e71c667907407b4fb5208d0d39fe9205475982197043b61854bd5e5bf6ce877a104e24e3e1bbd244062cd76a1a40ba0a97db2ba62ae6327f37f922811bafd1f8f7c2d9587ea4a39e495309dff7966db9b7a4ea0b85a211653bc1635a31205ca44459ca3bcb83b19de73f6176e48b3f6cf416eb35690b40c83cb234684ca153716d5b5ee3c5c554810f1d1ef1a04e9dc593ee006abb01743bdfe6b1aa4ebcf586b1278ad695f9d7bca36aab2466d09bb394528121812285a3db3cea0990290008e08039bdb32828735a29000"
765
2014.11.21 11:41:38.335 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0cb001fe0d9701ff8e0866090720bcecf13f00"
766
2014.11.21 11:41:38.367 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
767
2014.11.21 11:41:38.367 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "878201010148a3b6ba452bf3404ddcda71b2ce31e4d7bf2c2e22d501dbfb91d87229b8b713e960ac46e877d6b34c1dfe1f97725751f3754d87332300c6640422999149718027218972cb06fcdf2619e54b275c97e19c083cb508c21346b5566afdcf227cf646ffcc84801cf7f81b28287e5269074bb631944f72f0c55ecebe5d62c2c502bbf38371a05c77272f77b77c248f1dc692c33b25b7ba8f6a257afd32b4dcb8e0656772a9f032713dc0a2c11a4f44cbc3e57059d9833b1955e120edc717905ffbad1afdb48eeacfa3597d975772d9cefdc8d319a9db9512f65f32292730b2aebd281f8f3f0a22890d40767b22fa8368e18467151d464d8b44d8541b3b0c9bd70d2a990290008e08a6a03a68f91a8b779000"
768
2014.11.21 11:41:38.367 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0cb002fd0d9701ff8e08fe71da88ce4cf4dc00"
769
2014.11.21 11:41:38.398 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
770
2014.11.21 11:41:38.398 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "8782010101b14f8b90b03119a62473ff0ebe18ffede8f0e23513508be54524f3f14e85532e86515c3e7ccb6d50e96144906db0a68b77b59600011cc89a55ae10e43a11674ab4686b1d0151822cf16416db6ff029ea53b8b4764f1d1cfdf0a7292c8b63590628d93eed4336dc906bf563210b4affaf311e444976dc1ff25545a85c9e8bbea52e284498f59fc1fae968117c0fe9f539ce712089828e04b4aac241cf414ab42931b64f5576139a2b7eb2f1b073751edcc2c9011594de1157f27c336efcca5e212384f8e9ee80343032f2e308166996d490f9bfe7f9bb5555a6d041899309e877b00a1a5406e70ce0c1f6851d2adfe31f68d25417f687870b8a2a06391fb994c5990290008e08d25b5049f20250059000"
771
2014.11.21 11:41:38.399 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0cb003fc0d9701ff8e081740473e4d39d00a00"
772
2014.11.21 11:41:38.429 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
773
2014.11.21 11:41:38.430 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "87820101014d02fc2c3503e69e8da01274c2b9f25057b3727b6f1a9c62a9d2ab905a8303aaf427e1f6edde14ce3af1676958ad8949b21fa2e8aeea084b24a1d3367d0c607c7fe2625be1b240be29d9ff95ed42f62eb11fdd0062e06b1affe68f4922a4dde4303b1cdfd15b30932a2b813cd81db785bfa6681419e98b1df32ae29952c8f8e3c9a09de831a7c95c6e2ab162685a333c540a63c8c546e1c6d8a32c3d7352b8bd707933d52f23f61e5615ea322b692d0bc72379ed717082fa8594cb798825cf89e77212e3e93559d5d666ec02f1113dc5d36e76be06ccbb4671ea03fac46c75eeafdd42f7f49a5353677020d23e5f51fca8a77dbbe80c0d5aa191e5ef287af079990290008e082c46dc41150778269000"
774
2014.11.21 11:41:38.430 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0cb004fb0d9701ff8e082799890d4ed9370400"
775
2014.11.21 11:41:38.452 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
776
2014.11.21 11:41:38.453 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "8781b101dfd5c65ce272b7287edb64b006b97d9fa985bae232dc8d750b6d32f21b928bc44ae0c166b2bd6043d05efa9cff2b6573cfd8e58ef05d593190f7c20be17ae1a00ed037d432f1960f52ce81f65bd577942f3d3a70b1d63e2f3fff262fd2326a2ad6b6d3dce5e197ca29c0fe1be8feeff0234d66aca8d3b23f314b4d1963a3b05181a22885c9bf1f0e89ce499bbc81a1158e7e5242363808b4a36087f05a35696b777163999c4dfec74f0c9451f6c2bd7e990262828e08a35effb0ac254e136282"
777
2014.11.21 11:41:38.453 D ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:116) : Parse TerminalAuthenticationInfo
778
2014.11.21 11:41:38.453 D ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:101) : Parse ChipAuthenticationInfo
779
2014.11.21 11:41:38.453 D ...rityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:91) : Parse PACEInfo
780
2014.11.21 11:41:38.454 W ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:121) : Skip unknown SecurityInfo  "0.4.0.127.0.7.2.2.5.2.3"
781
2014.11.21 11:41:38.454 W ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:121) : Skip unknown SecurityInfo  "0.4.0.127.0.7.2.2.5.2.3"
782
2014.11.21 11:41:38.454 W ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:121) : Skip unknown SecurityInfo  "0.4.0.127.0.7.2.2.5.2"
783
2014.11.21 11:41:38.454 D ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:106) : Parse ChipAuthenticationDomainParameterInfo
784
2014.11.21 11:41:38.455 W ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:121) : Skip unknown SecurityInfo  "0.4.0.127.0.7.2.2.6"
785
2014.11.21 11:41:38.455 D ...ityInfoFactory::createSecurityInfo(card/base/asn1/SecurityInfo.cpp:111) : Parse ChipAuthenticationPublicKeyInfo
786
2014.11.21 11:41:38.455 D CardController::didAuthenticateEAC2(card/base/CardController.cpp:279)      : Chose ChipAuthenticationInfo(0): protocol "0.4.0.127.0.7.2.2.3.2.2" , keyId "41"
787
2014.11.21 11:41:38.455 D ...Controller::performChipAuthentication(card/base/CardController.cpp:399) : Performing CA MSE:Set AT
788
2014.11.21 11:41:38.455 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2241a41d87110141f9f7026cd27eeef5e95d07627830278e089d34ff8f9f2342e600"
789
2014.11.21 11:41:38.493 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
790
2014.11.21 11:41:38.493 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08ac74e8d6dd8f1bed9000"
791
2014.11.21 11:41:38.494 D ...Controller::performChipAuthentication(card/base/CardController.cpp:415) : Performing CA General Authenticate
792
2014.11.21 11:41:38.494 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c86000060875101aba34bad64c74626e2966af7530399dd0983465e2f5d394c67cdb1c5036489cc3e8e98a8d34e5ef52147d138a1f9e0d9f6d332a5ebbb83c87627b76b3b53c3854268cd4752a05476188512b78258648b9701008e08d29b1afff3b4e29200"
793
2014.11.21 11:41:38.752 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
794
2014.11.21 11:41:38.752 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "87210151b1d7f519dfa488dafe50b76516719c335d1c71ad3739d2f34cf5c16679aada990290008e08493ef383cbad93139000"
795
2014.11.21 11:41:38.752 C GAResponseApdu::setBuffer(card/base/Commands.cpp:607)                      : Cannot parse dynamic data
796
2014.11.21 11:41:38.752 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepDidAuthenticateEac2"
797
2014.11.21 11:41:38.752 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepDidAuthenticateEac2"
798
2014.11.21 11:41:38.752 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepDidAuthenticateEac2" | StepResult: 0
799
2014.11.21 11:41:38.752 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendDIDAuthenticateResponseEAC2"
800
2014.11.21 11:41:38.752 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendDIDAuthenticateResponseEAC2" state 0x4024148
801
2014.11.21 11:41:38.752 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
802
2014.11.21 11:41:38.752 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
803
2014.11.21 11:41:38.752 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendDIDAuthenticateResponseEAC2"
804
2014.11.21 11:41:38.752 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendDIDAuthenticateResponseEAC2"
805
2014.11.21 11:41:38.752 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepDidAuthenticateEac2"
806
2014.11.21 11:41:38.752 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendDIDAuthenticateResponseEAC2"
807
2014.11.21 11:41:38.753 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
808
2014.11.21 11:41:38.753 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
809
 "POST /ecardpaos/paosreceiver HTTP/1.1
810
Host: prodpaos.governikus-eid.de
811
User-Agent: AusweisApp2/1.0.0
812
Connection: keep-alive
813
Accept: text/html; application/vnd.paos+xml
814
PAOS: ver="urn:liberty:paos:2006-08"
815
Content-Type: application/vnd.paos+xml; charset=UTF-8
816
Content-Length: 4582
817
requestid: f8241bf1-7858-43f9-ab54-a94187522256
818

    
819
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
820
 <soap:Header>
821
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
822
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
823
   <paos:EndpointReference>
824
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
825
    <paos:MetaData>
826
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
827
    </paos:MetaData>
828
   </paos:EndpointReference>
829
  </paos:PAOS>
830
  <wsa:ReplyTo>
831
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
832
  </wsa:ReplyTo>
833
  <wsa:MessageID>urn:uuid:5c9065de-774b-4180-aae7-6043200cd266</wsa:MessageID>
834
 </soap:Header>
835
 <soap:Body>
836
  <DIDAuthenticateResponse Profile="http://www.bsi.bund.de/ecard/api/1.1" xmlns="urn:iso:std:iso-iec:24727:tech:schema">
837
   <Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
838
    <ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
839
   </Result>
840
   <AuthenticationProtocolData Protocol="urn:oid:1.3.162.15480.3.0.14.2" xsi:type="iso:EAC2OutputType">
841
    <EFCardSecurity>3082059e06092a864886f70d010702a082058f3082058b020103310f300d0609608648016503040201050030820148060804007f0007030201a082013a0482013631820132300d060804007f00070202020201023012060a04007f000702020302020201020201413012060a04007f0007020204020202010202010d3017060a04007f0007020205020330090201010201430101ff3017060a04007f0007020205020330090201010201440101003019060904007f000702020502300c060704007f0007010202010d301c060904007f000702020302300c060704007f0007010202010d020141302a060804007f0007020206161e687474703a2f2f6273692e62756e642e64652f6369662f6e70612e786d6c3062060904007f0007020201023052300c060704007f0007010202010d03420004925db4e17ade58209f96faa07f1f8a223f823f96cc5d78cbef5d17422088fdd58e56bc4250de3346b3c832cae48635fb6c43789de8b3102f4393b418e24a13d9020141a082031c30820318308202bca0030201020202015c300c06082a8648ce3d0403020500304f310b3009060355040613024445310d300b060355040a0c0462756e64310c300a060355040b0c03627369310c300a060355040513033031333115301306035504030c0c637363612d6765726d616e79301e170d3130313030353131303735325a170d3231303430353038333934375a3047310b3009060355040613024445311d301b060355040a0c1442756e646573647275636b6572656920476d6248310c300a06035504051303303734310b300906035504030c024453308201133081d406072a8648ce3d02013081c8020101302806072a8648ce3d0101021d00d7c134aa264366862a18302575d1d787b09f075797da89f57ec8c0ff303c041c68a5e62ca9ce6c1c299803a6c1530b514e182ad8b0042a59cad29f43041c2580f63ccfe44138870713b1a92369e33e2135d266dbb372386c400b0439040d9029ad2c7e5cf4340823b2a87dc68c9e4ce3174c1e6efdee12c07d58aa56f772c0726f24c6b89e4ecdac24354b9e99caa3f6d3761402cd021d00d7c134aa264366862a18302575d0fb98d116bc4b6ddebca3a5a7939f020101033a00043d6a7c2a6f205f839b0414ec58c6c71b75f515dec3ae733b5f4788ddc815f05bc1f6538fd96954e1f840a2e2189962ccaa14900824c7ddb9a381d13081ce300e0603551d0f0101ff040403020780301f0603551d230418301680146044f245f2e071d4d564f4e577d63669dbeb185930410603551d20043a30383036060904007f0007030101013029302706082b06010505070201161b687474703a2f2f7777772e6273692e62756e642e64652f63736361302b06092a864886f70d010915041e041c312e322e3237362e302e38302e312e31322e302e32302e352e312e30302b0603551d1004243022800f32303130313030353131303735325a810f32303131303230353039333934375a300c06082a8648ce3d04030205000348003045022013e9e17a9efe8bd7d7276292305bccc32b70c2b76040f48830666226cd6a4bf402210087f471e24435b4c34af3573094fb1f1c2a48b13ee5ed67f1726dcf56e384e36f31820107308201030201013055304f310b3009060355040613024445310d300b060355040a0c0462756e64310c300a060355040b0c03627369310c300a060355040513033031333115301306035504030c0c637363612d6765726d616e790202015c300d06096086480165030402010500a04a301706092a864886f70d010903310a060804007f0007030201302f06092a864886f70d01090431220420ef0fda942e5a0f6fc9c546ee01f91031436430f75e9d3654d369309e8be71748300c06082a8648ce3d0403020500043e303c021c7a770c893d8da7040db2eed1a52aeb4bc14ee9d703323040e3b9ef7e021c48b75ca267d2d26238ae22b1abb103465240c7e1a942202532acd744</EFCardSecurity>
842
    <AuthenticationToken>0e18c42d03defa81</AuthenticationToken>
843
    <Nonce>ec8a001b432fd383</Nonce>
844
   </AuthenticationProtocolData>
845
  </DIDAuthenticateResponse>
846
 </soap:Body>
847
</soap:Envelope>
848
"
849
2014.11.21 11:41:38.753 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
850
2014.11.21 11:41:38.753 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
851
2014.11.21 11:41:38.846 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
852
2014.11.21 11:41:38.846 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
853
2014.11.21 11:41:38.846 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 2813
854
2014.11.21 11:41:38.847 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
855
2014.11.21 11:41:38.847 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "2818"  bytes)
856
2014.11.21 11:41:38.847 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
857
2014.11.21 11:41:38.847 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
858
2014.11.21 11:41:38.847 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
859
2014.11.21 11:41:38.848 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
860
2014.11.21 11:41:38.848 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
861
2014.11.21 11:41:38.848 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
862
2014.11.21 11:41:38.848 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
863
   <soap:Header>
864
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id3999" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
865
   </soap:Header>
866
   <soap:Body>
867
   <Transmit xmlns="urn:iso:std:iso-iec:24727:tech:schema">
868
<SlotHandle>33393236323631373630</SlotHandle>
869
<InputAPDUInfo>
870
<InputAPDU>0CA4040C1D871101C8FDC392F382FE8AF60224D6901422E08E08C3A6E3A5521F7E7400</InputAPDU>
871
</InputAPDUInfo>
872
<InputAPDUInfo>
873
<InputAPDU>8C2080001D8711017E58B4C08F25761FC2DBA55FF5A166CC8E08B762029E85B1DA1700</InputAPDU>
874
</InputAPDUInfo>
875
<InputAPDUInfo>
876
<InputAPDU>0C2241A41D8711014AFE19EF1DD4D33D9DE8CAA41FEAC9928E08E4C463874EFE505800</InputAPDU>
877
<AcceptableStatusCode>9000</AcceptableStatusCode>
878
</InputAPDUInfo>
879
<InputAPDUInfo>
880
<InputAPDU>0C8600000001428782013101DD4B31F1DD8E38B119858D209C1AEB2D52F81EB963E5E5E4C7EEA4F45E37AF58B163D2C600B2DBE7DA2F81502DD515C1BC66AF71156459535FC3A38799DCA7933ADD54976613F9C7F070D3CE3F94EDB17490A73FA7B36F9CA13797FE8FF437A72D7FB7A7D27F337D6741449F52FA6461614DE62F8C0C27079AABD8D7731FF5413FB1D9AAE0CF10A9A0E34E029D630FBABDBE6BDE818C83420C48B0CCB90A66D0E880258FE06D85367CBE1CDC840C34A5EAF5164F2D9D544240D1C5400819767BC9BAC3DB609C3E88209E809A20970E8C78363EF9EAE06C0B600D2423A7B8474C4F856313CB1AB0AABC50F91FC3AB4A96304645909432F1450A0C769C49C0667401FA2BBF1D6DD75E3DDAB8BD64CE2AEAD41430F561B87911D5737F591F0EADCCBDABECF15EAD0221408787C4C34FF1899701248E08A2372287B47531D90000</InputAPDU>
881
<AcceptableStatusCode>9000</AcceptableStatusCode>
882
</InputAPDUInfo>
883
<InputAPDUInfo>
884
<InputAPDU>0C2241A41D87110137D6F6B81D626FA178B99E0B7D6661928E08CDC2BB7515F2952C00</InputAPDU>
885
<AcceptableStatusCode>9000</AcceptableStatusCode>
886
</InputAPDUInfo>
887
<InputAPDUInfo>
888
<InputAPDU>0C86000000014287820131011C6D9B1BE973CD735CA599BA53AA5EEE792269766B1D2B70A3CB2A1C1BE2EFEB58F69739CA9A550A65AFC7223DF0B3B58851A6C5C61270C67A91E950C78CC0AC970B2E47CDDF242B08897B3308CF3BA213C70D136FFCE2F03067D34C1E6E5F268D9EBBC2675DD4CD99133315C541C6B8829FA542947EEFF6F758DC43B176E6735EC66784F8CC5F4CE36A6C77EE7EE37536E6DE2370C383FF71586664E02BFDD11FEE0446B35FA3DDDC8EC80DCF71ECAFA552E5AEEA2D668999E614447183E890C6CE7F6DCEB2BA288AEFAB142BFF3408597DB257F8C72CE4D0E2B9919E4BA1C43E6DB8C926B5424856D98251F9B7A1E23A146DB094C76822355A465B3BA8169A735AE575CAF17FBDC1FFC3A478E44B6180893D3C02180AA854EACFFE71EC7B6D828067FC33C4EFB806D55D117B58B7659701248E083CEF26B3AEE4CAC40000</InputAPDU>
889
<AcceptableStatusCode>9000</AcceptableStatusCode>
890
</InputAPDUInfo>
891
</Transmit>
892
</soap:Body>
893
</soap:Envelope>
894
"
895
2014.11.21 11:41:38.848 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
896
2014.11.21 11:41:38.849 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "SlotHandle"
897
2014.11.21 11:41:38.849 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "InputAPDUInfo"
898
2014.11.21 11:41:38.849 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "InputAPDU"
899
2014.11.21 11:41:38.849 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "InputAPDUInfo"
900
2014.11.21 11:41:38.849 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "InputAPDU"
901
2014.11.21 11:41:38.849 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "InputAPDUInfo"
902
2014.11.21 11:41:38.849 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "InputAPDU"
903
2014.11.21 11:41:38.849 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "AcceptableStatusCode"
904
2014.11.21 11:41:38.850 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "InputAPDUInfo"
905
2014.11.21 11:41:38.850 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "InputAPDU"
906
2014.11.21 11:41:38.850 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "AcceptableStatusCode"
907
2014.11.21 11:41:38.850 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "InputAPDUInfo"
908
2014.11.21 11:41:38.850 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "InputAPDU"
909
2014.11.21 11:41:38.850 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "AcceptableStatusCode"
910
2014.11.21 11:41:38.850 D TransmitParser::parseMessage(core/paos/retrieve/TransmitParser.cpp:34)     : "InputAPDUInfo"
911
2014.11.21 11:41:38.850 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "InputAPDU"
912
2014.11.21 11:41:38.851 D ...mitParser::parseInputApduInfo(core/paos/retrieve/TransmitParser.cpp:70) : "AcceptableStatusCode"
913
2014.11.21 11:41:38.851 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "TRANSMIT"
914
2014.11.21 11:41:38.851 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendDIDAuthenticateResponseEAC2"
915
2014.11.21 11:41:38.851 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendDIDAuthenticateResponseEAC2"
916
2014.11.21 11:41:38.851 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendDIDAuthenticateResponseEAC2" | StepResult: 0
917
2014.11.21 11:41:38.851 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepTransmit"
918
2014.11.21 11:41:38.852 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepTransmit" state 0x40244e8
919
2014.11.21 11:41:38.852 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
920
2014.11.21 11:41:38.852 D StateMachine::initStepUi(core/StateMachine.cpp:204)                        : step's UI type matches previous one; keeping previous one
921
2014.11.21 11:41:38.852 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepTransmit"
922
2014.11.21 11:41:38.852 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepTransmit"
923
2014.11.21 11:41:38.852 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendDIDAuthenticateResponseEAC2"
924
2014.11.21 11:41:38.852 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepTransmit"
925
2014.11.21 11:41:38.857 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0ca4040c1d871101c8fdc392f382fe8af60224d6901422e08e08c3a6e3a5521f7e7400"
926
2014.11.21 11:41:38.912 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
927
2014.11.21 11:41:38.912 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e082c9143e3fe55ec789000"
928
2014.11.21 11:41:38.912 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "8c2080001d8711017e58b4c08f25761fc2dba55ff5a166cc8e08b762029e85b1da1700"
929
2014.11.21 11:41:38.941 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
930
2014.11.21 11:41:38.941 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08cc6660e2c44ec00d9000"
931
2014.11.21 11:41:38.941 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2241a41d8711014afe19ef1dd4d33d9de8caa41feac9928e08e4c463874efe505800"
932
2014.11.21 11:41:38.990 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
933
2014.11.21 11:41:38.990 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08c3f71aa177a3aab09000"
934
2014.11.21 11:41:38.990 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c8600000001428782013101dd4b31f1dd8e38b119858d209c1aeb2d52f81eb963e5e5e4c7eea4f45e37af58b163d2c600b2dbe7da2f81502dd515c1bc66af71156459535fc3a38799dca7933add54976613f9c7f070d3ce3f94edb17490a73fa7b36f9ca13797fe8ff437a72d7fb7a7d27f337d6741449f52fa6461614de62f8c0c27079aabd8d7731ff5413fb1d9aae0cf10a9a0e34e029d630fbabdbe6bde818c83420c48b0ccb90a66d0e880258fe06d85367cbe1cdc840c34a5eaf5164f2d9d544240d1c5400819767bc9bac3db609c3e88209e809a20970e8c78363ef9eae06c0b600d2423a7b8474c4f856313cb1ab0aabc50f91fc3ab4a96304645909432f1450a0c769c49c0667401fa2bbf1d6dd75e3ddab8bd64ce2aead41430f561b87911d5737f591f0eadccbdabecf15ead0221408787c4c34ff1899701248e08a2372287b47531d90000"
935
2014.11.21 11:41:39.242 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
936
2014.11.21 11:41:39.243 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "8731019d61c5ac5e30db1709174e63a31a6dd7e2a66e8ad07dbec92d67755dbcab5c29fc4644c0e4ed096db2fd71f6d7691878990290008e08712b8fe19278f8579000"
937
2014.11.21 11:41:39.243 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c2241a41d87110137d6f6b81d626fa178b99e0b7d6661928e08cdc2bb7515f2952c00"
938
2014.11.21 11:41:39.290 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
939
2014.11.21 11:41:39.290 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "990290008e08ceb092a69363b9909000"
940
2014.11.21 11:41:39.290 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0c86000000014287820131011c6d9b1be973cd735ca599ba53aa5eee792269766b1d2b70a3cb2a1c1be2efeb58f69739ca9a550a65afc7223df0b3b58851a6c5c61270c67a91e950c78cc0ac970b2e47cddf242b08897b3308cf3ba213c70d136ffce2f03067d34c1e6e5f268d9ebbc2675dd4cd99133315c541c6b8829fa542947eeff6f758dc43b176e6735ec66784f8cc5f4ce36a6c77ee7ee37536e6de2370c383ff71586664e02bfdd11fee0446b35fa3dddc8ec80dcf71ecafa552e5aeea2d668999e614447183e890c6ce7f6dceb2ba288aefab142bff3408597db257f8c72ce4d0e2b9919e4ba1c43e6db8c926b5424856d98251f9b7a1e23a146db094c76822355a465b3ba8169a735ae575caf17fbdc1ffc3a478e44b6180893d3c02180aa854eacffe71ec7b6d828067fc33c4efb806d55d117b58b7659701248e083cef26b3aee4cac40000"
941
2014.11.21 11:41:39.542 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
942
2014.11.21 11:41:39.542 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "873101a4e634df3e58e5265423fc0086be78fe24f530810c084c49643c7e70bafda750392b58665668669db8fc79c982d145a3990290008e084d6645a173d7e7269000"
943
2014.11.21 11:41:39.542 D CardController::transmit(card/base/CardController.cpp:336)                 : transmit ende
944
2014.11.21 11:41:39.543 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepTransmit"
945
2014.11.21 11:41:39.543 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepTransmit"
946
2014.11.21 11:41:39.543 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepTransmit" | StepResult: 0
947
2014.11.21 11:41:39.543 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendTransmitResponse"
948
2014.11.21 11:41:39.543 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendTransmitResponse" state 0x4024058
949
2014.11.21 11:41:39.544 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
950
2014.11.21 11:41:39.544 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
951
2014.11.21 11:41:39.544 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendTransmitResponse"
952
2014.11.21 11:41:39.544 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendTransmitResponse"
953
2014.11.21 11:41:39.544 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepTransmit"
954
2014.11.21 11:41:39.544 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendTransmitResponse"
955
2014.11.21 11:41:39.545 W Reader::createCardController(card/base/Reader.cpp:43)                      : SmardCardHandle is already connected.
956
2014.11.21 11:41:39.545 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
957
 "POST /ecardpaos/paosreceiver HTTP/1.1
958
Host: prodpaos.governikus-eid.de
959
User-Agent: AusweisApp2/1.0.0
960
Connection: keep-alive
961
Accept: text/html; application/vnd.paos+xml
962
PAOS: ver="urn:liberty:paos:2006-08"
963
Content-Type: application/vnd.paos+xml; charset=UTF-8
964
Content-Length: 1979
965
requestid: f8241bf1-7858-43f9-ab54-a94187522256
966

    
967
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
968
 <soap:Header>
969
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
970
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
971
   <paos:EndpointReference>
972
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
973
    <paos:MetaData>
974
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
975
    </paos:MetaData>
976
   </paos:EndpointReference>
977
  </paos:PAOS>
978
  <wsa:ReplyTo>
979
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
980
  </wsa:ReplyTo>
981
  <wsa:MessageID>urn:uuid:3c2848bb-5c66-431b-a070-10c36306a8df</wsa:MessageID>
982
 </soap:Header>
983
 <soap:Body>
984
  <TransmitResponse Profile="http://www.bsi.bund.de/ecard/api/1.1" xmlns="urn:iso:std:iso-iec:24727:tech:schema">
985
   <Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
986
    <ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
987
   </Result>
988
   <OutputAPDU>990290008e082c9143e3fe55ec789000</OutputAPDU>
989
   <OutputAPDU>990290008e08cc6660e2c44ec00d9000</OutputAPDU>
990
   <OutputAPDU>990290008e08c3f71aa177a3aab09000</OutputAPDU>
991
   <OutputAPDU>8731019d61c5ac5e30db1709174e63a31a6dd7e2a66e8ad07dbec92d67755dbcab5c29fc4644c0e4ed096db2fd71f6d7691878990290008e08712b8fe19278f8579000</OutputAPDU>
992
   <OutputAPDU>990290008e08ceb092a69363b9909000</OutputAPDU>
993
   <OutputAPDU>873101a4e634df3e58e5265423fc0086be78fe24f530810c084c49643c7e70bafda750392b58665668669db8fc79c982d145a3990290008e084d6645a173d7e7269000</OutputAPDU>
994
  </TransmitResponse>
995
 </soap:Body>
996
</soap:Envelope>
997
"
998
2014.11.21 11:41:39.545 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
999
2014.11.21 11:41:39.545 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
1000
2014.11.21 11:41:39.591 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
1001
2014.11.21 11:41:39.591 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 671
1002
2014.11.21 11:41:39.592 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
1003
2014.11.21 11:41:39.592 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "671"  bytes)
1004
2014.11.21 11:41:39.592 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
1005
2014.11.21 11:41:39.592 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
1006
2014.11.21 11:41:39.592 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
1007
2014.11.21 11:41:39.593 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
1008
2014.11.21 11:41:39.593 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
1009
2014.11.21 11:41:39.593 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
1010
2014.11.21 11:41:39.593 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
1011
2014.11.21 11:41:39.593 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
1012
   <soap:Header>
1013
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id4000" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
1014
   </soap:Header>
1015
   <soap:Body>
1016
   <Disconnect xmlns="urn:iso:std:iso-iec:24727:tech:schema">
1017
<SlotHandle>33393236323631373630</SlotHandle>
1018
</Disconnect>
1019
</soap:Body>
1020
</soap:Envelope>
1021
"
1022
2014.11.21 11:41:39.593 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "5"  bytes)
1023
2014.11.21 11:41:39.593 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
1024
2014.11.21 11:41:39.594 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "DISCONNECT"
1025
2014.11.21 11:41:39.594 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendTransmitResponse"
1026
2014.11.21 11:41:39.594 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendTransmitResponse"
1027
2014.11.21 11:41:39.594 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendTransmitResponse" | StepResult: 3
1028
2014.11.21 11:41:39.594 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepDisconnect"
1029
2014.11.21 11:41:39.595 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepDisconnect" state 0x40243a8
1030
2014.11.21 11:41:39.595 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1031
2014.11.21 11:41:39.595 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1032
2014.11.21 11:41:39.595 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepDisconnect"
1033
2014.11.21 11:41:39.595 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepDisconnect"
1034
2014.11.21 11:41:39.595 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendTransmitResponse"
1035
2014.11.21 11:41:39.595 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepDisconnect"
1036
2014.11.21 11:41:39.595 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepDisconnect"
1037
2014.11.21 11:41:39.595 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepDisconnect"
1038
2014.11.21 11:41:39.596 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepDisconnect" | StepResult: 0
1039
2014.11.21 11:41:39.596 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepSendDisconnectResponse"
1040
2014.11.21 11:41:39.596 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepSendDisconnectResponse" state 0x4024588
1041
2014.11.21 11:41:39.596 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1042
2014.11.21 11:41:39.596 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1043
2014.11.21 11:41:39.596 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepSendDisconnectResponse"
1044
2014.11.21 11:41:39.596 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepSendDisconnectResponse"
1045
2014.11.21 11:41:39.596 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepDisconnect"
1046
2014.11.21 11:41:39.596 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepSendDisconnectResponse"
1047
2014.11.21 11:41:39.597 D HttpClient::sendRequest(core/network/HttpClient.cpp:96)                    : 
1048
 "POST /ecardpaos/paosreceiver HTTP/1.1
1049
Host: prodpaos.governikus-eid.de
1050
User-Agent: AusweisApp2/1.0.0
1051
Connection: keep-alive
1052
Accept: text/html; application/vnd.paos+xml
1053
PAOS: ver="urn:liberty:paos:2006-08"
1054
Content-Type: application/vnd.paos+xml; charset=UTF-8
1055
Content-Length: 1462
1056
requestid: f8241bf1-7858-43f9-ab54-a94187522256
1057

    
1058
<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:paos="urn:liberty:paos:2006-08" xmlns:iso="urn:iso:std:iso-iec:24727:tech:schema" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:ecard="http://www.bsi.bund.de/ecard/api/1.1" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:wsa="http://www.w3.org/2005/03/addressing" xmlns:dss="urn:oasis:names:tc:dss:1.0:core:schema">
1059
 <soap:Header>
1060
  <paos:PAOS soap:actor="http://schemas.xmlsoap.org/soap/actor/next" soap:mustUnderstand="1">
1061
   <paos:Version>urn:liberty:paos:2006-08</paos:Version>
1062
   <paos:EndpointReference>
1063
    <paos:Address>http://www.projectliberty.org/2006/01/role/paos</paos:Address>
1064
    <paos:MetaData>
1065
     <paos:ServiceType>http://www.bsi.bund.de/ecard/api/1.1/PAOS/GetNextCommand</paos:ServiceType>
1066
    </paos:MetaData>
1067
   </paos:EndpointReference>
1068
  </paos:PAOS>
1069
  <wsa:ReplyTo>
1070
   <wsa:Address>http://www.projectliberty.org/2006/02/role/paos</wsa:Address>
1071
  </wsa:ReplyTo>
1072
  <wsa:MessageID>urn:uuid:eb13e0c2-381a-41c9-b9a7-e5cadd9acd72</wsa:MessageID>
1073
 </soap:Header>
1074
 <soap:Body>
1075
  <DisconnectResponse Profile="http://www.bsi.bund.de/ecard/api/1.1" xmlns="urn:iso:std:iso-iec:24727:tech:schema">
1076
   <Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
1077
    <ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
1078
   </Result>
1079
   <SlotHandle>33393236323631373630</SlotHandle>
1080
  </DisconnectResponse>
1081
 </soap:Body>
1082
</soap:Envelope>
1083
"
1084
2014.11.21 11:41:39.597 D GnuTls::doWrite(core/network/GnuTls.cpp:380)                               : Write data over encrypted tunnel
1085
2014.11.21 11:41:39.598 D GnuTls::doWrite(core/network/GnuTls.cpp:385)                               : Write chunk to tunnel
1086
2014.11.21 11:41:39.639 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
1087
2014.11.21 11:41:39.639 D GnuTls::doReadyRead(core/network/GnuTls.cpp:764)                           : Got data over encrypted tunnel | Available: 0
1088
2014.11.21 11:41:39.639 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 831
1089
2014.11.21 11:41:39.640 D GnuTls::doRead(core/network/GnuTls.cpp:427)                                : Try to read chunk: 5
1090
2014.11.21 11:41:39.640 D HttpClient::doDataReceived(core/network/HttpClient.cpp:198)                : Data received ( "836"  bytes)
1091
2014.11.21 11:41:39.640 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Server: Apache-Coyote/1.1
1092
2014.11.21 11:41:39.640 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Security-Policy: default-src 'self'
1093
2014.11.21 11:41:39.640 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Content-Type: application/vnd.paos+xml;charset=ISO-8859-1
1094
2014.11.21 11:41:39.640 D HttpClient::headerFieldCallback(core/network/HttpClient.cpp:167)           : Header | Transfer-Encoding: chunked
1095
2014.11.21 11:41:39.640 D HttpClient::headerCompleteCallback(core/network/HttpClient.cpp:120)        : Header completed: 200
1096
2014.11.21 11:41:39.640 D HttpClient::bodyCallback(core/network/HttpClient.cpp:151)                  : Body completed
1097
2014.11.21 11:41:39.641 D HttpClient::appendToPaosMessage(core/network/HttpClient.cpp:191)           : Append data to paos message: "<?xml version="1.0" encoding="UTF-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">
1098
   <soap:Header>
1099
      <sb:Correlation xmlns:sb="http://urn:liberty:sb:2003-08" messageID="Id4001" refToMessageID="f8241bf1-7858-43f9-ab54-a94187522256"/>
1100
   </soap:Header>
1101
   <soap:Body>
1102
   <StartPAOSResponse Profile="http://www.bsi.bund.de/ecard/api/1.1" xmlns="urn:iso:std:iso-iec:24727:tech:schema">
1103
<Result xmlns="urn:oasis:names:tc:dss:1.0:core:schema">
1104
<ResultMajor>http://www.bsi.bund.de/ecard/api/1.1/resultmajor#ok</ResultMajor>
1105
</Result>
1106
</StartPAOSResponse>
1107
</soap:Body>
1108
</soap:Envelope>
1109
"
1110
2014.11.21 11:41:39.641 D HttpClient::paosMessageComplete(core/network/HttpClient.cpp:109)           : PAOS message seems to be complete
1111
2014.11.21 11:41:39.641 D ...ndReceive::onResponseReceived(core/step/StepGenericSendReceive.cpp:241) : Received PAOS message of type: "STARTPAOS_RESPONSE"
1112
2014.11.21 11:41:39.641 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepSendDisconnectResponse"
1113
2014.11.21 11:41:39.642 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepSendDisconnectResponse"
1114
2014.11.21 11:41:39.642 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepSendDisconnectResponse" | StepResult: 0
1115
2014.11.21 11:41:39.642 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepStartPaosResponse"
1116
2014.11.21 11:41:39.642 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepStartPaosResponse" state 0x4024548
1117
2014.11.21 11:41:39.642 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1118
2014.11.21 11:41:39.642 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1119
2014.11.21 11:41:39.642 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepStartPaosResponse"
1120
2014.11.21 11:41:39.642 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepStartPaosResponse"
1121
2014.11.21 11:41:39.642 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepSendDisconnectResponse"
1122
2014.11.21 11:41:39.643 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepStartPaosResponse"
1123
2014.11.21 11:41:39.643 D PcscCard::disconnectCard(card/pcsc/PcscCard.cpp:157)                       : SCardEndTransaction for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1124
2014.11.21 11:41:39.707 D PcscCard::disconnectCard(card/pcsc/PcscCard.cpp:162)                       : SCardDisconnect for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1125
2014.11.21 11:41:39.707 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepStartPaosResponse"
1126
2014.11.21 11:41:39.707 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepStartPaosResponse"
1127
2014.11.21 11:41:39.707 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepStartPaosResponse" | StepResult: 0
1128
2014.11.21 11:41:39.708 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepShutdown"
1129
2014.11.21 11:41:39.708 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepShutdown" state 0x4024578
1130
2014.11.21 11:41:39.708 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1131
2014.11.21 11:41:39.708 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1132
2014.11.21 11:41:39.708 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepShutdown"
1133
2014.11.21 11:41:39.708 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepShutdown"
1134
2014.11.21 11:41:39.708 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepStartPaosResponse"
1135
2014.11.21 11:41:39.708 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepShutdown"
1136
2014.11.21 11:41:39.708 D GnuTls::disconnectFromHost(core/network/GnuTls.cpp:623)                    : Disconnect from host
1137
2014.11.21 11:41:39.710 D GnuTls::doStateChanged(core/network/GnuTls.cpp:790)                        : State: QAbstractSocket::ClosingState
1138
2014.11.21 11:41:39.710 D GnuTls::doStateChanged(core/network/GnuTls.cpp:790)                        : State: QAbstractSocket::UnconnectedState
1139
2014.11.21 11:41:39.710 D GnuTls::clearSession(core/network/GnuTls.cpp:668)                          : Clear session
1140
2014.11.21 11:41:39.710 D GnuTls::clearPskCredentials(core/network/GnuTls.cpp:643)                   : Clear credentials
1141
2014.11.21 11:41:39.710 D GnuTls::clearPskCredentials(core/network/GnuTls.cpp:650)                   : Clear credentials certificate
1142
2014.11.21 11:41:39.712 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepShutdown"
1143
2014.11.21 11:41:39.712 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepShutdown"
1144
2014.11.21 11:41:39.712 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepShutdown" | StepResult: 0
1145
2014.11.21 11:41:39.712 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepCheckRefreshAddress"
1146
2014.11.21 11:41:39.712 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepCheckRefreshAddress" state 0x4024598
1147
2014.11.21 11:41:39.713 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1148
2014.11.21 11:41:39.713 D StateMachine::initStepUi(core/StateMachine.cpp:204)                        : step's UI type matches previous one; keeping previous one
1149
2014.11.21 11:41:39.713 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepCheckRefreshAddress"
1150
2014.11.21 11:41:39.713 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepCheckRefreshAddress"
1151
2014.11.21 11:41:39.713 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepShutdown"
1152
2014.11.21 11:41:39.713 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepCheckRefreshAddress"
1153
2014.11.21 11:41:39.713 D StepCheckRefreshAddress::run(core/step/StepCheckRefreshAddress.cpp:55)     : Current URL:  "https://www.sixform.com:443/ID-Safe/success/login?refID=17019c67-0479-41a8-87b0-2a77166fe2d6"
1154
2014.11.21 11:41:39.713 D StepCheckRefreshAddress::run(core/step/StepCheckRefreshAddress.cpp:58)     : SubjectUrl:  "https://www.sixform.com"
1155
2014.11.21 11:41:39.714 D UrlUtil::isMatchingSameOriginPolicy(core/network/UrlUtil.cpp:133)          : SOP-Check( "https://www.sixform.com:443" , "https://www.sixform.com:443" )= true
1156
2014.11.21 11:41:39.714 D StepCheckRefreshAddress::run(core/step/StepCheckRefreshAddress.cpp:62)     : SOP-Check succeeded, abort process
1157
2014.11.21 11:41:39.849 D ...hAddress::onSslHandshakeDone(core/step/StepCheckRefreshAddress.cpp:241) : SSL handshake for getting the server certificate done
1158
2014.11.21 11:41:39.850 D ...hAddress::onSslHandshakeDone(core/step/StepCheckRefreshAddress.cpp:242) : QSslCipher(name= DHE-RSA-AES256-GCM-SHA384 , bits= 256 , proto= TLSv1.2 )
1159
2014.11.21 11:41:39.857 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:29)       : Check certificate CN= ("www.sixform.com") SN= "2e:7d:6e:67:26:d7:be:84"
1160
2014.11.21 11:41:39.857 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:31)       : Certificate hash( "SHA256" ) "63317224e931a55c91406a98a65fbf2d3de9b3d1b6fed62e80a4049c841731f9"
1161
2014.11.21 11:41:39.858 D CertificateChecker::checkCertificate(core/CertificateChecker.cpp:32)       : Accepted certificate hashes QSet("DB37C8E02D6D715EFBFB819D9620C0D411BB6D5F8000200148FFCFA3467F7158", "9D8EB0BDF36B19C4AF3147E57401FD792845F0413102A7BD784DF9418098BEBE", "63317224E931A55C91406A98A65FBF2D3DE9B3D1B6FED62E80A4049C841731F9", "EBD2A9610AA53AE1C159B2C7B238451E2C6AF06F7034723BD4B9743196E6A720", "29F04459C39E4B68C70AA3961FA7B1B40E8A49238446CFE606C56FF8DC0989F4")
1162
2014.11.21 11:41:39.858 D AuthModel::addCertificateData(core/model/AuthModel.h:123)                  : Adding certificate CN= ("www.sixform.com") SN= "2e:7d:6e:67:26:d7:be:84"
1163
2014.11.21 11:41:39.858 D ...kRefreshAddress::doneSuccess(core/step/StepCheckRefreshAddress.cpp:230) : Determined RefreshUrl:   QUrl( "https://www.sixform.com:443/ID-Safe/success/login?refID=17019c67-0479-41a8-87b0-2a77166fe2d6" ) 
1164
2014.11.21 11:41:39.860 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepCheckRefreshAddress"
1165
2014.11.21 11:41:39.860 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepCheckRefreshAddress"
1166
2014.11.21 11:41:39.860 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepCheckRefreshAddress" | StepResult: 0
1167
2014.11.21 11:41:39.860 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepWriteHistory"
1168
2014.11.21 11:41:39.860 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepWriteHistory" state 0x4024388
1169
2014.11.21 11:41:39.860 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1170
2014.11.21 11:41:39.861 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1171
2014.11.21 11:41:39.861 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepWriteHistory"
1172
2014.11.21 11:41:39.861 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepWriteHistory"
1173
2014.11.21 11:41:39.861 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepCheckRefreshAddress"
1174
2014.11.21 11:41:39.861 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepWriteHistory"
1175
2014.11.21 11:41:39.863 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepWriteHistory"
1176
2014.11.21 11:41:39.863 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepWriteHistory"
1177
2014.11.21 11:41:39.864 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepWriteHistory" | StepResult: 0
1178
2014.11.21 11:41:39.864 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepRedirectBrowser"
1179
2014.11.21 11:41:39.864 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepRedirectBrowser" state 0x4024568
1180
2014.11.21 11:41:39.864 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1181
2014.11.21 11:41:39.864 D StateMachine::initStepUi(core/StateMachine.cpp:204)                        : step's UI type matches previous one; keeping previous one
1182
2014.11.21 11:41:39.864 D AuthModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepRedirectBrowser"
1183
2014.11.21 11:41:39.864 D AuthModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepRedirectBrowser"
1184
2014.11.21 11:41:39.864 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepWriteHistory"
1185
2014.11.21 11:41:39.864 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepRedirectBrowser"
1186
2014.11.21 11:41:39.865 D ...rectBrowser::sendRedirectRequest(core/step/StepRedirectBrowser.cpp:137) : Redirect URL:  QUrl( "https://www.sixform.com:443/ID-Safe/success/login?refID=17019c67-0479-41a8-87b0-2a77166fe2d6&ResultMajor=ok" ) 
1187
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepRedirectBrowser"
1188
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepRedirectBrowser"
1189
2014.11.21 11:41:39.865 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepRedirectBrowser" | StepResult: 0
1190
2014.11.21 11:41:39.865 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepCheckError"
1191
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepCheckError" state 0x40245a8
1192
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1193
2014.11.21 11:41:39.865 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1194
2014.11.21 11:41:39.865 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepCheckError"
1195
2014.11.21 11:41:39.865 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepCheckError"
1196
2014.11.21 11:41:39.865 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepRedirectBrowser"
1197
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepCheckError"
1198
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepCheckError"
1199
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepCheckError"
1200
2014.11.21 11:41:39.865 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepCheckError" | StepResult: 0
1201
2014.11.21 11:41:39.865 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepAdviseUserToRemoveCard"
1202
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepAdviseUserToRemoveCard" state 0x40245c8
1203
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1204
2014.11.21 11:41:39.865 D StateMachine::initStepUi(core/StateMachine.cpp:216)                        : step declares UI "governikus::StepAdviseUserToRemoveCardUi"  (previous:  governikus::StepAuthenticationEac1Gui ); creating new one
1205
2014.11.21 11:41:39.865 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepAdviseUserToRemoveCard"
1206
2014.11.21 11:41:39.865 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepAdviseUserToRemoveCard"
1207
2014.11.21 11:41:39.865 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepCheckError"
1208
2014.11.21 11:41:39.865 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepAdviseUserToRemoveCard"
1209
2014.11.21 11:41:40.044 D PcscReader::update(card/pcsc/PcscReader.cpp:271)                           : 
1210
  old state:  "(0x90122) CHANGED PRESENT INUSE" 
1211
  new state:  "(0x90022) CHANGED PRESENT"
1212
2014.11.21 11:41:40.044 D Reader::createCardController(card/base/Reader.cpp:47)                      : Connect to card in reader  "REINER SCT cyberJack RFID basis 0"
1213
2014.11.21 11:41:40.044 D PcscCard::connectCard(card/pcsc/PcscCard.cpp:123)                          : "SCardConnect(cd010003, R, 2, 3, 0, 0)"
1214
2014.11.21 11:41:40.049 D PcscCard::connectCard(card/pcsc/PcscCard.cpp:131)                          : SCardConnect for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"  cardHandle:  3926327296  protocol: T 1
1215
2014.11.21 11:41:40.049 D PcscCard::connectCard(card/pcsc/PcscCard.cpp:138)                          : SCardBeginTransaction for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1216
2014.11.21 11:41:40.049 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "00a4020c02011c"
1217
2014.11.21 11:41:40.075 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1218
2014.11.21 11:41:40.075 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
1219
2014.11.21 11:41:40.075 D PcscCard::transmit(card/pcsc/PcscCard.cpp:174)                             : SCardTransmit cmdBuffer  "0022c1a412800a04007f0007020204020283010384010d"
1220
2014.11.21 11:41:40.128 D PcscCard::transmit(card/pcsc/PcscCard.cpp:182)                             : SCardTransmit for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1221
2014.11.21 11:41:40.128 D PcscCard::transmit(card/pcsc/PcscCard.cpp:242)                             : SCardTransmit resBuffer  "9000"
1222
2014.11.21 11:41:40.128 D CardController::getRetryCounter(card/base/CardController.cpp:154)          : StatusCode:  "SUCCESS"
1223
2014.11.21 11:41:40.128 D PcscReader::updateRetryCounterIfNecessary(card/pcsc/PcscReader.cpp:208)    : retrieved retry counter: 3 , was: 3
1224
2014.11.21 11:41:40.128 D PcscCard::disconnectCard(card/pcsc/PcscCard.cpp:157)                       : SCardEndTransaction for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1225
2014.11.21 11:41:40.190 D PcscCard::disconnectCard(card/pcsc/PcscCard.cpp:162)                       : SCardDisconnect for  "REINER SCT cyberJack RFID basis 0"  :  "SCARD_S_SUCCESS"
1226
2014.11.21 11:41:40.190 D PcscReader::update(card/pcsc/PcscReader.cpp:338)                           : fireCardAccessRightsChanged
1227
2014.11.21 11:41:44.535 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepAdviseUserToRemoveCard"
1228
2014.11.21 11:41:44.536 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepAdviseUserToRemoveCard"
1229
2014.11.21 11:41:44.536 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepAdviseUserToRemoveCard" | StepResult: 0
1230
2014.11.21 11:41:44.536 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepAuthenticationDone"
1231
2014.11.21 11:41:44.536 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepAuthenticationDone" state 0x40245d8
1232
2014.11.21 11:41:44.536 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1233
2014.11.21 11:41:44.536 D StateMachine::initStepUi(core/StateMachine.cpp:216)                        : step declares UI "governikus::StepAuthenticationDoneUi"  (previous:  governikus::StepAdviseUserToRemoveCardGui ); creating new one
1234
2014.11.21 11:41:44.537 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepAuthenticationDone"
1235
2014.11.21 11:41:44.537 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepAuthenticationDone"
1236
2014.11.21 11:41:44.537 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepAdviseUserToRemoveCard"
1237
2014.11.21 11:41:44.537 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepAuthenticationDone"
1238
2014.11.21 11:41:44.559 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepAuthenticationDone"
1239
2014.11.21 11:41:44.559 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepAuthenticationDone"
1240
2014.11.21 11:41:44.559 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepAuthenticationDone" | StepResult: 0
1241
2014.11.21 11:41:44.559 D StateMachine::transitionFunction(core/StateMachine.cpp:172)                : Next state: "governikus::StepStopMachine"
1242
2014.11.21 11:41:44.559 D StateMachine::onTransition(core/StateMachine.cpp:96)                       : Set up next step "StepStopMachine" state 0x40244b8
1243
2014.11.21 11:41:44.560 D StateMachine::onTransition(core/StateMachine.cpp:102)                      : mStepModel: true
1244
2014.11.21 11:41:44.560 D StateMachine::initStepUi(core/StateMachine.cpp:189)                        : step declares no UI; keeping previous one
1245
2014.11.21 11:41:44.560 D StepModel](core/controller/GenericStepController.h:57)                     : Initialize Step "StepStopMachine"
1246
2014.11.21 11:41:44.560 D StepModel](core/controller/GenericStepController.h:61)                     : Initialized Step "StepStopMachine"
1247
2014.11.21 11:41:44.560 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepAuthenticationDone"
1248
2014.11.21 11:41:44.560 D StateMachine::onTransition(core/StateMachine.cpp:126)                      : Perform next step "StepStopMachine"
1249
2014.11.21 11:41:44.560 D StepStopMachine::run(core/step/StepStopMachine.cpp:23)                     : "StepStopMachine"
1250
2014.11.21 11:41:44.560 D StateMachine::onTransition(core/StateMachine.cpp:66)                       : Clean up previous step  "StepStopMachine"
1251
2014.11.21 11:41:44.560 D StateMachine::onTransition(core/StateMachine.cpp:72)                       : Cleaned up previous step  "StepStopMachine"
1252
2014.11.21 11:41:44.560 D StateMachine::transitionFunction(core/StateMachine.cpp:160)                : State: "governikus::StepStopMachine" | StepResult: -1
1253
2014.11.21 11:41:44.560 D StateMachine::transitionFunction(core/StateMachine.cpp:164)                : Final state.  Suspending state machine.
1254
2014.11.21 11:41:44.560 D StateMachine::onTransition(core/StateMachine.cpp:88)                       : Suspend state machine
1255
2014.11.21 11:41:44.560 D StateMachine::onTransition(core/StateMachine.cpp:90)                       : State machine suspended
1256
2014.11.21 11:41:44.560 D StepController::~StepController(core/controller/StepController.cpp:30)     : "StepStopMachine"
1257
2014.11.21 11:41:44.560 D ...ntroller::onActiveControllerDone(core/controller/AppController.cpp:282) : governikus::AuthController done
1258
2014.11.21 11:41:44.570 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
1259
2014.11.21 11:41:44.570 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
1260
2014.11.21 11:41:44.570 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:99)           : Free key
1261
2014.11.21 11:41:44.570 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
1262
2014.11.21 11:41:44.570 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
1263
2014.11.21 11:41:44.570 D EcUtil::create::<lambda(card/base/pace/ec/EcUtil.h:135)       : Clear and free ecdsa signature
1264
2014.11.21 11:41:50.238 D PcscReader::update(card/pcsc/PcscReader.cpp:271)                           : 
1265
  old state:  "(0x90022) CHANGED PRESENT" 
1266
  new state:  "(0x90422) CHANGED PRESENT UNPOWERED"
    (1-1/1)