"go test -v -timeout 1h0m0s -remote TestBox: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsChangeNotify$'" - Starting (try 2/5)
=== RUN   TestIntegration
    fstests.go:442: Using remote "TestBox:"
2025/02/19 04:49:51 DEBUG : Creating backend with remote "TestBox:rclone-test-letuqeb0sale"
2025/02/19 04:49:51 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/02/19 04:49:52 DEBUG : box root 'rclone-test-letuqeb0sale': Ignoring "Shared folder — ForNick" - unknown type "web_link"
2025/02/19 04:49:54 DEBUG : box root 'rclone-test-letuqeb0sale': Ignoring "Shared folder — ForNick" - unknown type "web_link"
=== RUN   TestIntegration/FsMkdir
=== RUN   TestIntegration/FsMkdir/FsChangeNotify
2025/02/19 04:49:56 INFO  : dir: Making directory
2025/02/19 04:49:58 INFO  : dir/subdir1: Making directory
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425344894")
2025/02/19 04:49:59 INFO  : dir/subdir3: Making directory
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': Received 5 events, resulting in 0 paths and 0 notifications
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425346155")
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["rclone-test-cinucef8nite"(3)|folder|ITEM_TRASH|308123773807|077049296598c49b3487e27b735b851359a0dc8d] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["êé"(1)|folder|ITEM_TRASH|308124616292|8ddfda3ecc5149f2ce21962ad27f2d9ff274be2b] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["Hello, 世界"(1)|folder|ITEM_TRASH|308125439064|247cc4db0469d78312b41926422ac932e3cbf68a] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': [" \" ' @ < > & ? + ≠"(1)|folder|ITEM_TRASH|308123324876|e5c4e89cc6411b5c483f40dd6910d41eba97a6b5] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["z.txt"(4)|file|ITEM_TRASH|1781692463094|cf86e1ddc8aae8f8f0053e4cfdc47981c1512f24] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["piped data.txt"(0)|file|ITEM_UPLOAD|1781684307768|5c8b462379d0c2695b7d4b41952e97dee7f4ca1f] new parent not found
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': Received 6 events, resulting in 0 paths and 0 notifications
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425346428")
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["rclone-test-cinucef8nite"(3)|folder|ITEM_TRASH|308123773807|077049296598c49b3487e27b735b851359a0dc8d] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["êé"(1)|folder|ITEM_TRASH|308124616292|8ddfda3ecc5149f2ce21962ad27f2d9ff274be2b] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["Hello, 世界"(1)|folder|ITEM_TRASH|308125439064|247cc4db0469d78312b41926422ac932e3cbf68a] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': [" \" ' @ < > & ? + ≠"(1)|folder|ITEM_TRASH|308123324876|e5c4e89cc6411b5c483f40dd6910d41eba97a6b5] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["z.txt"(4)|file|ITEM_TRASH|1781692463094|cf86e1ddc8aae8f8f0053e4cfdc47981c1512f24] ignored due to duplicate EventID
2025/02/19 04:49:59 DEBUG : box root 'rclone-test-letuqeb0sale': ["piped data.txt"(0)|file|ITEM_UPLOAD|1781684307768|5c8b462379d0c2695b7d4b41952e97dee7f4ca1f] ignored due to duplicate EventID
2025/02/19 04:50:00 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425346675")
2025/02/19 04:50:00 INFO  : dir/subdir2: Making directory
2025/02/19 04:50:01 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425347418")
2025/02/19 04:50:02 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425348449")
2025/02/19 04:50:02 DEBUG : box root 'rclone-test-letuqeb0sale': ["êé"(1)|folder|ITEM_TRASH|308124616292|8ddfda3ecc5149f2ce21962ad27f2d9ff274be2b] ignored due to duplicate EventID
2025/02/19 04:50:02 DEBUG : box root 'rclone-test-letuqeb0sale': ["Hello, 世界"(1)|folder|ITEM_TRASH|308125439064|247cc4db0469d78312b41926422ac932e3cbf68a] ignored due to duplicate EventID
2025/02/19 04:50:02 DEBUG : box root 'rclone-test-letuqeb0sale': [" \" ' @ < > & ? + ≠"(1)|folder|ITEM_TRASH|308123324876|e5c4e89cc6411b5c483f40dd6910d41eba97a6b5] ignored due to duplicate EventID
2025/02/19 04:50:02 DEBUG : box root 'rclone-test-letuqeb0sale': ["z.txt"(4)|file|ITEM_TRASH|1781692463094|cf86e1ddc8aae8f8f0053e4cfdc47981c1512f24] ignored due to duplicate EventID
2025/02/19 04:50:02 DEBUG : box root 'rclone-test-letuqeb0sale': ["piped data.txt"(0)|file|ITEM_UPLOAD|1781684307768|5c8b462379d0c2695b7d4b41952e97dee7f4ca1f] ignored due to duplicate EventID
2025/02/19 04:50:03 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425349178")
2025/02/19 04:50:03 DEBUG : box root 'rclone-test-letuqeb0sale': ["z.txt"(4)|file|ITEM_TRASH|1781692463094|cf86e1ddc8aae8f8f0053e4cfdc47981c1512f24] ignored due to duplicate EventID
2025/02/19 04:50:03 DEBUG : box root 'rclone-test-letuqeb0sale': ["piped data.txt"(0)|file|ITEM_UPLOAD|1781684307768|5c8b462379d0c2695b7d4b41952e97dee7f4ca1f] ignored due to duplicate EventID
2025/02/19 04:50:04 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425350164")
2025/02/19 04:50:04 DEBUG : box root 'rclone-test-letuqeb0sale': ["piped data.txt"(0)|file|ITEM_UPLOAD|1781684307768|5c8b462379d0c2695b7d4b41952e97dee7f4ca1f] ignored due to duplicate EventID
2025/02/19 04:50:05 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425351672")
2025/02/19 04:50:06 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425352139")
2025/02/19 04:50:07 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425353189")
2025/02/19 04:50:08 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425354135")
2025/02/19 04:50:09 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425355144")
2025/02/19 04:50:10 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425356138")
    fstests.go:935: Try 1/10 waiting for dirChanges and objChanges
