acknowledge_abuse=true no longer working on a file

[puterboy]

The config option 'acknowledge_abuse' used to work for me, but I now have a file on google drive that is flagged as abuse by google drive.
Looking back in my logs, it seems like I was able to read the file using google-drive-ocamlfuse at least in October 2023.

Has anything changed since then in the google protocol for marking spam & malware.

Note: I unfortunately am stuck with an older version of google-drive-ocamlfuse (0.7.27) since my server still runs Ubuntu 20.04

[puterboy]

I upgraded to latest (0.7.32) and error persists.

In summary, the "malware" file is perfectly accessible using rclone to mount the drive. Also perfectly accessible from Windows using the official Google Drive install. But when I try to access it from google-drive-ocamlfuse, I get back an "Input/output error" regardless of whether acknowledge_abuse is set to true or false.

Interestingly, the debug logs for both the true and false abuse cases show that the file is detected as malware but in the true case it seems to trigger a backtrace error in the code (and fails to download) while in the false case it appropriately gracefully returns the Input/output error without triggering a backtrace error.

@astrada any ideas on why even with 'acknowledge_abuse' set, I still can't access file?

Specifically, in both cases I get the following:

# ls -al myfile.tgz
-rw-r--r-- 1 me me 43757341 Jul 30  2023 myfile.tgz
#time head ~/gdrive/file.tgz
head: error reading '/home/me/gdrive/file.tgz': Input/output error

real    0m22.929s
user    0m0.003s
sys     0m0.001s

(note time changes a little between runs but interestingly it takes almost half a minute to error out)

BOTH logs show the file is malware (though the error messaging is different)

Specifically, if acknowledge_abuse=true, then the log seems to show that the program itself errored (and creates a backtrace -- see below for full logs)

[4.077197] TID=10: BEGIN: Stream resource (id=4, offset=0, finish=1048575, length=1048576)
[16.291853] TID=10: Releasing memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, buffer id=1, state=Writing)
[16.291902] TID=10: Broadcasting streaming error (buffer id=1, state=Error(Failure("Error: {\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n    \"errors\": [\n      {\n        \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n        \"domain\": \"global\",\n        \"reason\": \"cannotDownloadAbusiveFile\"\n      }\n    ]\n  }\n}\n\255\004\004\003\002\001\1340\015\006\003U\029\019\001\001\255\004\0050\003\001\001\2550\029\006\003U\029\014\004\022\004\020T\176{\173E\184\226@\127\251\nn\251\1903\201<\163\132\2130\n\006\b*\134H\206=\004\003\002\003G (HTTP response code: 403)")))
[16.298729] TID=10: Error during request: Error: {
  "error": {
    "code": 403,
    "message": "This file has been identified as malware or spam and cannot be downloaded.",
    "errors": [
      {
        "message": "This file has been identified as malware or spam and cannot be downloaded.",
        "domain": "global",
        "reason": "cannotDownloadAbusiveFile"
      }
    ]
  }
}
 ����� 0���U���� ��0��� 0���U������T { E  @� 
n  3 <   0
��* H =����G (HTTP response code: 403)
[16.298759] TID=10: Giving up
[16.298774] TID=10: Exception:Failure("Error: {\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n    \"errors\": [\n      {\n        \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n        \"domain\": \"global\",\n        \"reason\": \"cannotDownloadAbusiveFile\"\n      }\n    ]\n  }\n}\n\255\004\004\003\002\001\1340\015\006\003U\029\019\001\001\255\004\0050\003\001\001\2550\029\006\003U\029\014\004\022\004\020T\176{\173E\184\226@\127\251\nn\251\1903\201<\163\132\2130\n\006\b*\134H\206=\004\003\002\003G (HTTP response code: 403)")

while if acknowledge_abuse=false, the log shows it detected the malware and gracefully sent an "Input/output error"

[2.763368] TID=10: BEGIN: Stream resource (id=4, offset=0, finish=1048575, length=1048576)
[15.274509] TID=10: Service error: {"error":{"errors":[{"domain":"global","reason":"cannotDownloadAbusiveFile","message":"This file has been identified as malware or spam and cannot be downloaded."}],"code":403,"message":"This file has been identified as malware or spam and cannot be downloaded."}}.
[15.274524] TID=10: Releasing memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, buffer id=1, state=Writing)
[15.274535] TID=10: Broadcasting streaming error (buffer id=1, state=Error(Drive.IO_error))
[15.279097] TID=10: Input/output error: read /file.tgz
[15.279287] TID=12: read /file.tgz [4096 bytes] 0 0

