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

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 :smiley: ).

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