2025/02/19 04:50:11 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425357138")
2025/02/19 04:50:12 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425358174")
2025/02/19 04:50:12 DEBUG : box root 'rclone-test-letuqeb0sale': ["rclone-test-letuqeb0sale"(0)|folder|ITEM_CREATE|308124049288|a4d6ed14b9bde39e5bab2b76c64fe112f6bc70de] new parent not found
2025/02/19 04:50:12 DEBUG : box root 'rclone-test-letuqeb0sale': ["dir"(0)|folder|ITEM_CREATE|308124580153|f8aebf9d385101af263c051e008b3b189b034d7c] added new path ("dir") for notify
2025/02/19 04:50:12 DEBUG : doChangeNotify("dir", 0)
2025/02/19 04:50:12 DEBUG : box root 'rclone-test-letuqeb0sale': Received 2 events, resulting in 1 paths and 1 notifications
2025/02/19 04:50:12 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425359139")
2025/02/19 04:50:13 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425359400")
    fstests.go:935: Try 2/10 waiting for dirChanges and objChanges
2025/02/19 04:50:14 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425360137")
2025/02/19 04:50:15 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425361149")
2025/02/19 04:50:15 DEBUG : box root 'rclone-test-letuqeb0sale': ["rclone-test-letuqeb0sale"(0)|folder|ITEM_CREATE|308124049288|a4d6ed14b9bde39e5bab2b76c64fe112f6bc70de] ignored due to duplicate EventID
2025/02/19 04:50:15 DEBUG : box root 'rclone-test-letuqeb0sale': ["dir"(0)|folder|ITEM_CREATE|308124580153|f8aebf9d385101af263c051e008b3b189b034d7c] ignored due to duplicate EventID
2025/02/19 04:50:15 DEBUG : box root 'rclone-test-letuqeb0sale': ["subdir1"(0)|folder|ITEM_CREATE|308123111857|34f7e2110e689645b1e6a6fc497c2eb64a02377e] added new path ("dir/subdir1") for notify
2025/02/19 04:50:15 DEBUG : doChangeNotify("dir/subdir1", 0)
2025/02/19 04:50:15 DEBUG : box root 'rclone-test-letuqeb0sale': Received 3 events, resulting in 1 paths and 1 notifications
2025/02/19 04:50:15 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425362159")
2025/02/19 04:50:16 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425362408")
    fstests.go:935: Try 3/10 waiting for dirChanges and objChanges