---

Full log for acknowledge_abuse=true

[0.000302] TID=0: Setting up default filesystem...
[0.000324] TID=0: BEGIN: Saving configuration in /home/me/.gdfuse/default/config
[0.001017] TID=0: END: Saving configuration in /home/me/.gdfuse/default/config
[0.001261] TID=0: Loading application state from /home/me/.gdfuse/default/state...done
Current version: 0.7.32
Docs mode not changed!
Cleaning up cache...done
Setting up cache db...done
Setting up CURL...done
Refresh token already present.
[0.011052] TID=0: Starting filesystem /home/me/gdrive
[0.028769] TID=1: init_filesystem
[0.028820] TID=1: Starting flush DB thread (TID=2, interval=30s)
[0.028863] TID=1: Starting async upload thread (TID=3)
[0.029194] TID=5: getattr /.Trash
[0.029218] TID=5: BEGIN: Loading metadata from db
[0.029224] TID=5: END: Getting metadata: Not found
[0.029228] TID=5: BEGIN: Refreshing metadata
[0.348760] TID=5: END: Refreshing metadata
[0.348771] TID=5: BEGIN: Getting changes from server
[0.478149] TID=5: END: Getting metadata: No need to update resource cache
[0.478177] TID=5: BEGIN: Updating timestamps
[0.478212] TID=5: END: Updating timestamps
[0.478230] TID=5: BEGIN: Updating metadata in db
[0.478244] TID=5: END: Updating metadata in db
[0.478248] TID=5: BEGIN: Updating context
[0.478261] TID=5: END: Updating context
[0.490795] TID=5: BEGIN: Getting root folder id (team drive id=, root folder=) from server
[0.490906] TID=5: BEGIN: Getting root resource from server
[0.742146] TID=5: END: Getting root resource (id=0AC0vymXplmO0Uk9PVA) from server
[0.742177] TID=5: END: Getting root folder id (id=0AC0vymXplmO0Uk9PVA) from server
[0.754732] TID=5: BEGIN: Loading resource / (trashed=true) from db
[0.754785] TID=5: END: Loading resource / (trashed=true) from db: Not found
[0.754812] TID=5: BEGIN: Saving root resource to db
[0.754847] TID=5: END: Saving root resource to db (id=1)
[0.755309] TID=6: getattr /.Trash/1001
[0.755375] TID=6: BEGIN: Getting metadata from context
[0.755392] TID=6: END: Getting metadata: Valid
[0.755407] TID=6: BEGIN: Loading resource /1001 (trashed=true) from db
[0.755434] TID=6: END: Loading resource /1001 (trashed=true) from db: Not found
[0.755452] TID=6: BEGIN: Loading resource / (trashed=true) from db
[0.755475] TID=6: END: Loading resource / (trashed=true) from db: Found (id=1, state=ToDownload)
[0.755520] TID=6: BEGIN: Getting resource 1001 (in folder0AC0vymXplmO0Uk9PVA) from server
[1.053340] TID=6: END: Getting resource 1001 (in folder 0AC0vymXplmO0Uk9PVA) from server
[1.053351] TID=6: BEGIN: Saving not found resource to db (name=1001)
[1.053368] TID=6: END: Saving not found resource to db (name=1001)
[1.059044] TID=6: File not found: stat /.Trash/1001
[1.059413] TID=7: getattr /.Trash-1001
[1.059443] TID=7: BEGIN: Getting metadata from context
[1.059451] TID=7: END: Getting metadata: Valid
[1.059459] TID=7: BEGIN: Loading resource /.Trash-1001 (trashed=false) from db
[1.059479] TID=7: END: Loading resource /.Trash-1001 (trashed=false) from db: Not found
[1.059488] TID=7: BEGIN: Loading resource / (trashed=false) from db
[1.059500] TID=7: END: Loading resource / (trashed=false) from db: Not found
[1.059525] TID=7: BEGIN: Getting resource .Trash-1001 (in folder0AC0vymXplmO0Uk9PVA) from server
[1.314857] TID=7: END: Getting resource .Trash-1001 (in folder 0AC0vymXplmO0Uk9PVA) from server
[1.314888] TID=7: BEGIN: Saving not found resource to db (name=.Trash-1001)
[1.314926] TID=7: END: Saving not found resource to db (name=.Trash-1001)
[1.327362] TID=7: File not found: stat /.Trash-1001
[3.800953] TID=8: getattr /file.tgz
[3.801034] TID=8: BEGIN: Getting metadata from context
[3.801051] TID=8: END: Getting metadata: Valid
[3.801066] TID=8: BEGIN: Loading resource /file.tgz (trashed=false) from db
[3.801094] TID=8: END: Loading resource /file.tgz (trashed=false) from db: Not found
[3.801117] TID=8: BEGIN: Loading resource / (trashed=false) from db
[3.801143] TID=8: END: Loading resource / (trashed=false) from db: Not found
[3.801187] TID=8: BEGIN: Getting resource file.tgz (in folder0AC0vymXplmO0Uk9PVA) from server
[4.068490] TID=8: END: Getting resource file.tgz (in folder 0AC0vymXplmO0Uk9PVA) from server
[4.068558] TID=8: BEGIN: Saving resource to db (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0)
[4.068603] TID=8: END: Saving resource to db (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, id=4, state=ToDownload)
[4.076144] TID=9: fopen /file.tgz O_RDONLY
[4.076169] TID=9: BEGIN: Getting metadata from context
[4.076175] TID=9: END: Getting metadata: Valid
[4.076180] TID=9: BEGIN: Loading resource /file.tgz (trashed=false) from db
[4.076190] TID=9: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[4.076411] TID=10: read /file.tgz [16384 bytes] 0 0
[4.076430] TID=10: BEGIN: Getting metadata from context
[4.076439] TID=10: END: Getting metadata: Valid
[4.076443] TID=10: BEGIN: Loading resource /file.tgz (trashed=false) from db
[4.076452] TID=10: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[4.076459] TID=10: BEGIN: Getting metadata from context
[4.076464] TID=10: END: Getting metadata: Valid
[4.076467] TID=10: BEGIN: Loading resource /file.tgz (trashed=false) from db
[4.076475] TID=10: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[4.076504] TID=10: Starting buffer eviction thread (TID=11)
[4.076516] TID=10: BEGIN: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, resource_size=43757341, start_pos=0)
[4.077183] TID=10: END: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, size=1048576, buffer id=1)
[4.077197] TID=10: BEGIN: Stream resource (id=4, offset=0, finish=1048575, length=1048576)
[16.291853] TID=10: Releasing memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, buffer id=1, state=Writing)
[16.291902] TID=10: Broadcasting streaming error (buffer id=1, state=Error(Failure("Error: {\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n    \"errors\": [\n      {\n        \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n        \"domain\": \"global\",\n        \"reason\": \"cannotDownloadAbusiveFile\"\n      }\n    ]\n  }\n}\n\255\004\004\003\002\001\1340\015\006\003U\029\019\001\001\255\004\0050\003\001\001\2550\029\006\003U\029\014\004\022\004\020T\176{\173E\184\226@\127\251\nn\251\1903\201<\163\132\2130\n\006\b*\134H\206=\004\003\002\003G (HTTP response code: 403)")))
[16.298729] TID=10: Error during request: Error: {
  "error": {
    "code": 403,
    "message": "This file has been identified as malware or spam and cannot be downloaded.",
    "errors": [
      {
        "message": "This file has been identified as malware or spam and cannot be downloaded.",
        "domain": "global",
        "reason": "cannotDownloadAbusiveFile"
      }
    ]
  }
}
 ����� 0���U���� ��0��� 0���U������T { E  @� 
n  3 <   0
��* H =����G (HTTP response code: 403)
[16.298759] TID=10: Giving up
[16.298774] TID=10: Exception:Failure("Error: {\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n    \"errors\": [\n      {\n        \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n        \"domain\": \"global\",\n        \"reason\": \"cannotDownloadAbusiveFile\"\n      }\n    ]\n  }\n}\n\255\004\004\003\002\001\1340\015\006\003U\029\019\001\001\255\004\0050\003\001\001\2550\029\006\003U\029\014\004\022\004\020T\176{\173E\184\226@\127\251\nn\251\1903\201<\163\132\2130\n\006\b*\134H\206=\004\003\002\003G (HTTP response code: 403)")
Backtrace:
[16.298953] TID=12: read /file.tgz [4096 bytes] 0 0
[16.298979] TID=12: BEGIN: Getting metadata from context
[16.298986] TID=12: END: Getting metadata: Valid
[16.298991] TID=12: BEGIN: Loading resource /file.tgz (trashed=false) from db
[16.299003] TID=12: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[16.299009] TID=12: BEGIN: Getting metadata from context
[16.299029] TID=12: END: Getting metadata: Valid
[16.299035] TID=12: BEGIN: Loading resource /file.tgz (trashed=false) from db
[16.299043] TID=12: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[16.299062] TID=12: BEGIN: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, resource_size=43757341, start_pos=0)
[16.299071] TID=12: END: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, size=1048576, buffer id=1)
[16.299078] TID=12: BEGIN: Stream resource (id=4, offset=0, finish=1048575, length=1048576)
[26.721404] TID=12: Releasing memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, buffer id=1, state=Writing)
[26.721481] TID=12: Broadcasting streaming error (buffer id=1, state=Error(Failure("Error: {\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n    \"errors\": [\n      {\n        \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n        \"domain\": \"global\",\n        \"reason\": \"cannotDownloadAbusiveFile\"\n      }\n    ]\n  }\n}\n\255\004\004\003\002\001\1340\015\006\003U\029\019\001\001\255\004\0050\003\001\001\2550\029\006\003U\029\014\004\022\004\020T\176{\173E\184\226@\127\251\nn\251\1903\201<\163\132\2130\n\006\b*\134H\206=\004\003\002\003G (HTTP response code: 403)")))
[26.726334] TID=12: Error during request: Error: {
  "error": {
    "code": 403,
    "message": "This file has been identified as malware or spam and cannot be downloaded.",
    "errors": [
      {
        "message": "This file has been identified as malware or spam and cannot be downloaded.",
        "domain": "global",
        "reason": "cannotDownloadAbusiveFile"
      }
    ]
  }
}
 ����� 0���U���� ��0��� 0���U������T { E  @� 
n  3 <   0
��* H =����G (HTTP response code: 403)
[26.726356] TID=12: Giving up
[26.726371] TID=12: Exception:Failure("Error: {\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n    \"errors\": [\n      {\n        \"message\": \"This file has been identified as malware or spam and cannot be downloaded.\",\n        \"domain\": \"global\",\n        \"reason\": \"cannotDownloadAbusiveFile\"\n      }\n    ]\n  }\n}\n\255\004\004\003\002\001\1340\015\006\003U\029\019\001\001\255\004\0050\003\001\001\2550\029\006\003U\029\014\004\022\004\020T\176{\173E\184\226@\127\251\nn\251\1903\201<\163\132\2130\n\006\b*\134H\206=\004\003\002\003G (HTTP response code: 403)")
Backtrace:
[26.726898] TID=13: flush /file.tgz 0
[26.726918] TID=13: BEGIN: Loading resource /file.tgz (trashed=false) from db
[26.726931] TID=13: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[26.727087] TID=14: release /file.tgz O_RDONLY
[26.727104] TID=14: BEGIN: Loading resource /file.tgz (trashed=false) from db
[26.727115] TID=14: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[30.036238] TID=2: Flushing DB...done
[97.757906] TID=0: Exiting.
[97.757942] TID=0: Stopping buffer eviction thread (TID=11)...done
[98.097489] TID=0: Stopping flush DB thread (TID=2)...done
[99.079142] TID=0: Stopping async upload thread (TID=3)
[100.054360] TID=3: Waiting for pending uploads (0)
[100.054485] TID=3: Waiting for pending upload threads (0)...done
[100.054588] TID=0: Flushing cache...
[100.054658] TID=0: Storing clean shutdown flag...done
[100.066207] TID=0: CURL cleanup...done
[100.066216] TID=0: Clearing context...done

Full log for acknowledge_abuse=false

[0.000311] TID=0: Setting up default filesystem...
[0.000330] TID=0: BEGIN: Saving configuration in /home/me/.gdfuse/default/config
[0.000954] TID=0: END: Saving configuration in /home/me/.gdfuse/default/config
[0.001028] TID=0: Loading application state from /home/me/.gdfuse/default/state...done
Current version: 0.7.32
Docs mode not changed!
Cleaning up cache...done
Setting up cache db...done
Setting up CURL...done
Refresh token already present.
[0.011193] TID=0: Starting filesystem /home/me/gdrive
[0.031664] TID=1: init_filesystem
[0.031708] TID=1: Starting flush DB thread (TID=2, interval=30s)
[0.031755] TID=1: Starting async upload thread (TID=3)
[0.032135] TID=5: getattr /.Trash
[0.032156] TID=5: BEGIN: Loading metadata from db
[0.032161] TID=5: END: Getting metadata: Not found
[0.032165] TID=5: BEGIN: Refreshing metadata
[0.367717] TID=5: END: Refreshing metadata
[0.367720] TID=5: BEGIN: Getting changes from server
[0.459310] TID=5: END: Getting metadata: No need to update resource cache
[0.459317] TID=5: BEGIN: Updating timestamps
[0.459326] TID=5: END: Updating timestamps
[0.459330] TID=5: BEGIN: Updating metadata in db
[0.459333] TID=5: END: Updating metadata in db
[0.459334] TID=5: BEGIN: Updating context
[0.459337] TID=5: END: Updating context
[0.463065] TID=5: BEGIN: Getting root folder id (team drive id=, root folder=) from server
[0.463094] TID=5: BEGIN: Getting root resource from server
[0.677115] TID=5: END: Getting root resource (id=0AC0vymXplmO0Uk9PVA) from server
[0.677124] TID=5: END: Getting root folder id (id=0AC0vymXplmO0Uk9PVA) from server
[0.681862] TID=5: BEGIN: Loading resource / (trashed=true) from db
[0.681878] TID=5: END: Loading resource / (trashed=true) from db: Not found
[0.681886] TID=5: BEGIN: Saving root resource to db
[0.681896] TID=5: END: Saving root resource to db (id=1)
[0.682171] TID=6: getattr /.Trash/1001
[0.682203] TID=6: BEGIN: Getting metadata from context
[0.682208] TID=6: END: Getting metadata: Valid
[0.682214] TID=6: BEGIN: Loading resource /1001 (trashed=true) from db
[0.682227] TID=6: END: Loading resource /1001 (trashed=true) from db: Not found
[0.682234] TID=6: BEGIN: Loading resource / (trashed=true) from db
[0.682243] TID=6: END: Loading resource / (trashed=true) from db: Found (id=1, state=ToDownload)
[0.682258] TID=6: BEGIN: Getting resource 1001 (in folder0AC0vymXplmO0Uk9PVA) from server
[0.979420] TID=6: END: Getting resource 1001 (in folder 0AC0vymXplmO0Uk9PVA) from server
[0.979434] TID=6: BEGIN: Saving not found resource to db (name=1001)
[0.979454] TID=6: END: Saving not found resource to db (name=1001)
[0.985325] TID=6: File not found: stat /.Trash/1001
[0.985685] TID=7: getattr /.Trash-1001
[0.985714] TID=7: BEGIN: Getting metadata from context
[0.985721] TID=7: END: Getting metadata: Valid
[0.985728] TID=7: BEGIN: Loading resource /.Trash-1001 (trashed=false) from db
[0.985747] TID=7: END: Loading resource /.Trash-1001 (trashed=false) from db: Not found
[0.985755] TID=7: BEGIN: Loading resource / (trashed=false) from db
[0.985766] TID=7: END: Loading resource / (trashed=false) from db: Not found
[0.985790] TID=7: BEGIN: Getting resource .Trash-1001 (in folder0AC0vymXplmO0Uk9PVA) from server
[1.251489] TID=7: END: Getting resource .Trash-1001 (in folder 0AC0vymXplmO0Uk9PVA) from server
[1.251519] TID=7: BEGIN: Saving not found resource to db (name=.Trash-1001)
[1.251558] TID=7: END: Saving not found resource to db (name=.Trash-1001)
[1.258712] TID=7: File not found: stat /.Trash-1001
[2.477720] TID=8: getattr /file.tgz
[2.477802] TID=8: BEGIN: Getting metadata from context
[2.477820] TID=8: END: Getting metadata: Valid
[2.477835] TID=8: BEGIN: Loading resource /file.tgz (trashed=false) from db
[2.477863] TID=8: END: Loading resource /file.tgz (trashed=false) from db: Not found
[2.477881] TID=8: BEGIN: Loading resource / (trashed=false) from db
[2.477911] TID=8: END: Loading resource / (trashed=false) from db: Not found
[2.477954] TID=8: BEGIN: Getting resource file.tgz (in folder0AC0vymXplmO0Uk9PVA) from server
[2.747397] TID=8: END: Getting resource file.tgz (in folder 0AC0vymXplmO0Uk9PVA) from server
[2.747471] TID=8: BEGIN: Saving resource to db (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0)
[2.747514] TID=8: END: Saving resource to db (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, id=4, state=ToDownload)
[2.760343] TID=9: fopen /file.tgz O_RDONLY
[2.760439] TID=9: BEGIN: Getting metadata from context
[2.760459] TID=9: END: Getting metadata: Valid
[2.760475] TID=9: BEGIN: Loading resource /file.tgz (trashed=false) from db
[2.760505] TID=9: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[2.760867] TID=10: read /file.tgz [16384 bytes] 0 0
[2.760926] TID=10: BEGIN: Getting metadata from context
[2.760943] TID=10: END: Getting metadata: Valid
[2.760965] TID=10: BEGIN: Loading resource /file.tgz (trashed=false) from db
[2.760994] TID=10: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[2.761013] TID=10: BEGIN: Getting metadata from context
[2.761026] TID=10: END: Getting metadata: Valid
[2.761043] TID=10: BEGIN: Loading resource /file.tgz (trashed=false) from db
[2.761067] TID=10: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[2.761163] TID=10: Starting buffer eviction thread (TID=11)
[2.761200] TID=10: BEGIN: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, resource_size=43757341, start_pos=0)
[2.763319] TID=10: END: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, size=1048576, buffer id=1)
[2.763368] TID=10: BEGIN: Stream resource (id=4, offset=0, finish=1048575, length=1048576)
[15.274509] TID=10: Service error: {"error":{"errors":[{"domain":"global","reason":"cannotDownloadAbusiveFile","message":"This file has been identified as malware or spam and cannot be downloaded."}],"code":403,"message":"This file has been identified as malware or spam and cannot be downloaded."}}.
[15.274524] TID=10: Releasing memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, buffer id=1, state=Writing)
[15.274535] TID=10: Broadcasting streaming error (buffer id=1, state=Error(Drive.IO_error))
[15.279097] TID=10: Input/output error: read /file.tgz
[15.279287] TID=12: read /file.tgz [4096 bytes] 0 0
[15.279308] TID=12: BEGIN: Getting metadata from context
[15.279315] TID=12: END: Getting metadata: Valid
[15.279320] TID=12: BEGIN: Loading resource /file.tgz (trashed=false) from db
[15.279331] TID=12: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[15.279337] TID=12: BEGIN: Getting metadata from context
[15.279342] TID=12: END: Getting metadata: Valid
[15.279346] TID=12: BEGIN: Loading resource /file.tgz (trashed=false) from db
[15.279353] TID=12: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[15.279371] TID=12: BEGIN: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, resource_size=43757341, start_pos=0)
[15.279380] TID=12: END: Acquiring memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, size=1048576, buffer id=1)
[15.279387] TID=12: BEGIN: Stream resource (id=4, offset=0, finish=1048575, length=1048576)
[28.539065] TID=12: Service error: {"error":{"errors":[{"domain":"global","reason":"cannotDownloadAbusiveFile","message":"This file has been identified as malware or spam and cannot be downloaded."}],"code":403,"message":"This file has been identified as malware or spam and cannot be downloaded."}}.
[28.539110] TID=12: Releasing memory buffer (remote id=1Ge0neftJu5tAlE95UO_h_sa4phCEw4n0, index=0, buffer id=1, state=Writing)
[28.539139] TID=12: Broadcasting streaming error (buffer id=1, state=Error(Drive.IO_error))
[28.551852] TID=12: Input/output error: read /file.tgz
[28.552830] TID=13: flush /file.tgz 0
[28.552893] TID=13: BEGIN: Loading resource /file.tgz (trashed=false) from db
[28.552929] TID=13: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[28.553238] TID=14: release /file.tgz O_RDONLY
[28.553294] TID=14: BEGIN: Loading resource /file.tgz (trashed=false) from db
[28.553367] TID=14: END: Loading resource /file.tgz (trashed=false) from db: Found (id=4, state=ToDownload)
[30.038223] TID=2: Flushing DB...done
[37.952492] TID=0: Exiting.
[37.952530] TID=0: Stopping buffer eviction thread (TID=11)...done
[38.771911] TID=0: Stopping flush DB thread (TID=2)...done
[39.068702] TID=0: Stopping async upload thread (TID=3)