better error reporting in log

[andreasbaumann]

For instance when deleting a document we want to see at least:

• when
• the docid attribute
• the transaction id (when transaction management is explicit)

At the moment we get:

2016-10-19 16:45:04; cppcms_http, info: POST /strus/document/delete/rrb (http_api.cpp:251)
2016-10-19 16:45:06; strusWebService, info: delete(rrb, <implicit>, 958-2016, 2.20212s) (document.cpp:394)

[andreasbaumann]

Actually no: delete is a bad example. There we get exactly the information we need.

TODO: find other examples.

[andreasbaumann]

Actually the problem is we get the interesting data only in the sunshine case, for instance when the delete succeeds. If the document is missing we get back an error in JSON to the client, but we don't see anything interesting in the log.

[andreasbaumann]

Similar case. There seems to be an error 500 Internal Server error happening and no traces are in the logfile.

[andreasbaumann]

The 500 error was not caused in the strusWebService but in a layer above..

[andreasbaumann]

    {
        if( !transaction ) {
            service.unlockIndex( name );
            report_error( ERROR_DOCUMENT_DELETE_CMD_CREATE_STORAGE_TRANSACTION, "Referencing illegal transaction, no begin transaction seen before" );
            return;
    }

...

    cppcms::json::value j;
    double execution_time = (double)timer.elapsed( ).wall / (double)1000000000;
    j["execution_time"] = execution_time;

    BOOSTER_INFO( PACKAGE ) << "delete(" << name << ", " << ( ( trans_id == "" ) ? "<implicit>" : trans_id ) << ", " << docid << ", " << std::fixed << std::setprecision( 6 ) << execution_time << "s)";
    std::ostringstream ss;
    if( protocol_pretty_printing ) {
        j.save( ss, cppcms::json::readable );
    } else {
        j.save( ss, cppcms::json::compact );
    }
    BOOSTER_DEBUG( PACKAGE ) << "delete(" << name << ", " << ( ( trans_id == "" ) ? "<implicit>" : trans_id ) << ", " << docid << "): " << ss.str( );

    report_ok( j );

All code must be refactored, highly to repetitive and the logging should happen in all report_error cases too.

[andreasbaumann]

Dito debugging output in all error cases.