[teiid-issues] [JBoss JIRA] (TEIID-4499) OData Kerberos cannot access VDB
Jan Stastny (JIRA)
issues at jboss.org
Wed Nov 2 10:07:01 EDT 2016
[ https://issues.jboss.org/browse/TEIID-4499?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13316104#comment-13316104 ]
Jan Stastny commented on TEIID-4499:
------------------------------------
Added a logger for that level and category
{code:plain}
14:54:26,905 WARN [org.jboss.as.dependency.deprecated] (MSC service thread 1-7) JBAS015980: Deployment "deployment.teiid-odata-kerberos-1.0.war" is using a deprecated module ("org.jboss.security.negotiation:main") which may be removed in future versions without notice.
14:54:26,961 INFO [org.jboss.web] (ServerService Thread Pool -- 18) JBAS018210: Register web context: /odata4
14:54:27,003 INFO [org.jboss.as.server] (management-handler-thread - 2) JBAS015859: Deployed "teiid-odata-kerberos-1.0.war" (runtime-name : "teiid-odata-kerberos-1.0.war")
14:54:27,009 INFO [org.jboss.as.protocol] (Remoting "dhcp-10-40-4-185:MANAGEMENT" task-11) JBAS012119: cancelled task by interrupting thread Thread[management-handler-thread - 2,5,management-handler-thread]
14:54:28,095 TRACE [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) Authenticating user
14:54:28,096 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) Header - null
14:54:28,097 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) No Authorization Header, initiating negotiation
14:54:28,652 TRACE [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) Authenticating user
14:54:28,652 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) Header - Negotiate YIIE4AYGKwYBBQUCoIIE1DCCBNCgDTALBgkqhkiG9xIBAgKhBAMCAfaiggS3BIIEs2CCBK8GCSqGSIb3EgECAgEAboIEnjCCBJqgAwIBBaEDAgEOogcDBQAgAAAAo4IBIGGCARwwggEYoAMCAQWhGxsZTVcuTEFCLkVORy5CT1MuUkVESEFULkNPTaIcMBqgAwIBAKETMBEbBEhUVFAbCWxvY2FsaG9zdKOB1TCB0qADAgERoQMCAQSigcUEgcLpK2K0yeBE8wil774Yfen6PChB6lqlmn+rPPDph5FFCY7ryBG3+bAjabVQ+EoeHQ4IS9z6Frr1mlEKPshND+TaqEV9BN7fzdJXZjH7mF5cKqbhyGsVTHo60L0V/dGul3w1Okp2jX7A22zN9Q08Eyptqz42eynkQvAfK27m/e+0CeOsETdbbQzRbvmPITv1093BwvfuWjfvtUv3lfBhRp79oJkyhrCSfHfpVe2arcFX0tGs2Nzp2I0m9D6C+tReFAo0yaSCA18wggNboAMCARGiggNSBIIDTtNxI1hLXDIhcgbtcKiIWqRUZI4hDkpKfJddkW3u08NGCQ6ghZyK97E8adcYLER05OcOzN6PWr5bR6QXEolFqgii/nuM9pK6VjQ0KfC4U5RMGdz2+8RAroS+wQdEtjGK698C1Q8VE+XA3OQngi0VnyGHp4KoQIIRN5UDzwCLZ6UvV5P4T/IoiT93/6PylGdngT3oLmSEnDw2EUpxZnLbOKoJyPa6oZ5xXPIgwawqpF5KHG/SMB1k61zDsAtJfdB1XjqEhWCgPGNRfP7tdHlnL/OVw7bbk2tzqvJ2B9ZR5voD3GOsTtMBGe5ADaxnV/qg3RdQzHIf0kgINyniU6d02M+m8yM/mLoYVp4TJGPJUv24pE2FsuelEAiEgTNnufCCEYFCKbKGDUqc6x7tYUq4KFGUXCRAagO21tRYX4nmcXCsONwaKQL8gItgCMEwX9Zs3xbMeShRpIsGoMVHJjhKLNqFYW31O1ruXYyRhsycE47NCaH/1hZyUS5xznaZbf38zoA2YceZ+GJXSRPe3DGYFFotdmStJ3sQihuJ/SuLQ1AWqvlhMHGHO0ARR6PPbLtWRWuhgzsGhbspbQ4giBonuL3BYyVcbp73aF0rBts3acEBCTDnr8ypAZmXX0SsqzYhmsYBXC2x2UW8ZuxXWI4xaxVoaUdfvQ8YZyz0Icev6p+SV6YptiTBpXkzpDo1cW7R6DFINdvvVACYrlViB5SibxM5VHXtLqHeGFdJjEni9pQELTNDvn3xqVRXDxn5spSxDIrHmxXjp8Z7CViUw+ryBGk3h22CFFNc1UO2lQJrWx+AMCDLAaKFQM7FQM4sVQRooKoppPRyGYH/Ast4wNZfMkvpnZ8e2KobnSPqOZDCiB0gMPh7K2pe9Rnhpu4S47/sPA5dnrQH17EACXaRQ+ZQTOguHw9+BTOLwt0yXC+GYXf6gkVmEM1E2LX8xsC5jsrdDpYxGQ/HJU/GK/oS9FHbLOmMxJbx7z46oFljmRILUAPm56I6dcLWYWncRxtV8hi5HVBrKi+58K81PY+ELUhrXe/vhMW8bejSnXK2cYGH+bp0IF1ttcCsqlcWkCF/Ta7DKCVwPZsv0j2WomJ33viTekjOFbjb2HGiBjCJbVjZMw==
14:54:28,660 TRACE [org.jboss.security.negotiation.common.MessageTrace.Request.Base64] (http-127.0.0.1:8080-1) YIIE4AYGKwYBBQUCoIIE1DCCBNCgDTALBgkqhkiG9xIBAgKhBAMCAfaiggS3BIIEs2CCBK8GCSqGSIb3EgECAgEAboIEnjCCBJqgAwIBBaEDAgEOogcDBQAgAAAAo4IBIGGCARwwggEYoAMCAQWhGxsZTVcuTEFCLkVORy5CT1MuUkVESEFULkNPTaIcMBqgAwIBAKETMBEbBEhUVFAbCWxvY2FsaG9zdKOB1TCB0qADAgERoQMCAQSigcUEgcLpK2K0yeBE8wil774Yfen6PChB6lqlmn+rPPDph5FFCY7ryBG3+bAjabVQ+EoeHQ4IS9z6Frr1mlEKPshND+TaqEV9BN7fzdJXZjH7mF5cKqbhyGsVTHo60L0V/dGul3w1Okp2jX7A22zN9Q08Eyptqz42eynkQvAfK27m/e+0CeOsETdbbQzRbvmPITv1093BwvfuWjfvtUv3lfBhRp79oJkyhrCSfHfpVe2arcFX0tGs2Nzp2I0m9D6C+tReFAo0yaSCA18wggNboAMCARGiggNSBIIDTtNxI1hLXDIhcgbtcKiIWqRUZI4hDkpKfJddkW3u08NGCQ6ghZyK97E8adcYLER05OcOzN6PWr5bR6QXEolFqgii/nuM9pK6VjQ0KfC4U5RMGdz2+8RAroS+wQdEtjGK698C1Q8VE+XA3OQngi0VnyGHp4KoQIIRN5UDzwCLZ6UvV5P4T/IoiT93/6PylGdngT3oLmSEnDw2EUpxZnLbOKoJyPa6oZ5xXPIgwawqpF5KHG/SMB1k61zDsAtJfdB1XjqEhWCgPGNRfP7tdHlnL/OVw7bbk2tzqvJ2B9ZR5voD3GOsTtMBGe5ADaxnV/qg3RdQzHIf0kgINyniU6d02M+m8yM/mLoYVp4TJGPJUv24pE2FsuelEAiEgTNnufCCEYFCKbKGDUqc6x7tYUq4KFGUXCRAagO21tRYX4nmcXCsONwaKQL8gItgCMEwX9Zs3xbMeShRpIsGoMVHJjhKLNqFYW31O1ruXYyRhsycE47NCaH/1hZyUS5xznaZbf38zoA2YceZ+GJXSRPe3DGYFFotdmStJ3sQihuJ/SuLQ1AWqvlhMHGHO0ARR6PPbLtWRWuhgzsGhbspbQ4giBonuL3BYyVcbp73aF0rBts3acEBCTDnr8ypAZmXX0SsqzYhmsYBXC2x2UW8ZuxXWI4xaxVoaUdfvQ8YZyz0Icev6p+SV6YptiTBpXkzpDo1cW7R6DFINdvvVACYrlViB5SibxM5VHXtLqHeGFdJjEni9pQELTNDvn3xqVRXDxn5spSxDIrHmxXjp8Z7CViUw+ryBGk3h22CFFNc1UO2lQJrWx+AMCDLAaKFQM7FQM4sVQRooKoppPRyGYH/Ast4wNZfMkvpnZ8e2KobnSPqOZDCiB0gMPh7K2pe9Rnhpu4S47/sPA5dnrQH17EACXaRQ+ZQTOguHw9+BTOLwt0yXC+GYXf6gkVmEM1E2LX8xsC5jsrdDpYxGQ/HJU/GK/oS9FHbLOmMxJbx7z46oFljmRILUAPm56I6dcLWYWncRxtV8hi5HVBrKi+58K81PY+ELUhrXe/vhMW8bejSnXK2cYGH+bp0IF1ttcCsqlcWkCF/Ta7DKCVwPZsv0j2WomJ33viTekjOFbjb2HGiBjCJbVjZMw==
14:54:28,661 TRACE [org.jboss.security.negotiation.common.MessageTrace.Request.Hex] (http-127.0.0.1:8080-1) 0x60 0x82 0x04 0xe0 0x06 0x06 0x2b 0x06 0x01 0x05 0x05 0x02 0xa0 0x82 0x04 0xd4 0x30 0x82 0x04 0xd0 0xa0 0x0d 0x30 0x0b 0x06 0x09 0x2a 0x86 0x48 0x86 0xf7 0x12 0x01 0x02 0x02 0xa1 0x04 0x03 0x02 0x01 0xf6 0xa2 0x82 0x04 0xb7 0x04 0x82 0x04 0xb3 0x60 0x82 0x04 0xaf 0x06 0x09 0x2a 0x86 0x48 0x86 0xf7 0x12 0x01 0x02 0x02 0x01 0x00 0x6e 0x82 0x04 0x9e 0x30 0x82 0x04 0x9a 0xa0 0x03 0x02 0x01 0x05 0xa1 0x03 0x02 0x01 0x0e 0xa2 0x07 0x03 0x05 0x00 0x20 0x00 0x00 0x00 0xa3 0x82 0x01 0x20 0x61 0x82 0x01 0x1c 0x30 0x82 0x01 0x18 0xa0 0x03 0x02 0x01 0x05 0xa1 0x1b 0x1b 0x19 0x4d 0x57 0x2e 0x4c 0x41 0x42 0x2e 0x45 0x4e 0x47 0x2e 0x42 0x4f 0x53 0x2e 0x52 0x45 0x44 0x48 0x41 0x54 0x2e 0x43 0x4f 0x4d 0xa2 0x1c 0x30 0x1a 0xa0 0x03 0x02 0x01 0x00 0xa1 0x13 0x30 0x11 0x1b 0x04 0x48 0x54 0x54 0x50 0x1b 0x09 0x6c 0x6f 0x63 0x61 0x6c 0x68 0x6f 0x73 0x74 0xa3 0x81 0xd5 0x30 0x81 0xd2 0xa0 0x03 0x02 0x01 0x11 0xa1 0x03 0x02 0x01 0x04 0xa2 0x81 0xc5 0x04 0x81 0xc2 0xe9 0x2b 0x62 0xb4 0xc9 0xe0 0x44 0xf3 0x08 0xa5 0xef 0xbe 0x18 0x7d 0xe9 0xfa 0x3c 0x28 0x41 0xea 0x5a 0xa5 0x9a 0x7f 0xab 0x3c 0xf0 0xe9 0x87 0x91 0x45 0x09 0x8e 0xeb 0xc8 0x11 0xb7 0xf9 0xb0 0x23 0x69 0xb5 0x50 0xf8 0x4a 0x1e 0x1d 0x0e 0x08 0x4b 0xdc 0xfa 0x16 0xba 0xf5 0x9a 0x51 0x0a 0x3e 0xc8 0x4d 0x0f 0xe4 0xda 0xa8 0x45 0x7d 0x04 0xde 0xdf 0xcd 0xd2 0x57 0x66 0x31 0xfb 0x98 0x5e 0x5c 0x2a 0xa6 0xe1 0xc8 0x6b 0x15 0x4c 0x7a 0x3a 0xd0 0xbd 0x15 0xfd 0xd1 0xae 0x97 0x7c 0x35 0x3a 0x4a 0x76 0x8d 0x7e 0xc0 0xdb 0x6c 0xcd 0xf5 0x0d 0x3c 0x13 0x2a 0x6d 0xab 0x3e 0x36 0x7b 0x29 0xe4 0x42 0xf0 0x1f 0x2b 0x6e 0xe6 0xfd 0xef 0xb4 0x09 0xe3 0xac 0x11 0x37 0x5b 0x6d 0x0c 0xd1 0x6e 0xf9 0x8f 0x21 0x3b 0xf5 0xd3 0xdd 0xc1 0xc2 0xf7 0xee 0x5a 0x37 0xef 0xb5 0x4b 0xf7 0x95 0xf0 0x61 0x46 0x9e 0xfd 0xa0 0x99 0x32 0x86 0xb0 0x92 0x7c 0x77 0xe9 0x55 0xed 0x9a 0xad 0xc1 0x57 0xd2 0xd1 0xac 0xd8 0xdc 0xe9 0xd8 0x8d 0x26 0xf4 0x3e 0x82 0xfa 0xd4 0x5e 0x14 0x0a 0x34 0xc9 0xa4 0x82 0x03 0x5f 0x30 0x82 0x03 0x5b 0xa0 0x03 0x02 0x01 0x11 0xa2 0x82 0x03 0x52 0x04 0x82 0x03 0x4e 0xd3 0x71 0x23 0x58 0x4b 0x5c 0x32 0x21 0x72 0x06 0xed 0x70 0xa8 0x88 0x5a 0xa4 0x54 0x64 0x8e 0x21 0x0e 0x4a 0x4a 0x7c 0x97 0x5d 0x91 0x6d 0xee 0xd3 0xc3 0x46 0x09 0x0e 0xa0 0x85 0x9c 0x8a 0xf7 0xb1 0x3c 0x69 0xd7 0x18 0x2c 0x44 0x74 0xe4 0xe7 0x0e 0xcc 0xde 0x8f 0x5a 0xbe 0x5b 0x47 0xa4 0x17 0x12 0x89 0x45 0xaa 0x08 0xa2 0xfe 0x7b 0x8c 0xf6 0x92 0xba 0x56 0x34 0x34 0x29 0xf0 0xb8 0x53 0x94 0x4c 0x19 0xdc 0xf6 0xfb 0xc4 0x40 0xae 0x84 0xbe 0xc1 0x07 0x44 0xb6 0x31 0x8a 0xeb 0xdf 0x02 0xd5 0x0f 0x15 0x13 0xe5 0xc0 0xdc 0xe4 0x27 0x82 0x2d 0x15 0x9f 0x21 0x87 0xa7 0x82 0xa8 0x40 0x82 0x11 0x37 0x95 0x03 0xcf 0x00 0x8b 0x67 0xa5 0x2f 0x57 0x93 0xf8 0x4f 0xf2 0x28 0x89 0x3f 0x77 0xff 0xa3 0xf2 0x94 0x67 0x67 0x81 0x3d 0xe8 0x2e 0x64 0x84 0x9c 0x3c 0x36 0x11 0x4a 0x71 0x66 0x72 0xdb 0x38 0xaa 0x09 0xc8 0xf6 0xba 0xa1 0x9e 0x71 0x5c 0xf2 0x20 0xc1 0xac 0x2a 0xa4 0x5e 0x4a 0x1c 0x6f 0xd2 0x30 0x1d 0x64 0xeb 0x5c 0xc3 0xb0 0x0b 0x49 0x7d 0xd0 0x75 0x5e 0x3a 0x84 0x85 0x60 0xa0 0x3c 0x63 0x51 0x7c 0xfe 0xed 0x74 0x79 0x67 0x2f 0xf3 0x95 0xc3 0xb6 0xdb 0x93 0x6b 0x73 0xaa 0xf2 0x76 0x07 0xd6 0x51 0xe6 0xfa 0x03 0xdc 0x63 0xac 0x4e 0xd3 0x01 0x19 0xee 0x40 0x0d 0xac 0x67 0x57 0xfa 0xa0 0xdd 0x17 0x50 0xcc 0x72 0x1f 0xd2 0x48 0x08 0x37 0x29 0xe2 0x53 0xa7 0x74 0xd8 0xcf 0xa6 0xf3 0x23 0x3f 0x98 0xba 0x18 0x56 0x9e 0x13 0x24 0x63 0xc9 0x52 0xfd 0xb8 0xa4 0x4d 0x85 0xb2 0xe7 0xa5 0x10 0x08 0x84 0x81 0x33 0x67 0xb9 0xf0 0x82 0x11 0x81 0x42 0x29 0xb2 0x86 0x0d 0x4a 0x9c 0xeb 0x1e 0xed 0x61 0x4a 0xb8 0x28 0x51 0x94 0x5c 0x24 0x40 0x6a 0x03 0xb6 0xd6 0xd4 0x58 0x5f 0x89 0xe6 0x71 0x70 0xac 0x38 0xdc 0x1a 0x29 0x02 0xfc 0x80 0x8b 0x60 0x08 0xc1 0x30 0x5f 0xd6 0x6c 0xdf 0x16 0xcc 0x79 0x28 0x51 0xa4 0x8b 0x06 0xa0 0xc5 0x47 0x26 0x38 0x4a 0x2c 0xda 0x85 0x61 0x6d 0xf5 0x3b 0x5a 0xee 0x5d 0x8c 0x91 0x86 0xcc 0x9c 0x13 0x8e 0xcd 0x09 0xa1 0xff 0xd6 0x16 0x72 0x51 0x2e 0x71 0xce 0x76 0x99 0x6d 0xfd 0xfc 0xce 0x80 0x36 0x61 0xc7 0x99 0xf8 0x62 0x57 0x49 0x13 0xde 0xdc 0x31 0x98 0x14 0x5a 0x2d 0x76 0x64 0xad 0x27 0x7b 0x10 0x8a 0x1b 0x89 0xfd 0x2b 0x8b 0x43 0x50 0x16 0xaa 0xf9 0x61 0x30 0x71 0x87 0x3b 0x40 0x11 0x47 0xa3 0xcf 0x6c 0xbb 0x56 0x45 0x6b 0xa1 0x83 0x3b 0x06 0x85 0xbb 0x29 0x6d 0x0e 0x20 0x88 0x1a 0x27 0xb8 0xbd 0xc1 0x63 0x25 0x5c 0x6e 0x9e 0xf7 0x68 0x5d 0x2b 0x06 0xdb 0x37 0x69 0xc1 0x01 0x09 0x30 0xe7 0xaf 0xcc 0xa9 0x01 0x99 0x97 0x5f 0x44 0xac 0xab 0x36 0x21 0x9a 0xc6 0x01 0x5c 0x2d 0xb1 0xd9 0x45 0xbc 0x66 0xec 0x57 0x58 0x8e 0x31 0x6b 0x15 0x68 0x69 0x47 0x5f 0xbd 0x0f 0x18 0x67 0x2c 0xf4 0x21 0xc7 0xaf 0xea 0x9f 0x92 0x57 0xa6 0x29 0xb6 0x24 0xc1 0xa5 0x79 0x33 0xa4 0x3a 0x35 0x71 0x6e 0xd1 0xe8 0x31 0x48 0x35 0xdb 0xef 0x54 0x00 0x98 0xae 0x55 0x62 0x07 0x94 0xa2 0x6f 0x13 0x39 0x54 0x75 0xed 0x2e 0xa1 0xde 0x18 0x57 0x49 0x8c 0x49 0xe2 0xf6 0x94 0x04 0x2d 0x33 0x43 0xbe 0x7d 0xf1 0xa9 0x54 0x57 0x0f 0x19 0xf9 0xb2 0x94 0xb1 0x0c 0x8a 0xc7 0x9b 0x15 0xe3 0xa7 0xc6 0x7b 0x09 0x58 0x94 0xc3 0xea 0xf2 0x04 0x69 0x37 0x87 0x6d 0x82 0x14 0x53 0x5c 0xd5 0x43 0xb6 0x95 0x02 0x6b 0x5b 0x1f 0x80 0x30 0x20 0xcb 0x01 0xa2 0x85 0x40 0xce 0xc5 0x40 0xce 0x2c 0x55 0x04 0x68 0xa0 0xaa 0x29 0xa4 0xf4 0x72 0x19 0x81 0xff 0x02 0xcb 0x78 0xc0 0xd6 0x5f 0x32 0x4b 0xe9 0x9d 0x9f 0x1e 0xd8 0xaa 0x1b 0x9d 0x23 0xea 0x39 0x90 0xc2 0x88 0x1d 0x20 0x30 0xf8 0x7b 0x2b 0x6a 0x5e 0xf5 0x19 0xe1 0xa6 0xee 0x12 0xe3 0xbf 0xec 0x3c 0x0e 0x5d 0x9e 0xb4 0x07 0xd7 0xb1 0x00 0x09 0x76 0x91 0x43 0xe6 0x50 0x4c 0xe8 0x2e 0x1f 0x0f 0x7e 0x05 0x33 0x8b 0xc2 0xdd 0x32 0x5c 0x2f 0x86 0x61 0x77 0xfa 0x82 0x45 0x66 0x10 0xcd 0x44 0xd8 0xb5 0xfc 0xc6 0xc0 0xb9 0x8e 0xca 0xdd 0x0e 0x96 0x31 0x19 0x0f 0xc7 0x25 0x4f 0xc6 0x2b 0xfa 0x12 0xf4 0x51 0xdb 0x2c 0xe9 0x8c 0xc4 0x96 0xf1 0xef 0x3e 0x3a 0xa0 0x59 0x63 0x99 0x12 0x0b 0x50 0x03 0xe6 0xe7 0xa2 0x3a 0x75 0xc2 0xd6 0x61 0x69 0xdc 0x47 0x1b 0x55 0xf2 0x18 0xb9 0x1d 0x50 0x6b 0x2a 0x2f 0xb9 0xf0 0xaf 0x35 0x3d 0x8f 0x84 0x2d 0x48 0x6b 0x5d 0xef 0xef 0x84 0xc5 0xbc 0x6d 0xe8 0xd2 0x9d 0x72 0xb6 0x71 0x81 0x87 0xf9 0xba 0x74 0x20 0x5d 0x6d 0xb5 0xc0 0xac 0xaa 0x57 0x16 0x90 0x21 0x7f 0x4d 0xae 0xc3 0x28 0x25 0x70 0x3d 0x9b 0x2f 0xd2 0x3d 0x96 0xa2 0x62 0x77 0xde 0xf8 0x93 0x7a 0x48 0xce 0x15 0xb8 0xdb 0xd8 0x71 0xa2 0x06 0x30 0x89 0x6d 0x58 0xd9 0x33
14:54:28,673 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) Creating new NegotiationContext
14:54:28,674 TRACE [org.jboss.security.negotiation.common.NegotiationContext] (http-127.0.0.1:8080-1) associate 1338194711
14:54:28,685 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) delegationCredential=USE
14:54:28,686 INFO [stdout] (http-127.0.0.1:8080-1) Debug is true storeKey true useTicketCache true useKeyTab true doNotPrompt true ticketCache is /tmp/krb5cc_1000 isInitiator true KeyTab is /home/jstastny/tmp-workspaces/workspace/HTTP_localhost refreshKrb5Config is false principal is HTTP/localhost at EXAMPLE.COM tryFirstPass is false useFirstPass is false storePass is false clearPass is false
14:54:28,686 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Initialised wrapped login module.
14:54:28,687 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) addGssCredential=true
14:54:28,687 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) wrapGssCredential=false
14:54:28,687 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) No delegation credential so falling through to use wrapped login module.
14:54:28,687 INFO [stdout] (http-127.0.0.1:8080-1) Acquire TGT from Cache
14:54:28,687 INFO [stdout] (http-127.0.0.1:8080-1) Principal is HTTP/localhost at EXAMPLE.COM
14:54:28,687 INFO [stdout] (http-127.0.0.1:8080-1) null credentials from Ticket Cache
14:54:29,038 INFO [stdout] (http-127.0.0.1:8080-1) principal is HTTP/localhost at EXAMPLE.COM
14:54:29,038 INFO [stdout] (http-127.0.0.1:8080-1) Will use keytab
14:54:29,039 INFO [stdout] (http-127.0.0.1:8080-1) Commit Succeeded
14:54:29,039 INFO [stdout] (http-127.0.0.1:8080-1)
14:54:29,039 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Called wrapped login module respone=true
14:54:29,039 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Adding GSSCredential to populated Subject
14:54:29,039 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Creating GSSName for Principal 'HTTP/localhost at EXAMPLE.COM'
14:54:29,039 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Added private credential.
14:54:29,060 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Removing GSSCredential added to subject during authentication.
14:54:29,060 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Passing to wrapped login module to logout.
14:54:29,060 INFO [stdout] (http-127.0.0.1:8080-1) [Krb5LoginModule]: Entering logout
14:54:29,060 INFO [stdout] (http-127.0.0.1:8080-1) [Krb5LoginModule]: logged out Subject
14:54:29,060 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Disposing of GSSCredential
14:54:29,079 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) authenticated principal = GenericPrincipal[7nURoXNahBTZEHCu2gp6ljKk_1478094868674(odata,user,)]
14:54:29,080 TRACE [org.jboss.security.negotiation.common.MessageTrace.Response.Base64] (http-127.0.0.1:8080-1) oXIwcKJuBGxgagYJKoZIhvcSAQICAgBvWzBZoAMCAQWhAwIBD6JNMEugAwIBEaJEBEI2fSIEnkAG
YmiKGNhR2RywpMW19iX6Xz2HBqRhoD+NVbdrseE4IiqJBe7JA5oKmcffRL6O/X+Hz+cLvN/w3gkL
1yI=
14:54:29,081 TRACE [org.jboss.security.negotiation.common.NegotiationContext] (http-127.0.0.1:8080-1) clear 1338194711
14:54:29,108 DEBUG [org.teiid.SECURITY] (http-127.0.0.1:8080-1) authenticateUser anonymous JDBC
14:54:29,110 DEBUG [org.teiid.SECURITY] (http-127.0.0.1:8080-1) Logon successful, created session: sessionid=2gA2AoKgbvFh; userName=dv\@EXAMPLE.COM at EXAMPLE.COM; vdbName=oracle_kerberos; vdbVersion=1; createdTime=Wed Nov 02 14:54:29 GMT+01:00 2016; applicationName=JDBC; clientHostName=null; clientHardwareAddress=null; IPAddress=null; securityDomain=EXAMPLE.COM; lastPingTime=Wed Nov 02 14:54:29 GMT+01:00 2016
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) Successfully obtained a session.
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) Connection Url=
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) ApplicationName=JDBC
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) PassthroughAuthentication=true
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) local-transport-name=odata
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) waitForLoad=0
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) batch-size=256
14:54:29,122 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) VirtualDatabaseName=oracle_kerberos.1
14:54:29,123 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) transportName=odata
14:54:29,123 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) skiptoken-cache-time=300000
14:54:29,123 FINE [org.teiid.jdbc] (http-127.0.0.1:8080-1) The JDBC Driver successfully obtained a connection.
14:54:29,299 DEBUG [org.teiid.ODATA] (http-127.0.0.1:8080-1) Teiid-Query: /*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */
14:54:29,304 FINER [org.teiid.jdbc] (http-127.0.0.1:8080-1) Executing: requestID -1 commands: [/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */] expecting: RESULTSET
14:54:29,305 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) before executeRequest:org.teiid.dqp.internal.process.DQPCore at 82f82b6(0,org.teiid.client.RequestMessage at 5613126a)
14:54:29,315 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0 start processing MORE_WORK
14:54:29,315 DEBUG [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Request Thread 2gA2AoKgbvFh.0 with state NEW
14:54:29,316 DEBUG [org.teiid.TXN_LOG] (http-127.0.0.1:8080-1) before getOrCreateTransactionContext:org.teiid.dqp.internal.process.TransactionServerImpl at 7507a681(2gA2AoKgbvFh)
14:54:29,317 DEBUG [org.teiid.TXN_LOG] (http-127.0.0.1:8080-1) after getOrCreateTransactionContext : 2gA2AoKgbvFh NONE ID:NONE
14:54:29,321 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Cache miss for Cache Entry<2gA2AoKgbvFh=dv\@EXAMPLE.COM at EXAMPLE.COM> params:null sql:/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */
14:54:29,321 DEBUG [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0 executing prepared /*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */
14:54:29,328 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Cache miss for Cache Entry<2gA2AoKgbvFh=dv\@EXAMPLE.COM at EXAMPLE.COM> params:null sql:/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */
14:54:29,329 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Query does not exist in cache: /*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */
14:54:29,331 TRACE [org.teiid.PLANNER.RESOLVER] (http-127.0.0.1:8080-1) Resolving command /*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1
14:54:29,410 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) delegationCredential=USE
14:54:29,410 INFO [stdout] (http-127.0.0.1:8080-1) Debug is true storeKey true useTicketCache true useKeyTab true doNotPrompt true ticketCache is /tmp/krb5cc_1000 isInitiator true KeyTab is /home/jstastny/tmp-workspaces/workspace/HTTP_localhost refreshKrb5Config is false principal is HTTP/localhost at EXAMPLE.COM tryFirstPass is false useFirstPass is false storePass is false clearPass is false
14:54:29,410 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Initialised wrapped login module.
14:54:29,410 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) addGssCredential=true
14:54:29,410 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) wrapGssCredential=false
14:54:29,410 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) We have a delegation credential, login() is a success.
14:54:29,410 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (http-127.0.0.1:8080-1) Jumping straight to mapping of delegation credential.
14:54:29,428 TRACE [org.jboss.security.negotiation.GSSUtil] (http-127.0.0.1:8080-1) Delegated credential converted to Subject.
14:54:29,428 TRACE [org.jboss.security.negotiation.GSSUtil] (http-127.0.0.1:8080-1) Copied conents of temporary Subject to Subject from the LoginContext
14:54:29,428 TRACE [org.jboss.security.negotiation.GSSUtil] (http-127.0.0.1:8080-1) Also add the GSSCredential to the Subject
14:54:32,396 INFO [org.teiid.CONNECTOR] (http-127.0.0.1:8080-1) OracleExecutionFactory Commit=true;DatabaseProductName=Oracle;DatabaseProductVersion=Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options;DriverMajorVersion=11;DriverMajorVersion=2;DriverName=Oracle JDBC driver;DriverVersion=11.2.0.4.0;IsolationLevel=2
14:54:32,397 DEBUG [org.teiid.CONNECTOR] (http-127.0.0.1:8080-1) Initializing the capabilities for oracle
14:54:32,397 DEBUG [org.teiid.CONNECTOR] (http-127.0.0.1:8080-1) Setting the database version to Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
14:54:32,421 TRACE [org.teiid.PLANNER] (http-127.0.0.1:8080-1)
============================================================================
USER COMMAND:
/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1
----------------------------------------------------------------------------
OPTIMIZE:
/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1
----------------------------------------------------------------------------
GENERATE CANONICAL:
/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1
CANONICAL PLAN:
TupleLimit(groups=[], props={MAX_TUPLE_LIMIT=1})
Sort(groups=[BQT1.dual AS g0], props={SORT_ORDER=ORDER BY g0."user"})
Project(groups=[BQT1.dual AS g0], props={PROJECT_COLS=[g0."user"]})
Source(groups=[BQT1.dual AS g0])
============================================================================
EXECUTING PlaceAccess
AFTER:
TupleLimit(groups=[], props={MAX_TUPLE_LIMIT=1})
Sort(groups=[BQT1.dual AS g0], props={SORT_ORDER=ORDER BY g0."user"})
Project(groups=[BQT1.dual AS g0], props={PROJECT_COLS=[g0."user"]})
Access(groups=[BQT1.dual AS g0], props={SOURCE_HINT=null, MODEL_ID=Schema name=BQT1, nameInSource=null, uuid=tid:be7921be52f1-001f3aec-00000000})
Source(groups=[BQT1.dual AS g0])
============================================================================
EXECUTING RaiseAccess
AFTER:
Access(groups=[BQT1.dual AS g0], props={SOURCE_HINT=null, MODEL_ID=Schema name=BQT1, nameInSource=null, uuid=tid:be7921be52f1-001f3aec-00000000})
TupleLimit(groups=[], props={MAX_TUPLE_LIMIT=1})
Sort(groups=[BQT1.dual AS g0], props={SORT_ORDER=ORDER BY g0."user"})
Project(groups=[BQT1.dual AS g0], props={PROJECT_COLS=[g0."user"]})
Source(groups=[BQT1.dual AS g0])
============================================================================
EXECUTING AssignOutputElements
AFTER:
Access(groups=[BQT1.dual AS g0], props={SOURCE_HINT=null, MODEL_ID=Schema name=BQT1, nameInSource=null, uuid=tid:be7921be52f1-001f3aec-00000000, OUTPUT_COLS=[g0."user"]})
TupleLimit(groups=[], props={MAX_TUPLE_LIMIT=1, OUTPUT_COLS=[g0."user"]})
Sort(groups=[BQT1.dual AS g0], props={SORT_ORDER=ORDER BY g0."user", OUTPUT_COLS=[g0."user"], UNRELATED_SORT=false})
Project(groups=[BQT1.dual AS g0], props={PROJECT_COLS=[g0."user"], OUTPUT_COLS=[g0."user"]})
Source(groups=[BQT1.dual AS g0], props={OUTPUT_COLS=[g0."user"]})
============================================================================
EXECUTING PushLimit
AFTER:
Access(groups=[BQT1.dual AS g0])
TupleLimit(groups=[])
Sort(groups=[BQT1.dual AS g0])
Project(groups=[BQT1.dual AS g0])
Source(groups=[BQT1.dual AS g0])
============================================================================
EXECUTING CalculateCost
AFTER:
Access(groups=[BQT1.dual AS g0], props={SOURCE_HINT=null, MODEL_ID=Schema name=BQT1, nameInSource=null, uuid=tid:be7921be52f1-001f3aec-00000000, OUTPUT_COLS=[g0."user"], EST_CARDINALITY=1.0, EST_COL_STATS={g0."user"=[1.0, 1.0]}})
TupleLimit(groups=[], props={MAX_TUPLE_LIMIT=1, OUTPUT_COLS=[g0."user"], EST_CARDINALITY=1.0, EST_COL_STATS={g0."user"=[1.0, 0.0]}})
Sort(groups=[BQT1.dual AS g0], props={SORT_ORDER=ORDER BY g0."user", OUTPUT_COLS=[g0."user"], UNRELATED_SORT=false, EST_CARDINALITY=-1.0})
Project(groups=[BQT1.dual AS g0], props={PROJECT_COLS=[g0."user"], OUTPUT_COLS=[g0."user"], EST_CARDINALITY=-1.0})
Source(groups=[BQT1.dual AS g0], props={OUTPUT_COLS=[g0."user"], EST_COL_STATS={g0."user"=[-1.0, -1.0]}, EST_CARDINALITY=-1.0})
============================================================================
EXECUTING PlanSorts
AFTER:
Access(groups=[BQT1.dual AS g0])
TupleLimit(groups=[])
Sort(groups=[BQT1.dual AS g0])
Project(groups=[BQT1.dual AS g0])
Source(groups=[BQT1.dual AS g0])
============================================================================
EXECUTING CollapseSource
AFTER:
Access(groups=[BQT1.dual AS g0], props={SOURCE_HINT=null, MODEL_ID=Schema name=BQT1, nameInSource=null, uuid=tid:be7921be52f1-001f3aec-00000000, OUTPUT_COLS=[g0."user"], EST_CARDINALITY=1.0, EST_COL_STATS={g0."user"=[1.0, 1.0]}, ATOMIC_REQUEST=SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1})
============================================================================
CONVERTING PLAN TREE TO PROCESS TREE
PROCESS PLAN =
AccessNode(0) output=[g0."user"] SELECT g_0."user" AS c_0 FROM BQT1.dual AS g_0 ORDER BY c_0 LIMIT 1
============================================================================
----------------------------------------------------------------------------
OPTIMIZATION COMPLETE:
PROCESSOR PLAN:
AccessNode(0) output=[g0."user"] SELECT g_0."user" AS c_0 FROM BQT1.dual AS g_0 ORDER BY c_0 LIMIT 1
============================================================================
14:54:32,422 DEBUG [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) ProcessTree for 2gA2AoKgbvFh.0 AccessNode(0) output=[g0."user"] SELECT g_0."user" AS c_0 FROM BQT1.dual AS g_0 ORDER BY c_0 LIMIT 1
14:54:32,423 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Cache hint modified the query determinism from DETERMINISTIC to DETERMINISTIC
14:54:32,423 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Adding to global/distributed cache Cache Entry<2gA2AoKgbvFh=dv\@EXAMPLE.COM at EXAMPLE.COM> params:null sql:/*+ cache(ttl:300000 scope:USER) */ SELECT g0."user" FROM BQT1.dual AS g0 ORDER BY g0."user" LIMIT 1 /* 2gA2AoKgbvFh */
14:54:32,436 DEBUG [org.teiid.TXN_LOG] (http-127.0.0.1:8080-1) before getOrCreateTransactionContext:org.teiid.dqp.internal.process.TransactionServerImpl at 7507a681(2gA2AoKgbvFh)
14:54:32,436 DEBUG [org.teiid.TXN_LOG] (http-127.0.0.1:8080-1) after getOrCreateTransactionContext : 2gA2AoKgbvFh NONE ID:NONE
14:54:32,444 DEBUG [org.teiid.BUFFER_MGR] (http-127.0.0.1:8080-1) Creating TupleBuffer: 0 [g0."user"] [class java.lang.String] batch size 1024 of type PROCESSOR
14:54:32,445 TRACE [org.teiid.BUFFER_MGR] (http-127.0.0.1:8080-1) Reserving buffer space 307200 FORCE
14:54:32,450 DEBUG [org.teiid.CONNECTOR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0.0.0 Create State
14:54:32,463 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0.0.0 no cache directive
14:54:32,470 DEBUG [org.teiid.BUFFER_MGR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0.0.0 Blocking on source query 2gA2AoKgbvFh.0.0.0
14:54:32,470 TRACE [org.teiid.RUNTIME] (Worker0_QueryProcessorQueue0) Beginning work with virtual worker Worker0_QueryProcessorQueue0
14:54:32,470 DEBUG [org.teiid.BUFFER_MGR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0 Blocking on source request(s).
14:54:32,470 DEBUG [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) Request Thread 2gA2AoKgbvFh.0 - processor blocked
14:54:32,470 TRACE [org.teiid.PROCESSOR] (http-127.0.0.1:8080-1) 2gA2AoKgbvFh.0 end processing WORKING
14:54:32,470 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue0) Running task for parent thread http-127.0.0.1:8080-1
14:54:32,471 DEBUG [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue0) 2gA2AoKgbvFh.0.0.0 Processing NEW request: SELECT g_0."user" AS c_0 FROM BQT1.dual AS g_0 ORDER BY c_0 LIMIT 1
14:54:32,474 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) delegationCredential=USE
14:54:32,475 INFO [stdout] (Worker0_QueryProcessorQueue0) Debug is true storeKey true useTicketCache true useKeyTab true doNotPrompt true ticketCache is /tmp/krb5cc_1000 isInitiator true KeyTab is /home/jstastny/tmp-workspaces/workspace/HTTP_localhost refreshKrb5Config is false principal is HTTP/localhost at EXAMPLE.COM tryFirstPass is false useFirstPass is false storePass is false clearPass is false
14:54:32,475 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) Initialised wrapped login module.
14:54:32,475 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) addGssCredential=true
14:54:32,475 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) wrapGssCredential=false
14:54:32,475 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) No delegation credential so falling through to use wrapped login module.
14:54:32,475 INFO [stdout] (Worker0_QueryProcessorQueue0) Acquire TGT from Cache
14:54:32,475 INFO [stdout] (Worker0_QueryProcessorQueue0) Principal is HTTP/localhost at EXAMPLE.COM
14:54:32,475 INFO [stdout] (Worker0_QueryProcessorQueue0) null credentials from Ticket Cache
14:54:32,798 INFO [stdout] (Worker0_QueryProcessorQueue0) principal is HTTP/localhost at EXAMPLE.COM
14:54:32,804 INFO [stdout] (Worker0_QueryProcessorQueue0) Will use keytab
14:54:32,804 INFO [stdout] (Worker0_QueryProcessorQueue0) Commit Succeeded
14:54:32,804 INFO [stdout] (Worker0_QueryProcessorQueue0)
14:54:32,804 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) Called wrapped login module respone=true
14:54:32,805 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) Adding GSSCredential to populated Subject
14:54:32,805 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) Creating GSSName for Principal 'HTTP/localhost at EXAMPLE.COM'
14:54:32,805 TRACE [org.jboss.security.negotiation.KerberosLoginModule] (Worker0_QueryProcessorQueue0) Added private credential.
14:54:35,948 WARN [org.jboss.jca.core.connectionmanager.pool.strategy.PoolBySubject] (Worker0_QueryProcessorQueue0) IJ000604: Throwable while attempting to get a new connection: null: javax.resource.ResourceException: Could not create connection
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:351)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.access$200(LocalManagedConnectionFactory.java:60)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory$1.run(LocalManagedConnectionFactory.java:274)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory$1.run(LocalManagedConnectionFactory.java:265)
at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.8.0_102]
at javax.security.auth.Subject.doAs(Subject.java:422) [rt.jar:1.8.0_102]
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createManagedConnection(LocalManagedConnectionFactory.java:264)
at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.createConnectionEventListener(SemaphoreArrayListManagedConnectionPool.java:858)
at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.getConnection(SemaphoreArrayListManagedConnectionPool.java:413)
at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getSimpleConnection(AbstractPool.java:457)
at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:429)
at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:344)
at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:367)
at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:499)
at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)
at org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:69)
at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:270) [translator-jdbc-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:68) [translator-jdbc-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
at org.teiid.translator.ExecutionFactory.getConnection(ExecutionFactory.java:202) [teiid-api-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
at org.teiid.dqp.internal.datamgr.ConnectorWorkItem.execute(ConnectorWorkItem.java:330)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_102]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_102]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_102]
at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_102]
at org.teiid.dqp.internal.datamgr.ConnectorManager$1.invoke(ConnectorManager.java:211)
at com.sun.proxy.$Proxy83.execute(Unknown Source)
at org.teiid.dqp.internal.process.DataTierTupleSource.getResults(DataTierTupleSource.java:306)
at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:112)
at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:108)
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_102]
at org.teiid.dqp.internal.process.FutureWork.run(FutureWork.java:65)
at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:276)
at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119)
at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:210)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_102]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_102]
at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_102]
Caused by: java.sql.SQLException: ORA-01017: invalid username/password; logon denied
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:447)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:389)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:382)
at oracle.jdbc.driver.T4CTTIfun.processError(T4CTTIfun.java:675)
at oracle.jdbc.driver.T4CTTIoauthenticate.processError(T4CTTIoauthenticate.java:448)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:513)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:227)
at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:383)
at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:776)
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:432)
at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:554)
at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:254)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:528)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:323)
... 36 more
14:54:35,957 WARN [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue0) Connector worker process failed for atomic-request=2gA2AoKgbvFh.0.0.0: org.teiid.translator.TranslatorException: TEIID11009 java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/Oracle12_krb
at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:274) [translator-jdbc-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:68) [translator-jdbc-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
at org.teiid.translator.ExecutionFactory.getConnection(ExecutionFactory.java:202) [teiid-api-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
at org.teiid.dqp.internal.datamgr.ConnectorWorkItem.execute(ConnectorWorkItem.java:330)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_102]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_102]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_102]
at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_102]
at org.teiid.dqp.internal.datamgr.ConnectorManager$1.invoke(ConnectorManager.java:211)
at com.sun.proxy.$Proxy83.execute(Unknown Source)
at org.teiid.dqp.internal.process.DataTierTupleSource.getResults(DataTierTupleSource.java:306)
at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:112)
at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:108)
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_102]
at org.teiid.dqp.internal.process.FutureWork.run(FutureWork.java:65)
at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:276)
at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119)
at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:210)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_102]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_102]
at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_102]
Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/Oracle12_krb
at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:151)
at org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:69)
at org.teiid.translator.jdbc.JDBCExecutionFactory.getConnection(JDBCExecutionFactory.java:270) [translator-jdbc-8.12.7.6_3-redhat-1.jar:8.12.7.6_3-redhat-1]
... 20 more
Caused by: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/Oracle12_krb
at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:410)
at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:367)
at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:499)
at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)
... 22 more
Caused by: javax.resource.ResourceException: IJ000658: Unexpected throwable while trying to create a connection: null
at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.getConnection(SemaphoreArrayListManagedConnectionPool.java:454)
at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getSimpleConnection(AbstractPool.java:457)
at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:429)
at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:344)
... 25 more
Caused by: javax.resource.ResourceException: Could not create connection
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:351)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.access$200(LocalManagedConnectionFactory.java:60)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory$1.run(LocalManagedConnectionFactory.java:274)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory$1.run(LocalManagedConnectionFactory.java:265)
at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.8.0_102]
at javax.security.auth.Subject.doAs(Subject.java:422) [rt.jar:1.8.0_102]
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createManagedConnection(LocalManagedConnectionFactory.java:264)
at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.createConnectionEventListener(SemaphoreArrayListManagedConnectionPool.java:858)
at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.getConnection(SemaphoreArrayListManagedConnectionPool.java:413)
... 28 more
Caused by: java.sql.SQLException: ORA-01017: invalid username/password; logon denied
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:447)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:389)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:382)
at oracle.jdbc.driver.T4CTTIfun.processError(T4CTTIfun.java:675)
at oracle.jdbc.driver.T4CTTIoauthenticate.processError(T4CTTIoauthenticate.java:448)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:513)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:227)
at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:383)
at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:776)
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:432)
at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:554)
at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:254)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:528)
at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:323)
... 36 more
{code}
> OData Kerberos cannot access VDB
> --------------------------------
>
> Key: TEIID-4499
> URL: https://issues.jboss.org/browse/TEIID-4499
> Project: Teiid
> Issue Type: Bug
> Components: OData
> Affects Versions: 8.12.6.6_3
> Reporter: Jan Stastny
> Assignee: Steven Hawkins
> Fix For: 9.2, 9.0.5, 9.1.1
>
>
> When configured odata war for Kerberos using https://teiid.gitbooks.io/documents/content/security/Kerberos_support_through_GSSAPI.html an error occurs when accessing a vdb, which is also secured by Kerberos.
> The error is following:
> {code:plain}
> 11:44:53,360 WARN [org.teiid.ODATA] (http-127.0.0.1:8080-1) TEIID16047 Could not process OData 4 request: 08001 TEIID40055 org.teiid.core.TeiidException: TEIID40055 org.teiid.net.ConnectionException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.: org.teiid.core.TeiidProcessingException: 08001 TEIID40055 org.teiid.core.TeiidException: TEIID40055 org.teiid.net.ConnectionException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.
> at org.teiid.olingo.web.ODataFilter.internalDoFilter(ODataFilter.java:233) [teiid-olingo-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> at org.teiid.olingo.web.ODataFilter.doFilter(ODataFilter.java:100) [teiid-olingo-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:246) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:231) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:149) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.jboss.security.negotiation.NegotiationAuthenticator$WrapperValve.invoke(NegotiationAuthenticator.java:492) [jboss-negotiation-common-2.3.11.Final-redhat-1.jar:2.3.11.Final-redhat-1]
> at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:512) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169) [jboss-as-web-7.5.9.Final-redhat-2.jar:7.5.9.Final-redhat-2]
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926) [jbossweb-7.5.17.Final-redhat-1.jar:7.5.17.Final-redhat-1]
> at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_102]
> Caused by: org.teiid.jdbc.TeiidSQLException: TEIID40055 org.teiid.core.TeiidException: TEIID40055 org.teiid.net.ConnectionException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.
> at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:135)
> at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:71)
> at org.teiid.jdbc.EmbeddedProfile.connect(EmbeddedProfile.java:55)
> at org.teiid.jdbc.TeiidDriver.connect(TeiidDriver.java:105)
> at org.teiid.olingo.service.LocalClient.buildConnection(LocalClient.java:119) [teiid-olingo-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> at org.teiid.olingo.service.LocalClient.open(LocalClient.java:89) [teiid-olingo-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> at org.teiid.olingo.web.ODataFilter.internalDoFilter(ODataFilter.java:226) [teiid-olingo-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> ... 16 more
> Caused by: org.teiid.core.TeiidException: TEIID40055 org.teiid.core.TeiidException: TEIID40055 org.teiid.net.ConnectionException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.
> at org.teiid.core.util.ReflectionHelper.create(ReflectionHelper.java:308) [teiid-common-core-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> at org.teiid.jdbc.ModuleHelper.createFromModule(ModuleHelper.java:53)
> at org.teiid.jdbc.EmbeddedProfile.createServerConnection(EmbeddedProfile.java:60)
> at org.teiid.jdbc.EmbeddedProfile.connect(EmbeddedProfile.java:50)
> ... 20 more
> Caused by: org.teiid.core.TeiidException: TEIID40055 org.teiid.net.ConnectionException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.
> at org.teiid.core.util.ReflectionHelper.create(ReflectionHelper.java:345) [teiid-common-core-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> at org.teiid.core.util.ReflectionHelper.create(ReflectionHelper.java:306) [teiid-common-core-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> ... 23 more
> Caused by: org.teiid.net.ConnectionException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.
> at org.teiid.transport.LocalServerConnection.authenticate(LocalServerConnection.java:146)
> at org.teiid.transport.LocalServerConnection.<init>(LocalServerConnection.java:106)
> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) [rt.jar:1.8.0_102]
> at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) [rt.jar:1.8.0_102]
> at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) [rt.jar:1.8.0_102]
> at java.lang.reflect.Constructor.newInstance(Constructor.java:423) [rt.jar:1.8.0_102]
> at org.teiid.core.util.ReflectionHelper.create(ReflectionHelper.java:343) [teiid-common-core-8.12.6.6_3-redhat-1.jar:8.12.6.6_3-redhat-1]
> ... 24 more
> Caused by: org.teiid.client.security.LogonException: TEIID40055 Wrong logon method is being used. Server is not set up for GSS based authentication.
> at org.teiid.transport.LogonImpl.logon(LogonImpl.java:119)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_102]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_102]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_102]
> at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_102]
> at org.teiid.transport.LocalServerConnection$1$1.call(LocalServerConnection.java:180)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_102]
> at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:276)
> at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:260)
> at org.teiid.transport.LocalServerConnection$1.invoke(LocalServerConnection.java:178)
> at com.sun.proxy.$Proxy81.logon(Unknown Source)
> at org.teiid.transport.LocalServerConnection.authenticate(LocalServerConnection.java:142)
> ... 30 more
> {code}
> Authentication of the user succeeded:
> {code:plain}
> principal is dv at EXAMPLE.COM
> Will use keytab
> Commit Succeeded
> {code}
> Authentication of the server succeeded:
> {code:plain}
> 11:44:52,873 INFO [stdout] (http-127.0.0.1:8080-1) Acquire TGT from Cache
> 11:44:52,874 INFO [stdout] (http-127.0.0.1:8080-1) Principal is HTTP/localhost at EXAMPLE.COM
> 11:44:52,874 INFO [stdout] (http-127.0.0.1:8080-1) null credentials from Ticket Cache
> 11:44:53,234 INFO [stdout] (http-127.0.0.1:8080-1) principal is HTTP/localhost at EXAMPLE.COM
> 11:44:53,234 INFO [stdout] (http-127.0.0.1:8080-1) Will use keytab
> 11:44:53,236 INFO [stdout] (http-127.0.0.1:8080-1) Commit Succeeded
> {code}
> Initial request:
> {code:plain}
> 12:44:52,325 DEBUG [MainClientExec] Opening connection {}->http://localhost:8080
> 12:44:52,327 DEBUG [DefaultHttpClientConnectionOperator] Connecting to localhost/127.0.0.1:8080
> 12:44:52,328 DEBUG [DefaultHttpClientConnectionOperator] Connection established 127.0.0.1:47980<->127.0.0.1:8080
> 12:44:52,328 DEBUG [MainClientExec] Executing request GET /odata4/kerberos_teiid/BQT1/smalla HTTP/1.1
> 12:44:52,328 DEBUG [MainClientExec] Target auth state: UNCHALLENGED
> 12:44:52,329 DEBUG [MainClientExec] Proxy auth state: UNCHALLENGED
> 12:44:52,330 DEBUG [headers] http-outgoing-0 >> GET /odata4/kerberos_teiid/BQT1/smalla HTTP/1.1
> 12:44:52,330 DEBUG [headers] http-outgoing-0 >> Host: localhost:8080
> 12:44:52,330 DEBUG [headers] http-outgoing-0 >> Connection: Keep-Alive
> 12:44:52,330 DEBUG [headers] http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_51)
> 12:44:52,330 DEBUG [headers] http-outgoing-0 >> Accept-Encoding: gzip,deflate
> 12:44:52,330 DEBUG [wire] http-outgoing-0 >> "GET /odata4/kerberos_teiid/BQT1/smalla HTTP/1.1[\r][\n]"
> 12:44:52,330 DEBUG [wire] http-outgoing-0 >> "Host: localhost:8080[\r][\n]"
> 12:44:52,331 DEBUG [wire] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
> 12:44:52,331 DEBUG [wire] http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_51)[\r][\n]"
> 12:44:52,331 DEBUG [wire] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
> 12:44:52,331 DEBUG [wire] http-outgoing-0 >> "[\r][\n]"
> {code}
> Negotiate request from server:
> {code:plain}
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "HTTP/1.1 401 Unauthorized[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Server: Apache-Coyote/1.1[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Pragma: No-cache[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Cache-Control: no-cache[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Expires: Thu, 01 Jan 1970 01:00:00 GMT+01:00[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "WWW-Authenticate: Negotiate[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Content-Type: text/html;charset=utf-8[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Content-Length: 996[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "Date: Mon, 10 Oct 2016 10:44:52 GMT[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "[\r][\n]"
> 12:44:52,457 DEBUG [wire] http-outgoing-0 << "<html><head><title>JBWEB000065: HTTP Status 401 - </title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} H2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} H3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} B {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} P {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A {color : black;}A.name {color : black;}HR {color : #525D76;}--></style> </head><body><h1>JBWEB000065: HTTP Status 401 - </h1><HR size="1" noshade="noshade"><p><b>JBWEB000309: type</b> JBWEB000067: Status report</p><p><b>JBWEB000068: message</b> <u></u></p><p><b>JBWEB000069: description</b> <u>JBWEB000121: This request requires HTTP authentication.</u></p><HR size="1" noshade="noshade"></body></html>"
> 12:44:52,459 DEBUG [headers] http-outgoing-0 << HTTP/1.1 401 Unauthorized
> 12:44:52,459 DEBUG [headers] http-outgoing-0 << Server: Apache-Coyote/1.1
> 12:44:52,459 DEBUG [headers] http-outgoing-0 << Pragma: No-cache
> 12:44:52,460 DEBUG [headers] http-outgoing-0 << Cache-Control: no-cache
> 12:44:52,460 DEBUG [headers] http-outgoing-0 << Expires: Thu, 01 Jan 1970 01:00:00 GMT+01:00
> 12:44:52,460 DEBUG [headers] http-outgoing-0 << WWW-Authenticate: Negotiate
> 12:44:52,460 DEBUG [headers] http-outgoing-0 << Content-Type: text/html;charset=utf-8
> 12:44:52,460 DEBUG [headers] http-outgoing-0 << Content-Length: 996
> 12:44:52,460 DEBUG [headers] http-outgoing-0 << Date: Mon, 10 Oct 2016 10:44:52 GMT
> {code}
> Response to auth server:
> {code:plain}
> Found ticket for dv at EXAMPLE.COM to go to krbtgt/EXAMPLE.COM at EXAMPLE.COM expiring on Mon Oct 10 20:44:52 CEST 2016
> Entered Krb5Context.initSecContext with state=STATE_NEW
> Service ticket not found in the subject
> 12:44:52,846 DEBUG [SPNegoScheme] Sending response 'YIIEjgYGKwYBBQUCoIIEgjCCBH6gDTALBgkqhkiG9xIBAgKhBAMCAfaiggRlBIIEYWCCBF0GCSqGSIb3EgECAgEAboIETDCCBEigAwIBBaEDAgEOogcDBQAgAAAAo4IBBmGCAQIwgf+gAwIBBaEbGxlNVy5MQUIuRU5HLkJPUy5SRURIQVQuQ09NohwwGqADAgEAoRMwERsESFRUUBsJbG9jYWxob3N0o4G8MIG5oAMCARGhAwIBBKKBrASBqdJuL2wF7+W0MD1qISt66VAyhitq77SR6vLKWJnpc/Yx60ch80GepVlYdoYxee0qW+d4u6aw3p0BaOWSgSMRoDnr9bSUn+tQXNevIfKE+oUM+5lC4afhAF0PB4dcJC7z6/wLZ9drDImvyhntm9lq/yv5LW76gSbVd9SjO58ZvD3cYRJnuF3CaFhm5ol0ce84ojZdX5mVvVBUU3+Vo1rh6SSEKda+xoBkK/ykggMnMIIDI6ADAgERooIDGgSCAxaG8huKFUf6vR0wVfeI1caKfIPtGC9rDSw5DYTz1dz43F8GI9we3YG9NC6kEi1zPdA4A2dxfBqgUl+/YkBdQco4udBCwLXNmziHCS5ypypBJsFdgFzRi/9hXukmqofSGIlKVJWH3ap1ap+37Amfm6LxZuQFDyY526onGXdWoAB0Jbcpsi74Ti5x3sRGZqoF5FTwUqI0pQYI+hLDh2GeBNXBNOHqdMXNfnLFOr+LpnNhl7ROxkWsBxNPv/4MmRLPsF/cGrc924L6R4PQvP7qVjGKUxayEoBPP/go5xb2b2z+TjruspzbJ5dw1wKAOH2RGlDJ5om0PUSqaxe0h2WhL9rXBOGVONTSv7lYQ2pcgaOqR6FutB5PZGP0B73ekwhbRfrt6zxLpHzZFnrSeV9lz1U4r8Bkyxuze3cuQGcL/cNTBbhE83cbNY8VJlu4E+6LmZ9ll3vpjNq3735S6gFArsOJ38FcLO0Kqj1rZr7/r9TRsV9f8agDnWusc5lQzZc+4H0BIeAPD34ApJxGogA63/8yF1Pl3uc1Rp+a6blQHLLCRZthIpi8LVF8rSizTkTDWUrTw+X5wGDunjslrUmClW25qzGeLTZpELrJXkKFstUnL4blaPboyPk8qDecaRed+dIjteVS9CgF51AtHrO9vhWgrr41TL+H8akHfjI6Q9GIgravWLSkNrVMsrNyVAlc1hdUAovLXJFfxS3Mg0OugjG3rJhSCiQqLCuhIRL8OB4Fz4Pa24fpBG0G/Rv1RrhuQaKoxNsZxuR67zzF+v7+4PRKK39y0cqFWBf95YV4SWz7qzXmZYcaDcVhrFzp723ecWunVa6Qt5YUZ3+pkKV+NGGb95PjS7HtvXZo4ko5tJX1QI+ke4I3j3cThrWlV5y3rNC2IKiE8eRNI6rKRGdvpYLwkL0B5AkJleqGjdiqZVy6Q2w/YdHN2oTOs8qUgIVgPHJMyRLUTT872ZOWdmmHWJuIe3sVkr1RLFDV2csmYggSZCbjCczFvlmKrcn6OLqVRGN3sNm6a9Q45wZimLvIkxePHag3vvtp' back to the auth server
> 12:44:52,846 DEBUG [MainClientExec] Proxy auth state: UNCHALLENGED
> 12:44:52,846 DEBUG [headers] http-outgoing-0 >> GET /odata4/kerberos_teiid/BQT1/smalla HTTP/1.1
> 12:44:52,846 DEBUG [headers] http-outgoing-0 >> Host: localhost:8080
> 12:44:52,846 DEBUG [headers] http-outgoing-0 >> Connection: Keep-Alive
> 12:44:52,846 DEBUG [headers] http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_51)
> 12:44:52,846 DEBUG [headers] http-outgoing-0 >> Accept-Encoding: gzip,deflate
> 12:44:52,846 DEBUG [headers] http-outgoing-0 >> Authorization: Negotiate YIIEjgYGKwYBBQUCoIIEgjCCBH6gDTALBgkqhkiG9xIBAgKhBAMCAfaiggRlBIIEYWCCBF0GCSqGSIb3EgECAgEAboIETDCCBEigAwIBBaEDAgEOogcDBQAgAAAAo4IBBmGCAQIwgf+gAwIBBaEbGxlNVy5MQUIuRU5HLkJPUy5SRURIQVQuQ09NohwwGqADAgEAoRMwERsESFRUUBsJbG9jYWxob3N0o4G8MIG5oAMCARGhAwIBBKKBrASBqdJuL2wF7+W0MD1qISt66VAyhitq77SR6vLKWJnpc/Yx60ch80GepVlYdoYxee0qW+d4u6aw3p0BaOWSgSMRoDnr9bSUn+tQXNevIfKE+oUM+5lC4afhAF0PB4dcJC7z6/wLZ9drDImvyhntm9lq/yv5LW76gSbVd9SjO58ZvD3cYRJnuF3CaFhm5ol0ce84ojZdX5mVvVBUU3+Vo1rh6SSEKda+xoBkK/ykggMnMIIDI6ADAgERooIDGgSCAxaG8huKFUf6vR0wVfeI1caKfIPtGC9rDSw5DYTz1dz43F8GI9we3YG9NC6kEi1zPdA4A2dxfBqgUl+/YkBdQco4udBCwLXNmziHCS5ypypBJsFdgFzRi/9hXukmqofSGIlKVJWH3ap1ap+37Amfm6LxZuQFDyY526onGXdWoAB0Jbcpsi74Ti5x3sRGZqoF5FTwUqI0pQYI+hLDh2GeBNXBNOHqdMXNfnLFOr+LpnNhl7ROxkWsBxNPv/4MmRLPsF/cGrc924L6R4PQvP7qVjGKUxayEoBPP/go5xb2b2z+TjruspzbJ5dw1wKAOH2RGlDJ5om0PUSqaxe0h2WhL9rXBOGVONTSv7lYQ2pcgaOqR6FutB5PZGP0B73ekwhbRfrt6zxLpHzZFnrSeV9lz1U4r8Bkyxuze3cuQGcL/cNTBbhE83cbNY8VJlu4E+6LmZ9ll3vpjNq3735S6gFArsOJ38FcLO0Kqj1rZr7/r9TRsV9f8agDnWusc5lQzZc+4H0BIeAPD34ApJxGogA63/8yF1Pl3uc1Rp+a6blQHLLCRZthIpi8LVF8rSizTkTDWUrTw+X5wGDunjslrUmClW25qzGeLTZpELrJXkKFstUnL4blaPboyPk8qDecaRed+dIjteVS9CgF51AtHrO9vhWgrr41TL+H8akHfjI6Q9GIgravWLSkNrVMsrNyVAlc1hdUAovLXJFfxS3Mg0OugjG3rJhSCiQqLCuhIRL8OB4Fz4Pa24fpBG0G/Rv1RrhuQaKoxNsZxuR67zzF+v7+4PRKK39y0cqFWBf95YV4SWz7qzXmZYcaDcVhrFzp723ecWunVa6Qt5YUZ3+pkKV+NGGb95PjS7HtvXZo4ko5tJX1QI+ke4I3j3cThrWlV5y3rNC2IKiE8eRNI6rKRGdvpYLwkL0B5AkJleqGjdiqZVy6Q2w/YdHN2oTOs8qUgIVgPHJMyRLUTT872ZOWdmmHWJuIe3sVkr1RLFDV2csmYggSZCbjCczFvlmKrcn6OLqVRGN3sNm6a9Q45wZimLvIkxePHag3vvtp
> 12:44:52,846 DEBUG [wire] http-outgoing-0 >> "GET /odata4/kerberos_teiid/BQT1/smalla HTTP/1.1[\r][\n]"
> 12:44:52,846 DEBUG [wire] http-outgoing-0 >> "Host: localhost:8080[\r][\n]"
> 12:44:52,847 DEBUG [wire] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
> 12:44:52,847 DEBUG [wire] http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_51)[\r][\n]"
> 12:44:52,847 DEBUG [wire] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
> 12:44:52,847 DEBUG [wire] http-outgoing-0 >> "Authorization: Negotiate YIIEjgYGKwYBBQUCoIIEgjCCBH6gDTALBgkqhkiG9xIBAgKhBAMCAfaiggRlBIIEYWCCBF0GCSqGSIb3EgECAgEAboIETDCCBEigAwIBBaEDAgEOogcDBQAgAAAAo4IBBmGCAQIwgf+gAwIBBaEbGxlNVy5MQUIuRU5HLkJPUy5SRURIQVQuQ09NohwwGqADAgEAoRMwERsESFRUUBsJbG9jYWxob3N0o4G8MIG5oAMCARGhAwIBBKKBrASBqdJuL2wF7+W0MD1qISt66VAyhitq77SR6vLKWJnpc/Yx60ch80GepVlYdoYxee0qW+d4u6aw3p0BaOWSgSMRoDnr9bSUn+tQXNevIfKE+oUM+5lC4afhAF0PB4dcJC7z6/wLZ9drDImvyhntm9lq/yv5LW76gSbVd9SjO58ZvD3cYRJnuF3CaFhm5ol0ce84ojZdX5mVvVBUU3+Vo1rh6SSEKda+xoBkK/ykggMnMIIDI6ADAgERooIDGgSCAxaG8huKFUf6vR0wVfeI1caKfIPtGC9rDSw5DYTz1dz43F8GI9we3YG9NC6kEi1zPdA4A2dxfBqgUl+/YkBdQco4udBCwLXNmziHCS5ypypBJsFdgFzRi/9hXukmqofSGIlKVJWH3ap1ap+37Amfm6LxZuQFDyY526onGXdWoAB0Jbcpsi74Ti5x3sRGZqoF5FTwUqI0pQYI+hLDh2GeBNXBNOHqdMXNfnLFOr+LpnNhl7ROxkWsBxNPv/4MmRLPsF/cGrc924L6R4PQvP7qVjGKUxayEoBPP/go5xb2b2z+TjruspzbJ5dw1wKAOH2RGlDJ5om0PUSqaxe0h2WhL9rXBOGVONTSv7lYQ2pcgaOqR6FutB5PZGP0B73ekwhbRfrt6zxLpHzZFnrSeV9lz1U4r8Bkyxuze3cuQGcL/cNTBbhE83cbNY8VJlu4E+6LmZ9ll3vpjNq3735S6gFArsOJ38FcLO0Kqj1rZr7/r9TRsV9f8agDnWusc5lQzZc+4H0BIeAPD34ApJxGogA63/8yF1Pl3uc1Rp+a6blQHLLCRZthIpi8LVF8rSizTkTDWUrTw+X5wGDunjslrUmClW25qzGeLTZpELrJXkKFstUnL4blaPboyPk8qDecaRed+dIjteVS9CgF51AtHrO9vhWgrr41TL+H8akHfjI6Q9GIgravWLSkNrVMsrNyVAlc1hdUAovLXJFfxS3Mg0OugjG3rJhSCiQqLCuhIRL8OB4Fz4Pa24fpBG0G/Rv1RrhuQaKoxNsZxuR67zzF+v7+4PRKK39y0cqFWBf95YV4SWz7qzXmZYcaDcVhrFzp723ecWunVa6Qt5YUZ3+pkKV+NGGb95PjS7HtvXZo4ko5tJX1QI+ke4I3j3cThrWlV5y3rNC2IKiE8eRNI6rKRGdvpYLwkL0B5AkJleqGjdiqZVy6Q2w/YdHN2oTOs8qUgIVgPHJMyRLUTT872ZOWdmmHWJuIe3sVkr1RLFDV2csmYggSZCbjCczFvlmKrcn6OLqVRGN3sNm6a9Q45wZimLvIkxePHag3vvtp[\r][\n]"
> 12:44:52,847 DEBUG [wire] http-outgoing-0 >> "[\r][\n]"
> {code}
> Last server logs before error:
> {code:plain}
> 11:44:53,246 DEBUG [org.jboss.security.auth.spi.AbstractServerLoginModule] (http-127.0.0.1:8080-1) Logged in 'host' LoginContext
> 11:44:53,247 DEBUG [org.jboss.security.auth.spi.AbstractServerLoginModule] (http-127.0.0.1:8080-1) Creating new GSSContext.
> 11:44:53,283 DEBUG [org.jboss.security.auth.spi.AbstractServerLoginModule] (http-127.0.0.1:8080-1) context.getCredDelegState() = true
> 11:44:53,284 DEBUG [org.jboss.security.auth.spi.AbstractServerLoginModule] (http-127.0.0.1:8080-1) context.getMutualAuthState() = true
> 11:44:53,284 DEBUG [org.jboss.security.auth.spi.AbstractServerLoginModule] (http-127.0.0.1:8080-1) context.getSrcName() = dv at EXAMPLE.COM
> 11:44:53,284 INFO [stdout] (http-127.0.0.1:8080-1) [Krb5LoginModule]: Entering logout
> 11:44:53,285 INFO [stdout] (http-127.0.0.1:8080-1) [Krb5LoginModule]: logged out Subject
> 11:44:53,285 DEBUG [org.jboss.security.auth.spi.AbstractServerLoginModule] (http-127.0.0.1:8080-1) Storing username 'dv at EXAMPLE.COM' and empty password
> 11:44:53,304 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-127.0.0.1:8080-1) authenticated principal = GenericPrincipal[5tV-f1mRV7tGghx2rk4krdFH_1476096292858(odata,user,)]
> {code}
> VDB used:
> {code:xml}
> <vdb name="kerberos_teiid" version="1">
> <property name="security-domain" value="EXAMPLE.COM"/>
> <property name="authentication-type" value="GSS"/>
> .
> .
> .
> </vdb>
> {code}
> Request URL:
> {code:plain}
> http://localhost:8080/odata4/kerberos_teiid/BQT1/smalla
> {code}
> Server configuration:
> {code:xml}
> <security-domain name="host">
> <authentication>
> <login-module code="Kerberos" flag="required" module="org.jboss.security.negotiation">
> <module-option name="storeKey" value="true"/>
> <module-option name="useKeyTab" value="true"/>
> <module-option name="keyTab" value="${jboss.home.dir}/HTTP_localhost"/>
> <module-option name="principal" value="HTTP/localhost at EXAMPLE.COM"/>
> <module-option name="doNotPrompt" value="true"/>
> <module-option name="useTicketCache" value="true"/>
> <module-option name="debug" value="true"/>
> <module-option name="refreshKrb5Config" value="false"/>
> <module-option name="isInitiator" value="true"/>
> <module-option name="addGSSCredential" value="true"/>
> <module-option name="delegationCredential" value="USE"/>
> <module-option name="ticketCache" value="/tmp/krb5cc_1000"/>
> </login-module>
> </authentication>
> </security-domain>
> <security-domain name="EXAMPLE.COM">
> <authentication>
> <login-module code="SPNEGO" flag="requisite" module="org.jboss.security.negotiation">
> <module-option name="password-stacking" value="useFirstPass"/>
> <module-option name="serverSecurityDomain" value="host"/>
> </login-module>
> </authentication>
> <mapping>
> <mapping-module code="SimpleRoles" type="role">
> <module-option name="dv at EXAMPLE.COM" value="user,odata"/>
> </mapping-module>
> </mapping>
> </security-domain>
> {code}
> Kerberos client configuration:
> {code:plain}
> ClientDV {
> com.sun.security.auth.module.Krb5LoginModule required
> storeKey="true"
> useKeyTab="true"
> keyTab="${dv.test.krb.dir}/dv.keytab"
> principal="dv at EXAMPLE.COM"
> doNotPrompt="true"
> refreshKrb5Config="false"
> useTicketCache="true"
> ticketCache="/tmp/krb5cc_1000"
> debug="true";
> };
> {code}
> KRB5 configuration file is passed to server by setting system-property java.security.krb5.conf:
> {code:xml}
> <system-properties>
> <property name="java.security.krb5.conf" value="${jboss.home.dir}/krb5.conf"/>
> <property name="java.security.krb5.debug" value="true"/>
> </system-properties>
> {code}
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
More information about the teiid-issues
mailing list