How to log "console.log(..)" from sync function to a file?

jda · August 2, 2019, 9:27am

Hi

I’m trying to develop my sync formula further to handle all syncs to mobile correctly. I have a need for seeing “print” statements from my own code somewhere. I run SG on CentOS as a service . As far as I understand my own console.log(...) statements are sent to the console - but that is probably just a “dark hole” when SG is running as a service…

I get this in the beginning of the sg_info.log file when starting SG:

[root@ds9 logs]# cat sg_info.log 
2019-08-02T11:03:44.114+02:00 ==== Couchbase Sync Gateway/2.5.1(12;3f5ce5d) CE ====
2019-08-02T11:03:44.114+02:00 [INF] Logging: Console to stderr
2019-08-02T11:03:44.114+02:00 [INF] Logging: Files to /home/sync_gateway/logs
2019-08-02T11:03:44.114+02:00 [INF] Logging: Console level: info
2019-08-02T11:03:44.114+02:00 [INF] Logging: Console keys: [HTTP HTTP+ Sync]
2019-08-02T11:03:44.114+02:00 [INF] Logging: Redaction level: none
2019-08-02T11:03:44.114+02:00 [INF] requestedSoftFDLimit >= currentHardFdLimit (5000 >= 4096) capping at 4096
2019-08-02T11:03:44.114+02:00 [INF] Configured process to allow 4096 open file descriptors
2019-08-02T11:03:44.114+02:00 [INF] Logging stats with frequency: 1m0s
2019-08-02T11:03:44.114+02:00 [INF] Opening db /data as bucket "data", pool "default", server <http://ds9:8091>
2019-08-02T11:03:44.115+02:00 [INF] GoCBCustomSGTranscoder Opening Couchbase database data on <http://ds9:8091> as user "remoteSync"
2019-08-02T11:03:44.115+02:00 [INF] Auth: Attempting credential authentication http://ds9:8091?http_idle_conn_timeout=90000&http_max_idle_conns=64000&http_max_idle_conns_per_host=256&n1ql_timeout=75000
2019-08-02T11:03:44.120+02:00 [INF] Successfully opened bucket data
2019-08-02T11:03:44.120+02:00 [INF] Set query timeouts for bucket data to cluster:1m15s, bucket:1m15s
2019-08-02T11:03:44.123+02:00 [INF] Initializing indexes with numReplicas: 0...
2019-08-02T11:03:44.217+02:00 [INF] Verifying index availability for bucket data...
2019-08-02T11:03:44.241+02:00 [INF] Indexes ready for bucket data.
2019-08-02T11:03:44.242+02:00 [INF] delta_sync enabled=false with rev_max_age_seconds=86400 for database data
2019-08-02T11:03:44.242+02:00 [INF] Cache: Initializing changes cache with options {ChannelCacheOptions:{ChannelCacheMinLength:50 ChannelCacheMaxLength:500 ChannelCacheAge:1m0s} CachePendingSeqMaxWait:5s CachePendingSeqMaxNum:10000 CacheSkippedSeqMaxWait:1h0m0s}
2019-08-02T11:03:44.242+02:00 [INF] Initializing changes cache for database data
2019-08-02T11:03:44.242+02:00 [INF] DCP: Starting mutation feed on bucket data due to either channel cache mode or doc tracking (auto-import/bucketshadow)
2019-08-02T11:03:44.242+02:00 [INF] DCP: Using DCP feed for bucket: "data" (based on feed_type specified in config file)
2019-08-02T11:03:44.429+02:00 [INF] Using metadata purge interval of 3.00 days for tombstone compaction.
2019-08-02T11:03:44.434+02:00 [INF] **NOTE:** "data"'s sync function has changed. The new function may assign different channels to documents, or permissions to users. You may want to re-sync the database to update these.
2019-08-02T11:03:44.434+02:00 [INF] Reset guest user to config
2019-08-02T11:03:44.434+02:00 [INF] Starting admin server on 0.0.0.0:4985
2019-08-02T11:03:44.436+02:00 [INF] Starting server on 0.0.0.0:4984 ...
2019-08-02T11:03:44.440+02:00 [INF] CBGoUtilsLogger: Using plain authentication for user <ud>remoteSync</ud>
2019-08-02T11:03:44.522+02:00 [INF] DCP: Backfill in progress: 0% (1 / 8826)
2019-08-02T11:03:44.830+02:00 [INF] Import: Created new rev ID for doc "Bait:17" / "2-b253eae98d1c76931091353c1f57c9a5"
2019-08-02T11:03:44.848+02:00 [INF] Sync fn rejected doc "Bait:17" / "" --> 403 Document type is required.
2019-08-02T11:03:44.848+02:00 [INF] Import: Error importing doc "Bait:17": 403 Document type is required.
2019-08-02T11:03:45.187+02:00 [INF] Import: Created new rev ID for doc "Bait:19" / "2-6b68d5407541e11bd883cda9f8cace7c"
2019-08-02T11:03:45.187+02:00 [INF] Sync fn rejected doc "Bait:19" / "" --> 403 Document type is required.
2019-08-02T11:03:45.187+02:00 [INF] Import: Error importing doc "Bait:19": 403 Document type is required.
2019-08-02T11:03:45.207+02:00 [INF] Import: Created new rev ID for doc "FishingTrip:A92742C44703D243C12583F400621F01" / "2-10ecf8499b1e97ee202a8da9d79f0637"
2019-08-02T11:03:45.208+02:00 [INF] Sync fn rejected doc "FishingTrip:A92742C44703D243C12583F400621F01" / "" --> 403 Document type is required.
2019-08-02T11:03:45.208+02:00 [INF] Import: Error importing doc "FishingTrip:A92742C44703D243C12583F400621F01": 403 Document type is required.
2019-08-02T11:03:45.209+02:00 [INF] Import: Created new rev ID for doc "ActivityLog:9A44B7186F56BFF7C1258410002C9C02" / "1-53e279f9ac845ea3aa773866b21f7473"
2019-08-02T11:03:45.209+02:00 [INF] Sync fn rejected doc "ActivityLog:9A44B7186F56BFF7C1258410002C9C02" / "" --> 403 Document type not allowed to sync to mobile...

