Understanding UDX logging

Like UDXs, AEs have access to the integrated NPS log facility. More documentation about UDX logging can be found in the Netezza User-Defined Functions Documentation.

Enable logging for the entire system using the NPS system nzudxdbg command utility; enable logging for a specific AE through the register_ae –mask option. For example:

--mask DEBUG
--mask TRACE

The --mask option can be specified twice to include both DEBUG and TRACE output in the log file. The application code can invoke the log function with either DEBUG or TRACE, and if logging is turned on for the system and the matching log facility is enabled during AE registration (DEBUG or TRACE), the log message is delivered.

This is similar to printf style logging. The following is an example using a C++ AE:

Code

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <nzaefactory.hpp>
using namespace nz::ae;
static int run(nz::ae::NzaeFunction *aeFunc);
static int doShaper(nz::ae::NzaeShaper *aeShaper);

int main(int argc, char * argv[])
{
        NzaeApiGenerator helper;
        while (true) {
            nz::ae::NzaeApi *api = helper.getApi(nz::ae::NzaeApi::ANY, 
                    true);
            if (helper.isRemote() && !api) {
                    continue; 
            }
            if (api->apiType == nz::ae::NzaeApi::FUNCTION) {
                    api->aeFunction->log(nz::ae::NzaeFunction::LOG_TRACE, 
                            "Got Function");
                    run(api->aeFunction);
            }
            else {
                    api->aeShaper->log(nz::ae::NzaeShaper::LOG_TRACE, 
                            "Got Shaper");
                    doShaper(api->aeShaper);
            }
            if (!helper.isRemote())
                    break;
            if (api)
                    break;
    }
    return 0;
}

class MyHandler : public nz::ae::NzaeFunctionMessageHandler
{
public:
        void evaluate(NzaeFunction& api, NzaeRecord &input, 
                NzaeRecord &result) {
                        const NzaeMetadata& m = api.getMetadata();
                        nz::ae::NzaeField &field = input.get(0);
                        if (!field.isNull() ) {
                            nz::ae::NzaeField &f = result.get(0);
                            f.assign(field); 
                        } 
        }
};

class MyHandler2 : public nz::ae::NzaeShaperMessageHandler
{
public:
        void shaper(NzaeShaper& api){
                const NzaeMetadata& m = api.getMetadata();
                char name[2];
                if (api.catalogIsUpper())
                        name[0] = 'I';
                else
                        name[0] = 'i';
                name[1] = 0;
                if (m.getInputType(0) == NzaeDataTypes::NZUDSUDX_FIXED ||
                        m.getInputType(0) == NzaeDataTypes::NZUDSUDX_VARIABLE ||
                        m.getInputType(0) == NzaeDataTypes::NZUDSUDX_NATIONAL_FIXED
||
                        m.getInputType(0) ==
NzaeDataTypes::NZUDSUDX_NATIONAL_VARIABLE) {
                              api.addOutputColumnString(m.getInputType(0),  
                                      name, m.getInputSize(0));
                }
                else if (m.getInputType(0) == NzaeDataTypes::NZUDSUDX_NUMERIC128
|| 
                        m.getInputType(0) == NzaeDataTypes::NZUDSUDX_NUMERIC64 ||
                        m.getInputType(0) == NzaeDataTypes::NZUDSUDX_NUMERIC32) {
                                api.addOutputColumnNumeric(m.getInputType(0), 
                                        name, m.getInputSize(0),
                                        m.getInputScale(0));
                }
                else {
                        api.addOutputColumn(m.getInputType(0), name);
                }
        }
};

static int doShaper(nz::ae::NzaeShaper *aeShaper)
{
    aeShaper->run(new MyHandler2());
    return 0;
}
static int run(nz::ae::NzaeFunction *aeFunc)
{
    aeFunc->run(new MyHandler());
    return 0;
}

Note the following lines:

api->aeFunction->log(nz::ae::NzaeFunction::LOG_TRACE, "Got Function");
api->aeShaper->log(nz::ae::NzaeShaper::LOG_TRACE, "Got Shaper");

Compilation

Compile the AE:

$NZ_EXPORT_DIR/ae/utilities/bin/compile_ae --language cpp --template compile \
     --version 3 TestIdentity.cpp --exe testidentity

Registration

$NZ_EXPORT_DIR/ae/utilities/bin/register_ae --language cpp --version 3 \
     --template udf --sig "logger(varchar(any))" \
     --return "varchar(any)" --exe testidentity --mask TRACE

Enable Debugging

Enable debugging using nzudxdbg:

$ nzudxdbg --file
Processing 1 spus
.
done
Processing host
done

Running

To run the logger, first create a simple table:

create table s (s varchar(100));
INZA(ADMIN)=> insert into s values('20101401');
INSERT 0 1
INZA(ADMIN)=> insert into s values('20101303');
INSERT 0 1

Run the logger using the following SQL:

SELECT logger(s) FROM s; 
LOGGER
----------
20101401
20101303
(2 rows)

You then get the following in pg.log:

2010-04-27 06:38:44.848757 EDT [27656] DEBUG: Got Shaper

And the following in sysmrg.log:

2010-04-27 06:38:45.168278 EDT (event1137.1[1]) (dsid=1)[d,udx ] Got Function

The above log messages occur because the shaper runs in postgres and the function runs on the SPU.