2025/02/19 04:50:17 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425363151")
2025/02/19 04:50:18 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425364140")
2025/02/19 04:50:18 DEBUG : box root 'rclone-test-letuqeb0sale': ["subdir1"(0)|folder|ITEM_CREATE|308123111857|34f7e2110e689645b1e6a6fc497c2eb64a02377e] ignored due to duplicate EventID
2025/02/19 04:50:19 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425365135")
    fstests.go:935: Try 4/10 waiting for dirChanges and objChanges
2025/02/19 04:50:19 DEBUG : box root 'rclone-test-letuqeb0sale': ["subdir1"(0)|folder|ITEM_CREATE|308123111857|34f7e2110e689645b1e6a6fc497c2eb64a02377e] ignored due to duplicate EventID
2025/02/19 04:50:20 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425366158")
2025/02/19 04:50:21 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425367136")
2025/02/19 04:50:22 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425368136")
    fstests.go:935: Try 5/10 waiting for dirChanges and objChanges
2025/02/19 04:50:23 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425369130")
2025/02/19 04:50:24 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425370125")
2025/02/19 04:50:25 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425371129")
    fstests.go:935: Try 6/10 waiting for dirChanges and objChanges
2025/02/19 04:50:26 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425372128")
2025/02/19 04:50:27 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425373131")
2025/02/19 04:50:28 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425374125")
    fstests.go:935: Try 7/10 waiting for dirChanges and objChanges
2025/02/19 04:50:29 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425375125")
2025/02/19 04:50:30 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425376122")
2025/02/19 04:50:31 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425377134")
    fstests.go:935: Try 8/10 waiting for dirChanges and objChanges
2025/02/19 04:50:32 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425378125")
2025/02/19 04:50:33 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425379120")
2025/02/19 04:50:34 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425380125")
    fstests.go:935: Try 9/10 waiting for dirChanges and objChanges
2025/02/19 04:50:35 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425381123")
2025/02/19 04:50:36 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425382125")
2025/02/19 04:50:37 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425383127")
    fstests.go:939: map[dir:{} dir/subdir1:{}] does not contain [dir/subdir1 dir/subdir3 dir/subdir2] or 
        map[] does not contain [dir/file2 dir/file4 dir/file3]
2025/02/19 04:50:38 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425384128")
2025/02/19 04:50:39 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425385132")
2025/02/19 04:50:40 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425386123")
2025/02/19 04:50:41 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425387130")
2025/02/19 04:50:42 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425388146")
2025/02/19 04:50:42 DEBUG : box root 'rclone-test-letuqeb0sale': ["subdir3"(0)|folder|ITEM_CREATE|308124820749|2f54ff502f1c92c463a3f745096dd488a3e3e902] added new path ("dir/subdir3") for notify
2025/02/19 04:50:42 DEBUG : doChangeNotify("dir/subdir3", 0)
2025/02/19 04:50:42 DEBUG : box root 'rclone-test-letuqeb0sale': Received 1 events, resulting in 1 paths and 1 notifications
2025/02/19 04:50:42 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425389135")
2025/02/19 04:50:42 DEBUG : box root 'rclone-test-letuqeb0sale': ["subdir3"(0)|folder|ITEM_CREATE|308124820749|2f54ff502f1c92c463a3f745096dd488a3e3e902] ignored due to duplicate EventID
2025/02/19 04:50:43 DEBUG : box root 'rclone-test-letuqeb0sale': Checking for changes on remote (next_stream_position: "30401037425389376")
2025/02/19 04:50:45 DEBUG : box root 'rclone-test-letuqeb0sale': Ignoring "Shared folder — ForNick" - unknown type "web_link"
2025/02/19 04:50:45 ERROR : : error listing: directory not found
2025/02/19 04:50:46 DEBUG : box root 'rclone-test-letuqeb0sale': Ignoring "Shared folder — ForNick" - unknown type "web_link"
--- FAIL: TestIntegration (54.56s)
    --- FAIL: TestIntegration/FsMkdir (50.29s)
        --- FAIL: TestIntegration/FsMkdir/FsChangeNotify (47.15s)
FAIL
exit status 1
FAIL	github.com/rclone/rclone/backend/box	54.569s
"go test -v -timeout 1h0m0s -remote TestBox: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsChangeNotify$'" - Finished ERROR in 55.353087363s (try 2/5): exit status 1: Failed [TestIntegration/FsMkdir/FsChangeNotify]