Back button fails: The folder contents could not be displayed

[Mikko Ohtamaa]

gnome-obexftp 0.4
Nokia E70
G nome 2.18
Ubuntu Feisty Fawn

Steps to reproduce

1. Type in obex://
2. Click your phone
3. Click "E:" drive
4. Click any folder
5. Press back in Nautilus

Expected result:

Shows previous folder

Actual result:

Shows an error dialog: "The folder contents could not be displayed. Sorry, couldn't display all content of folder E:"

Workaround:

Click folder name in Nautlius location bar the folder is reloaded, displaying it properly

[Leszek Koltunski (leszek-3miasto)]

gnome-vfs-obexftp 0.4-1
bluez-utils 3.13-1
libbluetooth2 3.15-1 ( this is part of bluez-libs as packaged in Debian unstable )
USB bluetooth dongle
Nokia 6260

this 'folder contents could not be displayed' happens very often here, practically rendering the whole package useless.
More precisely, I enter 'obex://' to Nautilus, it properly displays the folders for some time, often I can even view images
stored in the phone's MMC, but ultimately it always starts displaying the dreaded 'folder contents could not be displayed'
error and from this point on it keeps doing so, no matter if I go back to folders I could display just 5 seconds ago or if I try
exploring new ones.

I've tried a lot of things, including upgrade of the kernel, bluez-utils, bluez-libs, but nothing helps. I can see no errors in
/var/log/*. Also, I am pretty confident that accessing the phone from command line with 'obexftp ****' works 100% reliably.

What can I do to help debug this?

[Leszek Koltunski (leszek-3miasto)]

I just tried the command

obexftp --bluetooth 00:11:9F:83:EC:DC --channel 12 --chdir E:/Images --list

30 times. Every single time the command returned what seems to be the correct output:

Browsing 00:11:9F:83:EC:DC ...
Channel: 10
Connecting...done
Sending "E:"... Sending "Images"... done
Receiving "(null)"...-<?xml version="1.0"?>
<!DOCTYPE folder-listing SYSTEM "obex-folder-listing.dtd"
  [ <!ATTLIST folder mem-type CDATA #IMPLIED>
  <!ATTLIST folder label CDATA #IMPLIED> ]>
<folder-listing version="1.0">
   <parent-folder />
   <file name="預設圖片名稱(102).jpg" size="62709" modified="20070707T194546Z" user-perm="RWD"/>
   <file name="預設圖片名稱(103).jpg" size="55899" modified="20070707T194502Z" user-perm="RWD"/>
   <file name="預設圖片名稱(105).jpg" size="77001" modified="20070707T194408Z" user-perm="RWD"/>
   <file name="預設圖片名稱(107).jpg" size="68235" modified="20070707T194310Z" user-perm="RWD"/>
   <file name="預設圖片名稱(108).jpg" size="67413" modified="20070707T194226Z" user-perm="RWD"/>
   <file name="預設圖片名稱(17).jpg" size="59742" modified="20060506T184318Z" user-perm="RWD"/>
   <file name="預設圖片名稱(18).jpg" size="38350" modified="20060506T184250Z" user-perm="RWD"/>
   <file name="預設圖片名稱(19).jpg" size="89109" modified="20060506T184144Z" user-perm="RWD"/>
   <file name="預設圖片名稱(20).jpg" size="107916" modified="20060506T184108Z" user-perm="RWD"/>
   <file name="預設圖片名稱(21).jpg" size="90334" modified="20060506T184034Z" user-perm="RWD"/>
   <file name="預設圖片名稱(22).jpg" size="103784" modified="20060506T183940Z" user-perm="RWD"/>
   <file name="預設圖片名稱(23).jpg" size="128575" modified="20060506T224954Z" user-perm="RWD"/>
   <file name="預設圖片名稱(24).jpg" size="107570" modified="20060506T224808Z" user-perm="RWD"/>
   <file name="預設圖片名稱(25).jpg" size="173383" modified="20060506T224728Z" user-perm="RWD"/>
   <file name="預設圖片名稱(27).jpg" size="115920" modified="20060506T224624Z" user-perm="RWD"/>
   <file name="預設圖片名稱(39).jpg" size="138720" modified="20061210T221422Z" user-perm="RWD"/>
   <file name="預設圖片名稱(52).jpg" size="85964" modified="20061210T221318Z" user-perm="RWD"/>
   <file name="預設圖片名稱(57).jpg" size="79759" modified="20061210T221242Z" user-perm="RWD"/>
   <file name="預設圖片名稱(58).jpg" size="91241" modified="20061210T221204Z" user-perm="RWD"/>
   <file name="預設圖片名稱(61).jpg" size="89720" modified="20070106T133308Z" user-perm="RWD"/>
   <file name="預設圖片名稱(62).jpg" size="93224" modified="20070106T133224Z" user-perm="RWD"/>
   <file name="預設圖片名稱(63).jpg" size="93741" modified="20070106T133116Z" user-perm="RWD"/>
   <file name="預設圖片名稱(64).jpg" size="142015" modified="20070106T132928Z" user-perm="RWD"/>
   <file name="預設圖片名稱(65).jpg" size="153838" modified="20070106T132842Z" user-perm="RWD"/>
   <file name="預設圖片名稱(66).jpg" size="56259" modified="20070707T202538Z" user-perm="RWD"/>
   <file name="預設圖片名稱(73).jpg" size="66003" modified="20070121T175652Z" user-perm="RWD"/>
   <file name="預設圖片名稱(75).jpg" size="68658" modified="20070122T125602Z" user-perm="RWD"/>
   <file name="預設圖片名稱(76).jpg" size="78706" modified="20070122T125522Z" user-perm="RWD"/>
   <file name="預設圖片名稱(79).jpg" size="77481" modified="20070707T202458Z" user-perm="RWD"/>
   <file name="預設圖片名稱(85).jpg" size="959...

[Leszek Koltunski (leszek-3miasto)]

1) I compiled the current bazaar, copied the resulting 'libobex.so' to /usr/lib/gnome-vfs-obexftp/modules'
( that's where Debian's package had this file ) and restarted X. The problem is still there.

2) I can see the '#define d(x)' in the code. If I redefine that to '#define d(x) x' I will see all those 'g_print's .
But where should I see them? Stdout? Syslog?

[Leszek Koltunski (leszek-3miasto)]

I have modified gnome-vfs-obexftp/osso-gwobex/src/Makefile , adding 'DEBUG' to compilation flags:

AM_CFLAGS = -DDEBUG $(am__append_1)

Now osso-gwobex logs to syslog. Here is an example log of a successful listing of a directory:

Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:242 (gw_obex_set_cancel_callback)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Unlocking GW_OBEX_LOCK at gw-obex.c:245 (gw_obex_set_cancel_callback)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:159 (gw_obex_read_dir)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_EV_STREAMAVAIL
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_HDR_LENGTH: 360
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_HDR_TYPE: x-obex/folder-listing
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: obex_readstream: got 360 bytes (360 in total)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_EV_STREAMAVAIL
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Error or no data on OBEX stream
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_EV_REQDONE
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Get command (0x03) succeeded.
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Unlocking GW_OBEX_LOCK at gw-obex.c:176 (gw_obex_read_dir)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:242 (gw_obex_set_cancel_callback)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Unlocking GW_OBEX_LOCK at gw-obex.c:245 (gw_obex_set_cancel_callback)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:134 (gw_obex_chdir)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_EV_REQDONE
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: SetPath command (0x05) succeeded.
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Unlocking GW_OBEX_LOCK at gw-obex.c:139 (gw_obex_chdir)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:134 (gw_obex_chdir)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_EV_REQDONE
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: SetPath command (0x05) succeeded.
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Unlocking GW_OBEX_LOCK at gw-obex.c:139 (gw_obex_chdir)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:242 (gw_obex_set_cancel_callback)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Unlocking GW_OBEX_LOCK at gw-obex.c:245 (gw_obex_set_cancel_callback)
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Attempting GW_OBEX_LOCK at gw-obex.c:159 (gw_obex_read_dir)...
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: got it!
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: OBEX_EV_REQDONE
Sep 12 23:19:24 tajwan gnome-vfs-daemon: gwobex: Get command (0x03) succeeded.
S...

[Leszek Koltunski (leszek-3miasto)]

Please disregard the last comment; that included debugs from osso-gwobex only.
Now I enabled (some) debugs in src/ and disabled in osso-gwobex/src/ and I can see some mighty strange behavior!

For example, when in Nautilus I am in obex://[....]/E:/ ( which contains folders 'Images', 'Others', 'Sounds', 'Videos' and '.Trash-leszek' )
and I click on 'Others' ( which contains files 'czaban.wav' and 'gnapplet.sis' ) , I can see the following:

Sep 13 02:02:42 tajwan gnome-vfs-daemon: devel: Connection timed out
Sep 13 02:02:42 tajwan gnome-vfs-daemon: devel: obex: om_connection_free calls disconnect
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: 'Images'
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: 'Others'
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: 'Sounds'
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: 'Videos'
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: '.Trash-leszek'
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: 'czaban.wav'
Sep 13 02:03:44 tajwan gnome-vfs-daemon: devel: Name: 'gnapplet.sis'
Sep 13 02:03:45 tajwan gnome-vfs-daemon: devel: Name: 'Images'
Sep 13 02:03:45 tajwan gnome-vfs-daemon: devel: Name: 'Others'
Sep 13 02:03:45 tajwan gnome-vfs-daemon: devel: Name: 'Sounds'
Sep 13 02:03:45 tajwan gnome-vfs-daemon: devel: Name: 'Videos'
Sep 13 02:03:45 tajwan gnome-vfs-daemon: devel: Name: '.Trash-leszek'
Sep 13 02:03:45 tajwan gnome-vfs-daemon: devel: do_get_volume_free_space: memory type is MMC
Sep 13 02:04:05 tajwan gnome-vfs-daemon: devel: Connection timed out
Sep 13 02:04:05 tajwan gnome-vfs-daemon: devel: obex: om_connection_free calls disconnect

We can see the following:

1) gnome-vfs-obexftp lists the folder E: (what for? )
2) then it lists the folder E:/Others ( good! that's the only thing that should happen, no?? )
3) then it lists E: again ( WTF??? )

Sometimes its even worse. I've seen a case when being in E:/Others and clicking 'Back' triggered the following:

1) list '/'
2) list '/'
3) list '/'
4) list '/' ( yes, 4 times it lists the root folder )
5) list E:
6) list E:/Others ( ??? )
7) list E:
8) list '/'

Looks like it will randomly list, rendom number of times, all the folders that are in the path of the current folder. Mighty strange!

******************************************************************************************
Additionally, quite often I can see the following:

Sep 13 02:01:39 tajwan gnome-vfs-daemon: devel: obex: folder listing parse failed: Couldn't parse the incoming data

This error manifests itself either by

a) nothing ( everything in Nautilus seems ok )
b) some folders missing
c) 'folder contents ould not be displayed' old friend of an error.

******************************************************************************************
Moreover, a few times I've seen the following:

Sep 13 02:01:20 tajwan gnome-vfs-daemon: devel: obex: Cancellation check => CANCEL
Sep 13 02:01:20 tajwan gnome-vfs-daemon: devel: Error: GW_OBEX_ERROR_ABORT

James, is this the expected behavior??

[Leszek Koltunski (leszek-3miasto)]

Solution: see bug 140478