skicka - panic: no parents, but path isn't "."?

46 views

Skip to first unread message

Rasta G.

unread,

Apr 16, 2015, 2:38:23 AM4/16/15

to skicka...@googlegroups.com

Hi,

with "old" skicka I am able to list My Drive root:

xxx@xxx:~$ skicka20150403 -verbose -debug -config=/home/xxx/.skicka.config-xxx ls /

2015/04/16 08:22:30 GetFileById: root

2015/04/16 08:22:30 Running query: trashed=false and '0AHGeSBTyPxUOUk9PVA' in parents

...

xxx@xxx:~$

But with new updated skicka with local metadata cache funcionality not:

xxx@xxx:~$ skicka -verbose -debug -config=/home/xxx/.skicka.config-xxx ls /

2015/04/16 08:22:36 Read max change id 20433361

2015/04/16 08:22:37 done updating from drive 2015-04-16 08:22:37.231529694 +0200 CEST

2015/04/16 08:22:43 Done reading file cache from disk @ 2015-04-16 08:22:43.38785249 +0200 CEST

2015/04/16 08:22:43 File cache has 1753575 items

2015/04/16 08:22:43 getFileById: root

panic: no parents, but path isn't "."?

goroutine 1 [running]:

runtime.panic(0x68c5c0, 0xc25d35ebf0)

/usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6

github.com/google/skicka/gdrive.getFilePath(0xc233233a40, 0x1e, 0xc233233aa0, 0x1c, 0xc2100659c0, ...)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:699 +0x1e1

github.com/google/skicka/gdrive.(*GDrive).UpdateMetadataCache(0xc210065780, 0xc2100654b0, 0x20, 0x0, 0x0)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:573 +0x56e

github.com/google/skicka/gdrive.New(0xc21001fb90, 0x48, 0xc21006b160, 0x18, 0xc210065420, ...)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:344 +0x4ea

main.main()

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:830 +0x8bf

goroutine 4 [chan receive]:

main.func·003()

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:821 +0x3f

created by main.main

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:824 +0x80e

goroutine 5 [sleep]:

time.Sleep(0x7735940)

/usr/lib/go/src/pkg/runtime/time.goc:31 +0x31

github.com/google/skicka/gdrive.func·003()

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/readers.go:86 +0x14b

created by github.com/google/skicka/gdrive.launchBandwidthTask

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/readers.go:88 +0x13f

goroutine 8 [syscall]:

runtime.goexit()

/usr/lib/go/src/pkg/runtime/proc.c:1394

goroutine 9 [IO wait]:

net.runtime_pollWait(0x7f501f844d28, 0x72, 0x0)

/usr/lib/go/src/pkg/runtime/netpoll.goc:116 +0x6a

net.(*pollDesc).Wait(0xc2100644c0, 0x72, 0x7f501f843110, 0xb)

/usr/lib/go/src/pkg/net/fd_poll_runtime.go:81 +0x34

net.(*pollDesc).WaitRead(0xc2100644c0, 0xb, 0x7f501f843110)

/usr/lib/go/src/pkg/net/fd_poll_runtime.go:86 +0x30

net.(*netFD).Read(0xc210064460, 0xc222c62000, 0x1000, 0x1000, 0x0, ...)

/usr/lib/go/src/pkg/net/fd_unix.go:204 +0x2a0

net.(*conn).Read(0xc210000a48, 0xc222c62000, 0x1000, 0x1000, 0x71eaa0, ...)

/usr/lib/go/src/pkg/net/net.go:122 +0xc5

crypto/tls.(*block).readFromUntil(0xc210073b40, 0x7f501f844e58, 0xc210000a48, 0x5, 0xc210000a48, ...)

/usr/lib/go/src/pkg/crypto/tls/conn.go:459 +0xb6

crypto/tls.(*Conn).readRecord(0xc210053a00, 0x17, 0x0, 0x8)

/usr/lib/go/src/pkg/crypto/tls/conn.go:539 +0x107

crypto/tls.(*Conn).Read(0xc210053a00, 0xc223137000, 0x1000, 0x1000, 0x0, ...)

/usr/lib/go/src/pkg/crypto/tls/conn.go:897 +0x135

bufio.(*Reader).fill(0xc223134240)

/usr/lib/go/src/pkg/bufio/bufio.go:91 +0x110

bufio.(*Reader).Peek(0xc223134240, 0x1, 0x0, 0x0, 0x0, ...)

/usr/lib/go/src/pkg/bufio/bufio.go:119 +0xcb