I guess that what I see here are the results of throw statements (where I can see that I have misunderstood something that needs to be fixed ).

I can also see that the Console is send to stderr - and I’m not sure where to find that for the service (I have looked without any success).

This is my sync function’ s logging section:

        "logging": {
                "console": {
                        "color_enabled": true,
                        "log_keys": ["HTTP+", "Sync"]
                        }
                },
            :

And here is my sync function with the code I try to use to “print” info about the data:

                        "sync": `function (doc, oldDoc) {
    function _log(t) {
        // Does not work - yet...
        console.log('SG: ' + t);
    }
    function _getUserKey(d) {
        var key = null;
        if (d) {
            if (d.type == 'User') {
                key = d.key;
            } else if (d.type == 'FishingTrip' || d.type == 'Catch' || d.type == 'Photo' || d.type == 'Private' || d.type == 'Image' || d.type == 'Feedback') {
                // TODO: Not sure about Feedback here....??
                key = d.userkey;
            }
	}
	return key;
    }

    if (doc && doc._deleted && oldDoc) {
        // Doc. deleted -> if public then require
/*
  	var userkey = _getUserKey(oldDoc);
        if (userkey != null) {
            requireUser(userkey);
        } else {
            channel('!');
            requireAdmin();
        }
*/
  	_log('doc deleted, id: ' + (doc._id || 'no id!') + ', ' + (oldDoc ? ('old key=' + oldDoc.key + ', userkey=' + oldDoc.userkey) : 'no oldDoc'));
        return;
    }
    // Document type is mandatory
    if (doc.type == undefined) {
        throw ({ forbidden: "Document type is required." });
    }
    // Some document types not allowed on mobile
    if (doc.type == 'EnvLake' || doc.type == 'EnvMeasurement' || doc.type == 'ActivityLog' || doc.type == 'Image') {
        throw ({ forbidden: "Document type not allowed to sync to mobile..." });
    }
    // Document key is mandatory
    if (doc.key == undefined) {
        throw ({ forbidden: "Document key is required." });
    }
    // Allow anyone to create a Feedback on the server
    if (oldDoc == null && doc.type == 'Feedback') {
        _log('Created feedback: ' + (doc._id || 'no id!') + ', key: ' + doc.key + ', user: ' + doc.userkey);
        return;
    }

    // All public docs are available in the app
    if (doc.ispublic) {
        _log('public, id: ' + (doc._id || 'no id!'));
        channel('!');
    }
    // All non-club fishing trips and catches are available (for stats)
    if ((doc.type == 'FishingTrip' || doc.type == 'Catch') && doc.clubonlykey == undefined) {
        _log('non-club trips, id: ' + (doc._id || 'no id!'));
        channel('!');
    }
    // All non-specific user info is available (for stats)
    if (doc.type == 'User') {
        _log('User doc, id: ' + (doc._id || 'no id!'));
        channel('!');
    }

    // Only non-public docs "owned" by user can be replicated
    var userkey = _getUserKey(doc);
    if (userkey != null) {
        if (oldDoc != null) {
            // Update
            if (oldDoc.type != doc.type) {
                throw ({ forbidden: "Can't change doc type" });
            }
            if (oldDoc.key != doc.key) {
                throw ({ forbidden: "Can't change doc key" });
            }
            if (oldDoc.userkey && oldDoc.userkey != doc.userkey) {
                throw ({ forbidden: "Can't change user key" });
            }
	}
	_log('User owned, id: ' + (doc._id || 'no id!') + ', type: ' + doc.type + ', user: ' + doc.userkey);
        if(doc.ispublic){
            requireAdmin();
        }
	requireUser(userkey);
        channel('channel.' + userkey);
        access(userkey, 'channel.' + userkey);
    }
    // TODO: Check if covered:
    // Creation of new Feedback docs (perhaps without userkey)?
    // Creation of new docs?
    // Updates to existing docs?
    // Readonly for all non-user specific docs...
}`,

