Tue Aug 21 10:50:26.503 - INFO: Query: PREFIX fb: SELECT ?1 ?1name WHERE { fb:m.060d2 fb:government.government_office_or_title.office_holders ?0 . ?0 fb:government.government_position_held.office_holder fb:m.03kdl . ?0 fb:government.government_position_held.from ?1 . OPTIONAL {?1 fb:type.object.name ?1name} . FILTER (?1 != fb:m.060d2 && ?1 != fb:m.03kdl) } LIMIT 300 Tue Aug 21 10:50:26.503 - DEBUG: Got 2 subplans to create. Tue Aug 21 10:50:26.503 - DEBUG: Creating execution plan. Tue Aug 21 10:50:26.503 - DEBUG: Creating execution plan. Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.503 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:26.504 - DEBUG: IndexScan result computation... Tue Aug 21 10:50:26.504 - DEBUG: Performing PSO scan of relation with fixed subject: ... Tue Aug 21 10:50:26.504 - DEBUG: Scan done, got 44 elements. Tue Aug 21 10:50:26.504 - DEBUG: IndexScan result computation done. Tue Aug 21 10:50:26.504 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:26.504 - DEBUG: IndexScan result computation... Tue Aug 21 10:50:26.504 - DEBUG: Performing POS scan of relation with fixed object: ... Tue Aug 21 10:50:26.504 - DEBUG: Scan done, got 2 elements. Tue Aug 21 10:50:26.504 - DEBUG: IndexScan result computation done. Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.504 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: filter type: 1 Tue Aug 21 10:50:26.505 - DEBUG: Done creating execution plan. Tue Aug 21 10:50:26.505 - INFO: { JOIN { SCAN PSO with P = "", S = "" qet-width: 1 } join-column: [0] |X| { SORT on column:0 { FILTER { OPTIONAL_JOIN { OrderBy { JOIN { SCAN PSO with P = "" qet-width: 2 } join-column: [0] |X| { SCAN POS with P = "", O = "" qet-width: 1 } join-column: [0] qet-width: 2 } order on asc(1) qet-width: 2 } join-columns: [1] |X| { SCAN PSO with P = "" qet-width: 2 } join-columns: [0] qet-width: 3 } with col 1 != entity Id 18446744073709551614 qet-width: 3 } qet-width: 3 } join-column: [0] qet-width: 3 } Tue Aug 21 10:50:26.505 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:26.505 - DEBUG: Getting sub-results for join result computation... Tue Aug 21 10:50:26.505 - INFO: Result already (being) computed Tue Aug 21 10:50:26.506 - INFO: Result already (being) computed Tue Aug 21 10:50:26.506 - DEBUG: Resolving strings for finished binary result... Tue Aug 21 10:50:26.506 - INFO: Result already (being) computed Tue Aug 21 10:50:26.506 - DEBUG: Done creating readable result. Tue Aug 21 10:50:26.506 - DEBUG: Sent 669 bytes. Tue Aug 21 10:50:26.506 - INFO: ---------- WAITING FOR QUERY AT PORT "7,001" ... Tue Aug 21 10:50:56.950 - INFO: Incoming connection, processing... Tue Aug 21 10:50:56.950 - DEBUG: Waiting for receive call to complete. Tue Aug 21 10:50:56.950 - DEBUG: 1,369 bytes received Tue Aug 21 10:50:56.950 - DEBUG: Request Line: 'GET /?query=PREFIX%20fb%3A%20%3Chttp%3A%2F%2Frdf.freebase.com%2Fns%2F%3E%0A%0ASELECT%20%20%20%20%3F1%20%3F1name%20WHERE%20%7B%0A%20%3F0%20fb%3Agovernment.government_position_held.office_holder%20fb%3Am.03kdl%20.%0A%20%3F0%20fb%3Agovernment.government_position_held.from%20%3F1%20.%0A%20OPTIONAL%20%7B%3F1%20fb%3Atype.object.name%20%3F1name%7D%20.%0A%20FILTER%20(%3F1%20!%3D%20fb%3Am.060d2%20%26%26%20%3F1%20!%3D%20fb%3Am.03kdl)%20%0A%7D%20LIMIT%20300&cmd=clearcache&send=100 HTTP/1.1' Tue Aug 21 10:50:56.951 - DEBUG: Headers: ' Host: fiji.informatik.privat:7001 Accept: application/json, text/javascript, */*; q=0.01 X-Requested-With: XMLHttpRequest User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36 Referer: http://fiji.informatik.privat:7001/index.html?query=PREFIX%20fb%3A%20%3Chttp%3A%2F%2Frdf.freebase.com%2Fns%2F%3E%0A%0ASELECT%20%20%20%20%3F1%20%3F1name%20WHERE%20%7B%0A%20%3F0%20fb%3Agovernment.government_position_held.office_holder%20fb%3Am.03kdl%20.%0A%20%3F0%20fb%3Agovernment.government_position_held.from%20%3F1%20.%0A%20OPTIONAL%20%7B%3F1%20fb%3Atype.object.name%20%3F1name%7D%20.%0A%20FILTER%20(%3F1%20!%3D%20fb%3Am.060d2%20%26%26%20%3F1%20!%3D%20fb%3Am.03kdl)%20%0A%7D%20LIMIT%20300&cmd=clearcache&send=100 Accept-Language: en-US,en;q=0.9,de;q=0.8 X-Forwarded-For: 10.8.152.88 Accept-Encoding: gzip X-Varnish: 32771 ' Tue Aug 21 10:50:56.951 - DEBUG: Got request from client with size: 483 and headers with total size: 886 Tue Aug 21 10:50:56.951 - DEBUG: Parsing HTTP Request. Tue Aug 21 10:50:56.951 - DEBUG: Done parsing HTTP Request. Tue Aug 21 10:50:56.951 - INFO: Query: PREFIX fb: SELECT ?1 ?1name WHERE { ?0 fb:government.government_position_held.office_holder fb:m.03kdl . ?0 fb:government.government_position_held.from ?1 . OPTIONAL {?1 fb:type.object.name ?1name} . FILTER (?1 != fb:m.060d2 && ?1 != fb:m.03kdl) } LIMIT 300 Tue Aug 21 10:50:56.951 - DEBUG: Got 2 subplans to create. Tue Aug 21 10:50:56.951 - DEBUG: Creating execution plan. Tue Aug 21 10:50:56.951 - DEBUG: Creating execution plan. Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.951 - DEBUG: IndexScan result computation... Tue Aug 21 10:50:56.951 - DEBUG: Performing POS scan of relation with fixed object: ... Tue Aug 21 10:50:56.951 - DEBUG: Scan done, got 2 elements. Tue Aug 21 10:50:56.951 - DEBUG: IndexScan result computation done. Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.951 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.952 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.952 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.952 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.952 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.952 - DEBUG: filter type: 1 Tue Aug 21 10:50:56.952 - DEBUG: Done creating execution plan. Tue Aug 21 10:50:56.952 - INFO: { OPTIONAL_JOIN { OrderBy { FILTER { JOIN { SCAN PSO with P = "" qet-width: 2 } join-column: [0] |X| { SCAN POS with P = "", O = "" qet-width: 1 } join-column: [0] qet-width: 2 } with col 1 != entity Id 18446744073709551614 qet-width: 2 } order on asc(1) qet-width: 2 } join-columns: [1] |X| { SCAN PSO with P = "" qet-width: 2 } join-columns: [0] qet-width: 3 } Tue Aug 21 10:50:56.952 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.952 - DEBUG: OptionalJoin result computation... Tue Aug 21 10:50:56.952 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.952 - DEBUG: Gettign sub-result for OrderBy result computation... Tue Aug 21 10:50:56.952 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.952 - DEBUG: Getting sub-result for Filter result computation... Tue Aug 21 10:50:56.952 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.952 - DEBUG: Getting sub-results for join result computation... Tue Aug 21 10:50:56.952 - INFO: Result already (being) computed Tue Aug 21 10:50:56.952 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.952 - DEBUG: IndexScan result computation... Tue Aug 21 10:50:56.952 - DEBUG: Performing PSO scan for full relation: Tue Aug 21 10:50:56.952 - DEBUG: Scan done, got 21,371 elements. Tue Aug 21 10:50:56.952 - DEBUG: IndexScan result computation done. Tue Aug 21 10:50:56.952 - INFO: Result already (being) computed Tue Aug 21 10:50:56.952 - DEBUG: Join result computation... Tue Aug 21 10:50:56.952 - DEBUG: Performing join between two fixed width tables. Tue Aug 21 10:50:56.952 - DEBUG: A: witdth = 2, size = 21,371 Tue Aug 21 10:50:56.952 - DEBUG: B: witdth = 1, size = 2 Tue Aug 21 10:50:56.952 - DEBUG: Galloping case. Tue Aug 21 10:50:56.952 - DEBUG: Join done. Tue Aug 21 10:50:56.952 - DEBUG: Result: width = 2, size = 1 Tue Aug 21 10:50:56.952 - DEBUG: Join result computation done. Tue Aug 21 10:50:56.952 - DEBUG: Filter result computation... Tue Aug 21 10:50:56.952 - DEBUG: Filter result computation... Tue Aug 21 10:50:56.952 - INFO: Result already (being) computed Tue Aug 21 10:50:56.952 - DEBUG: Filtering 1 elements. Tue Aug 21 10:50:56.952 - DEBUG: Filter done, size now: 1 elements. Tue Aug 21 10:50:56.952 - DEBUG: Filter result computation done. Tue Aug 21 10:50:56.952 - DEBUG: OrderBy result computation... Tue Aug 21 10:50:56.952 - DEBUG: Sorting 1 elements. Tue Aug 21 10:50:56.952 - DEBUG: Sort done. Tue Aug 21 10:50:56.952 - DEBUG: OrderBy result computation done. Tue Aug 21 10:50:56.952 - DEBUG: We were the first to emplace, need to compute result Tue Aug 21 10:50:56.952 - DEBUG: IndexScan result computation... Tue Aug 21 10:50:56.952 - DEBUG: Performing PSO scan for full relation: Tue Aug 21 10:50:57.422 - DEBUG: Scan done, got 47,236,131 elements. Tue Aug 21 10:50:57.422 - DEBUG: IndexScan result computation done. Tue Aug 21 10:50:57.422 - DEBUG: Computing optional join between results of size 1 and 47,236,131 Tue Aug 21 10:50:57.422 - DEBUG: Left side optional: 0 right side optional: 1 Tue Aug 21 10:50:57.512 - DEBUG: OptionalJoin result computation done. Tue Aug 21 10:50:57.512 - INFO: Result already (being) computed Tue Aug 21 10:50:57.512 - DEBUG: Resolving strings for finished binary result... Tue Aug 21 10:50:57.512 - INFO: Result already (being) computed Tue Aug 21 10:50:57.512 - DEBUG: Done creating readable result. Tue Aug 21 10:50:57.512 - DEBUG: Sent 676 bytes. Tue Aug 21 10:50:57.512 - INFO: ---------- WAITING FOR QUERY AT PORT "7,001" ...