net/http.(*persistConn).readLoop(0xc210059600)

/usr/lib/go/src/pkg/net/http/transport.go:687 +0xb7

created by net/http.(*Transport).dialConn

/usr/lib/go/src/pkg/net/http/transport.go:528 +0x607

goroutine 10 [select]:

net/http.(*persistConn).writeLoop(0xc210059600)

/usr/lib/go/src/pkg/net/http/transport.go:791 +0x271

created by net/http.(*Transport).dialConn

/usr/lib/go/src/pkg/net/http/transport.go:529 +0x61e

xxx@xxx:~$

xxx@xxx:~$ ls -la .skicka.*

-rw------- 1 xxx xxx 886 Apr 3 11:05 .skicka.config-xxx

-rw------- 1 xxx xxx 886 Apr 3 11:25 .skicka.config-yyy

-rw------- 1 xxx xxx 314384468 Apr 16 08:33 .skicka.metadata.cache

-rw------- 1 xxx xxx 246 Apr 16 08:20 .skicka.tokencache.json

-rw------- 1 xxx xxx 246 Apr 16 08:32 .skicka.tokencache.json-xxx

-rw------- 1 xxx xxx 225 Apr 3 11:26 .skicka.tokencache.json-yyy

BTW. first metadata cache update took about 4 hours (1753575 items).

Thanks,

Rasta

Matt Pharr

unread,

Apr 17, 2015, 7:55:42 PM4/17/15

to Rasta G., skicka...@googlegroups.com