So basically, I have a number of “public” documents that should be synced to the device - but never synced back. And then I have a number of documents owned by the user (same userkey) that the user can update/create.

I have a “feeling” that I need to better understand the concepts of oldDoc and doc to understand the “direction” of the sync - and then what to do with it.

If there are any other ways to debug this function then I’m quite open to that as well!

Thanks in advance!
/John

priya.rajagopal · September 13, 2019, 3:51am

Starting 2.6, console.log(…) output will be directed to Sync Gateway sg_info.log files .

Also, noticed you have

// Some document types not allowed on mobile
if (doc.type == ‘EnvLake’ || doc.type == ‘EnvMeasurement’ || doc.type == ‘ActivityLog’ || doc.type == ‘Image’) {
throw ({ forbidden: “Document type not allowed to sync to mobile…” });
}

If you don’t have documents to be synced to mobile , make sure you specify import filter

jda · September 13, 2019, 8:13am

Thanks for the “heads up” on the import filter. Is that a new thing? - or have I just not been able to see the forrest for all the trees (don’t know if that saying translates well to English, but… )

I have a special case of the above:

I have a Feedback document that the user on the mobile should be able to create - but Feedback docs. from the server should never be sync’ed to mobile. Should I just include it in the import filter to let the sync. gateway ignore them from the server?

I suppose I could just use the code I have - but the less number of documents that the sync. gateway should look at the better, I guess…

priya.rajagopal · September 13, 2019, 1:41pm

Nope. import filters has been around since version 1.5 when we announced shared bucket access.

I suppose I could just use the code I have - but the less number of documents that the sync. gateway should look at the better, I guess…

Yes. Would not recommend that. Use import filters .

jda · October 4, 2019, 10:59am

Hi Priya

I implemented an import filter following your suggestions.

However, it is not behaving exactly the way I expected…

This is my import filter:

function(doc) {
    // Some document types not allowed on mobile
    if (doc.type == 'EnvLake' || doc.type == 'EnvMeasurement' || doc.type == 'ActivityLog' || doc.type == 'Image') {
        return false;
    }
    if ((doc.type == 'FishingTrip' || doc.type == 'Catch') && typeof doc.clubonlykey !== 'undefined' && doc.clubonlykey != '') {
        return false;
    }
    return true;
}

And this is my sync function after I added the import filter:

