making tmpdir
[Wed Jun 27 16:28:22 +0200 2012] [main] [debug] 'tmpdir: C:/Users/KMALEW~1/AppData/Local/Temp/mydatamart_1988'
[Wed Jun 27 16:28:48 +0200 2012] [main] [debug] 'dhis(status) = C:/Temp/Test.dmart open'
[Wed Jun 27 16:28:48 +0200 2012] [main] [debug] 'New datamart created at C:/Temp/Test.dmart'
[Wed Jun 27 16:28:48 +0200 2012] [main] [debug] 'dhis(status) = No orgunit data - you need to download metadata'
[Wed Jun 27 16:29:03 +0200 2012] [main] [debug] 'dhis(status) = Logging in to http://localhost:8082'
[Wed Jun 27 16:29:03 +0200 2012] [dhisweb] [debug] '{Using sock1212 for localhost:8082} {}'
[Wed Jun 27 16:29:03 +0200 2012] [main] [debug] 'Persisting url'
[Wed Jun 27 16:29:03 +0200 2012] [main] [debug] 'Persisting username'
[Wed Jun 27 16:29:03 +0200 2012] [dhisweb] [debug] '{Closing socket sock1212 (no connection info)}'
[Wed Jun 27 16:29:03 +0200 2012] [dhisweb] [debug] 'in loginCallback'
[Wed Jun 27 16:29:03 +0200 2012] [dhisweb] [debug] 'login success'
[Wed Jun 27 16:29:03 +0200 2012] [main] [debug] 'login status: LSUCCESS'
[Wed Jun 27 16:29:03 +0200 2012] [main] [debug] 'dhis(status) = Logged in'
[Wed Jun 27 16:29:07 +0200 2012] [dhisweb] [debug] 'fetching metadata'
[Wed Jun 27 16:29:07 +0200 2012] [dhisweb] [debug] '{Using sock1228 for localhost:8082} {}'
finally
[Wed Jun 27 16:29:07 +0200 2012] [main] [debug] 'dhis(status) = Downloading metadata'
[Wed Jun 27 16:29:07 +0200 2012] [main] [debug] 'Metadata download success'
[Wed Jun 27 16:29:07 +0200 2012] [main] [debug] 'extracting zip'
[Wed Jun 27 16:29:07 +0200 2012] [main] [debug] 'transforming metadata'
[Wed Jun 27 16:29:07 +0200 2012] [main] [debug] 'dhis(status) = Transforming metadata'
[Wed Jun 27 16:29:07 +0200 2012] [dhisweb] [debug] '{Closing socket sock1228 (no connection info)}'
[Wed Jun 27 16:29:07 +0200 2012] [dhisweb] [debug] 'Metadata download done: HTTP/1.1 200 OK'
[Wed Jun 27 16:29:12 +0200 2012] [main] [debug] 'transform: Done'
[Wed Jun 27 16:29:12 +0200 2012] [main] [debug] 'Transform metadata done'
[Wed Jun 27 16:29:12 +0200 2012] [main] [debug] 'dhis(status) = Importing metadata'
[Wed Jun 27 16:29:12 +0200 2012] [main] [debug] 'dhis(status) = Generating views'
[Wed Jun 27 16:29:13 +0200 2012] [main] [debug] 'dhis(status) = Metadata import done'
[Wed Jun 27 16:29:15 +0200 2012] [main] [debug] 'Persisting myorgunit'
[Wed Jun 27 16:29:15 +0200 2012] [main] [debug] 'Persisting myorgunitid'
[Wed Jun 27 16:29:15 +0200 2012] [main] [debug] 'Persisting parentorgunit'
[Wed Jun 27 16:29:15 +0200 2012] [main] [debug] 'Persisting parentorgunitid'
[Wed Jun 27 16:29:18 +0200 2012] [main] [debug] 'Persisting myorgunit'
[Wed Jun 27 16:29:18 +0200 2012] [main] [debug] 'Persisting myorgunitid'
[Wed Jun 27 16:29:18 +0200 2012] [main] [debug] 'Persisting parentorgunit'
[Wed Jun 27 16:29:18 +0200 2012] [main] [debug] 'Persisting parentorgunitid'
[Wed Jun 27 16:29:20 +0200 2012] [main] [debug] 'Persisting myorgunit'
[Wed Jun 27 16:29:20 +0200 2012] [main] [debug] 'Persisting myorgunitid'
[Wed Jun 27 16:29:20 +0200 2012] [main] [debug] 'Persisting parentorgunit'
[Wed Jun 27 16:29:20 +0200 2012] [main] [debug] 'Persisting parentorgunitid'
[Wed Jun 27 16:29:23 +0200 2012] [main] [debug] 'Persisting myorgunit'
[Wed Jun 27 16:29:23 +0200 2012] [main] [debug] 'Persisting myorgunitid'
[Wed Jun 27 16:29:23 +0200 2012] [main] [debug] 'Persisting parentorgunit'
[Wed Jun 27 16:29:23 +0200 2012] [main] [debug] 'Persisting parentorgunitid'
[Wed Jun 27 16:29:26 +0200 2012] [main] [debug] 'level and orgunit are set.  ok to download'
[Wed Jun 27 16:29:26 +0200 2012] [main] [debug] 'level select from .win.display.ou.level is 4'
[Wed Jun 27 16:29:26 +0200 2012] [main] [debug] 'Persisting level'
[Wed Jun 27 16:29:30 +0200 2012] [main] [debug] 'last: 197912 ; current: 201206'
179 4 1 297 174 179 {} {} {} {}
[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'Download periods 20120101 20120628'
[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'dhis(status) = Downloading aggregate data'
delete old values
[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'Downloading for monthly datavalue'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'fetching monthly DataValues with : JSESSIONID=2k70yo4s50oc1kade1bwqbs8x'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'http params: dataSourceLevel=4&dataSourceRoot=179&startDate=20120101&endDate=20120628'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] '{Using sock764 for localhost:8082} {}'
delete old values
[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'Downloading for monthly indicator'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'fetching monthly IndicatorValues with : JSESSIONID=2k70yo4s50oc1kade1bwqbs8x'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'http params: dataSourceLevel=4&dataSourceRoot=179&startDate=20120101&endDate=20120628'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] '{Using sock1008 for localhost:8082} {}'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'datavalue callback http: 200'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'http ok : there should be data available'
metadata(Content-Type) = text/html; charset=utf-8
metadata(Server)       = Jetty(6.1.x)

[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'monthly,indicator finished: error'
::http::4(-binary)         = false
::http::4(-blocksize)      = 8192
::http::4(-command)        = ::dhisweb::datavalueFinishHandler
::http::4(-handler)        = ::dhisweb::datavalueCallback
::http::4(-headers)        = Cookie JSESSIONID=2k70yo4s50oc1kade1bwqbs8x
::http::4(-keepalive)      = 0
::http::4(-protocol)       = 1.0
::http::4(-query)          = dataSourceLevel=4&dataSourceRoot=179&startDate=20120101&endDate=20120628
::http::4(-queryblocksize) = 8192
::http::4(-queryprogress)  = 
::http::4(-strict)         = 1
::http::4(-timeout)        = 0
::http::4(-type)           = application/x-www-form-urlencoded
::http::4(-validate)       = 0
::http::4(binary)          = 0
::http::4(body)            = 
::http::4(charset)         = utf-8
::http::4(coding)          = 
::http::4(connection)      = close
::http::4(currentsize)     = 0
::http::4(db)              = db
::http::4(error)           = {can't read "metadata(X-Number-Of-Rows)": no such element in array} {can't read "metadata(X-Number-Of-Rows)": no such element in array
    while executing
"set state(valuesToRead) $metadata(X-Number-Of-Rows)"
    (procedure "::dhisweb::datavalueCallback" line 25)
    invoked from within
"::dhisweb::datavalueCallback sock1008 ::http::4"
    ("eval" body line 1)
    invoked from within
"eval $state(-handler) [list $sock $token]"} {TCL READ VARNAME}
::http::4(http)            = HTTP/1.1 200 OK
::http::4(meta)            = Content-Type {text/html; charset=utf-8} Server Jetty(6.1.x)
::http::4(periodtype)      = monthly
::http::4(querylength)     = 72
::http::4(queryoffset)     = 72
::http::4(sock)            = sock1008
::http::4(socketinfo)      = localhost:8082
::http::4(state)           = body
::http::4(status)          = error
::http::4(totalsize)       = 0
::http::4(type)            = text/html; charset=utf-8
::http::4(url)             = http://localhost:8082/dhis-web-reporting/exp/monthlyIndicatorValues.action
::http::4(valuesRead)      = 0
::http::4(valuesToRead)    = 0
::http::4(valuetype)       = IndicatorValues
[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'dhis(status) = Download failed - see console for detailed error'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] '{Closing socket sock1008 (no connection info)}'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'finished: error'
::http::4(-binary)         = false
::http::4(-blocksize)      = 8192
::http::4(-command)        = ::dhisweb::datavalueFinishHandler
::http::4(-handler)        = ::dhisweb::datavalueCallback
::http::4(-headers)        = Cookie JSESSIONID=2k70yo4s50oc1kade1bwqbs8x
::http::4(-keepalive)      = 0
::http::4(-protocol)       = 1.0
::http::4(-query)          = dataSourceLevel=4&dataSourceRoot=179&startDate=20120101&endDate=20120628
::http::4(-queryblocksize) = 8192
::http::4(-queryprogress)  = 
::http::4(-strict)         = 1
::http::4(-timeout)        = 0
::http::4(-type)           = application/x-www-form-urlencoded
::http::4(-validate)       = 0
::http::4(binary)          = 0
::http::4(body)            = 
::http::4(charset)         = utf-8
::http::4(coding)          = 
::http::4(connection)      = close
::http::4(currentsize)     = 0
::http::4(db)              = db
::http::4(error)           = {can't read "metadata(X-Number-Of-Rows)": no such element in array} {can't read "metadata(X-Number-Of-Rows)": no such element in array
    while executing
"set state(valuesToRead) $metadata(X-Number-Of-Rows)"
    (procedure "::dhisweb::datavalueCallback" line 25)
    invoked from within
"::dhisweb::datavalueCallback sock1008 ::http::4"
    ("eval" body line 1)
    invoked from within
"eval $state(-handler) [list $sock $token]"} {TCL READ VARNAME}
::http::4(http)            = HTTP/1.1 200 OK
::http::4(meta)            = Content-Type {text/html; charset=utf-8} Server Jetty(6.1.x)
::http::4(periodtype)      = monthly
::http::4(querylength)     = 72
::http::4(queryoffset)     = 72
::http::4(sock)            = sock1008
::http::4(socketinfo)      = localhost:8082
::http::4(state)           = body
::http::4(status)          = error
::http::4(totalsize)       = 0
::http::4(type)            = text/html; charset=utf-8
::http::4(url)             = http://localhost:8082/dhis-web-reporting/exp/monthlyIndicatorValues.action
::http::4(valuesRead)      = 0
::http::4(valuesToRead)    = 0
::http::4(valuetype)       = IndicatorValues
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'datavalue callback http: 200'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'http ok : there should be data available'
metadata(Content-Type) = text/html; charset=utf-8
metadata(Server)       = Jetty(6.1.x)

[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'monthly,datavalue finished: error'
::http::3(-binary)         = false
::http::3(-blocksize)      = 8192
::http::3(-command)        = ::dhisweb::datavalueFinishHandler
::http::3(-handler)        = ::dhisweb::datavalueCallback
::http::3(-headers)        = Cookie JSESSIONID=2k70yo4s50oc1kade1bwqbs8x
::http::3(-keepalive)      = 0
::http::3(-protocol)       = 1.0
::http::3(-query)          = dataSourceLevel=4&dataSourceRoot=179&startDate=20120101&endDate=20120628
::http::3(-queryblocksize) = 8192
::http::3(-queryprogress)  = 
::http::3(-strict)         = 1
::http::3(-timeout)        = 0
::http::3(-type)           = application/x-www-form-urlencoded
::http::3(-validate)       = 0
::http::3(binary)          = 0
::http::3(body)            = 
::http::3(charset)         = utf-8
::http::3(coding)          = 
::http::3(connection)      = close
::http::3(currentsize)     = 0
::http::3(db)              = db
::http::3(error)           = {can't read "metadata(X-Number-Of-Rows)": no such element in array} {can't read "metadata(X-Number-Of-Rows)": no such element in array
    while executing
"set state(valuesToRead) $metadata(X-Number-Of-Rows)"
    (procedure "::dhisweb::datavalueCallback" line 25)
    invoked from within
"::dhisweb::datavalueCallback sock764 ::http::3"
    ("eval" body line 1)
    invoked from within
"eval $state(-handler) [list $sock $token]"} {TCL READ VARNAME}
::http::3(http)            = HTTP/1.1 200 OK
::http::3(meta)            = Content-Type {text/html; charset=utf-8} Server Jetty(6.1.x)
::http::3(periodtype)      = monthly
::http::3(querylength)     = 72
::http::3(queryoffset)     = 72
::http::3(sock)            = sock764
::http::3(socketinfo)      = localhost:8082
::http::3(state)           = body
::http::3(status)          = error
::http::3(totalsize)       = 0
::http::3(type)            = text/html; charset=utf-8
::http::3(url)             = http://localhost:8082/dhis-web-reporting/exp/monthlyDataValues.action
::http::3(valuesRead)      = 0
::http::3(valuesToRead)    = 0
::http::3(valuetype)       = DataValues
[Wed Jun 27 16:29:38 +0200 2012] [main] [debug] 'dhis(status) = Download failed - see console for detailed error'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] '{Closing socket sock764 (no connection info)}'
[Wed Jun 27 16:29:38 +0200 2012] [dhisweb] [debug] 'finished: error'
::http::3(-binary)         = false
::http::3(-blocksize)      = 8192
::http::3(-command)        = ::dhisweb::datavalueFinishHandler
::http::3(-handler)        = ::dhisweb::datavalueCallback
::http::3(-headers)        = Cookie JSESSIONID=2k70yo4s50oc1kade1bwqbs8x
::http::3(-keepalive)      = 0
::http::3(-protocol)       = 1.0
::http::3(-query)          = dataSourceLevel=4&dataSourceRoot=179&startDate=20120101&endDate=20120628
::http::3(-queryblocksize) = 8192
::http::3(-queryprogress)  = 
::http::3(-strict)         = 1
::http::3(-timeout)        = 0
::http::3(-type)           = application/x-www-form-urlencoded
::http::3(-validate)       = 0
::http::3(binary)          = 0
::http::3(body)            = 
::http::3(charset)         = utf-8
::http::3(coding)          = 
::http::3(connection)      = close
::http::3(currentsize)     = 0
::http::3(db)              = db
::http::3(error)           = {can't read "metadata(X-Number-Of-Rows)": no such element in array} {can't read "metadata(X-Number-Of-Rows)": no such element in array
    while executing
"set state(valuesToRead) $metadata(X-Number-Of-Rows)"
    (procedure "::dhisweb::datavalueCallback" line 25)
    invoked from within
"::dhisweb::datavalueCallback sock764 ::http::3"
    ("eval" body line 1)
    invoked from within
"eval $state(-handler) [list $sock $token]"} {TCL READ VARNAME}
::http::3(http)            = HTTP/1.1 200 OK
::http::3(meta)            = Content-Type {text/html; charset=utf-8} Server Jetty(6.1.x)
::http::3(periodtype)      = monthly
::http::3(querylength)     = 72
::http::3(queryoffset)     = 72
::http::3(sock)            = sock764
::http::3(socketinfo)      = localhost:8082
::http::3(state)           = body
::http::3(status)          = error
::http::3(totalsize)       = 0
::http::3(type)            = text/html; charset=utf-8
::http::3(url)             = http://localhost:8082/dhis-web-reporting/exp/monthlyDataValues.action
::http::3(valuesRead)      = 0
::http::3(valuesToRead)    = 0
::http::3(valuetype)       = DataValues
(Installs) 1 %