Hmm, very curious. I've tried to audit the code to figure out why this could be happening, but haven't had any luck. I just pushed an update with some improved error logging; would you mind running it again and sending the output? (You may want to elide some file/path names in the output if they're sensitive, etc.)

That's a very long initial metadata cache initialization (and a large file to store it all)--I'll see what can be done to improve both of those. I hope that the performance that the cache gives is worth it!

Thanks,

Matt

--
You received this message because you are subscribed to the Google Groups "skicka-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to skicka-users...@googlegroups.com.
To post to this group, send email to skicka...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/skicka-users/2dc7c74d-498f-49ae-84bf-0ce837952380%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Radek Šafránek

unread,

Apr 18, 2015, 4:45:06 PM4/18/15

to ma...@pharr.org, skicka...@googlegroups.com

Hi Matt,

skicka update:

xxx@xxx:~$ go get -u github.com/google/skicka

list:

xxx@xxx:~$ skicka -debug ls /

2015/04/18 19:52:05 Read max change id 20437844

Updating metadata cache: [--------------------------------------------------------------------------------------------------------------------------------------------------------------------] 0.00 % 2015/04/18 19:52:14 Done reading file cache from disk

Updating metadata cache: [========================================================================>-------------------------------------------------------------------------------------] 45.83 % 13m3s

memory usage (from other terminal - top):

top - 20:03:19 up 15 min, 1 user, load average: 0.21, 0.34, 0.34

Tasks: 204 total, 1 running, 202 sleeping, 0 stopped, 1 zombie

%Cpu(s): 2.2 us, 0.5 sy, 0.0 ni, 97.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st

KiB Mem: 8128880 total, 3764956 used, 4363924 free, 65296 buffers

KiB Swap: 8343548 total, 0 used, 8343548 free. 1083412 cached Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

3078 xxx 20 0 1717532 1.341g 4160 S 1.0 17.3 0:32.94 skicka -debug ls /

xxx@xxx:~$ skicka -debug ls /

2015/04/18 19:52:05 Read max change id 20437844

Updating metadata cache: [============================================================================================================================================================] 100.00 % 44m41s

2015/04/18 20:36:48 Done updating metadata from Drive

2015/04/18 20:36:48 File cache has 1758209 items

2015/04/18 20:36:48 Writing updated file cache to disk: maxChangeId now 20932522

2015/04/18 20:36:51 /tmp/skicka.metadata603273540 -> /home/xxx/.skicka.metadata.cache: rename failed. Trying manual copy.

2015/04/18 20:36:52 Done writing new file cache to disk

2015/04/18 20:36:53 getFileById: root

panic: no parents for file &{Path:pictures_osobni_bankovnictvi FileSize:0 Id:0BwXQf59uibEgS0lwOXdfd1lldFk Md5: MimeType:application/vnd.google-apps.folder ModTime:2014-09-10 16:52:27 +0000 UTC ParentIds:[] Properties:[]} with WIP path proc-platit-kartou.jpg but parent path isn't "."?

goroutine 1 [running]:

runtime.panic(0x68c5c0, 0xc289ca1e80)

/usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6

github.com/google/skicka/gdrive.getFilePath(0xc22f856cc0, 0x16, 0xc22f856d40, 0x1c, 0xc210065960, ...)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:700 +0x2d7

github.com/google/skicka/gdrive.(*GDrive).UpdateMetadataCache(0xc210065720, 0xc2100654b0, 0x20, 0x0, 0x0)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:573 +0x56e

github.com/google/skicka/gdrive.New(0xc21001fb90, 0x48, 0xc21006b1a0, 0x18, 0xc210065420, ...)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:344 +0x4ea

main.main()

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:830 +0x8bf

goroutine 4 [chan receive]:

main.func·003()

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:821 +0x3f

created by main.main

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:824 +0x80e

goroutine 5 [sleep]:

time.Sleep(0x7735940)

/usr/lib/go/src/pkg/runtime/time.goc:31 +0x31

github.com/google/skicka/gdrive.func·003()

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/readers.go:86 +0x14b

created by github.com/google/skicka/gdrive.launchBandwidthTask

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/readers.go:88 +0x13f

goroutine 8 [syscall]:

runtime.goexit()

/usr/lib/go/src/pkg/runtime/proc.c:1394

goroutine 9 [IO wait]:

net.runtime_pollWait(0x7f6d94f44b00, 0x72, 0x0)

/usr/lib/go/src/pkg/runtime/netpoll.goc:116 +0x6a

net.(*pollDesc).Wait(0xc2100644c0, 0x72, 0x7f6d94f43110, 0xb)

/usr/lib/go/src/pkg/net/fd_poll_runtime.go:81 +0x34

net.(*pollDesc).WaitRead(0xc2100644c0, 0xb, 0x7f6d94f43110)

/usr/lib/go/src/pkg/net/fd_poll_runtime.go:86 +0x30

net.(*netFD).Read(0xc210064460, 0xc222fb3000, 0x1000, 0x1000, 0x0, ...)

/usr/lib/go/src/pkg/net/fd_unix.go:204 +0x2a0

net.(*conn).Read(0xc210000a48, 0xc222fb3000, 0x1000, 0x1000, 0xb18a28, ...)

/usr/lib/go/src/pkg/net/net.go:122 +0xc5

crypto/tls.(*block).readFromUntil(0xc2100705a0, 0x7f6d94f44c30, 0xc210000a48, 0x5, 0xc210000a48, ...)

/usr/lib/go/src/pkg/crypto/tls/conn.go:459 +0xb6

crypto/tls.(*Conn).readRecord(0xc210053a00, 0x17, 0x0, 0x8)

/usr/lib/go/src/pkg/crypto/tls/conn.go:539 +0x107

crypto/tls.(*Conn).Read(0xc210053a00, 0xc222fad000, 0x1000, 0x1000, 0x0, ...)

/usr/lib/go/src/pkg/crypto/tls/conn.go:897 +0x135

bufio.(*Reader).fill(0xc222f68ba0)

/usr/lib/go/src/pkg/bufio/bufio.go:91 +0x110

bufio.(*Reader).Peek(0xc222f68ba0, 0x1, 0x0, 0x0, 0x0, ...)

/usr/lib/go/src/pkg/bufio/bufio.go:119 +0xcb

net/http.(*persistConn).readLoop(0xc210059600)

/usr/lib/go/src/pkg/net/http/transport.go:687 +0xb7

created by net/http.(*Transport).dialConn

/usr/lib/go/src/pkg/net/http/transport.go:528 +0x607

goroutine 10 [select]:

net/http.(*persistConn).writeLoop(0xc210059600)

/usr/lib/go/src/pkg/net/http/transport.go:791 +0x271

created by net/http.(*Transport).dialConn

/usr/lib/go/src/pkg/net/http/transport.go:529 +0x61e

xxx@xxx:~$

old skicka:

xxx@xxx:~$ skicka20150403 -debug ls /

2015/04/18 22:14:52 GetFileById: root

2015/04/18 22:14:52 Running query: trashed=false and '0AHGeSBTyPxUOUk9PVA' in parents

xxx/

xxxxxxxx/

xxxxxxxxxxxxxxxxx

xxx/

xxxxxxxx/

xxx@xxx:~$

metadata cache file size:

xxx@xxx:~$ ls -lah .skicka.metadata.cache

-rw------- 1 xxx xxx 301M Apr 18 20:36 .skicka.metadata.cache

repeated list:

xxx@xxx:~$ skicka -debug ls /

2015/04/18 22:20:11 Read max change id 20932522

2015/04/18 22:20:12 Done updating metadata from Drive

2015/04/18 22:20:18 Done reading file cache from disk

2015/04/18 22:20:18 File cache has 1758209 items

2015/04/18 22:20:18 getFileById: root

panic: no parents for file &{Path:proof.de FileSize:0 Id:0BwXQf59uibEgczZ2ZWdROEhEeW8 Md5: MimeType:application/vnd.google-apps.folder ModTime:2014-07-23 10:37:57.908 +0000 UTC ParentIds:[] Properties:[]} with WIP path proof.xml but parent path isn't "."?

goroutine 1 [running]:

runtime.panic(0x68c5c0, 0xc25c120aa0)

/usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6

github.com/google/skicka/gdrive.getFilePath(0xc24b251410, 0x9, 0xc24b253520, 0x1c, 0xc210065960, ...)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:700 +0x2d7

github.com/google/skicka/gdrive.(*GDrive).UpdateMetadataCache(0xc210065720, 0xc2100654b0, 0x20, 0x0, 0x0)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:573 +0x56e

github.com/google/skicka/gdrive.New(0xc21001fb90, 0x48, 0xc21006b1a0, 0x18, 0xc210065420, ...)

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/gdrive.go:344 +0x4ea

main.main()

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:830 +0x8bf

goroutine 4 [chan receive]:

main.func·003()

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:821 +0x3f

created by main.main

/home/xxx/opt/go/src/github.com/google/skicka/skicka.go:824 +0x80e

goroutine 5 [sleep]:

time.Sleep(0x7735940)

/usr/lib/go/src/pkg/runtime/time.goc:31 +0x31

github.com/google/skicka/gdrive.func·003()

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/readers.go:86 +0x14b

created by github.com/google/skicka/gdrive.launchBandwidthTask

/home/xxx/opt/go/src/github.com/google/skicka/gdrive/readers.go:88 +0x13f

goroutine 8 [syscall]:

runtime.goexit()

/usr/lib/go/src/pkg/runtime/proc.c:1394

goroutine 9 [IO wait]:

net.runtime_pollWait(0x7f0e62601b00, 0x72, 0x0)

/usr/lib/go/src/pkg/runtime/netpoll.goc:116 +0x6a

net.(*pollDesc).Wait(0xc2100644c0, 0x72, 0x7f0e62600110, 0xb)

/usr/lib/go/src/pkg/net/fd_poll_runtime.go:81 +0x34

net.(*pollDesc).WaitRead(0xc2100644c0, 0xb, 0x7f0e62600110)

/usr/lib/go/src/pkg/net/fd_poll_runtime.go:86 +0x30

net.(*netFD).Read(0xc210064460, 0xc228fb0000, 0x1000, 0x1000, 0x0, ...)

/usr/lib/go/src/pkg/net/fd_unix.go:204 +0x2a0

net.(*conn).Read(0xc210000a48, 0xc228fb0000, 0x1000, 0x1000, 0x71eaa0, ...)

/usr/lib/go/src/pkg/net/net.go:122 +0xc5

crypto/tls.(*block).readFromUntil(0xc210074ab0, 0x7f0e62601c30, 0xc210000a48, 0x5, 0xc210000a48, ...)

/usr/lib/go/src/pkg/crypto/tls/conn.go:459 +0xb6

crypto/tls.(*Conn).readRecord(0xc210054a00, 0x17, 0x0, 0x8)

/usr/lib/go/src/pkg/crypto/tls/conn.go:539 +0x107

crypto/tls.(*Conn).Read(0xc210054a00, 0xc223dbd000, 0x1000, 0x1000, 0x0, ...)

/usr/lib/go/src/pkg/crypto/tls/conn.go:897 +0x135

bufio.(*Reader).fill(0xc223d96540)

/usr/lib/go/src/pkg/bufio/bufio.go:91 +0x110

bufio.(*Reader).Peek(0xc223d96540, 0x1, 0x0, 0x0, 0x0, ...)

/usr/lib/go/src/pkg/bufio/bufio.go:119 +0xcb

net/http.(*persistConn).readLoop(0xc21005a600)

/usr/lib/go/src/pkg/net/http/transport.go:687 +0xb7

created by net/http.(*Transport).dialConn

/usr/lib/go/src/pkg/net/http/transport.go:528 +0x607

goroutine 10 [select]:

net/http.(*persistConn).writeLoop(0xc21005a600)

/usr/lib/go/src/pkg/net/http/transport.go:791 +0x271

created by net/http.(*Transport).dialConn

/usr/lib/go/src/pkg/net/http/transport.go:529 +0x61e

xxx@xxx:~$

and again:

xxx@xxx:~$ skicka -debug ls /

2015/04/18 22:22:22 Read max change id 20932522

2015/04/18 22:22:23 Done updating metadata from Drive

2015/04/18 22:22:28 Done reading file cache from disk

2015/04/18 22:22:28 File cache has 1758209 items

2015/04/18 22:22:28 getFileById: root

goroutine 1 [running]:

runtime.panic(0x68c5c0, 0xc2651d3410)

/usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6

...

and again:

xxx@xxx:~$ skicka -debug ls /

2015/04/18 22:23:40 Read max change id 20932522

2015/04/18 22:23:40 Done updating metadata from Drive

2015/04/18 22:23:46 Done reading file cache from disk

2015/04/18 22:23:46 File cache has 1758209 items

2015/04/18 22:23:46 getFileById: root

goroutine 1 [running]:

runtime.panic(0x68c5c0, 0xc25e8cc0e0)

/usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6

....

xxx@xxx:~$ skicka -debug ls /

2015/04/18 22:25:43 Read max change id 20932522

2015/04/18 22:25:44 Done updating metadata from Drive

2015/04/18 22:25:50 Done reading file cache from disk

2015/04/18 22:25:50 File cache has 1758209 items

2015/04/18 22:25:50 getFileById: root

panic: no parents for file &{Path:psd FileSize:0 Id:0B9ZjO8Alt1XyUGxUOFZseDZUTlE Md5: MimeType:application/vnd.google-apps.folder ModTime:2015-04-02 09:15:56.651 +0000 UTC ParentIds:[] Properties:[]} with WIP path draft but parent path isn't "."?

goroutine 1 [running]:

and again with only few top output lines:

xxx@xxx:~$ skicka -debug ls / 2>&1 | head -n 7

2015/04/18 22:27:07 Read max change id 20932522

2015/04/18 22:27:08 Done updating metadata from Drive

2015/04/18 22:27:14 Done reading file cache from disk

2015/04/18 22:27:14 File cache has 1758209 items

2015/04/18 22:27:14 getFileById: root

panic: no parents for file &{Path:_production_ FileSize:0 Id:0BwXQf59uibEgYnpHVy1nRk9DZm8 Md5: MimeType:application/vnd.google-apps.folder ModTime:2014-09-11 03:02:48 +0000 UTC ParentIds:[] Properties:[]} with WIP path __common__ but parent path isn't "."?

xxx@xxx:~$

xxx@xxx~$ skicka -debug ls / 2>&1 | head -n 7

2015/04/18 22:27:21 Read max change id 20932522

2015/04/18 22:27:22 Done updating metadata from Drive

2015/04/18 22:27:28 Done reading file cache from disk

2015/04/18 22:27:28 File cache has 1758209 items

2015/04/18 22:27:28 getFileById: root

panic: no parents for file &{Path:proof.sk FileSize:0 Id:0BwXQf59uibEgQnd1WDZyNm5YdWs Md5: MimeType:application/vnd.google-apps.folder ModTime:2014-07-23 10:37:57.908 +0000 UTC ParentIds:[] Properties:[]} with WIP path proof.msi but parent path isn't "."?

xxx@xxx:~$ skicka -debug ls / 2>&1 | head -n 7

2015/04/18 22:27:36 Read max change id 20932522

2015/04/18 22:27:36 Done updating metadata from Drive

2015/04/18 22:27:42 Done reading file cache from disk

2015/04/18 22:27:42 File cache has 1758209 items

2015/04/18 22:27:42 getFileById: root

panic: no parents for file &{Path:proof.en FileSize:0 Id:0BwXQf59uibEgMHM0SF9JNDBGR2M Md5: MimeType:application/vnd.google-apps.folder ModTime:2014-07-23 10:37:57.908 +0000 UTC ParentIds:[] Properties:[]} with WIP path proof.xml but parent path isn't "."?

xxx@xxx:~$ skicka -debug ls / 2>&1 | head -n 7

2015/04/18 22:27:51 Read max change id 20932522

2015/04/18 22:27:52 Done updating metadata from Drive

2015/04/18 22:27:58 Done reading file cache from disk

2015/04/18 22:27:58 File cache has 1758209 items

2015/04/18 22:27:58 getFileById: root

Thanks,

Rasta

Reply all

Reply to author

Forward

0 new messages