function(doc) {
    // Some document types not allowed on mobile
    if (doc.type == 'EnvLake' || doc.type == 'EnvMeasurement' || doc.type == 'ActivityLog' || doc.type == 'Image') {
        return false;
    }
    if ((doc.type == 'FishingTrip' || doc.type == 'Catch') && typeof doc.clubonlykey !== 'undefined' && doc.clubonlykey != '') {
        return false;
    }
    return true;
}
`,
"sync": `
function (doc, oldDoc) {
    function _log(t) {
        // Does not work - yet...
        console.log('SG: ' + t);
    }
    function _getUserKey(d) {
        var key = null;
        if (d) {
            if (d.type == 'User') {
                key = d.key;
            } else if (d.type == 'FishingTrip' || d.type == 'Catch' || d.type == 'Photo' || d.type == 'Private' || d.type == 'Image' || d.type == 'Feedback') {
                // TODO: Not sure about Feedback here....??
                key = d.userkey;
            }
        }
        return key;
    }

    if (doc && doc._deleted && oldDoc) {
        // Doc. deleted -> if public then require
/*
        var userkey = _getUserKey(oldDoc);
        if (userkey != null) {
            requireUser(userkey);
        } else {
        channel('!');
            requireAdmin();
        }
*/
        _log('doc deleted, id: ' + (doc._id || 'no id!') + ', ' + (oldDoc ? ('old key=' + oldDoc.key + ', userkey=' + oldDoc.userkey) : 'no oldDoc'));
        return;
    }
    _log('doc id: ' + (doc._id || 'no id!') + ', ' + (oldDoc ? ('old key=' + oldDoc.key + ', userkey=' + oldDoc.userkey) : 'no oldDoc'));
    // Document type is mandatory
    if (typeof doc.type === 'undefined') {
        throw ({ forbidden: "Document type is required. id=" + JSON.stringify(doc) });
    }
    //  --> Moved to import filter!
    // Some document types not allowed on mobile
    /*
    if (doc.type == 'EnvLake' || doc.type == 'EnvMeasurement' || doc.type == 'ActivityLog' || doc.type == 'Image') {
        throw ({ forbidden: "Document type " + doc.type + " not allowed to sync to mobile..." });
    }
    // Some document types not allowed on mobile
    if(oldDoc != null) {
        if (doc.type == 'EnvLake' || doc.type == 'EnvMeasurement' || doc.type == 'ActivityLog' || doc.type == 'Image') {
            throw ({ forbidden: "Document type " + doc.type + " not allowed to sync to mobile..." });
        }
    }
    */
    // Document key is mandatory
    if (typeof doc.key === 'undefined') {
    throw ({ forbidden: "Document key is required. id=" + doc._id });
    }
    // Allow anyone to create a Feedback on the server
    if (oldDoc == null && doc.type == 'Feedback') {
        _log('Created feedback: ' + (doc._id || 'no id!') + ', key: ' + doc.key + ', user: ' + doc.userkey);
        return;
    }

    // All public docs are available in the app
    if (doc.ispublic) {
        _log('public, id: ' + (doc._id || 'no id!'));
        channel('!');
    }
    // All non-club fishing trips and catches are available (for stats)
    if ((doc.type == 'FishingTrip' || doc.type == 'Catch') && doc.clubonlykey === 'undefined') {
        _log('non-club trips, id: ' + (doc._id || 'no id!'));
        channel('!');
    }
    // All non-specific user info is available (for stats)
    if (doc.type == 'User') {
        _log('User doc, id: ' + (doc._id || 'no id!'));
        channel('!');
    }

    // Only non-public docs "owned" by user can be replicated
    var userkey = _getUserKey(doc);
    if (userkey != null) {
        if (oldDoc != null) {
            // Update
            if (oldDoc.type != doc.type) {
                throw ({ forbidden: "Can't change doc type" });
            }
            if (oldDoc.key != doc.key) {
                throw ({ forbidden: "Can't change doc key" });
            }
            if (oldDoc.userkey && oldDoc.userkey != doc.userkey) {
                throw ({ forbidden: "Can't change user key" });
            }
        }
        _log('User owned, id: ' + (doc._id || 'no id!') + ', type: ' + doc.type + ', user: ' + doc.userkey);
        if(doc.ispublic){
            requireAdmin();
        }
        requireUser(userkey);
        channel('channel.' + userkey);
        access(userkey, 'channel.' + userkey);
    }
}

What happens is that some of the Image documents are synced to the mobile as soon as the replicator is started. One of these look like this:

{
  "file": "/9j/4AAQSkZJRgA....p//Z",
  "datetaken": "2019-09-12T07:43:18+0200",
  "ispublic": true,
  "thumbnailfile": "/9j/4AAQSkZJRg....==",
  "type": "Image",
  "parenttype": "Photo",
  "key": "5FFB49585CB0BDBFC1258473001F6E1F",
  "userkey": "2124DEFEC111BA8FC1257ED20034B387"
}

And the meta data of the same document:

{
  "meta": {
    "id": "Photo:Image:5FFB49585CB0BDBFC1258473001F6E1F",
    "rev": "43-15c39a86c2c800000000000002000000",
    "expiration": 0,
    "flags": 33554432,
    "type": "json"
  },
  "xattrs": {}
}

So it does have ispublic set to true and even the same userkey as the the user that the replication is running under…

But, the way I understand import filters it shouldn’t even consider these attributes of the document when the import filter returns false for all documents of this type???

So what did I not understand?

The reason these control fields are on the document is due to an earlier implementation where these documents were synced to mobile. Now the images are loaded via http on request instead of spending space and bandwith as replicated documents…

Topic		Replies	Views
Console.log is not working on SG Sync Gateway	4	794	January 7, 2020
Using console.log() in sync function Sync Gateway	4	1369	August 29, 2019
Console.log is not working in sync function Sync Gateway	6	2603	February 19, 2020
Console logging stopped working in SG 2.5 Sync Gateway	3	960	August 28, 2019
SG (2.1) documentation about logging Sync Gateway	1	854	April 13, 2019

How to log "console.log(..)" from sync function to a file?

Related topics